MMCLI debug mode

Dan Williams dcbw at redhat.com
Wed Oct 31 14:46:18 UTC 2018 

On Wed, 2018-10-31 at 06:43 -0700, Srinivasan Jagannadhan wrote:
> 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#

What happens if you do:

mmcli -m 0 -v --simple-connect="apn=VZWINTERNET,ip-type=ipv4v6"

That should cause MM to match CID #3.  It seems your device doesn't
want to allow additional contexts to be added, and by default (if ip-
type isn't given) MM will just use IPv4.  So lets try with ipv4v6.

Dan

> 
> 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.MobileEquipmen
> > > > t.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-dev
> > > > el
> 
> _______________________________________________
> ModemManager-devel mailing list
> ModemManager-devel at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel

More information about the ModemManager-devel mailing list