Beefy Boxes and Bandwidth Generously Provided by pair Networks
Welcome to the Monastery
 
PerlMonks  

chargen program is too slow / IO::Select socket handle outputting timing issue

by kabeldag (Hermit)
on Jul 11, 2006 at 09:45 UTC ( [id://560377]=perlquestion: print w/replies, xml ) Need Help??

kabeldag has asked for the wisdom of the Perl Monks concerning the following question:

use strict; use warnings; use IO::Select; use IO::Socket; $|=1; $SIG{INT}=\&exit_genchars; my $time_zone_inc=10; my %sock_client_hash; my $cc=48; my $server_sock = new IO::Socket::INET( Listen => 1,LocalPort => 19,Reuse=> 1 ); my $sel = new IO::Select( $server_sock ); my @ready; while($server_sock) { @ready = $sel->can_read(0.0001); foreach my $socket (@ready) { if($socket == $server_sock ) { new_socket($socket); }else{ if(defined ($socket)) { close_socket($socket); } } } my @wready = $sel->can_write(0.0001); my $wsocket; foreach $wsocket (@wready) { gen_chars($wsocket); } } sub new_socket { my $newclientsock=shift; $newclientsock = $server_sock ->accept; $sel->add($newclientsock); my ($ip,$peer_port)=sock_attrs($newclientsock); $sock_client_hash{$newclientsock->fileno}{ip}=$ip; $sock_client_hash{$newclientsock->fileno}{port}=$peer_port; my $fileNo=$newclientsock->fileno; log_event("New Client connected -> FileNo($fileNo) $ip:$peer_port\ +n"); } sub gen_chars { my($wrs) = $_[0]; if($cc==58) { $cc=65; }elsif($cc==91) { $cc=97; }elsif($cc==123) { $cc=48; } $wrs->send(chr($cc)) or close_socket($wrs); $cc++; } sub close_socket { my $socket=$_[0]; my $sock_ip=$sock_client_hash{$socket->fileno}{ip}; my $sock_peer_port=$sock_client_hash{$socket->fileno}{port}; my $fileNo=$socket->fileno; log_event("Unable to write to -> FileNo($fileNo) $sock_ip:$sock_pe +er_port\n"); if(defined ($socket)) { $sel->remove($socket); $socket->close; log_event("Removed socket -> FileNo($fileNo) $sock_ip:$sock_pe +er_port\n"); } } sub sock_attrs { my $socket=$_[0]; my $ip=$socket->peerhost; my $port=$socket->peerport; return $ip,$port; } sub log_event { my $msg=shift; my $gmTime=rTime(); print "$gmTime -> $msg"; } sub rTime { my ($sec,$min,$hour,$mday,$mon,$year,$wday,$yday) = gmtime(time); my $militaryTime=($hour)+$time_zone_inc; my $m; my $s; if($militaryTime>24) { $militaryTime=$militaryTime-24; } $militaryTime=$hour; if(length($min)==1) { $m="0".$min; $min=$m; } if(length($sec)==1) { $s="0".$sec; $sec=$s; } my $roundedTime="$militaryTime:$min:$sec"; return $roundedTime; } sub exit_genchars { log_event("Exit called\n"); exit(0); }

The processing/controlling of incoming sockets whilst also outputting to connected sockets needs to be handled better.
But with my while loop, with one client connected, it is still far too slow. I want to avoid spawning a new process at any cost.
  • Comment on chargen program is too slow / IO::Select socket handle outputting timing issue
  • Download Code

Replies are listed 'Best First'.
Re: chargen program is too slow / IO::Select socket handle outputting timing issue
by liverpole (Monsignor) on Jul 11, 2006 at 15:05 UTC
    Hi kabeldag,

    As per our conversation, I gave your program a try on Windows and Linux both.  For me, the program ran a lot faster under Linux.  I had to change the port from "19" to "77777", since the reserved port 19 wasn't working for me; I don't know if that has any effect on the outcome.

    First of all, here's a suggestion I have:  instrument the program so you can see what the transfer rate is.  I added the following code to your program so I could see exactly what the rate was:

    # Global variables (added $total_chars and $start_time) my $time_zone_inc=10; my $total_chars = 0; my $start_time; my %sock_client_hash; my $cc=48; # Subroutines (added start_timer() and stop_timer()) sub start_timer() { $start_time = time; $total_chars = 0; } sub stop_timer() { my $stop_time = time; my $nsecs = $stop_time - $start_time; my $cps = sprintf "%.4f", $total_chars / $nsecs; log_event("$total_chars chars / $nsecs seconds = $cps chars / sec\ +n"); } # Added call to start_timer() sub new_socket { my $newclientsock=shift; $newclientsock = $server_sock ->accept; $sel->add($newclientsock); my ($ip,$peer_port)=sock_attrs($newclientsock); $sock_client_hash{$newclientsock->fileno}{ip}=$ip; $sock_client_hash{$newclientsock->fileno}{port}=$peer_port; my $fileNo=$newclientsock->fileno; log_event("New Client connected -> FileNo($fileNo) $ip:$peer_port\ +n"); start_timer(); } # Added increment of $total_chars sub gen_chars { my($wrs) = $_[0]; if($cc==58) { $cc=65; }elsif($cc==91) { $cc=97; }elsif($cc==123) { $cc=48; } $wrs->send(chr($cc)) or close_socket($wrs); $cc++; ++$total_chars; } # Added call to stop_timer() sub close_socket { my $socket=$_[0]; my $sock_ip=$sock_client_hash{$socket->fileno}{ip}; my $sock_peer_port=$sock_client_hash{$socket->fileno}{port}; my $fileNo=$socket->fileno; log_event("Unable to write to -> FileNo($fileNo) $sock_ip:$sock_pe +er_port\n"); if(defined ($socket)) { $sel->remove($socket); $socket->close; log_event("Removed socket -> FileNo($fileNo) $sock_ip:$sock_pe +er_port\n"); stop_timer(); } }
    Now I get the following results in Linux and Windows respectively.  (Note that I'm on a laptop, so I used 'localhost' from Linux for all connections, but used my IP address 192.168.2.2 for the first 2 of the 3 Windows connections):
    === Linux === [root@localhost ~]% sock.pl 14:03:28 -> New Client connected -> FileNo(4) 127.0.0.1:44999 14:03:35 -> Unable to write to -> FileNo(4) 127.0.0.1:44999 14:03:35 -> Removed socket -> FileNo(4) 127.0.0.1:44999 14:03:35 -> 6614 chars / 7 seconds = 944.8571 chars / sec 14:03:45 -> Exit called [root@localhost ~]% [root@localhost ~]% sock.pl 14:03:46 -> New Client connected -> FileNo(4) 127.0.0.1:45000 14:04:06 -> Unable to write to -> FileNo(4) 127.0.0.1:45000 14:04:06 -> Removed socket -> FileNo(4) 127.0.0.1:45000 14:04:06 -> 17046 chars / 20 seconds = 852.3000 chars / sec 14:04:13 -> New Client connected -> FileNo(4) 127.0.0.1:45001 14:04:44 -> Unable to write to -> FileNo(4) 127.0.0.1:45001 14:04:44 -> Removed socket -> FileNo(4) 127.0.0.1:45001 14:04:44 -> 26861 chars / 31 seconds = 866.4839 chars / sec 14:04:59 -> Exit called === Windows === C:\Documents and Settings\liverpole\Desktop>sock 14:49:04 -> New Client connected -> FileNo(4) 192.168.2.2:1204 14:49:12 -> Unable to write to -> FileNo(4) 192.168.2.2:1204 14:49:12 -> Removed socket -> FileNo(4) 192.168.2.2:1204 14:49:12 -> 774 chars / 8 seconds = 96.7500 chars / sec 14:49:16 -> New Client connected -> FileNo(4) 192.168.2.2:1205 14:49:39 -> Unable to write to -> FileNo(4) 192.168.2.2:1205 14:49:39 -> Removed socket -> FileNo(4) 192.168.2.2:1205 14:49:39 -> 2374 chars / 23 seconds = 103.2174 chars / sec 14:49:52 -> New Client connected -> FileNo(4) 127.0.0.1:1209 14:50:12 -> Unable to write to -> FileNo(4) 127.0.0.1:1209 14:50:12 -> Removed socket -> FileNo(4) 127.0.0.1:1209 14:50:12 -> 2024 chars / 20 seconds = 101.2000 chars / sec 14:50:35 -> Exit called

    So, how do those speeds compare with what you are seeing?


    s''(q.S:$/9=(T1';s;(..)(..);$..=substr+crypt($1,$2),2,3;eg;print$..$/
Re: chargen program is too slow / IO::Select socket handle outputting timing issue
by Jenda (Abbot) on Jul 11, 2006 at 15:24 UTC

    The problem is in the @ready = $sel->can_read(0.0001); The thing is that this returns a socket only whenever there is a new socket or whenever a socket is closed. Otherwise it waits those 0.0001 seconds. Which may seem small but for 10*1024 (that's how many characters my test script tried to read) this means 1.024s wasted. And is it really necessary to check for new sockets 10000 times a second?;-)

    This script

    use strict; use warnings; use IO::Socket; use Time::HiRes qw(gettimeofday tv_interval); my $sock = IO::Socket::INET->new(PeerAddr => 'localhost', PeerPort => '19', Proto => 'tcp'); my $start_time = [gettimeofday]; my $buff; for (1..10) { read $sock, $buff, 1024; } print "Taken " . tv_interval($start_time) . "seconds\n"; $sock->close();
    took approximately 10s to read those 10*1024 characters with your code, no matter if I ran just one or eight of them. With this change:
    use constant NEW_SOCK_EVERY => 1000; ... my $server_sock = new IO::Socket::INET( Listen => 1,LocalPort => 19,Reuse=> 1 ); my $sel = new IO::Select( $server_sock ); my $i = NEW_SOCK_EVERY; while($server_sock) { if (++$i>=NEW_SOCK_EVERY) { $i=0; foreach my $socket ($sel->can_read(0.0001)) { if($socket == $server_sock ) { new_socket($socket); }else{ if(defined ($socket)) { close_socket($socket); } } } } foreach my $wsocket ($sel->can_write(0.0001)) { gen_chars($wsocket); } } ...
    the time went down to about 2s. I think it's enough to test for new clients 10 times a second, don't you? ;-)

    Another option that seems to work (though I can't find it mentioned in the IO::Select's docs) is to specify a negative timeout for the can_read(). That seems to bring the time down to 1.1-1.3 seconds. And it's a much smaller change to your code :-)

Re: chargen program is too slow / IO::Select socket handle outputting timing issue (using IO::Select)
by tye (Sage) on Jul 11, 2006 at 16:49 UTC

    Gah, IO::Select's design sure encourages people to use it badly for cases where they are doing more than just reading or just writing. You've fallen victim to this design. It could really use another layer. I should write a patch... but not at the momement.

    The "proper" way to use IO::Select for a case like this, is more like:

    while( 1 ) { my( $readers, $writers )= IO::Select->select( $sel, $sel, unde +f ); foreach my $socket ( @$readers ) { if( $socket == $server_sock ) { new_socket( $socket ); } elsif( defined($socket) ) { close_socket($socket); } } foreach my $socket ( @$writers ) { gen_chars( $socket ); } }

    Which will be fast and not wasteful of CPU, which are major points of select (rather than just preventing blocking).

    - tye        

Re: chargen program is too slow / IO::Select socket handle outputting timing issue
by Jeppe (Monk) on Jul 11, 2006 at 12:23 UTC
    When I run into performance trouble, I do like this:
    use Time::HiRes; my $ENABLE_PROFILING = 1; my $exit_genchars_time = 0; ... sub exit_genchars { my $temp_time = Time::HiRes::time() if $ENABLE_PROFILING; log_event("Exit called\n"); $exit_genchars_time += Time::HiRes::time() - $temp_time if $ENABLE_PROFILING; exit(0); } ... sub END { if ($ENABLE_PROFILING) { print "Spent " . sprintf("%.2f") . " seconds inside exit_genchars\n"; ... ... } }
    etc. It ain't very pretty. It's low-tech, not very expensive, fairly easy to remove afterwards, and most of all in my domain: Thread-safe.
Re: chargen program is too slow / IO::Select socket handle outputting timing issue
by ikegami (Patriarch) on Jul 11, 2006 at 16:30 UTC
    This is not an answer to your question, but an improvement for your code. You are polling using select, while select's purpose is to eliminate polling. Replace the two calls to select (can_read and can_write) with a single call by replacing
    @ready = $sel->can_read(0.0001); foreach my $socket (@ready) { ... } my @wready = $sel->can_write(0.0001); my $wsocket; foreach $wsocket (@wready) { ... }
    with
    my ($rready, $wready) = IO::Select->select($sel, $sel); foreach my $rsocket (@$rready) { ... } foreach my $wsocket (@$wready) { ... }

      I think part of the problem is the slightly awkward syntax of the IO::Select->select($sel, $sel); and the fact that there is no example of this call in IO::Select's docs.

      I think it would make a lot of sense to have a method like this:

      my ($rready, $wready) = $sel->can([TIMEOUT]);
      or maybe even better
      my ($rready, $wready) = $sel->select([TIMEOUT]);
      Looking at the code in IO::Select.pm it seems to me the only change necessary would be on lines 181-184:
      - shift - if defined $_[0] && !ref($_[0]); - - my($r,$w,$e,$t) = @_; + my($r,$w,$e,$t); + if (defined $_[0] && !ref($_[0])) { # called as a static method + shift; + ($r,$w,$e,$t) = @_; + } elsif (@_ == 1 || @_ == 2 && !ref($_[1])) { # called as $sel->sele +ct() or $sel->select($timeout) + $r=$w=$e=$_[0]; + $t=$_[1]; + } else { # called as IO::Select::select(...) + ($r,$w,$e,$t) = @_; + }
      the question is whether anyone would notice that $sel->select() not longer means IO::Select->select($sel) but rather IO::Select->select($sel,$sel,$sel)

        The first two arguments of IO::Select->select are rarely the same, so I'm not sure that's a useful patch. In fact, the first two arguments should be different in your code. (Why are you waiting to write to the listen socket?) It should look more like:

        my $rsel = IO::Select->new(); my $wsel = IO::Select->new(); ... for (;;) { my ($rready, $wready) = IO::Select->select($rsel, $wsel); foreach my $rsocket (@$rready) { ... } foreach my $wsocket (@$wready) { ... } }
Re: chargen program is too slow / IO::Select socket handle outputting timing issue
by bart (Canon) on Jul 11, 2006 at 10:00 UTC
    This looks wrong:
    my @wready = $sel->can_write(0.0001); my $wsocket; foreach $wsocket (@ready) { gen_chars($wsocket); }
    Replace @ready with @wready, perhaps?
Re: chargen program is too slow / IO::Select socket handle outputting timing issue
by jdtoronto (Prior) on Jul 11, 2006 at 13:06 UTC
    It might also help if you would explain what you are trying to do, give some bench marking results and tell us what you have already tried.

    jdtoronto

Re: chargen program is too slow / IO::Select socket handle outputting timing issue
by kabeldag (Hermit) on Jul 12, 2006 at 13:27 UTC
    Interesting. Thanks for the replies there everyone.

    Ok. So I now have added Jeppe / liverpole's transferr rate stuff and modified it to be socket specific (ie; within the hash).
    I have also changed up the handling process using my ($readable,$writable) = IO::Select->select($sel,$sel);
    as mentioned as a possibility by previous monks ikegami and tye.

    I have also added a priority control flow if statement case to chose what socket to handle based on what select has to offer.

    Here is my new updated code :
    use strict; use warnings; use IO::Select; use IO::Socket; $|=1; $SIG{INT}=\&exit_genchars; my $time_zone_inc=10; my %sock_client_hash; my $cc=48; my $lsn = new IO::Socket::INET(Listen => 1,LocalPort => 19,Reuse=> + 1); my $sel = new IO::Select( $lsn ); my $rready; my $wready; while(1) { my @priority_array; ($rready,$wready) = IO::Select->select($sel, $sel, undef); if(@$rready&&!@$wready) { # Let's process the read ready socket array. As there are +no writables yet @priority_array=@$rready; }elsif(@$rready&&@$wready) { # Let's process the read ready socket array before the wri +te array # as a new socket/client has arrived @priority_array=@$rready; }else{ # Let's process the write ready socket array this time. As + no readables are ready @priority_array=@$wready; } foreach my $socket (@priority_array) { if($socket == $lsn) { new_socket($socket); }else{ # Let's actually generate those chars to the client/so +cket # that is write ready gen_chars($socket); } } } sub start_timer { my $socket = $_[0]; $sock_client_hash{$socket->fileno}{send_start_time}=time; $sock_client_hash{$socket->fileno}{bytes_recvd}=0; } sub stop_timer { my $socket = $_[0]; my $stop_time = time; my $start_time = $sock_client_hash{$socket->fileno}{send_start_tim +e}; my $elapsed_seconds = $stop_time - $start_time; my $bytes_recvd = $sock_client_hash{$socket->fileno}{bytes_recvd}; my $bps = sprintf "%.4f", $bytes_recvd / $elapsed_seconds; my ($ip,$port) = sock_attrs($socket); log_event("Transfer rate to $ip:$port was $bps bytes/second\n----- +-----> Seconds elapsed: $elapsed_seconds\n"); } sub new_socket { my $newclientsock=shift; $newclientsock = $lsn->accept; $sel->add($newclientsock); my ($ip,$peer_port)=sock_attrs($newclientsock); $sock_client_hash{$newclientsock->fileno}{ip}=$ip; $sock_client_hash{$newclientsock->fileno}{port}=$peer_port; my $fileNo=$newclientsock->fileno; log_event("New Client connected -> FileNo($fileNo) $ip:$peer_port\ +n"); start_timer($newclientsock); } sub gen_chars { my $wrs = $_[0]; if($cc==58) { $cc=65; }elsif($cc==91) { $cc=97; }elsif($cc==123) { $cc=48; } $wrs->send(chr($cc)) or close_socket($wrs); $cc++; $sock_client_hash{$wrs->fileno}{bytes_recvd}++; } sub close_socket { my $socket=$_[0]; my $sock_ip=$sock_client_hash{$socket->fileno}{ip}; my $sock_peer_port=$sock_client_hash{$socket->fileno}{port}; my $fileNo=$socket->fileno; log_event("Unable to write to -> FileNo($fileNo) $sock_ip:$sock_pe +er_port\n"); if(defined ($socket)) { stop_timer($socket); $sel->remove($socket); $socket->close; log_event("Removed socket -> FileNo($fileNo) $sock_ip:$sock_pe +er_port\n"); } } sub sock_attrs { my $socket=$_[0]; my $ip=$socket->peerhost; my $port=$socket->peerport; return $ip,$port; } sub log_event { my $msg=shift; my $gmTime=rTime(); print "$gmTime -> $msg"; } sub rTime { my ($sec,$min,$hour,$mday,$mon,$year,$wday,$yday) = gmtime(time); my $militaryTime=($hour)+$time_zone_inc; my $m; my $s; if($militaryTime>24) { $militaryTime=$militaryTime-24; } $militaryTime=$hour; if(length($min)==1) { $m="0".$min; $min=$m; } if(length($sec)==1) { $s="0".$sec; $sec=$s; } my $roundedTime="$militaryTime:$min:$sec"; return $roundedTime; } sub exit_genchars { log_event("Exit called\n"); exit(0); }
    Now I get an un-initialized error on this part in the actual gen_chars() sub : $sock_client_hash{$wrs->fileno}{bytes_recvd}++;

    Here are the results from a windblows machine. Decent for char by char gen when handling multiple clients :->

    C:\Perl\bin>perl chargen.pl 13:08:07 -> New Client connected -> FileNo(4) 127.0.0.1:1133 13:08:17 -> New Client connected -> FileNo(5) 127.0.0.1:1134 13:08:21 -> Unable to write to -> FileNo(5) 127.0.0.1:1134 13:08:21 -> Transfer rate to 127.0.0.1:1134 was 8686.7500 bytes/second ----------> Seconds elapsed: 4 13:08:21 -> Removed socket -> FileNo(5) 127.0.0.1:1134 Use of uninitialized value in hash element at chargen.pl line 87. Use of uninitialized value in hash element at chargen.pl line 87. 13:08:26 -> Unable to write to -> FileNo(4) 127.0.0.1:1133 13:08:26 -> Transfer rate to 127.0.0.1:1133 was 11280.1579 bytes/secon +d ----------> Seconds elapsed: 19 13:08:26 -> Removed socket -> FileNo(4) 127.0.0.1:1133 Use of uninitialized value in hash element at chargen.pl line 87. 13:08:29 -> Exit called C:\Perl\bin>perl chargen.pl 13:10:56 -> New Client connected -> FileNo(4) 127.0.0.1:1135 13:11:03 -> New Client connected -> FileNo(5) 127.0.0.1:1136 13:11:09 -> New Client connected -> FileNo(6) 127.0.0.1:1137 13:11:16 -> Unable to write to -> FileNo(5) 127.0.0.1:1136 13:11:16 -> Transfer rate to 127.0.0.1:1136 was 6994.7692 bytes/second ----------> Seconds elapsed: 13 13:11:16 -> Removed socket -> FileNo(5) 127.0.0.1:1136 Use of uninitialized value in hash element at chargen.pl line 82. Use of uninitialized value in hash element at chargen.pl line 82. 13:11:18 -> Unable to write to -> FileNo(4) 127.0.0.1:1135 13:11:18 -> Transfer rate to 127.0.0.1:1135 was 5619.4545 bytes/second ----------> Seconds elapsed: 22 13:11:18 -> Removed socket -> FileNo(4) 127.0.0.1:1135 Use of uninitialized value in hash element at chargen.pl line 82. 13:11:19 -> Unable to write to -> FileNo(6) 127.0.0.1:1137 13:11:19 -> Transfer rate to 127.0.0.1:1137 was 10929.8000 bytes/secon +d ----------> Seconds elapsed: 10 13:11:19 -> Removed socket -> FileNo(6) 127.0.0.1:1137 Use of uninitialized value in hash element at chargen.pl line 82. 13:11:22 -> Exit called

      I'm not sure what you are trying to accomplish with this extra complexity. Just process the ready-to-read-from sockets first if there are any, then process the ready-to-write-to sockets if there are any.

      Now I get an un-initialized error on this part in the actual gen_chars() sub : $sock_client_hash{$wrs->fileno}{bytes_recvd}++;
      $wrs->send­(chr($cc)) or close_sock­et($wrs); $cc++; $sock_clie­nt_hash{$w­rs->fileno­}{bytes_re­cvd}++;

      If you close the socket, then fileno() will return undef. What did you expect?

      - tye        

Re: chargen program is too slow / IO::Select socket handle outputting timing issue
by kabeldag (Hermit) on Jul 12, 2006 at 21:47 UTC
    lol. That's quite true.

    Yes well I was tired. I also have to fix the rTime(), but that's not an issue (even though nobody pointed it out yet ; strangely).

    My new code doesn't make things more complex, seems logical to me at least.

    while(1) { my @priority_array; ($rready,$wready) = IO::Select->select($sel, $sel, undef); if(@$rready&&!@$wready) { # Let's process the read ready socket array. # As there are no writables yet @priority_array=@$rready; }elsif(@$rready&&@$wready) { # Let's process the read ready socket # # array before the write array # as a new socket/client has arrived @priority_array=@$rready; }else{ # Let's process the write ready socket array # this time. As no readables are ready @priority_array=@$wready; } foreach my $socket (@priority_array) { if($socket == $lsn) { new_socket($socket); }else{ # Let's actually generate those chars to # the client/socket # that is write ready gen_chars($socket); } } }
    You see, I have decided that I would like to process a socket array of priority, instead of checking any read-ready socket array,
    then immediately after that, check/process any write-ready socket array's no matter what the situation at that given time, IE:
    while(1) { ($rready,$wready) = IO::Select->select($sel, $sel, undef); foreach my $rsocket (@$rready) { if($rsocket == $lsn) { new_socket($rsocket); }else{ # whatever } } foreach my $wsocket (@$wready) { gen_chars($wsocket); } }
    With the above. The else block within the @$ready processing loop seems to only get executed
    after the 'TCP Handshake' occurs AND the client actually sends data.

A reply falls below the community's threshold of quality. You may see it by logging in.
A reply falls below the community's threshold of quality. You may see it by logging in.

Log In?
Username:
Password:

What's my password?
Create A New User
Domain Nodelet?
Node Status?
node history
Node Type: perlquestion [id://560377]
Approved by BrowserUk
Front-paged by grinder
help
Chatterbox?
and the web crawler heard nothing...

How do I use this?Last hourOther CB clients
Other Users?
Others sharing their wisdom with the Monastery: (1)
As of 2024-04-24 16:04 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?

    No recent polls found