I am using dgraph live to upload all of my data into an empty graph, specifying a JSON data file, and txt schema file. Most of the data is uploaded without any errors, but I am occasionally getting a couple of transactions in a row failing with the following errors:
[15:32:10+0400] Elapsed: 15m35s Txns: 17437 N-Quads: 17437000 N-Quads/s [last 5s]: 5800 Aborts: 8
[15:32:15+0400] Elapsed: 15m40s Txns: 17446 N-Quads: 17446000 N-Quads/s [last 5s]: 1800 Aborts: 8
Error while mutating: Assigning IDs is only allowed on leader. s.Code Unknown
Error while mutating: Assigning IDs is only allowed on leader. s.Code Unknown
Error while mutating: Assigning IDs is only allowed on leader. s.Code Unknown
Error while mutating: Assigning IDs is only allowed on leader. s.Code Unknown
Error while mutating: Assigning IDs is only allowed on leader. s.Code Unknown
Error while mutating: Assigning IDs is only allowed on leader. s.Code Unknown
Error while mutating: Assigning IDs is only allowed on leader. s.Code Unknown
[15:32:20+0400] Elapsed: 15m45s Txns: 17498 N-Quads: 17498000 N-Quads/s [last 5s]: 10400 Aborts: 15
[15:32:25+0400] Elapsed: 15m50s Txns: 17600 N-Quads: 17600000 N-Quads/s [last 5s]: 20400 Aborts: 15
What exactly does this mean? What in my data would be causing the erorr?
Anurag
June 14, 2020, 1:18pm
2
Can you share logs from zero as well?
I think this is from when I started inserting the data:
I0614 15:17:00.611879 95643 oracle.go:107] Purged below ts:366377, len(o.commits):203, len(o.rowCommit):341084
W0614 15:17:00.611949 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 1.886s. Breakdown: [{proposals 1.877s} {sync 9ms} {disk 0s} {advance 0s}]. Num entries: 2. MustSync: true
I0614 15:17:08.611057 95643 raft.go:616] Writing snapshot at index: 144164, applied mark: 144787
W0614 15:22:07.627127 95643 node.go:674] [0x1] Read index context timed out
W0614 15:22:09.629401 95643 node.go:674] [0x1] Read index context timed out
W0614 15:22:11.630064 95643 node.go:674] [0x1] Read index context timed out
I0614 15:22:12.498385 95643 oracle.go:107] Purged below ts:383017, len(o.commits):155, len(o.rowCommit):264938
W0614 15:22:12.500656 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 7.744s. Breakdown: [{proposals 7.686s} {sync 58ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
E0614 15:22:12.523823 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:22:12.537139 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:22:12.558622 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:22:12.601106 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:22:12.683159 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
I0614 15:22:12.780222 95643 raft.go:616] Writing snapshot at index: 152768, applied mark: 152925
E0614 15:22:12.844093 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
I0614 15:22:12.940746 95643 oracle.go:107] Purged below ts:383017, len(o.commits):155, len(o.rowCommit):264938
W0614 15:22:12.940818 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 440ms. Breakdown: [{sync 276ms} {proposals 163ms} {disk 1ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:26:37.967976 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 603ms. Breakdown: [{sync 603ms} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:26:53.310930 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 447ms. Breakdown: [{proposals 342ms} {sync 82ms} {disk 11ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:27:16.319116 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 224ms. Breakdown: [{sync 219ms} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:27:27.196620 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 770ms. Breakdown: [{proposals 703ms} {sync 67ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:29:27.922033 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 281ms. Breakdown: [{disk 206ms} {sync 62ms} {proposals 11ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:30:22.447161 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 228ms. Breakdown: [{sync 168ms} {disk 60ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:30:22.703972 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 253ms. Breakdown: [{sync 163ms} {disk 88ms} {proposals 2ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:30:25.057484 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 212ms. Breakdown: [{sync 211ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:30:46.740708 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 236ms. Breakdown: [{sync 234ms} {disk 2ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:31:37.230179 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 464ms. Breakdown: [{sync 235ms} {proposals 221ms} {disk 7ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:31:38.537101 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 267ms. Breakdown: [{sync 265ms} {disk 2ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:32:07.090820 95643 node.go:674] [0x1] Read index context timed out
W0614 15:32:07.592829 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 3.602s. Breakdown: [{proposals 2.512s} {sync 1.089s} {disk 1ms} {advance 0s}]. Num entries: 2. MustSync: true
W0614 15:32:08.593964 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 1.001s. Breakdown: [{proposals 805ms} {sync 193ms} {disk 3ms} {advance 0s}]. Num entries: 3. MustSync: true
W0614 15:32:12.724805 95643 node.go:674] [0x1] Read index context timed out
W0614 15:32:14.725179 95643 node.go:674] [0x1] Read index context timed out
W0614 15:32:16.725489 95643 node.go:674] [0x1] Read index context timed out
I0614 15:32:17.212848 95643 oracle.go:107] Purged below ts:399430, len(o.commits):201, len(o.rowCommit):343547
W0614 15:32:17.212936 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 6.488s. Breakdown: [{proposals 6.451s} {sync 36ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
E0614 15:32:17.240908 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:32:17.264687 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:32:17.300617 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:32:17.341969 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:32:17.422765 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
I0614 15:32:17.527124 95643 oracle.go:107] Purged below ts:399430, len(o.commits):202, len(o.rowCommit):343547
W0614 15:32:17.527187 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 314ms. Breakdown: [{sync 211ms} {proposals 103ms} {disk 0s} {advance 0s}]. Num entries: 3. MustSync: true
I0614 15:32:18.652194 95643 raft.go:616] Writing snapshot at index: 161240, applied mark: 161472
W0614 15:34:06.931256 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 241ms. Breakdown: [{proposals 28ms} {advance 19ms} {disk 0s}]. Num entries: 0. MustSync: false
W0614 15:35:27.694971 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 209ms. Breakdown: [{sync 207ms} {disk 1ms} {proposals 1ms} {advance 0s}]. Num entries: 3. MustSync: true
W0614 15:36:35.041344 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 210ms. Breakdown: [{sync 209ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:36:41.040262 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 221ms. Breakdown: [{sync 220ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 2. MustSync: true
W0614 15:38:08.074839 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 247ms. Breakdown: [{sync 240ms} {disk 7ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:39:10.671062 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 552ms. Breakdown: [{sync 552ms} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 3. MustSync: true
W0614 15:40:21.609618 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 261ms. Breakdown: [{sync 256ms} {proposals 3ms} {advance 2ms} {disk 0s}]. Num entries: 1. MustSync: true
W0614 15:41:05.918342 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 223ms. Breakdown: [{sync 222ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:41:10.928588 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 206ms. Breakdown: [{sync 205ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 4. MustSync: true
W0614 15:41:12.762877 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 240ms. Breakdown: [{sync 239ms} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:42:33.605752 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 328ms. Breakdown: [{proposals 287ms} {sync 39ms} {disk 2ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:44:16.577649 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 209ms. Breakdown: [{sync 169ms} {proposals 19ms} {advance 5ms} {disk 3ms}]. Num entries: 1. MustSync: true
W0614 15:44:25.357937 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 236ms. Breakdown: [{sync 236ms} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:44:37.234887 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 1.183s. Breakdown: [{proposals 1.006s} {sync 174ms} {disk 4ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:44:40.622815 95643 node.go:674] [0x1] Read index context timed out
W0614 15:44:42.625220 95643 node.go:674] [0x1] Read index context timed out
W0614 15:44:44.626616 95643 node.go:674] [0x1] Read index context timed out
W0614 15:44:46.627983 95643 node.go:674] [0x1] Read index context timed out
W0614 15:44:48.637969 95643 node.go:674] [0x1] Read index context timed out
E0614 15:44:49.682612 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:44:49.720837 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:44:49.771390 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:44:49.857155 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:44:50.026597 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:44:50.348759 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:44:50.638415 95643 node.go:674] [0x1] Read index context timed out
E0614 15:44:50.993240 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:44:51.997791 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:44:52.640110 95643 node.go:674] [0x1] Read index context timed out
E0614 15:44:53.002198 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:44:54.004344 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:44:54.642787 95643 node.go:674] [0x1] Read index context timed out
E0614 15:44:55.006167 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:44:56.007548 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:44:56.643369 95643 node.go:674] [0x1] Read index context timed out
E0614 15:44:57.009040 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:44:58.010757 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:44:58.646481 95643 node.go:674] [0x1] Read index context timed out
E0614 15:44:59.011699 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:45:00.013161 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:45:00.647661 95643 node.go:674] [0x1] Read index context timed out
E0614 15:45:01.014256 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:45:02.030052 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:45:02.648833 95643 node.go:674] [0x1] Read index context timed out
E0614 15:45:03.178656 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:45:04.241686 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:45:04.649269 95643 node.go:674] [0x1] Read index context timed out
E0614 15:45:05.244169 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:45:06.260495 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:45:06.649534 95643 node.go:674] [0x1] Read index context timed out
E0614 15:45:07.266998 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:45:08.271807 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:45:08.652556 95643 node.go:674] [0x1] Read index context timed out
E0614 15:45:09.273948 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:45:10.277238 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
I0614 15:45:10.484165 95643 oracle.go:107] Purged below ts:414888, len(o.commits):343, len(o.rowCommit):588485
W0614 15:45:10.484943 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 32.75s. Breakdown: [{proposals 32.653s} {sync 96ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
I0614 15:45:10.621222 95643 raft.go:616] Writing snapshot at index: 169221, applied mark: 169573
E0614 15:45:11.279144 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:45:12.281793 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:45:12.489440 95643 node.go:674] [0x1] Read index context timed out
I0614 15:45:12.623302 95643 oracle.go:107] Purged below ts:414888, len(o.commits):343, len(o.rowCommit):588485
I0614 15:45:12.806554 95643 oracle.go:107] Purged below ts:414888, len(o.commits):343, len(o.rowCommit):588485
I0614 15:45:12.975067 95643 oracle.go:107] Purged below ts:414888, len(o.commits):343, len(o.rowCommit):588485
W0614 15:45:12.975152 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 2.49s. Breakdown: [{proposals 2.359s} {sync 129ms} {disk 3ms} {advance 0s}]. Num entries: 3. MustSync: true
W0614 15:46:17.039096 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 279ms. Breakdown: [{proposals 232ms} {sync 47ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:46:54.084139 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 210ms. Breakdown: [{sync 210ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:47:36.438660 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 247ms. Breakdown: [{sync 220ms} {proposals 25ms} {disk 2ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:47:39.125915 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 333ms. Breakdown: [{sync 255ms} {proposals 69ms} {disk 9ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:47:48.097524 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 227ms. Breakdown: [{sync 224ms} {disk 3ms} {proposals 0s} {advance 0s}]. Num entries: 3. MustSync: true
W0614 15:48:11.126996 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 260ms. Breakdown: [{sync 259ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:48:18.251539 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 419ms. Breakdown: [{proposals 351ms} {sync 67ms} {disk 1ms} {advance 0s}]. Num entries: 3. MustSync: true
W0614 15:48:18.615215 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 344ms. Breakdown: [{sync 159ms} {proposals 105ms} {disk 75ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:49:38.079421 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 201ms. Breakdown: [{sync 142ms} {proposals 50ms} {disk 3ms} {advance 1ms}]. Num entries: 1. MustSync: true
W0614 15:49:42.329008 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 268ms. Breakdown: [{sync 231ms} {advance 35ms} {disk 2ms} {proposals 0s}]. Num entries: 1. MustSync: true
W0614 15:49:42.708477 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 208ms. Breakdown: [{sync 129ms} {proposals 78ms} {disk 1ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:50:19.186855 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 381ms. Breakdown: [{proposals 295ms} {sync 54ms} {disk 32ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:50:20.196563 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 542ms. Breakdown: [{proposals 378ms} {sync 126ms} {disk 38ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:50:40.251519 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 216ms. Breakdown: [{proposals 140ms} {sync 75ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:51:04.386498 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 266ms. Breakdown: [{sync 255ms} {proposals 11ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:51:04.589765 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 203ms. Breakdown: [{sync 198ms} {disk 3ms} {proposals 2ms} {advance 0s}]. Num entries: 2. MustSync: true
W0614 15:51:07.277790 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 210ms. Breakdown: [{sync 193ms} {proposals 16ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:51:13.204086 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 254ms. Breakdown: [{sync 184ms} {disk 63ms} {proposals 7ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:51:31.812598 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 241ms. Breakdown: [{proposals 202ms} {sync 31ms} {disk 7ms} {advance 0s}]. Num entries: 3. MustSync: true
W0614 15:53:36.450079 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 295ms. Breakdown: [{sync 236ms} {disk 57ms} {proposals 1ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:53:37.511856 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 253ms. Breakdown: [{sync 252ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:53:41.641080 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 285ms. Breakdown: [{proposals 142ms} {sync 111ms} {disk 32ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:54:00.006417 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 203ms. Breakdown: [{sync 201ms} {disk 2ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:54:07.529823 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 239ms. Breakdown: [{sync 238ms} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:54:13.099673 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 273ms. Breakdown: [{sync 272ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:54:13.307785 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 208ms. Breakdown: [{sync 129ms} {proposals 78ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:54:18.102353 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 247ms. Breakdown: [{sync 118ms} {proposals 87ms} {disk 42ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:54:18.304552 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 201ms. Breakdown: [{sync 177ms} {proposals 23ms} {disk 0s} {advance 0s}]. Num entries: 2. MustSync: true
W0614 15:55:18.563407 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 209ms. Breakdown: [{disk 117ms} {sync 92ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:56:05.985332 95643 node.go:674] [0x1] Read index context timed out
W0614 15:56:07.986141 95643 node.go:674] [0x1] Read index context timed out
W0614 15:56:09.986341 95643 node.go:674] [0x1] Read index context timed out
W0614 15:56:12.001664 95643 node.go:674] [0x1] Read index context timed out
W0614 15:56:14.020533 95643 node.go:674] [0x1] Read index context timed out
E0614 15:56:15.992201 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:56:16.021077 95643 node.go:674] [0x1] Read index context timed out
E0614 15:56:16.026193 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:56:16.068003 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:56:16.157219 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:56:16.318606 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:56:16.651502 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:56:17.304311 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:56:18.022494 95643 node.go:674] [0x1] Read index context timed out
E0614 15:56:18.382235 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:56:19.414428 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:56:20.024245 95643 node.go:674] [0x1] Read index context timed out
E0614 15:56:20.418198 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:56:21.420344 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:56:22.027042 95643 node.go:674] [0x1] Read index context timed out
E0614 15:56:22.422476 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:56:23.438795 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
W0614 15:56:24.064165 95643 node.go:674] [0x1] Read index context timed out
E0614 15:56:24.453370 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
E0614 15:56:25.456819 95643 oracle.go:522] Got error: Assigning IDs is only allowed on leader. while leasing timestamps: val:1
I0614 15:56:25.639278 95643 oracle.go:107] Purged below ts:431797, len(o.commits):130, len(o.rowCommit):230456
W0614 15:56:25.643273 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 21.88s. Breakdown: [{proposals 21.805s} {sync 75ms} {disk 1ms} {advance 0s}]. Num entries: 3. MustSync: true
I0614 15:56:25.648732 95643 raft.go:616] Writing snapshot at index: 177944, applied mark: 178078
I0614 15:56:26.153156 95643 oracle.go:107] Purged below ts:431797, len(o.commits):133, len(o.rowCommit):232446
I0614 15:56:26.285395 95643 oracle.go:107] Purged below ts:431797, len(o.commits):133, len(o.rowCommit):232446
W0614 15:56:26.285506 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 642ms. Breakdown: [{proposals 320ms} {sync 318ms} {disk 4ms} {advance 0s}]. Num entries: 10. MustSync: true
W0614 15:56:49.381320 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 223ms. Breakdown: [{sync 162ms} {proposals 60ms} {disk 1ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:57:06.253253 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 288ms. Breakdown: [{sync 286ms} {disk 2ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:57:16.532674 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 205ms. Breakdown: [{sync 203ms} {disk 2ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:57:16.794507 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 262ms. Breakdown: [{sync 261ms} {disk 0s} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:57:18.363878 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 524ms. Breakdown: [{proposals 504ms} {sync 20ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:57:26.015150 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 228ms. Breakdown: [{disk 149ms} {sync 79ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:57:27.722683 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 378ms. Breakdown: [{sync 378ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:58:44.013881 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 1.218s. Breakdown: [{proposals 1.026s} {sync 190ms} {disk 1ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:58:46.985196 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 204ms. Breakdown: [{sync 202ms} {proposals 1ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 15:59:39.186541 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 348ms. Breakdown: [{proposals 318ms} {sync 27ms} {disk 3ms} {advance 0s}]. Num entries: 1. MustSync: true
W0614 16:01:05.887271 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 235ms. Breakdown: [{sync 234ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 16:01:13.931761 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 361ms. Breakdown: [{sync 307ms} {disk 54ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 16:01:24.017980 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 256ms. Breakdown: [{sync 255ms} {disk 1ms} {proposals 0s} {advance 0s}]. Num entries: 1. MustSync: true
W0614 16:01:48.568883 95643 raft.go:733] Raft.Ready took too long to process: Timer Total: 208ms. Breakdown: [{sync 140ms} {proposals 68ms} {disk 0s} {advance 0s}]. Num entries: 1. MustSync: true
Anurag
June 14, 2020, 1:49pm
4
What cluster configuration are you using? It looks like zero leader gets switched in middle of mutation.
How do I check the cluster config? I have just run dgraph zero and dgraph alpha to start everything, then dgraph live to insert my data.
Neeraj
June 15, 2020, 4:48am
6
The transactions need zero leader to assign the IDs and they got aborted as there was no zero leader for some time. But they were appended in the log entries so that they can be processed later on when the zero leader is up.
There were some aborts but they were taken care when the zero leader was up. Your data isn’t causing any error in this case and it’ll be consistent after upload.
Tagging @MichelDiz to make sure.
3 Likes
MichelDiz
June 15, 2020, 5:19am
7
How many Zeros are being executed? You might at least 3+ zeros. If one of them dies another election would take place to elect* a new leader. And wait for the other to recover.
Also, Dgraph accepts a list of Zero or Alphas addresses. Always good to provide all addresses. Because when a Zero is elected, during the Liveload, the node Alpha will try to communicate with the provided addresses.
➜ ~ dgraph alpha -h | grep zero
-z, --zero string Comma separated list of Dgraph zero addresses of the form IP_ADDRESS:PORT. (default "localhost:5080")
➜ ~ dgraph live -h | grep alpha
-a, --alpha string Comma-separated list of Dgraph alpha gRPC server addresses (default "127.0.0.1:9080")
You should also check the specs of your machine. Avoid using the standalone tag or all nodes in the same machine if you don’t have enough resources.
1 Like
Naman
June 15, 2020, 5:45am
8
I guess only one instance of zero is running, as the user mentioned that he used dgraph zero to start zero without any other flags.
@kevin.obrien You may have a look at High Availability Cluster Setup in case you want to avoid facing this problem. And as @MichelDiz mentioned, it provides all the addresses through flags. A single address would be sufficient, but other addresses in the list act as a fallback option in case if the first address is not up.