search

Brewskey / spark-server

An API compatible open source server for interacting with devices speaking the spark-protocol
https://www.particle.io/
GNU Affero General Public License v3.0
54 stars 27 forks source link

Problem updating Particle with firmware 0.6.0-Photon with App compiled against 0.6.2 #239

Closed haeferer closed 7 years ago

haeferer commented 7 years ago

Im currently trying to OTA Update a Photon which runs an App with firmware 0.6.0. It seems to be stuck in an Loop

the AppHash 7E3EA28C3510F02BE7EA3D533873D6487F1C0FCB806D71F7E6235BE0B8D208B6 is an App compiled against 0.6.2

The Photon logs into WLAN (green etc) , then flickers purple (Loading Data, during OTA Update ) and ends up in a few seconds solid purple (if the Server says OTA Update finished). -> Starts over

14:10:17.284Z  INFO rabbit.js: Queue Asserted (queueName=EV_spark/device/safemode)
14:10:17.292Z  INFO rabbit.js: Queue Send (queueName=EV_spark/device/safemode)
14:10:17.295Z  INFO rabbit.js: Queue Asserted (queueName=EV_spark/status)
14:10:17.297Z  INFO rabbit.js: Queue Send (queueName=EV_spark/status)
14:10:17.327Z  INFO rabbit.js: Queue Asserted (queueName=EV_spark/device/safemode)
14:10:17.329Z  INFO rabbit.js: Queue Send (queueName=EV_spark/device/safemode)
14:10:17.332Z  INFO rabbit.js: Queue Asserted (queueName=DEVICE_STATE)
14:10:17.334Z  INFO rabbit.js: Queue Send (queueName=DEVICE_STATE)
14:10:18.081Z  INFO Device.js: flash device started! - sending api event (deviceID=1d003b000447333437333039)
14:10:18.090Z  INFO Flasher.js: fast ota enabled! 
    logInfo: {
      "cache_key": "_1",
      "deviceID": "1d003b000447333437333039"
    }
14:10:18.098Z  INFO headlessmanager.js: Event (data=1, deviceID=1d003b000447333437333039, event=spark/safe-mode-updater/updating)
    evx: {
      "data": 1,
      "deviceID": "1d003b000447333437333039",
      "name": "spark/safe-mode-updater/updating",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:10:18.095Z",
      "ttl": 60
    }
14:10:18.098Z  INFO headlessmanager.js: Event (data=started, deviceID=1d003b000447333437333039, event=spark/flash/status)
    evx: {
      "data": "started",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/flash/status",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:10:18.096Z",
      "ttl": 60
    }
14:10:18.301Z  INFO rabbit.js: Queue Asserted (queueName=EV_spark/safe-mode-updater/updating)
14:10:18.304Z  INFO rabbit.js: Queue Send (queueName=EV_spark/safe-mode-updater/updating)
14:10:18.307Z  INFO rabbit.js: Queue Asserted (queueName=EV_spark/flash/status)
14:10:18.309Z  INFO rabbit.js: Queue Send (queueName=EV_spark/flash/status)
14:10:20.151Z  INFO Flasher.js: Starting FastOTA update (deviceID=1d003b000447333437333039)
14:10:23.238Z  INFO Flasher.js: finished waiting
14:10:23.239Z  INFO Device.js: releasing flash ownership  (deviceID=1d003b000447333437333039)
14:10:23.240Z  INFO Device.js: flash device finished! - sending api event (deviceID=1d003b000447333437333039)
14:10:23.241Z  INFO headlessmanager.js: Event (data=success, deviceID=1d003b000447333437333039, event=spark/flash/status)
    evx: {
      "data": "success",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/flash/status",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:10:23.241Z",
      "ttl": 60
    }
14:10:23.369Z  INFO rabbit.js: Queue Send (queueName=EV_spark/flash/status)
14:10:26.085Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
14:10:34.050Z  INFO pmanager.js: HEAP Info
    stats: {
      "num_full_gc": 1,
      "num_inc_gc": 2,
      "heap_compactions": 1,
      "usage_trend": 0,
      "estimated_base": 33210264,
      "current_base": 33210264,
      "min": 0,
      "max": 0
    }
14:10:34.119Z  INFO rabbit.js: Queue Asserted (queueName=LOG_INFO)
14:10:34.120Z  INFO rabbit.js: Queue Send (queueName=LOG_INFO)
14:10:36.085Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
14:10:38.055Z  INFO pmanager.js: HEAP Info
    stats: {
      "num_full_gc": 2,
      "num_inc_gc": 3,
      "heap_compactions": 2,
      "usage_trend": 0,
      "estimated_base": 32894944,
      "current_base": 32894944,
      "min": 0,
      "max": 0
    }
14:10:38.132Z  INFO rabbit.js: Queue Send (queueName=LOG_INFO)
14:10:43.266Z  INFO pmanager.js: HEAP Info
    stats: {
      "num_full_gc": 3,
      "num_inc_gc": 4,
      "heap_compactions": 3,
      "usage_trend": 0,
      "estimated_base": 29890288,
      "current_base": 29890288,
      "min": 29890288,
      "max": 29890288
    }
14:10:43.347Z  INFO rabbit.js: Queue Send (queueName=LOG_INFO)
14:10:46.085Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
14:10:56.085Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
14:10:59.712Z  INFO DeviceServer.js: Connection (connectionID=2, deviceID=1d003b000447333437333039, remoteIPAddress=::ffff:217.92.242.230)
14:10:59.717Z ERROR Device.js: Device disconnected (disconnectCounter=1, message="Device was already connected. Reconnecting.")
    logInfo: {
      "cache_key": "_1",
      "deviceID": "1d003b000447333437333039",
      "duration": 42.851
    }
14:10:59.736Z  WARN DeviceServer.js: Session ended for Device (connectionKey=_1, deviceID=1d003b000447333437333039)
14:10:59.738Z  INFO headlessmanager.js: Event (data=offline, deviceID=1d003b000447333437333039, event=spark/status)
    evx: {
      "data": "offline",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/status",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:10:59.737Z",
      "ttl": 60
    }
14:10:59.899Z  INFO rabbit.js: Queue Send (queueName=EV_spark/status)
14:10:59.900Z  INFO rabbit.js: Queue Send (queueName=DEVICE_STATE)
14:10:59.926Z  INFO Device.js: On device protocol initialization complete (cache_key=_2, deviceID=1d003b000447333437333039, firmwareVersion=65535, ip=::ffff:217.92.242.230, platformID=6, productID=6)
14:10:59.929Z  INFO DeviceServer.js: Subscribe Request (deviceID=1d003b000447333437333039, isFromMyDevices=false, messageName=spark)
14:10:59.933Z  INFO headlessmanager.js: Event (data="", deviceID=1d003b000447333437333039, event=spark/device/safemode)
    evx: {
      "connectionID": "_2",
      "data": "",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/device/safemode",
      "ttl": 60,
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:10:59.929Z"
    }
14:10:59.934Z  INFO headlessmanager.js: Event (data=online, deviceID=1d003b000447333437333039, event=spark/status)
    evx: {
      "data": "online",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/status",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:10:59.932Z",
      "ttl": 60
    }
14:10:59.935Z  INFO headlessmanager.js: Event (data="", deviceID=1d003b000447333437333039, event=spark/device/safemode)
    evx: {
      "data": "",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/device/safemode",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:10:59.932Z",
      "ttl": 60
    }
14:10:59.935Z  INFO headlessmanager.js: Event (data=update_timeout, deviceID=1d003b000447333437333039, event=spark/device/last_reset)
    evx: {
      "data": "update_timeout",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/device/last_reset",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:10:59.932Z",
      "ttl": 60
    }
14:10:59.938Z  INFO headlessmanager.js: Attributes found
    attr: {
      "appHash": "7E3EA28C3510F02BE7EA3D533873D6487F1C0FCB806D71F7E6235BE0B8D208B6",
      "deviceID": "1d003b000447333437333039",
      "functions": [],
      "ip": "::ffff:217.92.242.230",
      "lastHeard": "2017-07-12T14:10:59.928Z",
      "name": "parallel-regret",
      "ownerID": "IucwnZMMuxAd69eQ",
      "particleProductId": 6,
      "platformId": 6,
      "productFirmwareVersion": 65535,
      "reservedFlags": 0,
      "variables": {},
      "firmware": "firmware.bin.0.9.2.aquatast_exta.bin"
    }
14:11:00.102Z  INFO rabbit.js: Queue Send (queueName=EV_spark/device/safemode)
14:11:00.102Z  INFO rabbit.js: Queue Send (queueName=EV_spark/status)
14:11:00.103Z  INFO rabbit.js: Queue Send (queueName=EV_spark/device/safemode)
14:11:00.104Z  INFO rabbit.js: Queue Send (queueName=DEVICE_STATE)
14:11:00.110Z  INFO rabbit.js: Queue Asserted (queueName=EV_spark/device/last_reset)
14:11:00.112Z  INFO rabbit.js: Queue Send (queueName=EV_spark/device/last_reset)
14:11:00.934Z  INFO Device.js: flash device started! - sending api event (deviceID=1d003b000447333437333039)
14:11:00.938Z  INFO Flasher.js: fast ota enabled! 
    logInfo: {
      "cache_key": "_2",
      "deviceID": "1d003b000447333437333039"
    }
14:11:00.944Z  INFO headlessmanager.js: Event (data=1, deviceID=1d003b000447333437333039, event=spark/safe-mode-updater/updating)
    evx: {
      "data": 1,
      "deviceID": "1d003b000447333437333039",
      "name": "spark/safe-mode-updater/updating",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:11:00.943Z",
      "ttl": 60
    }
14:11:00.945Z  INFO headlessmanager.js: Event (data=started, deviceID=1d003b000447333437333039, event=spark/flash/status)
    evx: {
      "data": "started",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/flash/status",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:11:00.944Z",
      "ttl": 60
    }
14:11:01.105Z  INFO rabbit.js: Queue Send (queueName=EV_spark/safe-mode-updater/updating)
14:11:01.106Z  INFO rabbit.js: Queue Send (queueName=EV_spark/flash/status)
14:11:02.964Z  INFO Flasher.js: Starting FastOTA update (deviceID=1d003b000447333437333039)
14:11:06.058Z  INFO Flasher.js: finished waiting
14:11:06.058Z  INFO Device.js: releasing flash ownership  (deviceID=1d003b000447333437333039)
14:11:06.058Z  INFO Device.js: flash device finished! - sending api event (deviceID=1d003b000447333437333039)
14:11:06.059Z  INFO headlessmanager.js: Event (data=success, deviceID=1d003b000447333437333039, event=spark/flash/status)
    evx: {
      "data": "success",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/flash/status",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:11:06.059Z",
      "ttl": 60
    }
14:11:06.086Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
14:11:06.119Z  INFO rabbit.js: Queue Send (queueName=EV_spark/flash/status)
14:11:16.086Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
14:11:26.087Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
14:11:36.088Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
14:11:43.531Z  INFO DeviceServer.js: Connection (connectionID=3, deviceID=1d003b000447333437333039, remoteIPAddress=::ffff:217.92.242.230)
14:11:43.532Z ERROR Device.js: Device disconnected (disconnectCounter=1, message="Device was already connected. Reconnecting.")
    logInfo: {
      "cache_key": "_2",
      "deviceID": "1d003b000447333437333039",
      "duration": 43.803
    }
14:11:43.536Z  WARN DeviceServer.js: Session ended for Device (connectionKey=_2, deviceID=1d003b000447333437333039)
14:11:43.536Z  INFO headlessmanager.js: Event (data=offline, deviceID=1d003b000447333437333039, event=spark/status)
    evx: {
      "data": "offline",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/status",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:11:43.536Z",
      "ttl": 60
    }
14:11:43.652Z  INFO rabbit.js: Queue Send (queueName=EV_spark/status)
14:11:43.652Z  INFO rabbit.js: Queue Send (queueName=DEVICE_STATE)
14:11:43.749Z  INFO Device.js: On device protocol initialization complete (cache_key=_3, deviceID=1d003b000447333437333039, firmwareVersion=65535, ip=::ffff:217.92.242.230, platformID=6, productID=6)
14:11:43.752Z  INFO DeviceServer.js: Subscribe Request (deviceID=1d003b000447333437333039, isFromMyDevices=false, messageName=spark)
14:11:43.755Z  INFO headlessmanager.js: Event (data="", deviceID=1d003b000447333437333039, event=spark/device/safemode)
    evx: {
      "connectionID": "_3",
      "data": "",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/device/safemode",
      "ttl": 60,
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:11:43.751Z"
    }
14:11:43.755Z  INFO headlessmanager.js: Event (data=online, deviceID=1d003b000447333437333039, event=spark/status)
    evx: {
      "data": "online",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/status",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:11:43.753Z",
      "ttl": 60
    }
14:11:43.756Z  INFO headlessmanager.js: Event (data="", deviceID=1d003b000447333437333039, event=spark/device/safemode)
    evx: {
      "data": "",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/device/safemode",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:11:43.753Z",
      "ttl": 60
    }
14:11:43.756Z  INFO headlessmanager.js: Event (data=update_timeout, deviceID=1d003b000447333437333039, event=spark/device/last_reset)
    evx: {
      "data": "update_timeout",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/device/last_reset",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:11:43.753Z",
      "ttl": 60
    }
14:11:43.757Z  INFO headlessmanager.js: Attributes found
    attr: {
      "appHash": "7E3EA28C3510F02BE7EA3D533873D6487F1C0FCB806D71F7E6235BE0B8D208B6",
      "deviceID": "1d003b000447333437333039",
      "functions": [],
      "ip": "::ffff:217.92.242.230",
      "lastHeard": "2017-07-12T14:11:43.750Z",
      "name": "parallel-regret",
      "ownerID": "IucwnZMMuxAd69eQ",
      "particleProductId": 6,
      "platformId": 6,
      "productFirmwareVersion": 65535,
      "reservedFlags": 0,
      "variables": {},
      "firmware": "firmware.bin.0.9.2.aquatast_exta.bin"
    }
14:11:43.852Z  INFO rabbit.js: Queue Send (queueName=EV_spark/device/safemode)
14:11:43.860Z  INFO rabbit.js: Queue Send (queueName=EV_spark/status)
14:11:43.863Z  INFO rabbit.js: Queue Send (queueName=EV_spark/device/safemode)
14:11:43.863Z  INFO rabbit.js: Queue Send (queueName=EV_spark/device/last_reset)
14:11:43.864Z  INFO rabbit.js: Queue Send (queueName=DEVICE_STATE)
14:11:44.756Z  INFO Device.js: flash device started! - sending api event (deviceID=1d003b000447333437333039)
14:11:44.758Z  INFO Flasher.js: fast ota enabled! 
    logInfo: {
      "cache_key": "_3",
      "deviceID": "1d003b000447333437333039"
    }
14:11:44.761Z  INFO headlessmanager.js: Event (data=1, deviceID=1d003b000447333437333039, event=spark/safe-mode-updater/updating)
    evx: {
      "data": 1,
      "deviceID": "1d003b000447333437333039",
      "name": "spark/safe-mode-updater/updating",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:11:44.759Z",
      "ttl": 60
    }
14:11:44.762Z  INFO headlessmanager.js: Event (data=started, deviceID=1d003b000447333437333039, event=spark/flash/status)
    evx: {
      "data": "started",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/flash/status",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:11:44.760Z",
      "ttl": 60
    }
14:11:44.855Z  INFO rabbit.js: Queue Send (queueName=EV_spark/safe-mode-updater/updating)
14:11:44.856Z  INFO rabbit.js: Queue Send (queueName=EV_spark/flash/status)
14:11:46.088Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
14:11:46.784Z  INFO Flasher.js: Starting FastOTA update (deviceID=1d003b000447333437333039)
14:11:49.819Z  INFO Flasher.js: finished waiting
14:11:49.821Z  INFO Device.js: releasing flash ownership  (deviceID=1d003b000447333437333039)
14:11:49.822Z  INFO Device.js: flash device finished! - sending api event (deviceID=1d003b000447333437333039)
14:11:49.823Z  INFO headlessmanager.js: Event (data=success, deviceID=1d003b000447333437333039, event=spark/flash/status)
    evx: {
      "data": "success",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/flash/status",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-12T14:11:49.822Z",
      "ttl": 60
    }
14:11:49.881Z  INFO rabbit.js: Queue Send (queueName=EV_spark/flash/status)
14:11:56.088Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
jlkalberer commented 7 years ago

Ok, I have a fix for this that I'll push out tonight but I need you to verify before this gets closed.

The issue was that our "missed chunk" code wasn't working as we had never really tested it since the beginning of the refactor. For some reason with the 0.6.2 firmware, there is a bad chunk that gets sent. It's the same chunk every time.

I'm not sure if it's the server code that is bad or if there is just a weird edge case with the CRC on one of the chunks. Anyways, this was a good thing to fix anyway as it will greatly improve the reliability of flashing devices. I just hope that we can eventually figure out the root cause.

In order to test this you should just have to update your server and see if the OTA update works.

cc: @AntonPuko

haeferer commented 7 years ago

Great. thx. I will test the version in the next 3 hours (as soon as I arrive at the office)

haeferer commented 7 years ago

for my understanding. At first run , a specific chunk is "wrong" and reconstructed during Retry, but fails because of the bug. So the 0.6.2 update has still a (this) bad Chunk, but retry works.

haeferer commented 7 years ago

Sorry, it does not worked. Now i get exact 10 Warnings (independed from WifiSignal strength) 

07:00:59.656Z  INFO Flasher.js: Starting FastOTA update (deviceID=1d003b000447333437333039)
07:01:02.720Z  INFO Flasher.js: finished waiting
07:01:02.721Z  INFO Device.js: releasing flash ownership  (deviceID=1d003b000447333437333039)
07:01:02.723Z  INFO Device.js: flash device finished! - sending api event (deviceID=1d003b000447333437333039)
07:01:02.725Z  INFO headlessmanager.js: Event (data=success, deviceID=1d003b000447333437333039, event=spark/flash/status)
    evx: {
      "data": "success",
      "deviceID": "1d003b000447333437333039",
      "name": "spark/flash/status",
      "userID": "IucwnZMMuxAd69eQ",
      "isInternal": false,
      "isPublic": false,
      "publishedAt": "2017-07-13T07:01:02.724Z",
      "ttl": 60
    }
07:01:02.808Z  INFO rabbit.js: Queue Send (queueName=EV_spark/flash/status)
07:01:06.380Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
07:01:07.873Z  WARN Flasher.js: flasher - chunk missed - recovering
    logInfo: {
      "cache_key": "_5",
      "deviceID": "1d003b000447333437333039"
    }
07:01:10.786Z  WARN Flasher.js: flasher - chunk missed - recovering
    logInfo: {
      "cache_key": "_5",
      "deviceID": "1d003b000447333437333039"
    }
07:01:13.787Z  WARN Flasher.js: flasher - chunk missed - recovering
    logInfo: {
      "cache_key": "_5",
      "deviceID": "1d003b000447333437333039"
    }
07:01:16.381Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
07:01:16.788Z  WARN Flasher.js: flasher - chunk missed - recovering
    logInfo: {
      "cache_key": "_5",
      "deviceID": "1d003b000447333437333039"
    }
07:01:19.788Z  WARN Flasher.js: flasher - chunk missed - recovering
    logInfo: {
      "cache_key": "_5",
      "deviceID": "1d003b000447333437333039"
    }
07:01:22.795Z  WARN Flasher.js: flasher - chunk missed - recovering
    logInfo: {
      "cache_key": "_5",
      "deviceID": "1d003b000447333437333039"
    }
07:01:25.790Z  WARN Flasher.js: flasher - chunk missed - recovering
    logInfo: {
      "cache_key": "_5",
      "deviceID": "1d003b000447333437333039"
    }
07:01:26.382Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
07:01:28.792Z  WARN Flasher.js: flasher - chunk missed - recovering
    logInfo: {
      "cache_key": "_5",
      "deviceID": "1d003b000447333437333039"
    }
07:01:31.793Z  WARN Flasher.js: flasher - chunk missed - recovering
    logInfo: {
      "cache_key": "_5",
      "deviceID": "1d003b000447333437333039"
    }
07:01:34.794Z  WARN Flasher.js: flasher - chunk missed - recovering
    logInfo: {
      "cache_key": "_5",
      "deviceID": "1d003b000447333437333039"
    }
07:01:36.383Z  INFO DeviceServer.js: Connected Devices (devices=1, sockets=1)
07:01:44.311Z  INFO DeviceServer.js: Connection (connectionID=6, deviceID=1d003b000447333437333039, remoteIPAddress=::ffff:217.92.242.230)
07:01:44.312Z ERROR Device.js: Device disconnected (disconnectCounter=1, message="Device was already connected. Reconnecting.")
haeferer commented 7 years ago

I've found the problems

https://github.com/Brewskey/spark-protocol/pull/130

jlkalberer commented 7 years ago

Ok, the issue was with tokens. There were a couple of bugs that issues

haeferer commented 7 years ago

Great, thx for solving this. I will check on Monday with different other devices and firmware