PPPD issue on ELS61-E | Telit Cinterion IoT Developer Community
March 3, 2020 - 12:27pm, 3634 views
Hi,
I'm experiencing a strange issue with an ELS61-E modem.
I have an ESEYE SIM that works just fine with a TC65i and an ELS61-E R2.
I'm connecting via PPP. Aparently the CHAP authentication is not triggered on the ELS61-E.
I really don't understand how that is possible because apparently it is requested from the other side.
After that, the ELS61 get no response when trying to set the VJ compression, while the ELS61-E R2 gets a ProtRej message and continues without issues.
EDIT: When disabling VJ compression the behaviour is still the same, so the problem proably sits on the authentication side.
Following are PPP logs for ELS61-E R2 and ELS61-E that show the difference. (The first differences are highlighted using bold).
ELS61-E R2 OK
<149>Mar 3 11:10:07 pppd[35]: pppd 2.3.8 started by (unknown), uid 0
<148>Mar 3 11:10:07 pppd[35]: /bin/chat -v -f /etc/ppp/connect
<150>Mar 3 11:10:08 chat[36]: timeout set to 8 seconds
<150>Mar 3 11:10:08 chat[36]: abort on (BUSY)
<150>Mar 3 11:10:08 chat[36]: abort on (VOICE)
<150>Mar 3 11:10:08 chat[36]: abort on (ERROR)
<150>Mar 3 11:10:08 chat[36]: abort on (NO CARRIER)
<150>Mar 3 11:10:08 chat[36]: send (ATD*99***1#^M)
<150>Mar 3 11:10:10 chat[36]: timeout set to 30 seconds
<150>Mar 3 11:10:10 chat[36]: expect (CONNECT)
<150>Mar 3 11:10:10 chat[36]: ^M
<150>Mar 3 11:10:10 chat[36]: CONNECT
<150>Mar 3 11:10:10 chat[36]: -- got it
<150>Mar 3 11:10:10 chat[36]: send (^M)
<148>Mar 3 11:10:13 pppd[35]: Serial connection established.
<148>Mar 3 11:10:13 pppd[35]: using channel 1
<148>Mar 3 11:10:13 pppd[35]: Using interface ppp0
<149>Mar 3 11:10:13 pppd[35]: pppd create pidfile
<148>Mar 3 11:10:13 pppd[35]: Connect: ppp0 <--> /dev/ttyS1
<148>Mar 3 11:10:14 pppd[35]: sent [LCP ConfReq id=0x1 <asyncmap 0xa0000> <magic 0x74b510de> <pcomp> <accomp>]
<148>Mar 3 11:10:14 pppd[35]: Timeout 0x649c2cc8:0x649fa664 in 3 seconds.
<148>Mar 3 11:10:14 pppd[35]: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MD5> <magic 0x34287b32> <pcomp> <accomp>]
<148>Mar 3 11:10:14 pppd[35]: lcp_reqci: returning CONFACK.
<148>Mar 3 11:10:14 pppd[35]: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <auth chap MD5> <magic 0x34287b32> <pcomp> <accomp>]
<148>Mar 3 11:10:14 pppd[35]: rcvd [LCP ConfAck id=0x1 <asyncmap 0xa0000> <magic 0x74b510de> <pcomp> <accomp>]
<148>Mar 3 11:10:14 pppd[35]: Untimeout 0x649c2cc8:0x649fa664.
<148>Mar 3 11:10:14 pppd[35]: rcvd [CHAP Challenge id=0x1 <9500fa931280f400>, name = ""]
<148>Mar 3 11:10:14 pppd[35]: ChapReceiveChallenge: rcvd type CHAP-DIGEST-MD5
<148>Mar 3 11:10:15 pppd[35]: sent [CHAP Response id=0x1 <166f3dc3e3b6f0285ed58cf1ceab6c09>, name = "USER"]
<148>Mar 3 11:10:15 pppd[35]: Timeout 0x649cacac:0x649fa974 in 3 seconds.
<148>Mar 3 11:10:15 pppd[35]: rcvd [CHAP Success id=0x1 "Welcome!"]
<148>Mar 3 11:10:15 pppd[35]: Untimeout 0x649cacac:0x649fa974.
<148>Mar 3 11:10:15 pppd[35]: Remote message: Welcome!
<148>Mar 3 11:10:15 pppd[35]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
<148>Mar 3 11:10:15 pppd[35]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:10:17 pppd[35]: sent [CCP ConfReq id=0x1]
<148>Mar 3 11:10:17 pppd[35]: Timeout 0x649c2cc8:0x649fa8c4 in 3 seconds.
<148>Mar 3 11:10:17 pppd[35]: rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 04]
<148>Mar 3 11:10:17 pppd[35]: Untimeout 0x649c2cc8:0x649fa8c4.
<148>Mar 3 11:10:17 pppd[35]: rcvd [IPCP ConfReq id=0x1]
<148>Mar 3 11:10:17 pppd[35]: ipcp: returning Configure-NAK
<148>Mar 3 11:10:17 pppd[35]: sent [IPCP ConfNak id=0x1 <addr 10.0.0.1>]
<148>Mar 3 11:10:17 pppd[35]: rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]
<148>Mar 3 11:10:17 pppd[35]: Untimeout 0x649c2cc8:0x649fa884.
<148>Mar 3 11:10:17 pppd[35]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0>]
<148>Mar 3 11:10:17 pppd[35]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:10:17 pppd[35]: rcvd [IPCP ConfReq id=0x2 <addr 10.228.127.220>]
<148>Mar 3 11:10:17 pppd[35]: ipcp: returning Configure-ACK
<148>Mar 3 11:10:17 pppd[35]: sent [IPCP ConfAck id=0x2 <addr 10.228.127.220>]
<148>Mar 3 11:10:17 pppd[35]: rcvd [IPCP ConfNak id=0x2 <addr 10.228.127.220>]
<148>Mar 3 11:10:17 pppd[35]: Untimeout 0x649c2cc8:0x649fa884.
<148>Mar 3 11:10:17 pppd[35]: sent [IPCP ConfReq id=0x3 <addr 10.228.127.220>]
<148>Mar 3 11:10:17 pppd[35]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:10:17 pppd[35]: rcvd [IPCP ConfAck id=0x3 <addr 10.228.127.220>]
<148>Mar 3 11:10:17 pppd[35]: Untimeout 0x649c2cc8:0x649fa884.
<148>Mar 3 11:10:17 pppd[35]: ipcp: up
<148>Mar 3 11:10:18 pppd[35]: ioctl(SIOCDELRT): No such process(3)
<148>Mar 3 11:10:18 pppd[35]: local IP address 10.228.127.220
<148>Mar 3 11:10:18 pppd[35]: remote IP address 10.228.127.220
ELS61-E (Fails to connect)
ELS61-E TIMEOUT
<149>Mar 3 11:36:24 pppd[44]:pppd 2.3.8 started by (unknown), uid 0
<148>Mar 3 11:36:24 pppd[44]: /bin/chat -v -f /etc/ppp/connect
<150>Mar 3 11:36:25 chat[45]: timeout set to 8 seconds
<150>Mar 3 11:36:25 chat[45]: abort on (BUSY)
<150>Mar 3 11:36:25 chat[45]: abort on (VOICE)
<150>Mar 3 11:36:25 chat[45]: abort on (ERROR)
<150>Mar 3 11:36:25 chat[45]: abort on (NO CARRIER)
<150>Mar 3 11:36:25 chat[45]: send (ATD*99***1#^M)
<150>Mar 3 11:36:28 chat[45]: timeout set to 30 seconds
<150>Mar 3 11:36:28 chat[45]: expect (CONNECT)
<150>Mar 3 11:36:28 chat[45]: ^M
<150>Mar 3 11:36:28 chat[45]: CONNECT
<150>Mar 3 11:36:28 chat[45]: -- got it
<150>Mar 3 11:36:28 chat[45]: send (^M)
<148>Mar 3 11:36:29 pppd[44]: Serial connection established.
<148>Mar 3 11:36:29 pppd[44]: using channel 2
<148>Mar 3 11:36:29 pppd[44]: Using interface ppp0
<149>Mar 3 11:36:29 pppd[44]: pppd create pidfile
<148>Mar 3 11:36:29 pppd[44]: Connect: ppp0 <--> /dev/ttyS1
<148>Mar 3 11:36:30 pppd[44]: sent [LCP ConfReq id=0x1 <asyncmap 0xa0000> <magic 0x22294d2b> <pcomp> <accomp>]
<148>Mar 3 11:36:30 pppd[44]: Timeout 0x649c2cc8:0x649fa664 in 3 seconds.
NO CHAP request here!
<148>Mar 3 11:36:30 pppd[44]: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x8602da91> <pcomp> <accomp>]
<148>Mar 3 11:36:30 pppd[44]: lcp_reqci: returning CONFACK.
<148>Mar 3 11:36:30 pppd[44]: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x8602da91> <pcomp> <accomp>]
<148>Mar 3 11:36:30 pppd[44]: rcvd [LCP ConfAck id=0x1 <asyncmap 0xa0000> <magic 0x22294d2b> <pcomp> <accomp>]
<148>Mar 3 11:36:30 pppd[44]: Untimeout 0x649c2cc8:0x649fa664.
<148>Mar 3 11:36:30 pppd[44]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
<148>Mar 3 11:36:30 pppd[44]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:36:34 pppd[44]: sent [CCP ConfReq id=0x1]
NO response to the VJ compression setup
<148>Mar 3 11:36:36 pppd[44]: Timeout 0x649c2cc8:0x649fa8c4 in 3 seconds.
<148>Mar 3 11:36:36 pppd[44]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
<148>Mar 3 11:36:36 pppd[44]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:36:36 pppd[44]: rcvd [LCP ProtRej id=0x2 80 fd 01 01]
<148>Mar 3 11:36:37 pppd[44]: Untimeout 0x649c2cc8:0x649fa8c4.
<148>Mar 3 11:36:39 pppd[44]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
<148>Mar 3 11:36:40 pppd[44]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:36:43 pppd[44]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
<148>Mar 3 11:36:45 pppd[44]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:36:48 pppd[44]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
<148>Mar 3 11:36:49 pppd[44]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:36:52 pppd[44]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
<148>Mar 3 11:36:53 pppd[44]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:36:56 pppd[44]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
<148>Mar 3 11:36:58 pppd[44]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:37:01 pppd[44]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
<148>Mar 3 11:37:01 pppd[44]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:37:04 pppd[44]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
<148>Mar 3 11:37:04 pppd[44]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:37:07 pppd[44]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
<148>Mar 3 11:37:09 pppd[44]: Timeout 0x649c2cc8:0x649fa884 in 3 seconds.
<148>Mar 3 11:37:12 pppd[44]: IPCP: timeout sending Config-Requests
<148>Mar 3 11:37:12 pppd[44]: CCP: Down event in state 1!
<148>Mar 3 11:37:12 pppd[44]: sent [LCP TermReq id=0x2 "No network protocols running"]
<148>Mar 3 11:37:13 pppd[44]: Timeout 0x649c2cc8:0x649fa664 in 3 seconds.
<148>Mar 3 11:37:16 pppd[44]: sent [LCP TermReq id=0x3 "No network protocols running"]
<148>Mar 3 11:37:17 pppd[44]: Timeout 0x649c2cc8:0x649fa664 in 3 seconds.
<148>Mar 3 11:37:20 pppd[44]: Connection terminated.
<150>Mar 3 11:37:20 pppd[44]: Exit.
----
PPP configration is exactly the same in both modems.
Thanks in advance for any advice
Toni
Hi,
apparently I managed to find a workaround to this issue, but I'd like to understand the implications.
The problem as stated in the OP is related to the authentication.
The Eseye SIM card required CHAP authentication to be used.
Normally, the modem should just use the authentication asked by the SIM card, however for unknown reason this only happens on TC65i and ELS61-E R2 (2G/3G/4G version). ELS61-E (2G/4G version) doesn't.
To fix the problem, I need to specify the authentication to be used using the AT^SGAUTH command.
Then it works as expected.
The exact command is AT^SGAUTH=1,2,"USER","PASS"
(profile 1, auth 2(CHAP), and the SIM user and pwd)
Is this a bug on the ELS61-E, or am I missing something?
What bothers me is that this parameter appears to be persistent, so if I change the SIM card I need to make sure I reset this command to the default value which is AT^SGAUTH=1,0,"","".
This is a problem because any "tainted" modem used on earler versions of my software might encounter authentication issues because it might force CHAP on SIMs not requiring it. Since the command is not used, it would stay with CHAP forever.
Any advice on how to handle this?
Hello,
The SGAUTH command can set the authentication type for PPP. According to documentation the defailt value for both ELS61 modules is 0 - no authentication, while for TC65i it's 1 - PAP. Have you verified SGAUTH settings for all modules under test?
Regards,
Bartłomiej
Hi Bartłomiej,
yes, I did.
The AT^SGAUTH had this values BEFORE any changes:
TC65: ^SGAUTH: 1
ELS61^-E: ^SGAUTH: 1,0,""
ELS61^-E R2: ^SGAUTH: 1,0,""
Both ELS61 had the same (default) value which is No authentication.
Yet, the R2 used CHAP without any problems, while "R1" failed to use it.
When I used AT^SGAUTH=1,2,"USER","PASS" I fixed the problem for the R1.
I tried to do it for the R2 and it kept working, but now I can't go back to 0 because it behaves like the R1 at the beggining. So now the R2 it only works if i set the parameter explicitly.
AT^SGAUTH has exactly the SAME value it had when it was working as default, but behaves differently.
I can ****** I changed nothing else and that the value was the default one, but it appears that using AT^SGAUTH once changes something internally that prevents going back to the desireable behaviour it has at the beginning.
In my opinion even if set as auth=0, it was behaving like it should use CHAP. Is this a bug?
Is there anything at all to go back to that behaviour? Some kind of modem o profile reset? (AT&F didn't help)
Regards
Toni
Hello,
SGAUTH command is intended for this configuration, so the current behavior is correct. Fo now I don't know why CHAP was used at first. I also believe that no command should be able to restore this behavior. Could you check the firmware version with 'ATI1' command?
Regards,
Bartłomiej
Hi Bartłomiej,
I'm not sure how the protocolo negotiation works, but I really think there should be an SGAUTH option, that accepts all protocols and leaves to the SIM card the decision to ask for a certain auhentication.
I'm also surprised that the ELS61-E R2 managed to use CHAP while without explicilty setting it and with a default SGAUTH value set to 0 (No auth). (Internally is was clearly assuming CHAP)
When SGAUTH was called explicitly it started to work as expected.
Firmware version for ELS61-E R2 is
REVISION 02.000'
A-REVISION 01.000.01
Firmware version for ELS61-E (R1) is
REVISION 01.000
A-REVISION 00.010.00
BR
Toni
Hello,
As far as I remember for some module types there is a setting PAP & CHAP. Then one authentication is tried and if failed the other one is attempted. But for this module there is no such setting.
Actually in this case the authentication in PPP is done twice:
-firstly between host and the module - host sends credentials to the module,
-secondly between module and network - module sends to the network credentials received from the host
You need SGAUTH command to tell the moudule what authentication type it should use. So using this command would be the correct approach even though you have tested that ELS61-E R2 is using CHAP by default until SGAUTH is not changed.
Best regards,
Bartłomiej