Linux에서 SSH를 통해 실행되는 멀티 스레드 Perl 스크립트의 문제점

Question

SSH를 통해 원격으로 실행하는 경우 다음의 간단한 Perl 스크립트의 동작을 이해할 수 없습니다. 나는 펄 5.10.0 내 리눅스 박스에 일반적으로 그것을 실행하면

use strict; 
use warnings; 
use threads; 
use threads::shared; 
use POSIX; 

my $print_mutex : shared; 

################################################################################ 

sub _print($) 
{ 
    my $str = shift; 
    lock($print_mutex); 
    my $id = threads->tid(); 
    my $time = strftime('%H:%M:%S', localtime time); 
    print "$time [$id] $str"; 
    return; 
} 

################################################################################ 

sub run() 
{ 
    for my $i (1 .. 3) 
     { 
     _print("Begin $i\n"); 
     sleep 1; 
     _print("End $i\n"); 
     } 
    return threads->tid(); 
} 

################################################################################ 

_print "Starting test.\n"; 
my @threads; 
for my $thr_num (1 .. 2) 
    { 
    my $thr = threads->create('run'); 
    push @threads, $thr; 
    _print "Thread created.\n"; 
    } 
foreach (@threads) 
    { 
    my $id = $_->join; 
    _print "Thread '$id' finished.\n"; 
    } 
_print "Test finished.\n"; 

################################################################################ 

내가 예상 결과를 얻을 : 나는 같은 로컬 호스트에 (SSH를 통해 실행 그러나

 
$ perl /tmp/a.pl 
14:25:54 [0] Starting test. 
14:25:54 [0] Thread created. 
14:25:54 [1] Begin 1 
14:25:54 [0] Thread created. 
14:25:54 [2] Begin 1 
14:25:55 [1] End 1 
14:25:55 [1] Begin 2 
14:25:55 [2] End 1 
14:25:55 [2] Begin 2 
14:25:56 [1] End 2 
14:25:56 [1] Begin 3 
14:25:56 [2] End 2 
14:25:56 [2] Begin 3 
14:25:57 [1] End 3 
14:25:57 [0] Thread '1' finished. 
14:25:57 [2] End 3 
14:25:57 [0] Thread '2' finished. 
14:25:57 [0] Test finished. 
$ 

을, 그러나 그것을

 
$ ssh localhost 'perl /tmp/a.pl' 
14:26:11 [0] Starting test. 
14:26:11 [0] Thread created. 
14:26:11 [1] Begin 1 
14:26:12 [1] End 1 
14:26:12 [1] Begin 2 
14:26:13 [1] End 2 
14:26:13 [1] Begin 3 
14:26:14 [1] End 3 
14:26:11 [2] Begin 1 
14:26:12 [2] End 1 
14:26:12 [2] Begin 2 
14:26:13 [2] End 2 
14:26:13 [2] Begin 3 
14:26:14 [2] End 3 
14:26:11 [0] Thread created. 
14:26:14 [0] Thread '1' finished. 
14:26:14 [0] Thread '2' finished. 
14:26:14 [0] Test finished. 
$ 

을 내가 단일 스레드 Perl 스크립트에서 이것을 본 적이과 내가 함께 문제를보기 시작하는 것이 내가 /주의 : 나는 아주 이상한 결과가() ID를 타임 스탬프 자세히 보면 및 스레드 수) 중요하지 않습니다 O 첫 번째 스레드가 생성 된 직후.

Windows에서 최신 Perl-5.12의 문제를 재현 할 수 있었으므로 문제가 Perl/OS에만 해당한다고 생각하지 않습니다.

누군가 여기서 잘못된 점을 설명해 주시겠습니까?

Answer 1

나는 이것을 스스로 재현 할 수있었습니다. 그러나 ssh를 통해 쉘에서 실행할 때 예상되는 동작을 얻었습니다. 차이점은 무엇입니까? 가짜 터미널!

이 시도 : 각 펄 스레드가 자신의 출력 버퍼의이 같은

ssh -t localhost 'perl /tmp/a.pl' 

Answer 2

사실, 그것은 보인다. 나는 파일 (그냥 라인 버퍼링을 비활성화하기 때문에 SSH를 통해 스크립트를 실행하는 것과 동일)에 출력을 리디렉션 및 strace를 아래 스크립트를 실행했습니다

 
$ strace -fF -tt -s200 bash -c "perl /tmp/a.pl > OUT" 2>&1 | grep write 
[pid 359] 12:12:24.674142 write(1, "12:12:24 [0] Starting test.\n"..., 28) = 28 
[pid 359] 12:12:24.687319 write(1, "12:12:24 [0] Thread created.\n"..., 29) = 29 
[pid 360] 12:12:27.693225 write(1, "12:12:24 [1] Begin 1\n12:12:25 [1] End 1\n12:12:25 [1] Begin 2\n12:12:26 [1] End 2\n12:12:26 [1] Begin 3\n12:12:27 [1] End 3\n"..., 120) = 120 
[pid 361] 12:12:27.706137 write(1, "12:12:24 [2] Begin 1\n12:12:25 [2] End 1\n12:12:25 [2] Begin 2\n12:12:26 [2] End 2\n12:12:26 [2] Begin 3\n12:12:27 [2] End 3\n"..., 120) = 120 
[pid 359] 12:12:27.711343 write(1, "12:12:24 [0] Thread created.\n12:12:27 [0] Thread '1' finished.\n12:12:27 [0] Thread '2' finished.\n12:12:27 [0] Test finished.\n"..., 125) = 125 
$ 

그것은 분명해진다 각 스레드 장소 모든 데이터를 쓰레드 로컬 버퍼에 넣고 그 다음에 만 (이 예에서는 스레드 종료 직전에) 해당 버퍼에서 "쓰기"시스템 호출을 호출합니다. IMHO, 스레드 로컬 출력 버퍼는 매우입니다. 왜냐하면 사람들은 "print"호출을 명시 적으로 직렬화하더라도 사람들이 혼란스러운 결과를 낳기 때문입니다.

내가 발견 한 솔루션은 명시 적 직렬화를 사용하고 스레드 로컬 버퍼가 항상 비어 있도록 STDOUT에서 autoflush를 활성화하는 것입니다.