add debugging for reconcileStaged calls for benchmarking

diff --git a/Database/Keys.hs b/Database/Keys.hs
index aca13f94e254903308e7abc5b5e430cffda43c71..3c0e3bede3480e14dbf7c585dec9eed5a6da6e36 100644 (file)
--- 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 (file)
index 0000000..8cc8b86
--- /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..)
+"""]]