New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Inserts can be lost during a predicate move #2338

Closed
aphyr opened this Issue Apr 16, 2018 · 6 comments

Comments

Projects
None yet
3 participants
@aphyr

aphyr commented Apr 16, 2018

With server-side ordering, @upsert schemas, no crashes or network faults, roughly 10 inserts/sec, and no updates or deletes, Dgraph can occasionally (once every five hours or so) lose successfully inserted records: 20180412T161038.000-0500.zip

 {:valid? false,
  :lost "#{10185}",
  :recovered "#{}",
  :ok
  "#{0..1 5..6 8 10 12..13 15 18 20 22 24 ... 74997 75000..75001}"
  :recovered-frac 0,
  :unexpected-frac 0,
  :unexpected "#{}",
  :lost-frac 1/75002,
  :ok-frac 16645/37501}

The lost records occur during a predicate move, which suggests this issue might be related to #2321. This occurs with

Dgraph version   : v1.0.4
Commit SHA-1     : 6fb69e2
Commit timestamp : 2018-04-09 21:26:31 +0530
Branch           : jan/node_lockup

and can be reproduced with Jepsen 23329ead4c4e3d8352234658026d09792f15c406 via

lein run test --package-url https://transfer.sh/BAPac/dgraph-linux-amd64.tar.gz --time-limit 3600 --concurrency 1n --nemesis none --test-count 20 --workload set --upsert-schema
@aphyr

This comment has been minimized.

Show comment
Hide comment
@aphyr

aphyr Apr 17, 2018

You can now reproduce this problem significantly faster in Jepsen eb796cfcc204c592545965968bd28ad1e6b2eff0 by using the move-tablet nemesis, which shuffles tablets around every 15 seconds or so.

lein run test --package-url https://github.com/dgraph-io/dgraph/releases/download/nightly/dgraph-linux-amd64.tar.gz --time-limit 60 --concurrency 1n --nemesis move-tablet --workload set --upsert-schema

With predicate moves, we can get dgraph to lose 99% of acknowledged inserts in 60 seconds:
20180416T185406.000-0500.zip

 {:ok-count 1,
  :valid? false,
  :lost-count 496,
  :lost
  "#{0 3 5..7 9 11..12 14 18 20..22 25..26 28..29 31..32 36 38 40 42..43 46..47 49 51 54 56 61..62 66..67 70..71 75..76 79 81 84 87 90..91 95..96 99 101 104 107..108 111 114..115 118 121..122 125 127 129 131..132 134 136..137 140 144 146 148 152..153 156 158 160 162 165 169 171 174 176 178 181..183 187 191 193 196 198 200 203 205..208 210..211 215 218 220 222..223 225 227 229 232 234 236 239 242 244 247 249 252 255 258 263 267 269 272 274 276 279 281 283 285 287 291 317 326 328 330 332 335 337 339 342 345..346 350..351 354 356 359 361..362 365 367 370 372 374 380 382..383 386 388 390 392 394..397 400..402 404 406 408 410 412 415 417..421 423 425 428..429 431..432 435..436 439 442 444 446 450..451 454 458..459 462 464 467 470 474..475 479..480 482 486 490 492..493 496..497 500..501 503..504 506 510 512 514 516..517 519 521 524 526 529..531 533 535..537 539..540 543..544 546 549 551 555 558 560 562 566..567 572 574 577 579 583 586 588 591 595 597..598 603 606 609..612 614..615 618 620 622 625 627 629 631 634 636 638 640..643 646 648 651 653..654 658 661 663 667 683 717 769..770 772 774..776 780 782 786 788 791 796 799 802 806..807 811 813 816 818 820..821 824 828..829 832 836 838 842 846..847 849..851 854..856 860 863..864 866..867 869 872 874 876 880..881 885..886 888 891 896 899 901 903 906 909 911 915..916 919..920 922 924 927 931 933 937..938 940..941 943 945 948 951 953..954 957 959 961 963 966 968 970 973..974 977 981 983..984 987 989 991 996..997 1000 1004 1007 1010 1013 1017 1021..1022 1026 1028 1030..1031 1033..1034 1036 1038 1041..1047 1049 1054 1056 1060 1063 1066 1069 1072 1074 1078 1080 1083 1086 1089 1092 1094 1097 1099 1102 1104 1107 1109 1112 1114 1116 1120 1123 1126 1128..1129 1133 1135 1137..1141 1144 1146 1148 1151 1153 1156 1159 1162 1165 1168..1169 1172 1175 1178 1181 1183 1187 1189 1191 1195..1196 1199 1201 1204 1208 1211..1213 1215 1217 1219..1220 1223 1225 1229..1230 1233 1235 1240 1243 1245 1248 1250 1253 1256 1258 1262 1265 1267 1269 1272 1275 1277 1279}",
  :acknowledged-count 497,
  :recovered "#{}",
  :ok "#{1284}",
  :attempt-count 1293,
  :unexpected "#{nil}",
  :unexpected-count 1,
  :recovered-count 0},

aphyr commented Apr 17, 2018

You can now reproduce this problem significantly faster in Jepsen eb796cfcc204c592545965968bd28ad1e6b2eff0 by using the move-tablet nemesis, which shuffles tablets around every 15 seconds or so.

lein run test --package-url https://github.com/dgraph-io/dgraph/releases/download/nightly/dgraph-linux-amd64.tar.gz --time-limit 60 --concurrency 1n --nemesis move-tablet --workload set --upsert-schema

With predicate moves, we can get dgraph to lose 99% of acknowledged inserts in 60 seconds:
20180416T185406.000-0500.zip

 {:ok-count 1,
  :valid? false,
  :lost-count 496,
  :lost
  "#{0 3 5..7 9 11..12 14 18 20..22 25..26 28..29 31..32 36 38 40 42..43 46..47 49 51 54 56 61..62 66..67 70..71 75..76 79 81 84 87 90..91 95..96 99 101 104 107..108 111 114..115 118 121..122 125 127 129 131..132 134 136..137 140 144 146 148 152..153 156 158 160 162 165 169 171 174 176 178 181..183 187 191 193 196 198 200 203 205..208 210..211 215 218 220 222..223 225 227 229 232 234 236 239 242 244 247 249 252 255 258 263 267 269 272 274 276 279 281 283 285 287 291 317 326 328 330 332 335 337 339 342 345..346 350..351 354 356 359 361..362 365 367 370 372 374 380 382..383 386 388 390 392 394..397 400..402 404 406 408 410 412 415 417..421 423 425 428..429 431..432 435..436 439 442 444 446 450..451 454 458..459 462 464 467 470 474..475 479..480 482 486 490 492..493 496..497 500..501 503..504 506 510 512 514 516..517 519 521 524 526 529..531 533 535..537 539..540 543..544 546 549 551 555 558 560 562 566..567 572 574 577 579 583 586 588 591 595 597..598 603 606 609..612 614..615 618 620 622 625 627 629 631 634 636 638 640..643 646 648 651 653..654 658 661 663 667 683 717 769..770 772 774..776 780 782 786 788 791 796 799 802 806..807 811 813 816 818 820..821 824 828..829 832 836 838 842 846..847 849..851 854..856 860 863..864 866..867 869 872 874 876 880..881 885..886 888 891 896 899 901 903 906 909 911 915..916 919..920 922 924 927 931 933 937..938 940..941 943 945 948 951 953..954 957 959 961 963 966 968 970 973..974 977 981 983..984 987 989 991 996..997 1000 1004 1007 1010 1013 1017 1021..1022 1026 1028 1030..1031 1033..1034 1036 1038 1041..1047 1049 1054 1056 1060 1063 1066 1069 1072 1074 1078 1080 1083 1086 1089 1092 1094 1097 1099 1102 1104 1107 1109 1112 1114 1116 1120 1123 1126 1128..1129 1133 1135 1137..1141 1144 1146 1148 1151 1153 1156 1159 1162 1165 1168..1169 1172 1175 1178 1181 1183 1187 1189 1191 1195..1196 1199 1201 1204 1208 1211..1213 1215 1217 1219..1220 1223 1225 1229..1230 1233 1235 1240 1243 1245 1248 1250 1253 1256 1258 1262 1265 1267 1269 1272 1275 1277 1279}",
  :acknowledged-count 497,
  :recovered "#{}",
  :ok "#{1284}",
  :attempt-count 1293,
  :unexpected "#{nil}",
  :unexpected-count 1,
  :recovered-count 0},

@janardhan1993 janardhan1993 self-assigned this Apr 17, 2018

@janardhan1993 janardhan1993 added the bug label Apr 17, 2018

@janardhan1993

This comment has been minimized.

Show comment
Hide comment
@janardhan1993

janardhan1993 Apr 17, 2018

Contributor

@aphyr You were probably using old nightly build, did you try with --force-download flag.

Contributor

janardhan1993 commented Apr 17, 2018

@aphyr You were probably using old nightly build, did you try with --force-download flag.

@aphyr

This comment has been minimized.

Show comment
Hide comment
@aphyr

aphyr Apr 17, 2018

Ah, good catch, thank you. Unfortunately we're still broken in b8c0908. :-(

aphyr commented Apr 17, 2018

Ah, good catch, thank you. Unfortunately we're still broken in b8c0908. :-(

@janardhan1993

This comment has been minimized.

Show comment
Hide comment
@janardhan1993

janardhan1993 Apr 17, 2018

Contributor

Some of the issue are fixed in #2339

Contributor

janardhan1993 commented Apr 17, 2018

Some of the issue are fixed in #2339

@aphyr aphyr changed the title from Inserts can be lost during normal operation to Inserts can be lost during a predicate move May 3, 2018

@manishrjain manishrjain self-assigned this May 9, 2018

manishrjain added a commit that referenced this issue May 16, 2018

Avoid race condition between predicate move and commit (#2392)
- The reason for bug #2338 was that there was a race condition between a mutation and predicate move. Zero was not checking if a predicate is under move before allowing a commit. Thus, a mutation could get proposed in a group, then a move starts, and get committed by Zero (after the move starts).
- This change this issue by ensuring that Zero checks if a predicate is being moved, before allowing commit.
- Any pending transactions are also cancelled once the move starts, so this would only happen as part of a race condition and not afterward.

Mechanism:
- Send the real keys back to Zero, as part of Transaction Context.
- Zero uses these keys to parse the predicate, and checks if that predicate is currently moving. If so, it would abort the transaction.
- Also, check for `_predicate_` being moved. For some reason, if we don't consider this predicate, we could still lose data.
- Before doing a mutation in Dgraph alpha, check if that tablet can be written to.
- Loop until all transactions corresponding to the predicate move are aborted. Only then start the move.

Tangential changes:
- Update the port number for bank integration test.
- Remove the separate key value or clean channel. Make it run as part of the main Node.Run loop.
- Add a max function.
- Small refactoring here and there.
@manishrjain

This comment has been minimized.

Show comment
Hide comment
@manishrjain

manishrjain May 16, 2018

Member

Can confirm that after half an hour of running this test, no violation was found with the above commit.

Member

manishrjain commented May 16, 2018

Can confirm that after half an hour of running this test, no violation was found with the above commit.

@manishrjain

This comment has been minimized.

Show comment
Hide comment
@manishrjain

manishrjain May 18, 2018

Member

Based on binary off mrjn/fix-2321.

lein run test --time-limit 1800 --concurrency 1n --nemesis move-tablet --workload set --upsert-schema --local-binary /gobin/dgraph --force-download --retry-db-setup --test-count 3

2018-05-18-121847_896x81_scrot

Fuck yeah!

Member

manishrjain commented May 18, 2018

Based on binary off mrjn/fix-2321.

lein run test --time-limit 1800 --concurrency 1n --nemesis move-tablet --workload set --upsert-schema --local-binary /gobin/dgraph --force-download --retry-db-setup --test-count 3

2018-05-18-121847_896x81_scrot

Fuck yeah!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment