Failing to connect Boron 2G/3G in Colombia

[Alondonob]

Hello everyone,

I would like to have some support with an issue that is been happening since last week.
I’m trying to test a new firmware for Boron 2G/3G because we have a client that requires this type of network connection (they don’t have wifi network) but it haven’t been possible because the device doesn’t connect to the cloud.

In april, I was testing another firmware in this particular device and everything worked fine by then. We were using the e-SIM, so everything was correctly configured.

Now, that I resumed the tests with this device, I can’t understand what the problem is.
Searching for the solution, I have been doing differents things as I numbered in the following list:

1. Reading in Community Particle, I found some similar cases and they proposed to do a “particle update” through the serial USB terminal (CLI). It made the device upgrade from OS 2.3.1 to OS 4.0.1. but the problem with the connectivity wasn’t solved.
2. I wondered if the problem had something to do with the choice SIM type (External - 3rth party sim/Internal - eSIM), so I made a test firmware choosing the INTERNAL sim through code and doing a debug. It was successfully configured but the device didn’t connect to th cloud either.
3. I deactived and actived the internal SIM in Particle console. It didn’t make the difference.
4. I did the downgrade manually to the earlier version (2.3.1), and then an upgrading manually to the latest version (4.0.1) because I wanted to be sure that the .bin archives were flashed in the right order on the device. The issue continues.
5. In the Community Particle someone mentioned a Cloud Debug firmware to see through “particle serial monitor” what was happening in the device when trying to connect to the cloud and understand the error. I have the logs but the errors aren’t clear to me so I can’t find a solution.
6. The device is presenting the following behavior: the led is in green (looking for network), then it goes to cyan and starts to blink faster (as it would finally connect), the led goes to cyan breathing for just 1 cycle (apparently it is connected) and goes inmediately to green again. Sometime happens that the led is in green, then it goes to cyan and starts to blink faster but when you think it is going to finally connect, the led blinks one time in red. I have been reading about this and the documentation says that there’s a problem with the server keys, but when I do the steps to fix that with particle CLI, the device keeps failling to connect.

I would appreciate any help that you may give me in this situation.

[Colleen]

Hi Alenjandra-

That sounds like a broken keys issue. Can you please try the device doctor and let me know what happens.

Thanks,
Colleen

[Alondonob]

Hi Colleen,

Thank you so much for your answer. I tried the Device Doctor but the issue remains
I have the logs, as you can see, teh devices connects to the cloud for a moment, but then loses the connection. Maybe you can understand something I’m missing to solve it .

Device ID: e00fce683bb72dead7f390f5
ICCID: 89883070000008850255
IMEI: 354762116399954
Modem Manufacturer: u-blox
Modem Model: SARA-U201
Modem Firmware Version: 23.60
Power Supply: USB Host
Battery: Charged
Battery SoC: 100
Country: Colombia
Carrier: Movistar
Access Technology: 3G
Band: UMTS 1900
Cellular Global Identity: cid=33106156 lac=5164 mcc=732 mnc=123
0000000304 [system.nm] TRACE: Request to power on the interface
0000000304 [ncp.client] TRACE: Powering modem on, ncpId: 0x42
0000000304 [ncp.client] TRACE: Modem already on
0000000305 [ncp.client] TRACE: Setting UART voltage translator state 1
0000000306 [system.nm] INFO: State changed: DISABLED → IFACE_DOWN
0000000405 [ncp.client] TRACE: Setting UART voltage translator state 0
0000000505 [ncp.client] TRACE: Setting UART voltage translator state 1
0000000505 [ncp.client] TRACE: Muxer is not currently running
0000000506 [ncp.client] TRACE: Initialized muxer @ 921600 baudrate
0000000506 [mux] INFO: Starting GSM07.10 muxer
0000000507 [mux] INFO: GSM07.10 muxer thread started
0000000509 [ncp.client] TRACE: Resumed muxed session
0000000510 [mux] INFO: Openning mux channel 1
0000000859 [mux] INFO: Closing mux channel 2
0000000911 [ncp.at] TRACE: > AT
0000000914 [ncp.at] TRACE: < OK
0000000914 [ncp.client] TRACE: NCP ready to accept AT commands
0000000915 [ncp.at] TRACE: > AT
0000000917 [ncp.at] TRACE: < OK
0000000918 [ncp.at] TRACE: > ATI9
0000000933 [ncp.at] TRACE: < OK
0000000933 [ncp.client] TRACE: App firmware: 101
0000000934 [ncp.at] TRACE: > AT+UGPIOC?
0000000937 [ncp.at] TRACE: < +UGPIOC:
0000000941 [ncp.at] TRACE: < OK
0000000942 [ncp.client] INFO: Using internal SIM card
0000000943 [ncp.at] TRACE: > AT+CPIN?
0000000945 [ncp.at] TRACE: < +CPIN: READY
0000000946 [ncp.at] TRACE: < OK
0000000947 [ncp.at] TRACE: > AT+CCID
0000000966 [ncp.at] TRACE: < +CCID: 89883070000008850255
0000000967 [ncp.at] TRACE: < OK
0000000967 [ncp.at] TRACE: > AT+IFC?
0000000970 [ncp.at] TRACE: < +IFC: 2,2
0000000970 [ncp.at] TRACE: < OK
0000000971 [ncp.at] TRACE: > AT+IFC=2,2
0000000973 [ncp.at] TRACE: < OK
0000000974 [ncp.at] TRACE: > AT
0000000976 [ncp.at] TRACE: < OK
0000000977 [ncp.at] TRACE: > AT+COPS=3,2
0000000979 [ncp.at] TRACE: < OK
0000000980 [ncp.at] TRACE: > AT+CGEREP=1,0
0000000983 [ncp.at] TRACE: < OK
0000000983 [ncp.at] TRACE: > AT+UPSV=0
0000000986 [ncp.at] TRACE: < OK
0000000986 [mux] INFO: Mux channel 1 already opened
0000000988 [ncp.at] TRACE: > AT
0000000990 [ncp.at] TRACE: < OK
0000000990 [ncp.client] TRACE: NCP state changed: 1
0000000990 [net.pppncp] TRACE: NCP event 1
0000000995 [app] INFO: cellular is on
0000000997 [ncp.at] TRACE: > AT+CCID
0000001016 [ncp.at] TRACE: < +CCID: 89883070000008850255
0000001018 [ncp.at] TRACE: < OK
0000001020 [ncp.at] TRACE: > AT+CGMI
0000001023 [ncp.at] TRACE: < OK
0000001025 [ncp.at] TRACE: > AT+CGMM
0000001027 [ncp.at] TRACE: < OK
0000001028 [ncp.at] TRACE: > AT+CGMR
0000001030 [ncp.at] TRACE: < OK
0000001032 [ncp.at] TRACE: > AT+CGSN
0000001046 [ncp.at] TRACE: < OK
0000005320 [app] INFO: Auto-connect disabled
0000005760 [ncp.at] TRACE: > AT+CFUN?
0000005765 [ncp.at] TRACE: < +CFUN: 1,0
0000005765 [ncp.at] TRACE: < OK
0000005767 [ncp.at] TRACE: > AT+CCID
0000005787 [ncp.at] TRACE: < +CCID: 89883070000008850255
0000005787 [ncp.at] TRACE: < OK
0000005788 [ncp.at] TRACE: > AT+CGSN
0000005802 [ncp.at] TRACE: < OK
0000005803 [ncp.at] TRACE: > ATI9
0000005815 [ncp.at] TRACE: < OK
0000006479 [system.nm] INFO: State changed: IFACE_DOWN → IFACE_REQUEST_UP
0000006482 [net.ppp.client] TRACE: PPP thread event ADM_UP data=0
0000006482 [net.ppp.client] TRACE: State NONE → READY
0000006484 [ncp.at] TRACE: > AT+CFUN?
0000006485 [system.nm] INFO: State changed: IFACE_REQUEST_UP → IFACE_UP
0000006487 [ncp.at] TRACE: < +CFUN: 1,0
0000006488 [ncp.at] TRACE: < OK
0000006489 [ncp.at] TRACE: > AT+CCID
0000006508 [ncp.at] TRACE: < +CCID: 89883070000008850255
0000006509 [ncp.at] TRACE: < OK
0000006509 [ncp.at] TRACE: > AT+CGDCONT?
0000006513 [ncp.at] TRACE: < +CGDCONT: 1,“IP”,“super”,“0.0.0.0”,0,0
0000006513 [ncp.at] TRACE: < OK
0000006514 [ncp.at] TRACE: > AT+CFUN?
0000006517 [ncp.at] TRACE: < +CFUN: 1,0
0000006518 [ncp.at] TRACE: < OK
0000006518 [ncp.at] TRACE: > AT+CREG=2
0000006521 [ncp.at] TRACE: < OK
0000006521 [ncp.at] TRACE: > AT+CGREG=2
0000006524 [ncp.at] TRACE: < OK
0000006525 [ncp.client] TRACE: NCP connection state changed: 1
0000006525 [net.pppncp] TRACE: NCP event 2
0000006525 [net.pppncp] TRACE: State changed event: 1
0000006526 [net.ppp.client] TRACE: PPP thread event LOWER_DOWN data=0
0000006527 [ncp.at] TRACE: > AT+COPS?
0000006530 [ncp.at] TRACE: < +COPS: 0,2,“732123”,2
0000006530 [ncp.at] TRACE: < OK
0000006531 [ncp.at] TRACE: > AT+CREG?
0000006534 [ncp.at] TRACE: < +CREG: 2,5,“142C”,“1F928EC”,6
0000006535 [ncp.at] TRACE: < OK
0000006536 [ncp.at] TRACE: > AT+CGREG?
0000006539 [ncp.at] TRACE: < +CGREG: 2,5,“142C”,“1F928EC”,6,“40”
0000006540 [ncp.at] TRACE: < OK
0000006540 [ncp.cli13 [ncp.at] TRACE: < OK
0000007814 [ncp.at] TRACE: > AT+CGATT?
0000007817 [ncp.at] TRACE: < +CGATT: 1
0000007818 [ncp.at] TRACE: < OK
0000008818 [ncp.at] TRACE: > AT
0000008820 [ncp.at] TRACE: < OK
0000008821 [ncp.at] TRACE: > ATH
0000008824 [ncp.at] TRACE: < OK
0000008824 [ncp.at] TRACE: > ATD991#
0000008829 [net.ppp.client] TRACE: PPP phase → Initialize
0000008829 [net.ppp.client] TRACE: PPP phase → Establish
0000008830 [lwip.ppp] TRACE: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x58521666> <pent] TRACE: NCP connection state changed: 2
0000006540 [mux] INFO: Openning mux channel 2
0000007806 [net.pppncp] TRACE: NCP event 100
0000007807 [net.pppncp] TRACE: New auth info
0000007808 [net.pppncp] TRACE: NCP event 2
0000007809 [net.pppncp] TRACE: State changed event: 2
0000007810 [net.ppp.client] TRACE: PPP thread event LOWER_UP data=0
0000007810 [net.ppp.client] TRACE: State READY → CONNECT
0000007810 [net.ppp.client] TRACE: State CONNECT → CONNECTING
0000007811 [ncp.at] TRACE: > AT+CIMI
00000078comp> <ac
0000008835 [lwip.ppp] TRACE: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xf1e9b3ef> <ac
0000008836 [lwip.ppp] TRACE: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xf1e9b3ef> <ac
0000008837 [lwip.ppp] TRACE: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x58521666> <ac
0000008838 [lwip.ppp] TRACE: sent [LCP EchoReq id=0x0 magic=0x58521666]
0000008838 [net.ppp.client] TRACE: PPP phase → Authenticate
0000008839 [net.ppp.client] TRACE: PPP phase → Network
0000008840 [lwip.ppp] TRACE: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <msdns1 8.8.8.8> <msdns2 8.8.
0000008842 [lwip.ppp] TRACE: rcvd [LCP EchoRep id=0x0 magic=0xf1e9b3ef]
0000013838 [lwip.ppp] TRACE: sent [LCP EchoReq id=0x1 magic=0x58521666]
0000013841 [lwip.ppp] TRACE: rcvd [LCP EchoRep id=0x1 magic=0xf1e9b3ef]
0000014840 [lwip.ppp] TRACE: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <msdns1 8.8.8.8> <msdns2 8.8.
0000014844 [lwip.ppp] TRACE: rcvd [IPCP ConfReq id=0x1]
0000014844 [lwip.ppp] TRACE: sent [IPCP ConfAck id=0x1]
0000014846 [lwip.ppp] TRACE: rcvd [IPCP ConfNak id=0x1 <addr 100.64.22.107>]
0000014846 [lwip.ppp] TRACE: sent [IPCP ConfReq id=0x2 <addr 100.64.22.107> <msdns1 8.8.8.8> <msdns
0000014850 [lwip.ppp] TRACE: rcvd [IPCP ConfAck id=0x2 <addr 100.64.22.107> <msdns1 8.8.8.8> <msdns
0000014850 [system.nm] INFO: State changed: IFACE_UP → IFACE_LINK_UP
0000014852 [net.ppp.client] TRACE: PPP thread event UP data=0
0000014852 [net.ppp.client] TRACE: State CONNECTING → CONNECTED
0000014853 [net.pppncp] TRACE: Negotiated MTU: 1500
0000014853 [system.nm] INFO: State changed: IFACE_LINK_UP → IP_CONFIGURED
0000014854 [net.ppp.client] TRACE: PPP phase → Running
0000014855 [system] INFO: Cloud: connecting
0000014859 [system] WARN: Failed to load session data from persistent storage
0000016559 [system] INFO: Cloud socket connected
0000016559 [comm.protocol.handshake] INFO: Establish secure connection
0000016565 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=2
0000017200 [lwip.ppp] TRACE: rcvd [LCP TermReq id=0x2]
0000017200 [system.nm] INFO: State changed: IP_CONFIGURED → IFACE_UP
0000017201 [net.ppp.client] TRACE: PPP phase → Network
0000017201 [net.ppp.client] TRACE: PPP phase → Establish
0000017202 [lwip.ppp] TRACE: sent [LCP TermAck id=0x2]
0000018630 [ncp.at] TRACE: < +CGEV: NW DEACT “IP”,“100.64.22.107”,1
0000019575 [system] ERROR: sock_send returned -1 118
0000019575 [comm.dtls] ERROR: handshake failed -4e
0000019577 [comm.dtls] ERROR: Invalid handshake state
0000019580 [comm.protocol.handshake] ERROR: Handshake failed: 17
0000023201 [net.ppp.client] TRACE: PPP phase → Disconnect
0000023201 [net.ppp.client] TRACE: PPP phase → Dead
0000023201 [net.ppp.client] TRACE: PPP thread event ERROR data=6
0000023202 [net.pppncp] ERROR: PPP error event data=6
0000023202 [net.ppp.client] TRACE: PPP thread event DOWN data=0
0000023203 [net.ppp.client] TRACE: State CONNECTED → DISCONNECT
0000023203 [net.ppp.client] TRACE: State DISCONNECT → DISCONNECTING
0000023203 [net.ppp.client] TRACE: PPP thread event ERROR data=5
0000023204 [net.pppncp] ERROR: PPP error event data=5
0000023204 [net.ppp.client] TRACE: PPP thread event DOWN data=0
0000023205 [net.ppp.client] TRACE: State DISCONNECTING → DISCONNECTED
0000023205 [net.ppp.client] TRACE: State DISCONNECTED → CONNECT
0000023305 [net.ppp.client] TRACE: State CONNECT → CONNECTING
0000023306 [ncp.at] TRACE: > AT+CGATT?
0000023309 [ncp.at] TRACE: < +CGATT: 1
0000023309 [ncp.at] TRACE: < OK
0000024310 [ncp.at] TRACE: > AT
0000024312 [ncp.at] TRACE: < OK
0000024313 [ncp.at] TRACE: > ATH
0000024316 [ncp.at] TRACE: < OK
0000024316 [ncp.at] TRACE: > ATD99**1#
0000024321 [net.ppp.client] TRACE: PPP phase → Initialize
0000024321 [net.ppp.client] TRACE: PPP phase → Establish
0000024322 [lwip.ppp] TRACE: sent [LCP ConfReq id=0x2 <asyncmap 0x0> <magic 0x40b49837> <ac
0000024327 [lwip.ppp] TRACE: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x1005237b> <ac
0000024328 [lwip.ppp] TRACE: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x1005237b> <ac
0000024329 [lwip.ppp] TRACE: rcvd [LCP ConfAck id=0x2 <asyncmap 0x0> <magic 0x40b49837> <ac
0000024330 [lwip.ppp] TRACE: sent [LCP EchoReq id=0x0 magic=0x40b49837]
0000024331 [net.ppp.client] TRACE: PPP phase → Authenticate
0000024331 [net.ppp.client] TRACE: PPP phase → Network
0000024332 [lwip.ppp] TRACE: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <msdns1 8.8.8.8> <msdns2 8.8.
0000024334 [lwip.ppp] TRACE: rcvd [LCP EchoRep id=0x0 magic=0x1005237b]
0000027076 [system] WARN: Internet test failed: DNS
0000027077 [system] WARN: Cloud handshake failed, code=-220
0000027328 [system] INFO: Cloud: disconnecting
0000027328 [system] INFO: Cloud: disconnected
0000029330 [lwip.ppp] TRACE: sent [LCP EchoReq id=0x1 magic=0x40b49837]
0000029333 [lwip.ppp] TRACE: rcvd [LCP EchoRep id=0x1 magic=0x1005237b]
0000030332 [lwip.ppp] TRACE: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <msdns1 8.8.8.8> <msdns2 8.8.
0000030336 [lwip.ppp] TRACE: rcvd [IPCP ConfReq id=0x1]
0000030336 [lwip.ppp] TRACE: sent [IPCP ConfAck id=0x1]
0000030338 [lwip.ppp] TRACE: rcvd [IPCP ConfNak id=0x1 <addr 100.79.186.178>]
0000030338 [lwip.ppp] TRACE: sent [IPCP ConfReq id=0x2 <addr 100.79.186.178> <msdns1 8.8.8.8> <msdn
0000030342 [lwip.ppp] TRACE: rcvd [IPCP ConfAck id=0x2 <addr 100.79.186.178> <msdns1 8.8.8.8> <msdn
0000030342 [system.nm] INFO: State changed: IFACE_UP → IFACE_LINK_UP
0000030344 [net.ppp.client] TRACE: PPP thread event UP data=0
0000030344 [net.ppp.client] TRACE: State CONNECTING → CONNECTED
0000030344 [system.nm] INFO: State changed: IFACE_LINK_UP → IP_CONFIGURED
0000030345 [net.pppncp] TRACE: Negotiated MTU: 1500
0000030346 [net.ppp.client] TRACE: PPP phase → Running
0000030348 [system] INFO: Cloud: connecting
0000030351 [system] WARN: Failed to load session data from persistent storage
0000031966 [lwip.ppp] TRACE: rcvd [LCP TermReq id=0x2]
0000031966 [system.nm] INFO: State changed: IP_CONFIGURED → IFACE_UP
0000031967 [net.ppp.client] TRACE: PPP phase → Network
0000031967 [net.ppp.client] TRACE: PPP phase → Establish
0000031967 [lwip.ppp] TRACE: sent [LCP TermAck id=0x2]
0000033422 [ncp.at] TRACE: < +CGEV: NW DEACT “IP”,“100.79.186.178”,1
0000037967 [net.ppp.client] TRACE: PPP phase → Disconnect
0000037967 [net.ppp.client] TRACE: PPP phase → Dead
0000037967 [net.ppp.client] TRACE: PPP thread event ERROR data=6
0000037968 [net.pppncp] ERROR: PPP error event data=6
0000037968 [net.ppp.client] TRACE: PPP thread event DOWN data=0
0000037969 [net.ppp.client] TRACE: State CONNECTED → DISCONNECT
0000037969 [net.ppp.client] TRACE: State DISCONNECT → DISCONNECTING
0000037969 [net.ppp.client] TRACE: PPP thread event ERROR data=5
0000037970 [net.pppncp] ERROR: PPP error event data=5
0000037970 [net.ppp.client] TRACE: PPP thread event DOWN data=0
0000037971 [net.ppp.client] TRACE: State DISCONNECTING → DISCONNECTED
0000037971 [net.ppp.client] TRACE: State DISCONNECTED → CONNECT
0000038071 [net.ppp.client] TRACE: State CONNECT → CONNECTING

[rickkas7]

This is a problem that is currently being investigated. EtherSIM devices may have difficultly connecting in Colombia, in particular when connecting to Movistar.

The network is rejecting the device immediately after connecting:

0000033422 [ncp.at] TRACE: < +CGEV: NW DEACT “IP”,“100.79.186.178”,1

[Alondonob]

Thanks a lot Rick for the answer. Is this an issue for this particular device or it’s a generilized issue affecting all boron’s trying to connect in Colombia? The carrier Particle has in Colombia is Movistar. if we buy another Boron, will we have the same issue?
Is there any workaround we can do on our end? what is the estimated time to solve the case you’re investigating?