Example (Ocata): http://logs.openstack.org/67/460867/1/check/gate-neutron-dsvm-functional-ubuntu-xenial/382d800/logs/dsvm-functional-logs/neutron.tests.functional.agent.ovsdb.test_impl_idl.ImplIdlTestCase.test_post_commit_vswitchd_completed_no_failures.txt.gz
2017-04-28 07:59:01.430 11929 WARNING neutron.agent.ovsdb.native.vlog [-] tcp:127.0.0.1:6640: error parsing stream: line 0, column 1, byte 1: syntax error at beginning of input
2017-04-28 07:59:01.431 11929 DEBUG neutron.agent.ovsdb.impl_idl [-] Running txn command(idx=0): AddBridgeCommand(name=test-brc6de03bf, may_exist=True, datapath_type=None) do_commit neutron/agent/ovsdb/impl_idl.py:100
2017-04-28 07:59:01.433 11929 DEBUG neutron.agent.ovsdb.impl_idl [-] OVSDB transaction returned TRY_AGAIN, retrying do_commit neutron/agent/ovsdb/impl_idl.py:111
2017-04-28 07:59:01.433 11929 WARNING neutron.agent.ovsdb.native.vlog [-] tcp:127.0.0.1:6640: connection dropped (Protocol error)
If we look at logstash here:
http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22tcp%3A127.0.0.1%3A6640%3A%20error%20parsing%20stream%5C%22
We see some interesting data points, sometimes it actually logs what's in the buffer, and I see instances of:
2017-04-27 19:02:51.755 [neutron.tests.functional.tests.common.exclusive_resources.test_port.TestExclusivePort.test_port] 3300 WARNING ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: error parsing stream: line 0, column 1355, byte 1355: invalid keyword 'id'
2017-04-27 14:22:02.294 [neutron.tests.functional.agent.linux.test_ovsdb_monitor.TestSimpleInterfaceMonitor.test_get_events_native_] 3433 WARNING ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: error parsing stream: line 0, column 3, byte 3: invalid keyword 'new'
2017-04-27 04:46:17.667 [neutron.tests.functional.agent.test_dhcp_agent.DHCPAgentOVSTestCase.test_bad_address_allocation] 4136 WARNING ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: error parsing stream: line 0, column 3, byte 3: invalid keyword 'ace'
2017-04-26 18:04:59.110 [neutron.tests.functional.agent.linux.test_linuxbridge_arp_protect.LinuxBridgeARPSpoofTestCase.test_arp_correct_protection_allowed_address_pairs] 3477 WARNING ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: error parsing stream: line 0, column 3, byte 3: invalid keyword 'err'
2017-04-25 19:00:01.452 [neutron.tests.functional.agent.test_dhcp_agent.DHCPAgentOVSTestCase.test_agent_mtu_set_on_interface_driver] 4251 WARNING ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: error parsing stream: line 0, column 3, byte 3: invalid keyword 'set'
2017-04-25 16:34:11.355 [neutron.tests.functional.agent.linux.test_linuxbridge_arp_protect.LinuxBridgeARPSpoofTestCase.test_arp_fails_incorrect_mac_protection] 3332 WARNING ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: error parsing stream: line 0, column 5, byte 5: invalid keyword 'tatus'
2017-04-25 03:28:25.858 [neutron.tests.functional.agent.ovsdb.test_impl_idl.ImplIdlTestCase.test_post_commit_vswitchd_completed_no_failures] 4112 WARNING ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: error parsing stream: line 0, column 3, byte 3: invalid keyword 'set'
2017-04-24 21:59:39.094 [neutron.tests.functional.agent.linux.test_linuxbridge_arp_protect.LinuxBridgeARPSpoofTestCase.test_arp_protection_port_security_disabled] 3682 WARNING ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: error parsing stream: line 0, column 5, byte 5: invalid keyword 'rsion'
Terry says it doesn't resemble the protocol, but some random crap, potentially from some random place in memory (SCARY!)
The least we could do is dumping some more details to understand where that bogus data came from. Maybe once we see more context, we will realize the source of the buffer.