Upgrade fails if zip file is compressed #36

New Issue

mashuptwice · 2022-11-13T23:21:26Z

mashuptwice commented

2022-11-13 23:21:26 +00:00

I've noticed that the firmware upgrade fails if the .zip file uses compression. Flashing the contents of the .zip seperately as .bin and .dat results in a successful upgrade.

The upgrade also succeeds if the files are repacked with zip -0.

I've noticed that the firmware upgrade fails if the .zip file uses compression. Flashing the contents of the .zip seperately as .bin and .dat results in a successful upgrade. The upgrade also succeeds if the files are repacked with `zip -0`.

Elara6331 commented

2022-11-13 23:23:39 +00:00

This is a thing I and many others have noticed as well. It seems Github zips often fail while zips created by building locally work fine. It is possibly because of the compression, and this is not an ITD-specific problem. People have also reported it with other companions.

Unfortunately, this isn't something I can fix in ITD. If it is a bug, it's in Go's standard library zip implementation.

This is a thing I and many others have noticed as well. It seems Github zips often fail while zips created by building locally work fine. It is possibly because of the compression, and this is not an ITD-specific problem. People have also reported it with other companions. Unfortunately, this isn't something I can fix in ITD. If it is a bug, it's in Go's standard library zip implementation.

Elara6331 commented

2022-11-18 22:58:18 +00:00

Can you try repackaging it with compression but on your machine directly and see if it fails then? I am wondering if it's something specific to Github's zips.

mashuptwice commented

2022-11-19 00:23:50 +00:00

Good point, but I think I've already tested that.

To be sure I've compressed the firmware with zip -9 and it fails to upgrade again.

Good point, but I think I've already tested that. To be sure I've compressed the firmware with `zip -9` and it fails to upgrade again.

mashuptwice commented

2022-11-19 00:35:13 +00:00

Should I open an issue on the library repo instead? If I understand correctly, func (c *Client) FirmwareUpgrade(ctx context.Context, upgType UpgradeType, files ...string) only passes the FW filename to your infinitime library, which does all the processing.

Should I open an issue on the [library repo](https://gitea.arsenm.dev/Arsen6331/infinitime) instead? If I understand correctly, `func (c *Client) FirmwareUpgrade(ctx context.Context, upgType UpgradeType, files ...string)` only passes the FW filename to your infinitime library, which does all the processing.

Elara6331 commented

2022-11-19 00:48:36 +00:00

Yes, you understand correctly. The problem is that actual extraction of the files is handled by Go's archive/zip package, not by any of my code. All I do is read bytes out of Go's file abstraction. There is not much I can do to fix this issue. Do you know what decompression method is being used by these files? Go already has Deflate registered which is what's used 99% of the time.

Yes, you understand correctly. The problem is that actual extraction of the files is handled by Go's [`archive/zip`](https://pkg.go.dev/archive/zip) package, not by any of my code. All I do is read bytes out of Go's file abstraction. There is not much I can do to fix this issue. Do you know what decompression method is being used by these files? Go already has Deflate registered which is what's used 99% of the time.

mashuptwice commented

2022-11-19 00:55:07 +00:00

Well, the manifest contains a CRC16 checksum of the firmware. After having a look over infinitime/dfu.go, it seems (I don't know anything about go) that there is no check if the firmware file has a matching CRC. Erroring out on a CRC mismatch would at least prevent the upgrade from starting then subsequentially failing in the case described.

Of course this is no fix for the behavior, but at least it could provide the user with additional information about the cause of the failure instead of the current error="timed out waiting for response".

Well, the manifest contains a CRC16 checksum of the firmware. After having a look over `infinitime/dfu.go`, it seems (I don't know anything about go) that there is no check if the firmware file has a matching CRC. Erroring out on a CRC mismatch would at least prevent the upgrade from starting then subsequentially failing in the case described. Of course this is no fix for the behavior, but at least it could provide the user with additional information about the cause of the failure instead of the current `error="timed out waiting for response"`.

Elara6331 commented

2022-11-19 01:02:58 +00:00

The CRC goes to the watch as part of the init packet. The watch errors if the CRC doesn't match once it receives the firmware. If I were to check the CRC myself, I'd have to read from the file twice, which would require the ability to seek to the beginning of a file, something the zip package does not implement. If I were to read it and calculate the CRC at the same time, I would only be able to provide an error at the end of the process, which I suppose would be an improvement and I could implement that.

mashuptwice commented

2022-11-19 01:23:26 +00:00

Considering the painfully slow upgrade procedure on my machine and considering that infinitime already does that at the end of the transfer by itself, I don't see the benefit of a CRC check at the end of the transfer.

I don't quite understand why it is necessary to go back to the beginning of the file, fwImgFl, err := zipReader.Open(manifest.Manifest.Application.BinFile) looks like it is reading the firmware file from the zip by the name provided in the manifest file. Could you, for my learning experience, elaborate why it is not possible to call that twice?

Considering the painfully slow upgrade procedure on my machine and considering that infinitime already does that at the end of the transfer by itself, I don't see the benefit of a CRC check at the end of the transfer. I don't quite understand why it is necessary to go back to the beginning of the file, `fwImgFl, err := zipReader.Open(manifest.Manifest.Application.BinFile)` looks like it is reading the firmware file from the zip by the name provided in the manifest file. Could you, for my learning experience, elaborate why it is not possible to call that twice?

Elara6331 commented

2022-11-19 01:40:40 +00:00

Considering the painfully slow upgrade procedure on my machine and considering that infinitime already does that at the end of the transfer by itself, I don't see the benefit of a CRC check at the end of the transfer.

The benefit would be a clearer error message, and a possibility to tell the user to try extracting the files beforehand.

I don't quite understand why it is necessary to go back to the beginning of the file, fwImgFl, err := zipReader.Open(manifest.Manifest.Application.BinFile) looks like it is reading the firmware file from the zip by the name provided in the manifest file.

Opening the file is not reading it. It's simply returning an implementation of the fs.File interface. The file is then read in chunks as part of the upgrade procedure itself. The entire file is never loaded into memory, and it keeps track of the offset as internal state.

Could you, for my learning experience, elaborate why it is not possible to call that twice?

facepalm

That somehow never crossed my mind. I was overthinking it because in a normal OS file, you can seek to the beginning to start reading from the beginning again. That would probably work, I'll implement that, thanks.

> Considering the painfully slow upgrade procedure on my machine and considering that infinitime already does that at the end of the transfer by itself, I don't see the benefit of a CRC check at the end of the transfer. The benefit would be a clearer error message, and a possibility to tell the user to try extracting the files beforehand. > I don't quite understand why it is necessary to go back to the beginning of the file, fwImgFl, err := zipReader.Open(manifest.Manifest.Application.BinFile) looks like it is reading the firmware file from the zip by the name provided in the manifest file. Opening the file is not reading it. It's simply returning an implementation of the `fs.File` interface. The file is then read in chunks as part of the upgrade procedure itself. The entire file is never loaded into memory, and it keeps track of the offset as internal state. > Could you, for my learning experience, elaborate why it is not possible to call that twice? _facepalm_ That somehow never crossed my mind. I was overthinking it because in a normal OS file, you can seek to the beginning to start reading from the beginning again. That would probably work, I'll implement that, thanks.

mashuptwice commented

2022-11-19 04:03:19 +00:00

Thanks for the explanation, I appreciate it!

I'll try to add a routine into your infinitime library which writes the contents of the zip file to a local folder, to identify the exact differences in the bin file extracted. This is just for testing and identifying the root cause, I hope I get my head wrapped around golang quickly.

By the way: I couldn't figure out the SSH connection to your gitea server, is it behind a firewall?

Thanks for the explanation, I appreciate it! I'll try to add a routine into your infinitime library which writes the contents of the zip file to a local folder, to identify the exact differences in the bin file extracted. This is just for testing and identifying the root cause, I hope I get my head wrapped around golang quickly. By the way: I couldn't figure out the SSH connection to your gitea server, is it behind a firewall?

Elara6331 commented

2022-11-19 04:08:43 +00:00

If you want to run ITD with your modified infinitime library, you can add replace go.arsenm.dev/infinitime => /path/to/infinitime into the go.mod file.

If you want to run ITD with your modified `infinitime` library, you can add `replace go.arsenm.dev/infinitime => /path/to/infinitime` into the `go.mod` file.

👍 1

Elara6331 commented

2022-11-19 04:11:20 +00:00

The SSH connection is to the server on my local network. I didn't want to expose it to prevent my server from being open to the internet. You should be able to push over HTTP and I believe git has a way to set the credentials so you don't have to type them every time.

mashuptwice commented

2022-11-19 04:14:17 +00:00

If you want to run ITD with your modified infinitime library, you can add replace go.arsenm.dev/infinitime => /path/to/infinitime into the go.mod file.

Thanks, that'll save me from using sed!

The SSH connection is to the server on my local network. I didn't want to expose it to prevent my server from being open to the internet.

Got it, I'll use the webinterface then.

> If you want to run ITD with your modified infinitime library, you can add replace go.arsenm.dev/infinitime => /path/to/infinitime into the go.mod file. Thanks, that'll save me from using `sed`! > The SSH connection is to the server on my local network. I didn't want to expose it to prevent my server from being open to the internet. Got it, I'll use the webinterface then.

Elara6331 commented

2022-11-23 21:44:23 +00:00

Alright, I tried implementing the CRC check. It seems to work, but the CRCs match even with the compressed zip straight from Github and zips created with zip -9, which raises the question: Why is it failing?

Alright, I tried implementing the CRC check. It seems to work, but the CRCs match even with the compressed zip straight from Github and zips created with `zip -9`, which raises the question: Why is it failing?

Elara6331 commented

2022-11-23 21:47:03 +00:00

Even sha256 hashes match, so it's definitely not an issue with crc16

Elara6331 commented

2022-11-23 21:50:38 +00:00

Yeah, I'm getting 9508 from ITD, and that matches the manifest.

For sha256, I get 31178a8f0113e48d2491c6d3581d8b7f0295ea6c5539a8bd573d197e11e1c32d from ITD, and the same thing from running sha256sum on the extracted file.

Yeah, I'm getting `9508` from ITD, and that matches the manifest. For sha256, I get `31178a8f0113e48d2491c6d3581d8b7f0295ea6c5539a8bd573d197e11e1c32d` from ITD, and the same thing from running `sha256sum` on the extracted file.

mashuptwice commented

2022-11-23 21:50:58 +00:00

Sounds like something funky is going on. That means I also don't need to check for differences in the files manually..

mashuptwice commented

2022-11-23 21:55:40 +00:00

I'll start a session with wireshark, will report back the results.

mashuptwice commented

2022-11-23 23:06:49 +00:00

According to pcap-diff the packages seem to be the same:

╭─mashuptwice@yoga ~/github/pcap-diff ‹master› 
╰─$ ./pcap_diff.py -i ../../pinetime_itd_success.pcapng -i ../../pinetime_itd_failed.pcapng -o ../../pinetime_itd_diff.pcapng                                                                                  1 ↵
/home/mashuptwice/.local/lib/python3.10/site-packages/scapy/layers/ipsec.py:471: CryptographyDeprecationWarning: Blowfish has been deprecated
  cipher=algorithms.Blowfish,
/home/mashuptwice/.local/lib/python3.10/site-packages/scapy/layers/ipsec.py:485: CryptographyDeprecationWarning: CAST5 has been deprecated
  cipher=algorithms.CAST5,
Reading file ../../pinetime_itd_success.pcapng:
Found 20961 packets

Reading file ../../pinetime_itd_failed.pcapng:
Found 20960 packets

Diffing packets: 

Found 0 different packets

╭─mashuptwice@yoga ~/github/pcap-diff ‹master› 
╰─$ ./pcap_diff.py -i ../../pinetime_itd_success.pcapng -i ../../pinetime_itd_failed.pcapng -o ../../pinetime_itd_diff.pcapng -c
/home/mashuptwice/.local/lib/python3.10/site-packages/scapy/layers/ipsec.py:471: CryptographyDeprecationWarning: Blowfish has been deprecated
  cipher=algorithms.Blowfish,
/home/mashuptwice/.local/lib/python3.10/site-packages/scapy/layers/ipsec.py:485: CryptographyDeprecationWarning: CAST5 has been deprecated
  cipher=algorithms.CAST5,
Reading file ../../pinetime_itd_success.pcapng:
Found 20961 packets

Reading file ../../pinetime_itd_failed.pcapng:
Found 20960 packets

Diffing packets: Complete, 

Found 0 different packets

I've filtered for btatt.opcode == 0x52 in wireshark, so I didn't compare all of the packages.

This could still leave the possibility of package missing.

According to pcap-diff the packages seem to be the same: ``` ╭─mashuptwice@yoga ~/github/pcap-diff ‹master› ╰─$ ./pcap_diff.py -i ../../pinetime_itd_success.pcapng -i ../../pinetime_itd_failed.pcapng -o ../../pinetime_itd_diff.pcapng 1 ↵ /home/mashuptwice/.local/lib/python3.10/site-packages/scapy/layers/ipsec.py:471: CryptographyDeprecationWarning: Blowfish has been deprecated cipher=algorithms.Blowfish, /home/mashuptwice/.local/lib/python3.10/site-packages/scapy/layers/ipsec.py:485: CryptographyDeprecationWarning: CAST5 has been deprecated cipher=algorithms.CAST5, Reading file ../../pinetime_itd_success.pcapng: Found 20961 packets Reading file ../../pinetime_itd_failed.pcapng: Found 20960 packets Diffing packets: Found 0 different packets ╭─mashuptwice@yoga ~/github/pcap-diff ‹master› ╰─$ ./pcap_diff.py -i ../../pinetime_itd_success.pcapng -i ../../pinetime_itd_failed.pcapng -o ../../pinetime_itd_diff.pcapng -c /home/mashuptwice/.local/lib/python3.10/site-packages/scapy/layers/ipsec.py:471: CryptographyDeprecationWarning: Blowfish has been deprecated cipher=algorithms.Blowfish, /home/mashuptwice/.local/lib/python3.10/site-packages/scapy/layers/ipsec.py:485: CryptographyDeprecationWarning: CAST5 has been deprecated cipher=algorithms.CAST5, Reading file ../../pinetime_itd_success.pcapng: Found 20961 packets Reading file ../../pinetime_itd_failed.pcapng: Found 20960 packets Diffing packets: Complete, Found 0 different packets ``` I've filtered for `btatt.opcode == 0x52` in wireshark, so I didn't compare all of the packages. This could still leave the possibility of package missing.

Elara6331 commented

2023-02-13 03:43:56 +00:00

The problem is that both archive and filesystem files are handled by the exact same code, so there shouldn't be any discrepancies in the actual bluetooth data as long as the data being read is the same, which it seems to be based on my testing with the hashes. It's an interesting problem that's nearly impossible to track down and has no clear reason behind it.

Sign in to join this conversation.