Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

test: profile wallet sqlite database operations #3451

Merged
merged 2 commits into from
Oct 14, 2021
Merged

test: profile wallet sqlite database operations #3451

merged 2 commits into from
Oct 14, 2021

Conversation

hansieodendaal
Copy link
Contributor

Description

Profiled all wallet SQLite database read and write operations by virtue of easily identifiable log entries.

Motivation and Context

We currently have lots of database contention, resulting in poor system-level performance in many instances and also impacting the console wallet's TUI. Providing insightful logging was therefore necessary.

Part of this investigation focussed on poor metadata update performance. The log extracts below clearly shows that it is due to database contention and not database query performance:

sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 9 = 9 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 6333 + db_op 9 = 6342 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 6965 + db_op 8 = 6974 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 104 + db_op 8 = 112 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 44 + db_op 7 = 52 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 177 + db_op 8 = 185 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 176 + db_op 8 = 185 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 5 + db_op 8 = 13 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 178 + db_op 8 = 186 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 129 + db_op 12 = 141 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 226 + db_op 8 = 234 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 129 + db_op 8 = 137 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 140 + db_op 11 = 152 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 201 + db_op 8 = 209 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 125 + db_op 7 = 133 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 170 + db_op 8 = 178 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 230 + db_op 8 = 238 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 232 + db_op 9 = 242 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 192 + db_op 8 = 200 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 18272 + db_op 8 = 18280 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 210 + db_op 8 = 218 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 300 + db_op 7 = 308 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 283 + db_op 7 = 291 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 287 + db_op 8 = 295 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 278 + db_op 9 = 288 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 248 + db_op 10 = 259 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 18892 + db_op 7 = 18900 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 341 + db_op 8 = 349 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 366 + db_op 8 = 374 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 297 + db_op 7 = 304 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 10 = 10 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 24276 + db_op 11 = 24287 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 15397 + db_op 11 = 15409 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 11303 + db_op 8 = 11311 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 193 + db_op 8 = 201 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 8 = 8 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 8 = 8 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 8 = 8 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 8 = 8 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 12 = 12 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 8 = 8 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 14 = 14 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 197 + db_op 11 = 208 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 124 + db_op 8 = 132 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 251 + db_op 18 = 270 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 8 = 8 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 7 = 7 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 0 + db_op 9 = 9 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 4637 + db_op 8 = 4645 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 373 + db_op 7 = 381 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 420 + db_op 7 = 428 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 416 + db_op 8 = 424 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 398 + db_op 7 = 405 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 321 + db_op 7 = 329 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 328 + db_op 7 = 336 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 19323 + db_op 8 = 19332 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 549 + db_op 8 = 557 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 554 + db_op 8 = 562 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 443 + db_op 8 = 452 ms
sqlite profile - insert_key_value_pair 'BaseNodeChainMetadata': lock 489 + db_op 8 = 497 ms

How Has This Been Tested?

System-level tests

@hansieodendaal
Profile wallet sqlite database operations
7d63add 
Profiled all wallet sqlite database read and write operations
by virtue of easily identifyable log entries.
philipr-za
philipr-za approved these changes Oct 14, 2021
View reviewed changes
Copy link
Contributor

@philipr-za philipr-za left a comment

Choose a reason for hiding this comment

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

Looks good, in the future once these problems are solved we will need to remember to clean these up.

@aviator-app aviator-app bot merged commit b02dd1d into tari-project:development Oct 14, 2021
@hansieodendaal hansieodendaal deleted the ho_sqlite_profiling branch October 14, 2021 10:19
sdbondi added a commit to sdbondi/tari that referenced this pull request Oct 15, 2021
@sdbondi
Merge branch 'development' into core-output-features-canonical-encoding
e7c35dd 
* development:
  fix: add display_currency_decimal method (tari-project#3445)
  fix: add sanity checks to prepare_new_block (tari-project#3448)
  test: profile wallet sqlite database operations (tari-project#3451)
  test: create cucumber test directory if necessary (tari-project#3452)
  chore: improve cucumber tags and run time speed (tari-project#3439)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@philipr-za philipr-za philipr-za approved these changes

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
2 participants
@hansieodendaal @philipr-za