forza slf4j per stampare i registri in sequenza


Sto usando slf4j su log-back. A volte i registri non vengono stampati nell'ordine (timestamp). Potremmo costringerlo ad accedere nello stesso ordine in cui il codice è in esecuzione?

Aggiornamento 1: Questo sta accadendo quando si eseguono test unitari su Jenkins tramite maven. Sta accadendo costantemente. Le prime istruzioni di registro dal codice stanno arrivando, quindi le istruzioni di registro dal test unitario stanno arrivando.

Anche tutti i file di logback sembrano normali come di seguito.

  <appender name="STDOUT"
            class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">

Aggiornamento 2: i frammenti di registro sono così (ho modificato il nome del file ecc..). Durante l'esecuzione di test1 chiamiamo il codice per invertire una transazione che è stata fallita a causa di un errore. Ma la cosa strana è che l'eccezione viene stampata prima e poi vengono stampate le istruzioni di log dei metodi di test. Anche i timestamp delle istruzioni di log sono come previsto, ma l'ordine di essi nel file è diverso (14:33:34.718 viene prima delle 14:33: 34.449)

14:33:34.667 [869082978@qtp-1587505558-0] [] WARN  org.hibernate.ejb.Ejb3Configuration - hibernate.connection.autocommit = false break the EJB3 specification
14:33:34.718 [869082978@qtp-1587505558-0] [] WARN  o.h.impl.SessionFactoryObjectFactory - InitialContext did not implement EventContext
14:33:34.843 [869082978@qtp-1587505558-0] [] 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.

Aggiornamento 3: Il nostro progetto utilizza maven e ci sono più moduli. Abbiamo logback-test.xml nella cartella src/test/resources.

La struttura del progetto è così
codemodule/src/test/resources/logback-test.xml - questo modulo sarà confezionato in file jar. Test case chiama il codice di questo modulo.
parent/src/test/resources/logback-test.xml - questo è il modulo genitore che avvolge i file e i pacchetti jar di tutti gli altri moduli in una guerra. Questo è dove ho il test case in esecuzione e chiama sopra il codice del modulo.

Ho istruzioni di log sia nel codice del test case che nel codice effettivo. Ho controllato sia il caso di test che il codice utilizza il pattern dal file di logback del genitore (il pattern in codemodule è diverso). Stampa costantemente le istruzioni di registro del codice prima di stampare i registri del test case.

Inoltre non stiamo eseguendo test in parallelo.
Concurrency config is parallel='none', perCoreThreadCount=true, threadCount=2, useUnlimitedThreads=false

Aggiornamento 4: capisco il problema. Stiamo facendo una richiesta http non una chiamata diretta al metodo. Quindi i casi di test sono in esecuzione nel thread main e il codice effettivo è in esecuzione in un altro thread (grazie Sebbe).

Capisco forzare la registrazione la sequenza può essere colpita dalle prestazioni, ma per la completezza della domanda farò un'altra domanda.

Poiché entrambi i registri stanno andando a singolo appender (STDOUT), posso forzarlo ad accedere nell'ordine di timestamp?

Author: Reddy, 2012-02-21

1 answers

Dal tuo log stesso puoi vedere che hai almeno 2 thread in esecuzione: 869082978@qtp-1587505558-0 e main.

Non è possibile controllare l'ordine in cui i thread separati registrano i loro eventi allo stesso output (probabilmente è possibile, ma sarebbe una cattiva idea).

Dal thread di log 869082978@qtp-1587505558-0 ottiene prima l'accesso in scrittura alla console. Durante la scrittura, gli eventi vengono registrati da main. Una volta che 869082978@qtp-1587505558-0 rilascia il suo blocco, main lo ottiene e può scaricare i suoi registri nel file.

 2
Author: Sebbe, 2012-02-28 08:59:54