Project

General

Profile

Actions

action #167557

closed

openQA Project - coordination #110833: [saga][epic] Scale up: openQA can handle a schedule of 100k jobs with 1k worker instances

openQA Project - coordination #157669: websockets+scheduler improvements to support more online worker instances

OSD not starting new jobs on 2024-09-28 due to >1k worker instances connected, overloading websocket server

Added by okurz about 2 months ago. Updated about 2 months ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
Regressions/Crashes
Target version:
Start date:
2024-09-28
Due date:
% Done:

0%

Estimated time:

Description

Observation

https://openqa.suse.de/tests shows right now on 2024-09-28 11:07Z only 1 job running, 4k scheduled, no new are picked up for execution. https://openqa.suse.de/admin/workers shows that we have 1003 worker instances online which might lead to overload, see #110833.


Related issues 3 (0 open3 closed)

Related to openQA Infrastructure - action #167164: osd-deployment | Minions returned with non-zero exit code (qesapworker-prg5.qa.suse.cz) size:MResolvedybonatakis

Actions
Related to openQA Project - action #157690: Simple global limit of registered/online workers size:MResolvedmkittler2024-03-21

Actions
Related to openQA Infrastructure - action #157666: OSD unresponsive and then not starting any more jobs on 2024-03-21Resolvedokurz2024-03-12

Actions
Actions #1

Updated by okurz about 2 months ago

  • Related to action #167164: osd-deployment | Minions returned with non-zero exit code (qesapworker-prg5.qa.suse.cz) size:M added
Actions #2

Updated by okurz about 2 months ago ยท Edited

  • Status changed from New to In Progress

I removed qesapworker-prg5 from production per https://progress.opensuse.org/projects/openqav3/wiki/#Take-machines-out-of-salt-controlled-production as it's not fully usable right now anway, see #167164. This happened 2024-09-28 11:09Z. This reduced the number of OSD connected workers from 1005 to 979. Immediately afterwards OSD assigned jobs and by now 11:15Z 300+ jobs are running again. Corresponding excerpt from journalctl -u openqa-websockets:

Sep 28 11:09:17 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 3936 from worker_status (free)
Sep 28 11:09:17 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2714 from worker_status (free)
Sep 28 11:09:17 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 3517 from worker_status (free)
Sep 28 11:09:17 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 3042 from worker_status (free)
Sep 28 11:09:18 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2318 from worker_status (free)
Sep 28 11:09:18 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2592 from worker_status (free)
Sep 28 11:09:18 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2386 from worker_status (free)
Sep 28 11:09:18 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2838 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2766 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 3052 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 3101 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 3890 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 3866 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 3879 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2527 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2491 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2539 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2435 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2494 from worker_status (free)
Sep 28 11:09:19 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2409 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2436 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2441 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2430 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2438 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2434 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2432 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2428 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2444 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2445 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2411 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2705 from worker_status (free)
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2446 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 3377 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2443 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2413 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2419 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2415 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 3912 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3085 for job(s) 15550571
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3048 for job(s) 15550567
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 3214 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2421 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 3220 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2423 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2418 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3046 for job(s) 15550566
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2426 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3073 for job(s) 15550568
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 2554 for job(s) 15550487
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3008 for job(s) 15550572
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3436 for job(s) 15550485
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3941 for job(s) 15550486
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Finishing current connection of worker 2680 before accepting new one
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Finishing current connection of worker 2515 before accepting new one
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2680 websocket connection closed - 1008: only one connection per worker allowed, finishing old one in favor of new >
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Finishing current connection of worker 2515 before accepting new one
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 2575 for job(s) 15550344
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Finishing current connection of worker 2680 before accepting new one
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Finishing current connection of worker 2523 before accepting new one
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2515 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2680 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2515 websocket connection closed - 1008: only one connection per worker allowed, finishing old one in favor of new >
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2515 websocket connection closed - 1008: only one connection per worker allowed, finishing old one in favor of new >
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Finishing current connection of worker 2523 before accepting new one
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2680 websocket connection closed - 1008: only one connection per worker allowed, finishing old one in favor of new >
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2523 websocket connection closed - 1008: only one connection per worker allowed, finishing old one in favor of new >
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2523 websocket connection closed - 1008: only one connection per worker allowed, finishing old one in favor of new >
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 2781 for job(s) 15550441
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3337 for job(s) 15550483
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3021 for job(s) 15550614
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3211 for job(s) 15554186
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 2269 for job(s) 15550482
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3031 for job(s) 15550565
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 2386 for job(s) 15550480
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3054 for job(s) 15550521
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3030 for job(s) 15550522
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 2722 for job(s) 15550476
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 2714 for job(s) 15550488
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 3085 accepted job 15550571 which was never assigned to it or has already finished
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3076 for job(s) 15550615
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 2817 for job(s) 15550474
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 2823 for job(s) 15550479
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3920 for job(s) 15550440
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3036 for job(s) 15550616
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2523 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3103 for job(s) 15550478
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2355 from worker_status (free)
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3081 for job(s) 15550569
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3016 for job(s) 15550564
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2515 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2680 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3050 for job(s) 15550573
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2523 websocket connection closed - 1006
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 3073 accepted job 15550568 which was never assigned to it or has already finished
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 3046 accepted job 15550566 which was never assigned to it or has already finished
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2554 accepted job 15550487 which was never assigned to it or has already finished
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 3941 accepted job 15550486 which was never assigned to it or has already finished
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 3048 accepted job 15550567 which was never assigned to it or has already finished
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 3008 accepted job 15550572 which was never assigned to it or has already finished
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Started to send message to 3885 for job(s) 15550481
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Updating seen of worker 2560 from worker_status (free)
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Finishing current connection of worker 2680 before accepting new one
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Finishing current connection of worker 2680 before accepting new one
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Finishing current connection of worker 2523 before accepting new one
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 3436 accepted job 15550485 which was never assigned to it or has already finished
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Finishing current connection of worker 2523 before accepting new one
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [info] [pid:16245] Worker 2575 accepted job 15550344 which was never assigned to it or has already finished
Sep 28 11:09:20 openqa openqa-websockets-daemon[16245]: [debug] [pid:16245] Finishing current connection of worker 2515 before accepting new one

this supports my hypothesis that either exactly 1000 or roughly 1000 is the limit of connected worker instances we can handle.

Actions #3

Updated by okurz about 2 months ago

  • Related to action #157690: Simple global limit of registered/online workers size:M added
Actions #4

Updated by okurz about 2 months ago

  • Related to coordination #110833: [saga][epic] Scale up: openQA can handle a schedule of 100k jobs with 1k worker instances added
Actions #5

Updated by okurz about 2 months ago

  • Parent task set to #157669

osd /var/log/openqa_scheduler shows

[2024-09-28T09:46:26.771165Z] [debug] [pid:16244] Need to schedule 1 parallel jobs for job 15550716 (with priority 20)
[2024-09-28T09:46:26.771616Z] [debug] [pid:16244] Need to schedule 1 parallel jobs for job 15550717 (with priority 20)
[2024-09-28T09:46:26.772073Z] [debug] [pid:16244] Need to schedule 1 parallel jobs for job 15550718 (with priority 20)
[2024-09-28T09:46:26.772524Z] [debug] [pid:16244] Need to schedule 1 parallel jobs for job 15550719 (with priority 20)
[2024-09-28T09:46:26.772976Z] [debug] [pid:16244] Need to schedule 1 parallel jobs for job 15550720 (with priority 20)
[2024-09-28T09:46:26.773422Z] [debug] [pid:16244] limit reached, scheduling no additional jobs (max_running_jobs=330, free workers=1002, running=1, allocated=80)
[2024-09-28T09:46:26.787721Z] [debug] [pid:16244] Assigned job '15550667' to worker ID '3072'
[2024-09-28T09:46:26.789989Z] [debug] [pid:16244] [Job#15550667] Prepare for being processed by worker 3072
[2024-09-28T09:56:26.918355Z] [warn] [pid:16244] Failed to send data to websocket server, reason: Inactivity timeout at /usr/share/openqa/script/../lib/OpenQA/WebSockets/Client.pm line 27.

[2024-09-28T09:56:26.918691Z] [warn] [pid:16244] Failed sending job(s) '15550667' to worker '3072': unknown error
[2024-09-28T09:56:26.932848Z] [debug] [pid:16244] Job 15550667 reset to state scheduled
[2024-09-28T09:56:26.945697Z] [debug] [pid:16244] Assigned job '15550616' to worker ID '3062'
[2024-09-28T09:56:26.947618Z] [debug] [pid:16244] [Job#15550616] Prepare for being processed by worker 3062
[2024-09-28T10:06:27.081449Z] [warn] [pid:16244] Failed to send data to websocket server, reason: Inactivity timeout at /usr/share/openqa/script/../lib/OpenQA/WebSockets/Client.pm line 27.

[2024-09-28T10:06:27.082536Z] [warn] [pid:16244] Failed sending job(s) '15550616' to worker '3062': unknown error
[2024-09-28T10:06:27.106975Z] [debug] [pid:16244] Job 15550616 reset to state scheduled
[2024-09-28T10:06:27.133636Z] [debug] [pid:16244] Assigned job '15550317' to worker ID '3068'
[2024-09-28T10:06:27.136082Z] [debug] [pid:16244] [Job#15550317] Prepare for being processed by worker 3068
[2024-09-28T10:16:27.277087Z] [warn] [pid:16244] Failed to send data to websocket server, reason: Inactivity timeout at /usr/share/openqa/script/../lib/OpenQA/WebSockets/Client.pm line 27.

[2024-09-28T10:16:27.277639Z] [warn] [pid:16244] Failed sending job(s) '15550317' to worker '3068': unknown error
[2024-09-28T10:16:27.298113Z] [debug] [pid:16244] Job 15550317 reset to state scheduled
[2024-09-28T10:16:27.335952Z] [debug] [pid:16244] Assigned job '15550717' to worker ID '3069'
[2024-09-28T10:16:27.341500Z] [debug] [pid:16244] [Job#15550717] Prepare for being processed by worker 3069
[2024-09-28T10:26:27.475470Z] [warn] [pid:16244] Failed to send data to websocket server, reason: Inactivity timeout at /usr/share/openqa/script/../lib/OpenQA/WebSockets/Client.pm line 27.

[2024-09-28T10:26:27.475726Z] [warn] [pid:16244] Failed sending job(s) '15550717' to worker '3069': unknown error
[2024-09-28T10:26:27.485267Z] [debug] [pid:16244] Job 15550717 reset to state scheduled
[2024-09-28T10:26:27.497421Z] [debug] [pid:16244] Assigned job '15550449' to worker ID '2660'
[2024-09-28T10:26:27.499433Z] [debug] [pid:16244] [Job#15550449] Prepare for being processed by worker 2660
[2024-09-28T10:36:27.622352Z] [warn] [pid:16244] Failed to send data to websocket server, reason: Inactivity timeout at /usr/share/openqa/script/../lib/OpenQA/WebSockets/Client.pm line 27.

[2024-09-28T10:36:27.622673Z] [warn] [pid:16244] Failed sending job(s) '15550449' to worker '2660': unknown error
[2024-09-28T10:36:27.634833Z] [debug] [pid:16244] Job 15550449 reset to state scheduled
[2024-09-28T10:36:27.649323Z] [debug] [pid:16244] Assigned job '15550349' to worker ID '2620'
[2024-09-28T10:36:27.651384Z] [debug] [pid:16244] [Job#15550349] Prepare for being processed by worker 2620
[2024-09-28T10:46:27.773287Z] [warn] [pid:16244] Failed to send data to websocket server, reason: Inactivity timeout at /usr/share/openqa/script/../lib/OpenQA/WebSockets/Client.pm line 27.

[2024-09-28T10:46:27.773523Z] [warn] [pid:16244] Failed sending job(s) '15550349' to worker '2620': unknown error
[2024-09-28T10:46:27.785035Z] [debug] [pid:16244] Job 15550349 reset to state scheduled
[2024-09-28T10:46:27.797429Z] [debug] [pid:16244] Assigned job '15550392' to worker ID '2628'
[2024-09-28T10:46:27.799030Z] [debug] [pid:16244] [Job#15550392] Prepare for being processed by worker 2628
[2024-09-28T10:56:27.841382Z] [warn] [pid:16244] Failed to send data to websocket server, reason: Inactivity timeout at /usr/share/openqa/script/../lib/OpenQA/WebSockets/Client.pm line 27.

[2024-09-28T10:56:27.842875Z] [warn] [pid:16244] Failed sending job(s) '15550392' to worker '2628': unknown error
[2024-09-28T10:56:27.866284Z] [debug] [pid:16244] Job 15550392 reset to state scheduled
[2024-09-28T10:56:27.886514Z] [debug] [pid:16244] Assigned job '15550718' to worker ID '3054'
[2024-09-28T10:56:27.889053Z] [debug] [pid:16244] [Job#15550718] Prepare for being processed by worker 3054
[2024-09-28T11:06:28.033297Z] [warn] [pid:16244] Failed to send data to websocket server, reason: Inactivity timeout at /usr/share/openqa/script/../lib/OpenQA/WebSockets/Client.pm line 27.

[2024-09-28T11:06:28.033660Z] [warn] [pid:16244] Failed sending job(s) '15550718' to worker '3054': unknown error
[2024-09-28T11:06:28.047757Z] [debug] [pid:16244] Job 15550718 reset to state scheduled
[2024-09-28T11:06:28.061513Z] [debug] [pid:16244] Assigned job '15550622' to worker ID '3052'
[2024-09-28T11:06:28.063435Z] [debug] [pid:16244] [Job#15550622] Prepare for being processed by worker 3052
[2024-09-28T11:09:20.315302Z] [debug] [pid:16244] Sent job(s) '15550622' to worker '3052'
[2024-09-28T11:09:20.332848Z] [debug] [pid:16244] Assigned job '15550351' to worker ID '2618'
[2024-09-28T11:09:20.335120Z] [debug] [pid:16244] [Job#15550351] Prepare for being processed by worker 2618
[2024-09-28T11:09:20.438921Z] [debug] [pid:16244] Sent job(s) '15550351' to worker '2618'
[2024-09-28T11:09:20.455366Z] [debug] [pid:16244] Assigned job '15550623' to worker ID '3013'
[2024-09-28T11:09:20.457376Z] [debug] [pid:16244] [Job#15550623] Prepare for being processed by worker 3013

so multiple Failed to send data to websocket server, reason: Inactivity timeout at /usr/share/openqa/script/../lib/OpenQA/WebSockets/Client.pm line 27. until the situation resolved after my mitigations at 11:09Z. I scheduled #157690 on our backlog now but I wonder how we could treat those already detected warnings better.

Actions #6

Updated by okurz about 2 months ago

  • Due date set to 2024-10-12
  • Status changed from In Progress to Feedback
  • Priority changed from Urgent to Normal

Awaiting feedback from monitoring and the team over the next days

Actions #7

Updated by okurz about 2 months ago

  • Subject changed from OSD not starting new jobs on 2024-09-28 to OSD not starting new jobs on 2024-09-28 due to >1k worker instances connected, overloading websocket server
Actions #8

Updated by tinita about 2 months ago

  • Related to action #157666: OSD unresponsive and then not starting any more jobs on 2024-03-21 added
Actions #9

Updated by okurz about 2 months ago

  • Due date deleted (2024-10-12)
  • Status changed from Feedback to Resolved

We discussed this issue today and other team members have supported my hypothesis and improvement ideas in the related tickets. No further problems observed. Monitoring looks good as well.

Actions

Also available in: Atom PDF