P2 won't connect to Ethernet

armor · April 18, 2023, 8:15am

Plans to migrate to P2 are on hold until the benefits of using the P2 can be reliably demonstrated to work.

Benefit 1 - the ability to support wired Ethernet and WiFi and switch between them (with an Ethernet adaptor).

Progress so far has been slow and inconclusive.

Having used the Particle Ethernet adaptor board before with Xenon and Argon I was expecting a ‘works out of the box’ experience - unfortunately it has been anything but.

I started trying with an Adafruit Ethernet Featherwing and a SSD1306 OLED display (I2C).

OLED display not working - I2C bug fixed in 5.3.1 - now works (since toolchain released to Particle WB)
Ethernet - stays connecting - substituting WiFi for Ethernet as in WiFi.connect(); works just fine.
Thought it might be the pins used (rst - D3, irq - D4, cs - D5) these are the standard ones - so also tested for Ethernet.isOn() - that returns true but still no connection?
I haven’t used the new feature api in 5.3.1 to swap or remap the pins used - maybe my next step.

Anything I should be aware of that is still not working for connectivity?

rickkas7 · April 18, 2023, 8:34am

Did you solder jumper wires on the Adafruit Ethernet Adapter to connect RST to D3 and IRQ to D4? This is not the default configuration for the Adafruit board. Scroll down to “Notes” here.

Also make sure you enable Ethernet detection from setup() and use SYSTEM_THREAD(ENABLED).

System.enableFeature(FEATURE_ETHERNET_DETECTION);

armor · April 18, 2023, 11:33am

@rickkas7 Thanks for picking this up. Here is a photo of the board - you can see I have soldered the jumper wires.

Surely if this was wrong Ethernet.isOn() would not have returned true?

I am using SYSTEM_THREAD(ENABLED); and System.enableFeature(FEATURE_ETHERNET_DETECTION); in setup().

This has once connected but is very fickle - I am coming under pressure to migrate now that you have shipped 3000 P2 to us.

Could we have an update on where you think there are still issues with Device OS please like the antenna selection?

rickkas7 · April 18, 2023, 11:37am

I’d use

SerialLogHandler logHandler(LOG_LEVEL_TRACE);

use

SYSTEM_MODE(SEMI_AUTOMATIC);

and include this before connecting in setup() so Serial has a chance to connect to view the logs:

waitFor(Serial.isConnected, 10000);
delay(2000);

Hopefully there will be something in the log that is helpful.

As long as you use BLE.selectAntenna() it should work fine for both BLE and Wi-Fi.

armor · April 18, 2023, 1:00pm

@rickkas7

This is the sum of the trace output

0000012713 [system.nm] INFO: State changed: DISABLED → IFACE_DOWN
0000012731 [system.nm] INFO: State changed: IFACE_DOWN → IFACE_REQUEST_UP
0000012751 [net.ifapi] INFO: Netif en2 state UP
0000012870 [net.en] TRACE: Closed MACRAW socket
0000012903 [net.en] TRACE: Opened MACRAW socket, err = 0
0000012920 [system.nm] INFO: State changed: IFACE_REQUEST_UP → IFACE_UP
0000012945 [net.en] INFO: Link up
0000012947 [net.ifapi] INFO: Netif en2 link UP, profile=NONE
0000012951 [system.nm] INFO: State changed: IFACE_UP → IFACE_LINK_UP

Can you see any reason why Ethernet.connect(); isn’t then working?

I just tried with LOG_LEVEL_ALL and got a bit further to Particle connected…so why is it working with Log Handler on and not when it isn’t on?

0000005451 [system.nm] INFO: State changed: IFACE_UP → IFACE_LINK_UP
0000005780 [hal] INFO: DNS server list changed
0000005781 [hal] INFO: DNS server list changed
0000005783 [net.ifapi] TRACE: Netif en2 ipv4 configuration changed
0000005786 [system.nm] INFO: State changed: IFACE_LINK_UP → IP_CONFIGURED
0000007970 [system] INFO: Cloud: connecting
0000007991 [system] INFO: Read Server Address = type:1,domain:$id.udp.particle.io
0000008033 [system] INFO: Loaded cloud server address and port from session data
0000008070 [system] TRACE: Address type: 1
0000008088 [system] TRACE: Cloud socket=0, family=2, type=2, protocol=17
0000008124 [system] INFO: Cloud socket=0, connecting to 3.222.143.118#5684
0000008162 [system] TRACE: Cloud socket=0, connected to 3.222.143.118#5684
0000008200 [system] TRACE: Updating cloud keepalive for AF_INET: 25000 → 25000
0000008298 [system] TRACE: Applying new keepalive interval now
0000008327 [system] INFO: Cloud socket connected
0000008350 [system] INFO: Starting handshake: presense_announce=0
0000008381 [comm.protocol.handshake] INFO: Establish secure connection
0000008413 [comm.dtls] INFO: session has 0 uses
0000008440 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=0
0000008471 [comm.dtls] INFO: out_ctr 0,1,0,0,0,0,0,21, next_coap_id=f5
0000008506 [comm.dtls] INFO: restored session from persisted session data. next_msg_id=245
0000008550 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 2
0000009483 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000009517 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000009545 [comm.protocol.handshake] INFO: Sending HELLO message
0000009573 [comm.coap] TRACE: Sending CoAP message
0000009596 [comm.coap] TRACE: CON POST /h size=39 token= id=246
0000014104 [comm.coap] TRACE: Retransmitting CoAP message; ID: 246; attempt 1 of 3
0000014139 [comm.coap] TRACE: Sending CoAP message
0000014163 [comm.coap] TRACE: CON POST /h size=39 token= id=246
0000023213 [comm.coap] TRACE: Retransmitting CoAP message; ID: 246; attempt 2 of 3
0000023258 [comm.coap] TRACE: Sending CoAP message
0000023285 [comm.coap] TRACE: CON POST /h size=39 token= id=246
0000043275 [comm.coap] TRACE: Retransmitting CoAP message; ID: 246; attempt 3 of 3
0000043294 [comm.coap] TRACE: Sending CoAP message
0000043309 [comm.coap] TRACE: CON POST /h size=39 token= id=246
0000084962 [comm.coap] ERROR: CoAP message timeout; ID: 246
0000084976 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 0
0000084994 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000085010 [comm.protocol.handshake] ERROR: Could not send HELLO message: 10
0000085237 [service.ntp] TRACE: NTP time: 2023-04-18T13:07:48.366447Z
0000085260 [system] WARN: Internet available, cloud not reachable
0000085276 [system] WARN: Cloud handshake failed, code=-160
0000085539 [system] INFO: Cloud: disconnecting
0000085553 [system] INFO: Cloud: disconnected
0000086080 [system] INFO: Cloud: connecting
0000086101 [system] INFO: Read Server Address = type:1,domain:$id.udp.particle.io
0000086144 [system] WARN: Failed to load session data from persistent storage
0000086183 [system] INFO: Discarding session data
0000086225 [system] TRACE: Resolving 0a10aced202194944a001698.v5.udp.particle.io#5684
0000086502 [system] TRACE: Address type: 3
0000086534 [system] TRACE: Cloud socket=0, family=2, type=2, protocol=17
0000086563 [system] INFO: Cloud socket=0, connecting to 3.215.122.234#5684
0000086596 [system] TRACE: Cloud socket=0, connected to 3.215.122.234#5684
0000086694 [system] TRACE: Updating cloud keepalive for AF_INET: 25000 → 25000
0000086770 [system] TRACE: Applying new keepalive interval now
0000086796 [system] INFO: Cloud socket connected
0000086814 [system] INFO: Starting handshake: presense_announce=0
0000086843 [comm.protocol.handshake] INFO: Establish secure connection
0000086876 [comm.dtls] INFO: (CMPL,RENEG,NO_SESS,ERR) restoreStatus=2
0000089678 [comm.protocol.handshake] INFO: Sending HELLO message
0000089701 [comm.coap] TRACE: Sending CoAP message
0000089720 [comm.coap] TRACE: CON POST /h size=39 token= id=247
0000089935 [comm.coap] TRACE: Received CoAP message
0000089954 [comm.coap] TRACE: ACK 0.00 size=4 token= id=247
0000089977 [comm.protocol.handshake] INFO: Handshake completed
0000089999 [comm.protocol.handshake] TRACE: Updating cached session parameters
0000090028 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000090054 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000091528 [comm.coap] TRACE: Sending CoAP message
0000091554 [comm.coap] TRACE: CON POST /d?\x01 size=505 token=ef id=248
0000091611 [system] INFO: Send spark/device/last_reset event
0000091657 [comm.coap] TRACE: Sending CoAP message
0000091681 [comm.coap] TRACE: CON POST /E/spark/device/last_reset size=42 token= id=249
0000091731 [comm.coap] TRACE: Sending CoAP message
0000091845 [comm.coap] TRACE: CON POST /E/particle/device/updates/enabled size=44 token= id=250
0000092008 [comm.coap] TRACE: Sending CoAP message
0000092120 [comm.coap] TRACE: CON POST /E/particle/device/updates/forced size=44 token= id=251
0000092286 [comm] INFO: Sending TIME request
0000092325 [comm.coap] TRACE: Sending CoAP message
0000092351 [comm.coap] TRACE: CON GET /t size=7 token=f0 id=252
0000092387 [system] INFO: Sending application DESCRIBE
0000092539 [comm.coap] TRACE: Sending CoAP message
0000092587 [comm.coap] TRACE: CON POST /d?\x02 size=25 token=f1 id=253
0000092627 [system] INFO: Sending subscriptions
0000092685 [comm.protocol] INFO: Sending subscriptions
0000092712 [comm.coap] TRACE: Sending CoAP message
0000092736 [comm.coap] TRACE: CON GET /e/particle?u size=17 token= id=254
0000092838 [comm.coap] TRACE: Sending CoAP message
0000092887 [comm.coap] TRACE: CON GET /e/spark?u size=14 token= id=255
0000092933 [comm.coap] TRACE: Sending CoAP message
0000093110 [comm.coap] TRACE: CON GET /e/particle/device/name size=28 token= id=256
0000093270 [system] TRACE: Waiting until all handshake messages are processed by the protocol layer
0000093371 [comm.coap] TRACE: Received CoAP message
0000093394 [comm.coap] TRACE: ACK 0.00 size=5 token=ef id=248
0000093425 [comm.protocol] TRACE: Updating system DESCRIBE checksum
0000093519 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000094549 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000094583 [comm.coap] TRACE: Received CoAP message
0000094608 [comm.coap] TRACE: ACK 0.00 size=4 token= id=249
0000094739 [comm.coap] TRACE: Received CoAP message
0000094762 [comm.coap] TRACE: CON GET /d?\x04 size=9 token=01 id=1402
0000094799 [comm.protocol] INFO: Received DESCRIBE request; flags: 0x04
0000094835 [comm.coap] TRACE: Sending CoAP message
0000094859 [comm.coap] TRACE: ACK 0.00 size=4 token= id=1402
0000094911 [comm.coap] TRACE: Sending CoAP message
0000094953 [comm.coap] TRACE: CON 2.05 size=151 token=01 id=257
0000095153 [comm.coap] TRACE: Received CoAP message
0000095204 [comm.coap] TRACE: ACK 0.00 size=4 token= id=250
0000095231 [comm.coap] TRACE: Received CoAP message
0000095255 [comm.coap] TRACE: ACK 0.00 size=4 token= id=251
0000095386 [comm.coap] TRACE: Received CoAP message
0000095410 [comm.coap] TRACE: ACK 2.05 size=10 token=f0 id=252
0000095441 [comm.protocol] INFO: Received TIME response: 1681823275
0000095573 [comm.coap] TRACE: Received CoAP message
0000095598 [comm.coap] TRACE: ACK 0.00 size=5 token=f1 id=253
0000095626 [comm.protocol] TRACE: Updating application DESCRIBE checksum
0000095662 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000095690 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000095936 [comm.coap] TRACE: Received CoAP message
0000095959 [comm.coap] TRACE: ACK 0.00 size=4 token= id=254
0000096098 [comm.coap] TRACE: Received CoAP message
0000096123 [comm.coap] TRACE: ACK 0.00 size=4 token= id=255
0000096249 [comm.coap] TRACE: Received CoAP message
0000096275 [comm.coap] TRACE: CON POST /E/particle/device/updates/pending size=47 token=02 id=1403
0000096314 [comm.coap] TRACE: Sending CoAP message
0000096340 [comm.coap] TRACE: ACK 0.00 size=4 token= id=1403
0000096489 [comm.coap] TRACE: Received CoAP message
0000096513 [comm.coap] TRACE: ACK 0.00 size=4 token= id=256
0000096543 [comm.protocol] TRACE: Updating subscriptions checksum
0000096570 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 4
0000096601 [comm.dtls] INFO: session cmd (CLS,DIS,MOV,LOD,SAV): 3
0000096803 [comm.coap] TRACE: Received CoAP message
0000096831 [comm.coap] TRACE: ACK 0.00 size=4 token= id=257
0000096858 [system] INFO: All handshake messages have been processed
0000096995 [system] INFO: Cloud connected
0000097015 [comm.coap] TRACE: Sending CoAP message
0000097027 [comm.coap] TRACE: CON POST /e/particle/device/name size=28 token= id=258
0000097410 [comm.coap] TRACE: Received CoAP message
0000097459 [comm.coap] TRACE: CON POST /E/particle/device/name size=39 token=03 id=1404
0000097499 [comm.coap] TRACE: Sending CoAP message
0000097523 [comm.coap] TRACE: ACK 0.00 size=4 token= id=1404
0000097575 [comm.coap] TRACE: Received CoAP message
0000097617 [comm.coap] TRACE: ACK 0.00 size=4 token= id=258
0000122663 [comm.coap] TRACE: Sending CoAP message
0000122685 [comm.coap] TRACE: CON 0.00 size=4 token= id=259
0000122906 [comm.coap] TRACE: Received CoAP message
0000122929 [comm.coap] TRACE: ACK 0.00 size=4 token= id=259
0000148000 [comm.coap] TRACE: Sending CoAP message
0000148024 [comm.coap] TRACE: CON 0.00 size=4 token= id=260

rickkas7 · April 18, 2023, 1:54pm

The second log looks like it eventually connected to the cloud. Was it breathing cyan at the end?

If you lose connectivity, you probably need to reduce the Particle.keepAlive when on Ethernet. I’d start with setting it to 25 seconds when on Ethernet, keep the default of 23 minutes on cellular.

armor · April 18, 2023, 3:04pm

Yes it did connect, but very very long time on Particle cloud connection.

Will reduce the keepAlive as you suggest. Still not clear what was changed that made it work - and that I find a bit worrying. How new is this network stack and are there other ‘odd behaviours’ to be discovered with WiFi?

Thanks for your help.

rickkas7 · April 18, 2023, 3:29pm

The Photon and P1 used the Broadcom/Cypress stack on Wi-Fi, and the Electron/E Series used the u-blox modem AT-command based socket implementation. This had the disadvantage of having completely different stacks and things like DNS across the platforms.

Starting with Gen 3 (Argon, Boron, B Series SoM), we run both the cellular modem (u-blox or Quectel) or the ESP32 in PPP mode and implement all of IP using LwIP identically across both cellular, Wi-Fi, and Ethernet.

On the P2/Photon 2, we do the same on the RTL872x.

What this means is that there are obviously some differences at the low-level of the stack, but at IP and higher layers, including UDP, TCP, and DNS, all of the devices should behave in the same way and use the same code.

And Ethernet on the P2/Photon 2 uses the same WizNET driver as Gen 3.

armor · April 18, 2023, 3:57pm

Why does the Particle Cloud connection take so long - 40-60 seconds. Seems to have many warnings and errors - previous experiences was Ethernet network and internet connections happened in 2-3 seconds.

rickkas7 · April 18, 2023, 4:22pm

It’s basically instantaneous for me. It looks like there are number of retries even in your success case. It’s not obvious to me why that’s happening on a wired Ethernet connection, but the first connection fails to connect but then it finally works normally.

rickkas7 · April 18, 2023, 6:10pm

The first time, it starts the connection here (8.3 seconds)

0000008327 [system] INFO: Cloud socket connected

Sending CoAP messages to the cloud fails repeatedly, with various timeouts, until it gives up at 85.5 seconds:

0000085553 [system] INFO: Cloud: disconnected

Then the next connection starts here:

0000086080 [system] INFO: Cloud: connecting

And is completed here:

0000096995 [system] INFO: Cloud connected

10 seconds is a little long, but not unreasonable for a full renegotiation. On a session resume it will be much faster.

So if the first failure to communicate did not happen, to would have been much faster, but it’s not clear from the log why the first time failed. It looks like traffic either wasn’t getting out or wasn’t getting back, which could be related to temporary port forwarding on your network.