Closed arctica closed 5 years ago
vivekmenezes
commented
6 years ago https://www.cockroachlabs.com/docs/v1.2/operational-faqs.html#why-is-disk-usage-increasing-despite-lack-of-writes is definitely one answer to your question. We might want to investigate the issue with the disk writes on an idle cluster linearly growing with the number of ranges.
arctica
commented
6 years ago @vivekmenezes thx for commenting but can the timeseries data really be responsible for 500KiB/s writes when the metric collection interval is 10s by default? That would mean each collection cycle would collect nearly 5MiB of data.
Here an excerpt from the strace output of the disk writes to the mentioned .log file. I can definitely see some "tsd" and other strings which could be related to the timeseries stats.
[pid 17038] write(64, "\17\362\307|3\0\1\204\5Q8\0\0\0\0\1\0\0\0\1\n\1i\366\322urfth\0\32\22\4\10\0\20\0\30\0 \0(\0002\f\240\23\213$\3\10\n\20\2\30\3378", 58 <unfinished ...>
[pid 17038] write(64, "\1\223M]\273\3\1\205\5Q8\0\0\0\0\t\0\0\0\0028\4tsd\22cr.node.sql.mem.client.session.max-p99.999\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\225\336\212\337\316\232\331\376\24\20\0\0027\4tsd\22cr.node.sql.mem.client.session.max-p99.99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\225\336\212\337\316\232\331\376\24\20\0\0026\4tsd\22cr.node.sql.mem.client.session.max-p99.9\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\225\336\212\337\316\232\331\376\24\20\0\0024\4tsd\22cr.node.sql.mem.client.session.max-p99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\225\336\212\337\316\232\331\376\24\20\0\0024\4tsd\22cr.node.sql.mem.client.session.max-p90\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\225\336\212\337\316\232\331\376\24\20\0\0024\4tsd\22cr.node.sql.mem.client.session.max-p75\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\225\336\212\337\316\232\331\376\24\20\0\1\n\1i\366\322rrfta\0\25\22\4\10\0\20\0\30\0 \0(\0002\7\0\0\0\0\1\276q\1\n\1i\366\322rrlla\0\25\22\4\10\0\20\0\30\0 \0(\0002\7\0\0\0\0\1\232q\1\n\1i\366\322rstat\0\212\1\22\4\10\0\20\0\30\0 \0(\0002|Dt*\311\3\t\25\257\342\353\324d\375\24\21\0\0\0\0\0\0\0\0\31\0\0\0\0\0\0\0\0!\\$\233\0\0\0\0\0)\223\5\0\0\0\0\0\00016*\1\0\0\0\0\0009\223\5\0\0\0\0\0\0A&\372\231\0\0\0\0\0I\223\5\0\0\0\0\0\0Q\0\0\0\0\0\0\0\0Y\0\0\0\0\0\0\0\0a\253\3\0\0\0\0\0\0i\f\0\0\0\0\0\0\0p\1", 962) = 962
[pid 17015] write(64, "0\177\203\3044\0\1\216\5Q8\0\0\0\0\1\0\0\0\1\n\1i\366\314urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r_=~\207\3\10\t\20\0\30\253\302\2", 59) = 59
[pid 17013] write(64, "\366\25\323\324\261\6\1\217\5Q8\0\0\0\0\21\0\0\0\1\n\1i\366\230urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r\37\250\307\n\3\10\22\20\3\30\220\257\5\0020\4tsd\22cr.node.round-trip-latency-p99.999\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\376\377.A:\f\10\260\373\353\336\316\232\331\376\24\20\0\2/\4tsd\22cr.node.round-trip-latency-p99.99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\376\377.A:\f\10\260\373\353\336\316\232\331\376\24\20\0\0022\4tsd\22cr.node.sql.distsql.exec.latency-max\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\260\373\353\336\316\232\331\376\24\20\0\0024\4tsd\22cr.node.sql.distsql.exec.latency-p99.9\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\260\373\353\336\316\232\331\376\24\20\0\0022\4tsd\22cr.node.sql.distsql.exec.latency-p99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\260\373\353\336\316\232\331\376\24\20\0\0022\4tsd\22cr.node.sql.distsql.exec.latency-p90\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\260\373\353\336\316\232\331\376\24\20\0\0022\4tsd\22cr.node.sql.distsql.exec.latency-p75\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\260\373\353\336\316\232\331\376\24\20\0\0022\4tsd\22cr.node.sql.distsql.exec.latency-p50\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\260\373\353\336\316\232\331\376\24\20\0\2&\4tsd\22"..., 1720 <unfinished ...>
[pid 17013] write(64, "\27\310\323\234\337\v\1\240\5Q8\0\0\0\0\33\0\0\0\2.\4tsd\22cr.node.sql.mem.internal.max-max\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\224\246\203\337\316\232\331\376\24\20\0\0022\4tsd\22cr.node.sql.mem.internal.max-p99.999\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\224\246\203\337\316\232\331\376\24\20\0\0021\4tsd\22cr.node.sql.mem.internal.max-p99.99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\224\246\203\337\316\232\331\376\24\20\0\0020\4tsd\22cr.node.sql.mem.internal.max-p99.9\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\224\246\203\337\316\232\331\376\24\20\0\2.\4tsd\22cr.node.sql.mem.internal.max-p99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\224\246\203\337\316\232\331\376\24\20\0\2.\4tsd\22cr.node.sql.mem.internal.max-p90\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\224\246\203\337\316\232\331\376\24\20\0\2.\4tsd\22cr.node.sql.mem.internal.max-p75\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\224\246\203\337\316\232\331\376\24\20\0\2.\4tsd\22cr.node.sql.mem.internal.max-p50\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\224\246\203\337\316\232\331\376\24\20\0\2.\4tsd\22cr.node.sql.mem.internal.current\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0"..., 3046) = 3046
[pid 17013] write(64, "\277\211pcr\1\1\273\5Q8\0\0\0\0\t\0\0\0\1\n\1i\366\316urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r@\234\7\271\3\10\10\20\3\30\267\345\1\1\n\1i\366\231urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r}\227X9\3\10\23\20\3\30\373\203\5\1\n\1i\366\313urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r\326Z\265\243\3\10\t\20\0\30\341\350\2\1\t\1i\364urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\rV\n\210Z\3\10\25\20\0\30\337\315\5\1\n\1i\366\317urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r\222E\206?\3\10\10\20\3\30\353\334\1\1\n\1i\366\236urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r\210;N\311\3\10\22\20\3\30\206\210\4\1\n\1i\366\233urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\rs\362\5\364\3\10\22\20\3\30\354\315\4\1\n\1i\366\347urfth\0\32\22\4\10\0\20\0\30\0 \0(\0002\f8\361!\377\3\10\10\20\3\30\356+\1\n\1i\366\324urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r\vHm\355\3\10\7\20\3\30\221\320\1", 377 <unfinished ...>
[pid 17013] write(64, "\262M\267B=\5\1\304\5Q8\0\0\0\0\r\0\0\0\0026\4tsd\22cr.node.sql.mem.internal.txn.max-p99.999\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\205\315\216\337\316\232\331\376\24\20\0\2&\4tsd\22cr.node.sql.select.count\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\205\315\216\337\316\232\331\376\24\20\0\2-\4tsd\22cr.node.sql.service.latency-max\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\205\315\216\337\316\232\331\376\24\20\0\2/\4tsd\22cr.node.sql.service.latency-p99.9\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\205\315\216\337\316\232\331\376\24\20\0\2-\4tsd\22cr.node.sql.service.latency-p99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\205\315\216\337\316\232\331\376\24\20\0\2-\4tsd\22cr.node.sql.service.latency-p90\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\205\315\216\337\316\232\331\376\24\20\0\2-\4tsd\22cr.node.sql.service.latency-p75\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\205\315\216\337\316\232\331\376\24\20\0\2-\4tsd\22cr.node.sql.service.latency-p50\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\205\315\216\337\316\232\331\376\24\20\0\2$\4tsd\22cr.node.sql.misc.count\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\1"..., 1348) = 1348
[pid 17013] write(64, "\333\372n\212\312\25\2\321\5Q8\0\0\0\0\204\0\0\0\2-\4tsd\22cr.node.sql.mem.distsql.max-max\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\344\343\376\336\316\232\331\376\24\20\0\2-\4tsd\22cr.node.sql.mem.distsql.max-p50\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\344\343\376\336\316\232\331\376\24\20\0\2-\4tsd\22cr.node.sql.mem.distsql.current\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\344\343\376\336\316\232\331\376\24\20\0\0023\4tsd\22cr.node.sql.mem.conns.txn.max-p99.999\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\344\343\376\336\316\232\331\376\24\20\0\0022\4tsd\22cr.node.sql.mem.conns.txn.max-p99.99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\344\343\376\336\316\232\331\376\24\20\0\0021\4tsd\22cr.node.sql.mem.conns.txn.max-p99.9\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\344\343\376\336\316\232\331\376\24\20\0\2/\4tsd\22cr.node.sql.mem.conns.txn.max-p99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\344\343\376\336\316\232\331\376\24\20\0\2/\4tsd\22cr.node.sql.mem.conns.txn.max-p90\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\344\343\376\336\316\232\331\376\24\20\0\1\n\1i\366\317rrfta\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0\0\1\326\271\3\1\n\1i\366\317rrlla\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0"..., 5585) = 5585
[pid 17013] write(64, "\21s\306F9 \4e.sys.gc.pause.percent\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\217\367!\367\217\375\370>:\f\10\364\353\222\337\316\232\331\376\24\20\0\2%\4tsd\22cr.node.sys.cpu.user.ns\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0@@\277\36JB:\f\10\364\353\222\337\316\232\331\376\24\20\0\2*\4tsd\22cr.node.sys.cpu.user.percent\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\250\227\336\330\32\262\235?:\f\10\364\353\222\337\316\232\331\376\24\20\0\2)\4tsd\22cr.node.sys.cpu.sys.percent\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019[\374l\234\366\253|?:\f\10\364\353\222\337\316\232\331\376\24\20\0\2\35\4tsd\22cr.node.sys.rss\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\366\274\344A:\f\10\364\353\222\337\316\232\331\376\24\20\0\2!\4tsd\22cr.node.sys.fd.open\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0@P@:\f\10\364\353\222\337\316\232\331\376\24\20\0\2&\4tsd\22cr.node.sys.fd.softlimit\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0L\315@:\f\10\364\353\222\337\316\232\331\376\24\20\0\2 \4tsd\22cr.node.sys.uptime\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\307\273@:\f\10\364\353\222\337\316\232\331\376\24\20\0\1\t\1i\364rrfta\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0\0\1\276\233\v\1\t\1i\364rrlla\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0\0\1\204\232\v\1\t\1i\364rstat\0\212\1\22\4\10\0\20\0\30\0 \0(\0002|\235\17\32\256\3\t\364\265\344\353\324d\375\24\21\0\0\0\0\0\0\0\0\31\0\0\0\0\0\0\0\0!\212\210Y\2\0\0\0\0)@\27\0\0\0\0\0\0001U^\3\0\0\0\0\0009@\27\0\0\0\0\0\0A5*V\2\0\0\0\0I@\27"..., 8256) = 8256
[pid 17038] write(64, "wW\210\320\10\21\1U\6Q8\0\0\0\0*\0\0\0\1\t\1i\330urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r8\215[\225\3\10\24\20\1\30\275\361\5\2\37\4tsd\22cr.store.valbytes\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\24\3608\277\24B:\f\10\241\361\301\337\316\232\331\376\24\20\0\2-\4tsd\22cr.store.tscache.skl.read.pages\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\360?:\f\10\241\361\301\337\316\232\331\376\24\20\0\0021\4tsd\22cr.store.tscache.skl.read.rotations\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\241\361\301\337\316\232\331\376\24\20\0\2.\4tsd\22cr.store.tscache.skl.write.pages\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\360?:\f\10\241\361\301\337\316\232\331\376\24\20\0\0022\4tsd\22cr.store.tscache.skl.write.rotations\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\241\361\301\337\316\232\331\376\24\20\0\1\n\1i\366\324rrfta\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0\0\1\242\240\3\1\n\1i\366\324rrlla\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0\0\1\374\237\3\1\n\1i\366\324rstat\0\212\1\22\4\10\0\20\0\30\0 \0(\0002|\271Xx*\3\t\241x\360\353\324d\375\24\21\0\0\0\0\0\0\0\0\31\0\0\0\0\0\0\0\0!\242\274\246\0\0\0\0\0)!\3\0\0\0\0\0\0001A\211\0\0\0\0\0\0009!\3\0\0\0\0\0\0Aa3\246\0\0\0\0\0I!\3\0\0\0\0\0\0Q\0\0\0\0\0\0\0\0Y\0\0\0\0\0\0\0\0a\201\3\0\0\0\0\0\0i\f\0\0\0\0\0\0\0p\1\2/\4tsd\22cr.node.sql.mem.conns.txn.max-max\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\264\355\371\336\316\232\331\376\24\20\0\2/\4tsd\22cr.node.sql.mem.conns.txn.max-p75\0\1\211\370\6i$3\0"..., 4367 <unfinished ...>
[pid 17013] write(64, "\213\302\362\225]\27\1\177\6Q8\0\0\0\0006\0\0\0\2/\4tsd\22cr.store.leases.transfers.success\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\200N@:\f\10\277\344\304\337\316\232\331\376\24\20\0\2 \4tsd\22cr.store.livebytes\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0 \225\10\367\32B:\f\10\277\344\304\337\316\232\331\376\24\20\0\2 \4tsd\22cr.store.livecount\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\262\331\226\240A:\f\10\277\344\304\337\316\232\331\376\24\20\0\0028\4tsd\22cr.store.queue.consistency.process.success\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\24@:\f\10\277\344\304\337\316\232\331\376\24\20\0\0028\4tsd\22cr.store.queue.consistency.process.failure\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\277\344\304\337\316\232\331\376\24\20\0\0020\4tsd\22cr.store.queue.consistency.pending\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\277\344\304\337\316\232\331\376\24\20\0\0028\4tsd\22cr.store.queue.consistency.processingnanos\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\300\345\304\257\363A:\f\10\277\344\304\337\316\232\331\376\24\20\0\0024\4tsd\22cr.store.queue.gc.info.numkeysaffected\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\277\344\304\337\316\232\331\376\24\20\0\0026\4tsd\22cr.store.queue.gc.info.intentsconsidered\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0"..., 5988 <unfinished ...>
[pid 17015] write(64, "\1\352\322\3524\0\1\265\6Q8\0\0\0\0\1\0\0\0\1\n\1i\366\235urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r\264\v\264a\3\10\26\20\0\30\362\227\4", 59) = 59
[pid 17015] write(64, "($\363\275\230\10\1\266\6Q8\0\0\0\0\25\0\0\0\2\37\4tsd\22cr.store.replicas\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0`f@:\f\10\231\236\357\337\316\232\331\376\24\20\0\2>\4tsd\22cr.store.replicas.commandqueue.combinedqueuesize\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\231\236\357\337\316\232\331\376\24\20\0\2\35\4tsd\22cr.store.ranges\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\200P@:\f\10\231\236\357\337\316\232\331\376\24\20\0\2)\4tsd\22cr.store.ranges.unavailable\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\231\236\357\337\316\232\331\376\24\20\0\2-\4tsd\22cr.store.ranges.underreplicated\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\231\236\357\337\316\232\331\376\24\20\0\0022\4tsd\22cr.store.rebalancing.writespersecond\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019Y\30\231\215\7._@:\f\10\231\236\357\337\316\232\331\376\24\20\0\2#\4tsd\22cr.store.range.splits\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\231\236\357\337\316\232\331\376\24\20\0\2!\4tsd\22cr.store.range.adds\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\231\236\357\337\316\232\331\376\24\20\0\2$\4tsd\22cr.store.range.removes\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\231\236\357\337\316\232\331\376\24\20\0\0020\4tsd\22cr.store"..., 2207) = 2207
[pid 17015] write(64, "\361\312#8\252\0\1\313\6Q8\0\0\0\0\4\0\0\0\1\n\1i\366\303urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r$[~p\3\10\n\20\2\30\206\335\1\1\n\1i\366\311urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\rp\0\255\255\3\10\t\20\0\30\300\262\3\1\t\1i\272urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r{\202\231\203\3\10\26\20\2\30\235\317\5\1\n\1i\366\307urfth\0\32\22\4\10\0\20\0\30\0 \0(\0002\f\23\260\377\t\3\10\t\20\0\30\347)", 177) = 177
[pid 17015] write(64, "\201\371\16\32\220\5\1\317\6Q8\0\0\0\0\r\0\0\0\0022\4tsd\22cr.store.queue.split.process.success\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\366\364\343\337\316\232\331\376\24\20\0\0022\4tsd\22cr.store.queue.split.process.failure\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\366\364\343\337\316\232\331\376\24\20\0\2*\4tsd\22cr.store.queue.split.pending\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\366\364\343\337\316\232\331\376\24\20\0\0022\4tsd\22cr.store.queue.split.processingnanos\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\366\364\343\337\316\232\331\376\24\20\0\2:\4tsd\22cr.store.queue.tsmaintenance.process.failure\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0@:\f\10\366\364\343\337\316\232\331\376\24\20\0\2:\4tsd\22cr.store.queue.tsmaintenance.process.success\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\366\364\343\337\316\232\331\376\24\20\0\0022\4tsd\22cr.store.queue.tsmaintenance.pending\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\366\364\343\337\316\232\331\376\24\20\0\2:\4tsd\22cr.store.queue.tsmaintenance.processingnanos\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0008\5\"\201A:\f\10\366\364\343\337\316\232\331\376\24\20\0\0024\4tsd\22cr.store.queue.replic"..., 1431) = 1431
[pid 17015] write(64, "J\202\366\25\227\16\1\334\6Q8\0\0\0\0&\0\0\0\2\37\4tsd\22cr.store.valcount\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\10J\235\240A:\f\10\241\233\347\337\316\232\331\376\24\20\0\1\t\1i\272rrfta\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0\0\1\272\236\v\1\t\1i\272rrlla\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0\0\1\304\234\v\1\t\1i\272rstat\0\212\1\22\4\10\0\20\0\30\0 \0(\0002|1{\355d\3\t\241\315\371\353\324d\375\24\21\0\0\0\0\0\0\0\0\31\0\0\0\0\0\0\0\0!i\236C\0\0\0\0\0)\1\0\0\0\0\0\0\0001\37\0\0\0\0\0\0\0009\1\0\0\0\0\0\0\0AJ\236C\0\0\0\0\0I\1\0\0\0\0\0\0\0Q\0\0\0\0\0\0\0\0Y\0\0\0\0\0\0\0\0a%\3\0\0\0\0\0\0i\f\0\0\0\0\0\0\0p\1\1\n\1i\366\325urfth\0\32\22\4\10\0\20\0\30\0 \0(\0002\f\177Le%\3\10\7\20\0\30\251\32\2+\4tsd\22cr.node.txn.durations-p99.999\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\360\377\377vA:\f\10\267\371\264\337\316\232\331\376\24\20\0\2*\4tsd\22cr.node.txn.durations-p99.99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\360\377\377vA:\f\10\267\371\264\337\316\232\331\376\24\20\0\2&\4tsd\22cr.node.txn.restarts-max\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\267\371\264\337\316\232\331\376\24\20\0\2(\4tsd\22cr.node.txn.restarts-p99.9\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\267\371\264\337\316\232\331\376\24\20\0\2&\4tsd\22cr.node.txn.restarts-p99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\267\371\264\337\316\232\331\376\24\20\0\2&\4tsd\22cr.node.txn.restarts-p90\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0"..., 3742 <unfinished ...>
[pid 17424] write(64, "\250sS\340\373\r\1\2\7Q8\0\0\0\0$\0\0\0\1\n\1i\366\302urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r/`U\267\3\10\t\20\0\30\261\343\2\1\n\1i\366\306urfth\0\32\22\4\10\0\20\0\30\0 \0(\0002\f\251\371[\370\3\10\t\20\0\30\213+\1\t\1i\310urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r2\232\372\201\3\10\22\20\0\30\353\343\5\1\n\1i\366\304urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r\266i\n+\3\10\n\20\0\30\267\333\1\0021\4tsd\22cr.node.gossip.connections.incoming\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\360?:\f\10\321\330\221\337\316\232\331\376\24\20\0\0020\4tsd\22cr.node.gossip.connections.refused\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\321\330\221\337\316\232\331\376\24\20\0\2+\4tsd\22cr.node.gossip.bytes.received\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\315\3657A:\f\10\321\330\221\337\316\232\331\376\24\20\0\2'\4tsd\22cr.node.gossip.bytes.sent\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0p\260\"A:\f\10\321\330\221\337\316\232\331\376\24\20\0\2+\4tsd\22cr.node.gossip.infos.received\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0=\277@:\f\10\321\330\221\337\316\232\331\376\24\20\0\2'\4tsd\22cr.node.gossip.infos.sent\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0x\230@:\f\10\321\330\221\337\316\232\331\376\24\20\0\0021\4tsd\22cr.node.gossip.connections.outgoing\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\321\330\221\337\316\232\331\376\24\20\0\2(\4tsd\22cr.node.distsender.batches\0\1\211\370\6i$3\0@"..., 3586 <unfinished ...>
[pid 17105] write(64, "D&\6\305\204\v\2&\7Q8\0\0\0\0F\0\0\0\2!\4tsd\22cr.store.totalbytes\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\304-\314\370\32B:\f\10\331\215\355\337\316\232\331\376\24\20\0\2\37\4tsd\22cr.store.sysbytes\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\340\237\3A:\f\10\331\215\355\337\316\232\331\376\24\20\0\2\37\4tsd\22cr.store.syscount\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0d\237@:\f\10\331\215\355\337\316\232\331\376\24\20\0\0022\4tsd\22cr.store.rocksdb.memtable.total-size\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\224\"pA:\f\10\331\215\355\337\316\232\331\376\24\20\0\0029\4tsd\22cr.store.rocksdb.table-readers-mem-estimate\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\320+/pA:\f\10\331\215\355\337\316\232\331\376\24\20\0\0021\4tsd\22cr.store.rocksdb.read-amplification\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\24@:\f\10\331\215\355\337\316\232\331\376\24\20\0\2+\4tsd\22cr.store.rocksdb.num-sstables\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\340g@:\f\10\331\215\355\337\316\232\331\376\24\20\0\1\n\1i\366\325rrfta\0\25\22\4\10\0\20\0\30\0 \0(\0002\7\0\0\0\0\1\3224\1\n\1i\366\325rrlla\0\25\22\4\10\0\20\0\30\0 \0(\0002\7\0\0\0\0\1\2704\1\n\1i\366\325rstat\0\212\1\22\4\10\0\20\0\30\0 \0(\0002|@\237\250,\3\t\331F\373\353\324d\375\24\21\0\0\0\0\0\0\0\0\31\0\0\0\0\0\0\0\0!Yd\270\0\0\0\0\0)\231\7\0\0\0\0\0\0001%@\1\0\0\0\0\0009\231\7\0\0\0\0\0\0A4$\267\0\0\0\0\0I\231\7\0\0\0\0\0\0Q\0\0\0\0\0\0\0\0Y\0\0\0\0\0\0\0\0a\240\3\0\0\0\0\0\0i\f\0\0\0\0\0\0"..., 2955 <unfinished ...>
[pid 17105] write(64, "LZZE\343\21\4\0\0\0\0\0\0p\1\2%\4tsd\22cr.store.leases.success\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\300^@:\f\10\215\222\260\337\316\232\331\376\24\20\0\2#\4tsd\22cr.store.leases.error\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\215\222\260\337\316\232\331\376\24\20\0\2-\4tsd\22cr.store.leases.transfers.error\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\215\222\260\337\316\232\331\376\24\20\0\2(\4tsd\22cr.store.leases.expiration\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\215\222\260\337\316\232\331\376\24\20\0\2#\4tsd\22cr.store.leases.epoch\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\200N@:\f\10\215\222\260\337\316\232\331\376\24\20\0\2\37\4tsd\22cr.store.keybytes\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\300\366L\346\370A:\f\10\215\222\260\337\316\232\331\376\24\20\0\2\"\4tsd\22cr.store.intentbytes\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\215\222\260\337\316\232\331\376\24\20\0\2\37\4tsd\22cr.store.keycount\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\270\331\226\240A:\f\10\215\222\260\337\316\232\331\376\24\20\0\2\"\4tsd\22cr.store.intentcount\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\215\222\260\337\316\232\331\376\24\20\0\2 \4tsd\22cr.store.intentage\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234"..., 4586) = 4586
[pid 17105] write(64, "\37\255\357\377\314\t\1l\7Q8\0\0\0\0\30\0\0\0\2*\4tsd\22cr.node.txn.restarts-p99.999\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\351\201\265\337\316\232\331\376\24\20\0\2)\4tsd\22cr.node.txn.restarts-p99.99\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\351\201\265\337\316\232\331\376\24\20\0\2.\4tsd\22cr.node.txn.restarts.writetooold\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\351\201\265\337\316\232\331\376\24\20\0\2.\4tsd\22cr.node.txn.restarts.deleterange\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\351\201\265\337\316\232\331\376\24\20\0\2/\4tsd\22cr.node.txn.restarts.serializable\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\351\201\265\337\316\232\331\376\24\20\0\0021\4tsd\22cr.node.txn.restarts.possiblereplay\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\351\201\265\337\316\232\331\376\24\20\0\2\37\4tsd\22cr.store.capacity\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0rS[B:\f\10\351\201\265\337\316\232\331\376\24\20\0\2)\4tsd\22cr.store.capacity.available\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0|\362\20VB:\f\10\351\201\265\337\316\232\331\376\24\20\0\2+\4tsd\22cr.store.addsstable.proposals\0\1\211\370\6i$3\0@\22\4\10\0\20\0\30\0 \0(\0002$\0\0\0\0d\10\200\200\332\234\345\205\331\376\24\20\200\310\257\240%\32\r\10G0\0019\0\0\0\0\0\0\0\0:\f\10\351\201"..., 2515) = 2515
[pid 17015] write(64, "\216_\266\3244\1\1\204\7Q8\0\0\0\0\1\0\0\0\1\22\1i\366\230urftl\0\0\0\0\0\1W\221\0\222\2\22\4\10\0\20\0\30\0 \0(\0002\203\2$\220\24\272\3\10\0\20\22\30\221\257\5\"\363\1\0I\374\341 \0237\t\35\22\6\10\3\20\3\30\3 \310\256\5*\"\n\n\10\366\201\366\255\370\313\327\376\24\32\6\10\3\20\3\30\3*\n\10\352\230\366\255\370\313\327\376\0240\fj\201\1\22\10*\6\10\216\257\5\20\22B\n\10\345\243\323\346\316\232\331\376\24h\210\356\373\377\377\377\377\377\377\1r,\4tsd\22cr.node.sql.mem.distsql.max-p75\0\1\211\370\6h\3272z-\4tsd\22cr.node.sql.mem.distsql.max-p75\0\1\211\370\6h\3272\0\222\1\0r4\n2\0\0\0\0\0\0\0\0\1\0\0\0\1\n\1i\366\230rrftt\0\31\22\4\10\0\20\0\30\0 \0(\0002\v\347i|\206\3\10\216\257\5\20\22", 315) = 315
[pid 17034] write(64, "\252\253\22\0374\0\1\205\7Q8\0\0\0\0\1\0\0\0\1\n\1i\366\230urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r\36j\255=\3\10\22\20\3\30\221\257\5", 59) = 59
[pid 17034] write(64, "\355B\234[\20\1\1\206\7Q8\0\0\0\0\4\0\0\0\1\n\1i\366\230rrftt\0\31\22\4\10\0\20\0\30\0 \0(\0002\v\347i|\206\3\10\216\257\5\20\22\1\n\1i\366\230rrfta\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0\0\1\242\336\n\1\n\1i\366\230rrlla\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0\0\1\220\335\n\1\n\1i\366\230rstat\0\212\1\22\4\10\0\20\0\30\0 \0(\0002|o\344\236\304\3\t\24\323\340\353\324d\375\24\21\0\0\0\0\0\0\0\0\31\0\0\0\0\0\0\0\0!\220\5\200\2\0\0\0\0)'\27\0\0\0\0\0\0001f\203\4\0\0\0\0\0009'\27\0\0\0\0\0\0A*\202{\2\0\0\0\0I'\27\0\0\0\0\0\0Q\0\0\0\0\0\0\0\0Y\0\0\0\0\0\0\0\0a\300\5\0\0\0\0\0\0i\f\0\0\0\0\0\0\0p\1", 279) = 279
[pid 17034] write(64, "C\221-B\330\1\1\212\7Q8\0\0\0\0\27\0\0\0\0\22\1i\366\230urftl\0\0\0\0\0\1Wx\0\0\22\1i\366\230urftl\0\0\0\0\0\1Wy\0\0\22\1i\366\230urftl\0\0\0\0\0\1Wz\0\0\22\1i\366\230urftl\0\0\0\0\0\1W{\0\0\22\1i\366\230urftl\0\0\0\0\0\1W|\0\0\22\1i\366\230urftl\0\0\0\0\0\1W}\0\0\22\1i\366\230urftl\0\0\0\0\0\1W~\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\177\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\200\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\201\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\202\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\203\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\204\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\205\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\206\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\207\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\210\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\211\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\212\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\213\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\214\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\215\0\0\22\1i\366\230urftl\0\0\0\0\0\1W\216\0", 479) = 479
[pid 17105] write(64, "\354\374\22Z\27\1\1\241\7Q8\0\0\0\0\1\0\0\0\1\21\1i\213urftl\0\0\0\0\0\4'w\0\366\1\22\4\10\0\20\0\30\0 \0(\0002\347\1\242\302\357\r\3\10\0\20\32\30\367\316\20\"\327\1\0+/\246\334G\322\365\323\22\6\10\1\20\1\30\1 \213\201\r*:\n\f\10\335\230\213\357\204\315\327\376\24\20\1\22\n\10\201\204\211\340\341\232\331\376\24\32\6\10\1\20\1\30\1\"\n\10\201\204\211\340\341\232\331\376\24*\n\10\237\367\304\234\300\232\331\376\24jDB\n\10\322\207\315\375\320\232\331\376\24r\f\4\0liveness-\212z\r\4\0liveness-\212\0\222\1\30\t\322C\263\17\325d\375\24\31\257\0\0\0\0\0\0\0000\30@.H\2r>\n<\0\0\0\0\0\0\0\0\1\0\0\0\1\26\4\0liveness-\212\0\24\375d\325\17\263C\322\t\27\214\306\255B\3\10\2\20\4\32\f\10\310\312\306\257\364\232\331\376\24\20\0", 286) = 286
[pid 17038] write(64, "\330\1\1\2303\0\1\242\7Q8\0\0\0\0\1\0\0\0\1\t\1i\213urfth\0\33\22\4\10\0\20\0\30\0 \0(\0002\r\277XhB\3\10\32\20\1\30\367\316\20", 58) = 58
[pid 17038] write(64, "\343~\230\352\27\1\1\243\7Q8\0\0\0\0\4\0\0\0\1\26\4\0liveness-\212\0\24\375d\325\17\263C\322\t\27\214\306\255B\3\10\2\20\4\32\f\10\310\312\306\257\364\232\331\376\24\20\0\1\t\1i\213rrfta\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0\0\1\356\235!\1\t\1i\213rrlla\0\26\22\4\10\0\20\0\30\0 \0(\0002\10\0\0\0\0\1\226\202\32\1\t\1i\213rstat\0\212\1\22\4\10\0\20\0\30\0 \0(\0002|&V\251\357\3\t\322C\263\17\325d\375\24\21\0\0\0\0\0\0\0\0\31Tc\355\225\17\1\0\0!\220\0\0\0\0\0\0\0)\3\0\0\0\0\0\0\0001\23\226&\0\0\0\0\0009\3\0\0\0\0\0\0\0A\317\364I\0\0\0\0\0I)7\3\0\0\0\0\0Q\0\0\0\0\0\0\0\0Y\0\0\0\0\0\0\0\0a$\3\0\0\0\0\0\0i\n\0\0\0\0\0\0\0p\0", 286) = 286
dianasaur323
commented
6 years ago @mrtracy do you mind providing your opinion on this?
mrtracy
commented
6 years ago The disk space needed for all time series we write should be <1.5 MiB per node, per hour. That's about 500b/s.
We could also double (or even triple) that to account for writing the NodeStatus reports (which are overwritten and don't take up disk space, but still are written to disk), but that still would only be 1.5k/s.
POTENTIAL RED HERRING: There is one aspect that could potentially cause time series writes to account for this, and its a bit of a leaky abstraction; when writing time series, under the hood we use RocksDB's "MergeOperator" to efficiently write updates to disk. Basically, each time series key in the underlying k/v store contains 1 hour of data for 1 time series. When writing data, we use RocksDB's merge operation to "merge" 1 sample into the latest hour. When reading data, RocksDB will lazily merge all of those samples together.
So, what I'm wondering is: if you have the AdminUI open on a graphs page, it might be causing this merge operation to run for every single key that is merged. I'm wondering if this causes the entire value of the time series hour to be written to re-written to the disk every time it is read; that would represent up to 360 times the write load (at the end of the hour), which could account for about 200k/s.
Note that this is just a theory, I have no evidence of this; however, the best indicator that this is happening would be that the write bandwidth would "sawtooth" over the course of an hour; it would be lower at the beginning of the wall-clock hour, reaching a maximum toward the end of the hour. If the writes follow that pattern, then this might hold.
Otherwise, I don't think time series is obviously accounting for those writes. I'm not personally familiar with the strace tool output, so i'm not immediately sure how to interpret those other keys.
petermattis
commented
6 years ago RocksDB reads should never write. I'd be very surprised to learn that reading the timeseries data is increasing writes.
mrtracy
commented
6 years ago When is the merge operator supposed to write? Granted i've been out of that code for a long time, but it's my understanding that the merge operator is invoked when the key is read.
edit: Regardless, I wouldn't think this would account for 7MiB/s in writes.
petermattis
commented
6 years ago The merge operator never writes. The merge operator is invoked to merge together the values for two or more versions of a key. It is invoked on reads when the read encounters two or more versions for a key, but the resulting merged value is never written. It is invoked on compactions when the compaction encounters two or more versions for the same key.
vivekmenezes
commented
6 years ago @mrtracy this is a high priority item to get into 2.0. Many customers notice it.
arctica
commented
6 years ago Small update: my cluster has been idle for over 3 weeks now but disk writes are currently slightly over 1MiB/s. There's also 50-80 KiB/s network traffic in and out.
mrtracy
commented
6 years ago An update, now that i've had some time to collect some metrics from the time series system:
~125 writes per second is about the number of writes per second you would expect to see on a 3 node cluster from time series. However, while the amount of network traffic (and thus the amount of write traffic) this generates is somewhat higher than the needed disk space, it still only accounts for about 12.4KiB/s; even accounting for replication, that's ~37KiB/s, which is less than a tenth of the traffic you have described (and certainly nowhere near the zenith of 7MiB/s).
Monitoring my own disk writes at the operating system level, I am seeing a much lower baseline of write traffic, more in line with expectations for an idle cluster, so this is clearly not a universal issue.
@arctica Some information I haven't been able to get from the issue:
arctica
commented
6 years ago @mrtracy thanks for looking into this again
I have used "dstat" to gather the disk write stats but your question made me double check if the numbers from this tool are actually correct. Well, turns out it got confused by the soft-raid and/or the NVME drive setup but when I specify the md2 device instead of letting it automatically detect drives, I get much lower numbers. In the past 5min, the total it reported was 853 KiB/s on avg while the md2 device had 208 KiB/s.
I checked now with "iotop" and it reported around 200 KiB/s. Then I checked "iostat" and it reported the same.
So the actual disk writes are ~200 KiB/s. Much lower than I initially reported but still on the high side for an idle cluster and 5x your 37KiB/s estimation.
As for the rebalancing question: no, there is no rebalancing or snapshotting going on.
knz
commented
6 years ago @mrtracy this has been addressed with ts rollups right? is there still anything actionable here?
mrtracy
commented
6 years ago No, this was a different issue, but given that the actual disk writes were discovered to be much less than originally reported, i'm still not sure how actionable it is.
nvanbenschoten
commented
5 years ago Closing as stale.
Not sure if this is a question or bug report as I'm unsure as to if the amount of disk writes that I'm seeing on this idle cluster is normal or not, to me it seems excessive.
Issue: I am seeing about 500KiB/s in disk writes on each node in a 3 node cluster running latest master. The cluster was loaded with about 139M rows totalling nearly 60GiB. This resulted in a table with 121 ranges (I increased the max range size to 256MiB). The loading happened days ago and the cluster is now completely idle. There are in total 133 ranges according to the "Databases" page of the admin UI, the "Overview" page though says 214. The "Ranges" graph also confirms 214 (with 178 Leaders and 170 Lease Holders).
The "Keys Written per Second per Store" graph shows about 125 writes/s on each store. If each write is a 4KiB page, that would match the ~500KiB/s. Using
strace, I found that the disk writes seem to be done tocockroach-data/016750.logBefore wiping and upgrading the cluster I actually had a table with a few thousand ranges and on that cluster, disk writes amounted to a staggering 7MiB/s while totally idle, leading me to believe that the amount of writes/s both in terms of count as well as size depends on the amount of ranges.
CPU wise the cluster is pretty idle with CockroachDB using about 3% of one out of 8 cores on average though of course I'd prefer to see that also being more idle :)
grep -F '[config]' cockroach-data/logs/cockroach.logLog from node2:
Log from master: