在Linux上通過SSH運行多線程Perl腳本的問題

如果我通過SSH遠程運行它，我無法理解以下簡單Perl腳本的行爲。在Linux上通過SSH運行多線程Perl腳本的問題

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"; 

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

當我在我的Linux系統中使用Perl-5.10.0正常運行它，我得到預期的結果：

 
$ 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運行它（在同一本地主機上，但它無所謂）我得到非常奇怪的結果（在時間戳仔細觀察和線程的ID）：

 
$ 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腳本，我注意到，我開始與我看到的問題/ O在創建第一個線程之後。

我能夠在Windows上重現最新的Perl-5.12問題，所以我不認爲這個問題是Perl/OS特有的。

有人能解釋這裏有什麼問題嗎？

來源

2011-05-03 Dmitry Krivenok

我能夠自己重現這一點。但是，當通過ssh從shell運行它時，我得到了預期的行爲。那有什麼區別？僞終端！

試試這個：

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

來源

2011-05-03 12:41:47

嗯..看起來像線路緩衝模式在這種情況下啓用。如果你刪除所有的「\ n」，即使用「ssh -t」運行，你也會看到相同的行爲。 – 2011-05-03 13:08:05

我最初的想法是一個緩衝問題，我正要建議添加\ n，但我再次查看，他們已經在那裏。我想你可以嘗試關閉IO緩衝，但它默認情況下是有原因的... – 2011-05-03 13:13:47

我不認爲它與緩衝模式有關。無論使用何種緩衝模式，輸出中的時間都必須單調增加（但不會）。緩衝模式可能只會影響寫入系統調用的時間和次數。我對嗎？ – 2011-05-03 13:25:49

事實上，它看起來像Perl的每個線程都有它自己的輸出緩衝區。我重定向輸出到文件（同通過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 
$

可以清楚地看到每個線程的地方全部數據寫入線程本地緩衝區，然後（在本例中就在線程終止之前）調用該緩衝區上的「寫入」系統調用。恕我直言，線程本地輸出緩衝區是非常想法因爲即使他們顯式序列化「打印」調用，人們也會得到令人困惑的結果。

我發現的解決方案是使用顯式序列化並在STDOUT上啓用自動刷新，以便線程局部緩衝區始終爲空。

來源

2011-05-04 08:33:20

在Linux上通過SSH運行多線程Perl腳本的問題

回答

相關問題