Sorry, this is a bit long, but this is the evidence on which I based my earlier remarks. If I have misinterpretted the evidence, then I shall be pleased to learn from my mistakes.
Further experiment shows that the effect I observed is associated only with <> input from the console -- following these remarks by BrowserUk.
I added stuff to the code to try to see what the exact sequence of operations was. Here's the code complete with instrumentation:
use strict;
use warnings;
use threads;
use threads::shared ;
use Thread::Queue;
#---------------------------------------------------------------------
+-------------------
# Options
my $YIELD = 0 ; # yield after async
my $CLOSE_STDIN = 0 ; # close STDIN after dispatching Terminal Wat
+cher
my $INPUT_FILE = 0 ; # read from "file" not from STDIN
foreach my $arg (@ARGV) {
if ($arg =~ m/^y/i) { $YIELD = 1 ; }
elsif ($arg =~ m/^c/i) { $CLOSE_STDIN = 1 ; }
elsif ($arg =~ m/^f/i) { $INPUT_FILE = 1 ; }
else { die "don't recognise $arg" ; } ;
} ;
#---------------------------------------------------------------------
+-------------------
# Instrumentation
use IO::Handle ;
use Time::HiRes qw(time) ;
my $START = time() ;
my @trace : shared = () ;
sub trace {
my ($s) = @_ ;
my $when = time() - $START ;
$s =~ s/\n/\\n/g ;
{ lock(@trace) ;
push @trace, sprintf("%12.6f: (%2d) '%s'\n", $when, threads->tid()
+, $s) ;
} ;
} ;
sub stdin_state {
my ($tag) = @_ ;
my $state = "STDIN is: " .(defined(fileno(STDIN)) ? 'open' : 'closed
+'). " $tag" ;
print "$state\n" ;
trace("$state") ;
} ;
my $IN = "fred\n"
."bill\n"
."john\n"
."mary\n"
."quit\n" ;
if ($INPUT_FILE) {
close STDIN ;
open STDIN, "<", \$IN or die "failed to reopen STDIN" ;
} ;
#---------------------------------------------------------------------
+-------------------
# The instrumented code
# Create terminal watcher
print "Create terminal watcher...\n";
my $Q_stdin = Thread::Queue->new;
async {
trace("Terminal Watcher started") ;
while (1) {
trace("Waiting for STDIN") ;
last if !defined($_ = <STDIN>) ;
trace("Input: '$_'") ;
$Q_stdin->enqueue($_) ;
} ;
trace("Terminal Watcher terminating") ;
}->detach;
threads->yield() if $YIELD ;
stdin_state("after Terminal Watcher dispatched") ;
if ($CLOSE_STDIN) {
close STDIN ;
stdin_state("after close") ;
} ;
my $Q_found = Thread::Queue->new;
my $cmd;
print "Awaiting commands...\n";
trace("Entering MAIN_LOOP") ;
MAIN_LOOP: while (not defined $cmd or $cmd !~ /^q/i) {
trace("Top of MAIN_LOOP") ;
sleep(1); # Reduce load
# Process commands
$cmd = $Q_stdin->dequeue_nb;
if (defined $cmd) {
trace("Dequeued '$cmd'") ;
chomp $cmd;
if ($cmd =~ /^q/i) {
trace("'QUIT' command") ;
print "Resolving open threads\n";
}
else {
trace("About to start child thread") ;
async {
trace("Child started") ;
$Q_found->enqueue( $cmd ) ;
trace("Child enqueued '$cmd' & terminating") ;
}->detach;
threads->yield() if $YIELD ;
trace("Dispatched child thread") ;
}
}
else {
trace("Nothing to dequeue") ;
} ;
# Print announcements
while (defined(my $output = $Q_found->dequeue_nb)) {
trace("Output: '$output'") ;
print ">$output\n";
}
}
trace("Left MAIN_LOOP") ;
#---------------------------------------------------------------------
+---------
print STDERR "-- with Yield after async\n" if $YIELD ;
print STDERR "-- with Close STDIN\n" if $CLOSE_STDIN ;
print STDERR "-- with Input from File" if $INPUT_FILE ;
print STDERR sort @trace ;
I tried to disturb the original code as little as possible.
Running this on my uni-processor, Windows XP, Perl 5.10.0, I get:
Z:\>perl threads.pl
Create terminal watcher...
STDIN is: open after Terminal Watcher dispatched
Awaiting commands...
fred
bill
john
>fred
mary
>bill
quit
>john
Resolving open threads
>mary
...so the instrumented code is doing what the original code did.
Looking at the trace, I see:
0.010775: ( 0) 'STDIN is: open after Terminal Watcher dispatched'
0.011655: ( 0) 'Entering MAIN_LOOP'
0.011695: ( 0) 'Top of MAIN_LOOP'
0.011784: ( 1) 'Terminal Watcher started'
0.011820: ( 1) 'Waiting for STDIN'
1.021469: ( 0) 'Nothing to dequeue'
1.021611: ( 0) 'Top of MAIN_LOOP'
2.022909: ( 0) 'Nothing to dequeue'
2.023037: ( 0) 'Top of MAIN_LOOP'
2.703888: ( 1) 'Input: 'fred\n''
2.704107: ( 1) 'Waiting for STDIN'
3.024349: ( 0) 'Dequeued 'fred\n''
3.024471: ( 0) 'About to start child thread' ###
14.330606: ( 0) 'Dispatched child thread'
14.330606: ( 1) 'Input: 'bill\n''
14.330606: ( 2) 'Child started'
14.330741: ( 2) 'Child enqueued 'fred' & terminating'
14.330745: ( 1) 'Waiting for STDIN'
14.330765: ( 0) 'Top of MAIN_LOOP'
15.332046: ( 0) 'Dequeued 'bill\n''
15.332174: ( 0) 'About to start child thread'
17.485142: ( 0) 'Dispatched child thread'
17.485142: ( 1) 'Input: 'john\n''
17.485142: ( 3) 'Child started'
17.485277: ( 0) 'Output: 'fred''
17.485289: ( 3) 'Child enqueued 'bill' & terminating'
17.485527: ( 1) 'Waiting for STDIN'
17.485623: ( 0) 'Top of MAIN_LOOP'
18.486582: ( 0) 'Dequeued 'john\n''
18.486729: ( 0) 'About to start child thread'
19.648253: ( 0) 'Dispatched child thread'
19.648253: ( 1) 'Input: 'mary\n''
19.648253: ( 4) 'Child started'
19.648385: ( 4) 'Child enqueued 'john' & terminating'
19.648389: ( 1) 'Waiting for STDIN'
19.648404: ( 0) 'Output: 'bill''
19.648753: ( 0) 'Top of MAIN_LOOP'
20.649693: ( 0) 'Dequeued 'mary\n''
20.649822: ( 0) 'About to start child thread'
21.400773: ( 0) 'Dispatched child thread'
21.400773: ( 1) 'Input: 'quit\n''
21.400773: ( 5) 'Child started'
21.400902: ( 5) 'Child enqueued 'mary' & terminating'
21.400911: ( 1) 'Waiting for STDIN'
21.400921: ( 0) 'Output: 'john''
21.401273: ( 0) 'Top of MAIN_LOOP'
22.402213: ( 0) 'Dequeued 'quit\n''
22.402345: ( 0) ''QUIT' command'
22.402832: ( 0) 'Output: 'mary''
22.403074: ( 0) 'Left MAIN_LOOP'
The interesting thing is that at time 3.024471 -- marked ###, above -- the main thread is about to async a new child thread, but nothing happens until after the "Terminal Watcher" gets the next input line -- where there's a burst of apparently simultaneous activity.
Now, I don't know how a thread inherits file handles. But whatever the procedure is, it appears to be blocked here until <STDIN> returns the next line. Note that the child thread doesn't go near STDIN or STDOUT. The main thread does output to STDOUT, but isn't blocking there.
I note that when a thread is created, the creator may or may not continue to run -- so the new thread may or may not wait (on my uni-processor). Adding a yield after the async changes the order of events slightly -- but doesn't affect the apparent blocking at thread creation.
As previously advertised, closing STDIN in the main thread, before it creates any child threads, causes the code to run "as expected"
Z:\>perl threads.pl c
Create terminal watcher...
STDIN is: open after Terminal Watcher dispatched
STDIN is: closed after close
Awaiting commands...
fred
>fred
bill
>bill
john
>john
mary
>mary
quit
Resolving open threads
and the trace is:
-- with Close STDIN
0.009832: ( 1) 'Terminal Watcher started'
0.009940: ( 1) 'Waiting for STDIN'
0.010435: ( 0) 'STDIN is: open after Terminal Watcher dispatched'
0.010642: ( 0) 'STDIN is: closed after close'
0.010927: ( 0) 'Entering MAIN_LOOP'
0.010955: ( 0) 'Top of MAIN_LOOP'
1.021469: ( 0) 'Nothing to dequeue'
1.021572: ( 0) 'Top of MAIN_LOOP'
2.022909: ( 0) 'Nothing to dequeue'
2.023017: ( 0) 'Top of MAIN_LOOP'
2.894161: ( 1) 'Input: 'fred\n''
2.894298: ( 1) 'Waiting for STDIN'
3.024349: ( 0) 'Dequeued 'fred\n''
3.024478: ( 0) 'About to start child thread'
3.047132: ( 2) 'Child started'
3.047330: ( 2) 'Child enqueued 'fred' & terminating'
3.076179: ( 0) 'Dispatched child thread'
3.076338: ( 0) 'Output: 'fred''
3.076676: ( 0) 'Top of MAIN_LOOP'
4.085875: ( 0) 'Nothing to dequeue'
4.086001: ( 0) 'Top of MAIN_LOOP'
5.087315: ( 0) 'Nothing to dequeue'
5.087388: ( 0) 'Top of MAIN_LOOP'
5.588035: ( 1) 'Input: 'bill\n''
5.588254: ( 1) 'Waiting for STDIN'
6.088755: ( 0) 'Dequeued 'bill\n''
6.088877: ( 0) 'About to start child thread'
6.116493: ( 0) 'Dispatched child thread'
6.116650: ( 0) 'Top of MAIN_LOOP'
6.117257: ( 3) 'Child started'
6.117413: ( 3) 'Child enqueued 'bill' & terminating'
7.110224: ( 0) 'Nothing to dequeue'
7.110354: ( 0) 'Output: 'bill''
7.110874: ( 0) 'Top of MAIN_LOOP'
8.111664: ( 0) 'Nothing to dequeue'
8.111787: ( 0) 'Top of MAIN_LOOP'
8.812672: ( 1) 'Input: 'john\n''
8.812890: ( 1) 'Waiting for STDIN'
9.113104: ( 0) 'Dequeued 'john\n''
9.113239: ( 0) 'About to start child thread'
9.134352: ( 0) 'Dispatched child thread'
9.134506: ( 0) 'Top of MAIN_LOOP'
9.135166: ( 4) 'Child started'
9.135317: ( 4) 'Child enqueued 'john' & terminating'
10.134573: ( 0) 'Nothing to dequeue'
10.134705: ( 0) 'Output: 'john''
10.135039: ( 0) 'Top of MAIN_LOOP'
11.136013: ( 0) 'Nothing to dequeue'
11.136139: ( 0) 'Top of MAIN_LOOP'
11.666776: ( 1) 'Input: 'mary\n''
11.666993: ( 1) 'Waiting for STDIN'
12.137453: ( 0) 'Dequeued 'mary\n''
12.137575: ( 0) 'About to start child thread'
12.159439: ( 0) 'Dispatched child thread'
12.159594: ( 0) 'Top of MAIN_LOOP'
12.159905: ( 5) 'Child started'
12.160045: ( 5) 'Child enqueued 'mary' & terminating'
13.158921: ( 0) 'Nothing to dequeue'
13.159051: ( 0) 'Output: 'mary''
13.159388: ( 0) 'Top of MAIN_LOOP'
14.160361: ( 0) 'Nothing to dequeue'
14.160494: ( 0) 'Top of MAIN_LOOP'
14.210433: ( 1) 'Input: 'quit\n''
14.210596: ( 1) 'Waiting for STDIN'
15.161801: ( 0) 'Dequeued 'quit\n''
15.161932: ( 0) ''QUIT' command'
15.162408: ( 0) 'Left MAIN_LOOP'
which clearly shows that the starting of the child thread is no longer delayed by the <STDIN>.
The OP reported that the close STDIN did not do the trick on a multi-processor. But it did with the addition of a semaphore that ensured that the main thread STDIN was closed before the Terminal Watcher reached the first <STDIN>.
I tried to simulate this on my uni-processor by yielding immediately after the creation of the Terminal Watcher. This doesn't cause it to fail -- I thought perhaps the file handle could not be closed once the <STDIN> was running... but that does not seem to be the case.
So this remains a puzzle. Which may be related to a misunderstanding of what's going on here. I look forward to enlightenment. |