trinodb / trino

Official repository of Trino, the distributed SQL query engine for big data, formerly known as PrestoSQL (https://trino.io)
https://trino.io
Apache License 2.0
10.22k stars 2.95k forks source link

insert_existing_partitions_behavior OVERWRITE does not work correctly on S3 with task level retries. #11196

Closed losipiuk closed 2 years ago

losipiuk commented 2 years ago

TestHiveTaskFailureRecoveryTest.testReplaceExistingPartition is failing when run locally since we migrated the test to use Minio instead HDFS (https://github.com/trinodb/trino/commit/0c2d802feb29da5344ac9e79d528e8c403cff1e6). It looks like a product issue, not a test failure. We see duplicated rows after INSERT which was supposed to overwrite partition. It needs to be diagnosed if the extra rows are the previous content of the partition or we overwrite but with too many rows.

Problem is reproducible locally in IntelliJ but for some reason does not happen on CI (or happens rarely)

Failure exception:

java.lang.AssertionError: For query: 
 INSERT INTO <table> SELECT *, 'partition1' p FROM orders
not equal
Actual rows (up to 100 of 15000 extra rows shown, 30000 rows in total):
    [6241, 136, F, 87037.94, 1994-12-30, 5-LOW, Clerk#000000353, 0, dencies snooze furiously above the blithely ironic p, partition1]
    [6242, 472, O, 199497.95, 1997-12-02, 3-MEDIUM, Clerk#000000172, 0, sits cajole blithely. pending accounts along the brave pinto beans will hav, partition1]
    [6243, 241, F, 81333.16, 1994-09-28, 4-NOT SPECIFIED, Clerk#000000358, 0, lent attainments? ironic, even dolphins above the furiously final inst, partition1]
    [6244, 1423, F, 60185.35, 1993-08-19, 2-HIGH, Clerk#000000549, 0, ic packages. regular platelets believe furiously foxes. blithely pen, partition1]
    [6245, 733, O, 99101.88, 1997-11-10, 3-MEDIUM, Clerk#000000167, 0, oxes cajole final foxes? ruthlessly special pinto beans boost against the foxe, partition1]
    [6246, 712, F, 245217.34, 1994-10-22, 4-NOT SPECIFIED, Clerk#000000229, 0, equests wake busily bold theodolites. even instruc, partition1]
    [6247, 466, O, 51480.94, 1996-11-22, 3-MEDIUM, Clerk#000000324, 0, dle, even accounts. ca, partition1]
    [6272, 898, F, 228876.91, 1993-02-28, 2-HIGH, Clerk#000000434, 0,  packages boost quickly even, even excuses! slyly ironic instruction, partition1]
    [6273, 43, F, 30827.17, 1995-02-06, 1-URGENT, Clerk#000000206, 0, above the fluffily regular accounts! furiously ironic ideas sleep regular , partition1]
    [6274, 79, O, 218754.47, 1995-07-15, 4-NOT SPECIFIED, Clerk#000000061, 0, packages. carefully express deposits dazzle quickly fur, partition1]
    [6275, 116, O, 215131.2, 1996-12-24, 1-URGENT, Clerk#000000818, 0,  pinto beans cajole. quickly unusual ideas caj, partition1]
    [6276, 736, P, 188453.84, 1995-05-08, 5-LOW, Clerk#000000914, 0, he always express platelets. spe, partition1]
    [6277, 563, O, 127760.48, 1997-01-28, 3-MEDIUM, Clerk#000000104, 0, furiously regular dolphins use quickly around the, partition1]
    [6278, 337, F, 160399.31, 1992-01-05, 2-HIGH, Clerk#000000042, 0, ironic deposits sleep carefully at the fluffily regular acc, partition1]
    [6279, 1109, F, 74788.1, 1993-01-30, 1-URGENT, Clerk#000000519, 0, about the regular frays. blithely regular courts wake , partition1]
    [6304, 560, O, 124120.12, 1995-08-12, 2-HIGH, Clerk#000000628, 0, jole slyly around the dogged ideas. slyly regular dependencies are blithely. , partition1]
    [6305, 79, O, 218216.09, 1997-01-16, 4-NOT SPECIFIED, Clerk#000000759, 0, p regular, quiet foxes. furiously unusual pac, partition1]
    [6306, 13, O, 24140.16, 1998-05-04, 4-NOT SPECIFIED, Clerk#000000005, 0, s haggle fluffily carefully pe, partition1]
    [6307, 23, O, 47944.47, 1997-11-06, 4-NOT SPECIFIED, Clerk#000000287, 0,  above the regular, even asymptotes. iron, partition1]
    [6308, 895, O, 40723.24, 1997-07-11, 2-HIGH, Clerk#000000231, 0, und the fluffily bold packages. blithely final plat, partition1]
    [6309, 1300, F, 218103.18, 1993-06-10, 3-MEDIUM, Clerk#000000476, 0, efully alongside of the quickly special requests. qu, partition1]
    [6310, 712, F, 271339.83, 1994-05-04, 4-NOT SPECIFIED, Clerk#000000272, 0, silent packages are carefully. packages , partition1]
    [6311, 622, F, 42859.41, 1993-02-11, 3-MEDIUM, Clerk#000000844, 0, ndencies cajole furiously alongside of the regular grouches. p, partition1]
    [6336, 1312, O, 75041.38, 1995-08-29, 2-HIGH, Clerk#000000875, 0, solve blithely blithely regular instructions! blithely final req, partition1]
    [6337, 1159, O, 201043.71, 1995-09-01, 4-NOT SPECIFIED, Clerk#000000301, 0, r ideas boost. even, unusual pint, partition1]
    [6338, 1480, F, 126794.13, 1992-02-25, 5-LOW, Clerk#000000413, 0, lent deposits boost doggedly afte, partition1]
    [6339, 1156, F, 138811.0, 1992-12-12, 1-URGENT, Clerk#000000413, 0, . blithely unusual platelets kindl, partition1]
    [6340, 232, O, 217548.67, 1996-10-09, 3-MEDIUM, Clerk#000000638, 0, requests sleep carefully. slyly bold pac, partition1]
    [6341, 1270, O, 178632.66, 1996-06-08, 3-MEDIUM, Clerk#000000910, 0,  grow alongside of the ironically ironic foxes. ironically final acc, partition1]
    [6342, 287, O, 187784.6, 1997-11-25, 1-URGENT, Clerk#000000859, 0, ickly after the furiou, partition1]
    [6343, 743, O, 289069.48, 1998-03-18, 4-NOT SPECIFIED, Clerk#000000072, 0, ccounts wake permanently. dependencies nag carefully across the quickly fina, partition1]
    [6368, 515, F, 175352.65, 1994-02-23, 4-NOT SPECIFIED, Clerk#000000262, 0,  bold accounts. blithely even pinto beans hinder furiously slyly, partition1]
    [6369, 850, F, 196618.52, 1994-12-20, 2-HIGH, Clerk#000000414, 0, nto beans affix fluffily depe, partition1]
    [6370, 1204, F, 57253.82, 1992-12-30, 3-MEDIUM, Clerk#000000281, 0, press asymptotes. express, ironic account, partition1]
    [6371, 838, F, 179096.82, 1993-04-02, 3-MEDIUM, Clerk#000000237, 0, sly ironic forges. carefully final accounts use. blithely even theodolites hag, partition1]
    [6372, 517, F, 159295.25, 1994-02-27, 4-NOT SPECIFIED, Clerk#000000852, 0, unusual pinto beans. slyly regular accounts nag across the regular deposits, partition1]
    [6373, 385, F, 178234.19, 1992-01-24, 4-NOT SPECIFIED, Clerk#000000432, 0, ts among the foxes cajole arou, partition1]
    [6374, 898, O, 155144.63, 1995-08-08, 1-URGENT, Clerk#000000058, 0, ickly. furiously final packages , partition1]
    [6375, 217, O, 271720.48, 1997-11-13, 4-NOT SPECIFIED, Clerk#000000466, 0, beans integrate ironically. foxes poach quickly. depos, partition1]
    [6400, 823, F, 106659.06, 1994-01-24, 3-MEDIUM, Clerk#000000166, 0, nag slyly pending, express pains. fina, partition1]
    [6401, 1273, O, 144203.63, 1997-04-23, 5-LOW, Clerk#000000941, 0, ly. accounts are. packages are about the regular theodolites. blit, partition1]
    [6402, 395, P, 215754.02, 1995-04-24, 5-LOW, Clerk#000000978, 0, slyly regular requests sleep blit, partition1]
    [6403, 280, F, 94578.04, 1995-02-12, 5-LOW, Clerk#000000816, 0, r theodolites. final, partition1]
    [6404, 319, O, 61110.56, 1996-07-07, 2-HIGH, Clerk#000000095, 0,  to the furiously express theodolites cajole furiously fluf, partition1]
    [6405, 1100, O, 37656.0, 1997-05-12, 2-HIGH, Clerk#000000379, 0, hely final deposits about the dol, partition1]
    [6406, 244, F, 104536.06, 1994-08-15, 1-URGENT, Clerk#000000996, 0, nal, unusual foxes ca, partition1]
    [6407, 847, O, 106491.85, 1995-07-25, 2-HIGH, Clerk#000000873, 0, packages. blithely regular platelets boost furiously slyly final plate, partition1]
    [6432, 304, O, 181270.7, 1995-11-11, 1-URGENT, Clerk#000000116, 0,  slyly final deposits. carefully regular asympto, partition1]
    [6433, 766, O, 287192.21, 1995-11-23, 3-MEDIUM, Clerk#000000494, 0, ronic ideas cajole carefully express dolphins. carefully final ideas s, partition1]
    [6434, 976, F, 180859.67, 1994-06-08, 2-HIGH, Clerk#000000643, 0, lphins haggle quickly, partition1]
    [6435, 1138, O, 269746.89, 1996-06-01, 1-URGENT, Clerk#000000355, 0, es breach carefully. ideas nag. slyly regular packages a, partition1]
    [6436, 1046, F, 17014.61, 1992-03-02, 5-LOW, Clerk#000000858, 0, unusual theodolites. slyly final requests inte, partition1]
    [6437, 1162, F, 198960.61, 1994-02-04, 1-URGENT, Clerk#000000328, 0, carefully above the , partition1]
    [6438, 1084, F, 119623.94, 1993-05-17, 4-NOT SPECIFIED, Clerk#000000814, 0, ckages wake carefully according to th, partition1]
    [6439, 988, O, 229454.16, 1995-07-03, 3-MEDIUM, Clerk#000000611, 0, theodolites along the carefully final deposits wake furiously , partition1]
    [6464, 160, F, 169920.37, 1994-05-29, 3-MEDIUM, Clerk#000000601, 0,  final theodolites after the silent accounts may hagg, partition1]
    [6465, 943, O, 214899.89, 1995-08-13, 5-LOW, Clerk#000000713, 0, s wake slyly carefully, partition1]
    [6466, 169, O, 42804.39, 1997-04-06, 1-URGENT, Clerk#000000289, 0, eep about the furiously special accounts, partition1]
    [6467, 754, O, 56503.77, 1998-03-02, 4-NOT SPECIFIED, Clerk#000000510, 0, osits. fluffily final packages boost by the , partition1]
    [6468, 1054, O, 30752.09, 1996-09-09, 5-LOW, Clerk#000000215, 0, e carefully regular courts. special packages integrate furiously across, partition1]
    [6469, 746, O, 275767.2, 1996-03-09, 3-MEDIUM, Clerk#000000974, 0, ckages use carefully careful, partition1]
    [6470, 62, O, 300362.24, 1995-09-11, 5-LOW, Clerk#000000421, 0, yly among the blithely careful dolphins. ironic account, partition1]
    [6471, 952, O, 283397.96, 1998-03-01, 5-LOW, Clerk#000000775, 0, egular platelets cajole quickly, partition1]
    [6496, 443, O, 213862.9, 1995-06-30, 1-URGENT, Clerk#000000015, 0,  pending deposits cajole around , partition1]
    [6497, 452, O, 47029.15, 1997-10-02, 3-MEDIUM, Clerk#000000430, 0, tions wake furiously fluffily enticing platele, partition1]
    [6498, 1229, F, 82192.11, 1994-03-18, 3-MEDIUM, Clerk#000000987, 0, e. even accounts past , partition1]
    [6499, 118, O, 94392.6, 1995-05-09, 1-URGENT, Clerk#000000647, 0, sly. accounts with the slyly final asymptotes are furiously regular pac, partition1]
    [6500, 772, F, 116920.53, 1992-10-13, 1-URGENT, Clerk#000000203, 0, ainst the quickly ironic dependencies. carefully i, partition1]
    [6501, 34, F, 169372.97, 1992-01-14, 2-HIGH, Clerk#000000637, 0, posits sleep furiously. furiously regu, partition1]
    [6502, 1364, O, 132481.49, 1995-08-21, 3-MEDIUM, Clerk#000000528, 0,  whithout the furio, partition1]
    [6503, 200, O, 126966.13, 1997-07-09, 5-LOW, Clerk#000000528, 0, e the express reques, partition1]
    [6528, 1127, F, 174394.9, 1993-02-04, 2-HIGH, Clerk#000000133, 0, ven deposits. ironic, final , partition1]
    [6529, 541, F, 180161.7, 1992-11-27, 3-MEDIUM, Clerk#000000591, 0, t. close accounts nag slyly according to, partition1]
    [6530, 64, O, 7676.1, 1997-08-05, 1-URGENT, Clerk#000000912, 0, the furiously sly depende, partition1]
    [6531, 593, F, 200954.37, 1993-07-18, 2-HIGH, Clerk#000000947, 0, ly special excuses sleep after the r, partition1]
    [6532, 4, O, 129232.21, 1996-02-18, 1-URGENT, Clerk#000000046, 0, al excuses wake special, partition1]
    [6533, 79, O, 204973.1, 1998-03-05, 3-MEDIUM, Clerk#000000114, 0, s kindle busily requests. ironic, pending depos, partition1]
    [6534, 970, O, 31457.22, 1997-04-20, 1-URGENT, Clerk#000000668, 0, ideas print slyly at t, partition1]
    [6535, 244, F, 207170.87, 1992-06-13, 1-URGENT, Clerk#000000650, 0, s. ironic, even theodolites haggle , partition1]
    [6560, 1204, F, 318034.04, 1995-01-05, 5-LOW, Clerk#000000328, 0, ven packages. deposits wake furiously enticingly regular theodolites; un, partition1]
    [6561, 1402, F, 200779.81, 1994-05-19, 2-HIGH, Clerk#000000813, 0,  have to are furiously furiously even deposits. carefu, partition1]
    [6562, 643, F, 221812.3, 1994-12-21, 1-URGENT, Clerk#000000616, 0, ely ironic, permanent deposits. blithely busy grouches wak, partition1]
    [6563, 1055, F, 94449.31, 1992-11-06, 5-LOW, Clerk#000000666, 0, he fluffily final requests s, partition1]
    [6564, 565, F, 150871.17, 1995-01-22, 5-LOW, Clerk#000000777, 0, nic forges! quickly unusual packages haggle. blithely reg, partition1]
    [6565, 277, O, 262344.82, 1997-02-25, 4-NOT SPECIFIED, Clerk#000000657, 0, final dependencies. blithely express pinto , partition1]
    [6566, 1369, P, 175594.82, 1995-05-22, 1-URGENT, Clerk#000000218, 0, al notornis. blithely express pac, partition1]
    [6567, 1294, O, 53318.58, 1997-07-22, 2-HIGH, Clerk#000000402, 0,  deposits haggle. slyly fluffy dependencies sleep carefully packages., partition1]
    [6592, 221, F, 240055.49, 1994-12-02, 5-LOW, Clerk#000000213, 0, he slyly final somas. slyly final accounts above , partition1]
    [6593, 293, O, 123753.91, 1997-05-16, 2-HIGH, Clerk#000000678, 0, ular deposits cajole furiously. doggedly regular accounts c, partition1]
    [6594, 1288, O, 205591.26, 1996-08-23, 1-URGENT, Clerk#000000712, 0, final deposits above the stealthily even packages , partition1]
    [6595, 881, F, 24750.02, 1992-10-03, 1-URGENT, Clerk#000000220, 0, onic, even dependencies sleep , partition1]
    [6596, 1120, O, 169485.95, 1995-07-22, 5-LOW, Clerk#000000106, 0, rough the blithely even pinto beans. quickl, partition1]
    [6597, 1189, O, 100902.3, 1998-06-27, 5-LOW, Clerk#000000392, 0,  furiously about the slyly spec, partition1]
    [6598, 109, F, 66566.87, 1992-05-08, 3-MEDIUM, Clerk#000000691, 0, ts. quickly ironic p, partition1]
    [6599, 599, O, 214143.21, 1998-04-17, 5-LOW, Clerk#000000365, 0,  x-ray fluffily according to the fu, partition1]
    [6624, 1130, O, 44018.37, 1997-08-18, 1-URGENT, Clerk#000000553, 0, e fluffily according to the ideas, partition1]
    [6625, 1345, F, 15961.57, 1993-08-16, 2-HIGH, Clerk#000000228, 0, rious theodolites against , partition1]
    [6626, 575, F, 104789.96, 1994-05-07, 1-URGENT, Clerk#000000213, 0, ans. carefully even dolphins , partition1]
    [6627, 967, P, 86219.59, 1995-03-26, 5-LOW, Clerk#000000603, 0,  the instructions. blithely eve, partition1]
    [6628, 448, F, 137905.54, 1994-04-28, 3-MEDIUM, Clerk#000000644, 0, uests detect. blithel, partition1]
Expected rows (up to 100 of 0 missing rows shown, 15000 rows in total):

    at org.testng.Assert.fail(Assert.java:94)
    at io.trino.testing.QueryAssertions.assertEqualsIgnoreOrder(QueryAssertions.java:237)
    at io.trino.testing.BaseFailureRecoveryTest$FailureRecoveryAssert.finishesSuccessfully(BaseFailureRecoveryTest.java:640)
    at io.trino.testing.BaseFailureRecoveryTest$FailureRecoveryAssert.finishesSuccessfully(BaseFailureRecoveryTest.java:609)
    at io.trino.testing.BaseFailureRecoveryTest$FailureRecoveryAssert.finishesSuccessfully(BaseFailureRecoveryTest.java:599)
    at io.trino.testing.BaseFailureRecoveryTest.testNonSelect(BaseFailureRecoveryTest.java:438)
    at io.trino.testing.BaseFailureRecoveryTest.testTableModification(BaseFailureRecoveryTest.java:364)
    at io.trino.plugin.hive.BaseHiveFailureRecoveryTest.testReplaceExistingPartition(BaseHiveFailureRecoveryTest.java:141)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:104)
    at org.testng.internal.Invoker.invokeMethod(Invoker.java:645)
    at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:851)
    at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1177)
    at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:129)
    at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:112)
    at org.testng.TestRunner.privateRun(TestRunner.java:756)
    at org.testng.TestRunner.run(TestRunner.java:610)
    at org.testng.SuiteRunner.runTest(SuiteRunner.java:387)
    at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:382)
    at org.testng.SuiteRunner.privateRun(SuiteRunner.java:340)
    at org.testng.SuiteRunner.run(SuiteRunner.java:289)
    at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
    at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
    at org.testng.TestNG.runSuitesSequentially(TestNG.java:1293)
    at org.testng.TestNG.runSuitesLocally(TestNG.java:1218)
    at org.testng.TestNG.runSuites(TestNG.java:1133)
    at org.testng.TestNG.run(TestNG.java:1104)
    at com.intellij.rt.testng.IDEARemoteTestNG.run(IDEARemoteTestNG.java:66)
    at com.intellij.rt.testng.RemoteTestNGStarter.main(RemoteTestNGStarter.java:109)

cc: @linzebing @arhimondr

losipiuk commented 2 years ago

Thanks, @MiguelWeezardo for finding the issue.

losipiuk commented 2 years ago

cc: @joshthoward

MiguelWeezardo commented 2 years ago

Original bug was found in a PR run which is weird since it uses the exact same workers as tests running on master. The bug seems to occur deterministically when run locally (5 out of 5 so far). Yet on master this test runs and passes: here and here

findepi commented 2 years ago

This causes PR build failures, eg https://github.com/trinodb/trino/runs/5415454534?check_suite_focus=true

Knowing that the test is legitimately failing, what is the plan for this? cc @arhimondr @losipiuk

findepi commented 2 years ago

https://github.com/trinodb/trino/runs/5420150846?check_suite_focus=true

findepi commented 2 years ago

https://github.com/trinodb/trino/runs/5421276792?check_suite_focus=true

arhimondr commented 2 years ago

It looks like the same problem as here: https://github.com/trinodb/trino/issues/10631#issuecomment-1059120654

losipiuk commented 2 years ago

It looks like the same problem as here: https://github.com/trinodb/trino/issues/10631#issuecomment-1059120654

I did not check now. But last time I checked I did not notice this problem there. There was same test failing - but symptoms were different.