Bug 2012857

Summary:	unhandled exception when plugin timeout happens during logging a collected file
Product:	Red Hat Enterprise Linux 8	Reporter:	Pavel Moravec <pmoravec>
Component:	sos	Assignee:	Pavel Moravec <pmoravec>
Status:	CLOSED ERRATA	QA Contact:	Radek Duda <rduda>
Severity:	medium	Docs Contact:
Priority:	medium
Version:	---	CC:	agk, bmr, mhradile, plambri, rduda, sbradley, theute
Target Milestone:	rc	Keywords:	Triaged
Target Release:	---
Hardware:	ppc64le
OS:	Linux
Whiteboard:
Fixed In Version:	sos-4.2-4.el8	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:
Clones:	2012859 (view as bug list)		Environment:
Last Closed:	2022-05-10 15:16:36 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:
Bug Blocks:	2012859

Description Pavel Moravec 2021-10-11 13:21:01 UTC

Description of problem:
Spin-off from https://bugzilla.redhat.com/show_bug.cgi?id=1869561#c19 / https://bugzilla.redhat.com/show_bug.cgi?id=1869561#c20 . When *all* above happens:

- sos report run in verbose mode
- a plugin timeouts when still collecting files
- the plugin is/was running as the latest one

then there is a race condition where debug logs attempt to write to sos.log file that was already moved away from temp.location to the final destination.

I.e. https://github.com/sosreport/sos/issues/2722 needs to be fixed&backported.


Version-Release number of selected component (if applicable):
sos-4.2-1


How reproducible:
100%


Steps to Reproduce:
(bit artificial reproducer for QE):
sos report -o selinux --batch --build -k selinux.timeout=1 -vv

(real reproducer):
have a ppc64le system with hundreds of CPUs, such that collecting /sys/devices/system/cpu* takes >600s plugin timeout for sos report


Actual results:
a backtrace like:

Traceback (most recent call last):
  File "/usr/lib64/python3.6/logging/__init__.py", line 996, in emit
    stream.write(msg)
ValueError: I/O operation on closed file.
Call stack:
  File "/usr/lib64/python3.6/threading.py", line 884, in _bootstrap
    self._bootstrap_inner()
  File "/usr/lib64/python3.6/threading.py", line 916, in _bootstrap_inner
    self.run()
  File "/usr/lib64/python3.6/threading.py", line 864, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib64/python3.6/concurrent/futures/thread.py", line 69, in _worker
    work_item.run()
  File "/usr/lib64/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/root/sos-main/sos/report/__init__.py", line 1083, in collect_plugin
    plug.collect()
  File "/root/sos-main/sos/report/plugins/__init__.py", line 2667, in collect
    self._collect_copy_specs()
  File "/root/sos-main/sos/report/plugins/__init__.py", line 2631, in _collect_copy_specs
    self._log_info("collecting path '%s'" % path)
  File "/root/sos-main/sos/report/plugins/__init__.py", line 706, in _log_info
    self.soslog.info(self._format_msg(msg))
Message: "[plugin:selinux] collecting path '/var/lib/selinux/targeted/active/modules/100/ntp/cil'"
Arguments: ()
[plugin:selinux] collecting path '/var/lib/selinux/targeted/active/modules/100/ntp/cil'



Expected results:
no backtrace / segfault


Additional info:

Comment 4 errata-xmlrpc 2022-05-10 15:16:36 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (sos bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2022:1998