Логирование с метками

На практике (с осознованием что иногда перепутывается) я такое сохранял через вывод в терминал а потом «сохранить вывод в файл» средствами терминала. Перепутывалось довольно мало при большой нагрузке.

Но, терминал ведь не может расставить теги, (ERROR), он даже не знает, через какой fd приложение отпраляло на него данные.

Только я не понял, вы утверждаете, что и при выводе в терминал иногда перепутывается порядок stdout/stderr сообщений? ИМХО, это уже проблеммы программы, выводящей строки, что там с буферами намутили или программа многопоточная...

Мне кажется что от датаграмных сокетов на fd0-2 могут какие-то баги возникнуть. Весь софт рассчитан на то, что там побайтовое что-то, хотя в большинстве случаев это не влияет.

На практике (с осознованием что иногда перепутывается) я такое сохранял через вывод в терминал а потом «сохранить вывод в файл» средствами терминала. Перепутывалось довольно мало при большой нагрузке.

Это то же самое что общий пайп на два дескриптора, который делается дописыванием 2>&1 в конец например.

Я неполно выразился.

На практике (с осознованием что иногда перепутывается) я такое сохранял через вывод в терминал а потом «сохранить вывод в файл» средствами терминала. Перепутывалось довольно мало при большой нагрузке.

Но, терминал ведь не может расставить теги, (ERROR), он даже не знает, через какой fd приложение отпраляло на него данные.

Тэги error расставлял пропусканием stderr через дополнительный обработчик через pipe, но при этом stdout шёл в pty терминала, поэтому был небуферзирован, и строки с error оказывались там же, вывод обработчика который ставил тэги тоже быд в pty и небуферизироввн.

Только я не понял, вы утверждаете, что и при выводе в терминал иногда перепутывается порядок stdout/stderr сообщений? ИМХО, это уже проблеммы программы, выводящей строки, что там с буферами намутили или программа многопоточная…

перепутывалось из-за того что напрямую в pty и через pipe+обработчик в pty - разные маршруты для out и err, вот они и перепутывались.

перепутывалось из-за того что напрямую в pty и через pipe+обработчик в pty - разные маршруты для out и err, вот они и перепутывались.

Об этом всё обсуждение и идёт, если ты не заметил.

SO_TIMESTAMPNS. Если этот флаг там корректно работает, то наносекунд ещё надолго хватит, чтобы различать, что было раньше

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

Случилось событие о котором надо сообщить, сперва получил идентификатор, потом собрал сообщение с этим ид, и записал/послал.

И, да, получение идентификатора будет влиять на поведение (конкурирующей) программы.

Заметил) и поскольку пришли к тому что никакого полностью корректного решения невозможно кроме рискованного через unix socket, поделился «приемлемо работающим практическим». Если в этом практическом решении вместо pty использовать pipe или файл вместо pty - то все программы начинают ещё и stdout активно буферезировать, что нивелирует практичность решения.

К сожалению unix socket не pty и как только он появится - у программ заработает буферизация

Создать pty не сильно сложнее чем создать сокет или пайп, а внешне это всё примерно одно и то же.

С таким же успехом можно сделать на баше

На баше можно сделать всё. Но через жопу.

То ли биология, то ли топология.

В начале был шар. Потом шар превратился в тор. Какая сторона тора - это голова, а какая - задница?

Можешь делать все, но через рот.

В логе события не попрядку

Буфер?

Вы [ERROR] добавить забыли.

#!/bin/bash
rm /tmp/log
#id=`date +%G%m%d_%H%M%S`

set -E  # наследовать ловушки в субшеллах
err_marker() {
   printf "[ERRORMARKER]\n" >&2
}
trap 'err_marker' ERR

{
   echo_ 1
   echo 2
   echo_ 3
   echo 4
   echo_ 5
    echo 6
} 2>&1 | sed -e 'N; s#\(.*\)\n\[ERRORMARKER\]#[ERROR] \1#; P; D' > /tmp/log

Без вмешательства в сам интерпретатор баша это нерешаемая задача. Если разделить out/err на два потока, их больше невозможно синхронизировать, разве что писать в оба метку времени, затем сшивать два файла.

[ERROR] buf.sh: line 12: echo_: command not found
2
[ERROR] buf.sh: line 14: echo_: command not found
4
[ERROR] buf.sh: line 16: echo_: command not found
6

Тогда

• https://manpages.debian.org/testing/devscripts/annotate-output.1.en.html

Запись (write()) в pipe не переключает контекст.

Любой сисколл, тем более IO, переключает из пользователя в ядро с TASK_INTERRUPTIBLE как минимум. А в ядре уже отработает шедулер.

Процесс пишет в stderr,

По дефолту не буферизированный вывод, write - уходим в ядро.

потом пишет в stdout,

Буфер полон, write - уходим в ядро.

когда здесь успеет поработать sed,

У sed есть данные на read, он выше в очереди на проц, управление должно быть передано ему.

На этой логике основана вся юниксовая порнография с потоками (которые pipe) - один процесс пишет данные, как только IO уходит в ядро, управление передаётся тому процессу, который читает данные с другого конца.

ваш скрипт ломается на таком (при выполнении не от root):

Не могу воспроизвести:

user@computer:/tmp$ bash redirect.sh 
user@computer:/tmp$ cat log.txt 
Start.
[ERROR] tar: Removing leading `/' from member names
/home/user/.bash_history
/home/user/.bashrc
[ERROR] tar: Removing leading `/' from hard link targets
[ERROR] tar: /root/.bash_history: Cannot stat: Permission denied
[ERROR] tar: Exiting with failure status due to previous errors
Stop.
user@computer:/tmp$ cat redirect.sh 
#!/usr/bin/bash
 
: > /tmp/log.txt
 
exec 2> >(sed -u 's/^/[ERROR] /' >> /tmp/log.txt )
exec 1>> /tmp/log.txt
 
echo 'Start.'
tar -v -c -f /tmp/A.tar ~/.bash_history  /root/.bash_history ~/.bashrc
echo 'Stop.'
user@computer:/tmp$ 

Когда я писал про перенаправление в unix сокеты, то именно из-за SO_TIMESTAMPNS.

Не имеет значения. Два условных echo / puts / printf в стандартный вывод в одном процессе могут иметь сколь угодно большую разницу во времени, но попадут вместе одним write в файловый дескриптор и внутри буфера их не различить, потому что libc для перенаправленного в файл стандартного вывода по дефолту включает буферизацию, которой нет для вывода на терминал.

Добро пожаловать в дружелюбный к пользователю unix, где буквально вся логика поведения ПО состоит из грязных хаков.

И да,

Процесс пишет в stderr, потом пишет в stdout,

Это уже подмена условий нашей специальной олимпиады.

Пример из ОП очевидно имеет в виду типовой сценарий - один процесс (много) пишет в stdout, другой тоже (много) в stdout, третий - в stderr, либо (много) в stdout, а потом в stderr.

Это неспортивно.

Не могу воспроизвести:

Не понял, вы же привели текст с переставленными строками. Я же написл, что «Permission denied» должно идти до «/home/user/.bashrc», tar последовательно обрабатывает файлы, указанные в командной строке. И написал, что по strace есть сначала write(2, «Permission denied», а потом write(1, ".bashrc"), а после добавления ERROR переставлено.

И сообщение «Removing leading `/' from hard link targets» должно идти сразу после первого добавленного в архив файла (/home/user/.bash_history).

Потому что libc для перенаправленного в файл стандартного вывода по дефолту включает буферизацию

Если бы это было так, и только так, то пример с tar давал бы другой результат. Во-первых, часть софта переключает stdout на построчную буферизацию. А тот софт, который по дефолту, и вобще не вызывает setbuf(), можно запускать через ″stdbuf". Возможно, есть софт, который и не по дефолту, специально вызывает setbuf() и переключает на полную буферизацию, если stdout не терминал, но его не много. И, если уж на то пошло, то можно и библиотеку подравить и через LD_PRELOAD грузить.

SO_TIMESTAMPNS — это именно для различия, когда одни процесс пишет и в stdout и в stdin. Пишет с построчной буферизацией, что нормально подходит для логов.

Это уже подмена условий нашей специальной олимпиады.

В каком месте это подмена? Я вам пример с tar привёл. И cp, mv должны отрабоать аналогично. Это база, ключ -v создаёт вывод на stdout, а ошибки на stderr.

очевидно

Очевидно, вы в ВУЗе не учились. Там, ещё на первых курсовых настоятельно били по рукам за «очевидно». ТС скрипт не показал, сегодня там одни команды, завтра будут другие. tar ещё умеет вызвать компрессор, который ругается своими сообщениями. ТС ведь не указал в списке команд компрессор, но, скорее всего, создаёт сжатые архивы.

переключает контекст.

переключает из пользователя в ядро с TASK_INTERRUPTIBLE

Общепризнанное значение термина «переключение контекста» означает именно переключение между процессами. Если процесс вызвал syscall, ушёл в ядро, то это не означает, что будет вызван context_switch()/switch_to(). Если процесс заблокировался на write(), то да, будет запущен другой из очереди. А если write() ушёл в буфер, то блокировки нет, процесс может успеть сделать ещё write() за отведённый ему квант времени.

один процесс пишет данные, как только IO уходит в ядро, управление передаётся тому процессу, который читает данные с другого конца.

У pipe есть буфер, если IO его не заполнило, то сразу управление другому процессу не передаётся.

Два условных echo / puts / printf в стандартный вывод в одном процессе могут иметь сколь угодно большую разницу во времени, но попадут вместе одним write в файловый дескриптор и внутри буфера их не различить,

Если echo это шелл-команда, то нет, не могут. Даже если шелл-команда builtin, она всё равно делает вид что она отдельная программа, хоть fork может и не делать, но буферы никакие с соседними командами не шарит.

Вообще архитектурно разные потоки вывода stdout и stderr предназначены для того, чтобы идти в разные приёмники (файлы). Они по дизайну, концептуально, по философии unix не синхронизированы. Сообщение в stderr должно быть понятно без контекста из stdout, а сообщение (данные) в stdout должны быть корректными несмотря на ругань в stderr или не выдаваться вовсе.

Так что решать задачу ТС с добавлением меток еггог в корректном порядке - НЕ НУЖНО.

Общепризнанное значение термина «переключение контекста» означает именно переключение между процессами

Общепризнанное значение термина "переключение контекста" говорит о переключении контекста в контексте предмета разговора. В нашем случае - точка неопределённости отправка буфера в ядро, и контекст соответственно такой.

В каком месте это подмена?

Собрать котёнка обратно из шаурмы - заведомо не решаемая задача. Нет смысла её обсуждать. Но есть практический (не уверен, что этому учат в ВУЗе) смысл обсуждать более частный случай из ОП, где для дочерних процессов можно предложить вполне работающее (пока Меркурий не стал ретроградным) решение.

Для наколеночного скрипта "для дома, для семьи" - этого достаточно.

Даже если шелл-команда builtin, она всё равно делает вид что она отдельная программа,

Заинтриговал, стервец! И как именно она это делает? Какие у нас технические критерии "отдельной программы", которым удовлетворяют башевские builtin?

У неё своя виртуальная копия таблицы дескрипторов. Ты же можешь сделать 1>&3 и подобное - и оно применится только к echo, а у следующей команды дескрипторы уже будут те что были раньше. Я проверил strace-ом на дебиановском /bin/sh, он это реализует примерно так:

save_1 = dup(1); set_CLOEXEC(save_1);
dup2(3,1);
execute_echo(...);
dup2(save_1,1); close(save_1);

Очевидно, такой способ дешевле чем fork поэтому виртуальная таблица дескрипторов эмулируется через предварительный бекап основной. А ещё после echo можно поставить & и тогда шеллу таки придётся сделать настоящий fork чтобы его выполнить. Для внешних же команд fork делается всегда, а & только означает что не надо делать после него wait().

Ещё у builtin-ов есть виртуальные exit-codes - у отдельных прог они через return из main-а передаются или через exit(), а у встроенных команд шелл внутреннее их сохраняет.

Когда коту делать нечего.

У неё своя виртуальная копия таблицы дескрипторов.
Ещё у builtin-ов есть виртуальные exit-codes

Это всё не имеет никакого отношения к "отдельная программа", это хитрости bash, чтобы builin можно было подставить в точки вызова внешних программ с сохранением shell-семантики. И сам набор этих костылей какбе намекает.

чтобы builin можно было подставить в точки вызова внешних программ с сохранением shell-семантики

Ага. А теперь это прочти:

делает вид что она отдельная программа,

Не видишь сходства?

Итог в любом случае такой: никакой сквозной буферизации между даже двумя соседними echo -n нет.

Не видишь сходства?

Нет, не вижу. Потроха башевского синтаксиса - это его глубоко личная и внутренняя кухня, не имеющая никакого отношения к процессам в системе.

У тебя с русским языком проблемы или как? Я даже подчеркнул куда обратить внимание. В контексте написания скриптов низкоуровневые детали (процессы на уровне ОС) несущественны, а вот то что у каждой команды свой контекст исполнения (ради чего и делаются процессы) - важно. И повторю ещё раз, оно «делает вид», а не создаёт настоящий процесс.

И баш тут ни при чём, он только реализует POSIX shell стандарт.

В контексте написания скриптов низкоуровневые детали (процессы на уровне ОС) несущественны,

Тащем-та процессы на уровне ОС - это ровно то, ради чего пишутся все эти баш-портянки.

у каждой команды свой контекст исполнения (ради чего и делаются процессы)

Давай, до свидания.

Контекст? Хмм.

А echo делает fork? Может получить сигнал как отдельная сущность?

Что там SUS на эту тему говорит, мне лень щас открывать справочник…

Нет, не делает, я ж выше писал что он только притворяется отдельным. (только не echo а шелл для echo, сам echo начинается уже после того как все подготовки сделаны)

Да, с сигналами там дыра в эмуляции, послать отдельный сигнал builtin-у без & нельзя. Однако если в скрипте запущен builtin без &, то слать из этого же скрипта сигналы уже не получится, ведь он ждёт окончания работы builtin-а. Т.е. это только снаружи видно, ну или если сделать что-то типа

( sleep 1; echo 1; sleep 1; echo 2 ) &
while true; do безуспешно пытаемся поймать echo и послать ему сигнал; done

В нашем случае - точка неопределённости отправка буфера в ядро, и контекст соответственно такой.

Что в этой точке такого неопределённого? Процесс запускается через stdbuf, в ядро строки будут отправлены в том же прорядке, что и на терминал.

пока Меркурий не стал ретроградным

Пока команде tar, cp и т.д. не указали ключ -v?

типовой сценарий - один процесс (много) пишет в stdout... третий - в stderr, либо (много) в stdout, а потом в stderr

И какой из этих процессов:

dd, tar, cp, mv

много логов пишет в stdout? Вы точно решаете задачу про скрипт ТС'а?

Процесс запускается через stdbuf,

Какой процесс? Где запускается? Ты о чём вообще? В моём скрипте нет ни одной запятой ни про какой stdbuf. В скрипте у ТС - тоже к слову.

Вы точно решаете задачу про скрипт ТС’а?

Исходя из твоих гипотез про какой-то stdbuf - вопрос к тебе.

пока Меркурий не стал ретроградным

Пока команде tar, cp и т.д. не указали ключ -v?

Да, примерно. Или не жахнули cat’ом в stderr чего-нибудь толстого.

в ядро строки будут отправлены в том же прорядке

И чем это поможет устранить неопределённость, про которую весь тред?

#!/bin/bash

xargs -I % bash -c 'eval "%" 2> >(sed s/^/ERROR:\\\ /)' <<EOF
  raz
  ls /
  dva
  pwd
  tri
  ls nosuchdir
EOF

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

В ядро строки придут в правильном порядке. Ядро на строки поставит временные метки (SO_TIMESTAMPNS), процесс, читающий датаграммы из сокетов их по этим меткам отсортирует. Но, понятно, это я пишу про свой вариант, когда скрипт запускается потомком утилиты, а не когда утилита запускается bash'ем при перенаправлении stderr. Устраивает это ТС или нет я не знаю, да и код нужно на Си или другом ЯП для системного программирования писать.

про которую весь тред?

Я достаточно давно написал:

Про то, что в программе может быть буферизация вывода речи не идёт.

В скриптах обычно не запускают произвольные утилиты, ограничиваются набором coreutils и около. Там, обычно, fflush() широко используют. Или их поведение можно скорректировать через stdbuf. Ну есть ещё sed, у него есть ключ -u. И, в рамках этой задачи, то, что:

данные в сокет будут улетать буферами, разделёнными в произвольном месте.

приведёт к проблеме, только если программа пишет и в stdout и stderr и не делате fflush. Пример TC без sed отправляет в ядро строки в правильном порядке.

Исходя из твоих гипотез про какой-то stdbuf - вопрос к тебе.

stdbuf относятся к моим вариантам решения задачи. Я не писал, что у вас или у ТС используется stdbuf. Но, ТС написал про dd, tar, cp, mv, вы написали про:

типовой сценарий - один процесс (много) пишет в stdout

А потом пишете, что tar -v — это «ретроградный Меркурий» для вашего скрипта. Получается, tar для вашего скрипта не подходит, он, если и пишет логи на stdout, то с ключём -v. Ну, или сконструируйте из tar, cp что-то, работающие с вашим скриптом.

Лично у меня вот это:

cp -v -f ~/.bash_history /root/.bash_history ~/.bashrc /tmp/

даёт ERROR в конце

В конце вызова команды цэпэ, а не в конце списка команд. Сойдет.

Смыла в таком ужосе с eval нет.

Во всем этом ужосе с самого начала нет смысла. Я ж исключительно в рамках спецолимпиады.

Но, понятно, это я пишу про свой вариант,

Не очень понятно, зачем ты разговариваешь сам с собой ответами на мои посты. Но отвечу вот на это:

вы написали про:

типовой сценарий - один процесс (много) пишет в stdout

А потом пишете, что tar -v — это «ретроградный Меркурий» для вашего скрипта. Получается, tar для вашего скрипта не подходит,

Не надо передёргивать. Не подходит программа, которая одновременно тугосерит в оба потока вывода большим объёмом щитпостинга вперемешку. Такое поведение - редкость. Большинство программ либо отрабатывают успешно, либо прекращают работу с диагностическим сообщением. tar в том числе. Нет, tar и tar -v длинный список некорректных аргументов - это разные вещи.

Это решение не идеальное, но лучше никакого.

а не в конце списка команд.

Дак, стоит записать эти команды в одну стоку и будет в конце списка. А записать в одну строку придётся, если захочется AND или OR список ( &&, || ).

Схреналь? Покажи пример, не догоняю.

Всё, что делает ваш скрипт — это построчно выполняет список из here-doc. И на каждую строку вызывается отдельный bash, запускающий отдельный sed. Если в here-doc написать строку со списоком команд, то все эти команды будут в один sed перенаправлены. Пример:

#!/bin/bash
DIR=/tmp/D
rm -rf $DIR
mkdir $DIR

xargs -I % bash -c 'eval "%" 2> >(sed s/^/ERROR:\\\ /)' <<EOF
  TT=25
  raz
  ls /
  cp -v -f ~/.bash_history /root/.bash_history ~/.bashrc /root/. bashrc $DIR || echo BBB $TT
EOF
rm -rf $DIR

На xeon скрип выполняется так:

ERROR: bash: line 1: raz: command not found
bin   dev  home  lib64       media  opt   root  sbin  tmp      var
boot  etc  lib   lost+found  mnt    proc  run   sys   usr  
'/home/user/.bash_history' -> '/tmp/D/.bash_history'
'/home/user/.bashrc' -> '/tmp/D/.bashrc'
ERROR: cp: cannot stat '/root/.bash_history': Permission denied
ERROR: cp: cannot stat '/root/.bashrc': Permission denied
BBB

А на одноядерном четвёртом пне (Intel(R) Pentium(R) 4 CPU 2.40GHz) так:

ERROR: bash: line 1: raz: command not found
bin   dev  home  lost+found  mnt  proc  run   sys  usr
boot  etc  lib   media       opt  root  sbin  tmp  var
'/home/user/.bash_history' -> '/tmp-ram/D/.bash_history'
'/home/user/.bashrc' -> '/tmp-ram/D/.bashrc'
BBB
[user@comp /tmp]$ ERROR: cp: cannot stat '/root/.bash_history': Permission denied
ERROR: cp: cannot stat '/root/.bashrc': Permission denied

Там и там gentoo, примерно одного времени компиляции, версии cp, sed, bash и пр. одинаковые. И я знаю, что одноядерники почти умерли, хотя одноядерные одноплатники, вроде, ещё есть, но под большой нагрузкой и многоядерный процессор может выполнять sed после скрипта.

Во всем этом ужосе с самого начала нет смысла.

Но во всех остальный вариантах из этой темы скрипт оставался скриптом, там могли быть переменные, циклы и т.д. А у вас просто набор строк-команд, поэтому и УЖОС, что нельзя нормальный скрипт с переменными, условными операторами и т.д. завернуть в ваш EOF.

выхлоп sed в терминал приходт после того, как bash отрисует промпт

В топике требовалось засунуть весь выхлоп в файл. Все еще не вижу проблемы.

там могли быть переменные, циклы

Да мне в целом пофиг. Я бы одинаково отрывал жопы и за свой вариант, и за варианты с циклами.

В спецолимпиаде главное неучастие, ну так я уже проиграл, какая разница шо там скрипт делает и как.

и тем более после вывода от echo BBB.

что не стыкуется с:

В конце вызова команды цэпэ, а не в конце списка команд

Но, если:

какая разница шо там скрипт делает и как.

дак не надо было меня какие-то примеры приводить.

В спецолимпиаде главное неучастие

Ну, может в этой олимпаде нашли бы рабочее решение, и его бы могли взять себе разработчики systemd-cat.