--debug log messages are now timestamped with fractional seconds.

4 files changed, 14 insertions, 9 deletions

diff --git a/Messages.hs b/Messages.hs
index f6d26db9d..c6d033402 100644
--- a/Messages.hs
+++ b/Messages.hs
@@ -173,7 +173,7 @@ setupConsole :: IO ()
 setupConsole = do
 	s <- setFormatter
 		<$> streamHandler stderr DEBUG
-		<*> pure (simpleLogFormatter "[$time] $msg")
+		<*> pure preciseLogFormatter
 	updateGlobalLogger rootLoggerName (setLevel NOTICE . setHandlers [s])
 	{- This avoids ghc's output layer crashing on
 	 - invalid encoded characters in
@@ -181,6 +181,10 @@ setupConsole = do
 	fileEncoding stdout
 	fileEncoding stderr
 
+{- Log formatter with precision into fractions of a second. -}
+preciseLogFormatter :: LogFormatter a
+preciseLogFormatter = tfLogFormatter "%F %X%Q" "[$time] $msg"
+
 enableDebugOutput :: IO ()
 enableDebugOutput = updateGlobalLogger rootLoggerName $ setLevel DEBUG
 
diff --git a/debian/changelog b/debian/changelog
index c43a3e813..b8b82512a 100644
--- a/debian/changelog
+++ b/debian/changelog
@@ -1,3 +1,9 @@
+git-annex (5.20150813) UNRELEASED; urgency=medium
+
+  * --debug log messages are now timestamped with fractional seconds.
+
+ -- Joey Hess <id@joeyh.name>  Wed, 12 Aug 2015 14:31:01 -0400
+
 git-annex (5.20150812) unstable; urgency=medium
 
   * Added support for SHA3 hashed keys (in 8 varieties), when git-annex is
diff --git a/doc/todo/subsecond_timestamping_of_the_--debug_output.mdwn b/doc/todo/subsecond_timestamping_of_the_--debug_output.mdwn
index 9820338ea..8d963c432 100644
--- a/doc/todo/subsecond_timestamping_of_the_--debug_output.mdwn
+++ b/doc/todo/subsecond_timestamping_of_the_--debug_output.mdwn
@@ -1 +1,4 @@
 ATM --debug uses timestamps at second precision.  Would be nice (to see where time is spent) to have subsecond timing
+
+> [[done]], I was able to get fractional seconds down to 0.000001
+> in the debug output. --[[Joey]]
diff --git a/doc/todo/subsecond_timestamping_of_the_--debug_output/comment_1_6067cf9dfbb9dcebfe90951515e2ccdf._comment b/doc/todo/subsecond_timestamping_of_the_--debug_output/comment_1_6067cf9dfbb9dcebfe90951515e2ccdf._comment
deleted file mode 100644
index d99959357..000000000
--- a/doc/todo/subsecond_timestamping_of_the_--debug_output/comment_1_6067cf9dfbb9dcebfe90951515e2ccdf._comment
+++ /dev/null
@@ -1,8 +0,0 @@
-[[!comment format=mdwn
- username="joey"
- subject="""comment 1"""
- date="2015-08-04T19:32:38Z"
- content="""
-This would require changes to the MissingH library, which is what provides
-the debug logger.
-"""]]