TSAN error at `Thread::get_hrtime`

[moonchen]

WARNING: ThreadSanitizer: data race (pid=741305)
  Write of size 8 at 0x55d6abb92a98 by thread T2 (mutexes: write M0):
    #0 Thread::get_hrtime_updated() /home/mo/work/trafficserver/iocore/eventsystem/./I_Thread.h:194:19 (traffic_server+0x6ce859) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #1 EThread::execute_regular() /home/mo/work/trafficserver/iocore/eventsystem/UnixEThread.cc:229:23 (traffic_server+0x6ce859)
    #2 EThread::execute() /home/mo/work/trafficserver/iocore/eventsystem/UnixEThread.cc:349:11 (traffic_server+0x6cf3e1) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #3 spawn_thread_internal(void*) /home/mo/work/trafficserver/iocore/eventsystem/Thread.cc:79:12 (traffic_server+0x6cc4f0) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)

  Previous read of size 8 at 0x55d6abb92a98 by thread T3:
    #0 Thread::get_hrtime() /home/mo/work/trafficserver/iocore/eventsystem/I_Thread.h:188:10 (traffic_server+0x65bbae) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #1 EThread::schedule_every(Continuation*, long, int, void*) /home/mo/work/trafficserver/iocore/eventsystem/P_UnixEThread.h:95:35 (traffic_server+0x65bbae)
    #2 initialize_thread_for_net(EThread*) /home/mo/work/trafficserver/iocore/net/UnixNet.cc:254:11 (traffic_server+0x65bbae)
    #3 (anonymous namespace)::ThreadInitByFunc::invoke(int, Event*) /home/mo/work/trafficserver/iocore/eventsystem/UnixEventProcessor.cc:134:5 (traffic_server+0x6d594d) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #4 Continuation::handleEvent(int, void*) /home/mo/work/trafficserver/iocore/eventsystem/./I_Continuation.h:227:12 (traffic_server+0x6d43b2) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #5 EventProcessor::initThreadState(EThread*) /home/mo/work/trafficserver/iocore/eventsystem/UnixEventProcessor.cc:464:27 (traffic_server+0x6d43b2)
    #6 EventProcessor::ThreadInit::init(int, Event*) /home/mo/work/trafficserver/iocore/eventsystem/./I_EventProcessor.h:388:13 (traffic_server+0x6d5f65) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #7 Continuation::handleEvent(int, void*) /home/mo/work/trafficserver/iocore/eventsystem/./I_Continuation.h:227:12 (traffic_server+0x6cf234) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #8 EThread::execute() /home/mo/work/trafficserver/iocore/eventsystem/UnixEThread.cc:333:32 (traffic_server+0x6cf234)
    #9 spawn_thread_internal(void*) /home/mo/work/trafficserver/iocore/eventsystem/Thread.cc:79:12 (traffic_server+0x6cc4f0) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)

  Location is global 'Thread::cur_time' of size 8 at 0x55d6abb92a98 (traffic_server+0x1d97a98)

  Mutex M0 (0x7fbe79ef3bb0) created at:
    #0 pthread_mutex_init <null> (traffic_server+0x18793f) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #1 ink_mutex_init(pthread_mutex_t*) /home/mo/work/trafficserver/src/tscore/ink_mutex.cc:59:11 (libtscore.so.10+0x85d9e) (BuildId: 2278ccd65396324427144106c06acb1c39e1eff1)
    #2 ProtectedQueue::ProtectedQueue() /home/mo/work/trafficserver/iocore/eventsystem/./P_ProtectedQueue.h:38:3 (traffic_server+0x6cca76) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #3 EThread::EThread(ThreadType, int) /home/mo/work/trafficserver/iocore/eventsystem/UnixEThread.cc:79:10 (traffic_server+0x6cca76)
    #4 EventProcessor::spawn_event_threads(int, int, unsigned long) /home/mo/work/trafficserver/iocore/eventsystem/UnixEventProcessor.cc:421:40 (traffic_server+0x6d370c) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #5 EventProcessor::start(int, unsigned long) /home/mo/work/trafficserver/iocore/eventsystem/UnixEventProcessor.cc:502:9 (traffic_server+0x6d48f9) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #6 main /home/mo/work/trafficserver/src/traffic_server/traffic_server.cc:2025:18 (traffic_server+0x259a5e) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)

  Thread T2 '[ET_NET 0]' (tid=741310, running) created by main thread at:
    #0 pthread_create <null> (traffic_server+0x18613d) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #1 ink_thread_create(unsigned long*, void* (*)(void*), void*, int, unsigned long, void*) /home/mo/work/trafficserver/iocore/eventsystem/../../include/tscore/ink_thread.h:137:9 (traffic_server+0x6cc3d0) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #2 Thread::start(char const*, void*, unsigned long, std::function<void ()> const&) /home/mo/work/trafficserver/iocore/eventsystem/Thread.cc:96:3 (traffic_server+0x6cc3d0)
    #3 EventProcessor::spawn_event_threads(int, int, unsigned long) /home/mo/work/trafficserver/iocore/eventsystem/UnixEventProcessor.cc:439:21 (traffic_server+0x6d38c3) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #4 EventProcessor::start(int, unsigned long) /home/mo/work/trafficserver/iocore/eventsystem/UnixEventProcessor.cc:502:9 (traffic_server+0x6d48f9) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #5 main /home/mo/work/trafficserver/src/traffic_server/traffic_server.cc:2025:18 (traffic_server+0x259a5e) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)

  Thread T3 '[ET_NET 1]' (tid=741311, running) created by main thread at:
    #0 pthread_create <null> (traffic_server+0x18613d) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #1 ink_thread_create(unsigned long*, void* (*)(void*), void*, int, unsigned long, void*) /home/mo/work/trafficserver/iocore/eventsystem/../../include/tscore/ink_thread.h:137:9 (traffic_server+0x6cc3d0) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #2 Thread::start(char const*, void*, unsigned long, std::function<void ()> const&) /home/mo/work/trafficserver/iocore/eventsystem/Thread.cc:96:3 (traffic_server+0x6cc3d0)
    #3 EventProcessor::spawn_event_threads(int, int, unsigned long) /home/mo/work/trafficserver/iocore/eventsystem/UnixEventProcessor.cc:439:21 (traffic_server+0x6d38c3) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #4 EventProcessor::start(int, unsigned long) /home/mo/work/trafficserver/iocore/eventsystem/UnixEventProcessor.cc:502:9 (traffic_server+0x6d48f9) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)
    #5 main /home/mo/work/trafficserver/src/traffic_server/traffic_server.cc:2025:18 (traffic_server+0x259a5e) (BuildId: cb1dcfdd8df6934d9957379a126676f4a558c54e)

SUMMARY: ThreadSanitizer: data race /home/mo/work/trafficserver/iocore/eventsystem/./I_Thread.h:194:19 in Thread::get_hrtime_updated()
==================

[moonchen]

Related to #9168

[github-actions]

This issue has been automatically marked as stale because it has not had recent activity. Marking it stale to flag it for further consideration by the community.

[bryancall]

This ThreadSanitizer data race on the global Thread::cur_time (the write in Thread::get_hrtime_updated() racing the read in Thread::get_hrtime() across ET_NET threads) was fixed by making that cached current time thread local in #9184, the alternative approach to the related issue #9168. That fix first shipped in release 9.2.1. On current master the global Thread::cur_time and the get_hrtime_updated() and get_hrtime() methods no longer exist, and the cached high resolution time is now per thread, so the cross thread race reported here is gone. A later change, #10163 (release 10.0.0), additionally ensured the thread local time is updated promptly. Closing as fixed.