preprocessing stuck at 99% if incomplete on smb3
Posted: May 13th, 2017, 5:17 pm
So a friend of mine got crazy with all the WannaCrypt nonsense, i told her to Windows Update and disable SMB1 and call it a day.
Shortly after she told me sabnzbd is no longer working...i really need to stop telling ppl what software i use personally
Shes running sab on a bananapi with a mount point to her windows box for sabs complete/incomplete stuff which of course was no longer accessible after disabling SMB1, added vers=3.0 to fstab, mount -a and all good - at least thats what i thought.
Now i'm sitting here and scratching my head over something which just doesn't make any sense at all.
With the incomplete folder on a cifs share using anything but SMBv1 and opt-pre_check enabled all downloads will get stuck at 99% during preprocessing, sab will remove any and all SABnzbd_nzf and nzo from the JOB_ADMIN folder leaving only the nzb.gz and SABnzbd_attrib behind and literally wait infinite for the end of days.
If i either disable opt-pre_check or mount using SMBv1 the preprocessing completes as expected and the download starts.
Log from running sab on cli with logging 2 (obfuscate because paranoia)
Shortly after she told me sabnzbd is no longer working...i really need to stop telling ppl what software i use personally
Shes running sab on a bananapi with a mount point to her windows box for sabs complete/incomplete stuff which of course was no longer accessible after disabling SMB1, added vers=3.0 to fstab, mount -a and all good - at least thats what i thought.
Now i'm sitting here and scratching my head over something which just doesn't make any sense at all.
With the incomplete folder on a cifs share using anything but SMBv1 and opt-pre_check enabled all downloads will get stuck at 99% during preprocessing, sab will remove any and all SABnzbd_nzf and nzo from the JOB_ADMIN folder leaving only the nzb.gz and SABnzbd_attrib behind and literally wait infinite for the end of days.
If i either disable opt-pre_check or mount using SMBv1 the preprocessing completes as expected and the download starts.
Log from running sab on cli with logging 2 (obfuscate because paranoia)
Code: Select all
2017-05-14 00:07:05,908::INFO::[__init__:677] Adding 10MB.nzb
2017-05-14 00:07:05,912::INFO::[misc:891] Creating directories: /mnt/Downloads/incomplete/10MB.1
2017-05-14 00:07:05,919::DEBUG::[__init__:899] Saving data for SABnzbd_nzf_mZ2D0c in /mnt/Downloads/incomplete/10MB.1/__ADMIN__
2017-05-14 00:07:05,922::INFO::[nzbstuff:467] File (t) [3/3] - "data_10mb.part3.rar" yEnc (1/1) added to queue
2017-05-14 00:07:05,924::DEBUG::[__init__:899] Saving data for SABnzbd_nzf_IDMLur in /mnt/Downloads/incomplete/10MB.1/__ADMIN__
2017-05-14 00:07:05,927::INFO::[nzbstuff:467] File (t) [2/3] - "data_10mb.part2.rar" yEnc (1/14) added to queue
2017-05-14 00:07:05,929::DEBUG::[__init__:899] Saving data for SABnzbd_nzf_qjF_rY in /mnt/Downloads/incomplete/10MB.1/__ADMIN__
2017-05-14 00:07:05,932::INFO::[nzbstuff:467] File (t) [1/3] - "data_10mb.part1.rar" yEnc (1/14) added to queue
2017-05-14 00:07:05,933::DEBUG::[nzbstuff:497] META-DATA = {}
2017-05-14 00:07:05,933::INFO::[__init__:620] Backing up /mnt/Downloads/incomplete/10MB.1/__ADMIN__/10MB.nzb.gz
2017-05-14 00:07:05,940::INFO::[nzbqueue:254] Saving queue
2017-05-14 00:07:05,943::DEBUG::[__init__:899] Saving data for SABnzbd_nzo_NjNxaj in /mnt/Downloads/incomplete/10MB.1/__ADMIN__
2017-05-14 00:07:05,948::INFO::[__init__:971] Saving data for queue10.sab in /home/sabuser/.sabnzbd/admin/queue10.sab
2017-05-14 00:07:05,949::DEBUG::[nzbstuff:235] Finishing import on (t) [1/3] - "data_10mb.part1.rar" yEnc (1/14)
2017-05-14 00:07:05,951::DEBUG::[__init__:933] Loading data for SABnzbd_nzf_qjF_rY from /mnt/Downloads/incomplete/10MB.1/__ADMIN__/SABnzbd_nzf_qjF_rY
2017-05-14 00:07:05,952::INFO::[downloader:491] [email protected]: Initiating connection
2017-05-14 00:07:06,172::INFO::[happyeyeballs:138] Quickest IP address for awesome.usenet.provider (port 563, ssl 1, preferipv6 True) is 127.0.0.1
2017-05-14 00:07:06,173::DEBUG::[happyeyeballs:140] Happy Eyeballs lookup and port connect took 80 ms
2017-05-14 00:07:06,173::DEBUG::[downloader:132] awesome.usenet.provider: Connecting to address 127.0.0.1
2017-05-14 00:07:06,193::INFO::[downloader:491] [email protected]: Initiating connection
2017-05-14 00:07:06,194::DEBUG::[downloader:113] awesome.usenet.provider: Re-using address 127.0.0.1
2017-05-14 00:07:06,214::INFO::[downloader:491] [email protected]: Initiating connection
2017-05-14 00:07:06,214::DEBUG::[downloader:113] awesome.usenet.provider: Re-using address 127.0.0.1
2017-05-14 00:07:06,234::INFO::[downloader:491] [email protected]: Initiating connection
2017-05-14 00:07:06,235::DEBUG::[downloader:113] awesome.usenet.provider: Re-using address 127.0.0.1
2017-05-14 00:07:06,255::INFO::[downloader:491] [email protected]: Initiating connection
2017-05-14 00:07:06,256::DEBUG::[downloader:113] awesome.usenet.provider: Re-using address 127.0.0.1
2017-05-14 00:07:06,276::INFO::[downloader:491] [email protected]: Initiating connection
2017-05-14 00:07:06,277::DEBUG::[downloader:113] awesome.usenet.provider: Re-using address 127.0.0.1
2017-05-14 00:07:06,296::INFO::[downloader:491] [email protected]: Initiating connection
2017-05-14 00:07:06,297::DEBUG::[downloader:113] awesome.usenet.provider: Re-using address 127.0.0.1
2017-05-14 00:07:06,318::INFO::[downloader:491] [email protected]: Initiating connection
2017-05-14 00:07:06,318::DEBUG::[downloader:113] awesome.usenet.provider: Re-using address 127.0.0.1
2017-05-14 00:07:06,340::INFO::[downloader:491] [email protected]: Initiating connection
2017-05-14 00:07:06,340::DEBUG::[downloader:113] awesome.usenet.provider: Re-using address 127.0.0.1
2017-05-14 00:07:06,361::INFO::[downloader:491] [email protected]: Initiating connection
2017-05-14 00:07:06,361::INFO::[newswrapper:124] [email protected]: Connected using TLSv1 (RC4-SHA)
2017-05-14 00:07:06,362::DEBUG::[downloader:113] awesome.usenet.provider: Re-using address 127.0.0.1
2017-05-14 00:07:06,385::INFO::[newswrapper:124] [email protected]: Connected using TLSv1 (RC4-SHA)
2017-05-14 00:07:06,445::INFO::[newswrapper:124] [email protected]: Connected using TLSv1 (RC4-SHA)
2017-05-14 00:07:06,451::INFO::[newswrapper:124] [email protected]: Connected using TLSv1 (RC4-SHA)
2017-05-14 00:07:06,458::INFO::[newswrapper:124] [email protected]: Connected using TLSv1 (RC4-SHA)
2017-05-14 00:07:06,489::INFO::[newswrapper:124] [email protected]: Connected using TLSv1 (RC4-SHA)
2017-05-14 00:07:06,503::INFO::[newswrapper:124] [email protected]: Connected using TLSv1 (RC4-SHA)
2017-05-14 00:07:06,517::INFO::[newswrapper:124] [email protected]: Connected using TLSv1 (RC4-SHA)
2017-05-14 00:07:06,538::INFO::[newswrapper:124] [email protected]: Connected using TLSv1 (RC4-SHA)
2017-05-14 00:07:06,565::INFO::[newswrapper:124] [email protected]: Connected using TLSv1 (RC4-SHA)
2017-05-14 00:07:06,576::INFO::[downloader:704] Connecting [email protected] finished
2017-05-14 00:07:06,616::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,617::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,629::INFO::[downloader:704] Connecting [email protected] finished
2017-05-14 00:07:06,670::INFO::[downloader:704] Connecting [email protected] finished
2017-05-14 00:07:06,672::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,672::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,681::INFO::[downloader:704] Connecting [email protected] finished
2017-05-14 00:07:06,684::INFO::[downloader:704] Connecting [email protected] finished
2017-05-14 00:07:06,687::INFO::[downloader:704] Connecting [email protected] finished
2017-05-14 00:07:06,714::INFO::[downloader:704] Connecting [email protected] finished
2017-05-14 00:07:06,714::INFO::[downloader:704] Connecting [email protected] finished
2017-05-14 00:07:06,716::INFO::[downloader:704] Connecting [email protected] finished
2017-05-14 00:07:06,726::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,727::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,745::INFO::[downloader:704] Connecting [email protected] finished
2017-05-14 00:07:06,813::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,814::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,876::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,877::DEBUG::[nzbstuff:235] Finishing import on (t) [2/3] - "data_10mb.part2.rar" yEnc (1/14)
2017-05-14 00:07:06,878::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,878::DEBUG::[__init__:933] Loading data for SABnzbd_nzf_IDMLur from /mnt/Downloads/incomplete/10MB.1/__ADMIN__/SABnzbd_nzf_IDMLur
2017-05-14 00:07:06,898::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,899::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,933::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,934::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,950::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,951::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,957::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,958::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,959::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,960::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,972::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,972::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,974::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,975::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,977::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,977::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:06,991::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:06,991::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,026::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,040::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,082::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,082::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,151::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,152::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,168::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,169::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,175::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,176::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,176::DEBUG::[nzbstuff:235] Finishing import on (t) [3/3] - "data_10mb.part3.rar" yEnc (1/1)
2017-05-14 00:07:07,179::DEBUG::[__init__:933] Loading data for SABnzbd_nzf_mZ2D0c from /mnt/Downloads/incomplete/10MB.1/__ADMIN__/SABnzbd_nzf_mZ2D0c
2017-05-14 00:07:07,192::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,192::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,209::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,210::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,251::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,251::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,318::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,319::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,440::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,441::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,441::DEBUG::[nzbstuff:1254] Download Quality: enough=True, have=10870230, need=10870230, ratio=1.0
2017-05-14 00:07:07,442::DEBUG::[__init__:899] Saving data for SABnzbd_nzo_NjNxaj in /mnt/Downloads/incomplete/10MB.1/__ADMIN__
2017-05-14 00:07:07,451::INFO::[__init__:971] Saving data for totals10.sab in /home/sabuser/.sabnzbd/admin/totals10.sab
2017-05-14 00:07:07,480::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,480::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,547::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,548::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,549::DEBUG::[nzbstuff:1254] Download Quality: enough=True, have=10870230, need=10870230, ratio=1.0
2017-05-14 00:07:07,549::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,550::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,578::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,578::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,625::DEBUG::[downloader:709] Article <[email protected]> is present
2017-05-14 00:07:07,625::DEBUG::[decoder:174] Server awesome.usenet.provider:563 has article [email protected]
2017-05-14 00:07:07,626::DEBUG::[nzbstuff:1254] Download Quality: enough=True, have=10870230, need=10870230, ratio=1.0
2017-05-14 00:07:07,630::DEBUG::[__init__:899] Saving data for SABnzbd_nzo_NjNxaj in /mnt/Downloads/incomplete/10MB.1/__ADMIN__
2017-05-14 00:07:07,637::DEBUG::[nzbstuff:1254] Download Quality: enough=True, have=10870230, need=10870230, ratio=1.0
2017-05-14 00:07:07,638::INFO::[__init__:962] /mnt/Downloads/incomplete/10MB.1/__ADMIN__/SABnzbd_nzf_mZ2D0c removed
2017-05-14 00:07:07,640::INFO::[__init__:962] /mnt/Downloads/incomplete/10MB.1/__ADMIN__/SABnzbd_nzf_qjF_rY removed
2017-05-14 00:07:07,642::INFO::[__init__:962] /mnt/Downloads/incomplete/10MB.1/__ADMIN__/SABnzbd_nzf_IDMLur removed
2017-05-14 00:07:08,626::INFO::[downloader:789] Thread [email protected]: forcing disconnect
2017-05-14 00:07:08,729::INFO::[downloader:789] Thread [email protected]: forcing disconnect
2017-05-14 00:07:08,832::INFO::[downloader:789] Thread [email protected]: forcing disconnect
2017-05-14 00:07:08,936::INFO::[downloader:789] Thread [email protected]: forcing disconnect
2017-05-14 00:07:09,039::INFO::[downloader:789] Thread [email protected]: forcing disconnect
2017-05-14 00:07:09,142::INFO::[downloader:789] Thread [email protected]: forcing disconnect
2017-05-14 00:07:09,246::INFO::[downloader:789] Thread [email protected]: forcing disconnect
2017-05-14 00:07:09,349::INFO::[downloader:789] Thread [email protected]: forcing disconnect
2017-05-14 00:07:09,453::INFO::[downloader:789] Thread [email protected]: forcing disconnect
2017-05-14 00:07:09,556::INFO::[downloader:789] Thread [email protected]: forcing disconnect