Однажды я писал один проект. Проект выдался большим и писал я его долго.
Там было все что только можно было запихнуть — и retrolambda/java8, и пара десятков
других библиотек (жадность заказчика до новых фич не знала границ, а потому
росло число зависимостей).

Но речь даже не об этом. Настало время делать релиз. И оказалось что в проекте
множество логов и неплохо бы их из релизной сборки убрать. Всем известный
способ с ProGuard не сработал с первого раза. С каждым новым "-keep"
приложение падало в каком-то новом месте. Так что ProGuard пришлось отключить
до лучших времен.

Все это время меня не покидало ощущуение, что управление уровнем логировния c
помощью изменения байт-кода — это нелепо. И тогда за полчаса я написал свой
примитивный логгер.

Обычно я редко довожу свои проекты до конца, но тут он был настолько прост — что теперь он лежит на гитхабе, желающие — пользуйтесь.

Совместимое API — залог простой миграции


Одна из причин почему я не стал использовать Timber — потому что мои пальцы
привыкли печатать Log.d. Свой класс я назвал тоже «Log», а методы сделал совместимыми с «android.util.Log».

Это значит, что если вы захотите соскочить со стандартного логгера — просто
замените импорты. Это можно сделать с помощью sed, или с помощью вашей любимой
IDE.

А в чем преимущество?


Ну вот несколько отрывков кода, показывающие основные фичи логгера:

// Весь ваш старый код останется работать как и прежде
Log.d(tag, "X equals " + x);
// Но теперь можно будет выводить несколько значений через запятую
Log.d(tag, "X", x)


// Можно будет не писать теги, по умолчанию они возьмутся из имени класса
class Foo {
		public void foo() {
				Log.d("Hello"); // выведет 'D/Foo: Hello'
		}
}

// Разве только в классе будет свой атрибут "tag" (или "TAG")
class Foo {
		private final static String TAG = "Bar";
		public void foo() {
				Log.d("Hello");      // выведет 'D/Bar: Hello'
				Log.d(TAG, "Hello"); // выведет 'D/Bar: Hello', не 'D/Bar: Bar Hello'
		}
}

// Конечно, все это настаиваемо и атрибут тега может называться как угодно
class Foo {
		static {
				Log.useTags(new String[]{"tag", "TAG", "MYTAG", "_TAG", "iLoveLongFieldName"});
		}
		private final static String _TAG = "Bar";
		...
}


// Можно выводить экспешены, для них будет напечатан стек-трейс
Exception e = new Exception("foo");
Log.d("Something bad happened", someObject, "error:", e);

// Длинные сообщения можно писать через точку
Log
		.d("First")
		.d("Second")
		.d("Third line")

// То с чего все начиналось - контроль за уровнем логирования
Log.level(Log.I);
Log.d("foo"); // ничего не выведет

// Можно использовать форматные стоки, как в String.format()
Log.useFormat(true);
Log.d("X equals %d", x); // выведет 'X equals 42'
// Если в первой строке нет процентов - будет использоваться вывод через запятую
Log.d("Value of X", x); // выведет 'Value of X 42'

// Длинные строки переносятся по '\n'. Непереносимые строки длиннее 4000
// символов будет переноситься по пробелам или пунктуации. Можно смело
// выводить длинные JSON-ы или HTML
Log.d("Hello\nworld"); // выведет 'D/SomeTag: Hello', затем 'D/SomeTag: world'

// Логгер работает как в андроиде, так и в JVM.
// В андроиде логирование ведется через стандартный логгер, в обычной джаве -
// через System.out.println
// Но все это можно настроить вручную
Log.usePrinter(Log.SYSTEM.true).usePrinter(Log.ANDROID, false).d("hello"); // использовать System.out, в том числе и в андроиде

// А еще можно использовать свои "принтеры", например для Crashlytics
Log.usePrinter(mCrashlyricsPrinter, true);


Уговорили, где взять?


Исходники на гитхабе: github.com/zserge/log

В build.gradle библиотека подключается как обычно:

repositories {
	jcenter() // или mavenCentral()
}
dependencies {
	compile 'co.trikita:log:1.1.5'
}

Вот так можно заменить импорты:

$ find -name "*.java" -type f -exec sed -i 's/import android.util.Log/import trikita.log.Log/g' {} \;


Логгер под лицензией MIT, используйте на здоровье. Там один класс без
зависимостей, всего на 250 строк, так что проект ваш тяжелей/тормозней не станет.

Любые пожелания или багрепорты (особенно с патчами) приветствуются!

UPD: Всем спасибо за код-ревью и конструктивные замечания. Благодаря вам выложил версию 1.1.5.
  • Потокобезопасность пришлось сделать в лоб, через synchronized. Померял скорость — практически не замедлилась, зато многострочные сообщения не разрываются если их печатать из разных потоков. Да и так спокойнее если вдруг принтер не многопоточный
  • Проверил бенчмарки — да, мой логгер медленнее чем android.util.Log за счет рефлексии. Однако он ничуть не медленнее Timber'а. Вообщем, если вы пишете меньше чем 10000 логов в секунду — проблем с производительностью не будет
  • Добавил приватный конструктор, ну и там по мелочам — где названия привел в порядок, где документацию

Комментарии (28)


  1. esinev
    23.07.2015 17:53
    +1

    Что бросилось в глаза при беглом взгляде на github.com/zserge/log/blob/master/library/src/main/java/trikita/log/Log.java

    1. Использование reflection медленно в android. У вас в каждом выводе в лог используется reflection.
    2. Не thread-safe, т.к. используется статических контейнер: private static Map<String, String> tags = new HashMap<>();
    3. Да и другие статические не final поля не дают использовать библиотеку в разных потоках


    1. zserge Автор
      23.07.2015 18:09

      Спасибо что заглянули в исходник!

      1. Рефлексия — это плата за удобство использования. Timber кстати делает так же, использует рефлексию для поиска тега. К тому же считается что компиляторы неплохо оптимизируют рефлексию в наши дни. Можно конечно проделать бенчмарки чтобы доказать обратное. Но логирование даже без рефлексии считается небыстрым — там JNI вызовы, затем syscall (запись в лог-устройство).

      2/3. А вот по поводу тред-сейфности вы дело говорите. Это точно надо бы исправить. Если хотите — можете багу открыть на гитхабе, чтобы не забылось.


      1. TimReset
        23.07.2015 18:13

        4. Получение имени вызываемого класса через создание исключение (new Throwable().getStackTrace();) медленно.
        5. Конструктор должен быть приватным. (насколько я понял, экземпляр этого класса из вне нельзя создать).
        6. Поля V, D, I, и т.д., наверное, стоит сделать в виде enum.

        P.S. Игра — найди 10 ошибок?


        1. zserge Автор
          23.07.2015 18:26

          Отнюдь. Не всё и не всегда замечаешь сам и сразу, так что за замечания — спасибо.

          4. А существует ли более быстрый способ узнать имя вызывающего класса?
          5. Упс. И ведь хотел сделать «utility class», а конструктор потерял где-то.
          6. Наверняка enum идеологичнее, но сейчас я могу написать Log.level(Log.D), а с энамом будет чуть длинее. Разве только сам Log попробовать сделать энамом. А кстати в android.util.Log уровни сделаны константами, а не энамом.


          1. TimReset
            23.07.2015 18:47

            4. А существует ли более быстрый способ узнать имя вызывающего класса?

            К сожалению, я его не знаю. По моему, в runtime этого нельзя быстро сделать.

            А кстати в android.util.Log уровни сделаны константами, а не энамом.

            Интересно, не знал. Сейчас посмотрел — действительно, числовые константы. Вообще в JUL (java.util.logging) Level тоже не enum, но используется как enum — final static поля с экземплярами этого класса на которые потом ссылаются.

            P.S. Я вообще не придираюсь — просто интересно сделать code review. :)


            1. zserge Автор
              23.07.2015 18:58

              Да я к критике нормально отношусь — чем больше потенциальных ошибок я узнаю сейчас, тем меньше времени потрачу если бы сам наступал на эти грабли в будушем.

              Кстати, внизу привел замеры скорости моего логгера и стандартного. Рефлексия конечно медленнее, но вполне приемлемо для логгера. Мы же как правило пишем логи несколько раз в секудну, не чаще.

              А к энамам у меня какая-то нелюбовь в джаве. Они там как-то сбоку-припеку прикручены и все время вызывают настороженность (ни отнаследовать, ни расширить). Хотя в том же C я энамы люблю и регулярно использую.


        1. HotIceCream
          23.07.2015 20:15
          +1

          4. Я пользовался Thread.currentThread().getStackTrace(). Вряд ли это быстрее, но выглядит красивее.


          1. zserge Автор
            23.07.2015 20:55

            Спасибо. Проверил. Увы, разницы по быстродействию никакой. Хотя обычно говорят что new Throwable() даже быстрее — stackoverflow.com/questions/2347828/how-expensive-is-thread-getstacktrace


            1. webkumo
              23.07.2015 21:36

              Разница-то скорее всего есть, но она минимальна — стоимость создания одного небольшого объекта намного дешевле разворачивания стека (которое выполняется в обоих случаях).


              1. zserge Автор
                24.07.2015 13:47

                Вот может быть интересно — www.docjar.com/html/api/java/lang/Thread.java.html
                Вообщем, getStackTrace() как и dumpStack() в итоге все равно упираются в new Exception().


      1. TimReset
        23.07.2015 18:24

        По поводу

        1. Рефлексия — это плата за удобство использования.
        В целом согласен — использовать удобно. Но нельзя ли в Android использовать compile-time аспекты? Может что то вроде AspectJ CTW? Может с этим получится сделать быстрое получение имени метода и класса? Т.е. при компиляции аспектов получать имя метод и класса у вызывающего кода и дальше его использовать. Конечно, будет сложнее чем сейчас — нужно будет компиляцию настраивать в gradle, но зато perfomance будет лучше.


      1. esinev
        23.07.2015 18:28

        И в .class и в .dex видно, что компилятор ничего не оптимизировал:

        ...
        public void print(int i, String s, String s1)
            {
                try
                {
                    if(loaded)
                        mLogMethods[i].invoke(null, new Object[] {
                            s, s1
                        });
                    return;
                }
        ...
        


        Или имелись ввиду hotspot, dalvik и ART?


        1. zserge Автор
          23.07.2015 18:52

          Да, я про конечное время работы, пользователю-то важно не тормозит ли его приложение из-за корявого логгера.

          Вообщем, я померял. Moto G 1st gen, середнячок, но не флагман. android.util.Log в среднем занимает 7-10 микросекунд на сообщение, trikita.log.Log в среднем занимает 40-50 микросекунд.

          Признаю, рефлексия (ожидаемо) медленнее, практически на порядок, но в целом можно успеть записать 300 логов пока сменится один кадр при 60 fps. Так что я бы не сказал что потеря скорости логгера здесь критична.


  1. lopatoid
    23.07.2015 18:12

    Ещё есть библиотека github.com/orhanobut/logger, если кому интересно.


  1. Suvitruf
    23.07.2015 19:13
    +1

  1. zserge Автор
    23.07.2015 19:21
    +1

    Да, неплохой и весьма популярный логгер. Кстати, упомянут в статье.
    Меня лично в нем не устроило: отсутствие логгирования через запятую (только форматные строки), странноватое API (я понимаю, что это игра слов на тему лесорубов, но глазу непривычно), нет поддержки просто JVM (без android.util.Log).

    (мимо, это должно было быть в ответ Suvitruf)


  1. webkumo
    23.07.2015 20:14
    +1

    Кхм… стесняюсь спросить… а почему нельзя было использовать slf4j?


    1. zserge Автор
      23.07.2015 20:26

      У него API совсем далекое от android.util.Log (а значит сложнее мигрировать). Да и как всегда, отсутствует вывод объектов через запятую без форматной строки (как console.log в js или log.Println в Go). Логеров много, каджый чем-то хорош. На вкус и цвет. Когда я писал свой — не было логгера с совместимым API и не было логгера для varargs через запятую без форматной строки. Теперь есть.


  1. TimReset
    24.07.2015 12:23

    А в чём фишка поля (field) tag? Я так по коду понял, что если это поле есть, то при выводе лога оно печатается. Так? Ну и не могли бы Вы use case показать применимости тега? А то я с таким первый раз встречаюсь.


    1. zserge Автор
      24.07.2015 13:21

      Смысл в легкой миграции. Если люди используют android.util.Log, то зачастую в их классах есть атрибут TAG (или tag). Если они перейдут на trikita.log.Log — то ожидаемо что теги по прежнему будут браться из атрибута TAG.


  1. MaximEfimov
    24.07.2015 12:48

    Было бы очень круто добавить функционал по управлению уровнем логирования отдельно для каждого тэга (или еще какой-то сущности). Обычно в очень большом проекте логов очень много, но часто хочется включить только какие-то определенные, например – посмотреть на одновременную работу уровня сети и уровня БД. Да, можно, конечно, фильтровать по набору тагов, но на мой взгляд в Logcat этот функционал реализован неудобно.


    1. zserge Автор
      24.07.2015 13:30

      В принципе, это технически можно провернуть с помощью кастомного принтера (туда приходит уровень лога, тэг и сообщение). Но лично я все равно фильтрую logcat'ом (точнее, надстройкой над ним).


  1. Mecid
    24.07.2015 13:15

    Зачем нужен был ещё один велосипед? Только из-за названия класса? В продакшине логи лучше отправлять в аналитику, не нашёл такого функционала у вас.


    1. zserge Автор
      24.07.2015 13:26

      Можно сделать собственный принтер логов. Например,

      Log.usePrinter(new Printer() {
        public void print(int level, String tag, String msg) {
          Crashlytics.log(level, tag, msg);
        }
      }, true).usePrinter(System.ANDROID, false);
      Log.d("Hello"); // выведется в крэшлитикс
      


  1. artemgapchenko
    24.07.2015 15:54

    Небольшой оффтопик: а что вы имели в виду, когда писали

    Там было все что только можно было запихнуть — и retrolambda/java8

    Как retrolambda подключить к Андроид-проекту я в курсе, а вот про Java 8 не слышал. Там же вроде только 1.7 доступна, причём try-with-resources — начиная с KitKat. Или я не прав?


  1. zserge Автор
    24.07.2015 16:20

    Не-не, все верно, я про то что компилилось все jdk8, затем с помощью ретролямбды в байткод 7й джавы превращалось. Да, увы всех фич java8 не видать, разве только гугл свои jack/jill доведут до ума. А, ну правда еще стримы бэкпортировали — github.com/aNNiMON/Lightweight-Stream-API

    (мимо, да что ж такое, это в ответ artemgapchenko )


  1. yanchenko
    25.07.2015 01:03

    Логгер, которым пользуюсь я: org.droidparts.util.L.
    Вкратце фишки:
    — тег не нужен. В debug версии в качестве тега название класса, метода и номер строки, откуда произведено логирование. В release — название класса.
    — логлевел можно настроить через AndroidManifest.xml (например, вообще выключить логирование для релиза).
    — можно логироавть любой объект, поддерживается стандартный синтаксис String.format.


  1. nekdenis
    27.07.2015 16:55

    А настройку Proguard вы зря отложили