SABnzbd: V4 Alpha 2 does not appear to be deleting .par2 files?

[buzzword]

V4 Alpha 2 does not appear to be deleting .par2 files

[sander]

In SABnzbd's upper right corner, click on the wrench symbol ("Status and interface options"), then click on first tab Status, click Test download 1GB.

What is the result? Are par files deleted?

[buzzword]

That results in
Error renaming "I:\DL\_UNPACK_test_download_1000MB" to "I:\DL\test_download_1000MB"

Note that this is with Alpha 3, I had already updated by the time I saw your request.

[sander]

Interesting.

What kind of drive is I: ?

What if you download to C: ?

[safihre]

I think your virusscanner is not trusting the new release and holding locks (to scan them) on the files while SABnzbd is trying to move them. Maybe try again a couple of times.

[buzzword]

To answer your questions...
Drive I: is a normal hard drive. Drive X: used for Temp is a ram disk.
Virus scanner is normal Windows Defender, which I disabled completely prior to running all tests below.

I ran a test using drive C: for Temp and DL.
I ran an additional test turning off Direct Unpack.
Same result Error renaming "I:\DL\_UNPACK_test_download_1000MB" to "I:\DL\test_download_1000MB" for all tests.

Here are the hopefully useful chunks of the +Debug Log, It was 100k lines so I deleted some beginning and ending chunks:

2023-03-08 10:35:23,966::INFO::[newsunpack:555] Set sometestfile-1GB completed by DirectUnpack
2023-03-08 10:35:23,966::DEBUG::[newsunpack:578] rar_unpack(): Rars: ['\\\\?\\X:\\test_download_1000MB\\sometestfile-1GB.part01.rar', '\\\\?\\X:\\test_download_1000MB\\sometestfile-1GB.part02.rar', '\\\\?\\X:\\test_download_1000MB\\sometestfile-1GB.part03.rar', '\\\\?\\X:\\test_download_1000MB\\sometestfile-1GB.part04.rar', '\\\\?\\X:\\test_download_1000MB\\sometestfile-1GB.part05.rar', '\\\\?\\X:\\test_download_1000MB\\sometestfile-1GB.part06.rar', '\\\\?\\X:\\test_download_1000MB\\sometestfile-1GB.part07.rar', '\\\\?\\X:\\test_download_1000MB\\sometestfile-1GB.part08.rar', '\\\\?\\X:\\test_download_1000MB\\sometestfile-1GB.part09.rar', '\\\\?\\X:\\test_download_1000MB\\sometestfile-1GB.part10.rar', '\\\\?\\X:\\test_download_1000MB\\sometestfile-1GB.part11.rar']
2023-03-08 10:35:23,966::DEBUG::[newsunpack:579] rar_unpack(): Newfiles: ['\\\\?\\I:\\DL\\_UNPACK_test_download_1000MB\\1GB-explanation.txt', '\\\\?\\I:\\DL\\_UNPACK_test_download_1000MB\\1GB.bin']
2023-03-08 10:35:23,966::DEBUG::[filesystem:911] [sabnzbd\newsunpack.py.rar_unpack] Deleting file \\?\X:\test_download_1000MB\sometestfile-1GB.part01.rar
2023-03-08 10:35:23,975::DEBUG::[filesystem:911] [sabnzbd\newsunpack.py.rar_unpack] Deleting file \\?\X:\test_download_1000MB\sometestfile-1GB.part02.rar
2023-03-08 10:35:23,985::DEBUG::[interface:141] Request GET /api from 127.0.0.1 [Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0] {'mode': 'queue', 'start': '0', 'limit': '250', 'output': 'json', 'apikey':<APIKEY>', '_': '1678300455941'}
2023-03-08 10:35:23,986::DEBUG::[interface:141] Request GET /api from 127.0.0.1 [Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0] {'mode': 'history', 'failed_only': '0', 'start': '0', 'limit': '250', 'last_history_update': '14', 'output': 'json', 'apikey':<APIKEY>', '_': '1678300455942'}
2023-03-08 10:35:23,986::DEBUG::[filesystem:911] [sabnzbd\newsunpack.py.rar_unpack] Deleting file \\?\X:\test_download_1000MB\sometestfile-1GB.part03.rar
2023-03-08 10:35:23,998::DEBUG::[filesystem:911] [sabnzbd\newsunpack.py.rar_unpack] Deleting file \\?\X:\test_download_1000MB\sometestfile-1GB.part04.rar
2023-03-08 10:35:24,009::DEBUG::[filesystem:911] [sabnzbd\newsunpack.py.rar_unpack] Deleting file \\?\X:\test_download_1000MB\sometestfile-1GB.part05.rar
2023-03-08 10:35:24,019::DEBUG::[filesystem:911] [sabnzbd\newsunpack.py.rar_unpack] Deleting file \\?\X:\test_download_1000MB\sometestfile-1GB.part06.rar
2023-03-08 10:35:24,029::DEBUG::[filesystem:911] [sabnzbd\newsunpack.py.rar_unpack] Deleting file \\?\X:\test_download_1000MB\sometestfile-1GB.part07.rar
2023-03-08 10:35:24,039::DEBUG::[filesystem:911] [sabnzbd\newsunpack.py.rar_unpack] Deleting file \\?\X:\test_download_1000MB\sometestfile-1GB.part08.rar
2023-03-08 10:35:24,050::DEBUG::[filesystem:911] [sabnzbd\newsunpack.py.rar_unpack] Deleting file \\?\X:\test_download_1000MB\sometestfile-1GB.part09.rar
2023-03-08 10:35:24,060::DEBUG::[filesystem:911] [sabnzbd\newsunpack.py.rar_unpack] Deleting file \\?\X:\test_download_1000MB\sometestfile-1GB.part10.rar
2023-03-08 10:35:24,070::DEBUG::[filesystem:911] [sabnzbd\newsunpack.py.rar_unpack] Deleting file \\?\X:\test_download_1000MB\sometestfile-1GB.part11.rar
2023-03-08 10:35:24,071::INFO::[newsunpack:298] Unrar finished on \\?\X:\test_download_1000MB
2023-03-08 10:35:24,071::DEBUG::[filesystem:504] build_filelists(): joinables: []
2023-03-08 10:35:24,071::DEBUG::[filesystem:505] build_filelists(): zips: []
2023-03-08 10:35:24,071::DEBUG::[filesystem:506] build_filelists(): rars: []
2023-03-08 10:35:24,072::DEBUG::[filesystem:507] build_filelists(): 7zips: []
2023-03-08 10:35:24,072::DEBUG::[filesystem:508] build_filelists(): ts: []
2023-03-08 10:35:24,073::DEBUG::[filesystem:504] build_filelists(): joinables: []
2023-03-08 10:35:24,073::DEBUG::[filesystem:505] build_filelists(): zips: []
2023-03-08 10:35:24,073::DEBUG::[filesystem:506] build_filelists(): rars: []
2023-03-08 10:35:24,073::DEBUG::[filesystem:507] build_filelists(): 7zips: []
2023-03-08 10:35:24,073::DEBUG::[filesystem:508] build_filelists(): ts: []
2023-03-08 10:35:24,074::INFO::[postproc:434] Unpacked files ['\\\\?\\I:\\DL\\_UNPACK_test_download_1000MB\\1GB-explanation.txt', '\\\\?\\I:\\DL\\_UNPACK_test_download_1000MB\\1GB.bin']
2023-03-08 10:35:24,074::INFO::[filesystem:329] Checking if any resulting filenames need to be sanitized
2023-03-08 10:35:24,074::INFO::[postproc:438] Finished unpack_magic on test_download_1000MB
2023-03-08 10:35:24,075::INFO::[postproc:1081] Removing unwanted file \\?\I:\DL\_UNPACK_test_download_1000MB\1GB-explanation.txt
2023-03-08 10:35:24,075::DEBUG::[filesystem:911] [sabnzbd\postproc.py.cleanup_list] Deleting file \\?\I:\DL\_UNPACK_test_download_1000MB\1GB-explanation.txt
2023-03-08 10:35:24,075::INFO::[postproc:1081] Removing unwanted file \\?\I:\DL\_UNPACK_test_download_1000MB\1GB.bin
2023-03-08 10:35:24,076::DEBUG::[filesystem:911] [sabnzbd\postproc.py.cleanup_list] Deleting file \\?\I:\DL\_UNPACK_test_download_1000MB\1GB.bin
2023-03-08 10:35:24,178::DEBUG::[filesystem:918] [sabnzbd\filesystem.py.cleanup_empty_directories] Removing dir \\?\I:\DL\_UNPACK_test_download_1000MB
2023-03-08 10:35:24,178::DEBUG::[filesystem:875] Renaming "\\?\I:\DL\_UNPACK_test_download_1000MB" to "\\?\I:\DL\test_download_1000MB"
2023-03-08 10:35:24,179::DEBUG::[filesystem:889] Error renaming "\\?\I:\DL\_UNPACK_test_download_1000MB" to "\\?\I:\DL\test_download_1000MB" <[WinError 2] The system cannot find the file specified: '\\\\?\\I:\\DL\\_UNPACK_test_download_1000MB' -> '\\\\?\\I:\\DL\\test_download_1000MB'>
2023-03-08 10:35:24,179::INFO::[notifier:123] Sending notification: Error - Error renaming "I:\DL\_UNPACK_test_download_1000MB" to "I:\DL\test_download_1000MB" (type=error, job_cat=None)
2023-03-08 10:35:24,179::ERROR::[postproc:498] Error renaming "I:\DL\_UNPACK_test_download_1000MB" to "I:\DL\test_download_1000MB"
2023-03-08 10:35:24,180::INFO::[postproc:503] Traceback:
Traceback (most recent call last):
File "sabnzbd\postproc.py", line 496, in process_job
File "sabnzbd\postproc.py", line 1206, in rename_and_collapse_folder
File "sabnzbd\decorators.py", line 39, in call_func
File "sabnzbd\filesystem.py", line 882, in renamer
FileNotFoundError: [WinError 2] The system cannot find the file specified: '\\\\?\\I:\\DL\\_UNPACK_test_download_1000MB' -> '\\\\?\\I:\\DL\\test_download_1000MB'
2023-03-08 10:35:24,181::INFO::[postproc:1185] Skipping sample-removal, false-positive
2023-03-08 10:35:24,181::DEBUG::[deobfuscate_filenames:88] No additional par2 files found to process
2023-03-08 10:35:24,181::INFO::[postproc:533] Running deobfuscate
2023-03-08 10:35:24,181::DEBUG::[deobfuscate_filenames:266] Trying to see if there are qualifying files to be deobfuscated
2023-03-08 10:35:24,182::INFO::[deobfuscate_filenames:278] No file given, or not found (None)
2023-03-08 10:35:24,182::INFO::[nzbstuff:1803] [sabnzbd\postproc.py.process_job] Purging data for job test_download_1000MB (delete_all_data=True)
2023-03-08 10:35:24,182::DEBUG::[articlecache:152] Purging 0 articles from the cache/disk
2023-03-08 10:35:24,182::DEBUG::[filesystem:944] Removing dir recursively \\?\X:\test_download_1000MB
2023-03-08 10:35:24,187::INFO::[notifier:123] Sending notification: Download Completed - test_download_1000MB (type=complete, job_cat=*)
2023-03-08 10:35:24,247::DEBUG::[sorting:637] Initial guess for test_download_1000MB is MatchesDict([('title', 'test download'), ('size', <Size [1000MB]>), ('type', 'movie')])
2023-03-08 10:35:24,248::DEBUG::[sorting:137] Matched sorter newsunpack__analyse_show to job test_download_1000MB (forced: True, custom: True)
2023-03-08 10:35:24,265::INFO::[database:292] Added job test_download_1000MB to history
2023-03-08 10:35:24,266::INFO::[postproc:129] Saving postproc queue
2023-03-08 10:35:24,266::DEBUG::[filesystem:1185] [sabnzbd\postproc.py.save] Saving data for postproc2.sab
2023-03-08 10:35:24,266::DEBUG::[filesystem:1117] [sabnzbd\filesystem.py.save_admin] Saving data for postproc2.sab in \\?\C:\Users\dean\AppData\Local\sabnzbd\admin
2023-03-08 10:35:24,266::INFO::[downloader:454] Post-processing finished, resuming download
2023-03-08 10:35:25,007::DEBUG::[interface:141] Request GET /api from 127.0.0.1 [Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0] {'mode': 'history', 'failed_only': '0', 'start': '0', 'limit': '250', 'last_history_update': '14', 'output': 'json', 'apikey':<APIKEY>', '_': '1678300455944'}

__version__ = 19
__encoding__ = utf-8
[misc]
pre_script = None
queue_complete = shutdown_pc
queue_complete_pers = 0
bandwidth_perc = 100
refresh_rate = 1
interface_settings = '{"dateFormat":"YYYY-MM-DD h:mma","extraQueueColumns":["age"],"extraHistoryColumns":["size"],"displayCompact":false,"displayFullWidth":false,"displayTabbed":true,"confirmDeleteQueue":true,"confirmDeleteHistory":true}'
queue_limit = 250
config_lock = 0
sched_converted = 0
notified_new_skin = 2
direct_unpack_tested = 1
check_new_rel = 1
auto_browser = 0
language = en
enable_https_verification = 1
host = 127.0.0.1
port = 8080
https_port = ""
username=<USER>
password=<PASSWORD>
bandwidth_max = 110M
cache_limit = -1
web_dir = Glitter
web_color = Auto
https_cert = server.cert
https_key = server.key
https_chain = ""
enable_https = 0
inet_exposure = 0
api_key = <HASH>a8733fe
nzb_key = <HASH>70552f2
permissions = ""
download_dir = X:\
download_free = ""
complete_dir = I:\DL\
complete_free = 2G
fulldisk_autoresume = 1
script_dir = ""
nzb_backup_dir = E:\NZB\sab\imported
admin_dir = admin
dirscan_dir = E:\NZB\sab
dirscan_speed = 5
password_file = ""
log_dir = logs
max_art_tries = 5
load_balancing = 2
top_only = 0
sfv_check = 0
quick_check_ext_ignore = nfo, sfv, srr
script_can_fail = 1
enable_recursive = 1
flat_unpack = 0
par_option = ""
pre_check = 0
nice = ""
win_process_prio = 3
ionice = ""
fail_hopeless_jobs = 1
fast_fail = 1
auto_disconnect = 1
no_dupes = 2
no_series_dupes = 0
series_propercheck = 0
pause_on_pwrar = 2
ignore_samples = 1
deobfuscate_final_filenames = 1
auto_sort = ""
direct_unpack = 1
direct_unpack_threads = 3
propagation_delay = 0
folder_rename = 1
replace_spaces = 0
replace_dots = 0
safe_postproc = 1
pause_on_post_processing = 0
enable_all_par = 1
sanitize_safe = 0
cleanup_list = nfo, sfv, url, txt, exe, bin, com, bat, html, htm, srr, bat, cmd, lib, dll
unwanted_extensions = ,
action_on_unwanted_extensions = 1
unwanted_extensions_mode = 0
new_nzb_on_failure = 1
history_retention = 0
enable_meta = 1
quota_size = ""
quota_day = ""
quota_resume = 0
quota_period = m
rating_enable = 0
rating_host = ""
rating_api_key = ""
rating_filter_enable = 0
rating_filter_abort_audio = 0
rating_filter_abort_video = 0
rating_filter_abort_encrypted = 0
rating_filter_abort_encrypted_confirm = 0
rating_filter_abort_spam = 0
rating_filter_abort_spam_confirm = 0
rating_filter_abort_downvoted = 0
rating_filter_abort_keywords = ""
rating_filter_pause_audio = 0
rating_filter_pause_video = 0
rating_filter_pause_encrypted = 0
rating_filter_pause_encrypted_confirm = 0
rating_filter_pause_spam = 0
rating_filter_pause_spam_confirm = 0
rating_filter_pause_downvoted = 0
rating_filter_pause_keywords = ""
enable_tv_sorting = 0
tv_sort_string = ""
tv_categories = tv,
enable_movie_sorting = 0
movie_sort_string = ""
movie_sort_extra = -cd%1
movie_extra_folder = 0
movie_categories = movies,
enable_date_sorting = 0
date_sort_string = ""
date_categories = tv,
schedlines = ,
rss_rate = 15
ampm = 0
replace_illegal = 1
start_paused = 1
enable_par_cleanup = 1
process_unpacked_par2 = 1
enable_unrar = 1
enable_unzip = 1
enable_7zip = 1
enable_filejoin = 1
enable_tsjoin = 1
overwrite_files = 1
ignore_unrar_dates = 0
backup_for_duplicates = 1
empty_postproc = 0
wait_for_dfolder = 0
rss_filenames = 0
api_logging = 1
html_login = 1
osx_menu = 1
osx_speed = 1
warn_dupl_jobs = 0
helpfull_warnings = 1
keep_awake = 1
win_menu = 1
allow_incomplete_nzb = 0
enable_broadcast = 1
ipv6_hosting = 0
fixed_ports = 1
api_warnings = 1
disable_api_key = 0
no_penalties = 1
x_frame_options = 1
require_modern_tls = 0
num_decoders = 3
rss_odd_titles = nzbindex.nl/, nzbindex.com/, nzbclub.com/
req_completion_rate = 100.2
selftest_host = self-test.sabnzbd.org
movie_rename_limit = 100M
episode_rename_limit = 20M
size_limit = 0
show_sysload = 2
history_limit = 250
wait_ext_drive = 5
max_foldername_length = 246
nomedia_marker = ""
ipv6_servers = 1
url_base = /sabnzbd
host_whitelist = dean-pc,
local_ranges = ,
max_url_retries = 10
downloader_sleep_time = 10
ssdp_broadcast_interval = 15
email_server = ""
email_to = <REMOVED>
email_from = ""
email_account = <REMOVED>
email_pwd = <REMOVED>
email_endjob = 0
email_full = 0
email_dir = dean
email_rss = 0
email_cats = *,
preserve_paused_state = 0
helpful_warnings = 1
allow_old_ssl_tls = 0
socks5_proxy_url = ""
num_simd_decoders = 2
ext_rename_ignore = ,
decoders = 0
assemblers = 0
backup_dir = E:\NZB\backup
replace_underscores = 0
tray_icon = 1
sorters_converted = 1
enable_season_sorting = 1
receive_threads = 2
switchinterval = 0.005
[logging]
log_level = 2
max_log_size = 5242880
log_backups = 5
[ncenter]
ncenter_enable = 0
ncenter_cats = *,
ncenter_prio_startup = 0
ncenter_prio_download = 0
ncenter_prio_pause_resume = 0
ncenter_prio_pp = 0
ncenter_prio_complete = 0
ncenter_prio_failed = 0
ncenter_prio_disk_full = 0
ncenter_prio_new_login = 0
ncenter_prio_warning = 0
ncenter_prio_error = 0
ncenter_prio_queue_done = 0
ncenter_prio_other = 0
[acenter]
acenter_enable = 1
acenter_cats = *,
acenter_prio_startup = 0
acenter_prio_download = 0
acenter_prio_pause_resume = 0
acenter_prio_pp = 0
acenter_prio_complete = 0
acenter_prio_failed = 0
acenter_prio_disk_full = 1
acenter_prio_new_login = 0
acenter_prio_warning = 0
acenter_prio_error = 0
acenter_prio_queue_done = 0
acenter_prio_other = 0
[ntfosd]
ntfosd_enable = 0
ntfosd_cats = *,
ntfosd_prio_startup = 0
ntfosd_prio_download = 0
ntfosd_prio_pause_resume = 0
ntfosd_prio_pp = 0
ntfosd_prio_complete = 0
ntfosd_prio_failed = 0
ntfosd_prio_disk_full = 0
ntfosd_prio_new_login = 0
ntfosd_prio_warning = 0
ntfosd_prio_error = 0
ntfosd_prio_queue_done = 0
ntfosd_prio_other = 0
[prowl]
prowl_enable = 0
prowl_cats = *,
prowl_apikey = <REMOVED>
prowl_prio_startup = -3
prowl_prio_download = -3
prowl_prio_pause_resume = -3
prowl_prio_pp = -3
prowl_prio_complete = 0
prowl_prio_failed = 1
prowl_prio_disk_full = 1
prowl_prio_new_login = -3
prowl_prio_warning = -3
prowl_prio_error = -3
prowl_prio_queue_done = 0
prowl_prio_other = 0
[pushover]
pushover_token = <REMOVED>
pushover_userkey = <REMOVED>
pushover_device = ""
pushover_emergency_expire = 3600
pushover_emergency_retry = 60
pushover_enable = 0
pushover_cats = *,
pushover_prio_startup = -3
pushover_prio_download = -2
pushover_prio_pause_resume = -2
pushover_prio_pp = -3
pushover_prio_complete = -1
pushover_prio_failed = -1
pushover_prio_disk_full = 1
pushover_prio_new_login = -3
pushover_prio_warning = 1
pushover_prio_error = 1
pushover_prio_queue_done = -1
pushover_prio_other = -1
[pushbullet]
pushbullet_enable = 0
pushbullet_cats = *,
pushbullet_apikey = <REMOVED>
pushbullet_device = ""
pushbullet_prio_startup = 0
pushbullet_prio_download = 0
pushbullet_prio_pause_resume = 0
pushbullet_prio_pp = 0
pushbullet_prio_complete = 1
pushbullet_prio_failed = 1
pushbullet_prio_disk_full = 1
pushbullet_prio_new_login = 0
pushbullet_prio_warning = 0
pushbullet_prio_error = 0
pushbullet_prio_queue_done = 0
pushbullet_prio_other = 1
[nscript]
nscript_enable = 0
nscript_cats = *,
nscript_script = None
nscript_parameters = ""
nscript_prio_startup = 1
nscript_prio_download = 0
nscript_prio_pause_resume = 0
nscript_prio_pp = 0
nscript_prio_complete = 1
nscript_prio_failed = 1
nscript_prio_disk_full = 1
nscript_prio_new_login = 0
nscript_prio_warning = 0
nscript_prio_error = 0
nscript_prio_queue_done = 1
nscript_prio_other = 1
[servers]
[[news.newshosting.com]]
name = news.newshosting.com
displayname = news.newshosting.com
host = news.newshosting.com
port = 563
timeout = 60
username=<USER>
password=<PASSWORD>
connections = 50
ssl = 1
ssl_verify = 2
ssl_ciphers = ""
enable = 1
required = 0
optional = 0
retention = 0
expire_date = ""
quota = ""
usage_at_start = 0
send_group = 0
priority = 0
notes = ""
[categories]
[[*]]
name = *
order = 0
pp = 3
script = Default
dir = ""
newzbin = ""
priority = 0
[[movies]]
name = movies
order = 0
pp = ""
script = Default
dir = E:\@Plex\*
newzbin = ""
priority = -100
[[tv]]
name = tv
order = 0
pp = ""
script = Default
dir = E:\@Plex\*
newzbin = ""
priority = -100
[[books]]
name = books
order = 0
pp = ""
script = Default
dir = E:\Books
newzbin = ""
priority = -100
[rss]
[[Feed1]]
name = Feed1
uri = https://api.nzbgeek.info/rss?t=-2&limit ... 71GUBF2Qcg,
cat = ""
pp = ""
script = ""
enable = 1
priority = -100
filter0 = "", "", "", A, *, -100, 1

[sander]

So even with Windows Defender inactive, you get the error below?
Are you 100% sure the virusscanner is not running anymore? I remember vaguely that on Windows only uninstalling & rebooting would work.

Code: Select all

2023-03-08 10:35:24,179::DEBUG::[filesystem:889] Error renaming "\\?\I:\DL\_UNPACK_test_download_1000MB" to "\\?\I:\DL\test_download_1000MB" <[WinError 2] The system cannot find the file specified: '\\\\?\\I:\\DL\\_UNPACK_test_download_1000MB' -> '\\\\?\\I:\\DL\\test_download_1000MB'>

And did you check: do those files / dirs exist?

[buzzword]

Yes, I still get the error with Windows Defender disabled, and I also tried rebooting after disabling. And you can't uninstall windows defender, it's no longer a stand alone package (and hasn't been for quite some time), you can run another app like Norton (I don't) and it will let that take over.

Those file/dirs do not pre-exist. I can see the _UNPACK_ folder get created and then disappear when it's unable to be renamed.I'm not having any issues whatsoever with any other files. only you "test" files (tried all 3 sizes).

[sander]

I'm not having any issues whatsoever with any other files. only you "test" files (tried all 3 sizes).

Oh, so the problem "V4 Alpha 2 does not appear to be deleting .par2 files" is gone?

[buzzword]

I stumbled upon the cause of the folder rename error. I was looking at the Switches page and noticed that my Cleanup List of file extensions to be deleted after download includes bin and txt, and recalled that those are the only two file types I had seen in the _UNPACK_ folder of your test download file.

When I removed bin and txt from the cleanup extensions list, the test file works, so it must have something to do with the only 2 files present getting immediately after download. Perhaps as a result the now empty _UNPACK_ folder is then deleted because there's nothing to do, but then you still attempt to do a folder rename. So something to look at.

The good news is, now that I was able to download the test file, I'm not seeing any leftover par2 files, so whatever was happening in Beta2 to leave those files un-deleted seems to have been corrected in Beta3.

[sander]

Wow ... Good find.

Glad it works now. (FWIW: we're still in Alpha, not Beta)

[buzzword]

>> (FWIW: we're still in Alpha, not Beta)

My bad, I'm aware, Also I left out a word, it should have read "getting immediately deleted after download'" hope you didn't have to puzzle out my meaning!

[sander]

I can reproduce:

put bin and txt into cleanup list, and do the test download

Result:

Error renaming "/home/sander/Downloads/complete/_UNPACK_test_download_100MB" to "/home/sander/Downloads/complete/test_download_100MB"

And indeed, before that:

Code: Select all

2023-03-10 11:06:08,045::INFO::[postproc:1077] Removing unwanted file /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB/100MB.bin
2023-03-10 11:06:08,045::DEBUG::[filesystem:911] [sabnzbd.postproc.cleanup_list] Deleting file /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB/100MB.bin
2023-03-10 11:06:08,059::INFO::[postproc:1077] Removing unwanted file /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB/100MB-explanation.txt
2023-03-10 11:06:08,060::DEBUG::[filesystem:911] [sabnzbd.postproc.cleanup_list] Deleting file /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB/100MB-explanation.txt
2023-03-10 11:06:08,060::DEBUG::[filesystem:918] [sabnzbd.filesystem.cleanup_empty_directories] Removing dir /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB
2023-03-10 11:06:08,060::DEBUG::[filesystem:875] Renaming "/home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB" to "/home/<USERNAME>/Downloads/complete/test_download_100MB"

So "Removing dir", and then trying Renaming the dir that was just deleted ...
I would say that is a bug within SAB. Maybe a "if exist(dir) rename" would solve it. Not sure of impact on other stuff.


Full log:

Code: Select all

2023-03-10 11:06:08,044::INFO::[filesystem:329] Checking if any resulting filenames need to be sanitized
2023-03-10 11:06:08,044::INFO::[postproc:438] Finished unpack_magic on test_download_100MB
2023-03-10 11:06:08,045::DEBUG::[filesystem:614] Applying permissions 0o744 (octal) to /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB
2023-03-10 11:06:08,045::DEBUG::[filesystem:614] Applying permissions 0o644 (octal) to /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB/100MB.bin
2023-03-10 11:06:08,045::DEBUG::[filesystem:614] Applying permissions 0o644 (octal) to /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB/100MB-explanation.txt
2023-03-10 11:06:08,045::INFO::[postproc:1077] Removing unwanted file /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB/100MB.bin
2023-03-10 11:06:08,045::DEBUG::[filesystem:911] [sabnzbd.postproc.cleanup_list] Deleting file /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB/100MB.bin
2023-03-10 11:06:08,059::INFO::[postproc:1077] Removing unwanted file /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB/100MB-explanation.txt
2023-03-10 11:06:08,060::DEBUG::[filesystem:911] [sabnzbd.postproc.cleanup_list] Deleting file /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB/100MB-explanation.txt
2023-03-10 11:06:08,060::DEBUG::[filesystem:918] [sabnzbd.filesystem.cleanup_empty_directories] Removing dir /home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB
2023-03-10 11:06:08,060::DEBUG::[filesystem:875] Renaming "/home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB" to "/home/<USERNAME>/Downloads/complete/test_download_100MB"
2023-03-10 11:06:08,060::INFO::[notifier:123] Sending notification: Error - Error renaming "/home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB" to "/home/<USERNAME>/Downloads/complete/test_download_100MB" (type=error, job_cat=None)
2023-03-10 11:06:08,060::ERROR::[postproc:498] Error renaming "/home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB" to "/home/<USERNAME>/Downloads/complete/test_download_100MB"
2023-03-10 11:06:08,061::INFO::[postproc:503] Traceback: 
Traceback (most recent call last):
  File "/usr/lib/python3.8/shutil.py", line 791, in move
    os.rename(src, real_dst)
FileNotFoundError: [Errno 2] No such file or directory: '/home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB' -> '/home/<USERNAME>/Downloads/complete/test_download_100MB'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/share/sabnzbdplus/sabnzbd/postproc.py", line 496, in process_job
    newfiles = rename_and_collapse_folder(tmp_workdir_complete, workdir_complete, newfiles)
  File "/usr/share/sabnzbdplus/sabnzbd/postproc.py", line 1202, in rename_and_collapse_folder
    renamer(oldpath, newpath)
  File "/usr/share/sabnzbdplus/sabnzbd/decorators.py", line 39, in call_func
    return func(*args, **kw)
  File "/usr/share/sabnzbdplus/sabnzbd/filesystem.py", line 905, in renamer
    shutil.move(old, new)
  File "/usr/lib/python3.8/shutil.py", line 811, in move
    copy_function(src, real_dst)
  File "/usr/lib/python3.8/shutil.py", line 435, in copy2
    copyfile(src, dst, follow_symlinks=follow_symlinks)
  File "/usr/lib/python3.8/shutil.py", line 264, in copyfile
    with open(src, 'rb') as fsrc, open(dst, 'wb') as fdst:
FileNotFoundError: [Errno 2] No such file or directory: '/home/<USERNAME>/Downloads/complete/_UNPACK_test_download_100MB'
2023-03-10 11:06:08,195::INFO::[postproc:1181] Skipping sample-removal, false-positive

[Puzzled]

This should fix the deleted folder issue: https://github.com/sabnzbd/sabnzbd/pull/2497

[zoggy]

@buzz you need to change your nzbgeek apikey since you shared it..


tossed pr to prevent this in the future: https://github.com/sabnzbd/sabnzbd/pull/2499

would hide the nn apikey

Code: Select all

[rss]
[[geek]]
name = geek
uri = https://api.nzbgeek.info/rss?t=-2&limit=200&dl=1&del=1&r=<APIKEY>,
cat = ""
pp = ""
script = ""
enable = 1