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
Updated by lynxis over 6 years ago
- Status changed from New to In Progress
- % Done changed from 0 to 70
I've implemented the more specific error reporting and pushed it to sysmocom/lynxis/master
It needs now testing with the gobi2000.
Updated by pespin over 6 years ago
- Assignee changed from lynxis to pespin
Assigning to myself to test it in RnD.
Updated by pespin over 6 years ago
- Assignee changed from pespin to lynxis
Still failing with the same "[ERR]: GDBus.Error:org.ofono.Error.Failed: Operation failed" after testing with the patches from lynxis.
Updated by lynxis over 6 years ago
root@osmo-gsm-tester-rnd:~# mdbus2 -s org.ofono /gobi_3/operator/26201 org.ofono.NetworkOperator.Register [ERR]: GDBus.Error:org.ofono.Error.NotSupported: Operation is not supported by the network / modem
Updated by lynxis over 6 years ago
- Status changed from In Progress to Feedback
- Assignee changed from lynxis to pespin
pespin: it works for me on the RnD setup.
Updated by pespin over 6 years ago
- Assignee changed from pespin to lynxis
- % Done changed from 70 to 90
Ok, ofono patch is now fixed and working. I wrote an osmo-gsm-tester patch to use that error and fallback to automatic registering, see https://gerrit.osmocom.org/#/c/4720/.
I assign the task back to you as the ofono patch still lacks upstreaming.
Updated by lynxis almost 6 years ago
- Status changed from Feedback to Closed
- % Done changed from 90 to 100