Rev 2666: Add debug timings for operations that have to send data in http://bzr.arbash-meinel.com/branches/bzr/0.19-dev/hpss_debug_timing

[John Arbash Meinel]

At http://bzr.arbash-meinel.com/branches/bzr/0.19-dev/hpss_debug_timing

------------------------------------------------------------
revno: 2666
revision-id: john at arbash-meinel.com-20070731181501-dnfycgar5ld0dqa9
parent: john at arbash-meinel.com-20070731180942-699o4e173i6h4878
committer: John Arbash Meinel <john at arbash-meinel.com>
branch nick: hpss_debug_timing
timestamp: Tue 2007-07-31 13:15:01 -0500
message:
  Add debug timings for operations that have to send data
modified:
  bzrlib/smart/protocol.py       protocol.py-20061108035435-ot0lstk2590yqhzr-1
-------------- next part --------------
=== modified file 'bzrlib/smart/protocol.py'
--- a/bzrlib/smart/protocol.py	2007-07-31 18:09:42 +0000
+++ b/bzrlib/smart/protocol.py	2007-07-31 18:15:01 +0000
@@ -315,10 +315,16 @@
         """
         if 'hpss' in debug.debug_flags:
             mutter('hpss call w/body: %r (%r...)', args, body[:20])
+            start = time.time()
         self._write_args(args)
         bytes = self._encode_bulk_data(body)
         self._request.accept_bytes(bytes)
         self._request.finished_writing()
+        if 'hpss' in debug.debug_flags:
+            # This gives us the time it took to send the information
+            # decoupled from the time it takes the server to respond to it.
+            mutter('hpss write time: %6.3fs', time.time() - start)
+            self._request_start_time = time.time()
 
     def call_with_body_readv_array(self, args, body):
         """Make a remote call with a readv array.
@@ -328,11 +334,15 @@
         """
         if 'hpss' in debug.debug_flags:
             mutter('hpss call w/readv: %r', args)
+            start = time.time()
         self._write_args(args)
         readv_bytes = self._serialise_offsets(body)
         bytes = self._encode_bulk_data(readv_bytes)
         self._request.accept_bytes(bytes)
         self._request.finished_writing()
+        if 'hpss' in debug.debug_flags:
+            mutter('hpss write time: %6.3fs', time.time() - start)
+            self._request_start_time = time.time()
 
     def cancel_read_body(self):
         """After expecting a body, a response code may indicate one otherwise.