nRF Mesh App Cannot Interact with Devices after IV Index Update

We are finding an issue where after a network is running for a while we are unable to interact with devices beyond connecting to them via the nRF Mesh App. Specifically, we are trying to deprovision the devices. This is true across multiple devices - iOS and Android running the latest App/Play Store versions. The devices are one nrf5240 and multiple nrf52840 on the network.

The steps to get to where we are right now:

- Setup the network and save the json

- Wait a while (letting devices operate, come back later to change configuration)

- Import the json from that network

- Try to connect to the devices to deprovision

    - Able to see all devices

    - Unable to interact with them

Using the nrf Mesh Sniffer I am able to see that the IV Index of the network has been incremented to 1 in this time. I don't have any logs to prove this is the issue (please let me know what can be collected to help) but I am unsure what the other culprits could be for this issue that seems to be time based only.

I found this issue on Github from the library that seems to be what we are facing: https://github.com/NordicSemiconductor/Android-nRF-Mesh-Library/issues/537

However that issue is resolved and the fix seems to have been rolled out into the apps. So unless there is a regression I am unsure why we are seeing the same issue today on the latest versions.

Any direction on how to confirm this is the issue and resolve this would be appreciated.

Thanks

Parents
  • Hi

    I talked to our nRF Mesh developer today, and they agree with you that you should get the IV index when returning. If you have a Mac OS device, you can use an app called Console (native on Mac), and select the connected iPhone, enable Debug and Info messages in the menu, and set a filter for 'subsystem = com.nordicsemi.nRFProvision' 

    That should give you some useful debug info. If you're not able to get anywhere from that, please upload that here and we can review the debug info on our end.

    Best regards,

    Simon

  • Hi Simon,

    I don't have logs for you yet, are Android logs okay? We currently primarily are developing for android so that will be easier for us.

    I wanted to update that one of our engineers seems to have found a "work around" perhaps. It seems that if we create a new provisioner and operate as that provisioner instead we can interact with the devices and de-provision them. This new provisioner can also be shared between devices. Perhaps the new provisioner will also stop working next IV-Index update. Unfortunately these devices need to be updated so I don't think they will operate that long. But I will try to get an android log before they are taken down.

  • --------- beginning of system
    03-03 15:41:23.191  2069  2069 E ActivityThread: Failed to find provider info for no.nordicsemi.android.log
    03-03 15:41:23.191  2069  2069 D AA      : Connect issued
    03-03 15:41:23.192  2069  2069 D CompatibilityChangeReporter: Compat change id reported: 265103382; UID 10301; state: DISABLED
    03-03 15:41:23.192  2069  2069 D BluetoothGatt: connect() - device: D7:09:8D:CD:56:1F, auto: false
    03-03 15:41:23.192  2069  2069 D BluetoothGatt: registerApp()
    03-03 15:41:23.192  2069  2069 D BluetoothGatt: registerApp() - UUID=9830fa9a-2e27-4afc-9f07-1587379d4d3f
    03-03 15:41:23.193  2069  2083 D BluetoothGatt: onClientRegistered() - status=0 clientIf=13
    03-03 15:41:23.492  2069  2093 D BluetoothGatt: onClientConnectionState() - status=0 clientIf=13 device=D7:09:8D:CD:56:1F
    03-03 15:41:23.493  2069  2069 I BleManager: Connected to D7:09:8D:CD:56:1F
    03-03 15:41:23.711  2069  2069 D VRI[ScannerActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:41:23.730  2069  2069 D BluetoothAdapter: isLeEnabled(): ON
    03-03 15:41:23.799  2069  2069 D BluetoothGatt: discoverServices() - device: D7:09:8D:CD:56:1F
    03-03 15:41:23.805  2069  2083 D BluetoothGatt: onSearchComplete() = Device=D7:09:8D:CD:56:1F Status=0
    03-03 15:41:23.805  2069  2069 I BleManager: Services discovered
    03-03 15:41:23.806  2069  2069 D BluetoothGatt: configureMTU() - device: D7:09:8D:CD:56:1F mtu: 517
    03-03 15:41:23.864  2069  2083 D BluetoothGatt: onConfigureMTU() - Device=D7:09:8D:CD:56:1F mtu=33 status=0
    03-03 15:41:23.864  2069  2069 I BleManager: MTU changed to: 33
    03-03 15:41:23.865  2069  2069 D BluetoothGatt: setCharacteristicNotification() - uuid: 00002ade-0000-1000-8000-00805f9b34fb enable: true
    03-03 15:41:23.963  2069  2069 I BleManager: Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
    03-03 15:41:23.965  2069  2069 I BleManager: Notification received from 00002ade-0000-1000-8000-00805f9b34fb, value: (0x) 01-01-00-CB-E3-53-DA-DE-99-F1-59-00-00-00-00-FA-64-F3-A7-EE-D5-AF-F8
    03-03 15:41:23.968  2069  2069 D MeshManagerApi: Received mesh beacon: SecureNetworkBeacon { KeyRefreshActive: false, IV Index: IV Index: 0, IV Update Active: false, Authentication Value: 0xFA64F3A7EED5AFF8}
    03-03 15:41:23.968  2069  2069 D MeshManagerApi: Secure Network Beacon authenticated.
    03-03 15:41:23.968  2069  2069 D MeshManagerApi: Last IV Index: 0
    03-03 15:41:23.969  2069  2069 I MeshManagerApi: Setting IV Update Active to: false
    03-03 15:41:23.991  2069  2069 D CompatibilityChangeReporter: Compat change id reported: 78294732; UID 10301; state: ENABLED
    03-03 15:41:23.995  2069  2069 D BluetoothAdapter: isLeEnabled(): ON
    03-03 15:41:24.000  2069  2460 D BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=2 mScannerId=0
    03-03 15:41:24.567  2069  2069 D VRI[ReconnectActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:41:24.588  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@4ea89f4
    03-03 15:41:24.591  2069  2069 D BluetoothAdapter: isLeEnabled(): ON
    03-03 15:41:24.594  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@63c78af
    03-03 15:41:24.693  2069  2093 D BluetoothGatt: onPhyUpdate() - status=0 address=D7:09:8D:CD:56:1F txPhy=2 rxPhy=2
    03-03 15:41:24.694  2069  2069 I BleManager: PHY updated (TX: LE 2M, RX: LE 2M)
    03-03 15:41:28.989  2069  2093 D BluetoothGatt: onConnectionUpdated() - Device=D7:09:8D:CD:56:1F interval=39 latency=0 timeout=42 status=0
    03-03 15:41:28.991  2069  2069 I BleManager: Connection parameters updated (interval: 48.75ms, latency: 0, timeout: 420ms)
    03-03 15:41:54.282  2069  2069 D VRI[MainActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:42:08.688  2069  2069 D VRI[MainActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:42:08.697  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22a38400 (RippleDrawable) with handle 0xb400007a229fccb0
    03-03 15:42:31.777  2069  2069 D VRI[NodeConfigurationActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:42:31.788  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22ab35e0 (RippleDrawable) with handle 0xb400007a229fccb0
    03-03 15:42:31.797  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@8791bee
    03-03 15:42:32.868  2069  2069 D VRI[MainActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:42:32.889  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22a3d7b0 (RippleDrawable) with handle 0xb400007a22a03ee0
    03-03 15:42:37.780  2069  2069 V MeshTransport: Src address: 0001
    03-03 15:42:37.781  2069  2069 V MeshTransport: Dst address: 0004
    03-03 15:42:37.781  2069  2069 V MeshTransport: Key: D2AB20799F6B6B6C027ED814EAF228D2
    03-03 15:42:37.781  2069  2069 V MeshTransport: akf: 0
    03-03 15:42:37.781  2069  2069 V MeshTransport: aid: 0
    03-03 15:42:37.781  2069  2069 V MeshTransport: aszmic: 0
    03-03 15:42:37.781  2069  2069 V MeshTransport: Sequence number: 15
    03-03 15:42:37.781  2069  2069 V MeshTransport: Access message opcode: 800c
    03-03 15:42:37.781  2069  2069 V MeshTransport: Access message parameters: 
    03-03 15:42:37.781  2069  2069 V AccessLayer: Created Access PDU 800C
    03-03 15:42:37.781  2069  2069 V UpperTransportLayer: Device nonce: 020000000F0001000400000000
    03-03 15:42:37.782  2069  2069 V UpperTransportLayer: Encrypted upper transport pdu: 899ECEB6D397
    03-03 15:42:37.783  2069  2069 V LowerTransportLayer: Unsegmented Lower transport access PDU 00899ECEB6D397
    03-03 15:42:37.783  2069  2069 V NetworkLayer: Encryption key: 1743DE77E31D4BBEAD88DC8DD44ABCCB
    03-03 15:42:37.783  2069  2069 V NetworkLayer: Privacy key: 995D751B9B3C990AB1E104C935FAD4BB
    03-03 15:42:37.783  2069  2069 V NetworkLayer: Sequence Number: 00000F
    03-03 15:42:37.783  2069  2069 V NetworkLayer: Encrypted Network payload: 61D6194BB6812C556435DCE977
    03-03 15:42:37.792  2069  2069 I BleManager: Data written to 00002add-0000-1000-8000-00805f9b34fb
    03-03 15:42:37.808  2069  2069 V MeshManagerApi: MeshNetwork pdu sent: 0x0048061243BE2D8061D6194BB6812C556435DCE977
    03-03 15:42:47.790  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:42:47.790  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:42:54.623  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@5131e3b
    03-03 15:42:54.626  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22b1cc80 (RippleDrawable) with handle 0xb400007a22a123d0
    03-03 15:42:54.634  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:42:54.634  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:43:05.122  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:43:05.122  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:43:06.044  2069  2069 V MeshTransport: Src address: 0001
    03-03 15:43:06.044  2069  2069 V MeshTransport: Dst address: 0004
    03-03 15:43:06.044  2069  2069 V MeshTransport: Key: D2AB20799F6B6B6C027ED814EAF228D2
    03-03 15:43:06.044  2069  2069 V MeshTransport: akf: 0
    03-03 15:43:06.044  2069  2069 V MeshTransport: aid: 0
    03-03 15:43:06.044  2069  2069 V MeshTransport: aszmic: 0
    03-03 15:43:06.044  2069  2069 V MeshTransport: Sequence number: 16
    03-03 15:43:06.044  2069  2069 V MeshTransport: Access message opcode: 8049
    03-03 15:43:06.044  2069  2069 V MeshTransport: Access message parameters: 
    03-03 15:43:06.044  2069  2069 V AccessLayer: Created Access PDU 8049
    03-03 15:43:06.044  2069  2069 V UpperTransportLayer: Device nonce: 02000000100001000400000000
    03-03 15:43:06.044  2069  2069 V UpperTransportLayer: Encrypted upper transport pdu: AD80C2EF07FD
    03-03 15:43:06.044  2069  2069 V LowerTransportLayer: Unsegmented Lower transport access PDU 00AD80C2EF07FD
    03-03 15:43:06.044  2069  2069 V NetworkLayer: Encryption key: 1743DE77E31D4BBEAD88DC8DD44ABCCB
    03-03 15:43:06.044  2069  2069 V NetworkLayer: Privacy key: 995D751B9B3C990AB1E104C935FAD4BB
    03-03 15:43:06.044  2069  2069 V NetworkLayer: Sequence Number: 000010
    03-03 15:43:06.044  2069  2069 V NetworkLayer: Encrypted Network payload: C4361028FC2EF17E7FABFC7D34
    03-03 15:43:06.050  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@8cb922e
    03-03 15:43:06.053  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22b2f4a0 (RippleDrawable) with handle 0xb400007a22a182e0
    03-03 15:43:06.062  2069  2069 I BleManager: Data written to 00002add-0000-1000-8000-00805f9b34fb
    03-03 15:43:06.063  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:43:06.063  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:43:06.076  2069  2069 V MeshManagerApi: MeshNetwork pdu sent: 0x0048E7CCBE323E8FC4361028FC2EF17E7FABFC7D34
    03-03 15:43:16.055  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:43:16.055  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:43:26.977  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@29b9002
    03-03 15:43:26.980  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22b3c2a0 (RippleDrawable) with handle 0xb400007a22a1a650
    03-03 15:43:26.987  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:43:26.987  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:43:28.528  2069  2069 D VRI[NodeConfigurationActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:43:28.541  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22af82b0 (RippleDrawable) with handle 0xb400007a22a1b670
    03-03 15:43:28.551  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@8f8d6d3
    03-03 15:43:29.821  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:43:29.821  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:43:31.493  2069  2069 D VRI[MainActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:43:31.514  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22a4f960 (RippleDrawable) with handle 0xb400007a22a1d380
    03-03 15:43:32.756  2069  2069 D VRI[ProvisionersActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:43:32.773  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22b59f00 (RippleDrawable) with handle 0xb400007a22a1d380
    03-03 15:43:35.269  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:43:35.269  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:43:35.296  2069  2069 D CompatibilityChangeReporter: Compat change id reported: 303326708; UID 10301; state: DISABLED
    03-03 15:43:35.362  2069  2069 D CompatibilityChangeReporter: Compat change id reported: 163400105; UID 10301; state: ENABLED
    03-03 15:43:35.363  2069  2069 I AssistStructure: Flattened final assist data: 8784 bytes, containing 2 windows, 64 views
    03-03 15:43:36.195  2069  2069 I ImeTracker: no.nordicsemi.android.nrfmeshprovisioner:4afd6da5: onRequestShow at ORIGIN_CLIENT reason SHOW_SOFT_INPUT fromUser true
    03-03 15:43:36.196  2069  2069 D InputMethodManager: showSoftInput() view=com.google.android.material.textfield.TextInputEditText{1e75f55 VFED..CL. .F.P..ID 0,0-748,147 #7f0903ad app:id/text_input aid=1073741828} flags=0 reason=SHOW_SOFT_INPUT
    03-03 15:43:36.255  2069  2069 D InsetsController: show(ime(), fromIme=true)
    03-03 15:43:36.259  2069  4003 W InteractionJankMonitor: Initializing without READ_DEVICE_CONFIG permission. enabled=false, interval=1, missedFrameThreshold=3, frameTimeThreshold=64, package=no.nordicsemi.android.nrfmeshprovisioner
    03-03 15:43:36.479  2069  2069 I ImeTracker: no.nordicsemi.android.nrfmeshprovisioner:4afd6da5: onShown
    03-03 15:43:46.037  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=ImeCallback=ImeOnBackInvokedCallback@2096171 Callback=android.window.IOnBackInvokedCallback$Stub$Proxy@fb3cea4
    03-03 15:43:46.040  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@6b82797
    03-03 15:43:46.044  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22b9f240 (RippleDrawable) with handle 0xb400007a22a2f620
    03-03 15:43:46.059  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:43:46.059  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:43:46.111  2069  2069 D InsetsController: hide(ime(), fromIme=true)
    03-03 15:43:46.111  2069  2069 I ImeTracker: no.nordicsemi.android.nrfmeshprovisioner:5b02d822: onCancelled at PHASE_CLIENT_APPLY_ANIMATION
    03-03 15:43:46.111  2069  2069 W RemoteInputConnectionImpl: requestCursorUpdates on inactive InputConnection
    03-03 15:43:46.130  2069  2069 E ImeBackDispatcher: Ime callback not found. Ignoring unregisterReceivedCallback. callbackId: 2096171
    03-03 15:43:53.180  2069  2069 D VRI[AddProvisionerActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:43:53.188  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22b754c0 (RippleDrawable) with handle 0xb400007a22a29140
    03-03 15:43:53.197  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@4a6b855
    03-03 15:43:56.077  2069  2069 D VRI[ProvisionersActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:43:56.096  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22b59f00 (RippleDrawable) with handle 0xb400007a22a31630
    03-03 15:43:56.708  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:43:56.708  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:43:56.781  2069  2069 I AssistStructure: Flattened final assist data: 8784 bytes, containing 2 windows, 64 views
    03-03 15:43:57.551  2069  2069 I ImeTracker: no.nordicsemi.android.nrfmeshprovisioner:7a83f7a0: onRequestShow at ORIGIN_CLIENT reason SHOW_SOFT_INPUT fromUser true
    03-03 15:43:57.551  2069  2069 D InputMethodManager: showSoftInput() view=com.google.android.material.textfield.TextInputEditText{528633d VFED..CL. .F.P..ID 0,0-748,147 #7f0903ad app:id/text_input aid=1073741828} flags=0 reason=SHOW_SOFT_INPUT
    03-03 15:43:57.606  2069  2069 D InsetsController: show(ime(), fromIme=true)
    03-03 15:43:57.819  2069  2069 I ImeTracker: no.nordicsemi.android.nrfmeshprovisioner:7a83f7a0: onShown
    03-03 15:44:00.563  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=ImeCallback=ImeOnBackInvokedCallback@2096171 Callback=android.window.IOnBackInvokedCallback$Stub$Proxy@c90647e
    03-03 15:44:00.566  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@486a410
    03-03 15:44:00.569  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22be0520 (RippleDrawable) with handle 0xb400007a22a39160
    03-03 15:44:00.585  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:44:00.585  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:44:00.640  2069  2069 D InsetsController: hide(ime(), fromIme=true)
    03-03 15:44:00.640  2069  2069 I ImeTracker: no.nordicsemi.android.nrfmeshprovisioner:5a11a938: onCancelled at PHASE_CLIENT_APPLY_ANIMATION
    03-03 15:44:00.640  2069  2069 W RemoteInputConnectionImpl: requestCursorUpdates on inactive InputConnection
    03-03 15:44:00.643  2069  2069 E ImeBackDispatcher: Ime callback not found. Ignoring unregisterReceivedCallback. callbackId: 2096171
    03-03 15:44:02.546  2069  2069 D VRI[AddProvisionerActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:44:02.556  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22bcc9b0 (RippleDrawable) with handle 0xb400007a22a39970
    03-03 15:44:02.565  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@9b5e665
    03-03 15:44:06.397  2069  2069 D VRI[ProvisionersActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:44:06.412  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22b517d0 (RippleDrawable) with handle 0xb400007a22a31030
    03-03 15:44:06.428  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@fd51768
    03-03 15:44:07.420  2069  2069 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
    03-03 15:44:07.420  2069  2069 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
    03-03 15:44:08.346  2069  2069 D BluetoothAdapter: isLeEnabled(): ON
    03-03 15:44:08.347  2069  2094 D BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=4 mScannerId=0
    03-03 15:44:08.866  2069  2069 D VRI[MainActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:44:08.877  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22a0c650 (RippleDrawable) with handle 0xb400007a22a3f760
    03-03 15:44:10.617  2069  2069 D VRI[ScannerActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:44:10.626  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22bfb470 (RippleDrawable) with handle 0xb400007a22a3ce20
    03-03 15:44:10.634  2069  2069 D BluetoothAdapter: isLeEnabled(): ON
    03-03 15:44:10.644  2069  2069 W WindowOnBackDispatcher: sendCancelIfRunning: isInProgress=falsecallback=android.view.ViewRootImpl$$ExternalSyntheticLambda11@b106681
    03-03 15:44:12.114  2069  2069 D VRI[MainActivity]: visibilityChanged oldVisibility=true newVisibility=false
    03-03 15:44:12.124  2069  2097 D HWUI    : endAllActiveAnimators on 0xb400007b22a3d7b0 (RippleDrawable) with handle 0xb400007a22a41bc0
    03-03 15:44:13.146  2069  2069 V MeshTransport: Src address: 2000
    03-03 15:44:13.146  2069  2069 V MeshTransport: Dst address: 0004
    03-03 15:44:13.146  2069  2069 V MeshTransport: Key: D2AB20799F6B6B6C027ED814EAF228D2
    03-03 15:44:13.146  2069  2069 V MeshTransport: akf: 0
    03-03 15:44:13.146  2069  2069 V MeshTransport: aid: 0
    03-03 15:44:13.146  2069  2069 V MeshTransport: aszmic: 0
    03-03 15:44:13.146  2069  2069 V MeshTransport: Sequence number: 1
    03-03 15:44:13.146  2069  2069 V MeshTransport: Access message opcode: 800c
    03-03 15:44:13.146  2069  2069 V MeshTransport: Access message parameters: 
    03-03 15:44:13.146  2069  2069 V AccessLayer: Created Access PDU 800C
    03-03 15:44:13.146  2069  2069 V UpperTransportLayer: Device nonce: 02000000012000000400000000
    03-03 15:44:13.146  2069  2069 V UpperTransportLayer: Encrypted upper transport pdu: CE67A47B42AA
    03-03 15:44:13.146  2069  2069 V LowerTransportLayer: Unsegmented Lower transport access PDU 00CE67A47B42AA
    03-03 15:44:13.146  2069  2069 V NetworkLayer: Encryption key: 1743DE77E31D4BBEAD88DC8DD44ABCCB
    03-03 15:44:13.146  2069  2069 V NetworkLayer: Privacy key: 995D751B9B3C990AB1E104C935FAD4BB
    03-03 15:44:13.146  2069  2069 V NetworkLayer: Sequence Number: 000001
    03-03 15:44:13.146  2069  2069 V NetworkLayer: Encrypted Network payload: 9149DCC25F796A8E52010B41E4
    03-03 15:44:13.169  2069  2069 I BleManager: Data written to 00002add-0000-1000-8000-00805f9b34fb
    03-03 15:44:13.184  2069  2069 V MeshManagerApi: MeshNetwork pdu sent: 0x0048601A8DF571299149DCC25F796A8E52010B41E4
    03-03 15:44:13.214  2069  2076 W meshprovisioner: Cleared Reference was only reachable from finalizer (only reported once)
    03-03 15:44:13.227  2069  2069 I BleManager: Notification received from 00002ade-0000-1000-8000-00805f9b34fb, value: (0x) 00-48-CA-9F-AF-C2-44-6A-9A-97-4B-56-67-14-8E-85-6D-03-23-98-FA-B3
    03-03 15:44:13.227  2069  2069 V MeshManagerApi: Received network pdu: 0x0048CA9FAFC2446A9A974B5667148E856D032398FAB3
    03-03 15:44:13.228  2069  2069 V BaseMeshMessageHandler: Sequence number of received Network PDU: 42756
    03-03 15:44:13.228  2069  2069 V NetworkLayer: TTL for received message: 7
    03-03 15:44:13.228  2069  2069 V NetworkLayer: Dst: 0x2000
    03-03 15:44:13.228  2069  2069 D LowerTransportLayer: IV Index of received message: 0
    03-03 15:44:13.228  2069  2069 D LowerTransportLayer: SeqAuth: 42756
    03-03 15:44:13.229  2069  2069 V AccessLayer: Received Access PDU 800E07
    

    I've attached a log from the Android app. In this session I did the following:

    1. Tried to get the TTL from the connected device (timed out)

    2. Tried to deprovision the connected device (timed out)

    3. Created a new provisioner and set the phone to use this new provisioner

    4. Again requested the TTL from the connected device which succeeded.

    I was also able to crack open one of our devices today to get logs (they were in sealed enclosures for environmental testing which restricted access). I found that the device was rejecting the messages as a replay attack - it seems the IV index update was a bit of a red herring. Apologies for spending your time on that.

    It seems like perhaps the best practice is that every device should be allocated its own address rather than having all the phone devices share an address? Or is there a good way to share the sequence number?

  • Ah, I see! I didn't catch that you were sharing the sequence number/address of the provisioners. Doing that will effectively be replay attacking yourself. Each provisioner should be allocated its own unicast address. This approach avoids sequence number conflicts and ensures that each provisioner operates independently within the network.

    Glad we have it figured out then. Let me know if we can close this case or if you have any further follow-ups.

  • Hi Simon,

    Thank you I think this is solved and can be closed

Reply Children
No Data
Related