Bug 702114
| Summary: | Add way to drop timestamps from log output | ||
|---|---|---|---|
| Product: | [Community] Virtualization Tools | Reporter: | Guido Günther <agx> |
| Component: | libvirt | Assignee: | Libvirt Maintainers <libvirt-maint> |
| Status: | CLOSED UPSTREAM | QA Contact: | |
| Severity: | unspecified | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | unspecified | CC: | crobinso, dallan, eblake, jdenemar, veillard, xen-maint |
| Target Milestone: | --- | ||
| Target Release: | --- | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2011-10-14 20:44:00 UTC | Type: | --- |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
| Embargoed: | |||
Starting with 0.9.0 libvirtd doesn't log to syslog by default but to /var/log/libvirt/libvirtd.log , then that file is logrotated. Having the full timestamp can be crucial when debugging some issues. We could optionally turn it off, but I wonder if the new behaviour isn't a better fix to the problem. Daniel DV, IIUC, the problem is that the timestamps are messing up logcheck's ability to coalesce the log lines, and where the log goes isn't going to affect that. Guido, does logcheck have some regex-like facility for ignoring parts of the lines it's coalescing? Also, would you mind taking the discussion to the mailing list, and provide a PoC patch if you're able to? Dave logcheck invokes syslog-summary which has a hardcoded pattern for matching dates:
re.compile(r"^(Jan|Feb|Mar|Apr|May|Jun|Jul|Aug|Sep|Oct|Nov|Dec) [ 0-9][0-9] [ 0-9][0-9]:[0-9][0-9]:[0-9][0-9] "),
re.compile(r"^(Mon|Tue|Wed|Thu|Fri|Sat|Sun) (Jan|Feb|Mar|Apr|May|Jun|Jul|Aug|Sep|Oct|Nov|Dec) [ 0-9][0-9][0-9][0-9]:[0-9][0-9] "),
re.compile(r"^(Mon|Tue|Wed|Thu|Fri|Sat|Sun) (Jan|Feb|Mar|Apr|May|Jun|Jul|Aug|Sep|Oct|Nov|Dec) [ 0-9][0-9][0-9][0-9]:[0-9][0-9]:[0-9][0-9] "),
The issue is that when logging through syslog the second timestamp isn't catched by that. Now with a separate syslog the timestamp used by libvirt itself doesn't match this either.
People might want to continue to log through syslog to use syslog-summary, etc. in that case disabling the timestamp would make sense.
I'll won't be able to come up with a patch nearterm that's why I filed the bug. I'll restart the discussion on the ML once I have time to work on this.
Thanks for your comments.
Does that mean libvirt needs to change its timestamp output to match the hardcoded expectations of syslog-summary? And/or, should we spawn a bug against syslog to improve the regex parser to accept libvirt's format? This means that we should not include timestamps in the log message when logging to syslog, syslog deamon will prefix the message with it's own timestamp anyway. Including them in libvirtd.log or any other file is fine and desirable. > This means that we should not include timestamps in the log message when > logging to syslog, syslog deamon will prefix the message with it's own > timestamp anyway. Having exactly that would be great! > Including them in libvirtd.log or any other file is fine and desirable. We might want use a format similar to syslog though to help parsers like logcheck with syslog-summary along. This is now fixed upstream by
commit 2a449549c1db0befef8a807bfe967a04af8b529b
Author: Jiri Denemark <jdenemar>
Date: Wed Sep 28 15:20:07 2011 +0200
logging: Do not log timestamp through syslog
Syslog puts the timestamp to every message anyway so this removes
redundant data.
|
Citing from the Debian bugreport: I run logcheck with syslog-summary enabled. That allows me to get ONE line like this, indicating the number of duplicate (in this case 10): 10 stomp dovecot: IMAP(russm): stat(/var/mail/lists/.managers/tmp) failed: Permission denied (euid=1033(russm) egid=1033(russm) missing +x perm: /var/mail/lists/.managers) However, libvirtd includes its own timestamps in its syslog messages, which completely ruins this: 1 theta libvirtd: 15:33:46.516: error : checkType:2495 : remoteReadConfigFile: /etc/libvirt/libvirtd.conf: unix_sock_group: invalid type: got long; expected string#012 1 theta libvirtd: 15:33:46.523: error : checkType:2495 : remoteReadConfigFile: /etc/libvirt/libvirtd.conf: unix_sock_group: invalid type: got long; expected string#012 1 theta libvirtd: 15:33:46.530: error : checkType:2495 : remoteReadConfigFile: /etc/libvirt/libvirtd.conf: unix_sock_group: invalid type: got long; expected string#012 1 theta libvirtd: 15:33:46.537: error : checkType:2495 : remoteReadConfigFile: /etc/libvirt/libvirtd.conf: unix_sock_group: invalid type: got long; expected string#012 1 theta libvirtd: 15:33:46.544: error : checkType:2495 : remoteReadConfigFile: /etc/libvirt/libvirtd.conf: unix_sock_group: invalid type: got long; expected string#012 1 theta libvirtd: 15:33:46.551: error : checkType:2495 : remoteReadConfigFile: /etc/libvirt/libvirtd.conf: unix_sock_group: invalid type: got long; expected string#012 1 theta libvirtd: 15:33:46.558: error : checkType:2495 : remoteReadConfigFile: /etc/libvirt/libvirtd.conf: unix_sock_group: invalid type: got long; expected string#012 1 theta libvirtd: 15:33:46.565: error : checkType:2495 : remoteReadConfigFile: /etc/libvirt/libvirtd.conf: unix_sock_group: invalid type: got long; expected string#012 1 theta libvirtd: 15:33:46.572: error : checkType:2495 : remoteReadConfigFile: /etc/libvirt/libvirtd.conf: unix_sock_group: invalid type: got long; expected string#012 1 theta libvirtd: 15:33:46.579: error : checkType:2495 : remoteReadConfigFile: /etc/libvirt/libvirtd.conf: unix_sock_group: invalid type: got long; expected string#012 1 theta libvirtd: 15:33:46.586: error : checkType:2495 : remoteReadConfigFile: /etc/libvirt/libvirtd.conf: unix_sock_group: invalid type: got long; expected string#012 Please remove, or at least make optional, these timestamps. This is analogous to these smb.conf options: [global] # Without these, logserv's syslog-summary(1) fails to merge # identical smb log entries in logcheck emails. debug prefix timestamp = no debug timestamp = no This imho makes a lot of sense.