add timing stats to cmd spawn_cmd

[spider.git] / perl / DXCommandmode.pm

diff --git a/perl/DXCommandmode.pm b/perl/DXCommandmode.pm
index 403dd134072841269777a6eda12e8f01d5561559..14e0dd2c9b8e599a856ddbb76410755d1efa5d48 100644 (file)
--- a/perl/DXCommandmode.pm
+++ b/perl/DXCommandmode.pm
@@ -37,6 +37,8 @@ use DB_File;
 use VE7CC;
 use DXXml;
 use AsyncMsg;
+use JSON;
+use Time::HiRes qw(gettimeofday tv_interval);
 
 use Mojo::IOLoop;
 use Mojo::IOLoop::ForkCall;
@@ -1091,7 +1093,7 @@ sub broadcast_debug
 {
        my $s = shift;                          # the line to be rebroadcast
        
-       foreach my $dxchan (DXChannel::get_all) {
+       foreach my $dxchan (DXChannel::get_all_users) {
                next unless $dxchan->{enhanced} && $dxchan->{senddbg};
                if ($dxchan->{gtk}) {
                        $dxchan->send_later('L', dd(['db', $s]));
@@ -1250,11 +1252,33 @@ sub send_motd
        $self->send_file($motd) if -e $motd;
 }
 
+sub _diffms
+{
+       return unless isdbg('chan');
+       my $call = shift;
+       my $a = shift;
+       my $b = shift || [gettimeofday];
+       my $prefix = shift;
+
+       my $secs = $b->[0] - $a->[0];
+       my $msecs = int(($b->[1] - $a->[1]) / 1000);
+
+       my $s = "forkcall stats: $call ";
+       $s .= "$prefix " if $prefix;
+       $s .= "${secs}S" if $secs;
+       $s .= "${msecs}mS";
+       dbg($s);
+}
+
 # Punt off a long running command into a separate process
 #
-# Hhis is called from commands to run some potentially long running
+# This is called from commands to run some potentially long running
 # function. The process forks and then runs the function and returns
 # the result back to the cmd. 
+#
+# NOTE: this merely forks the current process and then runs the cmd in that (current) context.
+#       IT DOES NOT START UP SOME NEW PROGRAM AND RELIES ON THE FACT THAT IT IS RUNNING DXSPIDER 
+#       THE CURRENT CONTEXT!!
 # 
 # call: $self->spawn_cmd(\<function>, [cb => sub{...}], [prefix => "cmd> "], [progress => 0|1], [args => [...]]);
 sub spawn_cmd
@@ -1269,10 +1293,13 @@ sub spawn_cmd
        my $prefix = delete $args{prefix};
        my $progress = delete $args{progress};
        my $args = delete $args{args} || [];
+       my $t0 = [gettimeofday];
 
        no strict 'refs';
                
        my $fc = Mojo::IOLoop::ForkCall->new;
+       $fc->serializer(\&encode_json);
+       $fc->deserializer(\&decode_json);
        $fc->run(
                         sub {my @args = @_; my @res = $cmdref->(@args); return @res},
                         $args,
@@ -1297,7 +1324,9 @@ sub spawn_cmd
                                                 $dxchan->send(@res);
                                         }
                                 }
+                                _diffms($call, $t0, [gettimeofday], $prefix);
                         });
+       
        return @out;
 }