Skip to content

Instantly share code, notes, and snippets.

@d4l3k

d4l3k/block_writer

Last active June 20, 2016 21:45
Show Gist options
  • Save d4l3k/e6b8106307154c18eb69c5307276b7c0 to your computer and use it in GitHub Desktop.
Save d4l3k/e6b8106307154c18eb69c5307276b7c0 to your computer and use it in GitHub Desktop.
Download ZIP
d9, extra log statements
Raw
block_writer
~/go/src/github.com/cockroachdb/cockroach   figuringoutshit ●  block_writer
2016/06/20 17:34:02 1s: 0.0/sec
2016/06/20 17:34:03 2s: 720.0/sec
2016/06/20 17:34:04 3s: 746.6/sec
2016/06/20 17:34:05 4s: 716.1/sec
2016/06/20 17:34:06 5s: 581.9/sec
2016/06/20 17:34:07 6s: 593.0/sec
2016/06/20 17:34:08 7s: 659.2/sec
2016/06/20 17:34:09 8s: 568.6/sec
2016/06/20 17:34:10 9s: 573.2/sec
2016/06/20 17:34:11 10s: 572.0/sec
2016/06/20 17:34:12 11s: 584.0/sec
2016/06/20 17:34:13 12s: 589.3/sec
2016/06/20 17:34:14 13s: 547.5/sec
2016/06/20 17:34:15 14s: 383.8/sec
2016/06/20 17:34:16 15s: 466.2/sec
2016/06/20 17:34:17 16s: 496.0/sec
2016/06/20 17:34:18 17s: 526.4/sec
2016/06/20 17:34:19 18s: 595.8/sec
2016/06/20 17:34:20 19s: 511.3/sec
2016/06/20 17:34:21 20s: 543.5/sec
2016/06/20 17:34:22 21s: 494.7/sec
2016/06/20 17:34:23 22s: 417.1/sec
2016/06/20 17:34:24 23s: 565.1/sec
2016/06/20 17:34:25 24s: 613.4/sec
2016/06/20 17:34:26 25s: 560.3/sec
2016/06/20 17:34:27 26s: 544.4/sec
2016/06/20 17:34:28 27s: 494.3/sec
2016/06/20 17:34:29 28s: 514.0/sec
2016/06/20 17:34:30 29s: 552.5/sec
2016/06/20 17:34:31 30s: 568.1/sec
2016/06/20 17:34:32 31s: 539.0/sec
2016/06/20 17:34:33 32s: 540.2/sec
2016/06/20 17:34:34 33s: 445.4/sec
2016/06/20 17:34:35 34s: 579.6/sec
2016/06/20 17:34:36 35s: 489.2/sec
2016/06/20 17:34:37 36s: 493.7/sec
2016/06/20 17:34:38 37s: 460.0/sec
2016/06/20 17:34:39 38s: 525.2/sec
2016/06/20 17:34:40 39s: 585.9/sec
2016/06/20 17:34:41 40s: 705.0/sec
2016/06/20 17:34:42 41s: 698.8/sec
2016/06/20 17:34:43 42s: 732.8/sec
2016/06/20 17:34:44 43s: 719.7/sec
2016/06/20 17:34:45 44s: 691.9/sec
2016/06/20 17:34:46 45s: 684.2/sec
2016/06/20 17:34:47 46s: 767.2/sec
2016/06/20 17:34:48 47s: 793.2/sec
2016/06/20 17:34:49 48s: 770.0/sec
2016/06/20 17:34:50 49s: 745.0/sec
2016/06/20 17:34:51 50s: 737.1/sec
2016/06/20 17:34:52 51s: 298.7/sec
2016/06/20 17:34:53 52s: 0.0/sec
2016/06/20 17:34:54 53s: 0.0/sec
2016/06/20 17:34:55 54s: 474.1/sec
2016/06/20 17:34:56 55s: 631.2/sec
2016/06/20 17:34:57 56s: 800.0/sec
2016/06/20 17:34:58 57s: 731.2/sec
2016/06/20 17:34:59 58s: 811.6/sec
2016/06/20 17:35:00 59s: 766.2/sec
2016/06/20 17:35:01 1m0s: 784.0/sec
2016/06/20 17:35:02 1m1s: 825.4/sec
2016/06/20 17:35:03 1m2s: 744.2/sec
2016/06/20 17:35:04 1m3s: 567.0/sec
2016/06/20 17:35:05 1m4s: 770.8/sec
2016/06/20 17:35:06 1m5s: 783.8/sec
2016/06/20 17:35:07 1m6s: 733.6/sec
2016/06/20 17:35:08 1m7s: 753.1/sec
2016/06/20 17:35:09 1m8s: 751.6/sec
2016/06/20 17:35:10 1m9s: 736.6/sec
2016/06/20 17:35:11 1m10s: 760.3/sec
2016/06/20 17:35:12 1m11s: 625.9/sec
2016/06/20 17:35:13 1m12s: 597.1/sec
2016/06/20 17:35:14 1m13s: 806.3/sec
2016/06/20 17:35:15 1m14s: 779.7/sec
2016/06/20 17:35:16 1m15s: 754.3/sec
2016/06/20 17:35:17 1m16s: 772.0/sec
2016/06/20 17:35:18 1m17s: 744.4/sec
2016/06/20 17:35:19 1m18s: 740.6/sec
2016/06/20 17:35:20 1m19s: 688.6/sec
2016/06/20 17:35:21 1m20s: 601.9/sec
2016/06/20 17:35:22 1m21s: 773.2/sec
2016/06/20 17:35:23 1m22s: 795.4/sec
2016/06/20 17:35:24 1m23s: 772.0/sec
2016/06/20 17:35:25 1m24s: 774.1/sec
2016/06/20 17:35:26 1m25s: 786.7/sec
2016/06/20 17:35:27 1m26s: 738.8/sec
2016/06/20 17:35:28 1m27s: 698.4/sec
2016/06/20 17:35:29 1m28s: 548.4/sec
2016/06/20 17:35:30 1m29s: 707.6/sec
2016/06/20 17:35:31 1m30s: 790.3/sec
2016/06/20 17:35:32 1m31s: 788.5/sec
2016/06/20 17:35:33 1m32s: 753.9/sec
2016/06/20 17:35:34 1m33s: 787.1/sec
2016/06/20 17:35:35 1m34s: 767.4/sec
2016/06/20 17:35:36 1m35s: 753.0/sec
2016/06/20 17:35:37 1m36s: 520.2/sec
2016/06/20 17:35:38 1m37s: 624.6/sec
2016/06/20 17:35:39 1m38s: 785.3/sec
2016/06/20 17:35:40 1m39s: 727.6/sec
2016/06/20 17:35:41 1m40s: 743.9/sec
2016/06/20 17:35:42 1m41s: 757.7/sec
2016/06/20 17:35:43 1m42s: 822.2/sec
2016/06/20 17:35:44 1m43s: 758.6/sec
2016/06/20 17:35:45 1m44s: 628.5/sec
2016/06/20 17:35:46 1m45s: 552.2/sec
2016/06/20 17:35:47 1m46s: 726.9/sec
2016/06/20 17:35:48 1m47s: 779.1/sec
2016/06/20 17:35:49 1m48s: 734.6/sec
2016/06/20 17:35:50 1m49s: 760.2/sec
2016/06/20 17:35:51 1m50s: 771.8/sec
2016/06/20 17:35:52 1m51s: 737.7/sec
2016/06/20 17:35:53 1m52s: 717.4/sec
2016/06/20 17:35:54 1m53s: 554.1/sec
2016/06/20 17:35:55 1m54s: 615.6/sec
2016/06/20 17:35:56 1m55s: 789.0/sec
2016/06/20 17:35:57 1m56s: 769.9/sec
2016/06/20 17:35:58 1m57s: 737.7/sec
2016/06/20 17:35:59 1m58s: 752.4/sec
2016/06/20 17:36:00 1m59s: 755.9/sec
2016/06/20 17:36:01 2m0s: 790.7/sec
2016/06/20 17:36:02 2m1s: 616.5/sec
2016/06/20 17:36:03 2m2s: 567.8/sec
2016/06/20 17:36:04 2m3s: 734.9/sec
2016/06/20 17:36:05 2m4s: 766.1/sec
2016/06/20 17:36:06 2m5s: 654.8/sec
2016/06/20 17:36:07 2m6s: 535.4/sec
2016/06/20 17:36:08 2m7s: 700.2/sec
2016/06/20 17:36:09 2m8s: 596.8/sec
2016/06/20 17:36:10 2m9s: 672.5/sec
2016/06/20 17:36:11 2m10s: 627.3/sec
2016/06/20 17:36:12 2m11s: 555.8/sec
2016/06/20 17:36:13 2m12s: 542.4/sec
2016/06/20 17:36:14 2m13s: 535.1/sec
2016/06/20 17:36:15 2m14s: 404.3/sec
2016/06/20 17:36:16 2m15s: 484.6/sec
2016/06/20 17:36:17 2m16s: 309.7/sec
2016/06/20 17:36:18 2m17s: 0.0/sec
2016/06/20 17:36:19 2m18s: 0.0/sec
2016/06/20 17:36:20 2m19s: 0.0/sec
2016/06/20 17:36:21 2m20s: 0.0/sec
2016/06/20 17:36:22 2m21s: 0.0/sec
2016/06/20 17:36:23 2m22s: 223.0/sec
2016/06/20 17:36:24 2m23s: 765.9/sec
2016/06/20 17:36:25 2m24s: 783.8/sec
2016/06/20 17:36:26 2m25s: 684.1/sec
2016/06/20 17:36:27 2m26s: 614.1/sec
2016/06/20 17:36:28 2m27s: 527.7/sec
2016/06/20 17:36:29 2m28s: 495.3/sec
2016/06/20 17:36:30 2m29s: 689.5/sec
2016/06/20 17:36:31 2m30s: 742.4/sec
2016/06/20 17:36:32 2m31s: 654.6/sec
2016/06/20 17:36:33 2m32s: 711.7/sec
Raw
drop 1
~/go/src/github.com/petermattis/roachdemo/d9   master ●  ag "17:34.*(\[split\]|splitting|campaigning|raft/raft|AdminSplit|leader lease|initiating a split)" cockroach-data/
cockroach-data/1/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_33_26-04_00.1212
8676:I160620 17:34:01.082270 storage/split_queue.go:97 splitting range=5 [/Table/14-/Max) at keys [/Table/50/0]
8688:I160620 17:34:01.083370 kv/transport.go:164 sending request to Tristans-MacBook-Pro.local:26257: AdminSplit [/Table/50/0,/Min)
8689:I160620 17:34:01.083419 storage/replica.go:1191 [admin] leader lease: acquiring 5
8690:I160620 17:34:01.083425 storage/replica.go:1196 [admin] leader lease: acquired 5
8691:I160620 17:34:01.083433 storage/replica_command.go:2067 [split] split begins: 5
8692:I160620 17:34:01.083439 storage/replica_command.go:2109 [split] found split key: 5
8693:I160620 17:34:01.083458 storage/replica_command.go:2122 initiating a split of range=5 [/Table/14-/Max) at key /Table/50
8712:I160620 17:34:01.088141 storage/replica_command.go:169 executed BeginTransaction command header:<key:"\001k\022\272\000\001rdsc" > : header:<txn:<meta:<id:<0df46e9a-c540-4d9f-bce6-6f9e5583f5b3> isolation:SERIALIZABLE key:"\001k\022\272\000\001rdsc" epoch:0 timestamp:<wall_time:1466458441083496177 logical:0 > priority:677110 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:PENDING orig_timestamp:<wall_time:1466458441083496177 logical:0 > max_timestamp:<wall_time:1466458441083496177 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458441083496177 logical:0 > > writing:true write_too_old:false retry_on_push:false > > , err=%!s(<nil>)
8883:I160620 17:34:01.123469 storage/replica_command.go:169 executed EndTransaction command header:<key:"\001k\022\272\000\001rdsc" > commit:true internal_commit_trigger:<split_trigger:<updated_desc:<range_id:5 start_key:"\226" end_key:"\272" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > new_desc:<range_id:6 start_key:"\272" end_key:"\377\377" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > initial_leader_store_id:1 > > intent_spans:<key:"\001k\022\224\000\001rtn-" > intent_spans:<key:"\001k\022\225\000\001rtn-" > intent_spans:<key:"\001k\022\226\000\001rdsc" > intent_spans:<key:"\001k\022\226\000\001rtn-" > intent_spans:<key:"\001k\022\272\000\001rdsc" > intent_spans:<key:"\001k\022\272\000\001rtn-" > intent_spans:<key:"\003\272" > intent_spans:<key:"\003\377\377" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\210" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\212\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\213\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\214\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\215\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\216\211" > : header:<txn:<meta:<id:<0df46e9a-c540-4d9f-bce6-6f9e5583f5b3> isolation:SERIALIZABLE key:"\001k\022\272\000\001rdsc" epoch:0 timestamp:<wall_time:1466458441083496177 logical:0 > priority:677110 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:COMMITTED orig_timestamp:<wall_time:1466458441083496177 logical:0 > max_timestamp:<wall_time:1466458441083496177 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458441083496177 logical:0 > > writing:true write_too_old:false retry_on_push:false intents:<key:"\001k\022\224\000\001rtn-" > intents:<key:"\001k\022\225\000\001rtn-" > intents:<key:"\003\272" > intents:<key:"\003\377\377" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\210" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\212\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\213\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\214\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\215\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\216\211" > > > commit_wait:0 one_phase_commit:false , err=%!s(<nil>)
8887:I160620 17:34:01.124627 kv/dist_sender.go:981 RPC reply: *roachpb.AdminSplitResponse
8889:I160620 17:34:01.124662 storage/queue.go:436 [split] range=5 [/Table/14-/Table/50): done: 42.390563ms
8892:I160620 17:34:01.125539 storage/queue.go:436 [split] range=5 [/Table/14-/Table/50): done: 15.397µs
8969:I160620 17:34:01.135448 raft/raft.go:469 [group 6] 1 became follower at term 5
8970:I160620 17:34:01.135499 raft/raft.go:238 [group 6] newRaft 1 [peers: [1,2,3], term: 5, commit: 10, applied: 10, lastindex: 10, lastterm: 5]
8971:I160620 17:34:01.135561 raft/raft.go:777 [group 6] 1 no leader at term 5; dropping proposal
8984:I160620 17:34:02.125268 storage/replica_command.go:2334 range=5 campaigning after split
8985:I160620 17:34:02.125284 raft/raft.go:549 [group 6] 1 is starting a new election at term 5
8986:I160620 17:34:02.125300 raft/raft.go:482 [group 6] 1 became candidate at term 6
8987:I160620 17:34:02.125304 raft/raft.go:531 [group 6] 1 received vote from 1 at term 6
8988:I160620 17:34:02.125372 raft/raft.go:524 [group 6] 1 [logterm: 5, index: 10] sent vote request to 2 at term 6
8989:I160620 17:34:02.125403 raft/raft.go:524 [group 6] 1 [logterm: 5, index: 10] sent vote request to 3 at term 6
8990:I160620 17:34:02.152045 raft/raft.go:531 [group 6] 1 received vote from 3 at term 6
8991:I160620 17:34:02.152076 raft/raft.go:760 [group 6] 1 [quorum:2] has received 2 votes and 0 vote rejections
8992:I160620 17:34:02.152145 raft/raft.go:510 [group 6] 1 became leader at term 6
8994:I160620 17:34:02.153502 storage/replica_command.go:1570 range 6: new leader lease replica {1 1 1} 1970-01-01 00:00:00 +0000 UTC 407349h34m5.885305243s following replica {0 0 0} 1970-01-01 00:00:00 +0000 UTC 0 [physicalTime=2016-06-20 21:34:02.153457044 +0000 UTC]
cockroach-data/1/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_34_25-04_00.1212
15880:I160620 17:34:27.287657 raft/raft.go:727 [group 3] 1 [term 6] starts to transfer leadership to 3
15881:I160620 17:34:27.287679 raft/raft.go:733 [group 3] 1 sends MsgTimeoutNow to 3 immediately as 3 already has up-to-date log
16101:I160620 17:34:27.315029 raft/raft.go:571 [group 3] 1 [term: 6] received a MsgVote message with higher term from 3 [term: 7]
16102:I160620 17:34:27.315045 raft/raft.go:469 [group 3] 1 became follower at term 7
16105:I160620 17:34:27.315214 raft/raft.go:797 [group 3] 1 [logterm: 6, index: 39, vote: 0] voted for 3 [logterm: 6, index: 39] at term 7
cockroach-data/1/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_34_49-04_00.1212
29717:I160620 17:34:51.476801 storage/split_queue.go:97 splitting range=6 [/Table/50-/Max) at keys [/Table/51/0]
29722:I160620 17:34:51.476927 kv/transport.go:164 sending request to Tristans-MacBook-Pro.local:26257: AdminSplit [/Table/51/0,/Min)
29724:I160620 17:34:51.476983 storage/replica.go:1191 [admin] leader lease: acquiring 6
29725:I160620 17:34:51.476990 storage/replica.go:1196 [admin] leader lease: acquired 6
29727:I160620 17:34:51.476998 storage/replica_command.go:2067 [split] split begins: 6
29728:I160620 17:34:51.477007 storage/replica_command.go:2109 [split] found split key: 6
29729:I160620 17:34:51.477052 storage/replica_command.go:2122 initiating a split of range=6 [/Table/50-/Max) at key /Table/51
29877:I160620 17:34:51.486829 storage/replica_command.go:169 executed BeginTransaction command header:<key:"\001k\022\273\000\001rdsc" > : header:<txn:<meta:<id:<ff308d2d-7bd2-4f55-91ae-c6ada13704f9> isolation:SERIALIZABLE key:"\001k\022\273\000\001rdsc" epoch:0 timestamp:<wall_time:1466458491477090684 logical:0 > priority:175999 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:PENDING orig_timestamp:<wall_time:1466458491477090684 logical:0 > max_timestamp:<wall_time:1466458491477090684 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458491477090684 logical:0 > > writing:true write_too_old:false retry_on_push:false > > , err=%!s(<nil>)
30382:I160620 17:34:51.530795 storage/replica_command.go:169 executed EndTransaction command header:<key:"\001k\022\273\000\001rdsc" > commit:true internal_commit_trigger:<split_trigger:<updated_desc:<range_id:6 start_key:"\272" end_key:"\273" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > new_desc:<range_id:7 start_key:"\273" end_key:"\377\377" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > initial_leader_store_id:1 > > intent_spans:<key:"\001k\022\225\000\001rtn-" > intent_spans:<key:"\001k\022\226\000\001rtn-" > intent_spans:<key:"\001k\022\272\000\001rdsc" > intent_spans:<key:"\001k\022\272\000\001rtn-" > intent_spans:<key:"\001k\022\273\000\001rdsc" > intent_spans:<key:"\001k\022\273\000\001rtn-" > intent_spans:<key:"\003\273" > intent_spans:<key:"\003\377\377" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\210" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\212\211" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\213\211" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\214\211" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\215\211" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\216\211" > : header:<txn:<meta:<id:<ff308d2d-7bd2-4f55-91ae-c6ada13704f9> isolation:SERIALIZABLE key:"\001k\022\273\000\001rdsc" epoch:0 timestamp:<wall_time:1466458491477090684 logical:0 > priority:175999 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:COMMITTED orig_timestamp:<wall_time:1466458491477090684 logical:0 > max_timestamp:<wall_time:1466458491477090684 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458491477090684 logical:0 > > writing:true write_too_old:false retry_on_push:false intents:<key:"\001k\022\225\000\001rtn-" > intents:<key:"\001k\022\226\000\001rtn-" > intents:<key:"\003\273" > intents:<key:"\003\377\377" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\210" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\212\211" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\213\211" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\214\211" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\215\211" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\216\211" > > > commit_wait:0 one_phase_commit:false , err=%!s(<nil>)
30391:I160620 17:34:51.531604 kv/dist_sender.go:981 RPC reply: *roachpb.AdminSplitResponse
30393:I160620 17:34:51.531627 storage/queue.go:436 [split] range=6 [/Table/50-/Table/51): done: 54.833344ms
30428:I160620 17:34:51.547011 raft/raft.go:469 [group 7] 1 became follower at term 5
30429:I160620 17:34:51.547078 raft/raft.go:238 [group 7] newRaft 1 [peers: [1,2,3], term: 5, commit: 10, applied: 10, lastindex: 10, lastterm: 5]
30445:I160620 17:34:52.533249 storage/replica_command.go:2334 range=6 campaigning after split
30446:I160620 17:34:52.533272 raft/raft.go:549 [group 7] 1 is starting a new election at term 5
30447:I160620 17:34:52.533297 raft/raft.go:482 [group 7] 1 became candidate at term 6
30448:I160620 17:34:52.533306 raft/raft.go:531 [group 7] 1 received vote from 1 at term 6
30449:I160620 17:34:52.533477 raft/raft.go:524 [group 7] 1 [logterm: 5, index: 10] sent vote request to 2 at term 6
30450:I160620 17:34:52.533599 raft/raft.go:524 [group 7] 1 [logterm: 5, index: 10] sent vote request to 3 at term 6
30456:I160620 17:34:52.548073 raft/raft.go:531 [group 7] 1 received vote from 3 at term 6
30457:I160620 17:34:52.548084 raft/raft.go:760 [group 7] 1 [quorum:2] has received 2 votes and 0 vote rejections
30458:I160620 17:34:52.548095 raft/raft.go:510 [group 7] 1 became leader at term 6
30513:I160620 17:34:54.534335 storage/replica_command.go:1570 range 7: new leader lease replica {1 1 1} 1970-01-01 00:00:00 +0000 UTC 407349h34m59.283568383s following replica {0 0 0} 1970-01-01 00:00:00 +0000 UTC 0 [physicalTime=2016-06-20 21:34:54.534310045 +0000 UTC]
cockroach-data/2/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_33_27-04_00.1213
1953:I160620 17:34:01.089583 storage/replica_command.go:169 executed BeginTransaction command header:<key:"\001k\022\272\000\001rdsc" > : header:<txn:<meta:<id:<0df46e9a-c540-4d9f-bce6-6f9e5583f5b3> isolation:SERIALIZABLE key:"\001k\022\272\000\001rdsc" epoch:0 timestamp:<wall_time:1466458441083496177 logical:0 > priority:677110 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:PENDING orig_timestamp:<wall_time:1466458441083496177 logical:0 > max_timestamp:<wall_time:1466458441083496177 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458441083496177 logical:0 > > writing:true write_too_old:false retry_on_push:false > > , err=%!s(<nil>)
1996:I160620 17:34:01.125015 storage/replica_command.go:169 executed EndTransaction command header:<key:"\001k\022\272\000\001rdsc" > commit:true internal_commit_trigger:<split_trigger:<updated_desc:<range_id:5 start_key:"\226" end_key:"\272" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > new_desc:<range_id:6 start_key:"\272" end_key:"\377\377" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > initial_leader_store_id:1 > > intent_spans:<key:"\001k\022\224\000\001rtn-" > intent_spans:<key:"\001k\022\225\000\001rtn-" > intent_spans:<key:"\001k\022\226\000\001rdsc" > intent_spans:<key:"\001k\022\226\000\001rtn-" > intent_spans:<key:"\001k\022\272\000\001rdsc" > intent_spans:<key:"\001k\022\272\000\001rtn-" > intent_spans:<key:"\003\272" > intent_spans:<key:"\003\377\377" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\210" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\212\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\213\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\214\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\215\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\216\211" > : header:<txn:<meta:<id:<0df46e9a-c540-4d9f-bce6-6f9e5583f5b3> isolation:SERIALIZABLE key:"\001k\022\272\000\001rdsc" epoch:0 timestamp:<wall_time:1466458441083496177 logical:0 > priority:677110 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:COMMITTED orig_timestamp:<wall_time:1466458441083496177 logical:0 > max_timestamp:<wall_time:1466458441083496177 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458441083496177 logical:0 > > writing:true write_too_old:false retry_on_push:false intents:<key:"\001k\022\224\000\001rtn-" > intents:<key:"\001k\022\225\000\001rtn-" > intents:<key:"\003\272" > intents:<key:"\003\377\377" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\210" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\212\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\213\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\214\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\215\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\216\211" > > > commit_wait:0 one_phase_commit:false , err=%!s(<nil>)
2015:I160620 17:34:01.161381 raft/raft.go:469 [group 6] 3 became follower at term 5
2016:I160620 17:34:01.161424 raft/raft.go:238 [group 6] newRaft 3 [peers: [1,2,3], term: 5, commit: 10, applied: 10, lastindex: 10, lastterm: 5]
2017:I160620 17:34:02.151112 raft/raft.go:571 [group 6] 3 [term: 5] received a MsgVote message with higher term from 1 [term: 6]
2018:I160620 17:34:02.151161 raft/raft.go:469 [group 6] 3 became follower at term 6
2019:I160620 17:34:02.151448 raft/raft.go:797 [group 6] 3 [logterm: 5, index: 10, vote: 0] voted for 1 [logterm: 5, index: 10] at term 6
cockroach-data/2/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_34_23-04_00.1213
4458:I160620 17:34:27.288077 storage/replica_command.go:1570 range 3: new leader lease replica {2 2 3} 2016-06-20 21:34:05.828264781 +0000 UTC 26.191764582s following replica {1 1 1} 1970-01-01 00:00:00 +0000 UTC 407349h34m5.828264781s [physicalTime=2016-06-20 21:34:27.287999076 +0000 UTC]
4463:I160620 17:34:27.293604 raft/raft.go:806 [group 3] 3 [term 6] received MsgTimeoutNow from 1 and starts an election to get leadership.
4464:I160620 17:34:27.293638 raft/raft.go:482 [group 3] 3 became candidate at term 7
4465:I160620 17:34:27.293662 raft/raft.go:531 [group 3] 3 received vote from 3 at term 7
4466:I160620 17:34:27.293723 raft/raft.go:524 [group 3] 3 [logterm: 6, index: 39] sent vote request to 1 at term 7
4467:I160620 17:34:27.293891 raft/raft.go:524 [group 3] 3 [logterm: 6, index: 39] sent vote request to 2 at term 7
4648:I160620 17:34:27.310090 raft/raft.go:531 [group 3] 3 received vote from 2 at term 7
4649:I160620 17:34:27.310116 raft/raft.go:760 [group 3] 3 [quorum:2] has received 2 votes and 0 vote rejections
4650:I160620 17:34:27.310147 raft/raft.go:510 [group 3] 3 became leader at term 7
cockroach-data/2/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_34_50-04_00.1213
909:I160620 17:34:51.486896 storage/replica_command.go:169 executed BeginTransaction command header:<key:"\001k\022\273\000\001rdsc" > : header:<txn:<meta:<id:<ff308d2d-7bd2-4f55-91ae-c6ada13704f9> isolation:SERIALIZABLE key:"\001k\022\273\000\001rdsc" epoch:0 timestamp:<wall_time:1466458491477090684 logical:0 > priority:175999 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:PENDING orig_timestamp:<wall_time:1466458491477090684 logical:0 > max_timestamp:<wall_time:1466458491477090684 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458491477090684 logical:0 > > writing:true write_too_old:false retry_on_push:false > > , err=%!s(<nil>)
974:I160620 17:34:51.528258 storage/replica_command.go:169 executed EndTransaction command header:<key:"\001k\022\273\000\001rdsc" > commit:true internal_commit_trigger:<split_trigger:<updated_desc:<range_id:6 start_key:"\272" end_key:"\273" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > new_desc:<range_id:7 start_key:"\273" end_key:"\377\377" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > initial_leader_store_id:1 > > intent_spans:<key:"\001k\022\225\000\001rtn-" > intent_spans:<key:"\001k\022\226\000\001rtn-" > intent_spans:<key:"\001k\022\272\000\001rdsc" > intent_spans:<key:"\001k\022\272\000\001rtn-" > intent_spans:<key:"\001k\022\273\000\001rdsc" > intent_spans:<key:"\001k\022\273\000\001rtn-" > intent_spans:<key:"\003\273" > intent_spans:<key:"\003\377\377" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\210" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\212\211" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\213\211" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\214\211" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\215\211" > intent_spans:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\216\211" > : header:<txn:<meta:<id:<ff308d2d-7bd2-4f55-91ae-c6ada13704f9> isolation:SERIALIZABLE key:"\001k\022\273\000\001rdsc" epoch:0 timestamp:<wall_time:1466458491477090684 logical:0 > priority:175999 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:COMMITTED orig_timestamp:<wall_time:1466458491477090684 logical:0 > max_timestamp:<wall_time:1466458491477090684 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458491477090684 logical:0 > > writing:true write_too_old:false retry_on_push:false intents:<key:"\001k\022\225\000\001rtn-" > intents:<key:"\001k\022\226\000\001rtn-" > intents:<key:"\003\273" > intents:<key:"\003\377\377" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\210" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\212\211" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\213\211" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\214\211" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\215\211" > intents:<key:"\225\211\024\371Wha{\371\034o\324\270\375\002\034\007I'\\\000\000\216\211" > > > commit_wait:0 one_phase_commit:false , err=%!s(<nil>)
990:I160620 17:34:51.560329 raft/raft.go:469 [group 7] 3 became follower at term 5
991:I160620 17:34:51.560465 raft/raft.go:238 [group 7] newRaft 3 [peers: [1,2,3], term: 5, commit: 10, applied: 10, lastindex: 10, lastterm: 5]
995:I160620 17:34:52.547777 raft/raft.go:571 [group 7] 3 [term: 5] received a MsgVote message with higher term from 1 [term: 6]
996:I160620 17:34:52.547789 raft/raft.go:469 [group 7] 3 became follower at term 6
997:I160620 17:34:52.547918 raft/raft.go:797 [group 7] 3 [logterm: 5, index: 10, vote: 0] voted for 1 [logterm: 5, index: 10] at term 6
cockroach-data/3/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_33_28-04_00.1214
1956:I160620 17:34:01.088416 storage/replica_command.go:169 executed BeginTransaction command header:<key:"\001k\022\272\000\001rdsc" > : header:<txn:<meta:<id:<0df46e9a-c540-4d9f-bce6-6f9e5583f5b3> isolation:SERIALIZABLE key:"\001k\022\272\000\001rdsc" epoch:0 timestamp:<wall_time:1466458441083496177 logical:0 > priority:677110 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:PENDING orig_timestamp:<wall_time:1466458441083496177 logical:0 > max_timestamp:<wall_time:1466458441083496177 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458441083496177 logical:0 > > writing:true write_too_old:false retry_on_push:false > > , err=%!s(<nil>)
1999:I160620 17:34:01.123782 storage/replica_command.go:169 executed EndTransaction command header:<key:"\001k\022\272\000\001rdsc" > commit:true internal_commit_trigger:<split_trigger:<updated_desc:<range_id:5 start_key:"\226" end_key:"\272" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > new_desc:<range_id:6 start_key:"\272" end_key:"\377\377" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > initial_leader_store_id:1 > > intent_spans:<key:"\001k\022\224\000\001rtn-" > intent_spans:<key:"\001k\022\225\000\001rtn-" > intent_spans:<key:"\001k\022\226\000\001rdsc" > intent_spans:<key:"\001k\022\226\000\001rtn-" > intent_spans:<key:"\001k\022\272\000\001rdsc" > intent_spans:<key:"\001k\022\272\000\001rtn-" > intent_spans:<key:"\003\272" > intent_spans:<key:"\003\377\377" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\210" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\212\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\213\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\214\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\215\211" > intent_spans:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\216\211" > : header:<txn:<meta:<id:<0df46e9a-c540-4d9f-bce6-6f9e5583f5b3> isolation:SERIALIZABLE key:"\001k\022\272\000\001rdsc" epoch:0 timestamp:<wall_time:1466458441083496177 logical:0 > priority:677110 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:COMMITTED orig_timestamp:<wall_time:1466458441083496177 logical:0 > max_timestamp:<wall_time:1466458441083496177 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458441083496177 logical:0 > > writing:true write_too_old:false retry_on_push:false intents:<key:"\001k\022\224\000\001rtn-" > intents:<key:"\001k\022\225\000\001rtn-" > intents:<key:"\003\272" > intents:<key:"\003\377\377" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\210" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\212\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\213\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\214\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\215\211" > intents:<key:"\225\211\024\371WhaI\371\004\372\014@\375\002\034\007\"\263\271\000\000\216\211" > > > commit_wait:0 one_phase_commit:false , err=%!s(<nil>)
2019:I160620 17:34:01.210222 raft/raft.go:469 [group 6] 2 became follower at term 5
2020:I160620 17:34:01.210281 raft/raft.go:238 [group 6] newRaft 2 [peers: [1,2,3], term: 5, commit: 10, applied: 10, lastindex: 10, lastterm: 5]
2029:I160620 17:34:02.151034 raft/raft.go:571 [group 6] 2 [term: 5] received a MsgVote message with higher term from 1 [term: 6]
2030:I160620 17:34:02.151092 raft/raft.go:469 [group 6] 2 became follower at term 6
2031:I160620 17:34:02.151434 raft/raft.go:797 [group 6] 2 [logterm: 5, index: 10, vote: 0] voted for 1 [logterm: 5, index: 10] at term 6
cockroach-data/3/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_34_23-04_00.1214
4639:I160620 17:34:27.305665 raft/raft.go:571 [group 3] 2 [term: 6] received a MsgVote message with higher term from 3 [term: 7]
4640:I160620 17:34:27.305687 raft/raft.go:469 [group 3] 2 became follower at term 7
4641:I160620 17:34:27.305818 raft/raft.go:797 [group 3] 2 [logterm: 6, index: 39, vote: 0] voted for 3 [logterm: 6, index: 39] at term 7
Raw
drop 2
~/go/src/github.com/petermattis/roachdemo/d9   master ●  ag "17:3[678].*(\[split\]|splitting|campaigning|raft/raft|AdminSplit|leader lease|initiating a split)" cockroach-data/
cockroach-data/1/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_36_11-04_00.1212
15446:I160620 17:36:13.124568 storage/split_queue.go:114 splitting range=7 [/Table/51-/Max) size=67109395 max=67108864
15447:I160620 17:36:13.124614 storage/replica.go:1191 [admin] leader lease: acquiring 7
15448:I160620 17:36:13.124621 storage/replica.go:1196 [admin] leader lease: acquired 7
15449:I160620 17:36:13.124630 storage/replica_command.go:2067 [split] split begins: 7
15450:I160620 17:36:13.124657 storage/replica_command.go:2076 [split] MVCCFindSplitKey: 7
cockroach-data/1/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_36_16-04_00.1212
9541:I160620 17:36:16.729272 storage/replica_command.go:2078 [split] MVCCFindSplitKey done: 7
9543:I160620 17:36:16.729279 storage/replica_command.go:2109 [split] found split key: 7
9546:I160620 17:36:16.729306 storage/replica_command.go:2122 initiating a split of range=7 [/Table/51-/Max) at key /Table/51/1/4606481057062370588/"84e0696b-1597-4afc-a851-e423df5f6532"/9216
9650:I160620 17:36:16.735713 storage/replica_command.go:169 executed BeginTransaction command header:<key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rdsc" > : header:<txn:<meta:<id:<6573f7b5-062e-423c-9eed-d02918c11a6b> isolation:SERIALIZABLE key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rdsc" epoch:0 timestamp:<wall_time:1466458576729358965 logical:0 > priority:423720 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:PENDING orig_timestamp:<wall_time:1466458576729358965 logical:0 > max_timestamp:<wall_time:1466458576729358965 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458576729358965 logical:0 > > writing:true write_too_old:false retry_on_push:false > > , err=%!s(<nil>)
10066:I160620 17:36:16.779216 storage/replica_command.go:1570 range 3: new leader lease replica {1 1 1} 2016-06-20 21:34:32.020029363 +0000 UTC 1m49.505761718s following replica {2 2 3} 2016-06-20 21:34:05.828264781 +0000 UTC 26.191764582s [physicalTime=2016-06-20 21:36:16.779174692 +0000 UTC]
10079:I160620 17:36:16.780847 raft/raft.go:806 [group 3] 1 [term 7] received MsgTimeoutNow from 3 and starts an election to get leadership.
10080:I160620 17:36:16.780859 raft/raft.go:482 [group 3] 1 became candidate at term 8
10081:I160620 17:36:16.780864 raft/raft.go:531 [group 3] 1 received vote from 1 at term 8
10082:I160620 17:36:16.780899 raft/raft.go:524 [group 3] 1 [logterm: 7, index: 41] sent vote request to 2 at term 8
10084:I160620 17:36:16.780931 raft/raft.go:524 [group 3] 1 [logterm: 7, index: 41] sent vote request to 3 at term 8
10127:I160620 17:36:16.783297 raft/raft.go:531 [group 3] 1 received vote from 3 at term 8
10128:I160620 17:36:16.783308 raft/raft.go:760 [group 3] 1 [quorum:2] has received 2 votes and 0 vote rejections
10129:I160620 17:36:16.783322 raft/raft.go:510 [group 3] 1 became leader at term 8
10415:I160620 17:36:16.846882 storage/replica_command.go:169 executed EndTransaction command header:<key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rdsc" > commit:true internal_commit_trigger:<split_trigger:<updated_desc:<range_id:7 start_key:"\273" end_key:"\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\001\367$\000" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > new_desc:<range_id:8 start_key:"\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\001\367$\000" end_key:"\377\377" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > initial_leader_store_id:1 > > intent_spans:<key:"\001k\022\223\000\001rtn-" > intent_spans:<key:"\001k\022\224\000\001rtn-" > intent_spans:<key:"\001k\022\225\000\001rtn-" > intent_spans:<key:"\001k\022\226\000\001rtn-" > intent_spans:<key:"\001k\022\272\000\001rtn-" > intent_spans:<key:"\001k\022\273\000\001rdsc" > intent_spans:<key:"\001k\022\273\000\001rtn-" > intent_spans:<key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rdsc" > intent_spans:<key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rtn-" > intent_spans:<key:"\003\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\001\367$\000" > intent_spans:<key:"\003\377\377" > intent_spans:<key:"\004range-tree-root" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\210" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\212\211" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\213\211" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\214\211" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\215\211" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\216\211" > : header:<txn:<meta:<id:<6573f7b5-062e-423c-9eed-d02918c11a6b> isolation:SERIALIZABLE key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rdsc" epoch:0 timestamp:<wall_time:1466458576729358965 logical:0 > priority:423720 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:COMMITTED orig_timestamp:<wall_time:1466458576729358965 logical:0 > max_timestamp:<wall_time:1466458576729358965 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458576729358965 logical:0 > > writing:true write_too_old:false retry_on_push:false intents:<key:"\001k\022\223\000\001rtn-" > intents:<key:"\001k\022\224\000\001rtn-" > intents:<key:"\001k\022\225\000\001rtn-" > intents:<key:"\001k\022\226\000\001rtn-" > intents:<key:"\001k\022\272\000\001rtn-" > intents:<key:"\003\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\001\367$\000" > intents:<key:"\003\377\377" > intents:<key:"\004range-tree-root" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\210" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\212\211" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\213\211" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\214\211" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\215\211" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\216\211" > > > commit_wait:0 one_phase_commit:false , err=%!s(<nil>)
10417:I160620 17:36:16.847578 storage/queue.go:436 [split] range=7 [/Table/51-/Table/51/1/4606481057062370588/"84e0696b-1597-4afc-a851-e423df5f6532"/9216): done: 3.723056106s
10432:I160620 17:36:16.850762 storage/queue.go:436 [split] range=7 [/Table/51-/Table/51/1/4606481057062370588/"84e0696b-1597-4afc-a851-e423df5f6532"/9216): done: 37.239µs
10433:I160620 17:36:16.850816 raft/raft.go:469 [group 8] 1 became follower at term 5
10434:I160620 17:36:16.850886 raft/raft.go:238 [group 8] newRaft 1 [peers: [1,2,3], term: 5, commit: 10, applied: 10, lastindex: 10, lastterm: 5]
10703:I160620 17:36:17.849983 storage/replica_command.go:2334 range=7 campaigning after split
10704:I160620 17:36:17.850000 raft/raft.go:549 [group 8] 1 is starting a new election at term 5
10705:I160620 17:36:17.850018 raft/raft.go:482 [group 8] 1 became candidate at term 6
10706:I160620 17:36:17.850024 raft/raft.go:531 [group 8] 1 received vote from 1 at term 6
10707:I160620 17:36:17.850242 raft/raft.go:524 [group 8] 1 [logterm: 5, index: 10] sent vote request to 3 at term 6
10708:I160620 17:36:17.850320 raft/raft.go:524 [group 8] 1 [logterm: 5, index: 10] sent vote request to 2 at term 6
10710:I160620 17:36:17.850997 raft/raft.go:531 [group 8] 1 received vote from 3 at term 6
10711:I160620 17:36:17.851008 raft/raft.go:760 [group 8] 1 [quorum:2] has received 2 votes and 0 vote rejections
10712:I160620 17:36:17.851022 raft/raft.go:510 [group 8] 1 became leader at term 6
11029:I160620 17:36:22.852552 storage/replica_command.go:1570 range 8: new leader lease replica {1 1 1} 1970-01-01 00:00:00 +0000 UTC 407349h36m27.601842993s following replica {0 0 0} 1970-01-01 00:00:00 +0000 UTC 0 [physicalTime=2016-06-20 21:36:22.852498929 +0000 UTC]
cockroach-data/1/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_36_32-04_00.1212
14084:I160620 17:36:37.309868 raft/raft.go:727 [group 3] 1 [term 8] starts to transfer leadership to 3
14085:I160620 17:36:37.309911 raft/raft.go:733 [group 3] 1 sends MsgTimeoutNow to 3 immediately as 3 already has up-to-date log
14087:I160620 17:36:37.312705 raft/raft.go:571 [group 3] 1 [term: 8] received a MsgVote message with higher term from 3 [term: 9]
14088:I160620 17:36:37.312750 raft/raft.go:469 [group 3] 1 became follower at term 9
14089:I160620 17:36:37.313140 raft/raft.go:797 [group 3] 1 [logterm: 8, index: 45, vote: 0] voted for 3 [logterm: 8, index: 45] at term 9
cockroach-data/1/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_36_29-04_00.1212
29425:I160620 17:36:32.296643 raft/raft.go:727 [group 2] 1 [term 6] starts to transfer leadership to 3
29426:I160620 17:36:32.296655 raft/raft.go:733 [group 2] 1 sends MsgTimeoutNow to 3 immediately as 3 already has up-to-date log
29468:I160620 17:36:32.299353 raft/raft.go:571 [group 2] 1 [term: 6] received a MsgVote message with higher term from 3 [term: 7]
29469:I160620 17:36:32.299363 raft/raft.go:469 [group 2] 1 became follower at term 7
29470:I160620 17:36:32.299472 raft/raft.go:797 [group 2] 1 [logterm: 6, index: 36, vote: 0] voted for 3 [logterm: 6, index: 36] at term 7
cockroach-data/2/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_36_09-04_00.1213
7605:I160620 17:36:16.736026 storage/replica_command.go:169 executed BeginTransaction command header:<key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rdsc" > : header:<txn:<meta:<id:<6573f7b5-062e-423c-9eed-d02918c11a6b> isolation:SERIALIZABLE key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rdsc" epoch:0 timestamp:<wall_time:1466458576729358965 logical:0 > priority:423720 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:PENDING orig_timestamp:<wall_time:1466458576729358965 logical:0 > max_timestamp:<wall_time:1466458576729358965 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458576729358965 logical:0 > > writing:true write_too_old:false retry_on_push:false > > , err=%!s(<nil>)
7657:I160620 17:36:16.778448 raft/raft.go:727 [group 3] 3 [term 7] starts to transfer leadership to 1
7658:I160620 17:36:16.778466 raft/raft.go:733 [group 3] 3 sends MsgTimeoutNow to 1 immediately as 1 already has up-to-date log
7664:I160620 17:36:16.781504 raft/raft.go:571 [group 3] 3 [term: 7] received a MsgVote message with higher term from 1 [term: 8]
7665:I160620 17:36:16.781521 raft/raft.go:469 [group 3] 3 became follower at term 8
7666:I160620 17:36:16.781613 raft/raft.go:797 [group 3] 3 [logterm: 7, index: 41, vote: 0] voted for 1 [logterm: 7, index: 41] at term 8
7707:I160620 17:36:16.913383 storage/replica_command.go:169 executed EndTransaction command header:<key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rdsc" > commit:true internal_commit_trigger:<split_trigger:<updated_desc:<range_id:7 start_key:"\273" end_key:"\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\001\367$\000" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > new_desc:<range_id:8 start_key:"\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\001\367$\000" end_key:"\377\377" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:3 store_id:3 replica_id:2 > replicas:<node_id:2 store_id:2 replica_id:3 > next_replica_id:4 > initial_leader_store_id:1 > > intent_spans:<key:"\001k\022\223\000\001rtn-" > intent_spans:<key:"\001k\022\224\000\001rtn-" > intent_spans:<key:"\001k\022\225\000\001rtn-" > intent_spans:<key:"\001k\022\226\000\001rtn-" > intent_spans:<key:"\001k\022\272\000\001rtn-" > intent_spans:<key:"\001k\022\273\000\001rdsc" > intent_spans:<key:"\001k\022\273\000\001rtn-" > intent_spans:<key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rdsc" > intent_spans:<key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rtn-" > intent_spans:<key:"\003\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\001\367$\000" > intent_spans:<key:"\003\377\377" > intent_spans:<key:"\004range-tree-root" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\210" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\212\211" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\213\211" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\214\211" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\215\211" > intent_spans:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\216\211" > : header:<txn:<meta:<id:<6573f7b5-062e-423c-9eed-d02918c11a6b> isolation:SERIALIZABLE key:"\001k\022\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\377\001\367$\000\377\000\001rdsc" epoch:0 timestamp:<wall_time:1466458576729358965 logical:0 > priority:423720 sequence:3 batch_index:0 > name:"storage/replica_command.go:2124 (*Replica).AdminSplit" status:COMMITTED orig_timestamp:<wall_time:1466458576729358965 logical:0 > max_timestamp:<wall_time:1466458576729358965 logical:0 > observed_timestamps:<key:1 value:<wall_time:1466458576729358965 logical:0 > > writing:true write_too_old:false retry_on_push:false intents:<key:"\001k\022\223\000\001rtn-" > intents:<key:"\001k\022\224\000\001rtn-" > intents:<key:"\001k\022\225\000\001rtn-" > intents:<key:"\001k\022\226\000\001rtn-" > intents:<key:"\001k\022\272\000\001rtn-" > intents:<key:"\003\273\211\375?\355\202\035~\304\275\034\02284e0696b-1597-4afc-a851-e423df5f6532\000\001\367$\000" > intents:<key:"\003\377\377" > intents:<key:"\004range-tree-root" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\210" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\212\211" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\213\211" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\214\211" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\215\211" > intents:<key:"\225\211\024\371Wha\320\371+y\"\230\375\002\034\007\2121\031\000\000\216\211" > > > commit_wait:0 one_phase_commit:false , err=%!s(<nil>)
7708:I160620 17:36:16.913673 raft/raft.go:469 [group 8] 3 became follower at term 5
7709:I160620 17:36:16.913725 raft/raft.go:238 [group 8] newRaft 3 [peers: [1,2,3], term: 5, commit: 10, applied: 10, lastindex: 10, lastterm: 5]
7914:I160620 17:36:17.850560 raft/raft.go:571 [group 8] 3 [term: 5] received a MsgVote message with higher term from 1 [term: 6]
7915:I160620 17:36:17.850578 raft/raft.go:469 [group 8] 3 became follower at term 6
7916:I160620 17:36:17.850746 raft/raft.go:797 [group 8] 3 [logterm: 5, index: 10, vote: 0] voted for 1 [logterm: 5, index: 10] at term 6
cockroach-data/2/logs/cockroach.Tristans-MacBook-Pro.wiz.log.INFO.2016-06-20T17_36_29-04_00.1213
3410:I160620 17:36:32.296986 storage/replica_command.go:1570 range 2: new leader lease replica {2 2 3} 2016-06-20 21:36:21.494648891 +0000 UTC 15.550087258s following replica {1 1 1} 1970-01-01 00:00:00 +0000 UTC 407349h36m21.494648891s [physicalTime=2016-06-20 21:36:32.296959748 +0000 UTC]
3416:I160620 17:36:32.298224 raft/raft.go:806 [group 2] 3 [term 6] received MsgTimeoutNow from 1 and starts an election to get leadership.
3417:I160620 17:36:32.298237 raft/raft.go:482 [group 2] 3 became candidate at term 7
3418:I160620 17:36:32.298244 raft/raft.go:531 [group 2] 3 received vote from 3 at term 7
3419:I160620 17:36:32.298305 raft/raft.go:524 [group 2] 3 [logterm: 6, index: 36] sent vote request to 1 at term 7
3420:I160620 17:36:32.298368 raft/raft.go:524 [group 2] 3 [logterm: 6, index: 36] sent vote request to 2 at term 7
3425:I160620 17:36:32.300086 raft/raft.go:531 [group 2] 3 received vote from 1 at term 7
3426:I160620 17:36:32.300094 raft/raft.go:760 [group 2] 3 [quorum:2] has received 2 votes and 0 vote rejections
3427:I160620 17:36:32.300106 raft/raft.go:510 [group 2] 3 became leader at term 7
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment