--Task-- name: Verification-idm enabled: True class_name: VerificationTask source_name: idm source_namespace: >default< target_name: idm target_namespace: >default< start: 0.0 stop: None timeout: not yet initialized for this Task as timeout was not explicitly defined, see updates bellow loop: False interval: None dependencies: [] wait_for: [] preceding_task: None options: {} group_name: None Current dir: /mnt/disks/data/xslou/lodestar-fork/pyrock ________________________________________________________________________________ [2024-04-15 00:03:27] Verification-idm pre : N/A ________________________________________________________________________________ [2024-04-15 00:03:27] - INFO: Timeout for this Task has changed to 14h (50400 seconds) [2024-04-15 00:03:27] - INFO: timeout was set to Task default (2x global_duration or 300 seconds (whatever is higher)), because it was unset ________________________________________________________________________________ [2024-04-15 00:03:27] Verification-idm step1 : Wait until pods are in Running state and check number of running pods ________________________________________________________________________________ 2024-04-15 00:03:27,759 INFO 2024-04-15 00:03:27,763 INFO --------------------- Get expected number of pods --------------------- 2024-04-15 00:03:27,785 INFO 2024-04-15 00:03:27,786 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get deployment --selector app=idm --output jsonpath={.items[*].spec.replicas} 2024-04-15 00:03:27,786 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-04-15 00:03:29,025 INFO [loop_until]: OK (rc = 0) 2024-04-15 00:03:29,025 DEBUG --- stdout --- 2024-04-15 00:03:29,025 DEBUG 2 2024-04-15 00:03:29,025 DEBUG --- stderr --- 2024-04-15 00:03:29,025 DEBUG 2024-04-15 00:03:29,025 INFO 2024-04-15 00:03:29,025 INFO -------------- Waiting for 2 expected pod(s) to be ready -------------- 2024-04-15 00:03:29,026 INFO 2024-04-15 00:03:29,026 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get deployment idm --output jsonpath="ready:{.status.readyReplicas} replicas:{.status.replicas}" | grep "ready:2 replicas:2" 2024-04-15 00:03:29,026 INFO [loop_until]: (max_time=900, interval=30, expected_rc=[0] 2024-04-15 00:03:29,932 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-04-15 00:03:29,933 INFO [loop_until]: OK (rc = 0) 2024-04-15 00:03:29,933 DEBUG --- stdout --- 2024-04-15 00:03:29,933 DEBUG ready:2 replicas:2 2024-04-15 00:03:29,933 DEBUG --- stderr --- 2024-04-15 00:03:29,933 DEBUG ________________________________________________________________________________ [2024-04-15 00:03:29] Verification-idm step2 : Discovering pods ________________________________________________________________________________ 2024-04-15 00:03:29,935 INFO 2024-04-15 00:03:29,935 INFO --------------------- Get expected number of pods --------------------- 2024-04-15 00:03:29,935 INFO 2024-04-15 00:03:29,936 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get deployment --selector app=idm --output jsonpath={.items[*].spec.replicas} 2024-04-15 00:03:29,936 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-04-15 00:03:30,843 INFO [loop_until]: OK (rc = 0) 2024-04-15 00:03:30,844 DEBUG --- stdout --- 2024-04-15 00:03:30,844 DEBUG 2 2024-04-15 00:03:30,844 DEBUG --- stderr --- 2024-04-15 00:03:30,844 DEBUG 2024-04-15 00:03:30,844 INFO 2024-04-15 00:03:30,844 INFO ---------------------------- Get pod list ---------------------------- 2024-04-15 00:03:30,844 INFO 2024-04-15 00:03:30,845 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=idm --output jsonpath={.items[*].metadata.name}` | grep 2 2024-04-15 00:03:30,845 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-04-15 00:03:31,498 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-04-15 00:03:31,499 INFO [loop_until]: OK (rc = 0) 2024-04-15 00:03:31,499 DEBUG --- stdout --- 2024-04-15 00:03:31,499 DEBUG idm-b85f9d978-j5pbm idm-b85f9d978-rl76f 2024-04-15 00:03:31,499 DEBUG --- stderr --- 2024-04-15 00:03:31,499 DEBUG ________________________________________________________________________________ [2024-04-15 00:03:31] Verification-idm step3 : Check component is alive ________________________________________________________________________________ 2024-04-15 00:03:31,500 INFO Livecheck to https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/info/ping 2024-04-15 00:03:31,500 INFO Set admin password: 1UXqmgfePB4NHghbGcuasRXC 2024-04-15 00:03:31,500 INFO [http_cmd]: curl -L --request GET "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/info/ping" 2024-04-15 00:03:31,728 INFO [http_cmd]: http status code OK 2024-04-15 00:03:31,729 DEBUG --- status code --- 2024-04-15 00:03:31,729 DEBUG http status code is 200 (expected 200) 2024-04-15 00:03:31,729 DEBUG --- http response --- 2024-04-15 00:03:31,729 DEBUG { "_id": "", "_rev": "", "shortDesc": "OpenIDM ready", "state": "ACTIVE_READY" } 2024-04-15 00:03:32,097 INFO [LoginSession] Get "access_token" token for user "amadmin" 2024-04-15 00:03:32,097 INFO [LoginSession] Obtaining new "access_token" token from server because it has expired 2024-04-15 00:03:32,097 INFO [LoginSession] Get "token_id" token for user "amadmin" 2024-04-15 00:03:32,097 DEBUG [LoginSession] re-using "token_id" token that remains valid for 2m 48s 2024-04-15 00:03:32,097 INFO Obtain Oauth2 authz code via REST 2024-04-15 00:03:32,097 DEBUG Oauth2 authorize for access token 2024-04-15 00:03:32,097 INFO [http_cmd]: curl --request POST --cookie "amlbcookie=01" --cookie "iPlanetDirectoryPro=jC_CTNhP2LBUlyXBiHN610etJF0.*AAJTSQACMDIAAlNLABxCakJTaVNGZkx6VnNzUVhUVjhKY2NtVmNIckE9AAR0eXBlAANDVFMAAlMxAAIwMQ..*" --cookie "route=1713139412.834.49430.8260|f60edb382037eb2df1e800d563ad78a7" --data '{"decision": "Allow", "csrf": "jC_CTNhP2LBUlyXBiHN610etJF0.*AAJTSQACMDIAAlNLABxCakJTaVNGZkx6VnNzUVhUVjhKY2NtVmNIckE9AAR0eXBlAANDVFMAAlMxAAIwMQ..*"}' "https://xlou.iam.xlou-cdm.engineeringpit.com/am/oauth2/authorize?client_id=smokeclient&scope=fr:idm:*&redirect_uri=https://fake.com&response_type=code&realm=/" 2024-04-15 00:03:32,344 INFO [http_cmd]: http status code OK 2024-04-15 00:03:32,345 DEBUG --- status code --- 2024-04-15 00:03:32,345 DEBUG http status code is 302 (expected 302) 2024-04-15 00:03:32,345 DEBUG --- http response --- 2024-04-15 00:03:32,345 DEBUG {'Date': 'Mon, 15 Apr 2024 00:03:32 GMT', 'Content-Length': '0', 'Connection': 'keep-alive', 'X-Frame-Options': 'SAMEORIGIN', 'X-Content-Type-Options': 'nosniff', 'Cache-Control': 'no-store', 'Location': 'https://fake.com?code=JeG-QHECXPCcW7mFOlJ4T9vPni4&iss=https%3A%2F%2Fxlou.iam.xlou-cdm.engineeringpit.com%2Fam%2Foauth2&client_id=smokeclient', 'Pragma': 'no-cache', 'Set-Cookie': 'OAUTH_REQUEST_ATTRIBUTES=DELETED; Expires=Thu, 01 Jan 1970 00:00:00 GMT; Path=/; Secure; HttpOnly; SameSite=none', 'Strict-Transport-Security': 'max-age=15724800; includeSubDomains'} 2024-04-15 00:03:32,345 DEBUG Oauth2 exchange authorize code for access token 2024-04-15 00:03:32,345 INFO [http_cmd]: curl -L --request POST --data '{"grant_type": "authorization_code", "redirect_uri": "https://fake.com", "client_id": "smokeclient", "code": "JeG-QHECXPCcW7mFOlJ4T9vPni4"}' "https://xlou.iam.xlou-cdm.engineeringpit.com/am/oauth2/access_token?realm=/" 2024-04-15 00:03:32,424 INFO [http_cmd]: http status code OK 2024-04-15 00:03:32,425 DEBUG --- status code --- 2024-04-15 00:03:32,425 DEBUG http status code is 200 (expected 200) 2024-04-15 00:03:32,425 DEBUG --- http response --- 2024-04-15 00:03:32,425 DEBUG { "access_token": "_If_d9Xa9v2hyBgy4gDr_FKRwog", "scope": "fr:idm:*", "token_type": "Bearer", "expires_in": 3599 } 2024-04-15 00:03:32,428 INFO Additional check to sync/queue to ensure sync with DS is ok (see LODESTAR-1245) 2024-04-15 00:03:32,429 INFO [http_cmd]: curl -L --request GET "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/sync/queue?_queryFilter=true&_pageSize=1" 2024-04-15 00:03:32,691 INFO [http_cmd]: http status code OK 2024-04-15 00:03:32,691 DEBUG --- status code --- 2024-04-15 00:03:32,691 DEBUG http status code is 200 (expected 200) 2024-04-15 00:03:32,691 DEBUG --- http response --- 2024-04-15 00:03:32,691 DEBUG { "result": [], "resultCount": 0, "pagedResultsCookie": null, "totalPagedResultsPolicy": "NONE", "totalPagedResults": -1, "remainingPagedResults": -1 } 2024-04-15 00:03:32,693 INFO Try to create, query and delete a user 2024-04-15 00:03:32,693 INFO Create user idm_sr9ug1b977 in IDM 2024-04-15 00:03:32,694 INFO [http_cmd]: curl --header "Authorization: Bearer _If_d9Xa9v2hyBgy4gDr_FKRwog" --header "Content-Type: application/json" --insecure -L --request POST --data '{"userName": "idm_sr9ug1b977", "givenName": "Peter", "sn": "Parker", "password": "T35tr0ck123", "telephoneNumber": "6669876987", "description": "IDM Test User", "roles": [], "mail": "idm_sr9ug1b977@forgerock.com"}' "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/managed/user?_action=create" 2024-04-15 00:03:32,975 INFO [http_cmd]: http status code OK 2024-04-15 00:03:32,975 DEBUG --- status code --- 2024-04-15 00:03:32,976 DEBUG http status code is 201 (expected [200, 201]) 2024-04-15 00:03:32,976 DEBUG --- http response --- 2024-04-15 00:03:32,976 DEBUG [print_head_tail]: Print head (10 lines) and tail (10 lines) of input string (34 lines): 2024-04-15 00:03:32,976 DEBUG ----- output ----- 2024-04-15 00:03:32,976 DEBUG { 2024-04-15 00:03:32,976 DEBUG "_id": "23510750-446b-4344-bf33-f43d0d6b37fd", 2024-04-15 00:03:32,976 DEBUG "_rev": "d2dd67f6-c775-4646-8c43-6112461729ba-1036659", 2024-04-15 00:03:32,976 DEBUG "country": null, 2024-04-15 00:03:32,976 DEBUG "mail": "idm_sr9ug1b977@forgerock.com", 2024-04-15 00:03:32,976 DEBUG "memberOfOrgIDs": [], 2024-04-15 00:03:32,976 DEBUG "postalCode": null, 2024-04-15 00:03:32,976 DEBUG "profileImage": null, 2024-04-15 00:03:32,976 DEBUG "expireAccount": null, 2024-04-15 00:03:32,976 DEBUG "activeDate": null, 2024-04-15 00:03:32,976 DEBUG 2024-04-15 00:03:32,976 DEBUG 2024-04-15 00:03:32,976 DEBUG 2024-04-15 00:03:32,976 DEBUG [...] 2024-04-15 00:03:32,976 DEBUG 2024-04-15 00:03:32,976 DEBUG 2024-04-15 00:03:32,976 DEBUG 2024-04-15 00:03:32,976 DEBUG "aliasList": [], 2024-04-15 00:03:32,976 DEBUG "kbaInfo": [], 2024-04-15 00:03:32,976 DEBUG "inactiveDate": null, 2024-04-15 00:03:32,976 DEBUG "sn": "Parker", 2024-04-15 00:03:32,976 DEBUG "preferences": null, 2024-04-15 00:03:32,977 DEBUG "userName": "idm_sr9ug1b977", 2024-04-15 00:03:32,977 DEBUG "passwordLastChangedTime": "2024-04-15T00:03:32.802Z", 2024-04-15 00:03:32,977 DEBUG "effectiveRoles": [], 2024-04-15 00:03:32,977 DEBUG "activateAccount": null 2024-04-15 00:03:32,977 DEBUG } 2024-04-15 00:03:32,977 INFO Query IDM to verify UserID 23510750-446b-4344-bf33-f43d0d6b37fd is visible 2024-04-15 00:03:32,977 INFO [http_cmd]: curl --insecure -L --request GET "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/managed/user/23510750-446b-4344-bf33-f43d0d6b37fd" 2024-04-15 00:03:33,189 INFO [http_cmd]: http status code OK 2024-04-15 00:03:33,189 DEBUG --- status code --- 2024-04-15 00:03:33,189 DEBUG http status code is 200 (expected 200) 2024-04-15 00:03:33,189 DEBUG --- http response --- 2024-04-15 00:03:33,190 DEBUG [print_head_tail]: Print head (10 lines) and tail (10 lines) of input string (34 lines): 2024-04-15 00:03:33,190 DEBUG ----- output ----- 2024-04-15 00:03:33,190 DEBUG { 2024-04-15 00:03:33,190 DEBUG "_id": "23510750-446b-4344-bf33-f43d0d6b37fd", 2024-04-15 00:03:33,190 DEBUG "_rev": "d2dd67f6-c775-4646-8c43-6112461729ba-1036659", 2024-04-15 00:03:33,190 DEBUG "country": null, 2024-04-15 00:03:33,190 DEBUG "mail": "idm_sr9ug1b977@forgerock.com", 2024-04-15 00:03:33,190 DEBUG "memberOfOrgIDs": [], 2024-04-15 00:03:33,191 DEBUG "postalCode": null, 2024-04-15 00:03:33,191 DEBUG "profileImage": null, 2024-04-15 00:03:33,191 DEBUG "expireAccount": null, 2024-04-15 00:03:33,191 DEBUG "activeDate": null, 2024-04-15 00:03:33,191 DEBUG 2024-04-15 00:03:33,191 DEBUG 2024-04-15 00:03:33,191 DEBUG 2024-04-15 00:03:33,191 DEBUG [...] 2024-04-15 00:03:33,191 DEBUG 2024-04-15 00:03:33,191 DEBUG 2024-04-15 00:03:33,191 DEBUG 2024-04-15 00:03:33,191 DEBUG "aliasList": [], 2024-04-15 00:03:33,191 DEBUG "kbaInfo": [], 2024-04-15 00:03:33,191 DEBUG "inactiveDate": null, 2024-04-15 00:03:33,191 DEBUG "sn": "Parker", 2024-04-15 00:03:33,191 DEBUG "preferences": null, 2024-04-15 00:03:33,191 DEBUG "userName": "idm_sr9ug1b977", 2024-04-15 00:03:33,191 DEBUG "passwordLastChangedTime": "2024-04-15T00:03:32.802Z", 2024-04-15 00:03:33,191 DEBUG "effectiveRoles": [], 2024-04-15 00:03:33,191 DEBUG "activateAccount": null 2024-04-15 00:03:33,191 DEBUG } 2024-04-15 00:03:33,192 INFO Authenticate as user idm_sr9ug1b977 2024-04-15 00:03:33,192 INFO [http_cmd]: curl --insecure -L --request POST "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/authentication?_action=login" 2024-04-15 00:03:33,420 INFO [http_cmd]: http status code OK 2024-04-15 00:03:33,420 DEBUG --- status code --- 2024-04-15 00:03:33,420 DEBUG http status code is 200 (expected 200) 2024-04-15 00:03:33,420 DEBUG --- http response --- 2024-04-15 00:03:33,421 DEBUG { "_id": "login", "authorization": { "id": "anonymous", "roles": [ "internal/role/openidm-reg" ], "component": "internal/user" }, "authenticationId": "anonymous" } 2024-04-15 00:03:33,425 INFO [http_cmd]: curl --insecure -L --request DELETE "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/managed/user/23510750-446b-4344-bf33-f43d0d6b37fd" 2024-04-15 00:03:33,694 INFO [http_cmd]: http status code OK 2024-04-15 00:03:33,695 DEBUG --- status code --- 2024-04-15 00:03:33,695 DEBUG http status code is 200 (expected 200) 2024-04-15 00:03:33,695 DEBUG --- http response --- 2024-04-15 00:03:33,696 DEBUG [print_head_tail]: Print head (10 lines) and tail (10 lines) of input string (34 lines): 2024-04-15 00:03:33,696 DEBUG ----- output ----- 2024-04-15 00:03:33,696 DEBUG { 2024-04-15 00:03:33,696 DEBUG "_id": "23510750-446b-4344-bf33-f43d0d6b37fd", 2024-04-15 00:03:33,696 DEBUG "_rev": "d2dd67f6-c775-4646-8c43-6112461729ba-1036659", 2024-04-15 00:03:33,696 DEBUG "country": null, 2024-04-15 00:03:33,696 DEBUG "mail": "idm_sr9ug1b977@forgerock.com", 2024-04-15 00:03:33,696 DEBUG "memberOfOrgIDs": [], 2024-04-15 00:03:33,696 DEBUG "postalCode": null, 2024-04-15 00:03:33,696 DEBUG "profileImage": null, 2024-04-15 00:03:33,696 DEBUG "expireAccount": null, 2024-04-15 00:03:33,696 DEBUG "activeDate": null, 2024-04-15 00:03:33,696 DEBUG 2024-04-15 00:03:33,697 DEBUG 2024-04-15 00:03:33,697 DEBUG 2024-04-15 00:03:33,697 DEBUG [...] 2024-04-15 00:03:33,697 DEBUG 2024-04-15 00:03:33,697 DEBUG 2024-04-15 00:03:33,697 DEBUG 2024-04-15 00:03:33,697 DEBUG "aliasList": [], 2024-04-15 00:03:33,697 DEBUG "kbaInfo": [], 2024-04-15 00:03:33,697 DEBUG "inactiveDate": null, 2024-04-15 00:03:33,697 DEBUG "sn": "Parker", 2024-04-15 00:03:33,697 DEBUG "preferences": null, 2024-04-15 00:03:33,697 DEBUG "userName": "idm_sr9ug1b977", 2024-04-15 00:03:33,697 DEBUG "passwordLastChangedTime": "2024-04-15T00:03:32.802Z", 2024-04-15 00:03:33,697 DEBUG "effectiveRoles": [], 2024-04-15 00:03:33,697 DEBUG "activateAccount": null 2024-04-15 00:03:33,697 DEBUG } PASS : component idm is alive ________________________________________________________________________________ [2024-04-15 00:03:33] Verification-idm step4 : Record version ________________________________________________________________________________ 2024-04-15 00:03:33,704 INFO 2024-04-15 00:03:33,735 INFO ---------------------- Get IDM software version ---------------------- 2024-04-15 00:03:33,736 INFO Getting product version from https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/info/version 2024-04-15 00:03:33,736 INFO [http_cmd]: curl -L --request GET "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/info/version" 2024-04-15 00:03:33,990 INFO [http_cmd]: http status code OK 2024-04-15 00:03:33,990 DEBUG --- status code --- 2024-04-15 00:03:33,990 DEBUG http status code is 200 (expected 200) 2024-04-15 00:03:33,990 DEBUG --- http response --- 2024-04-15 00:03:33,990 DEBUG { "_id": "version", "productVersion": "7.6.0-SNAPSHOT", "productBuildDate": "20240411202127", "productRevision": "8554e0d1c5" } Version is 7.6.0-SNAPSHOT Revision is 8554e0d1c5 ________________________________________________________________________________ [2024-04-15 00:03:33] Verification-idm step5 : Checking pod restart counts ________________________________________________________________________________ 2024-04-15 00:03:33,992 INFO 2024-04-15 00:03:33,992 INFO ------------- Check pod idm-b85f9d978-j5pbm restart count ------------- 2024-04-15 00:03:33,993 INFO 2024-04-15 00:03:33,993 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pod idm-b85f9d978-j5pbm --output jsonpath={.status.containerStatuses[*].restartCount} 2024-04-15 00:03:33,993 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-04-15 00:03:34,380 INFO [loop_until]: OK (rc = 0) 2024-04-15 00:03:34,380 DEBUG --- stdout --- 2024-04-15 00:03:34,380 DEBUG 0 2024-04-15 00:03:34,380 DEBUG --- stderr --- 2024-04-15 00:03:34,380 DEBUG 2024-04-15 00:03:34,380 INFO Pod idm-b85f9d978-j5pbm has been restarted 0 times. SUCCESS : pod restart count (0) did not change between validation and verification phases 2024-04-15 00:03:34,380 INFO 2024-04-15 00:03:34,380 INFO ------------- Check pod idm-b85f9d978-rl76f restart count ------------- 2024-04-15 00:03:34,381 INFO 2024-04-15 00:03:34,381 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pod idm-b85f9d978-rl76f --output jsonpath={.status.containerStatuses[*].restartCount} 2024-04-15 00:03:34,381 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-04-15 00:03:34,820 INFO [loop_until]: OK (rc = 0) 2024-04-15 00:03:34,821 DEBUG --- stdout --- 2024-04-15 00:03:34,821 DEBUG 0 2024-04-15 00:03:34,821 DEBUG --- stderr --- 2024-04-15 00:03:34,821 DEBUG 2024-04-15 00:03:34,821 INFO Pod idm-b85f9d978-rl76f has been restarted 0 times. SUCCESS : pod restart count (0) did not change between validation and verification phases ________________________________________________________________________________ [2024-04-15 00:03:34] Verification-idm post : Post method ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped