Добавление временной метки к каждой строке вывода команды

Я хочу добавить временную метку к каждой строке вывода команды. Например:

foo
bar
baz

станет

[2011-12-13 12:20:38] foo
[2011-12-13 12:21:32] bar
[2011-12-13 12:22:20] baz

…где время, добавляемое в начале, – это время, когда строка была выведена. Как я могу этого достичь?

moreutils включает в себя ts, который делает это довольно хорошо:

command | ts '[%Y-%m-%d %H:%M:%S]'

Это также устраняет необходимость в цикле, каждая строка вывода будет содержать временную метку.

$ echo -e "foo\nbar\nbaz" | ts '[%Y-%m-%d %H:%M:%S]'
[2011-12-13 22:07:03] foo
[2011-12-13 22:07:03] bar
[2011-12-13 22:07:03] baz

Хотите узнать, когда сервер снова запустился после перезагрузки? Просто выполните ping | ts, проблема решена :D.

Примечание: Используйте [%Y-%m-%d %H:%M:%.S] для микросекундной точности.

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

Вы также можете проверить, не имеет ли ваша команда встроенной функции, предназначенной для этой цели. Например, ping -D существует в некоторых версиях ping и печатает время с начала эпохи Unix перед каждой строкой. Если ваша команда не содержит собственного метода, однако, есть несколько методов и инструментов, которые можно использовать, среди прочего:

Оболочка POSIX

Имейте в виду, что поскольку многие оболочки хранят свои строки внутренне как cстроки, если ввод содержит нулевой символ (\0), это может привести к тому, что строка закончится преждевременно.

command | while IFS= read -r line; do printf '[%s] %s\n' "$(date '+%Y-%m-%d %H:%M:%S')" "$line"; done

GNU awk

command | gawk '{ print strftime("[%Y-%m-%d %H:%M:%S]"), $0 }'

Perl

command | perl -pe 'use POSIX strftime; print strftime "[%Y-%m-%d %H:%M:%S] ", localtime'

Python

command | python -c 'import sys,time;sys.stdout.write("".join(( " ".join((time.strftime("[%Y-%m-%d %H:%M:%S]", time.localtime()), line)) for line in sys.stdin )))'

Ruby

command | ruby -pe 'print Time.now.strftime("[%Y-%m-%d %H:%M:%S] ")'

Для измерения дельты построчно попробуйте gnomon.

Это утилита командной строки, немного похожая на ts из moreutils, для добавления информации о времени к стандартному выходу другой команды. Полезно для долгосрочных процессов, когда вы хотите иметь историческую запись того, что так долго занимает время.

Передача чего-либо в gnomon добавит временную метку к каждой строке, указывая, как долго эта строка была последней строкой в буфере — то есть, сколько времени понадобилось, чтобы появилась следующая строка. По умолчанию gnomon будет отображать секунды, прошедшие между каждой строкой, но это настраиваемо.

Я бы предпочел прокомментировать выше, но я не могу, репутационно. В любом случае, приведенный выше пример на Perl можно сделать неблокирующим следующим образом:

command | perl -pe 'use POSIX strftime; 
                    $|=1; 
                    select((select(STDERR), $| = 1)[0]);
                    print strftime "[%Y-%m-%d %H:%M:%S] ", localtime'

Первый ‘$|’ отключает буферизацию STDOUT. Второй устанавливает stderr как текущий канал вывода по умолчанию и отключает его буферизацию. Поскольку select возвращает исходную настройку $|, обернув select внутри select, мы также сбрасываем $| к его значению по умолчанию, STDOUT.

И да, вы можете копировать и вставлять как есть. Я сделал многострочный для удобочитаемости.

А если вы действительно хотите получить точность (и у вас установлен Time::Hires):

command | perl -pe 'use POSIX strftime; use Time::HiRes gettimeofday;
                    $|=1; 
                    select((select(STDERR), $| = 1)[0]);
                    ($s,$ms)=gettimeofday();
                    $ms=substr(q(000000) . $ms,-6);
                    print strftime "[%Y-%m-%d %H:%M:%S.$ms]", localtime($s)'

Обновление 2024 года

Программа ets, описанная ниже, не обновлялась с 2020 года, поэтому, начиная с апреля 2024 года, вы можете рассмотреть возможность получения её обновлённой версии из https://github.com/gdubicki/ets с новой версией.

Оригинальный ответ

Непостыженно рекламирую что-то, что я только что написал, чтобы решить эту именно проблему: ets, написанное на Go.

Вы можете найти много примеров использования на странице проекта.

Основное отличие от существующих ответов и аналогичных предложений заключается в том, что ets предназначен для выполнения вашей команды за вас, в псевдотерминале (pty) — то есть, эмулируя выполнение вашей команды, как если бы она выполнялась в терминале. По сравнению с передачей вывода команды, например, в ts, это делает временные метки почти прозрачными и решает множество проблем, связанных с передачей:

• Некоторые программы агрессивно буферизуют при записи в канал, поэтому вы не видите вывода, а затем видите целый поток вывода (да, вы можете использовать stdbuf, вы даже можете обернуть stdbuf и ts в псевдоним/функцию, но разве не было бы лучше, если бы все работало сразу);
• Некоторые программы отключают цвет и/или интерактивность при записи в канал;
• Статус выхода пропадает, если вы не включили pipefail; и т.д.

Команды могут быть выполнены напрямую, что означает, что вы можете просто добавить ets к вашей существующей командной строке, или они могут быть командными оболочками (как показано на гифке выше). Конечно, если вы хотите направить вывод, ets также может это сделать.

ets поддерживает те же режимы временных меток, что и ts из moreutils: режим абсолютного времени, режим прошедшего времени и режим инкрементального времени. Он использует более разумные значения по умолчанию (например, монотонные часы всегда используются для временных меток прошедшего/инкрементального времени) и имеет дополнительную поддержку для пользовательских часовых поясов. Существует детальное сравнение здесь.

Снова, https://github.com/zmwangx/ets. Попробуйте, сообщите об ошибках и т.д.

Большинство ответов предлагают использовать date, но это достаточно медленно. Если ваша версия bash больше 4.2.0, лучше использовать printf, это встроенная функция bash. Если вам нужно поддерживать старые версии bash, вы можете создать функцию log, зависящую от версии bash:

TIMESTAMP_FORMAT='%Y-%m-%dT%H:%M:%S'
# Версия Bash в числах как 4003046, где 4 - основная версия, 003 - минорная, 046 - подпункт.
printf -v BV '%d%03d%03d' ${BASH_VERSINFO[0]} ${BASH_VERSINFO[1]} ${BASH_VERSINFO[2]}
if ((BV > 4002000)); then
log() {
    ## Быстро (встроенное), но секунда является минимальным образцом для большинства реализаций
    printf "%(${TIMESTAMP_FORMAT})T %5d %s\n" '-1' $$ "$*"  # %b конвертирует эскейпы, %s печатает как есть
}
else
log() {
    ## Медленно (поток, date), но поддерживает наносекунды и старые версии bash
    echo "$(date +"${TIMESTAMP_FORMAT}") $$ $*"
}
fi

Смотрите различия в скорости:

user@host:~$time for i in {1..10000}; do printf "%(${TIMESTAMP_FORMAT})T %s\n" '-1' "Some text" >/dev/null; done

real    0m0.410s
user    0m0.272s
sys     0m0.096s
user@host:~$time for i in {1..10000}; do echo "$(date +"${TIMESTAMP_FORMAT}") Some text" >/dev/null; done

real    0m27.377s
user    0m1.404s
sys     0m5.432s

UPD: вместо $(date +"${TIMESTAMP_FORMAT}") лучше использовать $(exec date +"${TIMESTAMP_FORMAT}") или даже $(exec -c date +"${TIMESTAMP_FORMAT}"), чтобы ускорить выполнение.

UPD2: bash 5 предоставляет переменную EPOCHREALTIME с микросекундной точностью, вы можете использовать её с этой командой (примерно на 30% медленнее, чем только секунды):
printf "%(${TIMESTAMP_FORMAT})T.%s %5d %s\n" ${EPOCHREALTIME/./ } $$ "$*"

Пост Раяна предлагает интересную идею, однако он имеет несколько недостатков. При тестировании с tail -f /var/log/syslog | xargs -L 1 echo $(date +'[%Y-%m-%d %H:%M:%S]') $1 я заметил, что временная метка остается неизменной, даже если stdout приходит позже с разницей в секундах. Рассмотрим этот вывод:

[2016-07-14 01:44:25] Jul 14 01:44:32 eagle dhclient[16091]: DHCPREQUEST of 192.168.0.78 on wlan7 to 255.255.255.255 port 67 (xid=0x411b8c21)
[2016-07-14 01:44:25] Jul 14 01:44:34 eagle avahi-daemon[740]: Joining mDNS multicast group on interface wlan7.IPv6 with address fe80::d253:49ff:fe3d:53fd.
[2016-07-14 01:44:25] Jul 14 01:44:34 eagle avahi-daemon[740]: New relevant interface wlan7.IPv6 for mDNS.

Мое предложенное решение похоже, однако обеспечивает правильное время и использует более универсальный printf, а не echo

| xargs -L 1 bash  -c 'printf "[%s] %s\n" "$(date +%Y-%m-%d\ %H:%M:%S )" "$*" ' bash

Почему bash -c '...' bash? Потому что из-за опции -c первый аргумент присваивается $0, и он не будет отображаться в выводе. Ознакомьтесь с документацией вашей оболочки для получения правильного описания -c.

Тестирование этого решения с tail -f /var/log/syslog и (как вы, вероятно, уже могли догадаться) отключением и повторным подключением к Wi-Fi, показало правильную временную маркировку как от date, так и от сообщений syslog.

Bash можно заменить любой оболочкой, подобной bourne, это можно сделать с помощью ksh или dash, как минимум, тех, которые имеют опцию -c.

Потенциальные проблемы:

Решение требует наличия xargs, который доступен на системах, совместимых с POSIX, поэтому большинство Unix-подобных систем должны быть покрыты. Очевидно, это не будет работать, если ваша система не совместима с POSIX или не имеет GNU findutils.

Сделайте это один раз для всех команд в вашем скрипте

Если вы работаете в bash, добавьте это ближе к началу вашего скрипта:

exec &> >( ts '%Y-%m-%d %H%M.%.S ' )  # добавьте временную метку ко всем выходным данным

Или, для дополнительного балла, выводить в файл журнала через:

script_name=foobar
log_file=$( printf "/tmp/${script_name}-%(%Y-%m-%d)T.%(%H%M%S)T.log" -1 )
echo "note: redirecting output to [${log_file}]"
exec &> >( ts '%Y-%m-%d %H:%M:%.S ' > ${log_file} )

чтобы отображать как в консоль, так и в файл журнала:

script_name=foobar
log_file=$( printf "/tmp/${script_name}-%(%Y-%m-%d)T.%(%H%M%S)T.log" -1 )
exec &> >( ts '%Y-%m-%d %H:%M:%.S ' | tee ${log_file} )

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

Программа ts находится в пакете moreutils, который должен быть доступен под любой разумной администраторской системой. 🙂

Другие программы для временных меток работают так же

Вы также можете использовать другие программы таким образом, например, эти из других ответов:

• rtts – предложено Timmmm – для относительных временных меток с точностью до микросекунд,
• ets – предложено Zhiming Wang (4ae1e1) – как выше, но с цветами 🌈, часовыми поясами и другими приятными функциями,

Большинство из этих ответов плохо подходят для измерения производительности. AWK не может показывать миллисекунды. Ruby и Python очень медленные. Кроме того, все они показывают абсолютное время, когда вам действительно нужно относительное время.

Я подумал, что кто-то, вероятно, написал достойное решение на Rust, и они это сделали!

rtts

Вы можете передать в него данные:

-% cargo build --release 2>&1 | rtss
 274.1ms  274.1ms |    Компиляция libc v0.2.40
   1.50s    1.22s |    Компиляция memchr v2.0.1
   2.28s  780.8ms |    Компиляция rtss v0.5.0 (file:///home/freaky/code/rtss)
   5.18s    2.90s |     Завершение релиза [оптимизированный] целевых в 5.17 секунд
   5.18s    код выхода: 0

Или обернуть команду:

-% rtss sh -c "echo foo; echo bar; sleep 1; echo moo >&2; sleep 1; echo baz; exit 64"
   1.7ms    1.7ms | foo
   1.7ms          | bar
   1.00s    1.00s # moo
   2.03s    2.03s | baz
   2.03s    код выхода: 64
zsh: exit 64    rtss sh -c

-% rtss sh -c "echo foo; echo bar; sleep 1; echo moo >&2; sleep 1; echo baz; exit 64" 2>/dev/null
   1.9ms    1.9ms | foo
   1.9ms          | bar
   2.05s    2.04s | baz
   2.05s    код выхода: 64
zsh: exit 64    rtss sh -c  2> /dev/null

Он также показывает вам время, затраченное на каждую строку (второй столбец), что весьма полезно.

Он также работает как для stderr, так и для stdout.

К сожалению, они не настроили CI для сборки исполняемых файлов, но установка программ Rust проста, если у вас уже установлен Rust:

cargo install rtss

Это можно легко сделать, используя logger, который обычно поставляется с большинством дистрибутивов, я бы предположил:

host ~ # echo sup | logger --no-act -s
<13>Февраля 11 15:59:00 root: sup

Это небольшой инструмент, реализованный на C:

/*
 * Перенаправление stdin в stdout, добавляя метку времени Unix с точностью до миллисекунд
 * к каждой строке.
 */
#include <stdio.h>
#include <sys/time.h>

int main(int argc, char *argv[]) {
   char *line = NULL;
   size_t linecap = 0;
   ssize_t linelen;
   struct timeval tv;

   while ((linelen = getline(&line, &linecap, stdin)) > 0) {
      gettimeofday(&tv, NULL);
      fprintf(stdout, "%lu ", tv.tv_sec*1000 + tv.tv_usec/1000);
      fwrite(line, linelen, 1, stdout);
   }
}

Вставьте приведенный выше код в файл .c. Я называю свой файл tsms.c. Затем

gcc -o tsms tsms.c

а затем

command | tsms

выдаст:

<метка времени> <вывод команды>

и вы тоже можете быть большим парнем.

В оригинальном Terminal Linux, я вижу, когда завершить команду, я вижу, когда ввожу следующую команду

Я использую это решение

https://unix.stackexchange.com/a/622928/675422

exec &> >( ts ‘%Y-%m-%d %H%M.%.S ‘ ) # добавьте временную метку ко всем выходным данным

Но после завершения команды я не вижу, когда ввожу следующую команду

Возможно, или очень-очень нужно сделать так, чтобы после завершения команды я видел, когда ввожу следующую команду + временная метка

Смотрите скриншот

Спасибо!