Skip to content

Only log read only queries if they take more than 100ms#2672

Merged
danieldoglas merged 1 commit into
mainfrom
dsilva_logOnlySlowQueries
Jul 9, 2026
Merged

Only log read only queries if they take more than 100ms#2672
danieldoglas merged 1 commit into
mainfrom
dsilva_logOnlySlowQueries

Conversation

@danieldoglas

@danieldoglas danieldoglas commented Jul 7, 2026

Copy link
Copy Markdown
Contributor

Details

Filter log so we only log transactions that took more than 100ms

Fixed Issues

Fixes https://github.com/Expensify/Expensify/issues/655406

Tests

N/A


Internal Testing Reminder: when changing bedrock, please compile auth against your new changes

@chatgpt-codex-connector chatgpt-codex-connector Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: 326c729342

ℹ️ About Codex in GitHub

Codex has been enabled to automatically review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

When you sign up for Codex through ChatGPT, Codex can also answer questions or update the PR, like "@codex address that feedback".

Comment thread sqlitecluster/SQLite.cpp
// If we're not inside a transaction, this doesn't get added to our normal transaction timing.
if (!_insideTransaction) {
// This log line will happen a lot. Let's log only when it takes more than 100ms to complete.
if (!_insideTransaction && _readElapsed > 100'000) {

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2 Badge Compare the current read duration, not the cumulative total

For autocommit reads, _readElapsed accumulates across calls and is only reset when an explicit transaction starts, while the logged totalTransactionElapsed value is the current timeSpent. Once enough fast reads outside a transaction cumulatively exceed 100ms, every later read on that handle will still emit this noisy log even if it only took a few microseconds, so the new filter does not actually limit logging to slow auto-transactions; this condition should gate on timeSpent instead.

Useful? React with 👍 / 👎.

@danieldoglas
danieldoglas merged commit 533f109 into main Jul 9, 2026
8 checks passed
@danieldoglas
danieldoglas deleted the dsilva_logOnlySlowQueries branch July 9, 2026 01:45
Comment thread sqlitecluster/SQLite.cpp
// If we're not inside a transaction, this doesn't get added to our normal transaction timing.
if (!_insideTransaction) {
// This log line will happen a lot. Let's log only when it takes more than 100ms to complete.
if (!_insideTransaction && _readElapsed > 100'000) {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I am seeing a lot of

Read with auto-transaction timing info ~~ totalTransactionElapsed: '0' command: 'OpenApp'

Maybe we should update the if to also check timeSpent?

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

+1

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I used the wrong var 😬
#2683

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants