Bug #2480
closedgobi2000: org.ofono.NetworkOperator.Register always fails
100%
Description
When using a gobi2000 modem, the Register method in the org.ofono.NetworkOperator interface always fails. On the other hand, the other API org.ofono.NetworkRegistration.Register works fine.
The difference between the former and the later is that the former is intended to register manually to a specific operator. In OsmoGsmTester we prefer the first one to the second one, as at that time we know the operator from Scan() and then we can enforce that the modem connects to that BTS (ie extra validation).
We actually support both ofono methods in osmo-gsm-tester. It uses one or the other based on availability of parameter passed to ofono_client.py:Modem.connect().
# mdbus2 -s org.ofono /gobi_3 org.ofono.Modem.SetProperty Powered true () root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_3 org.ofono.Modem.SetProperty Online true () root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_3 org.ofono.NetworkRegistration.Scan ([('/gobi_3/operator/26203', {'Name': <'E-Plus'>, 'Status': <'forbidden'>, 'MobileCountryCode': <'262'>, 'MobileNetworkCode': <'03'>}), ('/gobi_3/operator/26202', {'Name': <'Vodafone.de'>, 'Status': <'forbidden'>, 'MobileCountryCode': <'262'>, 'MobileNetworkCode': <'02'>}), ('/gobi_3/operator/26201', {'Name': <'TMO D'>, 'Status': <'forbidden'>, 'MobileCountryCode': <'262'>, 'MobileNetworkCode': <'01'>})],) root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_3/operator/26201 [METHOD] org.freedesktop.DBus.Introspectable.Introspect() -> (s:xml) [METHOD] org.ofono.NetworkOperator.GetProperties() -> (a{sv}:properties) [METHOD] org.ofono.NetworkOperator.Register() -> () [SIGNAL] org.ofono.NetworkOperator.PropertyChanged(s:name, v:value) root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_3/operator/26201 org.ofono.NetworkOperator.Register [ERR]: GDBus.Error:org.ofono.Error.Failed: Operation failed root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_3 org.ofono.NetworkRegistration.Register ()
ofono seems to be failing with "DeviceUnsupported". If it is not supported, then another error should be returned, like org.ofono.Error.NotImplemented as specified in https://github.com/intgr/ofono/blob/master/doc/network-api.txt. Then, we can check in osmo-gsm-tester if that error code is return, and call the default Register() in that case.
log of ofono -n -d:
Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: < 01 6e 00 80 03 02 02 13 01 21 00 62 00 02 04 00 .n.......!.b.... Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: 00 00 00 00 10 58 00 07 00 85 03 46 00 66 00 06 .....X.....F.f.. Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: 01 01 00 9a 05 54 4d 4f 20 44 06 01 03 00 9a 06 .....TMO D...... Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: 45 2d 50 6c 75 73 06 01 03 00 9a 06 45 2d 50 6c E-Plus......E-Pl Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: 75 73 06 01 02 00 9a 0b 56 6f 64 61 66 6f 6e 65 us......Vodafone Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: 2e 64 65 06 01 02 00 9a 0b 56 6f 64 61 66 6f 6e .de......Vodafon Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: 65 2e 64 65 06 01 01 00 9a 05 54 4d 4f 20 44 e.de......TMO D Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/qmibridge.c:ask_qmi() READ: QMI QMUX: QMI length = 110 QMI flags = 0x80 QMI service = "nas" QMI client = 2 QMI QMI: QMI flags = "response" QMI transaction = 275 QMI tlv_length = 98 QMI message = "Network Scan" (0x0021) QMI TLV: QMI type = "Result" (0x02) QMI length = 4 QMI value = 00:00:00:00 QMI translated = SUCCESS QMI TLV: QMI type = "Network Information" (0x10) QMI length = 88 QMI value = 07:00:85:03:46:00:66:00:06:01:01:00:9A:05:54:4D:4F:20 :44:06:01:03:00:9A:06:45:2D:50:6C:75:73:06:01:03:00:9A:06:45:2D:50:6C:75:73:06:01:02:00:9A:0B:56:6F:64:61:66:6F:6E:65:2E:64 :65:06:01:02:00:9A:0B:56:6F:64:61:66:6F:6E:65:2E:64:65:06:01:01:00:9A:05:54:4D:4F:20:44 QMI translated = { [0] = '[ mcc = '901' mnc = '70' network_status = 'a vailable, home, not-forbidden, preferred' description = '' ] ' [1] = '[ mcc = '262' mnc = '1' network_status = 'available, roaming, forbidden, not-preferred' description = 'TMO D' ] ' [2] = '[ mcc = '262' mnc = '3' network_status = 'available, ro aming, forbidden, not-preferred' description = 'E-Plus' ] ' [3] = '[ mcc = '262' mnc = '3' network_status = 'available, roa ming, forbidden, not-preferred' description = 'E-Plus' ] ' [4] = '[ mcc = '262' mnc = '2' network_status = 'available, roam ing, forbidden, not-preferred' description = 'Vodafone.de' ] ' [5] = '[ mcc = '262' mnc = '2' network_status = 'available, roaming, forbidden, not-preferred' description = 'Vodafone.de' ] ' [6] = '[ mcc = '262' mnc = '1' network_status = 'availab le, roaming, forbidden, not-preferred' description = 'TMO D' ] '} Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: NAS_resp msg=33 len=98 [client=2,type=2,tid=275,len=110] Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: {type=2,error=NONE} {type=16,len=88} Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:scan_nets_cb() Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:scan_nets_cb() found 7 operators Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:scan_nets_cb() (901:70) status 1 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:scan_nets_cb() TMO D (262:01) st atus 3 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:scan_nets_cb() E-Plus (262:03) s tatus 3 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:scan_nets_cb() E-Plus (262:03) s tatus 3 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:scan_nets_cb() Vodafone.de (262: 02) status 3 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:scan_nets_cb() Vodafone.de (262: 02) status 3 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:scan_nets_cb() TMO D (262:01) st atus 3 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: < 01 19 00 80 03 ff 04 00 00 24 00 0d 00 01 06 00 .........$...... Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: 00 02 02 00 01 00 11 01 00 00 .......... Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/qmibridge.c:ask_qmi() READ: QMI QMUX: QMI length = 25 QMI flags = 0x80 QMI service = "nas" QMI client = 255 QMI QMI: QMI flags = "indication" QMI transaction = 0 QMI tlv_length = 13 QMI message = "Serving System" (0x0024) QMI TLV: QMI type = "Serving System" (0x01) QMI length = 6 QMI value = 00:02:02:00:01:00 QMI translated = [ registration_state = 'not-registered' cs_attach_sta te = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ] QMI TLV: QMI type = "Data Service Capability" (0x11) QMI length = 1 QMI value = 00 QMI translated = {} Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: NAS_ind msg=36 len=13 [client=255,type=4,tid=0,len=25] Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: QMI: {type=1,len=6} {type=17,len=1} Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:ss_info_notify() Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:extract_ss_info() Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 0 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 0 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech -1 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: src/network.c:ofono_netreg_status_notify() /gobi_3 status 0 tech -1 lac -1 ci -1 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: src/network.c:current_operator_callback() 0x5613064f7e00, (nil) Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: src/gprs.c:netreg_status_changed() 0 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/gprs.c:ss_info_notify() Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/gprs.c:handle_ss_info() Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/gprs.c:extract_ss_info() Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/gprs.c:extract_ss_info() radio in use 0 Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: src/gprs.c:ofono_gprs_status_notify() /gobi_3 status 0 (unregistered) Sep 01 17:31:04 osmo-gsm-tester-rnd ofonod[31099]: src/gprs.c:ofono_gprs_detached_notify() /gobi_3 Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:qmi_register_manual() Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: > 01 18 00 00 03 02 00 14 01 22 00 0c 00 01 01 00 ........."...... Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: 02 10 05 00 85 03 46 00 ff ......F.. Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: NAS_req msg=34 len=12 [client=2,type=0,tid=276,len=24] Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: {type=1,len=1} {type=16,len=5} Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/qmibridge.c:ask_qmi() _REQ: QMI QMUX: QMI length = 24 QMI flags = 0x00 QMI service = "nas" QMI client = 2 QMI QMI: QMI flags = "none" QMI transaction = 276 QMI tlv_length = 12 QMI message = "Initiate Network Register" (0x0022) QMI TLV: QMI type = "Action" (0x01) QMI length = 1 QMI value = 02 QMI translated = manual QMI TLV: QMI type = "Manual Registration Info 3GPP" (0x10) QMI length = 5 QMI value = 85:03:46:00:FF QMI translated = [ mcc = '901' mnc = '70' radio_interface = 'unknown' ] Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: < 01 13 00 80 03 02 02 14 01 22 00 07 00 02 04 00 ........."...... Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: 01 00 19 00 .... Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/qmibridge.c:ask_qmi() READ: QMI QMUX: QMI length = 19 QMI flags = 0x80 QMI service = "nas" QMI client = 2 QMI QMI: QMI flags = "response" QMI transaction = 276 QMI tlv_length = 7 QMI message = "Initiate Network Register" (0x0022) QMI TLV: QMI type = "Result" (0x02) QMI length = 4 QMI value = 01:00:19:00 QMI translated = FAILURE: DeviceUnsupported Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: NAS_resp msg=34 len=7 [client=2,type=2,tid=276,len=19] Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: {type=2,error=OP_DEVICE_UNSUPPORTED} Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:register_net_cb() Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:qmi_registration_status() Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: > 01 0c 00 00 03 02 00 15 01 24 00 00 00 .........$... Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: NAS_req msg=36 len=0 [client=2,type=0,tid=277,len=12] Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/qmibridge.c:ask_qmi() _REQ: QMI QMUX: QMI length = 12 QMI flags = 0x00 QMI service = "nas" QMI client = 2 QMI QMI: QMI flags = "none" QMI transaction = 277 QMI tlv_length = 0 QMI message = "Get Serving System" (0x0024) Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: < 01 20 00 80 03 02 02 15 01 24 00 14 00 02 04 00 . .......$...... Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: 00 00 00 00 01 06 00 00 02 02 00 01 00 11 01 00 ................ Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: 00 . Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/qmibridge.c:ask_qmi() READ: QMI QMUX: QMI length = 32 QMI flags = 0x80 QMI service = "nas" QMI client = 2 QMI QMI: QMI flags = "response" QMI transaction = 277 QMI tlv_length = 20 QMI message = "Get Serving System" (0x0024) QMI TLV: QMI type = "Result" (0x02) QMI length = 4 QMI value = 00:00:00:00 QMI translated = SUCCESS QMI TLV: QMI type = "Serving System" (0x01) QMI length = 6 QMI value = 00:02:02:00:01:00 QMI translated = [ registration_state = 'not-registered' cs_attach_sta te = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ] QMI TLV: QMI type = "Data Service Capability" (0x11) QMI length = 1 QMI value = 00 QMI translated = {} Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: NAS_resp msg=36 len=20 [client=2,type=2,tid=277,len=32] Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: QMI: {type=2,error=NONE} {type=1,len=6} {type=17,len=1} Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:get_ss_info_cb() Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:extract_ss_info() Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:extract_ss_info() serving system status 0 Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:extract_ss_info() radio in use 0 Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: drivers/qmimodem/network-registration.c:extract_ss_info() lac -1 cellid -1 tech -1 Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: src/network.c:ofono_netreg_status_notify() /gobi_3 status 0 tech -1 lac -1 ci -1 Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: src/network.c:current_operator_callback() 0x5613064f7e00, (nil) Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: src/gprs.c:netreg_status_changed() 0 Sep 01 17:31:05 osmo-gsm-tester-rnd ofonod[31099]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 0