|
| 1 | +--- |
| 2 | +title: "SQLite Profiling" |
| 3 | +description: "Profile SQLite statements and transactions in Rivet Actors using bounded metrics and sampled diagnostics." |
| 4 | +skill: true |
| 5 | +--- |
| 6 | + |
| 7 | +Profiling helps you find slow queries, transaction contention, and unnecessary storage activity. |
| 8 | + |
| 9 | +## Logging slow queries |
| 10 | + |
| 11 | +RivetKit logs slow or failed SQLite statements and transactions. Logs include the fingerprint, outcome, timing breakdown, and storage activity; statement logs also include rows and bytes, while transaction logs include the statement count. |
| 12 | + |
| 13 | +Search actor logs for `sampled SQLite operation profile` for statements or `sampled SQLite transaction profile` for transactions. |
| 14 | + |
| 15 | +## Identify operations |
| 16 | + |
| 17 | +### Transaction names |
| 18 | + |
| 19 | +Transaction names provide a stable identity for profiling transactions. Use a short, static name to correlate metrics. |
| 20 | + |
| 21 | +Pass `{ name: "complete-order" }` as the options argument to `db.transaction()`. |
| 22 | + |
| 23 | +Without a name, RivetKit falls back to a fingerprint of the transaction's statement sequence. Branches and different loop counts can therefore produce separate fingerprints. |
| 24 | + |
| 25 | +### Statement fingerprints |
| 26 | + |
| 27 | +RivetKit hashes each SQL statement exactly as provided. The fingerprint groups metrics without putting SQL text in a Prometheus label. |
| 28 | + |
| 29 | +For example, repeated `SELECT * FROM orders WHERE id = ?` calls share one fingerprint regardless of the bound ID. |
| 30 | + |
| 31 | +### Find the SQL for a fingerprint |
| 32 | + |
| 33 | +RivetKit logs the SQL statement or transaction name for each tracked fingerprint. |
| 34 | + |
| 35 | +For example, suppose a Prometheus result contains `fingerprint="select-a1b2c3d4e5f60718"`: |
| 36 | + |
| 37 | +1. Copy the fingerprint: `select-a1b2c3d4e5f60718`. |
| 38 | +2. Search the actor logs for `sqlite fingerprint catalog` and `select-a1b2c3d4e5f60718`. |
| 39 | +3. Read `identity` from the matching log line: |
| 40 | + |
| 41 | + ```text |
| 42 | + sqlite fingerprint catalog fingerprint="select-a1b2c3d4e5f60718" identity="SELECT value FROM items WHERE id = ?" |
| 43 | + ``` |
| 44 | + |
| 45 | +## Query metrics |
| 46 | + |
| 47 | +Collect [Prometheus metrics from each worker](/actors/self-host/workers/prometheus-metrics/) to use the queries below. |
| 48 | + |
| 49 | +### Slowest statements and transactions |
| 50 | + |
| 51 | +Find the statements and transactions with the highest 95th-percentile latency. |
| 52 | + |
| 53 | +```promql |
| 54 | +histogram_quantile( |
| 55 | + 0.95, |
| 56 | + sum by (le, actor_name, type, fingerprint) ( |
| 57 | + rate(rivet_rivetkit_sqlite_duration_seconds_bucket[5m]) |
| 58 | + ) |
| 59 | +) |
| 60 | +``` |
| 61 | + |
| 62 | +### Slowest latency phases |
| 63 | + |
| 64 | +Break down slow operations to see whether they spend time waiting, executing SQL, or accessing storage. |
| 65 | + |
| 66 | +- `transaction_wait`: waiting for another transaction on the actor to finish. |
| 67 | +- `worker_wait`: waiting for earlier SQLite work on the actor to finish. |
| 68 | +- `storage`: loading or saving SQLite data. |
| 69 | +- `local_work`: executing SQL and preparing results, excluding storage time. |
| 70 | +- `application_time`: time the transaction stays open between SQL calls. |
| 71 | +- `commit`: saving changes at the end of a transaction. |
| 72 | + |
| 73 | +```promql |
| 74 | +histogram_quantile( |
| 75 | + 0.95, |
| 76 | + sum by (le, actor_name, type, fingerprint, phase) ( |
| 77 | + rate(rivet_rivetkit_sqlite_phase_duration_seconds_bucket[5m]) |
| 78 | + ) |
| 79 | +) |
| 80 | +``` |
| 81 | + |
| 82 | +### Non-success outcomes |
| 83 | + |
| 84 | +Find statements and transactions that fail, roll back, expire, or lose their connection. |
| 85 | + |
| 86 | +```promql |
| 87 | +sum by (actor_name, type, fingerprint, outcome) ( |
| 88 | + rate(rivet_rivetkit_sqlite_outcome_total{outcome!="success"}[5m]) |
| 89 | +) |
| 90 | +``` |
| 91 | + |
| 92 | +### Transaction contention |
| 93 | + |
| 94 | +See whether transactions are waiting for other transactions on the same actor. |
| 95 | + |
| 96 | +```promql |
| 97 | +max by (actor_name) ( |
| 98 | + max_over_time(rivet_rivetkit_sqlite_coordinator_queue_depth[5m]) |
| 99 | +) |
| 100 | +``` |
| 101 | + |
| 102 | +### Native worker saturation |
| 103 | + |
| 104 | +See whether SQLite operations are backing up on an actor. A sustained queue means work is arriving faster than SQLite can finish it, while `worker_inflight` shows how often SQLite is busy. |
| 105 | + |
| 106 | +```promql |
| 107 | +max by (actor_name) ( |
| 108 | + max_over_time(rivet_rivetkit_sqlite_worker_queue_depth[5m]) |
| 109 | +) |
| 110 | +``` |
| 111 | + |
| 112 | +```promql |
| 113 | +avg by (actor_name) ( |
| 114 | + avg_over_time(rivet_rivetkit_sqlite_worker_inflight[5m]) |
| 115 | +) |
| 116 | +``` |
| 117 | + |
| 118 | +### Transactions with the most statements |
| 119 | + |
| 120 | +Find transactions that execute many SQL statements before finishing. Large counts can identify loops or oversized units of work; use a static transaction name to keep its fingerprint stable. |
| 121 | + |
| 122 | +```promql |
| 123 | +histogram_quantile( |
| 124 | + 0.95, |
| 125 | + sum by (le, actor_name, fingerprint) ( |
| 126 | + rate(rivet_rivetkit_sqlite_transaction_statement_count_bucket[5m]) |
| 127 | + ) |
| 128 | +) |
| 129 | +``` |
| 130 | + |
| 131 | +### Average storage round trips per operation |
| 132 | + |
| 133 | +See how many times each operation contacts storage on average. High counts can indicate a missing index, a large scan, or ineffective prefetching. |
| 134 | + |
| 135 | +```promql |
| 136 | +sum by (actor_name, type, fingerprint) ( |
| 137 | + rate(rivet_rivetkit_sqlite_get_pages_round_trips_sum[5m]) |
| 138 | +) |
| 139 | +/ |
| 140 | +sum by (actor_name, type, fingerprint) ( |
| 141 | + rate(rivet_rivetkit_sqlite_get_pages_round_trips_count[5m]) |
| 142 | +) |
| 143 | +``` |
| 144 | + |
| 145 | +### Pages per physical storage request |
| 146 | + |
| 147 | +See how many pages each storage request asks for and returns. Compare `response_present` with `demand_requested` to find response amplification; `overflow_expansion_extra` shows overflow-chain reads, and `prefetch_requested` shows speculative reads. |
| 148 | + |
| 149 | +```promql |
| 150 | +sum by (actor_name, request_ordinal, page_kind) ( |
| 151 | + rate(rivet_rivetkit_sqlite_get_pages_pages_sum[5m]) |
| 152 | +) |
| 153 | +/ |
| 154 | +sum by (actor_name, request_ordinal, page_kind) ( |
| 155 | + rate(rivet_rivetkit_sqlite_get_pages_pages_count[5m]) |
| 156 | +) |
| 157 | +``` |
| 158 | + |
| 159 | +### Large storage responses |
| 160 | + |
| 161 | +Find storage requests that return unusually large amounts of SQLite data. |
| 162 | + |
| 163 | +```promql |
| 164 | +histogram_quantile( |
| 165 | + 0.95, |
| 166 | + sum by (le, actor_name, request_ordinal) ( |
| 167 | + rate(rivet_rivetkit_sqlite_get_pages_response_bytes_bucket[5m]) |
| 168 | + ) |
| 169 | +) |
| 170 | +``` |
| 171 | + |
| 172 | +### Missing response pages |
| 173 | + |
| 174 | +Find storage requests that could not return every requested page. |
| 175 | + |
| 176 | +```promql |
| 177 | +sum by (actor_name, request_ordinal) ( |
| 178 | + rate(rivet_rivetkit_sqlite_get_pages_missing_pages_total[5m]) |
| 179 | +) |
| 180 | +``` |
| 181 | + |
| 182 | +### SQLite page usage by kind |
| 183 | + |
| 184 | +Break down the pages used for each kind of SQLite activity. High page counts can indicate a missing index or a large scan. |
| 185 | + |
| 186 | +```promql |
| 187 | +sum by (actor_name, type, page_kind) ( |
| 188 | + rate(rivet_rivetkit_sqlite_local_pages_total[5m]) |
| 189 | +) |
| 190 | +``` |
| 191 | + |
| 192 | +### SQLite data volume by kind |
| 193 | + |
| 194 | +Compare bytes used by query parameters, results, storage reads, and writes. |
| 195 | + |
| 196 | +```promql |
| 197 | +sum by (actor_name, type, byte_kind) ( |
| 198 | + rate(rivet_rivetkit_sqlite_local_bytes_total[5m]) |
| 199 | +) |
| 200 | +``` |
| 201 | + |
| 202 | +## Configure profiling |
| 203 | + |
| 204 | +Profiling is enabled by default and most applications do not need to configure it. The entire profiling configuration surface is experimental and subject to change without notice. Set `profiling.slowOperationThresholdMs` or `profiling.baselineSampleRate` on the database provider when needed. |
| 205 | + |
| 206 | +Increase fingerprint limits only when `other` is hiding frequently repeated operations. Prometheus series remain allocated for the life of the process after admission. |
| 207 | + |
| 208 | +## Troubleshooting |
| 209 | + |
| 210 | +### Most results are `other` |
| 211 | + |
| 212 | +Fast statements initially appear under `other`, while overflow metrics show when a fingerprint limit was reached. Increase limits only for useful operations that repeat regularly. |
| 213 | + |
| 214 | +### Too many fingerprints |
| 215 | + |
| 216 | +Statement fingerprints use the exact query text. Keep formatting and query structure static, and pass dynamic values as bindings instead of constructing SQL strings. |
| 217 | + |
| 218 | +### Transactions are hard to identify |
| 219 | + |
| 220 | +Unnamed transactions are grouped by their statement sequence, which can vary across branches. Add a static `name` to each important transaction. |
| 221 | + |
| 222 | +### Storage activity is high |
| 223 | + |
| 224 | +Use the storage queries above to compare page counts, response bytes, and round trips by actor name. Large scans or missing indexes are common causes. |
| 225 | + |
| 226 | +### Diagnostics are missing |
| 227 | + |
| 228 | +Diagnostic events are sampled and bounded. Check `rivet_rivetkit_sqlite_event_dropped_total` for rate limiting or backpressure; aggregate Prometheus metrics continue reporting when events are dropped. |
| 229 | + |
| 230 | +### No profiling metrics appear |
| 231 | + |
| 232 | +Confirm profiling was not disabled in the database provider. Profiling currently applies to native actor-local SQLite, not remote or wasm SQLite. |
0 commit comments