Reopen Bluetooth connection (CON-1461)

[MaplestoryAlen]

 When the device is in Commissioning, the WIFI password is incorrect. After waiting for the Bluetooth to disconnect, manually open the Commissioning window again and pair it with the Apple Home app. However, it is found that the Bluetooth connection cannot be established
May I ask how to turn on Bluetooth again and connect it, and call it “SetAdvertiseingEnabled (true) ”doesn't seem to be very useful

code：

static void UserActiveCommissioningWindow(void)
{
USER_LOGI(TAG, "user open Commissioning window .......");

constexpr auto k_timeout_seconds = 300;
chip::CommissioningWindowManager & commissionMgr = chip::Server::GetInstance().GetCommissioningWindowManager();
constexpr auto kTimeoutSeconds = chip::System::Clock::Seconds16(k_timeout_seconds);
if (!commissionMgr.IsCommissioningWindowOpen())
{	    
    chip::DeviceLayer::Internal::BLEManager & bleMgr = chip::DeviceLayer::Internal::BLEMgr();
    if(bleMgr.SetAdvertisingEnabled(true) == CHIP_NO_ERROR)
    {
        USER_LOGW(TAG, "Set Advertising Enabled OK!");
    }
   else
   {
	 USER_LOGW(TAG, "Set Advertising fail");
   }
  CHIP_ERROR err = commissionMgr.OpenBasicCommissioningWindow(kTimeoutSeconds,
				   chip::CommissioningWindowAdvertisement::kAllSupported);
	if (err != CHIP_NO_ERROR)
	{
	   USER_LOGE(TAG, "Failed to open commissioning window, err:%" CHIP_ERROR_FORMAT, err.Format());
	}
}
else
{
   USER_LOGW(TAG, "Already open Commissioning window !");		
}

}

static void StartCommissioningWindowWork(intptr_t context)
{
if (chip::Server::GetInstance().GetFabricTable().FabricCount() == 0)
{
UserActiveCommissioningWindow();
}
else
{
auto & failSafeContext = Server::GetInstance().GetFailSafeContext();
if (failSafeContext.IsFailSafeArmed())
{
failSafeContext.ForceFailSafeTimerExpiry();
}
chip::CommissioningWindowManager & commissionMgr = chip::Server::GetInstance().GetCommissioningWindowManager();
commissionMgr.CloseCommissioningWindow();
chip::Server::GetInstance().GetFabricTable().DeleteAllFabrics();
UserActiveCommissioningWindow();
}
}

void OpenCommissioningWindow(void)
{
chip::DeviceLayer::PlatformMgr().ScheduleWork(StartCommissioningWindowWork,reinterpret_cast<intptr_t>(nullptr));

}

log:

(94121) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 1) status= 14
I (94634) wifi:state: run -> init (f00)
I (94635) wifi:new:<6,0>, old:<6,2>, ap:<255,255>, sta:<6,2>, prof:1
I (94637) chip[DL]: WIFI_EVENT_STA_DISCONNECTED
I (94638) chip[DL]: WiFi station state change: Connecting -> Connecting_Failed
W (94649) wifi:Haven't to connect to a suitable AP now!
I (94666) chip[DL]: WiFi station state change: Connecting_Failed -> NotConnected
I (94668) chip[DL]: Done driving station state, nothing else to do...
W (94717) wifi:Haven't to connect to a suitable AP now!
E (94718) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F
W (94767) wifi:Haven't to connect to a suitable AP now!
E (94768) chip[DL]: Failed to get configured network when updating network status: Error ESP32:0x0500300F
I (95172) chip[DL]: Write request/command received for CHIPoBLE TX CCCD characteristic (con 1 ) indicate = 0
I (95174) chip[DL]: CHIPoBLE unsubscribe received
I (95185) chip[DL]: BLE GAP connection terminated (con 1 reason 0x213)
I (95190) chip[BLE]: Releasing end point's BLE connection back to application.
I (95202) chip[DL]: Closing BLE GATT connection (con 1)
E (95218) chip[DL]: ble_gap_terminate() failed: Error CHIP:0x00000048
I (95219) esp_matter_core: BLE Disconnected
I (133467) SENSOR: Temp: 159
I (133468) ACInterface: AC event ntc :159

I (200936) chip[DL]: IP_EVENT_STA_LOST_IP
I (200936) chip[DL]: IPv4 address lost on WiFi station interface
I (200937) app_main: Interface IP Address changed
I (200948) app_main: kIpV4_Lost
I (236023) chip[FS]: Fail-safe timer expired
I (236023) chip[SVR]: Closing pairing window
I (236024) chip[DIS]: Updating services using commissioning mode 0
I (236035) chip[DIS]: CHIP minimal mDNS started advertising.
I (236037) chip[DIS]: Advertise operational node EC47C7650FDF9FF9-0912FBCF0F226000
I (236054) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'; instance name: EC47C7650FDF9FF9-0912FBCF0F226000.
I (236134) chip[DIS]: mDNS service published: _matter._tcp
E (236135) chip[FP]: Reverting pending fabric data for fabric 0x1
E (236154) chip[FP]: Warning: metadata not found during delete of fabric 0x1
I (236158) chip[FP]: Fabric (0x1) deleted.
I (236233) chip[ZCL]: OpCreds: Fabric index 0x1 was removed
I (236234) chip[DIS]: Updating services using commissioning mode 0
I (236254) chip[DIS]: CHIP minimal mDNS started advertising.
I (236269) chip[TS]: Pending Last Known Good Time: 2024-12-09T07:33:12
I (236271) chip[TS]: Previous Last Known Good Time: 2023-10-14T01:16:48
I (236282) chip[TS]: Reverted Last Known Good Time to previous value
I (236283) app_driver: user open Commissioning window .......
W (236294) app_driver: Set Advertising Enabled OK!
I (236295) chip[DIS]: Updating services using commissioning mode 0
I (236306) chip[DIS]: CHIP minimal mDNS started advertising.
E (236308) app_driver: Failed to open commissioning window, err:3
E (236383) chip[ZCL]: OpCreds: Got FailSafeTimerExpired
E (236384) chip[ZCL]: OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry!
I (236404) chip[SC]: SecureSession[0x3fca3678, LSID:44926]: State change 'kActive' --> 'kPendingEviction'
I (236416) chip[TS]: Pending Last Known Good Time: 2023-10-14T01:16:48
I (236418) chip[TS]: Previous Last Known Good Time: 2023-10-14T01:16:48
I (236429) chip[TS]: Reverted Last Known Good Time to previous value
E (236430) chip[FP]: Warning: metadata not found during delete of fabric 0x1
E (236442) chip[ZCL]: OpCreds: failed to delete fabric at index 1: d8
I (236454) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 0 **********
I (236465) app_main: attribute_update_cb type : PRE_UPDATE

I (236466) app_driver: endpoint 0,cluster: 48 write : 0

I (236478) app_main: attribute_update_cb type : POST_UPDATE

I (236479) app_main: Commissioning failed, fail safe timer expired
I (236490) chip[FS]: Fail-safe cleanly disarmed
I (236491) app_main: Commissioning window closed
I (236502) app_main: Fabric will be removed
I (236502) app_main: Fabric removed successfully
I (236505) chip[DIS]: Updating services using commissioning mode 1
I (236516) chip[DIS]: CHIP minimal mDNS started advertising.
I (236517) chip[DIS]: Advertise commission parameter vendorID=5493 productID=8228 discriminator=1101/04 cm=1
I (236529) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 43E22DAC604FBE78.
I (236541) chip[DIS]: mDNS service published: _matterc._udp
I (236553) app_main: Commissioning window closed
I (236553) app_main: Fabric will be removed
I (236554) app_main: Commissioning window opened
I (261556) SENSOR: Humi: 42
I (261572) ACInterface: AC event humidity :42

[pimpalemahesh]

@MaplestoryAlen You can use esp_matter::factory_reset();, if you want to Open Commissioning Window and start ble advertising.

[MaplestoryAlen]

@MaplestoryAlen You can use esp_matter::factory_reset();, if you want to Open Commissioning Window and start ble advertising.

Is there any other method besides using 'esp_matter:: factory_reset();'? Turn on Bluetooth again while the device is running, and connect the Apple "home app"

[shubhamdp]

  CHIP_ERROR err = commissionMgr.OpenBasicCommissioningWindow(kTimeoutSeconds,
				   chip::CommissioningWindowAdvertisement::kAllSupported);

kAllSupported will enable the BLE advertising internally, and not required to manually call bleMgr.SetAdvertisingEnabled(true).

In StartCommissioningWindowWork() why are you deleting the fabrics? It should be handled in the fail safe expiry context.
Also, there will be an event, kFailSafeTimerExpired, that says the prior commissioning attempt was not successful.

Also, after opening the commissioning window, if something fails, the failsafe will be expired and device will start advertising with provided networking technologies. In this case its kAllSupported i.e. m-DNS and BLE.

I think you should wait and ignore the other subsequent calls to open the commissioning window rather than force closing it.

When I try opening the commissioning window (with disabling autostart), commissioning window opens automatically after ble disconnection, but it waits till fail safe expiration. Please check logs, it took around 60 seconds to re-advertise.

Logs

I (91965) chip[DL]: CHIPoBLE unsubscribe received
I (91975) chip[DL]: BLE GAP connection terminated (con 1 reason 0x213)
I (91945) chip[BLE]: Releasing end point's BLE connection back to application.
I (91985) chip[DL]: Closing BLE GATT connection (con 1)
E (91985) chip[DL]: ble_gap_terminate() failed: Error CHIP:0x00000048
I (91995) esp_matter_core: BLE Disconnected
I (149315) chip[FS]: Fail-safe timer expired
E (149315) chip[SVR]: Failsafe timer expired
I (149315) chip[SC]: SecureSession[0x3fc9fd10, LSID:17277]: State change 'kActive' --> 'kPendingEviction'
E (149335) chip[SVR]: Commissioning failed (attempt 2): 32
I (149345) chip[DIS]: Updating services using commissioning mode 1
I (149345) chip[DIS]: CHIP minimal mDNS started advertising.
I (149355) chip[DIS]: Advertise operational node 14DE927F81705C2F-0000000000000001
I (149355) chip[DIS]: CHIP minimal mDNS configured as 'Operational device'; instance name: 14DE927F81705C2F-0000000000000001.
I (149375) chip[DIS]: mDNS service published: _matter._tcp
I (149385) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0
I (149395) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 17BA8047A92B4DCA.
I (149395) chip[DIS]: mDNS service published: _matterc._udp
E (149405) chip[ZCL]: OpCreds: Got FailSafeTimerExpired
E (149405) chip[ZCL]: OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry!
E (149415) chip[FP]: Reverting pending fabric data for fabric 0x1
E (149435) chip[FP]: Warning: metadata not found during delete of fabric 0x1
I (149435) chip[FP]: Fabric (0x1) deleted.
I (149445) chip[ZCL]: OpCreds: Fabric index 0x1 was removed
I (149445) chip[DIS]: Updating services using commissioning mode 1
I (149455) chip[DIS]: CHIP minimal mDNS started advertising.
I (149455) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=3840/15 cm=1 cp=0
I (149475) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 17BA8047A92B4DCA.
I (149485) chip[DIS]: mDNS service published: _matterc._udp
I (149515) chip[TS]: Pending Last Known Good Time: 2023-10-14T01:16:48
I (149515) chip[TS]: Previous Last Known Good Time: 2023-10-14T01:16:48
I (149525) chip[TS]: Reverted Last Known Good Time to previous value
E (149525) chip[FP]: Warning: metadata not found during delete of fabric 0x1
E (149535) chip[ZCL]: OpCreds: failed to delete fabric at index 1: d8
I (149535) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 4 **********
I (149555) esp_matter_attribute: ********** W : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 0 **********
I (149565) app_main: Commissioning failed, fail safe timer expired
I (149575) chip[FS]: Fail-safe cleanly disarmed
I (149575) chip[DL]: Configuring CHIPoBLE advertising (interval 25 ms, connectable)
I (149585) NimBLE: GAP procedure initiated: advertise;
I (149585) NimBLE: disc_mode=2
I (149595) NimBLE:  adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40
I (149615) NimBLE:

After scrubbing through the CommissioningWindowManager.cpp and FailSafeContext.cpp, here's my observations and what could have been wrong with the above code.

• CloseCommissioningWindow performs a fail safe clean up task asynchronously, hence you opening the commissioning window in the safe context won't let that clean up to happen and being stuck in this state.
• I (236553) app_main: Fabric will be removed, there will be kFabricRemoved event once you close the commissioning window and force disarm the fail safe, and if you have the code to open the commissioning window here, that would cause some damage.

Logs confirm the story.

• E (236308) app_driver: Failed to open commissioning window, err:3, is from app_driver so, it was unable to open the commissioning window (why? because cleanup wasn't done, it was supposed to be scheduled after your function returns).
• And the code which opened the commissioning window is from app_main's kFabricRemoved event, which opened the commissioning window with kDnssdOnly. Hence No BLE.

My suggestion would be to perform the async close and open operations. Schedule Close() then Schedule Open(). This would let the fail safe to do any cleanup. Remove open commissioning from that event.

or do not open it its already open, just close it, and let the event open it but with kAllSupported.

I have some test code, I'll drop a patch. NOTE: I used double click rather than scheduling the open/close for testing. I hope the snippet will be helpful reference.

close-open-comm-window.patch

[shubhamdp]

@MaplestoryAlen did the suggested changes in the patch worked?

[MaplestoryAlen]

did the suggested changes in the patch worked?

I have tested it and found that there is a conflict between "chip_stack-lock (portMAX_deLAY)" and "chip_stack_unlock()" in Schedule Work(), which can cause the chip to die. If the user needs to open the pairing again, I use the esp_destart() method because there are too many exceptions during network distribution, such as sudden app disconnection or incorrect WIFI password. Therefore, resetting directly would be more convenient

[shubhamdp]

@MaplestoryAlen You should not use any delays, and no locks are required for tasks scheduled on chip task.

Had some issue opening commissioning window when scheduling both, below code worked out for me, please check.

If timing is an issue, may be StartTimer can be used instead of ScheduleWork to schedule opening the window after few seconds.

open/close window

#include <app/server/CommissioningWindowManager.h>
#include <app/server/Server.h>

static void OpenCommissioningWindowWork(intptr_t arg)
{
    chip::CommissioningWindowManager & commissionMgr = chip::Server::GetInstance().GetCommissioningWindowManager();

    constexpr auto kTimeoutSeconds = chip::System::Clock::Seconds16(300);
    if (commissionMgr.IsCommissioningWindowOpen() == true)
    {
        ESP_LOGI(TAG, "Commissioning window is already open");
    }

    CHIP_ERROR err = commissionMgr.OpenBasicCommissioningWindow(kTimeoutSeconds,
                                    chip::CommissioningWindowAdvertisement::kAllSupported);
    if (err != CHIP_NO_ERROR)
    {
        ESP_LOGE(TAG, "Failed to open commissioning window, err:%" CHIP_ERROR_FORMAT, err.Format());
    }
    else
    {
        ESP_LOGI(TAG, "Commissioning window opened");
    }
}

static void app_driver_button_toggle_cb(void *arg, void *data)
{

    chip::CommissioningWindowManager & commissionMgr = chip::Server::GetInstance().GetCommissioningWindowManager();

    if (commissionMgr.IsCommissioningWindowOpen())
    {
        esp_matter::lock::chip_stack_lock(portMAX_DELAY);
        auto & failSafeContext = chip::Server::GetInstance().GetFailSafeContext();
        failSafeContext.ForceFailSafeTimerExpiry();

        commissionMgr.CloseCommissioningWindow();
        /*chip::Server::GetInstance().GetBleLayerObject()->Shutdown();*/
        esp_matter::lock::chip_stack_unlock();
    }

    chip::DeviceLayer::PlatformMgr().ScheduleWork(OpenCommissioningWindowWork,reinterpret_cast<intptr_t>(nullptr));
}

[MaplestoryAlen]

@MaplestoryAlen You should not use any delays, and no locks are required for tasks scheduled on chip task.

Had some issue opening commissioning window when scheduling both, below code worked out for me, please check.

If timing is an issue, may be StartTimer can be used instead of ScheduleWork to schedule opening the window after few seconds.

open/close window

#include <app/server/CommissioningWindowManager.h>
#include <app/server/Server.h>

static void OpenCommissioningWindowWork(intptr_t arg)
{
    chip::CommissioningWindowManager & commissionMgr = chip::Server::GetInstance().GetCommissioningWindowManager();

    constexpr auto kTimeoutSeconds = chip::System::Clock::Seconds16(300);
    if (commissionMgr.IsCommissioningWindowOpen() == true)
    {
        ESP_LOGI(TAG, "Commissioning window is already open");
    }

    CHIP_ERROR err = commissionMgr.OpenBasicCommissioningWindow(kTimeoutSeconds,
                                    chip::CommissioningWindowAdvertisement::kAllSupported);
    if (err != CHIP_NO_ERROR)
    {
        ESP_LOGE(TAG, "Failed to open commissioning window, err:%" CHIP_ERROR_FORMAT, err.Format());
    }
    else
    {
        ESP_LOGI(TAG, "Commissioning window opened");
    }
}

static void app_driver_button_toggle_cb(void *arg, void *data)
{

    chip::CommissioningWindowManager & commissionMgr = chip::Server::GetInstance().GetCommissioningWindowManager();

    if (commissionMgr.IsCommissioningWindowOpen())
    {
        esp_matter::lock::chip_stack_lock(portMAX_DELAY);
        auto & failSafeContext = chip::Server::GetInstance().GetFailSafeContext();
        failSafeContext.ForceFailSafeTimerExpiry();

        commissionMgr.CloseCommissioningWindow();
        /*chip::Server::GetInstance().GetBleLayerObject()->Shutdown();*/
        esp_matter::lock::chip_stack_unlock();
    }

    chip::DeviceLayer::PlatformMgr().ScheduleWork(OpenCommissioningWindowWork,reinterpret_cast<intptr_t>(nullptr));
}

Thank you very much for your answer. I will close this issue