I had an interesting case recently. We discovered a hang in ASP.Net application caused by string.IndexOf method.
Problem description:
Frequently, this ASP.Net application would hang and the IIS worker process needs to be restarted for the application to function correctly. This happens even when the load is low.
Troubleshooting:
Same as before, we captured hang dumps for investigation. From the dump, we could see that almost requests were blocked by GC. Here is a sample calling stack.
ntdll!ZwWaitForSingleObject
kernel32!WaitForSingleObjectEx
mscorwks!CLREventWaitHelper
mscorwks!CLREvent::WaitEx
mscorwks!SVR::gc_heap::wait_for_gc_done
mscorwks!SVR::gc_heap::try_allocate_more_space
…
Some customer code here
…
System_Web_ni!System.Web.Hosting.ISAPIRuntime.ProcessRequest(IntPtr, Int32)
However, if we look at the GC threads, they were not in GC status at all. Then, we found that thread 48 disabled PreEmptive GC, not allowing GC to suspend it. The GC had to wait this thread to finish.
PreEmptive Lock
ID OSID ThreadOBJ State GC GC Alloc Context Domain Count APT Exception
24 1 1e48 000000000015f280 1808220 Enabled 00000000902c9e50:00000000902c9e70 00000000001bbbe0 1 MTA (Threadpool Worker)
……………………
48 8 2070 00000000091043e0 180b222 Disabled 0000000000000000:0000000000000000 00000000001bbbe0 1 MTA (Threadpool Worker)
………………..
Thread 48 was replacing strings.
mscorwks!COMStringBuffer::LocalIndexOfString
mscorwks!COMString::ReplaceString
MyAssembly!MyFunction.RemoveSpaces(System.String)
And thread 48 ate most of the CPU.
0:048> !runaway
User Mode Time
Thread Time
48:2070 0 days 0:01:02.468
52:20b8 0 days 0:00:16.359
34:1ef0 0 days 0:00:16.171
….
If we dump out the string, it is really small string which contains ~200 chars only. Replacing something inside this string should not take such long time. The code running looks like below, it tries to replace all continuous spaces with single space. Actually, there were no continuous spaces in the string already. In addition, we don’t need the while loop here cause String.Replace returns a new string in which all occurrences of a specified string in the current instance are replaced with another specified string. At this moment, I suspect that the while loop was not able to terminate as expected.
if ((str != null) && (str.Length != 0))
{
while (str.IndexOf(" ") != -1) // as long as there are two continuous spaces
{
str = str.Replace(" ", " "); //replace it with single space
}
Look at the hex value of this string, I found something abnormal. Inside the string, there is one special char 0x fffd.
0:048> dd 801fc6d8
00000000`801fc6d8 0041004d 00200058 0020fffd 00680054
Read more: AsiaTech: Learning by Practice
Problem description:
Frequently, this ASP.Net application would hang and the IIS worker process needs to be restarted for the application to function correctly. This happens even when the load is low.
Troubleshooting:
Same as before, we captured hang dumps for investigation. From the dump, we could see that almost requests were blocked by GC. Here is a sample calling stack.
ntdll!ZwWaitForSingleObject
kernel32!WaitForSingleObjectEx
mscorwks!CLREventWaitHelper
mscorwks!CLREvent::WaitEx
mscorwks!SVR::gc_heap::wait_for_gc_done
mscorwks!SVR::gc_heap::try_allocate_more_space
…
Some customer code here
…
System_Web_ni!System.Web.Hosting.ISAPIRuntime.ProcessRequest(IntPtr, Int32)
However, if we look at the GC threads, they were not in GC status at all. Then, we found that thread 48 disabled PreEmptive GC, not allowing GC to suspend it. The GC had to wait this thread to finish.
PreEmptive Lock
ID OSID ThreadOBJ State GC GC Alloc Context Domain Count APT Exception
24 1 1e48 000000000015f280 1808220 Enabled 00000000902c9e50:00000000902c9e70 00000000001bbbe0 1 MTA (Threadpool Worker)
……………………
48 8 2070 00000000091043e0 180b222 Disabled 0000000000000000:0000000000000000 00000000001bbbe0 1 MTA (Threadpool Worker)
………………..
Thread 48 was replacing strings.
mscorwks!COMStringBuffer::LocalIndexOfString
mscorwks!COMString::ReplaceString
MyAssembly!MyFunction.RemoveSpaces(System.String)
And thread 48 ate most of the CPU.
0:048> !runaway
User Mode Time
Thread Time
48:2070 0 days 0:01:02.468
52:20b8 0 days 0:00:16.359
34:1ef0 0 days 0:00:16.171
….
If we dump out the string, it is really small string which contains ~200 chars only. Replacing something inside this string should not take such long time. The code running looks like below, it tries to replace all continuous spaces with single space. Actually, there were no continuous spaces in the string already. In addition, we don’t need the while loop here cause String.Replace returns a new string in which all occurrences of a specified string in the current instance are replaced with another specified string. At this moment, I suspect that the while loop was not able to terminate as expected.
if ((str != null) && (str.Length != 0))
{
while (str.IndexOf(" ") != -1) // as long as there are two continuous spaces
{
str = str.Replace(" ", " "); //replace it with single space
}
Look at the hex value of this string, I found something abnormal. Inside the string, there is one special char 0x fffd.
0:048> dd 801fc6d8
00000000`801fc6d8 0041004d 00200058 0020fffd 00680054
Read more: AsiaTech: Learning by Practice