Examining DRIVER_POWER_STATE_FAILURE (9f) BSOD

My work computer recently hanged when shutting down to sleep mode.

When booting the computer the next day I realized that it had eventually crashed.

This happened again after disabling hyper-threading, so I decided to investigate.

 

Checked Event Viewer and found:

Log Name: System
Source: Microsoft-Windows-WER-SystemErrorReporting
Event ID: 1001
Task Category: None
Level: Error
Keywords: Classic
Description:
The computer has rebooted from a bugcheck. The bugcheck was: 0x0000009f (0x0000000000000003, 0xfffffa800cd5e060, 0xfffff80000b9a3d8, 0xfffffa802e232590). A dump was saved in: C:\Windows\MEMORY.DMP.

 

Searched online for BSOD 0x0000009f and found:

https://docs.microsoft.com/en-us/windows-hardware/drivers/debugger/bug-check-0x9f–driver-power-state-failure

 

Examined the memory dump with WinDbg (x64).

Checked for details about the crash with:

!analyze -v

Part of the result:

DRIVER_POWER_STATE_FAILURE (9f)
A driver has failed to complete a power IRP within a specific time.
Arguments:
Arg1: 0000000000000003, A device object has been blocking an Irp for too long a time
Arg2: fffffa800cd5e060, Physical Device Object of the stack
Arg3: fffff80000b9a3d8, nt!TRIAGE_9F_POWER on Win7 and higher, otherwise the Functional Device Object of the stack
Arg4: fffffa802e232590, The blocked IRP

FAILURE_BUCKET_ID: X64_0x9F_3_POWER_DOWN_Rt64win7_IMAGE_pci.sys

BUCKET_ID: X64_0x9F_3_POWER_DOWN_Rt64win7_IMAGE_pci.sys

FAILURE_ID_HASH_STRING: km:x64_0x9f_3_power_down_rt64win7_image_pci.sys

 

Checked for information about the I/O request packet with:

!irp fffffa802e232590

Result:

Irp is active with 5 stacks 4 is current (= 0xfffffa802e232738)
No Mdl: No System Buffer: Thread 00000000: Irp stack trace.
cmd flg cl Device File Completion-Context
[ 0, 0] 0 0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[ 0, 0] 0 0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
[ 0, 0] 0 0 00000000 00000000 00000000-00000000

Args: 00000000 00000000 00000000 00000000
>[ 16, 2] 0 e1 fffffa800da84050 00000000 fffff800032ca230-fffffa800eb3bb50 Success Error Cancel pending
*** ERROR: Module load completed but symbols could not be loaded for Rt64win7.sys
\Driver\RTL8167 nt!PopSystemIrpCompletion
Args: 00015400 00000000 00000005 00000003
[ 0, 0] 0 0 00000000 00000000 00000000-fffffa800eb3bb50

Args: 00000000 00000000 00000000 00000000

 

Examined available information about Rt64win7 with:

lmvm Rt64win7

Result:

start end module name
fffff880`05c3a000 fffff880`05d39000 Rt64win7 (no symbols)
Loaded symbol image file: Rt64win7.sys
Image path: \SystemRoot\system32\DRIVERS\Rt64win7.sys
Image name: Rt64win7.sys
Timestamp: Fri Oct 07 11:27:12 2016 (57F76A70)
CheckSum: 0010CDA5
ImageSize: 000FF000
Translations: 0000.04b0 0000.04e4 0409.04b0 0409.04e4

 

Found the driver file in Windows explorer under:

C:\Windows\system32\DRIVERS\Rt64win7.sys

Then checked Properties. The details view confirmed that the driver was for the Realtek network interface card, version: 7.103.1007.2016.

 

Decided to look for a newer driver from Realtek.

Found, downloaded and installed the current latest version 7.109.

Unfortunately this was not the solution, the problems continued.

However, later on I discovered that adjusting power options seemed effective.

Examining BAD_POOL_CALLER (c2) BSOD

My work computer recently crashed again with another BSOD.

 

Checked Event Viewer and found:

Log Name:      System
Source:        Microsoft-Windows-WER-SystemErrorReporting
Event ID:      1001
Level:         Error
Keywords:      Classic
Description:
The computer has rebooted from a bugcheck.  The bugcheck was: 0x000000c2 (0x0000000000000007, 0x000000000000109b, 0x0000000000000000, 0xfffffa800cd9d010). A dump was saved in: C:\Windows\MEMORY.DMP.

 

Examined the memory dump with WinDbg (x64).

Checked for details about the crash with:

!analyze -v

Part of the result:

BAD_POOL_CALLER (c2)
The current thread is making a bad pool request.  Typically this is at a bad IRQL level or double freeing the same allocation, etc.
Arguments:
Arg1: 0000000000000007, Attempt to free pool which was already freed
Arg2: 000000000000109b, (reserved)
Arg3: 0000000000000000, Memory contents of the pool block
Arg4: fffffa800cd9d010, Address of the block of pool being deallocated

Debugging Details:
------------------

POOL_ADDRESS:  fffffa800cd9d010 Nonpaged pool

BUGCHECK_STR:  0xc2_7

DEFAULT_BUCKET_ID:  WIN7_DRIVER_FAULT

PROCESS_NAME:  vlc.exe

CURRENT_IRQL:  2

MODULE_NAME: avgtdia

IMAGE_NAME:  avgtdia.sys

 

Examined the call stack with:

kp

Result:

Child-SP          RetAddr           Call Site
fffff880`0db9b1f8 fffff800`031c3bf9 nt!KeBugCheckEx
fffff880`0db9b200 fffff880`01f729c5 nt!ExAllocatePoolWithTag+0x1951
fffff880`0db9b2b0 fffff880`04272775 avgtdia+0xb9c5
fffff880`0db9b330 fffff880`042407bb afd! ?? ::GFJBLGFE::`string'+0xd64c
fffff880`0db9b550 fffff800`033b028e afd!AfdFastIoDeviceControl+0x7ab
fffff880`0db9b8c0 fffff800`033b0896 nt!IopXxxControlFile+0x6be
fffff880`0db9ba00 fffff800`0308c693 nt!NtDeviceIoControlFile+0x56
fffff880`0db9ba70 00000000`73b12e09 nt!KiSystemServiceCopyEnd+0x13
00000000`045af0f8 00000000`00000000 0x73b12e09

 

The driver avgtdia.sys seemed to cause the crash.

 

Examined information about the avgtdia driver with:

lm v m avgtdia

Result:

start             end                 module name
fffff880`01f67000 fffff880`01fad000   avgtdia    (no symbols)
Loaded symbol image file: avgtdia.sys
Image path: \SystemRoot\system32\DRIVERS\avgtdia.sys
Image name: avgtdia.sys
Timestamp:        Wed Jul 27 15:24:36 2016 (5798B614)
CheckSum:         00053AED
ImageSize:        00046000
Translations:     0000.04b0 0000.04e4 0409.04b0 0409.04e4

 

Discovered that avgtdia.sys was: AVG Network connection watcher

 

This made me suspect that other BSOD crashes were also caused by AVG Internet Security:

Examining PFN_LIST_CORRUPT (4e) and PAGE_FAULT_IN_NONPAGED_AREA (50) BSOD

 

I decided to uninstall AVG Internet Security using: AVG Remover

Installed replacement: Avira Antivirus

 

I used to experience 2 BSOD crashes per week on this computer.

After uninstalling AVG Internet Security, the computer has been running for 1 week without any crashes…

I hope that the root cause has been identified and that the computer will finally be stable and reliable.

Conclusion

Common causes for computer stability problems are failing hard disks, defective memory and buggy drivers.

It seems that some antivirus products can also cause stability problems, possibly combined with specific drivers or other system level software.

Examining SYSTEM_THREAD_EXCEPTION_NOT_HANDLED (7e) BSOD

My work computer recently crashed with a BSOD just after inserting a USB 3.0 memory stick.

Considering the circumstances I suspected that a USB driver bug caused the crash.

 

Checked Event Viewer and found:

Log Name:      System
Source:        Microsoft-Windows-WER-SystemErrorReporting
Event ID:      1001
Task Category: None
Level:         Error
Keywords:      Classic
Description:
The computer has rebooted from a bugcheck.  The bugcheck was: 0x0000007e (0xffffffffc0000005, 0xfffff88001e685fe, 0xfffff8800394e5a8, 0xfffff8800394de00). A dump was saved in: C:\Windows\MEMORY.DMP.

 

Examined the memory dump with WinDbg (x64).

Checked for details about the crash with:

!analyze -v

Part of the result:

SYSTEM_THREAD_EXCEPTION_NOT_HANDLED (7e)
This is a very common bugcheck.  Usually the exception address pinpoints
the driver/function that caused the problem.  Always note this address
as well as the link date of the driver/image that contains this address.
Arguments:
Arg1: ffffffffc0000005, The exception code that was not handled
Arg2: fffff88001e685fe, The address that the exception occurred at
Arg3: fffff8800394e5a8, Exception Record Address
Arg4: fffff8800394de00, Context Record Address

Debugging Details:
------------------

EXCEPTION_CODE: (NTSTATUS) 0xc0000005 - The instruction at 0x%08lx referenced memory at 0x%08lx. The memory could not be %s.

FAULTING_IP:
iusb3hub+235fe
fffff880`01e685fe 4c8b00          mov     r8,qword ptr [rax]

EXCEPTION_RECORD:  fffff8800394e5a8 -- (.exr 0xfffff8800394e5a8)
ExceptionAddress: fffff88001e685fe (iusb3hub+0x00000000000235fe)
ExceptionCode: c0000005 (Access violation)
ExceptionFlags: 00000000
NumberParameters: 2
Parameter[0]: 0000000000000000
Parameter[1]: 0000000000000000
Attempt to read from address 0000000000000000

MODULE_NAME: iusb3hub

IMAGE_NAME:  iusb3hub.sys

 

Examined the call stack with:

kp

Result:

Child-SP          RetAddr           Call Site
fffff880`0394d5d8 fffff800`0344cf24 nt!KeBugCheckEx
fffff880`0394d5e0 fffff800`0340a745 nt!PspUnhandledExceptionInSystemThread+0x24
fffff880`0394d620 fffff800`03101cb4 nt! ?? ::NNGAKEGL::`string'+0x21dc
fffff880`0394d650 fffff800`0310172d nt!_C_specific_handler+0x8c
fffff880`0394d6c0 fffff800`03100505 nt!RtlpExecuteHandlerForException+0xd
fffff880`0394d6f0 fffff800`03111a05 nt!RtlDispatchException+0x415
fffff880`0394ddd0 fffff800`030d5a82 nt!KiDispatchException+0x135
fffff880`0394e470 fffff800`030d45fa nt!KiExceptionDispatch+0xc2
fffff880`0394e650 fffff880`01e685fe nt!KiPageFault+0x23a
fffff880`0394e7e0 fffff880`01e4a2b6 iusb3hub+0x235fe
fffff880`0394e840 fffff880`01e4a055 iusb3hub+0x52b6
fffff880`0394e8b0 fffff880`01e4a7fd iusb3hub+0x5055
fffff880`0394e920 fffff880`01e5c9a7 iusb3hub+0x57fd
fffff880`0394e980 fffff880`01e5c3e4 iusb3hub+0x179a7
fffff880`0394ea90 fffff880`01e69b3b iusb3hub+0x173e4
fffff880`0394eb10 fffff800`033d2413 iusb3hub+0x24b3b
fffff880`0394eb40 fffff800`030df355 nt!IopProcessWorkItem+0x23
fffff880`0394eb70 fffff800`03371236 nt!ExpWorkerThread+0x111
fffff880`0394ec00 fffff800`030c7706 nt!PspSystemThreadStartup+0x5a
fffff880`0394ec40 00000000`00000000 nt!KxStartSystemThread+0x16

 

Apparently iusb3hub.sys caused an access violation by reading from address 0 (null pointer bug).

 

Examined information about the iusb3hub driver with:

lmv m iusb3hub

Result:

start             end                 module name
fffff880`01e45000 fffff880`01eaa000   iusb3hub   (no symbols)
Loaded symbol image file: iusb3hub.sys
Image path: \SystemRoot\system32\DRIVERS\iusb3hub.sys
Image name: iusb3hub.sys
Timestamp:        Fri Dec 18 16:59:07 2015 (56742D4B)
CheckSum:         0006D07A
ImageSize:        00065000
Translations:     0000.04b0 0000.04e4 0409.04b0 0409.04e4

 

Noticed that the driver was more than 1 year old.

Found details about “Intel(R) USB 3.0 Root Hub” in Device Manager.

 

Decided to search for an updated driver.

Installed and ran Intel Driver Update Utility, which found a newer USB 3.0 driver (5.0.0.32)

Installed the updated driver and rebooted the system.

Hoping that this will prevent the computer from crashing in the future.

Wireshark can hang when stopping capture

I have experienced problems with recent Wireshark versions on Windows, including the current latest version 2.2.3.

 

The way I normally use Wireshark is to capture the traffic of interest, then stop the capture and finally analyze the traffic.

However Wireshark on Windows can hang when stopping the capture…

 

When it happens the Wireshark UI becomes non-responsive:

 

The main thread runs at 100% CPU utilization.

 

And Process Monitor shows that the Wireshark process reads the “End Of File” from the same temporary file over and over:

 

Started debugging the issue by taking multiple memory dumps of the wireshark.exe process using procdump with:

procdump -ma -n 10 -s 1 wireshark.exe

 

Opened the first memory dump in WinDbg (x64).

Checked the call stack for the main thread (0) with:

~0 kp

Result:

# Child-SP          RetAddr           Call Site
00 00000039`a00f9fc8 00007ffc`e5dbc264 ntdll!NtReadFile+0x14
01 00000039`a00f9fd0 00007ffc`d9ca9aa7 KERNELBASE!ReadFile+0x74
02 00000039`a00fa050 00007ffc`d9ca9782 msvcr120!_read_nolock(int fh = 0n8, void * inputbuf = 0x000001a8`3e57bd20, unsigned int cnt = 0x1000)+0x2cf [f:\dd\vctools\crt\crtw32\lowio\read.c @ 256]
03 00000039`a00fa0f0 00007ffc`a14f09b3 msvcr120!_read(int fh = 0n8, void * buf = 0x000001a8`3e57bd20, unsigned int cnt = 0x1000)+0xc6 [f:\dd\vctools\crt\crtw32\lowio\read.c @ 92]
04 00000039`a00fa140 00007ffc`a14efde4 libwiretap!file_tell+0xc93
05 00000039`a00fa170 00007ffc`a14ef98c libwiretap!file_tell+0xc4
06 00000039`a00fa1a0 00007ffc`a1517c8d libwiretap!file_read+0xac
07 00000039`a00fa1e0 00007ffc`a150abb3 libwiretap!wtap_read_bytes_or_eof+0x2d
08 00000039`a00fa210 00007ffc`a150a9a9 libwiretap!wtap_wtap_encap_to_pcap_encap+0xbd3
09 00000039`a00fa290 00007ffc`a1517b77 libwiretap!wtap_wtap_encap_to_pcap_encap+0x9c9
0a 00000039`a00fa310 00007ff7`c7929fd3 libwiretap!wtap_read+0x37
0b 00000039`a00fa350 00007ff7`c7b7cfd7 Wireshark+0x9fd3
0c 00000039`a00fa3a0 00007ff7`c7b963dd Wireshark+0x25cfd7
0d 00000039`a00fa3e0 00007ff7`c798889a Wireshark+0x2763dd
0e 00000039`a00fb470 00007ff7`c79d5144 Wireshark+0x6889a
0f 00000039`a00fb4c0 00000000`5b94f906 Wireshark+0xb5144
10 00000039`a00fb5c0 00000000`5b9c4d66 Qt5Core!QMetaObject::activate+0x5a6
11 00000039`a00fb6d0 00000000`5b95413a Qt5Core!QTimer::timeout+0x16
12 00000039`a00fb700 00000000`5bcf7d12 Qt5Core!QObject::event+0x6a
13 00000039`a00fb8b0 00000000`5bcf6c2f Qt5Widgets!QApplicationPrivate::notify_helper+0x112
14 00000039`a00fb8e0 00000000`5b92f689 Qt5Widgets!QApplication::notify+0x1b3f
15 00000039`a00fc000 00000000`5b977a8c Qt5Core!QCoreApplication::notifyInternal2+0xb9
16 00000039`a00fc080 00000000`5b976a32 Qt5Core!QEventDispatcherWin32Private::sendTimerEvent+0x10c
17 00000039`a00fc0e0 00007ffc`e6851c24 Qt5Core!QEventDispatcherWin32::processEvents+0xd82
18 00000039`a00fc1f0 00007ffc`e685156c user32!UserCallWinProcCheckWow+0x274
19 00000039`a00fc350 00000000`5b9761d9 user32!DispatchMessageWorker+0x1ac
1a 00000039`a00fc3d0 00007ffc`a14029b9 Qt5Core!QEventDispatcherWin32::processEvents+0x529
1b 00000039`a00ff760 00000000`5b92bf91 qwindows!qt_plugin_query_metadata+0x2499
1c 00000039`a00ff790 00000000`5b92e477 Qt5Core!QEventLoop::exec+0x1b1
1d 00000039`a00ff810 00007ff7`c7929ccd Qt5Core!QCoreApplication::exec+0x147
1e 00000039`a00ff880 00007ff7`c7ba2ac5 Wireshark+0x9ccd
1f 00000039`a00ffd50 00007ff7`c7ba22fd Wireshark+0x282ac5
20 00000039`a00ffde0 00007ffc`e87c8364 Wireshark+0x2822fd
21 00000039`a00ffe20 00007ffc`e8f470d1 kernel32!BaseThreadInitThunk+0x14
22 00000039`a00ffe50 00000000`00000000 ntdll!RtlUserThreadStart+0x21

 

Checked the main thread (0) call stack for all the memory dumps by scripting CDB, the console version of WinDbg.

Used this PowerShell script:

$dmpPath = 'C:\Bin\Procdump\Wireshark\'
$dmpFiles = Get-ChildItem -Path $dmpPath -Recurse -Include *.dmp

foreach ($dmpFile in $dmpFiles)
{
    & "C:\Program Files (x86)\Windows Kits\10\Debuggers\x64\cdb.exe" -z $dmpFile -c "~0 kp; Q"
}

 

Noticed that all the memory dumps had the same call stack for thread 0, which further indicated that WireShark was stuck or running in an endless loop.

 

Now I wanted to identify if this was a hang or endless loop.

Attached to the running, but non-responsive Wireshark process with WinDbg (x64).

Experimented by setting breakpoints from the initial call stack.

 

Set a single breakpoint at:

MSVCR120!_read_nolock(...)+0x2cf

With:

bc *
bp MSVCR120!_read_nolock+0x2cf

Result after continue: Breakpoint was continually hit.

 

This definitely indicated an endless loop.

 

Set a single breakpoint at:

libwiretap!wtap_read_bytes_or_eof+0x2d

With:

bc *
bp libwiretap!wtap_read_bytes_or_eof+0x2d

Result after continue: Breakpoint was continually hit.

 

Set a single breakpoint at:

Qt5Core!QTimer::timeout+0x16

With:

bc *
bp Qt5Core!QTimer::timeout+0x16

Result after continue: Breakpoint was not hit (within 1 minute)

 

Set single breakpoints at the various Wireshark functions.

The breakpoint was not hit until setting a single breakpoint at:

Wireshark+0x9fd3

With:

bc *
bp Wireshark+0x9fd3

Result after continue: The breakpoint was continually hit.

 

This indicated that the endless loop occured in the Wireshark module.

 

Had a quick look at the disassembly and tried single stepping with:

p

The code was definitely looping, but the problem was not obvious by looking at the machine code.

 

Went looking for debug symbols and found them here:

https://1.eu.dl.wireshark.org/win64/all-versions/Wireshark-pdb-win64-2.2.3.zip

Downloaded the debug symbols and unpacked them to a temporary folder.

 

Then modified the symbol path in WinDbg with:

.sympath C:\Temp\WSSymbols\;srv*c:\SymbolsCache*https://msdl.microsoft.com/download/symbols

And reloaded the symbols with:

.reload /f

 

Checked the call stack again with:

~0 kp

Result:

# Child-SP          RetAddr           Call Site
00 00000039`a00f9fc8 00007ffc`e5dbc264 ntdll!NtReadFile+0x14
01 00000039`a00f9fd0 00007ffc`d9ca9aa7 KERNELBASE!ReadFile+0x74
02 00000039`a00fa050 00007ffc`d9ca9782 MSVCR120!_read_nolock(int fh = 0n8, void * inputbuf = 0x000001a8`3e57bd20, unsigned int cnt = 0x1000)+0x2cf [f:\dd\vctools\crt\crtw32\lowio\read.c @ 256]
03 00000039`a00fa0f0 00007ffc`a14f09b3 MSVCR120!_read(int fh = 0n8, void * buf = 0x000001a8`3e57bd20, unsigned int cnt = 0x1000)+0xc6 [f:\dd\vctools\crt\crtw32\lowio\read.c @ 92]
04 00000039`a00fa140 00007ffc`a14efde4 libwiretap!raw_read(struct wtap_reader * state = 0x000001a8`4ad0ebd0, unsigned char * buf = 0x000001a8`3e57bd20 "vided by dumpcap???", unsigned int count = 0x1000, unsigned int * have = 0x000001a8`4ad0ec08)+0x43 [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\wiretap\file_wrappers.c @ 133]
05 00000039`a00fa170 00007ffc`a14ef98c libwiretap!fill_out_buffer(struct wtap_reader * state = 0x000001a8`4ad0ebd0)+0x44 [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\wiretap\file_wrappers.c @ 704]
06 00000039`a00fa1a0 00007ffc`a1517c8d libwiretap!file_read(void * buf = 0x00000039`a00fa250, unsigned int len = 8, struct wtap_reader * file = 0x000001a8`4ad0ebd0)+0xac [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\wiretap\file_wrappers.c @ 1237]
07 00000039`a00fa1e0 00007ffc`a150abb3 libwiretap!wtap_read_bytes_or_eof(struct wtap_reader * fh = 0x000001a8`4ad0ebd0, void * buf = <Value unavailable error>, unsigned int count = 8, int * err = 0x00000039`a00fa3a0, char ** err_info = 0x00000039`a00fa3b0)+0x2d [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\wiretap\wtap.c @ 1291]
08 00000039`a00fa210 00007ffc`a150a9a9 libwiretap!pcapng_read_block(struct wtap * wth = 0x000001a8`41f48790, struct wtap_reader * fh = 0x000001a8`4ad0ebd0, struct pcapng_t * pn = 0x000001a8`41f1ca40, struct wtapng_block_s * wblock = 0x00000039`a00fa2c0, int * err = 0x00000039`a00fa3a0, char ** err_info = 0x00000039`a00fa3b0)+0x53 [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\wiretap\pcapng.c @ 2303]
09 00000039`a00fa290 00007ffc`a1517b77 libwiretap!pcapng_read(struct wtap * wth = 0x000001a8`41f48790, int * err = 0x00000039`a00fa3a0, char ** err_info = 0x00000039`a00fa3b0, int64 * data_offset = 0x00000039`a00fa3a8)+0x79 [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\wiretap\pcapng.c @ 2589]
0a 00000039`a00fa310 00007ff7`c7929fd3 libwiretap!wtap_read(struct wtap * wth = 0x000001a8`41f48790, int * err = 0x00000039`a00fa3a0, char ** err_info = 0x00000039`a00fa3b0, int64 * data_offset = <Value unavailable error>)+0x37 [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\wiretap\wtap.c @ 1237]
0b 00000039`a00fa350 00007ff7`c7b7cfd7 Wireshark!capture_info_new_packets(int to_read = 0n14, struct _info_data * cap_info = 0x000001a8`3f1838b8)+0x43 [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\capture_info.c @ 211]
0c 00000039`a00fa3a0 00007ff7`c7b963dd Wireshark!capture_input_new_packets(struct _capture_session * cap_session = 0x000001a8`3f183878, int to_read = 0n23)+0xa7 [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\ui\capture.c @ 407]
0d 00000039`a00fa3e0 00007ff7`c798889a Wireshark!sync_pipe_input_cb(int source = 0n4, void * user_data = 0x000001a8`3f183878)+0x1bd [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\capchild\capture_sync.c @ 1775]
0e 00000039`a00fb470 00007ff7`c79d5144 Wireshark!MainWindow::pipeTimeout(void)+0x8a [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\ui\qt\main_window_slots.cpp @ 949]
0f 00000039`a00fb4c0 00000000`5b94f906 Wireshark!MainWindow::qt_static_metacall(class QObject * _o = 0x000001a8`3f1836e0, QMetaObject::Call _c = <Value unavailable error>, int _id = <Value unavailable error>, void ** _a = 0x00000039`a00fb5f8)+0x4c4 [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\cmbuild\ui\qt\moc_main_window.cpp @ 1436]
10 00000039`a00fb5c0 00000000`5b9c4d66 Qt5Core!QMetaObject::activate+0x5a6
11 00000039`a00fb6d0 00000000`5b95413a Qt5Core!QTimer::timeout+0x16
12 00000039`a00fb700 00000000`5bcf7d12 Qt5Core!QObject::event+0x6a
13 00000039`a00fb8b0 00000000`5bcf6c2f Qt5Widgets!QApplicationPrivate::notify_helper+0x112
14 00000039`a00fb8e0 00000000`5b92f689 Qt5Widgets!QApplication::notify+0x1b3f
15 00000039`a00fc000 00000000`5b977a8c Qt5Core!QCoreApplication::notifyInternal2+0xb9
16 00000039`a00fc080 00000000`5b976a32 Qt5Core!QEventDispatcherWin32Private::sendTimerEvent+0x10c
17 00000039`a00fc0e0 00007ffc`e6851c24 Qt5Core!QEventDispatcherWin32::processEvents+0xd82
18 00000039`a00fc1f0 00007ffc`e685156c USER32!UserCallWinProcCheckWow+0x274
19 00000039`a00fc350 00000000`5b9761d9 USER32!DispatchMessageWorker+0x1ac
1a 00000039`a00fc3d0 00007ffc`a14029b9 Qt5Core!QEventDispatcherWin32::processEvents+0x529
1b 00000039`a00ff760 00000000`5b92bf91 qwindows!qt_plugin_query_metadata+0x2499
1c 00000039`a00ff790 00000000`5b92e477 Qt5Core!QEventLoop::exec+0x1b1
1d 00000039`a00ff810 00007ff7`c7929ccd Qt5Core!QCoreApplication::exec+0x147
1e 00000039`a00ff880 00007ff7`c7ba2ac5 Wireshark!main(int argc = 0n1, char ** qt_argv = <Value unavailable error>)+0xe3d [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\wireshark-qt.cpp @ 853]
1f 00000039`a00ffd50 00007ff7`c7ba22fd Wireshark!WinMain+0x155
20 00000039`a00ffde0 00007ffc`e87c8364 Wireshark!__tmainCRTStartup(void)+0x149 [f:\dd\vctools\crt\crtw32\dllstuff\crtexe.c @ 618]
21 00000039`a00ffe20 00007ffc`e8f470d1 KERNEL32!BaseThreadInitThunk+0x14
22 00000039`a00ffe50 00000000`00000000 ntdll!RtlUserThreadStart+0x21

 

The symbols seemed to be correct and functional.

 

Wanted to verify the location of the endless loop by setting breakpoints again.

 

Set a single breakpoint at:

Wireshark!capture_input_new_packets

With:

bc *
bp Wireshark!capture_input_new_packets

Result after continue: Breakpoint was not hit (within 1 minute)

 

Set a single breakpoint at:

Wireshark!capture_info_new_packets

With:

bc *
bp Wireshark!capture_info_new_packets

Result after continue: Breakpoint was not hit (within 1 minute)

 

Set a single breakpoint at:

libwiretap!wtap_read

With:

bc *
bp libwiretap!wtap_read

Result after continue: The breakpoint was continually hit.

 

This result indicated that the endless loop was in Wireshark!capture_info_new_packets(…) calling libwiretap!wtap_read(…), specifically here:

Wireshark!capture_info_new_packets(int to_read = 0n14, struct _info_data * cap_info = 0x000001a8`3f1838b8)+0x43 [c:\buildbot\wireshark\wireshark-2.2-64\windows-2012r2-x64\build\capture_info.c @ 211]

 

Downloaded the source code for Wireshark from:

https://1.eu.dl.wireshark.org/src/wireshark-2.2.3.tar.bz2

 

Looked for and opened: capture_info.c

Found the method, which has been included here:

/* new packets arrived */
void capture_info_new_packets(int to_read, info_data_t* cap_info)
{
    int err;
    gchar *err_info;
    gint64 data_offset;
    struct wtap_pkthdr *phdr;
    union wtap_pseudo_header *pseudo_header;
    int wtap_linktype;
    const guchar *buf;

    cap_info->ui.new_packets = to_read;

    /*g_warning("new packets: %u", to_read);*/

    while (to_read > 0) {
        wtap_cleareof(cap_info->wtap);
        if (wtap_read(cap_info->wtap, &err, &err_info, &data_offset)) {
            phdr = wtap_phdr(cap_info->wtap);
            pseudo_header = &phdr->pseudo_header;
            wtap_linktype = phdr->pkt_encap;
            buf = wtap_buf_ptr(cap_info->wtap);

            capture_info_packet(cap_info, wtap_linktype, buf, phdr->caplen, pseudo_header);

            /*g_warning("new packet");*/
            to_read--;
        }
    }

    capture_info_ui_update(&cap_info->ui);
}

 

I have marked some points of interest with bold.

 

The while loop continues as long as to_read is greater than 0.

Noticed that the to_read variable continued to have the value 14.

to_read is only decremented in case wtap_read returns a non-zero value.

It seems that this never happens, when the endless loop occurs in Wireshark.

 

I have noticed that the problem apparently doesn’t occur with Wireshark Legacy based on GTK (at least with default settings).

I wanted to determine the cause for the difference.

 

Examined symbols for Wireshark (QT) with:

x /D /f Wireshark!capture_info_new_packets

Result:

00007ff7`c7929f90 Wireshark!capture_info_new_packets (int, struct _info_data *)

 

Examined symbols for Wireshark Legacy (GTK) with:

x /D /f Wireshark_gtk!capture_info_new_packets

Result:

00007ff7`c03310f0 Wireshark_gtk!capture_info_new_packets (int, struct _info_data *)

 

Both versions include the function capture_info_new_packets (…)

 

Checked where the function was mentioned in the source code with grep (from Cygwin):

grep "capture_info_new_packets" -r

Result:

capture_info.c:void capture_info_new_packets(int to_read, info_data_t* cap_info)
capture_info.h:extern void capture_info_new_packets(int to_read, info_data_t* cap_info);
ui/capture.c:    capture_info_new_packets(to_read, cap_session->cap_data_info);

 

Checked the content of ui/capture.c and found:

if(capture_opts->show_info)
    capture_info_new_packets(to_read, cap_session->cap_data_info);

 

So the capture_info_new_packets(…) function will only be called if the show_info option is true…

 

Looked for places where show_info was used with:

grep "show_info" -r

Part of the result was:

ui/gtk/capture_dlg.c:  gtk_toggle_button_set_active(GTK_TOGGLE_BUTTON(hide_info_cb), !global_capture_opts.show_info);
ui/gtk/capture_dlg.c:  global_capture_opts.show_info =
ui/qt/capture_interfaces_dialog.cpp:    global_capture_opts.show_info = checked;
ui/qt/capture_interfaces_dialog.cpp:    ui->cbExtraCaptureInfo->setChecked(global_capture_opts.show_info);

 

For Wireshark Legacy (GTK) I checked the content of ui/gtk/capture_dlg.c and found:

global_capture_opts.show_info =
    !gtk_toggle_button_get_active(GTK_TOGGLE_BUTTON(hide_info_cb));

 

For Wireshark Legacy (GTK) the endless loop problem can be avoided by enabling this option in the Capture Options dialog :

Hide capture info dialog   (default setting)

 

For Wireshark (QT) I checked the content of ui/qt/capture_interfaces_dialog.cpp and found:

void CaptureInterfacesDialog::on_cbExtraCaptureInfo_toggled(bool checked)
{
    global_capture_opts.show_info = checked;
}

 

For Wireshark (QT) the endless loop problem can be avoided by disabling this option in the Capture Interfaces dialog :

Show extra capture information dialog   (not default setting)

 

Conclusion

The endless loop problem occurs consistently depending on the identified settings, so the problem cause has likely been found along with a workaround.

Until the endless loop bug has been fixed in Wireshark, it is recommended to set the Wireshark options like described above.

Examining DRIVER_CORRUPTED_EXPOOL (c5) BSOD

My work computer recently crashed with a BSOD, when disconnecting or reconnecting Cisco AnyConnect Secure Mobility Client.

Considering the circumstances I suspected that Cisco AnyConnect was the culprit, but I wanted to confirm this.

 

I started looking for information in Event Viewer and found:

Log Name:      System
Source:        Microsoft-Windows-WER-SystemErrorReporting
Event ID:      1001
Task Category: None
Level:         Error
Keywords:      Classic
Description:
The computer has rebooted from a bugcheck.  The bugcheck was: 0x000000c5 (0x00000000760e0002, 0x0000000000000002, 0x0000000000000000, 0xfffff802fba61850). A dump was saved in: C:\WINDOWS\MEMORY.DMP.

 

Needed to examine the memory dump, so started WinDbg (x64) and opened:

C:\Windows\Memory.dmp

This message was displayed:

BugCheck C5, {760e0002, 2, 0, fffff802fba61850}

*** ERROR: Module load completed but symbols could not be loaded for acsock64.sys
Probably caused by : memory_corruption

 

Checked for more details with:

!analyze -v

Part of the result:

DRIVER_CORRUPTED_EXPOOL (c5)
An attempt was made to access a pageable (or completely invalid) address at an
interrupt request level (IRQL) that is too high.  This is
caused by drivers that have corrupted the system pool.  Run the driver
verifier against any new (or suspect) drivers, and if that doesn't turn up
the culprit, then use gflags to enable special pool.
Arguments:
Arg1: 00000000760e0002, memory referenced
Arg2: 0000000000000002, IRQL
Arg3: 0000000000000000, value 0 = read operation, 1 = write operation
Arg4: fffff802fba61850, address which referenced memory

 

The crash definitely seemed to be caused by a driver bug.

Now I wanted to identify which driver caused the problem.

 

Checked the call stack with:

kc

Result:

# Call Site
00 nt!KeBugCheckEx
01 nt!KiBugCheckDispatch
02 nt!KiPageFault
03 nt!ExDeferredFreePool
04 nt!ExFreePoolWithTag
05 acsock64
06 acsock64
07 acsock64
08 NETIO!ProcessCallout
09 NETIO!ProcessFastCalloutClassify
0a NETIO!KfdClassify
0b tcpip!AleNotifyEndpointTeardown
0c tcpip!UdpCleanupEndpointWorkQueueRoutine
0d tcpip!UdpCloseEndpoint
0e afd!AfdTLCloseEndpoint
0f afd!AfdCloseTransportEndpoint
10 afd!AfdCleanupCore
11 afd!AfdDispatch
12 nt!IopCloseFile
13 nt!ObCloseHandleTableEntry
14 nt!NtClose
15 nt!KiSystemServiceCopyEnd
16 0x0

 

Noticed that the acsock64 calls occured just before the crash.

 

Examined available information about acsock64 with:

lmv m acsock64

Part of the result:

start             end                 module name
fffff807`453d0000 fffff807`45406000   acsock64   (no symbols)
Loaded symbol image file: acsock64.sys
Image path: \SystemRoot\system32\DRIVERS\acsock64.sys
Image name: acsock64.sys
Timestamp:        Thu Oct 08 17:12:56 2015 (561687F8)
CheckSum:         0003DD8B
ImageSize:        00036000
Translations:     0000.04b0 0000.04e4 0409.04b0 0409.04e4

 

Noticed that the driver was around 14 months old at the time of writing.

 

Found the driver file in Windows explorer under:

C:\Windows\system32\DRIVERS\acsock64.sys

Then checked Properties. The details view revealed that the driver was:

Cisco AnyConnect Kernel Driver Framework Socket Layer Interceptor

Version: 4.2.1009.0

 

This confirmed my suspicion, Cisco AnyConnect most likely caused the BSOD.

 

At this point I would have updated to the latest version, if updates to Cisco AnyConnect were freely available.

Instead I decided to install and use the Windows port of OpenConnect as an alternative to Cisco AnyConnect.

Examining UNEXPECTED_KERNEL_MODE_TRAP (7f) BSOD with WinDbg

Recently one of my computers was performing slowly and I decided to close some programs.

When closing all Windows explorers the computer crashed with a BSOD

 

After reboot this message was displayed:

windows_has_recovered_from_an_unexpected_shutdown_bsod_7f_08

Windows has recovered from an unexpected shutdown

Problem signature:
Problem Event Name:    BlueScreen
OS Version:    6.1.7601.2.1.0.768.3
Locale ID:    1030

Additional information about the problem:
BCCode:    7f
BCP1:    0000000000000008
BCP2:    0000000080050031
BCP3:    00000000000006F8
BCP4:    FFFFF9600025C28C
OS Version:    6_1_7601
Service Pack:    1_0
Product:    768_1

 

A similar message was logged in Event Viewer:

Log Name:      System
Source:        Microsoft-Windows-WER-SystemErrorReporting
Event ID:      1001
Task Category: None
Level:         Error
Keywords:      Classic
Description:
The computer has rebooted from a bugcheck.  The bugcheck was: 0x0000007f (0x0000000000000008, 0x0000000080050031, 0x00000000000006f8, 0xfffff9600025c28c). A dump was saved in: C:\Windows\MEMORY.DMP.

 

Decided to examine this further, so started WinDbg (x64) and opened:

C:\Windows\Memory.dmp

This message was displayed:

BugCheck 7F, {8, 80050031, 6f8, fffff9600025c28c}

 

Checked for more details with:

!analyze -v

Part of the result:

*****************************************************************
*                                                               *
*                      Bugcheck Analysis                        *
*                                                               *
*****************************************************************

UNEXPECTED_KERNEL_MODE_TRAP (7f)
This means a trap occurred in kernel mode, and it's a trap of a kind
that the kernel isn't allowed to have/catch (bound trap) or that
is always instant death (double fault).  The first number in the
bugcheck params is the number of the trap (8 = double fault, etc)
Consult an Intel x86 family manual to learn more about what these
traps are. Here is a *portion* of those codes:
If kv shows a taskGate
use .tss on the part before the colon, then kv.
Else if kv shows a trapframe
use .trap on that value
Else
.trap on the appropriate frame will show where the trap was taken
(on x86, this will be the ebp that goes with the procedure KiTrap)
Endif
kb will then show the corrected stack.
Arguments:
Arg1: 0000000000000008, EXCEPTION_DOUBLE_FAULT
Arg2: 0000000080050031
Arg3: 00000000000006f8
Arg4: fffff9600025c28c

 

Decided to search online for: UNEXPECTED_KERNEL_MODE_TRAP (7f) exception double fault

And found this article: Bug Check 0x7F: UNEXPECTED_KERNEL_MODE_TRAP

 

It mentioned that a common cause for this error was kernel stack overflow.

So I checked the stack usage with:

!stackusage

The result was:

Stack Usage By Function
===================================================================

Size     Count  Module
0x00001500        14  win32k!xxxDesktopWndProcWorker
0x00000DD0        13  win32k!xxxInterSendMsgEx
0x00000D20        14  win32k!xxxReceiveMessage
0x000009C0        13  win32k!xxxRealSleepThread
0x000008F0        13  win32k!xxxSendMessageTimeout
0x000004E0        13  win32k!xxxBeginPaint
0x00000410        13  win32k!xxxSendNCPaint
0x00000400         2  win32k!RGNOBJAPI::bSubtractComplex
0x00000380         1  win32k!CalcVisRgnWorker
0x000002A0        14  win32k!xxxDesktopWndProc
0x00000270        13  win32k!xxxSleepThread
0x000000E0         1  win32k!xxxRealInternalGetMessage
0x00000090         1  win32k!xxxHandleDesktopMessages
0x00000090         1  win32k!GetDCEx
0x00000080         1  win32k!xxxDesktopThread
0x00000080         1  win32k!RGNOBJAPI::bSubtract
0x00000060         1  win32k!xxxBeginPaint
0x00000050         1  win32k!GreSubtractRgnRectList
0x00000040         1  win32k!xxxInternalGetMessage
0x00000030         1  win32k!xxxCreateSystemThreads
0x00000030         1  win32k!CalcVisRgn
0x00000030         1  win32k!NtUserCallNoParam

Total Size: 0x00005CA0


Stack Usage By Module
===================================================================

Size     Count  Module
0x00005CA0       134  win32k

Total Size: 0x00005CA0

 

Noticed that 0x5CA0 = 23712 bytes is very close to the 24K kernel stack limit for 64-bit Windows.

The most likely cause for the BSOD was indeed kernel stack overflow.

 

Examined the call stack with:

kf

Part of the result:

#   Memory  Child-SP          RetAddr           Call Site
00           fffff800`0449ed28 fffff800`030889e9 nt!KeBugCheckEx
01         8 fffff800`0449ed30 fffff800`03086eb2 nt!KeSynchronizeExecution+0x3d39
02       140 fffff800`0449ee70 fffff960`0025c28c nt!KeSynchronizeExecution+0x2202
03   20f4110 fffff880`06592f80 fffff960`0025c1c1 win32k!RGNOBJAPI::bSubtractComplex+0x44
04       400 fffff880`06593380 fffff960`001d3379 win32k!RGNOBJAPI::bSubtract+0x871
05        80 fffff880`06593400 fffff960`0014d7c4 win32k!GreSubtractRgnRectList+0x49
06        50 fffff880`06593450 fffff960`000c5c47 win32k!CalcVisRgnWorker+0x314
07       380 fffff880`065937d0 fffff960`000d23be win32k!CalcVisRgn+0x97
08        30 fffff880`06593800 fffff960`00056cf6 win32k!GetDCEx+0x50e
09        90 fffff880`06593890 fffff960`0009ede7 win32k!xxxBeginPaint+0x192
0a        60 fffff880`065938f0 fffff960`0009ead5 win32k!xxxDesktopWndProcWorker+0x2f7
0b       180 fffff880`06593a70 fffff960`00094013 win32k!xxxDesktopWndProc+0x55
0c        30 fffff880`06593aa0 fffff960`000def3f win32k!xxxReceiveMessage+0x6cb

 

Noticed the very large stack frame difference at:

win32k!RGNOBJAPI::bSubtractComplex+0x44

 

Examined details about win32k.sys with:

lmDvm win32k

Part of the result:

Image path: \SystemRoot\System32\win32k.sys
Image name: win32k.sys
Timestamp:        Mon Sep 12 22:37:06 2016 (57D711F2)
CheckSum:         00314AE8
ImageSize:        00326000
File version:     6.1.7601.23545
Product version:  6.1.7601.23545
File flags:       0 (Mask 3F)
File OS:          40004 NT Win32
File type:        3.7 Driver
File date:        00000000.00000000
Translations:     0409.04b0
CompanyName:      Microsoft Corporation
ProductName:      Microsoft® Windows® Operating System
InternalName:     win32k.sys
OriginalFilename: win32k.sys
ProductVersion:   6.1.7601.23545
FileVersion:      6.1.7601.23545 (win7sp1_ldr.160912-1137)
FileDescription:  Multi-User Win32 Driver
LegalCopyright:   © Microsoft Corporation. All rights reserved.

 

Noticed that win32k.sys had been updated recently.

Knowing that win32k.sys interacts with the graphics driver, I decided to update this to the latest version.

Debugging failing SSRS report caused by read-only report parameter

I recently experienced problems when trying to view a report for SQL Server Reporting Services with ReportViewer for MVC.

 

The report worked in some cases, but failed when certain parameters were set.

Exception and stack trace:

[ReportServerException: The report parameter 'DeviceTypes' is read-only and cannot be modified. (rsReadOnlyReportParameter)]
Microsoft.Reporting.WebForms.ServerReportSoapProxy.OnSoapException(SoapException e) +155
Microsoft.Reporting.WebForms.Internal.Soap.ReportingServices2005.Execution.ProxyMethodInvocation.Execute(RSExecutionConnection connection, ProxyMethod`1 initialMethod, ProxyMethod`1 retryMethod) +1256
Microsoft.Reporting.WebForms.Internal.Soap.ReportingServices2005.Execution.RSExecutionConnection.SetExecutionParameters(ParameterValue[] Parameters, String ParameterLanguage) +370
Microsoft.Reporting.WebForms.SoapReportExecutionService.SetExecutionParameters(IEnumerable`1 parameters, String parameterLanguage) +530
Microsoft.Reporting.WebForms.ServerReport.SetParameters(IEnumerable`1 parameters) +896
Microsoft.Reporting.WebForms.Report.SetParameters(ReportParameter parameter) +136
ReportViewerForMvc.ReportExtensions.SetParameters(Report report, ReportParameterInfoCollection collection) +114
ReportViewerForMvc.ReportViewerExtensions.SetProperties(ServerReport serverReport, ServerReport properties) +84
ReportViewerForMvc.ReportViewerExtensions.SetProperties(ReportViewer reportViewer, ReportViewer properties) +117
ReportViewerForMvc.ReportViewerWebForm.BuildReportViewer() +92
System.Web.UI.Control.OnLoad(EventArgs e) +109
System.Web.UI.Control.LoadRecursive() +68
System.Web.UI.Page.ProcessRequestMain(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint) +4498

 

Checked the ReportServerService__*.log and ExecutionLog* database views, but they contained no additional clues about the error.

 

I attached WinDbg (x64) to the IIS worker process (w3wp.exe) and set a breakpoint with:

!bpmd   ReportViewerForMvc.dll   ReportViewerForMvc.ReportExtensions.SetParameters

Messages from WinDbg:

Found 2 methods in module 00007ff9bde79bb0...
MethodDesc = 00007ff9c00a30d0
MethodDesc = 00007ff9c00a30e0
Setting breakpoint: bp 00007FF9C0EE5590 [ReportViewerForMvc.ReportExtensions.SetParameters(Microsoft.Reporting.WebForms.Report, Microsoft.Reporting.WebForms.ReportParameterInfo)]
Setting breakpoint: bp 00007FF9C0EE53E4 [ReportViewerForMvc.ReportExtensions.SetParameters(Microsoft.Reporting.WebForms.Report, Microsoft.Reporting.WebForms.ReportParameterInfoCollection)]
Adding pending breakpoints...

 

Continued exection, reloaded the report and the breakpoint was hit.

Checked the .NET call stack with:

!clrstack -a

Part of the result:

OS Thread Id: 0x273c (45)
Child SP               IP Call Site
00000007dba9d030 00007ff9c0ee53e4 ReportViewerForMvc.ReportExtensions.SetParameters(Microsoft.Reporting.WebForms.Report, Microsoft.Reporting.WebForms.ReportParameterInfoCollection)
PARAMETERS:
report (<CLR reg>) = 0x0000000390e93650
collection (<CLR reg>) = 0x0000000490886678

 

Examined the collection object with:

!DumpObj /d 0000000490886678

Result:

Name:        Microsoft.Reporting.WebForms.ReportParameterInfoCollection
MethodTable: 00007ff9bff1cc98
EEClass:     00007ff9bff08d40
Size:        32(0x20) bytes
File:        C:\Windows\assembly\GAC_MSIL\Microsoft.ReportViewer.WebForms\11.0.0.0__89845dcd8080cc91\Microsoft.ReportViewer.WebForms.dll
Fields:
MT    Field   Offset                 Type VT     Attr            Value Name
00007ffa1b23d408  40017fa        8 ...Canon, mscorlib]]  0 instance 00000004908823f0 list
00007ffa1b8de068  40017fb       10        System.Object  0 instance 0000000000000000 _syncRoot

 

Examined the list array with:

!DumpArray /d 00000004908823f0

Result:

Name:        Microsoft.Reporting.WebForms.ReportParameterInfo[]
MethodTable: 00007ff9c0fd9e60
EEClass:     00007ffa1b2f0f10
Size:        120(0x78) bytes
Array:       Rank 1, Number of elements 12, Type CLASS
Element Methodtable: 00007ff9bff1cbc0
[0] 00000004908826c8
[1] 00000004908829d8
[2] 0000000490882ce8
[3] 00000004908832e0
[4] 0000000490884490
[5] 00000004908847a8
[6] 0000000490884ac0
[7] 0000000490884e38
[8] 00000004908853f8
[9] 0000000490885818
[10] 0000000490886250
[11] 00000004908865c8

 

Examined details for the list array with:

!DumpArray /d -details 00000004908823f0

Part of the result:

[11] 00000004908865c8
Name:        Microsoft.Reporting.WebForms.ReportParameterInfo
MethodTable: 00007ff9bff1cbc0
EEClass:     00007ff9bff08cc8
Size:        104(0x68) bytes
File:        C:\Windows\assembly\GAC_MSIL\Microsoft.ReportViewer.WebForms\11.0.0.0__89845dcd8080cc91\Microsoft.ReportViewer.WebForms.dll
Fields:
MT    Field   Offset                 Type VT     Attr            Value Name
00007ffa1b8dda88  4000120        8            System.String      0     instance     0000000490881950     m_name
00007ff9bff1c678  4000121       50             System.Int32      1     instance                    4     m_dataType
00007ffa1b8cd6f8  4000122       58           System.Boolean      1     instance                    0     m_isNullable
00007ffa1b8cd6f8  4000123       59           System.Boolean      1     instance                    1     m_allowBlank
00007ffa1b8cd6f8  4000124       5a           System.Boolean      1     instance                    1     m_isMultiValue
00007ffa1b8cd6f8  4000125       5b           System.Boolean      1     instance                    1     m_isQueryParameter
00007ffa1b8dda88  4000126       10            System.String      0     instance     000000038e411420     m_prompt
00007ffa1b8cd6f8  4000127       5c           System.Boolean      1     instance                    0     m_promptUser
00007ffa1b8cd6f8  4000128       5d           System.Boolean      1     instance                    1     m_areDefaultValuesQueryBased
00007ffa1b8cd6f8  4000129       5e           System.Boolean      1     instance                    1     m_areValidValuesQueryBased
00007ffa1b8dda88  400012a       18            System.String      0     instance     0000000000000000     m_errorMessage
00007ff9c0fda240  400012b       20     ...Viewer.WebForms]]      0     instance     0000000490886320     m_validValues
00007ffa1b23d128  400012c       28     ...tring, mscorlib]]      0     instance     0000000490886658     m_currentValues
00007ff9bff1c7c8  400012d       54             System.Int32      1     instance                    0     m_state
00007ff9bff1cc98  400012e       30     ...terInfoCollection      0     instance     0000000490886fb8     m_dependencyCollection
00007ff9bff1cc98  400012f       38     ...terInfoCollection      0     instance     0000000000000000     m_dependentsCollection
00007ffa1b8c1480  4000130       40          System.String[]      0     instance     0000000490881bb8     m_dependencies
00007ff9c0fda5d0  4000131       48     ...Viewer.WebForms]]      0     instance     0000000490886630     m_dependentsCollectionConstruction
00007ffa1b8cd6f8  4000132       5f           System.Boolean      1     instance                    1     m_visible

 

Examined the name of the last report parameter with:

!DumpObj /d 0000000490881950

Part of the result:

Name:        System.String
MethodTable: 00007ffa1b8dda88
EEClass:     00007ffa1b236a08
Size:        48(0x30) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
String:      DeviceTypes

So the last parameter was DeviceTypes, the one causing the problem.

 

Looked for a read-only property among the report parameters. Noticed that m_promptUser was 0 for the DeviceTypes parameter, while m_promptUser was 1 for all other parameters.

 

I decided to use procdump to log exception messages from the ReportingServicesService.exe process with:

procdump.exe -f "" -l -e 1 ReportingServicesService.exe

 

Reloaded the report to recreate the error.

Part of the result was:

[07:10:37] Exception: E0434F4D.Microsoft.ReportingServices.Diagnostics.Utilities.ReadOnlyReportParameterException ("The report parameter 'DeviceTypes' is read-only and cannot be modified.")
[07:10:37] Exception: E0434F4D.Microsoft.ReportingServices.Diagnostics.Utilities.RSException ("The report parameter 'DeviceTypes' is read-only and cannot be modified.")

 

Then loaded all DLL files from SSRS into ILSpy from:

C:\Program Files\Microsoft SQL Server\MSRS11.MSSQLSERVER\Reporting Services\ReportServer\bin

 

Searched for the ReadOnlyReportParameterException class in ILSpy.

Found it and noticed that it was apparently only used by:

Microsoft.ReportingServices.ReportProcessing.ParameterInfoCollection.Combine(...)

 

Read the decompiled code for the above method and noticed this part:

if (checkReadOnly && !parameterInfo.PromptUser)
{
  ParameterInfoCollection.ThrowReadOnlyParameterException(parameterInfo.Name, isSharedDataSetParameter);
}

Apparently the value of parameterInfo.PromptUser determined the read-only status.

 

I decided to examine the XML for the RDL report and noticed that the DeviceTypes report parameter did not have a Prompt section.

I added this:

<Prompt>DeviceTypes</Prompt>

Then uploaded the new version of the report (by overwriting).

However this did not seem to have any immediate effect, the error still occured…

 

I spent some time examining various other ideas and internals of SSRS.

 

Then I got an idea: I decided to delete the problematic report and then recreate the modified version with a Prompt section.

This fixed the problem! The report now worked in all cases, no matter which parameters were set.

This behavior was consistent across 2 SSRS instances.

Conclusion

It seems that read-only status for a report parameter is derived from the presence of a <Prompt>Description</Prompt> section.

However this status is not updated if the report is overwritten, it has to be deleted and then recreated…

 

Due to the way ReportViewerForMvc.dll is implemented all report parameters are copied from the initial instance to another instance of ReportViewer.

This means that report parameters can’t be read-only, so <Prompt>Description</Prompt> should always be specified for all report parameters, when using ReportViewer for MVC.

Debugging blank SSRS report caused by SecurityException

I was testing reports for SQL Server Reporting Services on a new computer, but the results were blank and no relevant error messages were logged by SSRS.

 

Investigated by using procdump to log exception messages from the IIS worker process with:

procdump.exe -f "" -l -e 1 ReportingServicesService.exe

Part of the result was:

[13:22:13] Exception: E0434F4D.System.Security.SecurityException ("Request for the permission of type 'System.Net.WebPermission, System, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089' failed.")
[13:22:13] Exception: E0434F4D.System.Security.SecurityException ("Request for the permission of type 'System.Security.Permissions.SecurityPermission, mscorlib, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089' failed.")

 

I knew that the reports performed HTTP/web service calls from VB code, so I had to modify rssrvpolicy.config to allow this.

It can be done by:

1. Appending a named permission set with both execution and web permission like:

<PermissionSet class="NamedPermissionSet"
version="1"
Name="ExecutionAndWebPermission"
Description="A special permission set that grants execution and web permission for specific site(s).">
  <IPermission class="SecurityPermission" version="1" Flags="Execution" />
  <IPermission class="WebPermission" version="1">
    <ConnectAccess>
      <URI uri="http://localhost/Test/ReportingUtilityService.svc"/>
    </ConnectAccess>
  </IPermission>
</PermissionSet>

 

2. Modifying the CodeGroup with Name=”Report_Expressions_Default_Permissions”

From:

PermissionSetName="Execution"

To:

PermissionSetName="ExecutionAndWebPermission"

 

3. Restarting Reporting Services.

 

I decided to verify that this was the issue before performing the changes.

Therefore I attached WinDbg (x64) to ReportingServicesService.exe and configured event filters to break on CLR exceptions.

 

Refreshed the report again and the first exception was thrown.

Checked the exception with:

!PrintException

 

The result was a very detailed (and useful) message, that confirmed the suspected issue:

Exception object: 0000000460198410
Exception type: System.Security.SecurityException
Message: Request for the permission of type 'System.Net.WebPermission, System, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089' failed.
InnerException: <none>
StackTrace (generated):
<none>
StackTraceString: <none>
HResult: 8013150a
SecurityException Message:
The action that failed was:
Demand
The type of the first permission that failed was:
System.Net.WebPermission
The first permission that failed was:
<IPermission class="System.Net.WebPermission, System, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"
version="1">
<ConnectAccess>
<URI uri="http://localhost/Test/ReportingUtilityService\.svc"/>
</ConnectAccess>
</IPermission>

The demand was for:
<IPermission class="System.Net.WebPermission, System, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"
version="1">
<ConnectAccess>
<URI uri="http://localhost/Test/ReportingUtilityService\.svc"/>
</ConnectAccess>
</IPermission>

The granted set of the failing assembly was:
<PermissionSet class="System.Security.PermissionSet"
version="1">
<IPermission class="System.Security.Permissions.SecurityPermission, mscorlib, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"
version="1"
Flags="Execution"/>
<IPermission class="System.Security.Permissions.StrongNameIdentityPermission, mscorlib, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"
version="1"
PublicKeyBlob="..."
Name="expression_host_..."
AssemblyVersion="1.0.0.0"/>
<IPermission class="System.Security.Permissions.ZoneIdentityPermission, mscorlib, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"
version="1"
Zone="MyComputer"/>
</PermissionSet>

The assembly or AppDomain that failed was:
expression_host_..., Version=12.2.6020.0, Culture=neutral, PublicKeyToken=null
The method that caused the failure was:
System.Object CallWebService(System.String, System.String)
The Zone of the assembly that failed was:
MyComputer

 

After modifying rssrvpolicy.config and restarting Reporting Services the issue was resolved.

Debugging endless loop caused by missing SignalR performance counters

I recently experienced a problem with an IIS website:

After changing and building code, the site would hang indefinitely at startup.

It seemed like an endless loop, because CPU activity was high.

 

One workaround was to reset IIS with:

iisreset

Then the site became functional until the next change + build.

 

However I decided to find the cause of the problem and a real solution.

 

I checked the process activity for w3wp.exe with Process Monitor:

These parts of the registry were continually accessed:

process_monitor_w3wp_registry_signalr_performance

HKLM
HKLM\SYSTEM\CurrentControlSet\Services\SignalR\Performance
HKLM\System\CurrentControlSet\Services\SignalR\Performance

 

At this point I should have checked if the system actually had SignalR performance counters installed…

 

However I decided to examine the situation further by attaching WinDbg (x64) to the w3wp.exe process.

 

Because I was suspecting an endless loop I decided to check the thread CPU activity with:

!runaway

Part of the result was:

User Mode Time
Thread       Time
6:26cc      0 days 0:05:39.750
15:2e00      0 days 0:00:11.187
13:27b0      0 days 0:00:06.718

 

Thread 6 was definitely the one with the most activity, so I switched to that with:

~6s

 

Then checked the .NET call stack with:

!clrstack

Part of the result was:

OS Thread Id: 0x26cc (6)
Child SP               IP Call Site
000000f1a0c6b158 00007ff98b60b1a6 [HelperMethodFrame: 000000f1a0c6b158] System.Security.SecurityRuntime.GetSecurityObjectForFrame(System.Threading.StackCrawlMark ByRef, Boolean)
000000f1a0c6b260 00007ff98a4b584c System.Security.SecurityRuntime.RevertAssert(System.Threading.StackCrawlMark ByRef)
000000f1a0c6b290 00007ff98a4b9e3d System.Security.PermissionSet.RevertAssert()
000000f1a0c6b2c0 00007ff989cd5e6d System.Diagnostics.PerformanceCounterLib.FindCustomCategory(System.String, System.Diagnostics.PerformanceCounterCategoryType ByRef)
000000f1a0c6b310 00007ff989cd5db8 System.Diagnostics.PerformanceCounterLib.FindCustomCategory(System.String, System.Diagnostics.PerformanceCounterCategoryType ByRef)
000000f1a0c6b380 00007ff989cd735c System.Diagnostics.PerformanceCounterLib.IsCustomCategory(System.String, System.String)
000000f1a0c6b3e0 00007ff989cdd1af System.Diagnostics.PerformanceCounter.InitializeImpl()
000000f1a0c6b450 00007ff989cdc35f System.Diagnostics.PerformanceCounter..ctor(System.String, System.String, System.String, Boolean)
000000f1a0c6b4a0 00007ff92f81b7b5 Microsoft.AspNet.SignalR.Infrastructure.PerformanceCounterManager.LoadCounter(System.String, System.String, System.String, Boolean)
000000f1a0c6b550 00007ff92f81b606 Microsoft.AspNet.SignalR.Infrastructure.PerformanceCounterManager.SetCounterProperties()
000000f1a0c6b5c0 00007ff92f81b2d7 Microsoft.AspNet.SignalR.Infrastructure.PerformanceCounterManager.Initialize(System.String, System.Threading.CancellationToken)
000000f1a0c6b640 00007ff92f81a23b Microsoft.AspNet.SignalR.Hosting.HostDependencyResolverExtensions.InitializeHost(Microsoft.AspNet.SignalR.IDependencyResolver, System.String, System.Threading.CancellationToken)
000000f1a0c6b680 00007ff92f81859b Owin.OwinExtensions.UseSignalRMiddleware[[System.__Canon, mscorlib]](Owin.IAppBuilder, System.Object[])
000000f1a0c6b770 00007ff92f818147 Owin.OwinExtensions+c__DisplayClass1.b__0(Owin.IAppBuilder)
000000f1a0c6b7b0 00007ff92f816c22 Owin.MapExtensions.Map(Owin.IAppBuilder, Microsoft.Owin.PathString, System.Action`1)
000000f1a0c6b800 00007ff92f816993 Owin.MapExtensions.Map(Owin.IAppBuilder, System.String, System.Action`1)
000000f1a0c6b850 00007ff92f816814 Owin.OwinExtensions.MapSignalR(Owin.IAppBuilder)

 

After continuing and breaking execution a few times I was seeing similar call stacks.

I needed to identify the endless loop.

 

Experimented by setting breakpoints from the above call stack.

 

Set a single breakpoint at:

00007ff989cd735c System.Diagnostics.PerformanceCounterLib.IsCustomCategory(System.String, System.String)

With:

bc *
bp 00007ff989cd735c

Result: Breakpoint was continually hit.

 

Set a single breakpoint at:

00007ff989cdd1af System.Diagnostics.PerformanceCounter.InitializeImpl()

With:

bc *
bp 00007ff989cdd1af

Result: breakpoint was not hit within 1 minute.

 

This indicated that the endless loop was in:

System.Diagnostics.PerformanceCounterLib.IsCustomCategory(System.String, System.String)

 

I used ILSpy to decompile the method and noticed this loop:

for (CultureInfo cultureInfo = CultureInfo.CurrentCulture; cultureInfo != CultureInfo.InvariantCulture; cultureInfo = cultureInfo.Parent)
{
    performanceCounterLib = PerformanceCounterLib.GetPerformanceCounterLib(machine, cultureInfo);
    if (performanceCounterLib.IsCustomCategory(category))
    {
        return true;
    }
}

 

I noted that the loop condition likely continued to be true.

And that performanceCounterLib.IsCustomCategory(category) most likely continued to be false.

This was likely the endless loop I was looking for.

 

I set an additional breakpoint with:

!bpmd   System.dll   System.Diagnostics.PerformanceCounterLib.IsCustomCategory

Messages from WinDbg:

Found 2 methods in module 00007ff989421000...
MethodDesc = 00007ff989524020
MethodDesc = 00007ff989524040
Setting breakpoint: bp 00007FF989CD73EB [System.Diagnostics.PerformanceCounterLib.IsCustomCategory(System.String)]
Setting breakpoint: bp 00007FF989CD727A [System.Diagnostics.PerformanceCounterLib.IsCustomCategory(System.String, System.String)]
Adding pending breakpoints...

 

However when continuing only breakpoint 0 was hit, further indicating that the endless loop occured inside PerformanceCounterLib.IsCustomCategory(…).

 

Decided to look for the CultureInfo object in the loop.

 

Checked the call stack including locals and parameters with:

clrstack -a

Top part of the call stack was:

OS Thread Id: 0x26cc (6)
Child SP               IP Call Site
000000f1a0c6b380 00007ff989cd735c System.Diagnostics.PerformanceCounterLib.IsCustomCategory(System.String, System.String)
PARAMETERS:
machine (<CLR reg>) = 0x000000f4a155df18
category (<CLR reg>) = 0x000000f4a1584228
LOCALS:
<CLR reg> = 0x000000f1a158f130

 

Examined the local reference with:

!DumpObj /d 000000f1a158f130

Part of the result was:

Name:        System.Globalization.CultureInfo
MethodTable: 00007ff98a701420
EEClass:     00007ff98a111e48
Size:        128(0x80) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT    Field   Offset                 Type VT     Attr            Value Name
00007ff98a6ed6f8  4001208       74       System.Boolean  1 instance                1 m_isReadOnly
00007ff98a6e0698  4001209        8 ...ation.CompareInfo  0 instance 000000f1a1593b40 compareInfo
...
...
00007ff98a6ed6f8  4001212       75       System.Boolean  1 instance                0 m_isInherited
00007ff98a6ed6f8  4001213       76       System.Boolean  1 instance                1 m_isSafeCrossDomain
00007ff98a7003d0  4001214       70         System.Int32  1 instance                2 m_createdDomainID
00007ff98a701420  4001215       40 ...ation.CultureInfo  0 instance 0000000000000000 m_consoleFallbackCulture
00007ff98a6fda88  4001216       48        System.String  0 instance 000000f1a1551420 m_name
00007ff98a6fda88  4001217       50        System.String  0 instance 000000f1a1551420 m_nonSortName
00007ff98a6fda88  4001218       58        System.String  0 instance 000000f1a1551420 m_sortName
00007ff98a701420  4001223       60 ...ation.CultureInfo  0 instance 000000f1a158f130 m_parent
...
...

 

Noticed that m_parent pointed to itself.

 

Cleared all breakpoints with:

bc *

Set another breakpoint with:

!bpmd   System.dll   System.Diagnostics.PerformanceCounterLib.FindCustomCategory

 

This breakpoint was continually hit as expected.

 

Then checked the PerformanceCounterLib.FindCustomCategory(…) method with ILSpy.

Noticed that the method accessed the registry and that the return value depended on what was found.

 

Searched online for: HKLM\System\CurrentControlSet\Services\SignalR\Performance

And found this article: http://www.asp.net/signalr/overview/performance/signalr-performance

 

Based on the article I decided to install SignalR performance counters by:

1. Installing the NuGet package: signalr.utils

2. Then installing the SignalR performance counters with:

SignalR.exe ipc

 

This was the solution!

After continuing execution, the loop ended and site initialization continued normally.

(The issue occured with version 2.2.1 of SignalR and version 4.6.1 of .NET, but targeting version 4.5)

Conclusion

A site using SignalR can hang with an endless loop when initializing, if the SignalR performance counters are not installed.

A combination of tools like Process Monitor, ILSpy and WinDbg can be used to discover the cause of an endless loop in 3rd party or framework code.

Debugging #Error in SSRS report caused by attempts to convert non-numeric strings

While testing another modified SSRS report I noticed that certain values were not shown, only the message:

#Error

 

Checked the ReportServerService__*.log and ExecutionLog* database views, but they contained no clues about the error.

 

Then I used procdump to log exception messages from ReportingServicesService.exe with:

procdump.exe -f "" -l -e 1 ReportingServicesService.exe

 

Part of the result was:

[13:15:59] Exception: E0434F4D.System.FormatException ("Input string was not in a correct format.")
[13:15:59] Exception: E0434F4D.System.FormatException ("Input string was not in a correct format.")
[13:15:59] Exception: E0434F4D.System.InvalidCastException ("Conversion from string " norm" to type 'Decimal' is not valid.")

 

I extracted and ran the dataset query in SQL Server Management Studio.

Then looked for “norm” strings and found them in a column normally used to store numbers.

Attempts to convert these caused the problem.

 

My solution was to exclude them from the dataset query by adding:

AND ISNUMERIC(ValueString) = 1