Ceedling icon indicating copy to clipboard operation
Ceedling copied to clipboard

Restore flatten message and output for console summarize view

Open lukzeg opened this issue 2 years ago • 7 comments

Correct display logs displayed in the console

lukzeg avatar Feb 14 '23 15:02 lukzeg

Hi @mvandervoord ,

If you will have time, can you look at those changes, which fix how the output log is visible when user see segmentation fault logs when they don't use:

:test_runner:
  :cmdline_args: true

The look with fix:

[test/test_multiplication.c]
  Test: test_multiplication_success
  At line (17): "test_multiplication.c:17:test_multiplication_success:FAIL: [Thread debugging using libthread_db enabled]
Using host libthread_db library '/lib/x86_64-linux-gnu/libthread_db.so.1'.

Program received signal SIGSEGV, Segmentation fault.
__pthread_kill_implementation (no_tid=0, signo=11, threadid=140737351472960) at ./nptl/pthread_kill.c:44
44	./nptl/pthread_kill.c: No such file or directory.
#0  __pthread_kill_implementation (no_tid=0, signo=11, threadid=140737351472960) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=11, threadid=140737351472960) at ./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=140737351472960, signo=signo@entry=11) at ./nptl/pthread_kill.c:89
#3  0x00007ffff7dba476 in __GI_raise (sig=11) at ../sysdeps/posix/raise.c:26
#4  0x000055555555545e in multiplication (a=1, b=2) at src/cal.c:26
#5  0x00005555555553b7 in test_multiplication_success () at test/test_multiplication.c:17
#6  0x00005555555552ee in run_test (func=0x5555555553a0 <test_multiplication_success>, name=0x55555555901a 'test_multiplication_success', line_num=15) at build/test/runners/test_multiplication_runner.c:63
#7  0x0000555555555365 in main () at build/test/runners/test_multiplication_runner.c:79


-----------------------

1 Tests 1 Failures 0 Ignored

FAIL
"

when originally looks:

[test/test_multiplication.c]
  Test: test_Unknown
  At line (1): "Segmentation Fault"

--------------------
OVERALL TEST SUMMARY


If you will have time, can you look at my changes?

lukzeg avatar Feb 14 '23 16:02 lukzeg

Hi @mvandervoord ,

My apologies for closing and restoring this PR'st, but checking the release candidate, I noticed that the gdb print does not work as was expected when we postpone to add:

:test_runner:
  :cmdline_args: true

I will be grateful if you will find some time to look at my changes and consider to add them to still not released rc 0.32.

lukzeg avatar Feb 14 '23 20:02 lukzeg

@lukzeg -- It's looking good overall. Can you verify a few things on your setup for me? Does it respond with something reasonable (non-crashing... reports some segfault message with varying degrees of detail) in all of these scenarios:

  • Both debugger and cmdline args TRUE
  • debugger TRUE, cmdline_args FALSE
  • debugger TRUE, cmdline_args FALSE, gdb doesn't exist (or, override the default debugger tool with a nonsense tool to produce an error)

This last case was the one that I was trying to correct with that last change. Sorry I lost the detailed view in the process of doing that. ;)

mvandervoord avatar Feb 16 '23 16:02 mvandervoord

Hi @mvandervoord ,

My apologies for a delay. I'm quietly overloaded by my work, and learning new stuff. I will try my best to give you answer on all mentioned by you questions

lukzeg avatar Feb 21 '23 22:02 lukzeg

Hi @mvandervoord ,

Small update from mentioned by you test: Answering on your question:


- debugger TRUE, cmdline_args FALSE, gdb doesn't exist (or, override the default debugger tool with a nonsense tool to produce an error)
ERROR: Config filepath [:tools][:backtrace_settings][:executable]['zumzum'] does not exist in system search paths.
/var/lib/gems/3.0.0/gems/ceedling-0.32.0/lib/ceedling/configurator.rb:308:in `validate': unhandled exception
	from /var/lib/gems/3.0.0/gems/ceedling-0.32.0/lib/ceedling/setupinator.rb:32:in `do_setup'
	from /var/lib/gems/3.0.0/gems/ceedling-0.32.0/lib/ceedling/rakefile.rb:46:in `<top (required)>'
	from /var/lib/gems/3.0.0/gems/ceedling-0.32.0/lib/ceedling.rb:66:in `load'
	from /var/lib/gems/3.0.0/gems/ceedling-0.32.0/lib/ceedling.rb:66:in `load_project'
	from /var/lib/gems/3.0.0/gems/ceedling-0.32.0/bin/ceedling:343:in `<top (required)>'
	from /usr/local/bin/ceedling:25:in `load'
	from /usr/local/bin/ceedling:25:in `<main>'

I assumed that if the debugger is not accessible on machine this error is correc, and describes issue perfectly.

The same issue we receive for both cases if we update project.yaml with:

Scenario 1:
- use_backtrace_gdb_reporter TRUE
- cmdline_args TRUE 

Scenario 2:
- use_backtrace_gdb_reporter TRUE
- cmdline_args TRUE 

Scenario with GDB set with default arguments(not overwritten by end user) set: debugger TRUE, cmdline_args FALSE

[test/test_multiplication.c]
  Test: test_multiplication_success
  At line (17): "test_multiplication.c:17:test_multiplication_success:FAIL: [Thread debugging using libthread_db enabled]
Using host libthread_db library '/lib/x86_64-linux-gnu/libthread_db.so.1'.

Program received signal SIGSEGV, Segmentation fault.
__pthread_kill_implementation (no_tid=0, signo=11, threadid=140737351468864) at ./nptl/pthread_kill.c:44
44	./nptl/pthread_kill.c: No such file or directory.
#0  __pthread_kill_implementation (no_tid=0, signo=11, threadid=140737351468864) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=11, threadid=140737351468864) at ./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=140737351468864, signo=signo@entry=11) at ./nptl/pthread_kill.c:89
#3  0x00007ffff7db9476 in __GI_raise (sig=11) at ../sysdeps/posix/raise.c:26
#4  0x000055555555545e in multiplication (a=1, b=2) at src/cal.c:26
#5  0x00005555555553b7 in test_multiplication_success () at test/test_multiplication.c:17
#6  0x00005555555552ee in run_test (func=0x5555555553a0 <test_multiplication_success>, name=0x55555555901a 'test_multiplication_success', line_num=15) at build/test/runners/test_multiplication_runner.c:63
#7  0x0000555555555365 in main () at build/test/runners/test_multiplication_runner.c:79


-----------------------

1 Tests 1 Failures 0 Ignored

FAIL
"

As expected, *.fail file exists, with correct debug data.


Scenario with GDB set with default arguments(not overwritten by end user) set: debugger TRUE, cmdline_args TRUE

-------------------
FAILED TEST SUMMARY
-------------------
[test/test_add.c]
  Test: test_minus_success
  At line (25): "test_add.c:17:test_add_success:PASS (10000 ms)
test_add.c:25:test_minus_success:FAIL: Expected 2 Was 1 (0 ms)

-----------------------
2 Tests 1 Failures 0 Ignored 
FAIL
"

[test/test_multiplication.c]
  Test: test_multiplication_success
  At line (17): "test_multiplication.c:17:test_multiplication_success:FAIL: [Thread debugging using libthread_db enabled]
Using host libthread_db library '/lib/x86_64-linux-gnu/libthread_db.so.1'.

Program received signal SIGSEGV, Segmentation fault.
__pthread_kill_implementation (no_tid=0, signo=11, threadid=140737351468864) at ./nptl/pthread_kill.c:44
44	./nptl/pthread_kill.c: No such file or directory.
#0  __pthread_kill_implementation (no_tid=0, signo=11, threadid=140737351468864) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=11, threadid=140737351468864) at ./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=140737351468864, signo=signo@entry=11) at ./nptl/pthread_kill.c:89
#3  0x00007ffff7db9476 in __GI_raise (sig=11) at ../sysdeps/posix/raise.c:26
#4  0x00005555555554ef in multiplication (a=1, b=2) at src/cal.c:26
#5  0x0000555555555448 in test_multiplication_success () at test/test_multiplication.c:17
#6  0x00005555555552fb in run_test (func=0x555555555431 <test_multiplication_success>, name=0x555555559064 'test_multiplication_success', line_num=15) at build/test/runners/test_multiplication_runner.c:63
#7  0x00005555555553f6 in main (argc=3, argv=0x7fffffffdbd8) at build/test/runners/test_multiplication_runner.c:94

test_multiplication.c:21:test_divider_failure:PASS (0 ms)

As expected

Scenario with for instance Valgrind set with project.yml set: debugger TRUE, cmdline_args False

:tools:
  :backtrace_settings:
    :executable: valgrind
    :arguments: []
[test/test_multiplication.c]
  Test: test_Unknown
  At line (1): ":1:test_Unknown:FAIL:==984777== Memcheck, a memory error detector
==984777== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==984777== Using Valgrind-3.18.1 and LibVEX; rerun with -h for copyright info
==984777== Command: build/test/out/test_multiplication.out
==984777== 
==984777== 
==984777== Process terminating with default action of signal 11 (SIGSEGV)
==984777==    at 0x490DA7C: __pthread_kill_implementation (pthread_kill.c:44)
==984777==    by 0x490DA7C: __pthread_kill_internal (pthread_kill.c:78)
==984777==    by 0x490DA7C: pthread_kill@@GLIBC_2.34 (pthread_kill.c:89)
==984777==    by 0x48B9475: raise (raise.c:26)
==984777==    by 0x10945D: multiplication (cal.c:26)
==984777==    by 0x1093B6: test_multiplication_success (test_multiplication.c:17)
==984777==    by 0x1092ED: run_test (test_multiplication_runner.c:63)
==984777==    by 0x109364: main (test_multiplication_runner.c:79)
==984777== 
==984777== HEAP SUMMARY:
==984777==     in use at exit: 0 bytes in 0 blocks
==984777==   total heap usage: 0 allocs, 0 frees, 0 bytes allocated
==984777== 
==984777== All heap blocks were freed -- no leaks are possible
==984777== 
==984777== For lists of detected and suppressed errors, rerun with: -s
==984777== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)
Segmentation fault (core dumped)


-----------------------

1 Tests 1 Failures 0 Ignored

FAIL
"

--------------------
OVERALL TEST SUMMARY
--------------------
TESTED:  3
PASSED:  1
FAILED:  2
IGNORED: 0

In such case, the regex which is used to withdraw data about files works only for gdb. The test name is not discovered.


Scenario with for instance Valgrind set with project.yml set: debugger TRUE, cmdline_args True

:tools:
  :backtrace_settings:
    :executable: valgrind
    :arguments: []


[test/test_multiplication.c]
  Test:   test_multiplication_success
  At line (1): ":1:  test_multiplication_success:FAIL:==984960== Memcheck, a memory error detector
==984960== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==984960== Using Valgrind-3.18.1 and LibVEX; rerun with -h for copyright info
==984960== Command: build/test/out/test_multiplication.out -n test_multiplication_success
==984960== 
==984960== 
==984960== Process terminating with default action of signal 11 (SIGSEGV)
==984960==    at 0x490DA7C: __pthread_kill_implementation (pthread_kill.c:44)
==984960==    by 0x490DA7C: __pthread_kill_internal (pthread_kill.c:78)
==984960==    by 0x490DA7C: pthread_kill@@GLIBC_2.34 (pthread_kill.c:89)
==984960==    by 0x48B9475: raise (raise.c:26)
==984960==    by 0x1094EE: multiplication (cal.c:26)
==984960==    by 0x109447: test_multiplication_success (test_multiplication.c:17)
==984960==    by 0x1092FA: run_test (test_multiplication_runner.c:63)
==984960==    by 0x1093F5: main (test_multiplication_runner.c:94)
==984960== 
==984960== HEAP SUMMARY:
==984960==     in use at exit: 0 bytes in 0 blocks
==984960==   total heap usage: 0 allocs, 0 frees, 0 bytes allocated
==984960== 
==984960== All heap blocks were freed -- no leaks are possible
==984960== 
==984960== For lists of detected and suppressed errors, rerun with: -s
==984960== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)
Segmentation fault (core dumped)

test_multiplication.c:21:test_divider_failure:PASS (0 ms)


In such case, the regex which is used to withdraw data about files works only for gdb. The test name is not discovered.

I'm not sure, but it might be a good idea to extend:

:use_backtrace_gdb_reporter:

with additional field to apply unique regex, to find test file name. For instance:

test_multiplication_success (test_multiplication.c:17) -> /test_.*\s\((\w+.c):(\d+)\)/

to withdraw file and line number.

I will look around this, to make this more configuration more powerful.

lukzeg avatar Feb 21 '23 23:02 lukzeg

Hi @mvandervoord , If you will have some time, can you look at latest changes.

I updated implementation and documentation, giving developer option to set additional regex, required to collect :

  • test_name
  • line_number

From crashes. I added as well UT, to cover newly added functionality.

lukzeg avatar Feb 26 '23 01:02 lukzeg

Hi @mvandervoord ,

My apologies for a silence from my side. Did you have maybe some time to look at my changes and do you think that they might be added to your new release candidate? Or should I point them to master branch?

lukzeg avatar Mar 20 '23 22:03 lukzeg

Thanks to multiple community members all this has been addressed in the latest Ceedling pre-release.

Lots of logging and console improvements were put in place over the last several months. More importantly, the latest pre-release of Ceedling now includes robust support for dissecting and reporting crashed tests. :project:use_backtrace recognizes :none, :simple, and :gdb. Ceedling defaults to :simple. If :gdb is selected (and gdb is installed), Ceedling extracts the most important lines from the backtrace report and presents them in a nicely packaged console report when using report_tests_pretty_stdout plugin. See the Release Notes and Ceedling Packet for details.

The full backtrace can be viewed with debug verbosity.

I am going to close this PR rather than merge it, but all the discussion and code snippets from this and another PR plus a couple of issues was super helpful to this whole process!

mkarlesky avatar Jun 13 '24 14:06 mkarlesky