search

ansible / awx

AWX provides a web-based user interface, REST API, and task engine built on top of Ansible. It is one of the upstream projects for Red Hat Ansible Automation Platform.
Other
14.06k stars 3.42k forks source link

Job Details Intermittently Missing Output lines #6534

Open grahamn-gr opened 4 years ago

grahamn-gr commented 4 years ago
ISSUE TYPE
SUMMARY

When checking the job output you can see that the job is sometimes missing lines

ENVIRONMENT
STEPS TO REPRODUCE

Run a job a few times and check output

EXPECTED RESULTS

Able to see all the lines

ACTUAL RESULTS

Sometimes lines don't appear;

image

ADDITIONAL INFORMATION
grahamn-gr commented 4 years ago

Can see here between lines 4 to 14 there are just three dots. If I click on the down arrow on line 4 it doesn't make any difference. If it download the log as a text file it shows the same problem

chrismeyersfsu commented 4 years ago

@grahamn-gr can you include any error output of awx_web and awx_task from the openshift container logs? I suspect awx is having trouble connecting to redis. This PR https://github.com/ansible/awx/pull/6542 might fix your issue.

grahamn-gr commented 4 years ago

Here's the logs from awx-task, at the point of starting the job and refreshing the screen to actually see output. That's another issue I've noticed the job output doesn't automatically scroll.

RESULT 2
OKREADY
2020-04-02 20:31:07,991 DEBUG    awx.main.dispatch task 4357d2fb-e80d-4baf-b9f5-53d339caa1c0 starting awx.main.scheduler.tasks.run_task_manager(*[])
2020-04-02 20:31:07,993 DEBUG    awx.main.scheduler Running Tower task manager.
2020-04-02 20:31:08,014 DEBUG    awx.main.scheduler Starting Scheduler
2020-04-02 20:31:13,987 DEBUG    awx.main.dispatch task 4df615e4-367a-4a34-915e-367e233f93b9 starting awx.main.tasks.update_inventory_computed_fields(*[69])
2020-04-02 20:31:14,009 DEBUG    awx.main.models.inventory Going to update inventory computed fields, pk=69
2020-04-02 20:31:14,029 DEBUG    awx.main.models.inventory Finished updating inventory computed fields, pk=69, in 0.019 seconds
2020-04-02 20:31:14,105 DEBUG    awx.main.dispatch task fa9d4567-513a-483c-8aa2-0f2f121acd90 starting awx.main.scheduler.tasks.run_task_manager(*[])
2020-04-02 20:31:14,105 DEBUG    awx.main.scheduler Running Tower task manager.
2020-04-02 20:31:14,124 DEBUG    awx.main.scheduler Starting Scheduler
2020-04-02 20:31:14,194 DEBUG    awx.main.scheduler Starting job 333 (pending) in group tower instance awx-0 (remaining_capacity=326)
2020-04-02 20:31:14,203 DEBUG    awx.main.scheduler Submitting job 333 (waiting) to <instance group, instance> <1,awx-0>.
2020-04-02 20:31:14,245 DEBUG    awx.main.scheduler job 333 (waiting) consumed 21 capacity units from tower with prior total of 0
2020-04-02 20:31:14,253 DEBUG    awx.main.models.mixins No credential configured to post back webhook status, skipping.
2020-04-02 20:31:14,268 DEBUG    awx.main.dispatch task 0c2fa257-af1f-42ec-adea-73d706b21d23 starting awx.main.tasks.RunJob(*[333])
2020-04-02 20:31:14,370 DEBUG    awx.main.models.mixins No credential configured to post back webhook status, skipping.
2020-04-02 20:31:14,397 DEBUG    awx.main.tasks Skipping project sync for job 333 (running) because commit is locally available
2020-04-02 20:31:15,308 DEBUG    awx.main.tasks Resource profiling not enabled for task
2020-04-02 20:31:16,189 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(4)
2020-04-02 20:31:16,189 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(4)
2020-04-02 20:31:16,242 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:16,242 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:16,642 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:16,642 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:16,669 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(7)
2020-04-02 20:31:16,669 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(7)
2020-04-02 20:31:16,719 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(9)
2020-04-02 20:31:16,719 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(9)
2020-04-02 20:31:16,767 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:16,767 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:16,885 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:16,885 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:16,890 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:16,890 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:16,895 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:16,895 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:17,377 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:17,377 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:17,381 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:17,381 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:17,510 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:17,510 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:17,514 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(4)
2020-04-02 20:31:17,514 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(4)
2020-04-02 20:31:17,514 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:17,514 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:17,729 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:17,729 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:17,738 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:17,738 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:17,752 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:17,752 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:17,903 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:17,903 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:17,940 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:17,940 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:17,946 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:17,946 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:18,014 DEBUG    awx.main.dispatch task 5adcfc59-dace-4f23-a683-939e97041ae8 starting awx.main.tasks.awx_periodic_scheduler(*[])
2020-04-02 20:31:18,029 DEBUG    awx.main.tasks Starting periodic scheduler
2020-04-02 20:31:18,031 DEBUG    awx.main.tasks Last scheduler run was: 2020-04-02 20:31:01.045756+00:00
2020-04-02 20:31:24,053 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,053 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,061 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:24,061 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:24,085 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:24,085 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:24,379 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:24,379 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:24,379 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,379 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,388 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:24,388 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:24,546 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,546 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,552 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,552 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,563 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:24,563 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:24,678 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,678 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,789 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,789 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,799 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:24,799 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:25,085 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(20)
2020-04-02 20:31:25,085 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(20)
2020-04-02 20:31:25,103 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(26)
2020-04-02 20:31:25,103 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(26)
2020-04-02 20:31:25,243 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:25,243 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:25,252 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(24)
2020-04-02 20:31:25,252 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(24)
2020-04-02 20:31:25,393 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(6)
2020-04-02 20:31:25,393 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(6)
2020-04-02 20:31:25,456 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(4)
2020-04-02 20:31:25,456 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(4)
2020-04-02 20:31:25,576 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(5)
2020-04-02 20:31:25,576 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(5)
2020-04-02 20:31:25,671 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(6)
2020-04-02 20:31:25,671 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(6)
2020-04-02 20:31:25,672 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:25,672 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:25,827 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:25,827 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:25,836 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:25,836 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:25,852 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:25,852 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(2)
2020-04-02 20:31:25,966 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:25,966 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:26,113 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:26,113 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:26,126 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:26,126 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:26,139 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:26,139 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:26,300 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:26,300 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(1)
2020-04-02 20:31:26,344 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:26,344 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(3)
2020-04-02 20:31:26,379 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(8)
2020-04-02 20:31:26,379 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(8)
2020-04-02 20:31:26,538 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(11)
2020-04-02 20:31:26,538 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(11)
2020-04-02 20:31:26,539 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(4)
2020-04-02 20:31:26,539 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(4)
2020-04-02 20:31:26,587 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(5)
2020-04-02 20:31:26,587 DEBUG    awx.main.commands.run_callback_receiver JobEvent.objects.bulk_create(5)
2020-04-02 20:31:26,597 DEBUG    awx.main.tasks job 333 (running) finished running, producing 285 events.
2020-04-02 20:31:26,631 INFO     awx.main.commands.run_callback_receiver Event processing is finished for Job 333, sending notifications
2020-04-02 20:31:26,631 INFO     awx.main.commands.run_callback_receiver Event processing is finished for Job 333, sending notifications
`background_callback` is deprecated and will be removed in 1.0, use `hooks` instead
2020-04-02 20:31:26,683 DEBUG    awx.main.dispatch task 0f2ad1d5-42f5-466f-b6c7-c85fba87fe10 starting awx.main.tasks.update_inventory_computed_fields(*[69])
2020-04-02 20:31:26,685 DEBUG    awx.main.models.mixins No credential configured to post back webhook status, skipping.
2020-04-02 20:31:26,701 DEBUG    awx.main.models.inventory Going to update inventory computed fields, pk=69
2020-04-02 20:31:26,716 DEBUG    awx.main.models.inventory Finished updating inventory computed fields, pk=69, in 0.014 seconds
2020-04-02 20:31:26,756 DEBUG    awx.main.dispatch task 0c2fa257-af1f-42ec-adea-73d706b21d23 starting awx.main.tasks.handle_work_success(*[])
2020-04-02 20:31:26,781 DEBUG    awx.main.dispatch task 3707cc93-b1c0-4970-a16e-ac425e6c7f25 starting awx.main.scheduler.tasks.run_task_manager(*[])
2020-04-02 20:31:26,783 DEBUG    awx.main.scheduler Running Tower task manager.
2020-04-02 20:31:26,803 DEBUG    awx.main.scheduler Starting Scheduler
2020-04-02 20:31:28,036 DEBUG    awx.main.dispatch task a45395d1-eadb-4fd7-ba4c-da1a49a74eec starting awx.main.scheduler.tasks.run_task_manager(*[])
2020-04-02 20:31:28,038 DEBUG    awx.main.scheduler Running Tower task manager.
2020-04-02 20:31:28,068 DEBUG    awx.main.scheduler Starting Scheduler

And here's awx-web

eq: 916/10130] 1.1.1.1 () {62 vars in 2821 bytes} [Thu Apr  2 20:34:47 2020] GET /api/v2/users/4/admin_of_organizations/ => generated 3110 bytes in 340 msecs (HTTP/1.1 200) 10 headers in 402 bytes (1 switches on core 0)
1.1.1.1 - - [02/Apr/2020:20:34:47 +0000] "GET /api/v2/users/4/admin_of_organizations/ HTTP/1.1" 200 3110 "https://awx/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.87 Safari/537.36" "127.0.0.1"
[pid: 109|app: 0|req: 867/10131] 1.1.1.1 () {64 vars in 2805 bytes} [Thu Apr  2 20:34:47 2020] OPTIONS /api/v2/unified_jobs/ => generated 10718 bytes in 339 msecs (HTTP/1.1 200) 10 headers in 403 bytes (1 switches on core 0)
1.1.1.1 - - [02/Apr/2020:20:34:47 +0000] "OPTIONS /api/v2/unified_jobs/ HTTP/1.1" 200 10718 "https://awx/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.87 Safari/537.36" "127.0.0.1"
[pid: 1045|app: 0|req: 818/10132] 1.1.1.1 () {62 vars in 2749 bytes} [Thu Apr  2 20:34:47 2020] GET /api/v2/config/ => generated 932 bytes in 598 msecs (HTTP/1.1 200) 10 headers in 415 bytes (1 switches on core 0)
1.1.1.1 - - [02/Apr/2020:20:34:47 +0000] "GET /api/v2/config/ HTTP/1.1" 200 932 "https://awx/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.87 Safari/537.36" "127.0.0.1"
[pid: 109|app: 0|req: 868/10133] 1.1.1.1 () {62 vars in 2749 bytes} [Thu Apr  2 20:34:48 2020] GET /api/v2/config/ => generated 932 bytes in 152 msecs (HTTP/1.1 200) 10 headers in 415 bytes (1 switches on core 0)
1.1.1.1 - - [02/Apr/2020:20:34:48 +0000] "GET /api/v2/config/ HTTP/1.1" 200 932 "https://awx/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.87 Safari/537.36" "127.0.0.1"
[pid: 1413|app: 0|req: 4/10134] 1.1.1.1 () {62 vars in 2755 bytes} [Thu Apr  2 20:34:47 2020] GET /api/v2/jobs/334/ => generated 7625 bytes in 257 msecs (HTTP/1.1 200) 10 headers in 410 bytes (1 switches on core 0)
1.1.1.1 - - [02/Apr/2020:20:34:48 +0000] "GET /api/v2/jobs/334/ HTTP/1.1" 200 7625 "https://awx/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.87 Safari/537.36" "127.0.0.1"
2020-04-02 20:34:48,276 DEBUG    awx.main.consumers Channel specific.ePaLnNMO!UgcYjGoyqPyp left groups set() and joined {'schedules-changed', 'jobs-status_changed', 'control-limit_reached_4'}
2020-04-02 20:34:48,276 DEBUG    Channel specific.ePaLnNMO!UgcYjGoyqPyp left groups set() and joined {'schedules-changed', 'jobs-status_changed', 'control-limit_reached_4'}
2020-04-02 20:34:48,447 DEBUG    awx.main.consumers Channel specific.ePaLnNMO!UgcYjGoyqPyp left groups {'schedules-changed'} and joined {'jobs-summary', 'job_events-334'}
2020-04-02 20:34:48,447 DEBUG    Channel specific.ePaLnNMO!UgcYjGoyqPyp left groups {'schedules-changed'} and joined {'jobs-summary', 'job_events-334'}
[pid: 932|app: 0|req: 917/10135] 1.1.1.1 () {62 vars in 2991 bytes} [Thu Apr  2 20:34:49 2020] GET /api/v2/jobs/334/job_events/?counter__gte=198&counter__lte=248&order_by=start_line&page_size=200 => generated 86701 bytes in 357 msecs (HTTP/1.1 200) 11 headers in 426 bytes (1 switches on core 0)
1.1.1.1 - - [02/Apr/2020:20:34:49 +0000] "GET /api/v2/jobs/334/job_events/?counter__gte=198&counter__lte=248&order_by=start_line&page_size=200 HTTP/1.1" 200 86701 "https://awx/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.87 Safari/537.36" "127.0.0.1"
RESULT 2
OKREADY
2020-04-02 20:35:33,917 DEBUG    awx.main.models.mixins No credential configured to post back webhook status, skipping.
2020-04-02 20:35:33,965 DEBUG    awx.main.utils.handlers Creating external log handler due to startup or settings change.
`background_callback` is deprecated and will be removed in 1.0, use `hooks` instead
[pid: 1413|app: 0|req: 10/10145] 1.1.1.1 () {68 vars in 2926 bytes} [Thu Apr  2 20:35:33 2020] POST /api/v2/jobs/334/relaunch/ => generated 3011 bytes in 376 msecs (HTTP/1.1 201) 11 headers in 442 bytes (1 switches on core 0)
1.1.1.1 - - [02/Apr/2020:20:35:33 +0000] "POST /api/v2/jobs/334/relaunch/ HTTP/1.1" 201 3011 "https://awx/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.87 Safari/537.36" "127.0.0.1"
2020-04-02 20:35:34,039 DEBUG    awx.main.consumers Channel specific.ePaLnNMO!UgcYjGoyqPyp left groups {'jobs-summary', 'job_events-334'} and joined {'schedules-changed'}
2020-04-02 20:35:34,039 DEBUG    Channel specific.ePaLnNMO!UgcYjGoyqPyp left groups {'jobs-summary', 'job_events-334'} and joined {'schedules-changed'}
[pid: 1413|app: 0|req: 11/10146] 1.1.1.1 () {62 vars in 2928 bytes} [Thu Apr  2 20:35:34 2020] GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&not__launch_type=sync => generated 46816 bytes in 480 msecs (HTTP/1.1 200) 10 headers in 403 bytes (1 switches on core 0)
1.1.1.1 - - [02/Apr/2020:20:35:34 +0000] "GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&not__launch_type=sync HTTP/1.1" 200 46816 "https://awx/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.87 Safari/537.36" "127.0.0.1"
2020-04-02 20:35:34,740 DEBUG    awx.main.consumers Channel specific.ePaLnNMO!UgcYjGoyqPyp left groups {'schedules-changed'} and joined {'jobs-summary', 'job_events-335'}
2020-04-02 20:35:34,740 DEBUG    Channel specific.ePaLnNMO!UgcYjGoyqPyp left groups {'schedules-changed'} and joined {'jobs-summary', 'job_events-335'}
1.1.1.1 - - [02/Apr/2020:20:35:34 +0000] "OPTIONS /api/v2/jobs/335/ HTTP/1.1" 200 11873 "https://awx/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.87 Safari/537.36" "127.0.0.1"
[pid: 1413|app: 0|req: 12/10147] 1.1.1.1 () {64 vars in 2793 bytes} [Thu Apr  2 20:35:34 2020] OPTIONS /api/v2/jobs/335/ => generated 11873 bytes in 201 msecs (HTTP/1.1 200) 10 headers in 411 bytes (1 switches on core 0)
grahamn-gr commented 4 years ago

I've applied #6542 to my installer and re-ran it, I see no change.

It looks to be the same file anyway:

@@ -175,7 +175,7 @@ spec:
             runAsUser: 999
           image: {{ kubernetes_redis_image }}:{{ kubernetes_redis_image_tag }}
           imagePullPolicy: IfNotPresent
-          args: ["/usr/local/etc/redis/redis.conf"]
+          args: ["{{ kubernetes_redis_config_mount_path }}"]

The var "kubernetes_redis_config_mount_path" = "/usr/local/etc/redis/redis.conf"

grahamn-gr commented 4 years ago

This still an issue for me. I applied the latest k8s installer from #6582 and I've updated my Chrome from an 78 version to Version 80.0.3987.122 (Official Build) (64-bit).

When I check stdout from the API I see no results for some of my jobs, this is reflected in the job details too.

image

chrismeyersfsu commented 4 years ago

I'm curious as to if your modifying any variables in the installer. What does your inventory file look like?

grahamn-gr commented 4 years ago

To be honest there are a few custom things, like we put our secrets in an ansible-vault rather than in the inventory, however the deployment and configmaps are pretty much in sync. Is there anything in particular you're thinking may cause this? I've noticed sometimes after a fresh install it works great, but then I had it as soon as I scaled the deployment to zero and back up again I got the issue.

ryanpetrello commented 4 years ago

@grahamn-gr we've just released a new version of AWX (11.0.0) that resolves a few issues we spotted related to the move to redis. I'm not certain that it will address your issue, but are you willing to try it out and report back?

Thanks!

tgates81 commented 4 years ago

I'm also experiencing this. It's always reproducible when observing the SCM revision not change after clicking update (though it really is when you click on job details or refresh the page). I noticed it in 9.2.0, currently on 11.2.0. This is a very helpful feature, would be nice to get this figured out. Please advise.

jsalatiel commented 3 years ago

Running awx 19.3.0 and missing output lines on job execution.

BartOpitz commented 3 months ago

Hi. Despite this being reported on 2020, this problem seems to come again and again even in 24.5.0 version. From what I have observed is - the underlying XHR API Call gets all events correctly, and those events include missing lines. However, JS that renders the view for some reason skips some lines from time to time. What is even worse - reloading the page (also clearing cookies) very often skips exactly the same lines.

The worst thing is - this behaviour is not 100% consistent. From time to time all lines are rendered correctly. Other times exactly the same lines are empty.

This often occurs for playbooks with strategy free, that run against hundreds of hosts and produce >10k lines of output. But those lines that get skipped are sometime some WARNING lines at the very beginning, sometimes task details in the middle of the output... the API calls deliver them however correctly (tested via developer tools in browser).