Project

General

Profile

Bug #2713

ofono: chosen pdp type (v4, v6, dual) not strictly followed in ofono qmi

Added by pespin 11 days ago. Updated 10 days ago.

Status:
New
Priority:
Normal
Assignee:
Target version:
-
Start date:
12/06/2017
Due date:
% Done:

0%

Spec Reference:

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

trial-4116-run.tgz (4.78 MB) pespin, 12/06/2017 02:23 PM


Related issues

Related to OsmoGSMTester - Bug #2683: ofono: EC20 failing to create ipv6 or dual contexts In Progress 11/27/2017

History

#1 Updated by pespin 11 days ago

  • Assignee set to osmo-gsm-tester

#2 Updated by pespin 11 days 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 osmo-gsm-tester 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.

#3 Updated by neels 11 days 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.

#4 Updated by pespin 10 days 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".

#5 Updated by pespin 10 days ago

  • Status changed from In Progress to New
  • Assignee changed from pespin to lynxis

#6 Updated by pespin 5 days ago

  • Related to Bug #2683: ofono: EC20 failing to create ipv6 or dual contexts added

Also available in: Atom PDF