From 2b5e6ff20a26e1523e85262fc426909f9a383037 Mon Sep 17 00:00:00 2001 From: Joey Hess Date: Mon, 28 Nov 2022 15:12:53 -0400 Subject: [PATCH] test: Add --test-debug option This work is supported by the NIH-funded NICEMAN (ReproNim TR&D3) project. --- CHANGELOG | 1 + Test.hs | 6 ++- Test/Framework.hs | 19 +++++-- Types/Test.hs | 1 + ..._e07a5dd0abb2049b4bb0bf26fa2ebab5._comment | 51 +++++++++++++++++++ doc/git-annex-test.mdwn | 10 ++++ 6 files changed, 84 insertions(+), 4 deletions(-) create mode 100644 doc/bugs/git_annex_test_never_exits__63__/comment_1_e07a5dd0abb2049b4bb0bf26fa2ebab5._comment diff --git a/CHANGELOG b/CHANGELOG index 78c8abc552..341bd930b2 100644 --- 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 Fri, 18 Nov 2022 12:58:06 -0400 diff --git a/Test.hs b/Test.hs index 6d3c58d3c5..89a947f755 100644 --- 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 diff --git a/Test/Framework.hs b/Test/Framework.hs index a4f24066ed..d74ae7f3e1 100644 --- a/Test/Framework.hs +++ b/Test/Framework.hs @@ -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 diff --git a/Types/Test.hs b/Types/Test.hs index 9d0af77208..90a182043f 100644 --- a/Types/Test.hs +++ b/Types/Test.hs @@ -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 index 0000000000..0df28ac7b5 --- /dev/null +++ b/doc/bugs/git_annex_test_never_exits__63__/comment_1_e07a5dd0abb2049b4bb0bf26fa2ebab5._comment @@ -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 +"""]] diff --git a/doc/git-annex-test.mdwn b/doc/git-annex-test.mdwn index 17923cc026..18a219c6b2 100644 --- a/doc/git-annex-test.mdwn +++ b/doc/git-annex-test.mdwn @@ -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)