Bug 1261830 - corosync.log sometimes misses timestamps causing crm_report to treat it as an invalid file
corosync.log sometimes misses timestamps causing crm_report to treat it as an...
Status: NEW
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: corosync (Show other bugs)
7.3
Unspecified Unspecified
medium Severity medium
: rc
: ---
Assigned To: Jan Friesse
cluster-qe@redhat.com
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-09-10 05:38 EDT by Jaroslav Kortus
Modified: 2017-01-16 07:07 EST (History)
3 users (show)

See Also:
Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Jaroslav Kortus 2015-09-10 05:38:08 EDT
Description of problem:
Some lines of corosync.log do have timestamps prepended, while some others do not. This later confuses crm_report and it discards that log file completely.

Version-Release number of selected component (if applicable):
corosync-2.3.4-7.el7.x86_64

How reproducible:
100%

Steps to Reproduce:
1. set up a cluster via pcs
2.
3.

Actual results:
corosync.log contains log entries with no timestamps, followed by timestamped ones
crm_report does not contain corosync.log from all nodes

Expected results:
timestamps everywhere
crm_report collecting the log files

Additional info:
My current example:

[root@virt-085 cluster]# cat corosync.log
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [MAIN  ] Corosync Cluster Engine ('2.3.4'): started and ready to provide service.
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncinfo    [MAIN  ] Corosync built-in features: dbus systemd xmlconf snmp pie relro bindnow
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [TOTEM ] Initializing transport (UDP/IP Unicast).
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [TOTEM ] Initializing transmit/receive security (NSS) crypto: none hash: none
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [TOTEM ] The network interface [10.34.71.85] is now up.
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [SERV  ] Service engine loaded: corosync configuration map access [0]
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncinfo    [QB    ] server name: cmap
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [SERV  ] Service engine loaded: corosync configuration service [1]
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncinfo    [QB    ] server name: cfg
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [SERV  ] Service engine loaded: corosync cluster closed process group service v1.01 [2]
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncinfo    [QB    ] server name: cpg
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [SERV  ] Service engine loaded: corosync profile loading service [4]
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [QUORUM] Using quorum provider corosync_votequorum
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [SERV  ] Service engine loaded: corosync vote quorum service v1.0 [5]
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncinfo    [QB    ] server name: votequorum
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [SERV  ] Service engine loaded: corosync cluster quorum service v0.1 [3]
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncinfo    [QB    ] server name: quorum
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [TOTEM ] adding new UDPU member {10.34.71.79}
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [TOTEM ] adding new UDPU member {10.34.71.85}
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [TOTEM ] adding new UDPU member {10.34.71.86}
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [TOTEM ] A new membership (10.34.71.85:20) was formed. Members joined: 2
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [QUORUM] Members[1]: 2
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [MAIN  ] Completed service synchronization, ready to provide service.
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [TOTEM ] A new membership (10.34.71.79:24) was formed. Members joined: 1 3
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [QUORUM] This node is within the primary component and will provide service.
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [QUORUM] Members[3]: 1 2 3
[8651] virt-085.cluster-qe.lab.eng.brq.redhat.com corosyncnotice  [MAIN  ] Completed service synchronization, ready to provide service.
Set r/w permissions for uid=189, gid=189 on /var/log/cluster/corosync.log
Sep 10 10:40:56 [8678] virt-085.cluster-qe.lab.eng.brq.redhat.com pacemakerd:   notice: mcp_read_config:        Configured corosync to accept connections from group 189: OK (1)
Sep 10 10:40:56 [8678] virt-085.cluster-qe.lab.eng.brq.redhat.com pacemakerd:   notice: main:   Starting Pacemaker 1.1.13 (Build: 44eb2dd):  generated-manpages agent-manpages ncurses libqb-logging libqb-ipc upstart systemd nagios  corosync-native atomic-attrd acls
Sep 10 10:40:56 [8678] virt-085.cluster-qe.lab.eng.brq.redhat.com pacemakerd:     info: main:   Maximum core file size is: 18446744073709551615
Sep 10 10:40:56 [8678] virt-085.cluster-qe.lab.eng.brq.redhat.com pacemakerd:     info: qb_ipcs_us_publish:     server name: pacemakerd


crm_report symptom:
[root@virt-086 ~]# crm_report --from "2011-01-01 00:00:00" report-out
virt-086:   Calculated node list: virt-079 virt-085 virt-086 
virt-086:   Collecting data from virt-079 virt-085 virt-086  (01/01/2011 12:00:00 AM to 09/10/2015 11:30:58 AM)
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Unknown time format used by: 
virt-079:   WARN: Skipping bad logfile '/var/log/cluster/corosync.log': Could not determine log dates
Comment 3 Jan Friesse 2016-01-25 11:22:49 EST
Capacity constrained, moving to 7.4 (7.3 is mostly about Qdevice).

Note You need to log in before you can comment on or make changes to this bug.