Logging features for 1.1.x

[wes-b]

Proposal

For logging in Azure Kinect we are planning to add an interface that will allow log messages from the SDK to be forward to the users executable. This will allow customers to merge K4a.dll logs into their own logging solution for better debuggability of system issues. It will also allow tools like K4A viewer can show error logs in real time in a dedicated window if it so chooses.

The proposal is to add k4a_register_debug_message_handler(). The function will take in a function pointer to deliver the messages to, a context for the callback function, and minimum log level setting the SDK should be sending to the user.

The registration API will only allow 1 callback function to be registered. If the user wants to change the logging level or the callback function, then the existing callback function needs to be unregistered first, and then a new callback function can be added. (I suppose we could allow the registration API to be called with the same callback function and treat that as an update to the logging level for a runtime change that doesn’t require unregistration. Anyone think that would be useful?)

The callback function will be invokable by any caller attempting to log. So if there are 3 threads running on 3 CPU, and all of then generate an error message at the same time, then all three of them can call into the users logging callback function at the same time. The user will need to protect against this.

The existing logging features (through the ENV variables) will continue to work as implemented when there is NO callback registered. When a callback is registered, then our current logging will be disabled.

The supported logging levels:

typedef enum
{
    K4A_LOG_LEVEL_CRITICAL = 0,
    K4A_LOG_LEVEL_ERROR,
    K4A_LOG_LEVEL_WARNING,
    K4A_LOG_LEVEL_INFO,
    K4A_LOG_LEVEL_TRACE,
} k4a_log_level_t;

Callback function signature:

typedef void(k4a_debug_logging_cb_t)(void *context, k4a_log_level_t level, char *message);

Register & unregister API’s

K4A_EXPORT k4a_result_t k4a_register_debug_message_handler(k4a_debug_logging_cb_t pfn, void *context, uint32_t min_log_level);
K4A_EXPORT k4a_result_t k4a_unregister_debug_message_handler(k4a_debug_logging_cb_t pfn);

Considerations

Using a callback function is a different programming paradigm when we currently use with K4A. In the case of debug messages, if we want to stay API philosophy of implementing a get_debug_message() API (similar to get_capture in that the user must own the thread), then we would be forced to implement a lot more code, that would likely be a duplication of functionality that the users logger would need to implement. Having an API like get_debug_message() would mean our SDK would have to queue up and store the debug messages in the event the users logger could not keep up. We would also then have to deal with dropped debug messages when the queue got full, and have to get the locking mechanics correct for having a single reader and multiple writers. Additionally we would also then want to consider how long a message has been in our queue and consider how the message will get the correct time stamp applied to it.

All these factors need to be taken into account by any logger that is accepting messages from multiple writers. So the logic that the SDK would need would be duplicated by the customers logger. So for this reason we are not considering the get_debug_message() style of API and instead going with a callback that can forwarded by any one of the SDK threads when an issue needs to be logged.

[wes-b]

Feedback from @skalldri

1. If it’s not too much trouble to add, I would find this useful. My tool has dynamic log-level reconfiguration during runtime, so being able to change the K4A log level when I get a ROS log-level change would be nice. I can un-register and re-register the callback function, but it would be nice to not have to.

(I suppose we could allow the registration API to be called with the same callback function and treat that as an update to the logging level for a runtime change that doesn’t require unregistration. Anyone think that would be useful?)

2. This sounds fine. I can build my own locks around the logging function, but there needs to be pretty clear documentation in the SDK docs / k4a.h that concurrent callbacks are possible.

The callback function will be invokable by any caller attempting to log. So if there are 3 threads running on 3 CPU, and all of then generate an error message at the same time, then all three of them can call into the users logging callback function at the same time. The user will need to protect against this.

[wes-b]

Feedback from @xthexder.

I don’t have any problems with a callback sort of system for this.

If we’re only going to support a single registered function, then maybe the API could be simplified to just set_debug_message_handler(), which would replace any existing handler, or unregister it if NULL. This would also make changing the log level easier if the user specifies the same function.

Needing to pass in the pointer to the existing callback function seems like an arbitrary requirement if it’s only possible to register a single callback.

-Jacob

[wes-b]

Feedback from @yijiew

The design sounds nice to me. But I am afraid we cannot leverage this nice feature in our body tracking SDK. Because body tracking SDK is created on top of the K4A SDK but not wrapping around it. In order to use the body tracking SDK, the user still requires to call the K4A APIs. Since the registration API will only allow 1 callback function to be registered, if we redirect the logging system to use our own callback function, the logging behavior will be strange when the user directly calls the K4A SDK.

[wes-b]

@skalldri thanks for the feedback, I will plan to allow runtime changing of logging level.

@xthexder I like the idea of calling this k4a_set_debug_message_handler() and using the same API to clear it. This is the same as k4a_capture_set_XXX_image() to add and clear an image.

@yijiew You should consider implementing the same k4a_set_debug_message_handler() API, which will allow the user to forward BT and SDK messages to the same tool owned by the user.

[schultetwin1]

I love this. As an FYI for getting started, spdlog has an idea of sinks. We may want to do this by creating a custom sink which is just a callback.

Someone tried to create a callback sink in spdlog a couple years ago but the PR was denied because it was too specific for the spdlog library. Even though it was rejected, it might be interesting to see how they did it as a starting point.

PR can be found here: https://github.com/gabime/spdlog/pull/205/files