<div dir="ltr"><div dir="ltr"><div class="gmail_default"><div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif">OK, great! Here is an update:</div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif"> </div><div class="gmail_default">We have had an active debugging session with Vodafone and we saw that the modem (a SIMCom SIM7100A) had collected multiple PDP contexts from networks along the way (4 of them): AT+CGDCONT? +CGDCONT: 1,"IP","phone","0.0.0.0",0,0 +CGDCONT: 2,"IP","3gnet","0.0.0.0",0,0 +CGDCONT: 3,"IP","vf-viriciti","0.0.0.0",0,0 +CGDCONT: 4,"IP","viriciti.com.attz","0.0.0.0",0,0 OK</div><div class="gmail_default"> A "phone" (no clue where that comes from), a "3gnet" (this seems to be an operator in China), the "vf-viriciti" (that is ours!), and a "viriciti.com.attz" (this is ours for AT&T). Looking at the selected one: AT+CGACT? +CGACT: 1,1 +CGACT: 2,0 +CGACT: 3,0 +CGACT: 4,0 OK The modem selected the first one! The "phone" APN... That will obviously not work in our case :) >From the ModemManager logs (below) we see that ModemManager does select the right CID (#3) when looking for the best CID matching the "vf-viriciti" APN. </div><div class="gmail_default">So it seems modem is the issue here: just removing the first context, and leaving the others, solves the problem of connectivity!!</div><div class="gmail_default">But why? Is this just a specific SIM7100A modem issue? Is there a work-around?</div><div class="gmail_default"> </div><div class="gmail_default">(</div><div class="gmail_default"> little extra context: we always use NetworkManager "nmcli" to initiate the connection using the nm-ppp-plguin, issuing:</div><div class="gmail_default"> "nmcli c add type gsm ifname ttyUSB2 apn vf-viriciti gsm.number *99***1# ipv6.method "ignore"</div><div class="gmail_default"> where "gsm.number" is deprecated in NetworkManager</div><div class="gmail_default">) HERE ARE THE ModemManager LOGS:</div><div class="gmail_default">(ModemManager just selects the right CID #3 as the active PDP context) </div></div><div class="gmail_default"> </div><div class="gmail_default"> May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] user request to connect modem May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <info> [modem1] simple connect started... May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] PIN: unspecified May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] operator ID: unspecified May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] allowed roaming: yes May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] APN: vf-viriciti May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] IP family: ipv4 May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] allowed authentication: unspecified May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] User: unspecified May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] Password: unspecified May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <info> [modem1] simple connect state (4/8): wait to get fully enabled May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <info> [modem1] simple connect state (5/8): register May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] already registered automatically in network '310260', automatic registration not launched... May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <info> [modem1] simple connect state (6/8): bearer May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] creating new bearer... May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1] creating broadband bearer in broadband modem... May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] device open count is 2 (open) May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <info> [modem1] simple connect state (7/8): connect May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] connecting... May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <info> [modem1] state changed (registered -> connecting) May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] launching 3GPP connection attempt with APN 'vf-viriciti' May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] checking context definition format... May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] device open count is 3 (open) May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] device open count is 2 (close) May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] unhandled PDP type in CGDCONT=? reply: 'PPP' May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] checking currently defined contexts... May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] device open count is 3 (open) May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] device open count is 2 (close) May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] --> 'AT+CGDCONT?<CR>' May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] <-- '<CR><LF>+CGDCONT: 1,"IP","phone","0.0.0.0",0,0<CR><LF>+CGDCONT: 2,"IP","3gnet","0.0.0.0",0,0<CR><LF>+CGDCONT: 3,"IP","vf-viriciti","0.0.0.0",0,0<CR><LF>+CGDCONT: 4,"IP","viriciti.com.attz","0.0.0.0",0,0<CR><LF><CR><LF>OK<CR><LF>' May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] found 4 PDP contexts May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] PDP context [cid=1] [type='ipv4'] [apn='phone'] May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] PDP context [cid=2] [type='ipv4'] [apn='3gnet'] May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] PDP context [cid=3] [type='ipv4'] [apn='vf-viriciti'] May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] PDP context [cid=4] [type='ipv4'] [apn='viriciti.com.attz'] May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] looking for best CID matching APN 'vf-viriciti' and PDP type 'ipv4'... May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] found exact context at CID 3 May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] device open count is 3 (open) May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] connection through a plain serial AT port: ttyUSB2 May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] device open count is 4 (open) May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] device open count is 3 (close) May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] --> 'ATD*99***3#<CR>' May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] <-- '<CR><LF>CONNECT 115200<CR><LF>' May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] setting flow control in ttyUSB2: rts-cts May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] enabling RTS/CTS flow control May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] port attributes not fully set May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] flow control settings updated to rts-cts May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] port now connected May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] connected May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] PPP is required for connection, will ignore disconnection reports May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <info> [modem1] state changed (connecting -> connected) May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <info> [modem1] simple connect state (8/8): all done May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] device open count is 2 (close) May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [base-manager] adding port ppp0 at sysfs path: /sys/devices/virtual/net/ppp0 May 18 08:36:52 vc-f14us31817 ModemManager[6547]: <debug> [filter] (net/ppp0) port filtered: forbidden port type May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB3/at] <-- '<CR><LF>NO CARRIER<CR><LF>' May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB3/at] operation failure: 1 (No carrier) May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB3/at] <-- '<CR><LF>+PPPD: DISCONNECTED<CR><LF>' May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1] user request to disconnect modem (all bearers) May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] disconnecting... May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <info> [modem1] state changed (connected -> disconnecting) May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] sending PDP context deactivation in secondary port... May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB3/at] device open count is 2 (open) May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB3/at] --> 'AT+CGACT=0,3<CR>' May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB3/at] <-- '<CR><LF>OK<CR><LF>' May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/bearer0] reopening data port ttyUSB2... May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] reopening port (2) May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] device open count is 1 (close) May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] device open count is 0 (close) May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] closing serial port... May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] port now disconnected May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB2/at] serial port closed May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1/ttyUSB3/at] device open count is 1 (close) May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1] user request to disconnect modem (all bearers) May 18 08:36:53 vc-f14us31817 ModemManager[6547]: <debug> [modem1] user request to connect modem </div><div style="font-family:arial,helvetica,sans-serif"> </div><blockquote class="gmail_quote" style="font-family:arial,helvetica,sans-serif;margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"></blockquote></div></div> <div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Tue, May 11, 2021 at 8:36 PM Aleksander Morgado <<a href="mailto:aleksander@aleksander.es" target="_blank">aleksander@aleksander.es</a>> wrote: </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Hey! > > We have some strange behavior (on a SIM7100A) where NetworkManager (using the nm-ppp-plugin) needs to initiate a connection with Vodafone (private APN). The modem gets registered successfully on the network (roaming over the available T-Mobile or AT&T networks), but receives a modem hangup (the modem gives a "NO CARRIER" error) which leads to pppd disconnecting. However, when using a custom pppd script (and without using ModemManager & NetworkManager), we are able to setup a data connection. This is a follow up of this email right? <a href="https://lists.freedesktop.org/archives/modemmanager-devel/2021-April/008526.html" rel="noreferrer" target="_blank">https://lists.freedesktop.org/archives/modemmanager-devel/2021-April/008526.html</a> Just for context. </blockquote><div>yes! </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"> > > * MM version is 1.14.10 > * NM version is 1.28.0 > * pppd version is 2.4.9 > > When using NetworkManager the pppd options that seem to be used (from evaluating debug output of NetworkManager) are: > ttyUSB2 > debug > idle 0 > ipparam > lcp-echo-failure 0 > lcp-echo-interval 0 > lock > noauth > nodefaultroute > nodetach > noipdefault > noipv6 > usepeerdns > > and this results into the following pppd output: > Serial connection established. > using channel 23 > Using interface ppp0 > Connect: ppp0 <--> /dev/ttyUSB3 > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x8e804837> <pcomp> <accomp>] > rcvd [LCP ConfReq id=0x3f <asyncmap 0x0> <auth chap MD5> <magic 0x88528a77> <pcomp> <accomp>] > No auth is possible > sent [LCP ConfRej id=0x3f <auth chap MD5>] > rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x8e804837> <pcomp> <accomp>] > rcvd [LCP ConfReq id=0x40 <asyncmap 0x0> <magic 0x88528a77> <pcomp> <accomp>] > sent [LCP ConfAck id=0x40 <asyncmap 0x0> <magic 0x88528a77> <pcomp> <accomp>] > sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>] > sent [IPV6CP ConfReq id=0x1 <addr fe80::9095:1777:829f:47a0>] > rcvd [LCP DiscReq id=0x41 magic=0x88528a77] > Modem hangup > Connection terminated. > > We do get good results when just running manual pppd script manually (no ModemManager and NetworkManager active), but with quite different options from the NetworkManager defaults. From the manual pppd script (a script taken from Quectel) the options are: > debug > defaultroute > dump > hide-password > ipcp-accept-local > ipcp-accept-remote > ipcp-max-failure 30 > ipparam 3gppp > lock > modem > noauth > noccp > nocrtscts > nodetach > noipdefault > novj > novjccomp > remotename 3gppp > usepeerdns > > And that gives a good result (shortened pppd output a bit): > $ pppd debug call gprs > pppd options in effect: > debug debug > nodetach > dump > noauth > remotename 3gppp > /dev/ttyUSB3 > 115200 > lock > connect chat -s -v -f /data/ppp/chatscripts/quectel-chat-connect -T vf-viriciti > disconnect chat -s -v -f /data/ppp/chatscripts/quectel-chat-disconnect > nocrtscts > modem > hide-password > novj > novjccomp > ipcp-accept-local > ipcp-accept-remote > ipparam 3gppp > noipdefault > ipcp-max-failure 30 > defaultroute > usepeerdns > noccp > abort on (BUSY) > abort on (NO CARRIER) > abort on (NO DIALTONE) > abort on (ERROR) > abort on (NO ANSWER) > timeout set to 30 seconds > send (AT^M) > expect (OK) > AT^M^M > OK > -- got it > > send (ATE0^M) > expect (OK) > ^M > ATE0^M^M > OK > -- got it > > send (ATI;+CSUB;+CSQ;+COPS?;+CGREG?;&D2^M) > expect (OK) > ^M > ^M > Manufacturer: SIMCOM INCORPORATED^M > Model: SIMCOM_SIM7100A^M > Revision: SIM7100A_V4.5^M > IMEISV: 014339000429148/05^M > +GCAP: +CGSM^M > ^M > +CSUB: B03V03^M > +CSUB: MDM9x15_AP_S_V1.63_161010^M > ^M > +CSQ: 26,99^M > ^M > +COPS: 1,0,"T-Mobile DATA ONLY",7^M > ^M > +CGREG: 0,5^M > ^M > OK > -- got it > > send (AT+COPS=1,2,310260^M) > expect (OK) > ^M > ^M > OK > -- got it > > send (AT+CGDCONT=1,"IP","vf-viriciti",,0,0^M) > expect (OK) > ^M > ^M > OK > -- got it > > send (ATDT*99***1#^M) > expect (CONNECT) > ^M > ^M > CONNECT > -- got it > > Script chat -s -v -f /data/ppp/chatscripts/quectel-chat-connect -T vf-viriciti finished (pid 11933), status = 0x0 > Serial connection established. > using channel 25 > Using interface ppp0 > Connect: ppp0 <--> /dev/ttyUSB3 > sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xfb7fbc11> <pcomp> <accomp>] > rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x8856fba8> <pcomp> <accomp>] > No auth is possible > sent [LCP ConfRej id=0x0 <auth chap MD5>] > rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xfb7fbc11> <pcomp> <accomp>] > rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x8856fba8> <pcomp> <accomp>] > sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x8856fba8> <pcomp> <accomp>] > sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>] > sent [IPV6CP ConfReq id=0x1 <addr fe80::64c5:e93a:eca7:5409>] > rcvd [LCP DiscReq id=0x2 magic=0x8856fba8] > rcvd [IPCP ConfReq id=0x0] > sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>] > rcvd [IPCP ConfNak id=0x1 <addr 10.141.107.204> <ms-dns1 10.1.2.199> <ms-dns2 10.1.2.200>] > sent [IPCP ConfReq id=0x2 <addr 10.141.107.204> <ms-dns1 10.1.2.199> <ms-dns2 10.1.2.200>] > rcvd [IPCP ConfReq id=0x1] > sent [IPCP ConfAck id=0x1] > rcvd [IPCP ConfAck id=0x2 <addr 10.141.107.204> <ms-dns1 10.1.2.199> <ms-dns2 10.1.2.200>] > Could not determine remote IP address: defaulting to 10.64.64.64 > not replacing default route to eth0 [192.168.1.254] > local IP address 10.141.107.204 > remote IP address 10.64.64.64 > primary DNS address 10.1.2.199 > secondary DNS address 10.1.2.200 > sent [IPV6CP ConfReq id=0x1 <addr fe80::64c5:e93a:eca7:5409>] > sent [IPV6CP ConfReq id=0x1 <addr fe80::64c5:e93a:eca7:5409>] > > > What we would like of course is for NetworkManager and the nm-ppp-plugin to basically also just get the connection up and running. At the moment we are clueless why the combination of ModemManager & NetworkManager is not able to obtain an active data sessions, but the manual pppd script is. Have you tried to add to the NM plugin the options that are in the manual pppd script? </blockquote><div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif">yes</div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif"> </div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif"> </div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif"></div></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"> > > More (debug) info if attached in a pdf! > > I hope someone has any clue on the particular case, how to debug better, or can give an idea if this is a network operator sided issue. > I'm afraid I haven't seen an issue like this before myself. -- Aleksander <a href="https://aleksander.es" rel="noreferrer" target="_blank">https://aleksander.es</a> </blockquote></div></div>