Applying firmware update errors

[coop]

I have recently switched over from nerves_hub - after returning :apply from my client I see the following exception in my logs:

00:47:39.221 [error] [NervesHubLink] Client: Elixir.MyApp.NervesHubLinkClient.update_available/1 bad return value: {:error, :function_clause} Applying update.

00:47:39.237 [error] GenServer NervesHubLink.Channel terminating
** (MatchError) no match of right hand side value: {:error, {{:badmatch, {:error, {:already_started, #PID<0.1875.0>}}}, [{NervesHubLink.HTTPFwupStream, :init, 1, [file: 'lib/nerves_hub_link/http_fwup_stream.ex', line: 72]}, {:gen_server, :init_it, 2, [file: 'gen_server.erl', line: 374]}, {:gen_server, :init_it, 6, [file: 'gen_server.erl', line: 342]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}}
    (nerves_hub_link) lib/nerves_hub_link/channel.ex:148: NervesHubLink.Channel.maybe_update_firmware/2
    (nerves_hub_link) lib/nerves_hub_link/channel.ex:58: NervesHubLink.Channel.handle_info/2
    (stdlib) gen_server.erl:637: :gen_server.try_dispatch/4
    (stdlib) gen_server.erl:711: :gen_server.handle_msg/6
    (stdlib) proc_lib.erl:249: :proc_lib.init_p_do_apply/3
Last message: %PhoenixClient.Message{channel_pid: #PID<0.1646.0>, event: "update", join_ref: nil, payload: %{"deployment_id" => 491, "firmware_url" => "https://s3.amazonaws.com/nerves-hub/firmware/316/xxx.fw?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=xxx&X-Amz-Date=20200216T004739Z&X-Amz-Expires=600&X-Amz-Security-Token=xxx&X-Amz-SignedHeaders=xxx&X-Amz-Signature=xxx"}, ref: nil, topic: "device"}
State: %NervesHubLink.Channel.State{channel: #PID<0.1711.0>, connected?: true, params: %{"nerves_fw_application_part0_devpath" => "/dev/mmcblk0p3", "nerves_fw_application_part0_fstype" => "ext4", "nerves_fw_application_part0_target" => "/root", "nerves_fw_architecture" => "arm", "nerves_fw_author" => "The Nerves Team", "nerves_fw_description" => "", "nerves_fw_misc" => "", "nerves_fw_platform" => "rpi3", "nerves_fw_product" => "claw", "nerves_fw_uuid" => "6097bae1-0553-596a-501a-82417e2432a7", "nerves_fw_vcs_identifier" => "", "nerves_fw_version" => "0.1.6"}, socket: NervesHubLink.Socket, status: {:updating, 38}, topic: "device"}

Here are the interesting deps:

$ mix deps
* fwup 0.4.0 (Hex package) (mix)
  locked at 0.4.0 (fwup) 88cdf2c2
  ok
* nerves 1.5.4 (Hex package) (mix)
  locked at 1.5.4 (nerves) 283ce855
  ok
* phoenix_client 0.10.0 (Hex package) (mix)
  locked at 0.10.0 (phoenix_client) 9374a29a
  ok
* nerves_runtime 0.11.0 (Hex package) (mix)
  locked at 0.11.0 (nerves_runtime) 7adc7f71
  ok
* nerves_hub_user_api 0.6.0 (Hex package) (mix)
  locked at 0.6.0 (nerves_hub_user_api) de682a5f
  ok
* nerves_hub_cli 0.9.1 (Hex package) (mix)
  locked at 0.9.1 (nerves_hub_cli) b956b75b
  ok
* nerves_hub_link 0.7.6 (Hex package) (mix)
  locked at 0.7.6 (nerves_hub_link) 550807ec
  ok

Thanks!

[jjcarstens]

Thanks @coop. Looking over a bit, this is actually an unchanged line from nerves_hub lib. Doesn't mean it shouldn't be fixed, but a bit more information might be helpful.

In theory, we shouldn't have a HTTPFwupStream process still hanging around when he device is told to update (it should either fail in the stream, fail applying the firmware, or download and update successfully), which is what is failing here. In your case, the device seems to have gotten an update message when it was 38% into updating from the last message. Since it didn't realize it was already in the process of updating, it crashed trying to do it again.

That update message from nerves-hub.org could have been triggered by a few different things:

• The deployment was edited/saved in the web UI
• The device was edited/saved in the web UI
• A new deployment was created which would affect this device (either by tag and/or version match)

Did any of these happen while your device was updating? Do you potentially have more log data to be reviewed?

A quick fix would be to adjust your client to only :apply the update when an update isn't already in progress. I think I might implement a simpler version of that in channel.ex, but want to review a bit more to make sure what I think happened, actually happened