Używam slf4j ponad logowaniem. Czasami logi nie są drukowane w kolejności (znacznik czasu). Czy możemy zmusić go do zalogowania się w takiej samej kolejności, w jakiej działa kod?force slf4j do drukowania logów w sekwencji
Aktualizacja 1: Dzieje się to podczas prowadzenia testów jednostkowych na Jenkinsie przez maven. Dzieje się to konsekwentnie. Pierwsze logi z kodu nadchodzą, a nadchodzą logi z testu jednostkowego.
Również wszystkie pliki logback wygląda normalnie, jak poniżej.
<appender name="STDOUT"
class="ch.qos.logback.core.ConsoleAppender">
<layout class="ch.qos.logback.classic.PatternLayout">
Aktualizacja 2: Fragmenty dziennika są tak (mam edytować nazwę pliku etc ..). Podczas wykonywania testu test1 wywołujemy kod, aby odwrócić transakcję, która nie powiodła się z powodu jakiegoś błędu. Ale dziwne jest, że wyjątek jest drukowany jako pierwszy, a następnie drukowane są instrukcje dziennika z metod testowych. Także znaczniki czasu sprawozdań z bali są zgodnie z oczekiwaniami, ale ich kolejność w pliku jest inna (14:33:34. przychodzi przed 14:33:34.)
14:33:34.667 [[email protected]05558-0] [] 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.
Aktualizacja 3: Nasz projekt wykorzystuje narzędzie maven i istnieje wiele modułów. Mamy logback-test.xml w folderze src/test/resources.
Struktura projektu wygląda następująco:
codemodule/src/test/resources/logback-test.xml - ten moduł zostanie spakowany w pliku jar. Przypadek testowy wywołuje kod tego modułu.
parent/src/test/resources/logback-test.xml - jest to moduł nadrzędny, który opakowuje wszystkie pliki jar i pakiety innych modułów w stan wojny. Tutaj mam uruchomiony test, który wywołuje powyższy kod modułu.
Mam instrukcje dziennika zarówno w kodzie przypadków testowych, jak iw kodzie rzeczywistym. Sprawdziłem, że zarówno przypadek testowy, jak i kod używają wzorca z pliku loginu nadrzędnego (wzór w kodzieodule jest inny). Konsekwentnie drukuje instrukcje dziennika kodu przed wydrukowaniem dzienników zdarzeń testowych.
Również nie przeprowadzamy testów równolegle.
Concurrency config is parallel='none', perCoreThreadCount=true, threadCount=2, useUnlimitedThreads=false
Update 4: Rozumiem problem. Robimy żądanie http, a nie bezpośrednie wywołanie metody. Tak więc przypadki testowe działają w wątku main, a aktualny kod działa w innym wątku (Thanks Sebbe).
Rozumiem, że wymuszanie sekwencji logowania może być skutecznym działaniem, ale dla kompletności pytania zadam jeszcze jedno pytanie.
Ponieważ oba logi przechodzą do pojedynczego aplikanta (STDOUT), czy mogę wymusić na nim zalogowanie się w kolejności znacznika czasu?
Czy mówisz, że w dzienniku widzisz wiadomości mieszane znaczniki czasu (nie rośnie?) Nigdy nie widziałem takich zjawisk. Którego aplikanta używasz? –
@TomaszNurkiewicz Tak, używam ch.qos.logback.core.ConsoleAppender – Reddy
Czy używasz jakiejkolwiek współbieżności? To może być powód. Ponadto, możesz podać fragment dziennika – Fixpoint