Hide Forgot
Description of problem: We frequently see the following error messages in neutron-server logs 2018-04-14 21:40:00.902 50 WARNING networking_odl.common.websocket_client [req-dfd5b668-55de-4a85-bd74-02c4c43d86eb - - - - -] websocket connection closed or IO error: WebSocketConnectionClosedException: Connection is already closed. 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client Traceback (most recent call last): 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/networking_odl/common/websocket_client.py", line 124, in run_websocket_thread 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client data = ws.recv() 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_core.py", line 348, in recv 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client opcode, data = self.recv_data() 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_core.py", line 365, in recv_data 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client opcode, frame = self.recv_data_frame(control_frame) 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_core.py", line 378, in recv_data_frame 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client frame = self.recv_frame() 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_core.py", line 410, in recv_frame 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client return self.frame_buffer.recv_frame() 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_abnf.py", line 300, in recv_frame 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client self.recv_header() 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_abnf.py", line 249, in recv_header 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client header = self.recv_strict(2) 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_abnf.py", line 334, in recv_strict 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client bytes = self.recv(min(16384, shortage)) 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_core.py", line 476, in _recv 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client return recv(self.sock, bufsize) 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_socket.py", line 89, in recv 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client raise WebSocketConnectionClosedException("Connection is already closed.") 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client WebSocketConnectionClosedException: Connection is already closed. 2018-04-14 21:40:00.902 50 ERROR networking_odl.common.websocket_client 2018-04-14 21:40:00.902 50 INFO networking_odl.common.websocket_client [req-dfd5b668-55de-4a85-bd74-02c4c43d86eb - - - - -] websocket transition to status ODL_WEBSOCKET_DISCONNECTED 2018-04-14 21:40:00.903 50 INFO networking_odl.common.websocket_client [req-dfd5b668-55de-4a85-bd74-02c4c43d86eb - - - - -] websocket transition to status ODL_WEBSOCKET_CONNECTING 2018-04-14 21:40:00.920 50 INFO networking_odl.common.websocket_client [req-dfd5b668-55de-4a85-bd74-02c4c43d86eb - - - - -] websocket transition to status ODL_WEBSOCKET_CONNECTED Version-Release number of selected component (if applicable): OSP 13 python-networking-odl-12.0.1-0.20180228140714.8733cf6.el7ost.noarch opendaylight-8.0.0-5.el7ost.noarch How reproducible: 100% Steps to Reproduce: 1. Install OSP 13 with ODL 2. Run scale tests 3. Actual results: WebSocket connection dropped messages in logs Expected results: No connection drops Additional info:
As far as I know, this issue no longer occurs. IIRC, Tim solved this.
Josh, This is a very recent puddle, from April 10th. Tim, was this fixed?
I can't tell from the log, but this is OK as long as it is happening once an hour in an idle state. The tunnel timeout is 3600s. So if you do not change any ports in an hour the timeout will fire and networking-odl will reconnect. That should be normal. Are you seeing it more often than every hour?
No. seeing it about once every hour. However, wondering if need to throw the stack trace in the log?
Yeah we could remove the stack trace to make the log cleaner, since this is only a warning and the output from the trace is in the websocket library and does not really help much anyway.
Hello guys, I've just deployed OSP13 with ODL in a customer, and I'm still seeing the following stack traces every hour, which makes it very confusing for the user. neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client frame = self.recv_frame() neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_core.py", line 410, in recv_frame neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client return self.frame_buffer.recv_frame() neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_abnf.py", line 300, in recv_frame neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client self.recv_header() neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_abnf.py", line 249, in recv_header neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client header = self.recv_strict(2) neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_abnf.py", line 334, in recv_strict neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client bytes = self.recv(min(16384, shortage)) neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_core.py", line 476, in _recv neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client return recv(self.sock, bufsize) neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client File "/usr/lib/python2.7/site-packages/websocket/_socket.py", line 89, in recv neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client raise WebSocketConnectionClosedException("Connection is already closed.") neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client WebSocketConnectionClosedException: Connection is already closed. neutron/server.log:2018-11-08 08:11:05.752 52 ERROR networking_odl.common.websocket_client Are we removing this trace in the code?
It's actually haproxy closing the connection. So networking-odl thinks it is an error and raising an exception. We could perhaps change the haproxy config to never timeout.
As per depreciation notice [1], closing this bug. Please reopen if relevant for RHOSP13, as this is the only version shipping ODL. [1] https://access.redhat.com/documentation/en-us/red_hat_openstack_platform/14/html-single/release_notes/index#deprecated_functionality