/var/log/messages, /var/log/syslogy algunos otros archivos de registro usan una marca de tiempo que contiene un tiempo absoluto, como Jan 13 14:13:10.
/var/log/Xorg.0.logy /var/log/dmesg, además de la salida de $ dmesg, use un formato que se vea como
[50595.991610] malkovich: malkovich malkovich malkovich malkovich
Supongo que los números representan segundos y microsegundos desde el inicio.
Sin embargo, mi intento de correlacionar estos dos conjuntos de marcas de tiempo (usando la salida de uptime) dio una discrepancia de aproximadamente 5000 segundos.
Esta es aproximadamente la cantidad de tiempo que mi computadora estuvo suspendida.
¿Hay una manera conveniente de asignar las marcas de tiempo numéricas utilizadas por dmesg y Xorg en marcas de tiempo absolutas?
actualizar
Como un paso preliminar para resolver esto, y también para que mi pregunta sea un poco más clara, he escrito un script de Python para analizar /var/log/syslogy generar el sesgo de tiempo. En mi máquina, ejecutando ubuntu 10.10, ese archivo contiene numerosas líneas originadas en el núcleo que están estampadas con la marca de tiempo dmesg y la marca de tiempo syslog. El script genera una línea para cada línea en ese archivo que contiene una marca de tiempo del núcleo.
Uso:
python syslogdriver.py /var/log/syslog | column -nts $'\t'
Salida expurgada (ver abajo para las definiciones de columna):
abs abs_since_boot rel_time rel_offset message
Jan 13 07:49:15 32842.1276569 32842.301498 0 malkovich malkovich
... rel_offsetes 0 para todas las líneas intermedias ...
Jan 13 09:55:14 40401.1276569 40401.306386 0 PM: Syncing filesystems ... done.
Jan 13 09:55:14 40401.1276569 40401.347469 0 PM: Preparing system for mem sleep
Jan 13 11:23:21 45688.1276569 40402.128198 -5280 Skipping EDID probe due to cached edid
Jan 13 11:23:21 45688.1276569 40402.729152 -5280 Freezing user space processes ... (elapsed 0.03 seconds) done.
Jan 13 11:23:21 45688.1276569 40402.760110 -5280 Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
Jan 13 11:23:21 45688.1276569 40402.776102 -5280 PM: Entering mem sleep
... rel_offsetes -5280 para todas las líneas restantes ...
Jan 13 11:23:21 45688.1276569 40403.149074 -5280 ACPI: Preparing to enter system sleep state S3
Jan 13 11:23:21 45688.1276569 40403.149477 -5280 PM: Saving platform NVS memory
Jan 13 11:23:21 45688.1276569 40403.149495 -5280 Disabling non-boot CPUs ...
Jan 13 11:23:21 45688.1276569 40403.149495 -5280 Back to C!
Jan 13 11:23:21 45688.1276569 40403.149495 -5280 PM: Restoring platform NVS memory
Jan 13 11:23:21 45688.1276569 40403.151034 -5280 ACPI: Waking up from system sleep state S3
... Las líneas finales son un poco más abajo, aún muy por encima del final de la salida. Algunos de ellos presumiblemente se escribieron en dmesgel búfer circular antes de que ocurriera la suspensión, y solo se propagaron syslogdespués. Esto explica por qué todos ellos tienen la misma marca de tiempo de syslog.
Definiciones de columna:
abs es el tiempo registrado por syslog.
abs_since_bootes el mismo tiempo en segundos desde el inicio del sistema, basado en el contenido /proc/uptimey el valor de time.time().
rel_time es la marca de tiempo del kernel.
rel_offsetes la diferencia entre abs_since_booty rel_time. Estoy redondeando esto a las decenas de segundos para evitar errores syslogúnicos debido a que las marcas de tiempo absolutas (es decir, generadas) solo tienen precisión de segundos. En realidad, esa no es la forma correcta de hacerlo, ya que realmente (creo que ...) solo da como resultado una menor posibilidad de tener un error de 10 por 10. Si alguien tiene una idea mejor, hágamelo saber.
También tengo algunas preguntas sobre el formato de fecha de syslog; en particular, me pregunto si alguna vez aparece un año en él. Supongo que no, y en cualquier caso probablemente podría ayudarme a mí mismo con esa información en TFM, pero si alguien sabe que sería útil. Suponiendo, por supuesto, que alguien use este script en algún momento en el futuro, en lugar de simplemente romper un par de líneas de código Perl.
Próximo:
Por lo tanto, a menos que una de ustedes me dé una revelación bienvenida, mi próximo paso será agregar una función para obtener el sesgo de tiempo para una marca de tiempo del núcleo dado. Debería poder alimentar el script uno o un conjunto de syslogs, junto con una marca de tiempo del núcleo, para obtener una marca de tiempo absoluta. Entonces puedo volver a depurar mis problemas de Xorg, que se me escapan en este momento.
fuente
sort, tener año, zona horaria, etc. +1 para el script de Python.Freezing user space processescual se hace claramente antes de dormir.[12345.6789]..) emitido por el núcleo, por lo que está haciendo las cosas correctamente , sujeto a los problemas abordados por mi último comentario. No estoy seguro de qué debería hacer realmente el núcleo aquí; depende de lo que esas marcas de tiempo relativas al inicio están destinadas a indicar. El tiempo de ejecución (en oposición al tiempo desde el arranque) puede ser significativo en algunos contextos. Supongo que idealmente habría un registro confiable de ambos valores.Respuestas:
Problema interesante, no estoy seguro de que alguna vez haya intentado hacer esto. Pero he notado la marca de tiempo de la que está hablando y siempre he creído que son segundos desde el arranque.
En mi syslog que tengo en mi servidor, tengo:
Me imagino que esto es bastante consistente entre la mayoría de las distribuciones de Linux, ya que este es el núcleo que escupe sus cosas.
Y aquí tengo la fecha junto con la marca de tiempo.
fuente
Puedes probar esto:
Primero, obtenga la marca de tiempo del archivo dmesg (supongo que este será el tiempo 0 de dmesg). Usarás
Puede convertir los segundos en una fecha legible para humanos con
Entonces, para ver un tiempo de evento legible, agregue los segundos del evento en dmesg. Si el evento dmesg fue de 55.290387 segundos, agregue 55 o 55.290387:
Otra forma de transformar los segundos arraigados en época en tiempo legible es usar date -d como se sugiere. Si le dice a 'fecha' que represente una hora provista con -d, puede indicar que la hora a convertir está en segundos desde la época usando @.
Esto le da algo como "Jue 13 de enero 15:26:18 CST 2011" como salida.
imprimirá la hora actual en el formato de segundos desde la época.No recuerdo cómo hacer matemática de shell, por lo que generalmente uso el método perl como se indicó anteriormente. :)
fuente
date -d @$((1294953978 + 55)), al menos bajo bash. Sin embargo, algunas marcas de tiempo del núcleo están sesgadas, lo que significa que los tiempos producidos por este método serían anteriores a sus marcas de tiempo correspondientes/var/log/syslog. Parece que esto sucede como resultado de los eventos de suspensión a RAM, presumiblemente además de la hibernación y posiblemente otras cosas, porque el tiempo del núcleo no se incrementa durante esos períodos. Vea la actualización de la pregunta para más información.La forma más fácil de asignar el número de dmesg a una fecha es usar el
dateprograma.Este comando muestra la fecha de la hora actual menos 50595 segundos.
De
man date:El número es igual al tiempo de encendido, no al tiempo transcurrido desde el momento del arranque.
fuente
Dado que notó el cambio de la inclinación del tiempo durante la suspensión / reanudación, notaré que esto está documentado en al menos un lugar. La página del comando man dmesg (1) dice:
No pude encontrar una manera de hacer que el núcleo mantenga estas marcas de tiempo sincronizadas con el tiempo de la pared.
fuente
Rápido, sucio, funciona.
Contenido de ese guión:
La salida de muestra es la siguiente:
fuente