v3.4.0RC3 and before randomly stops responding
Posted: October 12th, 2021, 10:42 am
For quite a few of the past releases my server randomly just stops responding - the only way to resolve it is to restart the Windows service then it continues as if nothing happens. I did think it was my HAProxy server but restarting that makes no difference and trying to connect directly is still the same. I've tried enabling the debug logging but it's not telling me much that I can see. Basically nothing is happening for many hours, just my PC with the site open, not even a download and then it stops logging. The next thing logged is the shutdown of the service followed by the start-up, with the only thing of note before that is the execution of a garbage collection:
Any ideas or suggestions on what I can do to get more info on this?
Code: Select all
2021-10-12 07:23:15,501::DEBUG::[postproc:1042] Triggering garbage collection and release of memory
2021-10-12 07:23:16,861::DEBUG::[interface:130] Request GET /api from 192.168.1.1 (X-Forwarded-For: 192.168.1.19) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/94.0.4606.71 Safari/537.36] {'mode': 'queue', 'search': '', 'start': '0', 'limit': '50', 'output': 'json', 'apikey': '**redacted**', '_': '1633979583819'}
2021-10-12 07:23:16,864::DEBUG::[interface:130] Request GET /api from 192.168.1.1 (X-Forwarded-For: 192.168.1.19) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/94.0.4606.71 Safari/537.36] {'mode': 'history', 'search': '', 'failed_only': '0', 'start': '0', 'limit': '50', 'last_history_update': '62', 'output': 'json', 'apikey': '**redacted**', '_': '1633979583820'}
2021-10-12 14:52:53,318::DEBUG::[interface:130] Request GET /api from 192.168.1.1 (X-Forwarded-For: 192.168.1.19) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/94.0.4606.71 Safari/537.36] {'mode': 'history', 'search': '', 'failed_only': '0', 'start': '0', 'limit': '50', 'last_history_update': '62', 'output': 'json', 'apikey': '**redacted**', '_': '1633979611014'}
2021-10-12 14:52:55,299::DEBUG::[interface:130] Request GET /api from 192.168.1.1 (X-Forwarded-For: 192.168.1.19) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/94.0.4606.71 Safari/537.36] {'mode': 'queue', 'search': '', 'start': '0', 'limit': '50', 'output': 'json', 'apikey': '**redacted**', '_': '1633979611015'}
2021-10-12 14:52:55,303::DEBUG::[interface:130] Request GET /api from 192.168.1.1 (X-Forwarded-For: 192.168.1.19) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/94.0.4606.71 Safari/537.36] {'mode': 'history', 'search': '', 'failed_only': '0', 'start': '0', 'limit': '50', 'last_history_update': '62', 'output': 'json', 'apikey': '**redacted**', '_': '1633979611016'}
2021-10-12 14:52:57,308::DEBUG::[interface:130] Request GET /api from 192.168.1.1 (X-Forwarded-For: 192.168.1.19) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/94.0.4606.71 Safari/537.36] {'mode': 'queue', 'search': '', 'start': '0', 'limit': '50', 'output': 'json', 'apikey': '**redacted**', '_': '1633979611017'}
2021-10-12 17:22:55,982::INFO::[__init__:463] [SABnzbd.py.SvcStop] Performing SABnzbd shutdown
2021-10-12 17:22:55,983::INFO::[__init__:370] SABnzbd shutting down...
2021-10-12 17:22:55,983::INFO::[ssdp:102] Stopping SSDP
2021-10-12 17:22:55,983::INFO::[directunpacker:531] Aborting all DirectUnpackers
2021-10-12 17:22:55,984::DEBUG::[__init__:386] Stopping RSSReader
2021-10-12 17:22:55,984::DEBUG::[__init__:389] Stopping URLGrabber
2021-10-12 17:22:55,984::DEBUG::[__init__:396] Stopping rating
2021-10-12 17:22:56,086::DEBUG::[rating:141] Stopping ratings
2021-10-12 17:22:56,086::DEBUG::[__init__:403] Stopping dirscanner
2021-10-12 17:22:56,087::DEBUG::[__init__:410] Stopping downloader
2021-10-12 17:22:56,087::INFO::[notifier:122] Sending notification: SABnzbd - Shutting down (type=startup, job_cat=None)
2021-10-12 17:22:56,087::DEBUG::[downloader:216] Resetting article queue for <Server: ssl-eu.astraweb.com:443>
2021-10-12 17:22:56,088::DEBUG::[downloader:216] Resetting article queue for <Server: ssl.astraweb.com:443>
2021-10-12 17:22:56,088::DEBUG::[downloader:216] Resetting article queue for <Server: ssl-us.astraweb.com:443>
2021-10-12 17:22:56,088::INFO::[downloader:673] Shutting down
2021-10-12 17:22:56,088::DEBUG::[__init__:418] Stopping decoders
2021-10-12 17:22:56,089::INFO::[decoder:124] Shutting down decoder Thread-8
2021-10-12 17:22:56,089::INFO::[decoder:124] Shutting down decoder Thread-9
2021-10-12 17:22:56,089::INFO::[decoder:124] Shutting down decoder Thread-7
2021-10-12 17:22:56,089::DEBUG::[__init__:422] Stopping assembler
2021-10-12 17:22:56,090::INFO::[assembler:70] Shutting down
2021-10-12 17:22:56,090::INFO::[misc:1092] [sabnzbd\notifier.py.send_nscript] Running external command: ['D:\\Program Files\\SABnzbd\\scripts\\Notify.cmd', 'startup', 'SABnzbd: Startup/Shutdown', 'Shutting down', '[email protected]']
2021-10-12 17:22:56,090::DEBUG::[__init__:429] Stopping postprocessor
2021-10-12 17:22:56,090::DEBUG::[misc:1093] Popen arguments: {'stdin': -1, 'stdout': -1, 'stderr': -2, 'startupinfo': <subprocess.STARTUPINFO object at 0x0000022725DDCDC0>, 'creationflags': 16384, 'env': None}
2021-10-12 17:22:56,091::DEBUG::[articlecache:137] Saving 0 cached articles to disk
2021-10-12 17:22:56,091::INFO::[nzbqueue:235] Saving queue
2021-10-12 17:22:56,092::DEBUG::[__init__:962] [sabnzbd\nzbqueue.py.save] Saving data for queue10.sab
2021-10-12 17:22:56,092::DEBUG::[__init__:894] [sabnzbd\__init__.py.save_admin] Saving data for queue10.sab in \\?\D:\Program Files\SABnzbd\admin
2021-10-12 17:22:56,093::DEBUG::[__init__:962] [sabnzbd\bpsmeter.py.save] Saving data for totals10.sab
2021-10-12 17:22:56,093::DEBUG::[__init__:894] [sabnzbd\__init__.py.save_admin] Saving data for totals10.sab in \\?\D:\Program Files\SABnzbd\admin
2021-10-12 17:22:56,094::DEBUG::[__init__:962] [sabnzbd\rating.py.save] Saving data for Rating.sab
2021-10-12 17:22:56,095::DEBUG::[__init__:894] [sabnzbd\__init__.py.save_admin] Saving data for Rating.sab in \\?\D:\Program Files\SABnzbd\admin
2021-10-12 17:22:56,096::DEBUG::[__init__:962] [sabnzbd\dirscanner.py.save] Saving data for watched_data2.sab
2021-10-12 17:22:56,096::DEBUG::[__init__:894] [sabnzbd\__init__.py.save_admin] Saving data for watched_data2.sab in \\?\D:\Program Files\SABnzbd\admin
2021-10-12 17:22:56,097::INFO::[postproc:130] Saving postproc queue
2021-10-12 17:22:56,097::DEBUG::[__init__:962] [sabnzbd\postproc.py.save] Saving data for postproc2.sab
2021-10-12 17:22:56,097::DEBUG::[__init__:894] [sabnzbd\__init__.py.save_admin] Saving data for postproc2.sab in \\?\D:\Program Files\SABnzbd\admin
2021-10-12 17:22:56,099::DEBUG::[__init__:962] [sabnzbd\rss.py.save] Saving data for rss_data.sab
2021-10-12 17:22:56,099::DEBUG::[__init__:894] [sabnzbd\__init__.py.save_admin] Saving data for rss_data.sab in \\?\D:\Program Files\SABnzbd\admin
2021-10-12 17:22:56,100::DEBUG::[__init__:446] Terminating scheduler
2021-10-12 17:22:56,100::INFO::[__init__:449] All processes stopped
2021-10-12 17:22:56,100::INFO::[_cplogging:213] [12/Oct/2021:17:22:56] ENGINE Bus STOPPING
2021-10-12 17:22:56,408::INFO::[_cplogging:213] [12/Oct/2021:17:22:56] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('0.0.0.0', 8080)) shut down
2021-10-12 17:22:56,530::INFO::[_cplogging:213] [12/Oct/2021:17:22:56] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('0.0.0.0', 9090)) shut down
2021-10-12 17:22:56,530::INFO::[_cplogging:213] [12/Oct/2021:17:22:56] ENGINE Bus STOPPED
2021-10-12 17:22:56,530::INFO::[_cplogging:213] [12/Oct/2021:17:22:56] ENGINE Bus EXITING
2021-10-12 17:22:56,530::INFO::[_cplogging:213] [12/Oct/2021:17:22:56] ENGINE Bus EXITED
2021-10-12 17:22:56,531::INFO::[notifier:122] Sending notification: SABnzbd - SABnzbd shutdown finished (type=startup, job_cat=None)
2021-10-12 17:22:56,531::INFO::[SABnzbd:1611] Leaving SABnzbd
2021-10-12 17:22:56,533::INFO::[misc:1092] [sabnzbd\notifier.py.send_nscript] Running external command: ['D:\\Program Files\\SABnzbd\\scripts\\Notify.cmd', 'startup', 'SABnzbd: Startup/Shutdown', 'SABnzbd shutdown finished', '[email protected]']
2021-10-12 17:22:56,534::DEBUG::[misc:1093] Popen arguments: {'stdin': -1, 'stdout': -1, 'stderr': -2, 'startupinfo': <subprocess.STARTUPINFO object at 0x0000022724B70A90>, 'creationflags': 16384, 'env': None}
2021-10-12 17:22:57,256::INFO::[notifier:377] Successfully executed notification script D:\Program Files\SABnzbd\scripts\Notify.cmd
2021-10-12 17:23:04,629::INFO::[SABnzbd:1180] --------------------------------
2021-10-12 17:23:04,629::INFO::[SABnzbd:1181] SABnzbd.exe-3.4.2RC3
2021-10-12 17:23:04,629::INFO::[SABnzbd:1191] Commit = 4042a5fe5d619983882580ef79efdd9be3ee6c36
2021-10-12 17:23:04,629::INFO::[SABnzbd:1193] Full executable path = D:\Program Files\SABnzbd\SABnzbd.exe
2021-10-12 17:23:04,629::INFO::[SABnzbd:1194] Arguments = "D:\Program Files\SABnzbd\SABnzbd.exe"
2021-10-12 17:23:04,629::INFO::[SABnzbd:1195] Python-version = 3.9.7 (tags/v3.9.7:1016ef3, Aug 30 2021, 20:19:38) [MSC v.1929 64 bit (AMD64)]
2021-10-12 17:23:04,630::INFO::[SABnzbd:1196] Dockerized = False
2021-10-12 17:23:04,630::INFO::[SABnzbd:1197] CPU architecture = AMD64
2021-10-12 17:23:04,957::INFO::[SABnzbd:1200] Platform = nt - Windows-10-10.0.17763-SP0
2021-10-12 17:23:04,957::INFO::[SABnzbd:1206] Preferred encoding = cp1252
2021-10-12 17:23:04,957::INFO::[SABnzbd:1218] SSL version = OpenSSL 1.1.1l 24 Aug 2021
2021-10-12 17:23:04,958::INFO::[SABnzbd:1227] Certifi version = 2021.05.30
2021-10-12 17:23:04,958::INFO::[SABnzbd:1228] Loaded additional certificates from D:\Program Files\SABnzbd\certifi\cacert.pem
2021-10-12 17:23:04,991::DEBUG::[SABnzbd:1237] Available certificates = {'x509': 152, 'crl': 0, 'x509_ca': 150}
2021-10-12 17:23:04,991::DEBUG::[SABnzbd:1240] Local IPv4 address = 192.168.1.10
2021-10-12 17:23:05,219::DEBUG::[SABnzbd:1241] Public IPv4 address = **redacted**
2021-10-12 17:23:05,219::DEBUG::[SABnzbd:1242] IPv6 address = None
2021-10-12 17:23:05,460::DEBUG::[SABnzbd:1245] CPU Pystone available performance = 161289
2021-10-12 17:23:05,461::DEBUG::[SABnzbd:1246] CPU model = AMD Ryzen Threadripper 1900X 8-Core Processor
2021-10-12 17:23:05,461::INFO::[SABnzbd:1248] Using INI file \\?\D:\Program Files\SABnzbd\sabnzbd.ini
2021-10-12 17:23:05,532::DEBUG::[__init__:968] [sabnzbd\bpsmeter.py.read] Loading data for totals10.sab
2021-10-12 17:23:05,532::DEBUG::[__init__:927] [sabnzbd\__init__.py.load_admin] Loading data for totals10.sab from \\?\D:\Program Files\SABnzbd\admin\totals10.sab