[SERVER-18605] Include thread id in log messages Created: 21/May/15  Updated: 25/Jan/17  Resolved: 27/May/15

Status: Closed
Project: Core Server
Component/s: Logging
Affects Version/s: None
Fix Version/s: 3.1.4

Type: Improvement Priority: Major - P3
Reporter: Scott Hernandez (Inactive) Assignee: Andy Schwerin
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
is related to SERVER-6555 Stack traces should show thread name Closed
Backwards Compatibility: Fully Compatible
Participants:

 Description   

When debugging and diagnosing issues it is very helpful for the thread id to be included with each log message.

Adding a switch or having this behavior in some special mode may be sufficient for mongodb developers, but I can also see this being useful for diagnosing end-user problems as well.

This can be tested by add a line to "MessageEventDetailsEncoder::encode":

os << std::this_thread::get_id();



 Comments   
Comment by Githook User [ 27/May/15 ]

Author:

{u'username': u'andy10gen', u'name': u'Andy Schwerin', u'email': u'schwerin@mongodb.com'}

Message: SERVER-18605 Update lsan.suppressions for default thread name setting.
Branch: master
https://github.com/mongodb/mongo/commit/845a2dcc23a597520065d1258089cc87dabf6cb8

Comment by Githook User [ 27/May/15 ]

Author:

{u'username': u'andy10gen', u'name': u'Andy Schwerin', u'email': u'schwerin@mongodb.com'}

Message: SERVER-18605 Always set some thread name.

This ensures that some thread name appears in log messages, even if a thread
name is never explicitly set. It is still preferable for programmers to
explicitly set more informative names, when possible.
Branch: master
https://github.com/mongodb/mongo/commit/4c221a9e5ed3d49b9c21508b0a2e688b9e6736e2

Comment by Andy Schwerin [ 21/May/15 ]

Yeah. I've got a patch for that I'll put up for review.

Comment by Scott Hernandez (Inactive) [ 21/May/15 ]

Use a counter?

Comment by Andy Schwerin [ 21/May/15 ]

So I did a little experiment. I compiled and ran the following program on Ubuntu 14 using gcc and clang.

#include <cstdint>
#include <iostream>
#include <sstream>
#include <thread>
#include <vector>
 
int main(int argc, char** argv) {
 constexpr int sz = 5;
  std::vector<std::thread> ts;
  std::vector<std::string> results(sz);
  for (int i = 0; i < sz; ++i) {
      ts.emplace_back([&results, i]() -> void {
          int a;
          void* stackAddr = &a;
          std::ostringstream os;
          os << std::this_thread::get_id();
          std::istringstream is(os.str());
          intptr_t tid = 0;
          is >> tid;
          os.str("");
          os << std::hex
             << stackAddr
             << ", 0x" << std::this_thread::get_id()
             << ", 0x" << (tid - reinterpret_cast<intptr_t>(stackAddr));
          results[i] = std::move(os.str());
      });
  }
  for (auto& t : ts) {
      t.join();
  }
  for (const auto& r : results) {
    std::cout << r << std::endl;
  }
  return 0;
}

The output was similar for both runs:

0x7fa45214cb0c, 0x7fa45214d700, 0xbf4
0x7fa45194bb0c, 0x7fa45194c700, 0xbf4
0x7fa45114ab0c, 0x7fa45114b700, 0xbf4
0x7fa450949b0c, 0x7fa45094a700, 0xbf4
0x7fa450148b0c, 0x7fa450149700, 0xbf4

What concerns me is that the thread id reveals the stack address of the thread.

Comment by Scott Hernandez (Inactive) [ 21/May/15 ]

Sounds good to me.

Comment by Andy Schwerin [ 21/May/15 ]

How about if instead of this behavior, we set the default thread name to contain the thread id, but if the thread explicitly calls setThreadName, that value is used instead? This could be achieved by altering the implementation of setThreadName slightly.

Generated at Thu Feb 08 03:48:13 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.