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

Observing high contention in yb::server::HybridClock::Now() #48

Closed
mchang31415 opened this issue Feb 9, 2018 · 4 comments
Closed

Observing high contention in yb::server::HybridClock::Now() #48

mchang31415 opened this issue Feb 9, 2018 · 4 comments
Assignees
@bmatican

Comments

@mchang31415
Copy link

mchang31415 commented Feb 9, 2018 •
edited
Loading

Grabbed the following from http://{hostname}:9000/pprof/contention
In the same workload as #47, seeing high number of cpu cycles spent in HybridClock::Now()
Looks like there might be a software bottleneck that could be optimized.

-----------

3515904	323 @ 00007f57a6271e60 00007f57a984612d 00007f57abe24671 00007f57abe25df5 00007f57abdc8a3f 00007f57ac0e0df0 00007f57ab166dc7 00007f57a7bf1d67 00007f57a7bf41b9 00007f57a6284b46 00007f57a251d314 00007f57a225ebed 0000000000000000
    @     0x7f57a6271e5f  SubmitSpinLockProfileData (yb/util/spinlock_profiling.cc:238)
    @     0x7f57a984612c  base::SpinLock::Unlock() (yb/gutil/spinlock.h:120)
    @     0x7f57a984612c  yb::simple_spinlock::unlock() (yb/util/locks.h:65)
    @     0x7f57a984612c  std::lock_guard<yb::simple_spinlock>::~lock_guard() (/home/centos/.linuxbrew-yb-build/Cellar/gcc/5.3.0/include/c++/5.3.0/mutex:383)
    @     0x7f57a984612c  yb::server::HybridClock::Now() (yb/server/hybrid_clock.cc:218)
    @     0x7f57abe24670  operator() (yb/tablet/mvcc.cc:173)
    @     0x7f57abe24670  wait<yb::tablet::MvccManager::DoGetSafeTime(yb::HybridTime, yb::MonoTime, yb::HybridTime, std::unique_lock<std::mutex>*) const::<lambda()> > (/home/centos/.linuxbrew-yb-build/Cellar/gcc/5.3.0/include/c++/5.3.0/condition_variable:97)
    @     0x7f57abe24670  yb::tablet::MvccManager::DoGetSafeTime(yb::HybridTime, yb::MonoTime, yb::HybridTime, std::unique_lock<std::mutex>*) const (yb/tablet/mvcc.cc:190)
    @     0x7f57abe25df4  yb::tablet::MvccManager::SafeTime(yb::HybridTime, yb::MonoTime, yb::HybridTime) const (yb/tablet/mvcc.cc:161)
    @     0x7f57abdc8a3e  yb::tablet::Tablet::DoGetSafeTime(yb::StronglyTypedBool<yb::tablet::RequireLease_Tag>, yb::HybridTime, yb::MonoTime) const (yb/tablet/tablet.cc:1209)
    @     0x7f57ac0e0def  yb::tablet::AbstractTablet::SafeTime(yb::StronglyTypedBool<yb::tablet::RequireLease_Tag>, yb::HybridTime, yb::MonoTime) const (yb/tablet/abstract_tablet.h:72)
    @     0x7f57ac0e0def  yb::tserver::TabletServiceImpl::Read(yb::tserver::ReadRequestPB const*, yb::tserver::ReadResponsePB*, yb::rpc::RpcContext) (yb/tserver/tablet_service.cc:813)
    @     0x7f57ab166dc6  yb::tserver::TabletServerServiceIf::Handle(std::shared_ptr<yb::rpc::InboundCall>) (yb/tserver/tserver_service.service.cc:135)
    @     0x7f57a7bf1d66  yb::rpc::ServicePoolImpl::Handle(std::shared_ptr<yb::rpc::InboundCall>) (yb/rpc/service_pool.cc:191)
    @     0x7f57a7bf1d66  Run (yb/rpc/service_pool.cc:206)
    @     0x7f57a7bf1d66  Run (yb/rpc/tasks_pool.h:70)
    @     0x7f57a7bf41b8  Execute (yb/rpc/thread_pool.cc:98)
    @     0x7f57a6284b45  std::function<void ()>::operator()() const (/home/centos/.linuxbrew-yb-build/Cellar/gcc/5.3.0/include/c++/5.3.0/functional:2271)
    @     0x7f57a6284b45  yb::Thread::SuperviseThread(void*) (yb/util/thread.cc:602)

Full output here:
contention.txt
@kmuthukk
Copy link
Collaborator

kmuthukk commented Feb 9, 2018

@bmatican : assigning to you.

From the "contention.txt" file that was uploaded, it seems that two most prominent stacks in terms of spinlock content have HybridClock::Now(), are as follows:

Stack 1:

3515904	323 @ 00007f57a6271e60 00007f57a984612d 00007f57abe24671 00007f57abe25df5 00007f57abdc8a3f 00007f57ac0e0df0 00007f57ab166dc7 00007f57a7bf1d67 00007f57a7bf41b9 00007f57a6284b46 00007f57a251d314 00007f57a225ebed 0000000000000000
    @     0x7f57a6271e5f  SubmitSpinLockProfileData (yb/util/spinlock_profiling.cc:238)
    @     0x7f57a984612c  base::SpinLock::Unlock() (yb/gutil/spinlock.h:120)
    @     0x7f57a984612c  yb::simple_spinlock::unlock() (yb/util/locks.h:65)
    @     0x7f57a984612c  std::lock_guard<yb::simple_spinlock>::~lock_guard() (/home/centos/.linuxbrew-yb-build/Cellar/gcc/5.3.0/include/c++/5.3.0/mutex:383)
    @     0x7f57a984612c  yb::server::HybridClock::Now() (yb/server/hybrid_clock.cc:218)
    @     0x7f57abe24670  operator() (yb/tablet/mvcc.cc:173)
    @     0x7f57abe24670  wait<yb::tablet::MvccManager::DoGetSafeTime(yb::HybridTime, yb::MonoTime, yb::HybridTime, std::unique_lock<std::mutex>*) const::<lambda()> > (/home/centos/.linuxbrew-yb-build/Cellar/gcc/5.3.0/include/c++/5.3.0/condition_variable:97)
    @     0x7f57abe24670  yb::tablet::MvccManager::DoGetSafeTime(yb::HybridTime, yb::MonoTime, yb::HybridTime, std::unique_lock<std::mutex>*) const (yb/tablet/mvcc.cc:190)
    @     0x7f57abe25df4  yb::tablet::MvccManager::SafeTime(yb::HybridTime, yb::MonoTime, yb::HybridTime) const (yb/tablet/mvcc.cc:161)
    @     0x7f57abdc8a3e  yb::tablet::Tablet::DoGetSafeTime(yb::StronglyTypedBool<yb::tablet::RequireLease_Tag>, yb::HybridTime, yb::MonoTime) const (yb/tablet/tablet.cc:1209)
    @     0x7f57ac0e0def  yb::tablet::AbstractTablet::SafeTime(yb::StronglyTypedBool<yb::tablet::RequireLease_Tag>, yb::HybridTime, yb::MonoTime) const (yb/tablet/abstract_tablet.h:72)
    @     0x7f57ac0e0def  yb::tserver::TabletServiceImpl::Read(yb::tserver::ReadRequestPB const*, yb::tserver::ReadResponsePB*, yb::rpc::RpcContext) (yb/tserver/tablet_service.cc:813)

Stack 2:

1722112	100 @ 00007f57a6271e60 00007f57a984612d 00007f57ac0e0c44 00007f57ab166dc7 00007f57a7bf1d67 00007f57a7bf41b9 00007f57a6284b46 00007f57a251d314 00007f57a225ebed 0000000000000000
    @     0x7f57a6271e5f  SubmitSpinLockProfileData (yb/util/spinlock_profiling.cc:238)
    @     0x7f57a984612c  base::SpinLock::Unlock() (yb/gutil/spinlock.h:120)
    @     0x7f57a984612c  yb::simple_spinlock::unlock() (yb/util/locks.h:65)
    @     0x7f57a984612c  std::lock_guard<yb::simple_spinlock>::~lock_guard() (/home/centos/.linuxbrew-yb-build/Cellar/gcc/5.3.0/include/c++/5.3.0/mutex:383)
    @     0x7f57a984612c  yb::server::HybridClock::Now() (yb/server/hybrid_clock.cc:218)
    @     0x7f57ac0e0c43  yb::tserver::RpcOperationCompletionCallback<yb::tserver::ReadResponsePB>::OperationCompleted() (yb/tserver/service_util.h:146)
    @     0x7f57ac0e0c43  yb::tserver::TabletServiceImpl::Read(yb::tserver::ReadRequestPB const*, yb::tserver::ReadResponsePB*, yb::rpc::RpcContext) (yb/tserver/tablet_service.cc:878)
    @     0x7f57ab166dc6  yb::tserver::TabletServerServiceIf::Handle(std::shared_ptr<yb::rpc::InboundCall>) (yb/tserver/tserver_service.service.cc:135)
    @     0x7f57a7bf1d66  yb::rpc::ServicePoolImpl::Handle(std::shared_ptr<yb::rpc::InboundCall>) (yb/rpc/service_pool.cc:191)
    @     0x7f57a7bf1d66  Run (yb/rpc/service_pool.cc:206)
    @     0x7f57a7bf1d66  Run (yb/rpc/tasks_pool.h:70)
    @     0x7f57a7bf41b8  Execute (yb/rpc/thread_pool.cc:98)
    @     0x7f57a6284b45  std::function<void ()>::operator()() const (/home/centos/.linuxbrew-yb-build/Cellar/gcc/5.3.0/include/c++/5.3.0/functional:2271)
    @     0x7f57a6284b45  yb::Thread::SuperviseThread(void*) (yb/util/thread.cc:602)

@kmuthukk
Copy link
Collaborator

kmuthukk commented Feb 9, 2018

@mchang31415 : can you please share how many cores per yugabyte node in your setup?

@kmuthukk
Copy link
Collaborator

@bmatican - can we close out this issue with a link to the relevant commit?

@bmatican
Copy link
Contributor

fixed in c62d02a

mbautin pushed a commit that referenced this issue Jun 20, 2019
#48 - new top logo needs to be auto-minimized to the YB tile for smal…
0e7f431 
…ler screens #48
mbautin pushed a commit that referenced this issue Jun 20, 2019
@schoudhury
Merge pull request #50 from YugaByte/logoresponsive
2dad982 
#48 - new top logo needs to be auto-minimized to the YB tile for smal…
@sushantrmishra sushantrmishra mentioned this issue May 25, 2022
Closed
jasonyb pushed a commit that referenced this issue Jun 11, 2024
@ibrarahmad
Issue (#48): Fix typos in the code.
db01ed5 
Jira: PG-133
abhinab-yb pushed a commit to abhinab-yb/yugabyte-db that referenced this issue Nov 14, 2024
@rishabhtanwar29 @abhinab-yb
BABEL: Store create date in pg_class reloptions (yugabyte#48)
76a658f 
Engine
Allow new bbf_rel_create_date reloption in parser which will be
used to store create_date for tables.

Extensions
Added support for sysobjects.crdate (create_date) for all user
defined tables, views, procedures, functions, triggers and table types.

We will store create date for different objects as follows:

Tables and Table-types: Store create date in pg_class.reloptions
column in bbf_rel_create_date=timestamp format.
Functions, procedures and triggers: Add new columns as
create_date and modify_date in babelfish_function_ext catalog table
to store creation timestamp of particular object. Currently
we will fill same timestamp in both create_date and modify_date
columns.
views: Add new columns as create_date and modify_date in
babelfish_view_def catalog table to store creation timestamp of particular
object.
Introduced a helper function babelfish_get_pltsql_function_signature
which returns signature of a function which is being used along with
function name to get primary key join for babelfish_function_ext table.

Fixed function is_table_type to correctly identify if a table is T-SQL table
type or not using reverse dependency between type and table.

Test description
Use case based/ MVU/mVU tests: Added normal jdbc test (BABEL-3010-vu-*) in
prepare-verify-cleanup format so that it can also run in latest -> latest
upgrade path. This only tests crdate and refdate columns since there are
already existing tests for other columns. Additionally, added MVU test
from 13.6 to latest and mVU test 14.5 to latest in their respective directories.
Fixed various JDBC tests to remove the output of create_date and
modify_date since the date will change with each test run. Following tests
are modified:
BABEL-3267
sys-triggers
sys-trigger_events
sys-table_types
BABEL-TABLEOPTIONS
BABEL-2877
BABEL-1566
Boundary conditions: N/A
Arbitrary inputs: View correctly returns NULL for existing objects.
Negative test scenarios: N/A
Performance tests: Performance looks intact for all modified views (no explicit perf testing).
Tooling impact: None
Client tests: JDBC tests are sufficient, no TDS side changes.

Signed-off-by: Rishabh Tanwar <ritanwar@amazon.com>
Co-authored-by: Rishabh Tanwar <ritanwar@amazon.com>
(cherry picked from commit f0f4d49d0c12f06da46c8c1c78d7d16bfcbf8b12)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@bmatican bmatican

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@bmatican @mchang31415 @kmuthukk