machinekit-hal
machinekit-hal copied to clipboard
Fix logging problems
In commit 77a23d3b over in the legacy repo, last hunk, I changed rtapi_print() to always print messages, as rtapi.h suggests should happen. However, this caused a lot of unwanted messages to spew through the error channel, leading to consternation finally resolved by reverting that hunk in 517f08a9.
The reason for the original fix was that important log information wasn't being printed ever, even with export DEBUG=5 (apparently rtapi_msg_handler(RTAPI_MSG_ALL, [...]) never prints anything, no matter the debug level, contrary to expectations). This is a problem, since many important failure messages are simply never logged.
I haven't tracked this all down to understand it properly yet, but I suspect this has something to do with the introduction of rtapi_msgd and the associated logging changes, perhaps rerouting the error channel through msgd into the same stream as messages that used to only be printed on the console, kernel log and file log.
This report on the ML shows the problem in a screenshot
@ArcEye I don't know how of if these issues are related however I have noticed that the DEBUG=5 halrun command is currently spewing lots of noise (at least on the Arm platforms). I have just traced the current origin to this recent commit by @machinekoder I have also posted a notice of the issue in the GGroup
I tried reverting that commit thar fixes the noise in running DEBUG=5 halrun, however then I loose the extra (needed) debug info in /var/log/linuxcnc.log
I have the same problems, an interactive halrun session, with debug level 5 is unworkable
The debug levels should now work as intended. Use DEBUG=4 or lower if you don't want the debug noise.
Or do you mean noise from ZMQ? https://github.com/machinekit/machinekit-hal/commit/61c1370b4179333f62a1e302f5e552d90b8a9a6a#diff-aa5b538722c64eba05229b4a37f7f2d9R1365, we could remove that.
DEBUG=4 seems to put all required debug messages into /var/log/linuxcnc.log ... OK
DEBUG=5 includes a continuous stream of:
D: 19-10-07 17:49:23 zloop polling for 999 msec
D: 19-10-07 17:49:24 zloop: call timer handler id=1
D: 19-10-07 17:49:24 zloop polling for 999 msec
D: 19-10-07 17:49:25 zloop: call timer handler id=1
D: 19-10-07 17:49:25 zloop polling for 998 msec
D: 19-10-07 17:49:26 zloop: call timer handler id=1
If that's the noise from ZMQ you mean, it would be very helpful to remove that endless stream