Awesome! I will try this on the Mi note 10. I guess you have these results on C2, right?
Adding to the ping list: @pvuorela as he was recently looking into this too ,
Thanks, I will definitely poke around running that script! We are aware that ngfd still needs work; let’s hope this helps luring the underlaying bug out.
2 Likes
Same principle, simpler call:
while sleep 0.5; do
busctl call com.nokia.NonGraphicFeedback1.Backend / com.nokia.NonGraphicFeedback1 Play 'sa(sv)' feedback_alert 0
done
2 Likes
BTW, ngfd tag 1.4.5 behaves the same. I’m looking at a C2 device.
I can see two different segfaults, sometimes it’s one, sometimes the other. I also have seen a SIGBUS error instead of the segfault, but can’t reproduce that one.
Backtrace after issuing:
busctl --quiet call com.nokia.NonGraphicFeedback1.Backend / com.nokia.NonGraphicFeedback1 Play 'sa(sv)' email 0
Thread 1 "ngfd" received signal SIGSEGV, Segmentation fault.
0x000000761e4eff7c in g_hash_table_lookup () from /usr/lib64/libglib-2.0.so.0
(gdb) backtrace
#0 0x000000761e4eff7c in g_hash_table_lookup () from /usr/lib64/libglib-2.0.so.0
#1 0x000000000040bbc0 in n_proplist_get (key=<optimized out>, proplist=0xd023010) at proplist.c:223
#2 n_proplist_get_pointer (proplist=proplist@entry=0xd023010, key=key@entry=0x761de7ce60 "dbus.event.client") at proplist.c:358
#3 0x000000761de7b250 in dbusif_send_reply (iface=<optimized out>, request=<optimized out>, code=1) at plugin.c:825
#4 0x000000000040a630 in n_core_request_done_cb (userdata=0xd20d9a0) at core-player.c:355
#5 0x000000761e5013c4 in ?? () from /usr/lib64/libglib-2.0.so.0
#6 0x000000761e504648 in ?? () from /usr/lib64/libglib-2.0.so.0
#7 0x000000761e5050b0 in g_main_loop_run () from /usr/lib64/libglib-2.0.so.0
#8 0x0000000000406838 in main (argc=<optimized out>, argv=0x7feb79a0d8) at main.c:204
Thread 1 "ngfd" received signal SIGSEGV, Segmentation fault.
0x000000000040a5d8 in n_core_stop_sinks (request=0x615e60, sinks=<optimized out>) at core-player.c:259
259 if (sink && sink->funcs.stop)
(gdb) backtrace
#0 0x000000000040a5d8 in n_core_stop_sinks (request=0x615e60, sinks=<optimized out>) at core-player.c:259
#1 n_core_request_done_cb (userdata=0x615e60) at core-player.c:339
#2 0x0000007ff7de13c4 in ?? () from /usr/lib64/libglib-2.0.so.0
#3 0x0000007ff7de4648 in ?? () from /usr/lib64/libglib-2.0.so.0
#4 0x0000007ff7de50b0 in g_main_loop_run () from /usr/lib64/libglib-2.0.so.0
#5 0x0000000000406838 in main (argc=<optimized out>, argv=0x7ffffff258) at main.c:204
Aha, finally got the BUS Error as well. Run with -vvvvvvvv. Note the garbage at request->name!
[13.18446744073709550725] DEBUG: ffmemless: prepare
[13.18446744073709550725] DEBUG: ffmemless: prep effect message, repeat 2 times, duration of 760 ms
[13.18446744073709550725] DEBUG: core: sink 'ffmemless' synchronized for request 'email'
[13.18446744073709550725] DEBUG: core: all sinks have been synchronized
[13.18446744073709550725] DEBUG: dbus: sending reply for request 'email' (event.id=1) with code 2
[13.18446744073709550725] DEBUG: ffmemless: play
[13.18446744073709550725] DEBUG: ffmemless: play id 11, repeat 2 times, iface 0x486b40, req 0x616110 data 0x619090
[13.18446744073709550725] DEBUG: ffmemless: setting up completion timer
[13.18446744073709550725] DEBUG: ffmemless: Starting playback 11
[13.18446744073709550727] INFO: dbus: >> client disconnect (:1.10877)
[13.18446744073709550727] DEBUG: core: stopping all sinks for request 'email'
[13.18446744073709550728] DEBUG: ffmemless: stop
[13.18446744073709550728] DEBUG: ffmemless: Effect id 11 completed
[13.18446744073709550728] DEBUG: core: sink 'ffmemless' completed request 'email'
[13.18446744073709550728] DEBUG: core: all sinks have been completed
[13.18446744073709550728] DEBUG: ffmemless: Stopping playback 11
[13.18446744073709550728] DEBUG: dbus: sending reply for request 'email' (event.id=1) with code 1
[13.18446744073709550728] DEBUG: core: request 'email' done
[13.18446744073709550728] DEBUG: core: stopping all sinks for request '� ^'
Thread 1 "ngfd" received signal SIGBUS, Bus error.
0x0068732f7273752f in ?? ()
(gdb) backtrace
#0 0x0068732f7273752f in ?? ()
#1 0x000000000040a5e4 in n_core_stop_sinks (request=0x616110, sinks=<optimized out>) at core-player.c:260
#2 n_core_request_done_cb (userdata=0x616110) at core-player.c:339
#3 0x0000007ff7de13c4 in ?? () from /usr/lib64/libglib-2.0.so.0
#4 0x0000007ff7de4648 in ?? () from /usr/lib64/libglib-2.0.so.0
#5 0x0000007ff7de50b0 in g_main_loop_run () from /usr/lib64/libglib-2.0.so.0
#6 0x0000000000406838 in main (argc=<optimized out>, argv=0x7ffffff248) at main.c:204
3 Likes
Looking at these three lines.
the code has:
321 static gboolean
322 n_core_request_done_cb (gpointer userdata)
323 {
324 NRequest *request = (NRequest*) userdata;
[...]
335 request->stop_source_id = 0;
336 core->requests = g_list_remove (core->requests, request);
337
338 N_DEBUG (LOG_CAT "stopping all sinks for request '%s'", request->name);
339 n_core_stop_sinks (request->stop_list, request);
340
[...]
388 done:
389 /* free the actual request */
390 N_DEBUG (LOG_CAT "request '%s' done", request->name);
391 n_request_free (request);
392
393 return FALSE;
394 }
So why do we get
core: request 'email' done
before
DEBUG: core: stopping all sinks for request '� ^'?
If I read this correctly, request is already freed after the ‘done’ message?
2 Likes
Nice investigations here! I think I’ve found something on the code side.
5 Likes
Could help with the crash:
Not sure how much that helps the original problem, though. No sounds can be more likely ngfd stuck. Also the regression related to the PR was introduced after this bug report.
Cool thing, it does! It makes all my known reproducers not reproduce any more.
I believe the hang (not crash) occurs through
339 n_core_stop_sinks (request->stop_list, request);`
in
260 sink->funcs.stop (sink, request);
in in the random case the deleted request does not cause a segfault elsewhere.
4 Likes