Snapshot status API returns different timing information than snapshot info API

[jen-huang]

Snapshot info API returns the following stats for a given snapshot:

      "start_time" : "2019-06-10T23:02:36.637Z",
      "start_time_in_millis" : 1560207756637,
      "end_time" : "2019-06-10T23:02:37.040Z",
      "end_time_in_millis" : 1560207757040,
      "duration_in_millis" : 403,

Snapshot status API returns the following overall stats for the same snapshot:

        "start_time_in_millis" : 1560207756712,
        "time_in_millis" : 290,

Note that the start_time_in_millis values are different. The overall duration is also different, if time_in_millis is meant to represent the same duration as duration_in_millis.

I'm not sure if this is a bug or expected behavior. If it is expected, the difference should be documented more clearly.

Full request and responses

# GET /_snapshot/my-backups/snapshot_3
{
  "snapshots" : [
    {
      "snapshot" : "snapshot_3",
      "uuid" : "e450-h_FSjuTKaTNFqaZAQ",
      "version_id" : 8000099,
      "version" : "8.0.0",
      "indices" : [
        ".kibana_1",
        ".kibana_task_manager",
        ".security-7"
      ],
      "include_global_state" : true,
      "state" : "SUCCESS",
      "start_time" : "2019-06-10T23:02:36.637Z",
      "start_time_in_millis" : 1560207756637,
      "end_time" : "2019-06-10T23:02:37.040Z",
      "end_time_in_millis" : 1560207757040,
      "duration_in_millis" : 403,
      "failures" : [ ],
      "shards" : {
        "total" : 3,
        "failed" : 0,
        "successful" : 3
      }
    }
  ]
}


# GET /_snapshot/my-backups/snapshot_3/_status
{
  "snapshots" : [
    {
      "snapshot" : "snapshot_3",
      "repository" : "my-backups",
      "uuid" : "e450-h_FSjuTKaTNFqaZAQ",
      "state" : "SUCCESS",
      "include_global_state" : true,
      "shards_stats" : {
        "initializing" : 0,
        "started" : 0,
        "finalizing" : 0,
        "done" : 3,
        "failed" : 0,
        "total" : 3
      },
      "stats" : {
        "incremental" : {
          "file_count" : 22,
          "size_in_bytes" : 26378
        },
        "total" : {
          "file_count" : 67,
          "size_in_bytes" : 107766
        },
        "start_time_in_millis" : 1560207756712,
        "time_in_millis" : 290
      },
      "indices" : {
        ".kibana_task_manager" : {
          "shards_stats" : {
            "initializing" : 0,
            "started" : 0,
            "finalizing" : 0,
            "done" : 1,
            "failed" : 0,
            "total" : 1
          },
          "stats" : {
            "incremental" : {
              "file_count" : 0,
              "size_in_bytes" : 0
            },
            "total" : {
              "file_count" : 7,
              "size_in_bytes" : 13074
            },
            "start_time_in_millis" : 1560207756712,
            "time_in_millis" : 11
          },
          "shards" : {
            "0" : {
              "stage" : "DONE",
              "stats" : {
                "incremental" : {
                  "file_count" : 0,
                  "size_in_bytes" : 0
                },
                "total" : {
                  "file_count" : 7,
                  "size_in_bytes" : 13074
                },
                "start_time_in_millis" : 1560207756712,
                "time_in_millis" : 11
              }
            }
          }
        },
        ".security-7" : {
          "shards_stats" : {
            "initializing" : 0,
            "started" : 0,
            "finalizing" : 0,
            "done" : 1,
            "failed" : 0,
            "total" : 1
          },
          "stats" : {
            "incremental" : {
              "file_count" : 0,
              "size_in_bytes" : 0
            },
            "total" : {
              "file_count" : 35,
              "size_in_bytes" : 59988
            },
            "start_time_in_millis" : 1560207756712,
            "time_in_millis" : 36
          },
          "shards" : {
            "0" : {
              "stage" : "DONE",
              "stats" : {
                "incremental" : {
                  "file_count" : 0,
                  "size_in_bytes" : 0
                },
                "total" : {
                  "file_count" : 35,
                  "size_in_bytes" : 59988
                },
                "start_time_in_millis" : 1560207756712,
                "time_in_millis" : 36
              }
            }
          }
        },
        ".kibana_1" : {
          "shards_stats" : {
            "initializing" : 0,
            "started" : 0,
            "finalizing" : 0,
            "done" : 1,
            "failed" : 0,
            "total" : 1
          },
          "stats" : {
            "incremental" : {
              "file_count" : 22,
              "size_in_bytes" : 26378
            },
            "total" : {
              "file_count" : 25,
              "size_in_bytes" : 34704
            },
            "start_time_in_millis" : 1560207756844,
            "time_in_millis" : 158
          },
          "shards" : {
            "0" : {
              "stage" : "DONE",
              "stats" : {
                "incremental" : {
                  "file_count" : 22,
                  "size_in_bytes" : 26378
                },
                "total" : {
                  "file_count" : 25,
                  "size_in_bytes" : 34704
                },
                "start_time_in_millis" : 1560207756844,
                "time_in_millis" : 158
              }
            }
          }
        }
      }
    }
  ]
}

[elasticmachine]

Pinging @elastic/es-distributed

[original-brownbear]

This is indeed a little strange. For the snapshot status API we return a serialized org.elasticsearch.action.admin.cluster.snapshots.status.SnapshotStatus which calculates the timings from the individual shard stats.
On the other hand, for the snapshot info API we return a SnapshotInfo which has the concrete start time stored in it. I think we should simply make the snapshot status API load the SnapshotInfo from the repo as well and use that instead of a calculation form the shard stats for determining the timings.