test: Add --test-debug option
authorJoey Hess <joeyh@joeyh.name>
Mon, 28 Nov 2022 19:12:53 +0000 (15:12 -0400)
committerJoey Hess <joeyh@joeyh.name>
Mon, 28 Nov 2022 19:12:53 +0000 (15:12 -0400)
This work is supported by the NIH-funded NICEMAN (ReproNim TR&D3) project.

CHANGELOG
Test.hs
Test/Framework.hs
Types/Test.hs
doc/bugs/git_annex_test_never_exits__63__/comment_1_e07a5dd0abb2049b4bb0bf26fa2ebab5._comment [new file with mode: 0644]
doc/git-annex-test.mdwn

index 78c8abc552a0920fc5fc16108dc3e7d683945999..341bd930b21f27ff02eae23899a9af06c5664697 100644 (file)
--- a/CHANGELOG
+++ b/CHANGELOG
@@ -6,6 +6,7 @@ git-annex (10.20221105) UNRELEASED; urgency=medium
     large repository. Instead that scan is done on demand.
   * When youtube-dl is not available in PATH, use yt-dlp instead.
   * Support parsing yt-dpl output to display download progress.
+  * test: Add --test-debug option.
 
  -- Joey Hess <id@joeyh.name>  Fri, 18 Nov 2022 12:58:06 -0400
 
diff --git a/Test.hs b/Test.hs
index 6d3c58d3c51c6aa51466fa8f00be08f2221e42f7..89a947f755cfc3d678346ced32d94b403752b007 100644 (file)
--- a/Test.hs
+++ b/Test.hs
@@ -92,7 +92,7 @@ import qualified Utility.Gpg
 
 optParser :: Parser TestOptions
 optParser = TestOptions
-       <$> snd (tastyParser (tests 1 False True (TestOptions mempty False False Nothing mempty mempty)))
+       <$> snd (tastyParser (tests 1 False True (TestOptions mempty False False Nothing mempty False mempty)))
        <*> switch
                ( long "keep-failures"
                <> help "preserve repositories on test failure"
@@ -111,6 +111,10 @@ optParser = TestOptions
                <> help "run tests with a git config set"
                <> metavar "NAME=VALUE"
                ))
+       <*> switch
+               ( long "test-debug"
+               <> help "show debug messages for commands run by test suite"
+               )
        <*> cmdParams "non-options are for internal use only"
   where
        parseconfigvalue s = case break (== '=') s of
index a4f24066ed3a2aa5b37aabf1d5c4413301cabf30..d74ae7f3e1345bfb488a989472d14e01dc0424ac 100644 (file)
@@ -65,11 +65,20 @@ import qualified Command.Uninit
 
 -- Run a process. The output and stderr is captured, and is only
 -- displayed if the process does not return the expected value.
+--
+-- In debug mode, the output is allowed to pass through.
 testProcess :: String -> [String] -> Maybe [(String, String)] -> (Bool -> Bool) -> String -> Assertion
 testProcess command params environ expectedret faildesc = do
        let p = (proc command params) { env = environ }
-       (transcript, ret) <- Utility.Process.Transcript.processTranscript' p Nothing
-       (expectedret ret) @? (faildesc ++ " failed (transcript follows)\n" ++ transcript)
+       debug <- testDebug . testOptions <$> getTestMode
+       if debug
+               then do
+                       ret <- withCreateProcess p $ \_ _ _ pid ->
+                               waitForProcess pid
+                       (expectedret (ret == ExitSuccess)) @? (faildesc ++ " failed")
+               else do
+                       (transcript, ret) <- Utility.Process.Transcript.processTranscript' p Nothing
+                       (expectedret ret) @? (faildesc ++ " failed (transcript follows)\n" ++ transcript)
 
 -- Run git. (Do not use to run git-annex as the one being tested
 -- may not be in path.)
@@ -98,7 +107,11 @@ git_annex_shouldfail' = git_annex'' (== False)
 git_annex'' :: (Bool -> Bool) -> String -> [String] -> Maybe [(String, String)] -> String -> Assertion
 git_annex'' expectedret command params environ faildesc = do
        pp <- Annex.Path.programPath
-       testProcess pp (command:params) environ expectedret faildesc
+       debug <- testDebug . testOptions <$> getTestMode
+       let params' = if debug
+               then "--debug":params
+               else params
+       testProcess pp (command:params') environ expectedret faildesc
 
 {- Runs git-annex and returns its standard output. -}
 git_annex_output :: String -> [String] -> IO String
index 9d0af7720834760c24c8594b401db60a94d69525..90a182043f8df12eb941633e108011042a4841f3 100644 (file)
@@ -19,6 +19,7 @@ data TestOptions = TestOptions
        , fakeSsh :: Bool
        , concurrentJobs :: Maybe Concurrency
        , testGitConfig :: [(ConfigKey, ConfigValue)]
+       , testDebug :: Bool
        , internalData :: CmdParams
        }
 
diff --git a/doc/bugs/git_annex_test_never_exits__63__/comment_1_e07a5dd0abb2049b4bb0bf26fa2ebab5._comment b/doc/bugs/git_annex_test_never_exits__63__/comment_1_e07a5dd0abb2049b4bb0bf26fa2ebab5._comment
new file mode 100644 (file)
index 0000000..0df28ac
--- /dev/null
@@ -0,0 +1,51 @@
+[[!comment format=mdwn
+ username="joey"
+ subject="""comment 1"""
+ date="2022-11-28T18:11:41Z"
+ content="""
+Seems like the test it is stuck in is "move (ssh remote)".
+
+Is this replicable?
+
+I wonder if `test_fs.py` is doing something that causes the problem.
+There is some complexity in there. Maybe it's happening on one
+particular FS.
+
+If it happens when not run by `test_fs.py`, it would be useful to get a
+debug log, because I think that seeing the P2P protocol dump would help
+explain what has happened.
+
+There was not a good way to get the test suite to output a full debug
+log, so I had to implement one. With an updated build of git-annex,
+you can use:
+
+       git-annex test -J1 --test-debug
+
+Here's the expected output of that section of the test suite, when it
+is working properly:
+
+       move foo [2022-11-28 14:54:11.10011679] (Utility.Process) process [390399] chat: sh ["-c","git-annex test --fakessh -- 'localhost' 'git-annex-shell '\"'\"'p2pstdio'\"'\"' '\"'\"'/home/joey/src/git-annex/.t/3/main1'\"'\"' '\"'\"'--debug'\"'\"' '\"'\"'c76e0406-38ea-413e-9fb0-56cc32847734'\"'\"' --uuid 000c7285-ec19-4c15-9c67-4dd4b7c74775'"]
+       [2022-11-28 14:54:11.129754519] (P2P.IO) [ThreadId 4] P2P > AUTH-SUCCESS 000c7285-ec19-4c15-9c67-4dd4b7c74775
+       [2022-11-28 14:54:11.130259741] (P2P.IO) [ssh connection Just 390399] [ThreadId 4] P2P < AUTH-SUCCESS 000c7285-ec19-4c15-9c67-4dd4b7c74775
+       [2022-11-28 14:54:11.13041388] (P2P.IO) [ssh connection Just 390399] [ThreadId 4] P2P > VERSION 1
+       [2022-11-28 14:54:11.130680315] (P2P.IO) [ThreadId 4] P2P < VERSION 1
+       [2022-11-28 14:54:11.13087982] (P2P.IO) [ThreadId 4] P2P > VERSION 1
+       [2022-11-28 14:54:11.131127415] (P2P.IO) [ssh connection Just 390399] [ThreadId 4] P2P < VERSION 1
+       [2022-11-28 14:54:11.131262307] (P2P.IO) [ssh connection Just 390399] [ThreadId 4] P2P > CHECKPRESENT SHA256E-s20--e394a389d787383843decc5d3d99b6d184ffa5fddeec23b911f9ee7fc8b9ea77
+       [2022-11-28 14:54:11.131679501] (P2P.IO) [ThreadId 4] P2P < CHECKPRESENT SHA256E-s20--e394a389d787383843decc5d3d99b6d184ffa5fddeec23b911f9ee7fc8b9ea77
+       [2022-11-28 14:54:11.132388822] (P2P.IO) [ThreadId 4] P2P > FAILURE
+       [2022-11-28 14:54:11.13261351] (P2P.IO) [ssh connection Just 390399] [ThreadId 4] P2P < FAILURE
+       (to origin...) 
+       [2022-11-28 14:54:11.135583194] (P2P.IO) [ssh connection Just 390399] [ThreadId 4] P2P > PUT foo SHA256E-s20--e394a389d787383843decc5d3d99b6d184ffa5fddeec23b911f9ee7fc8b9ea77
+       [2022-11-28 14:54:11.136134981] (P2P.IO) [ThreadId 4] P2P < PUT foo SHA256E-s20--e394a389d787383843decc5d3d99b6d184ffa5fddeec23b911f9ee7fc8b9ea77
+       [2022-11-28 14:54:11.136824468] (P2P.IO) [ThreadId 4] P2P > PUT-FROM 0
+       [2022-11-28 14:54:11.137123219] (P2P.IO) [ssh connection Just 390399] [ThreadId 4] P2P < PUT-FROM 0
+       ...
+       [2022-11-28 14:54:11.148194515] (P2P.IO) [ssh connection Just 390399] [ThreadId 4] P2P > DATA 20
+       [2022-11-28 14:54:11.148414855] (P2P.IO) [ThreadId 4] P2P < DATA 20
+       [2022-11-28 14:54:11.148739395] (P2P.IO) [ssh connection Just 390399] [ThreadId 4] P2P > VALID
+       ^M100%  20 B              2 KiB/s 0s[2022-11-28 14:54:11.152428942] (P2P.IO) [ThreadId 4] P2P < VALID
+       ...
+       [2022-11-28 14:54:11.177599567] (P2P.IO) [ThreadId 4] P2P > SUCCESS
+       [2022-11-28 14:54:11.177858296] (P2P.IO) [ssh connection Just 390399] [ThreadId 4] P2P < SUCCESS
+"""]]
index 17923cc0260889ff600c5e079e093d8a3ce70fc5..18a219c6b2d893a63ef7e12bcf5a48fd03eed77d 100644 (file)
@@ -44,6 +44,16 @@ framework. Pass --help for details about those.
   One valid use of this is to change a git configuration to a value that
   is planned to be the new default in a future version of git.
 
+* `--test-debug`
+
+  Normally output of commands run by the test suite is hidden, so even
+  when annex.debug or --debug is enabled, it will not be displayed.
+  This option makes the full output of commands run by the test suite be
+  displayed. It also makes the test suite run git-annex with --debug.
+
+  It's a good idea to use `-J1` in combinaton with this, otherwise
+  the output of concurrent tests will be mixed together.
+
 # SEE ALSO
 
 [[git-annex]](1)