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
13.55k stars 3.35k forks source link

500 error after API call #7253

Closed therealrobopablo closed 3 years ago

therealrobopablo commented 3 years ago
ISSUE TYPE
SUMMARY

We started testing API calls to AWX via ServiceNow. Suddenly we're getting "Invalid search term entered. GET returned: 500 A server error has occurred." when viewing job info after it finishes. Job monitoring works fine while job is running. It seems to be not affecting jobs that fail. We've been using an external PSQL db

ENVIRONMENT
STEPS TO REPRODUCE

PErform API call to AWX, job completes and then check job history and click on job link

EXPECTED RESULTS

job run info displays

ACTUAL RESULTS

Invalid search term entered. GET returned: 500 A server error has occurred.

ADDITIONAL INFORMATION

awx_web tail 2020-06-04 15:09:43,523 ERROR django.request Internal Server Error: /api/v2/project_updates/27792/ Traceback (most recent call last): File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/exception.py", line 34, in inner response = get_response(request) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/base.py", line 115, in _get_response response = self.process_exception_by_middleware(e, request) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/base.py", line 113, in _get_response response = wrapped_callback(request, *callback_args, callback_kwargs) File "/usr/lib64/python3.6/contextlib.py", line 52, in inner return func(*args, *kwds) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view return view_func(args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/views/generic/base.py", line 71, in view return self.dispatch(request, *args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/generics.py", line 299, in dispatch return super(APIView, self).dispatch(request, *args, *kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 505, in dispatch response = self.handle_exception(exc) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 465, in handle_exception self.raise_uncaught_exception(exc) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 476, in raise_uncaught_exception raise exc File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 502, in dispatch response = handler(request, args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/generics.py", line 208, in get return self.retrieve(request, *args, **kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/mixins.py", line 56, in retrieve return Response(serializer.data) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 562, in data ret = super().data File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 260, in data self._data = self.to_representation(self.instance) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/serializers.py", line 802, in to_representation ret = super(UnifiedJobSerializer, self).to_representation(obj) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 529, in to_representation ret[field.field_name] = field.to_representation(attribute) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/fields.py", line 1905, in to_representation return method(value) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/serializers.py", line 1515, in get_host_status_counts counts = obj.project_update_events.only('event_data').get(event='playbook_on_stats').get_host_status_counts() File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/db/models/query.py", line 412, in get (self.model._meta.object_name, num) awx.main.models.events.ProjectUpdateEvent.MultipleObjectsReturned: get() returned more than one ProjectUpdateEvent -- it returned 3!

therealrobopablo commented 3 years ago

Displaying completed management jobs seem to be OK.

AlanCoding commented 3 years ago

Most likely case here is that the callback receiver saved 3 duplicates of the playbook_on_stats event for the job.

https://github.com/ansible/awx/blob/4b02e4ab57f22017c80b3c2b29feaa64da486d70/awx/api/serializers.py#L1517

Could you try to confirm or deny this by going to /api/v2/project_updates/27792/events/?event=playbook_on_stats in your browser?

therealrobopablo commented 3 years ago

Here;s the output on that. However I just realized this was maybe not the best example since it wasn't a workflow job, which is what's happening. I'll do the same with one that's more appropriate HTTP 200 OK Allow: GET, HEAD, OPTIONS Content-Type: application/json Vary: Accept X-API-Node: awx X-API-Product-Name: AWX X-API-Product-Version: 11.2.0 X-API-Time: 0.024s X-UI-Max-Events: 4000

{ "count": 3, "next": null, "previous": null, "results": [ { "id": 426721, "type": "project_update_event", "url": "", "related": { "project_update": "/api/v2/project_updates/27792/" }, "summary_fields": { "project_update": { "id": 27792, "name": "Yum_playbooks", "description": "", "status": "successful", "failed": false }, "role": {} }, "created": "2020-06-04T14:43:25.698014Z", "modified": "2020-06-04T14:43:25.804159Z", "event": "playbook_on_stats", "counter": 13, "event_display": "Playbook Complete", "event_data": { "playbook": "project_update.yml", "playbook_uuid": "a20f154e-aead-447a-bc67-016a1f8bdfb4", "changed": {}, "dark": {}, "failures": {}, "ignored": {}, "ok": { "localhost": 3 }, "processed": { "localhost": 1 }, "rescued": {}, "skipped": {}, "artifact_data": {}, "uuid": "70c75ac7-19e7-4051-8558-785f4dff565c" }, "event_level": 1, "failed": false, "changed": false, "uuid": "70c75ac7-19e7-4051-8558-785f4dff565c", "host_name": "localhost", "playbook": "project_update.yml", "play": "", "task": "", "role": "", "stdout": "\r\nPLAY RECAP \r\n\u001b[0;32mlocalhost\u001b[0m : \u001b[0;32mok=3 \u001b[0m changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 \r\n", "start_line": 15, "end_line": 19, "verbosity": 0, "project_update": 27792 }, { "id": 426724, "type": "project_update_event", "url": "", "related": { "project_update": "/api/v2/project_updates/27792/" }, "summary_fields": { "project_update": { "id": 27792, "name": "Yum_playbooks", "description": "", "status": "successful", "failed": false }, "role": {} }, "created": "2020-06-04T14:43:25.953059Z", "modified": "2020-06-04T14:43:26.058365Z", "event": "playbook_on_stats", "counter": 13, "event_display": "Playbook Complete", "event_data": { "playbook": "project_update.yml", "playbook_uuid": "30730e96-eeda-4d36-946d-fe67d421af3a", "changed": {}, "dark": {}, "failures": {}, "ignored": {}, "ok": { "localhost": 3 }, "processed": { "localhost": 1 }, "rescued": {}, "skipped": {}, "artifact_data": {}, "uuid": "36d53497-cda2-4a91-8a5a-ef6a9c72de51" }, "event_level": 1, "failed": false, "changed": false, "uuid": "36d53497-cda2-4a91-8a5a-ef6a9c72de51", "host_name": "localhost", "playbook": "project_update.yml", "play": "", "task": "", "role": "", "stdout": "\r\nPLAY RECAP \r\n\u001b[0;32mlocalhost\u001b[0m : \u001b[0;32mok=3 \u001b[0m changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 \r\n", "start_line": 15, "end_line": 19, "verbosity": 0, "project_update": 27792 }, { "id": 426737, "type": "project_update_event", "url": "", "related": { "project_update": "/api/v2/project_updates/27792/" }, "summary_fields": { "project_update": { "id": 27792, "name": "Yum_playbooks", "description": "", "status": "successful", "failed": false }, "role": {} }, "created": "2020-06-04T14:43:32.948684Z", "modified": "2020-06-04T14:43:33.069551Z", "event": "playbook_on_stats", "counter": 13, "event_display": "Playbook Complete", "event_data": { "playbook": "project_update.yml", "playbook_uuid": "a445b951-ea70-4df9-94b2-7611dcc77eea", "changed": {}, "dark": {}, "failures": {}, "ignored": {}, "ok": { "localhost": 3 }, "processed": { "localhost": 1 }, "rescued": {}, "skipped": {}, "artifact_data": {}, "uuid": "f8b2abf3-abb3-461c-a8b5-f62a1ea159bb" }, "event_level": 1, "failed": false, "changed": false, "uuid": "f8b2abf3-abb3-461c-a8b5-f62a1ea159bb", "host_name": "localhost", "playbook": "project_update.yml", "play": "", "task": "", "role": "", "stdout": "\r\nPLAY RECAP *****\r\n\u001b[0;32mlocalhost\u001b[0m : \u001b[0;32mok=3 \u001b[0m changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 \r\n", "start_line": 15, "end_line": 19, "verbosity": 0, "project_update": 27792 } ] }

AlanCoding commented 3 years ago

This information certainly raises my interest.

Do you have any more information about the structure of the API calls that caused this? Did they hit /api/v2/jobs/N/launch/? Are the other events duplicated too (if you take off the event=playbook_on_stats filter, do you see 3 of each)? Is there anything else you did that might be relevant for replicating this?

therealrobopablo commented 3 years ago

I've asked for a complete API call.

GET /api/v2/project_updates/27792/events/ HTTP 200 OK Allow: GET, HEAD, OPTIONS Content-Type: application/json Vary: Accept X-API-Node: awx X-API-Product-Name: AWX X-API-Product-Version: 11.2.0 X-API-Time: 0.044s X-UI-Max-Events: 4000

{ "name": "Project Update Events List", "description": "# List Project Update Events for a Project Update:\n\nMake a GET request to this resource to retrieve a list of\nproject update events associated with the selected\nproject update.\n\nThe resulting data structure contains:\n\n {\n \"count\": 99,\n \"next\": null,\n \"previous\": null,\n \"results\": [\n ...\n ]\n }\n\nThe count field indicates the total number of project update events\nfound for the given query. The next and previous fields provides links to\nadditional results if there are more than will fit on a single page. The\nresults list contains zero or more project update event records. \n\n## Results\n\nEach project update event data structure includes the following fields:\n\n id: Database ID for this project update event. (integer)\n type: Data type for this project update event. (choice)\n url: URL for this project update event. (string)\n related: Data structure with URLs of related resources. (object)\n summary_fields: Data structure with name/description for related resources. The output for some objects may be limited for performance reasons. (object)\n created: Timestamp when this project update event was created. (datetime)\n modified: Timestamp when this project update event was last modified. (datetime)\n event: (choice)\n - runner_on_failed: Host Failed\n - runner_on_start: Host Started\n - runner_on_ok: Host OK\n - runner_on_error: Host Failure\n - runner_on_skipped: Host Skipped\n - runner_on_unreachable: Host Unreachable\n - runner_on_no_hosts: No Hosts Remaining\n - runner_on_async_poll: Host Polling\n - runner_on_async_ok: Host Async OK\n - runner_on_async_failed: Host Async Failure\n - runner_item_on_ok: Item OK\n - runner_item_on_failed: Item Failed\n - runner_item_on_skipped: Item Skipped\n - runner_retry: Host Retry\n - runner_on_file_diff: File Difference\n - playbook_on_start: Playbook Started\n - playbook_on_notify: Running Handlers\n - playbook_on_include: Including File\n - playbook_on_no_hosts_matched: No Hosts Matched\n - playbook_on_no_hosts_remaining: No Hosts Remaining\n - playbook_on_task_start: Task Started\n - playbook_on_vars_prompt: Variables Prompted\n - playbook_on_setup: Gathering Facts\n - playbook_on_import_for_host: internal: on Import for Host\n - playbook_on_not_import_for_host: internal: on Not Import for Host\n - playbook_on_play_start: Play Started\n - playbook_on_stats: Playbook Complete\n - debug: Debug\n - verbose: Verbose\n - deprecated: Deprecated\n - warning: Warning\n - system_warning: System Warning\n - error: Error\n counter: (integer)\n event_display: (string)\n event_data: (json)\n event_level: (integer)\n failed: (boolean)\n changed: (boolean)\n uuid: (string)\n host_name: (field)\n playbook: (string)\n play: (string)\n task: (string)\n role: (string)\n stdout: (field)\n start_line: (integer)\n end_line: (integer)\n verbosity: (integer)\n project_update: (id)\n\n\n\n## Sorting\n\nTo specify that project update events are returned in a particular\norder, use the order_by query string parameter on the GET request.\n\n ?order_by=name\n\nPrefix the field name with a dash - to sort in reverse:\n\n ?order_by=-name\n\nMultiple sorting fields may be specified by separating the field names with a\ncomma ,:\n\n ?order_by=name,some_other_field\n\n## Pagination\n\nUse the page_size query string parameter to change the number of results\nreturned for each request. Use the page query string parameter to retrieve\na particular page of results.\n\n ?page_size=100&page=2\n\nThe previous and next links returned with the results will set these query\nstring parameters automatically.\n\n## Searching\n\nUse the search query string parameter to perform a case-insensitive search\nwithin all designated text fields of a model.\n\n ?search=findme\n\n(Added in Ansible Tower 3.1.0) Search across related fields:\n\n ?relatedsearch=findme\n\nNote: If you want to provide more than one search term, multiple\nsearch fields with the same key, like `?relatedsearch=foo&relatedsearch=bar,\nwill be ORed together. Terms separated by commas, like?relatedsearch=foo,bar\nwill be ANDed together.\n\n## Filtering\n\nAny additional query string parameters may be used to filter the list of\nresults returned to those matching a given value. Only fields and relations\nthat exist in the database may be used for filtering. Any special characters\nin the specified value should be url-encoded. For example:\n\n ?field=value%20xyz\n\nFields may also span relations, only for fields and relationships defined in\nthe database:\n\n ?other__field=value\n\nTo exclude results matching certain criteria, prefix the field parameter with\nnot`:\n\n ?notfield=value\n\nBy default, all query string filters are AND'ed together, so\nonly the results matching all filters will be returned. To combine results\nmatching any one of multiple criteria, prefix each query string parameter\nwith or__:\n\n ?orfield=value&orfield=othervalue\n ?ornotfield=value&orfield=othervalue\n\n(Added in Ansible Tower 1.4.5) The default AND filtering applies all filters\nsimultaneously to each related object being filtered across database\nrelationships. The chain filter instead applies filters separately for each\nrelated object. To use, prefix the query string parameter with `chain:\n\n ?chain__related__field=value&chain__related__field2=othervalue\n ?chain__not__related__field=value&chain__related__field2=othervalue\n\nIf the first query above were written as\n?relatedfield=value&relatedfield2=othervalue`, it would return only the\nprimary objects where the same related object satisfied both conditions. As\nwritten using the chain filter, it would return the intersection of primary\nobjects matching each condition.\n\nField lookups may also be used for more advanced queries, by appending the\nlookup to the field name:\n\n ?field__lookup=value\n\nThe following field lookups are supported:\n\n exact: Exact match (default lookup if not specified).\n iexact: Case-insensitive version of exact.\n contains: Field contains value.\n icontains: Case-insensitive version of contains.\n startswith: Field starts with value.\n istartswith: Case-insensitive version of startswith.\n endswith: Field ends with value.\n iendswith: Case-insensitive version of endswith.\n regex: Field matches the given regular expression.\n iregex: Case-insensitive version of regex.\n gt: Greater than comparison.\n gte: Greater than or equal to comparison.\n lt: Less than comparison.\n lte: Less than or equal to comparison.\n isnull: Check whether the given field or related object is null; expects a\n boolean value.\n in: Check whether the given field's value is present in the list provided;\n expects a list of items.\n\nBoolean values may be specified as True or 1 for true, False or 0 for\nfalse (both case-insensitive).\n\nNull values may be specified as None or Null (both case-insensitive),\nthough it is preferred to use the isnull lookup to explicitly check for null\nvalues.\n\nLists (for the in lookup) may be specified as a comma-separated list of\nvalues.\n\n(Added in Ansible Tower 3.1.0) Filtering based on the requesting user's\nlevel of access by query string parameter.\n\n role_level: Level of role to filter on, such as admin_role", "renders": [ "application/json", "text/html" ], "parses": [ "application/json" ], "actions": { "GET": { "id": { "type": "integer", "label": "ID", "help_text": "Database ID for this project update event.", "filterable": true }, "type": { "type": "choice", "label": "Type", "help_text": "Data type for this project update event.", "filterable": true, "choices": [ [ "project_update_event", "Project Update Event" ] ] }, "url": { "type": "string", "label": "Url", "help_text": "URL for this project update event.", "filterable": false }, "related": { "type": "object", "label": "Related", "help_text": "Data structure with URLs of related resources.", "filterable": false }, "summary_fields": { "type": "object", "label": "Summary fields", "help_text": "Data structure with name/description for related resources. The output for some objects may be limited for performance reasons.", "filterable": false }, "created": { "type": "datetime", "label": "Created", "help_text": "Timestamp when this project update event was created.", "filterable": true }, "modified": { "type": "datetime", "label": "Modified", "help_text": "Timestamp when this project update event was last modified.", "filterable": true }, "event": { "type": "choice", "label": "Event", "filterable": true, "choices": [ [ "runner_on_failed", "Host Failed" ], [ "runner_on_start", "Host Started" ], [ "runner_on_ok", "Host OK" ], [ "runner_on_error", "Host Failure" ], [ "runner_on_skipped", "Host Skipped" ], [ "runner_on_unreachable", "Host Unreachable" ], [ "runner_on_no_hosts", "No Hosts Remaining" ], [ "runner_on_async_poll", "Host Polling" ], [ "runner_on_async_ok", "Host Async OK" ], [ "runner_on_async_failed", "Host Async Failure" ], [ "runner_item_on_ok", "Item OK" ], [ "runner_item_on_failed", "Item Failed" ], [ "runner_item_on_skipped", "Item Skipped" ], [ "runner_retry", "Host Retry" ], [ "runner_on_file_diff", "File Difference" ], [ "playbook_on_start", "Playbook Started" ], [ "playbook_on_notify", "Running Handlers" ], [ "playbook_on_include", "Including File" ], [ "playbook_on_no_hosts_matched", "No Hosts Matched" ], [ "playbook_on_no_hosts_remaining", "No Hosts Remaining" ], [ "playbook_on_task_start", "Task Started" ], [ "playbook_on_vars_prompt", "Variables Prompted" ], [ "playbook_on_setup", "Gathering Facts" ], [ "playbook_on_import_for_host", "internal: on Import for Host" ], [ "playbook_on_not_import_for_host", "internal: on Not Import for Host" ], [ "playbook_on_play_start", "Play Started" ], [ "playbook_on_stats", "Playbook Complete" ], [ "debug", "Debug" ], [ "verbose", "Verbose" ], [ "deprecated", "Deprecated" ], [ "warning", "Warning" ], [ "system_warning", "System Warning" ], [ "error", "Error" ] ] }, "counter": { "type": "integer", "label": "Counter", "min_value": 0, "filterable": true }, "event_display": { "type": "string", "label": "Event display", "filterable": false }, "event_data": { "type": "json", "label": "Event data", "filterable": true }, "event_level": { "type": "integer", "label": "Event level", "filterable": false }, "failed": { "type": "boolean", "label": "Failed", "filterable": true }, "changed": { "type": "boolean", "label": "Changed", "filterable": true }, "uuid": { "type": "string", "label": "Uuid", "filterable": true }, "host_name": { "type": "field", "label": "Host name", "filterable": false }, "playbook": { "type": "string", "label": "Playbook", "filterable": true }, "play": { "type": "string", "label": "Play", "filterable": true }, "task": { "type": "string", "label": "Task", "filterable": true }, "role": { "type": "string", "label": "Role", "filterable": true }, "stdout": { "type": "field", "label": "Stdout", "filterable": true }, "start_line": { "type": "integer", "label": "Start line", "min_value": 0, "filterable": true }, "end_line": { "type": "integer", "label": "End line", "min_value": 0, "filterable": true }, "verbosity": { "type": "integer", "label": "Verbosity", "min_value": 0, "filterable": true }, "project_update": { "type": "id", "label": "Project update", "filterable": true } } }, "types": [ "project_update_event" ], "search_fields": [ "stdout" ], "related_search_fields": [ "project_update__search" ], "max_page_size": 200 }

therealrobopablo commented 3 years ago

Here's an API output of the workflow template and the resulting jobs: GET /api/v2/workflow_jobs/27807/ { "id": 27807, "type": "workflow_job", "url": "/api/v2/workflow_jobs/27807/", "related": { "created_by": "/api/v2/users/3/", "modified_by": "/api/v2/users/3/", "unified_job_template": "/api/v2/workflow_job_templates/71/", "workflow_job_template": "/api/v2/workflow_job_templates/71/", "notifications": "/api/v2/workflow_jobs/27807/notifications/", "workflow_nodes": "/api/v2/workflow_jobs/27807/workflow_nodes/", "labels": "/api/v2/workflow_jobs/27807/labels/", "activity_stream": "/api/v2/workflow_jobs/27807/activity_stream/", "relaunch": "/api/v2/workflow_jobs/27807/relaunch/", "cancel": "/api/v2/workflow_jobs/27807/cancel/" }, "summary_fields": { "organization": { "id": 2, "name": "HP", "description": "" }, "inventory": { "id": 29, "name": "Blank", "description": "", "has_active_failures": false, "total_hosts": 0, "hosts_with_active_failures": 0, "total_groups": 2, "has_inventory_sources": false, "total_inventory_sources": 0, "inventory_sources_with_failures": 0, "organization_id": 2, "kind": "" }, "workflow_job_template": { "id": 71, "name": "HPIT_AWX_Linux_Builds_Virtual", "description": "building linux VMs" }, "unified_job_template": { "id": 71, "name": "HPIT_AWX_Linux_Builds_Virtual", "description": "building linux VMs", "unified_job_type": "workflow_job" }, "created_by": { "id": 3, "username": "wilsonpa", "first_name": "Paul", "last_name": "Wilson" }, "modified_by": { "id": 3, "username": "wilsonpa", "first_name": "Paul", "last_name": "Wilson" }, "user_capabilities": { "delete": true, "start": true }, "labels": { "count": 0, "results": [] } }, "created": "2020-06-04T20:58:35.405189Z", "modified": "2020-06-04T20:58:36.149867Z", "name": "HPIT_AWX_Linux_Builds_Virtual", "description": "building linux VMs", "unified_job_template": 71, "launch_type": "relaunch", "status": "successful", "failed": false, "started": "2020-06-04T20:58:36.143345Z", "finished": "2020-06-04T21:04:08.327791Z", "canceled_on": null, "elapsed": 332.184, "job_args": "", "job_cwd": "", "job_env": {}, "job_explanation": "", "result_traceback": "", "workflow_job_template": 71, "extra_vars": "{\"hostname\": \"v790\", \"ip_address\": \"15.63.225.200\", \"location\": \"15.63.225.253\", \"resource_type\": \"virtual\", \"platform\": \"x86\", \"device_class\": \"linux\", \"operating_system\": \"centos_7\", \"cpu\": 2, \"memory\": 8192, \"storage\": [10, 10, 10, 10], \"resource_function\": \"Application Server\", \"functional_software\": \"\", \"clustering_services\": \"Service Guard Local\", \"network_segment\": \"VM Network\"}", "allow_simultaneous": false, "job_template": null, "is_sliced_job": false, "inventory": 29, "limit": null, "scm_branch": null, "webhook_service": "", "webhook_credential": null, "webhook_guid": "" }

When I try API calls to see the templates imitated by the workflow I get no results.

GET /api/v2/jobs/27810/ TTP 500 Internal Server Error Content-Type: application/json Vary: Accept

{ "detail": "A server error has occurred." }

but if I look at the database I see the attached.

image

It looks like this has maybe damaged the database, as well, since the 500 is also popping up on random job checks .

wenottingham commented 3 years ago

see also https://github.com/ansible/awx/issues/6982

therealrobopablo commented 3 years ago

see also #6982

I saw that when I was initially researching. It 'ed me down a good path, but didn't tell me a solid way to fix it. I'm not a DBA so monkeying with the DB is daunting...

therealrobopablo commented 3 years ago

Here's an example API POST command:

http://AWX_SERVER/api/v2/workflow_job_templates/71/launch/

{ "extra_vars": { "hostname":"testvm1000", "ip_address":"xxx.xxx.xxx.xxx", "location":"xxx.xxx.xxx.xxx", "resource_type":"virtual", "platform":"x86", "device_class":"linux", "operating_system":"rhel_7", "cpu":2, "memory":8192, "storage":[10, 10, 10], "resource_function":"application_server", "functional_software":"apache", "clustering_services":"service_guard_local", "network_segment":"VM Network" } }

there are 2 templates in the workflow, a VM build and then some package installs, post build. The workflow completes and I can click on the jobs tab and see the info there, but the templated jobs are the ones throwing a 500. But as I stated earlier it seems like the 500s also show up in other jobs like SCM update etc

AlanCoding commented 3 years ago

The workflow completes and I can click on the jobs tab and see the info there, but the templated jobs are the ones throwing a 500.

What do you mean by "templated jobs"? Jobs from job templates should show in the jobs list in the UI. Do you mean that you get the error when you click on the link for a specific job run?

therealrobopablo commented 3 years ago

What do you mean by "templated jobs"? Jobs from job templates should show in the jobs list in the UI. Do you mean that you get the error when you click on the link for a specific job run?

I click on the "JOBS" tab and click on the complete workflow job, it opens and shows job details. If I then click on the jobs associated with the workflow, it throws the 500 error. That also happens if I click the job itself on the Jobs tab. I'll add some screen shots.

The other weird thing is I can watch the jobs as they run. This only happens after completion. The jobs do complete though.

image

image

image

ryanpetrello commented 3 years ago

@therealrobopablo can you share a listing of your Docker containers e.g., docker ps -a ?

therealrobopablo commented 3 years ago

@ryanpetrello CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 21f2f2b15344 ansible/awx_task:11.0.0 "tini -- /bin/sh -c …" 2 months ago Up 2 weeks 8052/tcp awx_task c79af6843c31 ansible/awx_web:11.0.0 "tini -- /bin/sh -c …" 2 months ago Up 3 weeks 0.0.0.0:80->8052/tcp awx_web c836df808559 redis "docker-entrypoint.s…" 2 months ago Up 3 weeks 6379/tcp awx_redis 43d22f763f17 memcached:alpine "docker-entrypoint.s…" 2 months ago Up 3 weeks 11211/tcp awx_memcached

bouluad commented 3 years ago

me too, i have the same issue

chrismeyersfsu commented 3 years ago

@therealrobopablo AWX API responses are reporting version 11.2.0 X-API-Product-Version: 11.2.0 but your containers are 11.0.0

ryanpetrello commented 3 years ago

So one way I've been able to reproduce this:

image

...is by intentionally running multiple distinct awx-manage run_dispatcher processes in the task container (on top of what supervisord manages).

@therealrobopablo can you share ps -ef inside the awx_task container?

bouluad commented 3 years ago

If i can help, I have the same, this is the ps for my awx_task container :

sh-4.4# ps -ef UID PID PPID C STIME TTY TIME CMD root 1 0 0 12:12 ? 00:00:00 tini -- /bin/sh -c /usr/bin/launch_awx_task.sh root 6 1 0 12:12 ? 00:00:00 bash /usr/bin/launch_awx_task.sh root 98 6 0 12:12 ? 00:00:06 /usr/bin/python3.6 /usr/local/bin/supervisord -c /supervisor_task.conf root 101 98 0 12:12 ? 00:00:00 python3 /usr/bin/config-watcher root 102 98 0 12:12 ? 00:00:10 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher root 103 98 0 12:12 ? 00:00:03 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_callback_receiver root 114 102 0 12:13 ? 00:00:06 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher root 115 103 0 12:13 ? 00:00:42 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_callback_receiver root 116 103 0 12:13 ? 00:00:42 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_callback_receiver root 117 103 0 12:13 ? 00:00:42 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_callback_receiver root 118 103 0 12:13 ? 00:00:42 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_callback_receiver root 326 102 0 12:51 ? 00:00:11 [awx-manage] root 346 102 0 13:33 ? 00:00:15 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher root 389 102 0 13:58 ? 00:00:11 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher root 392 102 0 14:31 ? 00:00:07 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher root 395 102 0 14:36 ? 00:00:07 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher

ryanpetrello commented 3 years ago

@bouluad,

Are you seeing the error for all project updates you run (as in, are you able to run one right now, and see the error?)

bouluad commented 3 years ago

@ryanpetrello Yes for all project updates and also for all jobs; i have exactly the same error (by the UI) mentionned by @therealrobopablo

ryanpetrello commented 3 years ago

@bouluad what version of AWX are you running? You can find it under /api/v2/config/.

ryanpetrello commented 3 years ago

Also @bouluad,

Can you share with me the ps -ef of the web container?

Is there any way you'd be willing to find the ID (X) of a project update that shows the 500 error, and share with me the results of this command run inside the task or web container:

~ awx-manage dbshell
SELECT * FROM main_projectupdateevent WHERE project_update_id=X;
ryanpetrello commented 3 years ago

Possibilities I can think of here:

ryanpetrello commented 3 years ago

Also @bouluad,

Can you share the output of this command run inside the task container?

supervisorctl -c /etc/supervisord_task.conf status
ryanpetrello commented 3 years ago

Another thing that would be very useful to collect, would be:

  1. Go run docker logs -f awx_task
  2. a few times to get some empty room
  3. Launch a project update or job that's known to exhibit the 500 error
  4. Share the results of the docker logs command, it should look something like this:
2020-07-02 16:47:14,276 DEBUG    awx.main.dispatch task 06f679b6-66a7-4764-8b32-02c5d18725ad starting awx.main.scheduler.tasks.run_task_manager(*[])
2020-07-02 16:47:14,277 DEBUG    awx.main.scheduler Running Tower task manager.
2020-07-02 16:47:14,285 DEBUG    awx.main.scheduler Starting Scheduler
2020-07-02 16:47:14,347 DEBUG    awx.main.scheduler Starting project_update 6 (pending) in group tower instance awx (remaining_capacity=99)
2020-07-02 16:47:14,353 DEBUG    awx.main.scheduler Submitting project_update 6 (waiting) to <instance group, instance> <1,awx>.
2020-07-02 16:47:14,384 DEBUG    awx.main.scheduler project_update 6 (waiting) consumed 1 capacity units from tower with prior total of 0
2020-07-02 16:47:14,384 DEBUG    awx.main.scheduler Finishing Scheduler
2020-07-02 16:47:14,487 DEBUG    awx.main.dispatch task 0446c9a4-59e4-4d97-bff8-99e6c7651ac3 starting awx.main.tasks.RunProjectUpdate(*[6])
2020-07-02 16:47:15,865 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:15,865 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:15,882 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(2)
2020-07-02 16:47:15,882 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(2)
2020-07-02 16:47:15,885 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:15,885 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:16,754 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:16,754 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(2)
2020-07-02 16:47:16,754 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(2)
2020-07-02 16:47:16,754 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:16,994 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:16,994 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:16,995 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:16,995 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:16,996 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:16,996 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:17,222 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:17,222 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:17,226 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:17,226 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:17,230 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:17,230 DEBUG    awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-02 16:47:17,313 DEBUG    awx.main.tasks project_update 6 (running) finished running, producing 13 events.
2020-07-02 16:47:17,313 INFO     awx.main.commands.run_callback_receiver Event processing is finished for Job 6, sending notifications
2020-07-02 16:47:17,313 INFO     awx.main.commands.run_callback_receiver Event processing is finished for Job 6, sending notifications
2020-07-02 16:47:17,335 DEBUG    awx.main.dispatch task 66eab96d-0003-4de1-8744-4c496e495a91 starting awx.main.tasks.handle_success_and_failure_notifications(*[6])
2020-07-02 16:47:17,410 DEBUG    awx.main.dispatch task 0446c9a4-59e4-4d97-bff8-99e6c7651ac3 starting awx.main.tasks.handle_work_success(*[])
2020-07-02 16:47:17,417 DEBUG    awx.main.dispatch task 96272d25-ecfd-4a8a-b14c-bbb11904f661 starting awx.main.scheduler.tasks.run_task_manager(*[])
2020-07-02 16:47:17,418 DEBUG    awx.main.scheduler Running Tower task manager.
2020-07-02 16:47:17,426 DEBUG    awx.main.scheduler Starting Scheduler
2020-07-02 16:47:17,457 DEBUG    awx.main.scheduler Finishing Scheduler
ryanpetrello commented 3 years ago

@therealrobopablo or @bouluad

Either of you able to share any of this information so I can assist in troubleshooting?

pacificbreeze007 commented 3 years ago

@ryanpetrello I am running into the same issue..here are the requested logs. If you can assist, it would be greatly appreciate. Thanks.

An organization is already in the system, exiting. (changed: False) 2020-07-29 21:12:59,020 CRIT Supervisor is running as root. Privileges were not dropped because no user is specified in the config file. If you intend to run as root, you can set user=root in the config file to avoid this message. 2020-07-29 21:12:59,020 CRIT Supervisor is running as root. Privileges were not dropped because no user is specified in the config file. If you intend to run as root, you can set user=root in the config file to avoid this message. 2020-07-29 21:12:59,326 INFO RPC interface 'supervisor' initialized 2020-07-29 21:12:59,326 INFO RPC interface 'supervisor' initialized 2020-07-29 21:12:59,326 CRIT Server 'unix_http_server' running without any HTTP authentication checking 2020-07-29 21:12:59,326 CRIT Server 'unix_http_server' running without any HTTP authentication checking 2020-07-29 21:12:59,327 INFO supervisord started with pid 100 2020-07-29 21:12:59,327 INFO supervisord started with pid 100 2020-07-29 21:13:00,331 INFO spawned: 'awx-config-watcher' with pid 103 2020-07-29 21:13:00,331 INFO spawned: 'awx-config-watcher' with pid 103 2020-07-29 21:13:00,334 INFO spawned: 'dispatcher' with pid 104 2020-07-29 21:13:00,334 INFO spawned: 'dispatcher' with pid 104 2020-07-29 21:13:00,337 INFO spawned: 'callback-receiver' with pid 105 2020-07-29 21:13:00,337 INFO spawned: 'callback-receiver' with pid 105 READY 2020-07-29 21:13:01,507 INFO success: awx-config-watcher entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) 2020-07-29 21:13:01,507 INFO success: awx-config-watcher entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) 2020-07-29 21:13:01,507 INFO success: dispatcher entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) 2020-07-29 21:13:01,507 INFO success: dispatcher entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) 2020-07-29 21:13:01,507 INFO success: callback-receiver entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) 2020-07-29 21:13:01,507 INFO success: callback-receiver entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) 2020-07-29 21:13:04,080 WARNING awx.main.dispatch.periodic periodic beat started 2020-07-29 21:13:04,096 WARNING awx.main.commands.run_callback_receiver scaling up worker pid:117 2020-07-29 21:13:04,096 WARNING awx.main.commands.run_callback_receiver scaling up worker pid:117 2020-07-29 21:13:04,106 WARNING awx.main.commands.run_callback_receiver scaling up worker pid:118 2020-07-29 21:13:04,106 WARNING awx.main.commands.run_callback_receiver scaling up worker pid:118 2020-07-29 21:13:04,117 WARNING awx.main.commands.run_callback_receiver scaling up worker pid:119 2020-07-29 21:13:04,117 WARNING awx.main.commands.run_callback_receiver scaling up worker pid:119 2020-07-29 21:13:04,128 WARNING awx.main.commands.run_callback_receiver scaling up worker pid:120 2020-07-29 21:13:04,128 WARNING awx.main.commands.run_callback_receiver scaling up worker pid:120 2020-07-29 21:13:04,172 WARNING awx.main.dispatch scaling up worker pid:121 2020-07-29 21:13:04,184 WARNING awx.main.dispatch scaling up worker pid:122 2020-07-29 21:13:04,195 WARNING awx.main.dispatch scaling up worker pid:123 2020-07-29 21:13:04,206 WARNING awx.main.dispatch scaling up worker pid:124 2020-07-29 21:13:04,211 WARNING awx.main.dispatch Running worker dispatcher listening to queues ['tower_broadcast_all', 'awx'] 2020-07-29 21:13:04,238 DEBUG awx.main.tasks Syncing Schedules 2020-07-29 21:13:04,288 DEBUG awx.main.tasks Waited 0.0030219554901123047 seconds to obtain lock name: cluster_policy_lock 2020-07-29 21:13:04,321 DEBUG awx.main.tasks Total non-isolated instances:1 available for policy: 1 2020-07-29 21:13:04,322 DEBUG awx.main.tasks Policy percentage, adding Instances [1] to Group tower 2020-07-29 21:13:04,323 DEBUG awx.main.tasks Cluster policy no-op finished in 0.03194689750671387 seconds 2020-07-29 21:13:04,324 DEBUG awx.main.tasks Cluster node heartbeat task. 2020-07-29 21:13:04,384 DEBUG awx.main.utils.reload Issuing command to restart services, args=['supervisorctl', '-c', '/etc/supervisord.conf', 'restart', 'tower-processes:awx-rsyslogd'] 2020-07-29 21:13:05,710 DEBUG awx.main.utils.reload supervisorctl restart awx-rsyslogd succeeded 2020-07-29 21:13:08,062 DEBUG awx.main.dispatch task 88362322-09be-4964-bf9f-141d69e5a28f starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:13:08,087 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:13:08,381 DEBUG awx.main.dispatch task 07c30b0f-8268-4ca1-9b2e-988112192018 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:08,385 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:08,432 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:13:18,086 DEBUG awx.main.dispatch task cd82be23-b600-4c9d-8187-0db9c1c12d2f starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:18,088 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:18,147 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:13:24,138 DEBUG awx.main.dispatch task cfe9a8d4-9cbe-4d3b-9c2d-722a2ae77e3b starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:24,142 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:24,187 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:13:28,443 DEBUG awx.main.dispatch task f2c7c5a1-7bcb-4569-9750-ef5e8d60bffc starting awx.main.tasks.cluster_node_heartbeat([]) 2020-07-29 21:13:28,447 DEBUG awx.main.tasks Cluster node heartbeat task. 2020-07-29 21:13:28,448 DEBUG awx.main.dispatch task c3550a50-f3d4-48f0-bdc1-87b1a605883c starting awx.main.tasks.awx_k8s_reaper([]) 2020-07-29 21:13:28,457 DEBUG awx.main.dispatch task b71ab8f6-a3d7-4c03-b7ac-78e071d2e684 starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:13:28,483 DEBUG awx.main.dispatch task bb8bd1d2-b677-405f-ae4e-1b893603e19a starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:28,485 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:28,512 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:13:28,538 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:13:34,169 DEBUG awx.main.dispatch task 77247630-fdf6-4c99-ba52-fb8a5496ad20 starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:13:34,189 DEBUG awx.main.tasks Starting periodic scheduler 2020-07-29 21:13:34,193 DEBUG awx.main.tasks Last scheduler run was: 2020-07-29 21:13:28.510282+00:00 2020-07-29 21:13:38,142 DEBUG awx.main.dispatch task 100009a8-38bb-4d30-b86f-f944ff6e4f3e starting awx.main.tasks.cluster_node_heartbeat([]) 2020-07-29 21:13:38,144 DEBUG awx.main.tasks Cluster node heartbeat task. 2020-07-29 21:13:38,168 DEBUG awx.main.dispatch task 615c14e6-6514-44d3-8ea5-8493fef0d354 starting awx.main.tasks.awx_k8s_reaper([]) 2020-07-29 21:13:38,216 DEBUG awx.main.dispatch task 0ecc98cb-14d5-4479-9884-72736242d7cb starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:13:38,239 DEBUG awx.main.dispatch task e72c1503-bed8-4521-bdce-6a98fedf0d4b starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:38,240 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:38,259 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:13:38,285 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:13:44,192 DEBUG awx.main.dispatch task 3bd487f9-cc80-4edd-847c-08bee29c3d6c starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:44,226 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:44,241 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:13:48,514 DEBUG awx.main.dispatch task 6f068f04-a13c-4875-a13a-6abc0e8f3789 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:48,516 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:48,550 DEBUG awx.main.scheduler Starting Scheduler 2020-07-29 21:13:48,600 DEBUG awx.main.scheduler Finishing Scheduler 2020-07-29 21:13:50,992 DEBUG awx.main.dispatch task 96e94b72-7585-4e0d-8ec9-7edd1f9bef82 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:50,995 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:51,025 DEBUG awx.main.scheduler Starting Scheduler 2020-07-29 21:13:51,158 DEBUG awx.main.scheduler Starting project_update 19 (pending) in group tower instance awx (remaining_capacity=57) 2020-07-29 21:13:51,171 DEBUG awx.main.scheduler Submitting project_update 19 (waiting) to <instance group, instance> <1,awx>. 2020-07-29 21:13:51,226 DEBUG awx.main.scheduler project_update 19 (waiting) consumed 1 capacity units from tower with prior total of 0 2020-07-29 21:13:51,228 DEBUG awx.main.scheduler Finishing Scheduler 2020-07-29 21:13:51,401 DEBUG awx.main.dispatch task d88e6d70-8fc5-45a8-bae3-a14d2b217081 starting awx.main.tasks.RunProjectUpdate([19]) 2020-07-29 21:13:53,947 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1) 2020-07-29 21:13:53,947 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1) 2020-07-29 21:13:53,970 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(3) 2020-07-29 21:13:53,970 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(3) 2020-07-29 21:13:54,895 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1) 2020-07-29 21:13:54,895 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1) 2020-07-29 21:13:54,897 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1) 2020-07-29 21:13:54,897 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1) 2020-07-29 21:13:55,051 DEBUG awx.main.tasks project_update 19 (running) finished running, producing 6 events. 2020-07-29 21:13:55,052 INFO awx.main.commands.run_callback_receiver Event processing is finished for Job 19, sending notifications 2020-07-29 21:13:55,052 INFO awx.main.commands.run_callback_receiver Event processing is finished for Job 19, sending notifications 2020-07-29 21:13:55,118 DEBUG awx.main.dispatch task 41f62e83-b8b1-4a0f-b7c2-e55a272f67f9 starting awx.main.tasks.handle_success_and_failure_notifications([19]) 2020-07-29 21:13:55,202 WARNING awx.main.dispatch project_update 19 (failed) encountered an error (rc=2), please see task stdout for details. 2020-07-29 21:13:55,204 DEBUG awx.main.dispatch task d88e6d70-8fc5-45a8-bae3-a14d2b217081 starting awx.main.tasks.handle_work_error(['d88e6d70-8fc5-45a8-bae3-a14d2b217081']) 2020-07-29 21:13:55,205 DEBUG awx.main.tasks Executing error task id d88e6d70-8fc5-45a8-bae3-a14d2b217081, subtasks: [{'type': 'project_update', 'id': 19}] 2020-07-29 21:13:55,226 DEBUG awx.main.dispatch task d88e6d70-8fc5-45a8-bae3-a14d2b217081 starting awx.main.tasks.handle_work_success([]) 2020-07-29 21:13:55,227 DEBUG awx.main.dispatch task d9bf4693-e22d-48e2-96e5-4e1383c1c31c starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:55,229 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:55,257 DEBUG awx.main.dispatch task 89bb92c3-0bba-43a7-9e22-b90910340096 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:55,259 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:55,269 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:13:55,302 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:13:55,336 DEBUG awx.main.dispatch task abea0d9a-06a1-479d-b3e6-5759c2d98b73 starting awx.main.tasks.handle_success_and_failure_notifications([19]) 2020-07-29 21:13:55,381 DEBUG awx.main.dispatch task a7891bb1-13a4-45fe-9cde-7f866ce350ca starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:55,383 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:55,411 DEBUG awx.main.dispatch task 4f022522-2563-4682-8533-8eeca9167d61 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:55,412 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:55,422 DEBUG awx.main.scheduler Starting Scheduler 2020-07-29 21:13:55,443 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:13:55,459 DEBUG awx.main.scheduler Finishing Scheduler 2020-07-29 21:13:56,904 DEBUG awx.main.dispatch task 4dd810b9-cecf-4a38-b57f-ff8290a4558f starting awx.main.tasks.handle_success_and_failure_notifications([19]) 2020-07-29 21:13:56,951 DEBUG awx.main.dispatch task 5ce31758-cad0-434f-a2b1-1ae0279c8ea5 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:56,953 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:56,976 DEBUG awx.main.dispatch task 9f04857d-a510-4b5f-b39f-8117c0020a86 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:56,978 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:57,004 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:13:57,019 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:13:58,277 DEBUG awx.main.dispatch task 299c6b15-4948-4db8-9a19-4d05168e7723 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:13:58,279 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:13:58,305 DEBUG awx.main.scheduler Starting Scheduler 2020-07-29 21:13:58,348 DEBUG awx.main.scheduler Finishing Scheduler 2020-07-29 21:13:58,539 DEBUG awx.main.dispatch task 69a6ec7e-1ec3-406d-80e8-fb75da715359 starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:13:58,560 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock RESULT 2 OKREADY 2020-07-29 21:14:04,253 DEBUG awx.main.dispatch task a4431e8b-e536-43e3-8e61-740df9d4a659 starting awx.main.tasks.cluster_node_heartbeat([]) 2020-07-29 21:14:04,255 DEBUG awx.main.tasks Cluster node heartbeat task. 2020-07-29 21:14:04,255 DEBUG awx.main.dispatch task 6df3fc00-2b53-4d8a-9533-857cfd4b63a4 starting awx.main.tasks.awx_k8s_reaper([]) 2020-07-29 21:14:04,286 DEBUG awx.main.dispatch task 20af9c82-0291-4bb6-b8f1-5b82089147cd starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:14:04,328 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:14:04,329 DEBUG awx.main.dispatch task b4a91d62-96a1-4fbb-addb-3ceaddb98955 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:14:04,332 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:14:04,375 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:14:08,302 DEBUG awx.main.dispatch task 4fe2b745-6af0-48d4-bdd9-23370ebacc0e starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:14:08,326 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:14:08,567 DEBUG awx.main.dispatch task 86706952-1c37-4b43-b8fe-83e98860793d starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:14:08,569 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:14:08,611 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:14:18,331 DEBUG awx.main.dispatch task 26d3e2ef-f1bd-4b62-bfc1-14e4931b48a9 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:14:18,334 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:14:18,364 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:14:24,353 DEBUG awx.main.dispatch task f3681830-3265-4c80-988f-1b79f414db69 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:14:24,355 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:14:24,389 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:14:28,622 DEBUG awx.main.dispatch task 8eb2ef9a-34bb-48de-898c-836df49ee12b starting awx.main.tasks.cluster_node_heartbeat([]) 2020-07-29 21:14:28,624 DEBUG awx.main.tasks Cluster node heartbeat task. 2020-07-29 21:14:28,629 DEBUG awx.main.dispatch task f166f8cf-025d-4efa-83e9-03fa68ac182a starting awx.main.tasks.awx_k8s_reaper([]) 2020-07-29 21:14:28,666 DEBUG awx.main.dispatch task 5e9b8045-df09-4cd0-b18e-e606b8ff1d66 starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:14:28,702 DEBUG awx.main.dispatch task 13797116-2ddd-4e37-aaef-c14a14eb47cf starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:14:28,704 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:14:28,717 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:14:28,743 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:14:34,383 DEBUG awx.main.dispatch task 494581ee-408e-459a-aaa0-43305a598dac starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:14:34,405 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:14:38,367 DEBUG awx.main.dispatch task fda5127d-4d97-4ad1-98d6-f970ae1615f7 starting awx.main.tasks.cluster_node_heartbeat([]) 2020-07-29 21:14:38,369 DEBUG awx.main.tasks Cluster node heartbeat task. 2020-07-29 21:14:38,379 DEBUG awx.main.dispatch task a25795ee-5d50-464d-8a45-afe66f7efc3a starting awx.main.tasks.awx_k8s_reaper([]) 2020-07-29 21:14:38,407 DEBUG awx.main.dispatch task b34759af-e932-4b02-ab61-06d3a59fc30e starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:14:38,437 DEBUG awx.main.dispatch task 740ef2ae-8265-4f2f-9ca2-549f919eb44b starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:14:38,439 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:14:38,459 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:14:38,475 DEBUG awx.main.scheduler Starting Scheduler 2020-07-29 21:14:38,525 DEBUG awx.main.scheduler Finishing Scheduler 2020-07-29 21:14:44,416 DEBUG awx.main.dispatch task 31119318-e56e-4dd0-818c-c77988711260 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:14:44,418 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:14:44,444 DEBUG awx.main.scheduler Starting Scheduler 2020-07-29 21:14:44,489 DEBUG awx.main.scheduler Finishing Scheduler 2020-07-29 21:14:48,736 DEBUG awx.main.dispatch task 2fd9e8b7-5968-4925-ba76-dc535cd852ca starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:14:48,771 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:14:48,782 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:14:58,473 DEBUG awx.main.dispatch task b5e114ef-fabb-43a2-9f71-ccc18e02a04d starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:14:58,475 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:14:58,520 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:14:58,780 DEBUG awx.main.dispatch task e7f2c4fb-5def-444b-b543-1df8fefbb76b starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:14:58,809 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock RESULT 2 OKREADY 2020-07-29 21:15:04,468 DEBUG awx.main.dispatch task 9e6bb15f-c767-4021-b294-d4a144de0917 starting awx.main.tasks.cluster_node_heartbeat([]) 2020-07-29 21:15:04,470 DEBUG awx.main.tasks Cluster node heartbeat task. 2020-07-29 21:15:04,481 DEBUG awx.main.dispatch task d2f0f377-396e-4fd7-a19a-079ed1176b69 starting awx.main.tasks.awx_k8s_reaper([]) 2020-07-29 21:15:04,518 DEBUG awx.main.dispatch task 1a65bd9e-e43b-49fb-8bf4-61825f63231f starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:15:04,560 DEBUG awx.main.dispatch task 2e8d2727-1ae9-45d2-a9ba-68bbebb949e3 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:15:04,562 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:15:04,570 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:15:04,602 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:15:08,501 DEBUG awx.main.dispatch task fc6ceb7e-278f-4fad-8d6e-9c0892735ee9 starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:15:08,531 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:15:08,805 DEBUG awx.main.dispatch task fc7c68e8-2944-4545-b840-a0204de79752 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:15:08,807 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:15:08,842 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:15:18,527 DEBUG awx.main.dispatch task 028722b1-573d-424e-a44f-d2abdee23652 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:15:18,528 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:15:18,557 DEBUG awx.main.scheduler Starting Scheduler 2020-07-29 21:15:18,607 DEBUG awx.main.scheduler Finishing Scheduler 2020-07-29 21:15:24,595 DEBUG awx.main.dispatch task bb49a863-e8d2-4209-a9c8-b3c78c8517d2 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:15:24,597 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:15:24,627 DEBUG awx.main.scheduler Starting Scheduler 2020-07-29 21:15:24,657 DEBUG awx.main.scheduler Finishing Scheduler 2020-07-29 21:15:28,850 DEBUG awx.main.dispatch task 67c0e1f9-d1bb-464b-9a1d-ef9cc47c4bd1 starting awx.main.tasks.cluster_node_heartbeat([]) 2020-07-29 21:15:28,853 DEBUG awx.main.tasks Cluster node heartbeat task. 2020-07-29 21:15:28,860 DEBUG awx.main.dispatch task fe8bbd56-e5ad-4772-a3de-8cbc1781fd52 starting awx.main.tasks.awx_k8s_reaper([]) 2020-07-29 21:15:28,888 DEBUG awx.main.dispatch task 81b78e92-1a6a-44f2-a70e-036a6fe29a74 starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:15:28,910 DEBUG awx.main.dispatch task 202bcb85-8426-4e35-af8b-131aa03fba98 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:15:28,911 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:15:28,911 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:15:28,957 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:15:34,615 DEBUG awx.main.dispatch task 10fcbfc5-8e68-4c35-96c5-b5cd7f8db0f2 starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:15:34,644 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:15:38,572 DEBUG awx.main.dispatch task 9d1172d2-8833-4646-ab06-048fe25a546a starting awx.main.tasks.cluster_node_heartbeat([]) 2020-07-29 21:15:38,574 DEBUG awx.main.tasks Cluster node heartbeat task. 2020-07-29 21:15:38,582 DEBUG awx.main.dispatch task 56a1c2ad-bcaf-405e-b58d-8021abb52d53 starting awx.main.tasks.awx_k8s_reaper([]) 2020-07-29 21:15:38,606 DEBUG awx.main.dispatch task adc8c07d-ab11-4ad4-a5e9-e41abfb3ade6 starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:15:38,637 DEBUG awx.main.dispatch task 4024d461-ddc6-4f28-948d-65f08519efa7 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:15:38,638 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:15:38,642 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:15:38,667 DEBUG awx.main.scheduler Starting Scheduler 2020-07-29 21:15:38,702 DEBUG awx.main.scheduler Finishing Scheduler 2020-07-29 21:15:44,648 DEBUG awx.main.dispatch task 4ff8852b-8938-44e1-a889-88f64ccfc8cd starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:15:44,649 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:15:44,678 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:15:48,937 DEBUG awx.main.dispatch task 24b24f9a-fa41-48a0-abc2-2edef66be8c1 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:15:48,941 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:15:48,971 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:15:58,664 DEBUG awx.main.dispatch task 87a2c2a4-7d31-47e8-beda-1f6fd045dea5 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:15:58,665 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:15:58,693 DEBUG awx.main.scheduler Starting Scheduler 2020-07-29 21:15:58,728 DEBUG awx.main.scheduler Finishing Scheduler 2020-07-29 21:15:58,960 DEBUG awx.main.dispatch task ff2d4831-4d55-458f-8e93-a3df0d0e2f50 starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:15:58,979 DEBUG awx.main.tasks Starting periodic scheduler 2020-07-29 21:15:58,984 DEBUG awx.main.tasks Last scheduler run was: 2020-07-29 21:15:38.656345+00:00 RESULT 2 OKREADY 2020-07-29 21:16:04,683 DEBUG awx.main.dispatch task 424f7098-7406-42db-b320-4c03fb0cb834 starting awx.main.tasks.cluster_node_heartbeat([]) 2020-07-29 21:16:04,685 DEBUG awx.main.tasks Cluster node heartbeat task. 2020-07-29 21:16:04,691 DEBUG awx.main.dispatch task c7268d13-4d5b-497d-b4b6-61048d066ef8 starting awx.main.tasks.awx_k8s_reaper([]) 2020-07-29 21:16:04,743 DEBUG awx.main.dispatch task 8e879ed2-09ec-4ac4-aefa-bbf446c8d57e starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:16:04,781 DEBUG awx.main.tasks Starting periodic scheduler 2020-07-29 21:16:04,783 DEBUG awx.main.dispatch task bd43c6b6-3958-49c2-89a9-d74af729d989 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:16:04,785 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:16:04,803 DEBUG awx.main.tasks Last scheduler run was: 2020-07-29 21:15:58.981240+00:00 2020-07-29 21:16:04,834 DEBUG awx.main.scheduler Starting Scheduler 2020-07-29 21:16:04,871 DEBUG awx.main.scheduler Finishing Scheduler 2020-07-29 21:16:08,693 DEBUG awx.main.dispatch task 53e86a67-d3c5-42a2-8bb2-c0a05ff4116b starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:16:08,712 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:16:08,982 DEBUG awx.main.dispatch task 6bd373b3-901a-4cbc-86ee-33442c1c71c7 starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:16:08,984 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:16:09,018 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:16:18,705 DEBUG awx.main.dispatch task a437c39a-3856-4fef-8fc9-29851e59a2dd starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:16:18,707 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:16:18,745 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:16:24,816 DEBUG awx.main.dispatch task 519de237-d9ad-4e43-8bac-3a71b339c77d starting awx.main.scheduler.tasks.run_task_manager([]) 2020-07-29 21:16:24,818 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:16:24,853 DEBUG awx.main.scheduler Not running scheduler, another task holds lock 2020-07-29 21:16:29,014 DEBUG awx.main.dispatch task 53d8d12e-a3dd-4287-bf43-f438c21312db starting awx.main.tasks.gather_analytics([]) 2020-07-29 21:16:29,039 DEBUG awx.main.dispatch task 09c51f55-6b2f-4a40-8b78-fa46e00511a3 starting awx.main.tasks.cluster_node_heartbeat([]) 2020-07-29 21:16:29,041 DEBUG awx.main.tasks Cluster node heartbeat task. 2020-07-29 21:16:29,044 DEBUG awx.main.dispatch task 98ebaebb-7eed-442d-9f34-9a1540037835 starting awx.main.tasks.awx_k8s_reaper([]) 2020-07-29 21:16:29,077 DEBUG awx.main.dispatch task 56174e47-48eb-44c5-8e20-9a51df5fa321 starting awx.main.tasks.awx_periodic_scheduler([]) 2020-07-29 21:16:29,111 DEBUG awx.main.dispatch task 1f6372a9-10a8-4614-9959-d1ef41a3518d starting awx.main.scheduler.tasks.run_task_manager(*[]) 2020-07-29 21:16:29,113 DEBUG awx.main.scheduler Running Tower task manager. 2020-07-29 21:16:29,130 DEBUG awx.main.tasks Not running periodic scheduler, another task holds lock 2020-07-29 21:16:29,159 DEBUG awx.main.scheduler Not running scheduler, another task holds lock

pacificbreeze007 commented 3 years ago

Just an update here. For me this issue was fixed by generating a proper key/cert pair, and updating the following vars in the "inventory" file, and re-running the install again.

ssl_certificate=/etc/tower/certs/tower.crt ssl_certificate_key=/etc/tower/certs/tower.key ca_trust_dir=/etc/pki/ca-trust/source/anchors

ansible-playbook -i inventory install.yml -vv

ryanpetrello commented 3 years ago

@pacificbreeze007,

2020-07-29 21:13:53,947 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-29 21:13:53,947 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-29 21:13:53,970 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(3)
2020-07-29 21:13:53,970 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(3)
2020-07-29 21:13:54,895 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-29 21:13:54,895 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-29 21:13:54,897 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-29 21:13:54,897 DEBUG awx.main.commands.run_callback_receiver ProjectUpdateEvent.objects.bulk_create(1)
2020-07-29 21:13:55,051 DEBUG awx.main.tasks project_update 19 (running) finished running, producing 6 events.
2020-07-29 21:13:55,052 INFO awx.main.commands.run_callback_receiver Event processing is finished for Job 19, sending notifications

There's supposed to be 6 events, but I see 12 inserts, which tells me events are being inserted twice. Are you certain you're not running multiple callback receivers on the same node? Can you share ps -ef of this container?

pacificbreeze007 commented 3 years ago

@ryanpetrello First of all, contrary to my earlier comment, the issue is not resolved. This error message has returned "Invalid search term entered. GET returned: 500 A server error has occurred." after I tried to sync on of my projects

UID PID PPID C STIME TTY TIME CMD root 71291 71259 0 15:42 ? 00:00:00 tini -- /usr/bin/launch_awx_task.sh root 71455 71291 0 15:42 ? 00:00:00 bash /usr/bin/launch_awx_task.sh root 71759 71455 0 15:42 ? 00:00:00 /usr/bin/python3.6 /usr/local/bin/supervisord -c /etc/supervisord_task.conf root 71762 71759 0 15:42 ? 00:00:00 python3 /usr/bin/config-watcher root 71763 71759 1 15:42 ? 00:00:03 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher root 71764 71759 1 15:42 ? 00:00:02 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_callback_receiver root 71783 71764 0 15:42 ? 00:00:00 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_callback_receiver root 71784 71764 0 15:42 ? 00:00:00 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_callback_receiver root 71785 71764 0 15:42 ? 00:00:00 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_callback_receiver root 71786 71764 0 15:42 ? 00:00:00 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_callback_receiver root 71787 71763 0 15:42 ? 00:00:00 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher root 71789 71763 0 15:42 ? 00:00:00 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher root 71790 71763 0 15:42 ? 00:00:00 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher root 71791 71763 0 15:42 ? 00:00:00 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher root 71792 71763 0 15:42 ? 00:00:00 /var/lib/awx/venv/awx/bin/python3 /usr/bin/awx-manage run_dispatcher

ryanpetrello commented 3 years ago

@pacificbreeze007 can you share a listing of all of your containers? You're certain this is the only task container you're running?

ppodgorsek commented 3 years ago

I had a similar issue, the AWX Task logs helped identifying the problem as they were showing many occurrences of a specific message like below:

2020-08-26 13:55:00,996 ERROR awx.main.dispatch.periodic encountered an error while scheduling periodic tasks Traceback (most recent call last): File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/main/dispatch/periodic.py", line 38, in run self.run_pending() File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/schedule/init.py", line 94, in run_pending self._run_job(job) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/schedule/init.py", line 147, in _run_job ret = job.run() File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/schedule/init.py", line 466, in run ret = self.job_func() File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/main/dispatch/publish.py", line 90, in apply_async with pg_bus_conn() as conn: File "/usr/lib64/python3.6/contextlib.py", line 81, in enter return next(self.gen) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/main/dispatch/init.py", line 55, in pg_bus_conn conf.get("OPTIONS", {})) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/psycopg2/init.py", line 126, in connect conn = _connect(dsn, connection_factory=connection_factory, kwasync) psycopg2.OperationalError: FATAL: remaining connection slots are reserved for non-replication superuser connections

If this can help anyone, I managed to solve it by increasing the max number of connections on the database side. Using PostgreSQL, it was by default set at 100 but this was insufficient. (see https://stackoverflow.com/questions/30778015/how-to-increase-the-max-connections-in-postgres for an explanation on how to update it)

EmmanuelRolland90 commented 3 years ago

Hello, I got the same error on any project update that stays in wait state before running! And then return the following errors to the various queries when the operation is complete!

2020-09-14 12:17:34,631 ERROR django.request Internal Server Error: /api/v2/project_updates/420/, 2020-09-14 12:17:34,631 ERROR django.request Internal Server Error: /api/v2/project_updates/420/, 10.0.2.118 - - [14/Sep/2020:12:17:34 +0000] "GET /api/v2/project_updates/420/ HTTP/1.1" 500 47 "http://

image

EmmanuelRolland90 commented 3 years ago

I Don't have the problem with internal DB ( in a container ) but only with my external DB !

EmmanuelRolland90 commented 3 years ago

awx_web log RESULT 2 OKREADY 2020-09-14 13:43:03,795 ERROR django.request Internal Server Error: /api/v2/project_updates/421/ Traceback (most recent call last): File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/exception.py", line 34, in inner response = get_response(request) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/base.py", line 115, in _get_response response = self.process_exception_by_middleware(e, request) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/base.py", line 113, in _get_response response = wrapped_callback(request, *callback_args, callback_kwargs) File "/usr/lib64/python3.6/contextlib.py", line 52, in inner return func(*args, *kwds) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view return view_func(args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/views/generic/base.py", line 71, in view return self.dispatch(request, *args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/generics.py", line 304, in dispatch return super(APIView, self).dispatch(request, *args, *kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 505, in dispatch response = self.handle_exception(exc) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 465, in handle_exception self.raise_uncaught_exception(exc) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 476, in raise_uncaught_exception raise exc File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 502, in dispatch response = handler(request, args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/generics.py", line 208, in get return self.retrieve(request, *args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/mixins.py", line 56, in retrieve return Response(serializer.data) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 562, in data ret = super().data File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 260, in data self._data = self.to_representation(self.instance) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/serializers.py", line 802, in to_representation ret = super(UnifiedJobSerializer, self).to_representation(obj) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 529, in to_representation ret[field.field_name] = field.to_representation(attribute) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/fields.py", line 1905, in to_representation return method(value) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/serializers.py", line 1517, in get_host_status_counts counts = obj.project_update_events.only('event_data').get(event='playbook_on_stats').get_host_status_counts() File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/db/models/query.py", line 412, in get (self.model._meta.object_name, num) awx.main.models.events.ProjectUpdateEvent.MultipleObjectsReturned: get() returned more than one ProjectUpdateEvent -- it returned 2! 2020-09-14 13:43:03,795 ERROR django.request Internal Server Error: /api/v2/project_updates/421/ Traceback (most recent call last): File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/exception.py", line 34, in inner response = get_response(request) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/base.py", line 115, in _get_response response = self.process_exception_by_middleware(e, request) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/base.py", line 113, in _get_response response = wrapped_callback(request, *callback_args, *callback_kwargs) File "/usr/lib64/python3.6/contextlib.py", line 52, in inner return func(args, kwds) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view return view_func(*args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/views/generic/base.py", line 71, in view return self.dispatch(request, *args, *kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/generics.py", line 304, in dispatch return super(APIView, self).dispatch(request, args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 505, in dispatch response = self.handle_exception(exc) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 465, in handle_exception self.raise_uncaught_exception(exc) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 476, in raise_uncaught_exception raise exc File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 502, in dispatch response = handler(request, *args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/generics.py", line 208, in get return self.retrieve(request, *args, **kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/mixins.py", line 56, in retrieve return Response(serializer.data) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 562, in data ret = super().data File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 260, in data self._data = self.to_representation(self.instance) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/serializers.py", line 802, in to_representation ret = super(UnifiedJobSerializer, self).to_representation(obj) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 529, in to_representation ret[field.field_name] = field.to_representation(attribute) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/fields.py", line 1905, in to_representation return method(value) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/serializers.py", line 1517, in get_host_status_counts counts = obj.project_update_events.only('event_data').get(event='playbook_on_stats').get_host_status_counts() File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/db/models/query.py", line 412, in get (self.model._meta.object_name, num) awx.main.models.events.ProjectUpdateEvent.MultipleObjectsReturned: get() returned more than one ProjectUpdateEvent -- it returned 2! 10.0.2.118 - - [14/Sep/2020:13:43:03 +0000] "GET /api/v2/project_updates/421/ HTTP/1.1" 500 47 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.234" [pid: 78|app: 0|req: 44/220] 10.0.2.118 () {54 vars in 2533 bytes} [Mon Sep 14 13:43:03 2020] GET /api/v2/project_updates/421/ => generated 47 bytes in 231 msecs (HTTP/1.1 500) 6 headers in 208 bytes (1 switches on core 0) 18 - - [14/Sep/2020:13:43:49 +0000] "OPTIONS /api/v2/settings/all/ HTTP/1.1" 200 343567 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.234" [pid: 78|app: 0|req: 45/221] 10.0.2.118 () {58 vars in 2639 bytes} [Mon Sep 14 13:43:48 2020] OPTIONS /api/v2/settings/all/ => generated 343567 bytes in 1053 msecs (HTTP/1.1 200) 12 headers in 475 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:43:50 +0000] "GET /api/v2/config/ HTTP/1.1" 200 1067 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 80|app: 0|req: 40/222] 10.0.2.118 () {54 vars in 2507 bytes} [Mon Sep 14 13:43:48 2020] GET /api/v2/config/ => generated 1067 bytes in 1352 msecs (HTTP/1.1 200) 12 headers in 467 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:43:50 +0000] "GET /static/partials/configuration/settings.partial.html HTTP/1.1" 200 940 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.234" [pid: 81|app: 0|req: 67/223] 10.0.2.118 () {54 vars in 2513 bytes} [Mon Sep 14 13:43:51 2020] GET /api/v2/settings/system/ => generated 626 bytes in 171 msecs (HTTP/1.1 200) 12 headers in 472 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:43:52 +0000] "GET /api/v2/settings/system/ HTTP/1.1" 200 626 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.234" 10.0.2.118 - - [14/Sep/2020:13:43:52 +0000] "GET /static/partials/configuration/forms/settings-form.partial.html HTTP/1.1" 200 1044 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.234" 10.0.2.118 - - [14/Sep/2020:13:43:52 +0000] "GET /static/partials/configuration/forms/auth-form/configuration-auth.partial.html HTTP/1.1" 200 3627 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:43:52 +0000] "GET /static/partials/configuration/forms/jobs-form/configuration-jobs.partial.html HTTP/1.1" 200 238 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:43:52 +0000] "GET /static/partials/configuration/forms/ui-form/configuration-ui.partial.html HTTP/1.1" 200 212 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" 10.0.2.118 - - [14/Sep/2020:13:43:52 +0000] "GET /static/partials/configuration/forms/system-form/configuration-system.partial.html HTTP/1.1" 200 2228 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:43:52 +0000] "GET /static/partials/license/license.partial.html HTTP/1.1" 200 13018 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" 10.0.2.118 - - [14/Sep/2020:13:43:52 +0000] "GET /static/images/ui-icons_469bdd_256x240.png HTTP/1.1" 200 4549 "http://opsigen-dev.psa-cloud.com/static/css/vendor.b9e10736403fdb16c260.css" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 78|app: 0|req: 46/224] 10.0.2.118 () {54 vars in 2507 bytes} [Mon Sep 14 13:43:52 2020] GET /api/v2/settings/all/ => generated 22340 bytes in 310 msecs (HTTP/1.1 200) 12 headers in 474 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:43:52 +0000] "GET /api/v2/settings/all/ HTTP/1.1" 200 22340 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 81|app: 0|req: 68/225] 10.0.2.118 () {54 vars in 2513 bytes} [Mon Sep 14 13:43:59 2020] GET /api/v2/settings/system/ => generated 626 bytes in 180 msecs (HTTP/1.1 200) 12 headers in 472 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:43:59 +0000] "GET /api/v2/settings/system/ HTTP/1.1" 200 626 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 82|app: 0|req: 37/226] 10.0.2.118 () {54 vars in 2507 bytes} [Mon Sep 14 13:43:59 2020] GET /api/v2/settings/all/ => generated 22340 bytes in 311 msecs (HTTP/1.1 200) 12 headers in 474 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:43:59 +0000] "GET /api/v2/settings/all/ HTTP/1.1" 200 22340 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" RESULT 2 OKREADY 10.0.2.118 - - [14/Sep/2020:13:44:14 +0000] "PATCH /api/v2/settings/all/ HTTP/1.1" 200 22339 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 82|app: 0|req: 38/227] 10.0.2.118 () {62 vars in 2750 bytes} [Mon Sep 14 13:44:13 2020] PATCH /api/v2/settings/all/ => generated 22339 bytes in 1146 msecs (HTTP/1.1 200) 12 headers in 474 bytes (1 switches on core 0) [pid: 78|app: 0|req: 47/228] 10.0.2.118 () {54 vars in 2522 bytes} [Mon Sep 14 13:44:54 2020] GET /api/v2/credential_types/ => generated 28446 bytes in 458 msecs (HTTP/1.1 200) 12 headers in 460 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:44:55 +0000] "GET /api/v2/credential_types/ HTTP/1.1" 200 28446 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 80|app: 0|req: 41/229] 10.0.2.118 () {56 vars in 2557 bytes} [Mon Sep 14 13:44:54 2020] OPTIONS /api/v2/projects/ => generated 18676 bytes in 538 msecs (HTTP/1.1 200) 12 headers in 460 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:44:55 +0000] "OPTIONS /api/v2/projects/ HTTP/1.1" 200 18676 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 82|app: 0|req: 39/230] 10.0.2.118 () {54 vars in 2559 bytes} [Mon Sep 14 13:44:54 2020] GET /api/v2/projects/?page_size=20&order_by=name => generated 44336 bytes in 601 msecs (HTTP/1.1 200) 12 headers in 460 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:44:55 +0000] "GET /api/v2/projects/?page_size=20&order_by=name HTTP/1.1" 200 44336 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:44:55 +0000] "GET /static/partials/shared/smart-search/smart-search.partial.html HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:44:55 +0000] "GET /static/partials/shared/paginate/paginate.partial.html HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:44:56 +0000] "OPTIONS /api/v2/projects/ HTTP/1.1" 200 18676 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 81|app: 0|req: 69/231] 10.0.2.118 () {58 vars in 2626 bytes} [Mon Sep 14 13:44:56 2020] OPTIONS /api/v2/projects/ => generated 18676 bytes in 238 msecs (HTTP/1.1 200) 12 headers in 460 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:44:57 +0000] "OPTIONS /api/v2/unified_jobs/ HTTP/1.1" 200 11135 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 78|app: 0|req: 48/232] 10.0.2.118 () {56 vars in 2558 bytes} [Mon Sep 14 13:44:57 2020] OPTIONS /api/v2/unified_jobs/ => generated 11135 bytes in 207 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:44:58 +0000] "GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&notlaunch_type=sync HTTP/1.1" 200 38165 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 80|app: 0|req: 42/233] 10.0.2.118 () {54 vars in 2614 bytes} [Mon Sep 14 13:44:57 2020] GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&notlaunch_type=sync => generated 38165 bytes in 893 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:44:58 +0000] "GET /static/partials/logviewer.html HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:44:58 +0000] "GET /static/partials/templates/labels/labelsList.partial.html HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 81|app: 0|req: 70/234] 10.0.2.118 () {58 vars in 2627 bytes} [Mon Sep 14 13:44:58 2020] OPTIONS /api/v2/unified_jobs/ => generated 11135 bytes in 214 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:44:58 +0000] "OPTIONS /api/v2/unified_jobs/ HTTP/1.1" 200 11135 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" RESULT 2 OKREADY [pid: 78|app: 0|req: 49/235] 10.0.2.118 () {54 vars in 2519 bytes} [Mon Sep 14 13:45:01 2020] GET /api/v2/projects/59/update/ => generated 19 bytes in 174 msecs (HTTP/1.1 200) 12 headers in 457 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:45:01 +0000] "GET /api/v2/projects/59/update/ HTTP/1.1" 200 19 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 80|app: 0|req: 43/236] 10.0.2.118 () {60 vars in 2676 bytes} [Mon Sep 14 13:45:01 2020] POST /api/v2/projects/59/update/ => generated 1693 bytes in 377 msecs (HTTP/1.1 202) 13 headers in 505 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:45:02 +0000] "POST /api/v2/projects/59/update/ HTTP/1.1" 202 1693 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 81|app: 0|req: 71/237] 10.0.2.118 () {54 vars in 2644 bytes} [Mon Sep 14 13:45:02 2020] GET /api/v2/unified_jobs/?order_by=-finished&notlaunch_type=sync&count_disabled=1&idin=422 => generated 1590 bytes in 333 msecs (HTTP/1.1 200) 12 headers in 453 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:45:02 +0000] "GET /api/v2/unified_jobs/?order_by=-finished&notlaunch_type=sync&count_disabled=1&idin=422 HTTP/1.1" 200 1590 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" 10.0.2.118 - - [14/Sep/2020:13:45:26 +0000] "GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 HTTP/1.1" 200 52 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 82|app: 0|req: 40/238] 10.0.2.118 () {54 vars in 2612 bytes} [Mon Sep 14 13:45:26 2020] GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 => generated 52 bytes in 240 msecs (HTTP/1.1 200) 13 headers in 474 bytes (1 switches on core 0) [pid: 81|app: 0|req: 72/239] 10.0.2.118 () {54 vars in 2517 bytes} [Mon Sep 14 13:45:26 2020] GET /api/v2/project_updates/422/ => generated 1746 bytes in 282 msecs (HTTP/1.1 200) 12 headers in 461 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:45:27 +0000] "GET /api/v2/project_updates/422/ HTTP/1.1" 200 1746 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:45:27 +0000] "OPTIONS /api/v2/project_updates/422/ HTTP/1.1" 200 9632 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 78|app: 0|req: 50/240] 10.0.2.118 () {56 vars in 2568 bytes} [Mon Sep 14 13:45:26 2020] OPTIONS /api/v2/project_updates/422/ => generated 9632 bytes in 358 msecs (HTTP/1.1 200) 12 headers in 461 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:45:27 +0000] "GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 HTTP/1.1" 200 52 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 81|app: 0|req: 73/241] 10.0.2.118 () {54 vars in 2612 bytes} [Mon Sep 14 13:45:27 2020] GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 => generated 52 bytes in 166 msecs (HTTP/1.1 200) 13 headers in 474 bytes (1 switches on core 0) RESULT 2 OKREADY 10.0.2.118 - - [14/Sep/2020:13:46:15 +0000] "GET / HTTP/1.1" 200 11460 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 81|app: 0|req: 74/242] 10.0.2.118 () {56 vars in 2592 bytes} [Mon Sep 14 13:46:15 2020] GET / => generated 11460 bytes in 279 msecs (HTTP/1.1 200) 7 headers in 334 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:16 +0000] "GET /websocket/ HTTP/1.1" 101 79481 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" 10.0.2.118 - - [14/Sep/2020:13:46:16 +0000] "GET /static/assets/favicon.ico?v=13.0.0 HTTP/1.1" 200 15086 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:46:16 +0000] "GET /api/ HTTP/1.1" 200 9669 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 78|app: 0|req: 51/243] 10.0.2.118 () {54 vars in 2441 bytes} [Mon Sep 14 13:46:16 2020] GET /api/ => generated 9669 bytes in 177 msecs (HTTP/1.1 200) 13 headers in 564 bytes (1 switches on core 0) [pid: 79|app: 0|req: 36/244] 10.0.2.118 () {56 vars in 2493 bytes} [Mon Sep 14 13:46:16 2020] GET /api/ => generated 9669 bytes in 169 msecs (HTTP/1.1 200) 13 headers in 564 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:16 +0000] "GET /api/ HTTP/1.1" 200 9669 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" 10.0.2.118 - - [14/Sep/2020:13:46:16 +0000] "GET /api/v2/workflow_approvals/?status=pending&page_size=1 HTTP/1.1" 200 52 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 80|app: 0|req: 44/245] 10.0.2.118 () {54 vars in 2568 bytes} [Mon Sep 14 13:46:16 2020] GET /api/v2/workflow_approvals/?status=pending&page_size=1 => generated 52 bytes in 210 msecs (HTTP/1.1 200) 12 headers in 457 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:17 +0000] "GET /api/v2/ HTTP/1.1" 200 1688 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 79|app: 0|req: 37/246] 10.0.2.118 () {56 vars in 2515 bytes} [Mon Sep 14 13:46:16 2020] GET /api/v2/ => generated 1688 bytes in 165 msecs (HTTP/1.1 200) 12 headers in 453 bytes (1 switches on core 0) [pid: 82|app: 0|req: 41/247] 10.0.2.118 () {56 vars in 2570 bytes} [Mon Sep 14 13:46:16 2020] OPTIONS /api/v2/unified_jobs/ => generated 11135 bytes in 271 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:17 +0000] "OPTIONS /api/v2/unified_jobs/ HTTP/1.1" 200 11135 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" 10.0.2.118 - - [14/Sep/2020:13:46:17 +0000] "GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&notlaunch_type=sync HTTP/1.1" 200 37649 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 81|app: 0|req: 75/248] 10.0.2.118 () {54 vars in 2626 bytes} [Mon Sep 14 13:46:16 2020] GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&notlaunch_type=sync => generated 37649 bytes in 1079 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) [pid: 78|app: 0|req: 52/249] 10.0.2.118 () {54 vars in 2491 bytes} [Mon Sep 14 13:46:16 2020] GET /api/v2/config/ => generated 1067 bytes in 1405 msecs (HTTP/1.1 200) 12 headers in 467 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:18 +0000] "GET /api/v2/config/ HTTP/1.1" 200 1067 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 79|app: 0|req: 38/250] 10.0.2.118 () {54 vars in 2628 bytes} [Mon Sep 14 13:46:18 2020] GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 => generated 52 bytes in 194 msecs (HTTP/1.1 200) 13 headers in 474 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:18 +0000] "GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 HTTP/1.1" 200 52 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 81|app: 0|req: 76/251] 10.0.2.118 () {54 vars in 2507 bytes} [Mon Sep 14 13:46:18 2020] GET /api/v2/config/ => generated 1067 bytes in 172 msecs (HTTP/1.1 200) 12 headers in 467 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:18 +0000] "GET /api/v2/config/ HTTP/1.1" 200 1067 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:46:18 +0000] "OPTIONS /api/v2/project_updates/422/ HTTP/1.1" 200 9632 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 82|app: 0|req: 42/252] 10.0.2.118 () {56 vars in 2584 bytes} [Mon Sep 14 13:46:18 2020] OPTIONS /api/v2/project_updates/422/ => generated 9632 bytes in 258 msecs (HTTP/1.1 200) 12 headers in 461 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:18 +0000] "GET /api/v2/project_updates/422/ HTTP/1.1" 200 1746 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" [pid: 80|app: 0|req: 45/253] 10.0.2.118 () {54 vars in 2533 bytes} [Mon Sep 14 13:46:18 2020] GET /api/v2/project_updates/422/ => generated 1746 bytes in 267 msecs (HTTP/1.1 200) 12 headers in 461 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:18 +0000] "GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 HTTP/1.1" 200 52 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" [pid: 82|app: 0|req: 43/254] 10.0.2.118 () {54 vars in 2628 bytes} [Mon Sep 14 13:46:18 2020] GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 => generated 52 bytes in 180 msecs (HTTP/1.1 200) 13 headers in 474 bytes (1 switches on core 0) [pid: 81|app: 0|req: 77/255] 10.0.2.118 () {56 vars in 2608 bytes} [Mon Sep 14 13:46:58 2020] GET / => generated 11460 bytes in 168 msecs (HTTP/1.1 200) 7 headers in 334 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:58 +0000] "GET / HTTP/1.1" 200 11460 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" 10.0.2.118 - - [14/Sep/2020:13:46:58 +0000] "GET /websocket/ HTTP/1.1" 101 460 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.235" 10.0.2.118 - - [14/Sep/2020:13:46:59 +0000] "GET /static/assets/favicon.ico?v=13.0.0 HTTP/1.1" 200 15086 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 81|app: 0|req: 78/256] 10.0.2.118 () {54 vars in 2457 bytes} [Mon Sep 14 13:46:59 2020] GET /api/ => generated 9669 bytes in 168 msecs (HTTP/1.1 200) 13 headers in 564 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:59 +0000] "GET /api/ HTTP/1.1" 200 9669 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" 10.0.2.118 - - [14/Sep/2020:13:46:59 +0000] "GET /api/v2/config/ HTTP/1.1" 200 1067 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 79|app: 0|req: 39/257] 10.0.2.118 () {54 vars in 2507 bytes} [Mon Sep 14 13:46:59 2020] GET /api/v2/config/ => generated 1067 bytes in 196 msecs (HTTP/1.1 200) 12 headers in 467 bytes (1 switches on core 0) [pid: 80|app: 0|req: 46/258] 10.0.2.118 () {54 vars in 2584 bytes} [Mon Sep 14 13:46:59 2020] GET /api/v2/workflow_approvals/?status=pending&page_size=1 => generated 52 bytes in 195 msecs (HTTP/1.1 200) 12 headers in 457 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:59 +0000] "GET /api/v2/workflow_approvals/?status=pending&page_size=1 HTTP/1.1" 200 52 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 82|app: 0|req: 44/259] 10.0.2.118 () {56 vars in 2509 bytes} [Mon Sep 14 13:46:59 2020] GET /api/ => generated 9669 bytes in 228 msecs (HTTP/1.1 200) 13 headers in 564 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:59 +0000] "GET /api/ HTTP/1.1" 200 9669 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" [pid: 81|app: 0|req: 79/260] 10.0.2.118 () {56 vars in 2570 bytes} [Mon Sep 14 13:46:59 2020] OPTIONS /api/v2/unified_jobs/ => generated 11135 bytes in 219 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:46:59 +0000] "OPTIONS /api/v2/unified_jobs/ HTTP/1.1" 200 11135 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 79|app: 0|req: 40/261] 10.0.2.118 () {56 vars in 2515 bytes} [Mon Sep 14 13:46:59 2020] GET /api/v2/ => generated 1688 bytes in 112 msecs (HTTP/1.1 200) 12 headers in 453 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:47:00 +0000] "GET /api/v2/ HTTP/1.1" 200 1688 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" RESULT 2 OKREADY 10.0.2.118 - - [14/Sep/2020:13:47:00 +0000] "GET /api/v2/config/ HTTP/1.1" 200 1067 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 82|app: 0|req: 45/262] 10.0.2.118 () {54 vars in 2507 bytes} [Mon Sep 14 13:46:59 2020] GET /api/v2/config/ => generated 1067 bytes in 164 msecs (HTTP/1.1 200) 12 headers in 467 bytes (1 switches on core 0) [pid: 78|app: 0|req: 53/263] 10.0.2.118 () {54 vars in 2626 bytes} [Mon Sep 14 13:46:59 2020] GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&notlaunch_type=sync => generated 37649 bytes in 1055 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:47:00 +0000] "GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&notlaunch_type=sync HTTP/1.1" 200 37649 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:47:01 +0000] "GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 HTTP/1.1" 200 52 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" [pid: 79|app: 0|req: 41/264] 10.0.2.118 () {54 vars in 2628 bytes} [Mon Sep 14 13:47:00 2020] GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 => generated 52 bytes in 167 msecs (HTTP/1.1 200) 13 headers in 474 bytes (1 switches on core 0) [pid: 80|app: 0|req: 47/265] 10.0.2.118 () {54 vars in 2533 bytes} [Mon Sep 14 13:47:00 2020] GET /api/v2/project_updates/422/ => generated 1746 bytes in 264 msecs (HTTP/1.1 200) 12 headers in 461 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:47:01 +0000] "GET /api/v2/project_updates/422/ HTTP/1.1" 200 1746 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:47:01 +0000] "OPTIONS /api/v2/project_updates/422/ HTTP/1.1" 200 9632 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 82|app: 0|req: 46/266] 10.0.2.118 () {56 vars in 2584 bytes} [Mon Sep 14 13:47:00 2020] OPTIONS /api/v2/project_updates/422/ => generated 9632 bytes in 311 msecs (HTTP/1.1 200) 12 headers in 461 bytes (1 switches on core 0) [pid: 79|app: 0|req: 42/267] 10.0.2.118 () {54 vars in 2628 bytes} [Mon Sep 14 13:47:01 2020] GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 => generated 52 bytes in 196 msecs (HTTP/1.1 200) 13 headers in 474 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:47:01 +0000] "GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 HTTP/1.1" 200 52 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 81|app: 0|req: 80/268] 10.0.2.118 () {58 vars in 2639 bytes} [Mon Sep 14 13:47:48 2020] OPTIONS /api/v2/settings/all/ => generated 343567 bytes in 1143 msecs (HTTP/1.1 200) 12 headers in 475 bytes (1 switches on core 0) 18 - - [14/Sep/2020:13:47:49 +0000] "OPTIONS /api/v2/settings/all/ HTTP/1.1" 200 343567 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:47:49 +0000] "GET /api/v2/config/ HTTP/1.1" 200 1067 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 78|app: 0|req: 54/269] 10.0.2.118 () {54 vars in 2507 bytes} [Mon Sep 14 13:47:48 2020] GET /api/v2/config/ => generated 1067 bytes in 1343 msecs (HTTP/1.1 200) 12 headers in 467 bytes (1 switches on core 0) [pid: 81|app: 0|req: 81/270] 10.0.2.118 () {54 vars in 2525 bytes} [Mon Sep 14 13:47:49 2020] GET /api/v2/settings/system/ => generated 626 bytes in 191 msecs (HTTP/1.1 200) 12 headers in 472 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:47:50 +0000] "GET /api/v2/settings/system/ HTTP/1.1" 200 626 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:47:50 +0000] "GET /api/v2/settings/all/ HTTP/1.1" 200 22339 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 81|app: 0|req: 82/271] 10.0.2.118 () {54 vars in 2519 bytes} [Mon Sep 14 13:47:50 2020] GET /api/v2/settings/all/ => generated 22339 bytes in 368 msecs (HTTP/1.1 200) 12 headers in 474 bytes (1 switches on core 0) RESULT 2 OKREADY 10.0.2.118 - - [14/Sep/2020:13:48:44 +0000] "GET /static/images/ui-bg_flat_50_ffffff_40x100.png HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/static/css/vendor.b9e10736403fdb16c260.css" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 82|app: 0|req: 47/272] 10.0.2.118 () {62 vars in 2762 bytes} [Mon Sep 14 13:48:51 2020] PATCH /api/v2/settings/all/ => generated 22349 bytes in 1802 msecs (HTTP/1.1 200) 12 headers in 474 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:48:53 +0000] "PATCH /api/v2/settings/all/ HTTP/1.1" 200 22349 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:48:53 +0000] "GET /api/v2/settings/all/ HTTP/1.1" 200 22349 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 82|app: 0|req: 48/273] 10.0.2.118 () {54 vars in 2519 bytes} [Mon Sep 14 13:48:53 2020] GET /api/v2/settings/all/ => generated 22349 bytes in 291 msecs (HTTP/1.1 200) 12 headers in 474 bytes (1 switches on core 0) [pid: 82|app: 0|req: 49/274] 10.0.2.118 () {62 vars in 2762 bytes} [Mon Sep 14 13:48:58 2020] PATCH /api/v2/settings/all/ => generated 22349 bytes in 500 msecs (HTTP/1.1 200) 12 headers in 474 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:48:59 +0000] "PATCH /api/v2/settings/all/ HTTP/1.1" 200 22349 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" RESULT 2 OKREADY [pid: 81|app: 0|req: 83/275] 10.0.2.118 () {56 vars in 2565 bytes} [Mon Sep 14 13:49:05 2020] OPTIONS /api/v2/unified_jobs/ => generated 11135 bytes in 273 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:05 +0000] "OPTIONS /api/v2/unified_jobs/ HTTP/1.1" 200 11135 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 82|app: 0|req: 50/276] 10.0.2.118 () {54 vars in 2621 bytes} [Mon Sep 14 13:49:05 2020] GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&notlaunch_type=sync => generated 37649 bytes in 1173 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:06 +0000] "GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&notlaunch_type=sync HTTP/1.1" 200 37649 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 78|app: 0|req: 55/277] 10.0.2.118 () {58 vars in 2634 bytes} [Mon Sep 14 13:49:07 2020] OPTIONS /api/v2/unified_jobs/ => generated 11135 bytes in 229 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:07 +0000] "OPTIONS /api/v2/unified_jobs/ HTTP/1.1" 200 11135 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 79|app: 0|req: 43/278] 10.0.2.118 () {54 vars in 2612 bytes} [Mon Sep 14 13:49:11 2020] GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 => generated 52 bytes in 185 msecs (HTTP/1.1 200) 13 headers in 474 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:11 +0000] "GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 HTTP/1.1" 200 52 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" 10.0.2.118 - - [14/Sep/2020:13:49:11 +0000] "GET /api/v2/project_updates/422/ HTTP/1.1" 200 1746 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 82|app: 0|req: 51/279] 10.0.2.118 () {54 vars in 2517 bytes} [Mon Sep 14 13:49:11 2020] GET /api/v2/project_updates/422/ => generated 1746 bytes in 236 msecs (HTTP/1.1 200) 12 headers in 461 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:11 +0000] "OPTIONS /api/v2/project_updates/422/ HTTP/1.1" 200 9632 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 81|app: 0|req: 84/280] 10.0.2.118 () {56 vars in 2568 bytes} [Mon Sep 14 13:49:11 2020] OPTIONS /api/v2/project_updates/422/ => generated 9632 bytes in 250 msecs (HTTP/1.1 200) 12 headers in 461 bytes (1 switches on core 0) [pid: 81|app: 0|req: 85/281] 10.0.2.118 () {54 vars in 2612 bytes} [Mon Sep 14 13:49:12 2020] GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 => generated 52 bytes in 142 msecs (HTTP/1.1 200) 13 headers in 474 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:12 +0000] "GET /api/v2/project_updates/422/events/?order_by=-start_line&page=1&page_size=50 HTTP/1.1" 200 52 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 78|app: 0|req: 56/282] 10.0.2.118 () {58 vars in 2639 bytes} [Mon Sep 14 13:49:19 2020] OPTIONS /api/v2/unified_jobs/ => generated 11135 bytes in 160 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:19 +0000] "OPTIONS /api/v2/unified_jobs/ HTTP/1.1" 200 11135 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 81|app: 0|req: 86/283] 10.0.2.118 () {54 vars in 2650 bytes} [Mon Sep 14 13:49:19 2020] GET /api/v2/schedules/?page_size=20&order_by=unified_job_templatepolymorphic_ctypemodel => generated 5837 bytes in 471 msecs (HTTP/1.1 200) 12 headers in 459 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:20 +0000] "GET /api/v2/schedules/?page_size=20&order_by=unified_job_templatepolymorphic_ctypemodel HTTP/1.1" 200 5837 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:49:20 +0000] "GET /static/partials/shared/column-sort/column-sort.partial.html HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:49:20 +0000] "GET /static/partials/shared/list-generator/list-actions.partial.html HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 79|app: 0|req: 44/284] 10.0.2.118 () {58 vars in 2633 bytes} [Mon Sep 14 13:49:20 2020] OPTIONS /api/v2/schedules/ => generated 14162 bytes in 195 msecs (HTTP/1.1 200) 12 headers in 460 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:20 +0000] "OPTIONS /api/v2/schedules/ HTTP/1.1" 200 14162 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" [pid: 78|app: 0|req: 57/285] 10.0.2.118 () {58 vars in 2633 bytes} [Mon Sep 14 13:49:20 2020] OPTIONS /api/v2/schedules/ => generated 14162 bytes in 231 msecs (HTTP/1.1 200) 12 headers in 460 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:20 +0000] "OPTIONS /api/v2/schedules/ HTTP/1.1" 200 14162 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:49:24 +0000] "GET /api/v2/dashboard/graphs/jobs/?period=month&job_type=all HTTP/1.1" 200 1124 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" [pid: 81|app: 0|req: 87/286] 10.0.2.118 () {56 vars in 2608 bytes} [Mon Sep 14 13:49:24 2020] GET /api/v2/dashboard/graphs/jobs/?period=month&job_type=all => generated 1124 bytes in 217 msecs (HTTP/1.1 200) 10 headers in 288 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:25 +0000] "GET /api/v2/dashboard/ HTTP/1.1" 200 1415 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240"[pid: 79|app: 0|req: 45/287] 10.0.2.118 () {56 vars in 2533 bytes} [Mon Sep 14 13:49:24 2020] GET /api/v2/dashboard/ => generated 1415 bytes in 266 msecs (HTTP/1.1 200) 11 headers in 383 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:25 +0000] "GET /api/v2/unified_job_templates/?order_by=-last_job_run&page_size=5&last_job_runisnull=false&type=workflow_job_template,job_template HTTP/1.1" 200 13732 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 81|app: 0|req: 88/288] 10.0.2.118 () {56 vars in 2760 bytes} [Mon Sep 14 13:49:24 2020] GET /api/v2/unified_job_templates/?order_by=-last_job_run&page_size=5&last_job_runisnull=false&type=workflow_job_template,job_template => generated 13732 bytes in 446 msecs (HTTP/1.1 200) 10 headers in 289 bytes (1 switches on core 0) 18 - - [14/Sep/2020:13:49:25 +0000] "OPTIONS /api/v2/job_templates/ HTTP/1.1" 200 24588 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 78|app: 0|req: 58/289] 10.0.2.118 () {60 vars in 2661 bytes} [Mon Sep 14 13:49:24 2020] OPTIONS /api/v2/job_templates/ => generated 24588 bytes in 385 msecs (HTTP/1.1 200) 10 headers in 295 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:25 +0000] "GET /api/v2/unified_jobs/?order_by=-finished&page_size=5&finishedisnull=false&type=workflow_job,job&count_disabled=1 HTTP/1.1" 200 16649 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" [pid: 80|app: 0|req: 48/290] 10.0.2.118 () {56 vars in 2724 bytes} [Mon Sep 14 13:49:24 2020] GET /api/v2/unified_jobs/?order_by=-finished&page_size=5&finishedisnull=false&type=workflow_job,job&count_disabled=1 => generated 16649 bytes in 586 msecs (HTTP/1.1 200) 10 headers in 289 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:31 +0000] "OPTIONS /api/v2/unified_jobs/ HTTP/1.1" 200 11135 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" [pid: 82|app: 0|req: 52/291] 10.0.2.118 () {56 vars in 2554 bytes} [Mon Sep 14 13:49:30 2020] OPTIONS /api/v2/unified_jobs/ => generated 11135 bytes in 146 msecs (HTTP/1.1 200) 12 headers in 454 bytes (1 switches on core 0) [pid: 78|app: 0|req: 59/292] 10.0.2.118 () {56 vars in 2641 bytes} [Mon Sep 14 13:49:30 2020] GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&notlaunch_type=sync => generated 37612 bytes in 862 msecs (HTTP/1.1 200) 10 headers in 289 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:31 +0000] "GET /api/v2/unified_jobs/?page_size=20&order_by=-finished&notlaunch_type=sync HTTP/1.1" 200 37612 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 81|app: 0|req: 89/293] 10.0.2.118 () {60 vars in 2654 bytes} [Mon Sep 14 13:49:31 2020] OPTIONS /api/v2/unified_jobs/ => generated 11135 bytes in 155 msecs (HTTP/1.1 200) 10 headers in 289 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:32 +0000] "OPTIONS /api/v2/unified_jobs/ HTTP/1.1" 200 11135 "http://opsigen-dev.psa-cloud.com/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" [pid: 79|app: 0|req: 46/294] 10.0.2.118 () {56 vars in 2674 bytes} [Mon Sep 14 13:49:42 2020] GET /api/v2/project_updates/?page=4 => generated 111807 bytes in 920 msecs (HTTP/1.1 200) 13 headers in 574 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /api/v2/project_updates/?page=4 HTTP/1.1" 200 111807 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/api/api.css?v=13.0.0 HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/rest_framework/css/default.css HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/rest_framework/css/bootstrap.min.css HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/rest_framework/css/prettify.css HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/assets/logo-header.svg HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/rest_framework/js/jquery-3.4.1.min.js HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.236" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/rest_framework/js/ajax-form.js HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.240" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/rest_framework/js/csrf.js HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.237" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/rest_framework/js/bootstrap.min.js HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/rest_framework/js/prettify-min.js HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/rest_framework/js/default.js HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.233" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/rest_framework/fonts/glyphicons-halflings-regular.woff2 HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/static/rest_framework/css/bootstrap.min.css" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.236" 10.0.2.118 - - [14/Sep/2020:13:49:43 +0000] "GET /static/api/api.js?v=13.0.0 HTTP/1.1" 304 0 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 10.0.2.118 - - [14/Sep/2020:13:49:45 +0000] "GET /static/assets/favicon.ico?v=13.0.0 HTTP/1.1" 200 15086 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" 2020-09-14 13:49:48,343 ERROR django.request Internal Server Error: /api/v2/project_updates/421/ Traceback (most recent call last): File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/exception.py", line 34, in inner response = get_response(request) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/base.py", line 115, in _get_response response = self.process_exception_by_middleware(e, request) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/base.py", line 113, in _get_response response = wrapped_callback(request, *callback_args, callback_kwargs) File "/usr/lib64/python3.6/contextlib.py", line 52, in inner return func(*args, kwds) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view return view_func(*args, *kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/views/generic/base.py", line 71, in view return self.dispatch(request, args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/generics.py", line 304, in dispatch return super(APIView, self).dispatch(request, *args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 505, in dispatch response = self.handle_exception(exc) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 465, in handle_exception self.raise_uncaught_exception(exc) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 476, in raise_uncaught_exception raise exc File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 502, in dispatch response = handler(request, *args, *kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/generics.py", line 208, in get return self.retrieve(request, args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/mixins.py", line 56, in retrieve return Response(serializer.data) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 562, in data ret = super().data File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 260, in data self._data = self.to_representation(self.instance) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/serializers.py", line 802, in to_representation ret = super(UnifiedJobSerializer, self).to_representation(obj) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 529, in to_representation ret[field.field_name] = field.to_representation(attribute) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/fields.py", line 1905, in to_representation return method(value) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/serializers.py", line 1517, in get_host_status_counts counts = obj.project_update_events.only('event_data').get(event='playbook_on_stats').get_host_status_counts() File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/db/models/query.py", line 412, in get (self.model._meta.object_name, num) awx.main.models.events.ProjectUpdateEvent.MultipleObjectsReturned: get() returned more than one ProjectUpdateEvent -- it returned 2! 2020-09-14 13:49:48,343 ERROR django.request Internal Server Error: /api/v2/project_updates/421/ Traceback (most recent call last): File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/exception.py", line 34, in inner response = get_response(request) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/base.py", line 115, in _get_response response = self.process_exception_by_middleware(e, request) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/core/handlers/base.py", line 113, in _get_response response = wrapped_callback(request, *callback_args, callback_kwargs) File "/usr/lib64/python3.6/contextlib.py", line 52, in inner return func(*args, *kwds) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view return view_func(args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/views/generic/base.py", line 71, in view return self.dispatch(request, *args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/generics.py", line 304, in dispatch return super(APIView, self).dispatch(request, *args, *kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 505, in dispatch response = self.handle_exception(exc) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 465, in handle_exception self.raise_uncaught_exception(exc) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 476, in raise_uncaught_exception raise exc File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/views.py", line 502, in dispatch response = handler(request, args, kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/generics.py", line 208, in get return self.retrieve(request, *args, **kwargs) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/mixins.py", line 56, in retrieve return Response(serializer.data) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 562, in data ret = super().data File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 260, in data self._data = self.to_representation(self.instance) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/serializers.py", line 802, in to_representation ret = super(UnifiedJobSerializer, self).to_representation(obj) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/serializers.py", line 529, in to_representation ret[field.field_name] = field.to_representation(attribute) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/rest_framework/fields.py", line 1905, in to_representation return method(value) File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/awx/api/serializers.py", line 1517, in get_host_status_counts counts = obj.project_update_events.only('event_data').get(event='playbook_on_stats').get_host_status_counts() File "/var/lib/awx/venv/awx/lib/python3.6/site-packages/django/db/models/query.py", line 412, in get (self.model._meta.object_name, num) awx.main.models.events.ProjectUpdateEvent.MultipleObjectsReturned: get() returned more than one ProjectUpdateEvent -- it returned 2! [pid: 78|app: 0|req: 60/295] 10.0.2.118 () {54 vars in 2645 bytes} [Mon Sep 14 13:49:48 2020] GET /api/v2/project_updates/421/ => generated 12123 bytes in 266 msecs (HTTP/1.1 500) 7 headers in 330 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:48 +0000] "GET /api/v2/project_updates/421/ HTTP/1.1" 500 12123 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" [pid: 78|app: 0|req: 61/296] 10.0.2.118 () {54 vars in 2645 bytes} [Mon Sep 14 13:49:57 2020] GET /api/v2/project_updates/422/ => generated 17975 bytes in 574 msecs (HTTP/1.1 200) 13 headers in 581 bytes (1 switches on core 0) 10.0.2.118 - - [14/Sep/2020:13:49:58 +0000] "GET /api/v2/project_updates/422/ HTTP/1.1" 200 17975 "http://opsigen-dev.psa-cloud.com/api/v2/project_updates/?page=4" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.102 Safari/537.36" "10.220.68.239" RESULT 2 OKREADY RESULT 2 OKREADY

therealrobopablo commented 3 years ago

I've tried upgrading to v13 and it's still occurring. Haven't tried 14 yet but since this is still open. It does seem to be tied to using an external DB with 2 nodes pointing at it. running it as a single node or in the contained DB is ok.

therealrobopablo commented 3 years ago

It would appear that deploying a cluster is the way to handle this. I see a "docker-compose-cluster" file in the tools folder, but no supporting documentation on how to stand it up. Any pointers?

EmmanuelRolland90 commented 3 years ago

Hello I've install from scratch a V9.1.0 : all is fine After I've upgrade with V15 : this issue comes again :-(( Still investigating ...

bouluad commented 3 years ago

I had the same issue : Running multi-instances of awx with a external database (i got 500 error when running any job). The issue come from CLUSTER_HOST_ID (by default is 'awx') so when you lunch multi-instance, you have the multi-lines data for the same CLUSTER ID (that's why you got: get() returned more than one ProjectUpdateEvent -- it returned 2! ). To fix it :

  1. you must override the file settings.py (/etc/tower) and change the line 29 (CLUSTER_HOST_ID ="{{ ansible_fqdn }}" ) if you use ansible otherwise CLUSTER_HOST_ID should be different than the second instance.

  2. you must override the script file launch_awx_task.sh (/usr/bin/) by overriding those lines : awx-manage provision_instance --hostname={{ ansible_fqdn }} awx-manage register_queue --queuename=tower --instance_percent=100 --hostnames={{ ansible_fqdn }}

kannurkars commented 3 years ago

I had the same issue : Running multi-instances of awx with a external database (i got 500 error when running any job). The issue come from CLUSTER_HOST_ID (by default is 'awx') so when you lunch multi-instance, you have the multi-lines data for the same CLUSTER ID (that's why you got: get() returned more than one ProjectUpdateEvent -- it returned 2! ). To fix it :

  1. you must override the file settings.py (/etc/tower) and change the line 29 (CLUSTER_HOST_ID ="{{ ansible_fqdn }}" ) if you use ansible otherwise CLUSTER_HOST_ID should be different than the second instance.
  2. you must override the script file launch_awx_task.sh (/usr/bin/) by overriding those lines : awx-manage provision_instance --hostname={{ ansible_fqdn }} awx-manage register_queue --queuename=tower --instance_percent=100 --hostnames={{ ansible_fqdn }}
  • _ansible_fqdn value is the full hostname of each instance._

Is there any way we can make these changes before 1st launch? I mean via inventory file or while using default images?

chrismeyersfsu commented 3 years ago

Multiple tower nodes supported in kubernetes only.