SABnzbd Forums

Hi,

On my media server (running Windows 10 anniversary), which holds Couchpotato, Nzbdrone for downloading series and movies, I noticed Sabnzbd is recently much slower during the postprocessing. So started to dig into it. I was looking at where in the whole process is 'hangs' or 'slows down' and this is what I found so far:
- It downloads
- It verifies
- It repairs
- It unpacks (unrar)
- It delete's rar-files
- Removes unwanted files

Al the above steps are still done within normal time-limits. But then the whole post-processing 'slows' at:
- Collapsing

In the Webgui it says that it is Moving... but looking into the logfile the actual moving of the files is done when it unpacks. In that step file are move from the 'complete' folder to the folder specified under categories. Which is in my case somewhere on my NAS. But all that is done, and with normal speed. So the 'collapsing' is what takes literally 11 minutes or so to finish (see line I made red in the logfile below). And I have no idea what it is doing there. Do you guy have any of idea of what is happening here? And even better of how to fix this or speed this up?

regards,

Roland

Abstract from logfile

2017-01-08 11:02:08,496::INFO::[__init__:628] Adding BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.nzb
2017-01-08 11:02:08,509::INFO::[misc:806] Creating directories: \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p
2017-01-08 11:02:08,512::INFO::[nzbstuff:501] File L3xm9QP2AT9sXdqBE2p6 - [01/52] - "L3xm9QP2AT9sXdqBE2p6.par2" yEnc (1/1) added to queue
....<CUT-OUT>....
2017-01-08 11:02:08,798::INFO::[nzbstuff:501] File L3xm9QP2AT9sXdqBE2p6 - [52/52] - "L3xm9QP2AT9sXdqBE2p6.vol056+46.PAR2" yEnc (1/139) added to queue
2017-01-08 11:02:08,798::INFO::[__init__:571] Backing up \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\__ADMIN__\BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.nzb.gz
2017-01-08 11:02:08,828::INFO::[nzbqueue:258] Saving queue
2017-01-08 11:02:08,834::INFO::[__init__:922] Saving data for queue10.sab in C:\Users\Roland\AppData\Local\sabnzbd\admin\queue10.sab
2017-01-08 11:02:08,839::INFO::[downloader:445] 15@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,858::INFO::[happyeyeballs:138] Quickest IP address for news.sunnyusenet.com (port 119, ssl 0, preferipv6 True) is 85.12.14.42
2017-01-08 11:02:08,858::INFO::[downloader:445] 14@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,862::INFO::[downloader:445] 5@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,864::INFO::[downloader:445] 6@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,865::INFO::[downloader:445] 9@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,865::INFO::[downloader:445] 7@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,868::INFO::[downloader:445] 8@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,868::INFO::[downloader:445] 12@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,871::INFO::[downloader:445] 2@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,871::INFO::[downloader:445] 10@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,874::INFO::[downloader:445] 11@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,875::INFO::[downloader:445] 13@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,875::INFO::[downloader:445] 3@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,877::INFO::[downloader:445] 1@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,878::INFO::[downloader:445] 4@news.sunnyusenet.com: Initiating connection
2017-01-08 11:02:08,903::INFO::[downloader:647] Connecting 9@news.sunnyusenet.com finished
2017-01-08 11:02:08,904::INFO::[downloader:647] Connecting 5@news.sunnyusenet.com finished
2017-01-08 11:02:08,904::INFO::[downloader:647] Connecting 14@news.sunnyusenet.com finished
2017-01-08 11:02:08,904::INFO::[downloader:647] Connecting 15@news.sunnyusenet.com finished
2017-01-08 11:02:08,918::INFO::[downloader:647] Connecting 3@news.sunnyusenet.com finished
2017-01-08 11:02:08,920::INFO::[downloader:647] Connecting 1@news.sunnyusenet.com finished
2017-01-08 11:02:08,920::INFO::[downloader:647] Connecting 7@news.sunnyusenet.com finished
2017-01-08 11:02:08,920::INFO::[downloader:647] Connecting 11@news.sunnyusenet.com finished
2017-01-08 11:02:08,920::INFO::[downloader:647] Connecting 2@news.sunnyusenet.com finished
2017-01-08 11:02:08,920::INFO::[downloader:647] Connecting 6@news.sunnyusenet.com finished
2017-01-08 11:02:08,921::INFO::[downloader:647] Connecting 13@news.sunnyusenet.com finished
2017-01-08 11:02:08,921::INFO::[downloader:647] Connecting 12@news.sunnyusenet.com finished
2017-01-08 11:02:08,921::INFO::[downloader:647] Connecting 8@news.sunnyusenet.com finished
2017-01-08 11:02:08,921::INFO::[downloader:647] Connecting 10@news.sunnyusenet.com finished
2017-01-08 11:02:08,947::INFO::[__init__:922] Saving data for totals10.sab in C:\Users\Roland\AppData\Local\sabnzbd\admin\totals10.sab
2017-01-08 11:02:08,950::INFO::[downloader:647] Connecting 4@news.sunnyusenet.com finished
2017-01-08 11:02:08,950::INFO::[assembler:87] Decoding \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\L3xm9QP2AT9sXdqBE2p6.par2 yenc
....<CUT-OUT>....
2017-01-08 11:02:48,029::INFO::[assembler:87] Decoding \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\L3xm9QP2AT9sXdqBE2p6.part44.rar yenc
2017-01-08 11:02:48,286::INFO::[__init__:913] \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\__ADMIN__\SABnzbd_nzo_01nlfp removed
2017-01-08 11:02:48,286::INFO::[nzbqueue:258] Saving queue
2017-01-08 11:02:48,286::INFO::[__init__:922] Saving data for queue10.sab in C:\Users\Roland\AppData\Local\sabnzbd\admin\queue10.sab
2017-01-08 11:02:48,288::INFO::[postproc:83] Saving postproc queue
2017-01-08 11:02:48,288::INFO::[__init__:922] Saving data for postproc2.sab in C:\Users\Roland\AppData\Local\sabnzbd\admin\postproc2.sab
2017-01-08 11:02:48,289::INFO::[postproc:294] Starting Post-Processing on BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose => Repair:True, Unpack:True, Delete:True, Script:nzbToNzbDrone.bat, Cat:televisie
2017-01-08 11:02:48,292::INFO::[postproc:595] Starting verification and repair of BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose
2017-01-08 11:02:48,359::INFO::[__init__:879] \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\__ADMIN__\__verified__ missing
2017-01-08 11:02:48,359::INFO::[postproc:616] Running verification and repair on set L3xm9QP2AT9sXdqBE2p6
2017-01-08 11:02:48,364::INFO::[newsunpack:1089] Quick-check for L3xm9QP2AT9sXdqBE2p6 is OK, skipping repair
2017-01-08 11:02:48,365::INFO::[newsunpack:1163] Deleting C:\Users\Roland\DOWNLO~1\INCOMP~1\BLINDS~1\L3xm9QP2AT9sXdqBE2p6.par2
2017-01-08 11:02:48,365::INFO::[postproc:643] Verification and repair finished for BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose
2017-01-08 11:02:48,529::INFO::[misc:806] Creating directories: \\?\UNC\192.168.2.117\Download\Download\Televisie\BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.2
2017-01-08 11:02:48,786::INFO::[postproc:366] Running unpack_magic on BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose
2017-01-08 11:02:48,891::INFO::[newsunpack:254] Unrar starting on C:\Users\Roland\DOWNLO~1\INCOMP~1\BLINDS~1
2017-01-08 11:02:48,894::INFO::[newsunpack:475] Extracting rarfile C:\Users\Roland\DOWNLO~1\INCOMP~1\BLINDS~1\L3xm9QP2AT9sXdqBE2p6.part01.rar (belonging to L3xm9QP2AT9sXdqBE2p6) to \\192.168.2.117\Download\Download\T4KS7G~7\_QSVNQ~G.2
2017-01-08 11:02:49,036::INFO::[downloader:734] Thread 1@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:49,137::INFO::[downloader:734] Thread 2@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:49,237::INFO::[downloader:734] Thread 8@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:49,338::INFO::[downloader:734] Thread 15@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:49,438::INFO::[downloader:734] Thread 7@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:49,539::INFO::[downloader:734] Thread 3@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:49,641::INFO::[downloader:734] Thread 13@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:49,740::INFO::[downloader:734] Thread 14@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:49,842::INFO::[downloader:734] Thread 10@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:49,943::INFO::[downloader:734] Thread 4@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:50,043::INFO::[downloader:734] Thread 12@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:50,148::INFO::[downloader:734] Thread 9@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:50,249::INFO::[downloader:734] Thread 11@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:50,348::INFO::[downloader:734] Thread 6@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:02:50,450::INFO::[downloader:734] Thread 5@news.sunnyusenet.com: forcing disconnect
2017-01-08 11:03:56,507::INFO::[newsunpack:814] 10 bestanden/mappen uitgepakt in 1 min 7 seconden
2017-01-08 11:03:56,507::INFO::[newsunpack:500] Deleting C:\Users\Roland\DOWNLO~1\INCOMP~1\BLINDS~1\L3xm9QP2AT9sXdqBE2p6.part01.rar
....<CUT-OUT>....
2017-01-08 11:03:56,717::INFO::[newsunpack:500] Deleting C:\Users\Roland\DOWNLO~1\INCOMP~1\BLINDS~1\L3xm9QP2AT9sXdqBE2p6.part44.rar
2017-01-08 11:03:56,723::INFO::[newsunpack:258] Unrar finished on C:\Users\Roland\DOWNLO~1\INCOMP~1\BLINDS~1
2017-01-08 11:03:56,992::INFO::[postproc:371] unpack_magic finished on BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose
2017-01-08 11:03:57,000::INFO::[postproc:728] Removing unwanted file \\?\UNC\192.168.2.117\Download\Download\Televisie\_UNPACK_BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.2\info\2.jpg
2017-01-08 11:03:57,102::INFO::[postproc:728] Removing unwanted file \\?\UNC\192.168.2.117\Download\Download\Televisie\_UNPACK_BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.2\info\cover2.png
2017-01-08 11:03:57,138::INFO::[postproc:728] Removing unwanted file \\?\UNC\192.168.2.117\Download\Download\Televisie\_UNPACK_BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.2\info\info.mkv.txt
2017-01-08 11:03:57,171::INFO::[postproc:728] Removing unwanted file \\?\UNC\192.168.2.117\Download\Download\Televisie\_UNPACK_BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.2\info\MMF als eerste op Quality-Place - Torrents.jpg
2017-01-08 11:03:57,203::INFO::[postproc:728] Removing unwanted file \\?\UNC\192.168.2.117\Download\Download\Televisie\_UNPACK_BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.2\info\Quality-Place - Torrents.url
2017-01-08 11:03:57,246::INFO::[postproc:728] Removing unwanted file \\?\UNC\192.168.2.117\Download\Download\Televisie\_UNPACK_BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.2\MMF als eerste op Quality-Place - Torrents.jpg
2017-01-08 11:03:57,278::INFO::[postproc:728] Removing unwanted file \\?\UNC\192.168.2.117\Download\Download\Televisie\_UNPACK_BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.2\Quality-Place - Torrents.url
2017-01-08 11:03:57,332::INFO::[postproc:822] Collapsing \\?\UNC\192.168.2.117\Download\Download\Televisie\BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.2\serie
2017-01-08 11:14:37,592::INFO::[newsunpack:167] Running external script C:\Scripts\nzbToNzbDrone.bat(\\192.168.2.117\Download\Download\Televisie\BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.2, BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose.nzb, BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose, , televisie, alt.binaries.boneless, 0, )
2017-01-08 11:15:40,184::INFO::[postproc:564] Cleaning up BLINDSPOT (2016) S02E10 1080p HDTV DD5_1 NL Subs Metamorfose (keep_basic=False)
2017-01-08 11:15:40,184::INFO::[__init__:913] \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\__ADMIN__\SABnzbd_nzf__epaxh removed
2017-01-08 11:15:40,186::INFO::[__init__:913] \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\__ADMIN__\SABnzbd_nzf_gy6gta removed
2017-01-08 11:15:40,186::INFO::[__init__:913] \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\__ADMIN__\SABnzbd_nzf_ka01wb removed
2017-01-08 11:15:40,187::INFO::[__init__:913] \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\__ADMIN__\SABnzbd_nzf_q6y3up removed
2017-01-08 11:15:40,187::INFO::[__init__:913] \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\__ADMIN__\SABnzbd_nzf_qtvii9 removed
2017-01-08 11:15:40,187::INFO::[__init__:913] \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\__ADMIN__\SABnzbd_nzf_n9fw2l removed
2017-01-08 11:15:40,187::INFO::[__init__:913] \\?\C:\Users\Roland\Downloads\incomplete\BLINDSPOT (2016) S02E10 1080p\__ADMIN__\SABnzbd_nzf_dy5hst removed
2017-01-08 11:15:40,191::INFO::[postproc:83] Saving postproc queue
2017-01-08 11:15:40,191::INFO::[__init__:922] Saving data for postproc2.sab in C:\Users\Roland\AppData\Local\sabnzbd\admin\postproc2.sab
2017-01-08 11:15:40,197::INFO::[downloader:278] Post-processing finished, resuming download
2017-01-08 11:15:41,197::INFO::[nzbqueue:258] Saving queue
2017-01-08 11:15:41,197::INFO::[__init__:922] Saving data for queue10.sab in C:\Users\Roland\AppData\Local\sabnzbd\admin\queue10.sab
2017-01-08 11:15:41,197::INFO::[__init__:922] Saving data for totals10.sab in C:\Users\Roland\AppData\Local\sabnzbd\admin\totals10.sab
2017-01-08 11:15:41,200::INFO::[__init__:922] Saving data for rss_data.sab in C:\Users\Roland\AppData\Local\sabnzbd\admin\rss_data.sab
2017-01-08 11:15:41,201::INFO::[__init__:922] Saving data for watched_data2.sab in C:\Users\Roland\AppData\Local\sabnzbd\admin\watched_data2.sab
2017-01-08 11:15:41,201::INFO::[postproc:83] Saving postproc queue
2017-01-08 11:15:41,203::INFO::[__init__:922] Saving data for postproc2.sab in C:\Users\Roland\AppData\Local\sabnzbd\admin\postproc2.sab
2017-01-08 11:15:41,203::INFO::[postproc:703] Queue has finished, launching: None (None)

It's a known bug. Due to how network paths are handled by python.
What you can try is connecting to your NAS for example by mounting it as a drive letter and using that as the destination.
Or, you can turn of Enable folder rename in Config Switches.

Yup, that did the trick. Thanks!

Which of the two? The drive-letter or the Switch?