Po raz pierwszy w życiu znalazłem się w sytuacji, w której piszę interfejs API języka Java, który będzie dostępny na zasadach open source. Mam nadzieję, że zostaną uwzględnione w wielu innych projektach.

Do logowania ja (i ludzie, z którymi pracuję) zawsze korzystałem z JUL (java.util.logging) i nigdy nie miałem z tym żadnych problemów. Jednak teraz muszę bardziej szczegółowo zrozumieć, co powinienem zrobić, aby opracować interfejs API. Zrobiłem trochę badań na ten temat, a dzięki posiadanym informacjom jestem coraz bardziej zdezorientowany. Stąd ten post.

Ponieważ pochodzę z JUL, jestem na to stronniczy. Moja wiedza na temat reszty nie jest tak duża.

Z przeprowadzonych przeze mnie badań wymyśliłem następujące powody, dla których ludzie nie lubią JUL:

1. „Zacząłem programować w Javie na długo przed wydaniem Sun przez JUL i łatwiej było mi kontynuować logowanie do frameworka-X niż nauczyć się czegoś nowego” . Hmm Nie żartuję, tak mówią ludzie. Z tym argumentem wszyscy moglibyśmy robić COBOL. (jednak z pewnością mogę odnieść się do tego, że jestem leniwym facetem)

2. „Nie podoba mi się nazwy poziomów rejestrowania w JUL” . Ok, poważnie, to po prostu za mało, by wprowadzić nową zależność.

3. „Nie podoba mi się standardowy format wyjścia z JUL” . Hmm To tylko konfiguracja. Nie musisz nawet nic robić kodowo. (to prawda, w dawnych czasach być może trzeba było stworzyć własną klasę Formatter, aby wszystko było dobrze).

4. „Korzystam z innych bibliotek, które również używają rejestrowania-framework-X, więc pomyślałem, że łatwiej jest po prostu z niego korzystać” . To jest okrągły argument, prawda? Dlaczego „wszyscy” używają rejestrowania-framework-X, a nie JUL?

5. „Wszyscy inni używają rejestrowania-framework-X” . To dla mnie tylko szczególny przypadek powyższego. Większość nie zawsze ma rację.

Tak więc prawdziwe wielkie pytanie brzmi: dlaczego nie JUL? . Czego mi brakowało? Raison d'être dla rejestrowania fasad (SLF4J, JCL) polega na tym, że wiele implementacji rejestrowania istniało historycznie, a powód tego naprawdę sięga czasów sprzed JUL. Gdyby JUL był idealny, to nie byłoby rejestrowania fasad, czy co? Sprawienie, by sprawy były bardziej mylące, JUL jest w pewnym stopniu samą fasadą, umożliwiającą zamianę Handlerów, Formatterów, a nawet LogManagera.

Czy zamiast pytać o wiele sposobów robienia tego samego (rejestrowanie), nie powinniśmy pytać, dlaczego były one konieczne? (i sprawdź, czy te powody nadal istnieją)

Ok, moje dotychczasowe badania doprowadziły do ​​kilku rzeczy, które widzę, mogą być prawdziwymi problemami z JUL:

1. Wydajność . Niektórzy twierdzą, że wydajność w SLF4J jest lepsza niż reszta. Wydaje mi się, że jest to przypadek przedwczesnej optymalizacji. Jeśli musisz rejestrować setki megabajtów na sekundę, to nie jestem pewien, czy idziesz właściwą drogą. JUL ewoluował również, a testy przeprowadzone na Javie 1.4 mogą już nie być prawdziwe. Możesz przeczytać o tym tutaj, a ta poprawka wprowadziła ją do Java 7. Wiele osób mówi również o narzutu łączenia łańcuchów w metodach rejestrowania. Jednak rejestrowanie oparte na szablonie pozwala uniknąć tego kosztu i istnieje również w lipcu. Osobiście nigdy tak naprawdę nie piszę rejestrowania opartego na szablonach. Zbyt leniwy z tego powodu. Na przykład, jeśli zrobię to z JUL:

   log.finest("Lookup request from username=" + username 
      + ", valueX=" + valueX
      + ", valueY=" + valueY));

   moje IDE ostrzeże mnie i poprosi o pozwolenie, aby zmienić je na:

   log.log(Level.FINEST, "Lookup request from username={0}, valueX={1}, valueY={2}", 
      new Object[]{username, valueX, valueY});

   .. które oczywiście zaakceptuję. Pozwolenie udzielone ! Dziękuję za pomoc

   Więc tak naprawdę nie piszę takich instrukcji, co robi IDE.

   Podsumowując na temat wydajności, nie znalazłem niczego, co sugerowałoby, że wydajność JUL-a nie jest odpowiednia w porównaniu z konkurencją.

2. Konfiguracja ze ścieżki klasy . JUL po wyjęciu z pudełka nie może załadować pliku konfiguracyjnego ze ścieżki klasy. Aby to zrobić, wystarczy kilka linii kodu . Rozumiem, dlaczego może to być denerwujące, ale rozwiązanie jest krótkie i proste.

3. Dostępność programów obsługi wyjścia . JUL jest dostarczany z 5 modułami wyjściowymi: konsolą, strumieniem plików, gniazdem i pamięcią. Można je rozszerzyć lub napisać nowe. Może to być na przykład zapisywanie w dzienniku zdarzeń systemu UNIX / Linux i dzienniku zdarzeń systemu Windows. Osobiście nigdy nie miałem tego wymogu ani go nie widziałem, ale z pewnością mogę odnieść się do tego, dlaczego może to być przydatna funkcja. Logback jest dostarczany na przykład z aplikacją do Syslog. Nadal bym to argumentował

   1. 99,5% zapotrzebowania na miejsca docelowe produkcji jest pokryte tym, co znajduje się w JUL od razu po wyjęciu z pudełka.
   2. Specjalne potrzeby mogą być zaspokojone przez niestandardowe programy obsługi na JUL, a nie na czymś innym. Nic dla mnie nie sugeruje, że napisanie procedury obsługi wyjścia Syslog dla JUL zajmuje więcej czasu niż w przypadku innej struktury rejestrowania.

Naprawdę martwię się, że coś przeoczyłem. Korzystanie z fasad logowania i implementacji logowania innych niż JUL jest tak powszechne, że muszę dojść do wniosku, że to ja po prostu nie rozumiem. Obawiam się, że to nie byłby pierwszy raz. :-)

Więc co powinienem zrobić z moim API? Chcę, żeby odniosło sukces. Mogę oczywiście po prostu „płynąć z prądem” i wdrożyć SLF4J (który wydaje się obecnie najbardziej popularny), ale dla własnego dobra wciąż muszę dokładnie zrozumieć, co jest nie tak z dzisiejszym JUL, który gwarantuje wszystkie kłopoty? Czy sabotuję się, wybierając JUL dla mojej biblioteki?

Testowanie wydajności

(sekcja dodana przez nolan600 w dniu 07-JUL-2012)

Poniżej znajduje się odniesienie od Ceki o parametryzacji SLF4J 10 lub więcej razy szybciej niż JUL. Więc zacząłem robić proste testy. Na pierwszy rzut oka twierdzenie jest z pewnością słuszne. Oto wstępne wyniki (ale czytaj dalej!):

• Czas wykonania SLF4J, backend Logback: 1515
• Czas wykonania SLF4J, backend JUL: 12938
• Czas realizacji LIPIEC: 16911

Powyższe liczby to ms, więc im mniej, tym lepiej. Tak więc 10-krotna różnica w wydajności jest na początku całkiem bliska. Moja początkowa reakcja: to dużo!

Oto rdzeń testu. Jak widać liczba całkowita i ciąg znaków są konstruowane w pętli, która jest następnie używana w instrukcji log:

    for (int i = 0; i < noOfExecutions; i++) {
        for (char x=32; x<88; x++) {
            String someString = Character.toString(x);
            // here we log 
        }
    }

(Chciałem, aby instrukcja dziennika miała zarówno prymitywny typ danych (w tym przypadku int), jak i bardziej złożony typ danych (w tym przypadku ciąg). Nie jestem pewien, czy to ważne, ale masz go.)

Instrukcja dziennika dla SLF4J:

logger.info("Logging {} and {} ", i, someString);

Instrukcja dziennika dla JUL:

logger.log(Level.INFO, "Logging {0} and {1}", new Object[]{i, someString});

JVM został „rozgrzany” tym samym testem wykonanym jeden raz przed faktycznym pomiarem. Java 1.7.03 był używany w Windows 7. Użyto najnowszych wersji SLF4J (v1.6.6) i Logback (v1.0.6). Stdout i stderr zostały przekierowane na urządzenie zerowe.

Jednak uważaj teraz, okazuje się, że JUL spędza większość czasu, getSourceClassName()ponieważ JUL domyślnie drukuje nazwę klasy źródłowej na wyjściu, podczas gdy Logback nie. Porównujemy więc jabłka i pomarańcze. Muszę ponownie wykonać test i skonfigurować implementacje rejestrowania w podobny sposób, aby faktycznie generowały te same rzeczy. Podejrzewam jednak, że SLF4J + Logback nadal będzie na topie, ale daleko mu do początkowych liczb, jak podano powyżej. Bądźcie czujni.

Btw: Test po raz pierwszy faktycznie współpracowałem z SLF4J lub Logback. Przyjemne doświadczenie. JUL z pewnością jest o wiele mniej przyjazny, gdy zaczynasz.

Testowanie wydajności (część 2)

(sekcja dodana przez nolan600 w dniu 08-JUL-2012)

Jak się okazuje, tak naprawdę nie ma znaczenia wydajność, w jaki sposób konfigurujesz swój wzorzec w JUL, tj. Czy zawiera nazwę źródła, czy nie. Próbowałem z bardzo prostym wzorem:

java.util.logging.SimpleFormatter.format="%4$s: %5$s [%1$tc]%n"

i to wcale nie zmieniło powyższych czasów. Mój profiler ujawnił, że logger nadal spędzał dużo czasu na rozmowach telefonicznych, getSourceClassName()nawet jeśli nie było to częścią mojego wzorca. Wzór nie ma znaczenia.

W związku z tym dochodzę do wniosku, że przynajmniej w przypadku testowanej instrukcji dziennika opartej na szablonie wydaje się, że w rzeczywistej różnicy wydajności między JUL (powolnym) a SLF4J + Logback (szybkim) jest około 10. Tak jak powiedział Ceki.

Widzę też inną rzecz, mianowicie to, że getLogger()połączenie SLF4J jest znacznie droższe niż JUL ditto. (95 ms vs 0,3 ms, jeśli mój profiler jest dokładny). To ma sens. SLF4J musi poświęcić trochę czasu na powiązanie podstawowej implementacji rejestrowania. To mnie nie przeraża. Połączenia te powinny być dość rzadkie w trakcie życia aplikacji. Szybkość powinna znajdować się w rzeczywistych wywołaniach dziennika.

Ostateczna konkluzja

(sekcja dodana przez nolan600 w dniu 08-JUL-2012)

Dziękuję za wszystkie odpowiedzi. W przeciwieństwie do tego, co początkowo myślałem, ostatecznie zdecydowałem się użyć SLF4J dla mojego API. Jest to oparte na wielu rzeczach i twoim wkładzie:

1. Daje elastyczność wyboru implementacji dziennika w czasie wdrażania.

2. Problemy z brakiem elastyczności konfiguracji JUL podczas uruchamiania na serwerze aplikacji.

3. SLF4J jest z pewnością znacznie szybszy, jak opisano powyżej, szczególnie jeśli połączysz go z Logbackiem. Nawet jeśli był to tylko trudny test, mam powody sądzić, że o wiele więcej wysiłku włożono w optymalizację SLF4J + Logback niż JUL.

4. Dokumentacja. Dokumentacja SLF4J jest po prostu o wiele bardziej wyczerpująca i precyzyjna.

5. Elastyczność wzoru. Podczas testów postanowiłem, że JUL naśladuje domyślny wzorzec z Logback. Ten wzór zawiera nazwę wątku. Okazuje się, że JUL nie może tego zrobić po wyjęciu z pudełka. Ok, nie przegapiłem tego do tej pory, ale nie sądzę, że jest to rzecz, której powinno brakować w logach. Kropka!

6. Większość (lub wiele) projektów Java korzysta obecnie z Maven, więc dodanie zależności nie jest aż tak duże, szczególnie jeśli ta zależność jest raczej stabilna, tj. Nie zmienia ciągle interfejsu API. Wydaje się, że tak jest w przypadku SLF4J. Również słoik SLF4J i przyjaciele są małe.

Dziwną rzeczą, która się wydarzyła, było to, że naprawdę bardzo się zdenerwowałem JUL po tym, jak trochę popracowałem nad SLF4J. Nadal żałuję, że tak musi być z JUL. JUL jest daleki od ideału, ale w pewnym sensie spełnia swoje zadanie. Po prostu nie dość dobrze. To samo można powiedzieć Propertiesjako przykład, ale nie myślimy o abstrakcji, aby ludzie mogli podłączyć własną bibliotekę konfiguracji i co masz. Myślę, że powodem jest to, że Propertiespojawia się tuż nad poprzeczką, podczas gdy odwrotnie jest w przypadku JUL dzisiejszego dnia ... a w przeszłości było zero, ponieważ nie istniało.

Oświadczenie : Jestem założycielem projektów log4j, SLF4J i logback.

Istnieją obiektywne powody preferowania SLF4J. Po pierwsze, SLF4J pozwala użytkownikowi końcowemu na swobodę wyboru podstawowej struktury rejestrowania . Ponadto, bardziej doświadczeni użytkownicy wolą logback, który oferuje możliwości wykraczające poza log4j , z dużym opóźnieniem. Pod względem funkcji jul może być wystarczający dla niektórych użytkowników, ale dla wielu innych tak nie jest. W skrócie, jeśli rejestrowanie jest dla Ciebie ważne, powinieneś użyć SLF4J z logback jako implementacji bazowej. Jeśli logowanie nie jest ważne, Jul jest w porządku.

Jednak jako programista systemu operacyjnego musisz wziąć pod uwagę preferencje użytkowników, a nie tylko własne. Wynika z tego, że powinieneś przyjąć SLF4J nie dlatego, że jesteś przekonany, że SLF4J jest lepszy niż lip, ale ponieważ większość programistów Java (lipiec 2012) preferuje SLF4J jako interfejs API rejestrowania. Jeśli ostatecznie zdecydujesz się nie przejmować popularną opinią, weź pod uwagę następujące fakty:

1. ci, którzy wolą Jul robią to dla wygody, ponieważ Jul jest dołączony do JDK. Według mojej wiedzy nie ma innych obiektywnych argumentów na korzyść Jul
2. twoja własna preferencja dla Jul jest właśnie taka, preferencja .

Zatem utrzymywanie „twardych faktów” ponad opinią publiczną, choć na pozór odważne, jest w tym przypadku logicznym błędem.

Jeśli nadal nie jest przekonany, JB Nizet przedstawia dodatkowy i mocny argument:

Z wyjątkiem tego, że użytkownik końcowy mógł już wykonać to dostosowanie dla własnego kodu lub innej biblioteki używającej log4j lub logback. jul jest rozszerzalny, ale konieczność rozszerzenia logback, jul, log4j i Bóg wie tylko, który inny system rejestrowania, ponieważ używa czterech bibliotek, które używają czterech różnych platform rejestrowania, jest uciążliwy. Korzystając z SLF4J, pozwalasz mu skonfigurować frameworki rejestrowania, których chce, a nie te, które wybrałeś. Pamiętaj, że typowy projekt wykorzystuje mnóstwo bibliotek, a nie tylko twoją .

Jeśli z jakiegoś powodu nienawidzisz interfejsu API SLF4J, a użycie go zniechęci zabawę do pracy, na pewno idź na lip Po tym wszystkim, istnieje sposób przekierowania Jul na SLF4J .

Nawiasem mówiąc, jul parametryzacja jest co najmniej 10 razy wolniejsza niż SLF4J, co ostatecznie robi zauważalną różnicę.

1. java.util.loggingzostał wprowadzony w Javie 1.4. Wcześniej były rejestrowane zastosowania, dlatego istnieje wiele innych interfejsów API rejestrowania. Te interfejsy API były często używane przed Javą 1.4, dzięki czemu miały świetny udział w rynku, który nie spadł do zera, gdy 1.4 był wydany.

2. JUL nie zaczął się tak dobrze, wiele rzeczy, o których wspominałeś, było znacznie gorszych w 1.4, a poprawiło się tylko w 1.5 (i chyba również w 6., ale nie jestem zbyt pewien).

3. JUL nie jest dobrze przystosowany do wielu aplikacji z różnymi konfiguracjami w tej samej JVM (pomyśl o wielu aplikacjach internetowych, które nie powinny wchodzić w interakcje). Tomcat musi przeskoczyć kilka obręczy, aby to zadziałało (skutecznie ponownie wdrażając JUL, jeśli dobrze to zrozumiałem).

4. Nie zawsze możesz wpływać na strukturę rejestrowania używaną przez biblioteki. Dlatego użycie SLF4J (który jest tak naprawdę bardzo cienką warstwą API nad innymi bibliotekami) pomaga zachować nieco spójny obraz całego świata rejestrowania (dzięki czemu możesz decydować o podstawowej strukturze rejestrowania, mając nadal rejestrację biblioteki w tym samym systemie).

5. Biblioteki nie można łatwo zmienić. Jeśli poprzednia wersja biblioteki używała rejestrowania biblioteki-X, nie może łatwo przejść do rejestrowania biblioteki-Y (na przykład JUL), nawet jeśli ta ostatnia jest wyraźnie zbyteczna: każdy użytkownik tej biblioteki musiałby się nauczyć nowa struktura rejestrowania i (przynajmniej) ponowna konfiguracja rejestrowania. To wielkie nie-nie, szczególnie gdy nie przynosi widocznego zysku większości ludzi.

Powiedziawszy wszystko, co myślę, że JUL jest przynajmniej ważną alternatywą dla innych struktur rejestrowania w dzisiejszych czasach.

IMHO, główną zaletą korzystania z elewacji rejestrującej, takiej jak slf4j, jest to, że użytkownik końcowy biblioteki może wybrać konkretną implementację rejestrowania, a nie narzucanie wyboru użytkownikowi końcowemu.

Być może zainwestował czas i pieniądze w Log4j lub LogBack (specjalne formatery, programy dołączające itp.) I woli nadal używać Log4j lub LogBack, niż konfigurować jul. Nie ma problemu: slf4j na to pozwala. Czy mądrze jest używać Log4j w lipcu? Może, może nie. Ale nie obchodzi cię to. Pozwól użytkownikowi końcowemu wybrać, co woli.

Zacząłem, jak podejrzewam, używając JUL, ponieważ było to najłatwiejsze, aby zacząć od razu. Jednak z biegiem lat zacząłem żałować, że nie poświęciłem trochę więcej czasu na wybór.

Moim głównym problemem jest teraz to, że mamy znaczną ilość kodu „biblioteki”, który jest używany w wielu aplikacjach i wszystkie używają JUL. Ilekroć używam tych narzędzi w aplikacji typu usługa sieciowa, rejestrowanie po prostu znika lub idzie w miejsce nieprzewidywalne lub dziwne.

Naszym rozwiązaniem było dodanie fasady do kodu biblioteki, co oznaczało, że wywołania dziennika biblioteki nie uległy zmianie, ale zostały dynamicznie przekierowane do dowolnego dostępnego mechanizmu rejestrowania. Gdy są zawarte w narzędziu POJO, są kierowane do JUL, ale po wdrożeniu jako aplikacja internetowa są przekierowywane do LogBack.

Oczywiście żałujemy, że kod biblioteki nie używa rejestrowania sparametryzowanego, ale można to teraz modyfikować w razie potrzeby.

Do zbudowania fasady użyliśmy slf4j.

Uruchomiłem jul przeciwko slf4j-1.7.21 przez logback-1.1.7, wyjście na dysk SSD, Java 1.8, Win64

jul uruchomił 48449 ms, logback 27185 ms dla pętli 1M.

Jednak trochę większa szybkość i nieco ładniejszy interfejs API nie są dla mnie warte 3 bibliotek i 800 KB.

package log;

import java.util.logging.Level;
import java.util.logging.Logger;

public class LogJUL
{
    final static Logger logger = Logger.getLogger(LogJUL.class.getSimpleName());

    public static void main(String[] args) 
    {
        int N = 1024*1024;

        long l = System.currentTimeMillis();

        for (int i = 0; i < N; i++)
        {
            Long lc = System.currentTimeMillis();

            Object[] o = { lc };

            logger.log(Level.INFO,"Epoch time {0}", o);
        }

        l = System.currentTimeMillis() - l;

        System.out.printf("time (ms) %d%n", l);
    }
}

i

package log;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class LogSLF
{
    static Logger logger = LoggerFactory.getLogger(LogSLF.class);


    public static void main(String[] args) 
    {
        int N = 1024*1024;

        long l = System.currentTimeMillis();

        for (int i = 0; i < N; i++)
        {
            Long lc = System.currentTimeMillis();

            logger.info("Epoch time {}", lc);
        }

        l = System.currentTimeMillis() - l;

        System.out.printf("time (ms) %d%n", l);
    }

}