Hang on printer close

[Timur Safin]

Hi All,

I didn't attend these groups for a some period of time so I might be wrong in
selecting the proper forum, so please bear with me.

Recently I got some strange problem in my queue - some our customer in Brazil
complains that sporadically they get process stucking in the command closing
the (remote) printer. According to their descriptio they have Frame-Relay
connection to other uilding where this printer is installed. Sometimes this
other building get power outtage and conincidentally these times produce such
close printer hangs.

Here is excerpt of some relevant lines:

if (pddb->subtype & SDTPRINT) { /* LFT363+ */
EndPagePrinter((HANDLE)pddb->lun);
EndDocPrinter((HANDLE)pddb->lun);
ClosePrinter((HANDLE)pddb->lun);
...
I thoiught the hang could be avoided if I'd add further return values
checkings, but apparently it is not that case. The hang is directly in the 1st
most call to EndPagePrinter. Here is the stack-trace of userdump which
customer was able to capture at the moment of hang.

0:000> !analyze -v
*******************************************************************************
*
*
* Exception Analysis
*
*
*
*******************************************************************************


FAULTING_IP:
SharedUserData+304
7ffe0304 c3 ret

EXCEPTION_RECORD: ffffffff -- (.exr ffffffffffffffff)
..exr ffffffffffffffff
ExceptionAddress: 7ffe0304 (SharedUserData+0x00000304)
ExceptionCode: 80000003 (Break instruction exception)
ExceptionFlags: 00000000
NumberParameters: 0

FAULTING_THREAD: 00000908

BUGCHECK_STR: 80000003

DEFAULT_BUCKET_ID: APPLICATION_FAULT

PROCESS_NAME: cache.exe

ERROR_CODE: (NTSTATUS) 0x80000003 - {EXCEPTION} Breakpoint A breakpoint has
been reached.

THREAD_ATTRIBUTES:
LAST_CONTROL_TRANSFER: from 77f4318f to 7ffe0304

STACK_TEXT:
0012f948 77f4318f 77c5add8 00000388 00148750 SharedUserData+0x304
0012f94c 77c5add8 00000388 00148750 00148750 ntdll!ZwRequestWaitReplyPort+0xc
0012f998 77c587af 0012f9cc 77c587f5 0012f9cc
RPCRT4!LRPC_CCALL::SendReceive+0x22d
0012f9a0 77c587f5 0012f9cc 730770f8 0012fd98 RPCRT4!I_RpcSendReceive+0x20
0012f9b0 77ce65be 0012f9f8 00155338 00000000 RPCRT4!NdrSendReceive+0x28
0012fd80 7307c4df 730770f8 730781b0 0012fd98 RPCRT4!NdrClientCall2+0x1e4
0012fd90 7307a360 0014a2d0 01070000 00009bf3 WINSPOOL!RpcWritePrinter+0x14
0012fdd8 730759c4 001446cc 00000000 00000000 WINSPOOL!FlushBuffer+0x7f
0012fe14 006543aa 001446cc 00000026 004e2307 WINSPOOL!EndPagePrinter+0x30
00000000 00000000 00000000 00000000 00000000 cache!sqclose+0x26e


FOLLOWUP_IP:
WINSPOOL!RpcWritePrinter+14
7307c4df 83c40c add esp,0xc

SYMBOL_STACK_INDEX: 6

FOLLOWUP_NAME: MachineOwner

SYMBOL_NAME: WINSPOOL!RpcWritePrinter+14

MODULE_NAME: WINSPOOL

IMAGE_NAME: WINSPOOL.DRV

DEBUG_FLR_IMAGE_TIMESTAMP: 3e8024b5

STACK_COMMAND: ~0s ; kb

BUCKET_ID: 80000003_WINSPOOL!RpcWritePrinter+14

Followup: MachineOwner
---------

....

Here is this call sequence:

1. Our code calls EndPagePrinter:

..B19.48: ; Preds .B19.47

;;; {
;;; if (pddb->subtype & SDTPRINT) { /* LFT363+ */

04ef4 0f b7 8b a0 01
00 00 movzx ecx, WORD PTR [ebx+416]
;c:/v/v5-0/build829/common/src/sqio.c:4826.12
04efb f6 c1 08 test cl, 8
;c:/v/v5-0/build829/common/src/sqio.c:4826.12
04efe 74 1e je .B19.52 ; Prob 60%
;c:/v/v5-0/build829/common/src/sqio.c:4826.8
; LOE edx ebx

006543a4 52 push edx
006543a5 e892950600 call cache!EndPagePrinter (006bd93c)
..B19.49: ; Preds .B19.48

;;; EndPagePrinter((HANDLE)pddb->lun);

04f00 52 push edx
;c:/v/v5-0/build829/common/src/sqio.c:4827.27
04f01 e8 fc ff ff ff call _EndPagePrinter@4
;c:/v/v5-0/build829/common/src/sqio.c:4827.27
; LOE ebx

006543aa ffb398010000 push dword ptr [ebx+0x198]

2. It does some anti-exception house-keepings and call FlushBuffer (?):

WINSPOOL!EndPagePrinter:
73075994 6a10 push 0x10
73075996 68589c0773 push 0x73079c58
7307599b e860b9ffff call WINSPOOL!_SEH_prolog (73071300)
730759a0 33ff xor edi,edi
730759a2 47 inc edi
730759a3 897de4 mov [ebp-0x1c],edi
730759a6 33f6 xor esi,esi
730759a8 56 push esi
730759a9 8b5d08 mov ebx,[ebp+0x8]
730759ac 53 push ebx
730759ad e8aebfffff call WINSPOOL!eProtectHandle (73071960)
730759b2 85c0 test eax,eax
730759b4 0f85884a0000 jne WINSPOOL!EndPagePrinter+0x22 (7307a442)
730759ba 8975fc mov [ebp-0x4],esi
730759bd 56 push esi
730759be 53 push ebx
730759bf e825c0ffff call WINSPOOL!FlushBuffer (730719e9)

730759c4 837b08ff cmp dword ptr [ebx+0x8],0xffffffff

730759c8 751c jnz WINSPOOL!EndPagePrinter+0x96 (730759e6)
730759ca 897dfc mov [ebp-0x4],edi
730759cd ff7304 push dword ptr [ebx+0x4]
730759d0 e82d000000 call WINSPOOL!RpcEndPagePrinter (73075a02)
730759d5 8945e4 mov [ebp-0x1c],eax
730759d8 3bc6 cmp eax,esi
730759da 0f85694a0000 jne WINSPOOL!EndPagePrinter+0x48 (7307a449)
730759e0 897de4 mov [ebp-0x1c],edi
730759e3 8975fc mov [ebp-0x4],esi
730759e6 834dfcff or dword ptr [ebp-0x4],0xffffffff
730759ea ff7508 push dword ptr [ebp+0x8]
730759ed e85ec0ffff call WINSPOOL!vUnprotectHandle (73071a50)
730759f2 8b45e4 mov eax,[ebp-0x1c]
730759f5 e856b9ffff call WINSPOOL!_SEH_epilog (73071350)
730759fa c20400 ret 0x4

3. FlushBuffer calls RpcWritePrinter, and so on.

So apparently at the moment Frame-Relay lost connection to other side this
WINSPOOL!EndPagePrinter has never been interrupted, and got stuck. And the
question is - how to intercept these kind of errors earlier, to prevent such
dangerous EndPagePrinter call? Or may be there is some Frame-Relay setting
which might be of some help here? (I never worked with Frame-Relay and don't
know where to see).


--
Thanks,
Timur Safin
Support Programmer
InterSystems Russia
mailto:[email protected]
http://www.intersystems.ru
-- Cache - The Postrelational Database --
55œ 46' 13" N 37œ 35' 20" E