logging timestamps

[jjanowsk]

Add granular timestamps to logs

There is a suspicion that our logs can lock from time to time.
Currently the timestamp in our logs comes from the very end of log
processing right before sending it to the writer thread which executes
application callback. To check if we do not have any locking inside
logging machinery on call site let's add two timestamps to our logs. One
directly from the call site and second in formatter. Third is already
there and comes from writter as explained above.

This is a temporary commit meant to be reverted once we have results.

☑️ Definition of Done checklist

• Commit history is clean (requirements)
• README.md is updated
• Functionality is covered by unit or integration tests

[Hasan6979]

+2
It would be worth to add dns or something with branch name, so that when we revert the commits -> easier to find. I feel that we might have to make more temp branches than we already have.

[LukasPukenis]

An idea: we can create a ticket about reverting this commit and link in TODO item in the code. This way we can leave it even for longer if needed with no worries about forgetting it(highly unlikeable though).

+1

[tomaszklak]

Maybe this mutex is causing problem: https://github.com/search?q=repo%3ANordSecurity%2Flibtelio%20LAST_LOG_STATUS&type=code ?

[jjanowsk]

Maybe this mutex is causing problem: https://github.com/search?q=repo%3ANordSecurity%2Flibtelio%20LAST_LOG_STATUS&type=code ?

It might. It's the only lock I saw on the call site. But I would like to first confirm that what we saw was actually a lock in logging and not somewhere else. BTW since I think you're the implementor of the logging thread I have a question: Is there a reason why this filtering and censoring is done on the call site instead of inside the logging thread?

[tomaszklak]

Maybe this mutex is causing problem: https://github.com/search?q=repo%3ANordSecurity%2Flibtelio%20LAST_LOG_STATUS&type=code ?

It might. It's the only lock I saw on the call site. But I would like to first confirm that what we saw was actually a lock in logging and not somewhere else. BTW since I think you're the implementor of the logging thread I have a question: Is there a reason why this filtering and censoring is done on the call site instead of inside the logging thread?

No real reason. The offloading to separate thread was done due to slow I/O (via python) - I wasn't expecting (and didn't see any symptoms) the processing (which was already present for quite some time) to be an issue. So I think it perfectly valid offload it to logger thread.