Description of problem:

While collecting sosreport , if a plugin gets timeout and at the same time if there a log file collection being done by that plugin and if the size of the file being collected is greater than default size limit (25 MiB as per man page of sosreport ) then the tailed log is not being captured.

To simulate this issue, we can add the "sleep 300" in the plugin file. However this can occur when any command in the plugin times out.
For example,

In file - /usr/lib/python3.6/site-packages/sos/report/plugins/logs.py
~~~
 90             else:
 91                 self.add_copy_spec([
 92                     "/var/log/syslog*",
 93                     "/var/log/kern.log*",
 94                     "/var/log/auth.log*",
 95                 ])
 96         self.add_cmd_output('sleep 300')     <--- Add this line inside setup()
 97 
 98     def postproc(self):
 99         self.do_path_regex_sub(
~~~

Make sure any file this plugin is going to collecting is bigger than 25 MiB.
For example on my system  I had /var/log/messages-20230508 which is greater than 25 MiB

~~~
2023-05-10 05:34:33,310 INFO: [plugin:logs] File '/var/log/messages-20230508' is over size limit, will instead tail the file during collection phase.
~~~

When the sosreport runs the log plugin , it get timeout because of the sleep command which it need to run for 300 seconds to run.
When this happens the log file which is greater than 25 MiB which we expect to  have the tailed logs collection of upto 25 MiB of the file for these file saved in the sos_strings as a symlink file.
However when the plugin timeouts, for example in case of the sleep command it skips the tailed log collection all together.


The collection happens in collect_plugin() method defined in /usr/lib/python3.6/site-packages/sos/report/plugins/__init__.py:
~~~
3184     def collect_plugin(self):
3185         """Collect the data for a plugin."""
3186         start = time()
3187         self._collect_copy_specs()
3188         self._collect_container_copy_specs()
3189         self._collect_tailed_files()
3190         self._collect_cmds()
3191         self._collect_strings()
3192         self._collect_manual()
~~~


Due to this, because of some command which timed out the log collection is incomplete even when the log collection is not getting timed out it not completed because collect_tailed_files() is done before running the collect_cmds() so the tailed log file is read into memory but not written to disk because collect_stings() is done after  the collect_cmds() completes. Which is timing out in our case and hence collect_strings() is not done.


By changing the ordering we were able to work around this issue,

If we change the ordering in the collect_plugin() to add the collection of `_collect_stings()` prior to the collection of `_collect_cmds()` to push the string collection before the tailed logs is captured.
~~~
    def collect_plugin(self):
        """Collect the data for a plugin."""
        start = time()
        self._collect_copy_specs()
        self._collect_container_copy_specs()
        self._collect_tailed_files()
        self._collect_strings()
        self._collect_cmds()
        self._collect_manual()
        fields = (self.name(), time() - start)
        self._log_debug("collected plugin '%s' in %s" % fields)
~~~

As per the seen in my test system, now we see that read() is done (possibly in _collect_tailed_files() )  and then before running command , writing is done (possibly in _collect_strings() ) and then commands (like sleep) are executed (possibly in _collect_cmds() )
~~~
# less sos.strace | grep -e 26214400  -e 'execve("/usr/bin/sleep"'
51071 09:09:44.987002 pread64(5</var/lib/rpm/Packages>, "\0\0\0\0\1\0\0\0\0\31\0\0\0\0\0\0\377\30\0\0\1\0\346\17\0\7\0\0\0K\0\1W\274\0\0\0?\0\0\0\7\0\1Q(\0\0\0\20\0\0\0d\0\0\0\10\0\0\0\0\0\0\0\1\0\0\3\350\0\0\0\6\0\0\0\2\0\0\0\1\0\0\3\351\0\0\0\6\0\0\0\23\0\0\0\1\0\0\3\352\0\0\0\6\0\0\0\34\0\0\0\1\0\0\3\353\0\0\0\4\0\0\0$\0\0"..., 4096, 26214400) = 4096 <0.000009>
51071 09:09:45.318863 pread64(5</var/lib/rpm/Packages>, "\0\0\0\0\1\0\0\0\0\372\0\0\377\371\0\0\1\372\0\0\1\0\346\17\0\7labs/puppet/lib/ruby/vendor_gems/gems/gettext-3.2.2/samples/cgi/po/uk/\0/opt/puppetlabs/puppet/lib/ruby"..., 4096, 262144000) = 4096 <0.000010>
51108 09:09:48.881786 lseek(5</var/log/messages-20230508>, -26214400, SEEK_END) = 8689563 <0.000008>
51108 09:09:48.882011 read(5</var/log/messages-20230508>, "046]: Found cgroup on /sys/fs/cgroup/systemd, legacy hierarchy\nMay  2 07:31:50 rhel8 systemd-user-runtime-dir[2046]: Failed to r"..., 26214401) = 26214400 <0.003822>
51108 09:09:48.925317 write(5</var/tmp/sos.k2a6qni0/sosreport-rhel8-2023-05-10-luhomlu/sos_strings/logs/var.log.messages-20230508.tailed>, "046]: Found cgroup on /sys/fs/cgroup/systemd, legacy hierarchy\nMay  2 07:31:50 rhel8 systemd-user-runtime-dir[2046]: Failed to r"..., 26214400 <unfinished ...>
51108 09:09:48.931311 <... write resumed>) = 26214400 <0.005949>
51123 09:09:50.633524 execve("/usr/bin/sleep", ["sleep", "300"], 0x7ffe085b0e60 /* 45 vars */) = 0 <0.000116>
50982 09:14:49.929088 lstat("/var/tmp/sos.k2a6qni0/sosreport-rhel8-2023-05-10-luhomlu/sos_strings/logs/var.log.messages-20230508.tailed", {st_mode=S_IFREG|0640, st_size=26214400, ...}) = 0 <0.000006>
50982 09:14:49.929835 fstat(12</var/tmp/sos.k2a6qni0/sosreport-rhel8-2023-05-10-luhomlu/sos_strings/logs/var.log.messages-20230508.tailed>, {st_mode=S_IFREG|0640, st_size=26214400, ...}) = 0 <0.000004>
50982 09:14:50.585211 newfstatat(13</var/tmp/sos.k2a6qni0/sosreport-rhel8-2023-05-10-luhomlu/sos_strings/logs>, "var.log.messages-20230508.tailed", {st_mode=S_IFREG|0640, st_size=26214400, ...}, AT_SYMLINK_NOFOLLOW) = 0 <0.000005>
~~~


OTHER Workaround we see is that , 

- To use "--log-size" parameter to extend this default size limit of 25 MiB based to a size you decide before hand which will not cause the tailed log collection to occur on the file you are intrested in by checking its size so the whole file is copied as is as log as its below the new size limit you define.
- Or use "--all-logs" both of which collect the whole file do not relay on tailed log collection so even when the command times out this copying of the whole file which likely happens in the _collect_copy_specs() which is done at the start and does not face any timeout issue due to commands.


So hence wanted to check if the above change of changing the order at which the _collect_strings() so as to enable this without affecting other functionality or if the there is other-way to do this.


Version-Release number of selected component (if applicable):
sos-4.5.1-3.el8.noarch


How reproducible:
Everytime.

Steps to Reproduce:
1. Add the "sleep 300" command to force the timeout, to a plugin like log.py at /usr/lib/python3.6/site-packages/sos/report/plugins/logs.py

   ~~~
   96         self.add_cmd_output('sleep 300')     <--- Add this line inside setup()
   ~~~

2. Confirm that you have a file /var/log/message greater than 25 MB. If not extend it size by adding some ascii text to it.

    # base64  < /dev/urandom | head -c 25M >> /var/log/messages

    # ls -lah /var/log/message

3. After this run the sosreport command and let it run till the log plugin times output.

    # sosreport -o logs

4. After check the extracted archive and you will see  that there is no tailed log collection done, in face the "sos_strings" directly is not present

   # tar -xvf <sosreport>
   # cd the <sosreport_extracted_directory>

   # ls -lah var/log/messages
   lrwxrwxrwx. 1 root root  55 May  8 03:38 var/log/messages  -> ../../sos_strings/logs/var.log.messages.tailed  <---(This symlink is broken)

   # No directory named "sos_string" present in the sos archive.


Actual results:
Tailed log collection is not saved to sosreport even when it read it not written to disk.


Expected results:
We want the tailed log collection to happen even when the command times out because that data is already read into memory during the before the command collection happens.

Additional info:
This is not only specific to log plugin but any plugin which collect tailed logs and store it in sos_strings for example the audit.py plugin and audit file also show similar behavior.