MMCLI debug mode
Dan Williams
dcbw at redhat.com
Thu Nov 1 13:40:16 UTC 2018
On Wed, 2018-10-31 at 09:45 -0700, Srinivasan Jagannadhan wrote:
> Thanks Dave! It connects with your suggestion. But there is no
> IPAddr/Gateway assigned
Ok, it looks like ModemManager is attempting to use PPP on the device
because MM doesn't handle the Telit cdc-ncm ethernet-like interface
that the modem provides. Ideally we'd like to use that interface,
rather than PPP but that's unimplemented for now, it seems.
But with your current setup, MM is waiting for you to start pppd on the
data port to configure the IP details.
Dan
> root at localhost:/var/log/inode# mmcli -m 1 --simple-status
> /org/freedesktop/ModemManager1/Modem/1
> -------------------------
> Status | state: 'connected'
> | signal quality: '85' (recent)
> | bands: 'eutran-ii, eutran-iv, eutran-xiii'
> | access tech: 'unknown'
> -------------------------
> 3GPP | registration: 'home'
> | operator code: '311480'
> | operator name: 'Verizon'
> | subscription: 'unknown'
>
>
>
> root at localhost:/var/log/inode# mmcli -b 19
> Bearer '/org/freedesktop/ModemManager1/Bearer/19'
> -------------------------
> Status | connected: 'yes'
> | suspended: 'no'
> | interface: 'ttyACM0'
> | IP timeout: '20'
> -------------------------
> Properties | apn: 'VZWINTERNET'
> | roaming: 'allowed'
> | IP type: 'ipv4v6'
> | user: 'none'
> | password: 'none'
> | number: 'none'
> | Rm protocol: 'unknown'
> -------------------------
> IPv4 configuration | method: 'ppp'
> | address: 'unknown'
> | prefix: '0'
> | gateway: 'unknown'
> | DNS: none
> -------------------------
> IPv6 configuration | method: 'ppp'
> | address: 'unknown'
> | prefix: '0'
> | gateway: 'unknown'
> | DNS: none
> -------------------------
> Stats | Duration: '180'
> | Bytes received: 'N/A'
> | Bytes transmitted: 'N/A'
>
>
> root at localhost:/var/log/inode# mmcli -m 1
>
> /org/freedesktop/ModemManager1/Modem/1 (device id
> '3b7220ee774f413d7be53e974a94c04f89a8b2b8')
> -------------------------
> Hardware | manufacturer: 'Telit'
> | model: 'LE910-SV V2'
> | revision: '20.00.002'
> | supported: 'gsm-umts, lte'
> | current: 'gsm-umts, lte'
> | equipment id: '351994070026033'
> -------------------------
> System | device:
> '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-4/1-4.1'
> | drivers: 'cdc_acm, cdc_ncm'
> | plugin: 'Dell'
> | primary port: 'ttyACM0'
> | ports: 'ttyACM3 (at), ttyACM4 (unknown),
> ttyACM5
> (unknown), wwx000011121314 (unknown), ttyACM0 (at), ttyACM1
> (unknown),
> ttyACM2 (unknown)'
> -------------------------
> Numbers | own : '+14086051571'
> -------------------------
> Status | lock: 'none'
> | unlock retries: 'sim-pin (3), sim-puk (10)'
> | state: 'connected'
> | power state: 'on'
> | access tech: 'unknown'
> | signal quality: '85' (recent)
> -------------------------
> Modes | supported: 'allowed: 4g; preferred: none'
> | current: 'allowed: 4g; preferred: none'
> -------------------------
> Bands | supported: 'eutran-ii, eutran-iv, eutran-xiii'
> | current: 'eutran-ii, eutran-iv, eutran-xiii'
> -------------------------
> IP | supported: 'ipv4, ipv6, ipv4v6'
> -------------------------
> 3GPP | imei: '351994070026033'
> | enabled locks: 'none'
> | operator id: '311480'
> | operator name: 'Verizon'
> | subscription: 'unknown'
> | registration: 'home'
> -------------------------
> SIM | path: '/org/freedesktop/ModemManager1/SIM/1'
>
> -------------------------
> Bearers | paths:
> '/org/freedesktop/ModemManager1/Bearer/19'
>
>
> Thanks
> Srini
>
> On Wed, Oct 31, 2018 at 7:46 AM Dan Williams <dcbw at redhat.com> wrote:
>
> > 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.MobileEqui
> > > > > > pmen
> > > > > > 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