[ILM] Rollover action errors after restart

[colings86]

4 node cluster with 1 hot, 2 warm and 1 cold node

1. Create a policy:

PUT _ilm/my_lifecycle3
{
  "policy": {
    "phases": {
      "hot": {
        "actions": {
          "rollover": {
            "max_age": "30s"
          }
        }
      },
      "warm": {
        "actions": {
          "forcemerge": {
            "max_num_segments": 1
          },
          "allocate": {
            "number_of_replicas": 1,
            "include": {
              "box_type": "warm"
            },
            "exclude": {},
            "require": {}
          }
        }
      },
      "cold": {
        "minimum_age": "1m",
        "actions": {
          "allocate": {
            "number_of_replicas": 0,
            "include": {
              "box_type": "cold"
            },
            "exclude": {},
            "require": {}
          }
        }
      },
      "delete": {
        "minimum_age": "2m",
        "actions": {
          "delete": {}
        }
      }
    }
  }
}

2. Create an index template:

PUT _template/my_template
{
  "index_patterns": ["test-*"],
  "settings": {
    "number_of_shards": 2,
    "number_of_replicas": 0,
    "index.lifecycle.name": "my_lifecycle3",
    "index.lifecycle.rollover_alias": "test-alias",
    "index.routing.allocation.include.box_type": "hot"
  }
}

3. create the first index:

PUT test-000001
{
  "aliases": {
    "test-alias":{
      "is_write_index": true
    }
  }
}

4. Check the index is on the attempt_rollover step using the explain api:

GET test-*/_ilm/explain?human

5. Shutdown all nodes

6. Restart all nodes

7. Wait for the 2nd index to appear using the explain API:

GET test-*/_ilm/explain?human

8. Observe that the first index is in the ERROR state with a response something like the following

{
  "indices": {
    "test-000001": {
      "index": "test-000001",
      "managed": true,
      "policy": "my_lifecycle3",
      "skip": false,
      "lifecycle_date": "2018-10-15T14:49:32.281Z",
      "phase": "hot",
      "phase_time": "2018-10-15T14:49:32.531Z",
      "action": "rollover",
      "action_time": "2018-10-15T14:49:32.531Z",
      "step": "ERROR",
      "step_time": "2018-10-15T14:50:18.632Z",
      "failed_step": "attempt_rollover",
      "step_info": {
        "type": "resource_already_exists_exception",
        "reason": "index [test-000002/cRr06akcS4mJXfZniAFfGQ] already exists",
        "index_uuid": "cRr06akcS4mJXfZniAFfGQ",
        "index": "test-000002"
      },
      "phase_execution": {
        "policy": "my_lifecycle3",
        "phase_definition": {
          "minimum_age": "0ms",
          "actions": {
            "rollover": {
              "max_age": "30s"
            }
          }
        },
        "version": 1,
        "modified_date": "2018-10-15T14:49:24.641Z",
        "modified_date_in_millis": 1539614964641
      }
    },
    "test-000002": {
      "index": "test-000002",
      "managed": true,
      "policy": "my_lifecycle3",
      "skip": false,
      "lifecycle_date": "2018-10-15T14:50:17.338Z",
      "phase": "new",
      "phase_time": "2018-10-15T14:50:18.725Z",
      "action": "complete",
      "action_time": "2018-10-15T14:50:18.384Z",
      "step": "complete",
      "step_time": "2018-10-15T14:50:18.384Z"
    }
  }
}

It seems like in this scenario the rollover step might be getting run twice?

[elasticmachine]

Pinging @elastic/es-core-infra

[gwbrown]

Summarizing a discussion on Slack:

Rollover is unique in that it is an Async action, but inherently needs to be run periodically, rather than exactly once as is the case with other async actions (i.e. Shrink). This makes it very difficult to force it to run only once, especially in the case where rollover has already been run successfully (or partially successfully), but the lifecycle state has not been updated to reflect that fact.

Before running the rollover call, we could check the rolloverInfo in the IndexMetaData to see if this index has already been rolled over, and if it has, skip the rollover call, and move to the next lifecycle step. However, there's no way to tell whether that rollover happened due to ILM or a separate administrative call, but in either case, it's likely that the solution the administrator would take is to simply use the Move to Step API to force the index to the next lifecycle step anyway.

However, even this is not a total solution. Per @talevy:

rollover action is not transactional, and 1) it will first update aliases 2) add rolloverInfo 3) wait for all shards to be active
so, master can go down after any one of these. if the cluster goes down before (2) we are stuck, no matter what

The solution above would still narrow the window in which the cluster would have to go down in order to cause the index to move to the error step.

If anyone has any other thoughts or feedback on this, please add them.

[DaveCTurner]

Would it help to persist more state prior to (1) and/or between (1) and (2) so that if the master changes part-way through then the new master has enough information to pick up where the old one left off? E.g.:

½) update cluster state indicating that a (specific) ILM rollover action is taking place
1) update aliases
1½) update cluster state indicating that the aliases were updated in the action
2) add rolloverInfo
2½) update cluster state indicating success
3) wait for active shards

By being specific about the changes that are still to be made, a new master can see if they've already been made. E.g. if the master changed between steps 1 and 1½ then the new master would see that there were some aliases to update but also that the aliases look like they've already been correctly updated, and can proceed rather than erroring out.

[colings86]

I spoke to @DaveCTurner about this separately and I think I know whats going on here, and @DaveCTurner has offered what I think might be a good solution.

Whats going on?

I accidentally left out a detail above which is that I had set the poll interval to 1 second.

What I think is happening is that when the cluster restarts a master is elected and triggers the policy in ILM which sends off the rollover API request. At the same time the scheduler is initialised and it also triggers the policy sending off a second rollover API call after a second whilst the first is still in flight. When these return the error is processed first and so we move to the error step.

Proposed solution

Have the attempt_rollover step catch resource_already_exists_exception and pass the step in this case (after all the new index exists which is what we expect to happen). This leave the case where the new index is created outside of ILM and is not configured with the policy which would be good to catch and warn the user about so we could add a new cluster state step that follows the attempt_rollover step that checks to make sure the new index has the index.lifecycle.name set correctly.

[gwbrown]

After a Zoom discussion with @colings86, @talevy, and @dakrone, we have decided to go forward with Colin's proposed solution of catching resource_already_exists_exception and passing to the next step. This should alleviate the issue of multiple instances of RolloverStep executing simultaneously, and we believe this is what an administrator would do in every case anyway.

If the new index was created via the Rollover API, simply moving on the with the policy is almost certainly the correct thing to do.

In the case where an administrator manually creates the index (e.g the current index is test-000001 and the admin created test-000002 before the rollover is triggered), the policy will fail on the update-rollover-lifecycle-date step with an IllegalStateException as it attempts to access data from the RolloverInfo on the index, which will not be present if test-000002 was created manually, rather than via the Rollover API.