[Errno 9] Bad file descriptor · Supervisor/supervisor#856

(0 comments) (0 reactions) (0 assignees)Python (7,941 stars) (1,233 forks)batch import

help wantedlogging

Description

i'm running supervisord==3.3.1(non-daemon args: -n) under pypy2 5.4.1 . after a moment, supervisor crashed, the log show "Bad file descripter", @mnaberez @mcdonc

os: CentOS release 6.7 (Final) Linux localhost.localdomain 2.6.32-573.el6.x86_64 #1 SMP Thu Jul 23 15:44:03 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

supervisord non-daemon log: Traceback (most recent call last): File "/opt/test/pypy2/bin/supervisord", line 11, in sys.exit(main()) File "/opt/test/pypy2/site-packages/supervisor/supervisord.py", line 365, in main go(options) File "/opt/test/pypy2/site-packages/supervisor/supervisord.py", line 375, in go d.main() File "/opt/test/pypy2/site-packages/supervisor/supervisord.py", line 84, in main self.run() File "/opt/test/pypy2/site-packages/supervisor/supervisord.py", line 101, in run self.runforever() File "/opt/test/pypy2/site-packages/supervisor/supervisord.py", line 234, in runforever combined_map[fd].handle_error() File "/opt/test/pypy2/site-packages/supervisor/dispatchers.py", line 50, in handle_error tbinfo File "/opt/test/pypy2/site-packages/supervisor/loggers.py", line 287, in critical self.log(LevelsByName.CRIT, msg, **kw) File "/opt/test/pypy2/site-packages/supervisor/loggers.py", line 293, in log handler.emit(record) File "/opt/test/pypy2/site-packages/supervisor/loggers.py", line 186, in emit self.doRollover() File "/opt/test/pypy2/site-packages/supervisor/loggers.py", line 211, in doRollover if not (self.stream.tell() >= self.maxBytes): IOError: [Errno 9] Bad file descriptor: '/opt/test/var/log/supervisord.log'

strace:

303 log file i checked, it's ok

close(282) = 0 close(285) = 0 close(291) = 0 close(292) = 0 close(303) = -1 EBADF (Bad file descriptor) write(2, "Exception IOError: IOError(9, 'B"..., 195) = 195 close(304) = -1 EBADF (Bad file descriptor) write(2, "Exception IOError: IOError(9, 'B"..., 195) = 195 close(308) = -1 EBADF (Bad file descriptor) write(2, "Exception IOError: IOError(9, 'B"..., 195) = 195 close(309) = -1 EBADF (Bad file descriptor) write(2, "Exception IOError: IOError(9, 'B"..., 195) = 195 close(313) = -1 EBADF (Bad file descriptor)

ulimit: core file size (blocks, -c) unlimited data seg size (kbytes, -d) unlimited scheduling priority (-e) 0 file size (blocks, -f) unlimited pending signals (-i) 386815 max locked memory (kbytes, -l) 3500000 max memory size (kbytes, -m) unlimited open files (-n) 1000000 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 10240 cpu time (seconds, -t) unlimited max user processes (-u) 131072 virtual memory (kbytes, -v) unlimited file locks (-x) unlimited

Contributor guide

Tech stack: python
Domain: backenddevops
Issue type: bug
Difficulty: 3
Estimated time: half day
Activity status: stale
Clarity: needs investigation
Prerequisites: Pythonfile descriptorsPyPysupervisor internals
Newbie friendliness: 20
Research direction: The error occurs in supervisor/loggers.py in the doRollover method when calling self.stream.tell(). The file descriptor may have been closed by PyPy's garbage collector. Investigate why fd 282,285,291,292 etc are being closed unexpectedly. Check if there is a known issue with PyPy and file descriptor management in supervisor. Look at loggers.py lines 186-211 and determine if the stream object's file descriptor is being finalized prematurely. Consider adding a guard to check if the stream is still open before calling tell().