Hi I’ve got an issue where a my Fin boards are being put to sleep using the Firmata API, but not always waking up again. We’ve got a photo taking app running in one container, and the Firmata container running separately. We call the Firmata API via a curl from one container to the other.
It responds and says it’s going to wake up again at a certain time e.g. in the logs below “main wakeup eta calculated: 2022-09-21T15:51:31+0000 +58ms”
but it never does.
Any ideas or suggestions what I could look at to fix it? Or is there a watchdog facility or anything similar available?
At the moment we have to physically access the device and turn it off/on again manually to fix.
There was a similar problem mentioned here, but no updates in over a year.
@bucknalla any luck with that?
Example log of a device that had this problem below. is my container that controls a photo taking camera. is the Firmata container.
22.09.22 03:06:08 (+1200) <camera> Outside photo taking window. Using night interval of 2700
22.09.22 03:06:08 (+1200) <camera> Deep sleep for 2700
22.09.22 03:06:08 (+1200) <camera> * Could not resolve host: POST
22.09.22 03:06:08 (+1200) <camera> * Closing connection 0
22.09.22 03:06:08 (+1200) <camera> curl: (6) Could not resolve host: POST
22.09.22 03:06:08 (+1200) <camera> * Trying ::1:1337...
22.09.22 03:06:08 (+1200) <camera> * Connected to localhost (::1) port 1337 (#1)
22.09.22 03:06:08 (+1200) <camera> > POST /sleep HTTP/1.1
22.09.22 03:06:08 (+1200) <camera> > Host: localhost:1337
22.09.22 03:06:08 (+1200) <camera> > User-Agent: curl/7.74.0
22.09.22 03:06:08 (+1200) <camera> > Accept: */*
22.09.22 03:06:08 (+1200) <camera> > Content-Type: application/json
22.09.22 03:06:08 (+1200) <camera> > Content-Length: 37
22.09.22 03:06:08 (+1200) <camera> >
22.09.22 03:06:08 (+1200) <camera> * upload completely sent off: 37 out of 37 bytes
22.09.22 03:06:07 (+1200) <fin> main fin-block version: 3.8.1 +0ms
22.09.22 03:06:07 (+1200) <fin> eeprom readSerial stdout: ��������������������� +0ms
22.09.22 03:06:07 (+1200) <fin> eeprom readSerial stderr: +1ms
22.09.22 03:06:08 (+1200) <fin> eeprom FTDI chip check stdout: Bus 001 Device 004: ID 1e0e:9001 Qualcomm / Option SimTech, Incorporated
22.09.22 03:06:08 (+1200) <fin> eeprom Bus 001 Device 003: ID 0424:ec00 Microchip Technology, Inc. (formerly SMSC) SMSC9512/9514 Fast Ethernet Adapter
22.09.22 03:06:08 (+1200) <fin> eeprom Bus 001 Device 002: ID 0424:9514 Microchip Technology, Inc. (formerly SMSC) SMC9514 Hub
22.09.22 03:06:08 (+1200) <fin> eeprom Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
22.09.22 03:06:08 (+1200) <fin> eeprom +746ms
22.09.22 03:06:08 (+1200) <fin> eeprom FTDI chip check stderr: +1ms
22.09.22 03:06:08 (+1200) <fin> eeprom false +1ms
22.09.22 03:06:08 (+1200) <fin> eeprom EEPROM is not flashed, assuming hw revision 11 based on the absence of the FTDI chip FT2232C (present only on hw rev 09) +7ms
22.09.22 03:06:08 (+1200) <fin> eeprom {
22.09.22 03:06:08 (+1200) <fin> eeprom schema: NaN,
22.09.22 03:06:08 (+1200) <fin> eeprom hardwareRevision: 11,
22.09.22 03:06:08 (+1200) <fin> eeprom batchSerial: NaN,
22.09.22 03:06:08 (+1200) <fin> eeprom week: NaN,
22.09.22 03:06:08 (+1200) <fin> eeprom year: NaN,
22.09.22 03:06:08 (+1200) <fin> eeprom pcbaLot: '���������',
22.09.22 03:06:08 (+1200) <fin> eeprom RAW: '���������������������'
22.09.22 03:06:08 (+1200) <fin> eeprom } +1ms
22.09.22 03:06:08 (+1200) <fin> firmata hardware revision is 11 - connecting firmata over /dev/ttyS0 +0ms
22.09.22 03:06:08 (+1200) <fin> main autoflash is set to 1 +930ms
22.09.22 03:06:08 (+1200) <fin> firmata Calling queryfirmware +19ms
22.09.22 03:06:08 (+1200) <fin> main autoconfig is set to 1 +10ms
22.09.22 03:06:08 (+1200) <fin> main sleep request received, attempting to go into sleep mode with 2ms delay and 2700ms sleep time +549ms
22.09.22 03:06:08 (+1200) <fin> 2022-09-21T15:06:08.813Z - info: [request-promise-retry] calling http://127.0.0.1:48484/v2/state/status?apikey=ee1a25a9a1484b0XXXXXX21bb11d with retry 5
22.09.22 03:06:08 (+1200) <fin> 2022-09-21T15:06:08.818Z - info: [request-promise-retry] calling http://127.0.0.1:48484/v2/state/status?apikey=ee1a25a9a1484b0XXXXXX21bb11d with retry 5, initial delay=5000, factor=3
22.09.22 03:06:08 (+1200) <fin> 2022-09-21T15:06:08.875Z - info: [request-promise-retry] Encountered error Error: connect ECONNREFUSED 127.0.0.1:48484 for GET request to http://127.0.0.1:48484/v2/state/status?apikey=ee1a25a9a1484b0XXXXXX21bb11d, retry count 5
22.09.22 03:06:13 (+1200) <fin> firmata queryfirmware completed +5s
22.09.22 03:06:13 (+1200) <fin> firmata sending sysex command +1ms
22.09.22 03:06:13 (+1200) <fin> firmata got sysex response +13ms
22.09.22 03:06:13 (+1200) <fin> firmata Balena Firmata Version: v2.0.1 +1ms
22.09.22 03:06:13 (+1200) <fin> main running firmata implementation version: v2.0.1 +4s
22.09.22 03:06:13 (+1200) <fin> 2022-09-21T15:06:13.897Z - info: [request-promise-retry] Encountered error Error: connect ECONNREFUSED 127.0.0.1:48484 for GET request to http://127.0.0.1:48484/v2/state/status?apikey=ee1a25a9a1484b01b34bb7da921bb11d, retry count 4
22.09.22 03:06:14 (+1200) <fin> downloader latest firmware version tag found is 2.0.1 +0ms
22.09.22 03:06:14 (+1200) <fin> main firmware 2.0.1 already running. needsReboot is false +1s
22.09.22 03:06:29 (+1200) Killing service 'camera sha256:1379fe3faf52b9771acd52dee4456be871c520c614f04fa9a604462a4cd15df9'
22.09.22 03:06:29 (+1200) <fin> 2022-09-21T15:06:29.063Z - info: [request-promise-retry] Result obtained for GET request to http://127.0.0.1:48484/v2/state/status?apikey=ee1a25a9a1484b01b34bb7da921bb11d
22.09.22 03:06:29 (+1200) <fin> supervisor supervisor returned device status success and app state applied +0ms
22.09.22 03:06:29 (+1200) <fin> main supervisor updating check: false +15s
22.09.22 03:06:29 (+1200) <fin> main wakeup eta calculated: 2022-09-21T15:51:31+0000 +58ms
22.09.22 03:06:29 (+1200) <fin> 2022-09-21T15:06:29.132Z - info: [request-promise-retry] calling http://127.0.0.1:48484/v1/shutdown?apikey=ee1a25a9a1484b0XXXXXX21bb11d&force=0 with retry 5
22.09.22 03:06:29 (+1200) <fin> 2022-09-21T15:06:29.132Z - info: [request-promise-retry] calling http://127.0.0.1:48484/v1/shutdown?apikey= ee1a25a9a1484b0XXXXXX21bb11d&force=0 with retry 5, initial delay=5000, factor=3
22.09.22 03:06:29 (+1200) <camera> * Mark bundle as not supporting multiuse
22.09.22 03:06:29 (+1200) <camera> < HTTP/1.1 200 OK
22.09.22 03:06:29 (+1200) <camera> < X-Powered-By: Express
22.09.22 03:06:29 (+1200) <camera> < Access-Control-Allow-Origin: *
22.09.22 03:06:29 (+1200) <camera> < Access-Control-Allow-Methods: GET,PUT,POST,DELETE
22.09.22 03:06:29 (+1200) <camera> < Access-Control-Allow-Headers: Origin, X-Requested-With, Content-Type, Accept
22.09.22 03:06:29 (+1200) <camera> < Content-Type: text/html; charset=utf-8
22.09.22 03:06:29 (+1200) <camera> < Content-Length: 2
22.09.22 03:06:29 (+1200) <camera> < ETag: W/"2-nOO9QiTIwXgNtWtBJezz8kv3SLc"
22.09.22 03:06:29 (+1200) <camera> < Vary: Accept-Encoding
22.09.22 03:06:29 (+1200) <camera> < Date: Wed, 21 Sep 2022 15:06:29 GMT
22.09.22 03:06:29 (+1200) <camera> < Connection: keep-alive
22.09.22 03:06:29 (+1200) <camera> < Keep-Alive: timeout=5
22.09.22 03:06:29 (+1200) <camera> <
22.09.22 03:06:29 (+1200) <camera> * Connection #1 to host localhost left intact