Bug 99661

Summary: ARM: nas_serving_system indication causes alignment trap
Product: libqmi Reporter: Wolfgang <wtolkien>
Component: libqmiAssignee: Dan Williams <dcbw>
Status: RESOLVED NOTOURBUG QA Contact:
Severity: normal    
Priority: medium    
Version: unspecified   
Hardware: ARM   
OS: Linux (All)   
Whiteboard:
i915 platform: i915 features:

Description Wolfgang 2017-02-03 02:38:04 UTC
I've just started to use libqmi on an AM335x platform (ARM Cortex-A8) with a Sierra MC7354 module. Under certain circumstances I'm getting an 'Alignment trap' error which causes the kernel to send SIGBUS to my application. I can reliably trigger the error by having my application do the following:

- setup a callback for NAS Serving System Indications (to detect registration state)
- establish an LTE connection
- disconnect the antenna from the module to trigger loss of registration
- re-connect the antenna to re-register

When re-registration occurs, there are typically a few 'Serving System' indications and this will trigger the problem. Note that I can leave the system online for hours with numerous prior 'Serving System' indications without any problems.

However, if I disconnect and reconnect the antenna (and thereby force a loss of registration) the problem occurs reliably every time when the cell module re-registers. 

I started out with libqmi 1.16 and glib 2.37 and then upgraded to libqmi 1.17.900 and glib 2.50.2, but nothing changed.

Here is the syslog showing the whole antenna disconnect/reconnect sequence. GDB output is below.

Any help would be greatly appreciated!

Wolfgang


<128> Feb  2 18:11:22 ql-dial: [/dev/cdc-wdm0] Received message...
<128> Feb  2 18:11:22 ql-dial: >>>>>> RAW:
<128> Feb  2 18:11:22 ql-dial: >>>>>>   length = 56
<128> Feb  2 18:11:22 ql-dial: >>>>>>   data   = 01:37:00:80:03:01:04:00:00:24:00:2B:00:29:05:00:2E:01:D0:02:01:1E:04:00:05:1D:60:01:12:0B:00:2E:01:D0:02:06:52:4F:47:45:52:53:11:02:00:01:0B:01:06:00:01:01:01:02:01:08
<128> Feb  2 18:11:22 ql-dial: [/dev/cdc-wdm0] Received message (translated)...
<128> Feb  2 18:11:22 ql-dial: >>>>>> QMUX:
<128> Feb  2 18:11:22 ql-dial: >>>>>>   length  = 55
<128> Feb  2 18:11:22 ql-dial: >>>>>>   flags   = 0x80
<128> Feb  2 18:11:22 ql-dial: >>>>>>   service = "nas"
<128> Feb  2 18:11:22 ql-dial: >>>>>>   client  = 1
<128> Feb  2 18:11:22 ql-dial: >>>>>> QMI:
<128> Feb  2 18:11:22 ql-dial: >>>>>>   flags       = "indication"
<128> Feb  2 18:11:22 ql-dial: >>>>>>   transaction = 0
<128> Feb  2 18:11:22 ql-dial: >>>>>>   tlv_length  = 43
<128> Feb  2 18:11:22 ql-dial: >>>>>>   message     = "Serving System" (0x0024)
<128> Feb  2 18:11:22 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:22 ql-dial: >>>>>>   type       = "MNC PCS Digit Include Status" (0x29)
<128> Feb  2 18:11:22 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:11:22 ql-dial: >>>>>>   value      = 2E:01:D0:02:01
<128> Feb  2 18:11:22 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' includes_pcs_digit = 'yes' ]
<128> Feb  2 18:11:22 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:22 ql-dial: >>>>>>   type       = "CID 3GPP" (0x1e)
<128> Feb  2 18:11:22 ql-dial: >>>>>>   length     = 4
<128> Feb  2 18:11:22 ql-dial: >>>>>>   value      = 05:1D:60:01
<128> Feb  2 18:11:22 ql-dial: >>>>>>   translated = 23076101
<128> Feb  2 18:11:22 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:22 ql-dial: >>>>>>   type       = "Current PLMN" (0x12)
<128> Feb  2 18:11:22 ql-dial: >>>>>>   length     = 11
<128> Feb  2 18:11:22 ql-dial: >>>>>>   value      = 2E:01:D0:02:06:52:4F:47:45:52:53
<128> Feb  2 18:11:22 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' description = 'ROGERS' ]
<128> Feb  2 18:11:22 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:22 ql-dial: >>>>>>   type       = "Data Service Capability" (0x11)
<128> Feb  2 18:11:22 ql-dial: >>>>>>   length     = 2
<128> Feb  2 18:11:22 ql-dial: >>>>>>   value      = 01:0B
<128> Feb  2 18:11:22 ql-dial: >>>>>>   translated = { [0] = 'lte '}
<128> Feb  2 18:11:22 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:22 ql-dial: >>>>>>   type       = "Serving System" (0x01)
<128> Feb  2 18:11:22 ql-dial: >>>>>>   length     = 6
<128> Feb  2 18:11:22 ql-dial: >>>>>>   value      = 01:01:01:02:01:08
<128> Feb  2 18:11:22 ql-dial: >>>>>>   translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'attached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'lte '}' ]
<128> Feb  2 18:11:22 ql-dial: received serving system callback (0)
<128> Feb  2 18:11:24 ql-dial: [/dev/cdc-wdm0] Received message...
<128> Feb  2 18:11:24 ql-dial: >>>>>> RAW:
<128> Feb  2 18:11:24 ql-dial: >>>>>>   length = 49
<128> Feb  2 18:11:24 ql-dial: >>>>>>   data   = 01:30:00:80:03:01:04:00:00:24:00:24:00:29:05:00:2E:01:D0:02:01:12:0B:00:2E:01:D0:02:06:52:4F:47:45:52:53:11:02:00:01:0B:01:06:00:01:01:01:02:01:08
<128> Feb  2 18:11:24 ql-dial: [/dev/cdc-wdm0] Received message (translated)...
<128> Feb  2 18:11:24 ql-dial: >>>>>> QMUX:
<128> Feb  2 18:11:24 ql-dial: >>>>>>   length  = 48
<128> Feb  2 18:11:24 ql-dial: >>>>>>   flags   = 0x80
<128> Feb  2 18:11:24 ql-dial: >>>>>>   service = "nas"
<128> Feb  2 18:11:24 ql-dial: >>>>>>   client  = 1
<128> Feb  2 18:11:24 ql-dial: >>>>>> QMI:
<128> Feb  2 18:11:24 ql-dial: >>>>>>   flags       = "indication"
<128> Feb  2 18:11:24 ql-dial: >>>>>>   transaction = 0
<128> Feb  2 18:11:24 ql-dial: >>>>>>   tlv_length  = 36
<128> Feb  2 18:11:24 ql-dial: >>>>>>   message     = "Serving System" (0x0024)
<128> Feb  2 18:11:24 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:24 ql-dial: >>>>>>   type       = "MNC PCS Digit Include Status" (0x29)
<128> Feb  2 18:11:24 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:11:24 ql-dial: >>>>>>   value      = 2E:01:D0:02:01
<128> Feb  2 18:11:24 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' includes_pcs_digit = 'yes' ]
<128> Feb  2 18:11:24 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:24 ql-dial: >>>>>>   type       = "Current PLMN" (0x12)
<128> Feb  2 18:11:24 ql-dial: >>>>>>   length     = 11
<128> Feb  2 18:11:24 ql-dial: >>>>>>   value      = 2E:01:D0:02:06:52:4F:47:45:52:53
<128> Feb  2 18:11:24 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' description = 'ROGERS' ]
<128> Feb  2 18:11:24 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:24 ql-dial: >>>>>>   type       = "Data Service Capability" (0x11)
<128> Feb  2 18:11:24 ql-dial: >>>>>>   length     = 2
<128> Feb  2 18:11:24 ql-dial: >>>>>>   value      = 01:0B
<128> Feb  2 18:11:24 ql-dial: >>>>>>   translated = { [0] = 'lte '}
<128> Feb  2 18:11:24 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:24 ql-dial: >>>>>>   type       = "Serving System" (0x01)
<128> Feb  2 18:11:24 ql-dial: >>>>>>   length     = 6
<128> Feb  2 18:11:24 ql-dial: >>>>>>   value      = 01:01:01:02:01:08
<128> Feb  2 18:11:24 ql-dial: >>>>>>   translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'attached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'lte '}' ]
<128> Feb  2 18:11:24 ql-dial: received serving system callback (1)
<029> Feb  2 18:11:31 notify: (O3-359225055376453) No Radio
<128> Feb  2 18:11:38 ql-dial: [/dev/cdc-wdm0] Received message...
<128> Feb  2 18:11:38 ql-dial: >>>>>> RAW:
<128> Feb  2 18:11:38 ql-dial: >>>>>>   length = 34
<128> Feb  2 18:11:38 ql-dial: >>>>>>   data   = 01:21:00:80:03:01:04:00:00:24:00:15:00:22:05:00:00:03:00:01:00:11:01:00:00:01:06:00:02:02:02:00:01:00
<128> Feb  2 18:11:38 ql-dial: [/dev/cdc-wdm0] Received message (translated)...
<128> Feb  2 18:11:38 ql-dial: >>>>>> QMUX:
<128> Feb  2 18:11:38 ql-dial: >>>>>>   length  = 33
<128> Feb  2 18:11:38 ql-dial: >>>>>>   flags   = 0x80
<128> Feb  2 18:11:38 ql-dial: >>>>>>   service = "nas"
<128> Feb  2 18:11:38 ql-dial: >>>>>>   client  = 1
<128> Feb  2 18:11:38 ql-dial: >>>>>> QMI:
<128> Feb  2 18:11:38 ql-dial: >>>>>>   flags       = "indication"
<128> Feb  2 18:11:38 ql-dial: >>>>>>   transaction = 0
<128> Feb  2 18:11:38 ql-dial: >>>>>>   tlv_length  = 21
<128> Feb  2 18:11:38 ql-dial: >>>>>>   message     = "Serving System" (0x0024)
<128> Feb  2 18:11:38 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:38 ql-dial: >>>>>>   type       = "Detailed Service Status" (0x22)
<128> Feb  2 18:11:38 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:11:38 ql-dial: >>>>>>   value      = 00:03:00:01:00
<128> Feb  2 18:11:38 ql-dial: >>>>>>   translated = [ status = 'none' capability = 'cs-ps' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<128> Feb  2 18:11:38 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:38 ql-dial: >>>>>>   type       = "Data Service Capability" (0x11)
<128> Feb  2 18:11:38 ql-dial: >>>>>>   length     = 1
<128> Feb  2 18:11:38 ql-dial: >>>>>>   value      = 00
<128> Feb  2 18:11:38 ql-dial: >>>>>>   translated = {}
<128> Feb  2 18:11:38 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:38 ql-dial: >>>>>>   type       = "Serving System" (0x01)
<128> Feb  2 18:11:38 ql-dial: >>>>>>   length     = 6
<128> Feb  2 18:11:38 ql-dial: >>>>>>   value      = 02:02:02:00:01:00
<128> Feb  2 18:11:38 ql-dial: >>>>>>   translated = [ registration_state = 'not-registered-searching' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ]
<128> Feb  2 18:11:38 ql-dial: received serving system callback (1)
<128> Feb  2 18:11:44 ql-dial: [/dev/cdc-wdm0] Received message...
<128> Feb  2 18:11:44 ql-dial: >>>>>> RAW:
<128> Feb  2 18:11:44 ql-dial: >>>>>>   length = 34
<128> Feb  2 18:11:44 ql-dial: >>>>>>   data   = 01:21:00:80:03:01:04:00:00:24:00:15:00:22:05:00:04:03:00:01:00:11:01:00:00:01:06:00:00:02:02:00:01:00
<128> Feb  2 18:11:44 ql-dial: [/dev/cdc-wdm0] Received message (translated)...
<128> Feb  2 18:11:44 ql-dial: >>>>>> QMUX:
<128> Feb  2 18:11:44 ql-dial: >>>>>>   length  = 33
<128> Feb  2 18:11:44 ql-dial: >>>>>>   flags   = 0x80
<128> Feb  2 18:11:44 ql-dial: >>>>>>   service = "nas"
<128> Feb  2 18:11:44 ql-dial: >>>>>>   client  = 1
<128> Feb  2 18:11:44 ql-dial: >>>>>> QMI:
<128> Feb  2 18:11:44 ql-dial: >>>>>>   flags       = "indication"
<128> Feb  2 18:11:44 ql-dial: >>>>>>   transaction = 0
<128> Feb  2 18:11:44 ql-dial: >>>>>>   tlv_length  = 21
<128> Feb  2 18:11:44 ql-dial: >>>>>>   message     = "Serving System" (0x0024)
<128> Feb  2 18:11:44 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:44 ql-dial: >>>>>>   type       = "Detailed Service Status" (0x22)
<128> Feb  2 18:11:44 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:11:44 ql-dial: >>>>>>   value      = 04:03:00:01:00
<128> Feb  2 18:11:44 ql-dial: >>>>>>   translated = [ status = 'power-save' capability = 'cs-ps' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<128> Feb  2 18:11:44 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:44 ql-dial: >>>>>>   type       = "Data Service Capability" (0x11)
<128> Feb  2 18:11:44 ql-dial: >>>>>>   length     = 1
<128> Feb  2 18:11:44 ql-dial: >>>>>>   value      = 00
<128> Feb  2 18:11:44 ql-dial: >>>>>>   translated = {}
<128> Feb  2 18:11:44 ql-dial: >>>>>> TLV:
<128> Feb  2 18:11:44 ql-dial: >>>>>>   type       = "Serving System" (0x01)
<128> Feb  2 18:11:44 ql-dial: >>>>>>   length     = 6
<128> Feb  2 18:11:44 ql-dial: >>>>>>   value      = 00:02:02:00:01:00
<128> Feb  2 18:11:44 ql-dial: >>>>>>   translated = [ registration_state = 'not-registered' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = 'unknown' radio_interfaces = '{ [0] = 'none '}' ]
<128> Feb  2 18:11:44 ql-dial: received serving system callback (1)
<128> Feb  2 18:12:14 ql-dial: [/dev/cdc-wdm0] Received message...
<128> Feb  2 18:12:14 ql-dial: >>>>>> RAW:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   length = 66
<128> Feb  2 18:12:14 ql-dial: >>>>>>   data   = 01:41:00:80:03:01:04:00:00:24:00:35:00:29:05:00:2E:01:D0:02:01:22:05:00:01:02:00:01:00:15:03:00:01:08:01:12:0B:00:2E:01:D0:02:06:52:4F:47:45:52:53:11:01:00:00:10:01:00:01:01:06:00:02:02:02:02:01:08
<128> Feb  2 18:12:14 ql-dial: [/dev/cdc-wdm0] Received message (translated)...
<128> Feb  2 18:12:14 ql-dial: >>>>>> QMUX:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   length  = 65
<128> Feb  2 18:12:14 ql-dial: >>>>>>   flags   = 0x80
<128> Feb  2 18:12:14 ql-dial: >>>>>>   service = "nas"
<128> Feb  2 18:12:14 ql-dial: >>>>>>   client  = 1
<128> Feb  2 18:12:14 ql-dial: >>>>>> QMI:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   flags       = "indication"
<128> Feb  2 18:12:14 ql-dial: >>>>>>   transaction = 0
<128> Feb  2 18:12:14 ql-dial: >>>>>>   tlv_length  = 53
<128> Feb  2 18:12:14 ql-dial: >>>>>>   message     = "Serving System" (0x0024)
<128> Feb  2 18:12:14 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   type       = "MNC PCS Digit Include Status" (0x29)
<128> Feb  2 18:12:14 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:12:14 ql-dial: >>>>>>   value      = 2E:01:D0:02:01
<128> Feb  2 18:12:14 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' includes_pcs_digit = 'yes' ]
<128> Feb  2 18:12:14 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   type       = "Detailed Service Status" (0x22)
<128> Feb  2 18:12:14 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:12:14 ql-dial: >>>>>>   value      = 01:02:00:01:00
<128> Feb  2 18:12:14 ql-dial: >>>>>>   translated = [ status = 'limited' capability = 'ps' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<128> Feb  2 18:12:14 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   type       = "Roaming Indicator List" (0x15)
<128> Feb  2 18:12:14 ql-dial: >>>>>>   length     = 3
<128> Feb  2 18:12:14 ql-dial: >>>>>>   value      = 01:08:01
<128> Feb  2 18:12:14 ql-dial: >>>>>>   translated = { [0] = '[ radio_interface = 'lte' roaming_indicator = 'off' ] '}
<128> Feb  2 18:12:14 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   type       = "Current PLMN" (0x12)
<128> Feb  2 18:12:14 ql-dial: >>>>>>   length     = 11
<128> Feb  2 18:12:14 ql-dial: >>>>>>   value      = 2E:01:D0:02:06:52:4F:47:45:52:53
<128> Feb  2 18:12:14 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' description = 'ROGERS' ]
<128> Feb  2 18:12:14 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   type       = "Data Service Capability" (0x11)
<128> Feb  2 18:12:14 ql-dial: >>>>>>   length     = 1
<128> Feb  2 18:12:14 ql-dial: >>>>>>   value      = 00
<128> Feb  2 18:12:14 ql-dial: >>>>>>   translated = {}
<128> Feb  2 18:12:14 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   type       = "Roaming Indicator" (0x10)
<128> Feb  2 18:12:14 ql-dial: >>>>>>   length     = 1
<128> Feb  2 18:12:14 ql-dial: >>>>>>   value      = 01
<128> Feb  2 18:12:14 ql-dial: >>>>>>   translated = off
<128> Feb  2 18:12:14 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   type       = "Serving System" (0x01)
<128> Feb  2 18:12:14 ql-dial: >>>>>>   length     = 6
<128> Feb  2 18:12:14 ql-dial: >>>>>>   value      = 02:02:02:02:01:08
<128> Feb  2 18:12:14 ql-dial: >>>>>>   translated = [ registration_state = 'not-registered-searching' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'lte '}' ]
<128> Feb  2 18:12:14 ql-dial: received serving system callback (1)
<128> Feb  2 18:12:14 ql-dial: [/dev/cdc-wdm0] Received message...
<128> Feb  2 18:12:14 ql-dial: >>>>>> RAW:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   length = 48
<128> Feb  2 18:12:14 ql-dial: >>>>>>   data   = 01:2F:00:80:03:01:04:00:00:24:00:23:00:29:05:00:2E:01:D0:02:01:12:0B:00:2E:01:D0:02:06:52:4F:47:45:52:53:11:01:00:00:01:06:00:02:02:02:02:01:08
<128> Feb  2 18:12:14 ql-dial: [/dev/cdc-wdm0] Received message (translated)...
<128> Feb  2 18:12:14 ql-dial: >>>>>> QMUX:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   length  = 47
<128> Feb  2 18:12:14 ql-dial: >>>>>>   flags   = 0x80
<128> Feb  2 18:12:14 ql-dial: >>>>>>   service = "nas"
<128> Feb  2 18:12:14 ql-dial: >>>>>>   client  = 1
<128> Feb  2 18:12:14 ql-dial: >>>>>> QMI:
<128> Feb  2 18:12:14 ql-dial: >>>>>>   flags       = "indication"
<128> Feb  2 18:12:14 ql-dial: >>>>>>   transaction = 0
<128> Feb  2 18:12:14 ql-dial: >>>>>>   tlv_length  = 35
<128> Feb  2 18:12:14 ql-dial: >>>>>>   message     = "Serving System" (0x0024)
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "MNC PCS Digit Include Status" (0x29)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 2E:01:D0:02:01
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' includes_pcs_digit = 'yes' ]
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "Current PLMN" (0x12)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 11
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 2E:01:D0:02:06:52:4F:47:45:52:53
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' description = 'ROGERS' ]
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "Data Service Capability" (0x11)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 1
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 00
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = {}
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "Serving System" (0x01)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 6
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 02:02:02:02:01:08
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = [ registration_state = 'not-registered-searching' cs_attach_state = 'detached' ps_attach_state = 'detached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'lte '}' ]
<128> Feb  2 18:12:15 ql-dial: received serving system callback (1)
<128> Feb  2 18:12:15 ql-dial: [/dev/cdc-wdm0] Received message...
<128> Feb  2 18:12:15 ql-dial: >>>>>> RAW:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length = 68
<128> Feb  2 18:12:15 ql-dial: >>>>>>   data   = 01:43:00:80:03:01:04:00:00:24:00:37:00:29:05:00:2E:01:D0:02:01:25:02:00:80:89:22:05:00:02:03:00:01:00:1E:04:00:01:C3:5F:01:1D:02:00:FE:FF:12:05:00:2E:01:D0:02:00:11:02:00:01:0B:01:06:00:01:01:01:02:01:08
<128> Feb  2 18:12:15 ql-dial: [/dev/cdc-wdm0] Received message (translated)...
<128> Feb  2 18:12:15 ql-dial: >>>>>> QMUX:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length  = 67
<128> Feb  2 18:12:15 ql-dial: >>>>>>   flags   = 0x80
<128> Feb  2 18:12:15 ql-dial: >>>>>>   service = "nas"
<128> Feb  2 18:12:15 ql-dial: >>>>>>   client  = 1
<128> Feb  2 18:12:15 ql-dial: >>>>>> QMI:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   flags       = "indication"
<128> Feb  2 18:12:15 ql-dial: >>>>>>   transaction = 0
<128> Feb  2 18:12:15 ql-dial: >>>>>>   tlv_length  = 55
<128> Feb  2 18:12:15 ql-dial: >>>>>>   message     = "Serving System" (0x0024)
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "MNC PCS Digit Include Status" (0x29)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 2E:01:D0:02:01
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' includes_pcs_digit = 'yes' ]
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "LTE TAC" (0x25)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 2
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 80:89
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = 35200
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "Detailed Service Status" (0x22)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 02:03:00:01:00
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = [ status = 'available' capability = 'cs-ps' hdr_status = 'none' hdr_hybrid = 'yes' forbidden = 'no' ]
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "CID 3GPP" (0x1e)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 4
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 01:C3:5F:01
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = 23053057
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "LAC 3GPP" (0x1d)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 2
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = FE:FF
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = 65534
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "Current PLMN" (0x12)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 2E:01:D0:02:00
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' description = '' ]
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "Data Service Capability" (0x11)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 2
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 01:0B
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = { [0] = 'lte '}
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "Serving System" (0x01)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 6
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 01:01:01:02:01:08
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'attached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'lte '}' ]
<128> Feb  2 18:12:15 ql-dial: received serving system callback (1)
<128> Feb  2 18:12:15 ql-dial: [/dev/cdc-wdm0] Received message...
<128> Feb  2 18:12:15 ql-dial: >>>>>> RAW:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length = 43
<128> Feb  2 18:12:15 ql-dial: >>>>>>   data   = 01:2A:00:80:03:01:04:00:00:24:00:1E:00:29:05:00:2E:01:D0:02:01:12:05:00:2E:01:D0:02:00:11:02:00:01:0B:01:06:00:01:01:01:02:01:08
<128> Feb  2 18:12:15 ql-dial: [/dev/cdc-wdm0] Received message (translated)...
<128> Feb  2 18:12:15 ql-dial: >>>>>> QMUX:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length  = 42
<128> Feb  2 18:12:15 ql-dial: >>>>>>   flags   = 0x80
<128> Feb  2 18:12:15 ql-dial: >>>>>>   service = "nas"
<128> Feb  2 18:12:15 ql-dial: >>>>>>   client  = 1
<128> Feb  2 18:12:15 ql-dial: >>>>>> QMI:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   flags       = "indication"
<128> Feb  2 18:12:15 ql-dial: >>>>>>   transaction = 0
<128> Feb  2 18:12:15 ql-dial: >>>>>>   tlv_length  = 30
<128> Feb  2 18:12:15 ql-dial: >>>>>>   message     = "Serving System" (0x0024)
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "MNC PCS Digit Include Status" (0x29)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 2E:01:D0:02:01
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' includes_pcs_digit = 'yes' ]
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "Current PLMN" (0x12)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 5
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 2E:01:D0:02:00
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = [ mcc = '302' mnc = '720' description = '' ]
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "Data Service Capability" (0x11)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 2
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 01:0B
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = { [0] = 'lte '}
<128> Feb  2 18:12:15 ql-dial: >>>>>> TLV:
<128> Feb  2 18:12:15 ql-dial: >>>>>>   type       = "Serving System" (0x01)
<128> Feb  2 18:12:15 ql-dial: >>>>>>   length     = 6
<128> Feb  2 18:12:15 ql-dial: >>>>>>   value      = 01:01:01:02:01:08
<128> Feb  2 18:12:15 ql-dial: >>>>>>   translated = [ registration_state = 'registered' cs_attach_state = 'attached' ps_attach_state = 'attached' selected_network = '3gpp' radio_interfaces = '{ [0] = 'lte '}' ]
<003> Feb  2 18:12:15 kernel: [ 1889.285870] Alignment trap: not handling instruction e1902f9f at [<b6b79d04>]
<001> Feb  2 18:12:15 kernel: [ 1889.285910] Unhandled fault: alignment exception (0x001) at 0x0002c4df
<001> Feb  2 18:12:15 kernel: [ 1889.285926] pgd = cd1a8000
<001> Feb  2 18:12:15 kernel: [ 1889.285942] [0002c4df] *pgd=8d196831, *pte=8154434f, *ppte=8154483f
<086> Feb  2 18:16:18 ssh-server[3032]: Child connection from 192.168.1.20:37288


gdb gives me the following information:


Program received signal SIGBUS, Bus error.
0xb6b79d08 in qmi_indication_nas_serving_system_output_ref ()
   from /opt/src/libqmi/build/src/libqmi-glib/.libs/libqmi-glib.so.5.1.0
(gdb) bt
#0  0xb6b79d08 in qmi_indication_nas_serving_system_output_ref ()
   from /opt/src/libqmi/build/src/libqmi-glib/.libs/libqmi-glib.so.5.1.0
#1  0xb6e273d4 in _g_type_boxed_copy ()
   from /opt/src/glib/build/glib-2.50.2-install/lib/libgobject-2.0.so.0.5000.2
#2  0xb6dfd820 in g_boxed_copy () from /opt/src/glib/build/glib-2.50.2-install/lib/libgobject-2.0.so.0.5000.2
#3  0xb6e02c88 in g_cclosure_marshal_VOID__BOXEDv ()
   from /opt/src/glib/build/glib-2.50.2-install/lib/libgobject-2.0.so.0.5000.2
#4  0xb6e001a8 in _g_closure_invoke_va ()
   from /opt/src/glib/build/glib-2.50.2-install/lib/libgobject-2.0.so.0.5000.2
#5  0xb6e1af08 in g_signal_emit_valist ()
   from /opt/src/glib/build/glib-2.50.2-install/lib/libgobject-2.0.so.0.5000.2
#6  0xb6e1bab0 in g_signal_emit () from /opt/src/glib/build/glib-2.50.2-install/lib/libgobject-2.0.so.0.5000.2
#7  0xb6ba5170 in process_indication () from /opt/src/libqmi/build/src/libqmi-glib/.libs/libqmi-glib.so.5.1.0
#8  0xb6b385a0 in qmi_client_process_indication ()
   from /opt/src/libqmi/build/src/libqmi-glib/.libs/libqmi-glib.so.5.1.0
#9  0xb6b34b08 in process_indication_idle ()
   from /opt/src/libqmi/build/src/libqmi-glib/.libs/libqmi-glib.so.5.1.0
#10 0xb6d0d10c in g_idle_dispatch () from /opt/src/glib/build/glib-2.50.2-install/lib/libglib-2.0.so.0.5000.2
#11 0xb6d10c14 in g_main_context_dispatch ()
   from /opt/src/glib/build/glib-2.50.2-install/lib/libglib-2.0.so.0.5000.2
#12 0xb6d10f2c in g_main_context_iterate ()
   from /opt/src/glib/build/glib-2.50.2-install/lib/libglib-2.0.so.0.5000.2
#13 0xb6d113a8 in g_main_loop_run () from /opt/src/glib/build/glib-2.50.2-install/lib/libglib-2.0.so.0.5000.2
#14 0x0000a5cc in main (argc=42444, argv=0xbefffe14) at ql-dial.c:241
(gdb)
Comment 1 Wolfgang 2017-02-03 23:29:41 UTC
Turns out the problem is with glib. g_slice_new0() in __qmi_indication_nas_serving_system_indication_parse() returns a misaligned memory block, contrary to what the glib documentation says. Turning off glib's 'magazine layer' seems to avoid this problem. This can be done by calling     

g_slice_set_config(G_SLICE_CONFIG_BYPASS_MAGAZINES, TRUE);

Note that g_slice_set_config() is flagged as deprecated, so it may be necessary to patch glib/gslice.c instead.
Comment 2 Dan Williams 2017-02-06 18:46:47 UTC
Is there an open glib bug for the alignment issue?  Would be nice to track it and make sure it gets fixed, or know what version it was fixed in if others encounter this.

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.