Comment 1 for bug 1674736

Revision history for this message
Alexandros Frantzis (afrantzis) wrote :

Some clarifications: these log messages correspond to activity events as they arrive from USC. They are not sent for every input event, but instead at most once every 0.5s seconds and only if USC gets an input event in that interval.

Now to the concerns:

> This makes debugging cumbersome and

It's true that the log seems somewhat spammed with these messages. However, activity events affect repowerd's state machine fundamentally and we would not be able to debug effectively if we didn't log them.

> is probably not great for battery life

From past measurements, the CPU time used by logging, and thus the effect on power, is negligible. The measurements also make sense from coarse-grained analysis of the processing involved: every time we have an input event the system needs to react to it possibly by compositing and doing other app specific processing. A couple of times per second, if we have input events, we also send an activity event to repowerd, which needs to update its state (inactivity timeouts etc). Logging the activity event is a negligible portion of the overall processing involved.

If we still consider this is an issue we could reduce the maximum rate at which USC sends activity events. For example, we could change from the current 2Hz to 1Hz. The downside is that the accuracy of inactivity timeouts depends on the rate of activity events. With 2Hz we have a maximum error of 0.5s, with 1Hz the maximum error goes up to 1s.

Another related topic is that we currently log to both /var/log/repowerd.log /var/log/syslog. /v/l/syslog logging was added so that we could correlate easily between repowerd events and other system events (e.g. suspending). If we think that the benefit of easy correlation is not worth repowerd "spamming" /v/l/syslog, we could consider logging only to /v/l/repowerd.log.