More timing tweaks.

2 files changed, 22 insertions, 15 deletions

diff --git a/hacks/analog.py b/hacks/analog.py
index fa1246014..de5a319c4 100644
--- a/hacks/analog.py
+++ b/hacks/analog.py
@@ -109,7 +109,7 @@ while True:
     # Not-so-human-readable log messages (LOG_TIMING)
     if message == 'add-frame-to-queue':
         queue_size.append((T, values['queue']))
-    elif message in ['encoder-sleep', 'encoder-wake', 'start-local-encode', 'finish-local-encode', 'start-remote-send', 'finish-remote-send', 'start-remote-encode-and-receive', 'finish-remote-encode-and-receive']:
+    elif message in ['encoder-sleep', 'encoder-wake', 'start-local-encode', 'finish-local-encode', 'start-remote-send', 'start-remote-encode', 'start-remote-receive', 'finish-remote-receive']:
         add_encoder_thread_event(values['thread'], T, message)
     # Human-readable log message (other LOG_*)
     elif message.startswith('Finished locally-encoded'):
@@ -238,13 +238,13 @@ elif args.encoder_stats:
     for t in encoder_threads:
         last = None
         asleep = Time()
-        encoding = Time()
+        local_encoding = Time()
         sending = Time()
-        remote_encoding_and_receiving = Time()
+        remote_encoding = Time()
+        receiving = Time()
         wakes = 0
         for e in encoder_thread_events[t]:
-            if e[1] not in ['encoder-sleep', 'encoder-wake', 'start-remote-send', 'finish-remote-send',
-                            'start-remote-encode-and-receive', 'finish-remote-encode-and-receive']:
+            if e[1] not in ['encoder-sleep', 'encoder-wake', 'start-remote-send', 'start-remote-encode', 'start-remote-receive', 'finish-remote-receive']:
                 continue
 
             if last is not None:
@@ -252,21 +252,28 @@ elif args.encoder_stats:
                     asleep += e[0] - last[0]
                 elif last[1] == 'encoder-wake':
                     wakes += 1
-                    encoding += e[0] - last[0]
+                    local_encoding += e[0] - last[0]
                 elif last[1] == 'start-remote-send':
                     sending += e[0] - last[0]
-                elif last[1] == 'start-remote-encode-and-receive':
-                    remote_encoding_and_receiving += e[0] - last[0]
+                elif last[1] == 'start-remote-encode':
+                    remote_encoding += e[0] - last[0]
+                elif last[1] == 'start-remote-receive':
+                    receiving += e[0] - last[0]
 
             last = e
 
         print '-- Encoder thread %s' % t
         print '\tAwoken %d times' % wakes
-        total = asleep.float_seconds() + encoding.float_seconds() + sending.float_seconds() + remote_encoding_and_receiving.float_seconds()
+        total = asleep.float_seconds() + local_encoding.float_seconds() + sending.float_seconds() + remote_encoding.float_seconds() + receiving.float_seconds()
         if total == 0:
             continue
         print '\tAsleep: %s (%.2f%%)' % (asleep, asleep.float_seconds() * 100 / total)
-        print '\tEncoding: %s (%.2f%%)' % (encoding, encoding.float_seconds() * 100 / total)
-        print '\tSending: %s (%.2f%%)' % (sending, sending.float_seconds() * 100 / total)
-        print '\tRemote encoding / receiving: %s (%.2f%%)' % (remote_encoding_and_receiving, remote_encoding_and_receiving.float_seconds() * 100 / total)
+        if local_encoding.float_seconds() > 0:
+            print '\tLocal encoding: %s (%.2f%%)' % (local_encoding, local_encoding.float_seconds() * 100 / total)
+        if sending.float_seconds() > 0:
+            print '\tSending: %s (%.2f%%)' % (sending, sending.float_seconds() * 100 / total)
+        if remote_encoding.float_seconds() > 0:
+            print '\tRemote encoding: %s (%.2f%%)' % (remote_encoding, remote_encoding.float_seconds() * 100 / total)
+        if receiving.float_seconds() > 0:
+            print '\tReceiving: %s (%.2f%%)' % (receiving, receiving.float_seconds() * 100 / total)
         print ''
diff --git a/src/lib/dcp_video.cc b/src/lib/dcp_video.cc
index 7d060b30d..f4c6222e2 100644
--- a/src/lib/dcp_video.cc
+++ b/src/lib/dcp_video.cc
@@ -268,15 +268,15 @@ DCPVideo::encode_remotely (ServerDescription serv)
 	/* Send binary data */
 	LOG_TIMING("start-remote-send thread=%1", boost::this_thread::get_id());
 	_frame->send_binary (socket);
-	LOG_TIMING("finish-remote-send thread=%1", boost::this_thread::get_id());
 
 	/* Read the response (JPEG2000-encoded data); this blocks until the data
 	   is ready and sent back.
 	*/
-	LOG_TIMING("start-remote-encode-and-receive thread=%1", boost::this_thread::get_id ());
+	LOG_TIMING("start-remote-encode thread=%1", boost::this_thread::get_id ());
 	Data e (socket->read_uint32 ());
+	LOG_TIMING("start-remote-receive thread=%1", boost::this_thread::get_id ());
 	socket->read (e.data().get(), e.size());
-	LOG_TIMING("finish-remote-encode-and-receive thread=%1", boost::this_thread::get_id ());
+	LOG_TIMING("finish-remote-receive thread=%1", boost::this_thread::get_id ());
 
 	LOG_DEBUG_ENCODE (N_("Finished remotely-encoded frame %1"), _index);