Wednesday, September 30, 2009

WCF Service application hangs

Ad Hoc Transfer (AHT) is a WCF ASP .NET application. When performing multiple downloads -- about 10 files from the FireFox, sometimes a transfer would pause ~30 seconds or more before download begins or in the middle of the download.

There could be various reasons for a WCF service application to hang.

From the size of memory dump, there was nothing out of ordinary, so the hang might not be related to the memory issue.

One possible reason could be WCF connection pool exhausion described in the post -- Troubleshooting WCF Service application hangs.

0:033> !dumpheap -type ServiceThrottle -short
02ebe87c
02f2b6e0
02f2d4ac


0:033> !do 02ebe87c
Name: System.ServiceModel.Dispatcher.ServiceThrottle
MethodTable: 0f1ea548
EEClass: 0ee51f20
Size: 36(0x24) bytes
(C:\WINDOWS\assembly\GAC_MSIL\System.ServiceModel\3.0.0.0__b77a5c561934e089\System.ServiceModel.dll)
Fields:
MT Field Offset Type VT Attr Value Name
0f1ea58c 400371d 4 ...cher.FlowThrottle 0 instance 02ebe93c calls ; maxConcurrentCalls
0f1ea58c 400371e 8 ...cher.FlowThrottle 0 instance 02ebea34 sessions ; maxConcurrentSessions
0f1a6020 400371f c ...her.QuotaThrottle 0 instance 00000000 dynamic
0f1ea58c 4003720 10 ...cher.FlowThrottle 0 instance 00000000 instanceContexts
0f1e9bb0 4003721 14 ...l.ServiceHostBase 0 instance 02ebe674 host
793044cc 4003722 1c System.Boolean 1 instance 1 isActive
7933061c 4003723 18 System.Object 0 instance 02ebe8a0 thisLock

0:033> !do 02ebea34
Name: System.ServiceModel.Dispatcher.FlowThrottle
MethodTable: 0f1ea58c
EEClass: 0ee51f8c
Size: 36(0x24) bytes
(C:\WINDOWS\assembly\GAC_MSIL\System.ServiceModel\3.0.0.0__b77a5c561934e089\System.ServiceModel.dll)
Fields:
MT Field Offset Type VT Attr Value Name
79332c4c 40034f5 18 System.Int32 1 instance 10 capacity
79332c4c 40034f6 1c System.Int32 1 instance 8 count
7933061c 40034f7 4 System.Object 0 instance 02ebea58 mutex
7931e960 40034f8 8 ...ding.WaitCallback 0 instance 02ebea14 release
00000000 40034f9 c 0 instance 02ebea64 waiters
79330a00 40034fa 10 System.String 0 instance 02ebe99c propertyName
79330a00 40034fb 14 System.String 0 instance 02ebe9d8 configName

0:033> !do 02ebe674
Name: System.ServiceModel.ServiceHost
MethodTable: 0f1ef2b4
EEClass: 0ee55db4
Size: 140(0x8c) bytes
(C:\WINDOWS\assembly\GAC_MSIL\System.ServiceModel\3.0.0.0__b77a5c561934e089\System.ServiceModel.dll)
Fields:
MT Field Offset Type VT Attr Value Name
...
System.Object 0 instance 00000000 singletonInstance 79331840 40032cd 7c System.Type 0 instance 02ebe660 serviceType
0f1ea7dc 40032ce 80 ...ontractCollection 0 instance 02ebed1c reflectedContracts
7932c8e0 40032cf 84 System.IDisposable 0 instance 00000000 disposableInstance

0:033> !do 02ebe660
Name: System.RuntimeType
MethodTable: 79331b80
EEClass: 790eddd8
Size: 20(0x14) bytes
Type MethodTable: 10fe7104
Type Name: WSFTPWebService.WSFTPWebService
(C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)
Fields:
...

Since the capacity is still larger than the count, so WCF connection pool exhaustion should not be the reason.

Since the hang only happens in multiple downloads, another possible reason could be the thread synchronization issue. From the code, it seems that in multiple downloads, the same WCF proxy is used for all the download requests among different threads. The MSDN site does not mention that the ClientBase class is thread-safe. However, in the code, the thread-safe assumption has been made and no calls to WCF proxy API have been synchronized among threads. So the possible fix would be to synchronize the call to WCF proxy API.

Friday, September 25, 2009

Counterfactual Debugging: Data Ordering

The post -- Counterfactual Debugging: Data Ordering by Dmitry Vostokov provides an interesting exercise on how to understand Dereference Fixpoints issue from the assembly code level.

Thursday, September 24, 2009

Mixed DLL Loading Problem

The post -- NET Hang Case Study: The GC-Loader Lock Deadlock (a story of mixed mode dlls) by Tess Ferrandez provides a good study case for mixed dll loading problem. Besides, it also shows some useful WinDBG tips, such as how to detect the deadlock caused by the mixed dll, how to tell whether GC has been triggered and which thread triggered it.

Monday, September 21, 2009

ETW Introduction and Overview

With the advent of Vista and Windows 7, ETW (Event Tracing for Windows) would become more and more widely used in debugging and instrumenting the applications. The following links provide some useful information regarding to what ETW is and how to enable ETW for troubleshooting,
  1. ETW Introduction and Overview
  2. Exploring and Decoding ETW Providers using Event Log Channels.

Thursday, September 17, 2009

Enable WCF debugging trace and message logs

WCF debugging trace and message logs are sometimes very crucial in resolving WCF related issues. To enable the trace and message logs, the application configuration would be modified as following,
  1. within [system.serviceModel] and [/system.serviceModel] tags, add [diagnostics] [messageLogging maxMessagesToLog="30000"
    logEntireMessage="true"
    logMessagesAtServiceLevel="true"
    logMalformedMessages="true"
    logMessagesAtTransportLevel="true"]
    [/messageLogging]
    [/diagnostics]
  2. within [configuration] and [/configuration] tags, add [system.diagnostics]
    [sources]
    [source name="System.ServiceModel" switchValue="Verbose, ActivityTracing" propagateActivity="true" ]
    [listeners]
    [add name="xml" /]
    [/listeners]
    [/source]
    [source name="System.ServiceModel.MessageLogging" switchValue="Verbose"]
    [listeners]
    [add name="xml" /]
    [/listeners]
    [/source]
    [/sources]
    [sharedListeners]
    [add name="xml" type="System.Diagnostics.XmlWriterTraceListener" initializeData="WCFTracing.svclog" /]
    [/sharedListeners]
    [trace autoflush="true" /]
    [/system.diagnostics]
After modifying the configuration file, make sure the process hosting the WCF proxy or service has the write permission to the folder where the trace and message log file will reside.

After the trace and message log file is generated, the Service Trace Viewer could be used to analyze the trace and log file.

Here is a tutorial on how to use the Service Trace Viewer.

Tuesday, September 1, 2009

Function keys for a command-prompt ninja

The following function keys might improve the usability of the command prompt.

F1 retypes the previous command one character at a time
F2 brings up a dialog and asks “Enter the char to copy up to:”
F3 retypes the last command in full
F4 brings up a dialog and asks “Enter char to delete up to:”
F5 as for F3
F6 Print EOF character (Ctrl+Z)
F7 brings up a dialog of all the recent command history
F8 brings up each of the most recent commands, one at a time
F9 brings up a dialog and asks “Enter command number:”