Android-DFU-Library
Android-DFU-Library copied to clipboard
NordicSemiconductor
CRC mismatch
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
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.
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.
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).
I don't know where in the DFULibrary project to best put delays. I will update this Issue when I have a sniffer trace.
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.
