Bienvenido a Kernel Debugging Land ...

Traducido desde : https://www.haiku-os.org/documents/dev/welcome_to_kernel_debugging_land/

Dentro(In) y fuera(Out)

A menos que el sistema haya ingresado a KDL por sí mismo, normalmente puede hacerlo invocando el método abreviado de teclado Alt-SysReq-D. Tenga en cuenta que en KDL su teclado puede no funcionar. Los teclados PS / 2 siempre lo hacen, los teclados USB conectados a través de los controladores UHCI solo lo hacen, si uno ha ingresado a KDL a través del atajo de teclado al menos una vez. USB OHCI no es compatible en este momento.
Una vez que el depurador del núcleo se está ejecutando, las actividades normales del sistema se detienen por completo. Hasta que se cierre, ningún subproceso avanzará en ninguna CPU y las interrupciones de hardware se desactivarán. Entonces, mientras que en KDL (Kernel Debugging Land) uno puede examinar pausadamente una instantánea inmóvil de todo el sistema. Después de usar uno de los comandos para dejar el depurador del kernel ( continue , exit ), el sistema continúa su operación normal. Sin embargo, si antes se había encontrado con un problema grave (como un error de página en el kernel), es probable que caiga de nuevo en KDL. En este caso, los comandos reboot o shutdown son la única salida. Sin embargo, no pueden apagar el sistema de forma ordenada, lo que significa que los datos que aún no se escriben en el disco se perderán.

La infraestructura básica

Edición de línea de comandos y salida

El depurador del kernel tiene una interfaz de línea de comandos simple. Uno puede ingresar un comando y, una vez que se ha ejecutado, a uno se le solicita la siguiente entrada. Se admite la edición básica de la línea de comandos, es decir, INICIO, FIN, las teclas de cursor Izquierda / Derecha, así como DELETE y RETROCESO funcionan como se espera Ctrl-K borra la línea que comienza en la posición del cursor. Incluso un breve historial de comandos está disponible. Cursor arriba / abajo navegar a través de los comandos introducidos anteriormente. Avance / retroceso de página: pase a la línea anterior / siguiente en el historial que comienza con los caracteres antes del cursor.
Al presionar TAB después de escribir una parte del nombre de un comando, se intentará completar el nombre del comando, si es posible. Se señalarán las ambigüedades. Al presionar la tecla TAB cuando el cursor se coloca después del nombre del comando y el espacio que sigue, invocará el comando con el argumento -- help , que, en la mayoría de los casos, imprimirá la información de uso del comando. La edición de la línea de comando puede continuar.
La forma en que el texto que se ha impreso se "desplaza", cuando se alcanza la parte inferior de la pantalla, necesita acostumbrarse, ya que no se desplaza en absoluto, pero el cursor simplemente se ajusta a la parte superior de la pantalla, sobrescribiendo La salida más antigua. De forma predeterminada, la salida de un comando del depurador se detiene justo antes de que sobrescriba lo que se imprimió antes, esperando que se presione una tecla antes de continuar. Presionando Q causará que la salida restante de ese comando sea descartada en silencio. El comando de paging cambia si la salida se detiene en tales casos o continúa sin preguntarle al usuario.

Ayuda

Cuando se busca un comando con cierta funcionalidad sin saber su nombre, el comando de help puede ayudar. Enumera todos los comandos disponibles, cada uno con una breve descripción. Al proporcionar help los primeros caracteres de un nombre de comando, la lista se restringirá a los comandos correspondientes (por ejemplo, " help a " enumera todos los comandos que comienzan con "a").
Un número creciente de comandos admite la invocación con el argumento -- help . Aquellos que sí imprimen una descripción más detallada de cómo se pueden utilizar. Como se mencionó anteriormente, al presionar la tecla TAB mientras se edita la línea de comando para tal comando, también se imprimirá esa información.

Una calculadora simple

Dado que las sesiones de depuración del núcleo a menudo involucran muchos números volando, se admiten las expresiones aritméticas básicas. El comando expr los evaluará por usted e imprimirá el resultado.

 kdebug> expr (0x898afe36 + 17 * 4 - 0x8014d184) / 32
 4960615 (0x4bb167)

Internamente, los números se representan como valores enteros de 64 bits sin signo (y expr imprime de esa manera), lo que significa que los números negativos se muestran como grandes números positivos. La mayoría de las operaciones con negativos funcionan bien, sin embargo, las excepciones son división ( / ) y módulo ( % ).

 kdebug> expr 7 + 3 * -4
 18446744073709551611 (0xfffffffffffffffffb)
 kdebug> expr - (7 + 3 * -4)
 5 (0x5)
 kdebug> expr -6 / -3
 0 (0x0)

Las personas familiarizadas con el lenguaje C conocerán al operador * único. Hace referencia a un puntero de dirección dado, es decir, busca el valor almacenado en esa dirección. El depurador del núcleo también soporta ese operador. Por defecto, lee cuatro bytes en la dirección dada y los interpreta como un número, pero el número de bytes que se leerán (1, 2, 4 u 8) se puede especificar explícitamente entre llaves. Se imprimirá un mensaje de error al intentar eliminar una referencia a una dirección que no existe.

 kdebug> expr * 0x80000000
 1179403647 (0x464c457f)
 kdebug> expr * {2} 0x80000000
 17791 (0x457f)
 kdebug> expr * 0x17
 error al anular la dirección 0x00000017, en la posición: 0, en la expresión: * 0x17

Si bien es bueno poder imprimir el valor de una expresión aritmética, a menudo no es necesario hacerlo, ya que uno generalmente solo quiere pasar el valor a un comando, y el valor de una expresión se puede proporcionar como un argumento a un comando simplemente poniendo esa expresión entre paréntesis. Por ejemplo, el comando db , que toma una dirección y una cantidad de bytes e imprime que muchos bytes leídos de la memoria comenzando en la dirección dada, puede invocarse así:

 kdebug> db (0x80000000 + 100) (6 * 4)
 [0x80000064] ............... 09 00 00 00 09 00 00 00 04 00 00 00 01 00 00 00
 [0x80000074] ....... 01 00 00 00 00 00 00 00

Variables

Dado que no es posible desplazar la salida en la pantalla, es probable que los valores que puedan ser de interés más adelante ya se sobrescriban cuando se necesiten. Afortunadamente, las variables se pueden definir para mantener los valores para su uso posterior. Pueden ser configurados por el operador de asignación ( = ), modificados por los operadores + = , - = , * = , / = , % = , y desarmados a través de unset . El comando vars imprime todas las variables que están definidas.

 kdebug> a = 7
 kdebug> b = 3 + a
 kdebug> a - = 2
 kdebug> expr c = b - a
 5 (0x5)
 kdebug> unset a
 kdebug> vars
                b: 10 (0xa)
                c: 5 (0x5)
          _hilo: 2148328320 (0x800ce380)
        _threadID: 1 (0x1)
            Equipo: 2424574464 (0x90841200)
          _teamID: 1 (0x1)
             _cpu: 0 (0x0)
                _: 5 (0x5)

En el ejemplo, se enumeran varias variables adicionales con un nombre que comienza con un guión bajo. Estas se denominan variables temporales y en este caso (excepto _ ) se configuraron automáticamente cuando se ingresó al depurador del kernel. _thread es el puntero a la estructura de administración interna del kernel del subproceso actual, _threadID su ID, _team la estructura del kernel del equipo actual, _teamID su ID, y _cpu el índice de la CPU en la que se está ejecutando el depurador del kernel.
Varios comandos también configuran variables temporales como un efecto secundario, por ejemplo, sem , que imprime información sobre un semáforo, también establece la variable _owner (la ID del equipo que posee el semáforo) y otros. La variable temporal _ se usa por convención como el valor de retorno de un comando (si tiene uno). En el ejemplo anterior, expr estableció en 5, que era el valor de la expresión que evaluó.
El número de variables temporales es limitado. Cuando se alcanza el límite y se define otra variable, la variable utilizada menos recientemente se desaloja automáticamente. Sin embargo, esto es válido solo para las variables temporales; Las variables no temporales también tienen un límite, pero están totalmente controladas por el usuario. Cuando se alcanza ese límite, no se puede definir una nueva variable hasta que otra se haya unset explícitamente.

Los comandos más populares

sc

sc ("stack crawl"), alias bt ("back trace"), alias where , imprime un seguimiento de pila del hilo con la ID dada o la dirección de la estructura del núcleo del hilo. Sin ningún argumento dado, se selecciona el hilo actual en la CPU actual.

 kdebug> sc
 seguimiento de la pila para el hilo 0x53 "evento de bucle"
     pila del núcleo: 0x90746000 a 0x9074a000
       pila de usuarios: 0x70145000 a 0x70185000
 llamador de marco <imagen>: función + desplazamiento
 90749c54 (+ 52) 8008187f <kernel>: invoke_debugger_command + 0x00cf
 90749c88 (+ 64) 80082620 <kernel>: _ParseCommand__16ExpressionParserRi + 0x01f8
 90749cc8 (+ 48) 80082012 <kernel>: EvaluateCommand__16ExpressionParserPCcRi + 0x01de
 90749cf8 (+ 228) 80083734 <kernel>: eval_debug_command + 0x0088
 90749ddc (+ 64) 80080680 <kernel>: kernel_debugger_loop__Fv + 0x0184
 90749e1c (+ 32) 800811b5 <kernel>: kernel_debugger + 0x00c9
 90749e3c (+ 192) 800810e1 <kernel>: panic + 0x0029
 90749efc (+ 48) 90771e19 </ boot / beos / system / add-ons / kernel / bus_managers / ps2>: ps2_interrupt + 0x00cd
 90749f2c (+ 64) 80027798 <kernel>: int_io_interrupt_handler + 0x00ac
 90749f6c (+ 48) 8008f75a <kernel>: hardware_interrupt + 0x007a
 90749f9c (+ 12) 800928a6 <kernel>: int_bottom_user + 0x005a (el más cercano)
 iframe en 0x90749fa8 (final = 0x9074a000)
  eax 0x13 ebx 0x2cdc78 ecx 0x180f7300 edx 0x29cd3
  esi 0x6a edi 0x92e3f054 ebp 0x70184acc esp 0x90749fdc
  eip 0x2900f5 eflags 0x202
  vector: 0x21, código de error: 0x0
 90749fa8 (+ 0) 002900f5 <_APP_>: _CopyToFront__C11HWInterfacePUcUlllll + 0x0279
 70184acc (+ 176) 0028f653 <_APP_>: CopyBackToFront__11HWInterfaceRC5BRect + 0x028b
 70184b7c (+ 48) 0028f3bd <_APP_>: Invalidate__11HWInterfaceRC5BRect + 0x0049
 70184bac (+ 416) 00288c66 <_APP_>: CopyRegion__13DrawingEngineP7BRegionll + 0x0686
 70184d4c (+ 208) 00247839 <_APP_>: MoveWindowBy__7DesktopP11WindowLayerffl + 0x02e5
 70184e1c (+ 112) 002808ac <_APP_>: MouseMoved__11WindowLayerP8BMessageG6BPointPlb + 0x0244
 70184e8c (+ 96) 002434ea <_APP_>: Filter__11MouseFilterP8BMessagePP11EventTargetPlT1 + 0x016a
 70184eec (+ 144) 0024ef46 <_APP_>: _EventLoop__15EventDispatcher + 0x02ae
 70184f7c (+ 48) 0024f657 <_APP_>: _event_looper__15EventDispatcherPv + 0x001f
 70184fac (+ 48) 00783264 <libroot.so>: _ get_next_team_info + 0x005c (el más cercano)
 70184fdc (+ 0) 70184fec 762: evento loop_53_stack @ 0x70145000 + 0x3ffec

El seguimiento de la pila es muy interesante, ya que muestra exactamente en qué función se encuentra actualmente el subproceso, desde qué función se ha llamado a esa función, etc. También se muestran las direcciones de los llamados marcos de pila, que son las direcciones base de los parámetros de las funciones respectivas y las variables locales.
Aproximadamente en el medio, el ejemplo de la pila anterior se interrumpe con un iframe (trama de interrupción). Un iframe termina en la pila cuando un hilo de usuario realiza una llamada al sistema (llamada al sistema), o una excepción (error de página, división por cero) o se produce una interrupción de hardware. El iframe inferior que se muestra para un hilo de usuario es siempre el de la transición al kernel. En el ejemplo, podemos ver que sucedió debido a una interrupción de hardware, lo cual no es sorprendente, ya que se debió al presionar el combo Alt-SysReq-D. Un iframe captura los registros del procesador en ese momento, así que junto con el desmontaje de la función respectiva es posible reconstruir, qué es exactamente lo que está sucediendo allí.

teams

teams enumera todos los equipos existentes, con su nombre, identificación y equipo de padres.

 kdebug> equipos
 identificación del equipo nombre del padre
 0x90841200 1 0x00000000 kernel_team
 0x90b0c200 128 0x909df600 sh
 0x909c0200 68 0x90906800 input_server
 0x908f4e00 41 0x90841200 registrador
 0x909c0e00 78 0x90841200 Rastreador
 0x908f9600 47 0x90841200 debug_server
 0x909d3600 79 0x90841200 Barra de escritorio
 0x90906200 48 0x90841200 net_server
 0x90906800 49 0x90841200 app_server
 0x909df600 81 0x90841200 Terminal
 0x909e4000 82 0x90841200 media_server
 0x90aaf200 114 0x909e4000 media_addon_server
 0x909e4a00 84 0x90841200 midi_server
 0x909f0200 85 0x90841200 print_server
 0x90906e00 61 0x90841200 syslog_daemon

Por lo general, este es el primer comando utilizado, cuando se busca un problema en un determinado programa, ya que el listado proporciona su ID de equipo.

threads

threads enumera todos los subprocesos de un equipo específico, o todos los subprocesos existentes, si no se proporciona ningún argumento

 kdebug> hilos 78
 hilo id estado sem / cv cpu pri pila nombre del equipo
 0x90b2d000 138 en espera 3921 - 5 0x99be1000 78 TrashWatcher
 0x90b14000 139 en espera 3950 - 5 0x99be5000 78 PortapapelesRefsWatcher
 0x90b28000 140 en espera 3961 - 5 0x99bd9000 78 AutoMounter
 0x90915000 78 en espera 2768 - 10 0x906d1000 78 Rastreador
 0x90b1e000 144 en espera 3995 - 15 0x99bf5000 78 w> Escritorio
 0x90abc000 115 en espera 3220 - 15 0x99b26000 78 w> Estado del rastreador
 0x90b43000 147 zzz 120 - 5 0x99d00000 78 TrackerTaskLoop

Para cada hilo se imprime una información compacta de una línea. Consiste en el puntero de la estructura del núcleo del subproceso, su ID, estado actual (en ejecución, en espera, etc.), el ID del semáforo o la variable de condición en la que está esperando actualmente (si existe), y otra información.

sem

sem imprime información sobre un semáforo, que puede especificarse por ID, dirección de su estructura de kernel o por nombre (aunque los nombres de semáforo no necesitan ser únicos).

 depuración> sem 2768
 SEM: 0x9930e700
 id: 2768 (0xad0)
 nombre: 'AppLooperPort'
 propietario: -1
 cuenta: -1
 cola: 78
 ultimo adquirido por: 78, cuenta: 1
 último publicado por: 78, cuenta: 1

De especial interés, particularmente cuando se analizan situaciones de interbloqueo, son las filas "último adquirido" y "último liberado". "último adquirido" muestra el ID del hilo que adquirió el semáforo con éxito. Este número es negado, si el semáforo fue lanzado después. En el caso de un punto muerto en el que se ve lo que está haciendo el último hilo de adquisición, por lo general se dará una idea de cuál es el problema. En una situación simple, esperaría un semáforo cuando el primer hilo adquiriera el último.
Los interbloqueos de la zona de usuario que incluyen BLocker (estilo predeterminado) de estilo BLocker no se pueden analizar tan fácilmente, ya que los sempahores respectivos no serán adquiridos por los hilos que sostienen las cerraduras. Sin embargo, en la mayoría de los casos, los rastros de pila de los hilos del equipo también ayudarán a comprender esos puntos muertos.

Rastreo De Kernel

Una característica de depuración bastante poderosa del kernel de Haiku es el rastreo del kernel. El kernel puede reservar una cantidad específica de memoria como buffer de rastreo y usarla para registrar información cuando ocurren ciertos eventos. En el depurador del núcleo, las entradas registradas se pueden filtrar e imprimir, lo que proporciona una herramienta de análisis para localizar errores y otros problemas. Una de las grandes ventajas del rastreo del kernel sobre la salida de depuración habitual en un archivo o mediante una conexión en serie es que viene con una penalización de rendimiento significativamente menor, que en la mayoría de los casos es incluso menor que el error de medición. También es muy bueno que los datos estén disponibles directamente en el depurador del kernel, de modo que uno pueda analizarlos en combinación con el sistema detenido.

Habilitándolo

El rastreo del kernel es una característica de tiempo de compilación, es decir, tiene que estar habilitada al construir Haiku. Esto se puede hacer en el archivo de encabezado build / user_config_headers / tracing_config. h build / user_config_headers / tracing_config. h (cree la carpeta y copie build / config_headers / tracing_config. h que contiene la configuración predeterminada) cambiando el valor de la macro ENABLE_TRACING al valor 1 . Además, es necesario especificar qué tipo de información se debe rastrear, lo que se hace estableciendo las macros respectivas en un valor mayor que 0:

BLOCK_CACHE_TRANSACTION_TRACING

Habilita el seguimiento de las transacciones de caché de bloque. Es muy probable que esto solo sea de interés para los desarrolladores que intentan rastrear la caché de bloques o los errores del sistema de archivos.

BMESSAGE_TRACING

Habilita el rastreo de envío de mensajes. Cada vez que se envía un mensaje, el destino del mensaje (equipo, puerto, token), el método de entrega (directo, remoto) y el campo "qué" del mensaje se registrarán.

KERNEL_HEAP_TRACING

Habilita el rastreo de asignaciones de memoria en el kernel. Para cada llamada a malloc ( ) , free ( ) o realloc ( ) en el kernel, los parámetros dados y el resultado serán registrados.

PAGE_ALLOCATION_TRACING

Habilita el rastreo de asignaciones de páginas en el kernel. Se registrará cómo las páginas se asignan, liberan, reservan, roban o limpian las páginas mediante el arrastre de páginas.

RUNTIME_LOADER_TRACING

Habilita el seguimiento de las actividades del cargador en tiempo de ejecución. Se registrará qué ejecutables, bibliotecas y complementos se cargan.

SIGNAL_TRACING

Habilita el rastreo de señales. Se registrará cuando se envíe una señal, se maneje, se enmascare o se instale un controlador de señales.

SYSCALL_TRACING

Habilita el rastreo de syscalls. Se registrará cuando un subproceso de la zona del usuario haya entrado en el kernel para ejecutar un syscall (incluidos los parámetros del syscall) y cuando esté a punto de salir del kernel de nuevo. Por lo general, uno también quiere definir la macro SYSCALL_TRACING_IGNORE_KTRACE_OUTPUT . Omite el rastreo del syscall _kern_ktrace_output (), que a su vez agrega una entrada de rastreo.

TEAM_TRACING

Permite el rastreo de las operaciones del equipo. Se registrará cuando un equipo está en fork ( ) ed o exec ( ) ed y cuando un equipo espera a sus hijos.

USER_MALLOC_TRACING

Habilita el rastreo de asignaciones de memoria en aplicaciones de usuario. Para cada llamada a malloc ( ) , free ( ) o realloc ( ) , etc., los parámetros dados y el resultado se registrarán. Tenga en cuenta que esto tiene un impacto considerable en el rendimiento.

La macro MAX_TRACE_SIZE define el tamaño del búfer de seguimiento (en bytes). El valor predeterminado de 1 MB es un poco ajustado, si se registra mucha información. El búfer de seguimiento es un búfer de anillo, es decir, cuando está lleno, comenzará a sobrescribir las entradas más antiguas.

El comando traced

El comando traced depurador del kernel imprime la información de rastreo registrada. Como normalmente habrá muchas entradas registradas, hay varios parámetros para especificar qué subconjunto se imprimirá. Las entradas en el búfer de seguimiento están indexadas; el más antiguo del búfer tiene el índice 1. El primer parámetro del traced es el índice de una entrada y el segundo el número de entradas que se imprimirán.

 kdebug> trazado 120 10
   120. [75] 62203012: syscall pre: _kern_read_port_etc (0x1025, 0x7003ff58, 0x7003ff24, 0x0, 0x0, 0x0)
   121. [75] 62203037: syscall post: _kern_read_port_etc () -> 0x0
   122. [75] 62203330: syscall pre: _kern_release_sem (0x857)
   123. [75] 62203352: syscall post: _kern_release_sem () -> 0x0
   124. [75] 62203545: syscall pre: _kern_ktrace_output (0x7003f9ac)
   125. [75] 62203558: usuario: envío remoto de mensajes de texto: equipo: -1, puerto: 4136, testigo: 0, mensaje: '_MMV'
   126. [75] 62203567: syscall post: _kern_ktrace_output () -> 0x20
   127. [75] 62203683: syscall pre: _kern_write_port_etc (0x1028, 0x706a7070, 0x1801c100, 0x121, 0x8, 0x1)
   128. [75] 62203724: syscall post: _kern_write_port_etc () -> 0x0
   129. [75] 62203871: syscall pre: _kern_port_buffer_size_etc (0x1025, 0x0, 0x0)
 impreso 10 entradas dentro del rango de 120 a 129 (10 de 20655 en total, 189725 siempre)

La información común que se incluye para cada entrada es el índice (entre corchetes), el ID del hilo que registra la entrada y la hora del sistema (en microsegundos) cuando se registró la entrada. Los siguientes datos son específicos para el tipo de entrada. Una línea final al final de la lista nos dice cuántas entradas se han impreso y de qué rango de índice (los ejemplos posteriores mostrarán que esta información no siempre es tan obvia), así como cuántas entradas hay actualmente en el búfer y cómo muchos se han registrado hasta ahora.
El segundo parámetro del comando se puede omitir; su valor predeterminado es 30. Si se da y es negativo, cambia el significado del primer parámetro. En lugar de especificar la primera entrada para imprimir, se referirá a la última, y ​​el valor negado del segundo parámetro define el número de entradas a listar.

 kdebug> trazado 120 -5
   116. [117] 62202452: syscall pre: _kern_write_port_etc (0x1025, 0x1, 0x0, 0x0, 0x8, 0x0)
   117. [117] 62202490: syscall post: _kern_write_port_etc () -> 0x0
   118. [117] 62202637: syscall pre: _kern_ioctl (0x13, 0x2773, 0x70143f54, 0x58cca4)
   119. [75] 62202872: syscall post: _kern_port_buffer_size_etc () -> 0x0
   120. [75] 62203012: syscall pre: _kern_read_port_etc (0x1025, 0x7003ff58, 0x7003ff24, 0x0, 0x0, 0x0)
 imprimió 5 entradas dentro del rango 116 a 120 (5 de 20655 en total, 189725 siempre)

Un valor especial para el primer parámetro es 0 (o cualquier valor negativo). Se refiere a la última entrada en el búfer y, además, hace que el segundo parámetro se interprete como negativo. Esto facilita la impresión de las últimas entradas grabadas.
Mirar a través de decenas o cientos de miles de entradas utilizando solo esos dos parámetros es poco práctico. Por lo tanto, hay un mecanismo de filtro simple pero poderoso. Un filtro se pasa a traced como una lista de parámetros adicionales precedidos por el filter palabras clave. Puede constar de varios filtros básicos que pueden combinarse a través de operadores booleanos para una expresión compleja. Esos operadores son and , or , y not , y se usan en notación de prefijo, lo que significa que el operador es el primero y va seguido por su uno, respectivamente, dos argumentos. Esto requiere un poco de tiempo para acostumbrarse, pero tiene las ventajas de que no requiere paréntesis (que ya están reservados para las expresiones numéricas del depurador del kernel) y que sigue analizando muy simple. Los filtros básicos son:

thread < thread id >

Coincide con las entradas registradas por el hilo con el ID especificado.

team < team id >

Coincide con las entradas registradas por un hilo del equipo con la ID especificada.

#<pattern>

Coincide con aquellas entradas cuya representación impresa contiene el patrón que distingue entre mayúsculas y minúsculas (en realidad no es un patrón real, solo una cadena). Si la cadena contiene espacios, se debe poner entre comillas (incluido el # ).

Muy útil en combinación con los filtros es el tercer parámetro numérico opcional del traced . Especifica en cuántas entradas se buscarán, como máximo, coincidencias (a diferencia del segundo parámetro que limita el número de entradas que se imprimirán). Si se omite, se utiliza el mismo valor dado para el segundo parámetro. El valor especial -1 significa que se buscarán todas las entradas en el búfer, que generalmente es lo que se quiere, pero que puede llevar mucho tiempo, cuando el búfer de seguimiento es grande y contiene muchas entradas. En el siguiente ejemplo, buscamos las entradas del equipo 41 que contienen el texto "Mensaje", imprimiendo cinco a la vez como máximo.

 kdebug> traza el filtro 0 5 -1 y el equipo 41 #BMessage
 16337. [44] 70393163: usuario: Enviar mensaje directo: puerto: 4, ficha: 1, mensaje: 'rgir'
 18402. [44] 71396774: usuario: Enviar mensaje directo: puerto: 4, ficha: 1, mensaje: 'rgir'
 19248. [44] 72402239: usuario: enviar mensaje directo: puerto: 4, ficha: 1, mensaje: 'rgir'
 19875. [44] 73404928: usuario: Enviar mensaje directo: puerto: 4, ficha: 1, mensaje: 'rgir'
 20489. [44] 74408450: usuario: Enviar mensaje directo: puerto: 4, ficha: 1, mensaje: 'rgir'
 imprimió 5 entradas dentro del rango 16337 a 20655 (4319 de 20655 en total, 189725 siempre)
 kdebug> trazado
  6027. [44] 65359596: usuario: Enviar mensaje directo: puerto: 4, ficha: 1, mensaje: 'rgir'
  6635. [44] 66363060: usuario: BMessage enviar directamente: puerto: 4, ficha: 1, mensaje: 'rgir'
  8968. [44] 67366540: usuario: enviar mensaje directo: puerto: 4, ficha: 1, mensaje: 'rgir'
 11422. [44] 68378551: usuario: Enviar mensaje directo: puerto: 4, ficha: 1, mensaje: 'rgir'
 13845. [44] 69386518: usuario: enviar mensaje directo: puerto: 4, ficha: 1, mensaje: 'rgir'
 Impreso 5 entradas dentro del rango 6027 a 16336 (10310 de 20655 en total, 189725 siempre)
 kdebug>
   611. [44] 62346221: usuario: BMessage send direct: puerto: 4, ficha: 1, mensaje: 'rgir'
  2770. [44] 63351796: usuario: BMessage enviar directamente: puerto: 4, ficha: 1, mensaje: 'rgir'
  5155. [44] 64355661: usuario: BMessage send direct: puerto: 4, ficha: 1, mensaje: 'rgir'
 imprimió 3 entradas dentro del rango 1 a 6026 (6026 de 20655 en total, 189725 siempre)

El ejemplo también muestra otra característica del comando traced . Cuando se invoca sin ningún parámetro, continúa la búsqueda de la invocación anterior. En este caso, la búsqueda continúa hacia atrás (el índice de inicio 0 implica una búsqueda hacia atrás), aún listando como máximo cinco entradas a la vez. En esta forma (y solo en esta forma) el traced es continuo, lo que significa que solo con presionar enter lo invocará nuevamente. Esto hace que navegar por las entradas sea muy conveniente.
traced admite algunas opciones de cambio que se pueden dar antes del primer argumento numérico. Uno es -- printteam que hace que también se -- printteam la ID del equipo que registró la entrada (después de dos puntos entre corchetes). Cuando -- difftime se especifica solo para la primera entrada, se imprime la hora absoluta del sistema. Para las entradas posteriores, se mostrará la diferencia horaria con respecto a la entrada impresa anteriormente. Si bien esta no es exactamente una opción de creación de perfiles, al menos puede usarse para obtener una primera impresión.

 kdebug> trazado --printteam 0 6 -1 filter #BMessage
 87852. [69: 69] 25882947: usuario: envío remoto de mensajes de correo: equipo: 82, puerto: 8252, ficha: -2, mensaje: '
 87960. [75: 69] 25952695: usuario: envío remoto de mensajes de texto: equipo: -1, puerto: 4136, testigo: 0, mensaje: '_MUP'
 87973. [88: 49] 25954926: usuario: envío remoto de mensajes de texto: equipo: 82, puerto: 28753, ficha: -2, mensaje: '_MUP'
 87980. [88: 49] 25955064: usuario: envío de mensajes remotos: equipo: 80, puerto: 32872, token: -2, mensaje: '_MUP'
 88148. [141: 78] 26090266: usuario: envío de mensajes remotos: equipo: -1, puerto: 28, token: -2, mensaje: 'Iuim'
 88161. [69: 69] 26090779: usuario: envío remoto de BMessage: equipo: 78, puerto: 8245, ficha: -2, mensaje: '
 imprimió 6 entradas dentro del rango 87852 a 88451 (600 de 88451 en total, 88451 siempre)
 kdebug> trace --difftime 0 7 -1 subproceso de filtro 43
 88197. [43] 26159620: syscall pre: _kern_snooze_etc (0x186a0, 0x0, 0x8)
 88254. [43] 100557: syscall post: _kern_snooze_etc () -> 0x0
 88255. [43] 70: syscall pre: _kern_snooze_etc (0x186a0, 0x0, 0x8)
 88406. [43] 100593: syscall post: _kern_snooze_etc () -> 0x0
 88407. [43] 65: syscall pre: _kern_snooze_etc (0x186a0, 0x0, 0x8)
 88440. [43] 100656: syscall post: _kern_snooze_etc () -> 0x0
 88441. [43] 71: syscall pre: _kern_snooze_etc (0x186a0, 0x0, 0x8)
 imprimió 7 entradas dentro del rango 88197 a 88451 (255 de 88451 en total, 88451 siempre)

Un ejemplo de sesión de depuración

Las secciones anteriores introdujeron todo lo que se necesita para encontrar una gran variedad de errores y problemas. Sin embargo, no en todos los casos el depurador del kernel es la mejor opción. Para errores fácilmente reproducibles en aplicaciones de la zona de usuario, la impresión simple printf ( ) depuración o el uso de gdb como un depurador de nivel de fuente podría ser una mejor opción. Sin embargo, algunos problemas, especialmente los que son difíciles de reproducir, conducen a situaciones que hacen que la depuración en el país sea imposible (por ejemplo, cuando ya no se puede iniciar el Terminal), o son condiciones de carrera que desaparecen al agregar demasiada salida de depuración. A menudo es mejor analizarlo con el depurador del kernel.
Esta sección documenta una sesión de depuración que descubre el error # 1745 que se produce en la revisión 23864. Es la primera vez que encuentro el error y, gracias a tener siempre habilitado el rastreo del kernel para syscalls, señales, equipos y BMessage , toda la información necesaria para El análisis ya estaba disponible. Los síntomas del error son que, justo después de arrancar, Deskbar se bloquea y el Rastreador ni siquiera aparece. Aquí vamos...

 PÁNICO: el teclado pidió que se detuviera.

 Bienvenido a Kernel Debugging Land ...
 Ejecutando en la CPU 0
 kdebug> equipos
 identificación del equipo nombre del padre
 0x9083e200 1 0x00000000 kernel_team
 0x908f0c00 36 0x9083e200 registrador
 0x90992e00 69 0x9083e200 Tracker
 0x908f5a00 40 0x9083e200 debug_server
 0x909b2e00 72 0x9083e200 Deskbar
 0x909cb000 73 0x9083e200 sh
 0x90900000 43 0x9083e200 net_server
 0x90900600 44 0x9083e200 app_server
 0x909dd000 77 0x9083e200 Terminal
 0x909dd600 78 0x9083e200 media_server
 0x909f4400 80 0x9083e200 midi_server
 0x90a40a00 81 0x9083e200 servidor de impresión
 0x90afd200 115 0x909dd000 sh
 0x909cba00 87 0x909cb000 ProcessController
 0x90900c00 56 0x9083e200 syslog_daemon
 0x90b08c00 121 0x909dd600 media_addon_server
 0x909b1c00 61 0x90900600 input_server
 kdebug> tracker = 69
 kdebug> deskbar = 72
 kdebug> hilos (rastreador)
 hilo id estado sem / cv cpu pri pila nombre del equipo
 0x90b25800 128 en espera 3834 - 5 0x90784000 69 TrashWatcher
 0x90ac7800 97 en espera 2974 - 15 0x906ed000 69 w> Estado del rastreador
 0x90b40800 129 en espera 3866 - 5 0x90788000 69 PortapapelesRefsWatcher
 0x90b3f800 130 en espera 3877 - 5 0x9079b000 69 AutoMounter
 0x90919000 69 en espera 2595 - 10 0x9063d000 69 rastreador
 0x90b48000 133 en espera 3917 - 15 0x99a0f000 69 w> Escritorio

teams nos dicen que, aunque no se presentó, Tracker está funcionando. De acuerdo con los threads todos sus hilos habituales están también allí. Veamos, ¿qué es lo que hace que la ventana del escritorio ("w> Escritorio") no muestre ningún icono:

 kdebug> sem 3917
 SEM: 0x99318e70
 id: 3917 (0xf4d)
 nombre: 'TrackerWindow'
 propietario: 69
 cuenta: -1
 cola: 133
 ultimo adquirido por: 69, cuenta: 1
 último publicado por: 133, cuenta: 1
 kdebug> sc 133
 traza de pila para el hilo 133 "w> Escritorio"
     pila de kernel: 0x99a0f000 a 0x99a13000
       pila de usuarios: 0x70145000 a 0x70185000
 llamador de marco <imagen>: función + desplazamiento
 99a12e48 (+ 32) 8002d352 <kernel>: context_switch__FP6threadT0 + 0x0026
 99a12e68 (+ 64) 8002d5e6 <kernel>: scheduler_reschedule + 0x0272
 99a12ea8 (+ 96) 8002ea5d <kernel>: switch_sem_etc + 0x039d
 99a12f08 (+ 64) 8002f303 <kernel>: _user_acquire_sem_etc + 0x0027
 99a12f48 (+ 96) 80091a13 <kernel>: x86_sysenter + 0x00ef (el más cercano)
 iframe en 0x99a12fa8 (final = 0x99a13000)
  eax 0xc ebx 0x766048 ecx 0x70184df0 edx 0xffff0104
  esi 0xffffffff edi 0x7fffffff ebp 0x70184e2c esp 0x99a12fdc
  eip 0xffff0104 eflags 0x203
  vector: 0x63, código de error: 0x0
 99a12fa8 (+ 0) ffff0104
 70184e2c (+ 64) 002e7f7c <libbe.so>: _ LockComplete__7BLooperP7BLooperlllx + 0x0034
 70184e6c (+ 80) 002e7e89 <libbe.so>: _ Lock__7BLooperP7BLooperlx + 0x01c1
 70184ebc (+ 48) 002e6e81 <libbe.so>: Lock__7BLooper + 0x002d
 70184eec (+ 128) 003be877 <libbe.so>: task_looper__7BWindow + 0x0137
 70184f6c (+ 64) 002e82cb <libbe.so>: _ task0___7BLooperPv + 0x0053
 70184fac (+ 48) 006e9264 <libroot.so>: _ get_next_team_info + 0x005c (el más cercano)
 70184fdc (+ 0) 70184fec 1261: w> TrackerWindow_133_stack @ 0x70145000 + 0x3ffec
 kdebug> escritorio = 133

El semáforo que el hilo de la ventana está esperando pertenece al bloqueo BWindow . El hilo está en el bucle de despachador de mensajes de la ventana, tratando de bloquear la ventana, para que pueda enviar el siguiente mensaje. Alguien más ya tiene la cerradura y aparentemente no la libera. Desafortunadamente, el bloqueo en cuestión es un BLocker de estilo benáforo, por lo que la salida "adquirida por última vez" no suele ser de mucha ayuda. En este caso, muestra el hilo 69, el hilo principal del Rastreador, como último adquirente. Puede o no puede ser el propietario real de la cerradura; En cualquier caso, no está mal tener una vista más cercana de lo que está haciendo el hilo:

 kdebug> sc (rastreador)
 traza de la pila para el hilo 69 "Tracker"
     pila del núcleo: 0x9063d000 a 0x90641000
       pila de usuarios: 0x7efe7000 a 0x7ffe7000
 llamador de marco <imagen>: función + desplazamiento
 90640dd8 (+ 32) 8002d352 <kernel>: context_switch__FP6threadT0 + 0x0026
 90640df8 (+ 64) 8002d5e6 <kernel>: scheduler_reschedule + 0x0272
 90640e38 (+ 96) 8002ea5d <kernel>: switch_sem_etc + 0x039d
 90640e98 (+ 64) 8002e692 <kernel>: adquiere_sem_etc + 0x0026
 90640ed8 (+ 80) 8002bd6c <kernel>: port_buffer_size_etc + 0x00ec
 90640f28 (+ 32) 8002c859 <kernel>: _user_port_buffer_size_etc + 0x001d
 90640f48 (+ 96) 80091a13 <kernel>: x86_sysenter + 0x00ef (el más cercano)
 iframe en 0x90640fa8 (final = 0x90641000)
  eax 0x8f ebx 0x766048 ecx 0x7ffe5f80 edx 0xffff0104
  esi 0xffffffff edi 0x7fffffff ebp 0x7ffe5fac esp 0x90640fdc
  eip 0xffff0104 eflags 0x216
  vector: 0x63, código de error: 0x0
 90640fa8 (+ 0) ffff0104
 7ffe5fac (+ 48) 002eeea3 <libbe.so>: _ SendFlattenedMessage__8BMessagePvlllx + 0x011b (el más cercano)
 7ffe5fdc (+ 144) 002eec88 <libbe.so>: _ SendMessage__C8BMessagelllP8BMessagexx + 0x01f8
 7ffe606c (+ 80) 0030cbc7 <libbe.so>: SendMessage__CQ28BMessage7PrivatelllP8BMessagexx + 0x0043
 7ffe60bc (+ 80) 002f5ea4 <libbe.so>: SendMessage__C10BMessengerP8BMessageT1xx + 0x0070
 7ffe610c (+ 240) 0032c5d8 <libbe.so>: get_deskbar_frame__FP5BRect + 0x00c0
 7ffe61fc (+ 144) 0060d2b4 <libtracker.so>: PlacePose__Q28BPrivate9BPoseViewPQ28BPrivate5BPoseR5BRect + 0x013c
 7ffe628c (+ 192) 00608065 <libtracker.so>: CreatePoses__Q28BPrivate9BPoseViewPPQ28BPrivate5ModelPQ28BPrivate8PoseInfolPPQ28BPrivate5BPosebPlP5BRectT5 + 0x06a5
 7ffe634c (+ 80) 0060783e <libtracker.so>: CreatePose__Q28BPrivate9BPoseViewPQ28BPrivate5ModelPQ28BPrivate8PoseInfobPlP5BRectT3 + 0x0056
 7ffe639c (+ 96) 00613e5f <libtracker.so>: EntryCreated__Q28BPrivate9BPoseViewPC8node_refT1PCcPl + 0x018b
 7ffe63fc (+ 256) 006076e1 <libtracker.so>: CreateVolumePose__Q28BPrivate9BPoseViewP7BVolumeb + 0x0111
 7ffe64fc (+ 352) 00606fe6 <libtracker.so>: AddRootPoses__Q28BPrivate9BPoseViewbT1 + 0x0252
 7ffe665c (+ 112) 00605f5f <libtracker.so>: AddPoses__Q28BPrivate9BPoseViewPQ28BPrivate5Model + 0x010f
7ffe66cc (+ 96) 006036a7 <libtracker.so>: InitCommon__Q28BPrivate9BPoseView + 0x0383
7ffe672c (+ 64) 006032d0 <libtracker.so>: Init__Q28BPrivate9BPoseViewPQ28BPrivate19AttributeStreamNode + 0x003c
7ffe676c (+ 80) 0057f832 <libtracker.so>: RestoreState__Q28BPrivate16BContainerWindow + 0x00ce
7ffe67bc (+ 224) 0057f390 <libtracker.so>: Init__Q28BPrivate16BContainerWindowPC8BMessage + 0x0920
7ffe689c (+ 128) 00592d6f <libtracker.so>: Init__Q28BPrivate11BDeskWindowPC8BMessage + 0x0237
7ffe691c (+ 528) 00649263 <libtracker.so>: ReadyToRun__Q28BPrivate8TTracker + 0x044b
7ffe6b2c (+ 528) 002dd27d <libbe.so>: DispatchMessage__12BApplicationP8BMessageP8BHandler + 0x0369
7ffe6d3c (+ 96) 002e8831 <libbe.so>: task_looper__7BLooper + 0x0299
7ffe6d9c (+ 64) 002db742 <libbe.so>: Run__12BApplication + 0x008a
7ffe6ddc (+ 416) 002009eb <_APP_>: main + 0x002f
7ffe6f7c (+ 48) 00200897 <_APP_>: _start + 0x005b
7ffe6fac (+ 48) 001007be 689: runtime_loader_seg0ro @ 0x00100000 + 0x7be
7ffe6fdc (+ 0) 7ffe6fec 674: Tracker_main_stack @ 0x7efe7000 + 0xffffec

Actualmente, obviamente está esperando una respuesta sincrónica a un mensaje que acaba de enviar ( en la parte del núcleo de la traza de la pila). El seguimiento de la pila también muestra que el hilo está todavía en el 's método y se invoca desde allí. Esta es, al menos, una buena razón para bloquear la ventana. Entonces, ¿quién no responde al mensaje?_user_port_buffer_size_etc ( )BApplicationReadyToRun ( )BDeskWindow :: Init ( )

kdebug> rastreado 0 -10 -1 hilo (rastreador)
80228. [69] 71666364: syscall pre: _kern_set_port_owner (0x1029, 0x48)
80229. [69] 71666387: syscall post: _kern_set_port_owner () -> 0x0
80230. [69] 71666438: syscall pre: _kern_get_port_info (0x1029, 0x7ffe5f18)
80231. [69] 71666628: syscall post: _kern_get_port_info () -> 0x0
80232. [69] 71666716: syscall pre: _kern_ktrace_output (0x7ffe5b0c)
80233. [69] 71666727: usuario: envío remoto de BMessage: equipo: -1, puerto: 4144, token: -2, mensaje: 'PGET'
80234. [69] 71666754: syscall post: _kern_ktrace_output () -> 0x20
80235. [69] 71666769: syscall pre: _kern_write_port_etc (0x1030, 0x706a7070, 0x180ab8a0, 0x125, 0x8, 0x7ffffffffffffffff)
80236. [69] 71666863: syscall post: _kern_write_port_etc () -> 0x0
80237. [69] 71666904: syscall pre: _kern_port_buffer_size_etc (0x1029, 0x8, 0x7fffffffffffffff)
imprimió 10 entradas dentro del rango 80228 a 90162 (9935 de 90162 en total, 90162 siempre)
kdebug> puerto 4144
PUERTO: 0x80135900
 id: 4144
 nombre: "AppLooperPort"
 propietario: 72
 capacidad: 100
 read_sem: 2662
 write_sem: 2663
 recuento de read_sem: 2
 recuento de write_sem: 98
 recuento total: 7
kdebug> hilos 72
hilo id estado sem / cv cpu pri pila nombre del equipo
0x90ac1800 95 en espera 2637 - 5 0x906e5000 72 TrackerTaskLoop
0x90ad1800 101 en espera 2637 - 15 0x906fd000 72 w> Twitcher
0x909c9000 72 en espera 3275 - 10 0x90669000 72 Barra de escritorio
0x90b06800 119 en espera 2637 - 5 0x90735000 72 Observador de la ventana de Expando
0x90b07000 120 en espera 2637 - 15 0x90739000 72 w> Barra de escritorio

Según lo registrado por la entrada de rastreo 80233, el mensaje se envió al puerto 4144. El propietario del puerto es el equipo 72, la Barra de escritorio, y el puerto en sí es, según su nombre, el BApplicationpuerto del looper. El threadslistado para el equipo de Deskbar parece sospechoso. Todos los hilos guardan el hilo principal y esperan el mismo semáforo, que pertenece a ...

kdebug> sem 2637
SEM: 0x99309e70
id: 2637 (0xa4d)
nombre: 'bloqueo de blooperlist'
propietario: 72
cuenta: -4
cola: 120 119 101 95
ultimo adquirido por: 0, cuenta: 0
último publicado por: 0, cuenta: 0

... la BLooperListcerradura. El BLooperListes una lista de todos los BLoopers de un equipo. Su principal objetivo es permitir la invocación de ciertos métodos ( , ) en punteros que ya no son necesariamente válidos. Esos métodos simplemente buscan el puntero antes de hacer algo con él que pueda causar un acceso de memoria no válido. La lista está protegida por un bloqueo, que debe mantenerse cuando se trabaja con la lista y también se puede mantener durante un breve período de tiempo para garantizar que no se eliminará ningún looper durante ese tiempo. Sin embargo, la cerradura es una cerradura más interna, es decir, mientras se mantiene, no se puede adquirir ninguna otra cerradura para evitar bloqueos potenciales. Ser unLock ( )PostMessage ( )BLooperBLooperListBLockery, por lo tanto, que admite el bloqueo anidado, también está claro que ninguno de los subprocesos que esperan el bloqueo es su propietario actual, lo que deja solo el subproceso de la barra de escritorio. A ver, qué está haciendo y por qué está esperando:

kdebug> sc 72
traza de pila para el hilo 72 "Barra de escritorio"
    pila del núcleo: 0x90669000 a 0x9066d000
      pila de usuarios: 0x7efe7000 a 0x7ffe7000
llamador de marco <imagen>: función + desplazamiento
9066ce48 (+ 32) 8002d352 <kernel>: context_switch__FP6threadT0 + 0x0026
9066ce68 (+ 64) 8002d5e6 <kernel>: scheduler_reschedule + 0x0272
9066cea8 (+ 96) 8002ea5d <kernel>: switch_sem_etc + 0x039d
9066cf08 (+ 64) 8002f303 <kernel>: _user_acquire_sem_etc + 0x0027
9066cf48 (+ 96) 80091a13 <kernel>: x86_sysenter + 0x00ef (el más cercano)
iframe en 0x9066cfa8 (final = 0x9066d000)
 eax 0xc ebx 0x7af048 ecx 0x7ffe66e0 edx 0xffff0104
 esi 0xffffffff edi 0x7fffffff ebp 0x7ffe671c esp 0x9066cfdc
 eip 0xffff0104 eflags 0x203
 vector: 0x63, código de error: 0x0
9066cfa8 (+ 0) ffff0104
7ffe671c (+ 64) 00477bdc <libbe.so>: AcquireLock__7BLockerxPl + 0x0064
7ffe675c (+ 48) 004779b3 <libbe.so>: Lock__7BLocker + 0x002f
7ffe678c (+ 48) 003546bd <libbe.so>: __ 9BAutolockR7BLocker + 0x002d
7ffe67bc (+ 64) 0033ce30 <libbe.so>: AddMessage__13BMessageQueueP8BMessage + 0x0034
7ffe67fc (+ 48) 0032af20 <libbe.so>: AddMessage__Q28BPrivate20BDirectMessageTargetP8BMessage + 0x0060
7ffe682c (+ 144) 00337911 <libbe.so>: _ SendMessage__C8BMessagelllxbR10BMessenger + 0x0319
7ffe68bc (+ 64) 00355b70 <libbe.so>: SendMessage__CQ28BMessage7PrivatelllxbR10BMessenger + 0x0040
7ffe68fc (+ 64) 0033ed01 <libbe.so>: SendMessage__C10BMessengerP8BMessageG10BMessengerx + 0x0069
7ffe693c (+ 112) 0033ec19 <libbe.so>: SendMessage__C10BMessengerP8BMessageP8BHandlerx + 0x0071
7ffe69ac (+ 96) 00330ba3 <libbe.so>: _ PostMessage__7BLooperP8BMessageP8BHandlerT2 + 0x010f
7ffe6a0c (+ 48) 0032f67c <libbe.so>: PostMessage__7BLooperP8BMessage + 0x0024
7ffe6a3c (+ 176) 0021c417 <_APP_>: MessageReceived__7TBarAppP8BMessage + 0x021b
7ffe6aec (+ 48) 0032f808 <libbe.so>: DispatchMessage__7BLooperP8BMessageP8BHandler + 0x0074
7ffe6b1c (+ 528) 003263f8 <libbe.so>: DispatchMessage__12BApplicationP8BMessageP8BHandler + 0x04e4
7ffe6d2c (+ 96) 00331831 <libbe.so>: task_looper__7BLooper + 0x0299
7ffe6d8c (+ 64) 00324742 <libbe.so>: Run__12BApplication + 0x008a
7ffe6dcc (+ 432) 0021aeff <_APP_>: main + 0x002f
7ffe6f7c (+ 48) 0021adab <_APP_>: _start + 0x005b
7ffe6fac (+ 48) 001007be 727: runtime_loader_seg0ro @ 0x00100000 + 0x7be
7ffe6fdc (+ 0) 7ffe6fec 723: Deskbar_main_stack @ 0x7efe7000 + 0xffffec
kdebug> trazado 0 -10 -1 hilo 72
64131. [72] 63166139: syscall pre: _kern_port_count (0x1030)
64132. [72] 63166161: syscall post: _kern_port_count () -> 0x0
64133. [72] 63166217: syscall pre: _kern_acquire_sem_etc (0xa65, 0x1, 0x8, 0x7fffffffffffffff)
64134. [72] 63166234: syscall post: _kern_acquire_sem_etc () -> 0x0
64135. [72] 63166506: syscall pre: _kern_get_port_info (0x2051, 0x7ffe67f8)
64136. [72] 63166539: syscall post: _kern_get_port_info () -> 0x0
64137. [72] 63166651: syscall pre: _kern_ktrace_output (0x7ffe63ec)
64138. [72] 63166666: usuario: Enviar mensaje directo: puerto: 16474, testigo: 12, mensaje: 'exst'
64139. [72] 63166690: syscall post: _kern_ktrace_output () -> 0x20
64140. [72] 63166723: syscall pre: _kern_acquire_sem_etc (0xccb, 0x1, 0x8, 0x7fffffffffffffff)
Impreso 10 entradas dentro del rango 64131 a 90162 (26032 de 90162 en total, 90162 siempre)
kdebug> puerto 16474
PUERTO: 0x801360e0
 id: 16474
 nombre: "barra de escritorio"
 propietario: 72
 capacidad: 100
 read_sem: 3277
 write_sem: 3278
 recuento de read_sem: 26
 recuento de write_sem: 74
 recuento total: 23
kdebug> sem 3275
SEM: 0x99311610
id: 3275 (0xccb)
nombre: 'BMessageQueue Lock'
propietario: 72
cuenta: -1
cola: 72
ultimo adquirido por: 0, cuenta: 0
último publicado por: 0, cuenta: 0 

De acuerdo con el seguimiento de la pila, el hilo está intentando enviar un mensaje. tracednos dice que es un mensaje "directo" (es decir, dentro de la aplicación) al puerto 16474, que pertenece a la ventana "Barra de escritorio". Sin embargo, los mensajes dentro de la aplicación no se envían realmente a un puerto. En su lugar, se agregan directamente a la cola de mensajes del destino. El semáforo que el hilo está esperando pertenece a eso BMessageQueue. En primer lugar, al examinar el código fuente de las funciones enumeradas en el seguimiento de pila, se revela dónde se BLooperListestá reteniendo el bloqueo, aunque no debería:

BLooper :: _ PostMessage (BMessage * msg, BHandler * handler,
    BHandler * replyTo)
 {
    AutoLocker <BLooperList> listLocker (gLooperList);
    if (! listLocker.IsLocked ())
        devuelve B_ERROR;

    if (! gLooperList.IsLooperValid (this))
        devuelve B_BAD_VALUE;

    // ¿El manejador pertenece a este looper?
    if (handler && handler-> Looper ()! = this)
        devuelve B_MISMATCHED_VALUES;

    status_t status;
    Mensajero de BMessenger (manejador, esto, y estado);
    si (estado == B_OK)
        status = messenger.SendMessage (msg, replyTo, 0);

    estado de retorno;
 } 

El bloqueo se mantiene hasta el final del método, incluida la línea donde se llama. Esto es un error: el bloqueo debe liberarse después de la construcción del último, a más tardar.messenger. SendMessage ( )BMessenger
Sin embargo, este es solo un problema. Al igual que el BLooperListbloqueo BMessageQueue, no se debe mantener un bloqueo al intentar adquirir otro bloqueo. Ese es el hilo principal que no debe bloquear en dicho bloqueo durante mucho tiempo, ya que el propietario debería liberarlo eventualmente. Aparte de las entregas directas de mensajes, la cola de mensajes normalmente solo se utiliza dentro del looper al que pertenece. Por lo tanto, es probable que en este caso el hilo de la ventana lo sostenga, aunque no debería:

kdebug> sc 120
Rastreo de pila para el hilo 120 "w> Barra de escritorio"
    pila del núcleo: 0x90739000 a 0x9073d000
      pila de usuarios: 0x700c3000 a 0x70103000
llamador de marco <imagen>: función + desplazamiento
9073ce48 (+ 32) 8002d352 <kernel>: context_switch__FP6threadT0 + 0x0026
9073ce68 (+ 64) 8002d5e6 <kernel>: scheduler_reschedule + 0x0272
9073cea8 (+ 96) 8002ea5d <kernel>: switch_sem_etc + 0x039d
9073cf08 (+ 64) 8002f303 <kernel>: _user_acquire_sem_etc + 0x0027
9073cf48 (+ 96) 80091a13 <kernel>: x86_sysenter + 0x00ef (el más cercano)
iframe en 0x9073cfa8 (final = 0x9073d000)
 eax 0xc ebx 0x7af048 ecx 0x701024d0 edx 0xffff0104
 esi 0xffffffff edi 0x7fffffff ebp 0x7010250c esp 0x9073cfdc
 eip 0xffff0104 eflags 0x207
 vector: 0x63, código de error: 0x0
9073cfa8 (+ 0) ffff0104
7010250c (+ 64) 00477bdc <libbe.so>: AcquireLock__7BLockerxPl + 0x0064
7010254c (+ 48) 004779b3 <libbe.so>: Lock__7BLocker + 0x002f
7010257c (+ 48) 003322d0 <libbe.so>: Lock__Q28BPrivate11BLooperList + 0x0020
701025ac (+ 48) 0034c21c <libbe.so>: Lock__Q28BPrivatet25AutoLockerStandardLocking1ZQ28BPrivate11BLooperListPQ28BPrivate11BLooperList + 0x0024
701025dc (+ 48) 0034c0c1 <libbe.so>: Lock__Q28BPrivatet10AutoLocker2ZQ28BPrivate11BLooperListZQ28BPrivatet25AutoLockerStandardLocking1ZQ28BPrivate11BLooperList + 0x0031
7010260c (+ 48) 0034bef4 <libbe.so>: __ Q28BPrivatet10AutoLocker2ZQ28BPrivate11BLooperListZQ28BPrivatet25AutoLockerStandardLocking1ZQ28BPrivate11BLooperList R
7010263c (+ 64) 00330d24 <libbe.so>: _ Lock__7BLooperP7BLooperlx + 0x005c
7010267c (+ 48) 0032fe81 <libbe.so>: Lock__7BLooper + 0x002d
701026ac (+ 48) 004009bc <libbe.so>: Flush__C7BWindow + 0x0020
701026dc (+ 48) 003f3ee1 <libbe.so>: Flush__C5BView + 0x0029
7010270c (+ 112) 003fdda0 <libbe.so>: _ Draw__5BViewG5BRect + 0x011c
7010277c (+ 736) 004033e9 <libbe.so>: DispatchMessage__7BWindowP8BMessageP8BHandler + 0x1cb9
70102a5c ​​(+ 64) 00404a29 <libbe.so>: UpdateIfNeeded__7BWindow + 0x00f9
70102a9c (+ 112) 00229cee <_APP_>: AddTeam__15TExpandoMenuBarP5BListP7BBitmapPcT3 + 0x032a
70102b0c (+ 160) 00228f3d <_APP_>: MessageReceived__15TExpandoMenuBarP8BMessage + 0x0195
70102bac (+ 48) 0032f808 <libbe.so>: DispatchMessage__7BLooperP8BMessageP8BHandler + 0x0074
70102bdc (+ 736) 004037c0 <libbe.so>: DispatchMessage__7BWindowP8BMessageP8BHandler + 0x2090
70102ebc (+ 48) 002220ec <_APP_>: DispatchMessage__10TBarWindowP8BMessageP8BHandler + 0x0054
70102eec (+ 128) 00407a66 <libbe.so>: task_looper__7BWindow + 0x0326
70102f6c (+ 64) 003312cb <libbe.so>: _ task0___7BLooperPv + 0x0053
70102fac (+ 48) 00732264 <libroot.so>: _ get_next_team_info + 0x005c (el más cercano)
70102fdc (+ 0) 70102fec 1156: w> Deskbar_120_stack @ 0x700c3000 + 0x3ffec

Después de examinar el código fuente de las funciones enumeradas en el seguimiento de pila, el código erróneo parece estar en :BWindow :: UpdateIfNeeded ( )

    BMessageQueue * queue = MessageQueue ();
    queue-> Lock ();

    // Primer proceso y eliminar cualquier mensaje _UPDATE_ en la cola
    // Con el diseño actual, solo puede haber uno a la vez

    Mensaje * msg;
    para (int32 i = 0; (msg = queue-> FindMessage (i))! = NULL; i ++) {
        if (msg-> what == _UPDATE_) {
            BWindow :: DispatchMessage (msg, este);
                // necesitamos asegurarnos de que no se llame a ningún método anulado
                // aquí; para BWindow :: DispatchMessage () ahora exactamente qué
                // pasará
            queue-> RemoveMessage (msg);
            eliminar msg;
             descanso;
                // NOTA: "i" tendría que disminuirse si hubiera
                // ¡Múltiples mensajes _UPDATE_ y no nos romperíamos!
         }
     }

    queue-> Unlock ();

BWindow :: DispatchMessage ( )se invoca mientras se mantiene el bloqueo de la cola de mensajes. llama a varias funciones, incluidas las que los desarrolladores de aplicaciones pueden anular. Entonces, aunque el comentario sugiere que llamar está bien, definitivamente no lo está.DispatchMessage ( )BView :: Draw ( )UpateIfNeeded ( )DispatchMessage ( )
Para resumir nuestros hallazgos: El rastreador se cuelga porque todavía está en su fase de inicialización y espera un mensaje de respuesta desde la barra de escritorio. La BLooperListbarra del escritorio, a su vez, se ha topado con un interbloqueo estándar con el bloqueo y el bloqueo de cola de mensajes de la ventana de la barra del escritorio implicado. El hilo principal y el de la ventana esperan mutuamente el bloqueo que mantiene el otro hilo respectivo.

Conclusión

El depurador de kernel de Haiku es una herramienta poderosa cuya utilidad no termina en el dominio del kernel. También puede ayudar con ciertos problemas de usuarios, que de otro modo serían difíciles de abordar. Este documento proporcionó una introducción a las características básicas del depurador de kernel, sus comandos más utilizados y el mecanismo de rastreo del kernel. Concluyó con una sesión de depuración documentada que muestra cómo aplicar la información presentada anteriormente para localizar un error en la práctica.
Espero que después de leer este documento, los desarrolladores de Haiku se sientan animados a considerar si el uso del depurador del kernel podría llevarlos a una solución más rápida cuando se enfrentan a un problema en Haiku. En particular, mantener el rastreo económico del kernel habilitado en todo momento podría proporcionar información útil cuando sea necesario.