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.

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

[docdb][ysql] Reuse iterators during txn conflict resolution #3521

Closed
bmatican opened this issue Feb 1, 2020 · 0 comments
Closed

[docdb][ysql] Reuse iterators during txn conflict resolution #3521

bmatican opened this issue Feb 1, 2020 · 0 comments
Assignees
Labels
area/docdb YugabyteDB core features area/ysql Yugabyte SQL (YSQL)

Comments

@bmatican
Copy link
Contributor

bmatican commented Feb 1, 2020

Did some recent tests with @d-uspenskiy 's upcoming ysql-side batching optimization, using:

java -jar yb-sample-apps-dl-batch.jar --workload SqlDataLoad --nodes $NODES --num_threads_write 27 --num_value_columns 128 --num_foreign_keys 1 --num_indexes 2 --batch_size 100 --num_unique_keys 100000000

This workload is doing batching of 100 inserts at a time, at the YSQL layer, but also in a schema with 128 columns.

When doing a perf run, observed the following

Screen Shot 2020-01-31 at 4 49 13 PM

While the perf tree is expanded quite a bit, I assume the problem is likely that we're spending that much time creating rocksdb iterators in the first place.

Doing some code digging, @ndeodhar pointed out that we have this aptly described TODO in src/yb/docdb/conflict_resolution.cc:

      // TODO(dtxn) reuse iterator
      auto value_iter = CreateRocksDBIterator(
          resolver->doc_db().regular,
          resolver->doc_db().key_bounds,
          BloomFilterMode::USE_BLOOM_FILTER,
          key_slice,
          rocksdb::kDefaultQueryId);

This seems like it is being executed over every row in the batch and over every column in the row.

cc @spolitov @mbautin

@bmatican bmatican added area/ysql Yugabyte SQL (YSQL) area/docdb YugabyteDB core features labels Feb 1, 2020
@ndeodhar ndeodhar assigned d-uspenskiy and unassigned bmatican and ndeodhar Feb 3, 2020
d-uspenskiy added a commit that referenced this issue Mar 17, 2020
Summary:
While checking transaction conflicts lots of intent can be processed.
Some of them may have keys with same DocKeyHash value. In this case these intents may use same iterator with bloom filter.
To reuse latest created iterator intents are processed in ascending key order.
For this purpose all keys are placed into `std::map` before processing.
Also this behavior guaranties that each weak intent will be processed only once (there can be multiple weak intents with same key).

The following workload on `--rf 1` cluster was used to estimate performance:

```
java -jar ./target/yb-sample-apps.jar --workload SqlDataLoad --nodes 127.0.0.1:5433 --num_threads_write 20 --num_value_columns 128 --num_foreign_keys 0 --num_indexes 1 --batch_size 30 --num_unique_keys 100000000
```

Before the change `yb::docdb::ResolveTransactionConflicts` function took `44.01%`:

```
-   44.01%     0.00%  rpc_tp_TabletSe  libyb_docdb.so                  [.] yb::docdb::ResolveTransactionConflicts                           ▒
   - 44.01% yb::docdb::ResolveTransactionConflicts                                                                                          ▒
      - 43.90% yb::docdb::(anonymous namespace)::TransactionConflictResolverContext::ReadConflicts                                          ▒
         - 43.24% yb::docdb::EnumerateIntents                                                                                               ▒
            - 27.32% boost::detail::function::function_obj_invoker4<std::_Bind<yb::Status (yb::docdb::(anonymous namespace)::TransactionConf▒
               - 27.21% yb::docdb::(anonymous namespace)::TransactionConflictResolverContext::ProcessIntent                                 ▒
                  + 15.86% yb::docdb::CreateRocksDBIterator                                                                                 ▒
                  + 6.39% yb::docdb::(anonymous namespace)::ConflictResolver::ReadIntentConflicts                                           ▒
                  + 3.97% yb::docdb::BoundedRocksDbIterator::Seek                                                                           ▒
                    0.50% rocksdb::ArenaWrappedDBIter::~ArenaWrappedDBIter                                                                  ▒
            + 15.64% yb::docdb::(anonymous namespace)::EnumerateWeakIntents
```

After the change it takes `19.42%`:

```
-   19.42%     0.00%  rpc_tp_TabletSe  libyb_docdb.so                  [.] yb::docdb::ResolveTransactionConflicts                                                                    ▒
   - 19.42% yb::docdb::ResolveTransactionConflicts                                                                                                                                   ▒
      - 19.22% yb::docdb::(anonymous namespace)::TransactionConflictResolverContext::ReadConflicts                                                                                   ▒
         + 5.31% yb::docdb::EnumerateIntents                                                                                                                                         ▒
         + 5.11% yb::docdb::(anonymous namespace)::ConflictResolver::ReadIntentConflicts                                                                                             ▒
         + 4.74% yb::docdb::BoundedRocksDbIterator::Seek                                                                                                                             ▒
         + 1.60% yb::docdb::DocKey::DecodeFrom                                                                                                                                       ▒
           0.55% yb::docdb::PgsqlWriteOperation::GetDocPaths
```

Also before the change  total ops processed in 120 secs is about `139k`

```
123059 [Thread-0] INFO com.yugabyte.sample.common.metrics.MetricsTracker  - Read: 0.00 ops/sec (0.00 ms/op), 0 total ops  |  Write: 551.96 ops/sec (732.56 ms/op), 138990 total ops  |  Uptime: 120020 ms |
```

After the change it is about  `168k` ops

```
122826 [Thread-0] INFO com.yugabyte.sample.common.metrics.MetricsTracker  - Read: 0.00 ops/sec (0.00 ms/op), 0 total ops  |  Write: 1235.91 ops/sec (438.44 ms/op), 168630 total ops  |  Uptime: 120013 ms |
```

Test Plan: Jenkins

Reviewers: timur, jason, sergei, mikhail

Reviewed By: sergei, mikhail

Subscribers: bogdan, neha, kannan, ybase

Differential Revision: https://phabricator.dev.yugabyte.com/D7921
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/docdb YugabyteDB core features area/ysql Yugabyte SQL (YSQL)
Projects
None yet
Development

No branches or pull requests

3 participants