Monitoring

A node tells its state in five places:

• The GET /health endpoint, for a load balancer or a supervisor.
• SQL statements: SHOW METRICS, SHOW MEMORY and the other SHOW statements of this page. The SQL reference gives the syntax and who may run each one.
• The admin console of the node, at /ui/: a Monitor page, a query console, reports and the audit log.
• The audit trail: the record of who did what (SHOW AUDIT), also in the console.
• The terminal of the node: one line for each log event.
• A collector: another kinedb server that stores the logs and the metrics of the nodes (KINEDB_LOG_SINK).

The examples on this page come from a real node of this version. The numbers on your node are different.

The admin console

Each node serves the admin console on its own port, at /ui/ (for example http://localhost:4820/ui/). See How the node serves /ui/. The console shows the node that you are connected to. The Monitor page reads its numbers with the SHOW statements of this page.

• Monitor (/ui/#/monitor) shows the state of the node and of its cluster: the nodes, the throughput, the memory reporters, the Calvin pipeline, the S3 archive, the replication to each follower and the slow queries.

• Query (/ui/#/query) runs any SQL, so it runs every SHOW statement of this page and shows the answer as a table. Use it when the Monitor page does not show the value that you need.

• Reports (/ui/#/reports) are pages of panels (tables, charts and key numbers), each made from SQL. A report shows the node that you are connected to. Open a built-in report, or duplicate it to change it. Your own reports stay in the browser, not on the server.

• Audit (/ui/#/audit) shows the audit trail.

The console has six built-in reports. The first four tell more about THIS node:

Report	What it shows
Cluster Health	The replication peers, the Raft groups and where the memory goes.
Throughput Snapshot	The query and write counters, where the Calvin pipeline spends its time and the slow queries.
Storage Snapshot	The use of the local disk, the S3 archive and the root of each table.
Memory Inspector	The heaviest memory reporters, the share of each and the full list.

The last two reports are for a collector, a kinedb server that stores the metrics and the logs of other nodes. They show the nodes over time, so open them on the collector, where the metrics table is:

Report	What it shows
Collector Metrics	Reads and writes each second, CPU and memory of each node over time, and the Raft compaction activity.
Memory Tracking	The memory of each node over time: tracked, allocated and RSS, and the gap that no reporter names.

The health endpoint

GET /health needs no login. It answers 200 OK when the node is healthy. It answers 503 Service Unavailable in two cases:

• An index is UNUSABLE. The unusable_indexes array has one line for each one. See Troubleshooting.

The endpoint shows no table or index name to a caller that is not a superuser. Each line of unusable_indexes then gives only the number of the index; the node log names each index and its repair. Send Authorization: Bearer <token> of a superuser to get the names and the repairs in the body. A token that is not valid gets 401 Unauthorized.

• The first boot has not made the user root yet. See A login fails right after the first start.

The body is one JSON object. This is a body from a node with one member; the memory array is left out here:

$ curl -s http://127.0.0.1:4962/health
{"elapsed_us":537,"memory_total_bytes":1188798,"peers":["127.0.0.1:4962"],"revision":"397e076827679e5aa3af475fb146bf3c7c0e0e54","rss_bytes":27062272,"status":"ok (1 nodes) calvin=true dml_via_calvin=1 memory=1MB","type":"health","unusable_indexes":[]}

Field	What it is
status	A text summary. It starts with ok and the number of nodes.
peers	The addresses of the nodes that this node knows.
rss_bytes	The resident memory of the process, from the operating system.
memory_total_bytes	The sum of the memory that kinedb counts itself (the summary.tracked_total of SHOW MEMORY).
memory	The same rows as SHOW MEMORY.
unusable_indexes	The UNUSABLE indexes. Empty on a healthy node.
revision	The build of the binary: the git commit it was built from, or unknown. Put it in a bug report.

The boot line of the node names the same revision:

KineDB v0.0.2 (revision 397e076827679e5aa3af475fb146bf3c7c0e0e54) node=… listening on http://0.0.0.0:4820

The node has no other HTTP endpoint for health or metrics. GET /metrics answers 404 Not Found. Use POST /sql with SHOW METRICS to read the counters over HTTP. See Ports and endpoints.

SHOW METRICS

SHOW METRICS returns one row for each counter of this node, with the columns key and value. A node with one table returned 368 rows without --calvin and 553 rows with --calvin. This is a part of the output:

SHOW METRICS;

key                                                   | value
------------------------------------------------------+--------------------------
dml.queries_total                                     | 13
dml.queries_failed_total                              | 3
io.block_puts_total                                   | 10
io.block_dedup_hits_total                             | 1
io.blocks_written_total                               | 9
log_sink.enabled                                      | 0
gc.enabled                                            | 0
shed.stage                                            | 0
raft.frame_undecodable_total                          | 0

No row resets when you read it

A read of SHOW METRICS has no side effect. Each counter only grows from the start of the process, and the other rows show a value of now. Two tools can read the same node, and each one sees the full counts. To measure one step, read SHOW METRICS before and after the step, and subtract the two values.

Before B3180 and B3228, some rows showed only the change since the previous read, and each read set them back to 0. These rows now hold totals, and they have new names that end with _total. A tool that reads an old name gets no row:

Old name	New name
applier.drain_calls	applier.drain_calls_total
applier.drain_batches	applier.drain_batches_total
applier.lock_wait_ns	applier.lock_wait_ns_total
applier.drain_loop_ns	applier.drain_loop_ns_total
applier.batch_total_ns	applier.batch_ns_total
applier.begin_ns	applier.begin_ns_total
applier.apply_ops_ns	applier.apply_ops_ns_total
applier.commit_or_buffer_ns	applier.commit_or_buffer_ns_total
applier.commit_seq_wait_ns	applier.commit_seq_wait_ns_total
applier.wal_ns	applier.wal_ns_total
applier.encode_ns	applier.encode_ns_total
applier.absorb_ns	applier.absorb_ns_total
ws_handler.op_tx_send_blocked_ns	ws_handler.op_tx_send_blocked_ns_total
ws_handler.op_tx_send_calls	ws_handler.op_tx_send_calls_total
ws_handler.handle_ws_request_total_ns	ws_handler.handle_ws_request_ns_total
ws_handler.handle_ws_request_calls	ws_handler.handle_ws_request_calls_total
ws_handler.op_to_shard_misses	ws_handler.op_to_shard_misses_total
ws_handler.idle_timeout_wakes_with_work	ws_handler.idle_timeout_wakes_with_work_total
prolly.mutate_bulk_calls	prolly.mutate_bulk_calls_total
prolly.mutate_bulk_total_ns	prolly.mutate_bulk_ns_total
prolly.collect_all_total_ns	prolly.collect_all_ns_total
prolly.merge_total_ns	prolly.merge_ns_total
prolly.build_from_sorted_total_ns	prolly.build_from_sorted_ns_total
prolly.build_leaf_per_entry_put_ns	prolly.build_leaf_per_entry_put_ns_total
prolly.build_leaf_per_node_put_ns	prolly.build_leaf_per_node_put_ns_total
prolly.build_internal_total_ns	prolly.build_internal_ns_total
prolly.commit_durable_total_ns	prolly.commit_durable_ns_total
prolly.commit_head_lock_total_ns	prolly.commit_head_lock_ns_total
io.cache_hits	io.cache_hits_total
io.cache_misses	io.cache_misses_total
io.segment_reads	io.segment_reads_total
io.segment_read_us	io.segment_read_us_total
io.segment_writes	io.segment_writes_total
io.segment_write_us	io.segment_write_us_total
io.slow_gets	io.slow_gets_total
io.slow_puts	io.slow_puts_total

Three rows keep their names: applier.ops_total, prolly.flush_cas_retries_total and prolly.flush_locked_fallbacks_total. Before B3228 they also reset on each read. Now they are totals, as their names say.

The counter families

The first part of a key names its family. A key that starts with shard_<id>. belongs to one shard.

Family	What it counts
dml.*	The client queries that ran, and the queries that failed.
query.slow_*	The slow queries, and the threshold in microseconds. See SHOW SLOW QUERIES.
auth.*	Refused reads and writes, refused tokens, refused logins and guest logins.
peer_auth.*	Connections from other nodes that the node refused.
io.*	The block store: cache hits and misses, segment reads and writes, block writes and the blocks that the store did not write again because it had them. See the SQL reference.
storage.*	The memory cap of the write buffer, and the index from a block to its segment (storage.front_index.*).
memtable_flush.*, flush.*	How often the write buffer went into the tree, and why. flush.* holds timings, and they stay at 0 unless a diagnostics variable is set.
prolly.*	The tree: timings of changes and commits, and the node cache.
gc.*	The garbage collection of dead blocks: sweeps, refusals, errors, reclaimed bytes. All 0 without --gc-retention. gc.sweep_in_progress is above 0 while a sweep runs. gc.last_sweep_start_ms and gc.last_sweep_end_ms give the window of the last sweep in unix epoch milliseconds.
shed.*	The memory ladder under --memory: the stage, the actions it took, the writes it held. All 0 without --memory.
write_admission.*	The largest client batch, and the transactions refused because they were larger.
pc.*	The page-cache advice that the node gives to the operating system.
ws_handler.*, ws.pipeline.*, server.ws_active_connections	The WebSocket connections of the clients.
stream.*, exchange.*, scatter.*	Streamed queries, streams between nodes, and partial results of aggregates over shards.
files.*	The file chunks that the node received and served.
log_sink.*, metrics_drain.*, drain.auth_rejected_total	The collector connection. See The collector.
calvin.sequencer.*, calvin_dml.*, applier.*	The ordering of the writes, and the applier that writes them to storage.
calvin.raft_log.*, calvin.raft_wal.*, calvin.election.*	The Raft logs of this node: unsent bytes, fsyncs, elections. Each is a sum over the shards.
raft.*	Raft log compaction, read leases, shard joins, rebuilds and placement records. raft.inbox_* counts the inboxes of the shards: each shard gets the Raft frames of the other nodes in its own queue, with one worker thread. raft.inbox_queued_total gives the frames that went into an inbox, and raft.inbox_served_total gives the frames that a worker served. raft.inbox_workers gives the workers that run now, and raft.inbox_workers_started_total gives the workers started since the start. raft.durable_clamp_unarmed_shards gives the shards of this node that had no storage sync yet. The log of such a shard can compact past the last storage sync. The first storage sync comes 5 s after the start, and then the value goes to 0. A new shard adds 1 until the next sync.
calvin.split_hold_park.*, split_manager.enabled	Writes that waited for a shard split, and whether this node splits shards.
server.write_refused_*, server.read_wait_*	Writes refused because no replica or no leader was ready, and reads that waited for a new shard.
b35.gtxn.*	Transactions over more than one shard.
b2597.read_hold.*	The read holds of this node: a shard that refuses reads until it applies the part of a transaction over more than one shard. b2597.read_hold.shard_<id>.pseq and b2597.read_hold.shard_<id>.held_ms exist only while the shard holds. b2597.read_hold.held and b2597.read_hold.stuck count the holds and the stuck holds.
b169.*, shard.acquire_install_aborted_applier_ahead_total	Replicas of a shard that did not agree, and the repairs.
peer_broadcast.*	The queue of messages to the other nodes.
quiesce.*	Work that waits: buffered write bytes, Raft entries not applied yet, messages to other nodes. All three are 0 on an idle node.
index_build.running	The CREATE INDEX builds that run on this node now. On a cluster, the node that coordinates a build and the leader of each shard count it. SHOW INDEXES gives the progress of each build.
shard_<id>.*	One shard: its status (active, splitting, retired), its size, and with --calvin its Raft log and its write queue.

Each shard of a --calvin node has seven rows for its Raft log: raft_log_entries, raft_log_bytes, raft_log_droppable_bytes, raft_log_compaction_trigger_bytes, raft_log_batch_entries, raft_log_batch_bytes and raft_log_unarmed_batch_entries. See the SQL reference.

Values that signal trouble

The code of the node defines these rules. A counter that is not in this table has no rule; compare it with its value on a healthy node.

Row	Trouble when
raft.frame_undecodable_total	Not 0. A peer runs a different build. This node cannot read the log of that peer and stops on the affected shard. The value never goes back to 0. Run one build on all nodes.
raft.inbox_full_waits_total	It grows. The inbox of a shard was full (128 Raft frames), so the connection from the peer waited for the shard. While it waits, the connection serves no frame of another shard. The disk of that shard is slow. No frame is lost. raft.inbox_full_wait_ns_total gives the total time of the waits, and raft.inbox_full_wait_max_ms gives the longest wait since the start. A wait of more than 100 ms writes a [B3177_INBOX_FULL_WAIT] line with the shard. raft.inbox_max_depth gives the deepest inbox since the start.
raft.inbox_panics_total	Not 0. The worker of a shard inbox stopped with a panic, and the queued frames of that shard were lost. Raft sends them again. The log has a [B3177_INBOX_WORKER_PANIC] line with the shard. Report it.
raft.inbox_stale_dropped_total	It grows fast. Frames came for a shard replica that this node removed. A small value after a move or a split of a shard is normal: the leader sends the frames again.
gc.mark_divergence_total	Not 0. The garbage collection found a fault in its own mark (the background sweep or a VACUUM statement). It stopped the sweep, so no data was lost. Report it.
gc.mark_corruption_total	Not 0. The garbage collection found damaged data before the sweep step (the background sweep or a VACUUM statement): a cycle or a bad level in a tree, or a block whose bytes do not match its hash (a commit, a pinned commit, a branch base, a node of the branch ledger or a node of a tree). It stopped before the sweep step, so it reclaimed nothing and no data was lost. The log has a [GC_MARK_CORRUPTION] line that names the block. The sweeps stay stopped until the block is correct: restore the block from a replica or a backup, then run VACUUM again. Report it.
gc.sweep_corruption_total	Not 0. The mark of the garbage collection ended without an error, but the sweep step stopped with a corruption error, for example a live record with a bad checksum. The sweep rewrites the old segment files one at a time, so the files that it finished before the error are reclaimed. The log has a [GC_SWEEP_CORRUPTION] line with the cause. For a damaged record, the cause names compaction:, the segment file and the block: the sweep did not change that segment file and deleted no live block. Restore the block from a replica or a backup, then run VACUUM again. Report it.
gc.mark_refused_total	Not 0. The garbage collection had not enough memory for its mark (the background sweep or a VACUUM statement). Raise --memory.
gc.sweep_errors_total	It grows. Sweeps fail (the background sweep or a VACUUM statement). The log gives the reason.
shed.terminal	1. The node refuses writes, and a retry cannot clear the refusal.
shed.parked_writes_now	It stays above 0 while shed.pause_refusals_total stays flat. Writes wait and are not refused: the node is stuck.
shed.pause_refusals_total	It grows. The node refuses writes because of memory pressure. The clients retry. This is the designed answer to pressure, not a fault.
storage.memtable.throttle_events_total	Not 0. The memory cap of the write buffer refused at least one write. Under --memory the cap comes from the budget: storage.memtable_max_bytes_effective gives the cap in force, and storage.memtable_max_bytes_configured gives the setting.
storage.flush_unknown_shard_noop_total	Not 0. A fault in the code. Report it.
applier.rmw_replay_skip_live_total	Not 0. A live write found its key already written by the same batch, so the applier skipped it. This is expected only on a restart, where applier.rmw_replay_skip_boot_total counts it. The shard_<id>.applier.rmw_replay_skip_live_total row names the shard. Report it.
applier.rejected_total	A replica of a shard has a different shard_<id>.applier.rejected_total from the other replicas at the same applied index. Every replica applies the same writes, so the replicas do not agree. A value above 0 by itself is normal: a duplicate key or a failed check rejects the write on every replica. The first rejected write of each kind on a shard writes one [APPLY_REJECT] line.
calvin.sequencer.backpressure_timeouts_total	Not 0. The write queue of a shard was full for 5 seconds.
calvin.raft_log.pending_bytes_total	It grows and does not stop. A follower does not apply its log.
calvin.raft_log.backpressure_timeouts_total	Not 0. A follower does not acknowledge. Under --memory the queue cap comes from the budget: calvin.raft_log_pending_bytes_limit_effective gives the cap in force, and calvin.raft_log_pending_bytes_limit_configured gives the setting.
peer_broadcast.backpressure_timeouts_total	Not 0. Another node takes its messages too slowly.
peer_auth.upgrade_refused_total	Not 0. The nodes do not have the same cluster key, or a node of an older version (on the cluster secret) runs in the cluster.
peer_auth.unproven_peer_refused_total	It grows. A node dials this node with a cluster name and no credential. It is a node of another cluster with the same --cluster-key name, or a node that has no cluster key yet. The log line [B1411_UNPROVEN_PEER] gives its address.
drain.auth_rejected_total	Not 0. The collector refused the login of this node.
pc.advise_errors	It grows. The operating system refused the page-cache advice.
b35.gtxn.ledger_stalled_index	Not 0. The metadata of this node stopped at that entry. The log line [B35_LEDGER_STALL] gives the error.
b35.gtxn.outcome_unknown_total	It grows. Transactions over more than one shard end without a known result. Each client must read its writes back before it runs the transaction again.
b35.gtxn.resolve_breach_total	Not 0. Stop and report it.
b35.gtxn.stale_abort_total	Not 0. It is 0 on a healthy cluster.
b2597.read_hold.stuck	Not 0. A shard refuses its reads for more than 30 seconds, because the apply of an acked transaction part did not happen. See A read hold is stuck.
ws_handler.op_to_shard_misses_total	Not 0. A shard has no write queue on this node.

SHOW MEMORY

SHOW MEMORY returns one row for each memory user of the node, the largest first:

Column	What it is
name	The memory user.
bytes	The bytes it holds now.
entries	The number of items it holds.
can_shed	true when the node can free this memory under pressure.
display_only	true for a row that shows memory that another row already counts. Such a row is not in the sum.

The rows that start with jemalloc. come from the memory allocator. They measure the same memory three times, so the sum leaves them out. The last rows are a summary:

SHOW MEMORY;

name                                            | bytes      | entries | can_shed | display_only
------------------------------------------------+------------+---------+----------+-------------
summary.tracked_total                           | 717016083  | 0       | false    | true
summary.process_rss                             | 741363712  | 0       | false    | true
summary.untracked_gap                           | 92977141   | 0       | false    | true
summary.budget                                  | 2147483648 | 0       | false    | true
summary.headroom                                | 1430467565 | 0       | false    | true
summary.over_budget                             | 0          | 0       | false    | true
summary.shed_stage                              | 0          | 0       | false    | true

Row	What it is
summary.tracked_total	The sum of the memory users that kinedb counts. --memory is enforced against this number.
summary.process_rss	The resident memory from the operating system.
summary.untracked_gap	The memory that the allocator holds, minus summary.tracked_total. Both values are from the same moment: SHOW MEMORY reads the allocator again when its last reading is older than 50 ms.
summary.budget	The --memory budget. Only with --memory.
summary.headroom	The budget minus the tracked total; 0 when over. Only with --memory.
summary.over_budget	The bytes over the budget; 0 when under. Only with --memory.
summary.shed_stage	The stage of the memory ladder: 0 is calm, 1 to 3 is shedding. Only with --memory.

SHOW DISK STATUS

SHOW DISK STATUS shows the local storage of the node:

key                       | value
--------------------------+-------------------------------------------------------------------
head_hash                 | "7b12040867def258609b583a1176e60753af0a21869d95e67b03637ee1f2b560"
head_txn                  | 117399658844061696
wal_size_bytes            | 156
segment_count             | 1
segment_total_bytes       | 1621
wal_poisoned_refusals     | 0
segment_poisoned_refusals | 0
gc_enabled                | false
gc_retention              | "none"
retention_floor           | "none (all history readable)"
(10 rows)

• head_hash and head_txn name the newest commit.
• wal_size_bytes is the size of the write-ahead log. It stays visible after a write-ahead log error.
• segment_count and segment_total_bytes are the segment files and their size.
• wal_poisoned_refusals counts the calls that the store refused after a write-ahead log error. A write-ahead log error stops the node. In an embedded database the store then refuses every later commit and sync. A value that is not 0 means: restart the process. The restart replays the write-ahead log.
• segment_poisoned_refusals counts the calls that the store refused after a failed fsync of the active segment file. A failed fsync of a segment file stops the node. In an embedded database the store then refuses every later write, seal and sync. After a stop in the periodic sync, reads continue. After a stop inside a commit, reads also return an error. A value that is not 0 means: restart the process. The restart replays the write-ahead log.
• On a node with S3, every value comes from the local data directory, the same as on a node without S3.
• gc_enabled, gc_retention and retention_floor tell whether the node reclaims dead blocks, and how far back the history is readable. gc_enabled false explains a segment_total_bytes that only grows. See --gc-retention in Run kinedb.

SHOW SYNC STATUS

SHOW SYNC STATUS writes the buffered writes into the tree first. Then it shows the newest commit and the peers that this node knows:

key         | value
------------+-------------------------------------------------------------------
head_hash   | "7b12040867def258609b583a1176e60753af0a21869d95e67b03637ee1f2b560"
head_txn    | 117399658844061696
known_peers | 0
peers       | ""
(4 rows)

SHOW S3 STATUS

SHOW S3 STATUS shows how far the S3 copy is behind the local data. A node without --s3 answers disabled. See S3 storage.

SHOW NODES

SHOW NODES returns one row for each member of the cluster that this node knows, including itself:

node           | node_id                          | status | rss_bytes | memory_total_bytes | last_seen_us
---------------+----------------------------------+--------+-----------+--------------------+-----------------
127.0.0.1:4962 | 72ec059a65db558c6fcf4a97a5173e07 | alive  | 24518656  | 1187706            | 1791376808793015
(1 rows)

• status is alive, suspect or dead, from the membership protocol of the cluster.
• rss_bytes and memory_total_bytes come from the /health endpoint of each node. They are NULL when this node cannot reach that node.
• last_seen_us is the time of the last change of status, in microseconds since the Unix epoch.

A node that stays suspect or dead is not reachable from this node.

SHOW PEERS

SHOW PEERS needs --calvin. Without it, the answer is ERROR: Raft is disabled; SHOW PEERS has no meaning. It returns one row for each voter of the metadata group:

peer           | role   | next_index | match_index | last_ae_ms_ago | lag_entries | state
---------------+--------+------------+-------------+----------------+-------------+------
127.0.0.1:4962 | leader | NULL       | NULL        | NULL           | NULL        | NULL
(1 rows)

Only the leader knows the progress of the other voters. On another node, and in the row of the leader itself, the progress columns are NULL. On the leader:

• lag_entries is the commit index minus the match_index of the peer.
• state is up when lag_entries is 10 or less, and lagging up to 100.
• state is unreachable above 100, or when the peer has not answered yet.

SHOW PLACEMENT

SHOW PLACEMENT returns one row for each placement record: the voters of a shard, the term and the index of that voter set, the replication factor, and attested_progress. A node with no placement records returns no rows:

shard_id | voters | config_term | config_index | rf   | anchor | attested_progress
---------+--------+-------------+--------------+------+--------+------------------
(0 rows)

attested_progress is 0 when no voter has confirmed its progress in this record. The node refuses a recovery after a quorum loss on a shard whose record has 0. A new shard of a split shows 0 until its leader confirms the progress for the first time.

SHOW RAFTGROUPS and SHOW RAFTGROUP

SHOW RAFTGROUPS needs --calvin and root. It returns one row for each Raft group on this node: the role, the term, the leader, the log indexes, the status and the size of each shard. SHOW RAFTGROUP <id> returns the same row for one group, with many more counters. Some columns of a real node:

shard_id   | role   | term | leader_id                        | last_log_index | commit_index | applied_count | peer_count | status
-----------+--------+------+----------------------------------+----------------+--------------+---------------+------------+---------
0          | leader | 1    | 72ec059a65db558c6fcf4a97a5173e07 | 1              | 1            | 0             | 1          | Active
1          | leader | 1    | 72ec059a65db558c6fcf4a97a5173e07 | 3              | 3            | 2             | 1          | Metadata
1476720639 | leader | 1    | 72ec059a65db558c6fcf4a97a5173e07 | 1              | 1            | 1             | 1          | Active

The row with status Metadata is the group that holds the cluster metadata.

To measure the apply lag of a group, use commit_index - applied_index. Both columns are Raft log indexes. Do not use applied_count for the lag. It counts the entries that this node applied in the group since the birth of the group on the node. A group that a split made starts its log at the split index of its parent, and its applied_count starts at 0. So commit_index - applied_count stays at about the split index, also when the apply is current. first_log_index shows the first index that the log of the group holds.

To see which followers the leader has heard, read the peer_match column of SHOW RAFTGROUP <id> on the leader. It is an object {"<node id>": <match index>} for each peer. On a follower it is NULL. The last_log_index of a follower is no proof that the leader heard it: a lost answer keeps the match of that follower at 0 on the leader. While a voter has match 0 under a new leadership, SPLIT SHARD answers split deferred: a parent voter has not answered the new leader yet, and the text names that voter and its match.

The progress of a CREATE INDEX build

A CREATE INDEX build writes [INDEX_BACKFILL] lines to the node log: start before the scan, built after it, parts before the entries are written, and servable at the end. While the build runs, the node also writes a progress line, at most once a minute for each build:

[INDEX_BACKFILL] progress index=idx_docs_k table=docs phase=scan rows=1200345 shards=0/1 parts=0/0 elapsed_s=420 scope=whole

phase is scan, parts or slices (the node that coordinates a cluster build). scope is whole for a build on one node, coordinator, or shard:<id> for the slice of one shard on its leader. The environment variable KINEDB_INDEX_BACKFILL_PROGRESS_SECS sets the interval in seconds; 0 writes a line at each update. SHOW INDEXES gives the same progress in its progress, started_at and elapsed_s columns.

The audit trail

The metrics tell how the node runs. The audit trail tells who did what: logins, refusals, changes of users, roles and grants, DDL, settings, branch merges and node starts. No row holds a password, a hash, a token or a statement text, and no statement changes or deletes a row.

SHOW AUDIT WHERE result = 'refused' LIMIT 50;

• SHOW AUDIT answers the newest rows first, and it can filter by actor, target, action, result, node and time. The syntax and the columns are in the SQL reference.
• A superuser, or a user with GRANT AUDIT, sees all rows. Another user sees only the rows where that user is the actor or the target. The guest gets an error.
• The Audit page of the console (/ui/#/audit) runs the same statement. It has a filter for each field and a limit. The action filter offers the name of each action.
• The node column tells which node recorded a row.

The diagnostic log

The node can write its memory and its Raft state to a file every 2 seconds. This is a tool for an investigation, and it is off by default, because it costs CPU on an idle node. Its format can change between versions.

Set KINEDB_DIAG_LOG=1 at the start. The node writes logs/server_diag_port<port>_<epoch>.log, relative to the working directory of the process. Each tick starts with == <epoch seconds> ==, then one line for the process, one summary line for the memory, and one line for each shard:

== 1791376920 ==
  proc rss=25288704 thr=38
  mem_tracked=1187066 delta_rss=0M delta_mem_tracked=0M top5=jemalloc.resident(21508096),jemalloc.active(6361088),jemalloc.allocated(5473184),storage.front_index(817284),storage.codec(263344) delta_top=jemalloc.resident(0)
  shard:1 leader Metadata t=2 log=4 commit=4 applied=2 noop_skipped=2 memtable=0 tree=0 leader=72ec059a65db558c6fcf4a97a5173e07 hb_emit=22 ae_emit=0 ae_bytes_sent=0 ae_entries_sent=0 compactions=0 comp_floor=4 comp_last=0
  shard:1476720639 leader Active t=2 log=2 commit=2 applied=1 noop_skipped=1 memtable=0 tree=58 leader=72ec059a65db558c6fcf4a97a5173e07 hb_emit=22 ae_emit=0 ae_bytes_sent=0 ae_entries_sent=0 compactions=0 comp_floor=2 comp_last=0

Every 5 seconds, and when the resident memory grows by more than 256 MB in one tick, the tick also lists every memory user (mem.<name> bytes=… entries=… can_shed=…).

The fields of a shard line:

Field	What it is
shard:<id>	The shard.
role, status	leader or follower; the status of the shard (Active, Metadata, Absent and others).
t	The Raft term.
log, commit	The last index of the Raft log, and the last committed index.
applied	The number of batches that the applier wrote to storage.
noop_skipped	The empty entries that a new leader writes. The applier does not count them.
memtable	The bytes in the write buffer of the shard now.
tree	The bytes written to the tree of the shard since it was made. It only grows.
leader	The node id of the leader.
hb_emit, ae_emit	The heartbeats, and the log messages with entries, that this node sent for the shard.
ae_bytes_sent, ae_entries_sent	The bytes and the entries of those log messages, summed over all peers.
compactions	The number of times that the node removed old entries from the Raft log of the shard.
comp_floor	The highest index below which the log can be removed, as this node knows it.
comp_last	The highest index that the node really removed up to. It is lower than comp_floor by a safety margin.

The code gives these readings:

• The applier is stuck. commit is larger than applied plus noop_skipped, and the difference grows from tick to tick.
• Replicas do not agree. Compare one shard on all its replicas. When the Raft state is the same but tree is different, the replicas wrote their buffers at different times. When memtable plus tree is different, the data is different.

The collector

A node can send its logs and its metrics to a collector: another kinedb server.

Use a collector when you want to query the logs and the metrics of all nodes in one place, also on a cluster of 2 or 3 nodes. A collector is not necessary: without KINEDB_LOG_SINK, each node writes its log lines to its console, and SHOW METRICS on each node gives its counters.

KINEDB_LOG_SINK=ws://10.0.0.9:4820 \
KINEDB_LOG_SINK_USER=collector KINEDB_LOG_SINK_PASSWORD='the-collector-password' \
  ./kinedb --port 4820 --data-dir /var/lib/kinedb

• Start the collector without KINEDB_LOG_SINK. Otherwise it sends its own logs to itself.
• KINEDB_LOG_SINK_PASSWORD is the password at the collector, not at this node. Without it, the node logs in to nothing, and a collector that needs a login refuses the data. Without KINEDB_LOG_SINK_USER, the user is root.
• The node makes two tables on the collector, with an index on time:
  • logs (id, nodeid, nodename, seq, time, level, target, msg): one row for each log event.
  • metrics (id, nodeid, nodename, time, scope, name, value): every 2 seconds, the memory users, the Raft state of each shard, reads and writes per second, and CPU use.
• The node deletes old rows from metrics. On the first send after it starts, and then every 10 minutes, it sends DELETE FROM metrics WHERE time < <now - retention>. The retention is KINEDB_METRICS_RETENTION_SECS, 7 days by default; 0 keeps all rows. metrics_drain.prunes_total counts these deletes, and metrics_drain.prune_errors_total counts the deletes that the node could not send. The logs table has no retention yet.
• Use a collector user that is not root. See The collector user.
• With the sink set, the console of the node shows only warn and error lines. The info and debug lines go only to the collector. The node prints one banner at the start that says this, and how to query the collector.

When the collector is not reachable, the node prints a warning and tries again: every second for the first 10 attempts, then at a longer interval up to 30 seconds. This is the warning when the collector port is closed (shortened here):

[kdtrace ts=1791376904957 server warn] [LOG_SINK_DOWN] sink=127.0.0.1:4969 reason=Internal: connect: Connection refused (os error 111) connect_failures_total=1 dropped_total=0 — this node cannot reach its collector, …

The node does not wait for the collector. When its queue of log events is full, it drops events and counts them. Read the state in SHOW METRICS:

log_sink.enabled                                      | 1
log_sink.connected                                    | 0
log_sink.connect_failures_total                       | 13
log_sink.down_warns_total                             | 1
log_sink.emitted_total                                | 39
log_sink.dropped_total                                | 0
metrics_drain.connected                               | 0
metrics_drain.connect_failures_total                  | 13

• log_sink.enabled is 1 when KINEDB_LOG_SINK is set.
• log_sink.connected and metrics_drain.connected are 1 while the connection is up. A node that sends no logs checks its collector connection once a second. So log_sink.connected goes to 0 about one second after the collector stops, also on a quiet node. log_sink.liveness_probes_total counts these checks.
• log_sink.dropped_total counts the log events that the node lost.
• drain.auth_rejected_total counts the logins that the collector refused.

The collector user

The collector user needs only three rights: INSERT on logs, and INSERT and DELETE on metrics. It needs no SELECT. It cannot create the tables: the setup revokes the default CREATE TABLE grant (who may create), and CREATE INDEX needs a superuser. So run these statements as root on the collector once, before you start the nodes:

CREATE TABLE logs (id TEXT, nodeid TEXT, nodename TEXT, seq INT, time TIMESTAMP, level TEXT, target TEXT, msg TEXT, PRIMARY KEY (id));
CREATE INDEX idx_logs_time ON logs (time);
CREATE TABLE metrics (id TEXT, nodeid TEXT, nodename TEXT, time TIMESTAMP, scope TEXT, name TEXT, value INT, PRIMARY KEY (id));
CREATE INDEX idx_metrics_name_time ON metrics (name, time);
CREATE INDEX idx_metrics_time ON metrics (time);
CREATE ROLE log_shipper;
GRANT INSERT ON logs TO ROLE log_shipper;
GRANT INSERT, DELETE ON metrics TO ROLE log_shipper;
CREATE USER collector PASSWORD 'the-collector-password';
GRANT ROLE log_shipper TO collector;
REVOKE CREATE TABLE ON DATABASE default FROM AUTHENTICATED;

Then start each node with KINEDB_LOG_SINK_USER=collector. At each connect, the node also sends the five CREATE statements. The collector refuses them for this user, and the node ignores the refusal. The test b2228_collector_user_minimum_grants runs this setup with 3 nodes that send to one collector.

When a right is missing, the collector refuses that statement, and the node loses the rows of that statement. These are the refusals:

The missing right	The refusal
INSERT on logs	permission denied: insert on 'logs' for user 'collector'
INSERT on metrics	permission denied: insert on 'metrics' for user 'collector'
DELETE on metrics	permission denied: delete on 'metrics' for user 'collector'

The node does not count a refused INSERT or DELETE, because it does not wait for the answer. So check the rows: as root, SELECT COUNT(*) FROM logs and SELECT COUNT(*) FROM metrics grow while the nodes run. To read the rows, use root or a user with SELECT on the two tables.