Ticket #245: SHLNotes.txt

Massimo zombie
2011-05-26 SHL
2011-06-02 SHL

Running:

I:\sla_dev2\stunnel\stunnel-4.34\0-zips\0\stunnel.exe
 1-14-11  20:09         775,694      0  stunnel.exe

a73b0119d7ae0e094e57412bbe330f72 *stunnel.exe

IBM OS/2 Dump Formatter for a retail or an hstrict SMP kernel.
Formatter is --> Internal revision 14.105_SMP
Dump file is --> Internal revision 14.104a_SMP (process dump)

Symbol (d:\devtools\pmdf\14_104a_smp_massimo\os2krnlr.sym) linked

# .p
 Slot  Pid  Ppid Csid Ord  Sta Pri  pTSD     pPTDA    pTCB     Disp SG Name
*0179# 5f39 0010 5f39 0001 crt 0200 f9178000 fe625c38 f9735afc 0f1c 26 STUNNEL
 019d  5f39 0010 5f39 0002 blk 0200 f919c000 fe625c38 f973c78c 0ebc 26 STUNNEL

# .pu
 Slot  Pid  Ord  pPTDA    Name     pstkframe  CS:EIP        SS:ESP     cbargs
*0179# 5f39 0001 fe625c38 STUNNEL  %f9178f48 005b:1f05921e 0053:002afd58 0000
 019d  5f39 0002 fe625c38 STUNNEL  %f919cf40 005b:1f057f55 0053:0270fb3c 0000

# .pb
 Slot  Sta BlockID  Name     Type        Addr        Symbol
 019d  blk fd43b904 STUNNEL  Sem32     0001 0050  Event

#            Checking call gates for all slots
Slot STUNNEL    179:
*** Not in a call ***
Slot STUNNEL    19d:
 is in a call to:
%1ffc08e8 DOSCALL1 DOS32WAITEVENTSEM

# .s (ord 1)
Current slot number: 0179

eax=00000000 ebx=006ceff8 ecx=00000db1 edx=006b0078 esi=006cf000 edi=006d4040
eip=1f05921e esp=002afd58 ebp=002afda8 iopl=0 rf -- -- nv up ei pl nz na po nc
cs=005b ss=0053 ds=0053 es=0053 fs=150b gs=0000 cr2=00000000 cr3=00000000 p=**
005b:1f05921e f3ab           repe stosd                    es:006d4040=00000000

# ln
%1f059210 LIBC063 _std_bzero + e

# k
005b:1f05a846 006b0000 00008704 00000010 00000002 [LIBC063 _um_alloc_no_lock + 86]
005b:1f05c9f3 006b0000 00008704 00000010 00000002 [LIBC063 _ucalloc + 9f]
005b:1f09b6e7 006b0000 00000001 00008704 1bc00050 [LIBC063 _std_calloc + 27]
005b:00013696 00000001 00008704 002afe58 1f09d0e5 [STUNNEL alloc_client_session + 1a]
005b:0002071c 006cb9e0 0000000c 0000000c 0000000c [STUNNEL main_execute + 188]
005b:00020bc4 00000002 0001ff70 002aff68 00000001 [STUNNEL main + c8]
005b:00010021 00000002 002aff7c 20030180 ffffffff [STUNNEL _text + 21]
005b:1f07854b 00000000 1ffece38 00001a2f 00000000 [LIBC063 __init_app + b]

# u _um_alloc_no_lock + 86-5 l1
%1f05a841 e85b010000         call      %1f05a9a1

# ln %1f05a9a1
%1f05a874 LIBC063 _um_lump_alloc + 12d (_um_lump_alloc_noexpand?)

# dd esp
                        eip
0053:002afd58  00008704 1f05abcc 006cf000 00008704
0053:002afd68  006b0078 006b0078 20035320 0000000c
0053:002afd78  002afd98 00008720 006ceff8 0000000f
0053:002afd88  00008720 006b0150 006cf000 00008720
0053:002afd98  0000000a 00008704 006b0000 00000002
                        eip      h        size
0053:002afda8  002afdd8 1f05a846 006b0000 00008704
               round    flags
0053:002afdb8  00000010 00000002 20035320 0000000c
0053:002afdc8  00000002 006b0000 006b013c 00008704

# ln %1f05abcc
%1f05a874 LIBC063 _um_lump_alloc + 358 (_um_lump_alloc_noexpand?)

# u _um_lump_alloc + 358-5
%1f05abc7 e844e6ffff         call      %1f059210 ; _std_bzero

# ln %1f059210
%1f059210 LIBC063 _std_bzero

# ln %1f05a846
%1f05a7c0 LIBC063 _um_alloc_no_lock + 86

# u %1f05a846-5 l1
%1f05a841 e85b010000         call      %1f05a9a1

# ln %1f05a9a1
%1f05a874 LIBC063 _um_lump_alloc + 12d (_um_lump_alloc_noexpand?)

# u _um_alloc_no_lock _um_alloc_no_lock + 86 ( code does not seem to match source )
LIBC063 _um_alloc_no_lock:
%1f05a7c0 55                 push      ebp
%1f05a7c1 89e5               mov       ebp,esp
%1f05a7c3 57                 push      edi
%1f05a7c4 56                 push      esi
%1f05a7c5 53                 push      ebx
%1f05a7c6 83ec0c             sub       esp,+0c
%1f05a7c9 8b7508             mov       esi,dword ptr [ebp+08]
%1f05a7cc 8b5d0c             mov       ebx,dword ptr [ebp+0c]
%1f05a7cf 8b7d14             mov       edi,dword ptr [ebp+14]
%1f05a7d2 8b86e8000000       mov       eax,dword ptr [esi+000000e8]
                             ; if...
%1f05a7d8 85c0               test      eax,eax
%1f05a7da 7e4e               jle       %1f05a82a

%1f05a7dc c1e004             shl       eax,04
%1f05a7df 3b9c06dc000000     cmp       ebx,dword ptr [esi+eax+000000dc]
%1f05a7e6 7742               ja        %1f05a82a

%1f05a7e8 31d2               xor       edx,edx
                             ; while...
%1f05a7ea 3b9eec000000       cmp       ebx,dword ptr [esi+000000ec]
%1f05a7f0 760e               jbe       %1f05a800
%1f05a7f2 8d86ec000000       lea       eax,[esi+000000ec]
%1f05a7f8 83c010             add       eax,+10
%1f05a7fb 42                 inc       edx
%1f05a7fc 3b18               cmp       ebx,dword ptr [eax]
%1f05a7fe 77f8               ja        %1f05a7f8

%1f05a800 83ec0c             sub       esp,+0c
%1f05a803 8b4d10             mov       ecx,dword ptr [ebp+10]
%1f05a806 c1e204             shl       edx,04
%1f05a809 57                 push      edi
%1f05a80a 51                 push      ecx
%1f05a80b 8d8c32ec000000     lea       ecx,[edx+esi+000000ec]
%1f05a812 53                 push      ebx
%1f05a813 51                 push      ecx
%1f05a814 56                 push      esi
%1f05a815 e8ab040000         call      %1f05acc5 ; _um_lump_alloc + 451 (_um_crateset_alloc)
%1f05a81a 83c420             add       esp,+20          ;' '
%1f05a81d 85c0               test      eax,eax
%1f05a81f 7409               jz        %1f05a82a
%1f05a821 90                 nop

                             ; exit
%1f05a822 8d65f4             lea       esp,[ebp-0c]
%1f05a825 5b                 pop       ebx
%1f05a826 5e                 pop       esi
%1f05a827 5f                 pop       edi
%1f05a828 5d                 pop       ebp
%1f05a829 c3                 retd

%1f05a82a 8d4b2b             lea       ecx,[ebx+2b]
%1f05a82d 31d2               xor       edx,edx
%1f05a82f 83e1e0             and       ecx,-20
%1f05a832 39d9               cmp       ecx,ebx
%1f05a834 7304               jnc       %1f05a83a

%1f05a836 89d0               mov       eax,edx
%1f05a838 ebe8               jmp       %1f05a822

%1f05a83a 8b4510             mov       eax,dword ptr [ebp+10]
%1f05a83d 57                 push      edi
%1f05a83e 50                 push      eax
%1f05a83f 53                 push      ebx
%1f05a840 56                 push      esi
%1f05a841 e85b010000         call      %1f05a9a1        ; _um_lump_alloc + 12d (_um_lump_alloc_noexpand?)
%1f05a846 83c410             add       esp,+10
%1f05a849 89c2               mov       edx,eax
%1f05a84b 85c0               test      eax,eax
%1f05a84d 75e7               jnz       %1f05a836
%1f05a84f 52                 push      edx
%1f05a850 52                 push      edx
%1f05a851 53                 push      ebx
%1f05a852 56                 push      esi
%1f05a853 e811040000         call      %1f05ac69        ; _um_lump_alloc + 3f5 (_um_crateset_alloc?)
%1f05a858 83c410             add       esp,+10
%1f05a85b 31d2               xor       edx,edx
%1f05a85d 85c0               test      eax,eax
%1f05a85f 74d5               jz        %1f05a836
%1f05a861 8b5510             mov       edx,dword ptr [ebp+10]
%1f05a864 57                 push      edi
%1f05a865 52                 push      edx
%1f05a866 53                 push      ebx
%1f05a867 56                 push      esi
%1f05a868 e834010000         call      %1f05a9a1        ; _um_lump_alloc + 12d (_um_lump_alloc_noexpand?)
%1f05a86d 83c410             add       esp,+10
%1f05a870 89c2               mov       edx,eax
%1f05a872 ebc2               jmp       %1f05a836

LIBC063 _um_lump_alloc:
%1f05a874 55                 push      ebp
%1f05a875 89e5               mov       ebp,esp

# ln %1f05a9a1
%1f05a874 LIBC063 _um_lump_alloc + 12d

# ln %1f05acc5
%1f05a874 LIBC063 _um_lump_alloc + 451

# ln %1f05ac69
%1f05a874 LIBC063 _um_lump_alloc + 3f5

# ln %1f05acc5
%1f05a874 LIBC063 _um_lump_alloc + 451 (_um_crateset_alloc)

_um_alloc_no_lock ->
  _um_lump_alloc_noexpand->
    _std_bzero

Looks OK, but can't run because ORD2 in critical section

-------------------------------------------------------------------------

# .s19d
Current slot number: 019d (ord 2)

# r
eax=00000000 ebx=006b013c ecx=00010050 edx=00000bb8 esi=00000001 edi=0270fb4c
eip=1f057f55 esp=0270fb3c ebp=0270fb64 iopl=0 -- -- -- nv up ei pl nz na pe nc
cs=005b ss=0053 ds=0053 es=0053 fs=150b gs=0000 cr2=00000000 cr3=00000000 p=**
005b:1f057f55 83c410         add       esp,+10

# ln
%1f057e14 LIBC063 __fmutex_request_internal + 141

# k
005b:1f05a758 006b013c 00000001 00000002 00000000 [LIBC063 _umalloc + 134]
005b:1f05a675 006b013c 00000001 006b0000 006b0000 [LIBC063 _umalloc + 51]
005b:1f060394 006b0000 00000064 000521d0 000521d0 [LIBC063 _std_malloc + 24]
005b:000521e4 00000064 0000001e 00115fcb 00000148 [STUNNEL TLSv1_server_method + a7]
005b:0005270d 00000064 00082f03 000000ce 00000000 [STUNNEL CRYPTO_malloc + 82]
005b:0008317d 00000064 00082f03 000000ce 00000000 [STUNNEL EVP_DigestInit_ex + 209]
005b:000b67d5 0270fca4 000843d0 00000000 00000101 [STUNNEL RAND_SSLeay + 2ae]
005b:000596cb 0270fd64 00000004 00000000 00000000 [STUNNEL RAND_add + 4d]
005b:00035b57 0270fd64 00000004 00000000 00000000 [STUNNEL ssl23_accept + 48]
005b:00022c6d 00715540 00000000 00000000 00000000 [STUNNEL SSL_accept + 2c]
005b:0001159e 00715540 0000012c 00000000 00000000
005b:00012c5a 006fc0e0 00011928 006c9aa8 006fc0e4
005b:00013616 006fc0e0 00013597 006c9aa8 20034800 [STUNNEL client + 6a]
005b:1f0899f3 006fc0e0 00000000 00000000 00000000 [LIBC063 _endthread + 7f]
005b:1ffece38 20034800 00000000 00000000 00000000

# u _umalloc + 134-5 l1
%1f05a753 e8bcd6ffff         call      %1f057e14

# ln %1f057e14
%1f057e14 LIBC063 __fmutex_request_internal

--------------------------------------------------------------------------------

# .pb
 Slot  Sta BlockID  Name     Type        Addr        Symbol
 019d  blk fd43b904 STUNNEL  Sem32     0001 0050  Event

# .d sem32 %fd43b904

 00        00
-----   -------- --------
SP-FF   00050020
   IN   00050020
   SP   00050020

RE-FF   00050020
   IN   00050020
   SP   00050020

FT-FF   00050020
   IN   00050020
   SP   00050020

UP-FF   00050020
   IN   00050020
   SP   00050020

VP-FF   00050020
   IN   00050020
   SP   00050020

GT-FF   00050020
   IN   00050020
   SP   00050020

ST-FF   00050020
   IN   00050020
   SP   00050020

        Type: Private Event
       Flags: Reset
       pMuxQ: 00000000
  Post Count: 0000
  Open Count: 0002
 Create Addr: 0010fd43
 Caller Addr: 0010ffc2

# dw %fd43b904
%fd43b904  0010 0000 0000 0000 0002 fd43 0010 ffc2
%fd43b914  0010 0000 0000 0000 0001 fd43 0010 ffc2

... .d sem32 looks broken - try another way

# .pu
 Slot  Pid  Ord  pPTDA    Name     pstkframe  CS:EIP        SS:ESP     cbargs
*0179# 5f39 0001 fe625c38 STUNNEL  %f9178f48 005b:1f05921e 0053:002afd58 0000
 019d  5f39 0002 fe625c38 STUNNEL  %f919cf40 005b:1f057f55 0053:0270fb3c 0000

# ln  %1f057f55
%1f057e14 LIBC063 __fmutex_request_internal + 141

# u %1f057f55-5 l1
%1f057f50 e89389f600         call      %1ffc08e8 ; DOS32WAITEVENTSEM

# ln %1ffc08e8
%1ffc08e8 DOSCALL1 DOS32WAITEVENTSEM

# u %1f057f36 1f057f55
%1f057f36 50                 push      eax
%1f057f37 50                 push      eax
%1f057f38 f6430501           test      byte ptr [ebx+05],01
%1f057f3c 0f94c2             sete      dl
%1f057f3f 81e2ff000000       and       edx,000000ff
%1f057f45 4a                 dec       edx
%1f057f46 81cab80b0000       or        edx,00000bb8 ; 3000
%1f057f4c 52                 push      edx
%1f057f4d 8b0b               mov       ecx,dword ptr [ebx]
%1f057f4f 51                 push      ecx
%1f057f50 e89389f600         call      %1ffc08e8 ; DOS32WAITEVENTSEM
%1f057f55 83c410             add       esp,+10

# r
                              hsem         timeout
eax=00000000 ebx=006b013c ecx=00010050 edx=00000bb8 esi=00000001 edi=0270fb4c
eip=1f057f55 esp=0270fb3c ebp=0270fb64 iopl=0 -- -- -- nv up ei pl nz na pe nc
cs=005b ss=0053 ds=0053 es=0053 fs=150b gs=0000 cr2=00000000 cr3=00000000 p=**
005b:1f057f55 83c410         add       esp,+10

# dd ebx
                            flfs pid tid
0053:006b013c  00010050 6d660003 5f390001 1f059c40

03 = _FMS_OWNED_HARD

# da 1f059c40
0053:1f059c40 LIBC Heap

# dd esp       hsem     timeout
0053:0270fb3c  00010050 00000bb8 00000000 00000000

Probably deadlock
Possible that ORD2 neglected to exit critical section
Possible that _FMC_MUST_COMPLETE sem held

02 = _FMC_MUST_COMPLETE

Try to find locked _FMC_MUST_COMPLETE sem

Find gmtxWait

LIBC063 __libc_back_processWaitNotifyExec:
%1f07bbf4 55                 push      ebp
%1f07bbf5 89e5               mov       ebp,esp
%1f07bbf7 56                 push      esi
%1f07bbf8 53                 push      ebx
%1f07bbf9 8b15a0ca7e18       mov       edx,dword ptr [187ecaa0] ; gpChildrenFree
%1f07bbff 8b7508             mov       esi,dword ptr [ebp+08] ; pid
%1f07bc02 85d2               test      edx,edx
%1f07bc04 0f85ae000000       jnz       %1f07bcb8

%1f07bcb8 50                 push      eax
%1f07bcb9 50                 push      eax
%1f07bcba 6a00               push      +00
%1f07bcbc 6830ba7e18         push      187eba30
%1f07bcc1 e80e060000         call      %1f07c2d4 ; _fmutex_request?
%1f07bcc6 83c410             add       esp,+10
%1f07bcc9 85c0               test      eax,eax

# dd %187eba30
%187eba30  0001004d 6d660201 00000000 1f07b6f0

# da %1f07b6f0
%1f07b6f0 b_processWait.c: gmtxWait

Check gmtx

# dd gmtx
%187d88c0  00010008 6d660201 00000000 1f05b100

# da 1f05b100
%1f05b100 LIBC SYS Filehandle Mutex

Find g_mtxFSInfoVolumes

# u __libc_back_fsInfoObjByDev

LIBC063 __libc_back_fsInfoObjByDev:
%1f1381a9 55                 push      ebp
%1f1381aa 89e5               mov       ebp,esp
%1f1381ac 57                 push      edi
%1f1381ad 56                 push      esi
%1f1381ae 31f6               xor       esi,esi
%1f1381b0 53                 push      ebx
%1f1381b1 83ec0c             sub       esp,+0c
%1f1381b4 8b5d08             mov       ebx,dword ptr [ebp+08]
%1f1381b7 0fb6cf             movzx     ecx,bh
%1f1381ba 83f956             cmp       ecx,+56          ;'V'
%1f1381bd 740b               jz        %1f1381ca

%1f1381ca 80fb40             cmp       bl,40            ;'@'
%1f1381cd 7ef0               jle       %1f1381bf
%1f1381cf 80fb5a             cmp       bl,5a            ;'Z'
%1f1381d2 7feb               jg        %1f1381bf

%1f1381d4 0fbefb             movsx     edi,bl
%1f1381d7 c1e705             shl       edi,05
%1f1381da 50                 push      eax
%1f1381db 50                 push      eax
%1f1381dc 6a00               push      +00
%1f1381de 8db7e8c18118       lea       esi,[edi+1881c1e8]
%1f1381e4 68a0737d18         push      187d73a0
%1f1381e9 e867060000         call      %1f138855
%1f1381ee 83c410             add       esp,+10

# dd %187d73a0
%187d73a0  00010053 42420201 00000000 1f13658f

# da %1f13658f
%1f13658f mtxFSInfoVolumes

Hmmm...