Project

General

Profile

Actions

action #105274

closed

Workers constantly logging websocket connection "finished by remote side with code 1006, no reason"

Added by AdamWill over 2 years ago. Updated about 2 years ago.

Status:
Resolved
Priority:
High
Assignee:
Category:
-
Target version:
Start date:
2022-01-21
Due date:
% Done:

0%

Estimated time:

Description

I deployed a couple of new worker hosts to our openQA instance today, and noticed that there seems to be some kind of constant websocket connection churn, like this (logs for just one worker process isolated, but I get this for every worker process):

Jan 21 21:49:28 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] worker 26:
Jan 21 21:49:28 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]:  - config file:           /etc/openqa/workers.ini
Jan 21 21:49:28 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]:  - worker hostname:       openqa-x86-worker06.iad2.fedoraproject.org
Jan 21 21:49:28 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]:  - isotovideo version:    24
Jan 21 21:49:28 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]:  - websocket API version: 1
Jan 21 21:49:28 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]:  - web UI hosts:          http://openqa-lab01.iad2.fedoraproject.org
Jan 21 21:49:28 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]:  - class:                 ?
Jan 21 21:49:28 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]:  - no cleanup:            no
Jan 21 21:49:28 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]:  - pool directory:        /var/lib/openqa/pool/26
Jan 21 21:49:28 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Project dir for host http://openqa-lab01.iad2.fedoraproject.org is /var/lib/openqa/share
Jan 21 21:49:28 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 21:49:29 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 21:49:29 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 21:50:29 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 21:50:39 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 21:50:39 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 21:50:39 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 21:51:39 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 21:51:49 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 21:51:49 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 21:51:49 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 21:52:49 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 21:52:59 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 21:53:00 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 21:53:00 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 21:54:00 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 21:54:10 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 21:54:10 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 21:54:10 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 21:55:10 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 21:55:20 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 21:55:20 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 21:55:20 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 21:56:20 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 21:56:30 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 21:56:30 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 21:56:30 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 21:57:30 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 21:57:40 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 21:57:40 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 21:57:40 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 21:58:40 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 21:58:50 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 21:58:50 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 21:58:50 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 21:59:50 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 22:00:00 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 22:00:00 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 22:00:00 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 22:01:00 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 22:01:10 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 22:01:10 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 22:01:10 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 22:02:10 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 22:02:20 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 22:02:20 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 22:02:20 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321
Jan 21 22:03:20 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [warn] Websocket connection to http://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321 finished by remote side with code 1006, no reason - trying again in 10 seconds
Jan 21 22:03:30 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registering with openQA http://openqa-lab01.iad2.fedoraproject.org
Jan 21 22:03:30 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Establishing ws connection via ws://openqa-lab01.iad2.fedoraproject.org/api/v1/ws/321
Jan 21 22:03:30 openqa-x86-worker06.iad2.fedoraproject.org worker[19244]: [info] Registered and connected via websockets with openQA host http://openqa-lab01.iad2.fedoraproject.org and worker ID 321

...and so on and so on. It goes on apparently forever. At first I thought this meant something was wrong with the new workers, but then I went and checked other existing worker hosts that are working OK, and found the same pattern there. It seems to be happening on all of them. It doesn't stop jobs from running and working, but it's a lot of log spam and probably wasted work/network traffic.

I found a couple of existing closed issues that mention this code 1006 message, but they seemed to be associated with other problems that were then resolved. Couldn't find any report of just this kind of...eternal connection loop going on without the workers actually being apparently broken.

Actions

Also available in: Atom PDF