Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Need a -log <PathToLogFile> commandline switch #1878

Closed
HenrikHolmIT opened this issue Feb 3, 2021 · 34 comments
Closed

Need a -log <PathToLogFile> commandline switch #1878

HenrikHolmIT opened this issue Feb 3, 2021 · 34 comments

Comments

@HenrikHolmIT
Copy link

Currently experience problems sending a lot of print jobs to a network printer from a server. These print jobs are created with the -silent -print-to commandline switches one after the other. This happens through out the day but at some point it is as though the server or the printer has had enough and SumatraPDF.exe starts to hang and will never exit. I had to start monitoring the process and if not finished after 60 seconds I have to kill the process. When it works it usually exits after a few seconds but when I does not work the process just hangs forever.

What I would like is a -log switch. Either with a or SumatraPDF.exe can just designate its own place where it wants to store the log file.

This would be something we would to able to use to trace why printing has stopped working. Most likely its a problem with the server or the printer but the -log switch would be great for debugging in the long run when debugging future problems.

Maybe logs would show how you could provide code to exit out with a proper exitcode if print job fails to send to printer.

@GitHubRulesOK
Copy link
Collaborator

GitHubRulesOK commented Feb 3, 2021

Possibly related to #301 where others have described "sometimes it works"

The description at https://www.sumatrapdfreader.org/docs/Debugging-Sumatra.html mentions a hanging state but I have not tried to check how useful those are for running within a server.

@kjk
Is there a means to export some debugging logs e.g. as when a crash occurs (but without inducing a crash)

@HenrikHolmIT HenrikHolmIT changed the title Need a -log <PathToLogFile> Need a -log <PathToLogFile> switch Feb 3, 2021
@HenrikHolmIT HenrikHolmIT changed the title Need a -log <PathToLogFile> switch Need a -log <PathToLogFile> commandline switch Feb 3, 2021
@HenrikHolmIT
Copy link
Author

I should add that the print code is running form a Windows Service installed on said server. Its mostly works perfect but then those times where management has to print a huge amount of documents something locks up. And after a reboot of the server every thing works again.
I'll check out your link.

@HenrikHolmIT
Copy link
Author

Server is a Windows Server 2012. Its old but it does work when it works. Our client is not able to upgrade to a more recent version of Windows Server due to legacy software compatibility.

@HenrikHolmIT
Copy link
Author

WinDbg is installed. Waiting for next hang to strip out a debug report

@HenrikHolmIT
Copy link
Author

HenrikHolmIT commented Feb 4, 2021

Executing the commands on the debug site this is what I get:

Microsoft (R) Windows Debugger Version 6.3.9600.17336 AMD64
Copyright (c) Microsoft Corporation. All rights reserved.

*** wait with pending attach
Symbol search path is: *** Invalid ***
****************************************************************************
* Symbol loading may be unreliable without a symbol search path.           *
* Use .symfix to have the debugger choose a symbol path.                   *
* After setting your symbol path, use .reload to refresh symbol locations. *
****************************************************************************
Executable search path is: 
ModLoad: 000007f7`01580000 000007f7`0248d000   C:\Windows\system32\config\systemprofile\AppData\Roaming\Inventio.IT\SMARTtransfer\Sumatra\v3.2\SumatraPDF-3.2-64.exe
ModLoad: 000007fb`47e00000 000007fb`47fbe000   C:\Windows\SYSTEM32\ntdll.dll
ModLoad: 000007fb`45ab0000 000007fb`45be7000   C:\Windows\system32\KERNEL32.DLL
ModLoad: 000007fb`44dc0000 000007fb`44eb4000   C:\Windows\system32\KERNELBASE.dll
ModLoad: 000007fb`41bf0000 000007fb`41e59000   C:\Windows\WinSxS\amd64_microsoft.windows.common-controls_6595b64144ccf1df_6.0.9200.22792_none_2abfb4e38b3001db\COMCTL32.dll
ModLoad: 000007fb`40d10000 000007fb`410be000   C:\Windows\SYSTEM32\d2d1.dll
ModLoad: 000007fb`450f0000 000007fb`4523c000   C:\Windows\system32\USER32.dll
ModLoad: 000007fb`45960000 000007fb`45aa3000   C:\Windows\system32\GDI32.dll
ModLoad: 000007fb`39b30000 000007fb`39bae000   C:\Windows\SYSTEM32\WINSPOOL.DRV
ModLoad: 000007fb`47c60000 000007fb`47d01000   C:\Windows\system32\COMDLG32.dll
ModLoad: 000007fb`46710000 000007fb`467ef000   C:\Windows\system32\ADVAPI32.dll
ModLoad: 000007fb`46970000 000007fb`47c58000   C:\Windows\system32\SHELL32.dll
ModLoad: 000007fb`467f0000 000007fb`4696c000   C:\Windows\system32\ole32.dll
ModLoad: 000007fb`47d10000 000007fb`47dd6000   C:\Windows\system32\OLEAUT32.dll
ModLoad: 000007fb`46660000 000007fb`46705000   C:\Windows\system32\msvcrt.dll
ModLoad: 000007fb`46490000 000007fb`464e0000   C:\Windows\system32\SHLWAPI.dll
ModLoad: 000007fb`45350000 000007fb`45398000   C:\Windows\SYSTEM32\sechost.dll
ModLoad: 000007fb`453a0000 000007fb`454db000   C:\Windows\system32\RPCRT4.dll
ModLoad: 000007fb`45c50000 000007fb`45dfa000   C:\Windows\SYSTEM32\combase.dll
ModLoad: 000007fb`429c0000 000007fb`42a57000   C:\Windows\SYSTEM32\SHCORE.DLL
ModLoad: 000007fb`436c0000 000007fb`437a4000   C:\Windows\system32\uxtheme.dll
ModLoad: 000007fb`420f0000 000007fb`42111000   C:\Windows\system32\dwmapi.dll
ModLoad: 000007fb`45bf0000 000007fb`45bf5000   C:\Windows\system32\normaliz.dll
ModLoad: 000007fb`409d0000 000007fb`40af2000   C:\Windows\system32\uiautomationcore.dll
ModLoad: 000007fb`38a20000 000007fb`38b83000   C:\Windows\system32\dbghelp.dll
ModLoad: 000007fb`34230000 000007fb`343d2000   C:\Windows\WinSxS\amd64_microsoft.windows.gdiplus_6595b64144ccf1df_1.1.9200.23246_none_5ba54dd0e5c75f0c\gdiplus.dll
ModLoad: 000007fb`40910000 000007fb`40917000   C:\Windows\system32\msimg32.dll
ModLoad: 000007fb`44ef0000 000007fb`4507b000   C:\Windows\system32\urlmon.dll
ModLoad: 000007fb`45690000 000007fb`4595d000   C:\Windows\system32\iertutil.dll
ModLoad: 000007fb`45e10000 000007fb`462bc000   C:\Windows\system32\WININET.dll
ModLoad: 000007fb`44da0000 000007fb`44dbf000   C:\Windows\system32\USERENV.dll
ModLoad: 000007fb`44a20000 000007fb`44a35000   C:\Windows\system32\profapi.dll
ModLoad: 000007fb`3ff60000 000007fb`3ff69000   C:\Windows\system32\version.dll
ModLoad: 000007fb`41e80000 000007fb`4200a000   C:\Windows\system32\windowscodecs.dll
ModLoad: 000007fb`447d0000 000007fb`447da000   C:\Windows\SYSTEM32\CRYPTBASE.dll
ModLoad: 000007fb`44770000 000007fb`447cc000   C:\Windows\SYSTEM32\bcryptPrimitives.dll
(1784.f40): Break instruction exception - code 80000003 (first chance)
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for C:\Windows\SYSTEM32\ntdll.dll - 
ntdll!DbgBreakPoint:
000007fb`47e01dd0 cc              int     3
0:006> .sympath+ SRV*c:\symbols*http://msdl.microsoft.com/download/symbols
Symbol search path is: SRV*c:\symbols*http://msdl.microsoft.com/download/symbols
Expanded Symbol search path is: srv*c:\symbols*http://msdl.microsoft.com/download/symbols

************* Symbol Path validation summary **************
Response                         Time (ms)     Location
Deferred                                       SRV*c:\symbols*http://msdl.microsoft.com/download/symbols
0:006> ~*kb

   0  Id: 1784.13f4 Suspend: 1 Teb: 000007f7`00a0e000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fb`459fab89 : 000000d5`34340000 00000000`00000002 00000000`00020006 00000000`00020010 : ntdll!NtRequestWaitReplyPort+0xa
000007fb`459f9de8 : 00000000`00000001 000000d5`353e0000 00000000`00000000 000000d5`3416e2f0 : GDI32!PROXYPORT::SendRequest+0x191
000007fb`45a28618 : 000000d5`3416e230 000000d5`34b6e2b0 00000000`00000001 00000000`00000000 : GDI32!PROXYPORT::DocumentEvent+0x524
000007fb`45988542 : 000000d5`351e1f50 000000d5`3416e350 00000000`00000000 000000d5`351e0080 : GDI32!DocumentEventEx+0xb5570
000007fb`459b0451 : 0000e2ed`17498559 000007f7`017d6676 000000d5`34b5d310 00000000`00000001 : GDI32!hdcCreateDCW+0x1e5
000007fb`459b048b : 00000000`00000002 000000d5`3416e730 000000d5`3416e9d0 00000000`00000000 : GDI32!bCreateDCW+0x89
000007f7`0167a721 : 000000d5`34b0ab50 000000d5`34b0b080 00000000`00000000 00000000`0000000b : GDI32!CreateDCW+0x13
000007f7`0167d047 : 000000d5`3416e9d0 000000d5`34b03850 000000d5`34b048c6 00000000`00000000 : SumatraPDF_3_2_64!PrintToDevice+0x1d1 [C:\Users\kjk\src\sumatrapdf\src\Print.cpp @ 161]
000007f7`016a4a54 : 000000d5`34355ed0 000000d5`3416eeb0 000000d5`3436bec0 00000000`410102ec : SumatraPDF_3_2_64!PrintFile+0x5a7 [C:\Users\kjk\src\sumatrapdf\src\Print.cpp @ 901]
(Inline Function) : --------`-------- --------`-------- --------`-------- --------`-------- : SumatraPDF_3_2_64!PrintFile+0xd0 [C:\Users\kjk\src\sumatrapdf\src\Print.cpp @ 927]
000007f7`019f9a8a : 00000000`00000000 00000000`00000001 00000000`00000000 00000000`00000000 : SumatraPDF_3_2_64!WinMain+0x1324 [C:\Users\kjk\src\sumatrapdf\src\SumatraStartup.cpp @ 990]
(Inline Function) : --------`-------- --------`-------- --------`-------- --------`-------- : SumatraPDF_3_2_64!invoke_main+0x21 [d:\agent\_work\5\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 102]
000007fb`45ab1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : SumatraPDF_3_2_64!__scrt_common_main_seh+0x106 [d:\agent\_work\5\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 288]
000007fb`47e5bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21

   1  Id: 1784.fb0 Suspend: 1 Teb: 000007f7`00a0c000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fb`44dc10ea : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!ZwWaitForSingleObject+0xa
000007f7`0167edac : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`000000c0 : KERNELBASE!WaitForSingleObjectEx+0x92
000007fb`45ab1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : SumatraPDF_3_2_64!RenderCache::RenderCacheThread+0xcc [C:\Users\kjk\src\sumatrapdf\src\RenderCache.cpp @ 604]
000007fb`47e5bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21

   2  Id: 1784.4dc Suspend: 1 Teb: 000007f7`00a0a000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fb`44dc10ea : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!ZwWaitForSingleObject+0xa
000007f7`01658076 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000124 : KERNELBASE!WaitForSingleObjectEx+0x92
000007fb`45ab1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : SumatraPDF_3_2_64!CrashDumpThread+0x16 [C:\Users\kjk\src\sumatrapdf\src\CrashHandler.cpp @ 304]
000007fb`47e5bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21

   3  Id: 1784.cd0 Suspend: 1 Teb: 000007f7`00a06000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fb`47e077a3 : 00000000`00000006 000000d5`34352550 000000d5`34beeaa0 00000000`00000000 : ntdll!NtWaitForWorkViaWorkerFactory+0xa
000007fb`45ab1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlCompareUnicodeString+0x267
000007fb`47e5bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21

   4  Id: 1784.f8c Suspend: 1 Teb: 000007f7`00a04000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fb`44dc10ea : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!ZwWaitForSingleObject+0xa
000007fb`39b59681 : 000007fb`39b30000 00000000`00000000 00000000`00000000 00000000`00000184 : KERNELBASE!WaitForSingleObjectEx+0x92
000007fb`45ab1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : WINSPOOL!MonitorRPCServerProcess+0x19
000007fb`47e5bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21

   5  Id: 1784.1380 Suspend: 1 Teb: 000007f7`008de000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fb`47e077a3 : 00000000`00000006 000000d5`34352550 000000d5`34beeaa0 00000000`00000000 : ntdll!NtWaitForWorkViaWorkerFactory+0xa
000007fb`45ab1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlCompareUnicodeString+0x267
000007fb`47e5bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21

#  6  Id: 1784.f40 Suspend: 1 Teb: 000007f7`008dc000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fb`47ea80e0 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!DbgBreakPoint
000007fb`45ab1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!DbgUiRemoteBreakin+0x34
000007fb`47e5bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
0:006> lmf
start             end                 module name
000007f7`01580000 000007f7`0248d000   SumatraPDF_3_2_64 C:\Windows\system32\config\systemprofile\AppData\Roaming\Inventio.IT\SMARTtransfer\Sumatra\v3.2\SumatraPDF-3.2-64.exe
000007fb`34230000 000007fb`343d2000   gdiplus  C:\Windows\WinSxS\amd64_microsoft.windows.gdiplus_6595b64144ccf1df_1.1.9200.23246_none_5ba54dd0e5c75f0c\gdiplus.dll
000007fb`38a20000 000007fb`38b83000   dbghelp  C:\Windows\system32\dbghelp.dll
000007fb`39b30000 000007fb`39bae000   WINSPOOL C:\Windows\SYSTEM32\WINSPOOL.DRV
000007fb`3ff60000 000007fb`3ff69000   version  C:\Windows\system32\version.dll
000007fb`40910000 000007fb`40917000   msimg32  C:\Windows\system32\msimg32.dll
000007fb`409d0000 000007fb`40af2000   uiautomationcore C:\Windows\system32\uiautomationcore.dll
000007fb`40d10000 000007fb`410be000   d2d1     C:\Windows\SYSTEM32\d2d1.dll
000007fb`41bf0000 000007fb`41e59000   COMCTL32 C:\Windows\WinSxS\amd64_microsoft.windows.common-controls_6595b64144ccf1df_6.0.9200.22792_none_2abfb4e38b3001db\COMCTL32.dll
000007fb`41e80000 000007fb`4200a000   windowscodecs C:\Windows\system32\windowscodecs.dll
000007fb`420f0000 000007fb`42111000   dwmapi   C:\Windows\system32\dwmapi.dll
000007fb`429c0000 000007fb`42a57000   SHCORE   C:\Windows\SYSTEM32\SHCORE.DLL
000007fb`436c0000 000007fb`437a4000   uxtheme  C:\Windows\system32\uxtheme.dll
000007fb`44770000 000007fb`447cc000   bcryptPrimitives C:\Windows\SYSTEM32\bcryptPrimitives.dll
000007fb`447d0000 000007fb`447da000   CRYPTBASE C:\Windows\SYSTEM32\CRYPTBASE.dll
000007fb`44a20000 000007fb`44a35000   profapi  C:\Windows\system32\profapi.dll
000007fb`44da0000 000007fb`44dbf000   USERENV  C:\Windows\system32\USERENV.dll
000007fb`44dc0000 000007fb`44eb4000   KERNELBASE C:\Windows\system32\KERNELBASE.dll
000007fb`44ef0000 000007fb`4507b000   urlmon   C:\Windows\system32\urlmon.dll
000007fb`450f0000 000007fb`4523c000   USER32   C:\Windows\system32\USER32.dll
000007fb`45350000 000007fb`45398000   sechost  C:\Windows\SYSTEM32\sechost.dll
000007fb`453a0000 000007fb`454db000   RPCRT4   C:\Windows\system32\RPCRT4.dll
000007fb`45690000 000007fb`4595d000   iertutil C:\Windows\system32\iertutil.dll
000007fb`45960000 000007fb`45aa3000   GDI32    C:\Windows\system32\GDI32.dll
000007fb`45ab0000 000007fb`45be7000   KERNEL32 C:\Windows\system32\KERNEL32.DLL
000007fb`45bf0000 000007fb`45bf5000   normaliz C:\Windows\system32\normaliz.dll
000007fb`45c50000 000007fb`45dfa000   combase  C:\Windows\SYSTEM32\combase.dll
000007fb`45e10000 000007fb`462bc000   WININET  C:\Windows\system32\WININET.dll
000007fb`46490000 000007fb`464e0000   SHLWAPI  C:\Windows\system32\SHLWAPI.dll
000007fb`46660000 000007fb`46705000   msvcrt   C:\Windows\system32\msvcrt.dll
000007fb`46710000 000007fb`467ef000   ADVAPI32 C:\Windows\system32\ADVAPI32.dll
000007fb`467f0000 000007fb`4696c000   ole32    C:\Windows\system32\ole32.dll
000007fb`46970000 000007fb`47c58000   SHELL32  C:\Windows\system32\SHELL32.dll
000007fb`47c60000 000007fb`47d01000   COMDLG32 C:\Windows\system32\COMDLG32.dll
000007fb`47d10000 000007fb`47dd6000   OLEAUT32 C:\Windows\system32\OLEAUT32.dll
000007fb`47e00000 000007fb`47fbe000   ntdll    C:\Windows\SYSTEM32\ntdll.dll

@GitHubRulesOK
Copy link
Collaborator

GitHubRulesOK commented Feb 4, 2021

[edited to avoid others later confusion]

Again I have not used the debugger tools however as the 1st warning is
Symbol search path is: *** Invalid ***
I think that needs to be resolved first
looking at https://docs.microsoft.com/en-us/windows-hardware/drivers/debugger/verifying-symbols

  1. Double check where SumatraPDF viewer downloads the debugger files Using the menu option Debug > Download symbols (NOTE the folder name displayed) in there you should find 3x .pdb.
    Location is usually where the exe is located then possibly a \crashinfo folder. Check files are rights accessible to the running user(s) perhaps check folder inherited permissions are broad enough for both WinDbg and Print processes.

Now the part where " I know what I dont know"

the Verifying Symbols instruction tell you to use
Windbg dbgcmd to find the working location

0:000> .sympath
Current Symbol Path is: the important bit

Which in your case should POSSIBLY be
C:\Windows\system32\config\systemprofile\AppData\Roaming\Inventio.IT\SMARTtransfer\Sumatra\v3.2

Unfortunately without any related experience, I can't help you ensure that is corrected.

@HenrikHolmIT
Copy link
Author

HenrikHolmIT commented Feb 4, 2021

I can verify that symbols have been downloaded via SumatraPDF UI before I loaded out the text above.

I've restarted the server in the meantime and will have to report back when the problem comes back. Ill have to try to get it to load the correct symbols next time.

image

@GitHubRulesOK
Copy link
Collaborator

OK I was wrong your screenshot shows that without a crash the .dbg files are NOT in a \crashinfo subfolder, good luck

@HenrikHolmIT
Copy link
Author

We're not exactly experiencing a crash. Its a hang. We kill the SumatraPDF process after waiting 60 seconds. Dont know if that makes a difference.

@GitHubRulesOK
Copy link
Collaborator

Could be a red herring but
I note your cut and paste is a bit different to plaintext thus slightly difficult to spot that the "default" location for debug files appears as if it MAY BE c:\symbols, thus I would be trying a copy of the three files there before next hang, in the hope they are found there within that folder ?

@HenrikHolmIT
Copy link
Author

Its this line that downloaded them to this folder from SumatraPDF documentation/Debugging Sumatra link. I've copied the pdb files to that folder and will set WinDBG to use that folder as Symbols folder.

.sympath+ SRVc:\symbolshttp://msdl.microsoft.com/download/symbols

@GitHubRulesOK
Copy link
Collaborator

"A little knowledge is a dangerous thing"

I "think" like in many "path" cases, you need to append default paths to include secondary locations such as SumatraPDF folder by using WibDbg commands but my suggestion is that I "think" c:\symbols may be a fallback location.

@HenrikHolmIT
Copy link
Author

I can confirm that it seems to load the symbols if I direct WinDBG to the symbols folder. Now just need it to hang again.

@HenrikHolmIT
Copy link
Author

HenrikHolmIT commented Feb 8, 2021

I just logged at hang an here is the output. Please let me know if you see something that can be used.

Microsoft (R) Windows Debugger Version 6.3.9600.17336 AMD64
Copyright (c) Microsoft Corporation. All rights reserved.

*** wait with pending attach

************* Symbol Path validation summary **************
Response                         Time (ms)     Location
OK                                             C:\symbols
Symbol search path is: C:\symbols
Executable search path is: 
ModLoad: 000007f7`82dd0000 000007f7`83cdd000   C:\Windows\system32\config\systemprofile\AppData\Roaming\Inventio.IT\SMARTtransfer\Sumatra\v3.2\SumatraPDF-3.2-64.exe
ModLoad: 000007fc`324d0000 000007fc`3268e000   C:\Windows\SYSTEM32\ntdll.dll
ModLoad: 000007fc`2f5c0000 000007fc`2f6f7000   C:\Windows\system32\KERNEL32.DLL
ModLoad: 000007fc`2f470000 000007fc`2f564000   C:\Windows\system32\KERNELBASE.dll
ModLoad: 000007fc`2c400000 000007fc`2c669000   C:\Windows\WinSxS\amd64_microsoft.windows.common-controls_6595b64144ccf1df_6.0.9200.22792_none_2abfb4e38b3001db\COMCTL32.dll
ModLoad: 000007fc`2b270000 000007fc`2b61e000   C:\Windows\SYSTEM32\d2d1.dll
ModLoad: 000007fc`30cf0000 000007fc`30e3c000   C:\Windows\system32\USER32.dll
ModLoad: 000007fc`31e60000 000007fc`31fa3000   C:\Windows\system32\GDI32.dll
ModLoad: 000007fc`24210000 000007fc`2428e000   C:\Windows\SYSTEM32\WINSPOOL.DRV
ModLoad: 000007fc`32420000 000007fc`324c1000   C:\Windows\system32\COMDLG32.dll
ModLoad: 000007fc`2f7d0000 000007fc`2f8af000   C:\Windows\system32\ADVAPI32.dll
ModLoad: 000007fc`2f8c0000 000007fc`30ba8000   C:\Windows\system32\SHELL32.dll
ModLoad: 000007fc`317d0000 000007fc`3194c000   C:\Windows\system32\ole32.dll
ModLoad: 000007fc`2f700000 000007fc`2f7c6000   C:\Windows\system32\OLEAUT32.dll
ModLoad: 000007fc`31070000 000007fc`31115000   C:\Windows\system32\msvcrt.dll
ModLoad: 000007fc`32160000 000007fc`321b0000   C:\Windows\system32\SHLWAPI.dll
ModLoad: 000007fc`32370000 000007fc`323b8000   C:\Windows\SYSTEM32\sechost.dll
ModLoad: 000007fc`30bb0000 000007fc`30ceb000   C:\Windows\system32\RPCRT4.dll
ModLoad: 000007fc`30eb0000 000007fc`3105a000   C:\Windows\SYSTEM32\combase.dll
ModLoad: 000007fc`2d090000 000007fc`2d127000   C:\Windows\SYSTEM32\SHCORE.DLL
ModLoad: 000007fc`2dd90000 000007fc`2de74000   C:\Windows\system32\uxtheme.dll
ModLoad: 000007fc`2ca10000 000007fc`2ca31000   C:\Windows\system32\dwmapi.dll
ModLoad: 000007fc`2f8b0000 000007fc`2f8b5000   C:\Windows\system32\normaliz.dll
ModLoad: 000007fc`2b050000 000007fc`2b172000   C:\Windows\system32\uiautomationcore.dll
ModLoad: 000007fc`22e70000 000007fc`22fd3000   C:\Windows\system32\dbghelp.dll
ModLoad: 000007fc`1d2e0000 000007fc`1d482000   C:\Windows\WinSxS\amd64_microsoft.windows.gdiplus_6595b64144ccf1df_1.1.9200.23246_none_5ba54dd0e5c75f0c\gdiplus.dll
ModLoad: 000007fc`2ac80000 000007fc`2ac87000   C:\Windows\system32\msimg32.dll
ModLoad: 000007fc`321b0000 000007fc`3233b000   C:\Windows\system32\urlmon.dll
ModLoad: 000007fc`31340000 000007fc`3160d000   C:\Windows\system32\iertutil.dll
ModLoad: 000007fc`31950000 000007fc`31dfc000   C:\Windows\system32\WININET.dll
ModLoad: 000007fc`2f570000 000007fc`2f58f000   C:\Windows\system32\USERENV.dll
ModLoad: 000007fc`2f110000 000007fc`2f125000   C:\Windows\system32\profapi.dll
ModLoad: 000007fc`2a630000 000007fc`2a639000   C:\Windows\system32\version.dll
ModLoad: 000007fc`2c270000 000007fc`2c3fa000   C:\Windows\system32\windowscodecs.dll
ModLoad: 000007fc`2eea0000 000007fc`2eeaa000   C:\Windows\SYSTEM32\CRYPTBASE.dll
ModLoad: 000007fc`2ee40000 000007fc`2ee9c000   C:\Windows\SYSTEM32\bcryptPrimitives.dll
(328.7c0): Break instruction exception - code 80000003 (first chance)
ntdll!DbgBreakPoint:
000007fc`324d1dd0 cc              int     3
0:005> ~*kb

   0  Id: 328.99c Suspend: 1 Teb: 000007f7`81f6e000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fc`31efab89 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!NtRequestWaitReplyPort+0xa
000007fc`31efa224 : 00000000`00000000 00000013`642b0000 00000090`dfa8e4b0 00000090`dfb65f70 : GDI32!PROXYPORT::SendRequest+0x191
000007fc`31ecc523 : 00000000`00000001 00000090`e0a3ce10 00000090`e04b4e20 00000000`00000000 : GDI32!PROXYPORT::LoadDriver+0x12c
000007fc`31efafab : 00000090`dfb65f70 00000000`00000000 00000090`dfa8e5d8 00000090`dfb67358 : GDI32!LoadUserModePrinterDriverEx+0x184
000007fc`31e884c8 : 00000090`dfb65f70 00000090`dfa8e5a0 00000090`dfa8e5d8 00000000`00000000 : GDI32!LoadUserModePrinterDriver+0x27
000007fc`31eb0451 : 000091e8`13265288 000007f7`83026676 00000090`e0940080 00000000`00000001 : GDI32!hdcCreateDCW+0x16b
000007fc`31eb048b : 00000000`00000002 00000090`dfa8ea30 00000090`dfa8ecd0 00000000`00000000 : GDI32!bCreateDCW+0x89
000007f7`82eca721 : 00000090`e045c3e0 00000090`e045c910 00000000`00000000 00000000`0000000a : GDI32!CreateDCW+0x13
000007f7`82ecd047 : 00000090`dfa8ecd0 00000090`e0452f80 00000090`e0453ff6 00000000`00000000 : SumatraPDF_3_2_64!PrintToDevice+0x1d1 [C:\Users\kjk\src\sumatrapdf\src\Print.cpp @ 161]
000007f7`82ef4a54 : 00000090`dfb66650 00000090`dfa8f1b0 00000090`dfb7ef30 00000000`1201028a : SumatraPDF_3_2_64!PrintFile+0x5a7 [C:\Users\kjk\src\sumatrapdf\src\Print.cpp @ 901]
(Inline Function) : --------`-------- --------`-------- --------`-------- --------`-------- : SumatraPDF_3_2_64!PrintFile+0xd0 [C:\Users\kjk\src\sumatrapdf\src\Print.cpp @ 927]
000007f7`83249a8a : 00000000`00000000 00000000`00000001 00000000`00000000 00000000`00000000 : SumatraPDF_3_2_64!WinMain+0x1324 [C:\Users\kjk\src\sumatrapdf\src\SumatraStartup.cpp @ 990]
(Inline Function) : --------`-------- --------`-------- --------`-------- --------`-------- : SumatraPDF_3_2_64!invoke_main+0x21 [d:\agent\_work\5\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 102]
000007fc`2f5c1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : SumatraPDF_3_2_64!__scrt_common_main_seh+0x106 [d:\agent\_work\5\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 288]
000007fc`3252bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d

   1  Id: 328.5dc Suspend: 1 Teb: 000007f7`81f6c000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fc`2f4710ea : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!NtWaitForSingleObject+0xa
000007f7`82ecedac : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`000000c4 : KERNELBASE!WaitForSingleObjectEx+0x92
000007fc`2f5c1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : SumatraPDF_3_2_64!RenderCache::RenderCacheThread+0xcc [C:\Users\kjk\src\sumatrapdf\src\RenderCache.cpp @ 604]
000007fc`3252bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d

   2  Id: 328.50 Suspend: 1 Teb: 000007f7`81f68000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fc`2f4710ea : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!NtWaitForSingleObject+0xa
000007f7`82ea8076 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000124 : KERNELBASE!WaitForSingleObjectEx+0x92
000007fc`2f5c1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : SumatraPDF_3_2_64!CrashDumpThread+0x16 [C:\Users\kjk\src\sumatrapdf\src\CrashHandler.cpp @ 304]
000007fc`3252bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d

   3  Id: 328.13d8 Suspend: 1 Teb: 000007f7`81f66000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fc`324d77a3 : 00000000`00000006 00000090`dfb62aa0 00000090`e0450880 00000000`00000000 : ntdll!NtWaitForWorkViaWorkerFactory+0xa
000007fc`2f5c1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!TppWorkerThread+0x275
000007fc`3252bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d

   4  Id: 328.12a4 Suspend: 1 Teb: 000007f7`81f64000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fc`2f4710ea : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!NtWaitForSingleObject+0xa
000007fc`24239681 : 000007fc`24210000 00000000`00000000 00000000`00000000 00000000`00000184 : KERNELBASE!WaitForSingleObjectEx+0x92
000007fc`2f5c1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : WINSPOOL!MonitorRPCServerProcess+0x19
000007fc`3252bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d

#  5  Id: 328.7c0 Suspend: 1 Teb: 000007f7`81e3e000 Unfrozen
RetAddr           : Args to Child                                                           : Call Site
000007fc`325780e0 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!DbgBreakPoint
000007fc`2f5c1652 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!DbgUiRemoteBreakin+0x34
000007fc`3252bed1 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1a
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d
0:005> lmf
start             end                 module name
000007f7`82dd0000 000007f7`83cdd000   SumatraPDF_3_2_64 C:\Windows\system32\config\systemprofile\AppData\Roaming\Inventio.IT\SMARTtransfer\Sumatra\v3.2\SumatraPDF-3.2-64.exe
000007fc`1d2e0000 000007fc`1d482000   gdiplus  C:\Windows\WinSxS\amd64_microsoft.windows.gdiplus_6595b64144ccf1df_1.1.9200.23246_none_5ba54dd0e5c75f0c\gdiplus.dll
000007fc`22e70000 000007fc`22fd3000   dbghelp  C:\Windows\system32\dbghelp.dll
000007fc`24210000 000007fc`2428e000   WINSPOOL C:\Windows\SYSTEM32\WINSPOOL.DRV
000007fc`2a630000 000007fc`2a639000   version  C:\Windows\system32\version.dll
000007fc`2ac80000 000007fc`2ac87000   msimg32  C:\Windows\system32\msimg32.dll
000007fc`2b050000 000007fc`2b172000   uiautomationcore C:\Windows\system32\uiautomationcore.dll
000007fc`2b270000 000007fc`2b61e000   d2d1     C:\Windows\SYSTEM32\d2d1.dll
000007fc`2c270000 000007fc`2c3fa000   windowscodecs C:\Windows\system32\windowscodecs.dll
000007fc`2c400000 000007fc`2c669000   COMCTL32 C:\Windows\WinSxS\amd64_microsoft.windows.common-controls_6595b64144ccf1df_6.0.9200.22792_none_2abfb4e38b3001db\COMCTL32.dll
000007fc`2ca10000 000007fc`2ca31000   dwmapi   C:\Windows\system32\dwmapi.dll
000007fc`2d090000 000007fc`2d127000   SHCORE   C:\Windows\SYSTEM32\SHCORE.DLL
000007fc`2dd90000 000007fc`2de74000   uxtheme  C:\Windows\system32\uxtheme.dll
000007fc`2ee40000 000007fc`2ee9c000   bcryptPrimitives C:\Windows\SYSTEM32\bcryptPrimitives.dll
000007fc`2eea0000 000007fc`2eeaa000   CRYPTBASE C:\Windows\SYSTEM32\CRYPTBASE.dll
000007fc`2f110000 000007fc`2f125000   profapi  C:\Windows\system32\profapi.dll
000007fc`2f470000 000007fc`2f564000   KERNELBASE C:\Windows\system32\KERNELBASE.dll
000007fc`2f570000 000007fc`2f58f000   USERENV  C:\Windows\system32\USERENV.dll
000007fc`2f5c0000 000007fc`2f6f7000   KERNEL32 C:\Windows\system32\KERNEL32.DLL
000007fc`2f700000 000007fc`2f7c6000   OLEAUT32 C:\Windows\system32\OLEAUT32.dll
000007fc`2f7d0000 000007fc`2f8af000   ADVAPI32 C:\Windows\system32\ADVAPI32.dll
000007fc`2f8b0000 000007fc`2f8b5000   normaliz C:\Windows\system32\normaliz.dll
000007fc`2f8c0000 000007fc`30ba8000   SHELL32  C:\Windows\system32\SHELL32.dll
000007fc`30bb0000 000007fc`30ceb000   RPCRT4   C:\Windows\system32\RPCRT4.dll
000007fc`30cf0000 000007fc`30e3c000   USER32   C:\Windows\system32\USER32.dll
000007fc`30eb0000 000007fc`3105a000   combase  C:\Windows\SYSTEM32\combase.dll
000007fc`31070000 000007fc`31115000   msvcrt   C:\Windows\system32\msvcrt.dll
000007fc`31340000 000007fc`3160d000   iertutil C:\Windows\system32\iertutil.dll
000007fc`317d0000 000007fc`3194c000   ole32    C:\Windows\system32\ole32.dll
000007fc`31950000 000007fc`31dfc000   WININET  C:\Windows\system32\WININET.dll
000007fc`31e60000 000007fc`31fa3000   GDI32    C:\Windows\system32\GDI32.dll
000007fc`32160000 000007fc`321b0000   SHLWAPI  C:\Windows\system32\SHLWAPI.dll
000007fc`321b0000 000007fc`3233b000   urlmon   C:\Windows\system32\urlmon.dll
000007fc`32370000 000007fc`323b8000   sechost  C:\Windows\SYSTEM32\sechost.dll
000007fc`32420000 000007fc`324c1000   COMDLG32 C:\Windows\system32\COMDLG32.dll
000007fc`324d0000 000007fc`3268e000   ntdll    C:\Windows\SYSTEM32\ntdll.dll

@GitHubRulesOK
Copy link
Collaborator

GitHubRulesOK commented Feb 8, 2021

Thanks for report but have to admit to me it looks like hieroglyphics so need @kjk to do analysis.
May help to confirm command line structure, and file handling workflow, but since other calls have previously worked it should not matter.
More important is causes of interference such as is Anti-virus scanning the files throughput e.g. inclusive of large spool file ? Was the invoked print, one that caused hang, a very large output, that might have exceeded some size limit or timeout ?
Working headless makes it difficult to suggest, where to look/see a difference but can the hang be repeated by frequently sending the same requested output?

@HenrikHolmIT
Copy link
Author

I do not know the size of the spool file. I did not know a spool file even existed?

There do not seem to be anything wrong with the file causing the hang. It's a file downloaded form server on request and are usually one/two page documents. Code checks if the file is still open before sending it to the printer. I've tried to open a failed document with SumatraPDF application to see if it would show an error but it opened the document without problem. When these hangs happen it keeps happening until server is restarted. As mentioned code will monitor the process and end the process if not exited after 60 seconds. The next process will also hang until server is restarted. The Windows Service will get them all again and queue them for printing and this time SumatraPDF.exe process return 0 after milliseconds of runtime.

I have yet to figure out how to push the server into a failed state. Sometimes it seems starts durring mass printing sessions and other times it seems to happen with a single print. But so far the only fix we have found has been to restart the server.

@kjk
Copy link
Member

kjk commented Feb 8, 2021

Thanks for providing debug information.

As you can see from:

ntdll!NtRequestWaitReplyPort+0xa
GDI32!PROXYPORT::SendRequest+0x191
GDI32!PROXYPORT::DocumentEvent+0x524
GDI32!DocumentEventEx+0xb5570
GDI32!hdcCreateDCW+0x1e5
GDI32!bCreateDCW+0x89
GDI32!CreateDCW+0x13
SumatraPDF_3_2_64!PrintToDevice+0x1d1 [C:\Users\kjk\src\sumatrapdf\src\Print.cpp @ 161]

the hang happens inside Windows code (in gdi32.CreateDC). Sumatra asks windows to create a Device Context (DC) for the printer and windows hangs. There's nothing I can do about it.

Further comments:

  • Sumatra is not really meant to be a printer for PDF files
  • printing from inside a service is not tested and not supported. There are restrictions on what's possible inside a service and Sumatra is not designed to be called from a service and therefore anything can happen

I agree that some sort of -logfile option would be good but this issue is about the printing problem so I'm closing it as there's nothing I can do about a hang that happens inside Windows code.

@kjk kjk closed this as completed Feb 8, 2021
@GitHubRulesOK
Copy link
Collaborator

@HenrikHolmIT
OK "knowing little about the deeper ramifications" I note this is possibly a common problem on network servers encountered by other 32bit printing software.
The only potential relative solution is to check if the server is 64bit and if SumatraPDF.exe is 32bit does switching to 64bit exe make any difference. But as pointed out SumatraPDF, as a lightweight personal PDF Viewer, is NOT designed to be a lean and mean vector based printing app.

@HenrikHolmIT
Copy link
Author

I appreciate you looking into this. Now that we have pinpointed that it is an error with Windows might you have any ideas as to a possibility to restart some specific part on this windows machine to make gdi32.CreateDC (or NtRequestWaitReplyPort) function respond again?
Its quite brutal to have to reboot the server each time it locks up.

Our next test at customer is to move the printing service to other hardware. It is currently running on Windows Server 2012 and we would like for the customer to try running the service on newer OS software. Hopefully they'll be able to setup a Windows 10 machine that we can test on soon.

About SumatraPDF not being ment for this kind of job I would just like to say that we looked into other solutions and so far SumatraPDF is the tool that has been most useful and that is the reason we chose to go with this tool.

@kjk
Copy link
Member

kjk commented Feb 9, 2021

@HenrikHolmIT This could be a Windows bug. I found one reference to a bug in Windows Server 2012: https://stackoverflow.com/a/57630317/2898

@HenrikHolmIT
Copy link
Author

Interesting case though it seems they have found a way they can reproduce by either having a KB installed or not. In this case it just seems to suddenly happen for no apparent reason.

Our Windows Service is set to build 'Any CPU' and we actively select the 64 bit version of Sumatra on OS running 64 bits. We'll have to try to move the service to other hardware. Or instruct customer to reboot the server if/when their print jobs start failing.

Thank you for all your help.

@GitHubRulesOK
Copy link
Collaborator

@HenrikHolmIT
Again without seeing your command line syntax, I do not know if it may help, but since 64bit does not make the difference the other historic alternative was to drop back to older version 3.0 32bit release unless you had compiled as 64bit, there are consequences as the code is much older.

  • Potential to experience unsupported bugs (e.g. possibility to crash/hang on files that might work in recent build)
  • some newer command line directives are not available e.g. forcing rotation
  • using version 3.0 print as vectors (watch out for the advanced setting =print as images) some users found the more efficient vector based output worked better for them, but there were many issues raised by some types of commercial hardware and thus their print drivers.

@HenrikHolmIT
Copy link
Author

HenrikHolmIT commented Feb 9, 2021

There is not much magic to our use of SumatraPDF. I first select which architecture to use and then launch it with parameters. As stated I've added a loop to detect a hang. Nothing wild.

`
if (Environment.Is64BitProcess)
{
sumatraPath = Path.Combine(path, "SumatraPDF-3.2-64.exe");

                if (!File.Exists(sumatraPath))
                {
                    if (!Directory.Exists(path))
                    {
                        Directory.CreateDirectory(path);
                    }

                    File.WriteAllBytes(sumatraPath, Properties.Resources.SumatraPDF_3_2_64);
                }
            }
            else
            {
                sumatraPath = Path.Combine(path, "SumatraPDF-3.2-32.exe");

                if (!File.Exists(sumatraPath))
                {
                    if (!Directory.Exists(path))
                    {
                        Directory.CreateDirectory(path);
                    }

                    File.WriteAllBytes(sumatraPath, Properties.Resources.SumatraPDF_3_2_32);
                }
            }

            ProcessStartInfo startInfo = new ProcessStartInfo
            {
                FileName = sumatraPath,
                Arguments = "-silent -print-to " + '"' + printerName + '"' + " " + '"' + filename + '"',
            };

            Process proc = Process.Start(startInfo);

            int maxLoops = 60;

            DateTime processStartedAt = DateTime.Now;
            DateTime lastLogged = DateTime.Now;

            logger.Info($"SumatraDebug: { Config.SumatraDebug }");

            while (true)
            {
                proc.WaitForExit(100);

                DateTime thisLoopDateTime = DateTime.Now;

                if (!proc.HasExited)
                {
                    if ((thisLoopDateTime - lastLogged).TotalSeconds > 2)
                    {
                        logger.Info($"Print process is still running: { Math.Truncate((thisLoopDateTime - processStartedAt).TotalSeconds) }s (waiting max { maxLoops }s)");
                        lastLogged = thisLoopDateTime;
                    }

                    if ((thisLoopDateTime - processStartedAt).TotalSeconds > maxLoops)
                    {
                        if (!Config.SumatraDebug)
                        {
                            proc.Kill();
                            throw new Exception("Print process did not exit on time and was killed");
                        }
                    }
                }
                else
                {
                    logger.Info("Print process has exited");
                    break;
                }
            }

`

@GitHubRulesOK
Copy link
Collaborator

I thought you said your using 64bit that looks like 3.2-32.exe ??
but as you point out it is not adding any specific directives such as tray or papersize so guess they are constant defaults, (beware newer windows 10 may muck those about)

@HenrikHolmIT
Copy link
Author

The codeblock is cutting off the top of the code block. As you can see from the debug insert it is in fact the 64 bit version that is launched

ModLoad: 000007f782dd0000 000007f783cdd000 C:\Windows\system32\config\systemprofile\AppData\Roaming\Inventio.IT\SMARTtransfer\Sumatra\v3.2\SumatraPDF-3.2-64.exe

if (Environment.Is64BitProcess)
{
sumatraPath = Path.Combine(path, "SumatraPDF-3.2-64.exe");

@GitHubRulesOK
Copy link
Collaborator

GitHubRulesOK commented Feb 9, 2021

OK forgot you said earlier it depends on architecture, I would still try 3.0 32bit

@HenrikHolmIT
Copy link
Author

We will most likely try to move the printing service to another machine first. I like to be on new hardware and software. If that machine experiences the same problem then maybe try that other version or maybe try to submit a support ticket at Microsoft.

@HenrikHolmIT
Copy link
Author

Was something changed on how printing is executed from version 3.0 forward?
I mean if 3.0 also prints by calling the same GDI32 function then I would be very confused if it would not begin to lock at some point.

@GitHubRulesOK
Copy link
Collaborator

Yes the biggest change to printing methods was changed after 3.0 after that the code was modified to ONLY allow print as image default settings for fresh 3.0 include

PrinterDefaults [
	PrintScale = shrink
	PrintAsImage = false

As it was compiled in older MS VC versions the underlying compilation may vary from more modern compilation, though if the faulty gdi primitive calls to the server are the root of the problem that part may not be different, but I having no idea, would simply try to see if there is a difference

@GitHubRulesOK
Copy link
Collaborator

P.S the issue is graphics device related and thus some solutions mentioned checking graphics driver updates, however working headless your graphics are possibly not showing (stable or not)
Thus I am wondering if a user was running a print their graphics would be active (not in a screensaver state) so is there a screen related timeout issue here such as triggered by power saving settings ?

@HenrikHolmIT
Copy link
Author

They have another piece of software running on the server that needs a logged in user so there is a desktop session. We use that session to monitor logs from the service and test different things. Service is running local system account.

@GitHubRulesOK
Copy link
Collaborator

Possibly another red herring (if it works sometimes, why not every time ?)

I emulated running with and without -silent, printing a small file to a virtual printer and requested the output file size, expecting it to differ with silent or be a constant without silent, to my surprise in neither case was it constant (feedback was generally variable).
Only by adding a few seconds delay in the loop for that small file could I see a constant result.
I perhaps should have realised that SumatraPDF is available for another invocation before the previous driver output is fully processed, The implication is that a second print request can be initiated before the printer is readied for the second stream of data. Thus although SumatraPDF correctly completes its printing and hands back control to the system with errorlevel 0, There is, without any enforced delay, the chance that SumatraPDF may be blocked / error when starting another run if the printer had not finished printing.
I need to check with much larger variable files and silent OFF if that can be the root cause. I would hope to see some visual clue / error message at some time.

@GitHubRulesOK
Copy link
Collaborator

GitHubRulesOK commented Feb 9, 2021

Well that was both inconclusive and as entertaining as watching paint dry.

Using variable files both with and without silent in both cases I got similar, but not identical results.
It was not a good emulation as I am running to a GhostScript printer from user command line, not as a service, but it raised some queries.
So file size of output does not reflect final size until the print spooler has completed its task perhaps 5 seconds later as such a delay seemed to provide a correct value.

In general SumatraPDF does not exit until it has somehow confirmed print was completed (handed over to system) then eventually exits with error level 0, However the length of time that takes on my machine can be less than 1 minute for a couple of pages, but nearer 10 minutes for a larger 500 page report (Fast for a printer at roughly 50ppm) so first time with a large file I thought it may have hung, but it eventually completed building a 1.3GB output (Unsure how a physical printer might baulk at such a long stream but any glitch would take some time to perhaps declare as a failure)

Using version 3.0 for comparison the small PDF files actually produced larger output from 3.0 so that would not be a help However for the 500 page report it ran faster in about 8 minutes but producing an output file about half the size (roughly 540 MB) so more efficient at roughly 60 ppm.

I am happy to accept that process times are generally measured in minutes when printing but see your scripting is phrased in seconds. are you sure you are not killing a hanging man prematurely ?

@HenrikHolmIT
Copy link
Author

Are you sure you are not killing a hanging man prematurely? Yes.

When this bug first appeared I did not monitor the process. I just started the process with Process.Start(startInfo).WaitForExit(); That worked fine inhouse. When service was installed at customer I was alerted of a strange behavior where print jobs would just stop processing for no reason. Customer was trying to restart the service but that failed because service executable would never exit because the PrintQueue thread was blocked because SumatraPDF.exe would never exit. That was when I made the 1 minute monitoring loop. When the hang occurs and the server is rebooted prints are executed in mere seconds on following attempts. So it seems that then the bug sets in there is no getting out of it. When the bug is active the process will wait forever until forcefully killed.

Service receives a wakeup call from backend when printjobs a waiting to be sent to printer. Service will then start downloading documents one by one and sending them to the printer. So the sequence is this

  • GetJob (if null then wait for another wakeup)
  • Download Document
  • Print Document
  • Wait for Sumatra to exit
  • GoTo GetJob

This is the current 'gameloop' and if 20 printjobs are queued it will download them one at a time. If files are small and printing goes fast it will process those prints pretty quickly with the current gameloop. I may just want to put in a 5 second wait time between printjobs to maybe make the system ease off on the printer a little and see if that makes a difference.

Also I dont know if our service is the only entity printing on this printer so it may just be swamped at times.

Thank you for investigating further.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants