Hi,
I am trying to implement AWX webui ldap authentication using FreeIPA + 2fa.
I am most of the way there and the initial login works, however subsequent logins thereafter fail with invalid username/password.
Another twist is that if i delete the user in AWX webui, I can login with that 2fa account again for that initial login.
Thanks in Advanced.
Simon.
awx-web logs that i’ve gathered if someone could take a look that would be great. These are the results from clicking “Log In” with the correct credential entered.
It seems once AWX has a record of a user it doesn’t perform a ldap lookup there after. However if i delete that user within awx-web that user can login again (once).
2021-11-04T22:41:08.399318451Z stderr F 2021-11-04 22:41:08,398 DEBUG [490812de53cb404a9944c49017e82b2c] awx.analytics.performance request: <WSGIRequest: GET ‘/api/login/’>, response_time: 0.055s
2021-11-04T22:41:08.400757615Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:08 +0000] “GET /api/login/ HTTP/1.1” 200 5710 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:08.400779134Z stderr F [pid: 194|app: 0|req: 293/1140] 10.42.0.14 () {68 vars in 2722 bytes} [Thu Nov 4 22:41:08 2021] GET /api/login/ => generated 5710 bytes in 56 msecs (HTTP/1.1 200) 10 headers in 483 bytes (1 switches on core 0)
2021-11-04T22:41:08.612229178Z stderr F 2021-11-04 22:41:08,610 DEBUG [36c7628494774a618db4cef62cd10e10] django_auth_ldap uid=sokell,cn=users,cn=accounts,dc=somewhere,dc=com is a member of cn=admins,cn=groups,cn=accounts,dc=somewhere,dc=com
2021-11-04T22:41:08.614743213Z stderr F 2021-11-04 22:41:08,614 DEBUG [36c7628494774a618db4cef62cd10e10] django_auth_ldap Creating Django user sokell
2021-11-04T22:41:08.615192103Z stderr F 2021-11-04 22:41:08,614 DEBUG [36c7628494774a618db4cef62cd10e10] django_auth_ldap Populating Django user sokell
2021-11-04T22:41:08.622256455Z stderr F 2021-11-04 22:41:08,621 DEBUG [36c7628494774a618db4cef62cd10e10] django_auth_ldap search_s(‘uid=sokell,cn=users,cn=accounts,dc=somewhere,dc=com’, 0, ‘(objectClass=*)’) returned 1 objects: uid=sokell,cn=users,cn=accounts,dc=somewhere,dc=com
2021-11-04T22:41:08.62343197Z stderr F 2021-11-04 22:41:08,623 DEBUG [36c7628494774a618db4cef62cd10e10] django_auth_ldap uid=sokell,cn=users,cn=accounts,dc=somewhere,dc=com is a member of cn=admins,cn=groups,cn=accounts,dc=somewhere,dc=com
2021-11-04T22:41:08.628409859Z stderr F 2021-11-04 22:41:08,627 DEBUG [36c7628494774a618db4cef62cd10e10] django_auth_ldap search_s(‘cn=groups,cn=accounts,dc=somewhere,dc=com’, 2, ‘(&(objectClass=groupOfNames)(member=uid=sokell,cn=users,cn=accounts,dc=somewhere,dc=com))’) returned 2 objects: cn=admins,cn=groups,cn=accounts,dc=somewhere,dc=com; cn=sysadmin,cn=groups,cn=accounts,dc=somewhere,dc=com
2021-11-04T22:41:08.659647092Z stderr F 2021-11-04 22:41:08,659 INFO [36c7628494774a618db4cef62cd10e10] awx.api.generics User sokell logged in from 10.42.0.14
2021-11-04T22:41:08.755822265Z stderr F 2021-11-04 22:41:08,755 DEBUG [36c7628494774a618db4cef62cd10e10] awx.analytics.performance request: <WSGIRequest: POST ‘/api/login/’>, response_time: 0.292s
2021-11-04T22:41:08.756956509Z stderr F [pid: 191|app: 0|req: 87/1141] 10.42.0.14 () {74 vars in 2880 bytes} [Thu Nov 4 22:41:08 2021] POST /api/login/ => generated 0 bytes in 294 msecs (HTTP/1.1 302) 15 headers in 2126 bytes (1 switches on core 0)
2021-11-04T22:41:08.756961547Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:08 +0000] “POST /api/login/ HTTP/1.1” 302 0 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:08.877737696Z stderr F 2021-11-04 22:41:08,876 DEBUG [5c963a80287a4e8bb93af4f9697dc882] awx.analytics.performance request: <WSGIRequest: GET ‘/api/v2/config/’>, response_time: 0.069s
2021-11-04T22:41:08.878479169Z stderr F [pid: 192|app: 0|req: 135/1142] 10.42.0.14 () {68 vars in 2773 bytes} [Thu Nov 4 22:41:08 2021] GET /api/v2/config/ => generated 2093 bytes in 70 msecs (HTTP/1.1 200) 14 headers in 584 bytes (1 switches on core 0)
2021-11-04T22:41:08.878598264Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:08 +0000] “GET /api/v2/config/ HTTP/1.1” 200 2093 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:08.942769461Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:08 +0000] “GET /static/media/logo-header.svg HTTP/1.1” 200 5459 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:08.946983233Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:08 +0000] “GET /static/media/default.strings.json HTTP/1.1” 200 53 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:09.067882045Z stderr F 2021-11-04 22:41:09,067 DEBUG [a6b7c0d02e3341a1a2b695e7929d47db] awx.analytics.performance request: <WSGIRequest: GET ‘/api/v2/config/’>, response_time: 0.069s
2021-11-04T22:41:09.068981444Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:09 +0000] “GET /api/v2/config/ HTTP/1.1” 200 2093 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:09.068990587Z stderr F [pid: 193|app: 0|req: 417/1143] 10.42.0.14 () {68 vars in 2773 bytes} [Thu Nov 4 22:41:08 2021] GET /api/v2/config/ => generated 2093 bytes in 71 msecs (HTTP/1.1 200) 14 headers in 584 bytes (1 switches on core 0)
2021-11-04T22:41:09.0866364Z stderr F 2021-11-04 22:41:09,086 DEBUG [b8f97278c6c54111b69ea448e336d347] awx.analytics.performance request: <WSGIRequest: GET ‘/api/v2/me/’>, response_time: 0.078s
2021-11-04T22:41:09.087473886Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:09 +0000] “GET /api/v2/me/ HTTP/1.1” 200 997 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:09.087820372Z stderr F [pid: 194|app: 0|req: 294/1144] 10.42.0.14 () {68 vars in 2765 bytes} [Thu Nov 4 22:41:09 2021] GET /api/v2/me/ => generated 997 bytes in 79 msecs (HTTP/1.1 200) 14 headers in 569 bytes (1 switches on core 0)
2021-11-04T22:41:09.247464016Z stderr F 2021-11-04 22:41:09,246 DEBUG [66502f937647406294ee372e310a94e3] awx.analytics.performance request: <WSGIRequest: GET ‘/api/v2/users/8/admin_of_organizations/’>, response_time: 0.099s
2021-11-04T22:41:09.247854155Z stderr F [pid: 193|app: 0|req: 418/1145] 10.42.0.14 () {68 vars in 2821 bytes} [Thu Nov 4 22:41:09 2021] GET /api/v2/users/8/admin_of_organizations/ => generated 52 bytes in 100 msecs (HTTP/1.1 200) 14 headers in 568 bytes (1 switches on core 0)
2021-11-04T22:41:09.248503124Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:09 +0000] “GET /api/v2/users/8/admin_of_organizations/ HTTP/1.1” 200 52 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:09.268922552Z stderr F 2021-11-04 22:41:09,268 DEBUG [73ed90dc213f42be8bd608ce5224b95b] awx.analytics.performance request: <WSGIRequest: GET ‘/api/v2/organizations/?page_size=1&role_level=notification_admin_role’>, response_time: 0.111s
2021-11-04T22:41:09.27158798Z stderr F [pid: 194|app: 0|req: 295/1146] 10.42.0.14 () {68 vars in 2880 bytes} [Thu Nov 4 22:41:09 2021] GET /api/v2/organizations/?page_size=1&role_level=notification_admin_role => generated 3408 bytes in 112 msecs (HTTP/1.1 200) 14 headers in 576 bytes (1 switches on core 0)
2021-11-04T22:41:09.271944681Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:09 +0000] “GET /api/v2/organizations/?page_size=1&role_level=notification_admin_role HTTP/1.1” 200 3408 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:09.421979637Z stderr F 2021-11-04 22:41:09,421 DEBUG [131934244f8f457b95e284c79cd5d311] awx.analytics.performance request: <WSGIRequest: GET ‘/api/v2/organizations/?page_size=1&role_level=execution_environment_admin_role’>, response_time: 0.119s
2021-11-04T22:41:09.42269119Z stderr F [pid: 193|app: 0|req: 419/1147] 10.42.0.14 () {68 vars in 2898 bytes} [Thu Nov 4 22:41:09 2021] GET /api/v2/organizations/?page_size=1&role_level=execution_environment_admin_role => generated 3408 bytes in 120 msecs (HTTP/1.1 200) 14 headers in 576 bytes (1 switches on core 0)
2021-11-04T22:41:09.422927201Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:09 +0000] “GET /api/v2/organizations/?page_size=1&role_level=execution_environment_admin_role HTTP/1.1” 200 3408 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:09.618163898Z stderr F 2021-11-04 22:41:09,617 DEBUG [362eee6c821c4ad78ca8be76bcc0706f] awx.analytics.performance request: <WSGIRequest: GET ‘/api/v2/dashboard/graphs/jobs/?job_type=all&period=month’>, response_time: 0.069s
2021-11-04T22:41:09.619223282Z stderr F [pid: 192|app: 0|req: 136/1148] 10.42.0.14 () {68 vars in 2854 bytes} [Thu Nov 4 22:41:09 2021] GET /api/v2/dashboard/graphs/jobs/?job_type=all&period=month => generated 1124 bytes in 70 msecs (HTTP/1.1 200) 14 headers in 570 bytes (1 switches on core 0)
2021-11-04T22:41:09.619666602Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:09 +0000] “GET /api/v2/dashboard/graphs/jobs/?job_type=all&period=month HTTP/1.1” 200 1124 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:09.622583087Z stderr F 2021-11-04 22:41:09,621 DEBUG [941a1b6d851d42ef86e9c4e1eab40598] awx.analytics.performance request: <WSGIRequest: GET ‘/api/v2/workflow_approvals/?page_size=1&status=pending’>, response_time: 0.073s
2021-11-04T22:41:09.624537252Z stderr F [pid: 193|app: 0|req: 420/1149] 10.42.0.14 () {68 vars in 2850 bytes} [Thu Nov 4 22:41:09 2021] GET /api/v2/workflow_approvals/?page_size=1&status=pending => generated 52 bytes in 75 msecs (HTTP/1.1 200) 14 headers in 574 bytes (1 switches on core 0)
2021-11-04T22:41:09.624570641Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:09 +0000] “GET /api/v2/workflow_approvals/?page_size=1&status=pending HTTP/1.1” 200 52 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:09.634678515Z stderr F 2021-11-04 22:41:09,634 DEBUG [742239a314f04a028971e09897cc2ff7] awx.analytics.performance request: <WSGIRequest: GET ‘/api/v2/dashboard/’>, response_time: 0.082s
2021-11-04T22:41:09.635702334Z stderr F [pid: 191|app: 0|req: 88/1150] 10.42.0.14 () {68 vars in 2779 bytes} [Thu Nov 4 22:41:09 2021] GET /api/v2/dashboard/ => generated 1428 bytes in 83 msecs (HTTP/1.1 200) 15 headers in 665 bytes (1 switches on core 0)
2021-11-04T22:41:09.635995229Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:09 +0000] “GET /api/v2/dashboard/ HTTP/1.1” 200 1428 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:09.6924989Z stderr F 2021-11-04 22:41:09,691 INFO Header X-API-Request-Id was not found in the incoming request. Generated new GUID: b3be8e4d3b4341019d87ff743f673497
2021-11-04T22:41:09.757282913Z stderr F 2021-11-04 22:41:09,756 DEBUG [b3be8e4d3b4341019d87ff743f673497] awx.analytics.performance request: <AsgiRequest: GET ‘/websocket/’>, response_time: 0.065s
2021-11-04T22:41:09.757774746Z stderr F 2021-11-04 22:41:09,757 WARNING [b3be8e4d3b4341019d87ff743f673497] django.request Not Found: /websocket/
2021-11-04T22:41:09.757817155Z stderr F 2021-11-04 22:41:09,757 WARNING [b3be8e4d3b4341019d87ff743f673497] django.request Not Found: /websocket/
2021-11-04T22:41:09.757838188Z stderr F 2021-11-04 22:41:09,757 WARNING Not Found: /websocket/
2021-11-04T22:41:09.75995741Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:09 +0000] “GET /websocket/ HTTP/1.1” 404 3878 “-” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:41:09.781237057Z stderr F 2021-11-04 22:41:09,780 DEBUG [0698aeeb994c4e23b2a7a64b0a54be6f] awx.analytics.performance request: <WSGIRequest: GET ‘/api/v2/dashboard/graphs/jobs/?job_type=all&period=month’>, response_time: 0.083s
2021-11-04T22:41:09.782144042Z stderr F [pid: 193|app: 0|req: 421/1151] 10.42.0.14 () {68 vars in 2854 bytes} [Thu Nov 4 22:41:09 2021] GET /api/v2/dashboard/graphs/jobs/?job_type=all&period=month => generated 1124 bytes in 85 msecs (HTTP/1.1 200) 14 headers in 570 bytes (1 switches on core 0)
2021-11-04T22:41:09.78225034Z stdout F 10.42.0.14 - - [04/Nov/2021:22:41:09 +0000] “GET /api/v2/dashboard/graphs/jobs/?job_type=all&period=month HTTP/1.1” 200 1124 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:43:00.260110299Z stderr F 2021-11-04 22:43:00,259 DEBUG [91a0d26d68af4732b2a4b8bc07876f3c] awx.analytics.performance request: <WSGIRequest: GET ‘/api/login/’>, response_time: 0.052s
2021-11-04T22:43:00.260748934Z stderr F [pid: 193|app: 0|req: 424/1156] 10.42.0.14 () {68 vars in 2722 bytes} [Thu Nov 4 22:43:00 2021] GET /api/login/ => generated 5710 bytes in 53 msecs (HTTP/1.1 200) 10 headers in 483 bytes (1 switches on core 0)
2021-11-04T22:43:00.261133799Z stdout F 10.42.0.14 - - [04/Nov/2021:22:43:00 +0000] “GET /api/login/ HTTP/1.1” 200 5710 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
2021-11-04T22:43:00.261268909Z stdout F RESULT 2
2021-11-04T22:43:00.261292733Z stdout F OKREADY
2021-11-04T22:43:00.383689339Z stderr F 2021-11-04 22:43:00,383 WARNING [cb428bff94a14c8891358348a7c08a55] awx.api.generics Login failed for user sokell from 10.42.0.14
2021-11-04T22:43:00.390776082Z stderr F 2021-11-04 22:43:00,390 DEBUG [cb428bff94a14c8891358348a7c08a55] awx.analytics.performance request: <WSGIRequest: POST ‘/api/login/’>, response_time: 0.072s
2021-11-04T22:43:00.391139316Z stderr F 2021-11-04 22:43:00,390 WARNING [cb428bff94a14c8891358348a7c08a55] django.request Unauthorized: /api/login/
2021-11-04T22:43:00.391204573Z stderr F 2021-11-04 22:43:00,390 WARNING [cb428bff94a14c8891358348a7c08a55] django.request Unauthorized: /api/login/
2021-11-04T22:43:00.391641793Z stderr F [pid: 193|app: 0|req: 425/1157] 10.42.0.14 () {74 vars in 2880 bytes} [Thu Nov 4 22:43:00 2021] POST /api/login/ => generated 5917 bytes in 74 msecs (HTTP/1.1 401) 10 headers in 493 bytes (1 switches on core 0)
2021-11-04T22:43:00.391851977Z stdout F 10.42.0.14 - - [04/Nov/2021:22:43:00 +0000] “POST /api/login/ HTTP/1.1” 401 5917 “https://awx.pci.somewhere.com/” “Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.54 Safari/537.36 Edg/95.0.1020.40” “10.42.0.1”
Thanks in advanced.