Actions
Bug #5872
closedtrxcon: heap-use-after-free in osmo_wqueue_bfd_cb after trx_if shutdown and L1CTL conn closed
Start date:
01/23/2023
Due date:
% Done:
100%
Resolution:
Spec Reference:
Description
After I killed a layer23 app (modem), I got this error caught by Asan in trxcon:
20230123184720790 DL1D NOTICE trxcon(0)[0x6120000c8f20]: L1CTL connection error: read() failed (rc=-1): Connection reset by peer (l1ctl_server.c:55) 20230123184720790 DL1C NOTICE trxcon(0)[0x6120000c8f20]: Closing L1CTL connection (l1ctl_server.c:206) 20230123184720790 DSCH NOTICE trxcon(0)[0x6120000c8f20]: Shutdown scheduler (sched_trx.c:206) 20230123184720790 DSCH NOTICE trxcon(0)[0x6120000c8f20]: Delete TDMA timeslot #0 (sched_trx.c:264) 20230123184720790 DTRXC NOTICE trx_interface(0)[0x6120000c9220]{ACTIVE}: Shutdown transceiver interface (trx_if.c:830) ================================================================= ==380250==ERROR: AddressSanitizer: heap-use-after-free on address 0x61100000070c at pc 0x7ffff6b922c0 bp 0x7fffffffde20 sp 0x7fffffffde10 READ of size 4 at 0x61100000070c thread T0 #0 0x7ffff6b922bf in osmo_wqueue_bfd_cb /git/libosmocore/src/core/write_queue.c:61 #1 0x7ffff6b5909f in poll_disp_fds /git/libosmocore/src/core/select.c:361 #2 0x7ffff6b5919f in _osmo_select_main /git/libosmocore/src/core/select.c:399 #3 0x7ffff6b59248 in osmo_select_main /git/libosmocore/src/core/select.c:438 #4 0x555555614025 in main /git/osmocom-bb/src/host/trxcon/src/trxcon_main.c:389 #5 0x7ffff703c28f (/usr/lib/libc.so.6+0x2328f) #6 0x7ffff703c349 in __libc_start_main (/usr/lib/libc.so.6+0x23349) #7 0x55555560d9a4 in _start (/build/new/out/bin/trxcon+0xb99a4) 0x61100000070c is located 140 bytes inside of 240-byte region [0x611000000680,0x611000000770) freed by thread T0 here: #0 0x7ffff78be672 in __interceptor_free /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_malloc_linux.cpp:52 #1 0x7ffff7ed0002 (/usr/lib/libtalloc.so.2+0x4002) #2 0x555555610cb8 in l1ctl_client_read_cb /git/osmocom-bb/src/host/trxcon/src/l1ctl_server.c:63 #3 0x7ffff6b91e7a in osmo_wqueue_bfd_cb /git/libosmocore/src/core/write_queue.c:47 #4 0x7ffff6b5909f in poll_disp_fds /git/libosmocore/src/core/select.c:361 #5 0x7ffff6b5919f in _osmo_select_main /git/libosmocore/src/core/select.c:399 #6 0x7ffff6b59248 in osmo_select_main /git/libosmocore/src/core/select.c:438 #7 0x555555614025 in main /git/osmocom-bb/src/host/trxcon/src/trxcon_main.c:389 #8 0x7ffff703c28f (/usr/lib/libc.so.6+0x2328f) previously allocated by thread T0 here: #0 0x7ffff78bfa89 in __interceptor_malloc /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_malloc_linux.cpp:69 #1 0x7ffff7ed0b5f (/usr/lib/libtalloc.so.2+0x4b5f) SUMMARY: AddressSanitizer: heap-use-after-free /git/libosmocore/src/core/write_queue.c:61 in osmo_wqueue_bfd_cb Shadow bytes around the buggy address: 0x0c227fff8090: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fa fa 0x0c227fff80a0: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd 0x0c227fff80b0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c227fff80c0: fd fd fd fd fd fd fa fa fa fa fa fa fa fa fa fa 0x0c227fff80d0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd =>0x0c227fff80e0: fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd fa fa 0x0c227fff80f0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c227fff8100: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c227fff8110: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c227fff8120: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c227fff8130: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa Shadow byte legend (one shadow byte represents 8 application bytes): Addressable: 00 Partially addressable: 01 02 03 04 05 06 07 Heap left redzone: fa Freed heap region: fd Stack left redzone: f1 Stack mid redzone: f2 Stack right redzone: f3 Stack after return: f5 Stack use after scope: f8 Global redzone: f9 Global init order: f6 Poisoned by user: f7 Container overflow: fc Array cookie: ac Intra object redzone: bb ASan internal: fe Left alloca redzone: ca Right alloca redzone: cb ==380250==ABORTING Program received signal SIGABRT, Aborted. 0x00007ffff70a164c in ?? () from /usr/lib/libc.so.6
This is not happening all the time, it only happened once so far.
Looks like some ofd is left registered?
Updated by pespin 10 months ago
(gdb) frame 8 #8 0x00007ffff6b922c0 in osmo_wqueue_bfd_cb (fd=0x6110000006f8, what=3) at /home/pespin/dev/sysmocom/git/libosmocore/src/core/write_queue.c:61 61 fd->when &= ~OSMO_FD_WRITE; (gdb) print queue->write_cb $1 = (int (*)(struct osmo_fd *, struct msgb *)) 0x55555560f717 <l1ctl_client_write_cb> (gdb) print queue->read_cb $2 = (int (*)(struct osmo_fd *)) 0x555555610b4b <l1ctl_client_read_cb>
Updated by fixeria 10 months ago
- Status changed from In Progress to Feedback
- Assignee changed from fixeria to pespin
I was not able to reproduce this heap-use-after-free, so questions:
- what exact CFLAGS you used when building trxcon, among with the --enable-sanitize ones?
- at which specific moment did you killed the modem app?
May I also ask you to run trxcon with -d DAPP:DL1C:DL1D:DTRXC:DTRXD
to see a bit more logging? Thanks!
Updated by pespin 10 months ago
I'm building with --enable-sanitize and following options:
export CPPFLAGS="-ggdb3 -Og -fno-omit-frame-pointer" export CFLAGS="-ggdb3 -Og -fno-omit-frame-pointer" export CXXFLAGS="-ggdb3 -Og -fno-omit-frame-pointer"
I start "modem" app (under gdb) and trxcon & company. Let it run a few seconds, then I CTRL+C on "modem" app until I see trxcon printing lots of errors bieng unable to enqueue more messages due to queue being full (due to "modem" being sleeping by gdb). Then I press "r" to restart "modem" app, and the crash in trxcon occurs.
I added the -d flags you requested:
20230130180939417 DL1D NOTICE trxcon(0)[0x612000019ba0]: L1CTL connection error: read() failed (rc=-1): Connection reset by peer (l1ctl_server.c:55) 20230130180939417 DL1C NOTICE trxcon(0)[0x612000019ba0]: Closing L1CTL connection (l1ctl_server.c:206) 20230130180939417 DSCH NOTICE trxcon(0)[0x612000019ba0]: Shutdown scheduler (sched_trx.c:206) 20230130180939417 DSCH NOTICE trxcon(0)[0x612000019ba0]: Delete TDMA timeslot #0 (sched_trx.c:264) 20230130180939417 DTRXC NOTICE trx_interface(0)[0x612000019ea0]{ACTIVE}: Shutdown transceiver interface (trx_if.c:830) ================================================================= ==57254==ERROR: AddressSanitizer: heap-use-after-free on address 0x6110000005cc at pc 0x7ffff6baa463 bp 0x7fffffffde30 sp 0x7fffffffde20 READ of size 4 at 0x6110000005cc thread T0 #0 0x7ffff6baa462 in osmo_wqueue_bfd_cb /home/pespin/dev/sysmocom/git/libosmocore/src/core/write_queue.c:61 #1 0x7ffff6b74fc2 in poll_disp_fds /home/pespin/dev/sysmocom/git/libosmocore/src/core/select.c:361 #2 0x7ffff6b750c2 in _osmo_select_main /home/pespin/dev/sysmocom/git/libosmocore/src/core/select.c:399 #3 0x7ffff6b7516b in osmo_select_main /home/pespin/dev/sysmocom/git/libosmocore/src/core/select.c:438 #4 0x555555614025 in main /home/pespin/dev/sysmocom/git/osmocom-bb/src/host/trxcon/src/trxcon_main.c:389 #5 0x7ffff703c28f (/usr/lib/libc.so.6+0x2328f) #6 0x7ffff703c349 in __libc_start_main (/usr/lib/libc.so.6+0x23349) #7 0x55555560d9a4 in _start (/home/pespin/dev/sysmocom/build/new/out/bin/trxcon+0xb99a4) 0x6110000005cc is located 140 bytes inside of 240-byte region [0x611000000540,0x611000000630) freed by thread T0 here: #0 0x7ffff78be672 in __interceptor_free /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_malloc_linux.cpp:52 #1 0x7ffff7ed8002 (/usr/lib/libtalloc.so.2+0x4002) #2 0x555555610cb8 in l1ctl_client_read_cb /home/pespin/dev/sysmocom/git/osmocom-bb/src/host/trxcon/src/l1ctl_server.c:63 #3 0x7ffff6baa01d in osmo_wqueue_bfd_cb /home/pespin/dev/sysmocom/git/libosmocore/src/core/write_queue.c:47 #4 0x7ffff6b74fc2 in poll_disp_fds /home/pespin/dev/sysmocom/git/libosmocore/src/core/select.c:361 #5 0x7ffff6b750c2 in _osmo_select_main /home/pespin/dev/sysmocom/git/libosmocore/src/core/select.c:399 #6 0x7ffff6b7516b in osmo_select_main /home/pespin/dev/sysmocom/git/libosmocore/src/core/select.c:438 #7 0x555555614025 in main /home/pespin/dev/sysmocom/git/osmocom-bb/src/host/trxcon/src/trxcon_main.c:389 #8 0x7ffff703c28f (/usr/lib/libc.so.6+0x2328f) previously allocated by thread T0 here: #0 0x7ffff78bfa89 in __interceptor_malloc /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_malloc_linux.cpp:69 #1 0x7ffff7ed8b5f (/usr/lib/libtalloc.so.2+0x4b5f) SUMMARY: AddressSanitizer: heap-use-after-free /home/pespin/dev/sysmocom/git/libosmocore/src/core/write_queue.c:61 in osmo_wqueue_bfd_cb Shadow bytes around the buggy address: 0x0c227fff8060: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c227fff8070: fd fd fd fd fd fd fa fa fa fa fa fa fa fa fa fa 0x0c227fff8080: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c227fff8090: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fa fa 0x0c227fff80a0: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd =>0x0c227fff80b0: fd fd fd fd fd fd fd fd fd[fd]fd fd fd fd fd fd 0x0c227fff80c0: fd fd fd fd fd fd fa fa fa fa fa fa fa fa fa fa 0x0c227fff80d0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c227fff80e0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c227fff80f0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c227fff8100: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa Shadow byte legend (one shadow byte represents 8 application bytes): Addressable: 00 Partially addressable: 01 02 03 04 05 06 07 Heap left redzone: fa Freed heap region: fd Stack left redzone: f1 Stack mid redzone: f2 Stack right redzone: f3 Stack after return: f5 Stack use after scope: f8 Global redzone: f9 Global init order: f6 Poisoned by user: f7 Container overflow: fc Array cookie: ac Intra object redzone: bb ASan internal: fe Left alloca redzone: ca Right alloca redzone: cb ==57254==ABORTING Program received signal SIGABRT, Aborted. 0x00007ffff70a164c in ?? () from /usr/lib/libc.so.6 (gdb) bt #0 0x00007ffff70a164c in ?? () from /usr/lib/libc.so.6 #1 0x00007ffff7051938 in raise () from /usr/lib/libc.so.6 #2 0x00007ffff703b53d in abort () from /usr/lib/libc.so.6 #3 0x00007ffff78dfce4 in __sanitizer::Abort () at /usr/src/debug/gcc/gcc/libsanitizer/sanitizer_common/sanitizer_posix_libcdep.cpp:143 #4 0x00007ffff78ed1c2 in __sanitizer::Die () at /usr/src/debug/gcc/gcc/libsanitizer/sanitizer_common/sanitizer_termination.cpp:58 #5 0x00007ffff78c9c20 in __asan::ScopedInErrorReport::~ScopedInErrorReport ( this=0x7fffffffd1b6, __in_chrg=<optimized out>) at /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_report.cpp:190 #6 0x00007ffff78c910c in __asan::ReportGenericError (pc=140737332814947, bp=bp@entry=140737488346672, sp=sp@entry=140737488346656, addr=106721347372492, is_write=is_write@entry=false, access_size=access_size@entry=4, exp=0, fatal=true) at /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_report.cpp:479 #7 0x00007ffff78ca38c in __asan::__asan_report_load4 (addr=<optimized out>) at /usr/src/debug/gcc/gcc/libsanitizer/asan/asan_rtl.cpp:122 #8 0x00007ffff6baa463 in osmo_wqueue_bfd_cb (fd=0x6110000005b8, what=3) at /home/pespin/dev/sysmocom/git/libosmocore/src/core/write_queue.c:61 #9 0x00007ffff6b74fc3 in poll_disp_fds (n_fd=n_fd@entry=4) at /home/pespin/dev/sysmocom/git/libosmocore/src/core/select.c:361 --Type <RET> for more, q to quit, c to continue without paging-- #10 0x00007ffff6b750c3 in _osmo_select_main (polling=polling@entry=0) at /home/pespin/dev/sysmocom/git/libosmocore/src/core/select.c:399 #11 0x00007ffff6b7516c in osmo_select_main (polling=polling@entry=0) at /home/pespin/dev/sysmocom/git/libosmocore/src/core/select.c:438 #12 0x0000555555614026 in main (argc=<optimized out>, argv=<optimized out>) at /home/pespin/dev/sysmocom/git/osmocom-bb/src/host/trxcon/src/trxcon_main.c:389 (gdb) frame 8 #8 0x00007ffff6baa463 in osmo_wqueue_bfd_cb (fd=0x6110000005b8, what=3) at /home/pespin/dev/sysmocom/git/libosmocore/src/core/write_queue.c:61 61 fd->when &= ~OSMO_FD_WRITE; (gdb) print queue->write_cb $1 = (int (*)(struct osmo_fd *, struct msgb *)) 0x55555560f717 <l1ctl_client_write_cb>
Updated by pespin 10 months ago
- % Done changed from 0 to 90
AFAICT I fixed it with this one:
https://gerrit.osmocom.org/c/osmocom-bb/+/31109 trxcon: Fix heap-use-after-free in l1ctl_client
Actions