--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 21:37:29] Verification-idm pre : N/A
________________________________________________________________________________

[2024-04-15 21:37:29] - INFO: Timeout for this Task has changed to 2h (7200 seconds)
[2024-04-15 21:37:29] - INFO: timeout was set to Task default (2x global_duration or 300 seconds (whatever is higher)), because it was unset
________________________________________________________________________________

[2024-04-15 21:37:29] Verification-idm step1 : Wait until pods are in Running state and check number of running pods
________________________________________________________________________________

2024-04-15 21:37:29,646 INFO    
2024-04-15 21:37:29,646 INFO    ---------------------   Get expected number of pods   ---------------------
2024-04-15 21:37:29,649 INFO    
2024-04-15 21:37:29,649 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 21:37:29,660 INFO    [loop_until]: (max_time=180, interval=5, expected_rc=[0]
2024-04-15 21:37:30,888 INFO    [loop_until]: OK (rc = 0)
2024-04-15 21:37:30,888 DEBUG   --- stdout ---
2024-04-15 21:37:30,888 DEBUG   2
2024-04-15 21:37:30,888 DEBUG   --- stderr ---
2024-04-15 21:37:30,888 DEBUG   
2024-04-15 21:37:30,888 INFO    
2024-04-15 21:37:30,888 INFO    --------------   Waiting for 2 expected pod(s) to be ready   --------------
2024-04-15 21:37:30,889 INFO    
2024-04-15 21:37:30,889 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 21:37:30,890 INFO    [loop_until]: (max_time=900, interval=30, expected_rc=[0]
2024-04-15 21:37:31,619 INFO    [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found
2024-04-15 21:37:31,619 INFO    [loop_until]: OK (rc = 0)
2024-04-15 21:37:31,619 DEBUG   --- stdout ---
2024-04-15 21:37:31,619 DEBUG   ready:2 replicas:2
2024-04-15 21:37:31,619 DEBUG   --- stderr ---
2024-04-15 21:37:31,619 DEBUG   
________________________________________________________________________________

[2024-04-15 21:37:31] Verification-idm step2 : Discovering pods
________________________________________________________________________________

2024-04-15 21:37:31,620 INFO    
2024-04-15 21:37:31,620 INFO    ---------------------   Get expected number of pods   ---------------------
2024-04-15 21:37:31,621 INFO    
2024-04-15 21:37:31,621 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 21:37:31,621 INFO    [loop_until]: (max_time=180, interval=5, expected_rc=[0]
2024-04-15 21:37:32,155 INFO    [loop_until]: OK (rc = 0)
2024-04-15 21:37:32,156 DEBUG   --- stdout ---
2024-04-15 21:37:32,156 DEBUG   2
2024-04-15 21:37:32,156 DEBUG   --- stderr ---
2024-04-15 21:37:32,156 DEBUG   
2024-04-15 21:37:32,156 INFO    
2024-04-15 21:37:32,156 INFO    ----------------------------    Get pod list   ----------------------------
2024-04-15 21:37:32,156 INFO    
2024-04-15 21:37:32,156 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 21:37:32,157 INFO    [loop_until]: (max_time=180, interval=10, expected_rc=[0]
2024-04-15 21:37:33,154 INFO    [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found
2024-04-15 21:37:33,155 INFO    [loop_until]: OK (rc = 0)
2024-04-15 21:37:33,155 DEBUG   --- stdout ---
2024-04-15 21:37:33,155 DEBUG   idm-b85f9d978-j5pbm idm-b85f9d978-rl76f
2024-04-15 21:37:33,155 DEBUG   --- stderr ---
2024-04-15 21:37:33,155 DEBUG   
________________________________________________________________________________

[2024-04-15 21:37:33] Verification-idm step3 : Check component is alive
________________________________________________________________________________

2024-04-15 21:37:33,156 INFO    Livecheck to https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/info/ping
2024-04-15 21:37:33,156 INFO    Set admin password: 1UXqmgfePB4NHghbGcuasRXC
2024-04-15 21:37:33,158 INFO    [http_cmd]: curl -L --request GET  "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/info/ping"
2024-04-15 21:37:33,551 INFO    [http_cmd]: http status code OK
2024-04-15 21:37:33,552 DEBUG   ---  status code  ---
2024-04-15 21:37:33,552 DEBUG   http status code is 200 (expected 200)
2024-04-15 21:37:33,552 DEBUG   --- http response ---
2024-04-15 21:37:33,552 DEBUG   {
    "_id": "",
    "_rev": "",
    "shortDesc": "OpenIDM ready",
    "state": "ACTIVE_READY"
}

2024-04-15 21:37:33,552 INFO    [LoginSession] Get "access_token" token for user "amadmin"
2024-04-15 21:37:33,553 DEBUG   [LoginSession]		re-using "access_token" token that remains valid for 18m 23s
2024-04-15 21:37:33,553 INFO    Additional check to sync/queue to ensure sync with DS is ok (see LODESTAR-1245)
2024-04-15 21:37:33,553 INFO    [http_cmd]: curl -L --request GET  "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/sync/queue?_queryFilter=true&_pageSize=1"
2024-04-15 21:37:34,078 INFO    [http_cmd]: http status code OK
2024-04-15 21:37:34,078 DEBUG   ---  status code  ---
2024-04-15 21:37:34,078 DEBUG   http status code is 200 (expected 200)
2024-04-15 21:37:34,078 DEBUG   --- http response ---
2024-04-15 21:37:34,079 DEBUG   {
    "result": [],
    "resultCount": 0,
    "pagedResultsCookie": null,
    "totalPagedResultsPolicy": "NONE",
    "totalPagedResults": -1,
    "remainingPagedResults": -1
}

2024-04-15 21:37:34,082 INFO    Try to create, query and delete a user
2024-04-15 21:37:34,087 INFO    Create user idm_156qrqdnfa in IDM
2024-04-15 21:37:34,091 INFO    [http_cmd]: curl --header "Authorization: Bearer 1udGVJBcBFJ1aq3Zg-MvgvsZ3bo" --header "Content-Type: application/json" --insecure -L --request POST  --data '{"userName": "idm_156qrqdnfa", "givenName": "Peter", "sn": "Parker", "password": "T35tr0ck123", "telephoneNumber": "6669876987", "description": "IDM Test User", "roles": [], "mail": "idm_156qrqdnfa@forgerock.com"}' "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/managed/user?_action=create"
2024-04-15 21:37:34,361 INFO    [http_cmd]: http status code OK
2024-04-15 21:37:34,361 DEBUG   ---  status code  ---
2024-04-15 21:37:34,361 DEBUG   http status code is 201 (expected [200, 201])
2024-04-15 21:37:34,361 DEBUG   --- http response ---
2024-04-15 21:37:34,361 DEBUG   [print_head_tail]: Print head (10 lines) and tail (10 lines) of input string (34 lines):
2024-04-15 21:37:34,362 DEBUG   ----- output -----
2024-04-15 21:37:34,362 DEBUG   {
2024-04-15 21:37:34,362 DEBUG       "_id": "caffead3-c977-41c0-a8a8-b2aea228b652",
2024-04-15 21:37:34,362 DEBUG       "_rev": "d2dd67f6-c775-4646-8c43-6112461729ba-1067745",
2024-04-15 21:37:34,362 DEBUG       "country": null,
2024-04-15 21:37:34,362 DEBUG       "mail": "idm_156qrqdnfa@forgerock.com",
2024-04-15 21:37:34,362 DEBUG       "memberOfOrgIDs": [],
2024-04-15 21:37:34,362 DEBUG       "postalCode": null,
2024-04-15 21:37:34,362 DEBUG       "profileImage": null,
2024-04-15 21:37:34,362 DEBUG       "expireAccount": null,
2024-04-15 21:37:34,362 DEBUG       "activeDate": null,
2024-04-15 21:37:34,362 DEBUG   
2024-04-15 21:37:34,362 DEBUG   
2024-04-15 21:37:34,362 DEBUG   
2024-04-15 21:37:34,363 DEBUG   [...]
2024-04-15 21:37:34,363 DEBUG   
2024-04-15 21:37:34,363 DEBUG   
2024-04-15 21:37:34,363 DEBUG   
2024-04-15 21:37:34,363 DEBUG       "aliasList": [],
2024-04-15 21:37:34,363 DEBUG       "kbaInfo": [],
2024-04-15 21:37:34,363 DEBUG       "inactiveDate": null,
2024-04-15 21:37:34,363 DEBUG       "sn": "Parker",
2024-04-15 21:37:34,363 DEBUG       "preferences": null,
2024-04-15 21:37:34,363 DEBUG       "userName": "idm_156qrqdnfa",
2024-04-15 21:37:34,363 DEBUG       "passwordLastChangedTime": "2024-04-15T21:37:34.235Z",
2024-04-15 21:37:34,363 DEBUG       "effectiveRoles": [],
2024-04-15 21:37:34,363 DEBUG       "activateAccount": null
2024-04-15 21:37:34,363 DEBUG   }
2024-04-15 21:37:34,363 INFO    Query IDM to verify UserID caffead3-c977-41c0-a8a8-b2aea228b652 is visible
2024-04-15 21:37:34,363 INFO    [http_cmd]: curl --insecure -L --request GET  "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/managed/user/caffead3-c977-41c0-a8a8-b2aea228b652"
2024-04-15 21:37:34,572 INFO    [http_cmd]: http status code OK
2024-04-15 21:37:34,572 DEBUG   ---  status code  ---
2024-04-15 21:37:34,572 DEBUG   http status code is 200 (expected 200)
2024-04-15 21:37:34,572 DEBUG   --- http response ---
2024-04-15 21:37:34,573 DEBUG   [print_head_tail]: Print head (10 lines) and tail (10 lines) of input string (34 lines):
2024-04-15 21:37:34,573 DEBUG   ----- output -----
2024-04-15 21:37:34,573 DEBUG   {
2024-04-15 21:37:34,573 DEBUG       "_id": "caffead3-c977-41c0-a8a8-b2aea228b652",
2024-04-15 21:37:34,573 DEBUG       "_rev": "d2dd67f6-c775-4646-8c43-6112461729ba-1067745",
2024-04-15 21:37:34,573 DEBUG       "country": null,
2024-04-15 21:37:34,573 DEBUG       "mail": "idm_156qrqdnfa@forgerock.com",
2024-04-15 21:37:34,573 DEBUG       "memberOfOrgIDs": [],
2024-04-15 21:37:34,573 DEBUG       "postalCode": null,
2024-04-15 21:37:34,573 DEBUG       "profileImage": null,
2024-04-15 21:37:34,573 DEBUG       "expireAccount": null,
2024-04-15 21:37:34,573 DEBUG       "activeDate": null,
2024-04-15 21:37:34,573 DEBUG   
2024-04-15 21:37:34,573 DEBUG   
2024-04-15 21:37:34,573 DEBUG   
2024-04-15 21:37:34,573 DEBUG   [...]
2024-04-15 21:37:34,573 DEBUG   
2024-04-15 21:37:34,573 DEBUG   
2024-04-15 21:37:34,573 DEBUG   
2024-04-15 21:37:34,573 DEBUG       "aliasList": [],
2024-04-15 21:37:34,573 DEBUG       "kbaInfo": [],
2024-04-15 21:37:34,573 DEBUG       "inactiveDate": null,
2024-04-15 21:37:34,573 DEBUG       "sn": "Parker",
2024-04-15 21:37:34,573 DEBUG       "preferences": null,
2024-04-15 21:37:34,573 DEBUG       "userName": "idm_156qrqdnfa",
2024-04-15 21:37:34,573 DEBUG       "passwordLastChangedTime": "2024-04-15T21:37:34.235Z",
2024-04-15 21:37:34,573 DEBUG       "effectiveRoles": [],
2024-04-15 21:37:34,573 DEBUG       "activateAccount": null
2024-04-15 21:37:34,573 DEBUG   }
2024-04-15 21:37:34,574 INFO    Authenticate as user idm_156qrqdnfa
2024-04-15 21:37:34,574 INFO    [http_cmd]: curl --insecure -L --request POST  "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/authentication?_action=login"
2024-04-15 21:37:34,779 INFO    [http_cmd]: http status code OK
2024-04-15 21:37:34,780 DEBUG   ---  status code  ---
2024-04-15 21:37:34,780 DEBUG   http status code is 200 (expected 200)
2024-04-15 21:37:34,780 DEBUG   --- http response ---
2024-04-15 21:37:34,780 DEBUG   {
    "_id": "login",
    "authorization": {
        "id": "anonymous",
        "roles": [
            "internal/role/openidm-reg"
        ],
        "component": "internal/user"
    },
    "authenticationId": "anonymous"
}

2024-04-15 21:37:34,782 INFO    [http_cmd]: curl --insecure -L --request DELETE  "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/managed/user/caffead3-c977-41c0-a8a8-b2aea228b652"
2024-04-15 21:37:35,086 INFO    [http_cmd]: http status code OK
2024-04-15 21:37:35,087 DEBUG   ---  status code  ---
2024-04-15 21:37:35,087 DEBUG   http status code is 200 (expected 200)
2024-04-15 21:37:35,087 DEBUG   --- http response ---
2024-04-15 21:37:35,087 DEBUG   [print_head_tail]: Print head (10 lines) and tail (10 lines) of input string (34 lines):
2024-04-15 21:37:35,088 DEBUG   ----- output -----
2024-04-15 21:37:35,088 DEBUG   {
2024-04-15 21:37:35,088 DEBUG       "_id": "caffead3-c977-41c0-a8a8-b2aea228b652",
2024-04-15 21:37:35,088 DEBUG       "_rev": "d2dd67f6-c775-4646-8c43-6112461729ba-1067745",
2024-04-15 21:37:35,088 DEBUG       "country": null,
2024-04-15 21:37:35,088 DEBUG       "mail": "idm_156qrqdnfa@forgerock.com",
2024-04-15 21:37:35,088 DEBUG       "memberOfOrgIDs": [],
2024-04-15 21:37:35,088 DEBUG       "postalCode": null,
2024-04-15 21:37:35,088 DEBUG       "profileImage": null,
2024-04-15 21:37:35,088 DEBUG       "expireAccount": null,
2024-04-15 21:37:35,088 DEBUG       "activeDate": null,
2024-04-15 21:37:35,088 DEBUG   
2024-04-15 21:37:35,088 DEBUG   
2024-04-15 21:37:35,088 DEBUG   
2024-04-15 21:37:35,088 DEBUG   [...]
2024-04-15 21:37:35,088 DEBUG   
2024-04-15 21:37:35,088 DEBUG   
2024-04-15 21:37:35,088 DEBUG   
2024-04-15 21:37:35,088 DEBUG       "aliasList": [],
2024-04-15 21:37:35,088 DEBUG       "kbaInfo": [],
2024-04-15 21:37:35,088 DEBUG       "inactiveDate": null,
2024-04-15 21:37:35,088 DEBUG       "sn": "Parker",
2024-04-15 21:37:35,088 DEBUG       "preferences": null,
2024-04-15 21:37:35,088 DEBUG       "userName": "idm_156qrqdnfa",
2024-04-15 21:37:35,088 DEBUG       "passwordLastChangedTime": "2024-04-15T21:37:34.235Z",
2024-04-15 21:37:35,088 DEBUG       "effectiveRoles": [],
2024-04-15 21:37:35,088 DEBUG       "activateAccount": null
2024-04-15 21:37:35,088 DEBUG   }
PASS : component idm is alive
________________________________________________________________________________

[2024-04-15 21:37:35] Verification-idm step4 : Record version
________________________________________________________________________________

2024-04-15 21:37:35,118 INFO    
2024-04-15 21:37:35,119 INFO    ----------------------    Get IDM software version   ----------------------
2024-04-15 21:37:35,121 INFO    Getting product version from https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/info/version
2024-04-15 21:37:35,127 INFO    [http_cmd]: curl -L --request GET  "https://xlou.iam.xlou-cdm.engineeringpit.com/openidm/info/version"
2024-04-15 21:37:35,434 INFO    [http_cmd]: http status code OK
2024-04-15 21:37:35,434 DEBUG   ---  status code  ---
2024-04-15 21:37:35,434 DEBUG   http status code is 200 (expected 200)
2024-04-15 21:37:35,435 DEBUG   --- http response ---
2024-04-15 21:37:35,435 DEBUG   {
    "_id": "version",
    "productVersion": "7.6.0-SNAPSHOT",
    "productBuildDate": "20240411202127",
    "productRevision": "8554e0d1c5"
}

Version is 7.6.0-SNAPSHOT
Revision is 8554e0d1c5
________________________________________________________________________________

[2024-04-15 21:37:35] Verification-idm step5 :  Checking pod restart counts 
________________________________________________________________________________

2024-04-15 21:37:35,452 INFO    
2024-04-15 21:37:35,452 INFO    -------------   Check pod idm-b85f9d978-j5pbm restart count   -------------
2024-04-15 21:37:35,453 INFO    
2024-04-15 21:37:35,453 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 21:37:35,453 INFO    [loop_until]: (max_time=180, interval=5, expected_rc=[0]
2024-04-15 21:37:36,005 INFO    [loop_until]: OK (rc = 0)
2024-04-15 21:37:36,005 DEBUG   --- stdout ---
2024-04-15 21:37:36,005 DEBUG   0
2024-04-15 21:37:36,005 DEBUG   --- stderr ---
2024-04-15 21:37:36,005 DEBUG   
2024-04-15 21:37:36,005 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 21:37:36,005 INFO    
2024-04-15 21:37:36,006 INFO    -------------   Check pod idm-b85f9d978-rl76f restart count   -------------
2024-04-15 21:37:36,006 INFO    
2024-04-15 21:37:36,006 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 21:37:36,006 INFO    [loop_until]: (max_time=180, interval=5, expected_rc=[0]
2024-04-15 21:37:36,401 INFO    [loop_until]: OK (rc = 0)
2024-04-15 21:37:36,402 DEBUG   --- stdout ---
2024-04-15 21:37:36,403 DEBUG   0
2024-04-15 21:37:36,403 DEBUG   --- stderr ---
2024-04-15 21:37:36,403 DEBUG   
2024-04-15 21:37:36,403 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 21:37:36] Verification-idm post : Post method
________________________________________________________________________________

Setting result to PASS
Task has been successfully stopped