The english version in red.
 
Qualche mese fa mi sono imbattuto in un problematica a dir poco “rognosa”; in pratica su un architettura distribuita di circa 60 server (una 50ina di server utilizzavano tecnologia Microsoft, circa 10 con Linux/Solaris e con una componente esterna DB2 su mainframe) che eroga un particolare servizio internet, in maniera del tutto casuale ed apparentemente inspiegabile, diversi web server IIS andavano in errore restituendo a video  "Server too busy" o un messaggio di crash del framework .net; inoltre restartando il servizio IIS dopo qualche ora il problema si ripresentava.
 
It was just a few months ago when I  get  involved in an hard questioning;basically on a 60 servers  distributed architecture  (50 of them were using Microsoft technology abbout 10 were usin’ Linux/Solaris and a DB2 Mainframe System) that offers a particularly internet service, unexpectedly,some of the ISS web servers occurred in error ,sometimes givin’ back the reporting message “server too busy” other ones a “framework crash message”,even if the system was started up again,nothing changed.
Visto  l'errore diedi un occhiata al traffico sui web server  che però non superava (su ognuno) le 500 sessioni concorrenti contro un traffico medio di 700 sessioni concorrenti e picchi di 900-1100;  a quel punto decisi di indagare altrove. Un primo e veloce nestat sui web server mi fece notare che c’erano diverse chiamate tcp in TIME_WAIT verso gli application server in back end e quel punto, dopo un po’ di controlli, decisi di prendere un dump dei processi COM+ che giravano sugli stessi application server.
So I took a look to the webserver traffic but it did not exceed the value of 500 concurrent sessions in spite of 700 medium value and 1100 edges.So using netstat I noticed that there were a lot of time/wait calls to application server in back end so after various checks I had a dump of COM+ processes (runnin’ on the same application server).
Analizzando il dump con WinDbg notati che la maggior parte dei threads erano in attesa di dati (WaitForSingleObject) in particolare da 2 threads (threads 19 e 57 ); successivamente andando ad analizzare i 2 threads notati una cosa molto interessante, ovvero che entrambi i threads stavano  effettuando una chiamata via rete ad un web services interno utilizzando l’ API WinInet (testo in blu) :
WinDbg was a friend in need,because I noticed that many threads were waitin’ for objects (WaitForSingleObject),in particularly 2 threads (19-57).I scanned the threads and I realized that 19-57 threads were using API WinInet for a netcall to an internal web service (text in blue) :
Threads 19
Function

ntdll!KiFastSystemCallRet  
ntdll!NtWaitForSingleObject+c  
mswsock!SockWaitForSingleObject+19d  
mswsock!WSPRecv+203  
ws2_32!WSARecv+77  
wsock32!recv+31  
wininet!ICSocket::Receive_Continue+87  
wininet!ICSocket::Receive_Start+bb  
wininet!CFsm_SocketReceive::RunSM+3b  
wininet!CFsm::Run+39  
wininet!DoFsm+25  
wininet!ICSocket::Receive+3e  
wininet!ICSecureSocket::NegotiateLoop_Fsm+1bc  
wininet!CFsm_NegotiateLoop::RunSM+2e  
wininet!CFsm::Run+39  
wininet!DoFsm+25  
wininet!ICSecureSocket::SSPINegotiateLoop+3b  
wininet!ICSecureSocket::SecureNegotiate_Fsm+2a4  
wininet!CFsm_SecureNegotiate::RunSM+2e  
wininet!CFsm::Run+39  
wininet!DoFsm+25  
wininet!ICSecureSocket::NegotiateSecConnection+2f  
wininet!ICSecureSocket::SecureHandshake_Fsm+db  
wininet!CFsm_SecureHandshake::RunSM+2e  
wininet!CFsm::Run+39  
wininet!DoFsm+25  
wininet!ICSecureSocket::SecureHandshakeWithServer+2c  
wininet!ICSecureSocket::Connect_Fsm+67  
wininet!CFsm_SecureConnect::RunSM+2e  
wininet!CFsm::Run+39  
wininet!DoFsm+25  
wininet!ICSecureSocket::Connect+32  
wininet!HTTP_REQUEST_HANDLE_OBJECT::OpenConnection_Fsm+3b1  
wininet!CFsm_OpenConnection::RunSM+33  
wininet!CFsm::Run+39  
wininet!DoFsm+25  
wininet!HTTP_REQUEST_HANDLE_OBJECT::OpenConnection+2f  
wininet!HTTP_REQUEST_HANDLE_OBJECT::MakeConnection_Fsm+87  
wininet!CFsm_MakeConnection::RunSM+2e  
wininet!CFsm::Run+39  
wininet!DoFsm+25  
wininet!HTTP_REQUEST_HANDLE_OBJECT::SendRequest_Fsm+9b  
wininet!CFsm_SendRequest::RunSM+2e  
wininet!CFsm::Run+39  
wininet!DoFsm+25  
wininet!HTTP_REQUEST_HANDLE_OBJECT::HttpSendRequest_Start+450  
wininet!CFsm_HttpSendRequest::RunSM+59  
wininet!CFsm::Run+39  
wininet!DoFsm+25  
wininet!HttpWrapSendRequest+127  
wininet!HttpSendRequestA+1d  
e24PaymentPipe!Createe24PaymentPipe+c68  
e24PaymentPipe!DllUnregisterServer+5e87  
rpcrt4!Invoke+30  
rpcrt4!NdrStubCall2+299  
rpcrt4!CStdStubBuffer_Invoke+3f
  
oleaut32!CUnivStubWrapper::Invoke+c5  
ole32!SyncStubInvoke+37  
ole32!StubInvoke+a7  
ole32!CCtxComChnl::ContextInvoke+ec  
ole32!MTAInvoke+1°  
ole32!STAInvoke+48  
ole32!AppInvoke+a3  
ole32!ComInvokeWithLockAndIPID+2c5  
ole32!ComInvoke+ca  
ole32!ThreadDispatch+23  
ole32!ThreadWndProc+fe  
user32!InternalCallWinProc+28  
user32!UserCallWinProcCheckWow+151  
user32!DispatchMessageWorker+327  
user32!DispatchMessageW+f  
comsvcs!CSTAQueueLessMessageWork::DoWork+4e  
comsvcs!CSTAThread::DoWork+18  
comsvcs!CSTAThread::ProcessQueueWork+37  
comsvcs!CSTAThread::WorkerLoop+190  
msvcrt!_endthreadex+a3  
kernel32!BaseThreadStart+34 

Socket properties:

Source Port 4066
Destination IP 192.168.X.X
Destination Port    443

In particolare la chiamata al web services veniva effettuata tramite un metodo chiamato “Createe24Payment”  di una dll “e24PaymentPipe.dll”  che girava all’interno dello stesso processo dllhost.exe dell’ applicazione.

Particullary  the webservice call was implemented usin’ a “Createe24Payment”  method   (“e24PaymentPipe.dll”) included in the dllhost.exe of the application.

Tutto  questo creava 2 tipi di problemi :

1- la serializzazione della maggior parte dei threads verso  2 threads che effettuavano le chiamate verso questo web services (in questo caso il thread 19 e il 57)
2- il fatto che, con l’uso della API “Wininet” da parte della “e24PaymentPipe.dll”, le connessioni simultanee verso il webservices interno erano al massimo 2.


So there were two kind of problem:

-        A serialize of threads to two particullary threads that were doing calls to this web service
 (thread n°19,
thread n°57)
-        API WinNet supports two maximum simultaneous connections to webservices

Tutto questo mandava in hang (e alcune volte addirittura in crash) il processo dllhost.exe presente sugli application server COM+ all’interno del quale girava l’applicazione e di conseguenza i web server rimanevano in attesa delle risposte fatte agli  application server. In pratica le chiamate al web services effettuate tramite il metodo “Createe24Payment “ di questa dll rappresentavano una strozzatura visto la natura stessa dell’ API WinInet; questa libreria infatti rappresenta un vecchio modo di programmare utilizzato ancora da alcuni sviluppatori per gestire comunicazioni di rete e poco scalabile; la WinInet infatti fu sviluppata da Microsoft anni fa per l’utilizzo con Internet Explorer.

These were causes of hang and crash of dllhost.exe on COM+ application servers,so web servers were waitin’ for application servers. Webservice calls implemented through “Createe24Payment “ method was a problem due to Api WiInet nature,infact this library is obsolete and it was used for net communications.Api WinNet was implemented by Microsoft just for Internet Explorer.

L’utilizzo della Wininet è una soluzione che in genere non viene utilizzata in ambienti server side proprio perché non riesce a scalare più di 2 connessioni.  Infatti da un veloce netstat fatto sugli application server notai che, in diversi momenti della giornata, le connessioni erano sempre al massimo 2 :
 
WinNet solution is not very popular in the server side,because it doesn’t support more of 2 connections,that’s was confirmed to me by using netstat :
C:\Documents and Settings\gianluca>netstat -n  |find "192.168.X.X"

  TCP    192.168.X.X:4066       192.168.X.X:443      ESTABLISHED

  TCP    192.168.X.X:4087       192.168.X.X:443      ESTABLISHED

 

cosa che non tornava assolutamente conoscendo il traffico del servizio.

A questo punto visto che la problematica era ben circoscritta a questa DLL“e24PaymentPipe.dll”   sviluppata esternamente, chiesi subito di segnalare questa anomalia al fornitore (un azienda americana) che, dopo un pò, ci rilasciò la relativa versione rivista e corretta. L’analisi che feci a suo tempo fu effettuata su un campione di 3 dump presi in giorni differenti e, fortunatamente , in tutti e 3 casi Il problema era molto evidente.
 
Quindi occhio che se utilizzate la dll “e24PaymentPipe.dll”   o comunque qualche sviluppatore ha deciso di gestire le comunicazione server 2 server nel proprio codice utilizzando la WinInet potreste incappare nella stessa problematica.
 

So “e24PaymentPipe.dll” was the problem and I reported it to the American developer company,in the end they gave us the right new version. Tests were did with Dump on three different days and in each day the problem was noticeable
So be aware if you’re using “e24PaymentPipe.dll,you can get in hard troubles.
Bye.
 
Di seguito alcuni articoli e testi utili ad approfondire la problematica ed analizzare dump :
If you want more:
Articoli relativi alla WinInet :
 
“Using WinInet in server side applications to make network calls is not recommended since Wininet was designed for client side applications in mind. For example, Wininet limits the number of simultaneous connections to a web server to not more than 2. This can have a serious performance impact causing hang like symptoms.”
 
 
 
 
Debugging Tools for Windows :
 
 
 
Testi utili :
 
Advanced Windows Debugging - Addison-Wesley Microsoft Technology Series
Mario Hewardt and Daniel Pravat
 
Windows® Internals, Fifth Edition – Microsoft Press
Mark E. Russinovich and David A. Solomon with Alex Ionescu