From 1a6fa5abc808ac2effbe410ea0d123a55e6c54ad Mon Sep 17 00:00:00 2001
From: Joey Hess <joeyh@joeyh.name>
Date: Tue, 8 Jun 2021 11:57:23 -0400
Subject: [PATCH] add debugging for reconcileStaged calls for benchmarking

---
 Database/Keys.hs                              |  4 +++
 ..._51a3a86a290b0e3994507f3f64e7c72a._comment | 25 +++++++++++++++++++
 2 files changed, 29 insertions(+)
 create mode 100644 doc/bugs/significant_performance_regression_impacting_datal/comment_11_51a3a86a290b0e3994507f3f64e7c72a._comment

diff --git a/Database/Keys.hs b/Database/Keys.hs
index aca13f94e2..3c0e3bede3 100644
--- a/Database/Keys.hs
+++ b/Database/Keys.hs
@@ -240,6 +240,7 @@ reconcileStaged qh = do
 	go cur indexcache (Just newtree) = do
 		oldtree <- getoldtree
 		when (oldtree /= newtree) $ do
+			fastDebug "Database.Keys" "reconcileStaged start"
 			g <- Annex.gitRepo
 			void $ catstream $ \mdfeeder -> 
 				void $ updatetodiff g
@@ -251,6 +252,7 @@ reconcileStaged qh = do
 			-- get garbage collected, and is available to diff
 			-- against next time.
 			inRepo $ update' lastindexref newtree
+			fastDebug "Database.Keys" "reconcileStaged end"
 	-- git write-tree will fail if the index is locked or when there is
 	-- a merge conflict. To get up-to-date with the current index, 
 	-- diff --staged with the old index tree. The current index tree
@@ -262,6 +264,7 @@ reconcileStaged qh = do
 	-- version of the files that are conflicted. So a second diff
 	-- is done, with --staged but no old tree.
 	go _ _ Nothing = do
+		fastDebug "Database.Keys" "reconcileStaged start (in conflict)"
 		oldtree <- getoldtree
 		g <- Annex.gitRepo
 		catstream $ \mdfeeder -> do
@@ -270,6 +273,7 @@ reconcileStaged qh = do
 			when conflicted $
 				void $ updatetodiff g Nothing "--staged"
 					(procmergeconflictdiff mdfeeder)
+		fastDebug "Database.Keys" "reconcileStaged end"
 	
 	updatetodiff g old new processor = do
 		(l, cleanup) <- pipeNullSplit' (diff old new) g
diff --git a/doc/bugs/significant_performance_regression_impacting_datal/comment_11_51a3a86a290b0e3994507f3f64e7c72a._comment b/doc/bugs/significant_performance_regression_impacting_datal/comment_11_51a3a86a290b0e3994507f3f64e7c72a._comment
new file mode 100644
index 0000000000..8cc8b86238
--- /dev/null
+++ b/doc/bugs/significant_performance_regression_impacting_datal/comment_11_51a3a86a290b0e3994507f3f64e7c72a._comment
@@ -0,0 +1,25 @@
+[[!comment format=mdwn
+ username="joey"
+ subject="""comment 11"""
+ date="2021-06-08T15:41:23Z"
+ content="""
+I can't think of anything OSX specific in the recent changes.
+
+I have added debugging of when reconcileStaged wakes up and possibly
+wastes some time, eg:
+
+	joey@darkstar:~/tmp/big> git config annex.debug true
+	joey@darkstar:~/tmp/big> git config annex.debugfilter Database.Keys
+	joey@darkstar:~/tmp/big> git-annex init
+	init  
+	[2021-06-08 11:52:11.854202926] (Database.Keys) reconcileStaged start
+	(scanning for annexed files...)
+	[2021-06-08 11:52:44.092620256] (Database.Keys) reconcileStaged end
+	ok
+
+All the new work happens in between those two debugs, so you could check if
+the time sink is there or elsewhere.
+
+(Note that the last release takes 2 seconds longer for that init than
+it does now..)
+"""]]