SABnzbd 3.1.0 not running pp script: "% 1 is not a valid Win32 application"

[FrizzleFry51]

SABnzbd 3.1.0 is not running my post-processing script. If I revert to 3.0.2 the script runs fine.

Exit(-1) Cannot run script D:\scripts\SABnzbd\video.ps1

It is a PowerShell script running on Windows 10 2004.
I am using the zip version of SABnzbd rather than the install one.

[sander]

Can you post the sabnzbd.log logging of 3.0.2 that it works (as you're a new user: put spaces arounds dots). Probably a few lines.

[FrizzleFry51]

I don't see anything in sabnzbd.log about the pp script just entries like this

2020-10-26 09:24:38,674::INFO::[_cplogging:213] [26/Oct/2020:09:24:38] ENGINE Bus STOPPED
2020-10-26 09:24:38,674::INFO::[_cplogging:213] [26/Oct/2020:09:24:38] ENGINE Bus EXITING
2020-10-26 09:24:38,674::INFO::[_cplogging:213] [26/Oct/2020:09:24:38] ENGINE Bus EXITED
2020-10-26 09:24:59,718::INFO::[_cplogging:213] [26/Oct/2020:09:24:59] ENGINE Bus STARTING
2020-10-26 09:24:59,967::INFO::[_cplogging:213] [26/Oct/2020:09:24:59] ENGINE Serving on
2020-10-26 09:24:59,969::INFO::[_cplogging:213] [26/Oct/2020:09:24:59] ENGINE Bus STARTED

I guess I need to up the logging level. Where is that setting? Nevermind... found it

2020-10-26 17:45:15,586::INFO::[newsunpack:206] Running external script D:\scripts\SABnzbd\video.ps1

2020-10-26 17:45:16,662::INFO::[downloader:310] Post-processing finished, resuming download

I have been using this script for years. All it currently does is verify there is only one video in the destination folder and move that video to another folder.

[FrizzleFry51]

Here is where it fails in 3.1.0:

2020-10-26 17:55:10,726::DEBUG::[newsunpack:227] Failed script D:\scripts\SABnzbd\video.ps1, Traceback:
Traceback (most recent call last):
File "sabnzbd\newsunpack.py", line 201, in external_processing
File "sabnzbd\misc.py", line 988, in build_and_run_command
File "subprocess.py", line 854, in __init__
File "subprocess.py", line 1307, in _execute_child
OSError: [WinError 193] % 1 is not a valid Win32 application

[sander]

And 3.0.2 and 3.1.0 are both the zip version? Or is 3.0.2 installed with the installer and/or 64-bit?

FWIW https://stackoverflow.com/questions/185 ... pplication

[FrizzleFry51]

Both 3.0.2 and 3.1.0 are 64 bit zip version

[safihre]

We need also the Debug logging just before it. It should output the whole environment setup of the process being run.

[FrizzleFry51]

Do you want the logs for 3.0.2 when it succeeds or 3.1.0 when it fails?

This is 3.1.0 log before it fails:

Code: Select all

2020-10-26 17:55:10,609::INFO::[newsunpack:269] Unrar finished on \\?\D:\download\SABnzbd\temporary\video.x264-N
2020-10-26 17:55:10,610::DEBUG::[newsunpack:2060] build_filelists(): joinables: []
2020-10-26 17:55:10,610::DEBUG::[newsunpack:2061] build_filelists(): zips: []
2020-10-26 17:55:10,611::DEBUG::[newsunpack:2062] build_filelists(): rars: []
2020-10-26 17:55:10,611::DEBUG::[newsunpack:2063] build_filelists(): 7zips: []
2020-10-26 17:55:10,611::DEBUG::[newsunpack:2064] build_filelists(): ts: []
2020-10-26 17:55:10,611::DEBUG::[newsunpack:2060] build_filelists(): joinables: []
2020-10-26 17:55:10,612::DEBUG::[newsunpack:2061] build_filelists(): zips: []
2020-10-26 17:55:10,612::DEBUG::[newsunpack:2062] build_filelists(): rars: []
2020-10-26 17:55:10,612::DEBUG::[newsunpack:2063] build_filelists(): 7zips: []
2020-10-26 17:55:10,612::DEBUG::[newsunpack:2064] build_filelists(): ts: []
2020-10-26 17:55:10,612::INFO::[postproc:429] Unpacked files ['\\\\?\\I:\\videos\\~~~\\_UNPACK_video.x264-NTb\\video.x264-NTb.mkv']
2020-10-26 17:55:10,612::INFO::[postproc:434] Finished unpack_magic on video.x264-NTb
2020-10-26 17:55:10,721::DEBUG::[filesystem:769] Renaming "\\?\I:\videos\~~~\_UNPACK_video.x264-NTb" to "\\?\I:\videos\~~~\video.x264-NTb"
2020-10-26 17:55:10,721::DEBUG::[filesystem:811] [sabnzbd\postproc.py.rename_and_collapse_folder] Removing dir \\?\I:\videos\~~~\_UNPACK_video.x264-NTb
2020-10-26 17:55:10,722::INFO::[misc:986] [sabnzbd\newsunpack.py.external_processing] Running external command: ['D:\\scripts\\SABnzbd\\video.ps1', 'I:\\videos\\~~~\\video.x264-NTb', 'video.x264-NTb.nzb', 'video.x264-NTb', '', 'videos', 'alt.binaries.kenpsx', '0', '']
2020-10-26 17:55:10,722::DEBUG::[misc:987] Popen arguments: {'stdin': -1, 'stdout': -1, 'stderr': -2, 'startupinfo': <subprocess.STARTUPINFO object at 0x00000216FE777B80>, 'creationflags': 32, 'env': {'ALLUSERSPROFILE': 'C:\\ProgramData', 'APPDATA': 'C:\\Users\\user\\AppData\\Roaming', 'COMMANDER_INI': 'C:\\Users\\user\\AppData\\Roaming\\zabkat\\tcplugins.ini', 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 'COMMONPROGRAMFILES(X86)': 'C:\\Program Files (x86)\\Common Files', 'COMMONPROGRAMW6432': 'C:\\Program Files\\Common Files', 'COMPUTERNAME': 'JUPITER', 'COMSPEC': 'C:\\WINDOWS\\system32\\cmd.exe', 'DRIVERDATA': 'C:\\Windows\\System32\\Drivers\\DriverData', 'FPS_BROWSER_APP_PROFILE_STRING': 'Internet Explorer', 'FPS_BROWSER_USER_PROFILE_STRING': 'Default', 'HOMEDRIVE': 'C:', 'HOMEPATH': '\\Users\\user', 'LOCALAPPDATA': 'C:\\Users\\user\\AppData\\Local', 'LOGONSERVER': '\\\\JUPITER', 'NUMBER_OF_PROCESSORS': '4', 'ONEDRIVE': 'C:\\Users\\user\\OneDrive', 'OS': 'Windows_NT', 'PATH': 'C:\\WINDOWS\\System32;C:\\WINDOWS;C:\\WINDOWS\\System32\\Wbem;C:\\WINDOWS\\System32\\WindowsPowerShell\\v1.0\\;C:\\WINDOWS\\System32\\OpenSSH;C:\\scripts;C:\\tools;C:\\tools\\Gow\\bin;', 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC;.PS1;.AU3;.AHK;.BTM', 'POWERSHELL_DISTRIBUTION_CHANNEL': 'MSI:Windows 10 Home', 'PROCESSOR_ARCHITECTURE': 'AMD64', 'PROCESSOR_IDENTIFIER': 'Intel64 Family 6 Model 60 Stepping 3, GenuineIntel', 'PROCESSOR_LEVEL': '6', 'PROCESSOR_REVISION': '3c03', 'PROGRAMDATA': 'C:\\ProgramData', 'PROGRAMFILES': 'C:\\Program Files', 'PROGRAMFILES(X86)': 'C:\\Program Files (x86)', 'PROGRAMW6432': 'C:\\Program Files', 'PSMODULEPATH': 'C:\\Program Files\\WindowsPowerShell\\Modules;C:\\WINDOWS\\system32\\WindowsPowerShell\\v1.0\\Modules;C:\\tools\\AutoIt3\\AutoItX', 'PUBLIC': 'C:\\Users\\Public', 'SESSIONNAME': 'Console', 'SYSTEMDRIVE': 'C:', 'SYSTEMROOT': 'C:\\WINDOWS', 'TEMP': 'C:\\Users\\user\\AppData\\Local\\Temp', 'TMP': 'C:\\Users\\user\\AppData\\Local\\Temp', 'USERDOMAIN': 'JUPITER', 'USERDOMAIN_ROAMINGPROFILE': 'JUPITER', 'USERNAME': 'user', 'USERPROFILE': 'C:\\Users\\user', 'VBOX_MSI_INSTALL_PATH': 'C:\\Program Files\\Oracle\\VirtualBox\\', 'WINDIR': 'C:\\WINDOWS', 'X2DIR': 'C:\\tools\\xplorer2_ultimate\\', 'SSL_CERT_FILE': 'D:\\tools\\SABnzbd\\certifi\\cacert.pem', 'SAB_BYTES': '439171756', 'SAB_BYTES_DOWNLOADED': '421557697', 'SAB_BYTES_TRIED': '439171756', 'SAB_CAT': 'videos', 'SAB_DUPLICATE': '0', 'SAB_ENCRYPTED': '0', 'SAB_FAIL_MSG': '', 'SAB_FILENAME': 'video.x264-NTb.nzb', 'SAB_FINAL_NAME': 'video.x264-NTb', 'SAB_GROUP': 'alt.binaries.kenpsx', 'SAB_NZO_ID': 'SABnzbd_nzo_gbgtx_9q', 'SAB_OVERSIZED': '0', 'SAB_PASSWORD': '', 'SAB_PP': '3', 'SAB_PRIORITY': '0', 'SAB_REPAIR': '1', 'SAB_SCRIPT': 'video.ps1', 'SAB_STATUS': 'Running', 'SAB_UNPACK': '1', 'SAB_UNWANTED_EXT': '0', 'SAB_URL': 'video.x264-NTb.nzb', 'SAB_FAILURE_URL': '', 'SAB_COMPLETE_DIR': 'I:\\videos\\~~~\\video.x264-NTb', 'SAB_PP_STATUS': '0', 'SAB_DOWNLOAD_TIME': '24', 'SAB_AVG_BPS': '17146', 'SAB_AGE': '10d', 'SAB_ORIG_NZB_GZ': 'D:\\download\\SABnzbd\\temporary\\video.x264-N\\__ADMIN__\\video.x264-NTb.nzb.gz', 'SAB_PROGRAM_DIR': 'D:\\tools\\SABnzbd', 'SAB_PAR2_COMMAND': '', 'SAB_MULTIPAR_COMMAND': 'D:\\tools\\SABnzbd\\win\\multipar\\par2j64.exe', 'SAB_RAR_COMMAND': 'D:\\tools\\SABnzbd\\win\\unrar\\x64\\UnRAR.exe', 'SAB_ZIP_COMMAND': '', 'SAB_7ZIP_COMMAND': 'D:\\tools\\SABnzbd\\win\\7zip\\7za.exe', 'SAB_VERSION': '3.1.0'}}
2020-10-26 17:55:10,726::DEBUG::[newsunpack:227] Failed script D:\scripts\SABnzbd\video.ps1, Traceback: 

This the 3.0.2 log where it succeeds

Code: Select all

2020-10-26 17:45:15,581::INFO::[newsunpack:322] Unrar finished on \\?\D:\download\SABnzbd\temporary\video.x264-N
2020-10-26 17:45:15,581::DEBUG::[newsunpack:2238] build_filelists(): joinables: []
2020-10-26 17:45:15,582::DEBUG::[newsunpack:2239] build_filelists(): zips: []
2020-10-26 17:45:15,582::DEBUG::[newsunpack:2240] build_filelists(): rars: []
2020-10-26 17:45:15,582::DEBUG::[newsunpack:2241] build_filelists(): 7zips: []
2020-10-26 17:45:15,582::DEBUG::[newsunpack:2242] build_filelists(): ts: []
2020-10-26 17:45:15,583::DEBUG::[newsunpack:2238] build_filelists(): joinables: []
2020-10-26 17:45:15,583::DEBUG::[newsunpack:2239] build_filelists(): zips: []
2020-10-26 17:45:15,583::DEBUG::[newsunpack:2240] build_filelists(): rars: []
2020-10-26 17:45:15,583::DEBUG::[newsunpack:2241] build_filelists(): 7zips: []
2020-10-26 17:45:15,583::DEBUG::[newsunpack:2242] build_filelists(): ts: []
2020-10-26 17:45:15,583::INFO::[postproc:428] Unpacked files ['\\\\?\\I:\\videos\\~~~\\_UNPACK_video.x264-NTb\\video.x264-NTb.mkv']
2020-10-26 17:45:15,584::INFO::[postproc:433] Finished unpack_magic on video.x264-NTb
2020-10-26 17:45:15,585::DEBUG::[filesystem:747] Renaming "\\?\I:\videos\~~~\_UNPACK_video.x264-NTb" to "\\?\I:\videos\~~~\video.x264-NTb"
2020-10-26 17:45:15,585::DEBUG::[filesystem:788] [sabnzbd\postproc.py.rename_and_collapse_folder] Removing dir \\?\I:\videos\~~~\_UNPACK_video.x264-NTb
2020-10-26 17:45:15,586::INFO::[newsunpack:206] Running external script D:\scripts\SABnzbd\video.ps1(I:\videos\~~~\video.x264-NTb, video.x264-NTb.nzb, video.x264-NTb, , videos, alt.binaries.boneless, 0, )
2020-10-26 17:45:16,044::DEBUG::[api:121] API-call from 127.0.0.1 [Mozilla/5.0 (Windows NT 10.0; WOW64; rv:68.9) Gecko/20100101 Goanna/4.6 Firefox/68.9 PaleMoon/28.14.2] {'mode': 'queue', 'search': '', 'start': '0', 'limit': '20', 'output': 'json', 'apikey': '9a8b55673a5c991806c5d20874e7addb', '_': '1603748616866'}
2020-10-26 17:45:16,048::DEBUG::[api:121] API-call from 127.0.0.1 [Mozilla/5.0 (Windows NT 10.0; WOW64; rv:68.9) Gecko/20100101 Goanna/4.6 Firefox/68.9 PaleMoon/28.14.2] {'mode': 'history', 'search': '', 'failed_only': '0', 'start': '0', 'limit': '10', 'last_history_update': '67', 'output': 'json', 'apikey': '9a8b55673a5c991806c5d20874e7addb', '_': '1603748616867'}
2020-10-26 17:45:16,550::INFO::[nzbstuff:1802] [sabnzbd\postproc.py.process_job] Purging data for job video.x264-NTb (delete_all_data=True)
2020-10-26 17:45:16,551::DEBUG::[filesystem:814] Removing dir recursively \\?\D:\download\SABnzbd\temporary\video.x264-N
2020-10-26 17:45:16,646::INFO::[database:290] Added job video.x264-NTb to history
2020-10-26 17:45:16,646::INFO::[database:261] Removing completed jobs older than 369 days from history
2020-10-26 17:45:16,661::INFO::[postproc:132] Saving postproc queue
2020-10-26 17:45:16,661::DEBUG::[__init__:994] [sabnzbd\postproc.py.save] Saving data for postproc2.sab
2020-10-26 17:45:16,662::DEBUG::[__init__:926] [sabnzbd\__init__.py.save_admin] Saving data for postproc2.sab in \\?\C:\Users\user\AppData\Local\sabnzbd\admin
2020-10-26 17:45:16,662::INFO::[downloader:310] Post-processing finished, resuming download

I replaced the actual NZB name with "video" for discretion.

[FrizzleFry51]

any update on this issue?

Still happening with 3.1.1

[safihre]

Oh sorry I thought I responded! In your PATH variable there is the path to powershell that ends with a \
Try to edit your PATH variable in system configuration and remove the slash from the powershell path.
Google suggested this.

[FrizzleFry51]

I fixed the path as suggested but I still get the same error with 3.1.1

BTW, I am able to execute the powershell script successfully with 3.1.1 if I run it indirectly by having SAB run a cmd script which executes the powershell script

Code: Select all

@echo off
D:\scripts\SABnzbd\video.ps1 %*

so I have a workaround.

I've had to use that method to run powershell scripts from other programs but SAB had been running that script fine for years until 3.1.0. Seems to me that SAB is no longer recognizing powershell scripts (.ps1) as valid executables.