subsync icon indicating copy to clipboard operation
subsync copied to clipboard

Subsync.exe will not open GUI on Windows (pyinstaller 3.6 builds)

Open DarkCeptor44 opened this issue 5 years ago • 20 comments

I used the portable version before and it worked fine for a while but now it simply does not do anything (v0.15.0), I launch it and I can see in Task Manager the process is gone. Installing it didn't do anything different however the subsync-debug.exe that comes with it does work correctly, this is the output it gives:

[13000] PyInstaller Bootloader 3.x
[13000] LOADER: executable is C:\Program Files\subsync\subsync-debug.exe
[13000] LOADER: homepath is C:\Program Files\subsync
[13000] LOADER: _MEIPASS2 is NULL
[13000] LOADER: archivename is C:\Program Files\subsync\subsync-debug.exe
[13000] LOADER: No need to extract files to run; setting extractionpath to homepath
[13000] LOADER: SetDllDirectory(C:\Program Files\subsync)
[13000] LOADER: Already in the child - running user's code.
[13000] LOADER: Python library: C:\Program Files\subsync\python36.dll
[13000] LOADER: Loaded functions from Python library.
[13000] LOADER: Manipulating environment (sys.path, sys.prefix)
[13000] LOADER: sys.prefix is C:\Program Files\subsync
[13000] LOADER: Pre-init sys.path is C:\Program Files\subsync\base_library.zip;C:\Program Files\subsync
[13000] LOADER: Setting runtime options
[13000] LOADER: Initializing python
[13000] LOADER: Overriding Python's sys.path
[13000] LOADER: Post-init sys.path is C:\Program Files\subsync\base_library.zip;C:\Program Files\subsync
[13000] LOADER: Setting sys.argv
[13000] LOADER: setting sys._MEIPASS
[13000] LOADER: importing modules from CArchive
[13000] LOADER: extracted struct
[13000] LOADER: callfunction returned...
[13000] LOADER: extracted pyimod01_os_path
[13000] LOADER: callfunction returned...
[13000] LOADER: extracted pyimod02_archive
[13000] LOADER: callfunction returned...
[13000] LOADER: extracted pyimod03_importers
[13000] LOADER: callfunction returned...
[13000] LOADER: Installing PYZ archive with Python modules.
[13000] LOADER: PYZ archive: PYZ-00.pyz
[13000] LOADER: Running pyiboot01_bootstrap.py
[13000] LOADER: Running pyi_rth_multiprocessing.py
[13000] LOADER: Running subsync.py

DarkCeptor44 avatar Apr 13 '20 23:04 DarkCeptor44

Could you run it again with more logs enabled subsync-debug.exe --loglevel=DEBUG? Thanks

sc0ty avatar Apr 14 '20 15:04 sc0ty

Full log:

[1956] PyInstaller Bootloader 3.x
[1956] LOADER: executable is C:\Program Files\subsync\subsync-debug.exe
[1956] LOADER: homepath is C:\Program Files\subsync
[1956] LOADER: _MEIPASS2 is NULL
[1956] LOADER: archivename is C:\Program Files\subsync\subsync-debug.exe
[1956] LOADER: No need to extract files to run; setting extractionpath to homepath
[1956] LOADER: SetDllDirectory(C:\Program Files\subsync)
[1956] LOADER: Already in the child - running user's code.
[1956] LOADER: Python library: C:\Program Files\subsync\python36.dll
[1956] LOADER: Loaded functions from Python library.
[1956] LOADER: Manipulating environment (sys.path, sys.prefix)
[1956] LOADER: sys.prefix is C:\Program Files\subsync
[1956] LOADER: Pre-init sys.path is C:\Program Files\subsync\base_library.zip;C:\Program Files\subsync
[1956] LOADER: Setting runtime options
[1956] LOADER: Initializing python
[1956] LOADER: Overriding Python's sys.path
[1956] LOADER: Post-init sys.path is C:\Program Files\subsync\base_library.zip;C:\Program Files\subsync
[1956] LOADER: Setting sys.argv
[1956] LOADER: setting sys._MEIPASS
[1956] LOADER: importing modules from CArchive
[1956] LOADER: extracted struct
[1956] LOADER: callfunction returned...
[1956] LOADER: extracted pyimod01_os_path
[1956] LOADER: callfunction returned...
[1956] LOADER: extracted pyimod02_archive
[1956] LOADER: callfunction returned...
[1956] LOADER: extracted pyimod03_importers
[1956] LOADER: callfunction returned...
[1956] LOADER: Installing PYZ archive with Python modules.
[1956] LOADER: PYZ archive: PYZ-00.pyz
[1956] LOADER: Running pyiboot01_bootstrap.py
[1956] LOADER: Running pyi_rth_multiprocessing.py
[1956] LOADER: Running subsync.py
13:47:50.146:   MainThread:     INFO:           subsync.settings: configuration loaded from C:\Users\MSI GX63VR\AppData\Roaming\subsync\subsync.json
13:47:50.148:   MainThread:    DEBUG:           subsync.settings: configuration: {'language': None, 'maxPointDist': 2.0, 'minPointsNo': 20, 'appendLangCode': True, 'outputCharEnc': 'UTF-8', 'windowSize': 1800.0, 'minWordProb': 0.3, 'jobsNo': None, 'minWordLen': 5, 'minCorrelation': 0.9999, 'minWordsSim': 0.6, 'minEffort': 0.5, 'outTimeOffset': 0.0, 'lastdir': 'H:\\Videos\\Filmes\\Bloodshot 2020 [2160p-4K] [DUAL]', 'lastSubLang': 'eng', 'lastRefLang': None, 'refsCache': True, 'autoUpdate': True, 'askForUpdate': True, 'overwriteExistingFiles': False, 'showOverwriteExistingFilesConfirmPopup': True, 'showLanguageNotSelectedPopup': True, 'batchOutPattern': '{ref_dir}\\{ref_name}{if:sub_lang:.}{sub_lang}.srt', 'batchSortFiles': False, 'debugOptions': False, 'logLevel': 30, 'logFile': None, 'logBlacklist': None}
13:47:50.153:   MainThread:    DEBUG:           subsync.settings: updating entry: language = None
13:47:50.154:   MainThread:    DEBUG:           subsync.settings: updating entry: maxPointDist = 2.0
13:47:50.156:   MainThread:    DEBUG:           subsync.settings: updating entry: minPointsNo = 20
13:47:50.157:   MainThread:    DEBUG:           subsync.settings: updating entry: appendLangCode = True
13:47:50.159:   MainThread:    DEBUG:           subsync.settings: updating entry: outputCharEnc = UTF-8
13:47:50.167:   MainThread:    DEBUG:           subsync.settings: updating entry: windowSize = 1800.0
13:47:50.169:   MainThread:    DEBUG:           subsync.settings: updating entry: minWordProb = 0.3
13:47:50.170:   MainThread:    DEBUG:           subsync.settings: updating entry: jobsNo = None
13:47:50.172:   MainThread:    DEBUG:           subsync.settings: updating entry: minWordLen = 5
13:47:50.173:   MainThread:    DEBUG:           subsync.settings: updating entry: minCorrelation = 0.9999
13:47:50.177:   MainThread:    DEBUG:           subsync.settings: updating entry: minWordsSim = 0.6
13:47:50.179:   MainThread:    DEBUG:           subsync.settings: updating entry: minEffort = 0.5
13:47:50.181:   MainThread:    DEBUG:           subsync.settings: updating entry: outTimeOffset = 0.0
13:47:50.183:   MainThread:    DEBUG:           subsync.settings: updating entry: lastdir = H:\Videos\Filmes\Bloodshot 2020 [2160p-4K] [DUAL]
13:47:50.184:   MainThread:    DEBUG:           subsync.settings: updating entry: lastSubLang = eng
13:47:50.185:   MainThread:    DEBUG:           subsync.settings: updating entry: lastRefLang = None
13:47:50.189:   MainThread:    DEBUG:           subsync.settings: updating entry: refsCache = True
13:47:50.192:   MainThread:    DEBUG:           subsync.settings: updating entry: autoUpdate = True
13:47:50.197:   MainThread:    DEBUG:           subsync.settings: updating entry: askForUpdate = True
13:47:50.204:   MainThread:    DEBUG:           subsync.settings: updating entry: overwriteExistingFiles = False
13:47:50.207:   MainThread:    DEBUG:           subsync.settings: updating entry: showOverwriteExistingFilesConfirmPopup = True
13:47:50.211:   MainThread:    DEBUG:           subsync.settings: updating entry: showLanguageNotSelectedPopup = True
13:47:50.213:   MainThread:    DEBUG:           subsync.settings: updating entry: batchOutPattern = {ref_dir}\{ref_name}{if:sub_lang:.}{sub_lang}.srt
13:47:50.215:   MainThread:    DEBUG:           subsync.settings: updating entry: batchSortFiles = False
13:47:50.217:   MainThread:    DEBUG:           subsync.settings: updating entry: debugOptions = False
13:47:50.218:   MainThread:    DEBUG:           subsync.settings: updating entry: logLevel = 30
13:47:50.223:   MainThread:    DEBUG:           subsync.settings: updating entry: logFile = None
13:47:50.225:   MainThread:    DEBUG:           subsync.settings: updating entry: logBlacklist = None
13:47:50.228:   MainThread:    DEBUG:           subsync.settings: updating entry: cli = False
13:47:50.229:   MainThread:    DEBUG:           subsync.settings: updating entry: verbose = 1
13:47:50.230:   MainThread:    DEBUG:           subsync.settings: updating entry: logLevel = 10
13:47:50.234:   MainThread:     INFO:           subsync.__main__: starting subsync 0.15@win32
13:47:50.238:   MainThread:     INFO:       subsync.translations: changing translation language to en
13:47:50.247:   MainThread:     INFO:           subsync.__main__: command line parameters: Namespace(cli=False, dumpWords=None, effort=None, jobsNo=None, logFile=None, logLevel=10, maxPointDist=None, minCorrelation=None, minPointsNo=None, minWordLen=None, minWordProb=None, minWordsSim=None, mode=None, outTimeOffset=None, verbose=1, windowSize=None)
13:47:53.325:   MainThread:    DEBUG:           subsync.settings: updating entry: windowSize = 1800.0
13:47:53.341: AssetListUpd:    DEBUG:                    asyncio: Using selector: SelectSelector
13:47:53.345: AssetListUpd:     INFO: subsync.assets.listupdater: reading remote asset list from C:\Users\MSI GX63VR\AppData\Roaming\subsync\assets.json
13:47:53.389: AssetListUpd:     INFO: subsync.assets.listupdater: update remote asset list, got 223 assets
13:47:53.402: AssetListUpd:     INFO: subsync.assets.listupdater: downloading remote assets list from https://github.com/sc0ty/subsync/releases/download/assets/assets.json
13:47:55.929: AssetListUpd:     INFO: subsync.assets.listupdater: update remote asset list, got 223 assets

DarkCeptor44 avatar Apr 14 '20 16:04 DarkCeptor44

I can't see anything wrong in this log. Do you know which version was working before? Could you check that version again? And maybe find first version that is broken?

sc0ty avatar Apr 15 '20 15:04 sc0ty

Same problem here

Sorry!

C:\Program Files\subsync>subsync-debug.exe --loglevel=DEBUG
[88] PyInstaller Bootloader 3.x
[88] LOADER: executable is C:\Program Files\subsync\subsync-debug.exe
[88] LOADER: homepath is C:\Program Files\subsync
[88] LOADER: _MEIPASS2 is NULL
[88] LOADER: archivename is C:\Program Files\subsync\subsync-debug.exe
[88] LOADER: No need to extract files to run; setting extractionpath to homepath
[88] LOADER: SetDllDirectory(C:\Program Files\subsync)
[88] LOADER: Already in the child - running user's code.
[88] LOADER: Python library: C:\Program Files\subsync\python36.dll
[88] LOADER: Loaded functions from Python library.
[88] LOADER: Manipulating environment (sys.path, sys.prefix)
[88] LOADER: sys.prefix is C:\Program Files\subsync
[88] LOADER: Pre-init sys.path is C:\Program Files\subsync\base_library.zip;C:\Program Files\subsync
[88] LOADER: Setting runtime options
[88] LOADER: Initializing python
[88] LOADER: Overriding Python's sys.path
[88] LOADER: Post-init sys.path is C:\Program Files\subsync\base_library.zip;C:\Program Files\subsync
[88] LOADER: Setting sys.argv
[88] LOADER: setting sys._MEIPASS
[88] LOADER: importing modules from CArchive
[88] LOADER: extracted struct
[88] LOADER: callfunction returned...
[88] LOADER: extracted pyimod01_os_path
[88] LOADER: callfunction returned...
[88] LOADER: extracted pyimod02_archive
[88] LOADER: callfunction returned...
[88] LOADER: extracted pyimod03_importers
[88] LOADER: callfunction returned...
[88] LOADER: Installing PYZ archive with Python modules.
[88] LOADER: PYZ archive: PYZ-00.pyz
[88] LOADER: Running pyiboot01_bootstrap.py
[88] LOADER: Running pyi_rth_multiprocessing.py
[88] LOADER: Running subsync.py
17:29:40.508:   MainThread:     INFO:           subsync.settings: configuration loaded from C:\Users\tigon\AppData\Roaming\subsync\subsync.json
17:29:40.509:   MainThread:    DEBUG:           subsync.settings: configuration: {'language': 'en', 'maxPointDist': 2.0, 'minPointsNo': 20, 'appendLangCode': True, 'outputCharEnc': 'UTF-8', 'windowSize': 1800.0, 'minWordProb': 0.3, 'jobsNo': None, 'minWordLen': 5, 'minCorrelation': 0.9999, 'minWordsSim': 0.6, 'minEffort': 0.5, 'outTimeOffset': 0.0, 'lastdir': '', 'lastSubLang': None, 'lastRefLang': None, 'refsCache': True, 'autoUpdate': True, 'askForUpdate': True, 'overwriteExistingFiles': False, 'showOverwriteExistingFilesConfirmPopup': True, 'showLanguageNotSelectedPopup': True, 'batchOutPattern': '{ref_dir}\\{ref_name}{if:sub_lang:.}{sub_lang}.srt', 'batchSortFiles': False, 'debugOptions': False, 'logLevel': 30, 'logFile': None, 'logBlacklist': None}
17:29:40.510:   MainThread:    DEBUG:           subsync.settings: updating entry: language = en
17:29:40.510:   MainThread:    DEBUG:           subsync.settings: updating entry: maxPointDist = 2.0
17:29:40.510:   MainThread:    DEBUG:           subsync.settings: updating entry: minPointsNo = 20
17:29:40.511:   MainThread:    DEBUG:           subsync.settings: updating entry: appendLangCode = True
17:29:40.511:   MainThread:    DEBUG:           subsync.settings: updating entry: outputCharEnc = UTF-8
17:29:40.511:   MainThread:    DEBUG:           subsync.settings: updating entry: windowSize = 1800.0
17:29:40.512:   MainThread:    DEBUG:           subsync.settings: updating entry: minWordProb = 0.3
17:29:40.512:   MainThread:    DEBUG:           subsync.settings: updating entry: jobsNo = None
17:29:40.512:   MainThread:    DEBUG:           subsync.settings: updating entry: minWordLen = 5
17:29:40.513:   MainThread:    DEBUG:           subsync.settings: updating entry: minCorrelation = 0.9999
17:29:40.513:   MainThread:    DEBUG:           subsync.settings: updating entry: minWordsSim = 0.6
17:29:40.513:   MainThread:    DEBUG:           subsync.settings: updating entry: minEffort = 0.5
17:29:40.514:   MainThread:    DEBUG:           subsync.settings: updating entry: outTimeOffset = 0.0
17:29:40.514:   MainThread:    DEBUG:           subsync.settings: updating entry: lastdir =
17:29:40.514:   MainThread:    DEBUG:           subsync.settings: updating entry: lastSubLang = None
17:29:40.515:   MainThread:    DEBUG:           subsync.settings: updating entry: lastRefLang = None
17:29:40.515:   MainThread:    DEBUG:           subsync.settings: updating entry: refsCache = True
17:29:40.515:   MainThread:    DEBUG:           subsync.settings: updating entry: autoUpdate = True
17:29:40.516:   MainThread:    DEBUG:           subsync.settings: updating entry: askForUpdate = True
17:29:40.516:   MainThread:    DEBUG:           subsync.settings: updating entry: overwriteExistingFiles = False
17:29:40.516:   MainThread:    DEBUG:           subsync.settings: updating entry: showOverwriteExistingFilesConfirmPopup = True
17:29:40.517:   MainThread:    DEBUG:           subsync.settings: updating entry: showLanguageNotSelectedPopup = True
17:29:40.517:   MainThread:    DEBUG:           subsync.settings: updating entry: batchOutPattern = {ref_dir}\{ref_name}{if:sub_lang:.}{sub_lang}.srt
17:29:40.520:   MainThread:    DEBUG:           subsync.settings: updating entry: batchSortFiles = False
17:29:40.520:   MainThread:    DEBUG:           subsync.settings: updating entry: debugOptions = False
17:29:40.520:   MainThread:    DEBUG:           subsync.settings: updating entry: logLevel = 30
17:29:40.521:   MainThread:    DEBUG:           subsync.settings: updating entry: logFile = None
17:29:40.521:   MainThread:    DEBUG:           subsync.settings: updating entry: logBlacklist = None
17:29:40.521:   MainThread:    DEBUG:           subsync.settings: updating entry: cli = False
17:29:40.521:   MainThread:    DEBUG:           subsync.settings: updating entry: verbose = 1
17:29:40.522:   MainThread:    DEBUG:           subsync.settings: updating entry: logLevel = 10
17:29:40.522:   MainThread:     INFO:           subsync.__main__: starting subsync 0.15@win32
17:29:40.523:   MainThread:     INFO:       subsync.translations: changing translation language to en
17:29:40.525:   MainThread:     INFO:           subsync.__main__: command line parameters: Namespace(cli=False, dumpWords=None, effort=None, jobsNo=None, logFile=None, logLevel=10, maxPointDist=None, minCorrelation=None, minPointsNo=None, minWordLen=None, minWordProb=None, minWordsSim=None, mode=None, outTimeOffset=None, verbose=1, windowSize=None)
17:29:41.327:   MainThread:    DEBUG:           subsync.settings: updating entry: windowSize = 1800.0
17:29:41.333: AssetListUpd:    DEBUG:                    asyncio: Using selector: SelectSelector
17:29:41.335: AssetListUpd:     INFO: subsync.assets.listupdater: reading remote asset list from C:\Users\tigon\AppData\Roaming\subsync\assets.json
17:29:41.361: AssetListUpd:     INFO: subsync.assets.listupdater: update remote asset list, got 223 assets
17:29:41.365: AssetListUpd:     INFO: subsync.assets.listupdater: downloading remote assets list from https://github.com/sc0ty/subsync/releases/download/assets/assets.json
17:29:47.122: AssetListUpd:     INFO: subsync.assets.listupdater: update remote asset list, got 223 assets


tnascif avatar May 14 '20 20:05 tnascif

subsync-cmd.exe is command line only (without GUI), you should use subsync.exe or subsync-debug.exe to dump logs.

sc0ty avatar May 14 '20 20:05 sc0ty

Sorry for the lack of response, I tested the portable versions of v0.14.0 and it also didn't work but v0.13.0 does work so 0.14.0 is the first version which stopped working for me.

DarkCeptor44 avatar May 15 '20 00:05 DarkCeptor44

I can't find anything that could've introduce such bug between these two versions. Are you willing to help me debug this issue? I would make several builds and you would try to run them (without installation, just run some exes) so we would trace offending change. Sorry for bothering you, but I can't reproduce this bug myself.

sc0ty avatar May 17 '20 17:05 sc0ty

Sure I'd be happy to help! But I should probably mention that upon installing the new version on another machine it's working as intended, now I'm unclear whether or not I should close this issue.

DarkCeptor44 avatar May 17 '20 18:05 DarkCeptor44

But its still not working on one of your machines? If so, here are builds I'd like you to check:

I've included plain 0.13 I've rebuild just to make sure it still works with updated dependencies. Just extract zip file, run subsync.exe and check if window shows up. Thanks for your help.

sc0ty avatar May 17 '20 20:05 sc0ty

Yeah it's not working on my laptop, anyway I tried the four versions and none of them work, I was curious so I again downloaded the 0.13 portable version from the Releases page and again it works.

Running them all through subsync-debug.exe always work and they seem to always give the same debug info, I noticed that after a few seconds an error shows up:

18:44:38.087:AssetListUpd:   ERROR:subsync.assets.listupdat: cannot download asset list from http://192.168.0.100:8000/assets-local.json: ClientConnectorError(ConnectionKey(host='192.168.0.100', port=8000, is_ssl=False, ssl=None, proxy=None, proxy_auth=None, proxy_headers_hash=None), TimeoutError(10060, "Connect call failed ('192.168.0.100', 8000)"))

But that doesn't crash the window or anything.

DarkCeptor44 avatar May 17 '20 21:05 DarkCeptor44

So it looks like the problem is with dependencies. One more idea, could you dump logs from subsync.exe (not subsync-debug.exe): subsync.exe --loglevel=DEBUG --logfile=c:\where\to\dump\log.txt

This connection error is because those builds are set to connect to my test server to check for updates, and its not accessible from internet. This won't affect startup.

Also what Windows are you running?

sc0ty avatar May 17 '20 22:05 sc0ty

@tnascif: sorry, I didn't noticed that you edited your comment. Is subsync-debug.exe working for you? It looks like from this log.

sc0ty avatar May 17 '20 22:05 sc0ty

That command doesn't output anything, I tried subsync.exe --loglevel=DEBUG --logfile=C:\log.txt on the portable plain 0.13 you've sent me and the installed 0.15 but the file is never created.

But answering your last question: Desktop: Windows 10 Home 1903 18362.778 (the one that worked) Laptop: Windows 10 Home 1909 18363.657 (the one that doesn't work)

DarkCeptor44 avatar May 17 '20 22:05 DarkCeptor44

Only difference between debug and standard version is in pyinstaller script (I'm using pyinstaller to compile python code to exe). And it looks like pyinstaller was updated around subsync version 0.14 (unfortunately I don't known exactly when I've started using new version).

So lets try with different versions:

I've added also subsync-test.exe - it should show console window and GUI, but without extra debugs like subsync-debug. Could you try both execs?

And about Windows version - I have 1909 Home on virtual machine and subsync is working there, so its probably not the case. I'll try to install latest updates and check again since the second number is lower than yours.

sc0ty avatar May 18 '20 16:05 sc0ty

Using subsync-test they both work and generate the correct logfiles, here they are:

But the normal subsync.exe only works on 3.5 not 3.6.

DarkCeptor44 avatar May 18 '20 20:05 DarkCeptor44

Thats subsync-test.exe right? What about subsync.exe? So it looks like builds with console enabled are fine.

sc0ty avatar May 18 '20 20:05 sc0ty

Thats subsync-test.exe right? What about subsync.exe?

As I've said only the pyinstaller-3.5\subsync.exe works.

So it looks like builds with console enabled are fine.

The subsync.exe from pyinstaller-3.5 works and is not console enabled.

DarkCeptor44 avatar May 18 '20 23:05 DarkCeptor44

Yeah, you right. It looks like pyinstaller 3.6 is to blame. Great thanks for your help. Could you try three more?

Its the latest and greatest subsync version build with pyinstaller 3.5 (I'm expecting this to work), 3.6 (this not). The last one is also build with 3.6 but with different build options (everything set to default) - that's the interesting case. Just run subsync.exe of each version, don't need to dump logs.

If we fail to identify the root cause of this bug I will stick to the pyinstaller 3.5 for the next official builds.

sc0ty avatar May 19 '20 19:05 sc0ty

Yep, only the 3.5 one works.

DarkCeptor44 avatar May 19 '20 20:05 DarkCeptor44

Ok, I will use 3.5 for now. Thanks a lot for your help, I wouldn't work it out myself. I would open an issue in pyinstaller github, but its hard to tell anything useful about this bug.

sc0ty avatar May 19 '20 20:05 sc0ty