adafruit / Adafruit_Wippersnapper_Arduino

WipperSnapper is a firmware for creating no-code IoT electronics projects.
https://io.adafruit.com/welcome
MIT License
31 stars 44 forks source link

feather s3 / qtpyS2 - issue early beta57 #381

Closed tyeth closed 1 year ago

tyeth commented 1 year ago

Probably my fault, but the s3 feather with psram is not keeping the co2 data updated, seems like it's logging erroneously too, this is the bootup and I've never seen so many connected messages between pings before: image Running on the vlx53l0x branch / build assets. This device: https://io.adafruit.com/tyeth/wippersnapper/feather-esp32s3-4mbflash-2mbpsram13617589

It had a vlx53l0x and SCD41 connected, but seems to fail to start logging again after being booted. For example today I added the lipo fuel sensor to the control panel, and it's updating fine but nothing else is.

tyeth commented 1 year ago

I've stuck it on adafruit/main and that connected message is gone, but I'm getting no data. Presumably due to a decode fail, I wonder if I got some legacy metadata I'm unaware of on that device. In the past failures on this and other devices I usually delete the sensors only. I'll give it a day and delete the device tomorrow.

image
tyeth commented 1 year ago

It i2c scans fine

image image
brentru commented 1 year ago

It had a vlx53l0x and SCD41 connected,

Do you know whether the VLX53l0x or the SCD41 is causing the sync packet error to be thrown?

tyeth commented 1 year ago

no didn't spot that. -Edit- Oh you mean the decode sync packet I presume? The vlx seemed most flaky, but have had the scd's drop out on the qtpys2's as well as the feather, I think (poor memory). If there's a useful procedure to follow am happy to try anything. I'll come back to it with a clear head tomorrow

tyeth commented 1 year ago

I also wonder if I'm overloading the world, i.e. filling and overflowing the 30second timeperiod between polling, as I have about 8metrics being polled and some fail I guess a bit like #215 taking longer than normal. How do you get that packet logging level of verbosity, just turn up arduino log level? (WS_Debug is defined by default)

brentru commented 1 year ago

I don't have the vlx but just tested the SCD41 resync and it was fine. Will wait on your results but this isn't blocking beta 56.

How do you get that packet logging level of verbosity, just turn up arduino log level? (WS_Debug is defined by default)

Enable debug mode within Adafruit MQTT Library

tyeth commented 1 year ago

It's more interesting that I thought, seems to be too big packet, then some decode error. Not examined in detail, just got logging terminal to disk with auto-reconnect working. Here's the problem moment on startup

image

And here's the log showing from a restart, and there's another forced restart at line 501 to see the repeat. featherS3_capture_2022-12-06_1356 - Copy.txt

brentru commented 1 year ago

It's more interesting that I thought, seems to be too big packet, then some decode error.

Looks like the packet is 58 bytes, the wippersnapper's mqtt rx buffer is ~ 256 bytes.

Could you take a screenshot of the device page on Adafruit IO so I can replicate your setup?

tyeth commented 1 year ago

Looks like the packet is 58 bytes, the wippersnapper's mqtt rx buffer is ~ 256 bytes.

Yeah decode error is 56 bytes, but the buffer length error is after init at the top, still only 201bytes, I wondered if multi-part messages are supported, or if I could have some old device metadata saved. I've not deleted this device yet.

Could you take a screenshot of the device page on Adafruit IO so I can replicate your setup?

All set to 30seconds image

brentru commented 1 year ago

@tyeth in Arduino IDE, go to Tools->Debug Level->Verbose. Does a SSL buffer error happen there?

tyeth commented 1 year ago

Don't see anything related, surprised there's not more debug listed, I put it on Verbose mode. There's another restart around line 450. capture.txt

tyeth commented 1 year ago

So I'm seeing similar on the QTPYs2. I'm unsure if it's switching versions from new to old leaving bad message hanging around, or related to power-cycling, or lack of uart. I stick a copy on, lets say 57, delete all the sensors and then create them again, without fahrenheit, then verify data flows. I create a dashboard for temp/humdity, and set the dashboard (and therefore feeds) to public. I then stick the device on a usb powerbank and no data flows. I stick the device on the laptop and it tells me decode packet error. I also sometimes delete the device entirely before adding sensors again. I stick an older firmware on, but decode error persists, long story short at some point I cock up a device and then it wont survive a power cycle. While on the powerbank it responds to i2c scan, so I have removed and readded sensors and seen data flow, until replugging usb cable.

None of my testing has been methodical so will revisit when have patience.

brentru commented 1 year ago

if it's switching versions from new to old leaving bad message hanging around

Could be a possible reason, but, we didn't change any protocol buffer messages recently. cc @lorennorman ^

What USB powerbank do you have? Were you using it with beta 56?

tyeth commented 1 year ago

powerbank or different mains->usb outlets, just not usb socket with serial listening

lorennorman commented 1 year ago

I can't think of a way that our protobufs could be changing meaningfully, for these scenarios. We always use backwards compatibility if we make breaking changes and we haven't actually made a breaking change like that in awhile.

brentru commented 1 year ago

Will take a full look at this after PicoW support is merged in.

brentru commented 1 year ago

Alright, duplicated the packet issue

11:07:23.882 -> Signal Msg Tag: Pin Configuration
11:07:23.882 -> Initial Pin Configuration Complete!
11:07:23.882 -> * NEW MESSAGE [Topic: Signal-I2C]: 
11:07:23.882 -> 70 bytes.
11:07:23.882 -> ERROR: Unable to decode I2C message
11:07:23.882 -> Publishing to pin config complete...
11:07:24.408 -> Dropped a packet
11:07:24.938 -> Hardware configured successfully!

with the following setup: image

Removing the LC7x sensor from this config does not yield the "Unable to decode I2C message" error, will look more into it. Possible packet size problem.

brentru commented 1 year ago

Looks like the max. packet size got changed back to 150 bytes from 512 in commit https://github.com/brentru/Adafruit_MQTT_Library/commit/28435eaf58d85b3c30e55b965a73447d129c7774#diff-240d52c08217f01fd327187461355707b15e7e24e0e6e3da37f0a67fa12006ceL110

brentru commented 1 year ago

as well as decreasing the size of subscription data len to 100 bytes, https://github.com/brentru/Adafruit_MQTT_Library/commit/28435eaf58d85b3c30e55b965a73447d129c7774#diff-240d52c08217f01fd327187461355707b15e7e24e0e6e3da37f0a67fa12006ceL127

tyeth commented 1 year ago

fascinating, well spotted! Oh and great work on the picow, just about to stick a copy on now 🥇

So just to help me understand/improve, do 'we' file an issue on adafruit mqtt as it may break a lot of projects, or define max size ourselves as it was never part of the librarys 'contract'? Having looked further it seems your work in the first commit got merged out by bens work https://github.com/adafruit/Adafruit_MQTT_Library/pull/218/commits

brentru commented 1 year ago

Ideally, Adafruit MQTT should have a method for requesting an increased buffer size instead of relying on these constants.

For now - I reverted the changes above and re-tested the configuration above with no errors:

11:18:02.639 -> Signal Msg Tag: Pin Configuration
11:18:02.639 -> Initial Pin Configuration Complete!
11:18:02.639 -> Publishing to pin config complete...
11:18:02.639 -> * NEW MESSAGE [Topic: Signal-I2C]: 
11:18:02.639 -> 78 bytes.
11:18:02.639 -> cbDecodeSignalRequestI2C
11:18:02.639 -> I2C Device LIST Init Request Found!
11:18:02.639 -> EXEC: cbDecodeI2CDeviceInitRequestList
11:18:02.639 -> EXEC: New I2C Port 
11:18:02.639 ->     Port #: 0
11:18:02.639 ->     SDA Pin: 42
11:18:02.639 ->     SCL Pin: 41
11:18:02.639 ->     Frequency (Hz): 100000
11:18:02.778 -> Attempting to initialize I2C device: lc709203f
11:18:02.813 -> LC709203F Sensor Initialized Successfully!
11:18:02.813 -> Publishing Message: I2CResponse...Published!
11:18:02.813 -> EXEC: cbDecodeI2CDeviceInitRequestList
11:18:02.813 -> Attempting to initialize I2C device: scd40

This will be fixed when in the next release when the CI pulls the updated Adafruit MQTT fork into the compiled firmware, closing for now. Feel free to re-open if the issue persists in beta 57.