Quantcast

GIRS stray trace messages

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

GIRS stray trace messages

Helen Foster
In 0.9.4pre1, starting lircd with the "girs" driver at log level
"Info" and connecting with irw:

If I set a log file for lircd, the Trace and Trace1 messages don't
appear, as expected. But using the default "syslog" mode they are
appearing.

On OpenPandora, running with "nodaemon", it prints output like this
over and over:
> lircd-0.9.4pre1[7747]: Trace: girs: written command "receive"
> lircd-0.9.4pre1[7747]: Trace1: girs: written command "\r"

On Fedora 22 i686, it does the same thing and also causes a large
number of broadcast messages:
> Broadcast message from systemd-journald (Sun 2016-03-27 23:26:52 BST):
> lircd-0.9.4pre1[19064]: Trace: girs: written command "receive"
In addition, once it starts doing that, lircd won't die from a
control-C or closing the window, and I have to use "kill -9" to make
it stop.

------------------------------------------------------------------------------
Transform Data into Opportunity.
Accelerate data analysis in your applications with
Intel Data Analytics Acceleration Library.
Click to learn more.
http://pubads.g.doubleclick.net/gampad/clk?id=278785471&iu=/4140
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: GIRS stray trace messages

Bengt Martensson-2
On 03/28/16 05:12, Helen Foster wrote:

> In 0.9.4pre1, starting lircd with the "girs" driver at log level
> "Info" and connecting with irw:
>
> If I set a log file for lircd, the Trace and Trace1 messages don't
> appear, as expected. But using the default "syslog" mode they are
> appearing.
>
> On OpenPandora, running with "nodaemon", it prints output like this
> over and over:
>> lircd-0.9.4pre1[7747]: Trace: girs: written command "receive"
>> lircd-0.9.4pre1[7747]: Trace1: girs: written command "\r"
>
> On Fedora 22 i686, it does the same thing and also causes a large
> number of broadcast messages:
>> Broadcast message from systemd-journald (Sun 2016-03-27 23:26:52 BST):
>> lircd-0.9.4pre1[19064]: Trace: girs: written command "receive"
> In addition, once it starts doing that, lircd won't die from a
> control-C or closing the window, and I have to use "kill -9" to make
> it stop.

If I understand correctly, if logging to a file, and everything is fine;
logging with syslogd hangs, rite? This appears to be a
Lircd/Fedora/syslog problem, nothing to do with the Girs driver. Can you
reproduce with another driver (like the "file" driver?)

Greetz,

Bengt


------------------------------------------------------------------------------
Transform Data into Opportunity.
Accelerate data analysis in your applications with
Intel Data Analytics Acceleration Library.
Click to learn more.
http://pubads.g.doubleclick.net/gampad/clk?id=278785471&iu=/4140
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: GIRS stray trace messages

Helen Foster
On 3/28/16, Bengt Martensson <[hidden email]> wrote:
> If I understand correctly, if logging to a file, and everything is fine;
> logging with syslogd hangs, rite?
Right.

> This appears to be a
> Lircd/Fedora/syslog problem, nothing to do with the Girs driver. Can you
> reproduce with another driver (like the "file" driver?)
With the Girs driver, the issue occurs only with the "logprintf" call,
and Girs appears to be the only driver that uses logprintf. So perhaps
there is a problem with logprintf in lircd.

------------------------------------------------------------------------------
Transform Data into Opportunity.
Accelerate data analysis in your applications with
Intel Data Analytics Acceleration Library.
Click to learn more.
http://pubads.g.doubleclick.net/gampad/clk?id=278785471&iu=/4140
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: GIRS stray trace messages

Helen Foster
I can see 2 bugs in LIRC's logprintf.

The first problem is with inconsistent checks for whether the priority fits.
log_debug, log_trace etc are macros in lirc_log.h which call logprintf
only if the priority fits with the current log level.
logprintf, in lirc_log.h says "Write a message to log", and in
lirc_log.c says "Prints the log request to the log, if the priority
fits."
If logging to a file, logprintf only adds the message if the priority
fits. If using syslog, it adds the message regardless of priority.

The second problem is, if using syslog, logprintf passes the prio
parameter onto the vsyslog function without checking it first. If prio
> 7 (less important than LOG_DEBUG), it should be changed to
LOG_DEBUG=7.
vsyslog takes the bottom 3 bits as the priority, so numbers greater
than 7 wrap around.
LIRC_TRACE2=10 -> LOG_CRIT=2
LIRC_TRACE1=9 -> LOG_ALERT=1
LIRC_TRACE=8 -> LOG_EMERG=0
So LIRC's trace messages are becoming emergencies when passed to
syslog, and hence the broadcast message spam on Fedora.

------------------------------------------------------------------------------
Transform Data into Opportunity.
Accelerate data analysis in your applications with
Intel Data Analytics Acceleration Library.
Click to learn more.
http://pubads.g.doubleclick.net/gampad/clk?id=278785471&iu=/4140
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: GIRS stray trace messages

Bengt Martensson-2
On 04/01/16 00:55, Helen Foster wrote:

> I can see 2 bugs in LIRC's logprintf.
>
> The first problem is with inconsistent checks for whether the priority fits.
> log_debug, log_trace etc are macros in lirc_log.h which call logprintf
> only if the priority fits with the current log level.
> logprintf, in lirc_log.h says "Write a message to log", and in
> lirc_log.c says "Prints the log request to the log, if the priority
> fits."
> If logging to a file, logprintf only adds the message if the priority
> fits. If using syslog, it adds the message regardless of priority.
>
> The second problem is, if using syslog, logprintf passes the prio
> parameter onto the vsyslog function without checking it first. If prio
>> 7 (less important than LOG_DEBUG), it should be changed to
> LOG_DEBUG=7.
> vsyslog takes the bottom 3 bits as the priority, so numbers greater
> than 7 wrap around.
> LIRC_TRACE2=10 -> LOG_CRIT=2
> LIRC_TRACE1=9 -> LOG_ALERT=1
> LIRC_TRACE=8 -> LOG_EMERG=0
> So LIRC's trace messages are becoming emergencies when passed to
> syslog, and hence the broadcast message spam on Fedora.

May I suggest that you file a ticket at
https://sourceforge.net/p/lirc/tickets/ ?

The moderator does not appear very active for the  moment :-(

PS. working on the second one.

------------------------------------------------------------------------------
Transform Data into Opportunity.
Accelerate data analysis in your applications with
Intel Data Analytics Acceleration Library.
Click to learn more.
http://pubads.g.doubleclick.net/gampad/clk?id=278785471&iu=/4140
Loading...