Missing atf-check output: example:failing_test -> failed: atf-check failed; see the output of the test for details

[Alan Somers]

On Fri, Jul 25, 2014 at 12:55 PM, Fabian Keil
<freebsd-listen at fabiankeil.de> wrote:
> I'm currently evaluating using kyua to test a FreeBSD-specific
> shell script, however I'm having trouble analysing failing tests.
>
> For example, using:
>
> | #!/usr/bin/env atf-sh
> |
> | atf_test_case failing_test
> | failing_test_body() {
> |    atf_check -s exit:1 -o empty -e empty 'true'
> | }
> |
> | atf_init_test_cases() {
> |    atf_add_test_case failing_test
> | }
>
> I get:
>
> | fk at r500 ~/git/zogftw/tests $kyua --loglevel debug test -k Kyuafile example:failing_test
> | example:failing_test  ->  failed: atf-check failed; see the output of the test for details  [0.150s]
> |
> | 0/1 passed (1 failed)
> | Committed action 21
>
> The test failure obviously is expected, but I'm missing the referenced
> "output of the test". The relevant log excerpt:
>
> ########
> 20140725-183911 D 71935 utils/sqlite/statement.cpp:192: Step statement; no more rows
> 20140725-183911 D 71935 utils/sqlite/database.cpp:275: Creating statement: INSERT INTO test_cases (test_program_id, name, metadata_id) VALUES (:test_program_id, :name, :metadata_id)
> 20140725-183911 D 71935 utils/sqlite/statement.cpp:192: Step statement; no more rows
> 20140725-183911 I 71935 utils/cmdline/ui.cpp:94: stdout: example:failing_test  ->
> 20140725-183911 D 71935 utils/process/child.cpp:350: Spawned process 71950: stdout=/tmp/kyua.7ESBAU/stdout.txt, stderr=/tmp/kyua.7ESBAU/stderr.txt
> 20140725-183911 D 71935 utils/process/child.cpp:167: Executing /usr/local/libexec/kyua-atf-tester -t300 test -vhas.cleanup=false -vunprivileged-user=tests /home/fk/git/zogftw/tests/example failing_test /tmp/kyua.7ESBAU/result.txt
> 20140725-183911 D 71935 utils/process/child.cpp:145: Waiting for pid=71950
> 20140725-183911 D 71935 store/transaction.cpp:896: Storing __STDOUT__ (/tmp/kyua.7ESBAU/stdout.txt) of test case 42
> 20140725-183911 D 71935 utils/sqlite/database.cpp:275: Creating statement: INSERT INTO files (contents) VALUES (:contents)
> 20140725-183911 D 71935 utils/sqlite/statement.cpp:192: Step statement; no more rows
> 20140725-183911 D 71935 utils/sqlite/database.cpp:275: Creating statement: INSERT INTO test_case_files (test_case_id, file_name, file_id) VALUES (:test_case_id, :file_name, :file_id)
> 20140725-183911 D 71935 utils/sqlite/statement.cpp:192: Step statement; no more rows
> 20140725-183911 D 71935 store/transaction.cpp:896: Storing __STDERR__ (/tmp/kyua.7ESBAU/stderr.txt) of test case 42
> 20140725-183911 D 71935 utils/sqlite/database.cpp:275: Creating statement: INSERT INTO files (contents) VALUES (:contents)
> 20140725-183911 D 71935 utils/sqlite/statement.cpp:192: Step statement; no more rows
> 20140725-183911 D 71935 utils/sqlite/database.cpp:275: Creating statement: INSERT INTO test_case_files (test_case_id, file_name, file_id) VALUES (:test_case_id, :file_name, :file_id)
> 20140725-183911 D 71935 utils/sqlite/statement.cpp:192: Step statement; no more rows
> 20140725-183911 D 71935 utils/sqlite/database.cpp:275: Creating statement: INSERT INTO test_results (test_case_id, result_type,                           result_reason, start_time,                           end_time) VALUES (:test_case_id, :result_type, :result_reason,         :start_time, :end_time)
> 20140725-183911 D 71935 utils/sqlite/statement.cpp:192: Step statement; no more rows
> 20140725-183911 I 71935 utils/cmdline/ui.cpp:94: stdout: failed: atf-check failed; see the output of the test for details  [0.150s]
> 20140725-183911 I 71935 utils/cmdline/ui.cpp:94: stdout:
> 20140725-183911 I 71935 utils/cmdline/ui.cpp:94: stdout: 0/1 passed (1 failed)
> 20140725-183911 I 71935 utils/cmdline/ui.cpp:94: stdout: Committed action 21
> 20140725-183911 I 71935 cli/main.cpp:326: Clean exit with code 1
> ########
>
> I'm looking for something like this:
>
> | fk at r500 ~ $/usr/local/libexec/atf-check -s exit:1 -o empty -e empty 'true'
> | Executing command [ true ]
> | Fail: incorrect exit status: 0, expected: 1
> | stdout:
> |
> | stderr:
> |
>
> I didn't read all the docs available yet and I may be missing something,
> but seeing test failures is something I'd expect to work out of the box.
> Can someone familiar with kyua confirm that this is working as expected?
>
> I'm currently using:
>
> fk at r500 ~ $uname -a
> FreeBSD r500.local 11.0-CURRENT FreeBSD 11.0-CURRENT #651 r269009+6d12a21(fk): Wed Jul 23 17:49:07 CEST 2014     fk at r500.local:/usr/obj/usr/src/sys/ZOEY  amd64
> fk at r500 ~ $pkg info kyua\*
> kyua-20140215,1
> kyua-atf-compat-0.2_2
> kyua-cli-0.8_3
> kyua-testers-0.2_3
>
> Fabian


The test output is stored in Kyua's sqlite database.  There are two
ways to see it:
1) Run " kyua report-html"
2) Sometimes its easier just to rerun the testcase in debug mode.  Do
"kyua debug example:failing_test"

-Alan