homieiot / homie-esp8266

💡 ESP8266 framework for Homie, a lightweight MQTT convention for the IoT
http://homieiot.github.io/homie-esp8266
MIT License
1.36k stars 308 forks source link

MQTT Socket error on connect #554

Closed kpishere closed 5 years ago

kpishere commented 5 years ago

With the mosquito MQTT broker on HighSierra .. I get the following (this worked 6 months ago). Note that I've reverted to the example test script Broadcast.ino and I still get the same issue.

Here is starting mqtt in terminal ... I've put '*' at the beginning of the lines below where things start to get weird.

Kevins-Mac-mini-10:~ kevinpeck$ /usr/local/sbin/mosquitto -d -v -c /usr/local/etc/mosquitto/mosquitto.conf & [1] 20646 Kevins-Mac-mini-10:~ kevinpeck$ 1546185065: mosquitto version 1.5.5 starting 1546185065: Config loaded from /usr/local/etc/mosquitto/mosquitto.conf. 1546185065: Opening ipv6 listen socket on port 1883. 1546185065: Opening ipv4 listen socket on port 1883. 1546185098: New connection from 192.168.1.101 on port 1883. 1546185098: New client connected from 192.168.1.101 as Homie-heatpump (c1, k15). 1546185098: Will message specified (5 bytes) (r1, q1). 1546185098: homie/heatpump/$online 1546185098: Sending CONNACK to Homie-heatpump (0, 0) 1546185098: Received PUBLISH from Homie-heatpump (d0, q1, r1, m1, 'homie/heatpump/$homie', ... (5 bytes)) 1546185098: Sending PUBACK to Homie-heatpump (Mid: 1) 1546185098: Received PUBLISH from Homie-heatpump (d0, q1, r1, m2, 'homie/heatpump/$mac', ... (17 bytes)) 1546185098: Sending PUBACK to Homie-heatpump (Mid: 2) 1546185098: Received PUBLISH from Homie-heatpump (d0, q1, r1, m3, 'homie/heatpump/$name', ... (8 bytes)) 1546185098: Sending PUBACK to Homie-heatpump (Mid: 3) 1546185098: Received PUBLISH from Homie-heatpump (d0, q1, r1, m4, 'homie/heatpump/$localip', ... (13 bytes)) 1546185098: Sending PUBACK to Homie-heatpump (Mid: 4) 1546185098: Received PUBLISH from Homie-heatpump (d0, q1, r1, m5, 'homie/heatpump/$stats/interval', ... (1 bytes)) 1546185098: Sending PUBACK to Homie-heatpump (Mid: 5) 1546185098: Received PUBLISH from Homie-heatpump (d0, q1, r1, m6, 'homie/heatpump/$fw/name', ... (14 bytes)) 1546185098: Sending PUBACK to Homie-heatpump (Mid: 6) 1546185098: Received PUBLISH from Homie-heatpump (d0, q1, r1, m7, 'homie/heatpump/$fw/version', ... (5 bytes)) 1546185098: Sending PUBACK to Homie-heatpump (Mid: 7) 1546185098: Received PUBLISH from Homie-heatpump (d0, q1, r1, m8, 'homie/heatpump/$fw/checksum', ... (32 bytes)) 1546185098: Sending PUBACK to Homie-heatpump (Mid: 8) 1546185098: Received PUBLISH from Homie-heatpump (d0, q1, r1, m9, 'homie/heatpump/$implementation', ... (7 bytes)) 1546185098: Sending PUBACK to Homie-heatpump (Mid: 9) 1546185098: Received PUBLISH from Homie-heatpump (d0, q1, r1, m10, 'homie/heatpump/$implementation/config', ... (154 bytes)) 1546185098: Sending PUBACK to Homie-heatpump (Mid: 10) 1546185109: New connection from 192.168.1.101 on port 1883. 1546185109: Client Homie-heatpump already connected, closing old connection. 1546185109: Socket error on client Homie-heatpump, disconnecting. 1546185109: New client connected from 192.168.1.101 as Homie-heatpump (c1, k15). 1546185109: Will message specified (5 bytes) (r1, q1). 1546185109: homie/heatpump/$online 1546185109: Sending CONNACK to Homie-heatpump (0, 0)

On the console output of the ESP8266 (NodeMCU) I see ... a wdt reset. I've got it configured for 1M SPIFFS and compilation reports usage of

Compile message

Sketch uses 552152 bytes (52%) of program storage space. Maximum is 1044464 bytes. Global variables use 33704 bytes (41%) of dynamic memory, leaving 48216 bytes for local variables. Maximum is 81920 bytes. /Users/kevinpeck/Library/Arduino15/packages/esp8266/tools/esptool/2.5.0-3-20ed2b9/esptool -vv -cd nodemcu -cb 115200 -cp /dev/cu.wchusbserial1470 -ca 0x00000 -cf /var/folders/x7/y17hyhq52_90jzym4661ntx80000gn/T/arduino_build_187343/Broadcast.ino.bin

Debug output on serial port

↕ Attempting to connect to MQTT... ↕ Attempting to connect to MQTT... Sending initial information...

ets Jan 8 2013,rst cause:4, boot mode:(3,7)

wdt reset load 0x4010f000, len 1384, room 16 tail 8 chksum 0x2d csum 0x2d v0fd86a07 ~ld

SDK:3.0.0-dev(c0f7b44)/Core:2.5.0-beta2=20499902/lwIP:STABLE-2_1_2_RELEASE/glue:1.0-4-gc434c6f/BearSSL:2398cc6

state: 2 -> 3 (0) state: 3 -> 5 (10) add 0 aid 4 cnt 💡 Firmware broadcast-test (1.0.0) 🔌 Booting into normal mode 🔌 {} Stored configuration • Hardware device ID: 84f3eb7a7fe5 • Device ID: heatpump • Name: heatpump • Device Stats Interval: 60 sec • Wi-Fi: ◦ SSID: 21BirchleaAve ◦ Password not shown • MQTT: ◦ Host: 192.168.1.199 ◦ Port: 1883 ◦ Base topic: homie/ ◦ Auth? no • OTA: ◦ Enabled? yes ↕ Attempting to connect to Wi-Fi...

connected with 21BirchleaAve, channel 7 dhcp client start... scandone ip:192.168.1.101,mask:255.255.255.0,gw:192.168.1.1 ✔ Wi-Fi connected, IP: 192.168.1.101 Triggering WIFI_CONNECTED event... ↕ Attempting to connect to MQTT... Sending initial information...

I'd tried capacitors, disconnecting everything but the USB, even tried a new NodeMCU board and still get this error. Version is 2.0.0 for Homie, ArduinoJson version 5.13.4, and the rest are at latest versions.

Attached is a wire shark dump of the communication between MQTT and the ESP8266. mqtt-homie-capture01.pcapng.zip

kpishere commented 5 years ago

This can be closed. Problem solved. I'd set all dependant libraries to their respective branch/masters .. still had error. then in log above, I see that I've got the beta2 of ESP8266 board management tools ... I'd set that back to 2.4.X (latest non-beta) and all is good. the above log suggests to me it is a threading issue/interrupt in beta code (some new stuff for ESP32). Anyhow. Happy NY!