High trace/logging volume and system impact if _jobs_running is held for too long

[warrenjmcdonald]

This snippet is used twice in the transport.cpp

while (_jobs_running) {
	TRACE("Transport::outbound: sleeping...");
	OS::sleep(0.0005);
}

It is problematic as even if the _jobs_running state is held for only 50ms there will be 100 lines generated.

In a fault condition where the state is locked on, GBs of logs are generated in very short time. This can be fatal for small machines like Raspi Zero with small SD cards with single partitions.

It can also consume inordinate CPU and Wait time (esp with slow SD) which makes it hard to debug the actual fault causing the long _jobs_running state.

[attermann]

Thanks for the heads-up. The fact this is logging at all could be an issue that deserves some attention.

[warrenjmcdonald]

I set up remote logging to a machine with a lot more storage and grunt, so that I could review the logs when this happens. There is no clues in the debug level logs obvious just before this state locks in.

I assume I would need to be using a debug build and attach to dbg or similar. It occurs seemingly randomly and so very hard to catch unless I set a break point on the TRACE statement. Trouble is I would not know what to look for. I suppose I could get you a dump to look at.

[attermann]

Are you saying that when it enters the state where it's logging excessively, it gets locked into that state and does not recover? Is that the case even with the TRACE logs disabled?

[attermann]

I moved the high frequency TRACE log out of the light loop and instead logging only once immediately before it enters the loop.
I would appreciate if you could send me logs demonstrating where/when this log occurs.

[warrenjmcdonald]

Thanks. I will update rebuild, run and see what happens.

[warrenjmcdonald]

With the new build it is working quite well. I have had it running continuously for 2 days without issues so far. This has not been in very busy use, but I will set up something in next few days to stress test.

It has been running in host mode, so I can reconfigure/control it more easily from linux RNS. Once that is cover by some tests, I will switch back to TNC mode to give that a work out.