{"thread":{"id":"48997","subject":"[PATCH] travis-ci: include the trash directories of failed tests in the trace log","startedAt":"2018-07-31T22:56:22Z","lastAt":"2018-08-07T19:02:39Z","messageCount":2,"participants":["SZEDER Gábor"],"isPatch":true,"patchVersion":1,"patchTotal":null},"messages":[{"id":"354132","messageId":"20180731225612.24075-1-szeder.dev@gmail.com","threadId":"48997","inReplyTo":null,"subject":"[PATCH] travis-ci: include the trash directories of failed tests in the trace log","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2018-07-31T22:56:12Z","receivedAt":"2018-07-31T22:56:22Z","isPatch":true,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"The trash directory of a failed test might contain invaluable\ninformation about the cause of the failure, but we have no access to\nthe trash directories of Travis CI build jobs.  The only feedback we\nget from there is the build job's trace log, so...\n\nModify 'ci/print-test-failures.sh' to create a tar.gz archive of the\ntrash directory of each failed test, encode that archive with base64,\nand print the resulting block of ASCII text, so it gets embedded in\nthe trace log.  Furthermore, run tests with '--immediate' to\nfaithfully preserve the failed state.\n\nExtracting the trash directories from the trace log turned out to be a\nbit of a hassle, partly because of the size of these logs (usually\nresulting in several hundreds or even thousands of lines of\nbase64-encoded text), and partly because these logs have CRLF, CRCRLF\nand occasionally even CRCRCRLF line endings, which cause 'base64 -d'\nfrom coreutils to complain about \"invalid input\".  For convenience add\na small script 'ci/util/extract-trash-dirs.sh', which will extract and\nunpack all base64-encoded trash directories embedded in the log fed to\nits standard input, and include an example command to be copy-pasted\ninto a terminal to do it all at the end of the failure report.\n\nA few of our tests create sizeable trash directories, so limit the\nsize of each included base64-encoded block, let's say, to 1MB.  And\njust in case something fundamental gets broken and a lot of tests fail\nat once, don't include trash directories when the combined size of the\nincluded base64-encoded blocks would exceed 1MB.\n\nSigned-off-by: SZEDER Gábor <szeder.dev@gmail.com>\n---\n\nNotes:\n    This is an improved version of the PoC mentioned some months ago at:\n    \n      https://public-inbox.org/git/20180122182717.21539-1-szeder.dev@gmail.com/\n    \n    I'm still not sure whether this is too clever or too ugly, or both,\n    but it did actually prove to be useful since then: it's very likely\n    that we wouldn't have 2f3cbcd8c5 (tests: make forging GPG signed\n    commits and tags more robust, 2018-06-04) without it.\n    \n    The output looks like this; with this patch on top of yesterday's\n    'pu' (6f49f36eba), which happens to have multiple test failures:\n    \n      https://travis-ci.org/szeder/git/jobs/410471312#L3010\n    \n    (Note: the Travis CI webpage will likely fold up the failure output\n    before you could take a closer look at it; then click on the line\n    containing '$ ci/print-test-failures.sh' and scroll down for a while.)\n\n ci/lib-travisci.sh            |  2 +-\n ci/print-test-failures.sh     | 55 +++++++++++++++++++++++++++++++++--\n ci/util/extract-trash-dirs.sh | 50 +++++++++++++++++++++++++++++++\n 3 files changed, 104 insertions(+), 3 deletions(-)\n create mode 100755 ci/util/extract-trash-dirs.sh\n\ndiff --git a/ci/lib-travisci.sh b/ci/lib-travisci.sh\nindex ceecc889ca..06970f7213 100755\n--- a/ci/lib-travisci.sh\n+++ b/ci/lib-travisci.sh\n@@ -97,7 +97,7 @@ fi\n export DEVELOPER=1\n export DEFAULT_TEST_TARGET=prove\n export GIT_PROVE_OPTS=\"--timer --jobs 3 --state=failed,slow,save\"\n-export GIT_TEST_OPTS=\"--verbose-log -x\"\n+export GIT_TEST_OPTS=\"--verbose-log -x --immediate\"\n export GIT_TEST_CLONE_2GB=YesPlease\n if [ \"$jobname\" = linux-gcc ]; then\n \texport CC=gcc-8\ndiff --git a/ci/print-test-failures.sh b/ci/print-test-failures.sh\nindex 4f261ddc01..d55460a212 100755\n--- a/ci/print-test-failures.sh\n+++ b/ci/print-test-failures.sh\n@@ -8,13 +8,24 @@\n # Tracing executed commands would produce too much noise in the loop below.\n set +x\n \n-if ! ls t/test-results/*.exit >/dev/null 2>/dev/null\n+cd t/\n+\n+if ! ls test-results/*.exit >/dev/null 2>/dev/null\n then\n \techo \"Build job failed before the tests could have been run\"\n \texit\n fi\n \n-for TEST_EXIT in t/test-results/*.exit\n+case \"$jobname\" in\n+osx-clang|osx-gcc)\n+\t# base64 in OSX doesn't wrap its output at 76 columns by\n+\t# default, but prints a single, very long line.\n+\tbase64_opts=\"-b 76\"\n+\t;;\n+esac\n+\n+combined_trash_size=0\n+for TEST_EXIT in test-results/*.exit\n do\n \tif [ \"$(cat \"$TEST_EXIT\")\" != \"0\" ]\n \tthen\n@@ -23,5 +34,45 @@ do\n \t\techo \"$(tput setaf 1)${TEST_OUT}...$(tput sgr0)\"\n \t\techo \"------------------------------------------------------------------------\"\n \t\tcat \"${TEST_OUT}\"\n+\n+\t\ttest_name=\"${TEST_EXIT%.exit}\"\n+\t\ttest_name=\"${test_name##*/}\"\n+\t\ttrash_dir=\"trash directory.$test_name\"\n+\t\ttrash_tgz_b64=\"trash.$test_name.base64\"\n+\t\tif [ -d \"$trash_dir\" ]\n+\t\tthen\n+\t\t\ttar czp \"$trash_dir\" |base64 $base64_opts >\"$trash_tgz_b64\"\n+\n+\t\t\ttrash_size=$(wc -c <\"$trash_tgz_b64\")\n+\t\t\tif [ $trash_size -gt 1048576 ]\n+\t\t\tthen\n+\t\t\t\t# larger than 1MB\n+\t\t\t\techo \"$(tput setaf 1)Didn't include the trash directory of '$test_name' in the trace log, it's too big$(tput sgr0)\"\n+\t\t\t\tcontinue\n+\t\t\tfi\n+\n+\t\t\tnew_combined_trash_size=$(($combined_trash_size + $trash_size))\n+\t\t\tif [ $new_combined_trash_size -gt 1048576 ]\n+\t\t\tthen\n+\t\t\t\techo \"$(tput setaf 1)Didn't include the trash directory of '$test_name' in the trace log, there is plenty of trash in there already.$(tput sgr0)\"\n+\t\t\t\tcontinue\n+\t\t\tfi\n+\t\t\tcombined_trash_size=$new_combined_trash_size\n+\n+\t\t\t# DO NOT modify these two 'echo'-ed strings below\n+\t\t\t# without updating 'ci/util/extract-trash-dirs.sh'\n+\t\t\t# as well.\n+\t\t\techo \"$(tput setaf 1)Start of trash directory of '$test_name':$(tput sgr0)\"\n+\t\t\tcat \"$trash_tgz_b64\"\n+\t\t\techo \"$(tput setaf 1)End of trash directory of '$test_name'$(tput sgr0)\"\n+\t\tfi\n \tfi\n done\n+\n+if [ $combined_trash_size -gt 0 ]\n+then\n+\techo \"------------------------------------------------------------------------\"\n+\techo \"Trash directories embedded in this log can be extracted by running:\"\n+\techo\n+\techo \"  curl https://api.travis-ci.org/v3/job/$TRAVIS_JOB_ID/log.txt |./ci/util/extract-trash-dirs.sh\"\n+fi\ndiff --git a/ci/util/extract-trash-dirs.sh b/ci/util/extract-trash-dirs.sh\nnew file mode 100755\nindex 0000000000..8e67bec21a\n--- /dev/null\n+++ b/ci/util/extract-trash-dirs.sh\n@@ -0,0 +1,50 @@\n+#!/bin/sh\n+\n+error () {\n+\techo >&2 \"error: $@\"\n+\texit 1\n+}\n+\n+find_embedded_trash () {\n+\twhile read -r line\n+\tdo\n+\t\tcase \"$line\" in\n+\t\t*Start\\ of\\ trash\\ directory\\ of\\ \\'t[0-9][0-9][0-9][0-9]-*\\':*)\n+\t\t\ttest_name=\"${line#*\\'}\"\n+\t\t\ttest_name=\"${test_name%\\'*}\"\n+\n+\t\t\treturn 0\n+\t\tesac\n+\tdone\n+\n+\treturn 1\n+}\n+\n+extract_embedded_trash () {\n+\twhile read -r line\n+\tdo\n+\t\tcase \"$line\" in\n+\t\t*End\\ of\\ trash\\ directory\\ of\\ \\'$test_name\\'*)\n+\t\t\treturn\n+\t\t\t;;\n+\t\t*)\n+\t\t\tprintf '%s\\n' \"$line\"\n+\t\t\t;;\n+\t\tesac\n+\tdone\n+\n+\terror \"unexpected end of input\"\n+}\n+\n+# Raw logs from Linux build jobs have CRLF line endings, while OSX\n+# build jobs mostly have CRCRLF, except an odd line every now and\n+# then that has CRCRCRLF.  'base64 -d' from 'coreutils' doesn't like\n+# CRs and complains about \"invalid input\", so remove all CRs at the\n+# end of lines.\n+sed -e 's/\\r*$//' | \\\n+while find_embedded_trash\n+do\n+\techo \"Extracting trash directory of '$test_name'\"\n+\n+\textract_embedded_trash |base64 -d |tar xzp\n+done\n-- \n2.18.0.408.g42635c01bc\n\n"},{"id":"354763","messageId":"CAM0VKjkdf7Rn7nxZQ5DScT_nYAbK76SFuWRUrcUJb23utKWf7A@mail.gmail.com","threadId":"48997","inReplyTo":"51083CBF-E805-4408-8973-E5C85100E319@gmail.com","subject":"Re: [PATCH] travis-ci: include the trash directories of failed tests in the trace log","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2018-08-07T18:58:13Z","receivedAt":"2018-08-07T19:02:39Z","isPatch":true,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"On Tue, Aug 7, 2018 at 5:12 PM Lars Schneider <larsxschneider@gmail.com> wrote:\n>\n> > On Aug 1, 2018, at 12:56 AM, SZEDER Gábor <szeder.dev@gmail.com> wrote:\n> >\n> > The trash directory of a failed test might contain invaluable\n> > information about the cause of the failure, but we have no access to\n> > the trash directories of Travis CI build jobs.  The only feedback we\n> > get from there is the build job's trace log, so...\n>\n> 100% agree that keeping the trash directory is valuable.\n>\n> > Modify 'ci/print-test-failures.sh' to create a tar.gz archive of the\n> > trash directory of each failed test, encode that archive with base64,\n> > and print the resulting block of ASCII text, so it gets embedded in\n> > the trace log.  Furthermore, run tests with '--immediate' to\n> > faithfully preserve the failed state.\n>\n> I feel that might be complicated to work with.\n\nIt works quite conveniently in practice, that was one of the points of\nthe next paragraph.\n\n> How about this:\n> We create an publicly available Git repo (e.g. github.com/git/git-test-trash`)\n\nI'm not sure I understand.  A publicly _writable_ repository?  That\nsounds like asking for trouble.\n\n> and then we push the trash directory of every failed test run to\n> this repo. Then we link the commit in the logs to help people find\n> them.\n>\n> Wouldn't that make it easier to access the trash dir?\n\nWith this patch, if there are any trash directories embedded in the\nlog, then the log will show a command near the very end that you can\ncopy-paste into a terminal, and bam! in less than 3 seconds you have\nall those trash directories downloaded and unpacked.\n\nI'm not sure how it could be made any easier than that.\n\n> > Extracting the trash directories from the trace log turned out to be a\n> > bit of a hassle, partly because of the size of these logs (usually\n> > resulting in several hundreds or even thousands of lines of\n> > base64-encoded text), and partly because these logs have CRLF, CRCRLF\n> > and occasionally even CRCRCRLF line endings, which cause 'base64 -d'\n> > from coreutils to complain about \"invalid input\".  For convenience add\n> > a small script 'ci/util/extract-trash-dirs.sh', which will extract and\n> > unpack all base64-encoded trash directories embedded in the log fed to\n> > its standard input, and include an example command to be copy-pasted\n> > into a terminal to do it all at the end of the failure report.\n> >\n> > A few of our tests create sizeable trash directories, so limit the\n> > size of each included base64-encoded block, let's say, to 1MB.  And\n> > just in case something fundamental gets broken and a lot of tests fail\n> > at once, don't include trash directories when the combined size of the\n> > included base64-encoded blocks would exceed 1MB.\n> >\n> > Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com>\n> > ---\n"}]}