MMCLI debug mode

Wed Oct 31 13:40:17 UTC 2018

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/ba2f8ec0/attachment-0001.html>