sqlite slow_threshold is set to 0 generating execution time exceeded alert at --log-level debug

[rngadam]

1.0.0-9-gc7c1993a4

Example (at debug level):

scripts/run_docker provision --log-level debug --wallet-type askar --wallet-name $(whoami) --wallet-key mysecretkey --endpoint http://localhost:8080 --no-ledger

results in:

2024-08-21 12:39:07,714 aries_askar.native.sqlx.query DEBUG     /cargo/registry/src/index.crates.io-6f17d22bba15001f/sqlx-core-0.7.3/src/logger.rs:120 | slow statement: execution time exceeded alert threshold summary="DELETE FROM config WHERE …" db.statement="\n\nDELETE FROM\n  config\nWHERE\n  0\n" rows_affected=0 rows_returned=0 elapsed=25.039µs slow_threshold=0ns
2024-08-21 12:39:07,714 aries_askar.native.aries_askar.ffi.store DEBUG  src/ffi/store.rs:643 | Started session SessionHandle(1) on store StoreHandle(1) (txn: true)
2024-08-21 12:39:07,714 aries_askar.native.sqlx.query DEBUG     /cargo/registry/src/index.crates.io-6f17d22bba15001f/sqlx-core-0.7.3/src/logger.rs:120 | slow statement: execution time exceeded alert threshold summary="SELECT COUNT(*) FROM profiles …" db.statement="\n\nSELECT\n  COUNT(*)\nFROM\n  profiles\nWHERE\n  id = $1\n" rows_affected=0 rows_returned=1 elapsed=25.96µs slow_threshold=0ns
2024-08-21 12:39:07,722 aries_askar.native.sqlx.query DEBUG     /cargo/registry/src/index.crates.io-6f17d22bba15001f/sqlx-core-0.7.3/src/logger.rs:120 | slow statement: execution time exceeded alert threshold summary="SELECT i.id, i.value, (SELECT …" db.statement="\n\nSELECT\n  i.id,\n  i.value,\n  (\n    SELECT\n      GROUP_CONCAT(\n        it.plaintext || ':' || HEX(it.name) || ':' || HEX(it.value)\n      )\n    FROM\n      items_tags it\n    WHERE\n      it.item_id = i.id\n  ) AS tags\nFROM\n  items i\nWHERE\n  i.profile_id = ?1\n  AND i.kind = ?2\n  AND i.category = ?3\n  AND i.name = ?4\n  AND (\n    i.expiry IS NULL\n    OR DATETIME(i.expiry) > DATETIME('now')\n  )\n" rows_affected=0 rows_returned=0 elapsed=59.773µs slow_threshold=0ns
2024-08-21 12:39:07,722 aries_askar.native.sqlx.query DEBUG     /cargo/registry/src/index.crates.io-6f17d22bba15001f/sqlx-core-0.7.3/src/logger.rs:120 | slow statement: execution time exceeded alert threshold summary="SELECT i.id, i.kind, i.category, …" db.statement="\n\nSELECT\n  i.id,\n  i.kind,\n  i.category,\n  i.name,\n  i.value,\n  (\n    SELECT\n      GROUP_CONCAT(\n        it.plaintext || ':' || HEX(it.name) || ':' || HEX(it.value)\n      )\n    FROM\n      items_tags it\n    WHERE\n      it.item_id = i.id\n  ) AS tags\nFROM\n  items i\nWHERE\n  i.profile_id = ?1\n  AND (\n    i.kind = ?2\n    OR ?2 IS NULL\n  )\n  AND (\n    i.category = ?3\n    OR ?3 IS NULL\n  )\n  AND (\n    i.expiry IS NULL\n    OR DATETIME(i.expiry) > DATETIME('now')\n  )\n" rows_affected=0 rows_returned=0 elapsed=58.314µs slow_threshold=0ns
2024-08-21 12:39:07,723 aries_askar.native.sqlx.query DEBUG     /cargo/registry/src/index.crates.io-6f17d22bba15001f/sqlx-core-0.7.3/src/logger.rs:120 | slow statement: execution time exceeded alert threshold summary="INSERT OR IGNORE INTO …" db.statement="\n\nINSERT\n  OR IGNORE INTO items (profile_id, kind, category, name, value, expiry)\nVALUES\n  (?1, ?2, ?3, ?4, ?5, ?6)\n" rows_affected=1 rows_returned=0 elapsed=29.049µs slow_threshold=0ns

This would probably be more helpful with a reasonable threshold (100ms), possibly logging at a higher log level.