trafficserver icon indicating copy to clipboard operation
trafficserver copied to clipboard

Add bcc tool to observe pthread trylock

Open masaori335 opened this issue 1 year ago • 1 comments

This is a bcc tool to check the pthread try lock, I talked at ATS Summit before.

masaori335 avatar Oct 02 '24 06:10 masaori335

Example output is below. We can see where the try-lock is failing. More details are in the later part of this slide. https://cwiki.apache.org/confluence/display/TS/Presentations+-+2022?preview=/211885742/235836401/tracing-userspace.pdf

thread 38875
        mutex [unknown] ::: wait time 0.00us ::: hold time 24692.07us ::: enter count 3051 ::: try-lock failure count 13693
                CacheVC::openReadStartHead(int, Event*)+0xd8 [traffic_server] (55e891616368)
                EThread::process_event(Event*, int)+0x276 [traffic_server] (55e89170b586)
                EThread::execute_regular()+0x33d [traffic_server] (55e89170bf0d)
                EThread::execute()+0x171 [traffic_server] (55e89170c361)
                spawn_thread_internal(void*)+0x55 [traffic_server] (55e89170a8a5)
                start_thread+0xc5 [libpthread-2.17.so] (7f1216cf8ea5)

        mutex [unknown] ::: wait time 0.00us ::: hold time 10263.61us ::: enter count 1372 ::: try-lock failure count 6294
                CacheVC::openReadClose(int, Event*)+0xab [traffic_server] (55e89161a1db)
                EThread::process_event(Event*, int)+0x276 [traffic_server] (55e89170b586)
                EThread::execute_regular()+0x33d [traffic_server] (55e89170bf0d)
                EThread::execute()+0x171 [traffic_server] (55e89170c361)
                spawn_thread_internal(void*)+0x55 [traffic_server] (55e89170a8a5)
                start_thread+0xc5 [libpthread-2.17.so] (7f1216cf8ea5)

        mutex [unknown] ::: wait time 0.00us ::: hold time 3041.71us ::: enter count 337 ::: try-lock failure count 1391
                Cache::open_read(Continuation*, ats::CryptoHash const*, HTTPHdr*, OverridableHttpConfigParams const*, CacheFragType, char const*, int)+0x10a [traffic_server] (55e89161845a)
                CacheProcessor::open_read(Continuation*, HttpCacheKey const*, HTTPHdr*, OverridableHttpConfigParams const*, long, CacheFragType)+0x27 [traffic_server] (55e8915fccf7)
                HttpCacheSM::open_read(HttpCacheKey const*, URL*, HTTPHdr*, OverridableHttpConfigParams const*, long)+0x9d [traffic_server] (55e89148b4cd)
                HttpSM::do_cache_lookup_and_read()+0x169 [traffic_server] (55e89147d929)
                HttpSM::set_next_state()+0x4d1 [traffic_server] (55e8914820f1)
                HttpSM::set_next_state()+0xb48 [traffic_server] (55e891482768)
                HttpSM::set_next_state()+0xa06 [traffic_server] (55e891482626)
                HttpSM::set_next_state()+0xb48 [traffic_server] (55e891482768)
                HttpSM::set_next_state()+0xb48 [traffic_server] (55e891482768)
                HttpSM::state_read_client_request_header(int, void*)+0xe8d [traffic_server] (55e89145eb7d)
                HttpSM::main_handler(int, void*)+0xe6 [traffic_server] (55e89145ccf6)
                HttpSM::state_add_to_list(int, void*)+0x1ef [traffic_server] (55e89145d0af)
                HttpSM::attach_client_session(ProxyTransaction*)+0x512 [traffic_server] (55e89145dca2)
                Http1ClientSession::new_transaction()+0x58 [traffic_server] (55e891443ef8)
                Http1ClientSession::state_keep_alive(int, void*)+0xa0 [traffic_server] (55e891443900)
                read_signal_and_update(int, UnixNetVConnection*)+0x1ed [traffic_server] (55e8916ead1d)
                UnixNetVConnection::net_read_io(NetHandler*, EThread*)+0x5ac [traffic_server] (55e8916e983c)
                NetHandler::process_ready_list()+0x32f [traffic_server] (55e8916d82af)
                NetHandler::waitForActivity(long)+0x6a4 [traffic_server] (55e8916d8dc4)
                non-virtual thunk to NetHandler::waitForActivity(long)+0xd [traffic_server] (55e8916d8e9d)
                EThread::execute_regular()+0x51f [traffic_server] (55e89170c0ef)
                EThread::execute()+0x171 [traffic_server] (55e89170c361)
                spawn_thread_internal(void*)+0x55 [traffic_server] (55e89170a8a5)
                start_thread+0xc5 [libpthread-2.17.so] (7f1216cf8ea5)

masaori335 avatar Oct 07 '24 22:10 masaori335