SAB initiated shutdown throws exception and crashes

[colmconn]

SAB version 3.0.0RC1 OS FreeNAS 11.3 jail running FreeBSD 11.3

I changed from the default theme of Glitter - Default to Glitter - Night (The dark theme only applies to the front page and not the settings page, is that the way it's supposed to be (Firefox 77.0.1 macOS 10.15.5 with cache cleared before reloading the page)? When prompted by SAB to restart itself I let it do so whereupon it crashed. The following is the log from the start of running 3.0.0RC1 to crash. I had to manually restart to get it back up again. Please let me know if you need anything beyond the log file below.

`2020-06-26 09:59:45,815::INFO::[SABnzbd:1137] SABnzbd.py-3.0.0-develop (rev=unknown) 2020-06-26 09:59:45,815::INFO::[SABnzbd:1138] Full executable path = /usr/local/bin/SABnzbd.py 2020-06-26 09:59:45,816::INFO::[SABnzbd:1148] Platform = posix 2020-06-26 09:59:45,817::INFO::[SABnzbd:1149] Python-version = 3.7.7 (default, Mar 21 2020, 01:18:50) [Clang 8.0.0 (tags/RELEASE_800/final 356365)] 2020-06-26 09:59:45,817::INFO::[SABnzbd:1150] Arguments = "/usr/local/bin/SABnzbd.py" "--daemon" "-f" "/var/db/sabnzbd/sabnzbd.ini" "--pidfile" "/var/run/sabnzbd/sabnzbd.pid" 2020-06-26 09:59:45,817::INFO::[SABnzbd:1154] Not inside a docker container 2020-06-26 09:59:45,818::INFO::[SABnzbd:1157] Preferred encoding = UTF-8 2020-06-26 09:59:45,818::INFO::[SABnzbd:1169] SSL version = OpenSSL 1.0.2s-freebsd 28 May 2019 2020-06-26 09:59:45,818::INFO::[SABnzbd:1217] Using INI file /var/db/sabnzbd/sabnzbd.ini 2020-06-26 09:59:45,848::INFO::[postproc:138] Loading postproc queue 2020-06-26 09:59:45,851::INFO::[init:955] [N/A] /var/db/sabnzbd/admin/Rating.sab missing 2020-06-26 09:59:45,853::INFO::[scheduler:216] Setting schedule for midnight BPS reset 2020-06-26 09:59:45,867::INFO::[config:857] Writing settings to INI file /var/db/sabnzbd/sabnzbd.ini 2020-06-26 09:59:45,886::INFO::[init:350] All processes started 2020-06-26 09:59:45,887::INFO::[SABnzbd:292] Template location for Glitter is /usr/local/share/sabnzbdplus/interfaces/Glitter 2020-06-26 09:59:45,888::INFO::[SABnzbd:292] Template location for Config is /usr/local/share/sabnzbdplus/interfaces/Config 2020-06-26 09:59:45,927::INFO::[SABnzbd:393] SABYenc module (v4.0.1)... found! 2020-06-26 09:59:45,927::INFO::[SABnzbd:412] Cryptography module (v2.6.1)... found! 2020-06-26 09:59:45,928::INFO::[SABnzbd:417] par2 binary... found (/usr/local/bin/par2) 2020-06-26 09:59:45,928::INFO::[SABnzbd:424] UNRAR binary... found (/usr/local/bin/unrar) 2020-06-26 09:59:45,928::INFO::[SABnzbd:432] UNRAR binary version 5.90 2020-06-26 09:59:45,929::INFO::[SABnzbd:440] 7za binary... found (/usr/local/bin/7za) 2020-06-26 09:59:45,929::INFO::[SABnzbd:451] nice binary... found (/usr/bin/nice) 2020-06-26 09:59:45,930::INFO::[SABnzbd:457] ionice binary... NOT found! 2020-06-26 09:59:45,935::INFO::[SABnzbd:1403] Starting web-interface on 192.168.1.23:8080 2020-06-26 09:59:45,936::INFO::[_cplogging:216] [26/Jun/2020:09:59:45] ENGINE Bus STARTING 2020-06-26 09:59:45,944::INFO::[_cplogging:216] [26/Jun/2020:09:59:45] ENGINE Started monitor thread '_TimeoutMonitor'. 2020-06-26 09:59:46,118::INFO::[_cplogging:216] [26/Jun/2020:09:59:46] ENGINE Serving on http://192.168.1.23:8080 2020-06-26 09:59:46,119::INFO::[_cplogging:216] [26/Jun/2020:09:59:46] ENGINE Bus STARTED 2020-06-26 09:59:46,119::INFO::[SABnzbd:1440] Starting SABnzbd.py-3.0.0-develop 2020-06-26 09:59:46,125::INFO::[postproc:228] Completed Download Folder /mnt/media/spool/news/complete is not on FAT 2020-06-26 09:59:46,128::INFO::[dirscanner:117] Dirscanner starting up 2020-06-26 09:59:46,130::INFO::[urlgrabber:96] URLGrabber starting up 2020-06-26 09:59:46,465::INFO::[zconfig:71] No Bonjour/ZeroConfig support installed 2020-06-26 10:01:42,294::INFO::[config:857] Writing settings to INI file /var/db/sabnzbd/sabnzbd.ini 2020-06-26 10:01:47,944::INFO::[interface:1142] Restart requested by interface 2020-06-26 10:01:48,947::INFO::[init:389] SABnzbd shutting down... 2020-06-26 10:01:48,948::INFO::[directunpacker:524] Aborting all DirectUnpackers 2020-06-26 10:01:48,949::INFO::[urlgrabber:91] URLGrabber shutting down 2020-06-26 10:01:49,725::INFO::[dirscanner:108] Dirscanner shutting down 2020-06-26 10:01:50,661::INFO::[downloader:538] Shutting down 2020-06-26 10:01:50,662::INFO::[decoder:131] Shutting down decoder Thread-3 2020-06-26 10:01:50,662::INFO::[decoder:131] Shutting down decoder Thread-2 2020-06-26 10:01:50,663::INFO::[decoder:131] Shutting down decoder Thread-4 2020-06-26 10:01:50,664::INFO::[assembler:64] Shutting down 2020-06-26 10:01:50,665::INFO::[nzbqueue:224] Saving queue 2020-06-26 10:01:50,668::INFO::[postproc:132] Saving postproc queue 2020-06-26 10:01:50,669::INFO::[init:458] All processes stopped 2020-06-26 10:01:50,670::INFO::[_cplogging:216] [26/Jun/2020:10:01:50] ENGINE Bus STOPPING 2020-06-26 10:01:50,677::ERROR::[_cplogging:216] [26/Jun/2020:10:01:50] ENGINE Error in 'stop' listener <bound method ServerAdapter.stop of <cherrypy._cpserver.Server object at 0x8048cdd10>> Traceback (most recent call last): File "/usr/local/lib/python3.7/site-packages/cherrypy/process/wspbus.py", line 203, in publish output.append(listener(*args, **kwargs)) File "/usr/local/lib/python3.7/site-packages/cherrypy/process/servers.py", line 238, in stop self.httpserver.stop() File "/usr/local/lib/python3.7/site-packages/cherrypy/wsgiserver/wsgiserver3.py", line 1880, in stop self.requests.stop(self.shutdown_timeout) File "/usr/local/lib/python3.7/site-packages/cherrypy/wsgiserver/wsgiserver3.py", line 1377, in stop remaining_time = endtime - time.time() UnboundLocalError: local variable 'endtime' referenced before assignment

2020-06-26 10:01:50,678::INFO::[_cplogging:216] [26/Jun/2020:10:01:50] ENGINE Stopped thread '_TimeoutMonitor'.`

[thezoggy]

yes, skins do not skin the settings anymore (we used to do that pre 0.7.x days) but it was a huge pain to update the config for each skin and test just to add any option.

[thezoggy]

just tried this on 3.0RC1 windows binary and was unable to reproduce. switching from glitter -> glitter night, save. let it restart. no error. then switched back to glitter. still all clean.

[sanderjo]

A problem deep down in cherrypy / wsgiserver / cheroot. I think that is not something SABnzbd can prevent. It's an upstream problem.

I cannot reproduce on my Ubuntu 20.04 with SAB3 RC1.

I checked cherrypy / wsgiserver / cheroot on my Ubuntu 20.04, and I think this is the relevant part:

        if timeout is not None and timeout >= 0:
            endtime = time.time() + timeout
        while self._threads:
            worker = self._threads.pop()
            if worker is not current and worker.isAlive():
                try:
                    if timeout is None or timeout < 0:
                        worker.join()
                    else:
                        remaining_time = endtime - time.time()

The above looks safe if the first if is not triggered. Do you have this code on your FreeBSD: File "/usr/local/lib/python3.7/site-packages/cherrypy/wsgiserver/wsgiserver3.py", around line 1377?

FWIW It looks like the author of cheroot has rewritten his/her current code https://github.com/cherrypy/cheroot/blob/bd0f6d27061312686a20cd65b98c36ba3c0485a0/cheroot/workers/threadpool.py#L274-L290

So ... what can you do ... ? Most easy is to not switch interfaces, or do the manual restart if you need to.

[Safihre]

From the source of cheroot it was changed 4 years ago. So your version is really behind. Can you use pip install -r requirements.txt -U or is this a FreeBSD package provided by someone?

[sanderjo]

From the source of cheroot it was changed 4 years ago. So your version is really behind. Can you use pip install -r requirements.txt -U or is this a FreeBSD package provided by someone?

Oh, yes, of course.

And now I'm curious: @colmconn what is the output on your FreeBSD of

python3 -c "import cherrypy; print(cherrypy.__version__)"
python3 -c "import cheroot; print(cheroot.__version__)"

I get

$ python3 -c "import cherrypy; print(cherrypy.__version__)" 
8.9.1
$ python3 -c "import cheroot; print(cheroot.__version__)"
8.3.0

[colmconn]

The cause of the issue being in the version of py-cherrypy currently in ports (5.4.0) was pretty much the conclusion I came to yesterday.

Since SAB 3 no longer includes the cherrypy source, I patched the SAB ports Makefile to use the version of py-cherrypy currently in ports (5.4.0). SAB worked OK until I tried to change the theme.

I just patched the Makefile for www/py-cherrypy to build 8.9.1, built it, and installed the resultant package, restarted SAB, and tried to change the theme. This succeeded without the crash reported above.

I have no cheroot package installed since www/py-cherrypy doesn't depend on it and cheroot not listed in requirements.txt. Indeed cheroot 8.3.0 is currently in ports.