Project

General

Profile

Bug #2239

Bug #2187: ofono: not all modems do what they should

ofono: USSD is not implemented for any modem

Added by neels about 1 year ago. Updated 4 months ago.

Status:
Closed
Priority:
High
Assignee:
Target version:
-
Start date:
05/05/2017
Due date:
% Done:

100%

Estimated time:
Spec Reference:

Description

Apparently we have no way of initiating USSD requests using ofono.

ofono.log.txt ofono.log.txt 122 KB pespin, 06/16/2017 01:39 PM
log log 51.3 KB pespin, 06/16/2017 01:39 PM
pcap-recorder_eth1(filters=_host 10.42.42.2 and port not 22_).pcap pcap-recorder_eth1(filters=_host 10.42.42.2 and port not 22_).pcap 181 KB pespin, 06/16/2017 01:41 PM
colorscheme_supservice colorscheme_supservice 333 Bytes wireshark colors lynxis, 06/16/2017 08:49 PM
run.2017-07-20_12-01-05.tar.gz run.2017-07-20_12-01-05.tar.gz 45 Bytes pespin, 07/20/2017 10:36 AM
run.2017-07-21_10-41-02.tar.gz run.2017-07-21_10-41-02.tar.gz 66.4 KB pespin, 07/21/2017 08:49 AM

Related issues

Blocked by OsmoGSMTester - Bug #2458: ofono: status=registered signal sent to ofono users before being attachedResolved2017-08-23

History

#1 Updated by neels about 1 year ago

EC20 and Sierra say:

# mdbus2 -s org.ofono /gobi_0 org.ofono.SupplementaryServices.Initiate "*#100#" 
[ERR]: GDBus.Error:org.ofono.Error.NotImplemented: Implementation not provided
# mdbus2 -s org.ofono /sierra_1 org.ofono.SupplementaryServices.Initiate "*#100#" 
[ERR]: GDBus.Error:org.ofono.Error.NotImplemented: Implementation not provided

Gobi has no such interface to begin with, says:

# mdbus2 -s org.ofono /gobi_3 org.ofono.SupplementaryServices.Initiate "*#100#" 
[ERR]: There is no method with name org.ofono.SupplementaryServices.Initiate on path /gobi_3!

#2 Updated by neels about 1 year ago

see also https://git.sysmocom.de/ofono/tree/test/send-ussd as verification that this is the proper ofono interface.
If I pick other arguments I also get:

root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_0 org.ofono.SupplementaryServices.Initiate "*#100#" 
[ERR]: GDBus.Error:org.ofono.Error.NotImplemented: Implementation not provided
root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_0 org.ofono.SupplementaryServices.Initiate "1234" 
[ERR]: GDBus.Error:org.ofono.Error.NotRecognized: String not recognized as USSD/SS
root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_0 org.ofono.SupplementaryServices.Initiate "100" 
[ERR]: GDBus.Error:org.ofono.Error.NotRecognized: String not recognized as USSD/SS
root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_0 org.ofono.SupplementaryServices.Initiate "#100" 
[ERR]: GDBus.Error:org.ofono.Error.NotRecognized: String not recognized as USSD/SS
root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_0 org.ofono.SupplementaryServices.Initiate "*100" 
[ERR]: GDBus.Error:org.ofono.Error.NotRecognized: String not recognized as USSD/SS
root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_0 org.ofono.SupplementaryServices.Initiate "*100#" 
[ERR]: GDBus.Error:org.ofono.Error.NotImplemented: Implementation not provided
root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_0 org.ofono.SupplementaryServices.Initiate "*#100#" 
[ERR]: GDBus.Error:org.ofono.Error.NotImplemented: Implementation not provided

#3 Updated by neels about 1 year ago

  • Priority changed from Normal to High

#4 Updated by laforge about 1 year ago

  • Assignee deleted (Osmocom Developers)

#5 Updated by laforge about 1 year ago

  • Assignee set to osmo-gsm-tester

#6 Updated by lynxis about 1 year ago

it's missing completely just the register + remove is implemented.

#7 Updated by neels about 1 year ago

  • Assignee changed from osmo-gsm-tester to lynxis

#8 Updated by lynxis about 1 year ago

MO USSD works now. I've pushed it to git://git.sysmocom.de/ofono branch ussd.

Missing: push it to upstream (rework coding style, naming defines).

#9 Updated by lynxis about 1 year ago

  • Status changed from New to In Progress
  • % Done changed from 0 to 90

#10 Updated by pespin about 1 year ago

Working example:

mdbus2 -s -i org.ofono $MODEM org.ofono.SupplementaryServices.Initiate "*#100#" => ('USSD', <'Your extension is 21101\r\r'>)

Or in the ofono test repo:

ofono/initiate-ussd /gobi_0 '*#100#'

#11 Updated by pespin about 1 year ago

I added some code to test the USSD '*#100#' feature. It sometimes works correctly, but sometimes the Initiate method fails with:

GLib.Error: g-io-error-quark: GDBus.Error:org.ofono.Error.Terminated: Operation was terminated by the network (36)

When that failure occurs, I cannot see any related messages in wireshark (filter: gsm_a.dtap.protocol_discriminator == 11).
Output from ofono -d:

ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() found 10 operators
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 901-70 (901:70) status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() E-Plus (262:03) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() TDG (262:01) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() TDG (262:01) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() E-Plus (262:03) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() Vodafone (262:02) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() TDG (262:01) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() Vodafone (262:02) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() E-Plus (262:03) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() Vodafone (262:02) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 901:70 4
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:03 5
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:01 8
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:01 4
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:03 4
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:02 4
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:01 5
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:02 5
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:03 8
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:02 8
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_register_manual()
ofonod[22411]: drivers/qmimodem/network-registration.c:register_net_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_registration_status()
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 0
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech -1
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 3 tech -1
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 3
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 0
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:get_ss_info_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 0
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech -1
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 3 tech -1
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 3
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() signal with -86 dBm on 4
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() osmo-gsm-tester-nitb (901:70)
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 0 tech 0
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 0
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 0 band 0 channel 0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 4 band 47 channel 868
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() osmo-gsm-tester-nitb (901:70)
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac 23 cellid 0 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 0
ofonod[22411]: drivers/qmimodem/gprs.c:qmi_set_attached() attached 1
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 0 band 0 channel 0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 4 band 47 channel 868
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() osmo-gsm-tester-nitb (901:70)
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, 0x26dcaf0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() osmo-gsm-tester-nitb (901:70)
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, 0x26dcaf0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() 901-70 (901:70)
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, 0x26dcaf0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/gprs.c:attach_detach_cb()
ofonod[22411]: src/gprs.c:gprs_attach_callback() /sierra_1 error = 0
ofonod[22411]: drivers/qmimodem/gprs.c:qmi_attached_status()
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() 901-70 (901:70)
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, 0x26dcaf0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() 901-70 (901:70)
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, 0x26dcaf0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -86 dBm on 4
ofonod[22411]: src/network.c:ofono_netreg_strength_notify() strength 20
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -86 dBm on 4
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -86 dBm on 4
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -86 dBm on 4
ofonod[22411]: drivers/qmimodem/gprs.c:get_ss_info_cb()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:registration_status_cb() /sierra_1 error 0 status 0
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -86 dBm on 4
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -86 dBm on 4
ofonod[22411]: src/ussd.c:ussd_initiate() checking if this is a recognized control string
ofonod[22411]: src/ussd.c:recognized_control_string() parsing control string
ofonod[22411]: src/ussd.c:recognized_control_string() Got parse result: 2, 100, , , , ,
ofonod[22411]: src/ussd.c:ussd_initiate() No.., checking if this is a USSD string
ofonod[22411]: src/ussd.c:ussd_initiate() OK, running USSD request
ofonod[22411]: drivers/qmimodem/ussd.c:qmi_ussd_request()
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() 901-70 (901:70)
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, 0x26dcaf0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() osmo-gsm-tester-nitb (901:70)
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, 0x26dcaf0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/ussd.c:qmi_ussd_request_cb()
ofonod[22411]: drivers/qmimodem/qmi.c:qmi_result_print_tlvs() tlv: 0x02 len 0x0004
ofonod[22411]: drivers/qmimodem/ussd.c:async_orig_ind()
ofonod[22411]: drivers/qmimodem/ussd.c:async_orig_ind() Failure Cause: 0x0019
ofonod[22411]: src/ussd.c:ofono_ussd_notify() status: 2 TERMINATED, state: 1 ACTIVE
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -86 dBm on 4
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -86 dBm on 4
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() osmo-gsm-tester-nitb (901:70)
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x26f3710, 0x26dcaf0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -86 dBm on 4

#12 Updated by pespin about 1 year ago

Exactly same issue with EC20 modem (before I tested with a Sierra one).

ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() found 10 operators
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 90170 (901:70) status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() E-Plus (262:03) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() TDG (262:01) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() TDG (262:01) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() E-Plus (262:03) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() Vodafone.de (262:02) statu
s 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() Vodafone.de (262:02) statu
s 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() TDG (262:01) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() E-Plus (262:03) status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() Vodafone.de (262:02) statu
s 3
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 901:70 4
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:03 5
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:01 4
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:01 5
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:03 4
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:02 4
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:02 5
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:01 8
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:03 8
ofonod[22411]: drivers/qmimodem/network-registration.c:scan_nets_cb() 262:02 8
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_register_manual()
ofonod[22411]: drivers/qmimodem/network-registration.c:register_net_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_registration_status()
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 0
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech -
1
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /gobi_0 status 3 tech -1
ofonod[22411]: src/network.c:current_operator_callback() 0x2708c00, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 3
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 0
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /gobi_0 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:get_ss_info_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 0
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech -
1
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /gobi_0 status 3 tech -1
ofonod[22411]: src/network.c:current_operator_callback() 0x2708c00, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 3
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 0 band 0 channel 0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 8 band 145 channel 620
0
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 5
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 2
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 3 tech 2
ofonod[22411]: src/network.c:current_operator_callback() 0x2700940, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 3
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 5
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 0 band 0 channel 0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 5 band 80 channel 6553
5
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 5
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 2
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 3 tech 2
ofonod[22411]: src/network.c:current_operator_callback() 0x2700940, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 3
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 5
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_1 status 0

ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() signal with -83 dBm on 4

ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()  (901:70)
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /gobi_0 status 0 tech 0
ofonod[22411]: src/network.c:current_operator_callback() 0x2708c00, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 0
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0

ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /gobi_0 status 0

ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 4 band 47 channel 868

ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac 23 cellid 0 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /gobi_0 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x2708c00, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 0
ofonod[22411]: drivers/qmimodem/gprs.c:qmi_set_attached() attached 1
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1

ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /gobi_0 status 0

ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 4 band 47 channel 868

ofonod[22411]: drivers/qmimodem/gprs.c:attach_detach_cb()
ofonod[22411]: src/gprs.c:gprs_attach_callback() /gobi_0 error = 0
ofonod[22411]: drivers/qmimodem/gprs.c:qmi_attached_status()

ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /gobi_0 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x2708c00, 0x2702a90
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1

ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /gobi_0 status 0

ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -83 dBm on 4
ofonod[22411]: src/network.c:ofono_netreg_strength_notify() strength 40
ofonod[22411]: drivers/qmimodem/gprs.c:get_ss_info_cb()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:registration_status_cb() /gobi_0 error 0 status 0
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /gobi_0 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -83 dBm on 4
ofonod[22411]: src/ussd.c:ussd_initiate() checking if this is a recognized control string
ofonod[22411]: src/ussd.c:recognized_control_string() parsing control string
ofonod[22411]: src/ussd.c:recognized_control_string() Got parse result: 2, 100, , , , ,
ofonod[22411]: src/ussd.c:ussd_initiate() No.., checking if this is a USSD string
ofonod[22411]: src/ussd.c:ussd_initiate() OK, running USSD request
ofonod[22411]: drivers/qmimodem/ussd.c:qmi_ussd_request()
ofonod[22411]: drivers/qmimodem/ussd.c:qmi_ussd_request_cb()
ofonod[22411]: drivers/qmimodem/qmi.c:qmi_result_print_tlvs() tlv: 0x02 len 0x0004
ofonod[22411]: drivers/qmimodem/ussd.c:async_orig_ind()
ofonod[22411]: drivers/qmimodem/ussd.c:async_orig_ind() Failure Cause: 0x0019
ofonod[22411]: src/ussd.c:ofono_ussd_notify() status: 2 TERMINATED, state: 1 ACTIVE
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 1
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 4
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 0
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /gobi_0 status 1 tech 0
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_current_operator()
ofonod[22411]: src/network.c:current_operator_callback() 0x2708c00, 0x2702a90
ofonod[22411]: drivers/qmimodem/network-registration.c:qmi_signal_strength()
ofonod[22411]: src/gprs.c:netreg_status_changed() 1
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 4
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /gobi_0 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb()
ofonod[22411]: drivers/qmimodem/network-registration.c:get_rssi_cb() signal with -83 dBm on 4
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() signal with -94 dBm on 4
ofonod[22411]: src/network.c:ofono_netreg_strength_notify() strength 20
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() signal with -109 dBm on 4
ofonod[22411]: src/network.c:ofono_netreg_strength_notify() strength -1
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 8 band 145 channel 620
0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() signal with -104 dBm on 5
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 5
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 2
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_2 status 3 tech 2
ofonod[22411]: src/network.c:current_operator_callback() 0x2711e60, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 3
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 5
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_2 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 5 band 80 channel 6553
5
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 3
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 5
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech 2
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /sierra_2 status 3 tech 2
ofonod[22411]: src/network.c:current_operator_callback() 0x2711e60, (nil)
ofonod[22411]: src/gprs.c:netreg_status_changed() 3
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 5
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /sierra_2 status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:event_notify() rat 4 band 47 channel 868
ofonod[22411]: drivers/qmimodem/network-registration.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 0
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 0
ofonod[22411]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech -
1
ofonod[22411]: src/network.c:ofono_netreg_status_notify() /gobi_0 status 0 tech -1
ofonod[22411]: src/network.c:current_operator_callback() 0x2708c00, 0x2702a90
ofonod[22411]: src/gprs.c:netreg_status_changed() 0
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 1
ofonod[22411]: drivers/qmimodem/gprs.c:qmi_set_attached() attached 0
ofonod[22411]: src/gprs.c:netreg_status_changed() 0
ofonod[22411]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0
ofonod[22411]: drivers/qmimodem/gprs.c:ss_info_notify()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 0
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /gobi_0 status 0
ofonod[22411]: drivers/qmimodem/gprs.c:attach_detach_cb()
ofonod[22411]: src/gprs.c:gprs_attach_callback() /gobi_0 error = 0
ofonod[22411]: drivers/qmimodem/gprs.c:qmi_attached_status()
ofonod[22411]: drivers/qmimodem/gprs.c:get_ss_info_cb()
ofonod[22411]: drivers/qmimodem/gprs.c:handle_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info()
ofonod[22411]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 0
ofonod[22411]: src/gprs.c:registration_status_cb() /gobi_0 error 0 status 0
ofonod[22411]: src/gprs.c:ofono_gprs_status_notify() /gobi_0 status 0

#13 Updated by lynxis about 1 year ago

I would guess, you're not yet connected to any network.
Since ofono has only the following codes,
I'm not sure which one I should use, if qmi reports an error:

/* 3GPP TS 27.007 section 7.15, values for <m> */
enum ofono_ussd_status {
        OFONO_USSD_STATUS_NOTIFY = 0,
        OFONO_USSD_STATUS_ACTION_REQUIRED = 1,
        OFONO_USSD_STATUS_TERMINATED = 2,
        OFONO_USSD_STATUS_LOCAL_CLIENT_RESPONDED = 3,
        OFONO_USSD_STATUS_NOT_SUPPORTED = 4,
        OFONO_USSD_STATUS_TIMED_OUT = 5,
};

#14 Updated by lynxis about 1 year ago

I can see, you're somehow connected to a network.
Can you try to send a sms before calling ussd?
The failure code 0x19 means QMI_FAILURE_CAUSE_REL_NORMAL. Do you see anything on the pcap on the bts?

#15 Updated by pespin about 1 year ago

Sending sms before doesn't help.

I modified the test to loop (while true) until it succeeds 10 times to do the USSD transaction (with failures in between). I attach the log of osmo-gsm-tester, the log of ofono (started + stopped for time scope of this test) + pcap file containing traces of NITB iface + GSMTAP from BTS.

Interestingly, sometimes fails too with another error code inside ofono: QMI_FAILURE_CAUSE_RADIO_LINK_LOST=225 (0xe1)

#17 Updated by lynxis about 1 year ago

when you apply the colorscheme (use wireshark: Views -> Coloring Rules -> Import). Some of them have doublicated CM Service Request/Response.

#18 Updated by lynxis about 1 year ago

pespin: do you tested the ofono stuff with a minipcie breakout board using usb-bus power? I've noticed problems with the modem if I'm using only the usb-bus powre instead of an external power supply.

#19 Updated by pespin about 1 year ago

TODO:
- Provide again logs, this time running ofonod inside systemd service to have timestamps in there.
- Test again the USSD loop test with a sleep(1) and see if it still fails from time to time.

#20 Updated by lynxis about 1 year ago

  • Assignee changed from lynxis to pespin

#21 Updated by pespin 12 months ago

Attached new test, this time running ofonod -d with systemd to have subsecond logging info (retrieved with "journalctl -u ofono -o short-precise").

In run.2017-07-20_12-01-05.tar.gz, you can find:
- log: osmo-gsm-tester log with debug enabled. Should give you an idea together with the timestamps on when it fails and when it succeeds.
- ofono-log.txt: ofono output from journalctl during the duration of the test.
- run.2017-07-20_12-01-05/ussd/assert_extension.py/osmo-nitb_10.42.42.2/pcap/*.pcap: pcap file with all GSMTAP + Abis traffic.

#22 Updated by lynxis 12 months ago

  • Assignee changed from lynxis to pespin

The logfile tarball is empty.

#23 Updated by pespin 12 months ago

I guess something went wrong during upload, I remember opening the targz to write about the file contents in the ticket. Unfortunately, I had that file in my tmpfs, so it got lost. I did re-run the test now and I provide a new tar.gz attached here.

#24 Updated by lynxis 12 months ago

  • Assignee changed from lynxis to pespin

The ussd looks much better now. No failures except at the beginning.
So the tester tries to send ussd to early, because of

10:41:51.526962 tst                        /sierra_1: DBG: status: registered  [trial↪ussd↪/sierra_1]  [ofono_client.py:408]

This is before the network send Location Updating Accept.
So the problems lies in ofono or the trigger when to start sending ussd.

Looking more into ofono, when exactly the signal network registered is created.

10:41:51.038730 osmo-gsm-tester-rnd ofonod[28097]: src/network.c:ofono_netreg_status_notify() /sierra_1 status 1 tech 0

But this is just after the modem requested the Location Update Request.
The qmimodem driver direct reports the network status from QMI which doesn't mean CS or PS is attached...

I'm also not sure when ofono should emit the `network registered` state.
How should we continue here?

#25 Updated by pespin 12 months ago

The ussd looks much better now. No failures except at the beginning.
So the tester tries to send ussd to early, because of

10:41:51.526962 tst /sierra_1: DBG: status: registered [trial↪ussd↪/sierra_1] [ofono_client.py:408]

This is before the network send Location Updating Accept.
So the problems lies in ofono or the trigger when to start sending ussd.

Looking more into ofono, when exactly the signal network registered is created.

10:41:51.038730 osmo-gsm-tester-rnd ofonod28097: src/network.c:ofono_netreg_status_notify() /sierra_1 status 1 tech 0

But this is just after the modem requested the Location Update Request.
The qmimodem driver direct reports the network status from QMI which doesn't mean CS or PS is attached...

I'm also not sure when ofono should emit the `network registered` state.
How should we continue here?

Well, from my point of view when using ofono we should not care whether the network already sent us "Location Updating Accept" or not, basically because there's no way to know that from ofono's API and that's probably too low level anyway.

I don't know the protocol specifics, but AFAIK this "Location Update Request/Accept" is done from time to time, so does that mean USSD will fail every time we are in the middle of that process? In that case I guess the code handling the USSD should account for that and sleep until Accept is received or timeout after a while with an error.

Harald, do you have a clearer view on this?

#26 Updated by laforge 12 months ago

On Thu, Jul 27, 2017 at 08:55:32AM +0000, pespin [REDMINE] wrote:

I don't know the protocol specifics, but AFAIK this "Location Update
Request/Accept" is done from time to time, so does that mean USSD will
fail every time we are in the middle of that process? In that case I
guess the code handling the USSD should account for that and sleep
until Accept is received or timeout after a while with an error.

"not attached" from a GSM protocol level can only happen before the
initial Location Update (i.e. an "IMSI Attach" type LU). The state
before/during a periodic LU, or a subsequent LU in a new cell is
already "attached".

#27 Updated by pespin 12 months ago

Is any service available while in "not attached state"? If that's not the case, then I'd suggest sending a patch to ofono which sets the status to "registered" once we successfully received the Location Accept.

Otherwise it may be worth sharing your founding on ofono ML and see if somebody with a better knowledge on ofono API has some strong belief regarding this?

#28 Updated by lynxis 12 months ago

I think the question is: Is there an QMI event which is emitted after the modem received the Location Update Accept?     

I'ven't looked yet into it.

#29 Updated by pespin 12 months ago

  • Assignee changed from pespin to lynxis

For now I pushed to gerrit 2 commits, one adding the USSD support and a a second patch adding a sleep() to workaround the issue now that we know better the failure cause.
https://gerrit.osmocom.org/#/c/3401/
https://gerrit.osmocom.org/#/c/3402/

Next steps (assign to lynxis):
- Check if we can assert somewhere in ofono/qmi to send status=registered event only after we are attached, or if we are not attached when Supplementaryservices.Init(), then start/wait until we are attached or timeout after a while.
- Testing the issue can be done easily reverting the second patch and running the test several times. For testing purposes, it can be changed by using this loop:

-response = ms.ussd_send(USSD_COMMAND_GET_EXTENSION)
-assert ' ' + ms.msisdn + '\r' in response
+cont = 10
+while cont:
+    try:
+        #log('send sms')
+        #ms.sms_send('123456', 'bla')
+        log('send ussd')
+        response = ms.ussd_send(USSD_COMMAND_GET_EXTENSION)
+        log('success!')
+        assert ' ' + ms.msisdn + '\r' in response
+        cont = cont - 1
+    except Exception as e:
+        print('failed:', repr(e))

A branch without the sleep() workaround and with that loop can be found in origin branch name "pespin/ussd-test". This way you can use it easily with the run-manual-all jenkins job. For the test suite parameter, you can pass "-s ussd".

#30 Updated by pespin 11 months ago

  • Blocked by Bug #2458: ofono: status=registered signal sent to ofono users before being attached added

#31 Updated by pespin 11 months ago

  • Status changed from In Progress to Stalled

#32 Updated by lynxis 8 months ago

I don't know how this can be done at the moment, because the original problem lies IMHO in the baseband firmware.

#33 Updated by lynxis 4 months ago

  • Status changed from Stalled to Feedback
  • Assignee changed from lynxis to pespin

pespin: Please close this issue. I don't think I can not do anything here further. If you think otherwise, please explain, what I should do here.

#34 Updated by pespin 4 months ago

  • Status changed from Feedback to In Progress
  • % Done changed from 90 to 100

#35 Updated by pespin 4 months ago

  • Status changed from In Progress to Closed

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)