Cellular Network Infrastructure » OsmoGSMTester

When running some tests, sometimes osmo-gsm-tester hangs forever when sending a method call to ofono. That's basically because it issues a sync call and waits for the response, which never arrives basically because ofonod process crashes but the process is still alive hanging. When the ofonod is in this state, calling any method from ofono using mdbus2 also shows the same behaviour.

I attached gdb and got a backtrace of the ofonod process while in this bogus state:

# gdb -p 1052
GNU gdb (Debian 7.7.1+dfsg-5) 7.7.1
Copyright (C) 2014 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying" 
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word".
Attaching to process 1052
Reading symbols from /usr/local/sbin/ofonod...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libudev.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/x86_64-linux-gnu/libudev.so.1
Reading symbols from /lib/x86_64-linux-gnu/libglib-2.0.so.0...(no debugging symbols found)...done.
Loaded symbols for /lib/x86_64-linux-gnu/libglib-2.0.so.0
Reading symbols from /lib/x86_64-linux-gnu/libdbus-1.so.3...(no debugging symbols found)...done.
Loaded symbols for /lib/x86_64-linux-gnu/libdbus-1.so.3
Reading symbols from /lib/x86_64-linux-gnu/libdl.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu
/libdl-2.19.so...done.
done.
Loaded symbols for /lib/x86_64-linux-gnu/libdl.so.2
Reading symbols from /lib/x86_64-linux-gnu/libc.so.6...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/
libc-2.19.so...done.
done.
Loaded symbols for /lib/x86_64-linux-gnu/libc.so.6
Reading symbols from /lib/x86_64-linux-gnu/librt.so.1...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu
/librt-2.19.so...done.
done.
Loaded symbols for /lib/x86_64-linux-gnu/librt.so.1
Reading symbols from /lib/x86_64-linux-gnu/libpthread.so.0...Reading symbols from /usr/lib/debug//lib/x86_64-linu
x-gnu/libpthread-2.19.so...done.
done.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Loaded symbols for /lib/x86_64-linux-gnu/libpthread.so.0
Reading symbols from /lib/x86_64-linux-gnu/libpcre.so.3...(no debugging symbols found)...done.
Loaded symbols for /lib/x86_64-linux-gnu/libpcre.so.3
Reading symbols from /lib64/ld-linux-x86-64.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/ld-2
.19.so...done.
done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
__lll_lock_wait_private () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:95
95      ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S: No such file or directory.
(gdb) bt
#0  __lll_lock_wait_private () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:95
#1  0x00007fb5880e44da in _L_lock_10381 () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x00007fb5880e2015 in __GI___libc_malloc (bytes=600) at malloc.c:2887
#3  0x00007fb5880d7d1a in __GI_open_memstream (bufloc=bufloc@entry=0x7ffe889a7080,
    sizeloc=sizeloc@entry=0x7ffe889a7088) at memstream.c:78
#4  0x00007fb588149e2d in __GI___vsyslog_chk (pri=27, flag=1, fmt=0x513b24 "Aborting (signal %d) [%s]",
    ap=0x7ffe889a7158) at ../misc/syslog.c:167
#5  0x0000000000498a89 in ofono_error ()
#6  0x0000000000498d89 in signal_handler ()
#7  <signal handler called>
#8  0x00007fb58809b067 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#9  0x00007fb58809c448 in __GI_abort () at abort.c:89
#10 0x00007fb5880d91b4 in __libc_message (do_abort=do_abort@entry=1,
    fmt=fmt@entry=0x7fb5881ce210 "*** Error in `%s': %s: 0x%s ***\n") at ../sysdeps/posix/libc_fatal.c:175
#11 0x00007fb5880de98e in malloc_printerr (action=1, str=0x7fb5881ca2ec "corrupted double-linked list",
    ptr=<optimized out>) at malloc.c:4996
#12 0x00007fb5880dec14 in malloc_consolidate (av=av@entry=0x7fb58840b620 <main_arena>) at malloc.c:4157
#13 0x00007fb5880dfe98 in _int_malloc (av=av@entry=0x7fb58840b620 <main_arena>, bytes=bytes@entry=8192)
    at malloc.c:3423
#14 0x00007fb5880e29dc in __libc_calloc (n=<optimized out>, elem_size=<optimized out>) at malloc.c:3219
#15 0x00007fb5880d7d43 in __GI_open_memstream (bufloc=bufloc@entry=0x7ffe889a7bf0,
    sizeloc=sizeloc@entry=0x7ffe889a7bf8) at memstream.c:85
#16 0x00007fb588149e2d in __GI___vsyslog_chk (pri=27, flag=1,
    fmt=0x522ca8 "Requested file structure differs from SIM: %x", ap=0x7ffe889a7cc8) at ../misc/syslog.c:167
#17 0x0000000000498a89 in ofono_error ()
#18 0x00000000004dbe6c in sim_fs_op_info_cb ()
#19 0x00000000004480a7 in get_file_attributes_cb ()
#20 0x0000000000443ef3 in service_send_callback ()
#21 0x000000000044344f in received_data.part ()
#22 0x00007fb5888a6b6d in g_main_context_dispatch () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#23 0x00007fb5888a6f48 in ?? () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#24 0x00007fb5888a7272 in g_main_loop_run () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#25 0x0000000000410bb6 in main ()

It looks like the heap is corrupted and then libc calls abort(), then ofono catches the signal and tries to alloc some memory using the corrupted heap which has the lock taken and thus it deadlocks there.

Seems to be related to the following lines I can see when using journalctl -u ofono:

May 04 10:52:10 osmo-gsm-tester-rnd ofonod[1052]: Requested file structure differs from SIM: 6fb7
May 04 10:52:25 osmo-gsm-tester-rnd ofonod[1052]: Requested file structure differs from SIM: 6fb7
May 04 10:55:17 osmo-gsm-tester-rnd ofonod[1052]: Requested file structure differs from SIM: 6fb7
May 04 10:55:30 osmo-gsm-tester-rnd ofonod[1052]: Requested file structure differs from SIM: 6fb7