Journal writes are dominated by validation #360
Description
I made some old skool timing changes to the journal code (journal.patch) to determine where the time during update was being spent. Results from several updates are below. The TL;DR is that of the time spent in Journal.Update, about half of this is spent re-reading the data back to make sure that we wrote it out correctly.
If we removed this validation code, it would make updating a checkpoint in a witness about 20% faster. I'm raising this bug to discuss if we can now remove this validation code.
I1114 10:12:13.414154 3 journal.go:170] journal.Update#marshal 1.016125ms
I1114 10:12:13.429342 3 journal.go:176] journal.Update#write 8.301125ms
I1114 10:12:13.468560 3 journal.go:188] journal.Update#validate 32.673625ms
I1114 10:12:13.475464 3 journal.go:144] journal.Update 63.209875ms
I1114 10:12:13.481932 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 142.1755ms
I1114 10:12:13.575325 3 journal.go:170] journal.Update#marshal 951µs
I1114 10:12:13.589534 3 journal.go:176] journal.Update#write 7.67975ms
I1114 10:12:13.650094 3 journal.go:188] journal.Update#validate 54.106ms
I1114 10:12:13.656732 3 journal.go:144] journal.Update 83.233875ms
I1114 10:12:13.663229 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 161.92525ms
I1114 10:12:13.791303 3 journal.go:170] journal.Update#marshal 1.050625ms
I1114 10:12:13.811861 3 journal.go:176] journal.Update#write 13.64225ms
I1114 10:12:13.852341 3 journal.go:188] journal.Update#validate 33.941125ms
I1114 10:12:13.859217 3 journal.go:144] journal.Update 69.8695ms
I1114 10:12:13.865528 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 166.51775ms
I1114 10:12:14.094958 3 journal.go:170] journal.Update#marshal 1.017875ms
I1114 10:12:14.110275 3 journal.go:176] journal.Update#write 8.45325ms
I1114 10:12:14.147135 3 journal.go:188] journal.Update#validate 30.454625ms
I1114 10:12:14.154021 3 journal.go:144] journal.Update 60.958375ms
I1114 10:12:14.160524 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 140.273625ms
I1114 10:12:14.255210 3 journal.go:170] journal.Update#marshal 944.125µs
I1114 10:12:14.269706 3 journal.go:176] journal.Update#write 7.60225ms
I1114 10:12:14.306875 3 journal.go:188] journal.Update#validate 30.761625ms
I1114 10:12:14.313765 3 journal.go:144] journal.Update 60.40225ms
I1114 10:12:14.320154 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.048125ms
I1114 10:12:14.414325 3 journal.go:170] journal.Update#marshal 966.625µs
I1114 10:12:14.428911 3 journal.go:176] journal.Update#write 7.73025ms
I1114 10:12:14.468920 3 journal.go:188] journal.Update#validate 33.612375ms
I1114 10:12:14.475779 3 journal.go:144] journal.Update 63.307375ms
I1114 10:12:14.482247 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 142.201625ms
I1114 10:12:14.575749 3 journal.go:170] journal.Update#marshal 953.125µs
I1114 10:12:14.590392 3 journal.go:176] journal.Update#write 7.675625ms
I1114 10:12:14.627441 3 journal.go:188] journal.Update#validate 30.538ms
I1114 10:12:14.633980 3 journal.go:144] journal.Update 60.07275ms
I1114 10:12:14.640377 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.5365ms
I1114 10:12:14.736920 3 journal.go:170] journal.Update#marshal 1.990875ms
I1114 10:12:14.762905 3 journal.go:176] journal.Update#write 19.040125ms
I1114 10:12:14.816615 3 journal.go:188] journal.Update#validate 47.060125ms
I1114 10:12:14.823511 3 journal.go:144] journal.Update 91.694875ms
I1114 10:12:14.830119 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 170.654375ms
I1114 10:12:15.095823 3 journal.go:170] journal.Update#marshal 974.5µs
I1114 10:12:15.112008 3 journal.go:176] journal.Update#write 9.635625ms
I1114 10:12:15.148561 3 journal.go:188] journal.Update#validate 30.08975ms
I1114 10:12:15.155279 3 journal.go:144] journal.Update 61.315875ms
I1114 10:12:15.161766 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 140.3705ms
I1114 10:12:15.256503 3 journal.go:170] journal.Update#marshal 1.04125ms
I1114 10:12:15.271386 3 journal.go:176] journal.Update#write 8.2475ms
I1114 10:12:15.308140 3 journal.go:188] journal.Update#validate 30.501875ms
I1114 10:12:15.314979 3 journal.go:144] journal.Update 60.423625ms
I1114 10:12:15.321471 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.097625ms
I1114 10:12:15.415373 3 journal.go:170] journal.Update#marshal 1.01075ms
I1114 10:12:15.430115 3 journal.go:176] journal.Update#write 7.9465ms
I1114 10:12:15.469990 3 journal.go:188] journal.Update#validate 33.653625ms
I1114 10:12:15.476771 3 journal.go:144] journal.Update 63.29775ms
I1114 10:12:15.483193 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 142.3505ms
I1114 10:12:15.576705 3 journal.go:170] journal.Update#marshal 948.25µs
I1114 10:12:15.591167 3 journal.go:176] journal.Update#write 7.777875ms
I1114 10:12:15.627750 3 journal.go:188] journal.Update#validate 30.164125ms
I1114 10:12:15.634561 3 journal.go:144] journal.Update 59.68925ms
I1114 10:12:15.640959 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.643125ms
I1114 10:12:15.734613 3 journal.go:170] journal.Update#marshal 941.625µs
I1114 10:12:15.749074 3 journal.go:176] journal.Update#write 7.66325ms
I1114 10:12:15.786197 3 journal.go:188] journal.Update#validate 30.808ms
I1114 10:12:15.792650 3 journal.go:144] journal.Update 59.854ms
I1114 10:12:15.798848 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.240875ms
I1114 10:12:16.100216 3 journal.go:170] journal.Update#marshal 951µs
I1114 10:12:16.130843 3 journal.go:176] journal.Update#write 24.166ms
I1114 10:12:16.184334 3 journal.go:188] journal.Update#validate 47.069625ms
I1114 10:12:16.191240 3 journal.go:144] journal.Update 92.83875ms
I1114 10:12:16.197613 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 177.632125ms
I1114 10:12:16.303416 3 journal.go:170] journal.Update#marshal 1.230875ms
I1114 10:12:16.318142 3 journal.go:176] journal.Update#write 7.87875ms
I1114 10:12:16.358233 3 journal.go:188] journal.Update#validate 33.704ms
I1114 10:12:16.364772 3 journal.go:144] journal.Update 63.472125ms
I1114 10:12:16.371257 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 145.093875ms
I1114 10:12:16.465038 3 journal.go:170] journal.Update#marshal 949.5µs
I1114 10:12:16.482026 3 journal.go:176] journal.Update#write 10.257125ms
I1114 10:12:16.519080 3 journal.go:188] journal.Update#validate 30.471625ms
I1114 10:12:16.525922 3 journal.go:144] journal.Update 62.72275ms
I1114 10:12:16.532329 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 141.360125ms
I1114 10:12:16.626082 3 journal.go:170] journal.Update#marshal 1.02825ms
I1114 10:12:16.640606 3 journal.go:176] journal.Update#write 7.79ms
I1114 10:12:16.677387 3 journal.go:188] journal.Update#validate 30.751375ms
I1114 10:12:16.684226 3 journal.go:144] journal.Update 60.078625ms
I1114 10:12:16.690707 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.070375ms
I1114 10:12:16.784290 3 journal.go:170] journal.Update#marshal 967µs
I1114 10:12:16.798432 3 journal.go:176] journal.Update#write 7.745875ms
I1114 10:12:16.835556 3 journal.go:188] journal.Update#validate 30.652625ms
I1114 10:12:16.842387 3 journal.go:144] journal.Update 59.954375ms
I1114 10:12:16.848863 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.6335ms
I1114 10:12:16.942844 3 journal.go:170] journal.Update#marshal 1.0115ms
I1114 10:12:16.957142 3 journal.go:176] journal.Update#write 7.6855ms
I1114 10:12:16.996477 3 journal.go:188] journal.Update#validate 33.09175ms
I1114 10:12:17.003255 3 journal.go:144] journal.Update 62.311ms
I1114 10:12:17.009478 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 140.9165ms
I1114 10:12:17.126083 3 journal.go:170] journal.Update#marshal 956.375µs
I1114 10:12:17.162676 3 journal.go:176] journal.Update#write 29.678375ms
I1114 10:12:17.202028 3 journal.go:188] journal.Update#validate 32.694375ms
I1114 10:12:17.208918 3 journal.go:144] journal.Update 84.688125ms
I1114 10:12:17.215394 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 186.819125ms
I1114 10:12:17.313366 3 journal.go:170] journal.Update#marshal 960.75µs
I1114 10:12:17.327932 3 journal.go:176] journal.Update#write 7.79625ms
I1114 10:12:17.365982 3 journal.go:188] journal.Update#validate 31.641125ms
I1114 10:12:17.372870 3 journal.go:144] journal.Update 61.346125ms
I1114 10:12:17.379343 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 143.026ms
I1114 10:12:17.472686 3 journal.go:170] journal.Update#marshal 952.25µs
I1114 10:12:17.490038 3 journal.go:176] journal.Update#write 10.4785ms
I1114 10:12:17.526480 3 journal.go:188] journal.Update#validate 30.0695ms
I1114 10:12:17.533115 3 journal.go:144] journal.Update 62.266625ms
I1114 10:12:17.539590 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 141.07125ms
I1114 10:12:17.632868 3 journal.go:170] journal.Update#marshal 954.375µs
I1114 10:12:17.647390 3 journal.go:176] journal.Update#write 7.609875ms
I1114 10:12:17.684505 3 journal.go:188] journal.Update#validate 30.604125ms
I1114 10:12:17.691350 3 journal.go:144] journal.Update 60.31875ms
I1114 10:12:17.697738 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.9005ms
I1114 10:12:17.791662 3 journal.go:170] journal.Update#marshal 1.008375ms
I1114 10:12:17.806311 3 journal.go:176] journal.Update#write 7.79675ms
I1114 10:12:17.843782 3 journal.go:188] journal.Update#validate 31.1045ms
I1114 10:12:17.850408 3 journal.go:144] journal.Update 60.646625ms
I1114 10:12:17.856890 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.852625ms
I1114 10:12:17.957825 3 journal.go:170] journal.Update#marshal 959.125µs
I1114 10:12:17.988633 3 journal.go:176] journal.Update#write 23.896375ms
I1114 10:12:18.045646 3 journal.go:188] journal.Update#validate 50.38675ms
I1114 10:12:18.052386 3 journal.go:144] journal.Update 96.407ms
I1114 10:12:18.058612 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 181.302375ms
I1114 10:12:18.163590 3 journal.go:170] journal.Update#marshal 1.177125ms
I1114 10:12:18.178511 3 journal.go:176] journal.Update#write 8.09575ms
I1114 10:12:18.215901 3 journal.go:188] journal.Update#validate 31.038625ms
I1114 10:12:18.222735 3 journal.go:144] journal.Update 61.202ms
I1114 10:12:18.228943 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 142.889125ms
I1114 10:12:18.321765 3 journal.go:170] journal.Update#marshal 953.875µs
I1114 10:12:18.336321 3 journal.go:176] journal.Update#write 7.74475ms
I1114 10:12:18.372915 3 journal.go:188] journal.Update#validate 30.240375ms
I1114 10:12:18.379756 3 journal.go:144] journal.Update 59.831125ms
I1114 10:12:18.386226 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 137.8825ms
I1114 10:12:18.480146 3 journal.go:170] journal.Update#marshal 964.125µs
I1114 10:12:18.495435 3 journal.go:176] journal.Update#write 8.2835ms
I1114 10:12:18.534732 3 journal.go:188] journal.Update#validate 32.958125ms
I1114 10:12:18.541622 3 journal.go:144] journal.Update 63.32025ms
I1114 10:12:18.548014 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 142.57025ms
I1114 10:12:18.641804 3 journal.go:170] journal.Update#marshal 954µs
I1114 10:12:18.655966 3 journal.go:176] journal.Update#write 7.73875ms
I1114 10:12:18.692731 3 journal.go:188] journal.Update#validate 30.36175ms
I1114 10:12:18.699507 3 journal.go:144] journal.Update 59.557875ms
I1114 10:12:18.705976 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.285875ms
I1114 10:12:18.805890 3 journal.go:170] journal.Update#marshal 943µs
I1114 10:12:18.836296 3 journal.go:176] journal.Update#write 23.893125ms
I1114 10:12:18.890947 3 journal.go:188] journal.Update#validate 47.977125ms
I1114 10:12:18.897883 3 journal.go:144] journal.Update 93.806875ms
I1114 10:12:18.904365 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 178.99825ms
I1114 10:12:19.009890 3 journal.go:170] journal.Update#marshal 1.145ms
I1114 10:12:19.026931 3 journal.go:176] journal.Update#write 10.411125ms
I1114 10:12:19.065023 3 journal.go:188] journal.Update#validate 31.467125ms
I1114 10:12:19.071878 3 journal.go:144] journal.Update 64.0255ms
I1114 10:12:19.078172 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 146.602625ms
I1114 10:12:19.171460 3 journal.go:170] journal.Update#marshal 995.25µs
I1114 10:12:19.194190 3 journal.go:176] journal.Update#write 15.97475ms
I1114 10:12:19.247149 3 journal.go:188] journal.Update#validate 45.713125ms
I1114 10:12:19.266767 3 journal.go:144] journal.Update 97.0655ms
I1114 10:12:19.280881 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 183.372625ms
I1114 10:12:19.375569 3 journal.go:170] journal.Update#marshal 932.375µs
I1114 10:12:19.390228 3 journal.go:176] journal.Update#write 7.782875ms
I1114 10:12:19.426825 3 journal.go:188] journal.Update#validate 30.057375ms
I1114 10:12:19.433713 3 journal.go:144] journal.Update 59.974625ms
I1114 10:12:19.440188 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.313875ms
I1114 10:12:19.534240 3 journal.go:170] journal.Update#marshal 939.375µs
I1114 10:12:19.551688 3 journal.go:176] journal.Update#write 10.431125ms
I1114 10:12:19.588656 3 journal.go:188] journal.Update#validate 30.326875ms
I1114 10:12:19.595529 3 journal.go:144] journal.Update 63.10275ms
I1114 10:12:19.601923 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 141.90825ms
I1114 10:12:19.701660 3 journal.go:170] journal.Update#marshal 1.002125ms
I1114 10:12:19.732295 3 journal.go:176] journal.Update#write 23.684ms
I1114 10:12:19.786711 3 journal.go:188] journal.Update#validate 47.96525ms
I1114 10:12:19.793530 3 journal.go:144] journal.Update 93.7365ms
I1114 10:12:19.799826 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 178.375ms
I1114 10:12:19.905278 3 journal.go:170] journal.Update#marshal 1.185875ms
I1114 10:12:19.920443 3 journal.go:176] journal.Update#write 8.302375ms
I1114 10:12:19.957871 3 journal.go:188] journal.Update#validate 30.904ms
I1114 10:12:19.964419 3 journal.go:144] journal.Update 61.2355ms
I1114 10:12:19.970756 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 144.075ms
I1114 10:12:20.063855 3 journal.go:170] journal.Update#marshal 1.027875ms
I1114 10:12:20.081161 3 journal.go:176] journal.Update#write 10.343875ms
I1114 10:12:20.119843 3 journal.go:188] journal.Update#validate 32.070125ms
I1114 10:12:20.126708 3 journal.go:144] journal.Update 64.7745ms
I1114 10:12:20.133014 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 143.076625ms
I1114 10:12:20.227075 3 journal.go:170] journal.Update#marshal 997.625µs
I1114 10:12:20.241725 3 journal.go:176] journal.Update#write 7.779625ms
I1114 10:12:20.278795 3 journal.go:188] journal.Update#validate 30.560125ms
I1114 10:12:20.285658 3 journal.go:144] journal.Update 60.4705ms
I1114 10:12:20.291993 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.60275ms
I1114 10:12:20.385771 3 journal.go:170] journal.Update#marshal 949.25µs
I1114 10:12:20.400355 3 journal.go:176] journal.Update#write 7.833125ms
I1114 10:12:20.437131 3 journal.go:188] journal.Update#validate 30.285375ms
I1114 10:12:20.443997 3 journal.go:144] journal.Update 60.069ms
I1114 10:12:20.450220 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.653375ms
I1114 10:12:20.550054 3 journal.go:170] journal.Update#marshal 1.027ms
I1114 10:12:20.580365 3 journal.go:176] journal.Update#write 23.741625ms
I1114 10:12:20.637379 3 journal.go:188] journal.Update#validate 50.3195ms
I1114 10:12:20.644062 3 journal.go:144] journal.Update 95.910375ms
I1114 10:12:20.650554 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 181.0195ms
I1114 10:12:20.756111 3 journal.go:170] journal.Update#marshal 1.177625ms
I1114 10:12:20.770880 3 journal.go:176] journal.Update#write 7.906ms
I1114 10:12:20.808378 3 journal.go:188] journal.Update#validate 31.309ms
I1114 10:12:20.814933 3 journal.go:144] journal.Update 60.875375ms
I1114 10:12:20.821402 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 143.76225ms
I1114 10:12:20.914793 3 journal.go:170] journal.Update#marshal 949.625µs
I1114 10:12:20.929990 3 journal.go:176] journal.Update#write 8.307625ms
I1114 10:12:20.966760 3 journal.go:188] journal.Update#validate 30.2495ms
I1114 10:12:20.973413 3 journal.go:144] journal.Update 60.46375ms
I1114 10:12:20.979808 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.01025ms
I1114 10:12:21.073550 3 journal.go:170] journal.Update#marshal 935.875µs
I1114 10:12:21.088361 3 journal.go:176] journal.Update#write 7.7985ms
I1114 10:12:21.127383 3 journal.go:188] journal.Update#validate 32.69725ms
I1114 10:12:21.134165 3 journal.go:144] journal.Update 62.451ms
I1114 10:12:21.140387 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 141.15625ms
I1114 10:12:21.233433 3 journal.go:170] journal.Update#marshal 958.875µs
I1114 10:12:21.248092 3 journal.go:176] journal.Update#write 7.773ms
I1114 10:12:21.284696 3 journal.go:188] journal.Update#validate 30.431625ms
I1114 10:12:21.291575 3 journal.go:144] journal.Update 59.978125ms
I1114 10:12:21.298057 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.36925ms
I1114 10:12:21.397635 3 journal.go:170] journal.Update#marshal 961.875µs
I1114 10:12:21.428183 3 journal.go:176] journal.Update#write 23.5845ms
I1114 10:12:21.484245 3 journal.go:188] journal.Update#validate 49.605875ms
I1114 10:12:21.491172 3 journal.go:144] journal.Update 95.378ms
I1114 10:12:21.497489 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 179.546375ms
I1114 10:12:21.599846 3 journal.go:170] journal.Update#marshal 1.101875ms
I1114 10:12:21.617570 3 journal.go:176] journal.Update#write 10.742ms
I1114 10:12:21.656585 3 journal.go:188] journal.Update#validate 32.72075ms
I1114 10:12:21.663337 3 journal.go:144] journal.Update 65.489ms
I1114 10:12:21.669553 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 145.084875ms
I1114 10:12:21.762646 3 journal.go:170] journal.Update#marshal 1.1895ms
I1114 10:12:21.777248 3 journal.go:176] journal.Update#write 7.97775ms
I1114 10:12:21.815435 3 journal.go:188] journal.Update#validate 31.8045ms
I1114 10:12:21.822070 3 journal.go:144] journal.Update 61.49475ms
I1114 10:12:21.828455 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.554875ms
I1114 10:12:21.922531 3 journal.go:170] journal.Update#marshal 955.5µs
I1114 10:12:21.936820 3 journal.go:176] journal.Update#write 7.65375ms
I1114 10:12:21.973932 3 journal.go:188] journal.Update#validate 30.7225ms
I1114 10:12:21.980566 3 journal.go:144] journal.Update 59.8995ms
I1114 10:12:21.986876 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.6425ms
I1114 10:12:22.080536 3 journal.go:170] journal.Update#marshal 1.028125ms
I1114 10:12:22.095167 3 journal.go:176] journal.Update#write 7.769375ms
I1114 10:12:22.135081 3 journal.go:188] journal.Update#validate 33.2955ms
I1114 10:12:22.141753 3 journal.go:144] journal.Update 63.124625ms
I1114 10:12:22.148218 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 141.84125ms
I1114 10:12:22.240848 3 journal.go:170] journal.Update#marshal 953.375µs
I1114 10:12:22.255416 3 journal.go:176] journal.Update#write 7.684ms
I1114 10:12:22.292535 3 journal.go:188] journal.Update#validate 30.935125ms
I1114 10:12:22.299435 3 journal.go:144] journal.Update 60.44525ms
I1114 10:12:22.305836 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.368125ms
I1114 10:12:22.398915 3 journal.go:170] journal.Update#marshal 934.625µs
I1114 10:12:22.413598 3 journal.go:176] journal.Update#write 7.787375ms
I1114 10:12:22.450912 3 journal.go:188] journal.Update#validate 30.779625ms
I1114 10:12:22.457904 3 journal.go:144] journal.Update 60.697875ms
I1114 10:12:22.464285 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.098ms
I1114 10:12:22.608440 3 journal.go:170] journal.Update#marshal 1.0365ms
I1114 10:12:22.626634 3 journal.go:176] journal.Update#write 11.366875ms
I1114 10:12:22.665963 3 journal.go:188] journal.Update#validate 32.692375ms
I1114 10:12:22.672862 3 journal.go:144] journal.Update 66.369125ms
I1114 10:12:22.679351 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 195.628ms
I1114 10:12:22.774938 3 journal.go:170] journal.Update#marshal 938.875µs
I1114 10:12:22.789588 3 journal.go:176] journal.Update#write 7.782875ms
I1114 10:12:22.828058 3 journal.go:188] journal.Update#validate 31.9505ms
I1114 10:12:22.834708 3 journal.go:144] journal.Update 61.606375ms
I1114 10:12:22.841320 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 141.309625ms
I1114 10:12:22.935255 3 journal.go:170] journal.Update#marshal 943.125µs
I1114 10:12:22.950152 3 journal.go:176] journal.Update#write 8.0085ms
I1114 10:12:22.986515 3 journal.go:188] journal.Update#validate 30.063125ms
I1114 10:12:22.993404 3 journal.go:144] journal.Update 59.9895ms
I1114 10:12:22.999708 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.63725ms
I1114 10:12:23.093229 3 journal.go:170] journal.Update#marshal 987.375µs
I1114 10:12:23.107748 3 journal.go:176] journal.Update#write 7.651ms
I1114 10:12:23.146706 3 journal.go:188] journal.Update#validate 32.662125ms
I1114 10:12:23.153562 3 journal.go:144] journal.Update 62.20425ms
I1114 10:12:23.159955 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 140.957625ms
I1114 10:12:23.253480 3 journal.go:170] journal.Update#marshal 933.75µs
I1114 10:12:23.267883 3 journal.go:176] journal.Update#write 7.646375ms
I1114 10:12:23.305291 3 journal.go:188] journal.Update#validate 30.92225ms
I1114 10:12:23.312026 3 journal.go:144] journal.Update 60.38425ms
I1114 10:12:23.318423 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.894875ms
I1114 10:12:23.412378 3 journal.go:170] journal.Update#marshal 936µs
I1114 10:12:23.426380 3 journal.go:176] journal.Update#write 7.586875ms
I1114 10:12:23.475775 3 journal.go:188] journal.Update#validate 42.904625ms
I1114 10:12:23.482725 3 journal.go:144] journal.Update 72.154875ms
I1114 10:12:23.489199 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 151.107375ms
I1114 10:12:23.620230 3 journal.go:170] journal.Update#marshal 1.027625ms
I1114 10:12:23.648524 3 journal.go:176] journal.Update#write 21.254125ms
I1114 10:12:23.692393 3 journal.go:188] journal.Update#validate 37.25675ms
I1114 10:12:23.699117 3 journal.go:144] journal.Update 80.803625ms
I1114 10:12:23.705635 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 177.496625ms
I1114 10:12:23.801712 3 journal.go:170] journal.Update#marshal 940.75µs
I1114 10:12:23.816424 3 journal.go:176] journal.Update#write 7.97ms
I1114 10:12:23.855807 3 journal.go:188] journal.Update#validate 33.339125ms
I1114 10:12:23.862665 3 journal.go:144] journal.Update 62.775875ms
I1114 10:12:23.869264 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 143.568375ms
I1114 10:12:23.962438 3 journal.go:170] journal.Update#marshal 939.5µs
I1114 10:12:23.976825 3 journal.go:176] journal.Update#write 7.762625ms
I1114 10:12:24.013573 3 journal.go:188] journal.Update#validate 30.29ms
I1114 10:12:24.019970 3 journal.go:144] journal.Update 59.349375ms
I1114 10:12:24.026551 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 137.728625ms
I1114 10:12:24.120426 3 journal.go:170] journal.Update#marshal 966.5µs
I1114 10:12:24.135109 3 journal.go:176] journal.Update#write 7.976125ms
I1114 10:12:24.174310 3 journal.go:188] journal.Update#validate 32.7595ms
I1114 10:12:24.180895 3 journal.go:144] journal.Update 62.315625ms
I1114 10:12:24.187372 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 141.175625ms
I1114 10:12:24.280972 3 journal.go:170] journal.Update#marshal 940.375µs
I1114 10:12:24.295491 3 journal.go:176] journal.Update#write 7.739875ms
I1114 10:12:24.332055 3 journal.go:188] journal.Update#validate 30.1425ms
I1114 10:12:24.338619 3 journal.go:144] journal.Update 59.466125ms
I1114 10:12:24.345164 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.296125ms
I1114 10:12:24.439416 3 journal.go:170] journal.Update#marshal 1.03175ms
I1114 10:12:24.453648 3 journal.go:176] journal.Update#write 7.550625ms
I1114 10:12:24.509819 3 journal.go:188] journal.Update#validate 49.52375ms
I1114 10:12:24.516598 3 journal.go:144] journal.Update 79.079ms
I1114 10:12:24.522833 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 157.816375ms
I1114 10:12:24.655914 3 journal.go:170] journal.Update#marshal 957.75µs
I1114 10:12:24.676972 3 journal.go:176] journal.Update#write 14.1645ms
I1114 10:12:24.716094 3 journal.go:188] journal.Update#validate 32.72975ms
I1114 10:12:24.722838 3 journal.go:144] journal.Update 68.796625ms
I1114 10:12:24.729314 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 165.36075ms
I1114 10:12:24.825656 3 journal.go:170] journal.Update#marshal 943.5µs
I1114 10:12:24.840731 3 journal.go:176] journal.Update#write 8.43625ms
I1114 10:12:24.880282 3 journal.go:188] journal.Update#validate 33.175875ms
I1114 10:12:24.887130 3 journal.go:144] journal.Update 63.31375ms
I1114 10:12:24.893517 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 144.4685ms
I1114 10:12:24.985755 3 journal.go:170] journal.Update#marshal 950.25µs
I1114 10:12:25.000316 3 journal.go:176] journal.Update#write 7.810375ms
I1114 10:12:25.037989 3 journal.go:188] journal.Update#validate 31.174625ms
I1114 10:12:25.044847 3 journal.go:144] journal.Update 60.941875ms
I1114 10:12:25.051321 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.7635ms
I1114 10:12:25.145201 3 journal.go:170] journal.Update#marshal 1.0035ms
I1114 10:12:25.161322 3 journal.go:176] journal.Update#write 9.493375ms
I1114 10:12:25.201075 3 journal.go:188] journal.Update#validate 33.27ms
I1114 10:12:25.207478 3 journal.go:144] journal.Update 64.147ms
I1114 10:12:25.213697 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 142.9675ms
I1114 10:12:25.307197 3 journal.go:170] journal.Update#marshal 924.25µs
I1114 10:12:25.321755 3 journal.go:176] journal.Update#write 7.85675ms
I1114 10:12:25.358818 3 journal.go:188] journal.Update#validate 30.692625ms
I1114 10:12:25.365659 3 journal.go:144] journal.Update 60.258375ms
I1114 10:12:25.372135 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.238125ms
I1114 10:12:25.470575 3 journal.go:170] journal.Update#marshal 963.375µs
I1114 10:12:25.493973 3 journal.go:176] journal.Update#write 16.50975ms
I1114 10:12:25.549946 3 journal.go:188] journal.Update#validate 49.457625ms
I1114 10:12:25.556819 3 journal.go:144] journal.Update 88.09025ms
I1114 10:12:25.563207 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 171.614375ms
I1114 10:12:25.672581 3 journal.go:170] journal.Update#marshal 1.14075ms
I1114 10:12:25.690111 3 journal.go:176] journal.Update#write 10.71ms
I1114 10:12:25.728967 3 journal.go:188] journal.Update#validate 32.76275ms
I1114 10:12:25.735647 3 journal.go:144] journal.Update 65.10275ms
I1114 10:12:25.742040 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 146.31525ms
I1114 10:12:25.835744 3 journal.go:170] journal.Update#marshal 1.07775ms
I1114 10:12:25.851305 3 journal.go:176] journal.Update#write 8.888375ms
I1114 10:12:25.888110 3 journal.go:188] journal.Update#validate 30.351ms
I1114 10:12:25.894559 3 journal.go:144] journal.Update 60.807875ms
I1114 10:12:25.901038 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.554375ms
I1114 10:12:25.994890 3 journal.go:170] journal.Update#marshal 1.011ms
I1114 10:12:26.009189 3 journal.go:176] journal.Update#write 7.844375ms
I1114 10:12:26.045690 3 journal.go:188] journal.Update#validate 30.075ms
I1114 10:12:26.052177 3 journal.go:144] journal.Update 59.165ms
I1114 10:12:26.058381 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.08675ms
I1114 10:12:26.152394 3 journal.go:170] journal.Update#marshal 1.011625ms
I1114 10:12:26.166748 3 journal.go:176] journal.Update#write 7.584375ms
I1114 10:12:26.206717 3 journal.go:188] journal.Update#validate 33.5345ms
I1114 10:12:26.213359 3 journal.go:144] journal.Update 62.859625ms
I1114 10:12:26.219835 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 142.0655ms
I1114 10:12:26.312798 3 journal.go:170] journal.Update#marshal 953.5µs
I1114 10:12:26.327117 3 journal.go:176] journal.Update#write 7.684ms
I1114 10:12:26.364311 3 journal.go:188] journal.Update#validate 31.043875ms
I1114 10:12:26.371168 3 journal.go:144] journal.Update 60.213125ms
I1114 10:12:26.377639 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 138.787625ms
I1114 10:12:26.488230 3 journal.go:170] journal.Update#marshal 1.038625ms
I1114 10:12:26.519296 3 journal.go:176] journal.Update#write 24.139ms
I1114 10:12:26.569455 3 journal.go:188] journal.Update#validate 43.616625ms
I1114 10:12:26.576348 3 journal.go:144] journal.Update 90.087ms
I1114 10:12:26.582547 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 185.438125ms
I1114 10:12:26.679659 3 journal.go:170] journal.Update#marshal 1.188375ms
I1114 10:12:26.697412 3 journal.go:176] journal.Update#write 10.79825ms
I1114 10:12:26.736597 3 journal.go:188] journal.Update#validate 32.701ms
I1114 10:12:26.743098 3 journal.go:144] journal.Update 65.501875ms
I1114 10:12:26.749579 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 146.060125ms
I1114 10:12:26.843417 3 journal.go:170] journal.Update#marshal 1.110125ms
I1114 10:12:26.858962 3 journal.go:176] journal.Update#write 8.769375ms
I1114 10:12:26.895886 3 journal.go:188] journal.Update#validate 30.4175ms
I1114 10:12:26.902504 3 journal.go:144] journal.Update 61.0785ms
I1114 10:12:26.908803 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 140.0385ms
I1114 10:12:27.002309 3 journal.go:170] journal.Update#marshal 939.375µs
I1114 10:12:27.016843 3 journal.go:176] journal.Update#write 7.67825ms
I1114 10:12:27.054023 3 journal.go:188] journal.Update#validate 30.78225ms
I1114 10:12:27.060758 3 journal.go:144] journal.Update 60.259625ms
I1114 10:12:27.067252 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 139.24525ms
I1114 10:12:27.160973 3 journal.go:170] journal.Update#marshal 949.75µs
I1114 10:12:27.175537 3 journal.go:176] journal.Update#write 7.829ms
I1114 10:12:27.215010 3 journal.go:188] journal.Update#validate 33.209125ms
I1114 10:12:27.221887 3 journal.go:144] journal.Update 62.773125ms
I1114 10:12:27.228384 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 141.798625ms
I1114 10:12:27.322526 3 journal.go:170] journal.Update#marshal 942.625µs
I1114 10:12:27.340352 3 journal.go:176] journal.Update#write 10.919ms
I1114 10:12:27.377779 3 journal.go:188] journal.Update#validate 31.12525ms
I1114 10:12:27.384558 3 journal.go:144] journal.Update 63.86175ms
I1114 10:12:27.390968 3 witness.go:145] Update 5a2c0ccb4e56e7bfb37139494bf90ed092f60609743c71357b87c72966ef6676: 142.952ms