Hi, I have found a problem with ofono and the modem SIMCOM7600E. In a context with a weak signal, sometimes ofono stops on signal 6 (SIGNAL ABORT). I use the last version from git (commit d90cfdd71cb9eb2b533a20e4aea6bbf79e79fd2e). I have some custom patches but it should not play a role in the problem. I have a little program that listen dbus signals from ofono and controls it. The problem always occurs in the same way. A GPRS detach is detected by ofono and it sends a PropertyChanged signal on org.ofono.ConnectionManager interface with "Attached" set to false. Right after, the Attached property change to true and a DBUS signal is sent by ofono. Therefore, my program sends SetProperty DBUS message on org.ofono.ConnectionContext interface with Active set to true to enable the data connection again. But there, a signal SIGABRT is raised in ofono. It is the layer DBUS that call abort() because an argument is NULL as you can see below (in the stack #5, message is 0x0). --- (gdb) bt #0 0xb6c7d2e0 in raise () from ./output/staging/lib/libc.so.0 #1 0xb6c776c0 in abort () from ./output/staging/lib/libc.so.0 #2 0xb6c1fa88 in _dbus_abort () at dbus-sysdeps.c:91 #3 0xb6c17964 in _dbus_warn_check_failed ( format=0xb6c266fc "arguments to %s() were incorrect, assertion \"%s\" failed in file %s line %d.\nThis is normally a bug in some application using the D-Bus library.\n") at dbus-internals.c:275 #4 0xb6c0c550 in dbus_message_new_error (reply_to=reply_to@entry=0x0, error_name=error_name@entry=0x121086 "org.ofono.Error.Failed", error_message=0xb6c6148c <vsnprintf+132> "", error_message@entry=0xbedf2688 "Operation failed") at dbus-message.c:1478 #5 0x000fc44c in g_dbus_create_error_valist (message=0x0, name=name@entry=0x121086 "org.ofono.Error.Failed", format=format@entry=0x149bb8 <__ofono_debug_desc.22176> "", args=..., args@entry=...) at gdbus/object.c:1420 #6 0x000fc46c in g_dbus_create_error (message=<optimized out>, name=name@entry=0x121086 "org.ofono.Error.Failed", format=0x12109d "Operation failed") at gdbus/object.c:1431 #7 0x000b3438 in __ofono_error_failed (msg=<optimized out>) at src/dbus.c:312 #8 0x000dcd98 in pri_activate_callback (error=0xbedf2b60, data=0x161048) at src/gprs.c:838 #9 0x0007149c in at_cgdcont_cb (ok=0, result=0xbedf2bb8, user_data=0x1602c8) at drivers/atmodem/gprs-context.c:229 #10 0x000a39d4 in at_chat_finish_command (p=p@entry=0x153b90, ok=0, final=final@entry=0x15e1a0 "NO CARRIER") at gatchat/gatchat.c:459 #11 0x000a4368 in at_chat_handle_command_response (line=<optimized out>, cmd=<optimized out>, p=<optimized out>) at gatchat/gatchat.c:529 #12 have_line (str=0x15e1a0 "NO CARRIER", p=0x153b90) at gatchat/gatchat.c:600 #13 new_bytes (rbuf=0x14fe18, user_data=user_data@entry=0x153b90) at gatchat/gatchat.c:759 #14 0x000a62e8 in g_at_io_set_read_handler (io=0x153c08, read_handler=read_handler@entry=0xa41c8 <new_bytes>, ---Type <return> to continue, or q <return> to quit--- user_data=user_data@entry=0x153b90) at gatchat/gatio.c:260 #15 0x000a4874 in at_chat_resume (chat=0x153b90) at gatchat/gatchat.c:955 #16 g_at_chat_resume (chat=<optimized out>) at gatchat/gatchat.c:1449 #17 0x00071704 in ppp_disconnect (reason=G_AT_PPP_REASON_PEER_CLOSED, user_data=0x1602c8) at drivers/atmodem/gprs-context.c:134 #18 0x000ab850 in ppp_dead (userdata=0x166cf8) at gatchat/gatppp.c:108 #19 0xb6e3db84 in g_main_dispatch (context=0x14f038) at gmain.c:3111 #20 g_main_context_dispatch (context=context@entry=0x14f038) at gmain.c:3710 #21 0xb6e3de28 in g_main_context_iterate (context=0x14f038, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3781 #22 0xb6e3e1f8 in g_main_loop_run (loop=0x150fb8) at gmain.c:3975 #23 0x0001de5c in main (argc=0, argv=0x0) at src/main.c:293 --- With DBG enabled, we can see this in the log: --- Jan 15 11:01:42 box ofonod[5828]: AT< \r\n+CREG: 2\r\n\r\n+CGREG: 2\r\n Jan 15 11:01:42 box ofonod[5828]: AT< \r\n+CREG: 5,FFFE,13D6204\r\n\r\n+CGREG: 5,FFFE,9C40\r\n Jan 15 11:01:42 box ofonod[5828]: src/network.c:ofono_netreg_status_notify() /sim7x00_0 status 2 tech -1 lac -1 ci -1 Jan 15 11:01:42 box ofonod[5828]: src/network.c:current_operator_callback() 0x160c00, 0x153e70 Jan 15 11:01:42 box ofonod[5828]: src/gprs.c:netreg_status_changed() 2 (searching) Jan 15 11:01:42 box ofonod[5828]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 1 Jan 15 11:01:42 box ofonod[5828]: src/gprs.c:netreg_status_changed() 2 (searching) Jan 15 11:01:42 box ofonod[5828]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0 Jan 15 11:01:42 box ofonod[5828]: src/gprs.c:ofono_gprs_status_notify() /sim7x00_0 status searching (2) Jan 15 11:01:42 box ofonod[5828]: src/network.c:ofono_netreg_status_notify() /sim7x00_0 status 5 tech 7 lac -1 ci -1 Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:netreg_status_changed() 5 (roaming) Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 0 Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:ofono_gprs_status_notify() /sim7x00_0 status roaming (5) Jan 15 11:01:43 box ofonod[5828]: AT> AT+CGATT=0\r Jan 15 11:01:43 box ofonod[5828]: AT< \r\n+CME ERROR: 30\r\n\r\n+CGEV: NW DETACH\r\n Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:gprs_attach_callback() /sim7x00_0 error = 1 Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:ofono_gprs_detached_notify() /sim7x00_0 Jan 15 11:01:43 box ofonod[5828]: AT> AT+COPS=3,2\r Jan 15 11:01:43 box ofonod[5828]: AT< \r\nOK\r\n\r\nNO CARRIER\r\n\r\n+PPPD: DISCONNECTED\r\n Jan 15 11:01:43 box ofonod[5828]: AT> AT+COPS?\r Jan 15 11:01:43 box ofonod[5828]: AT< \r\n+COPS: 0,2,"22802",7\r\n\r\nOK\r\n Jan 15 11:01:43 box ofonod[5828]: drivers/atmodem/network-registration.c:cops_numeric_cb() Cops numeric got mcc: 228, mnc: 02 Jan 15 11:01:43 box ofonod[5828]: AT> AT+CSQ\r Jan 15 11:01:43 box ofonod[5828]: AT< \r\n+CSQ: 20,7\r\n\r\nOK\r\n Jan 15 11:01:43 box ofonod[5828]: drivers/atmodem/network-registration.c:csq_cb() csq_cb: 20 Jan 15 11:01:43 box ofonod[5828]: src/network.c:ofono_netreg_strength_notify() strength 64 Jan 15 11:01:43 box ofonod[5828]: AT> AT+CGREG?\r Jan 15 11:01:43 box ofonod[5828]: plugins/udevng.c:remove_device() /sys/devices/virtual/net/ppp0 Jan 15 11:01:43 box ofonod[5828]: AT< \r\n+CGREG: 2,5,9C40,13D6204\r\n\r\nOK\r\n Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:registration_status_cb() /sim7x00_0 error 0 status 5 Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:ofono_gprs_status_notify() /sim7x00_0 status roaming (5) Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1 Jan 15 11:01:43 box ofonod[5828]: AT> AT+CLCC\r Jan 15 11:01:43 box ofonod[5828]: AT< \r\n+CGEV: ME DETACH\r\n Jan 15 11:01:43 box ofonod[5828]: AT< \r\n+CGREG: 2\r\n\r\nOK\r\n Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:ofono_gprs_detached_notify() /sim7x00_0 Jan 15 11:01:43 box ofonod[5828]: drivers/atmodem/gprs-context.c:at_gprs_detach_shutdown() cid 1 Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:ofono_gprs_status_notify() /sim7x00_0 status searching (2) Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:ofono_gprs_detached_notify() /sim7x00_0 Jan 15 11:01:43 box ofonod[5828]: AT> AT+COPS=3,0\r Jan 15 11:01:43 box ofonod[5828]: AT< \r\nOK\r\n Jan 15 11:01:43 box ofonod[5828]: AT> AT+COPS?\r Jan 15 11:01:43 box ofonod[5828]: AT< \r\n+COPS: 0,0,"Sunrise Tele2 IoT",7\r\n\r\nOK\r\n Jan 15 11:01:43 box ofonod[5828]: drivers/atmodem/network-registration.c:cops_cb() cops_cb: Sunrise Tele2 IoT, 228 02 7 Jan 15 11:01:43 box ofonod[5828]: src/network.c:current_operator_callback() 0x160c00, (nil) Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:netreg_status_changed() 5 (roaming) Jan 15 11:01:43 box ofonod[5828]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 0 Jan 15 11:01:43 box ofonod[5828]: AT> AT+CGATT=1\r Jan 15 11:01:44 box ofonod[5828]: AT< \r\n+CGREG: 5,FFFE,9C40\r\n\r\nOK\r\n Jan 15 11:01:44 box ofonod[5828]: src/gprs.c:ofono_gprs_status_notify() /sim7x00_0 status roaming (5) Jan 15 11:01:44 box ofonod[5828]: src/gprs.c:gprs_attach_callback() /sim7x00_0 error = 0 Jan 15 11:01:44 box ofonod[5828]: AT> AT+CGREG?\r Jan 15 11:01:44 box ofonod[5828]: AT< \r\n+CGREG: 2,5,9C40,13D6204\r\n\r\nOK\r\n Jan 15 11:01:44 box ofonod[5828]: src/gprs.c:registration_status_cb() /sim7x00_0 error 0 status 5 Jan 15 11:01:44 box ofonod[5828]: src/gprs.c:ofono_gprs_status_notify() /sim7x00_0 status roaming (5) Jan 15 11:01:44 box ofonod[5828]: drivers/atmodem/gprs-context.c:at_gprs_activate_primary() cid 1 Jan 15 11:01:46 box ofonod[5828]: drivers/atmodem/gprs-context.c:ppp_disconnect() Reason: 4 Jan 15 11:01:46 box ofonod[5828]: src/gprs.c:pri_activate_callback() 0x15e760 Jan 15 11:01:46 box ofonod[5828]: src/gprs.c:pri_activate_callback() Activating context failed with error: Unknown error type Jan 15 11:01:46 box ofonod[5828]: drivers/atmodem/gprs-context.c:at_cgdcont_cb() ok 0 Jan 15 11:01:46 box ofonod[5828]: src/gprs.c:pri_activate_callback() 0x15e760 Jan 15 11:01:46 box ofonod[5828]: src/gprs.c:pri_activate_callback() Activating context failed with error: Unknown error type --- The line above is the last before ofono gets killed. I can guess with the log and the code that there is a double hit of pri_activate_callback() whereas there is only one DBUS request coming from my program (modemd): --- Jan 15 10:57:06 box modemd[1131]: /sim7x00_0/context1: PPP is up (ipaddr=100.77.207.2) Jan 15 11:01:42 box modemd[1131]: Network status changed: searching Jan 15 11:01:43 box modemd[1131]: Network status changed: roaming Jan 15 11:01:43 box modemd[1131]: packet domain is non-attached Jan 15 11:01:43 box modemd[1131]: /sim7x00_0/context1: PPP is down (lost packet domain) Jan 15 11:01:44 box modemd[1131]: packet domain is attached Jan 15 11:01:44 box modemd[1131]: /sim7x00_0/context1: enabling context... Jan 15 11:01:46 box modemd[1131]: gprs.c:307 gprs_enable_context() Set 'Active' to '1' failed Jan 15 11:01:46 box modemd[1131]: gprs.c:636 gprs_sm_conduct() /sim7x00_0/context1: enabling context failed --- Is there anyone have an idea to explain why this problem occur and how to fix it ? Best regards, Anthony V. --