During an active arakoon collapse we experienced this on our 10ms latency multidatacenter environment:
2016/05/20 10:13:12 684721 +0200 - ctl03 - 19683/0 - arakoon - 33779 - debug - tlogs_to_collapse 102425 952109 2 => Some (1138,949193)
2016/05/20 10:13:12 684734 +0200 - ctl03 - 19683/0 - arakoon - 33780 - info - Going to collapse 1138 tlogs
2016/05/20 10:13:12 685096 +0200 - ctl03 - 19683/0 - arakoon - 33781 - info - Creating db clone at /mnt/ssd1/arakoon/mybackend-a-nsm_0/tlogs/head.db.clone (throttling:0.000000)
2016/05/20 10:13:12 685214 +0200 - ctl03 - 19683/0 - arakoon - 33782 - info - copy_file /mnt/ssd1/arakoon/mybackend-a-nsm_0/tlogs/head.db /mnt/ssd1/arakoon/mybackend-a-nsm_0/tlogs/
head.db.clone (overwrite=true,throttling=0.000000)
2016/05/20 10:13:12 685322 +0200 - ctl03 - 19683/0 - arakoon - 33783 - info - Unlinking "/mnt/ssd1/arakoon/mybackend-a-nsm_0/tlogs/head.db.clone.tmp"
2016/05/20 10:13:12 685447 +0200 - ctl03 - 19683/0 - arakoon - 33784 - info - Unlink of "/mnt/ssd1/arakoon/mybackend-a-nsm_0/tlogs/head.db.clone.tmp" failed with ENOENT
2016/05/20 10:13:13 375508 +0200 - ctl03 - 19683/0 - arakoon - 33785 - info - done: copy_file
2016/05/20 10:13:13 616942 +0200 - ctl03 - 19683/0 - arakoon - 33786 - info - rename /mnt/ssd1/arakoon/mybackend-a-nsm_0/tlogs/head.db.clone.tmp -> /mnt/ssd1/arakoon/mybackend-a-ns
m_0/tlogs/head.db.clone
2016/05/20 10:13:13 617955 +0200 - ctl03 - 19683/0 - arakoon - 33787 - info - Creating local store at /mnt/ssd1/arakoon/mybackend-a-nsm_0/tlogs/head.db.clone (lcnum=16384) (ncnum=8
192)
2016/05/20 10:13:13 656021 +0200 - ctl03 - 19683/0 - arakoon - 33788 - info - infimum=102425
2016/05/20 10:13:13 688919 +0200 - ctl03 - 19683/0 - arakoon - 33789 - info - Replaying tlog file: 133.tlx (1/1144)
2016/05/20 10:13:13 689507 +0200 - ctl03 - 19683/0 - arakoon - 33790 - debug - fold_read extension=.tlx => index':None
2016/05/20 10:13:15 108387 +0200 - ctl03 - 19683/0 - arakoon - 33791 - info - Completed replay of 133.tlx, took 1.418846 seconds, 1143 to go
2016/05/20 10:13:15 108834 +0200 - ctl03 - 19683/0 - arakoon - 33792 - info - Replaying tlog file: 134.tlx (2/1144)
2016/05/20 10:13:15 109065 +0200 - ctl03 - 19683/0 - arakoon - 33793 - debug - fold_read extension=.tlx => index':None
2016/05/20 10:13:16 706671 +0200 - ctl03 - 19683/0 - arakoon - 33794 - info - Completed replay of 134.tlx, took 1.597610 seconds, 1142 to go
2016/05/20 10:13:16 706949 +0200 - ctl03 - 19683/0 - arakoon - 33795 - info - Replaying tlog file: 135.tlx (3/1144)
2016/05/20 10:13:16 707222 +0200 - ctl03 - 19683/0 - arakoon - 33796 - debug - fold_read extension=.tlx => index':None
2016/05/20 10:13:18 513171 +0200 - ctl03 - 19683/0 - arakoon - 33797 - info - Completed replay of 135.tlx, took 1.805939 seconds, 1141 to go
2016/05/20 10:13:18 513744 +0200 - ctl03 - 19683/0 - arakoon - 33798 - info - Replaying tlog file: 136.tlx (4/1144)
2016/05/20 10:13:18 513909 +0200 - ctl03 - 19683/0 - arakoon - 33799 - debug - fold_read extension=.tlx => index':None
2016/05/20 10:13:20 267673 +0200 - ctl03 - 19683/0 - arakoon - 33800 - info - Completed replay of 136.tlx, took 1.753726 seconds, 1140 to go
2016/05/20 10:13:20 268058 +0200 - ctl03 - 19683/0 - arakoon - 33801 - info - Replaying tlog file: 137.tlx (5/1144)
2016/05/20 10:13:20 268245 +0200 - ctl03 - 19683/0 - arakoon - 33802 - debug - fold_read extension=.tlx => index':None
2016/05/20 10:13:21 877769 +0200 - ctl03 - 19683/0 - arakoon - 33803 - info - stats: {start: 1463731701.821941, last: 1463731701.821943,; avg_set_size: 0.000000,; avg_get_size: 0.0
00000,; avg_range_size: 0.000000,; avg_range_entries_size: 0.000000,; avg_rev_range_entries_size: 0.000000,; avg_prefix_size: 0.000000,; avg_del_prefix_size: 0.000000,; harvest_sta
ts: (n:279 min: 1., max: 9., avg: 1.3476702509, dev: 1.47311150372),; set_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a),; get_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a
),; del_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a),; mget_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a),; mget_option_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a
); seq_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a),; tas_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a),; replace_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a),; ra
nge_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a),; range_entries_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a),; rev_range_entries_info: (n:0 min: n/a, max: n/a, avg: n/
a, dev: n/a),; prefix_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a),; delete_prefix_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a),; ops_info: (n:0 min: n/a, max: n/a, avg: n/a, dev: n/a),; mem_allocated: 275121871.906250 KB,; mem_maxrss: 439628 KB,; mem_minor_collections: 101344,; mem_major_collections: 28514,; mem_compactions: 5441,; node_is: (SywfRodETohwFTW4,952116)(oJ9guhHLBBJWzDnT,657081)(9995UaXuBIjq721q,952118)}
2016/05/20 10:13:22 155802 +0200 - ctl03 - 19683/0 - arakoon - 33804 - info - Completed replay of 137.tlx, took 1.887547 seconds, 1139 to go
2016/05/20 10:13:22 156157 +0200 - ctl03 - 19683/0 - arakoon - 33805 - info - Replaying tlog file: 138.tlog (6/1144)
2016/05/20 10:13:22 156253 +0200 - ctl03 - 19683/0 - arakoon - 33806 - debug - fold_read extension=.tlog => index':Some {filename="/mnt/ssd1/arakoon/mybackend-a-nsm_0/tlogs/1276.tlog";mapping=(952000,3573298)::(951000,3137088)}
2016/05/20 10:13:22 170317 +0200 - ctl03 - 19683/0 - arakoon - 33807 - info - Completed replay of 138.tlog, took 0.014062 seconds, 1138 to go
2016/05/20 10:13:22 170599 +0200 - ctl03 - 19683/0 - arakoon - 33808 - info - Replaying tlog file: 139.tlx (7/1144)
2016/05/20 10:13:22 170681 +0200 - ctl03 - 19683/0 - arakoon - 33809 - debug - fold_read extension=.tlx => index':None
2016/05/20 10:13:23 924851 +0200 - ctl03 - 19683/0 - arakoon - 33810 - info - Completed replay of 139.tlx, took 1.754160 seconds, 1137 to go
2016/05/20 10:13:23 925149 +0200 - ctl03 - 19683/0 - arakoon - 33811 - info - Replaying tlog file: 140.tlx (8/1144)
2016/05/20 10:13:23 925234 +0200 - ctl03 - 19683/0 - arakoon - 33812 - debug - fold_read extension=.tlx => index':None
2016/05/20 10:13:25 610909 +0200 - ctl03 - 19683/0 - arakoon - 33813 - info - Completed replay of 140.tlx, took 1.685666 seconds, 1136 to go
2016/05/20 10:13:26 199980 +0200 - ctl03 - 19683/0 - arakoon - 33814 - info - local_store "/mnt/ssd1/arakoon/mybackend-a-nsm_0/tlogs/head.db.clone" :: closed ()
2016/05/20 10:13:26 200977 +0200 - ctl03 - 19683/0 - arakoon - 33815 - info - unlinking /mnt/ssd1/arakoon/mybackend-a-nsm_0/tlogs/head.db.clone
2016/05/20 10:13:26 201150 +0200 - ctl03 - 19683/0 - arakoon - 33816 - info - Unlinking "/mnt/ssd1/arakoon/mybackend-a-nsm_0/tlogs/head.db.clone"
2016/05/20 10:13:26 248670 +0200 - ctl03 - 19683/0 - arakoon - 33817 - error - Exception during client request ((Failure "Head db has invalid counter: 105838")) => rc:ff msg:unknown failure
2016/05/20 10:13:26 249054 +0200 - ctl03 - 19683/0 - arakoon - 33818 - info - 172.19.10.32:client_service_632: closing
2016/05/19 20:10:27 671283 +0200 - ctl01 - 26562/0 - arakoon - 30828 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/19 20:20:23 755491 +0200 - ctl01 - 26562/0 - arakoon - 31428 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/19 20:21:15 528745 +0200 - ctl01 - 26562/0 - arakoon - 31466 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/19 22:10:29 303992 +0200 - ctl01 - 26562/0 - arakoon - 33183 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/19 22:14:39 466363 +0200 - ctl01 - 26562/0 - arakoon - 33369 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/19 22:15:30 401192 +0200 - ctl01 - 26562/0 - arakoon - 33407 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 00:10:27 704010 +0200 - ctl01 - 26562/0 - arakoon - 34638 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 00:14:15 176851 +0200 - ctl01 - 26562/0 - arakoon - 34726 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 00:15:01 923924 +0200 - ctl01 - 26562/0 - arakoon - 34776 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 02:10:31 657418 +0200 - ctl01 - 26562/0 - arakoon - 36203 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 02:15:52 321904 +0200 - ctl01 - 26562/0 - arakoon - 36443 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 02:16:43 176822 +0200 - ctl01 - 26562/0 - arakoon - 36503 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 04:10:27 805505 +0200 - ctl01 - 26562/0 - arakoon - 37490 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 04:14:00 714565 +0200 - ctl01 - 26562/0 - arakoon - 37548 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 04:14:46 783472 +0200 - ctl01 - 26562/0 - arakoon - 37597 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 06:10:27 307234 +0200 - ctl01 - 26562/0 - arakoon - 38182 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 06:12:39 258997 +0200 - ctl01 - 26562/0 - arakoon - 38230 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 06:13:23 762371 +0200 - ctl01 - 26562/0 - arakoon - 38278 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 08:10:28 711716 +0200 - ctl01 - 26562/0 - arakoon - 38920 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 08:12:50 406347 +0200 - ctl01 - 26562/0 - arakoon - 38979 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 08:13:41 517715 +0200 - ctl01 - 26562/0 - arakoon - 39018 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 10:10:27 854089 +0200 - ctl01 - 26562/0 - arakoon - 39636 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 10:12:51 886109 +0200 - ctl01 - 26562/0 - arakoon - 39685 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
2016/05/20 10:13:39 547445 +0200 - ctl01 - 26562/0 - arakoon - 39723 - error - Exception during client request ((Failure "Head db has invalid counter: 657082")) => rc:ff msg:unknown failure
Although it succeeded the day before.
arakoon:
Installed: 1.9.3
Candidate: 1.9.3
Version table:
*** 1.9.3 0
500 http://apt.openvstorage.org/ unstable/main amd64 Packages
100 /var/lib/dpkg/status
ii openvstorage 2.7.0-rev.3451.9fa0267-1 amd64 openvStorage
ii openvstorage-backend 1.7.0-rev.588.2e534bc-1 amd64 openvStorage Backend plugin
ii openvstorage-backend-core 1.7.0-rev.588.2e534bc-1 amd64 openvStorage Backend plugin core
ii openvstorage-backend-webapps 1.7.0-rev.588.2e534bc-1 amd64 openvStorage Backend plugin Web Applications
ii openvstorage-cinder-plugin 1.2.0-rev.26.fd48d23-1 amd64 OpenvStorage Cinder plugin for OpenStack
ii openvstorage-core 2.7.0-rev.3451.9fa0267-1 amd64 openvStorage core
ii openvstorage-webapps 2.7.0-rev.3451.9fa0267-1 amd64 openvStorage Web Applications