la visión de un ingeniero de campo

Alto consumo de memoria y cursores de datos

pmackay — Thu, 20 Mar 2008 21:22:00 GMT

Sorpresas te llevas en la vida, siempre. A pesar de lo que parezca, hoy no ando sermoneador ni nada por el estilo. Es sólo que no se me ocurre como comenzar este post así que escribo lo primero que se me ocurre . Total, lo interesante viene ahora.

Viaje de emergencia, aplicación ASP con excepciones por falta de memoria (Out Of Memory), servicio interrumpido.
Resumen: problemas... un poco de entretención para unos meses muy aburridos.

Síntomas

Como mencionaba, tenemos una aplicación ASP que de vez en cuando lanza excepciones por falta de memoria, mas conocidos como error 500 ASP 147. Obviamente con el reinicio del proceso, todo vuelve a la normalidad, pero luego de la calma, llega la tormenta.

Como ya es costumbre, se capturaron algunos dumps de memoria cuando se estaba produciendo el error y se analizaron. Los resultados fueron sorprendentes, los que pasan a ser mostrados ahora.

Lo primero muy interesante es que el dump apenas sobrepasaba los 100 megabytes. Un dump contiene, sin entrar en grandes detalles, los datos privados del proceso y las librerías cargadas entre otras cosas. Si son un poco más de 100 megabytes, ¿cómo es posible que haya falta de memoria?. El administrador de tareas confirmaba que el proceso estaba utilizando algo más de 100 megabytes en working set y un poco menos en memoria privada

¿Entonces?

Debugging Tool For Windows entra a ayudarnos. Revisando el estado de cada heap, nos encontramos con lo que muestra el bloque de más abajo. Hay muchas columnas y muchos datos, pero fijemos la atención en las columnas que hacen mención a la memoria reservada y comprometida.

Recordemos que en un sistema operativo Windows, la memoria puede estar en tres estados: libre, reservada y comprometida. Para que una aplicación la pueda utilizar necesita primero reservarla, y luego comprometerla. Después de usarla, la debe des-comprometer (fea palabra, lo sé) y luego liberar (des-reservar, también es fea).

  Heap     Flags   Reserv  Commit  Virt   Free  List   UCR  Virt  Lock  Fast 
                    (k)     (k)    (k)     (k) length      blocks cont. heap 
-----------------------------------------------------------------------------
00080000 00000002   15360  13424  14512   2362   514   137    0     9d   L  
    External fragmentation  17 % (514 free blocks)
00180000 00008000      64     12     12     10     1     1    0      0      
002b0000 00001002   22080   9560  17536   1629   231   124   25     5b   L  
    External fragmentation  17 % (231 free blocks)
    Virtual address fragmentation  45 % (124 uncommited ranges)
00550000 00000002    1024     20     20      2     1     1    0      0   L  
00690000 00001002     256     32     32      2     1     1    0      0   L  
01bb0000 00001002     256     12     12      4     1     1    0      0   L  
01bf0000 00001002   39872  11200  29608    722    62    60    0      7   LFH
01c30000 00001002     256     12     12      4     1     1    0      0   L  
01c70000 00001002     256     12     12      4     1     1    0      0   L  
<recortado>
02630000 00001002     256     12     12      2     1     1    0      0   L  
02670000 00001002     256     12     12      4     1     1    0      0   L  
02730000 00001002      64     32     32      4     1     1    0      0   L  
02a20000 00001002    3328   2084   2396    110    23    16    0      0   LFH
02a60000 00001002   19968   7164   8076     35     6    10   21      0   LFH
02f60000 00001003    1280   1152   1152      2     1     1    0    bad      
03470000 00001003    1280    512    512      1     1     1    0    bad      
034b0000 00001003    1280    524    524      2     1     1    0    bad      
034f0000 00001003     256     96     96      0     0     1    0    bad      
03730000 00001003    1280    356    356      1     1     1    0    bad      
03970000 00001003    1280    264    264      0     0     1    0    bad      
049b0000 00001003     256    204    204      3     1     1    0    bad      
049f0000 00001003  130304    128    300     63    11    12    0    bad      
04a30000 00001003  441600    112    188    101    11    12    0    bad  <-éste
04a70000 00001003  167204    352    424    264    49    67    0    bad      
04ab0000 00001003  465716    128  36532    103    20    27    0    bad      
04af0000 00001003  469708    164   1696     92    13    32    0    bad      
04b30000 00001003   46312    324    328    254    47    65    0    bad      
04b70000 00001003    9700    372    372    348    62    64    0    bad      
039c0000 00001002      64     16     16      2     1     1    0      0   L  
04c30000 00001003     256    148    148     92    36     1    0    bad      
<recortado>

En el listado anterior, vemos que hay un par de heaps que han reservado (memoria en estado reservado) más de 400 megabytes, pero que sólo están utilizando (memoria en estado comprometido) un poco más de 100 kilobytes. Entre varios, el heap 04a30000, indicado más arriba en negrilla y con la palabra "<- éste", es uno de los más grandes.

Veamos el detalle de este heap y sus segmentos, listados a continuación.

Index   Address  Name      Debugging options enabled
111:   04a30000 
    Segment at 04a30000 to 04a70000 (00010000 bytes committed)
    Segment at 0f940000 to 0fa40000 (00003000 bytes committed)
    Segment at 0fa40000 to 0fc40000 (00001000 bytes committed)
    Segment at 100d0000 to 104d0000 (00001000 bytes committed)
    Segment at 104d0000 to 10cd0000 (00001000 bytes committed)
    Segment at 10cd0000 to 11cd0000 (00001000 bytes committed)
    Segment at 11cd0000 to 13cd0000 (00001000 bytes committed)
    Segment at 13cd0000 to 17cd0000 (00001000 bytes committed)
    Segment at 17ed0000 to 1fed0000 (00001000 bytes committed)
    Segment at 4dbd0000 to 55bd0000 (00001000 bytes committed)
    Segment at 5bb60000 to 5eb60000 (00001000 bytes committed)

Mmm... mmm...mmm...mmm (esto me recuerda una canción de hace unos años), la mayoría de ellos no tiene más de 4 kilobytes usados para bloques de varios megabytes reservados. Si las matemáticas no te ayudan ahora, 1000 en hexadecimal es equivalente a 4096 en decimal.

Análisis de la situación

Recordemos que el manejo de la memoria lo realiza generalmente el sistema operativo aunque algunas aplicaciones pueden utilizar sus propios manejadores de memoria. Desde código ASP (VBScript) o Visual Basic 6.0, como también desde código manejado NO es posible trabajar a este nivel con la memoria. Lo anterior es un problema en un manejador de memoria.

Si no es ASP, VB. 6.0, ¿qué puede ser? (considerando que no hay componentes desarrollados por el cliente en C o C++)

La respuesta la da Debug Diagnostics. Quien creo el heap es "Microsoft Data Access Runtime", es decir, MDAC. Revisando la versión instalada, comprobamos que es la última con Windows Server 2003 SP2. El camino se pone difícil.

Investigación y resolución

Involucrando a las personas adecuadas, aprendimos que este comportamiento es considerado "esperado" cuando se cumplen las siguientes condiciones:

Se utilizan recordset del lado del cliente (client-side cursor)
Se obtienen muchos datos, muchos datos de una tabla

Ok ¿client-side cursor?¿que significa "muchos datos"?

"Cliente" es quien consulta la base de datos, que para este caso es IIS/ASP. En ese caso, los datos se llevan al cliente para ser luego procesados.

Después de investigar en el código, se encontró que una consulta estaba retornando más de 2 millones de registros. Eso es mucho

Reproducción

Decidido a demostrarlo, procedí a hacer unas pruebas con el siguiente código en mi "servidor."

Y le agregué a mi tabla algo así como 4 millones de registros.

Después de varias ejecuciones, tanto en paralelo como en serie, los contadores de memoria reservada, comprometida y utilización de procesador mostraron esto:

Se puede ver que la memoria comprometida (verde) llegó como mucho hasta 300 megabytes, pero la memoria reservada (roja) aumentó sin mostrar intención de disminuir, llegando casi hasta 900 megabytes.

¿Cuál es la explicación a que no reutilice la memoria reservada y siga reservando más? Al menos yo no tengo la respuesta.

¿Que sucede cuando llegue a 2 gigabytes? excepciones por falta de memoria (Out Of Memory)

Conclusiones

1.- Nunca desplegar "muchos" registros en una página. Mejor aún, nunca pedir muchos registros a la base de datos.

2.- Utilicen server-side cursors. Hagan la prueba con el mismo código y comparen los resultados.

Saludos,
Patrick

Internet Explorer se cuelga por algunos segundos

pmackay — Thu, 10 Jan 2008 09:15:00 GMT

A diferencia de los otros casos descritos, en esta oportunidad quien estaba en problemas era yo mismo, con un síntoma que seguro a alguno de ustedes le ha ocurrido antes. Veamos de que se trata.

Síntomas

Cada vez que abría una nueva instancia de Internet Explorer, como también al abrir una nueva pestaña de una instancia que ya llevase corriendo, algunas veces se demoraba una buena cantidad de segundos (entre 10 y 15 segundos) en quedar disponible para poder usarla. Si bien el proceso se creaba y se pintaba rápidamente (menos de 1 segundo), quedaba como "esperando" algo.

Esta es una ventana del navegador en ese estado intermedio de espera.

Una vez que la espera termina, el navegador funciona como se espera. Sin embargo, si se deja pasar un tiempo sin hacer nada en la ventana de éste, al tratar de usarlo nuevamente, ya sea creando un tabulador nuevo o incluso cerrando el proceso, otra vez debo esperar una cantidad de segundos similar a la anterior.

En resumen, mientras esté usando la ventana (haciendo clics), todo bien. Dejo de usarla un rato, hay que esperar para que reaccione.

Intención de detección del problema

Aunque sabía que no sería nada fácil encontrar el problema, hice mi intento usando Debugging Tool For Windows y atachándome al proceso una vez creara un nuevo tab mientras estaba "esperando".

Un listado de los threads relevantes (0 y 5) y sus stacks correspondientes en el momento de espera mostraba lo siguiente.

   0  Id: 12f0.123c Suspend: 1 Teb: 7efdd000 Unfrozen
ChildEBP RetAddr  
002ce690 7d4e286c ntdll!NtWaitForMultipleObjects+0x15
002ce738 7d94d299 kernel32!WaitForMultipleObjectsEx+0x11a
002ce794 02596029 user32!RealMsgWaitForMultipleObjectsEx+0x152
002ce7b4 0259632d ieui!CoreSC::Wait+0x49
002ce7dc 025960d8 ieui!CoreSC::WaitMessage+0x54
002ce7e8 4640994d ieui!WaitMessageEx+0x33
002ce818 463fabcc ieframe!CBrowserFrame::FrameMessagePump+0x199
002ce824 463fbc3b ieframe!BrowserThreadProc+0x3f
002ce848 463fbb89 ieframe!BrowserNewThreadProc+0x7b
002cf8b8 463fba39 ieframe!SHOpenFolderWindow+0x188
002cfae8 00401464 ieframe!IEWinMain+0x2d9
002cff2c 004012ff iexplore!wWinMain+0x2c1
002cffc0 7d4e7d2a iexplore!_initterm_e+0x1b1
002cfff0 00000000 kernel32!BaseProcessStart+0x28

   5  Id: 12f0.12e8 Suspend: 1 Teb: 7efa9000 Unfrozen
ChildEBP RetAddr  
02fee038 7d4d8c82 ntdll!ZwWaitForSingleObject+0x15
02fee0a8 7da3936a kernel32!WaitForSingleObjectEx+0xac
02fee0c4 7da3ba11 rpcrt4!UTIL_WaitForSyncIO+0x20
02fee0e8 7da3b9eb rpcrt4!UTIL_GetOverlappedResultEx+0x1d
02fee104 7da3b9a9 rpcrt4!UTIL_GetOverlappedResult+0x17
02fee124 7da3ad05 rpcrt4!NMP_SyncSendRecv+0x73
02fee14c 7da3af2d rpcrt4!OSF_CCONNECTION::TransSendReceive+0x7d
02fee1d4 7da3aea2 rpcrt4!OSF_CCONNECTION::SendFragment+0x2ae
02fee22c 7da3b1b9 rpcrt4!OSF_CCALL::SendNextFragment+0x1e2
02fee274 7da3b834 rpcrt4!OSF_CCALL::FastSendReceive+0x148
02fee290 7da3b7b7 rpcrt4!OSF_CCALL::SendReceiveHelper+0x5b
02fee2c0 7da37d3e rpcrt4!OSF_CCALL::SendReceive+0x41
02fee2cc 7da37cf0 rpcrt4!I_RpcSendReceive+0x24
02fee2e0 7dac01b6 rpcrt4!NdrSendReceive+0x2b
02fee6c8 71c4b685 rpcrt4!NdrClientCall2+0x22e
02fee6e0 71c4b644 netapi32!NetrLogonGetTrustRid+0x1c
02fee720 7da4af08 netapi32!I_NetlogonGetTrustRid+0x1e
02fee768 7da4ae60 rpcrt4!GetMachineAccountSid+0xcb
02fee780 7da3f97e rpcrt4!NormalizeAccountSid+0x4c
02fee88c 7da4aaa4 rpcrt4!LRPC_CASSOCIATION::OpenLpcPort+0x1e9
02feeb88 7da4a40b rpcrt4!LRPC_CASSOCIATION::CreateBackConnection+0x74
02feebc4 7da456fb rpcrt4!LRPC_CASSOCIATION::ActuallyDoBinding+0x32
02feec3c 7da3843a rpcrt4!LRPC_CASSOCIATION::AllocateCCall+0x190
02feec70 7da38366 rpcrt4!LRPC_BINDING_HANDLE::AllocateCCall+0x1f2
02feec9c 7da37a1c rpcrt4!LRPC_BINDING_HANDLE::NegotiateTransferSyntax+0xd3
02feecb4 7778c956 rpcrt4!I_RpcGetBufferWithObject+0x5b
02feecf8 7778c629 ole32!CRpcChannelBuffer::ClientGetBuffer+0x31c
02feed08 776c0e9e ole32!CRpcChannelBuffer::GetBuffer+0x20
02feed28 776c0f7a ole32!CAptRpcChnl::GetBuffer+0x209
02feed8c 7dac0fda ole32!CCtxComChnl::GetBuffer+0x1e5
02feeda8 7dac0f89 rpcrt4!NdrProxyGetBuffer+0x47
02fef190 776a3717 rpcrt4!NdrClientCall2+0x173
02fef1a8 7778b6e4 ole32!IClassFactory_RemoteCreateInstance_Proxy+0x1c
02fef1c4 776ad8ac ole32!IClassFactory_CreateInstance_Proxy+0x41
02fef24c 776aaf7e ole32!CServerContextActivator::CreateInstance+0x175
02fef28c 776ad9b6 ole32!ActivationPropertiesIn::DelegateCreateInstance+0xf7
02fef2e0 776ad92d ole32!CApartmentActivator::CreateInstance+0x110
02fef300 776acb27 ole32!CProcessActivator::CCICallback+0x6d
02fef320 776acad8 ole32!CProcessActivator::AttemptActivation+0x2c
02fef35c 776ada17 ole32!CProcessActivator::ActivateByContext+0x4f
02fef384 776aaf7e ole32!CProcessActivator::CreateInstance+0x49
02fef3c4 776aaf19 ole32!ActivationPropertiesIn::DelegateCreateInstance+0xf7
02fef614 776aaf7e ole32!CClientContextActivator::CreateInstance+0x8f
02fef654 776ab10f ole32!ActivationPropertiesIn::DelegateCreateInstance+0xf7
02fefe08 776a679a ole32!ICoCreateInstanceEx+0x3f8
02fefe3c 776a6762 ole32!CComActivator::DoCreateInstance+0x6a
02fefe60 776a6963 ole32!CoCreateInstanceEx+0x23
02fefe90 4635a747 ole32!CoCreateInstance+0x3c
02fefec0 4638f691 ieframe!SHCoCreateInstanceAC+0x9e
02feff08 463c167a ieframe!WinList_RegisterPending+0x2c
02feff4c 463ee4b9 ieframe!CTabWindow::_RegisterPendingWindow+0x149
02feffb8 7d4dfe21 ieframe!CTabWindow::_TabWindowThreadProc+0x99
02feffec 00000000 kernel32!BaseThreadStart+0x34

El thread 0 es el thread principal y aparentemente no está haciendo mucho, salvo esperar que el kernel le avise que ciertos eventos han ocurrido.

Sin embargo, el thread 5 sí está haciendo algo y es exactamente lo que yo le había pedido. Crear un tabulador. Esto lo puedo inferir por las llamadas a las funciones con nombres acordes, como se puede apreciar ahora

<cortado ...>
02feff4c 463ee4b9 ieframe!CTabWindow::_RegisterPendingWindow+0x149
02feffb8 7d4dfe21 ieframe!CTabWindow::_TabWindowThreadProc+0x99
02feffec 00000000 kernel32!BaseThreadStart+0x34

Ok, tenemos el thread que crea el tabulador. ¿qué más?

Mirando el stack, se puede observar creación de objetos COM, posiblemente una creación de contexto de COM o una reutilización de uno existente (no estoy del todo seguro de cual opción), una llamada RPC, interacción con el sub-sistema de Windows (kernel32.dll) y el kernel (ntdll.dll).

A diferencia de una revisión de aplicaciones como asp.net o asp tradicional, donde uno espera encontrar código del cliente que no está optimizado y que consume recursos, en esta oportunidad no había código de terceros. El camino se veía difícil.

Golpes de suerte

Con dos sucesivos golpes de suerte logré dar con el problema, pero jamás podría haberlo detectado sin un post de Mark Russinovich, donde él experimentó un problema similar. El primer golpe de suerte fue elegir alguna función que pareciese sospechosa y luego, livear en internet. La función elegida fue GetMachineAccountSid y la búsqueda retornó este post en primera opción.

http://blogs.technet.com/markrussinovich/archive/2006/08/31/453100.aspx
The Case of the Process Startup Delays

Con ese título del post, claramente estábamos enfrentando el mismo problema. Eso sí, la diferencia es que Mark sabe reconocer el problema, pero uno debe apelar a la suerte y a los buscadores de internet.

Haciendo pruebas similares a las del post mencionado, obtuve respuestas similares.

Bien. Traté de atacharme a lsass.exe (local security authority subsystem) con nefastos resultados. Una vez atachado windbg a lsass, hice una mala maniobra y windbg dejó de responder, haciendo que el sistema quedase medianamente bloqueado (respondía muy lento) ya que muchos procesos depende de lsass.exe. Como no hubo más opción que matar windbg, esto traería como consecuencia que el proceso que se estaba debugueando también moriría. Y si muere lsass.exe, el sistema operativo te pide amablemente reiniciar, con una pantalla similar a la pantalla del virus que atacaba XP antes de SP2 y que te daba 48 segundos para cerrar todo.

La consecuencia.

Como dirían en algunos programas de televisión; "niños, no traten de hacer esto en casa," o mejor dicho, no lo hagan mientras visitan a un cliente y deben trabajar con su equipo.

Resolución

A diferencia del post de Mark, en donde el causante del problema era Defender, en este caso no había un tercer involucrado que remover del sistema.

La solución no fue la más elegante, pero no tuve más alternativa que ejecutar Internet Explorer en el contexto de un usuario local de la máquina, para así evitar que se trate de obtener información desde el dominio, el cual no puede ser alcanzado.

Lamentablemente esto trajo como consecuencia que no pudiese accesar a mi historial ni favoritos. Espero que cuando logre conectarme al dominio se acaben los problemas.

Saludos,
Patrick

Signos vitales de un servidor: Parte III (disco)

pmackay — Fri, 04 Jan 2008 03:38:00 GMT

Después de unos días de descanso debido a las fiestas ampliamente conocidas, continuamos con la tercera entrega de la serie de monitoreo de signos vitales de un servidor, en la cual presentaremos la información necesaria para detectar problemas de rendimiento en las unidades lógicas de disco de un servidor.

Si bien es posible determinar problemas en unidades físicas, las diferentes configuraciones físicas de arreglos RAID 0, 1, 5, 1+0 y 0+1 y la creación posterior de unidades lógicas en el arreglo, hace muy difícil, si es que no imposible, el determinar si es o no un disco físico específico.

Antes de comenzar, hago un mini corte para recomendar este link de una presentación de David Solomon sobre cómo maneja la memoria Windows y como hacer un troubleshooting básico de los problemas. Además, se da tiempo de romper algunos mitos. Definitivamente un video imperdible. Está en inglés y dura 1 hora y 37 minutos.

http://www.microsoft.com/uk/technet/itsshowtime/sessionh.aspx?videoid=64

Diferentes caminos

Para la verificación de los contadores de disco, existen dos caminos conocidos. Uno de ellos el difícil y otro mucho más simple y agnóstico del hardware.

El primer camino, el cual NO veremos aquí corresponde a obtener información de los IOs de los discos, calcular la cantidad de operaciones de lectura y escritura que se realizan por cada tipo de RAID, la cantidad de discos físicos (ejes) involucrados en el RAID y hacer una cantidad importantes de cálculos y asumir con poca certeza algunas constantes o valores.

El segundo camino, mucho más simple, es agnóstico del tipo de RAID, la cantidad de discos y otras variables. ¿Qué es lo que mide? muy simple y básico:

¿Cuánto tiempo se demora el sistema de discos en realizar una operación de escritura o lectura?

Si se demora "mucho," hay un problema. Si se demora "poco," estamos bien. Si tienes picos elevados constantes, podemos estar en presencia de algún inconveniente o escasez de capacidad de procesamiento.

Además de la información relacionada con escrituras y lecturas, se debe complementar con información general del disco como el porcentaje de tiempo disponible y largo de la cola de requerimientos.

Veamos los contadores y contra qué compararlos, es decir, que es "bueno" y "malo."

Nota: Antes de comenzar aclaro que cuando digo disco "malo," no estoy mencionando que el disco está malo físicamente o que presenta alguna falla sino que realmente me refiero a que el disco no responde de acuerdo a lo que es espera de él, generalmente producto de una tasa muy elevada de requerimientos.

Contadores

Los contadores a medir del objeto Logical Disk, para la instancia específica (c:, d:, etc.), son los siguientes:

Avg Disk Sec/read: milisegundos en que una operación de lectura es llevada a cabo.
Avg disk Sec/write: milisegundos en que una operación de escritura es llevada a cabo.
% Idle time: porcentaje de tiempo que el disco está desocupado.
Avg disk queue length: largo promedio de la cola de requerimientos del disco
Current disk queue length: largo actual de la cola de requerimientos del disco

¿Contra que los comparamos?

Los dos primeros contadores se comparan contra la misma tabla de valores, la cual despliego a continuación:

Valor medido	Significado
entre 1 milisegundo y 15 milisegundos	Perfecto estado
entre 16 milisegundos y 25 milisegundos	Se debe monitorear
más de 25 milisegundos	Disco degradado

Se deben considerar valores promedios. Es esperable que un disco tenga picos por sobre los 25 milisegundos pero el valor promedio debe ser bajo.

Nota: Si tienes un storage con caché de escritura, deberás ser más estricto en las comparaciones y reducir un poco los valores. Esto se debe a que el caché de escritura mejora sustancialmente el rendimiento. Si antes 15 ms era el tope para considerar el valor como perfecto, entonces si mides 15 ms y tienes caché habilitado, no estarás dentro del grupo de perfecto estado sino que el rendimiento será medio y deberás monitorear la actividad.

Anécdota: El valor más alto que he presenciado en algunos casos ha sido de más de 900 milisegundos. Por supuesto, el servicio que se estaba exponiendo estaba severamente afectado, con tiempos de respuesta muy bajos.

El contador del tiempo porcentaje de tiempo disponible es simple también. Más de 50%, perfecto estado. Entre 20% y 50%, se deberá monitorear y menor a 20%, el disco está degradado.

Por último, para los contadores de largo de cola de requerimientos promedio y actual, estos dos valores se comparan y calculan de la misma forma. Si la cantidad de discos físicos que componen el arreglo de discos es conocida, se deberá comparar contra el valor medido menos la cantidad de discos y dividirlo por dos.

Por ejemplo: Si el valor medido del largo promedio de la cola de requerimientos es 25 y tengo 10 discos en el arreglo, la formula nos retorna: (25-10)/2 = 7,5.

Este valor es menor a 1, el rendimiento es excelente. Entre 1 y 3, se deberá monitorear. Mayor a 3, crítico o degradado.

Por supuesto, la formula presenta inconvenientes cuando los valores medidos son menores a la cantidad de discos, pero en ese caso el disco claramente no tiene problemas.

¿Qué sucede si no conozco la cantidad de discos? y bueno, en ese caso se recomienda dividir por 2 el valor medido en el contador y aplicar la misma regla de comparación. Entendemos que no es un valor fidedigno, pero tampoco es "tan errado." Para el mismo ejemplo, 25/2 es 12,5, un valor mayor a 7,5, pero igual de malo de acuerdo a el parámetro de comparación.

Como pueden ver, monitorear un disco es muy simple. Si no responde en tiempos breves, claramente le estamos pidiendo más de lo que puede dar.

Queda pendiente una o dos entregas más de signos vitales, las que llegarán espero durante este mes.

Saludos,
Patrick

Traza de asp.net y el consumo de memoria

pmackay — Tue, 18 Dec 2007 02:24:00 GMT

El siguiente caso a presentar está relacionado con el alto consumo de memoria de una aplicación. Como el título lo dice, está relacionado con el uso de la traza de asp.net (trace en web.config.)

El escenario era similar a lo descrito ahora. La aplicación analizada empezaba a consumir memoria y aunque tenía momentos donde la liberaba, la impresión general era que en el largo plazo, siempre subía. Este es un típico comportamiento de un memory leak o pérdida de memoria; la tendencia al alza, aunque con momentos donde baja un poco.

Como ya es tradición, un dump del proceso y mi amigo Debugging Tool For Windows nos darían las pistas necesarias. También nos apoyamos en performance monitor, pero hay veces que ya sabes que es una pérdida de memoria y éste no te dirá mucho más de lo que ya sabes.

Con el dump en mis manos, hacemos una revisión del proceso afectado y el estado de la memoria virtual del éste.

Recolección de información general

Tamaño del dump: ~300 MB. No es muy grande, pero tampoco es descartable. Tradicionalmente se espera a que la memoria privada del proceso llegue al menos hasta 500 MB para declararlo como sospechoso.

Información del proceso:

System Uptime: 180 days 15:52:41.140
Process Uptime: 0 days 2:08:23.000
Kernel time: 0 days 0:00:13.000
User time: 0 days 0:08:48.000

El sistema operativo lleva corriendo 180 días sin reiniciarse. El proceso en cuestión lleva del orden de 2 horas y 8 minutos corriendo y que ha consumido 13 segundos en modo privilegiado (kernel) y 8 minutos y 48 segundos en modo usuario.

Con 8 minutos de procesamiento ya llegó a 300 MB. Interesante.

El estado de la memoria virtual concuerda con el tamaño del dump, reflejado gráficamente en la imagen de la derecha, la cual pueden pinchar para agrandar.

Efectivamente hay aproximadamente 300 MB de memoria virtual, de los cuales casi 190 son de memoria manejada.

Memoria manejada

Haciendo una revisión de los heaps del GC, obtenemos la información de la siguiente lista. El servidor tiene 4 procesadores por lo que se crean cuatro heaps del GC, cada uno con sus propias generaciones, heaps efímeros y heaps de objetos grandes.

Number of GC Heaps: 4
------------------------------
Heap 0 (0x000d01c8)
generation 0 starts at 0x121135c8
generation 1 starts at 0x12109a44
generation 2 starts at 0x102d0030
ephemeral segment allocation context: none
segment begin allocated size reserved
0x102d0000 0x102d0030 0x121135d4 0x01e435a4(31,733,156) 0x00d79000
Large object heap starts at 0x202d0030
segment begin allocated size reserved
0x202d0000 0x202d0030 0x205d2168 0x00302138(3,154,232) 0x00cdd000
Heap Size 0x2245770(35,936,112)
------------------------------
Heap 1 (0x000d08d8)
generation 0 starts at 0x16009a28
generation 1 starts at 0x15eaacac
generation 2 starts at 0x142d0030
ephemeral segment allocation context: none
segment begin allocated size reserved
0x142d0000 0x142d0030 0x16009a34 0x01d39a04(30,644,740) 0x014c7000
Large object heap starts at 0x212d0030
segment begin allocated size reserved
0x212d0000 0x212d0030 0x21449a38 0x00179a08(1,546,760) 0x00e66000
Heap Size 0x1f2b4a0(32,683,168)
------------------------------
Heap 2 (0x000d13d8)
generation 0 starts at 0x24461404
generation 1 starts at 0x243e6e2c
generation 2 starts at 0x182d0030
ephemeral segment allocation context: none
segment begin allocated size reserved
0x182d0000 0x182d0030 0x1998c7dc 0x016bc7ac(23,840,684) 0x028ef000
0x242d0000 0x242d0030 0x24461410 0x001913e0(1,643,488) 0x033c4000
Large object heap starts at 0x2a2d0030
segment begin allocated size reserved
0x2a2d0000 0x2a2d0030 0x2a2d0030 0x00000000(0) 0x047df000
Heap Size 0x198fb8c(26,803,084)
------------------------------
Heap 3 (0x000d1ca0)
generation 0 starts at 0x087954cc
generation 1 starts at 0x083dd820
generation 2 starts at 0x1c2d0030
ephemeral segment allocation context: none
segment begin allocated size reserved
0x1c2d0000 0x1c2d0030 0x1df48b8c 0x01c78b5c(29,854,556) 0x02310000
0x08330000 0x08330030 0x087954d8 0x004654a8(4,609,192) 0x01fff000
Large object heap starts at 0x232d0030
segment begin allocated size reserved
0x232d0000 0x232d0030 0x2344ed50 0x0017ed20(1,568,032) 0x00e61000
0x0edc0000 0x0edc0030 0x0f195f40 0x003d5f10(4,022,032) 0x00c2a000
Heap Size 0x277ac50(41,397,328)
------------------------------
Reserved segments:
------------------------------
GC Heap Size 0x827b3ec(136,819,692)

De esta información se puede ver que hay muchos objetos en generación 2, lo que significa que hay objetos que no se han liberado y han ido envejeciendo más de lo necesario.

¿Qué hay en la memoria?

Haciendo un vaciado estadístico de los objetos, utilizando Debugging Tool For Windows y sos, obtenemos un listado como el de a continuación, donde se ha eliminado parte del comienzo y sólo se ha dejado el final, que contiene la información relevante para el caso.

MT Count TotalSize Class Name
.....<recortado por el bien de esta página>...
0x028665f0 22,807 273,684 System.Xml.Xsl.EndEvent
0x02784adc 14,800 296,000 System.Data.DataRowCollection
0x027844dc 14,800 296,000 System.Data.DataRowBuilder
0x027862d4 14,911 298,220 System.Data.ColumnQueue
0x02782a74 11,824 331,072 System.ComponentModel.CollectionChangeEventHandler
0x0230159c 14,866 356,784 System.Xml.NameTable/Entry
0x02925aec 7,847 408,044 System.Xml.Xsl.XsltCompileContext
0x02926bfc 11,589 417,204 System.Xml.XPath.XPathChildIterator
0x02863d04 8,692 417,216 System.Xml.XPath.ChildrenQuery
0x027846d4 14,800 473,600 System.Data.RecordManager
0x0278001c 14,800 473,600 System.Data.ConstraintCollection
0x027842e4 14,913 477,216 System.ComponentModel.PropertyDescriptorCollection
0x0280cddc 16,754 670,160 System.Xml.XPath.XPathWhitespace
0x0280c924 10,044 682,992 System.Xml.XPath.XPathElement
0x02866564 22,807 729,824 System.Xml.Xsl.BeginEvent
0x0252ebe4 14,800 769,600 System.Data.DataColumnCollection
0x79bda488 14,813 888,780 System.Threading.ReaderWriterLock
0x79bab93c 17,498 909,896 System.Collections.Hashtable
0x02923770 28,877 924,064 System.Xml.DocumentXPathNavigator
0x027882e4 40,203 964,872 System.Data.Common.StringStorage
0x0280cba4 21,157 1,015,536 System.Xml.XPath.XPathAttribute
0x0278489c 29,600 1,184,000 System.Data.DataRelationCollection/DataTableRelationCollection
0x01ba2c28 17,561 2,839,896 System.Collections.Hashtable/bucket[]
0x0252e4b0 14,800 3,433,600 System.Data.DataTable
0x79ba2ee4 145,618 3,494,832 System.Collections.ArrayList
0x0278670c 54,976 3,518,464 System.Data.DataColumnPropertyDescriptor
0x01ba2964 24,879 5,024,760 System.Int32[]
0x0278513c 136,364 5,454,560 System.Data.DataRow
0x0252f5d0 54,760 7,009,280 System.Data.DataColumn
0x01ba26b0 1,262 8,513,840 System.Byte[]
0x000cff48 2,829 14,897,824 Free
0x79b94638 238,884 23,296,388 System.String
0x01ba209c 235,235 40,966,392 System.Object[]
Total 1,509,853 objects, Total size: 136,798,976

Existe un poco más de 1,5 millones de objetos en memoria, que consumen cerca de 136 MB, similar al resultado entregado en la lista anterior.

De esos 1,5 millones de objetos, existe una gran cantidad de strings y arreglos de objeto, como también de filas de datos y columnas de datos. Este comportamiento se presenta cuando se han creado Datasets y no se han liberado.

Un DataSet contiene filas y columnas, y en cada celda encontramos objetos de los tipos básicos como strings, enteros, decimales, objetos, etc. Por lo tanto, estos objetos que se ven al final no viven solos sino que están referenciados desde otro objeto, como podría ser un dataset. No significa que todos estén referenciados, pero con 136 mil filas (DataRow) y 54 mil columnas (DataColumn), varios de esos miles de objetos si lo están.

¿Cuantos DataSets hay?

MT Count TotalSize Class Name
0x0252ce84 1,597 127,760 System.Data.DataSet
Total 1,597 objects, Total size: 127,760

Bueno, tomemos uno al azar y veamos donde nos lleva. Elegimos el objeto en la posición de memoria 0x0834d148.

Name: System.Data.DataSet
MethodTable 0x0252ce84
EEClass 0x0275b43c
Size 80(0x50) bytes
GC Generation: 2
mdToken: 0x0200003b (c:\windows\assembly\gac\system.data\1.0.5000.0__b77a5c561934e089\system.data.dll)
FieldDesc*: 0x0252c4b4
MT Field Offset Type Attr Value Name
0x0252c23c 0x4000583 0x4 CLASS instance 0x00000000 site
0x0252c23c 0x4000584 0x8 CLASS instance 0x00000000 events
0x0252c23c 0x4000582 0 CLASS shared static EventDisposed
>> Domain:Value 0x000c4ac8:NotInit 0x00138380:0x1c331c58 <<
0x0252ce84 0x40003d3 0xc CLASS instance 0x15cee704 defaultViewManager
0x0252ce84 0x40003d4 0x10 CLASS instance 0x0834d198 tableCollection
0x0252ce84 0x40003d5 0x14 CLASS instance 0x0834d220 relationCollection
0x0252ce84 0x40003d6 0x18 CLASS instance 0x00000000 extendedProperties
0x0252ce84 0x40003d7 0x1c CLASS instance 0x1c331c30 dataSetName
0x0252ce84 0x40003d8 0x20 CLASS instance 0x102d0224 _datasetPrefix
0x0252ce84 0x40003d9 0x24 CLASS instance 0x102d0224 namespaceURI
0x0252ce84 0x40003da 0x40 System.Boolean instance 0 caseSensitive
0x0252ce84 0x40003db 0x28 CLASS instance 0x1c2e69c8 culture
0x0252ce84 0x40003dc 0x41 System.Boolean instance 1 enforceConstraints
0x0252ce84 0x40003dd 0x42 System.Boolean instance 0 fInReadXml
0x0252ce84 0x40003de 0x43 System.Boolean instance 0 fInLoadDiffgram
0x0252ce84 0x40003df 0x44 System.Boolean instance 0 fTopLevelTable
0x0252ce84 0x40003e0 0x45 System.Boolean instance 0 fInitInProgress
0x0252ce84 0x40003e1 0x46 System.Boolean instance 1 fEnableCascading
0x0252ce84 0x40003e2 0x47 System.Boolean instance 0 fIsSchemaLoading
0x0252ce84 0x40003e3 0x2c CLASS instance 0x00000000 rowDiffId
0x0252ce84 0x40003e4 0x48 System.Boolean instance 0 fBoundToDocument
0x0252ce84 0x40003e5 0x30 CLASS instance 0x00000000 onPropertyChangingDelegate
0x0252ce84 0x40003e6 0x34 CLASS instance 0x00000000 onMergeFailed
0x0252ce84 0x40003e7 0x38 CLASS instance 0x00000000 onDataRowCreated
0x0252ce84 0x40003e8 0x3c CLASS instance 0x00000000 onClearFunctionCalled
0x0252ce84 0x40003e9 0 CLASS shared static zeroTables
>> Domain:Value 0x000c4ac8:NotInit 0x00138380:0x1c331c20 <<

Mmm, nada más que un dataset. No se si podría haber encontrado otra cosa . Veamos el nombre de éste, en la posición 0x1c331c30 (línea blanca arriba).

String: NewDataSet

. El nombre genérico no da pistas para encontrar alguna parte del código que lo esté creando. Vemos entonces quién lo está apuntando.

Scan Thread 10 (0x1cac)
Scan Thread 16 (0xa00)
Scan Thread 17 (0x1908)
Scan Thread 5 (0xa0c)
Scan Thread 4 (0x1dcc)
Scan Thread 19 (0x1a6c)
Scan Thread 3 (0x1584)
Scan Thread 2 (0x444)
Scan Thread 20 (0x15f4)
ESP:36ff548:Root:0x1c6b59a8(System.Threading.Thread)->0x15cecad4(System.Runtime.Remoting.Messaging.IllogicalCallContext)->0x15cecae0(System.Collections.Hashtable)->0x15cecb14(System.Collections.Hashtable/bucket[])->0x15cec81c(System.Web.HttpContext)->0x15cec608(System.Web.Hosting.ISAPIWorkerRequestInProcForIIS6)->0x182d81c4(System.Web.HttpWorkerRequest/EndOfSendNotification)->0x14339e70(System.Web.HttpRuntime)->0x182d7fac(System.Web.Util.Profiler)->0x14358454(System.Collections.ArrayList)->0x1d89d7b0(System.Object[])->0x834d148(System.Data.DataSet)
Scan Thread 22 (0x1098)
Scan Thread 24 (0xcd8)
.....<recortado por el bien de esta página>...
Scan Thread 67 (0x1938)
Scan Thread 54 (0x618)
Scan HandleTable 0xc9ec0
Scan HandleTable 0xcd008
Scan HandleTable 0x147008

El thread 20, que está procesando un requerimiento en la extensión ISAPI de asp.net en IIS6 (System.Web.Hosting.ISAPIWorkerRequestInProcForIIS6) tiene una referencia fuerte al objeto. Vemos también un HashTable, el Contexto y Runtime de http, los cuales se pueden considerar normales en el ciclo de vida de un requerimiento web.

Sin embargo, hay un invitado especial en esta lista de referencias. Éste es System.Web.Util.Profiler, del cual no hay mucha información disponible, pero después de examinarlo, ya podemos inferir de quién se trata. Veamos su contenido.

Name: System.Web.Util.Profiler
MethodTable 0x021c49d0
EEClass 0x0215912c
Size 28(0x1c) bytes
GC Generation: 2
mdToken: 0x0200029d (c:\windows\assembly\gac\system.web\1.0.5000.0__b03f5f7f11d50a3a\system.web.dll)
FieldDesc*: 0x021c4704
MT Field Offset Type Attr Value Name
0x021c49d0 0x4001076 0x8 System.Int32 instance 1478 _requestNum
0x021c49d0 0x4001077 0xc System.Int32 instance 7500 _requestsToProfile
0x021c49d0 0x4001078 0x4 CLASS instance 0x14358454 _requests
0x021c49d0 0x4001079 0x14 System.Boolean instance 0 _pageOutput
0x021c49d0 0x400107a 0x15 System.Boolean instance 1 _isEnabled
0x021c49d0 0x400107b 0x16 System.Boolean instance 1 _oldEnabled
0x021c49d0 0x400107c 0x17 System.Boolean instance 0 _localOnly
0x021c49d0 0x400107d 0x10 System.Int32 instance 0 _outputMode

Recordando las propiedades de la traza de asp.net, podemos ver asombrosas similitudes con las propiedades. Veamos la definición de la traza en el archivo web.config. La información oficial dice:

El dump dice que la traza estaba habilitada (_isEnabled), no estaba local (_localOnly), que tenía marcado para almacenar hasta 7.500 requerimientos (segunda línea blanca) y que habían 1478 almacenados (primera línea blanca). El resto de las propiedades las pueden chequear ustedes. Recordemos que habían 1597 DataSets en memoria.

El objeto _requests es un System.Collections.ArrayList y los 1478 objetos dentro suman casi la totalidad de memoria manejada, que si bien recordarán, sumaba cerca de 136 MB.

sizeof(0x14358454) = 91,258,512 (0x5707e90) bytes (System.Collections.ArrayList)

Entonces, la condición de memoria elevada, se da en parte porque hay ~90 MB de objetos referenciados por la traza de asp.net. También hay una cantidad de importante de memoria (~70 MB) consumida por dlls y ensamblados (ver la primera imagen.)

Conclusiones

Las conclusiones que se pueden obtener en este caso son:

No todos las pérdidas de memoria son producto de errores en la codificación.
Si vas a habilitar la traza en producción, recuerda deshabilitarla una vez que termines.
También, si no vas a poder leer la información de 7500 trazas, configúralo para que almacene menos.

Saludos,
Patrick

Signos vitales de un servidor: Parte II (procesador)

pmackay — Mon, 17 Dec 2007 04:08:00 GMT

Continuando con los signos vitales de un servidor, hoy día veremos en la segunda parte, el procesador.

El análisis del procesador es bastante más simple que el de la memoria. Hay dos contadores importantes. Uno de ellos corresponde al uso del procesador, con dos matices especiales; uso del procesador en modo usuario y el otro en modo kernel. El otro contador corresponde a la cantidad de requerimientos encolados del procesador.

Como ya hemos visto en otros posts, Windows utiliza dos modos de ejecución. Uno de ellos es el modo usuario, donde corren las aplicaciones que nosotros ejecutamos y el otro es el modo Kernel, en el cual corre el kernel del sistema operativo.

¿Por qué es importante esta explicación?

Si logramos identificar quién está consumiendo el procesador, podremos inferir y tener mejores pistas para encontrar al culpable del consumo de éste.

Si te preguntas ¿para qué necesitas saber el modo (usuario o kernel) que está consumiendo el procesador, si mirando el task manager sabrás fácilmente qué aplicación es responsable?

Bueno. Hay un par de razones. Veamos cada una de ellas.

1.- Task manager te dirá la aplicación que está consumiendo el procesador, pero no te dirá más. Solo la aplicación. Perfmon por otra parte te podrá entregar más información. Process Explorer de Sysinternals es una excelente herramienta.
2.- Task manager no muestra siempre el consumo del kernel.

El segundo punto no está tan relacionado con aplicaciones, pero vale la pena aclarar que hay ciertas actividades del kernel que no son cuantificadas por Task Manager, o son cuantificadas pero no desplegadas. Recordemos que el kernel corresponde al proceso llamado System, siempre con el PID 4. Entonces puede parecer que tu sistema tiene bajo uso del procesador, pero el kernel está trabajando activamente. Para mejores resultados en el despliegue de los recursos consumidos, puedes utilizar Process Explorer.

Resumiendo

Podemos decir que para una aplicación específica:

El porcentaje de consumo en modo kernel corresponde a las actividades que debe realizar el kernel para cumplir con los requerimientos de la aplicación, como por ejemplo, trabajar con archivos, mover memoria, escribir en sockets, pintar ventanas, etc.

El porcentaje de consumo en modo usuario corresponde a la ejecución de código sin interacción con el kernel, es decir, algo así como "el código sin acceso a recursos externos." Si estuviésemos utilizando un profiler, diríamos entonces que corresponde a lo que se llama "exclusive time."

Contadores

La siguiente es la lista de contadores de perfmon a utilizar, que como podrán notar, es muy breve, repetitiva y casi no requiere mayor explicación.

Objeto System, contador Processor Queue Length: muestra la cantidad de requerimientos encolados para el procesador.
Objeto Processor, contador % Privileged Time: muestra el porcentaje de tiempo utilizado por el kernel, para todo el procesador
Objeto Processor, contador % User Time: similar al anterior, pero para modo usuario
Objeto Process, contador % Privileged Time, instancia específica. muestra el porcentaje de tiempo utilizado por el kernel, para la aplicación seleccionada en el campo instancia
Objeto Process, contador % User Time, instancia específica: similar al anterior, pero para modo usuario
Objeto Thread, contador % Privileged Time, instancia específica: muestra el porcentaje de tiempo utilizado por el kernel, para un thread especifico de la aplicación seleccionada
Objeto Thread, contador % User Time, instancia especifica: similar al anterior, pero para modo usuario

Probablemente te podrás estar preguntando la utilidad de la información de los últimos 2 contadores. ¿de que te serviría saber cuál es el thread responsable si no se puede hacer mucho con esa información?

Si se puede hacer bastante. Puedes determinar si es un único thread que está ocupando mucho el procesador o es un conjunto de ellos en que todos aportan. Te sirve para obtener pistas.

Podría ser el thread o los threads del GC, el thread del Finalizador, un thread que se quedó pegado en un ciclo, etc. Process Explorer entrega mucha información referente a tipos de procesos e informacón de los threads.

Ok, ya tengo todos los datos...

¿Contra qué comparar la información?

Salvo para el primer contador, no hay punto de comparación. Si el uso del procesador llega a 80% o más, probablemente sea hora de proveer alivio al servidor, ya sea corrigiendo el código o haciendo un upgrade del hardware.

El primer contador no debe ser mayor a 2 multiplicado por la cantidad de procesadores (cores) de tu servidor. Para el caso de HT (Hyper Threading), no estoy seguro, pero creo que no se deben contabilizar.

Ya vendrá una tercera entrega relacionada con el disco duro.

Saludos,
Patrick

Signos vitales de un servidor: Parte I (memoria)

pmackay — Sat, 08 Dec 2007 21:34:00 GMT

¿Qué sucede si uno no se siente bien?; en condiciones normales, uno visita al doctor para saber qué sucede y éste hace una revisión general. Si el doctor encuentra algo interesante, te pide hacer unos exámenes para saber con mayor detalle qué está sucediendo.

Llevando este mismo ejemplo al área de la informática, si tienes un servidor y presientes (o tienes total certeza) que algo no funciona como debiera, un buen punto de partida es determinar si los signos vitales de éste están bien.

El objetivo de este post es dar una pauta general para determinar cuando un servidor Windows 2003, cualquier versión, puede tener algún problema que afecte sus signos vitales. Hoy veremos los signos vitales de la memoria. Los siguientes posts abordarán otras áreas.

Un poco de contexto

Si has escuchado muchas veces la palabra contadores, y no tienes claro a que se refieren cuando lo escuchas, esta sección debiera aclararte un poco. Si tienes claro a que se refiere, puedes saltarte esta sección.

Los contadores son entidades u objetos que mantienen información del funcionamiento de algún programa o sistema operativo (SO de ahora en adelante). Cada programa que utilizas --todos debieran, pero no siempre lo hacen-- genera información con estadística y en tiempo real del funcionamiento de éste, la cual se le informa al SO. A su vez, el SO también genera información que almacena para que nosotros podamos consultarla y saber cómo está funcionando.

Los contadores se categorizan por objetos (por ejemplo, memoria, sistema, sql server, iis) y se pueden o no aplicar a instancias (procesos, sitios web, bases de datos, etc.)

Por ejemplo, un contador de importante SO es la cantidad de memoria disponible que le queda. Este se categoriza en el objeto Memory, y el contador se llama Available MBytes, que nos dice la cantidad de megabytes de memoria disponible. Los nombres de los contadores dependen del idioma del programa o SO. Si estás ejecutando un SO en español, el objeto podría llamarse Memoria y el contador, cantidad de MB disponibles.

La siguiente es una imagen de cómo se agrega este contador utilizando performance monitor (perfmon).

Luego, después de habar agregado los contadores, podrás ver una pantalla como ésta, donde la primera es la representación gráfica y la otra la textual, para la misma información.

Suponiendo que ya se entiende la idea, vamos entonces a ver la primera parte de cómo chequear la salud de un sistema operativo.

Grupos de contadores

Aunque los contadores ya están agrupados de acuerdo a los objetos a los cuales pertenecen, los volveremos a agrupar en clasificaciones más grandes, más generales. Tendremos entonces un grupo para colocar los contadores de memoria, uno para los del procesador, otro para el disco duro, otro para la tarjeta de red y otro para el sistema operativo. En otra oportunidad veremos los asociados a productos específicos como SQL, IIS o .NET.

Contadores de memoria

Los contadores de memoria son variados. Podemos encontrar desde la memoria utilizada por una aplicación, la memoria libre del servidor y la memoria utilizada por los componentes del Kernel del SO. Todas estas son importantes y están de alguna forma relacionadas.

Veamos cada uno de los contadores mencionados y contra qué compararlos (cuando aplica).

Memoria del sistema (incluido kernel)

La memoria libre del sistema la entrega el contador Available MBytes, del objeto Memory. El mismo contador existe retornando el valor en otras unidades como KBytes y Bytes. De acuerdo a la cantidad de memoria que hoy en día tiene un servidor, medir en bytes o kilobytes puede no ser necesario.

Diversa documentación podrán encontrar referente a este contador. Algunos dirán que con 10 MB disponibles, es momento de preocuparse. Otros dirán que 25 MB es una señal de preocupación. En general, menos del 10% de la memoria total instalada ya es reflejo de que al sistema le falta memoria. Por ejemplo, si mi servidor tiene 2GB instalados y le quedan 150 MB disponibles, significa que estoy consumiendo el 92,5% de la memoria. Sin embargo, otros contadores te ayudarán a determinar si esto es cierto o no (si hay o no un problema). Puede ser que tengas mucha memoria ocupada, pero el sistema funcione bien.

Otro contador importante es Pages/sec del objeto Memory. Este refleja la tasa de lecturas y escrituras a disco para resolver problemas de páginas no encontradas (hard faults) en la memoria física, y por ende, tiene que ir al archivo de paginación a buscarla (y guardar otra para hacer espacio).

La información disponible públicamente es muy variada. Desde sitios que dicen que valores de más de 100 son preocupantes. Otros dicen que más de 5 de forma constante es preocupante. Lamentablemente ninguna de esas medidas es agnóstica y depende de otros factores (como el disco). Una medida agnóstica se obtiene al multiplicar este contador por Avg. Disk sec/Transfer del objeto Physical Disk, en la instancia (disco) donde está el archivo de paginación. El resultado de multiplicar ambos corresponde al porcentaje de tiempo de acceso a disco. Si es mayor a 10%, está paginando mucho, lo que puede ser producto de falta de memoria.

Los contadores de memoria del kernel se deben comparar contra valores en unas tablas específicas. Estos son Pool Paged Bytes y Pool Nonpaged Bytes del objeto Memory. Las tablas se encuentran a continuación, tanto para Windows 2000 como Windows 2003 (clic para agrandar).

Windows 2003

Windows 2000 SP4

Los valores obtenidos para cada unos de los contadores, tanto para paged como nonpaged, corresponden a la cantidad de bytes de cada pool que ha sido utilizado. Si es menor al 50% del pool, todo está bien. Mayor a 50% y menor a 80%, es hora de preocuparse. Si es mayor a 80%, hay problemas.

¿Cómo se mide?

Si obtuviste un valor de 56 MB en el contador de paged pool bytes y tu sistema es Windows 2003 con 4 GB y estás usando /3GB, el tamaño total del paged pool bytes es de 258 MB (revisa la tabla). La tasa de uso (56/258) es cercana al 21%, lo que nos dice que nuestro sistema está bien. Lo mismo para nonpaged pool bytes, pero considerando el otro valor en la tabla.

El último contador relacionado con la memoria en el kernel corresponde a Free System Page Table Entries (PTEs), del objeto Memory. Los PTEs son estructuras internas utilizadas por el componente del kernel llamado Memory Manager y que tiene como objetivo administrar la memoria.

Si este contador se reduce mucho (menos de 15 mil o 10 mil), habrá problemas. Usualmente este contador se ve afectado por la utilización de la opción /3GB sin utilizar la opción /userva. Esta anécdota ocurrió en un caso donde no se utilizó /userva.

Después de haber visto las opciones para el sistema y kernel, podemos ver las opciones de memoria disponibles para las aplicaciones.

Memoria de aplicaciones

Para medir la memoria de una aplicación específica, tengo que agregar los siguientes contadores, y asociarlos con el proceso que quiero medir (instancia en la parte derecha de la ventana):

Objeto Process, contador Private Bytes
Objeto Process, contador Virtual Bytes
Objeto Process, contador Working Set

El primer contador corresponde a la memoria privada el proceso. El segundo contador, a la memoria virtual del proceso. Para un mejor entendimiento de los tipos de memoria que miden, te recomiendo la lectura de estos posts:

El working set corresponde a la cantidad de memoria privada (sumada a la memoria usada por dlls y otras estructuras) que está cargada en memoria real (física). A grosso modo, la suma de los working set de todos los procesos no podrá superar la memora física de tu máquina.

Lamentablemente no hay valores contra qué compararlos, pero de acuerdo a lo que vimos en el segundo post de la lista de más arriba, la memoria virtual no podrá superar los 2 GB en un sistema de 32 bits.

Si virtual bytes es muy elevado en comparación con private bytes, podría haber un problema de fragmentación de memoria. ¿Qué significa muy elevado?; tampoco hay una respuesta, pero unas 10 veces debiera ser preocupante, como también es preocupante acercarse a los 2 GB. Claro que las 10 veces dependerá de la memoria que use nuestro proceso. Si un proceso utiliza 10 MB de memoria privada, es normal que utilice 100 MB de memoria virtual.

Hay muchas cosas relativas, pero lo importante es monitorearlos en el tiempo.

Si virtual bytes sube y sube sin descender (o descendiendo menos de lo que aumenta), habrá un problema de fragmentación de memoria, aunque dependerá de cómo aumente private bytes también.

Si private bytes sube y sube sin descender (o descendiendo menos de lo que aumenta), tendrás un problema de pérdida de memoria o memory leak. Private bytes no podrá ser superior al máximo de memoria virtual de un proceso (2GB).

Otros contadores

Sin duda, hay muchos más contadores, pero para determinar signos vitales, con éstos basta.

Desde Santiago de Chile,
Patrick