Description of problem: Tons of "invalid character 'c' looking for beginning of value" errors appear in node log when cluster running with crio. Jun 13 23:58:12 ip-172-18-14-79.ec2.internal atomic-openshift-node[18924]: ERROR: logging before flag.Parse: W0613 23:58:12.971203 18924 manager.go:1178] Failed to process watch event {EventType:0 Name:/kubepods.slice/kubepods-besteffort.slice/kubepods-besteffort-pod2262d6c2_6f87_11e8_86dd_0eb037b2774e.slice/crio-b188fba45a612b6fd7cbb00dd6150e182e86ecef6f0447abd67210f08e2a456f.scope WatchSource:0}: invalid character 'c' looking for beginning of value Jun 13 23:58:16 ip-172-18-14-79.ec2.internal atomic-openshift-node[18924]: ERROR: logging before flag.Parse: W0613 23:58:16.489277 18924 manager.go:1178] Failed to process watch event {EventType:0 Name:/kubepods.slice/kubepods-besteffort.slice/kubepods-besteffort-pod2262d6c2_6f87_11e8_86dd_0eb037b2774e.slice/crio-2cb7f38521db0cd9584b4d52c7d5e76e39aea96f226b7f4fadf811252e3c5e5a.scope WatchSource:0}: invalid character 'c' looking for beginning of value Jun 13 23:59:40 ip-172-18-14-79.ec2.internal atomic-openshift-node[18924]: ERROR: logging before flag.Parse: W0613 23:59:40.225422 18924 manager.go:1178] Failed to process watch event {EventType:0 Name:/kubepods.slice/kubepods-besteffort.slice/kubepods-besteffort-pod5b7ccb19_6f87_11e8_86dd_0eb037b2774e.slice/crio-e6ccc38071c3b403accd153c11775f7fd933305f31b551d4b6c6597692ce777d.scope WatchSource:0}: invalid character 'c' looking for beginning of value Jun 13 23:59:54 ip-172-18-14-79.ec2.internal atomic-openshift-node[18924]: ERROR: logging before flag.Parse: W0613 23:59:54.687828 18924 manager.go:1178] Failed to process watch event {EventType:0 Name:/kubepods.slice/kubepods-besteffort.slice/kubepods-besteffort-pod5b7ccb19_6f87_11e8_86dd_0eb037b2774e.slice/crio-ea3d01c5538a2b238bbdacf534aa30b77454cecde90d47c782a9e2c2722ae297.scope WatchSource:0}: invalid character 'c' looking for beginning of value Version-Release number of selected component (if applicable): always How reproducible: v3.10.0-0.67.0 Steps to Reproduce: 1. Setup ocp cluster with crio 2. Check the node log 3. Actual results: Tons of "invalid character 'c' looking for beginning of value" errors Expected results: Should not have such error Additional info: There is no such problem on docker container env.
Fix is here: https://github.com/kubernetes-incubator/cri-o/pull/1615
that was not the fix, my bad, I'm working on one right now
Fix here https://github.com/kubernetes-incubator/cri-o/pull/1616
This is fixed in crio 1.10.3
Can this be tested and moved to verified?
still seeing the errors in the node logs with crio verison 1.10.3 [root@qe-pruan-auto-310-all-in-one-crio-preserve-merrn-1 ~]# crio --version crio version 1.10.3 commit: "54383a69903e1b46526be3dbe0bea71b14f00e46-dirty" [root@qe-pruan-auto-310-all-in-one-crio-preserve-merrn-1 ~]# journalctl -u atomic-openshift-node.service | grep "Failed to process watch event" Jun 18 16:30:00 qe-pruan-auto-310-all-in-one-crio-preserve-merrn-1 atomic-openshift-node[22829]: W0618 16:30:00.331301 22829 manager.go:1178] Failed to process watch event {EventType:0 Name:/kubepods.slice/kubepods-besteffort.slice/kubepods-besteffort-podf8ddfa563d27a7f9ca95644fe2f8cdd0.slice/crio-28263d9946f502dc7ed03ecb134d8f13f55b6cc3863aad0e3e4f42ea8bfcfc34.scope WatchSource:0}: invalid character 'c' looking for beginning of value Jun 18 16:30:00 qe-pruan-auto-310-all-in-one-crio-preserve-merrn-1 atomic-openshift-node[22829]: W0618 16:30:00.333551 22829 manager.go:1178] Failed to process watch event {EventType:0 Name:/kubepods.slice/kubepods-besteffort.slice/kubepods-besteffort-pod83e9c11b241c6539016d50a962142eda.slice/crio-075774ac13d768cf7f4729bba748570a5eaa329ca63eae303417d28ffcfe494a.scope WatchSource:0}: invalid character 'c' looking for beginning of value
Could you provide full cri-o log for the above run please?
(In reply to Peter Ruan from comment #6) > still seeing the errors in the node logs with crio verison 1.10.3 > > [root@qe-pruan-auto-310-all-in-one-crio-preserve-merrn-1 ~]# crio --version > crio version 1.10.3 > commit: "54383a69903e1b46526be3dbe0bea71b14f00e46-dirty" > [root@qe-pruan-auto-310-all-in-one-crio-preserve-merrn-1 ~]# journalctl -u > atomic-openshift-node.service | grep "Failed to process watch event" > Jun 18 16:30:00 qe-pruan-auto-310-all-in-one-crio-preserve-merrn-1 > atomic-openshift-node[22829]: W0618 16:30:00.331301 22829 manager.go:1178] > Failed to process watch event {EventType:0 > Name:/kubepods.slice/kubepods-besteffort.slice/kubepods-besteffort- > podf8ddfa563d27a7f9ca95644fe2f8cdd0.slice/crio- > 28263d9946f502dc7ed03ecb134d8f13f55b6cc3863aad0e3e4f42ea8bfcfc34.scope > WatchSource:0}: invalid character 'c' looking for beginning of value > Jun 18 16:30:00 qe-pruan-auto-310-all-in-one-crio-preserve-merrn-1 > atomic-openshift-node[22829]: W0618 16:30:00.333551 22829 manager.go:1178] > Failed to process watch event {EventType:0 > Name:/kubepods.slice/kubepods-besteffort.slice/kubepods-besteffort- > pod83e9c11b241c6539016d50a962142eda.slice/crio- > 075774ac13d768cf7f4729bba748570a5eaa329ca63eae303417d28ffcfe494a.scope > WatchSource:0}: invalid character 'c' looking for beginning of value could you also provide access to the test machine?
Yeah, I can see the problem on OCP 3.10.2-1 and cri-o 1.10.3 Jun 21 17:25:40 ocp310-node2.bmeng.local atomic-openshift-node[1663]: ERROR: logging before flag.Parse: E0621 17:25:36.856474 1663 manager.go:1130] Failed to create existing container: /kubepods.slice/kubepods-burstable.slice/kubepods-burstable-pod32c61a68_6881_11e8_8add_525400c1455c.slice/crio-10cb6cd6ad5a692d5a7cd31ee355447ebda9d3d16026768ae4c4978ddf643e60.scope: invalid character 'c' looking for beginning of value Jun 21 17:25:40 ocp310-node2.bmeng.local atomic-openshift-node[1663]: ERROR: logging before flag.Parse: E0621 17:25:36.857341 1663 manager.go:1130] Failed to create existing container: /kubepods.slice/kubepods-burstable.slice/kubepods-burstable-pod32c61a68_6881_11e8_8add_525400c1455c.slice/crio-60e955109ec274dc6b4d3e7237097e1eb106aa2e2255d94a2ae221b69b18873c.scope: invalid character 'c' looking for beginning of value
Tentatively moving this to 3.10.z because I don't believe this is a blocker (though, we're still actively working on it!). The issue here is that cgroups show up earlier than cadvisor querying the CRI-O endpoint, resulting in that error in logs. Anyway, the next time cadvisor queries the CRI-O endpoing, everything is gonna be successful.
can you re-test with latest openshift+crio? if it's not working could you please provide a test vm where I can reproduce myself? Thanks
I cannot see the ERRORs on ocp v3.10.34 with cri-o-1.10.6-1.rhaos3.10.git56d7d9a.el7.x86_64
can you move to verified?
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2019:0620