MMCLI debug mode

Wed Oct 31 13:43:04 UTC 2018

CGD Dump is as follows:
====================
root at localhost:/home/iotium# mmcli -m 0 --command="AT+CGDCONT?"
response: '+CGDCONT: 1,"IPV4V6","vzwims","",0,0
+CGDCONT: 2,"IPV4V6","vzwadmin","",0,0
+CGDCONT: 3,"IPV4V6","VZWINTERNET","",0,0'
root at localhost:/home/iotium#

On Wed, Oct 31, 2018 at 6:40 AM Srinivasan Jagannadhan <
srjagannwork at gmail.com> wrote:

> Thanks Dan!
>
> Here is the log with debug turned on
>
> ct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.565839]
> [mm-broadband-bearer.c:961] parse_pdp_list(): Found '3' PDP contexts
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.565948]
> [mm-broadband-bearer.c:970] parse_pdp_list():   PDP context [cid=1]
> [type='ipv4v6'] [apn='vzwims']
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.566036]
> [mm-broadband-bearer.c:970] parse_pdp_list():   PDP context [cid=2]
> [type='ipv4v6'] [apn='vzwadmin']
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.566186]
> [mm-broadband-bearer.c:970] parse_pdp_list():   PDP context [cid=3]
> [type='ipv4v6'] [apn='VZWINTERNET']
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.566398]
> [mm-port-serial-at.c:459] debug_log(): (ttyACM0): --> 'AT+CREG?<CR>'
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.590470]
> [mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '<CR><LF>+CREG:
> 2,3<CR><LF><CR><LF>OK<CR><LF>'
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.590912]
> [mm-port-serial.c:1288] mm_port_serial_open(): (ttyACM0) device open count
> is 4 (open)
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.591105]
> [mm-port-serial.c:1345] _close_internal(): (ttyACM0) device open count is 3
> (close)
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.591887]
> [mm-broadband-bearer.c:903] parse_cid_range(): Using CID 4
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.592096]
> [mm-port-serial.c:1288] mm_port_serial_open(): (ttyACM0) device open count
> is 4 (open)
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.592272]
> [mm-port-serial.c:1345] _close_internal(): (ttyACM0) device open count is 3
> (close)
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.592471]
> [mm-port-serial-at.c:459] debug_log(): (ttyACM0): --> 'AT+CGREG?<CR>'
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.616142]
> [mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '<CR><LF>+CGREG:
> 2,1,"1F06","9A34D16",7,"00"<CR><LF><CR><LF>OK<CR><LF>'
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.616703]
> [mm-port-serial.c:1345] _close_internal(): (ttyACM0) device open count is 2
> (close)
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.616926]
> [mm-broadband-modem.c:8574] modem_3gpp_run_registration_checks_ready():
> Initial 3GPP registration checks finished
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.617430]
> [mm-port-serial-at.c:459] debug_log(): (ttyACM0): -->
> 'AT+CGDCONT=4,"IP","VZWINTERNET"<CR>'
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.675572]
> [mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '<CR><LF>+CME ERROR:
> 3<CR><LF>'
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.675867]
> [mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code 3:
> Operation not allowed
> Oct 31 13:37:01 localhost ModemManager[1988]: <warn>  [1540993021.676126]
> [mm-broadband-bearer.c:775] initialize_pdp_context_ready(): Couldn't
> initialize PDP context with our APN: 'Operation not allowed'
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.676264]
> [mm-port-serial.c:1345] _close_internal(): (ttyACM0) device open count is 1
> (close)
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.676515]
> [mm-base-bearer.c:578] connect_ready(): Couldn't connect bearer
> '/org/freedesktop/ModemManager1/Bearer/1': 'Operation not allowed'
> Oct 31 13:37:01 localhost ModemManager[1988]: <info>  [1540993021.677020]
> [mm-iface-modem.c:1431] __iface_modem_update_state_internal(): Modem
> /org/freedesktop/ModemManager1/Modem/1: state changed (connecting ->
> registered)
> Oct 31 13:37:01 localhost ModemManager[1988]: <debug> [1540993021.678607]
> [mm-iface-modem-simple.c:221] connect_bearer_ready(): Couldn't connect
> bearer: 'Operation not allowed'
> Oct 31 13:37:06 localhost ModemManager[1988]: <debug> [1540993026.719837]
> [mm-port-serial.c:1288] mm_port_serial_open(): (ttyACM0) device open count
> is 2 (open)
> Oct 31 13:37:06 localhost ModemManager[1988]: <debug> [1540993026.720165]
> [mm-port-serial-at.c:459] debug_log(): (ttyACM0): --> 'AT+CCLK?<CR>'
> Oct 31 13:37:06 localhost ModemManager[1988]: <debug> [1540993026.745426]
> [mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '<CR><LF>'
> Oct 31 13:37:06 localhost ModemManager[1988]: <debug> [1540993026.745738]
> [mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '+CCLK:
> "18/10/31,06:37:12-28"<CR><LF><CR><LF>OK<CR><LF>'
> Oct 31 13:37:06 localhost ModemManager[1988]: <debug> [1540993026.746379]
> [mm-port-serial.c:1345] _close_internal(): (ttyACM0) device open count is 1
> (close)
>
>
> On Wed, Oct 31, 2018 at 6:36 AM Dan Williams <dcbw at redhat.com> wrote:
>
>> On Wed, 2018-10-31 at 04:18 -0700, Srinivasan Jagannadhan wrote:
>> > I was trying to bringup Dell 5000 Gateway with
>> > 1) Modem:  'Telit model: 'LE910-SV V2' rev: '20.00.002'
>> > 2) Sim: Verizon
>> >
>> > Following were the commands executed
>> > 1. mmcli -m 0 -v --simple-connect="apn=VZWINTERNET"
>> >
>> > [31 Oct 2018, 11:11:10] [Debug] Forcing request to be run
>> > asynchronously
>> > [31 Oct 2018, 11:11:10] [Debug] Assuming '0' is the modem index
>> > [31 Oct 2018, 11:11:10] [Debug] ModemManager process found at ':1.3'
>> > [31 Oct 2018, 11:11:10] [Debug] Modem found at
>> > '/org/freedesktop/ModemManager1/Modem/0'
>> >
>> > [31 Oct 2018, 11:11:10] [Debug] Asynchronously connecting the
>> > modem...
>> > error: couldn't connect the modem:
>> > 'GDBus.Error:org.freedesktop.ModemManager1.Error.MobileEquipment.NotA
>> > llowed:
>> > Operation not allowed'
>> >
>> > 2. /var/log/syslog
>> > Oct 31 11:01:54 localhost ModemManager[804]: <info>  Modem
>> > /org/freedesktop/ModemManager1/Modem/0: state changed (disabled ->
>> > enabling)
>>
>> ModemManager debug logging would be useful here.  You can enable that
>> with "mmcli --set-logging=DEBUG" and then reproduce the issue.  Then
>> /var/log/syslog will contain quite a bit more information that we can
>> use to debug the problem.
>>
>> Thanks!
>> Dan
>>
>>
>> > Oct 31 11:01:55 localhost ModemManager[804]: <info>  Modem
>> > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
>> > changed
>> > (unknown -> registering)
>> > Oct 31 11:01:55 localhost ModemManager[804]: <info>  Modem
>> > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
>> > changed
>> > (registering -> home)
>> > Oct 31 11:01:55 localhost ModemManager[804]: <info>  Modem
>> > /org/freedesktop/ModemManager1/Modem/0: state changed (enabling ->
>> > registered)
>> > Oct 31 11:01:55 localhost ModemManager[804]: <info>  Simple connect
>> > started...
>> > Oct 31 11:01:55 localhost ModemManager[804]: <info>  Simple connect
>> > state
>> > (4/8): Wait to get fully enabled
>> > Oct 31 11:01:55 localhost ModemManager[804]: <info>  Simple connect
>> > state
>> > (5/8): Register
>> > Oct 31 11:01:55 localhost ModemManager[804]: <info>  Simple connect
>> > state
>> > (6/8): Bearer
>> > Oct 31 11:01:55 localhost ModemManager[804]: <info>  Simple connect
>> > state
>> > (7/8): Connect
>> > Oct 31 11:01:55 localhost ModemManager[804]: <info>  Modem
>> > /org/freedesktop/ModemManager1/Modem/0: state changed (registered ->
>> > connecting)
>> > Oct 31 11:01:55 localhost ModemManager[804]: <warn>  Couldn't
>> > initialize
>> > PDP context with our APN: 'Operation not allowed'
>> > Oct 31 11:01:55 localhost ModemManager[804]: <info>  Modem
>> > /org/freedesktop/ModemManager1/Modem/0: state changed (connecting ->
>> > registered)
>> > Oct 31 11:11:10 localhost ModemManager[804]: <info>  Simple connect
>> > started...
>> > Oct 31 11:11:10 localhost ModemManager[804]: <info>  Simple connect
>> > state
>> > (4/8): Wait to get fully enabled
>> > Oct 31 11:11:10 localhost ModemManager[804]: <info>  Simple connect
>> > state
>> > (5/8): Register
>> > Oct 31 11:11:10 localhost ModemManager[804]: <info>  Simple connect
>> > state
>> > (6/8): Bearer
>> > Oct 31 11:11:10 localhost ModemManager[804]: <info>  Simple connect
>> > state
>> > (7/8): Connect
>> > Oct 31 11:11:10 localhost ModemManager[804]: <info>  Modem
>> > /org/freedesktop/ModemManager1/Modem/0: state changed (registered ->
>> > connecting)
>> > Oct 31 11:11:10 localhost ModemManager[804]: <warn>  Couldn't
>> > initialize
>> > PDP context with our APN: 'Operation not allowed'
>> >
>> > Questions:
>> > 1. Does this require explicit AT commands to be passed through MMCLI?
>> > 2. What AT Commands to must be used?
>> > 3. How do we compile MMCLI in debug mode to issue AT Commands?
>> >
>> > Thanks
>> > -Srini-
>> > _______________________________________________
>> > ModemManager-devel mailing list
>> > ModemManager-devel at lists.freedesktop.org
>> > https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/modemmanager-devel/attachments/20181031/b10c49e3/attachment.html>