Debug Batocera

Batocera offers logs which can help explain the more obvious problems, but sometimes you need something a bit more robust to analyze a particular problem, such as if an emulator is taking too long to load something or EmulationStation is incorrectly caching something when it shouldn't.

More extensive debugging tools can be downloaded from http://mirrors.o2switch.fr/batocera/extensions/ and then placed into /userdata/system to analyze such problems. On Batocera v36 and higher, these extensions will be available automatically upon next boot with these files present.

Strace is a Linux syscall tracer which monitors interactions between programs and the Linux kernel, including system calls, signal deliveries and changes of process states. More extensive documentation can be found on its homepage, but this article will be a crash-course introduction to using it in the context of Batocera.

The usual method to use strace to analyze an individual program.

Launch the program as usual with its stderr pointed to a file output (ie. put 2> file.log at the end of the command) and then add strace to the start of it.

For instance, if wanting to analyze possible errors that EmulationStation is encountering:

strace ./emulationstation 2> strace.log

Or if needing to see what an individual emulator is doing:

strace /usr/bin/flycast 2> flycast-strace.log

It is also possible to just use > to see all output, but that is usually far too overwhelming to be useful.

The -p flag can be used to attach strace to a process.

For example, if the application in question has a PID of 26380:

strace -p 26380

The resulting output will show a record of all interactions that program did with the system. This is usually overbearing, so it is useful to use grep or similar tools to filter down the output to what is relevant to the problem.

For instance, if the problem is related to the opening of a file:

cat strace.log | grep "open"

which might result in something like:

openat(AT_FDCWD, "/media/ssd/dev/batocera-emulationstation/resources/genres.xml", O_RDONLY) = 6
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libxml2.so.2", O_RDONLY|O_CLOEXEC) = 13
openat(AT_FDCWD, "/media/ssd/dev/batocera-emulationstation/resources/mamenames.xml", O_RDONLY) = 16
openat(AT_FDCWD, "/media/ssd/dev/batocera-emulationstation/resources/mamebioses.xml", O_RDONLY) = 16

If the problem is not obvious (as is the case many times) then the operation code number can be searched instead:

cat strace.log | grep "fd=6"

which might result in something like:

poll([{fd=6, events=POLLOUT}], 1, 0)    = 1 ([{fd=6, revents=POLLOUT}])
poll([{fd=6, events=POLLIN}], 1, -1)    = 1 ([{fd=6, revents=POLLIN}])
poll([{fd=6, events=POLLOUT}], 1, -1)   = 1 ([{fd=6, revents=POLLOUT}])
poll([{fd=6, events=POLLIN}], 1, -1)    = 1 ([{fd=6, revents=POLLIN}])

If looking at a time-sensitive issue (such as an emulator being slow to launch), then

strace -c /usr/bin/flycast > /dev/null

which might result in something like:

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 89.76    0.008016           4      1912           getdents
  8.71    0.000778           0     11778           lstat
  0.81    0.000072           0      8894           write
  0.60    0.000054           0       943           open
[...]
  0.00    0.000000           0         1           sysinfo
  0.00    0.000000           0         1           arch_prctl
------ ----------- ----------- --------- --------- ----------------
100.00    0.008930                 25440         3 total

https://sourceware.org/gdb/

Open the program:

gdb /usr/bin/program

Then run additional commands in the interactive shell which appears:

run

Some useful functions:

• run → Executes the program from start to end.
• break → Sets breakpoint on a particular line.
• next → executes next line of code, but don’t dive into functions.
• step → go to next instruction, diving into the function.
• continue → continue normal execution.
• list → displays the code.
• clear → to clear all breakpoints.
• quit → exits out of gdb.

In case of segfault, the backtrace (bt) commands is really helpfull:

$ gdb /usr/bin/mame/mame
Thread 1 "mame" received signal SIGSEGV, Segmentation fault.
0x000000000b2aca8b in ImGui::ShutdownDockContext() ()
(gdb) bt
#0  0x000000000b2aca8b in ImGui::ShutdownDockContext() ()
#1  0x000000000b31f8e9 in imguiDestroy() ()
#2  0x000000000a7aba09 in renderer_bgfx::exit() ()
#3  0x000000000a78d365 in sdl_osd_interface::window_exit() ()
#4  0x000000000a7940f5 in osd_common_t::osd_exit() ()
#5  0x000000000a784869 in sdl_osd_interface::osd_exit() ()
#6  0x000000000a69d47a in running_machine::run(bool) ()
#7  0x000000000b409f17 in mame_machine_manager::execute() ()
#8  0x000000000b4bb658 in cli_frontend::start_execution(mame_machine_manager*, std::vector<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > const&) ()
#9  0x000000000b4bb891 in cli_frontend::execute(std::vector<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&) ()
#10 0x000000000b4057d3 in emulator_info::start_frontend(emu_options&, osd_interface&, std::vector<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&) ()
#11 0x00000000021c91ed in main ()