Snapshot error with minio trailing / in the base_path of the repository gives FileAlreadyExistsException for recursive snapshots of the same index

[thasija]

Elasticsearch version (5.6.11):

Plugins installed: [repository-s3]

JVM version (jdk1.8.0_77):

OS version (uname -a 3.10.0-862.el7.x86_64 #1 SMP Fri Apr 20 16:44:24 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux):

Description of the problem including expected versus actual behavior:
Am taking snapshots of indices on Minio server which are taken in a bucket , The successive snapshots of the same indices complete successfully when taken at the bucket root level , but if I register a new repository with a base_path to take snapshots under sub directory the first snapshot gets created successfully but the successive snapshots fail with the FileAlreadyExistsException.

Provide logs (if relevant):

Parent root level bucket snapshot repository

curl -XGET "esi1rvmm03-inc.tw-test.net:9200/_snapshot/intc_minio_repository/_all?pretty"
{
"snapshots" : [
{
"snapshot" : "usg_report_month_2018_09_snapshot",
"uuid" : "b1cXPStzSA245j6rNABL8g",
"version_id" : 5061199,
"version" : "5.6.11",
"indices" : [
"usg_report_month_2018_09"
],
"state" : "SUCCESS",
"start_time" : "2019-04-15T01:57:54.293Z",
"start_time_in_millis" : 1555293474293,
"end_time" : "2019-04-15T01:57:57.365Z",
"end_time_in_millis" : 1555293477365,
"duration_in_millis" : 3072,
"failures" : [ ],
"shards" : {
"total" : 1,
"failed" : 0,
"successful" : 1
}
},
{
"snapshot" : "snapshot_1",
"uuid" : "EsSYscL_REK7KVORsYrWuQ",
"version_id" : 5061199,
"version" : "5.6.11",
"indices" : [
"doclocker"
],
"state" : "SUCCESS",
"start_time" : "2019-05-02T22:35:02.206Z",
"start_time_in_millis" : 1556836502206,
"end_time" : "2019-05-02T22:35:13.609Z",
"end_time_in_millis" : 1556836513609,
"duration_in_millis" : 11403,
"failures" : [ ],
"shards" : {
"total" : 5,
"failed" : 0,
"successful" : 5
}
},
{
"snapshot" : "snapshot_2",
"uuid" : "vWpuP64ET5KBGuWJ4PmP2w",
"version_id" : 5061199,
"version" : "5.6.11",
"indices" : [
"doclocker"
],
"state" : "SUCCESS",
"start_time" : "2019-05-02T22:39:10.484Z",
"start_time_in_millis" : 1556836750484,
"end_time" : "2019-05-02T22:39:11.230Z",
"end_time_in_millis" : 1556836751230,
"duration_in_millis" : 746,
"failures" : [ ],
"shards" : {
"total" : 5,
"failed" : 0,
"successful" : 5
}

Nested directory snapshot repository

curl -XGET "esi1rvmm03-inc.tw-test.net:9200/_snapshot/intc_minio_repository_doclocker/_all?pretty"
{
"snapshots" : [
{
"snapshot" : "snapshot_1",
"uuid" : "c_VRGCCdSSKLr-i0PTXLZg",
"version_id" : 5061199,
"version" : "5.6.11",
"indices" : [
"doclocker"
],
"state" : "SUCCESS",
"start_time" : "2019-05-03T19:33:20.166Z",
"start_time_in_millis" : 1556912000166,
"end_time" : "2019-05-03T19:33:28.478Z",
"end_time_in_millis" : 1556912008478,
"duration_in_millis" : 8312,
"failures" : [ ],
"shards" : {
"total" : 5,
"failed" : 0,
"successful" : 5
}
},
{
"snapshot" : "snapshot_2",
"uuid" : "wQD5j389QK2nHMoNKDCIwA",
"version_id" : 5061199,
"version" : "5.6.11",
"indices" : [
"doclocker"
],
"state" : "PARTIAL",
"start_time" : "2019-05-03T19:35:59.364Z",
"start_time_in_millis" : 1556912159364,
"end_time" : "2019-05-03T19:35:59.627Z",
"end_time_in_millis" : 1556912159627,
"duration_in_millis" : 263,
"failures" : [
{
"index" : "doclocker",
"index_uuid" : "doclocker",
"shard_id" : 0,
"reason" : "IndexShardSnapshotFailedException[Failed to perform snapshot (index files)]; nested: FileAlreadyExistsException[blob [__0] already exists, cannot overwrite]; ",
"node_id" : "9XnkBOa5Q3mUiHp1WvY5hQ",
"status" : "INTERNAL_SERVER_ERROR"
},
{
"index" : "doclocker",
"index_uuid" : "doclocker",
"shard_id" : 2,
"reason" : "IndexShardSnapshotFailedException[Failed to perform snapshot (index files)]; nested: FileAlreadyExistsException[blob [__0] already exists, cannot overwrite]; ",
"node_id" : "cw3A2lK5SAOw1qQ2CY3sTw",
"status" : "INTERNAL_SERVER_ERROR"
},
{
"index" : "doclocker",
"index_uuid" : "doclocker",
"shard_id" : 4,
"reason" : "IndexShardSnapshotFailedException[Failed to perform snapshot (index files)]; nested: FileAlreadyExistsException[blob [__0] already exists, cannot overwrite]; ",
"node_id" : "cw3A2lK5SAOw1qQ2CY3sTw",
"status" : "INTERNAL_SERVER_ERROR"
},
{
"index" : "doclocker",
"index_uuid" : "doclocker",
"shard_id" : 1,
"reason" : "IndexShardSnapshotFailedException[Failed to perform snapshot (index files)]; nested: FileAlreadyExistsException[blob [__0] already exists, cannot overwrite]; ",
"node_id" : "9XnkBOa5Q3mUiHp1WvY5hQ",
"status" : "INTERNAL_SERVER_ERROR"
},
{
"index" : "doclocker",
"index_uuid" : "doclocker",
"shard_id" : 3,
"reason" : "IndexShardSnapshotFailedException[Failed to perform snapshot (index files)]; nested: FileAlreadyExistsException[blob [__0] already exists, cannot overwrite]; ",
"node_id" : "9XnkBOa5Q3mUiHp1WvY5hQ",
"status" : "INTERNAL_SERVER_ERROR"
}
],
"shards" : {
"total" : 5,
"failed" : 5,
"successful" : 0
}
}

[elasticmachine]

Pinging @elastic/es-distributed

[DaveCTurner]

Hi @thasija,

Please note that the 5.6 series has reached the end of its supported life. Nonetheless, I tried and failed to reproduce the problem you describe against a brand-new one-node 5.6.16 cluster:

PUT /_snapshot/my_s3_repository
{
  "settings": {
    "base_path": "test_base_path",
    "bucket": "bucketname",
    "endpoint": "127.0.0.1:9000"
  },
  "type": "s3"
}

PUT /i
{
  "settings": {
    "number_of_shards": 1
  }
}

POST /i/doc
{}

POST /i/_flush

PUT /_snapshot/my_s3_repository/snapshot_1?wait_for_completion=true

POST /i/doc
{}

POST /i/_flush

PUT /_snapshot/my_s3_repository/snapshot_2?wait_for_completion=true

This last command reported:

# 200 OK
# {
#   "snapshot": {
#     "snapshot": "snapshot_2",
#     "duration_in_millis": 75,
#     "state": "SUCCESS",
#     "uuid": "4U7W9roOQHeCuxXOZwWeog",
#     "failures": [],
#     "end_time_in_millis": 1556988029412,
#     "indices": [
#       "i"
#     ],
#     "shards": {
#       "successful": 1,
#       "total": 1,
#       "failed": 0
#     },
#     "version": "5.6.16",
#     "start_time": "2019-05-04T16:40:29.337Z",
#     "end_time": "2019-05-04T16:40:29.412Z",
#     "version_id": 5061699,
#     "start_time_in_millis": 1556988029337
#   }
# }

Could you try again with a supported version (ideally 6.7.2 or 7.0.1) and give a more detailed sequence of steps to help us reproduce what you're seeing?

[thasija]

Hi @DaveCTurner
The steps to reproduce the issue are the same you have done, In my Minio bucket base path directory I see an indices directory getting created that has blobs for the individual shards , These blobs are what are causing FileAlreadyException. Can you check if your test_base_path has the indices directory? Also what version of minio are you using ?

[minio@devchi-inf-012 ~]$ /opt/minio/bin/mc ls myminio/elasticsearch-esp3-intc/doclocker/indices/ju4twZSTSCaMGA9-O04qtw/
[2019-05-03 23:07:05 CDT] 3.1KiB meta-4g8_EJ8ESfekUOI9xAkCsQ.dat
[2019-05-03 23:05:47 CDT] 3.1KiB meta-Dmyo1S6nQ1-20-7wlFDl8g.dat
[2019-05-04 12:53:39 CDT] 0B 0/
[2019-05-04 12:53:39 CDT] 0B 1/
[2019-05-04 12:53:39 CDT] 0B 2/
[2019-05-04 12:53:39 CDT] 0B 3/
[2019-05-04 12:53:39 CDT] 0B 4/

[DaveCTurner]

Yep, that's what I'd expect it to look like:

$ find minio/bucketname | sort
minio/bucketname
minio/bucketname/test_base_path
minio/bucketname/test_base_path/incompatible-snapshots
minio/bucketname/test_base_path/index-0
minio/bucketname/test_base_path/index-1
minio/bucketname/test_base_path/index.latest
minio/bucketname/test_base_path/indices
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0/__0
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0/__1
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0/__2
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0/__3
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0/__4
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0/__5
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0/__6
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0/__7
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0/index-1
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0/snap-HXt1s7GDQpqH3FAqF9IFWQ.dat
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/0/snap-egP5oQSwTuG8V2xhbLnJtw.dat
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/meta-HXt1s7GDQpqH3FAqF9IFWQ.dat
minio/bucketname/test_base_path/indices/_P-iWqjYSoOaUcOw6YWH-A/meta-egP5oQSwTuG8V2xhbLnJtw.dat
minio/bucketname/test_base_path/meta-HXt1s7GDQpqH3FAqF9IFWQ.dat
minio/bucketname/test_base_path/meta-egP5oQSwTuG8V2xhbLnJtw.dat
minio/bucketname/test_base_path/snap-HXt1s7GDQpqH3FAqF9IFWQ.dat
minio/bucketname/test_base_path/snap-egP5oQSwTuG8V2xhbLnJtw.dat

I'm using a recent version:

$ minio version
Version: 2019-05-02T19:07:09Z
Release-Tag: RELEASE.2019-05-02T19-07-09Z
Commit-ID: 4b858b562a0887e10bfd0414dc87e68f1af31c3a

[original-brownbear]

@thasija do you actually have two repositories configured at the same time (one at the root and one nested?) or did you remove the root repo before creating the nested one?

I think this could be an issue in the line of things that were eventually resolved in #37393 where having multiple S3 repos all sharing the same client (in this case the default client) could lead to the S3 client internally using broken settings.
You should be able to fix this situation by removing the root level repository.

[thasija]

Hi @original-brownbear yes I had the root level repository as well but later I deleted the root level repository and deleted all the files from the bucket , should I try fresh with a new bucket that doesn't has the root level repository ?

curl -X GET "esi1rvmm03-inc.tw-test.net:9200/_snapshot/?pretty"
{
"intc_minio_repository_doclocker" : {
"type" : "s3",
"settings" : {
"bucket" : "elasticsearch-esp3-intc",
"base_path" : "doclocker/",
"endpoint" : "http://10.70.255.229:9000",
"protocol" : "http"
}
}

[original-brownbear]

@thasija if possible try restarting your cluster fully to get a settings reload for the S3 client first and see if the nested path repo works. If it doesn't yea try a clean repo like @DaveCTurner suggested.

[thasija]

I restarted the cluster and tried with a fresh new bucket in the same minio server but the issue happens again.

"intc_minio_repository_doclocker_new" : {
"type" : "s3",
"settings" : {
"bucket" : "elasticsearch-esp3-intc-new",
"base_path" : "doclocker/",
"endpoint" : "http://10.70.255.229:9000",
"protocol" : "http"
}
}
}

{
"snapshots" : [
{
"snapshot" : "snapshot_1",
"uuid" : "Yt--Z2xYQ12xFYezre71lQ",
"version_id" : 5061199,
"version" : "5.6.11",
"indices" : [
"usg_report_month_2018_09"
],
"state" : "SUCCESS",
"start_time" : "2019-05-04T18:59:59.437Z",
"start_time_in_millis" : 1556996399437,
"end_time" : "2019-05-04T19:00:01.196Z",
"end_time_in_millis" : 1556996401196,
"duration_in_millis" : 1759,
"failures" : [ ],
"shards" : {
"total" : 1,
"failed" : 0,
"successful" : 1
}
},
{
"snapshot" : "snapshot_2",
"uuid" : "vM_AGQrRQkCZn3F8VtDqAQ",
"version_id" : 5061199,
"version" : "5.6.11",
"indices" : [
"usg_report_month_2018_09"
],
"state" : "PARTIAL",
"start_time" : "2019-05-04T19:01:25.437Z",
"start_time_in_millis" : 1556996485437,
"end_time" : "2019-05-04T19:01:26.004Z",
"end_time_in_millis" : 1556996486004,
"duration_in_millis" : 567,
"failures" : [
{
"index" : "usg_report_month_2018_09",
"index_uuid" : "usg_report_month_2018_09",
"shard_id" : 0,
"reason" : "IndexShardSnapshotFailedException[Failed to perform snapshot (index files)]; nested: FileAlreadyExistsException[blob [__0] already exists, cannot overwrite]; ",
"node_id" : "9XnkBOa5Q3mUiHp1WvY5hQ",
"status" : "INTERNAL_SERVER_ERROR"
}
],
"shards" : {
"total" : 1,
"failed" : 1,
"successful" : 0
}
}
]
}

[original-brownbear]

@thasija Could you try a newer version of ES with your repository like David suggested?

Also, it might be worth testing with base_path set to doclocker without the trailing / as that is the only difference I can really see in the steps you took and those taken by David.

[thasija]

Thanks @original-brownbear that helped to solve the issue , I created a new bucket and registered a new repository with the base path not having the trailing / , the successive snapshots worked this time and didn't gave any errors , Thanks @DaveCTurner

{
  "snapshot" : "snapshot_4",
  "uuid" : "ygQwYtVuQaS__WZ5InAJOw",
  "version_id" : 5061199,
  "version" : "5.6.11",
  "indices" : [
    "doclocker"
  ],
  "state" : "SUCCESS",
  "start_time" : "2019-05-04T20:17:03.811Z",
  "start_time_in_millis" : 1557001023811,
  "end_time" : "2019-05-04T20:17:11.482Z",
  "end_time_in_millis" : 1557001031482,
  "duration_in_millis" : 7671,
  "failures" : [ ],
  "shards" : {
    "total" : 5,
    "failed" : 0,
    "successful" : 5
  }
},
{
  "snapshot" : "snapshot_5",
  "uuid" : "2297qkujSa6i5IgzOgufFw",
  "version_id" : 5061199,
  "version" : "5.6.11",
  "indices" : [
    "doclocker"
  ],
  "state" : "SUCCESS",
  "start_time" : "2019-05-04T20:17:38.955Z",
  "start_time_in_millis" : 1557001058955,
  "end_time" : "2019-05-04T20:17:39.633Z",
  "end_time_in_millis" : 1557001059633,
  "duration_in_millis" : 678,
  "failures" : [ ],
  "shards" : {
    "total" : 5,
    "failed" : 0,
    "successful" : 5
  }
}

{
"intc_minio_repository_doclocker_05-04-2019" : {
"type" : "s3",
"settings" : {
"bucket" : "elasticsearch-esp3-intc-05-04-2019",
"base_path" : "doclocker",
"endpoint" : "http://10.70.255.229:9000",
"protocol" : "http"
}
}
}

[original-brownbear]

Interesting, seems we're sometimes stripping the trailing / and sometimes not in BlobPath so every path that ends in a / breaks for a few situations. I think we should fix this!

Could you add the conclusion that a trailing / in the base_path breaks the S3 repository to the issue description and adjust the title of the issue accordingly please? :)