Snapshot restoration wait_for_completion doesn't get respected

[SperleaAdrian]

curator --dry-run --config myconfig mytemplate doesn't wait for completion even if "wait_for_completion" is set as True in yaml template.

Example yml for restore:

actions:
  1:
    action: restore
    description: >-
      Restore all indices in the most recent curator-* snapshot with state
      SUCCESS.  Wait for the restore to complete before continuing.  Do not skip
      the repository filesystem access check.  Use the other options to define
      the index/shard settings for the restore.
    options:
      repository: snapshots-repo
      name:
      indices: ["myindex*"]
      rename_pattern: 'myindex-images-(.+)'
      rename_replacement: 'restored-myindex-images-$1'
      wait_for_completion: True
      max_wait: 3600
      wait_interval: 10
    filters:
    #filter for snapshots with SUCCESS state and with prefix curator-
    - filtertype: pattern
      kind: prefix
      value: curator-
    - filtertype: state
      state: SUCCESS

Hier is an excerpt of the curator DEBUG Logs

..
2024-01-22 18:07:40,298 DEBUG     curator.actions.snapshot               __init__:1836 "most_recent" snapshot: curator-myindex-20240122170002
2024-01-22 18:07:40,299 DEBUG     curator.actions.snapshot               __init__:1906 REPOSITORY: snapshots-repo
2024-01-22 18:07:40,299 DEBUG     curator.actions.snapshot               __init__:1907 WAIT_FOR_COMPLETION: True
2024-01-22 18:07:40,299 DEBUG     curator.actions.snapshot               __init__:1908 SKIP_REPO_FS_CHECK: False
2024-01-22 18:07:40,299 DEBUG     curator.actions.snapshot               __init__:1910 BODY: {'indices': ['myindex*'], 'include_aliases': False, 'ignore_unavailable': False, 'include_global_state': False, 'partial': False, 'rename_pattern': 'myindex-images-(.+)', 'rename_replacement': 'restored-myindex-images-$1'}
2024-01-22 18:07:40,300 DEBUG     curator.actions.snapshot   _get_expected_output:1927 index: myindex* replacement: myindex*
2024-01-22 18:07:40,300 DEBUG                curator.cli         process_action:103  Doing the action here.
..
2024-01-22 18:07:40,505 INFO      curator.actions.snapshot              do_action:1992 Restoring indices "['myindex*']" from snapshot: curator-myindex-20240122170002
2024-01-22 18:07:41,666 DEBUG     urllib3.connectionpool          _make_request:474  https://mydomainindex:443 "POST /_snapshot/snapshots-repo/curator-myindex-20240122170002/_restore?wait_for_completion=false HTTP/1.1" 200 17
2024-01-22 18:07:41,667 INFO                  opensearch    log_request_success:259  POST https://mydomainindex:443/_snapshot/snapshots-repo/curator-myindex-20240122170002/_restore?wait_for_completion=false [status:200 request:1.161s]
2024-01-22 18:07:41,667 DEBUG                 opensearch  _log_request_response:198  > {"indices":["myindex*"],"include_aliases":false,"ignore_unavailable":false,"include_global_state":false,"partial":false,"rename_pattern":"myindex-images-(.+)","rename_replacement":"restored-myindex-images-$1"}
2024-01-22 18:07:41,667 DEBUG                 opensearch  _log_request_response:200  < {"accepted":true}
2024-01-22 18:07:41,668 DEBUG              curator.utils            wait_for_it:1926 Elapsed time: 0 seconds
...
2024-01-22 18:07:41,762 DEBUG     urllib3.connectionpool          _make_request:474  https://mydomainindex:443 "GET /myindex*/_recovery?human=true HTTP/1.1" 200 2266
2024-01-22 18:07:41,763 INFO                  opensearch    log_request_success:259  GET https://mydomainindex:443/myindex*/_recovery?human=true [status:200 request:0.095s]
2024-01-22 18:07:41,763 DEBUG                 opensearch  _log_request_response:198  > None
2024-01-22 18:07:41,764 DEBUG                 opensearch  _log_request_response:200  < {"myindex-images-2023-07-06-14-22":{"shards":[{"id":0,"type":"EXISTING_STORE","stage":"DONE","primary":true,"start_time":"2024-01-21T12:48:32.641Z","start_time_in_millis":1705841312641,"stop_time":"2024-01-21T12:48:33.946Z","stop_time_in_millis":1705841313946,"total_time":"1.3s","total_time_in_millis":1305,"source":{"bootstrap_new_history_uuid":false},"target":{"id":"U9MqM7W2QxWRRHgK3VaqEw","host":"x.x.x.x","transport_address":"x.x.x.x:9300","ip":"x.x.x.x","name":"e2ececbd2113789a34ec878eeb2e23fa"},"index":{"size":{"total":"13.9gb","total_in_bytes":15029918919,"reused":"13.9gb","reused_in_bytes":15029918919,"recovered":"0b","recovered_in_bytes":0,"percent":"100.0%"},"files":{"total":183,"reused":183,"recovered":0,"percent":"100.0%"},"total_time":"35ms","total_time_in_millis":35,"source_throttle_time":"-1","source_throttle_time_in_millis":0,"target_throttle_time":"-1","target_throttle_time_in_millis":0},"translog":{"recovered":0,"total":0,"percent":"100.0%","total_on_start":0,"total_time":"1.2s","total_time_in_millis":1244},"verify_index":{"check_index_time":"0s","check_index_time_in_millis":0,"total_time":"0s","total_time_in_millis":0}},{"id":1,"type":"EXISTING_STORE","stage":"DONE","primary":true,"start_time":"2024-01-21T12:48:32.377Z","start_time_in_millis":1705841312377,"stop_time":"2024-01-21T12:48:33.917Z","stop_time_in_millis":1705841313917,"total_time":"1.5s","total_time_in_millis":1540,"source":{"bootstrap_new_history_uuid":false},"target":{"id":"U9MqM7W2QxWRRHgK3VaqEw","host":"x.x.x.x","transport_address":"x.x.x.x:9300","ip":"x.x.x.x","name":"e2ececbd2113789a34ec878eeb2e23fa"},"index":{"size":{"total":"13.8gb","total_in_bytes":14869328371,"reused":"13.8gb","reused_in_bytes":14869328371,"recovered":"0b","recovered_in_bytes":0,"percent":"100.0%"},"files":{"total":171,"reused":171,"recovered":0,"percent":"100.0%"},"total_time":"53ms","total_time_in_millis":53,"source_throttle_time":"-1","source_throttle_time_in_millis":0,"target_throttle_time":"-1","target_throttle_time_in_millis":0},"translog":{"recovered":0,"total":0,"percent":"100.0%","total_on_start":0,"total_time":"1.4s","total_time_in_millis":1471},"verify_index":{"check_index_time":"0s","check_index_time_in_millis":0,"total_time":"0s","total_time_in_millis":0}}]}}
2024-01-22 18:07:41,765 INFO               curator.utils          restore_check:1772 Provided indices: ['myindex*']
2024-01-22 18:07:41,765 INFO               curator.utils          restore_check:1773 Found indices: ['myindex-images-2023-07-06-14-22']
2024-01-22 18:07:41,765 DEBUG              curator.utils            wait_for_it:1929 Response: True
2024-01-22 18:07:41,765 DEBUG              curator.utils            wait_for_it:1932 Action "restore" finished executing (may or may not have been successful)
2024-01-22 18:07:41,765 DEBUG              curator.utils            wait_for_it:1952 Result: True
2024-01-22 18:07:41,779 DEBUG     urllib3.connectionpool          _make_request:474  https://mydomainindex:443 "GET /_all/_settings?expand_wildcards=open%2Cclosed HTTP/1.1" 200 4353
2024-01-22 18:07:41,780 INFO                  opensearch    log_request_success:259  GET https://mydomainindex:443/_all/_settings?expand_wildcards=open%2Cclosed [status:200 request:0.014s]
2024-01-22 18:07:41,780 DEBUG                 opensearch  _log_request_response:198  > None
..
2024-01-22 18:07:41,796 DEBUG              curator.utils            get_indices:664  Detected Elasticsearch version 7.10.2
2024-01-22 18:07:41,797 DEBUG              curator.utils            get_indices:668  All indices: ['.opensearch-observability', '.plugins-ml-config','.ql-datasources', 'restored-myindex-images-2023-07-06-14-22', 'myindex-images-2023-07-06-14-22', '.kibana_1']
2024-01-22 18:07:41,797 INFO      curator.actions.snapshot           report_state:1942 Found restored index myindex-images-2023-07-06-14-22
2024-01-22 18:07:41,797 INFO      curator.actions.snapshot           report_state:1946 All indices appear to have been restored.
2024-01-22 18:07:41,798 INFO                 curator.cli                    run:224  Action ID: 1, "restore" completed.
2024-01-22 18:07:41,798 INFO                 curator.cli                    run:225  Job completed.

You can see here the API call:

2024-01-22 18:07:41,667 INFO opensearch log_request_success:259 POST https://mydomainindex:443/_snapshot/snapshots-repo/curator-myindex-20240122170002/_restore?wait_for_completion=false [status:200 request:1.161s]

wait_for_completion is FALSE even if curator recognize the parameter set in YAML template as true:

2024-01-22 18:07:40,299 DEBUG curator.actions.snapshot __init__:1907 WAIT_FOR_COMPLETION: True

Version of curator: curator-opensearch 0.0.12