Debugging VoLTE issue: BM818 (Librem 5 Modem), MM 1.18.6
Chris Talbot
chris at talbothome.com
Thu Jun 23 01:48:00 UTC 2022
Hello!
I am trying to debug a VoLTE issue with the BM818. I am using T-Mobile USA with VoLTE enabled on the BM818, with a Librem 5, PureOS Byzantium
(based on Debian Bullseye).
With certain numbers, I have seen that the call terminates right after the call is picked up. However, With the same hardware/software
set up with an AT&T MVNO (AweSIM, Purism's MVNO), I have no trouble with the exact same number. Additionally, Calling the number with the
Pinephone Pro, VoLTE on T-Mobile USA (EG-25, MM 1.18) did not have this issue either.
For one number, I found that the `1-800` number had this issue (it was my bank), but calling the same number to it's local area code
(but the same bank call system) allowed the call to complete just fine.
I am including the log below, but the log seems to show that the other side just terminated the call. What would be a good way to help debug/solve
this issue?
Relevant logs from Modem Manager (Number sanitized):
@ 16:15:27 all is still well:
```
Jun 01 16:15:27 pureos ModemManager[655]: <debug> [modem0] reported 1 ongoing calls
Jun 01 16:15:27 pureos ModemManager[655]: <debug> [modem0] call at index 1: direction outgoing, state dialing, number 800531****
Jun 01 16:15:27 pureos ModemManager[655]: <debug> [modem0] call info matched (matched direction/state yes, matched number yes, matched index no, matched terminated no) with call at
'/org/freedesktop/ModemManager1/Call/4'
Jun 01 16:15:27 pureos ModemManager[655]: <debug> [modem0] index set: 1
Jun 01 16:15:27 pureos ModemManager[655]: [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<< length = 28
<<<<<< data = 01:1B:00:80:09:02:02:08:00:20:00:0F:00:02:04:00:00:00:00:00:10:01:00:01:15:01:00:0A
Jun 01 16:15:27 pureos ModemManager[655]: [/dev/cdc-wdm0] Received generic response (translated)...
<<<<<< QMUX:
<<<<<< length = 27
<<<<<< flags = 0x80
<<<<<< service = "voice"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "response"
<<<<<< transaction = 8
<<<<<< tlv_length = 15
<<<<<< message = "Dial Call" (0x0020)
<<<<<< TLV:
<<<<<< type = "Result" (0x02)
<<<<<< length = 4
<<<<<< value = 00:00:00:00
<<<<<< translated = SUCCESS ### <-- success?! \o/
<<<<<< TLV:
<<<<<< type = "Call ID" (0x10)
<<<<<< length = 1
<<<<<< value = 01
<<<<<< translated = 1
<<<<<< TLV:
<<<<<< type = 0x15
<<<<<< length = 1
<<<<<< value = 0A
Jun 01 16:15:27 pureos ModemManager[655]: <info> [modem0/call4] call is started
```
and at 16:15:29 it starts ringing the other side
```
Jun 01 16:15:29 pureos ModemManager[655]: [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<< length = 67
<<<<<< data =
01:42:00:80:09:02:04:15:00:2E:00:36:00:01:08:00:01:01:05:02:01:04:00:00:10:0E:00:01:01:00:0A:38:30:30:35:33:31:38:37:32:32:32:03:00:01:01:00:2B:11:00:01:01:00:00:00:01:0A:38:30:30:35:33:31:38:37:32:32
Jun 01 16:15:29 pureos ModemManager[655]: [/dev/cdc-wdm0] Received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 66
<<<<<< flags = 0x80
<<<<<< service = "voice"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 21
<<<<<< tlv_length = 54
<<<<<< message = "All Call Status" (0x002E)
<<<<<< TLV:
<<<<<< type = "Call Information" (0x01)
<<<<<< length = 8
<<<<<< value = 01:01:05:02:01:04:00:00
<<<<<< translated = { [0] = '[ id = '1' state = 'alerting' type = 'voice-ip' direction = 'mo' mode = 'lte' multipart_indicator = 'no' als = '1' ] '}
### <-- alerting
<<<<<< TLV:
<<<<<< type = "Remote Party Number" (0x10)
<<<<<< length = 14
<<<<<< value = 01:01:00:0A:38:30:30:35:33:31:38:37:32:32
<<<<<< translated = { [0] = '[ id = '1' presentation_indicator = 'allowed' type = '800*******' ] '}
<<<<<< TLV:
<<<<<< type = 0x32
<<<<<< length = 3
<<<<<< value = 01:01:00
<<<<<< TLV:
<<<<<< type = 0x2b
<<<<<< length = 17
<<<<<< value = 01:01:00:00:00:01:0A:38:30:30:35:33:31:38:37:32:32
Jun 01 16:15:29 pureos ModemManager[655]: <debug> [modem0] reported 1 ongoing calls
Jun 01 16:15:29 pureos ModemManager[655]: <debug> [modem0] call at index 1: direction outgoing, state ringing-out, number 800*******
Jun 01 16:15:29 pureos ModemManager[655]: <debug> [modem0] call info matched (matched direction/state no, matched number yes, matched index yes, matched terminated no) with call at
'/org/freedesktop/ModemManager1/Call/4'
Jun 01 16:15:29 pureos ModemManager[655]: <debug> [modem0] state updated: ringing-out
Jun 01 16:15:29 pureos ModemManager[655]: <info> [modem0/call4] call state changed: dialing -> ringing-out (unknown)
```
and 3 seconds later at 16:15:32 it just terminates
```
Jun 01 16:15:32 pureos ModemManager[655]: [/dev/cdc-wdm0] Received message...
<<<<<< RAW:
<<<<<< length = 114
<<<<<< data =
01:71:00:80:09:02:04:16:00:2E:00:65:00:01:08:00:01:01:09:02:01:04:00:00:10:0E:00:01:01:00:0A:38:30:30:35:33:31:38:37:32:32:14:04:00:01:01:19:00:32:03:00:01:01:00:2B:11:00:01:01:00:00:00:01:0A:38:30:30
:35:33:31:38:37:32:32:2E:25:00:01:01:11:53:00:44:00:50:00:20:00:6E:00:6F:00:74:00:20:00:73:00:75:00:70:00:70:00:6F:00:72:00:74:00:65:00:64:00
Jun 01 16:15:32 pureos ModemManager[655]: [/dev/cdc-wdm0] Received generic indication (translated)...
<<<<<< QMUX:
<<<<<< length = 113
<<<<<< flags = 0x80
<<<<<< service = "voice"
<<<<<< client = 2
<<<<<< QMI:
<<<<<< flags = "indication"
<<<<<< transaction = 22
<<<<<< tlv_length = 101
<<<<<< message = "All Call Status" (0x002E)
<<<<<< TLV:
<<<<<< type = "Call Information" (0x01)
<<<<<< length = 8
<<<<<< value = 01:01:09:02:01:04:00:00
<<<<<< translated = { [0] = '[ id = '1' state = 'end' type = 'voice-ip' direction = 'mo' mode = 'lte' multipart_indicator = 'no' als = '1' ] '}
### <-- end ?
<<<<<< TLV:
<<<<<< type = "Remote Party Number" (0x10)
<<<<<< length = 14
<<<<<< value = 01:01:00:0A:38:30:30:35:33:31:38:37:32:32
<<<<<< translated = { [0] = '[ id = '1' presentation_indicator = 'allowed' type = '800*******' ] '}
<<<<<< TLV:
<<<<<< type = 0x14
<<<<<< length = 4
<<<<<< value = 01:01:19:00
<<<<<< TLV:
<<<<<< type = 0x32
<<<<<< length = 3
<<<<<< value = 01:01:00
<<<<<< TLV:
<<<<<< type = 0x2b
<<<<<< length = 17
<<<<<< value = 01:01:00:00:00:01:0A:38:30:30:35:33:31:38:37:32:32
<<<<<< TLV:
<<<<<< type = 0x2e
<<<<<< length = 37
<<<<<< value = 01:01:11:53:00:44:00:50:00:20:00:6E:00:6F:00:74:00:20:00:73:00:75:00:70:00:70:00:6F:00:72:00:74:00:65:00:64:00
Jun 01 16:15:32 pureos ModemManager[655]: <debug> [modem0] reported 1 ongoing calls
Jun 01 16:15:32 pureos ModemManager[655]: <debug> [modem0] call at index 1: direction outgoing, state terminated, number 800*******
Jun 01 16:15:32 pureos ModemManager[655]: <debug> [modem0] call info matched (matched direction/state no, matched number yes, matched index yes, matched terminated no) with call at
'/org/freedesktop/ModemManager1/Call/4'
Jun 01 16:15:32 pureos ModemManager[655]: <debug> [modem0] state updated: terminated
```
--
Respectfully,
Chris Talbot
More information about the ModemManager-devel
mailing list