Page 1 of 2
Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 7th, 2020, 6:02 pm
by RadioActiveLamb
I am running SABnzbd as a service. I installed the service as-per the instructions. It runs for HOURS without trouble, then it simply stops. This is the the Windows application event log for each time this happens:
The instance's SvcRun() method failed
Traceback (most recent call last):
File "win32serviceutil.py", line 839, in SvcRun
File "SABnzbd.py", line 1630, in SvcDoRun
File "SABnzbd.py", line 1529, in main
File "sabnzbd\__init__.py", line 1047, in check_all_tasks
File "sabnzbd\decorators.py", line 49, in call_func
File "sabnzbd\decorators.py", line 36, in call_func
File "sabnzbd\downloader.py", line 917, in check_timers
RuntimeError: dictionary changed size during iteration
%2: %3
I've seen this issue published in the forum under different circumstances, but I don't see any solution that applies to this situation. Any thoughts on the root cause? I'll set-up a watchdog script to run as local system to auto restart the service, should it stop again.
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 8th, 2020, 3:55 am
by safihre
Thanks for reporting.
You found a bug
Will fix!
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 8th, 2020, 4:16 am
by safihre
In a few minutes you can download an updated build of 3.1.1 here with the fix:
https://github.com/sabnzbd/sabbuild/rel ... test-3.1.2
If you could verify that it works, that would be great!
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 8th, 2020, 10:15 am
by RadioActiveLamb
Hey, you're awesome!! It's refreshing, not being sent down the "reboot three times and clear your cache" route
I will install that now and let it run a few days. Did you find a specific trigger where the bug would reveal itself?
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 9th, 2020, 4:33 pm
by safihre
The code was broken since the conversion to Python 3, the automatic conversion tool changed the code in a very subtle way that broke it. As soon as you posted the Traceback I knew the problem
When running the conversion so much code was changed that I missed this tiny difference that was introduced.
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 9th, 2020, 6:19 pm
by RadioActiveLamb
So far, no stop errors.
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 10th, 2020, 9:55 am
by safihre
Great!
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 12th, 2020, 5:12 pm
by RadioActiveLamb
The service stopped again, but now with a different, less-descriptive error:
The instance's SvcRun() method failed
<Error getting traceback - traceback.print_exception() failed
%2: %3
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 12th, 2020, 5:23 pm
by RadioActiveLamb
This may be happening when Radarr adds a download. It just happened again at the same time that it tried. I'm not 100% sure of the correlation, but the timing is suspect. Radarr has successfully added other downloads.
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 13th, 2020, 12:25 am
by sander
RadioActiveLamb wrote: ↑December 12th, 2020, 5:23 pm
This may be happening when Radarr adds a download. It just happened again at the same time that it tried. I'm not 100% sure of the correlation, but the timing is suspect. Radarr has successfully added other downloads.
In sabnzbd.log, search for "Radarr" ... the logging will tell the API call Radarr did.
And please post what happend before the traceback.
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 13th, 2020, 7:48 am
by safihre
No other logs available?
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 13th, 2020, 11:16 am
by RadioActiveLamb
Here are the logs, just before and including the two crashes that I've seen so far. The latest one, you can see that the downloader had trouble accessing the news reader. At the time, I was having some Internet service "quality" issues. I included them because an Internet outage might help cause the issue. However, the earlier crash had no-such connectivity error in the log. Both crashes seem to do with the RSS scheduler.
Code: Select all
2020-12-12 11:57:20,453::INFO::[downloader:806] Thread [email protected]: timed out
2020-12-12 11:57:22,265::INFO::[downloader:806] Thread [email protected]: timed out
2020-12-12 11:57:23,203::INFO::[downloader:806] Thread [email protected]: timed out
2020-12-12 11:57:23,203::INFO::[downloader:806] Thread [email protected]: timed out
2020-12-12 11:57:26,077::INFO::[downloader:806] Thread [email protected]: timed out
2020-12-12 11:57:27,140::INFO::[downloader:806] Thread [email protected]: timed out
2020-12-12 11:57:34,672::INFO::[rss:563] Starting scheduled RSS read-out for "Blue"
2020-12-12 11:57:53,859::INFO::[rss:563] Starting scheduled RSS read-out for "Green"
2020-12-12 11:58:01,171::INFO::[__init__:1060] Restarting crashed scheduler
2020-12-12 11:58:01,171::INFO::[scheduler:216] Setting schedule for midnight BPS reset
2020-12-12 11:58:01,171::INFO::[_cplogging:213] [12/Dec/2020:11:58:01] ENGINE Bus STOPPING
2020-12-12 11:58:01,296::INFO::[_cplogging:213] [12/Dec/2020:11:58:01] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('###.###.###.###', 8080)) shut down
2020-12-12 11:58:01,296::INFO::[_cplogging:213] [12/Dec/2020:11:58:01] ENGINE Bus STOPPED
2020-12-12 11:58:01,296::INFO::[_cplogging:213] [12/Dec/2020:11:58:01] ENGINE Bus EXITING
2020-12-12 11:58:01,296::INFO::[_cplogging:213] [12/Dec/2020:11:58:01] ENGINE Bus EXITED
Code: Select all
2020-12-09 04:47:42,767::INFO::[rss:563] Starting scheduled RSS read-out for "Extra"
2020-12-09 04:48:01,219::INFO::[rss:563] Starting scheduled RSS read-out for "Space"
2020-12-09 04:48:19,031::INFO::[rss:563] Starting scheduled RSS read-out for "Ocean"
2020-12-09 04:48:23,984::INFO::[assembler:114] Decoding finished \\?\D:\Temp\Complete\########\V0bNAFpqyZ74Tn8jSVeg0.part24.rar
2020-12-09 04:48:24,109::INFO::[directunpacker:293] DirectUnpacked volume 24 for V0bNAFpqyZ74Tn8jSVeg0
2020-12-09 04:49:10,420::INFO::[__init__:1060] Restarting crashed scheduler
2020-12-09 04:49:10,420::INFO::[scheduler:216] Setting schedule for midnight BPS reset
2020-12-09 04:49:10,420::INFO::[_cplogging:213] [09/Dec/2020:04:49:10] ENGINE Bus STOPPING
2020-12-09 04:49:10,545::INFO::[_cplogging:213] [09/Dec/2020:04:49:10] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('###.###.###.###', 8080)) shut down
2020-12-09 04:49:10,545::INFO::[_cplogging:213] [09/Dec/2020:04:49:10] ENGINE Bus STOPPED
2020-12-09 04:49:10,545::INFO::[_cplogging:213] [09/Dec/2020:04:49:10] ENGINE Bus EXITING
2020-12-09 04:49:10,545::INFO::[_cplogging:213] [09/Dec/2020:04:49:10] ENGINE Bus EXITED
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 13th, 2020, 11:31 am
by sander
Mabye you can try to reproduce:
With SABnzbd running,
disable your Wifi / Ethernet,
then, in SABnzbd,
http://127.0.0.1:8080/sabnzbd/config/rss/ click on Read All Feeds Now ... what happens?
On my Linux, I get the stuff below. If you can reproduce the traceback, my first guess would be the "Sending notification: Warning" ... maybe that is a problem for a Windows Service ... ?
Code: Select all
2020-12-13 17:26:50,072::DEBUG::[interface:1743] RSS READOUT = True
2020-12-13 17:26:50,072::DEBUG::[rss:208] Running feedparser on https://nzbindex.com/search/rss?q=reftestnzb&max=25&minage=0&maxage=0&hidespam=1&hidepassword=0&sort=agedesc&minsize=0&maxsize=0&complete=0&hidecross=0&hasNFO=0&poster=
2020-12-13 17:26:50,085::DEBUG::[rss:214] Finished parsing https://nzbindex.com/search/rss?q=reftestnzb&max=25&minage=0&maxage=0&hidespam=1&hidepassword=0&sort=agedesc&minsize=0&maxsize=0&complete=0&hidecross=0&hasNFO=0&poster=
2020-12-13 17:26:50,085::INFO::[notifier:122] Sending notification: Warning - Failed to retrieve RSS from https://nzbindex.com/search/rss?q=reftestnzb&max=25&minage=0&maxage=0&hidespam=1&hidepassword=0&sort=agedesc&minsize=0&maxsize=0&complete=0&hidecross=0&hasNFO=0&poster=: <urlopen error [Errno -3] Temporary failure in name resolution> (type=warning, job_cat=None)
2020-12-13 17:26:50,085::WARNING::[SABnzbd:111] Failed to retrieve RSS from https://nzbindex.com/search/rss?q=reftestnzb&max=25&minage=0&maxage=0&hidespam=1&hidepassword=0&sort=agedesc&minsize=0&maxsize=0&complete=0&hidecross=0&hasNFO=0&poster=: <urlopen error [Errno -3] Temporary failure in name resolution>
2020-12-13 17:26:50,085::DEBUG::[__init__:962] [sabnzbd.rss.save] Saving data for rss_data.sab
2020-12-13 17:26:50,086::DEBUG::[__init__:894] [sabnzbd.save_admin] Saving data for rss_data.sab in /home/sander/.sabnzbd/admin
2020-12-13 17:26:50,121::DEBUG::[interface:1743] RSS READOUT = False
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 14th, 2020, 7:53 am
by safihre
Interesting, sounds like a bug indeed.
Seems some error was outputted that was unable to be parsed, but which one..
Re: Service stops unexpectedly: RuntimeError: dictionary changed size during iteration
Posted: December 14th, 2020, 8:28 am
by sander
safihre wrote: ↑December 14th, 2020, 7:53 am
Interesting, sounds like a bug indeed.
Seems some error was outputted that was unable to be parsed, but which one..
Or a Windows Service is not allowed to send to STDERR or a Popup ...