Bug #2713
openofono: chosen pdp type (v4, v6, dual) not strictly followed in ofono qmi
0%
Description
I am able to run -s sms -t ping.py fine with a SierraWireless modem in R&D setup, but /sierra_2 modem seems to fail systematically to achieve it during tests in PROD.
That's the issue from osmo-gsm-tester point of view (test failure):
14:23:28.448014 tst /sierra_2: DBG: status: searching [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:449] 14:23:29.531629 tst /sierra_2: DBG: 'org.ofono.NetworkRegistration'.PropertyChanged() -> Status=registered [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:443] 14:23:29.629196 tst /sierra_2: DBG: 'org.ofono.NetworkRegistration'.PropertyChanged() -> LocationAreaCode=12165 [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:443] 14:23:29.729500 tst /sierra_2: DBG: 'org.ofono.NetworkRegistration'.PropertyChanged() -> CellId=12165 [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:443] 14:23:29.828394 tst /sierra_2: DBG: 'org.ofono.NetworkRegistration'.PropertyChanged() -> Name=osmo-gsm-tester-nitb [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:443] 14:23:29.920381 tst /sierra_2: DBG: 'org.ofono.NetworkRegistration'.PropertyChanged() -> MobileCountryCode=901 [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:443] 14:23:30.005776 tst /sierra_2: DBG: 'org.ofono.NetworkRegistration'.PropertyChanged() -> MobileNetworkCode=70 [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:443] 14:23:30.066072 tst /sierra_2: DBG: 'org.ofono.NetworkRegistration'.PropertyChanged() -> Strength=40 [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:443] 14:23:30.140646 tst /sierra_2: DBG: status: registered [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:449] 14:23:30.212708 bus Ctrl(host='10.42.42.8', port=4255): DBG: Connecting [trial-4116↪gprs:trx-b200↪osmo-msc_10.42.42.8↪CTRL(10.42.42.8:4255)↪Ctrl(host='10.42.42.8', port=4255)] [osmo_ctrl.py:54] 14:23:30.281244 bus Ctrl(host='10.42.42.8', port=4255): DBG: Sending {data='GET 0 subscriber-list-active-v1'} [trial-4116↪gprs:trx-b200↪osmo-msc_10.42.42.8↪CTRL(10.42.42.8:4255)↪Ctrl(host='10.42.42.8', port=4255)] [osmo_ctrl.py:65] 14:23:30.366858 bus Ctrl(host='10.42.42.8', port=4255): DBG: Receiving {data=b'\x00=\xee\x00GET_REPLY 0 subscriber-list-active-v1 901700000015252,21439\n'} [trial-4116↪gprs:trx-b200↪osmo-msc_10.42.42.8↪CTRL(10.42.42.8:4255)↪Ctrl(host='10.42.42.8', port=4255)] [osmo_ctrl.py:71] 14:23:30.471581 bus Ctrl(host='10.42.42.8', port=4255): DBG: Disconnecting [trial-4116↪gprs:trx-b200↪osmo-msc_10.42.42.8↪CTRL(10.42.42.8:4255)↪Ctrl(host='10.42.42.8', port=4255)] [osmo_ctrl.py:60] 14:23:30.583918 run osmo-msc_10.42.42.8: DBG: attached: GET_REPLY 0 subscriber-list-active-v1 901700000015252,21439 [trial-4116↪gprs:trx-b200↪osmo-msc_10.42.42.8] [osmo_msc.py:129] 14:23:30.846131 tst ping.py:45: waiting for modems to attach to data services... [trial-4116↪gprs:trx-b200↪ping.py:45] [ping.py:45] 14:23:31.223555 tst /sierra_2: DBG: attached: False [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:579] 14:23:32.291954 tst /sierra_2: DBG: attached: False [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:579] 14:23:33.363160 tst /sierra_2: DBG: 'org.ofono.ConnectionManager'.PropertyChanged() -> Attached=True [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:723] 14:23:33.432808 tst /sierra_2: DBG: attached: True [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:579] 14:23:33.499989 tst /sierra_2: DBG: activate_context {apn='internet', user='ogt'} [trial-4116↪gprs:trx-b200↪/sierra_2] [modem.py:599] 14:23:36.999938 tst ping.py:47: ERR: Error: g-io-error-quark: GDBus.Error:org.ofono.Error.Failed: Operation failed (36) [trial-4116↪gprs:trx-b200↪ping.py:47] [proxy_method.py:75: 0, timeout_to_glib(timeout), None).unpack()] 14:23:37.007427 tst ping.py:47: TRACEBACK: Traceback (most recent call last): File "/home/jenkins/workspace/osmo-gsm-tester_run/osmo-gsm-tester/src/osmo_gsm_tester/test.py", line 61, in run self.path) File "/home/jenkins/workspace/osmo-gsm-tester_run/osmo-gsm-tester/src/osmo_gsm_tester/util.py", line 308, in run_python_file SourceFileLoader(module_name, path).load_module() File "<frozen importlib._bootstrap>", line 539, in _check_name_wrapper File "<frozen importlib._bootstrap>", line 1614, in load_module File "<frozen importlib._bootstrap>", line 596, in _load_module_shim File "<frozen importlib._bootstrap>", line 1220, in load File "<frozen importlib._bootstrap>", line 1200, in _load_unlocked File "<frozen importlib._bootstrap>", line 1129, in _exec File "<frozen importlib._bootstrap>", line 1471, in exec_module File "<frozen importlib._bootstrap>", line 321, in _call_with_frames_removed File "/home/jenkins/workspace/osmo-gsm-tester_run/osmo-gsm-tester/suites/gprs/ping.py", line 47, in <module> ctx_id_v4 = ms.activate_context(apn='internet', protocol=ms.CTX_PROT_IPv4) File "/home/jenkins/workspace/osmo-gsm-tester_run/osmo-gsm-tester/src/osmo_gsm_tester/modem.py", line 611, in activate_context ctx.SetProperty('Active', Variant('b', True)) File "/usr/local/lib/python3.4/dist-packages/pydbus/proxy_method.py", line 75, in __call__ 0, timeout_to_glib(timeout), None).unpack() GLib.Error: g-io-error-quark: GDBus.Error:org.ofono.Error.Failed: Operation failed (36)
During that time, ofono.log shows:
Dec 06 14:23:31.583936 testbed-production ofonod[25802]: drivers/qmimodem/network-registration.c:get_rssi_cb() Dec 06 14:23:36.991841 testbed-production ofonod[25802]: drivers/qmimodem/qmibridge.c:ask_qmi() READ: QMI QMUX: QMI length = 31 QMI flags = 0x80 QMI service = "wds" QMI client = 9 QMI QMI: QMI flags = "response" QMI transaction = 358 QMI tlv_length = 19 QMI message = "Start Network" (0x0020) QMI TLV: QMI type = "Result" (0x02) QMI length = 4 QMI value = 01:00:0E:00 QMI translated = FAILURE: CallFailed QMI TLV: QMI type = "Call End Reason" (0x10) QMI length = 2 QMI value = F5:03 QMI translated = gsm-wcdma-unknown-apn QMI TLV: QMI type = "Verbose Call End Reason" (0x11) QMI length = 4 QMI value = 06:00:1B:00 QMI translated = [ type = '3gpp' reason = '27' ] Dec 06 14:23:36.991897 testbed-production ofonod[25802]: drivers/qmimodem/gprs-context.c:start_net_cb() Dec 06 14:23:36.991922 testbed-production ofonod[25802]: src/gprs.c:pri_activate_callback() 0x6fed140 Dec 06 14:23:36.991944 testbed-production ofonod[25802]: src/gprs.c:pri_activate_callback() Activating context failed with error: Unknown error type Dec 06 14:23:50.401621 testbed-production ofonod[25802]: src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: 1 Dec 06 14:23:50.401676 testbed-production ofonod[25802]: drivers/qmimodem/gprs.c:qmi_set_attached() attached 0
Files
Related issues
Updated by pespin over 6 years ago
- Subject changed from ofono: sierra_2 modem in prod unable to activate context to osmo-gsm-tester: sierra_2 modem in prod unable to activate context
- Status changed from New to In Progress
- Assignee changed from 55360 to pespin
The GGSN is sending an error inside the "Create PDP context request" message, as can be seen in the osmo-sgsn pcap trace in the tar.gz with all the run logs.
It worked in my R&D setup because I was using an older fixed version (3897). Once moving to the new trial (4117), I get the same issue in R&D. So, it seems between 3897->4117 something changed which we are not taking into account in osmo-gsm-tester, or we introduced a regression.
Updated by neels over 6 years ago
translated = gsm-wcdma-unknown-apn
- WCDMA is the wrong RAN, this is about 2G, right?
- Does the APN the modem is using match the osmo-ggsn config? Or does the osmo-ggsn config have a default APN set?
That's what comes to mind on the first glance.
Updated by pespin over 6 years ago
- Subject changed from osmo-gsm-tester: sierra_2 modem in prod unable to activate context to ofono: chosen pdp type (v4, v6, dual) not strictly followed in ofono qmi
That's probably related to the "ims" pdp context which is an automatic one which is always created to support voice calls through packet-switched network, used for instance in LTE as far as I've been told. In the pcap traces we can actually see the modem trying to activate that one ("ims") while concurrently activating our own one ("internet").
The main issue seems to be that ofono doesn't have complete support for setting up contexts and it only specifies the kind of IP address it wants, but leaves the PDP type decision to the modem, which might use IPv4v6 to fullfil the IPv4 requirement. The problem is that osmo-ggsn didn't support Context Request for this kind of pdp type. I created a patch which adds support for it. After it is merged, the modem should be able to activate the context: https://gerrit.osmocom.org/#/c/5216/
The difference here is that in R&D, the modem tries to establish an IPv4 ctx after the IPV4v6 is rejected, and as a result it can eventually activate the context. In PROD env, however, it never tries to use IPv4 after the IPV4v6 one is rejected. lynxis pointed out that they may have been configured differently through the AT interface.
We still want to support specifying the type of PDP context we want to create from ofono user point of view, and so we should implement the missing bits in there to be able to do so. Consequently, I rename the task again to be ofono-related and paste here parts of the conversation with lynxis regarding next steps:
ofono doesn't can not set the context type in a direct way missing things in the ofono-qmi thing ofono just ask the modem via qmi: attach context and I need a ipv4 address. it should do "create pdp context type: ipv4, activate this context" the whole pdp context handling is missing in ofono drivers/qmimodem/gprs-context.c: qmi_activate_primary() qmi_activate_primary is using APN/username/password/ipfamily as context. ipfamily != pdp context type qmi_activate_primary should use "Profile Index 3GPP" or " Profile Index 3GPP2" instead which need to be created before ipfamily = ipv4 "might" use a "dual". my ec20 first tried to get an dual context, because this fails, it's trying to get an ipv4 context
Information on the structures requeried to implement this new QMI WDS methods can be found in: https://cgit.freedesktop.org/libqmi/tree/data/qmi-service-wds.json , grep for "Create Profile", "Start Network" and "Profile Index 3GPP".
Updated by pespin over 6 years ago
- Status changed from In Progress to New
- Assignee changed from pespin to lynxis
Updated by pespin over 6 years ago
- Related to Bug #2683: ofono: EC20 failing to create ipv6 or dual contexts added