libmm-glib: no signal when call/sms status changes
I'm using libmm-glib with python to interact with ModemManager (similar to the ModemWatcher.py example). I am trying to log calls and messages and monitor their status transitions.
To make it easier to reproduce the problem I'm facing, I added/modified some functions with debug output of the original ModemWatcher.py example (notice that it's just for debug purposes since I don't disconnect/deregister the callback handlers):
Click to expand
"""
Object added (modified: connecting to callback signals)
"""
def on_object_added(self, manager, obj):
modem = obj.get_modem()
print('[ModemWatcher] %s (%s) modem managed by ModemManager [%s]: %s' %
(modem.get_manufacturer(),
modem.get_model(),
modem.get_equipment_identifier(),
obj.get_object_path()))
if modem.get_state() == ModemManager.ModemState.FAILED:
print('[ModemWatcher,%s] ignoring failed modem' %
modem_index(obj.get_object_path()))
else:
obj.get_modem_messaging().connect('added', self.on_sms_added, obj)
obj.get_modem_voice().connect('call_added', self.on_call_added, obj)
"""
Additional functions that print some debug output to monitor call/sms status transitions
"""
def on_call_added(self, voice, call_path, modem_obj):
print('on_call_added: %s' % call_path)
calls = voice.list_calls_sync()
call = self.find_obj_via_path(call_path, calls)
call.connect('state_changed', self.on_call_state_changed)
def on_call_state_changed(self, call, state_reason, s1, s2):
print('on_call_state_changed')
def on_sms_added(self, messaging, sms_path, received, modem_obj):
print('on_sms_added: %s' % sms_path)
messages = messaging.list_sync()
sms = self.find_obj_via_path(sms_path, messages)
state = ModemManager.SmsState.get_string(sms.get_state())
if (received and state == "receiving") or state == "sending": #received == true when message came from network
print("queue message -> notify on state transition!")
sms.connect('notify::state', self.on_sms_notify)
def on_sms_notify(self, messaging, sms_path, modem_obj):
print('on_sms_notify')
def find_obj_via_path(self, path, list):
for o in list:
o_path = o.get_object_path()
if o.get_object_path() == path:
return o
raise ValueError("There is no object with the provided path")
To monitor status transitions of current calls I use the 'state_changed'-signal and for messages I simply connect to changes of the 'state' property since there is no actual signal for it. For (incoming) singlepart messages we actually don't expect any transition updates, however for multipart messages the status is usually 'receiving' until the message is concatenated.
I was able to test the script with a Telit LE910 and Huawei ME909s-120, however I didn't get any status update signals ('on_call_state_changed'/'on_sms_notify' is never executed).
At the ModemManager debug output I can see that the status changes are actually registered by ModemManager.
Is this a bug or am I just using the wrong callbacks/signals?
If needed for further investigation I also gathered some logging output:
Telit call
#new call
ModemManager[20543]: <debug> [1580134581.990382] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134581.990867] (ttyACM1): <-- '+CRING: VOICE<CR><LF><CR><LF>+CLIP: "+43699********",145,"",128,"",0<CR><LF><CR><LF>+CIEV: sounder,1<CR><LF>'
ModemManager[20543]: <debug> [1580134581.990994] Ringing (+43699********)
ModemManager[20543]: <debug> [1580134581.991023] call at index 0: direction incoming, state ringing-in, number +43699********
ModemManager[20543]: <debug> [1580134581.991060] Creating new incoming call...
ModemManager[20543]: <info> [1580134581.991488] Call state changed: unknown -> ringing-in (incoming-new)
ModemManager[20543]: <debug> [1580134581.991646] Added call at '/org/freedesktop/ModemManager1/Call/0'
ModemManager[20543]: <debug> [1580134581.992016] Ringing (VOICE)
ModemManager[20543]: <debug> [1580134581.992061] call at index 0: direction incoming, state ringing-in, number n/a
ModemManager[20543]: <debug> [1580134581.992111] call info matched (matched direction/state yes, matched index no, matched terminated no) with call at '/org/freedesktop/ModemManager1/Call/0'
ModemManager[20543]: <debug> [1580134581.992152] incoming refreshed
ModemManager[20543]: <debug> [1580134581.992270] (ttyACM4): <-- '<CR><LF>+CRING: VOICE<CR><LF><CR><LF>+CLIP: "+43699********",145,"",128,"",0<CR><LF>'
ModemManager[20543]: <debug> [1580134581.992327] Ringing (+43699********)
ModemManager[20543]: <debug> [1580134581.992358] call at index 0: direction incoming, state ringing-in, number +43699********
ModemManager[20543]: <debug> [1580134581.992398] call info matched (matched direction/state yes, matched index no, matched terminated no) with call at '/org/freedesktop/ModemManager1/Call/0'
ModemManager[20543]: <debug> [1580134581.992431] incoming refreshed
ModemManager[20543]: <debug> [1580134581.992483] Ringing (VOICE)
ModemManager[20543]: <debug> [1580134581.992512] call at index 0: direction incoming, state ringing-in, number n/a
ModemManager[20543]: <debug> [1580134581.992547] call info matched (matched direction/state yes, matched index no, matched terminated no) with call at '/org/freedesktop/ModemManager1/Call/0'
ModemManager[20543]: <debug> [1580134581.992580] incoming refreshed
ModemManager[20543]: <debug> [1580134583.869144] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134583.870603] (ttyACM1): <-- '+CIEV: rssi,4<CR><LF>'
ModemManager[20543]: <debug> [1580134584.656569] 1 calls being established: call list polling required
ModemManager[20543]: <debug> [1580134584.656675] (ttyACM1) device open count is 3 (open)
ModemManager[20543]: <debug> [1580134584.656749] (ttyACM1): --> 'AT+CLCC<CR>'
ModemManager[20543]: <debug> [1580134584.683758] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134584.684478] (ttyACM1): <-- '+CLCC: 1,1,4,0,0,"+43699********",145,""<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[20543]: <debug> [1580134584.684690] Reported 1 ongoing calls
ModemManager[20543]: <debug> [1580134584.684730] call at index 1: direction incoming, state ringing-in, number +43699********
ModemManager[20543]: <debug> [1580134584.684793] call info matched (matched direction/state yes, matched index no, matched terminated no) with call at '/org/freedesktop/ModemManager1/Call/0'
ModemManager[20543]: <debug> [1580134584.684864] index set: 1
ModemManager[20543]: <debug> [1580134584.684893] incoming refreshed
ModemManager[20543]: <debug> [1580134584.684941] (ttyACM1) device open count is 2 (close)
#call dropped
ModemManager[20543]: <debug> [1580134594.408971] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134594.409773] (ttyACM1): <-- '+CIEV: call,0<CR><LF><CR><LF>+CIEV: sounder,0<CR><LF>'
ModemManager[20543]: <debug> [1580134594.655280] 1 calls being established: call list polling required
ModemManager[20543]: <debug> [1580134594.655379] (ttyACM1) device open count is 3 (open)
ModemManager[20543]: <debug> [1580134594.655454] (ttyACM1): --> 'AT+CLCC<CR>'
ModemManager[20543]: <debug> [1580134594.671127] (ttyACM1): <-- '<CR><LF>OK<CR><LF>'
ModemManager[20543]: <debug> [1580134594.671347] Reported 0 ongoing calls
ModemManager[20543]: <info> [1580134594.671402] Call state changed: ringing-in -> terminated (unknown)
ModemManager[20543]: <debug> [1580134594.671688] (ttyACM1) device open count is 2 (close)
ModemManager[20543]: <debug> [1580134595.656044] loading signal quality...
ModemManager[20543]: <debug> [1580134595.656157] (ttyACM1) device open count is 3 (open)
ModemManager[20543]: <debug> [1580134595.656228] (ttyACM1): --> 'AT+CIND?<CR>'
ModemManager[20543]: <debug> [1580134595.671734] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134595.672638] (ttyACM1): <-- '+CIND: 0,99,1,0,0,0,0,0,4<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[20543]: <debug> [1580134595.673175] (ttyACM1) device open count is 4 (open)
ModemManager[20543]: <debug> [1580134595.673240] (ttyACM1) device open count is 3 (close)
ModemManager[20543]: <debug> [1580134595.673294] (ttyACM1): --> 'AT+CSQ<CR>'
ModemManager[20543]: <debug> [1580134595.685975] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134595.686837] (ttyACM1): <-- '+CSQ: 15,1<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[20543]: <debug> [1580134595.686978] Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (48)
ModemManager[20543]: <debug> [1580134595.686993] loading access technology (Telit)...
ModemManager[20543]: <debug> [1580134595.687021] (ttyACM1) device open count is 4 (open)
ModemManager[20543]: <debug> [1580134595.687034] (ttyACM1) device open count is 3 (close)
ModemManager[20543]: <debug> [1580134595.687151] (ttyACM1): --> 'AT#PSNT?<CR>'
ModemManager[20543]: <debug> [1580134595.699596] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134595.700051] (ttyACM1): <-- '#PSNT: 0,2<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[20543]: <debug> [1580134595.700141] Modem /org/freedesktop/ModemManager1/Modem/0: access technology changed (lte -> umts)
ModemManager[20543]: <debug> [1580134595.700159] Periodic signal quality and access technology checks scheduled
ModemManager[20543]: <debug> [1580134595.700173] (ttyACM1) device open count is 2 (close)
ModemManager[20543]: <debug> [1580134596.656353] no calls being established: call list polling stopped
#debug script
[ModemWatcher] ModemManager 1.13.0 service is available in bus
[ModemWatcher] Telit (LE910-EU V2) modem managed by ModemManager [351622075051116]: /org/freedesktop/ModemManager1/Modem/0
on_call_added: /org/freedesktop/ModemManager1/Call/0
#mmcli (when calling / after dropping call)
$ mmcli -m 0 --call=0
----------------------------
General | dbus path: /org/freedesktop/ModemManager1/Call/0
----------------------------
Properties | number: +43699********
| direction: incoming
| multiparty: no
| state: ringing-in
| state reason: incoming-new
----------------------------
Audio format | rate: 0
$ mmcli -m 0 --call=0
--------------------------
General | dbus path: /org/freedesktop/ModemManager1/Call/0
--------------------------
Properties | number: +43699********
| direction: incoming
| multiparty: no
| state: terminated
--------------------------
Audio format | rate: 0
Telit message
#multipart message received
ModemManager[20543]: <debug> [1580134908.160655] (ttyACM1): <-- '<CR><LF>+CIEV: sounder,1<CR><LF><CR><LF>+CIEV: message,1<CR><LF><CR><LF>+CMTI: "ME",1<CR><LF>'
ModemManager[20543]: <debug> [1580134908.160792] Locking SMS storages to: mem1 (ME), mem2 (none)...
ModemManager[20543]: <debug> [1580134908.160840] (ttyACM1) device open count is 3 (open)
ModemManager[20543]: <debug> [1580134908.160937] (ttyACM4): <-- '<CR><LF>+CMTI: "ME",1<CR><LF>'
ModemManager[20543]: <debug> [1580134908.161053] (ttyACM1): --> 'AT+CPMS="ME"<CR>'
ModemManager[20543]: <debug> [1580134908.185013] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134908.185736] (ttyACM1): <-- '+CPMS: "ME",1,100,"ME",1,100,"ME",1,100<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[20543]: <debug> [1580134908.185881] (ttyACM1) device open count is 4 (open)
ModemManager[20543]: <debug> [1580134908.185940] (ttyACM1) device open count is 3 (close)
ModemManager[20543]: <debug> [1580134908.185991] (ttyACM1): --> 'AT+CMGR=1<CR>'
ModemManager[20543]: <debug> [1580134908.312150] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134908.313211] (ttyACM1): <-- '+CMGR: 0,"",107<CR><LF>06913496096006440D91349619062719F900000210725112614063050003920202EEE8B21B147683EAEEB5FB7D7783E0F2B49B5E9683E8EFF71A14069DC36C76390F7A9B41F43CBC0C0ABBC9A0F9581E6E8BD96532284D07D1DFA076785D068541F43CBC0C9AC3CBE374BBEC0689DFEFB50B<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[20543]: <debug> [1580134908.313418] Parsing PDU (1)...
ModemManager[20543]: <debug> [1580134908.313457] SMSC address parsed: '+4369900660'
ModemManager[20543]: <debug> [1580134908.313475] Deliver type PDU detected
ModemManager[20543]: <debug> [1580134908.313491] Number parsed: '+43699********'
ModemManager[20543]: <debug> [1580134908.313521] PID: 0
ModemManager[20543]: <debug> [1580134908.313549] user data encoding is GSM7
ModemManager[20543]: <debug> [1580134908.313579] user data length: 99 elements
ModemManager[20543]: <debug> [1580134908.313607] user data length: 87 bytes
ModemManager[20543]: <debug> [1580134908.313628] Decoding SMS text with '92' elements
ModemManager[20543]: <debug> [1580134908.313646] Converting SMS part text from GSM-7 to UTF-8...
ModemManager[20543]: <debug> [1580134908.313676] Got UTF-8 text: 'when an unknown printer took a galley of type and scrambled it to make a type specimen book.'
ModemManager[20543]: <debug> [1580134908.313699] Correctly parsed PDU (1)
ModemManager[20543]: <debug> [1580134908.313737] SMS part at 'me/1' is from a multipart SMS (reference: '146', sequence: '2/2')
ModemManager[20543]: <debug> [1580134908.314344] Creating new multipart SMS object: need to receive 2 parts with reference '146'
ModemManager[20543]: <debug> [1580134908.314405] Added received SMS at '/org/freedesktop/ModemManager1/SMS/0'
ModemManager[20543]: <debug> [1580134908.314745] (ttyACM1) device open count is 2 (close)
ModemManager[20543]: <debug> [1580134908.314829] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134908.315851] (ttyACM1): <-- '+CIEV: message,0<CR><LF>'
ModemManager[20543]: <debug> [1580134909.181987] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134909.182401] (ttyACM1): <-- '+CIEV: sounder,1<CR><LF><CR><LF>+CIEV: message,1<CR><LF><CR><LF>+CMTI: "ME",2<CR><LF>'
ModemManager[20543]: <debug> [1580134909.182516] Locking SMS storages to: mem1 (ME), mem2 (none)...
ModemManager[20543]: <debug> [1580134909.182566] (ttyACM1) device open count is 3 (open)
ModemManager[20543]: <debug> [1580134909.182660] (ttyACM1): --> 'AT+CPMS="ME"<CR>'
ModemManager[20543]: <debug> [1580134909.182760] (ttyACM4): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134909.183212] (ttyACM4): <-- '+CMTI: "ME",2<CR><LF>'
ModemManager[20543]: <debug> [1580134909.205466] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134909.205888] (ttyACM1): <-- '+CPMS: "ME",2,100,"ME",2,100,"ME",2,100<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[20543]: <debug> [1580134909.206014] (ttyACM1) device open count is 4 (open)
ModemManager[20543]: <debug> [1580134909.206077] (ttyACM1) device open count is 3 (close)
ModemManager[20543]: <debug> [1580134909.206133] (ttyACM1): --> 'AT+CMGR=2<CR>'
ModemManager[20543]: <debug> [1580134909.318548] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134909.319457] (ttyACM1): <-- '+CMGR: 0,"",160<CR><LF>06913496096006440D91349619062719F9000002107251125140A0050003920201986F79B90D4AC2E7F536283D07CDD36D383B0F22D7DBED3C885EC6D3416F33888E2E83E0F2B49B9E769F4161371944CFC3CBF3329D9E769F416937B93EA7CBF32E10F32D2FB74149F8BCDE06A1C37390B85C7683E8E83228ED26D7E77479FE3407CDE96137392C2783C8F5763B0FA297F17450D95E9683E669F7B80CA2A3CBA0580D069BB340<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[20543]: <debug> [1580134909.319678] Parsing PDU (2)...
ModemManager[20543]: <debug> [1580134909.319714] SMSC address parsed: '+4369900660'
ModemManager[20543]: <debug> [1580134909.319736] Deliver type PDU detected
ModemManager[20543]: <debug> [1580134909.319757] Number parsed: '+43699********'
ModemManager[20543]: <debug> [1580134909.319781] PID: 0
ModemManager[20543]: <debug> [1580134909.319801] user data encoding is GSM7
ModemManager[20543]: <debug> [1580134909.319819] user data length: 160 elements
ModemManager[20543]: <debug> [1580134909.319838] user data length: 140 bytes
ModemManager[20543]: <debug> [1580134909.319858] Decoding SMS text with '153' elements
ModemManager[20543]: <debug> [1580134909.319877] Converting SMS part text from GSM-7 to UTF-8...
ModemManager[20543]: <debug> [1580134909.319911] Got UTF-8 text: 'Lorem Ipsum is simply dummy text of the printing and typesetting industry. Lorem Ipsum has been the industry's standard dummy text ever since the 1500s, '
ModemManager[20543]: <debug> [1580134909.319935] Correctly parsed PDU (2)
ModemManager[20543]: <debug> [1580134909.319973] SMS part at 'me/2' is from a multipart SMS (reference: '146', sequence: '1/2')
ModemManager[20543]: <debug> [1580134909.319997] Found existing multipart SMS object with reference '146': adding new part
ModemManager[20543]: <debug> [1580134909.320106] (ttyACM1) device open count is 2 (close)
ModemManager[20543]: <debug> [1580134909.320643] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134909.321173] (ttyACM1): <-- '+CIEV: message,0<CR><LF>'
ModemManager[20543]: <debug> [1580134914.239965] (ttyACM1): <-- '<CR><LF>+CIEV: sounder,0<CR><LF>'
ModemManager[20543]: <debug> [1580134925.659144] loading signal quality...
ModemManager[20543]: <debug> [1580134925.659179] (ttyACM1) device open count is 3 (open)
ModemManager[20543]: <debug> [1580134925.659197] (ttyACM1): --> 'AT+CIND?<CR>'
ModemManager[20543]: <debug> [1580134925.793862] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134925.795205] (ttyACM1): <-- '+CIND: 0,5,1,0,0,0,0,0,4<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[20543]: <debug> [1580134925.795456] Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (71)
ModemManager[20543]: <debug> [1580134925.795505] loading access technology (Telit)...
ModemManager[20543]: <debug> [1580134925.795536] (ttyACM1) device open count is 4 (open)
ModemManager[20543]: <debug> [1580134925.795584] (ttyACM1) device open count is 3 (close)
ModemManager[20543]: <debug> [1580134925.795801] (ttyACM1): --> 'AT#PSNT?<CR>'
ModemManager[20543]: <debug> [1580134925.808733] (ttyACM1): <-- '<CR><LF>'
ModemManager[20543]: <debug> [1580134925.809525] (ttyACM1): <-- '#PSNT: 0,4<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[20543]: <debug> [1580134925.809655] Periodic signal quality and access technology checks scheduled
ModemManager[20543]: <debug> [1580134925.809693] (ttyACM1) device open count is 2 (close)
#debug script
[ModemWatcher] ModemManager 1.13.0 service is available in bus
[ModemWatcher] Telit (LE910-EU V2) modem managed by ModemManager [351622075051116]: /org/freedesktop/ModemManager1/Modem/0
on_sms_added: /org/freedesktop/ModemManager1/SMS/0
queue message -> notify on state transition!
Huawei call
#new call
ModemManager[817]: <debug> [1580222121.075369] Ringing (+43699********)
ModemManager[817]: <debug> [1580222121.075475] call at index 0: direction incoming, state ringing-in, number +43699********
ModemManager[817]: <debug> [1580222121.075580] Creating new incoming call...
ModemManager[817]: <info> [1580222121.076935] Call state changed: unknown -> ringing-in (incoming-new)
ModemManager[817]: <debug> [1580222121.077577] Added call at '/org/freedesktop/ModemManager1/Call/0'
ModemManager[817]: <debug> [1580222121.081419] Ringing (VOICE)
ModemManager[817]: <debug> [1580222121.081566] call at index 0: direction incoming, state ringing-in, number n/a
ModemManager[817]: <debug> [1580222121.081698] call info matched (matched direction/state yes, matched#new call
``` index no, matched terminated no) with call at '/org/freedesktop/ModemManager1/Call/0'
ModemManager[817]: <debug> [1580222121.081778] incoming refreshed
ModemManager[817]: <debug> [1580222121.082146] (ttyUSB0): <-- '<CR><LF>+CRING: VOICE<CR><LF><CR><LF>+CLIP: "+43699********",145,,,,0<CR><LF>'
ModemManager[817]: <debug> [1580222121.082326] Ringing (+43699********)
ModemManager[817]: <debug> [1580222121.082399] call at index 0: direction incoming, state ringing-in, number +43699********
ModemManager[817]: <debug> [1580222121.082504] call info matched (matched direction/state yes, matched index no, matched terminated no) with call at '/org/freedesktop/ModemManager1/Call/0'
ModemManager[817]: <debug> [1580222121.082576] incoming refreshed
ModemManager[817]: <debug> [1580222121.082858] Ringing (VOICE)
ModemManager[817]: <debug> [1580222121.082934] call at index 0: direction incoming, state ringing-in, number n/a
ModemManager[817]: <debug> [1580222121.083035] call info matched (matched direction/state yes, matched index no, matched terminated no) with call at '/org/freedesktop/ModemManager1/Call/0'
ModemManager[817]: <debug> [1580222121.083111] incoming refreshed
ModemManager[817]: <debug> [1580222121.604253] (ttyUSB2): <-- '<CR><LF>^ECCLIST: 112,911,122,133,140,144<CR><LF>'
ModemManager[817]: <debug> [1580222121.624855] (ttyUSB0): <-- '<CR><LF>^ECCLIST: 112,911,122,133,140,144<CR><LF>'
ModemManager[817]: <debug> [1580222123.115885] 1 calls being established: call list polling required
ModemManager[817]: <debug> [1580222123.116177] (ttyUSB0) device open count is 2 (open)
ModemManager[817]: <debug> [1580222123.116381] (ttyUSB0): --> 'AT+CLCC<CR>'
ModemManager[817]: <debug> [1580222123.125405] (ttyUSB0): <-- '<CR><LF>+CLCC: 1,1,4,0,0,"+43699********",145<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[817]: <debug> [1580222123.126330] Reported 1 ongoing calls
ModemManager[817]: <debug> [1580222123.126498] call at index 1: direction incoming, state ringing-in, number +43699********
ModemManager[817]: <debug> [1580222123.126678] call info matched (matched direction/state yes, matched index no, matched terminated no) with call at '/org/freedesktop/ModemManager1/Call/0'
ModemManager[817]: <debug> [1580222123.126794] index set: 1
ModemManager[817]: <debug> [1580222123.126890] incoming refreshed
#call dropped
ModemManager[817]: <debug> [1580222128.840687] (ttyUSB2): <-- '<CR><LF>^CEND: 1,0,104,16<CR><LF>'
ModemManager[817]: <debug> [1580222128.840939] call 1 state updated: terminated
ModemManager[817]: <debug> [1580222128.841019] call duration: 0 seconds
ModemManager[817]: <debug> [1580222128.841124] end status code: 104
ModemManager[817]: <debug> [1580222128.841225] call control cause: 16
ModemManager[817]: <debug> [1580222128.841328] call at index 1: direction unknown, state terminated, number n/a
ModemManager[817]: <debug> [1580222128.841482] call info matched (matched direction/state no, matched index yes, matched terminated no) with call at '/org/freedesktop/ModemManager1/Call/0'
ModemManager[817]: <debug> [1580222128.841600] state updated: terminated
ModemManager[817]: <info> [1580222128.841719] Call state changed: ringing-in -> terminated (unknown)
ModemManager[817]: <debug> [1580222128.844721] (ttyUSB0): <-- '<CR><LF>^CEND: 1,0,104,16<CR><LF>'
ModemManager[817]: <debug> [1580222128.844983] call 1 state updated: terminated
ModemManager[817]: <debug> [1580222128.845098] call duration: 0 seconds
ModemManager[817]: <debug> [1580222128.845205] end status code: 104
ModemManager[817]: <debug> [1580222128.845304] call control cause: 16
ModemManager[817]: <debug> [1580222128.845406] call at index 1: direction unknown, state terminated, number n/a
ModemManager[817]: <debug> [1580222128.845552] unhandled call state update reported: direction: unknown, state terminated
ModemManager[817]: <debug> [1580222129.114980] no calls being established: call list polling stopped
#debug script
[ModemWatcher] ModemManager 1.13.0 service is available in bus
[ModemWatcher] Huawei Technologies Co., Ltd. (ME909s-120) modem managed by ModemManager [867377024887147]: /org/freedesktop/ModemManager1/Modem/0
on_call_added: /org/freedesktop/ModemManager1/Call/0
#mmcli (when calling / after dropping call)
$ mmcli -m 0 --call=0
----------------------------
General | dbus path: /org/freedesktop/ModemManager1/Call/0
----------------------------
Properties | number: +43699********
| direction: incoming
| multiparty: no
| state: ringing-in
| state reason: incoming-new
----------------------------
Audio format | rate: 0
$ mmcli -m 0 --call=0
--------------------------
General | dbus path: /org/freedesktop/ModemManager1/Call/0
--------------------------
Properties | number: +43699********
| direction: incoming
| multiparty: no
| state: terminated
--------------------------
Audio format | rate: 0
Huawei message
#multipart message received
ModemManager[817]: <debug> [1580222508.972243] (ttyUSB2): <-- '<CR><LF>+CMTI: "SM",1<CR><LF>'
ModemManager[817]: <debug> [1580222508.972781] Locking SMS storages to: mem1 (SM), mem2 (none)...
ModemManager[817]: <debug> [1580222508.972950] (ttyUSB0) device open count is 2 (open)
ModemManager[817]: <debug> [1580222508.973276] (ttyUSB0): <-- '<CR><LF>+CMTI: "SM",1<CR><LF>'
ModemManager[817]: <debug> [1580222508.973837] (ttyUSB0): --> 'AT+CPMS="SM"<CR>'
ModemManager[817]: <debug> [1580222508.988935] (ttyUSB0): <-- '<CR><LF>+CPMS: 1,20,1,20,1,20<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[817]: <debug> [1580222508.989563] (ttyUSB0) device open count is 3 (open)
ModemManager[817]: <debug> [1580222508.989757] (ttyUSB0) device open count is 2 (close)
ModemManager[817]: <debug> [1580222508.989890] (ttyUSB0): --> 'AT+CMGR=1<CR>'
ModemManager[817]: <debug> [1580222509.001378] (ttyUSB0): <-- '<CR><LF>+CMGR: 0,,160<CR><LF>06913496096006440D91349619062719F9000002108251147440A0050003500201986F79B90D4AC2E7F536283D07CDD36D383B0F22D7DBED3C885EC6D3416F33888E2E83E0F2B49B9E769F4161371944CFC3CBF3329D9E769F416937B93EA7CBF32E10F32D2FB74149F8BCDE06A1C37390B85C7683E8E83228ED26D7E77479FE3407CDE96137392C2783C8F5763B0FA297F17450D95E9683E669F7B80CA2A3CBA0580D069BB340<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[817]: <debug> [1580222509.002374] Parsing PDU (1)...
ModemManager[817]: <debug> [1580222509.002497] SMSC address parsed: '+4369900660'
ModemManager[817]: <debug> [1580222509.002563] Deliver type PDU detected
ModemManager[817]: <debug> [1580222509.002618] Number parsed: '+43699********'
ModemManager[817]: <debug> [1580222509.002693] PID: 0
ModemManager[817]: <debug> [1580222509.002744] user data encoding is GSM7
ModemManager[817]: <debug> [1580222509.002796] user data length: 160 elements
ModemManager[817]: <debug> [1580222509.002853] user data length: 140 bytes
ModemManager[817]: <debug> [1580222509.002910] Decoding SMS text with '153' elements
ModemManager[817]: <debug> [1580222509.002973] Converting SMS part text from GSM-7 to UTF-8...
ModemManager[817]: <debug> [1580222509.003151] Got UTF-8 text: 'Lorem Ipsum is simply dummy text of the printing and typesetting industry. Lorem Ipsum has been the industry's standard dummy text ever since the 1500s, '
ModemManager[817]: <debug> [1580222509.003226] Correctly parsed PDU (1)
ModemManager[817]: <debug> [1580222509.003322] SMS part at 'sm/1' is from a multipart SMS (reference: '80', sequence: '1/2')
ModemManager[817]: <debug> [1580222509.005239] Creating new multipart SMS object: need to receive 2 parts with reference '80'
ModemManager[817]: <debug> [1580222509.005407] Added received SMS at '/org/freedesktop/ModemManager1/SMS/0'
ModemManager[817]: <debug> [1580222509.006396] (ttyUSB0) device open count is 1 (close)
ModemManager[817]: <debug> [1580222509.600447] (ttyUSB2): <-- '<CR><LF>+CMTI: "SM",2<CR><LF>'
ModemManager[817]: <debug> [1580222509.600971] Locking SMS storages to: mem1 (SM), mem2 (none)...
ModemManager[817]: <debug> [1580222509.601156] (ttyUSB0) device open count is 2 (open)
ModemManager[817]: <debug> [1580222509.601502] (ttyUSB0): <-- '<CR><LF>+CMTI: "SM",2<CR><LF>'
ModemManager[817]: <debug> [1580222509.602074] (ttyUSB0): --> 'AT+CPMS="SM"<CR>'
ModemManager[817]: <debug> [1580222509.617128] (ttyUSB0): <-- '<CR><LF>+CPMS: 2,20,2,20,2,20<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[817]: <debug> [1580222509.617888] (ttyUSB0) device open count is 3 (open)
ModemManager[817]: <debug> [1580222509.618105] (ttyUSB0) device open count is 2 (close)
ModemManager[817]: <debug> [1580222509.618513] (ttyUSB0): --> 'AT+CMGR=2<CR>'
ModemManager[817]: <debug> [1580222509.629995] (ttyUSB0): <-- '<CR><LF>+CMGR: 0,,107<CR><LF>06913496096006440D91349619062719F900000210825114844063050003500202EEE8B21B147683EAEEB5FB7D7783E0F2B49B5E9683E8EFF71A14069DC36C76390F7A9B41F43CBC0C0ABBC9A0F9581E6E8BD96532284D07D1DFA076785D068541F43CBC0C9AC3CBE374BBEC0689DFEFB50B<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[817]: <debug> [1580222509.630990] Parsing PDU (2)...
ModemManager[817]: <debug> [1580222509.631108] SMSC address parsed: '+4369900660'
ModemManager[817]: <debug> [1580222509.631174] Deliver type PDU detected
ModemManager[817]: <debug> [1580222509.631229] Number parsed: '+43699********'
ModemManager[817]: <debug> [1580222509.631307] PID: 0
ModemManager[817]: <debug> [1580222509.631529] user data encoding is GSM7
ModemManager[817]: <debug> [1580222509.631597] user data length: 99 elements
ModemManager[817]: <debug> [1580222509.631655] user data length: 87 bytes
ModemManager[817]: <debug> [1580222509.631716] Decoding SMS text with '92' elements
ModemManager[817]: <debug> [1580222509.631770] Converting SMS part text from GSM-7 to UTF-8...
ModemManager[817]: <debug> [1580222509.631904] Got UTF-8 text: 'when an unknown printer took a galley of type and scrambled it to make a type specimen book.'
ModemManager[817]: <debug> [1580222509.631971] Correctly parsed PDU (2)
ModemManager[817]: <debug> [1580222509.632078] SMS part at 'sm/2' is from a multipart SMS (reference: '80', sequence: '2/2')
ModemManager[817]: <debug> [1580222509.632146] Found existing multipart SMS object with reference '80': adding new part
ModemManager[817]: <debug> [1580222509.632551] (ttyUSB0) device open count is 1 (close)
ModemManager[817]: <debug> [1580222510.655298] (ttyUSB2): <-- '<CR><LF>+CREG: 1,"426F","00011308",7<CR><LF>'
ModemManager[817]: <debug> [1580222510.655993] building consolidated registration state: cs 'home', ps 'home', eps 'unknown' --> 'home'
#debug script
[ModemWatcher] ModemManager 1.13.0 service is available in bus
[ModemWatcher] Huawei Technologies Co., Ltd. (ME909s-120) modem managed by ModemManager [867377024887147]: /org/freedesktop/ModemManager1/Modem/0
on_sms_added: /org/freedesktop/ModemManager1/SMS/0
queue message -> notify on state transition!