← Back to team overview

yahoo-eng-team team mailing list archive

  1. yahoo-eng-team team
  2. Mailing list archive
  3. Message #63681

[Bug 1687074] [NEW] Sometimes ovsdb fails with "tcp:127.0.0.1:6640: error parsing stream"

  Thread Previous • Date Previous • • Thread Next 
Public bug reported:

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!)

** Affects: neutron
     Importance: High
         Status: Confirmed

** Affects: ovsdbapp
     Importance: Undecided
         Status: Confirmed


** Tags: fullstack functional-tests gate-failure ovs

** Changed in: neutron
   Importance: Undecided => High

** Changed in: neutron
       Status: New => Confirmed

** Also affects: ovsdbapp
   Importance: Undecided
       Status: New

** Changed in: ovsdbapp
       Status: New => Confirmed

** Tags added: fullstack functional-tests gate-failure ovs

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1687074

Title:
  Sometimes ovsdb fails with "tcp:127.0.0.1:6640: error parsing stream"

Status in neutron:
  Confirmed
Status in ovsdbapp:
  Confirmed

Bug description:
  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!)

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1687074/+subscriptions

Follow ups

  Thread Previous • Date Previous • • Thread Next