add arguments to CMD progress debug

[spider.git] / perl / DXCommandmode.pm

diff --git a/perl/DXCommandmode.pm b/perl/DXCommandmode.pm
index 1b08b36e6a149d4a9c82070a47e8b3f328e09c04..74e53b10b1547a9af6cd729903b7397d33d26ea1 100644 (file)
--- a/perl/DXCommandmode.pm
+++ b/perl/DXCommandmode.pm
@@ -544,8 +544,17 @@ sub run_cmd
                        if ($package && $self->can("${package}::handle")) {
                                no strict 'refs';
                                dbg("cmd: package $package") if isdbg('command');
+                               if (isdbg('progress')) {
+                                       my $s = "CMD: '$cmd' by $call ip $self->{hostname}";
+                               }
+                               my $t0 = [gettimeofday];
                                eval { @ans = &{"${package}::handle"}($self, $args) };
                                return (DXDebug::shortmess($@)) if $@;
+                               if (isdbg('progress')) {
+                                       my $msecs = _diffms($t0);
+                                       my $s = "CMD: '$cmd $args' by $call ip: $self->{hostname} ${msecs}mS";
+                                       dbg($s);
+                               }
                        } else {
                                dbg("cmd: $package not present") if isdbg('command');
                                return $self->_error_out('e1');
@@ -1265,22 +1274,6 @@ sub send_motd
        $self->send_file($motd) if -e $motd;
 }
 
-sub _diffms
-{
-       return unless isdbg('chan');
-       my $call = shift;
-       my $line = shift;
-       my $ta = shift;
-       my $tb = shift || [gettimeofday];
-
-       my $a = int($ta->[0] * 1000) + int($ta->[1] / 1000); 
-       my $b = int($tb->[0] * 1000) + int($tb->[1] / 1000);
-       my $msecs = $b - $a;
-
-       my $s = "forkcall stats: $call '$line' ";
-       $s .= "${msecs}mS";
-       dbg($s);
-}
 
 # Punt off a long running command into a separate process
 #
@@ -1309,18 +1302,22 @@ sub spawn_cmd
        my $t0 = [gettimeofday];
 
        no strict 'refs';
-               
+
+       # just behave normally if something has set the "one-shot" _nospawn in the channel
+       return ($cmdref->(@$args)) if $self->{_nospawn};
+       
        my $fc = Mojo::IOLoop::Subprocess->new;
 #      $fc->serializer(\&encode_json);
 #      $fc->deserializer(\&decode_json);
        $fc->run(
                         sub {
                                 my $subpro = shift;
-                                if (isdbg('chan')) {
+                                if (isdbg('spawn_cmd')) {
                                         my $s = "line: $line";
                                         $s .= ", args: " . join(', ', @$args) if $args && @$args;
                                 }
                                 my @res = $cmdref->(@$args);
+#                               diffms("rcmd from $call 1", $line, $t0, scalar @res) if isdbg('chan');
                                 return @res;
                         },
 #                       $args,
@@ -1330,7 +1327,7 @@ sub spawn_cmd
                                 return unless $dxchan;
 
                                 if ($err) {
-                                        my $s = "DXCommand::spawn_cmd: call $call error $err";
+                                        my $s = "DXProt::spawn_cmd: call $call error $err";
                                         dbg($s) if isdbg('chan');
                                         $dxchan->send($s);
                                         return;
@@ -1346,7 +1343,7 @@ sub spawn_cmd
                                                 $dxchan->send(@res);
                                         }
                                 }
-                                _diffms($call, $line, $t0);
+                                diffms("by $call", $line, $t0, scalar @res) if isdbg('progress');
                         });
        
        return @out;