search

NordicSemiconductor / Android-DFU-Library

Device Firmware Update library and Android app
http://www.nordicsemi.com/dfu
BSD 3-Clause "New" or "Revised" License
761 stars 269 forks source link

CRC mismatch #128

Open philips77 opened 5 years ago

philips77 commented 5 years ago

Ordinarily I wouldn't bother you, but I've been working full-time for a week to get Android DFU into my app. The new error is a CRC mismatch. In the DfuProgressListener, it's expressed as a 4109 error followed by a 4096 error. I can open up a separate Issue thread for this CRC mismatch if you'd prefer.

Setup

The setup begins with the nRF52 unbonded, unconnected and advertising. The phone does not have any connections saved. Then I perform a BLE scan programmatically in my Android app's Java code. My programmatic BLE scan detects the advertising nRF52 chip. Then I call DfuServiceInitiator.start(...). The Android-DFU-Library updates firmware just fine on the stock Verizon Samsung phone. It fails on the LineageOS Moto X Pure phone.

Samsung Galaxy S5 with Verizon's stock ROM

The Samsung Galaxy S5 running Verizon's version of Samsung's stock ROM (Android 6.0.1) updates firmware just fine.

DfuProgressListener callbacks

onDeviceConnected
onDfuProcessStarting
onEnablingDfuMode
onDeviceConnecting
onDeviceConnected (again)
onDfuProcessStarting (again)
onDfuProcessStarted
onProgressChanged 0-100
onDeviceDisconnecting
onDeviceDisconnected
onDfuCompleted

DfuImpl logs

10-15 00:41:39.402  6569 12562 W DfuImpl : Secure DFU bootloader found
10-15 00:41:39.402  6569  6569 D sr_mobile:MainActivity: DFU onDfuProcessStarting
10-15 00:41:40.422  6569 12562 I DfuImpl : Requesting MTU = 517
10-15 00:41:40.462  6569  6579 I DfuImpl : MTU changed to: 247
10-15 00:41:40.462  6569 12562 I DfuImpl : Enabling notifications...
10-15 00:41:41.492  6569 12562 I DfuImpl : Setting object to Command (Op Code = 6, Type = 1)
10-15 00:41:41.562  6569 12562 I DfuImpl : Command object info received (Max size = 256, Offset = 0, CRC = 00000000)
10-15 00:41:41.562  6569 12562 I DfuImpl : Sending the number of packets before notifications (Op Code = 2, Value = 0)
10-15 00:41:41.582  6569 12562 I DfuImpl : Creating Init packet object (Op Code = 1, Type = 1, Size = 136)
10-15 00:41:41.622  6569 12562 I DfuImpl : Sending 136 bytes of init packet...
10-15 00:41:41.622  6569 12562 I DfuImpl : Sending init packet (Value = 12-85-01-0A-3F-08-01-12-3B-08-FF-01-10-34-1A-02-A8-01-20-00-28-00-30-00-38-B4-A3-04-42-24-08-03-12-20-5A-F4-27-A6-5D-36-4E-D6-23-59-87-72-40-F8-F3-29-8E-86-AF-F9-70-63-58-01-DE-7E-0E-56-2E-8B-46-4E-48-00-10-00-1A-40-07-BD-96-2B-FC-D5-1C-7D-8A-F3-EA-D2-67-D7-5E-92-DE-A0-6D-AB-07-19-79-92-C3-5D-FF-0A-20-66-30-9F-35-C1-FC-1D-6C-9C-59-C5-7C-DC-F6-26-5B-8C-F5-94-7D-E8-CA-3C-72-AD-E7-DB-82-76-BB-BF-6D-9D-35-45)
10-15 00:41:41.622  6569 12562 I DfuImpl : Sending Calculate Checksum command (Op Code = 3)
10-15 00:41:41.662  6569 12562 I DfuImpl : Checksum received (Offset = 136, CRC = 6D55674D)
10-15 00:41:41.662  6569 12562 I DfuImpl : Executing init packet (Op Code = 4)
10-15 00:41:41.822  6569 12562 I DfuImpl : Setting object to Data (Op Code = 6, Type = 2)
10-15 00:41:41.852  6569 12562 I DfuImpl : Data object info received (Max size = 4096, Offset = 0, CRC = 00000000)
10-15 00:41:41.862  6569  6569 D sr_mobile:MainActivity: DFU onDfuProcessStarted
10-15 00:41:41.882  6569 12562 I DfuImpl : Creating Data object (Op Code = 1, Type = 2, Size = 4096) (1/18)
10-15 00:41:42.002  6569 12562 I DfuImpl : Uploading firmware...
10-15 00:41:42.072  6569 12562 I DfuImpl : Sending Calculate Checksum command (Op Code = 3)
10-15 00:41:42.762  6569 12562 I DfuImpl : Checksum received (Offset = 4096, CRC = 0F68E099)
10-15 00:41:42.762  6569 12562 I DfuImpl : Executing data object (Op Code = 4)
10-15 00:41:42.792  6569 12562 I DfuImpl : Creating Data object (Op Code = 1, Type = 2, Size = 4096) (2/18)
10-15 00:41:42.822  6569 12562 I DfuImpl : Uploading firmware...

Moto X running LineageOS

I'm running exactly the same mobile app on the Moto X. I've made sure to grant the runtime location in the phone's settings. I do not get a java.lang.SecurityException. However, when I perform a scan, the DFU fails. My mobile application does not request the Location Permission outside of AndroidManifest.xml, nor does my app check for it.

DfuProgressListener callbacks

onDeviceConnected
onDfuProcessStarting
onEnablingDfuMode
onDeviceConnecting
onDeviceConnected (again)
onDfuProcessStarting (again)
onDeviceDisconnecting <-- where it begins to differ from the Verizon Samsung phone
onDeviceDisconnected
onError 4109
onDeviceDisconnected
onError 4096

DfuImpl logs

10-15 00:33:10.080  9222  9235 I DfuBaseService: Services discovered
10-15 00:33:10.085  9222  9270 I DfuImpl : Buttonless service without bond sharing found -> SDK 13 or newer
10-15 00:33:10.088  9222  9222 D sr_mobile:MainActivity: DFU onDfuProcessStarting
10-15 00:33:11.097  9222  9270 I DfuImpl : Enabling indications...
10-15 00:33:12.187  9222  9222 D sr_mobile:MainActivity: DFU onEnablingDfuMode
10-15 00:33:12.200  9222  9270 I DfuImpl : Sending Enter Bootloader (Op Code = 1)
10-15 00:33:12.274  9222  9270 I DfuImpl : Response received (Op Code = 1, Status = 1)
10-15 00:33:32.344  9222  9234 W DfuBaseService: Target device disconnected with status: 8
10-15 00:33:32.351  9222  9270 I DfuBaseService: Refreshing result: true
10-15 00:33:32.351  9222  9270 I DfuBaseService: Cleaning up...
10-15 00:33:32.362  9222  9222 I DfuBaseService: Action received: android.bluetooth.device.action.ACL_DISCONNECTED
10-15 00:33:32.368  9222  9270 I DfuImpl : Restarting to bootloader mode
10-15 00:33:32.466  9222  9270 I DfuImpl : Scanning for new address finished with: FA:72:66:E5:BA:DB
10-15 00:33:34.508  9222  9270 I DfuBaseService: Connecting to the device...
10-15 00:33:34.656  9222  9235 I DfuBaseService: Connected to GATT server
10-15 00:33:34.657  9222  9222 I DfuBaseService: Action received: android.bluetooth.device.action.ACL_CONNECTED
10-15 00:33:34.661  9222  9235 I DfuBaseService: Attempting to start service discovery... succeed
10-15 00:33:34.662  2794  2794 I TrustAgent.Tracker: [BluetoothConnectionTracker] Bluetooth connect broadast for DfuTarg FA:72:66:E5:BA:DB
10-15 00:33:35.290  9222  9234 I DfuBaseService: Services discovered
10-15 00:33:35.293  9222  9270 W DfuImpl : Secure DFU bootloader found
10-15 00:33:35.294  9222  9222 D sr_mobile:MainActivity: DFU onDfuProcessStarting
10-15 00:33:36.299  9222  9270 I DfuImpl : Requesting MTU = 517
10-15 00:33:36.341  9222  9235 I DfuImpl : MTU changed to: 247
10-15 00:33:36.341  9222  9270 I DfuImpl : Enabling notifications...
10-15 00:33:37.386  9222  9270 I DfuImpl : Setting object to Command (Op Code = 6, Type = 1)
10-15 00:33:37.428  9222  9270 I DfuImpl : Command object info received (Max size = 256, Offset = 0, CRC = 00000000)
10-15 00:33:37.429  9222  9270 I DfuImpl : Sending the number of packets before notifications (Op Code = 2, Value = 0)
10-15 00:33:37.468  9222  9270 I DfuImpl : Creating Init packet object (Op Code = 1, Type = 1, Size = 136)
10-15 00:33:37.499  9222  9270 I DfuImpl : Sending 136 bytes of init packet...
10-15 00:33:37.500  9222  9270 I DfuImpl : Sending init packet (Value = 12-85-01-0A-3F-08-01-12-3B-08-FF-01-10-34-1A-02-A8-01-20-00-28-00-30-00-38-B4-A3-04-42-24-08-03-12-20-5A-F4-27-A6-5D-36-4E-D6-23-59-87-72-40-F8-F3-29-8E-86-AF-F9-70-63-58-01-DE-7E-0E-56-2E-8B-46-4E-48-00-10-00-1A-40-07-BD-96-2B-FC-D5-1C-7D-8A-F3-EA-D2-67-D7-5E-92-DE-A0-6D-AB-07-19-79-92-C3-5D-FF-0A-20-66-30-9F-35-C1-FC-1D-6C-9C-59-C5-7C-DC-F6-26-5B-8C-F5-94-7D-E8-CA-3C-72-AD-E7-DB-82-76-BB-BF-6D-9D-35-45)
10-15 00:33:37.515  9222  9270 I DfuImpl : Sending Calculate Checksum command (Op Code = 3)
10-15 00:33:37.545  9222  9270 I DfuImpl : Checksum received (Offset = 0, CRC = 00000000)
10-15 00:33:37.545  9222  9270 I DfuImpl : CRC does not match! Retrying...(2/3)
10-15 00:33:37.545  9222  9270 I DfuImpl : Creating Init packet object (Op Code = 1, Type = 1, Size = 136)
10-15 00:33:37.600  9222  9270 I DfuImpl : Sending 136 bytes of init packet...
10-15 00:33:37.600  9222  9270 I DfuImpl : Sending init packet (Value = 12-85-01-0A-3F-08-01-12-3B-08-FF-01-10-34-1A-02-A8-01-20-00-28-00-30-00-38-B4-A3-04-42-24-08-03-12-20-5A-F4-27-A6-5D-36-4E-D6-23-59-87-72-40-F8-F3-29-8E-86-AF-F9-70-63-58-01-DE-7E-0E-56-2E-8B-46-4E-48-00-10-00-1A-40-07-BD-96-2B-FC-D5-1C-7D-8A-F3-EA-D2-67-D7-5E-92-DE-A0-6D-AB-07-19-79-92-C3-5D-FF-0A-20-66-30-9F-35-C1-FC-1D-6C-9C-59-C5-7C-DC-F6-26-5B-8C-F5-94-7D-E8-CA-3C-72-AD-E7-DB-82-76-BB-BF-6D-9D-35-45)
10-15 00:33:37.606  9222  9270 I DfuImpl : Sending Calculate Checksum command (Op Code = 3)
10-15 00:33:37.630  9222  9270 I DfuImpl : Checksum received (Offset = 0, CRC = 00000000)
10-15 00:33:37.630  9222  9270 I DfuImpl : CRC does not match! Retrying...(3/3)
10-15 00:33:37.630  9222  9270 I DfuImpl : Creating Init packet object (Op Code = 1, Type = 1, Size = 136)
10-15 00:33:37.659  9222  9270 I DfuImpl : Sending 136 bytes of init packet...
10-15 00:33:37.659  9222  9270 I DfuImpl : Sending init packet (Value = 12-85-01-0A-3F-08-01-12-3B-08-FF-01-10-34-1A-02-A8-01-20-00-28-00-30-00-38-B4-A3-04-42-24-08-03-12-20-5A-F4-27-A6-5D-36-4E-D6-23-59-87-72-40-F8-F3-29-8E-86-AF-F9-70-63-58-01-DE-7E-0E-56-2E-8B-46-4E-48-00-10-00-1A-40-07-BD-96-2B-FC-D5-1C-7D-8A-F3-EA-D2-67-D7-5E-92-DE-A0-6D-AB-07-19-79-92-C3-5D-FF-0A-20-66-30-9F-35-C1-FC-1D-6C-9C-59-C5-7C-DC-F6-26-5B-8C-F5-94-7D-E8-CA-3C-72-AD-E7-DB-82-76-BB-BF-6D-9D-35-45)
10-15 00:33:37.666  9222  9270 I DfuImpl : Sending Calculate Checksum command (Op Code = 3)
10-15 00:33:37.690  9222  9270 I DfuImpl : Checksum received (Offset = 0, CRC = 00000000)
10-15 00:33:37.690  9222  9270 E DfuImpl : CRC does not match!
10-15 00:33:37.701  9222  9270 I DfuBaseService: Disconnecting from the device...
10-15 00:33:37.709  9222  9234 I DfuBaseService: Disconnected from GATT server
10-15 00:33:37.717  9222  9270 I DfuBaseService: Refreshing result: true
10-15 00:33:37.717  9222  9270 I DfuBaseService: Cleaning up...
10-15 00:33:38.331  9222  9270 I DfuImpl : Setting object to Data (Op Code = 6, Type = 2)
10-15 00:33:38.332  9222  9270 E DfuBaseService: Unable to read object info: device disconnected
10-15 00:33:38.332  9222  9270 I DfuBaseService: Cleaning up...
10-15 00:33:38.363  9222  9222 I DfuBaseService: DFU service destroyed
10-15 00:33:38.744  2794  2794 I TrustAgent.Tracker: [BluetoothConnectionTracker] Bluetooth disconnect broadast for DfuTarg FA:72:66:E5:BA:DB

Conclusion

As you can see, the Checksum succeeds on the Verizon Samsung phone but fails on the LineageOS Moto X phone. Do you know why this might be? Both phones are running exactly the same Android mobile app. They are uploading the same zip packet to the same nRF52. I haven't done anything unusual to configure either of their Bluetooth systems.

Originally posted by @josephtoles in https://github.com/NordicSemiconductor/Android-DFU-Library/issues/127#issuecomment-429742633

philips77 commented 5 years ago

I'm only doing one weird thing, at least knowingly. My nRF52 firmware application always erases the device's bond information when it starts up. I don't think the bond-erasing weirdness should be causing my CRC error because I am not bonding anything. Besides, a DFU kicks the nRF52 into bootloader mode, which shouldn't be running my application anyway. It is possible there is an interaction I am overlooking.

philips77 commented 5 years ago

Erasing bonding should not matter.

I see that the Init Packet write fails. The device reports 3 times that it received 0 bytes. It seems that shorter packets were sent correctly, prior to that. You may try disabling MTU request (import the lib as module, not from jcenter, and comment out MTU request), or adding some delays around sending the Init Packet (also requires importing the lib as a module). I don't know why would the target fail to save the data. It may be related to the upload speed, the LineagaOS may handle MTUs incorrectly, etc. I can't tell without a sniffer trace.

philips77 commented 5 years ago

@josephtoles

josephtoles commented 5 years ago

Disabling MTU request does not appear to have any effect. I disabled MTU by importing the library from source and then writing this.mtu = 0 in the method public DfuServiceInitiator setMtu(final int mtu).

josephtoles commented 5 years ago

I don't know where in the DFULibrary project to best put delays. I will update this Issue when I have a sniffer trace.

philips77 commented 5 years ago

Hi, did you manage to solve the issue?

BlueCorso commented 3 years ago

@philips77 any news about this issue? we're having the same problem :(

philips77 commented 3 years ago

Try setting the delay for each object using https://github.com/NordicSemiconductor/Android-DFU-Library/blob/07bdaa50cfc5786790bf1ac589b14931de65d099/dfu/src/main/java/no/nordicsemi/android/dfu/DfuServiceInitiator.java#L213. Value 300ms should work.

BlueCorso commented 3 years ago

@philips77 Thank you very much, I'll try right away!

ytrainis commented 1 year ago

Any news about this issue? We're having the same problem.

philips77 commented 1 year ago

Could you paste your logs, please?