Estoy usando slf4j sobre log-back. A veces, los registros no se imprimen en el orden (marca de tiempo). ¿Podríamos obligarlo a iniciar sesión en el mismo orden en que se está ejecutando el código?forzar slf4j para imprimir registros en secuencia
Actualización 1: Esto sucede cuando se ejecutan pruebas unitarias en Jenkins a través de maven. Está sucediendo consistentemente. Las primeras declaraciones de registro del código están llegando y luego vienen las declaraciones de registro de la prueba unitaria.
También todos los archivos de inicio de sesión se ven normales como a continuación.
<appender name="STDOUT"
class="ch.qos.logback.core.ConsoleAppender">
<layout class="ch.qos.logback.classic.PatternLayout">
Actualización 2: los fragmentos de registro son así (he editado nombre de archivo, etc ..). Durante la ejecución de test1 llamamos al código para revertir una transacción que falló debido a algún error. Pero lo extraño es que la excepción se imprime primero y luego se imprimen las instrucciones de registro de los métodos de prueba. También las marcas de tiempo de las declaraciones de registro son como se esperaba, pero el orden de ellos en el archivo es diferente (14:33:34. viene antes de 14:33:34.)
14:33:34.667 [[email protected]] [] WARN org.hibernate.ejb.Ejb3Configuration - hibernate.connection.autocommit = false break the EJB3 specification
14:33:34.718 [[email protected]] [] WARN o.h.impl.SessionFactoryObjectFactory - InitialContext did not implement EventContext
14:33:34.843 [[email protected]] [] DEBUG c.r.a.exception.ExceptionMapper - <3003> can't reverse transaction. [id=10000000100120014]
.
.
.
.
.
14:33:34.158 [main] [] DEBUG c.r.a.test - ========================= test0: finished.
14:33:34.158 [main] [] DEBUG c.r.a.test - ========================= test1: started.
.
.
.
.
14:33:34.449 [main] [] DEBUG c.r.a.test - reversing transaction, id=10000000100120014
14:33:34.856 [main] [] DEBUG c.r.a.test - ========================= test2: started.
actualización 3: Nuestro proyecto utiliza maven y hay múltiples módulos. Tenemos logback-test.xml en la carpeta src/test/resources.
La estructura del proyecto es como esta
codemodule/src/test/resources/logback-test.xml - este módulo se empaquetará en archivo jar. El caso de prueba llama al código de este módulo.
parent/src/test/resources/logback-test.xml - este es el módulo principal que envuelve todos los paquetes jar y paquetes de otros módulos en una guerra. Aquí es donde ejecuto el caso de prueba y llama al código del módulo anterior.
Tengo instrucciones de registro tanto en el código del caso de prueba como en el código real. He comprobado que tanto el caso de prueba como el código están usando un patrón del archivo de inicio de sesión del padre (el patrón en el paquete es diferente). Imprime consistentemente las declaraciones de registro del código antes de imprimir los registros del caso de prueba.
Además, no estamos ejecutando pruebas en paralelo.
Concurrency config is parallel='none', perCoreThreadCount=true, threadCount=2, useUnlimitedThreads=false
Update 4: Entiendo el problema. Estamos realizando una solicitud de HTTP, no una llamada de método directo. Por lo tanto, los casos de prueba se ejecutan en el hilo main y el código actual se está ejecutando en otro hilo (Gracias Sebbe).
Entiendo que forzar la secuencia de registro puede ser un impacto en el rendimiento, pero para la compleción de la pregunta haré una pregunta más.
Dado que ambos registros van a un único appender (STDOUT), ¿puedo obligarlo a iniciar sesión en el orden de la marca de tiempo?
¿Estás diciendo que en tu registro ves mensajes de sellos de fecha y hora mixtos (que no crecen?) Nunca se han visto tales fenómenos. ¿Qué appender estás usando? –
@TomaszNurkiewicz Sí, estoy usando ch.qos.logback.core.ConsoleAppender – Reddy
¿Utiliza alguna concurrencia? Esa podría ser una causa. Además, podría proporcionar un extracto de registro – Fixpoint