weliem / bluez_inc

A C library for Bluez (BLE) that hides all DBus communication. It doesn't get easier than this. This library can also be used in C++.
MIT License
84 stars 19 forks source link

Cannot re-init GATT server #10

Closed krisnaresi89 closed 1 year ago

krisnaresi89 commented 1 year ago

Hi there,

Thank you for sharing this library. I have create GATT server based on peripheral example, and it works great. I can do write/read/notify using nRF Connect.

Now, one of my requirement is to have power saving feature. In order to do that, I have to close GATT server when receiving power saving signal and re-init GATT server again later on. Here is how I init the GATT server

bool BleHandler::Init()
{
    if(mInit) {
        AP_LOG_DEBUG("BLE handler already initialized");
        return true;
    }

    // Init dbus, mainloop, and adapter
    mDbusConnection = g_bus_get_sync(G_BUS_TYPE_SYSTEM, NULL, NULL);
    mLoop = g_main_loop_new(NULL, FALSE);

    // Get adapter
    for(int i = 0; i < BLE_HANDLER_ADAPTER_RETRY_COUNT; i++) {
        mAdapter = binc_adapter_get_default(mDbusConnection);
        if(mAdapter != NULL) {
            break;
        }
        std::this_thread::sleep_for(std::chrono::milliseconds(BLE_HANDLER_ADAPTER_RETRY_INTERVAL));
    }
    if (mAdapter == NULL) {
        AP_LOG_WARNING("No adapter found");
        return false;
    }
    AP_LOG_DEBUG("Adapter: %s", binc_adapter_get_path(mAdapter));

    // Make sure the adapter is on
    binc_adapter_set_powered_state_cb(mAdapter, &BleHandler::OnPoweredStateChanged);
    if (!binc_adapter_get_powered_state(mAdapter)) {
        binc_adapter_power_on(mAdapter);
    }

    // Setup remote central connection state callback
    binc_adapter_set_remote_central_cb(mAdapter, &BleHandler::OnCentralStateChanged);

    // Create, add and register advertisement, services, characteristic and descriptor, excluded as it way too long

    // Create thread
    mRunning = true;
    mStop = false;
    std::thread t1 (&BleHandler::Process, this);
    t1.detach();

    mInit = true;
    return true;
}

Debug log:

2022-04-28 17:42:50:320 DEBUG [Adapter] finding adapters
2022-04-28 17:42:50:329 DEBUG [Adapter] found 1 adapter
[D][27752] Adapter: /org/bluez/hci0     (ble-handler.cpp line 224)
2022-04-28 17:42:50:330 DEBUG [Application] successfully published application
2022-04-28 17:42:50:330 DEBUG [Application] successfully published local service 12345678-1234-5678-1234-56789abcdef0
2022-04-28 17:42:50:330 DEBUG [Application] successfully published local characteristic 12345678-1234-5678-1234-56789abcdef1
2022-04-28 17:42:50:330 DEBUG [Application] successfully published local characteristic 12345678-1234-5678-1234-56789abcdef2
2022-04-28 17:42:50:330 DEBUG [Application] successfully published local characteristic 12345678-1234-5678-1234-56789abcdef3
2022-04-28 17:42:50:331 DEBUG [Application] successfully published local descriptor 12345678-1234-5678-1234-56789abcdef4
2022-04-28 17:42:50:331 DEBUG [Application] set value <5050505050505050> to <12345678-1234-5678-1234-56789abcdef4>
2022-04-28 17:42:50:390 DEBUG [Application] adding /org/bluez/bincapplication/service0
2022-04-28 17:42:50:390 DEBUG [Application] adding /org/bluez/bincapplication/service0/char0
2022-04-28 17:42:50:390 DEBUG [Application] adding /org/bluez/bincapplication/service0/char2
2022-04-28 17:42:50:391 DEBUG [Application] adding /org/bluez/bincapplication/service0/char1
2022-04-28 17:42:50:391 DEBUG [Application] adding /org/bluez/bincapplication/service0/char1/desc0
2022-04-28 17:42:50:438 DEBUG [Adapter] successfully registered application
2022-04-28 17:42:50:532 DEBUG [Adapter] started advertising (XX:XX:XX:XX:XX:XX)

Init function will create thread for g_main_loop_run to live on:

void BleHandler::Process()
{
    // Start mainloop
    while(mRunning) {
        g_main_loop_run(mLoop);
    }
    mStop = true;
}

The thread will live until mRunning is set false on close command:

bool BleHandler::Close()
{
    if (!mInit) {
        AP_LOG_DEBUG("BLE handler already closed");
        return true;
    }

    // Delete app, advertisement and adapter
    if (mApp != NULL) {
        binc_adapter_unregister_application(mAdapter, mApp);
        binc_application_free(mApp);
        mApp = NULL;
    }
    if (mAdvertisement != NULL) {
        binc_adapter_stop_advertising(mAdapter, mAdvertisement);
        binc_advertisement_free(mAdvertisement);
        mAdvertisement = NULL;
    }
    if (mAdapter != NULL) {
        binc_adapter_free(mAdapter);
        mAdapter = NULL;
    }

    // Kill thread
    mRunning = false;
    g_main_loop_quit(mLoop);
    while(!mStop); // Wait for thread to be stopped

    // Clean up
    g_main_loop_unref(mLoop);
    g_dbus_connection_close_sync(mDbusConnection, NULL, NULL);
    g_object_unref(mDbusConnection);

    mInit = false;
    return true;
}

Debug log:

2022-04-28 17:43:53:486 DEBUG [Application] freeing application /org/bluez/bincapplication
2022-04-28 17:43:53:486 DEBUG [Application] freeing service /org/bluez/bincapplication/service0
2022-04-28 17:43:53:486 DEBUG [Application] freeing characteristic /org/bluez/bincapplication/service0/char0
2022-04-28 17:43:53:486 DEBUG [Application] freeing characteristic /org/bluez/bincapplication/service0/char2
2022-04-28 17:43:53:486 DEBUG [Application] freeing characteristic /org/bluez/bincapplication/service0/char1
2022-04-28 17:43:53:486 DEBUG [Application] freeing descriptor /org/bluez/bincapplication/service0/char1/desc0

Now, after I call close, and re-init again after some times, somehow it cannot find adapter. Here is the debug log when I tried to re-init again:

2022-04-28 17:44:10:846 DEBUG [Adapter] finding adapters
2022-04-28 17:44:10:847 ERROR [Adapter] Unable to get result for GetManagedObjects
2022-04-28 17:44:10:847 DEBUG [Adapter] found 0 adapter

Any idea or some kind of pointer is appreciated. Thank you for your time and assistance.

weliem commented 1 year ago

It looks like the DBus call 'GetManagedObjects' is failing and therefore no adapters are found. No idea why it is failing. Try to put a breakpoint to inspect all parameters...

krisnaresi commented 1 year ago

Thanks for the reply. I have modified binc_adapter_find_all function like this:

    GPtrArray *binc_adapters = g_ptr_array_new();
    GError *error = NULL;
    log_debug(TAG, "finding adapters");

    GVariant *result = g_dbus_connection_call_sync(dbusConnection,
                                                   BLUEZ_DBUS,
                                                   "/",
                                                   INTERFACE_OBJECT_MANAGER,
                                                   "GetManagedObjects",
                                                   NULL,
                                                   G_VARIANT_TYPE("(a{oa{sa{sv}}})"),
                                                   G_DBUS_CALL_FLAGS_NONE,
                                                   -1,
                                                   NULL,
                                                   &error);

    if (error != NULL) {
        log_error(TAG, "Error GetManagedObjects: %s", error->message);
        g_error_free(error);
    }

The debug log is as follow:

2022-04-28 17:43:12:989 DEBUG [Adapter] finding adapters
2022-04-28 17:43:12:992 ERROR [Adapter] Error GetManagedObjects: The connection is closed
2022-04-28 17:43:12:992 ERROR [Adapter] Unable to get result for GetManagedObjects
2022-04-28 17:43:12:992 DEBUG [Adapter] found 0 adapter

So there is something wrong with the DBus connection. I delete g_dbus_connection_close_sync(mDbusConnection, NULL, NULL); line on close function and add g_dbus_connection_set_exit_on_close(mDbusConnection, FALSE); line on init function, now I can see adapter being found, but the result is segmentation fault after set value to descriptor:

2022-04-28 17:43:15:241 DEBUG [Adapter] finding adapters
2022-04-28 17:43:15:248 DEBUG [Adapter] found 1 adapter
[D][52708] Adapter: /org/bluez/hci0     (ble-handler.cpp line 225)
2022-04-28 17:43:15:264 DEBUG [Advertisement] registering advertisement failed: An object is already exported for the interface org.bluez.LEAdvertisement1 at /org/bluez/bincadvertisement
2022-04-28 17:43:15:298 DEBUG [Application] successfully published application
2022-04-28 17:43:15:299 DEBUG [Application] successfully published local service 12345678-1234-5678-1234-56789abcdef0
2022-04-28 17:43:15:299 DEBUG [Application] success[   52.778303] audit: type=1701 audit(1651167795.312:3): auid=4294967295 uid=0 gid=0 ses=4294967295 pid=516 comm="main" exe="/usr/bin/main" sig=11 res=1
fully published local characteristic 12345678-1234-5678-1234-56789abcdef1
2022-04-28 17:43:15:299 DEBUG [Application] successfully published local characteristic 12345678-1234-5678-1234-56789abcdef2
2022-04-28 17:43:15:299 DEBUG [Application] successfully published local characteristic 12345678-1234-5678-1234-56789abcdef3
2022-04-28 17:43:15:300 DEBUG [Application] successfully published local descriptor 12345678-1234-5678-1234-56789abcdef4
2022-04-28 17:43:15:300 DEBUG [Application] set value <5050505050505050> to <12345678-1234-5678-1234-56789abcdef4>
Segmentation fault

Any ideas? Thanks.

weliem commented 1 year ago

What exactly does it crash on?

krisnaresi commented 1 year ago

Just an update. Finally manage to resolve the problem. The problem is because when I call binc_adapter_stop_advertising, my application didn't wait for binc_internal_stop_advertising_cb callback, and already unregister and free everything at that point. Somehow this callback is re-called after re-init and make my application crash. So, I just need to add delay, and now everything works nicely.

To summarize everything:

Just wondering if there is any caveat on first point. Any thoughts are welcome.

weliem commented 1 year ago

Great that you resolved all issues! I need will think about making some calls like start/stop advertising synchronous instead if asynchronous. Or maybe support both.... Most Bluez operations must be asynchronous but maybe there can be some exceptions.

Regarding the first issue of closing the DBus connection, I wonder if closing it at all is necessary in your case. I think it would hardly affect battery consumption...

Anyway, thanks for the summary!

On Fri, 18 Aug 2023, 06:25 krisnaresi, @.***> wrote:

Just an update. Finally manage to resolve the problem. The problem is because when I call binc_adapter_stop_advertising, my application didn't wait for binc_internal_stop_advertising_cb callback, and already unregister and free everything at that point. Somehow this callback is re-called after re-init and make my application crash. So, I just need to add delay, and now everything works nicely.

To summarize everything:

  • Need to remove g_dbus_connection_close_sync on close function and add g_dbus_connection_set_exit_on_close on init function
  • Need to put delay after calling binc_adapter_stop_advertising. On my side, the delay is around 1 second, it could be lessen, but haven't tried it yet.

Just wondering if there is any caveat on first point. Any thoughts are welcome.

— Reply to this email directly, view it on GitHub https://github.com/weliem/bluez_inc/issues/10#issuecomment-1683335420, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACT7HZYCSDMZWARFOMD46MTXV3VDFANCNFSM6AAAAAA3POZD6E . You are receiving this because you commented.Message ID: @.***>

krisnaresi commented 1 year ago

Thanks for the feedback. That's make sense, so I'll proceed with keep DBus connection opened the whole time.

Synchronous would be great in my opinion, as I don't really see the benefit of using asynchronous unless we have a very tight timing when closing. If you can implement both and documented it somewhere, then it would be great. For now, I'll close the issues. Thank you for your assistance.