Device not going to DFU mode on some devices

[vishnu3391_uh]

Hi,

We are currently stuck with a big issue on as we are not able to update the devices(nRF52840) on field. We have changed the clock source to internal in the last released build. But we changed the settings only in the application and released only an application update. Now when we tried to release a new application many users are not able to update to the new version and we found that they are getting DFU error. Upon searching the devzone we found we should've updated the bootloader also with the same clock settings change as in application. More than 10k devices were able to update to the new version. 
Does this says that those devices which were failing has external clock accuracy issue? Why is it failing on certain devices and not on other devices? How to fix this issue? 

Also we changed the softdevice version to v7.3 and same like above we didn't change this in bootloader. What is the proper and best way to update SD and bootloader update in this scenarios. Considering the devices on field has bootloader with external clock and application with internal clock and the SD version 7.2. What is the proper DFU package file making process here to update Bootloader+SD+application?

Thanks,

Vishnu

[Vidar Berg]

Hi Vishnu,

I don't think the different clock source configuration explains the DFU failure.The new clock configuration will not take effect until after the update is complete. Are you able to provide more information about when and where the DFU process is failing? Is the failure happening when attempting to enter DFU mode, or does it happen at some point during the firmware transfer? Also, do you have any data to check if the failure might be specific to certain phone models?

What is the proper and best way to update SD and bootloader update in this scenarios.

You can make a distribution packet that contains the SD+BL and application.

Best regards,

Vidar

[vishnu3391_uh]

Hi Vidar,

No no. The current version on the field is have application with internal clock and bootloader with default settings. Now on top of this build some users are not able to update. Yes we got one device back for troubleshooting and it is failing when attempting to enter DFU mode. It is coming on many phone models. 

Vidar Berg said:

You can make a distribution packet that contains the SD+BL and application.

For this do we need to update the bootloader first to take new SD? If yes what is the change?

Thanks,

Vishnu

[vishnu3391_uh]

Vidar Berg said:

What is failing? Is the DFU enter command returning with an error?

 It is not able to discover the device after sending DFU mode command? Attached the nRF connect logs.

Fullscreen dfu fail.txt Download

nRF Connect, 2024-03-18
UH_D0B3A4A3F17E (D0:B3:A4:A3:F1:7E)
V	15:32:52.247	Connecting to D0:B3:A4:A3:F1:7E...
D	15:32:52.247	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
D	15:32:55.275	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
I	15:32:55.275	Connected to D0:B3:A4:A3:F1:7E
V	15:32:55.278	Discovering services...
D	15:32:55.278	gatt.discoverServices()
I	15:32:55.701	Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
D	15:32:55.829	[Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
D	15:32:56.203	[Callback] Services discovered with status: 0
I	15:32:56.203	Services discovered
V	15:32:56.204	Generic Access (0x1800)
- Device Name [R W] (0x2A00)
- Appearance [R] (0x2A01)
- Peripheral Preferred Connection Parameters [R] (0x2A04)
- Central Address Resolution [R] (0x2AA6)
Generic Attribute (0x1801)
- Service Changed [I] (0x2A05)
   Client Characteristic Configuration (0x2902)
Bond Management (0x181E)
- Bond Management Feature [R] (0x2AA5)
- Bond Management Control Point [W] (0x2AA4)
Secure DFU Service (0xFE59)
- Buttonless DFU [I W] (8ec90003-f315-4f60-9fb8-838830daea50)
   Client Characteristic Configuration (0x2902)
Device Information (0x180A)
- Manufacturer Name String [R] (0x2A29)
- Model Number String [R] (0x2A24)
- Serial Number String [R] (0x2A25)
- Hardware Revision String [R] (0x2A27)
- Firmware Revision String [R] (0x2A26)
Unknown Service (86f61000-f706-58a0-95b2-1fb9261e4dc7)
- Unknown Characteristic [N R] (86f61001-f706-58a0-95b2-1fb9261e4dc7)
   Client Characteristic Configuration (0x2902)
Unknown Service (86f63000-f706-58a0-95b2-1fb9261e4dc7)
- Unknown Characteristic [N R] (86f63001-f706-58a0-95b2-1fb9261e4dc7)
   Client Characteristic Configuration (0x2902)
Unknown Service (86f65000-f706-58a0-95b2-1fb9261e4dc7)
- Unknown Characteristic [W] (86f65001-f706-58a0-95b2-1fb9261e4dc7)
- Unknown Characteristic [N R] (86f65002-f706-58a0-95b2-1fb9261e4dc7)
   Client Characteristic Configuration (0x2902)
Unknown Service (86f66000-f706-58a0-95b2-1fb9261e4dc7)
- Unknown Characteristic [N R] (86f66001-f706-58a0-95b2-1fb9261e4dc7)
   Client Characteristic Configuration (0x2902)
D	15:32:56.204	gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
D	15:32:56.207	gatt.setCharacteristicNotification(86f61001-f706-58a0-95b2-1fb9261e4dc7, true)
D	15:32:56.211	gatt.setCharacteristicNotification(86f63001-f706-58a0-95b2-1fb9261e4dc7, true)
D	15:32:56.214	gatt.setCharacteristicNotification(86f65002-f706-58a0-95b2-1fb9261e4dc7, true)
D	15:32:56.218	gatt.setCharacteristicNotification(86f66001-f706-58a0-95b2-1fb9261e4dc7, true)
I	15:32:56.352	Connection parameters updated (interval: 90.0ms, latency: 2, timeout: 5000ms)
I	15:33:02.387	Connection parameters updated (interval: 90.0ms, latency: 2, timeout: 5000ms)
V	15:33:27.036	[DFU] DFU service started
V	15:33:27.036	[DFU] Opening file...
I	15:33:27.082	[DFU] Firmware file opened successfully
V	15:33:27.082	[DFU] Connecting to DFU target...
D	15:33:27.082	[DFU] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferredPhy = LE_1M | LE_2M)
I	15:33:27.093	[DFU] Connected to D0:B3:A4:A3:F1:7E
V	15:33:27.093	[DFU] Discovering services...
D	15:33:27.093	[DFU] gatt.discoverServices()
I	15:33:27.097	[DFU] Services discovered
W	15:33:27.104	[DFU] Application with buttonless update found
V	15:33:27.104	[DFU] Jumping to the DFU Bootloader...
V	15:33:27.104	[DFU] Enabling indications for 8ec90003-f315-4f60-9fb8-838830daea50
D	15:33:27.104	[DFU] gatt.setCharacteristicNotification(8ec90003-f315-4f60-9fb8-838830daea50, true)
D	15:33:27.104	[DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x02-00)
I	15:33:27.221	[DFU] Data written to descr.8ec90003-f315-4f60-9fb8-838830daea50
V	15:33:27.222	[DFU] Notifications enabled for 8ec90003-f315-4f60-9fb8-838830daea50
A	15:33:27.222	[DFU] Indications enabled
V	15:33:27.222	[DFU] Writing to characteristic 8ec90003-f315-4f60-9fb8-838830daea50, value (0x): 01
D	15:33:27.222	[DFU] gatt.writeCharacteristic(8ec90003-f315-4f60-9fb8-838830daea50, value=0x01, WRITE_TYPE_DEFAULT)
A	15:33:27.402	[DFU] Enter bootloader sent (Op Code = 1)
I	15:33:27.402	[DFU] Notification received from 8ec90003-f315-4f60-9fb8-838830daea50, value (0x): 20-01-01
A	15:33:27.402	[DFU] Response received (Op Code = 1, Status = 1)
V	15:33:27.402	[DFU] Disconnecting...
D	15:33:27.411	[DFU] gatt.disconnect()
I	15:33:27.411	[DFU] Disconnected
D	15:33:27.411	[DFU] gatt.refresh() (hidden)
D	15:33:27.411	[DFU] gatt.disconnect()
D	15:33:27.412	[DFU] gatt.close()
V	15:33:27.413	[DFU] Scanning for the DFU Bootloader... (timeout 5000 ms)
I	15:33:29.205	Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
I	15:33:32.423	[DFU] DFU Bootloader not found. Trying the same address...
V	15:33:32.438	[DFU] DFU service started
I	15:33:32.438	[DFU] Firmware file opened successfully
V	15:33:32.438	[DFU] Connecting to DFU target...
D	15:33:32.466	[DFU] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferredPhy = LE_1M | LE_2M)
I	15:33:32.466	[DFU] Connected to D0:B3:A4:A3:F1:7E
V	15:33:32.466	[DFU] Discovering services...
D	15:33:32.466	[DFU] gatt.discoverServices()
E	15:33:34.706	[DFU] Connection failed (0x08): GATT CONN TIMEOUT
W	15:33:34.706	[DFU] Retrying...
D	15:33:34.706	[DFU] gatt.refresh() (hidden)
D	15:33:34.707	[DFU] gatt.disconnect()
D	15:33:34.711	[Callback] Connection state changed with status: 8 and new state: DISCONNECTED (0)
E	15:33:34.712	Error 8 (0x8): GATT CONN TIMEOUT
I	15:33:34.712	Disconnected
D	15:33:34.712	[DFU] gatt.close()
D	15:33:34.739	[Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
D	15:33:34.739	[DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
V	15:33:34.768	[DFU] DFU service started
I	15:33:34.768	[DFU] Firmware file opened successfully
V	15:33:34.768	[DFU] Connecting to DFU target...
D	15:33:34.768	[DFU] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferredPhy = LE_1M | LE_2M)
E	15:33:44.792	[DFU] Connection failed (0x85): GATT ERROR
W	15:33:44.792	[DFU] Retrying...
D	15:33:44.792	[DFU] gatt.refresh() (hidden)
D	15:33:44.797	[DFU] gatt.disconnect()
D	15:33:44.801	[DFU] gatt.close()
V	15:33:44.809	[DFU] DFU service started
I	15:33:44.810	[DFU] Firmware file opened successfully
V	15:33:44.810	[DFU] Connecting to DFU target...
D	15:33:44.810	[DFU] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferredPhy = LE_1M | LE_2M)
E	15:33:54.838	[DFU] Connection failed (0x85): GATT ERROR
D	15:33:54.838	[DFU] gatt.refresh() (hidden)
D	15:33:54.839	[DFU] gatt.disconnect()
D	15:33:54.841	[DFU] gatt.close()
D	15:33:54.843	[DFU] wait(600)
D	15:33:55.446	gatt.close()
D	15:33:55.457	wait(200)
V	15:33:55.658	Connecting to D0:B3:A4:A3:F1:7E...
D	15:33:55.658	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
D	15:34:05.686	[Callback] Connection state changed with status: 133 and new state: DISCONNECTED (0)
E	15:34:05.686	Error 133 (0x85): GATT ERROR
I	15:34:05.686	Disconnected
D	15:34:13.082	gatt.close()
D	15:34:13.087	wait(200)
V	15:34:13.288	Connecting to D0:B3:A4:A3:F1:7E...
D	15:34:13.288	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
D	15:34:23.314	[Callback] Connection state changed with status: 133 and new state: DISCONNECTED (0)
E	15:34:23.315	Error 133 (0x85): GATT ERROR
I	15:34:23.315	Disconnected

[vishnu3391_uh]

Hi Vidar,

Is this because of the clock settings mismatch between app and bootloader on the existing version? What are the possible reasons for this behavior? This is very critical blocker for us now. Without this we cannot release new build.

Thanks,

Vishnu

[Vidar Berg]

vishnu3391_uh said:

No no. The current version on the field is have application with internal clock and bootloader with default settings.

So, is the firmware application in the field running off the internal RC oscillator, while the bootloader uses the LF crystal? Have you tried to debug the bootloader when it's failing to enter DFU mode.

vishnu3391_uh said:

Is this because of the clock settings mismatch between app and bootloader on the existing version?

It is possible, but it is not clear why only some devices are affected.

[vishnu3391_uh]

Vidar Berg said:

So, is the firmware application in the field running off the internal RC oscillator, while the bootloader uses the LF crystal? Have you tried to debug the bootloader when it's failing to enter DFU mode

Yes. The application is with internal RC and bootloader uses default external crystal settings. The device is fully enclosed and no debug pins available to debug. Anyway to recover this? 

It is trying to connect for few times and then disconnecting. After that it take 15-20 minutes to start advertising again with old application

Thanks,

Vishnu

[Vidar Berg]

Hi Vishnu,

vishnu3391_uh said:

Yes. The application is with internal RC and bootloader uses default external crystal settings. The device is fully enclosed and no debug pins available to debug. Anyway to recover this? 

Thanks for confirming.

vishnu3391_uh said:

It is trying to connect for few times and then disconnecting. After that it take 15-20 minutes to start advertising again with old application

Is this behavior consistent on the failing devices? That is, do they always go "offline" for 15-20 minutes after a failed DFU attempt?

Best regards,

Vidar 

 

[vishnu3391_uh]

Hi Vidar,

Vidar Berg said:

Is this behavior consistent on the failing devices? That is, do they always go "offline" for 15-20 minutes after a failed DFU attempt?

We got only device back here and it was going offline for 15-20 minutes always on DFU attempt. Most devices would be facing the same. 

Thanks,

Vishnu

[Vidar Berg]

Hi Vishnu,

This is interesting, the bootloader should time out and reset after 2 minutes of inactivity and fall back to the old application with the default configuration. The fact that it takes more than 15 minutes to recover suggests that there may be an issue with the clock source. Maybe the BLE transport is waiting for the crystal to start up, or do you have a WD enabled on DFU entry? 

I tried to replicate this scenario on my desk by using the buttonless application with the RC oscillator, and the bootloader with the default configuration, but did not experience any problems with DFU. 

Best regards,

Vidar

[vishnu3391_uh]

Hi Vidar,

Vidar Berg said:

Maybe the BLE transport is waiting for the crystal to start up, or do you have a WD enabled on DFU entry? 

WDT is enabled in the application and and WD settings is same as default settings in bootloader. Unchanged. 

Vidar Berg said:

I tried to replicate this scenario on my desk by using the buttonless application with the RC oscillator, and the bootloader with the default configuration, but did not experience any problems with DFU

Even we are not able to replicating the issue on PCB here. But atleast 200-500 users faced this issue on field and we had to pull back the release. 

Thanks,

Vishnu

[Vidar Berg]

Hi Vishnu,

I would have expected the WDT to trigger a reset and caused the bootloader to exit DFU mode and revert to the old application. Is it impossible to open the enclosure and access the SWD lines?

Best regards,

Vidar

[vishnu3391_uh]

That is possible. What should we check?