thread safe and non-blocking log function

Discussion to talk about software related topics only.
Post Reply
zealott
Posts: 40
Joined: Thu Oct 30, 2008 1:15 am

thread safe and non-blocking log function

Post by zealott »

Hello,
I have used the function below as a "syslog" type function for logging misc stuff, works good, but I am unsure if it sometimes gives me a bit of lag/hang.
If multiple tasks are calling this (from a "tools.cpp" file), would there be any implications?
Since I have a OSLockObj() there, would the other tasks trying to use this function, just wait a bit that would cause a slight lag.

Any other ways of doing this neatly (non-blocking fifo buffer and a tasks that processes it?)
Thanks,

char log_f[256];
char log_t[300];
void log_message(const char *format, ...)
{
OSLockObj();
va_list args;

va_start (args, format);
vsnprintf (log_f, sizeof(log_f), format, args);
va_end (args);
snprintf(log_t, sizeof(log_t), "%lu:%s\r\n", TimeTick, log_f);
printf(log_t);
}

Edit:
If I create the variables inside the function, they would be use the task stack, right?
If so, I could also get rid of the OSLockObj(). Would the rest be thread-safe also?
sulliwk06
Posts: 118
Joined: Tue Sep 17, 2013 7:14 am

Re: thread safe and non-blocking log function

Post by sulliwk06 »

If you make the log strings local they would be on the stack for each task, but if you remove the task lock the print statement could be interrupted by a higher priority task, which would mangle your messages a bit having some in the middle of others.

What I typically have done in this type of situation is to create a fifo of strings and a dedicated task to handling the printing.
User avatar
pbreed
Posts: 1088
Joined: Thu Apr 24, 2008 3:58 pm

Re: thread safe and non-blocking log function

Post by pbreed »

You don't need the Critlock...
Everything there is thread safe...

I might keep the critlock and then do printf of all the diseperate pieces and not have the intermediate buffer...


There is one down side...

If A higher priority task interupts the printf....

"HipriorityMessage"

"LowPrioMsg"

What you might get is ....

LowPHipriorityMessagerioMsg

The Critlock keeps that from happening...

If you use the syslog functions everything is thread safe...
You can monitor syslog messages with the udpterminal utility....
KE5FX
Posts: 25
Joined: Tue Dec 10, 2019 11:17 pm

Re: thread safe and non-blocking log function

Post by KE5FX »

pbreed wrote: Wed Apr 01, 2020 10:20 am If A higher priority task interupts the printf....
That leads to another question -- under what conditions could another task interrupt a printf() call?

The OS never performs preemptive task switching, correct?
User avatar
pbreed
Posts: 1088
Joined: Thu Apr 24, 2008 3:58 pm

Re: thread safe and non-blocking log function

Post by pbreed »

>The OS never performs preemptive task switching, correct?
Not correct...
If a higher priority task becomes unblocked then you will get a task switch to that task, preemptively at any time.

The highest priority task that is not blocked runs, exclusively.
Things block at:
Queue, semaphore, fifo critical sections Pend functions.
OSTimeDly.
Serial or Network I/O read, write, printf etc.. can all block waiting on buffer space,
or input can block waiting for serial or TCP data....

Example:
A task filled the serial output buffer in the middle of a Printf.....this task blocks till more buffer space is available.



When a task blocks, the next highest task that is unblocked runs....
(Which is why OS Idle never blocks, something has to bee ready to run at all times.)



When a task is blocked
Things can unblock for several reasons...

Another task can do something (release a critical section post to semaphore, queue, fifo etc...)
A timeout can expire... (time outs are interrupt based so this can happen at any time)
An I/O event can happen... ie:
Ethernet interrupt -> wakes up IP task ->wakes up task waiting on TCP data via select...
The serial ISR sends out data, making more TX buffer space available, unblocking task in the middle of print waiting for space.

A task waiting on serial port wakes up when interrupt for serial RX data puts data in the buffer
Again these can happen preemptively at any time....
Task switching is in no way timed to TimeTicks (other than timeouts)
KE5FX
Posts: 25
Joined: Tue Dec 10, 2019 11:17 pm

Re: thread safe and non-blocking log function

Post by KE5FX »

Hmm, OK, got it, I think. My impression (and experience so far) is that if a given task doesn't explicitly yield by pending on something (possibly via printf or some other function that itself will wait for a resource to become available), nothing other than interrupts will run, ever. Then, as soon as the current task yields, the OS will hand control over to the highest-priority task that can run (i.e., whatever it was pending on is now enabled, whether by a timer ISR or a lock released by my own task.)

It sounds like a lot more functionality is interrupt-driven than I thought. I was thinking that ISRs just set flags to allow other tasks to run when the current task yields, but from what you're saying, that's not the case, and tasks are themselves running from ISRs. (Or, I guess, the OS idle loop.)

That makes me wonder how I'm getting away with some stuff I seem to be getting away with... :shock: To my way of thinking, printf() couldn't be interrupted by another task, per se, but it could block while waiting for a buffer or handshake or whatever. Good to know.
User avatar
pbreed
Posts: 1088
Joined: Thu Apr 24, 2008 3:58 pm

Re: thread safe and non-blocking log function

Post by pbreed »

Its likely that your task yields preemptively to higher priority system tasks (network stuff mostly)
and you just don't notice as its back to your task fairly quickly...
Post Reply