STDOUT и STDERR вышли из строя - PullRequest
2 голосов
/ 14 февраля 2020

У меня есть сценарий perl, который записывает сообщения в STDOUT и STDERR (через операторы print / croak), но я также перенаправляю STDOUT и STDERR в файл журнала:

File::Tee::tee STDOUT, ">>", "$logFile" ;
File::Tee::tee STDERR, ">>", "$logFile" ;

Теперь выходной файл журнала сообщения от STDOUT и STDERR отображаются не по порядку. Также фактический выходной сигнал на клемме также не в порядке. Я попытался очистить буферы (как рекомендовано здесь: https://perl.plover.com/FAQs/Buffering.html), но это не помогает:

select(STDERR) ;
$| = 1 ;
select(STDOUT) ;
$| = 1 ;

Кто-нибудь знает, что я должен сделать, чтобы увидеть вывод в порядке (Я также попытался дополнительно очистить дескриптор файла, соответствующий $ logfile, но он все тот же)?


РЕДАКТИРОВАТЬ:

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

  1. Я уже сбрасывал STDOUT и STDERR, прежде чем использовал File :: Tee. Как и подозревал @jimtut, виновником был File :: Tee - удаление его восстановило порядок на консоли. Но я действительно хотел перенаправить STDOUT и STDERR.
  2. @ mob предложил вместо этого использовать IO :: Tee, но я не совсем понял, как сделать так, чтобы они работали так, как я хочу в своем коде.
  3. @ briandfoy указал, что не существует надежного способа обеспечить отображение 2 отдельных файловых дескрипторов в правильном порядке в реальном времени, а также предложил использовать процедуру записи в журнал, которая является единственным местом, которое может записывать в STDOUT / STDERR. , @zimd также отметил, что File :: Tee использует fork, который является сердцем проблемы, поскольку 2 процесса не могут гарантировать какой-либо порядок вывода.
  4. Поскольку виноват File :: Tee, я попытался удалить это из кода. Я обновил свою функцию ведения журнала, чтобы печатать в STDOUT / STDERR, а также дополнительно печатать в дескриптор файла $ log. Далее для сбора предупреждений в журнале я сделал следующее:
sub warning_handler {
  my $msg = $_[0] ;
  print STDERR $msg ;
  print $log $msg if defined $log ;
}
$SIG{__WARN__} = \&warning_handler ;

Это отлично работало для всего кода под моим контролем. Теперь все печаталось по порядку как на консоли, так и в лог-файле. Однако я понял, что не могу использовать это решение, так как я также вызывал чьи-то пакеты perl для некоторой функциональности, и, очевидно, я не мог перехватить print / croak et c, которая писала в STDOUT / STDERR в пределах 'off the полочный пакет. Так что сейчас у меня нет хорошего решения. Однако я подозреваю, что если я найду способ перехватить STDOUT / STDERR в perl, я смогу получить то, что мне нужно.


EDIT2: я добавил свой собственный ответ, который, вероятно, наиболее близок к решению проблемы, изменив решение моба использовать IO :: Tee вместо File :: Tee, но даже при этом пропускаются некоторые сообщения (хотя это исправляет порядок).


EDIT3: наконец-то найдено «решение»

use IO::Tee ;
use Capture::Tiny qw(capture);
...
...
select(STDERR) ;
$| = 1 ;
select(STDOUT) ;
$| = 1 ;
open (my $log, ">", $logfilename) ;
*REALSTDOUT = *STDOUT ;
*REALSTDERR = *STDERR ;
*STDOUT = IO::Tee->new(\*REALSTDOUT, $log);
*STDERR = IO::Tee->new(\*REALSTDERR, $log);

# Regular Perl code here which sends output to STDOUT/STDERR
...
...
# system calls / calls to .so needs to be catpured 
&log_streams(sub { &some_func_which_calls_shared_object() ; }) ;

sub log_streams {
    my ($cr, @args) = @_;  # code reference, with its arguments
    my ($out, $err, $exit) = capture { $cr->(@args) };

    if ($out) {
        print STDOUT $out;
    }
    if ($err) {
        print STDERR $err;
    }
}

Использование IO :: Tee гарантирует, что все сгенерированные perl выходные данные для консоли также go для файла журнала, и это происходит немедленно, обновляя журнал и консоль в реальном времени. Поскольку IO :: Tee меняет значение файловых дескрипторов STDOUT / STDERR, чтобы теперь ссылаться на дескрипторы teed, он может перехватывать только stdio из операторов perl, он пропускает вызовы sys, поскольку они пропускают дескрипторы perl STDOUT / STDERR. Таким образом, мы записываем выходные данные системного вызова и затем используем процедуру log_streams, чтобы переслать ее в потоки STDOUT / STDERR с псевдонимами. Это создает задержку в сгенерированном системном вызове выводе, отображаемом в журнале / терминале, но нет задержки для perl сгенерированного вывода - т.е. лучшего из обоих миров. Обратите внимание, что порядок stderr и stdout, генерируемый вызовом подпрограммы some_func_which_calls_shared_object, не сохраняется, поскольку в подпрограмме log_streams мы сначала печатаем в STDOUT, а затем в STDERR - до тех пор, пока системный вызов не атомом c и не сделать многое с точки зрения чередования сообщений stdout / stderr, мы должны быть в порядке. Цените решения от briandfoy, mob и zimd, ответы которых я объединил, чтобы прийти к этому решению! Никогда не думал, что потребуется 1048 * для прохождения этой детали, что кажется очень простой проблемой.

Ответы [ 4 ]

6 голосов
/ 14 февраля 2020

С двумя отдельными файловыми дескрипторами нет договора или гарантии, что вы увидите их в реальном времени. На это влияют различные настройки и буферы, поэтому вы видите auto flu sh ($|). Это та же идея для файлов или терминала.

Поймите, что это скорее архитектурная проблема, чем проблема syntacti c. У вас есть две вещи, конкурирующие за один и тот же ресурс. Это обычно заканчивается слезами. Я не решаюсь предложить решение, когда я не знаю, в чем заключается проблема, но подумайте о том, чтобы иметь все, что пытается записать в STDOUT или STDERR запись в какой-то брокер сообщений, который собирает все сообщения и является единственным который пишет в конечный (общий) пункт назначения. Например, вещи, которые хотят добавить записи в системный журнал, не записывают в системный журнал; они отправляют сообщения тому, что пишет в системный журнал.

Еще один пример Perly: в Log4 perl вы не пишете в конечные пункты назначения. Вы просто регистрируете сообщение, и регистратор - единственная вещь, которая выясняет, как с ним обращаться. Когда мне нужно такое поведение с модулем, я не использую средства вывода напрямую:

debug( "Some debug message" );

sub debug {
    my $message = shift;
    output( "DEBUG: $message" );
    }

sub output { # single thing that can output message
    ...
    }

Затем делайте все, что вам нужно сделать в output.

Но вы не всегда можете контролировать это в других вещах, которые также пытаются выводить вещи. Perl давайте обойдем это, переопределив то, что warn и друзья делают, добавив кодовую ссылку в $SIG{__WARN__}. Вы можете записывать предупреждающие сообщения и делать с ними все что угодно (например, отправлять их на стандартный вывод). Кроме того, черные маги c открывают STDERR на то, что вы можете контролировать. Это не так уж плохо, и он изолирован в одном месте.

В какой-то момент, когда другой человек не хочет объединенного вывода, а навязчивые решения делают невозможным их разделение. Я бы предпочел гибкость, чем жестко запрограммированное ограничение. Если я хочу только ошибки, я хочу способ получить только ошибки. Есть много других видов обходных путей, таких как обертки, которые собирают как выходные потоки (то есть совсем не навязчиво), так и различные перенаправления команд.

4 голосов
/ 14 февраля 2020

У вас будет два дескриптора файла, записывающих в $logfile. Если File::Tee не позаботится о поиске конца файлового дескриптора перед каждой записью (чего он не выглядит), вы получите условие гонки, при котором один файловый дескриптор будет перезаписывать другой.

Обходной путь будет использовать параметр reopen для функции File::Tee::tee, которая закрывает файл после каждой записи и открывает его (в соответствующем конце файла) перед следующей записью. Это может ухудшить вашу производительность, в зависимости от того, как часто вы пишете в эти файловые дескрипторы.


Возможно, вам также повезет больше с IO::Tee, который является более простой реализацией (с использованием связанных файловых дескрипторов), чем File::Tee использует (фоновый процесс для каждого File::Tee::tee вызова), поэтому вы можете получить меньше сюрпризов. Вот как может выглядеть решение IO::Tee:

use IO::Tee;
$| = 1;
open my $stdout, ">&=1";  # to write to original stdout
open my $stderr, ">&=2";  # to write to original stderr
open my $fh_log, ">>", $logfile;
*STDOUT = IO::Tee->new($stdout, $fh_log);
*STDERR = IO::Tee->new($stderr, $fh_log);
...

Нет фонового процесса, дополнительных потоков или чего-либо еще, что могло бы вызвать состояние гонки. И STDOUT, и STDERR будут записывать в один и тот же дескриптор файла журнала один и тот же процесс.

3 голосов
/ 15 февраля 2020

Примечание Первая часть выполняется с помощью ручек t ie -d; Решение во второй части использует Capture::Tiny


Базовое подтверждение концепции для подхода с использованием t ie -d ручек.

Пакет, который связывает дескриптор путем печати из него в файл и в (копию) STDOUT stream

package DupePrints; 

use warnings; 
use strict; 
use feature 'say'; 

my $log = 't_tee_log.out'; 
open my $fh_out, '>', $log or die $!;  # for logging

# An independent copy of STDOUT (via dup2), for prints to terminal
open my $stdout, '>&', STDOUT or die $!;

sub TIEHANDLE { bless {} } 

sub PRINT { 
    my $self = shift; 

    print $fh_out @_; 
    print $stdout @_;
}

1;

Программа, которая использует его

use warnings;
use strict;
use feature 'say';

use DupePrints;    
$| = 1;
tie *STDERR, 'DupePrints';
tie *STDOUT, 'DupePrints';

say "hi";

warn "\t==> ohno";

my $y;
my $x = $y + 7;

say "done";

Это печатает как на терминал, так и на t_tee_log.out текст

hi
        ==> ohno at main_DupePrints.pl line 14.
Use of uninitialized value $y in addition (+) at main_DupePrints.pl line 17.
done

См. perlt ie и T ie :: Handle , и этот пост с соответствующими примерами и, возможно, этот пост

Запись в файл потоков STDOUT и STDERR (вместе с копией распечатки) работает и с другими модулями, которые могут быть use d в основной программе.

Чтобы также иметь «чистые» отпечатки, которые не регистрируются, скопируйте дескриптор STDOUT в основной программе. , как это сделано в модуле, и распечатать на это. Если вам нужно использовать это более избирательно и изощренно, пожалуйста, измените его по мере необходимости - так как оно есть, оно должно быть только базовой c демонстрацией.


С уточнением в редактировании вопроса, здесь есть другой подход: заключить вызов в Capture :: Tiny , который захватывает весь вывод из any код, а затем управляйте захваченными отпечатками по мере необходимости

use warnings;
use strict;
use feature qw(say state);

use Capture::Tiny qw(capture);

sub log_streams {
    my ($cr, @args) = @_;  # code reference, with its arguments

    # Initialize "state" variable, so it runs once and stays open over calls
    state $fh_log = do {
        open my $fh, '>', 'tee_log.txt' or die $!;
        $fh;
    };

    my ($out, $err, $exit) = capture { $cr->(@args) };

    if ($out) {
        print $fh_log $out;
        print         $out;
    }
    if ($err) {
        print $fh_log $err;
        print         $err;
    }
}

log_streams( sub { say "hi" } );
log_streams( sub { warn "==> ohno" } );
log_streams( sub { my $y; my $x = $y + 7; } );

log_streams( sub { system('perl', '-wE', q(say "external perl one-liner")) } );

log_streams( sub { say "done" } );

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

Функция состояния используется для «инициализации» дескриптора файла, потому что переменная, объявленная как state, никогда не повторяется инициализируется; поэтому файл открывается только один раз, при первом вызове, и остается открытым.

Это также демонстрационная программа, требующая завершения.

2 голосов
/ 16 февраля 2020

Получив подсказку из ответа @ mob, чтобы использовать IO :: T ie вместо File :: Tee (так как последний использует fork, вызывающий неработоспособность STDERR против STDOUT), я немного изменил исходное решение моба, и оно сработало (почти - читайте дальше):

use IO::Tee
...
...
open (my $log, ">", $logfilename) ;
*MYSTDOUT = *STDOUT ;
*MYSTDERR = *STDERR ;
*STDOUT = IO::Tee->new(\*MYSTDOUT, $log);
*STDERR = IO::Tee->new(\*MYSTDERR, $log);

Это привело к правильному упорядочению как на консоли, так и в лог-файле (оригинальное решение моба, использующее open для дублирования STDOUT / STDERR, не работало - это привело к правильному порядок в журнале, но не в порядке на консоли. Использование псевдонима типа «глоб» вместо dup работает по какой-то странной причине).

Однако, как бы хорошо ни звучало это решение, оно пропустило печать некоторых сообщений из пакета, который я позвоните в лог-файл (хотя они выводятся на консоль). Мой оригинальный код с File :: Tee привел к тому, что те же самые сообщения из пакета были показаны в лог-файле, так что где-то происходит какое-то вуду. Указанный пакет c является файлом .so, поэтому я не вижу, как именно он печатает свои сообщения.

РЕДАКТИРОВАТЬ: я думаю, что .so файл так же хорошо, как печать внешней команды системы в stdout / stderr. Поскольку он не проходит perl IO, дескрипторы, на которые указывают типовые ручки STDOUT / STDERR в perl, не будут отражать вывод внешних программ, вызываемых из perl. Я думаю, что лучшим решением было бы использовать комбинацию этого решения для сообщений, поступающих из кода perl, и использовать Capture :: Tiny :: capture, как указано @zdim, для захвата и перенаправления сообщений от системных вызовов / вызовов Проходя через интерфейс Swig.

...