[MDEV-23648] s3.partition_move 'innodb' test failure - object deleted before copy attempted Created: 2020-09-02  Updated: 2020-10-21  Resolved: 2020-10-21

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - S3, Tests
Affects Version/s: 10.5.5
Fix Version/s: 10.5.7

Type: Bug Priority: Critical
Reporter: Daniel Black Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-23650 test S3 in buildbot Closed

 Description   

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
s3.partition_move 'innodb'               [ fail ]
        Test ended at 2020-09-02 14:11:20
 
CURRENT_TEST: s3.partition_move
mysqltest: At line 61: query 'alter table archive exchange partition p1 with table p1' failed: 29: Expected object 's3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p1/data/000001' didn't exist

fake s3 server

04:11:19.772 [200 OK] s3.ListObjectsV1 127.0.0.1/justdoit/?delimiter=%2F&prefix=test%2F  127.0.0.1         271µs       ↑ 73 B ↓ 513 B
04:11:19.775 [200 OK] s3.ListObjectsV1 127.0.0.1/justdoit/?delimiter=%2F&prefix=performance_schema%2F  127.0.0.1         158µs       ↑ 73 B ↓ 527 B
04:11:19.777 [200 OK] s3.ListObjectsV1 127.0.0.1/justdoit/?delimiter=%2F&prefix=test%2F  127.0.0.1         209µs       ↑ 73 B ↓ 513 B
04:11:19.778 [200 OK] s3.ListObjectsV1 127.0.0.1/justdoit/?delimiter=%2F&prefix=mtr%2F  127.0.0.1         165µs       ↑ 73 B ↓ 512 B
04:11:19.810 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p0/frm 127.0.0.1         315µs       ↑ 73 B ↓ 225 B
04:11:19.812 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p0/frm 127.0.0.1         213µs       ↑ 73 B ↓ 225 B
04:11:19.820 [404 Not Found] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/seq_1_to_99/frm 127.0.0.1         374µs       ↑ 73 B ↓ 664 B
04:11:19.823 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/frm 127.0.0.1         267µs       ↑ 73 B ↓ 225 B
04:11:19.827 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p0/aria 127.0.0.1         325µs       ↑ 73 B ↓ 225 B
04:11:19.839 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p0/aria 127.0.0.1         11.79ms      ↑ 8.1 KiB ↓ 259 B
04:11:19.845 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p0/index/000001 127.0.0.1         4.269ms      ↑ 8.1 KiB ↓ 259 B
04:11:19.850 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p0/data/000001 127.0.0.1         4.199ms      ↑ 16 KiB ↓ 259 B
04:11:19.852 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/frm 127.0.0.1         262µs       ↑ 73 B ↓ 225 B
04:11:19.857 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/frm 127.0.0.1         3.79ms       ↑ 1.1 KiB ↓ 259 B
04:11:19.858 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/par 127.0.0.1         299µs       ↑ 73 B ↓ 225 B
04:11:19.862 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/par 127.0.0.1         3.565ms      ↑ 114 B ↓ 259 B
04:11:19.866 [200 OK] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/frm 127.0.0.1         825µs       ↑ 73 B ↓ 1.4 KiB
04:11:19.868 [200 OK] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p0/aria 127.0.0.1         946µs       ↑ 73 B ↓ 8.3 KiB
04:11:19.871 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/t1/frm 127.0.0.1         369µs       ↑ 73 B ↓ 225 B
04:11:19.873 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/t1/frm 127.0.0.1         277µs       ↑ 73 B ↓ 225 B
04:11:19.877 [404 Not Found] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/seq_100_to_399/frm 127.0.0.1         413µs       ↑ 73 B ↓ 670 B
04:11:19.881 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/frm 127.0.0.1         300µs       ↑ 73 B ↓ 225 B
04:11:19.883 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/frm 127.0.0.1         297µs       ↑ 73 B ↓ 225 B
04:11:19.893 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/aria 127.0.0.1         290µs       ↑ 73 B ↓ 225 B
04:11:19.898 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/frm 127.0.0.1         4.21ms       ↑ 1.0 KiB ↓ 259 B
04:11:19.903 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/aria 127.0.0.1         4.384ms      ↑ 8.1 KiB ↓ 259 B
04:11:19.908 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/index/000001 127.0.0.1         4.031ms      ↑ 8.1 KiB ↓ 259 B
04:11:19.913 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/data/000001 127.0.0.1         3.358ms      ↑ 16 KiB ↓ 259 B
04:11:19.915 [200 OK] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/frm 127.0.0.1         748µs       ↑ 73 B ↓ 1.4 KiB
04:11:19.918 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p1/aria 127.0.0.1         345µs       ↑ 73 B ↓ 225 B
04:11:19.922 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p1/aria 127.0.0.1         3.906ms      ↑ 8.1 KiB ↓ 259 B
04:11:19.927 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p1/data/000001 127.0.0.1         4.077ms      ↑ 8.1 KiB ↓ 259 B
04:11:19.931 [200 OK] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/frm 127.0.0.1         950µs       ↑ 73 B ↓ 355 B
04:11:19.932 [204 No Content] s3.DeleteObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/frm 127.0.0.1         603µs       ↑ 73 B ↓ 226 B
04:11:19.937 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/frm 127.0.0.1         4.089ms      ↑ 1.1 KiB ↓ 259 B
04:11:19.939 [200 OK] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/par 127.0.0.1         735µs       ↑ 73 B ↓ 353 B
04:11:19.940 [204 No Content] s3.DeleteObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/par 127.0.0.1         545µs       ↑ 73 B ↓ 226 B
04:11:19.944 [200 OK] s3.PutObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/par 127.0.0.1         3.34ms       ↑ 122 B ↓ 259 B
04:11:19.947 [200 OK] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/frm 127.0.0.1         912µs       ↑ 73 B ↓ 1.4 KiB
04:11:19.949 [200 OK] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p0/aria 127.0.0.1         826µs       ↑ 73 B ↓ 8.3 KiB
04:11:19.951 [200 OK] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive/frm 127.0.0.1         809µs       ↑ 73 B ↓ 1.4 KiB
04:11:19.953 [200 OK] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p1/aria 127.0.0.1         783µs       ↑ 73 B ↓ 8.3 KiB
04:11:19.955 [200 OK] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/frm 127.0.0.1         764µs       ↑ 73 B ↓ 1.3 KiB
04:11:19.957 [200 OK] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/aria 127.0.0.1         978µs       ↑ 73 B ↓ 8.3 KiB
04:11:19.958 [200 OK] s3.GetObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/data/000001 127.0.0.1         746µs       ↑ 73 B ↓ 16 KiB
04:11:19.961 [200 OK] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/aria 127.0.0.1         692µs       ↑ 73 B ↓ 355 B
04:11:19.962 [200 OK] s3.ListObjectsV1 127.0.0.1/justdoit/?prefix=s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c%2Fp1%2Findex  127.0.0.1         663µs       ↑ 73 B ↓ 921 B
04:11:19.969 [200 OK] s3.CopyObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/#sql-exchange-1bbf43-4/index/000001 127.0.0.1         6.156ms      ↑ 104 B ↓ 523 B
04:11:19.971 [204 No Content] s3.DeleteObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/index/000001 127.0.0.1         665µs       ↑ 73 B ↓ 226 B
04:11:19.972 [200 OK] s3.ListObjectsV1 127.0.0.1/justdoit/?prefix=s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c%2Fp1%2Fdata  127.0.0.1         626µs       ↑ 73 B ↓ 920 B
04:11:19.977 [200 OK] s3.CopyObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/#sql-exchange-1bbf43-4/data/000001 127.0.0.1         4.723ms      ↑ 104 B ↓ 523 B
04:11:19.979 [204 No Content] s3.DeleteObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/data/000001 127.0.0.1         566µs       ↑ 73 B ↓ 226 B
04:11:19.984 [200 OK] s3.CopyObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/#sql-exchange-1bbf43-4/aria 127.0.0.1         4.198ms      ↑ 104 B ↓ 523 B
04:11:19.985 [204 No Content] s3.DeleteObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/aria 127.0.0.1         438µs       ↑ 73 B ↓ 226 B
04:11:19.987 [200 OK] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/archive#P#p1/aria 127.0.0.1         692µs       ↑ 73 B ↓ 355 B
04:11:19.989 [200 OK] s3.ListObjectsV1 127.0.0.1/justdoit/?prefix=s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c%2Farchive%23P%23p1%2Findex  127.0.0.1         440µs       ↑ 73 B ↓ 566 B
04:11:19.990 [200 OK] s3.ListObjectsV1 127.0.0.1/justdoit/?prefix=s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c%2Farchive%23P%23p1%2Fdata  127.0.0.1         613µs       ↑ 73 B ↓ 939 B
04:11:19.991 [404 Not Found] s3.CopyObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/data/000001 127.0.0.1         495µs       ↑ 104 B ↓ 662 B
04:11:19.992 [404 Not Found] s3.CopyObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/aria 127.0.0.1         451µs       ↑ 104 B ↓ 648 B
04:11:19.994 [404 Not Found] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/aria 127.0.0.1         223µs       ↑ 73 B ↓ 225 B
04:11:19.997 [200 OK] s3.HeadObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/#sql-exchange-1bbf43-4/aria 127.0.0.1         965µs       ↑ 73 B ↓ 355 B
04:11:19.999 [200 OK] s3.ListObjectsV1 127.0.0.1/justdoit/?prefix=s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c%2F%23sql-exchange-1bbf43-4%2Findex  127.0.0.1         852µs       ↑ 73 B ↓ 961 B
04:11:20.000 [404 Not Found] s3.CopyObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/index/000001 127.0.0.1         735µs       ↑ 104 B ↓ 664 B
04:11:20.002 [200 OK] s3.ListObjectsV1 127.0.0.1/justdoit/?prefix=s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c%2F%23sql-exchange-1bbf43-4%2Fdata  127.0.0.1         582µs       ↑ 73 B ↓ 960 B
04:11:20.003 [404 Not Found] s3.CopyObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/data/000001 127.0.0.1         496µs       ↑ 104 B ↓ 662 B
04:11:20.004 [404 Not Found] s3.CopyObject 127.0.0.1/justdoit/s3_test_5ac0aae8ecd211ea8032cabbbeb0fc5c/p1/aria 127.0.0.1         508µs       ↑ 104 B ↓ 648 B

The server logs show that the missing object was deleted by s3 (04:11:19.979) before it tried to access it later.



 Comments   
Comment by Michael Widenius [ 2020-09-13 ]

I was not able to repeat this issue,
The log that I get with:

 mtr --mysqld=--s3-debug=1 s3.partition_move

(in var/log/mysqld.1.err) shows that there is a put at once after the object delete.

Does this test always fail for you?
What s3 storage are you using?
How did you get the above log?

Comment by Daniel Black [ 2020-09-14 ]

Apparently I forgot the back ref: MDEV-23650

With MDEV-23662 merged the following + a trace should be sufficient:

https://jira.mariadb.org/browse/MDEV-23662?focusedCommentId=165200&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-165200

Yes, it was always failing.

Comment by Daniel Black [ 2020-09-14 ]

minio get/run server

wget http://dl.min.io/server/minio/release/linux-amd64/minio -O ~/bin/minio
chmod a+x ~/bin/minio
MINIO_ACCESS_KEY=minio MINIO_SECRET_KEY=minioadmin minio server /tmp/shared

mc (minio client)

wget http://dl.min.io/client/mc/release/linux-amd64/mc -O ~/bin/mc
chmod a+x ~/bin/mc
mc  alias set  local  http://127.0.0.1:9000  minio minioadmin
 mc mb --ignore-existing local/storage-engine
 mc admin trace   local

run mtr test

mysql-test/mtr --mem s3.partition_move
Logging: /home/dan/repos/mariadb-server-10.5/mysql-test/mysql-test-run.pl  --mem s3.partition_move
vardir: /home/dan/repos/build-mariadb-server-10.5/mysql-test/var
Removing old var directory...
Creating var directory '/home/dan/repos/build-mariadb-server-10.5/mysql-test/var'...
 - symlinking 'var' to '/dev/shm/var_auto_Ao41'
Checking supported features...
MariaDB Version 10.5.6-MariaDB
 - SSL connections supported
 - binaries built with wsrep patch
Collecting tests...
WARNING: cgroup v2 is not fully supported yet, proceeding with partial confinement
Installing system database...
 
==============================================================================
 
TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
s3.partition_move 'innodb'               [ fail ]
        Test ended at 2020-09-14 15:49:32
 
CURRENT_TEST: s3.partition_move
mysqltest: At line 61: query 'alter table archive exchange partition p1 with table p1' failed: 29: Expected object 's3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/archive#P#p1/data/000001' didn't exist
...

trace output (tail) 10.5-5f2728d594bf0202afebeff2323324df79b50425

05:49:32.696 [200 OK] s3.GetObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/aria 127.0.0.1         397µs       ↑ 73 B ↓ 8.3 KiB
05:49:32.696 [200 OK] s3.GetObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/data/000001 127.0.0.1         339µs       ↑ 73 B ↓ 16 KiB
05:49:32.697 [200 OK] s3.HeadObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/aria 127.0.0.1         363µs       ↑ 73 B ↓ 355 B
05:49:32.698 [200 OK] s3.ListObjectsV1 127.0.0.1/storage-engine/?prefix=s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c%2Fp1%2Findex  127.0.0.1         297µs       ↑ 73 B ↓ 927 B
05:49:32.699 [200 OK] s3.CopyObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/#sql-exchange-108ade-4/index/000001 127.0.0.1         723µs       ↑ 104 B ↓ 523 B
05:49:32.699 [204 No Content] s3.DeleteObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/index/000001 127.0.0.1         187µs       ↑ 73 B ↓ 226 B
05:49:32.699 [200 OK] s3.ListObjectsV1 127.0.0.1/storage-engine/?prefix=s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c%2Fp1%2Fdata  127.0.0.1         253µs       ↑ 73 B ↓ 926 B
05:49:32.700 [200 OK] s3.CopyObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/#sql-exchange-108ade-4/data/000001 127.0.0.1         612µs       ↑ 104 B ↓ 523 B
05:49:32.701 [204 No Content] s3.DeleteObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/data/000001 127.0.0.1         203µs       ↑ 73 B ↓ 226 B
05:49:32.702 [200 OK] s3.CopyObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/#sql-exchange-108ade-4/aria 127.0.0.1         624µs       ↑ 104 B ↓ 523 B
05:49:32.702 [204 No Content] s3.DeleteObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/aria 127.0.0.1         161µs       ↑ 73 B ↓ 226 B
05:49:32.703 [200 OK] s3.HeadObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/archive#P#p1/aria 127.0.0.1         371µs       ↑ 73 B ↓ 355 B
05:49:32.703 [200 OK] s3.ListObjectsV1 127.0.0.1/storage-engine/?prefix=s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c%2Farchive%23P%23p1%2Findex  127.0.0.1         205µs       ↑ 73 B ↓ 572 B
05:49:32.704 [200 OK] s3.ListObjectsV1 127.0.0.1/storage-engine/?prefix=s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c%2Farchive%23P%23p1%2Fdata  127.0.0.1         295µs       ↑ 73 B ↓ 945 B
05:49:32.704 [404 Not Found] s3.CopyObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/data/000001 127.0.0.1         227µs       ↑ 104 B ↓ 674 B
05:49:32.705 [404 Not Found] s3.CopyObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/aria 127.0.0.1         285µs       ↑ 104 B ↓ 660 B
05:49:32.706 [404 Not Found] s3.HeadObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/aria 127.0.0.1         132µs       ↑ 73 B ↓ 225 B
05:49:32.706 [200 OK] s3.HeadObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/#sql-exchange-108ade-4/aria 127.0.0.1         345µs       ↑ 73 B ↓ 355 B
05:49:32.707 [200 OK] s3.ListObjectsV1 127.0.0.1/storage-engine/?prefix=s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c%2F%23sql-exchange-108ade-4%2Findex  127.0.0.1         244µs       ↑ 73 B ↓ 967 B
05:49:32.707 [404 Not Found] s3.CopyObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/index/000001 127.0.0.1         259µs       ↑ 104 B ↓ 676 B
05:49:32.708 [200 OK] s3.ListObjectsV1 127.0.0.1/storage-engine/?prefix=s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c%2F%23sql-exchange-108ade-4%2Fdata  127.0.0.1         325µs       ↑ 73 B ↓ 966 B
05:49:32.709 [404 Not Found] s3.CopyObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/data/000001 127.0.0.1         253µs       ↑ 104 B ↓ 674 B
05:49:32.709 [404 Not Found] s3.CopyObject 127.0.0.1/storage-engine/s3_test_101f1c01f64e11eaa7a4cabbbeb0fc5c/p1/aria 127.0.0.1         355µs       ↑ 104 B ↓ 660 B

Also repeatable on 6844212f01c65a8d78ff218d4f2a731a62e096f8 bb-10.5-monty

Comment by Michael Widenius [ 2020-09-15 ]

Have you tried with using Amazon S3? Could be a problem with min.io where it differs from Amazon?

Comment by Daniel Black [ 2020-09-16 ]

If an object is deleted before a copy is attempted on it, min.io didn't manufacture the delete request. It definitely came from the storage engine. S3 having a slower delete process where S3 can exploit a race condition to copy the object before the delete has had an effect shouldn't be relied upon.

Comment by Elena Stepanova [ 2020-09-20 ]

Raising to critical because the tests (s3.partition and s3.partition_move) have been conditionally disabled for the emulator setup. I didn't disable them completely because I couldn't reproduce the failure with Amazon.

When the problem is fixed, please remove the skip logic from the test cases, it looks like this:

index 03bbc2f0da9..b60eb1bf2dd 100644
--- a/mysql-test/suite/s3/partition.test
+++ b/mysql-test/suite/s3/partition.test
@@ -1,3 +1,8 @@
+if (`SELECT @@s3_host_name <> "s3.amazonaws.com"`)
+{
+  skip The test is disabled for emulator environment due to MDEV-23648;
+}
+
 --source include/have_partition.inc
 --source include/have_s3.inc
 --source create_database.inc
diff --git a/mysql-test/suite/s3/partition_move.test b/mysql-test/suite/s3/partition_move.test
index 35edbd75b5a..1a5c45ca0b1 100644
--- a/mysql-test/suite/s3/partition_move.test
+++ b/mysql-test/suite/s3/partition_move.test
@@ -1,3 +1,8 @@
+if (`SELECT @@s3_host_name <> "s3.amazonaws.com"`)
+{
+  skip The test is disabled for emulator environment due to MDEV-23648;
+}
+

Comment by Michael Widenius [ 2020-10-20 ]

The problem was in libmarias3 that didn't work correctly with MinIO.

Comment by Michael Widenius [ 2020-10-21 ]

Running tests, rebase etc

Generated at Thu Feb 08 09:23:59 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.