• State Not Answered
  • Replies 7 replies
  • Subscribers 69 subscribers
  • Views 99 views
  • Users 0 members are here
Attachments (0)
Nordic Case Info
  • Case ID: 338506
Options

Bug in Matter Light_Bulb Example on nRF52840 Development Board

sbehnam3

Dear Nordic Support Team,

I am currently using the nRF52840 development board and working on developing a dimmer switch. During the development process, I encountered a bug. I have tried updating the SDKs to resolve the issue, but even after upgrading to SDK version 2.9, the problem persists.

Here is the issue:
When running the Matter light_bulb example without making any modifications and flashing it to the development board, the dimming and on/off functionality work perfectly when controlled through the Apple HomeKit app. However, the issue occurs in the following scenario:

  1. I turn off the light using the HomeKit app.
  2. Then, I turn it back on using the physical button on the development board.

In this case, the light turns on at 1% brightness, but the HomeKit app incorrectly shows the brightness level as 100%.

This issue has been present since SDK version 2.5 and persists in version 2.9. Despite my efforts, I have not been able to resolve it.

Could you please provide guidance or a solution to address this issue?

Thank you for your support.

Parents
  • 0

    Hi Marte,

    Thank you for your response.

    I’ve been trying to retrieve the application logs from my nRF52840 development board but haven’t been successful so far. I attempted to use Segger RTT Viewer for this purpose, but I couldn’t get it to work.

    Could you please guide me on how to properly retrieve hardware logs from the device? Any specific steps or recommendations would be greatly appreciated.

    Looking forward to your advice.

    Best regards,

Reply
  • 0

    Hi Marte,

    Thank you for your response.

    I’ve been trying to retrieve the application logs from my nRF52840 development board but haven’t been successful so far. I attempted to use Segger RTT Viewer for this purpose, but I couldn’t get it to work.

    Could you please guide me on how to properly retrieve hardware logs from the device? Any specific steps or recommendations would be greatly appreciated.

    Looking forward to your advice.

    Best regards,

Children
  • 0 in reply to sbehnam3

    Hi,

    The Matter samples use UART for logging by default, so you should be able to see the log in a terminal emulator. Some options we provide are the Serial Terminal app in nRF Connect for Desktop or using the terminal in our nRF Connect for VS Code extension. You can also use other programs such as PuTTy, TeraTerm, Picocom, etc.

    Our documentation provides more detailed information about logging here: Testing and optimization.

    Best regards,
    Marte

  • 0 in reply to Marte Myrvold

    The following log corresponds to the scenario outlined below, and it's worth mentioning again that this is the default Matter Light Bulb example without any modifications.

    Scenario:

    1. First, the LED was turned on using Apple HomeKit.
    2. Then, the LED was turned off using Apple HomeKit.
    3. Finally, LED 2 was turned on using Button 2 on the development board.

    Expected behavior:
    The LED 2 should turn on with a dim level of 100%.

    Observed behavior:
    The LED 2 turns on with a dim level of 1%, even though Apple HomeKit displays a dim level of 100%.

    [05:21:00.444,580] <inf> chip: [EM]>>> [E:18241r S:32150 M:152249912] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0001:08 (IM:InvokeCommandRequest)
[05:21:00.475,769] <inf> chip: [ZCL]Endpoint 1 On/off already set to new value
[05:21:00.500,671] <inf> chip: [EM]<<< [E:18241r S:32150 M:217333112 (Ack:152249912)] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0001:09 (IM:InvokeCommandResponse)
[05:21:00.532,714] <inf> chip: [IN](S) Sending msg 217333112 on secure session with LSID: 32150
[05:21:00.592,102] <inf> chip: [EM]>>> [E:18241r S:32150 M:152249913 (Ack:217333112)] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0000:10 (SecureChannel:StandaloneAck)
[05:21:00.627,807] <inf> chip: [EM]>>> [E:18242r S:32150 M:152249914] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0001:08 (IM:InvokeCommandRequest)
[05:21:00.659,118] <inf> chip: [ZCL]RX level-control: MOVE_TO_LEVEL_WITH_ON_OFF fe null 0 0
[05:21:00.684,143] <inf> chip: [ZCL]Setting on/off to ON due to level change
[05:21:00.707,763] <inf> chip: [ZCL]Endpoint 1 On/off already set to new value
[05:21:00.732,879] <inf> chip: [EM]<<< [E:18242r S:32150 M:217333113 (Ack:152249914)] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0001:09 (IM:InvokeCommandResponse)
[05:21:00.764,953] <inf> chip: [IN](S) Sending msg 217333113 on secure session with LSID: 32150
[05:21:00.791,687] <inf> chip: [ZCL]Event: move from 216
[05:21:00.814,575] <inf> chip: [ZCL] to 254 
[05:21:00.837,066] <inf> chip: [ZCL](diff +1)
[05:21:00.858,062] <inf> chip: [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254
[05:21:00.882,965] <inf> app: Level Action has been initiated
[05:21:00.905,151] <inf> app: Setting brightness level to 254
[05:21:00.927,398] <inf> app: Level Action has been completed
[05:21:00.949,676] <inf> chip: [ZCL]Setting on/off to ON due to level change
[05:21:00.973,327] <inf> chip: [ZCL]Endpoint 1 On/off already set to new value
[05:21:01.007,934] <inf> chip: [EM]<<< [E:63069i S:32150 M:217333114] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0001:05 (IM:ReportData)
[05:21:01.037,567] <inf> chip: [IN](S) Sending msg 217333114 on secure session with LSID: 32150
[05:21:01.064,514] <inf> chip: [DMG]Refresh Subscribe Sync Timer with min 0 seconds and max 600 seconds
[05:21:01.093,902] <inf> chip: [EM]>>> [E:18242r S:32150 M:152249915 (Ack:217333113)] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0000:10 (SecureChannel:StandaloneAck)
[05:21:01.129,241] <inf> chip: [EM]>>> [E:63069i S:32150 M:152249916 (Ack:217333114)] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0001:01 (IM:StatusResponse)
[05:21:01.160,980] <inf> chip: [IM]Received status response, status is 0x00
[05:21:01.185,302] <inf> chip: [EM]<<< [E:63069i S:32150 M:217333115 (Ack:152249916)] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0000:10 (SecureChannel:StandaloneAck)
[05:21:01.217,651] <inf> chip: [IN](S) Sending msg 217333115 on secure session with LSID: 32150
[05:21:08.335,021] <inf> chip: [EM]>>> [E:18243r S:32150 M:152249917] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0001:08 (IM:InvokeCommandRequest)
[05:21:08.366,210] <inf> chip: [ZCL]Toggle ep1 on/off from state 1 to 0
[05:21:08.390,686] <inf> chip: [EM]<<< [E:18243r S:32150 M:217333116 (Ack:152249917)] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0001:09 (IM:InvokeCommandResponse)
[05:21:08.422,760] <inf> chip: [IN](S) Sending msg 217333116 on secure session with LSID: 32150
[05:21:08.449,493] <inf> chip: [ZCL]Event: move from 254
[05:21:08.472,503] <inf> chip: [ZCL] to 1 
[05:21:08.494,720] <inf> chip: [ZCL](diff -1)
[05:21:08.515,716] <inf> chip: [ZCL]Cluster LevelControl: attribute CurrentLevel set to 1
[05:21:08.540,466] <inf> app: Level Action has been initiated
[05:21:08.562,652] <inf> app: Setting brightness level to 1
[05:21:08.584,716] <inf> app: Level Action has been completed
[05:21:08.606,994] <inf> chip: [ZCL]Setting on/off to OFF due to level change
[05:21:08.630,767] <inf> chip: [ZCL]Toggle ep1 on/off from state 1 to 0
[05:21:08.673,431] <inf> chip: [ZCL]Cluster OnOff: attribute OnOff set to 0
[05:21:08.697,021] <inf> app: Turn Off Action has been initiated
[05:21:08.719,543] <inf> app: Turn Off Action has been completed
[05:21:08.742,065] <inf> chip: [ZCL]Off completed. reset OnTime to  0
[05:21:08.765,258] <inf> chip: [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254
[05:21:08.801,239] <inf> chip: [EM]<<< [E:63070i S:32150 M:217333117] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0001:05 (IM:ReportData)
[05:21:08.830,871] <inf> chip: [IN](S) Sending msg 217333117 on secure session with LSID: 32150
[05:21:08.857,635] <inf> chip: [DMG]Refresh Subscribe Sync Timer with min 0 seconds and max 600 seconds
[05:21:08.888,732] <inf> chip: [EM]>>> [E:18243r S:32150 M:152249918 (Ack:217333116)] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0000:10 (SecureChannel:StandaloneAck)
[05:21:08.922,302] <inf> chip: [EM]>>> [E:63070i S:32150 M:152249919 (Ack:217333117)] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0001:01 (IM:StatusResponse)
[05:21:08.954,010] <inf> chip: [IM]Received status response, status is 0x00
[05:21:08.978,332] <inf> chip: [EM]<<< [E:63070i S:32150 M:217333118 (Ack:152249919)] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0000:10 (SecureChannel:StandaloneAck)
[05:21:09.010,864] <inf> chip: [IN](S) Sending msg 217333118 on secure session with LSID: 32150
[05:21:11.764,282] <inf> app: Turn On Action has been initiated
[05:21:11.786,834] <inf> app: Turn On Action has been completed
[05:21:11.809,417] <inf> app: Action is already in progress or active.
[05:21:11.849,182] <inf> chip: [ZCL]Cluster OnOff: attribute OnOff set to 1
[05:21:11.873,138] <inf> chip: [ZCL]Cluster LevelControl: attribute CurrentLevel set to 1
[05:21:11.908,599] <inf> chip: [EM]<<< [E:63071i S:32150 M:217333119] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0001:05 (IM:ReportData)
[05:21:11.938,476] <inf> chip: [IN](S) Sending msg 217333119 on secure session with LSID: 32150
[05:21:11.965,393] <inf> chip: [DMG]Refresh Subscribe Sync Timer with min 0 seconds and max 600 seconds
[05:21:11.996,978] <inf> chip: [EM]>>> [E:63071i S:32150 M:152249920 (Ack:217333119)] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0001:01 (IM:StatusResponse)
[05:21:12.028,778] <inf> chip: [IM]Received status response, status is 0x00
[05:21:12.053,100] <inf> chip: [EM]<<< [E:63071i S:32150 M:217333120 (Ack:152249920)] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0000:10 (SecureChannel:StandaloneAck)
[05:21:12.085,418] <inf> chip: [IN](S) Sending msg 217333120 on secure session with LSID: 32150
uart:~$

  • 0 in reply to sbehnam3

    Hi,

    How are you turning the LED off in Apple Homekit? Based on the log, it seems like you are turning it off by dimming it instead of toggling it. This will cause the brightness to be 1 just before it's turned off. Pressing button 2 will cause the LED to toggle to the previous state, which in this case would be turned on with a brighness of 1%.

    Here you can see that the brightness is reduced from 254 to 1, and finally turned off:

    [05:21:08.449,493] <inf> chip: [ZCL]Event: move from 254
[05:21:08.472,503] <inf> chip: [ZCL] to 1 
[05:21:08.494,720] <inf> chip: [ZCL](diff -1)
[05:21:08.515,716] <inf> chip: [ZCL]Cluster LevelControl: attribute CurrentLevel set to 1
[05:21:08.540,466] <inf> app: Level Action has been initiated
[05:21:08.562,652] <inf> app: Setting brightness level to 1
[05:21:08.584,716] <inf> app: Level Action has been completed
[05:21:08.606,994] <inf> chip: [ZCL]Setting on/off to OFF due to level change
[05:21:08.630,767] <inf> chip: [ZCL]Toggle ep1 on/off from state 1 to 0
[05:21:08.673,431] <inf> chip: [ZCL]Cluster OnOff: attribute OnOff set to 0
[05:21:08.697,021] <inf> app: Turn Off Action has been initiated
[05:21:08.719,543] <inf> app: Turn Off Action has been completed

    Here it is turned on after pressing button 2, with CurrentLevel set to 1:

    [05:21:11.764,282] <inf> app: Turn On Action has been initiated
[05:21:11.786,834] <inf> app: Turn On Action has been completed
[05:21:11.809,417] <inf> app: Action is already in progress or active.
[05:21:11.849,182] <inf> chip: [ZCL]Cluster OnOff: attribute OnOff set to 1
[05:21:11.873,138] <inf> chip: [ZCL]Cluster LevelControl: attribute CurrentLevel set to 1

    Best regards,
    Marte

  • 0 in reply to Marte Myrvold

    Hi Marte
    Thanks you for your fast response.

    I will also send you the logs for when I turn off the light via HomeKit toggle and then turn it back on using the physical button on the development board. You'll see that the same issue occurs again.

    That said, regardless of whether this problem persists, your point isn’t entirely accurate. No dimmer product remembers the last dimmed state (e.g., 1%) when turned off through the dimmer. Instead, it recalls the last state before dimming.

    Even assuming your argument is correct, why does the light turn on at 1% while HomeKit displays its status as 100%?

    [01:54:29.106,201] <inf> chip: [EM]>>> [E:18258r S:23797 M:242747526] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0001:08 (IM:InvokeCommandRequest)
[01:54:29.137,420] <inf> chip: [ZCL]Toggle ep1 on/off from state 1 to 0
[01:54:29.161,895] <inf> chip: [EM]<<< [E:18258r S:23797 M:27083915 (Ack:242747526)] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0001:09 (IM:InvokeCommandResponse)
[01:54:29.193,847] <inf> chip: [IN](S) Sending msg 27083915 on secure session with LSID: 23797
[01:54:29.220,947] <inf> chip: [ZCL]Event: move from 254
[01:54:29.245,941] <inf> chip: [ZCL] to 1 
[01:54:29.266,479] <inf> chip: [ZCL](diff -1)
[01:54:29.287,506] <inf> chip: [ZCL]Cluster LevelControl: attribute CurrentLevel set to 1
[01:54:29.312,225] <inf> app: Level Action has been initiated
[01:54:29.334,442] <inf> app: Setting brightness level to 1
[01:54:29.356,506] <inf> app: Level Action has been completed
[01:54:29.378,784] <inf> chip: [ZCL]Setting on/off to OFF due to level change
[01:54:29.402,526] <inf> chip: [ZCL]Toggle ep1 on/off from state 1 to 0
[01:54:29.441,650] <inf> chip: [ZCL]Cluster OnOff: attribute OnOff set to 0
[01:54:29.465,270] <inf> app: Turn Off Action has been initiated
[01:54:29.487,762] <inf> app: Turn Off Action has been completed
[01:54:29.510,467] <inf> chip: [ZCL]Off completed. reset OnTime to  0
[01:54:29.533,660] <inf> chip: [ZCL]Cluster LevelControl: attribute CurrentLevel set to 254
[01:54:29.565,979] <inf> chip: [EM]<<< [E:13241i S:23797 M:27083916] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0001:05 (IM:ReportData)
[01:54:29.595,520] <inf> chip: [IN](S) Sending msg 27083916 on secure session with LSID: 23797
[01:54:29.622,406] <inf> chip: [DMG]Refresh Subscribe Sync Timer with min 0 seconds and max 600 seconds
[01:54:29.653,381] <inf> chip: [EM]>>> [E:18258r S:23797 M:242747527 (Ack:27083915)] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0000:10 (SecureChannel:StandaloneAck)
[01:54:29.686,828] <inf> chip: [EM]>>> [E:13241i S:23797 M:242747528 (Ack:27083916)] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0001:01 (IM:StatusResponse)
[01:54:29.718,475] <inf> chip: [IM]Received status response, status is 0x00
[01:54:29.742,797] <inf> chip: [EM]<<< [E:13241i S:23797 M:27083917 (Ack:242747528)] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0000:10 (SecureChannel:StandaloneAck)
[01:54:29.775,054] <inf> chip: [IN](S) Sending msg 27083917 on secure session with LSID: 23797
[01:54:34.365,081] <inf> app: Turn On Action has been initiated
[01:54:34.387,634] <inf> app: Turn On Action has been completed
[01:54:34.410,217] <inf> app: Action is already in progress or active.
[01:54:34.454,193] <inf> chip: [ZCL]Cluster OnOff: attribute OnOff set to 1
[01:54:34.478,302] <inf> chip: [ZCL]Cluster LevelControl: attribute CurrentLevel set to 1
[01:54:34.510,192] <inf> chip: [EM]<<< [E:13242i S:23797 M:27083918] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0001:05 (IM:ReportData)
[01:54:34.539,978] <inf> chip: [IN](S) Sending msg 27083918 on secure session with LSID: 23797
[01:54:34.567,413] <inf> chip: [DMG]Refresh Subscribe Sync Timer with min 0 seconds and max 600 seconds
[01:54:34.612,030] <inf> chip: [EM]>>> [E:13242i S:23797 M:242747529 (Ack:27083918)] (S) Msg RX from 1:000000007394C4FD [364F] --- Type 0001:01 (IM:StatusResponse)
[01:54:34.643,676] <inf> chip: [IM]Received status response, status is 0x00
[01:54:34.667,999] <inf> chip: [EM]<<< [E:13242i S:23797 M:27083919 (Ack:242747529)] (S) Msg TX to 1:000000007394C4FD [364F] --- Type 0000:10 (SecureChannel:StandaloneAck)
[01:54:34.700,225] <inf> chip: [IN](S) Sending msg 27083919 on secure session with LSID: 23797
uart:~$

  • 0 in reply to sbehnam3

    Hi,

    I have asked the developers about this, and I am waiting for a reply from them. I will get back to you early next week.

    Best regards,
    Marte

Related