Missing error message when connecting with invalid APN

[Ivar Simensen]

Hi
I'm currently using ModemManager 1.6.10 on Ubuntu 16.04 server, on a system without user interaction. The modem is unlocked and enabled based on a configuration in a database.
I tried to set an invalid APN on a modem to see if this error situation easily could be reported back to my database, but I can't find any good error messages from ModemManager that I can use.
The modem is in enabled state (as expected), but  MMModemStateFailedReason is MM_MODEM_STATE_FAILED_REASON_NONE. I had hoped for something like SIM_ERROR or even better, a message telling that the APN is invalid.

Is this maybe solved in newer versions of MM? Or can I extract this error from somewhere else?
Thanks,
Ivar

Some logs:
>From DBus I can't get more info, but journalctrl indicates that something went wrong with reason unknown:

#journalctl messages from ModemManager and NetworkManager
Jun 25 10:25:15 btkn-16240000 NetworkManager[1413]: <info>  [1561451115.4307] keyfile: add connection in-memory (a71fc2fd-7f55-429e-8a13-84951665938b,"gsm_ANT-3")
Jun 25 10:25:15 btkn-16240000 NetworkManager[1413]: <info>  [1561451115.4333] device (cdc-wdm2): Activation: starting connection 'gsm_ANT-3' (a71fc2fd-7f55-429e-8a13-84951665938b)
Jun 25 10:25:15 btkn-16240000 NetworkManager[1413]: <info>  [1561451115.4343] keyfile: update /etc/NetworkManager/system-connections/gsm_ANT-3 (a71fc2fd-7f55-429e-8a13-84951665938b,"gsm_ANT-3") and persist connection
Jun 25 10:25:15 btkn-16240000 NetworkManager[1413]: <info>  [1561451115.4345] audit: op="connection-add-activate" uuid="a71fc2fd-7f55-429e-8a13-84951665938b" name="gsm_ANT-3" pid=1829 uid=0 result="success"
Jun 25 10:25:15 btkn-16240000 NetworkManager[1413]: <info>  [1561451115.4364] device (cdc-wdm2): state change: disconnected -> prepare (reason 'none') [30 40 0]
Jun 25 10:25:15 btkn-16240000 ModemManager[1433]: <info>  Simple connect started...
Jun 25 10:25:15 btkn-16240000 ModemManager[1433]: <info>  Simple connect state (4/8): Wait to get fully enabled
Jun 25 10:25:15 btkn-16240000 ModemManager[1433]: <info>  Simple connect state (5/8): Register
Jun 25 10:25:15 btkn-16240000 ModemManager[1433]: <info>  Simple connect state (6/8): Bearer
Jun 25 10:25:15 btkn-16240000 ModemManager[1433]: <info>  Simple connect state (7/8): Connect
Jun 25 10:25:15 btkn-16240000 ModemManager[1433]: <info>  Modem /org/freedesktop/ModemManager1/Modem/3: state changed (registered -> connecting)
Jun 25 10:25:15 btkn-16240000 NetworkManager[1413]: <info>  [1561451115.4426] (cdc-wdm2): modem state changed, 'registered' --> 'connecting' (reason: user-requested)
Jun 25 10:25:20 btkn-16240000 ModemManager[1433]: <info>  Modem /org/freedesktop/ModemManager1/Modem/3: 3GPP Registration state changed (home -> idle)
Jun 25 10:25:20 btkn-16240000 ModemManager[1433]: <info>  Modem /org/freedesktop/ModemManager1/Modem/3: state changed (connecting -> disconnecting)
Jun 25 10:25:20 btkn-16240000 ModemManager[1433]: <warn>  Error disconnecting bearer '/org/freedesktop/ModemManager1/Bearer/4': 'Couldn't disconnect QMI bearer: this bearer is not connected'. Will assume disconnected anyway.
Jun 25 10:25:20 btkn-16240000 ModemManager[1433]: <info>  Modem /org/freedesktop/ModemManager1/Modem/3: state changed (disconnecting -> enabled)
Jun 25 10:25:20 btkn-16240000 NetworkManager[1413]: <info>  [1561451120.5931] (cdc-wdm2): modem state changed, 'connecting' --> 'disconnecting' (reason: user-requested)
Jun 25 10:25:20 btkn-16240000 NetworkManager[1413]: <warn>  [1561451120.5935] (cdc-wdm2): failed to connect modem: Connection setup operation has been cancelled
Jun 25 10:25:20 btkn-16240000 NetworkManager[1413]: <info>  [1561451120.5936] device (cdc-wdm2): state change: prepare -> failed (reason 'unknown') [40 120 1]
Jun 25 10:25:20 btkn-16240000 NetworkManager[1413]: <warn>  [1561451120.5947] device (cdc-wdm2): Activation: failed for connection 'gsm_ANT-3'
Jun 25 10:25:20 btkn-16240000 NetworkManager[1413]: <info>  [1561451120.5983] (cdc-wdm2): modem state changed, 'disconnecting' --> 'enabled' (reason: user-requested)
Jun 25 10:25:20 btkn-16240000 NetworkManager[1413]: <warn>  [1561451120.5986] device (cdc-wdm2): overwriting previously queued state change to disconnected (none)
Jun 25 10:25:20 btkn-16240000 NetworkManager[1413]: <info>  [1561451120.5990] device (cdc-wdm2): state change: failed -> unavailable (reason 'modem-failed') [120 20 57]
Jun 25 10:25:20 btkn-16240000 ModemManager[1433]: [/dev/cdc-wdm2] No transaction matched in received message

#DBus message from modem:
busctl call org.freedesktop.ModemManager1 /org/freedesktop/ModemManager1 org.freedesktop.DBus.ObjectManager GetManagedObjects
a{oa{sa{sv}}} 1 "/org/freedesktop/ModemManager1/Modem/3" 8 "org.freedesktop.ModemManager1.Modem.Simple" 0 "org.freedesktop.ModemManager1.Modem.Time" 1 "NetworkTimezone" a{sv} 1 "offset" i 120 "org.freedesktop.ModemManager1.Modem.Modem3gpp" 6 "Imei" s "359072060110778" "RegistrationState" u 0 "OperatorCode" s "" "OperatorName" s "" "EnabledFacilityLocks" u 0 "SubscriptionState" u 0 "org.freedesktop.ModemManager1.Modem.Voice" 1 "Calls" ao 0 "org.freedesktop.ModemManager1.Modem.Messaging" 3 "Messages" ao 2 "/org/freedesktop/ModemManager1/SMS/2" "/org/freedesktop/ModemManager1/SMS/1" "SupportedStorages" au 2 1 2 "DefaultStorage" u 2 "org.freedesktop.ModemManager1.Modem.Location" 6 "Capabilities" u 1 "Enabled" u 1 "SignalsLocation" b false "Location" a{uv} 0 "SuplServer" s "" "GpsRefreshRate" u 0 "org.freedesktop.ModemManager1.Modem.Signal" 6 "Rate" u 0 "Cdma" a{sv} 0 "Evdo" a{sv} 0 "Gsm" a{sv} 0 "Umts" a{sv} 0 "Lte" a{sv} 0 "org.freedesktop.ModemManager1.Modem" 29 "Sim" o "/org/freedesktop/ModemManager1/SIM/3" "Bearers" ao 1 "/org/freedesktop/ModemManager1/Bearer/4" "SupportedCapabilities" au 3 4 8 12 "CurrentCapabilities" u 12 "MaxBearers" u 1 "MaxActiveBearers" u 1 "Manufacturer" s "Sierra Wireless, Incorporated" "Model" s "MC7455" "Revision" s "SWI9X30C_02.30.03.00 r7804 CARMD-EV-FRMWR2 2018/07/25 01:10:04" "DeviceIdentifier" s "5419b0dc21f3a40a433475c6365983f1fc5dc489" "Device" s "/sys/devices/pci0000:00/0000:00:14.0/usb2/2-2" "Drivers" as 2 "qcserial" "qmi_wwan" "Plugin" s "Sierra" "PrimaryPort" s "cdc-wdm2" "Ports" a(su) 4 "ttyUSB0" 4 "wwp0s20f0u2i8" 2 "ttyUSB2" 3 "cdc-wdm2" 6 "EquipmentIdentifier" s "359072060110778" "UnlockRequired" u 5 "UnlockRetries" a{uu} 4 2 3 3 0 4 10 5 10 "State" i 6 "StateFailedReason" u 0 "AccessTechnologies" u 0 "SignalQuality" (ub) 0 false "OwnNumbers" as 0 "PowerState" u 3 "SupportedModes" a(uu) 1 14 0 "CurrentModes" (uu) 14 0 "SupportedBands" au 18 5 6 12 7 9 10 31 32 33 34 35 37 38 42 43 50 55 71 "CurrentBands" au 18 5 6 12 7 9 10 31 32 33 34 35 37 38 42 43 50 55 71 "SupportedIpFamilies" u 7

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/modemmanager-devel/attachments/20190625/3298fa09/attachment-0001.html>