sabnzbd / sabnzbd

SABnzbd - The automated Usenet download tool
http://sabnzbd.org
Other
2.33k stars 340 forks source link

sabnzbd 3.2.0 develop latest version won't start anymore #1624

Closed anonvoy closed 4 years ago

anonvoy commented 4 years ago

I'm running the develop version of sabnzbd (currently 3.2.0) from source on Linux (OpenSuse Leap 15.1).

When updating to the latest commit, sabnzbd won't start any more. When going back several commits, it will start again.

From file sabnzbd.log after having updated to the currently latest commit (https://github.com/sabnzbd/sabnzbd/commit/d75f1ed966b3b03dd4a77e8800bbd4b551a51132) and trying to start sabnzbd:

2020-09-26 21:24:39,480::INFO::[SABnzbd:1142] --------------------------------
2020-09-26 21:24:39,480::INFO::[SABnzbd:1143] SABnzbd.py-3.2.0-develop (rev=unknown)
2020-09-26 21:24:39,480::INFO::[SABnzbd:1144] Full executable path = /home/abc/.sabnzbd/SABnzbd.py
2020-09-26 21:24:39,482::INFO::[SABnzbd:1154] Platform = posix
2020-09-26 21:24:39,482::INFO::[SABnzbd:1155] Python-version = 3.6.10 (default, Jan 16 2020, 09:12:04) [GCC]
2020-09-26 21:24:39,482::INFO::[SABnzbd:1156] Arguments = "/home/abc/.sabnzbd/SABnzbd.py" "-d" "-f" "/home/abc/.sabnzbd/sabnzbd.ini"
2020-09-26 21:24:39,482::INFO::[SABnzbd:1160] Not inside a docker container
2020-09-26 21:24:39,482::INFO::[SABnzbd:1163] Preferred encoding = UTF-8
2020-09-26 21:24:39,482::INFO::[SABnzbd:1175] SSL version = OpenSSL 1.1.0i-fips  14 Aug 2018
2020-09-26 21:24:39,484::INFO::[SABnzbd:1184] Certifi version: 2018.01.18
2020-09-26 21:24:39,484::INFO::[SABnzbd:1185] Loaded additional certificates from: /etc/ssl/ca-bundle.pem
2020-09-26 21:24:39,485::INFO::[SABnzbd:1230] Using INI file /home/abc/.sabnzbd/sabnzbd.ini
2020-09-26 21:24:41,149::INFO::[postproc:135] Loading postproc queue
2020-09-26 21:24:41,149::ERROR::[__init__:958] Loading /home/abc/.sabnzbd/admin/Rating.sab failed
2020-09-26 21:24:41,149::INFO::[__init__:959] Traceback: 
Traceback (most recent call last):
  File "/home/abc/.sabnzbd/sabnzbd/__init__.py", line 948, in load_data
    data = pickle.load(data_file, encoding=sabnzbd.encoding.CODEPAGE)
AttributeError: Can't get attribute 'NzbRatingV2' on <module 'sabnzbd.rating' from '/home/abc/.sabnzbd/sabnzbd/rating.py'>
2020-09-26 21:24:41,150::INFO::[rating:115] Corrupt Rating.sab file, discarding
2020-09-26 21:24:41,150::INFO::[rating:116] Traceback: 
Traceback (most recent call last):
  File "/home/abc/.sabnzbd/sabnzbd/rating.py", line 113, in __init__
    self.version, self.ratings, self.nzo_indexer_map = sabnzbd.load_admin(RATING_FILE_NAME)
TypeError: 'NoneType' object is not iterable

From file sabnzbd.error.log after having updated to the currently latest commit and trying to start sabnzbd:

Traceback (most recent call last):
  File "/home/abc/.sabnzbd/SABnzbd.py", line 1733, in <module>
    main()
  File "/home/abc/.sabnzbd/SABnzbd.py", line 1235, in main
    sabnzbd.initialize(pause, clean_up, evaluate_schedules=True, repair=repair)
  File "/home/abc/.sabnzbd/sabnzbd/decorators.py", line 36, in call_func
    return f(*args, **kw)
  File "/home/abc/.sabnzbd/sabnzbd/__init__.py", line 342, in initialize
    scheduler.init()
  File "/home/abc/.sabnzbd/sabnzbd/scheduler.py", line 125, in init
    action = rss.run_method
NameError: name 'rss' is not defined

From file sabnzbd.log after executing "git reset --hard 730d7179368ae96778d7fea2faf3cc6b99f7301a", successfully starting sabnzbd 3.2.0 and shutting it down again:

2020-09-26 21:28:00,235::INFO::[SABnzbd:1142] --------------------------------
2020-09-26 21:28:00,236::INFO::[SABnzbd:1143] SABnzbd.py-3.2.0-develop (rev=unknown)
2020-09-26 21:28:00,236::INFO::[SABnzbd:1144] Full executable path = /home/abc/.sabnzbd/SABnzbd.py
2020-09-26 21:28:00,238::INFO::[SABnzbd:1154] Platform = posix
2020-09-26 21:28:00,238::INFO::[SABnzbd:1155] Python-version = 3.6.10 (default, Jan 16 2020, 09:12:04) [GCC]
2020-09-26 21:28:00,238::INFO::[SABnzbd:1156] Arguments = "/home/abc/.sabnzbd/SABnzbd.py" "-d" "-f" "/home/abc/.sabnzbd/sabnzbd.ini"
2020-09-26 21:28:00,238::INFO::[SABnzbd:1160] Not inside a docker container
2020-09-26 21:28:00,238::INFO::[SABnzbd:1163] Preferred encoding = UTF-8
2020-09-26 21:28:00,238::INFO::[SABnzbd:1175] SSL version = OpenSSL 1.1.0i-fips  14 Aug 2018
2020-09-26 21:28:00,240::INFO::[SABnzbd:1184] Certifi version: 2018.01.18
2020-09-26 21:28:00,240::INFO::[SABnzbd:1185] Loaded additional certificates from: /etc/ssl/ca-bundle.pem
2020-09-26 21:28:00,240::INFO::[SABnzbd:1230] Using INI file /home/abc/.sabnzbd/sabnzbd.ini
2020-09-26 21:28:01,936::INFO::[postproc:140] Loading postproc queue
2020-09-26 21:28:02,115::INFO::[scheduler:216] Setting schedule for midnight BPS reset
2020-09-26 21:28:02,116::INFO::[__init__:349] All processes started
2020-09-26 21:28:02,116::INFO::[SABnzbd:297] Template location for Glitter is /home/abc/.sabnzbd/interfaces/Glitter
2020-09-26 21:28:02,116::INFO::[SABnzbd:297] Template location for Config is /home/abc/.sabnzbd/interfaces/Config
2020-09-26 21:28:02,116::INFO::[misc:986] [N/A] Running external command: ['/usr/bin/nice', '-n19', '/usr/bin/ionice', '-c3', '/usr/bin/unrar']
2020-09-26 21:28:02,145::INFO::[misc:986] [N/A] Running external command: ['/usr/bin/nice', '-n19', '/usr/bin/ionice', '-c3', '/usr/bin/par2', '-h']
2020-09-26 21:28:02,167::INFO::[SABnzbd:398] SABYenc module (v4.0.1)... found!
2020-09-26 21:28:02,167::INFO::[SABnzbd:417] Cryptography module (v2.8)... found!
2020-09-26 21:28:02,167::INFO::[SABnzbd:422] par2 binary... found (/usr/bin/par2)
2020-09-26 21:28:02,167::INFO::[SABnzbd:429] UNRAR binary... found (/usr/bin/unrar)
2020-09-26 21:28:02,168::INFO::[SABnzbd:439] UNRAR binary version 5.91
2020-09-26 21:28:02,168::INFO::[SABnzbd:447] 7za binary... found (/usr/bin/7za)
2020-09-26 21:28:02,168::INFO::[SABnzbd:458] nice binary... found (/usr/bin/nice)
2020-09-26 21:28:02,168::INFO::[SABnzbd:462] ionice binary... found (/usr/bin/ionice)
2020-09-26 21:28:02,170::INFO::[SABnzbd:1289] HTTPS keys are OK
2020-09-26 21:28:02,171::INFO::[SABnzbd:1417] Starting web-interface on 127.0.0.1:9100
2020-09-26 21:28:02,171::INFO::[_cplogging:216] [26/Sep/2020:21:28:02] ENGINE Bus STARTING
2020-09-26 21:28:02,275::INFO::[_cplogging:216] [26/Sep/2020:21:28:02] ENGINE Serving on http://127.0.0.1:8095
2020-09-26 21:28:02,381::INFO::[_cplogging:216] [26/Sep/2020:21:28:02] ENGINE Serving on https://127.0.0.1:9100
2020-09-26 21:28:02,381::INFO::[_cplogging:216] [26/Sep/2020:21:28:02] ENGINE Bus STARTED
2020-09-26 21:28:02,381::INFO::[SABnzbd:1454] Starting SABnzbd.py-3.2.0-develop
2020-09-26 21:28:02,396::INFO::[dirscanner:117] Dirscanner starting up
2020-09-26 21:28:02,399::INFO::[urlgrabber:96] URLGrabber starting up
2020-09-26 21:28:02,399::INFO::[notifier:122] Sending notification: SABnzbd - SABnzbd 3.2.0-develop started (type=startup, job_cat=None)
2020-09-26 21:28:02,411::INFO::[postproc:230] Completed Download Folder /home/abc/Downloads/sabnzbd/complete is not on FAT
2020-09-26 21:28:02,412::INFO::[misc:986] [N/A] Running external command: ['/usr/bin/nice', '-n19', '/usr/bin/ionice', '-c3', '/home/abc/.sabnzbd/scripts/nzbToMedia/sabnzbd-notify.py', 'startup', 'SABnzbd: Startup/Shutdown', 'SABnzbd 3.2.0-develop started', 'dbus://']
2020-09-26 21:28:02,520::INFO::[zconfig:71] No Bonjour/ZeroConfig support installed
2020-09-26 21:28:03,281::INFO::[notifier:377] Successfully executed notification script /home/abc/.sabnzbd/scripts/nzbToMedia/sabnzbd-notify.py
2020-09-26 21:28:16,613::INFO::[__init__:803] [N/A] Performing SABnzbd shutdown
2020-09-26 21:28:16,613::INFO::[__init__:388] SABnzbd shutting down...
2020-09-26 21:28:16,613::INFO::[directunpacker:513] Aborting all DirectUnpackers
2020-09-26 21:28:16,614::INFO::[urlgrabber:91] URLGrabber shutting down
2020-09-26 21:28:16,614::INFO::[dirscanner:108] Dirscanner shutting down
2020-09-26 21:28:16,895::INFO::[notifier:122] Sending notification: SABnzbd - Shutting down (type=startup, job_cat=None)
2020-09-26 21:28:16,897::INFO::[downloader:538] Shutting down
2020-09-26 21:28:16,897::INFO::[decoder:131] Shutting down decoder Thread-2
2020-09-26 21:28:16,897::INFO::[decoder:131] Shutting down decoder Thread-3
2020-09-26 21:28:16,897::INFO::[misc:986] [N/A] Running external command: ['/usr/bin/nice', '-n19', '/usr/bin/ionice', '-c3', '/home/abc/.sabnzbd/scripts/nzbToMedia/sabnzbd-notify.py', 'startup', 'SABnzbd: Startup/Shutdown', 'Shutting down', 'dbus://']
2020-09-26 21:28:16,898::INFO::[decoder:131] Shutting down decoder Thread-4
2020-09-26 21:28:16,911::INFO::[assembler:64] Shutting down
2020-09-26 21:28:16,912::INFO::[nzbqueue:225] Saving queue
2020-09-26 21:28:18,101::INFO::[notifier:377] Successfully executed notification script /home/abc/.sabnzbd/scripts/nzbToMedia/sabnzbd-notify.py
2020-09-26 21:28:18,319::INFO::[postproc:134] Saving postproc queue
2020-09-26 21:28:18,319::INFO::[__init__:457] All processes stopped
2020-09-26 21:28:18,319::INFO::[_cplogging:216] [26/Sep/2020:21:28:18] ENGINE Bus STOPPING
2020-09-26 21:28:18,321::INFO::[_cplogging:216] [26/Sep/2020:21:28:18] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('127.0.0.1', 8095)) shut down
2020-09-26 21:28:18,325::INFO::[_cplogging:216] [26/Sep/2020:21:28:18] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('127.0.0.1', 9100)) shut down
2020-09-26 21:28:18,325::INFO::[_cplogging:216] [26/Sep/2020:21:28:18] ENGINE Bus STOPPED
2020-09-26 21:28:18,325::INFO::[_cplogging:216] [26/Sep/2020:21:28:18] ENGINE Bus EXITING
2020-09-26 21:28:18,325::INFO::[_cplogging:216] [26/Sep/2020:21:28:18] ENGINE Bus EXITED
2020-09-26 21:28:21,100::INFO::[notifier:122] Sending notification: SABnzbd - SABnzbd shutdown finished (type=startup, job_cat=None)
2020-09-26 21:28:21,101::INFO::[SABnzbd:1565] Leaving SABnzbd
anonvoy commented 4 years ago

Oh, and also: The built-in script Deobfuscate.py initially won't run anymore after going back to the older commit because the execute bit is not set. After setting that bit manually it works now.

thezoggy commented 4 years ago

looks to be fallout of rating attributes code update where 'NzbRatingV2' is no more https://github.com/sabnzbd/sabnzbd/commit/2c2642a92ae5198bf710fcb707b76d9b7498f11b#

and i can confirm exec bit isnt set in git for Deobfuscate.py

sabnzbd-dev\scripts>git ls-files -s .
100644 7f372b6863572fb6f3a00ebdcb8e3b8ef8191fe7 0       Deobfuscate.py
100644 e5b06e4ba88dccdf71f99864dfdf656b87db7a20 0       Sample-PostProc.cmd
100755 a0778caafd265f976893ecb1cd84169dc9bf53df 0       Sample-PostProc.py
100755 b9b71f65e7fe460d32da88f2704ec7ca43900f81 0       Sample-PostProc.sh
sanderjo commented 4 years ago

I get this one with SABnzbd.py-3.2.0-develop

2020-09-27 05:50:22,301::DEBUG::[__init__:983] [sabnzbd.rating.__init__] Loading data for Rating.sab
2020-09-27 05:50:22,301::INFO::[__init__:938] [sabnzbd.load_admin] /home/sander/.sabnzbd/admin/Rating.sab missing
2020-09-27 05:50:22,301::INFO::[rating:115] Corrupt Rating.sab file, discarding
2020-09-27 05:50:22,301::INFO::[rating:116] Traceback: 
Traceback (most recent call last):
  File "/home/sander/git/sabnzbd/sabnzbd/rating.py", line 113, in __init__
    self.version, self.ratings, self.nzo_indexer_map = sabnzbd.load_admin(RATING_FILE_NAME)
TypeError: cannot unpack non-iterable NoneType object
Safihre commented 4 years ago

The INFO warnings are fine. Indeed we need NzbRatingV2.

sanderjo commented 4 years ago

The built-in script Deobfuscate.py initially won't run anymore after going back

deobfuscate is now built in into SABnzbd: see http://127.0.0.1:8080/sabnzbd/config/switches/#deobfuscate_final_filenames