Improve error messages when test programs are bogus

[jmmv]

From jmmv@google.com on February 06, 2011 10:58:44

atf-run's reporting of error messages is suboptimal, and Kyua is still pretty similar to it in this regard. There have been some issues raised recently regarding the error messages reported when we try to execute invalid test programs.

Take a look at: http://mail-index.netbsd.org/atf-devel/2011/02/06/msg000237.html http://mail-index.netbsd.org/atf-devel/2011/02/06/msg000236.html Audit such error messages in Kyua and make them clearer. At the very least:

• If a test program does not exist, error out (current behavior) because the Kyuafile is just incorrectly defined.
• If the test program exists but fails to execute (for whatever reason, not just the lack of executable permissions), clearly report it as such instead of saying "failed to parse test case list".
• If the test program fails to provide the test case list, make sure to report it as such instead of a cryptic parse error.

Original issue: http://code.google.com/p/kyua/issues/detail?id=13

[jmmv]

From yanegomi on February 06, 2011 11:48:35

Another case is when the testcase fails via atf_fail and .

Compare the former output (snippet):

tc-se:+ _atf_run_tc builtins_alias__0:body
tc-se:+ _tcname=builtins_alias__0
tc-se:+ _tcpart=body
tc-se:+ [ body != body -a body != cleanup ]
tc-se:+ _atf_has_tc builtins_alias__0
tc-se:+ return 1
tc-se:+ _atf_syntax_error 'Unknown test case builtins_alias__0:body'\' tc-se:+ echo 'regress.sh: ERROR: Unknown test casebuiltins_alias__0:body''
tc-se:regress.sh: ERROR: Unknown test case `builtins_alias__0:body'
tc-se:+ echo 'regress.sh: See atf-test-program(1) for usage details.'
tc-se:regress.sh: See atf-test-program(1) for usage details.
tc-se:+ exit 1
tc-end: builtins_alias__0, failed, Test case exited normally but failed to create the results file: Failed to open /tmp/atf-run.fjJAJ2/tcr
tc-start: builtins_alias__1
tc-se:+ main -r/tmp/atf-run.fjJAJ2/tcr -s/scratch/freebsd/atf-head/tools/regression/bin/sh builtins_alias__1:body

to the latter (full testcase being run manually via ${testcase}_body; exit

$ atf-run
Content-Type: application/X-atf-tps; version="2"

info: atf.version, Automated Testing Framework 0.12 (atf-0.12)
info: tests.root, /scratch/freebsd/atf-head/tools/regression/bin/sh
info: time.start, Sun Feb 6 11:36:22 PST 2011
info: uname.sysname, FreeBSD
info: uname.nodename, bayonetta.local
info: uname.release, 9.0-CURRENT
info: uname.version, FreeBSD 9.0-CURRENT #0 r218082M: Sun Jan 30 00:20:08 PST 2011 gcooper@bayonetta.local:/usr/obj/usr/src/sys/BAYONETTA
info: uname.machine, amd64
info: env, USER=gcooper
info: env, MAIL=/var/mail/gcooper
info: env, SSH_AGENT_PID=2772
info: env, SHLVL=2
info: env, OLDPWD=/scratch/freebsd/atf-head/tools/regression/bin
info: env, HOME=/usr/home/gcooper
info: env, GTK_PATH=:/usr/local/lib/gtk-2.0
info: env, PAGER=more
info: env, DBUS_SESSION_BUS_ADDRESS=unix:path=/var/tmp/dbus-Tmu9Ifs7EO,guid=b837076b13d3a1bae2785bae0000005d
info: env, ENV=/usr/home/gcooper/.shrc
info: env, COLORTERM=Terminal
info: env, GLADE_MODULE_PATH=:
info: env, LOGNAME=gcooper
info: env, _=/usr/bin/atf-run
info: env, WINDOWID=48740759
info: env, BLOCKSIZE=K
info: env, TERM=xterm
info: env, WINDOWPATH=9
info: env, SESSION_MANAGER=local/bayonetta.local:/tmp/.ICE-unix/2780
info: env, GLADE_PIXMAP_PATH=:
info: env, PATH=/sbin:/bin:/usr/sbin:/usr/bin:/usr/games:/usr/local/sbin:/usr/local/bin:/usr/home/gcooper/bin:/usr/home/gcooper/bin
info: env, DISPLAY=:0.0
info: env, GLADE_CATALOG_PATH=:
info: env, SSH_AUTH_SOCK=/tmp/ssh-qHA03bA3RO/agent.2771
info: env, SHELL=/usr/local/bin/bash
info: env, PWD=/scratch/freebsd/atf-head/tools/regression/bin/sh
info: env, LIBGLADE_MODULE_PATH=:/usr/local/lib/libglade/2.0
info: env, XDG_DATA_DIRS=/usr/share:/usr/local/share
info: env, FTP_PASSIVE_MODE=YES
info: env, EDITOR=/usr/local/bin/vim
tps-count: 1

• main -l -s.
• _numargs=2
• _lflag=false
• getopts :lr:s✌️ arg
• _lflag=true
• getopts :lr:s✌️ arg
• Source_Dir=.
• getopts :lr:s✌️ arg
• expr 3 - 1
• shift 2
• pwd
• Source_Dir=/scratch/freebsd/atf-head/tools/regression/bin/sh/.
• [ -f /scratch/freebsd/atf-head/tools/regression/bin/sh/./regress.sh ]
• _atf_internal_set srcdir /scratch/freebsd/atf-head/tools/regression/bin/sh/.
• _var=srcdir
• shift
• eval '__tc_internal_var__srcdir="${*}"'
• __tc_internal_var__srcdir=/scratch/freebsd/atf-head/tools/regression/bin/sh/.
• atf_init_test_cases
• local testcase testcase_path
• find -Es . -regex '.*.[0-9]+'
• echo ./builtins/alias.0
• sed -e s,^./,,g -e s,/,,g -e 's,.,__,g' -e s,-,___,g
• testcase=builtins_alias__0
• atf_test_case builtins_alias__0
• Defined_Test_Cases=' builtins_alias__0'
• eval 'builtins_alias__0_head() { :; }'
• eval 'builtins_alias__0_body() { :; }'
• [ '' = cleanup ]
• eval 'builtins_alias__0_cleanup() {
  _atf_error 1 '''Test case builtins_alias__0 declared without a cleanup routine'''; }'
• eval 'builtins_alias__0_head() { atf_set '''descr''' '''builtins_alias__0 testcase'''; }'
• eval 'builtins_alias__0_body() { do_test '''./builtins/alias.0'''; }'
• builtins_alias__0_body
• do_test ./builtins/alias.0
• local atf_args expected_exit_status testcase_path testcase_prefix
• testcase_path=./builtins/alias.0
• expected_exit_status=0
• testcase_prefix=./builtins/alias
• echo 'INFO: expected_exit_status: 0, testcase_path: ./builtins/alias.0, testcase_prefix: ./builtins/alias'
• atf_args='-s exit:0'
• output=./builtins/alias.stderr
• [ -f ./builtins/alias.stderr ]
• output=./builtins/alias.stdout
• [ -f ./builtins/alias.stdout ]
• echo 'INFO: atf_args: -s exit:0'
• atf_check -s exit:0 /bin/sh ./builtins/alias.0
• /usr/libexec/atf-check -s exit:0 /bin/sh ./builtins/alias.0
  Fail: stdout not empty
  --- /dev/null 2011-02-06 11:36:22.000000000 -0800
  +++ /tmp/check.GP6uO0/stdout 2011-02-06 11:36:22.000000000 -0800
  @@ -0,0 +1,4 @@
  +bar=''
  +foo=bar
  +quux='1 2 3'
  +foo=bar
• atf_fail 'atf-check failed; see the output of the test for details'
• _atf_create_resfile failed -1 'atf-check failed; see the output of the test for details'
• _result=failed
• shift
• [ -1 -eq -1 ]
• _arg=''
• shift
• [ 1 -gt 0 ]
• _reason=': atf-check failed; see the output of the test for details'
• [ -n '' ]
• echo 'failed: atf-check failed; see the output of the test for details'
• exit 1
  tp-start: regress.sh, 0
  tp-end: regress.sh, Invalid format for test case list: 1: Unexpected token command'; expected:'; 2: Unexpected token failed'; expected eof,;' or new line
  info: time.end, Sun Feb 6 11:36:22 PST 2011

The archive attached contains a snapshot of the testcases in the latter case for reproduction.

Attachment: sh-testcases.tgz

[jmmv]

From yanegomi on February 06, 2011 19:51:48

Looking back on my experience today, the above comment is a subset of item 3 as this was fed by failing to understand the importance of scope with respect to shell functions (please note the conclusion at the end of the first thread).

[jmmv]

From jmmv@google.com on June 11, 2011 01:54:15

This issue was updated by revision r145 .

The improvement of error messages when the test case terminates prematurely
addresses part of this issue.

[jmmv]

From jmmv@google.com on June 11, 2011 09:02:16

This issue was updated by revision r147 .

This change is required to permit the engine to report nicer error
messages when there are problems executing test program binaries.

[jmmv]

From jmmv@google.com on June 11, 2011 09:42:57

This issue was updated by revision r148 .

This change addresses part of the problems reported in this ticket.
It clarifies a potential source of confusion when test programs are
really broken and fail even in their 'list' operation.

[jmmv]

From jmmv@google.com on June 11, 2011 09:57:07

This issue was updated by revision r149 .

Ensures some error conditions are reported in a useful manner.

[jmmv]

From jmmv@julipedia.org on June 11, 2011 09:57:47

I think the major culprits mentioned by this issue have now been addressed, so closing :-)

Status: Fixed