Rev 3929: Update mutter() to flush occasionally. in http://bzr.arbash-meinel.com/branches/bzr/flush_bzr_log

[John Arbash Meinel]

At http://bzr.arbash-meinel.com/branches/bzr/flush_bzr_log

------------------------------------------------------------
revno: 3929
revision-id: john at arbash-meinel.com-20090108175346-92tja47yon06yfzi
parent: pqm at pqm.ubuntu.com-20090108161207-d95v7ouel5ibahh0
committer: John Arbash Meinel <john at arbash-meinel.com>
branch nick: flush_bzr_log
timestamp: Thu 2009-01-08 11:53:46 -0600
message:
  Update mutter() to flush occasionally.
-------------- next part --------------
=== modified file 'NEWS'
--- a/NEWS	2009-01-08 16:12:07 +0000
+++ b/NEWS	2009-01-08 17:53:46 +0000
@@ -177,6 +177,9 @@
       Previously the order was fully random, now the records should be
       returned from each pack in turn, in forward I/O order.
       (John Arbash Meinel)
+    
+    * ``mutter()`` will now flush the ``~/.bzr.log`` if it has been more
+      than 2s since the last time it flushed. (John Arbash Meinel)
 
     * New method ``bzrlib.repository.Repository.add_inventory_by_delta``
       allows adding an inventory via an inventory delta, which can be

=== modified file 'bzrlib/trace.py'
--- a/bzrlib/trace.py	2008-11-01 14:44:47 +0000
+++ b/bzrlib/trace.py	2009-01-08 17:53:46 +0000
@@ -131,7 +131,10 @@
 error =     _bzr_logger.error
 
 
+_last_mutter_flush_time = None
+
 def mutter(fmt, *args):
+    global _last_mutter_flush_time
     if _trace_file is None:
         return
     if (getattr(_trace_file, 'closed', None) is not None) and _trace_file.closed:
@@ -152,11 +155,19 @@
         out = fmt % tuple(real_args)
     else:
         out = fmt
-    timestamp = '%0.3f  ' % (time.time() - _bzr_log_start_time,)
+    now = time.time()
+    timestamp = '%0.3f  ' % (now - _bzr_log_start_time,)
     out = timestamp + out + '\n'
     _trace_file.write(out)
-    # no need to flush here, the trace file is now linebuffered when it's
-    # opened.
+    # We flush if we haven't flushed for a few seconds. We don't want to flush
+    # on every mutter, but when a command takes a while, it can be nice to see
+    # updates in the debug log.
+    if (_last_mutter_flush_time is None
+        or (now - _last_mutter_flush_time) > 2.0):
+        flush = getattr(_trace_file, 'flush', None)
+        if flush is not None:
+            flush()
+        _last_mutter_flush_time = now
 
 
 def mutter_callsite(stacklevel, fmt, *args):