-2

I trying do simple threadsafe logger, which print messages to console.

// Test function for check logger. It is work
void test(double& diff)
{
  std::vector<double> result;
  for( int counter = 0; counter < 100000; ++counter)
  {
    result.push_back(clock());

    std::string text = "counter = ";
    text.append(std::to_string(counter));
    LOG_MESSAGE(text); //<-- Correct log..
  }
  diff = clock() - result.front();

}

int main(int argc, char** argv)
{
  double time2;
  double time1;
  std::vector<double> timerResult;
  std::vector<std::thread> threadVector;

  time1 = clock();
  for(int i = 0; i < 5; ++i) //<-- Create 5 thread of test function
  {
    timerResult.push_back(0);
    threadVector.push_back(std::thread(test, std::ref(timerResult[i])));
  }
  for(std::thread& t : threadVector)
    t.join();
  time2 = clock(); //<-- Threads is finished

  double res = 0;
  for(double tRes : timerResult)
     res += tRes;
  res = res / static_cast<double>(CLOCKS_PER_SEC);

  std::string message; //<-- Generate final message
  message.append("Timer: ")
      .append(std::to_string((time2 - time1) / (double)CLOCKS_PER_SEC))
      .append(" - thread timer: ")
      .append(std::to_string(res));

  LOG_MESSAGE(message); //<-- Crash inside!!    

  return 0;
}

Logger is good working in threads. But when I try log in main() function that call SIGSEGV signal in destructor of std::ostringstream (in function of construct log message):

static Logger::Core logger; //<--Global Logger variable

#define LOG_MESSAGE( TEXT ) logger.addNoteInLog(TEXT) //<-- Define for log message

void Core::addNoteInLog(const Message &message) //<-- threadsafe log function
{  
  std::string text;
  message.generateString(text); //<-- [Crash here] generate log message
  g_lock.lock();
  std::cout << text;
  g_lock.unlock();
}

void Message::generateString(std::string& text) const
{
  text.clear();
  tm *ltm = localtime(&mDate);

  std::ostringstream data; //<-- [Crash here] function is finished, but cannot destruct object.
  data << 1900 + ltm->tm_year << "/"
       << 1 + ltm->tm_mon << "/"
       << ltm->tm_mday << "\t";
  data << "[INF] - ";
  data << std::this_thread::get_id() << " - "
       << mMessage << "\n";

  text = data.str();
}

I dont understand why logger in threads is work, but in main() function crashed. Using the exclusion method, I found out when the error is occurred:

  • when I use 5 (or more) threads
  • when test function is not empty
  • when in generateString use stringstream or ostringstream or string.append() (in last case application crash in std::string destructor in same place)

What say debugger in QtCreater.

Build in Ubuntu OS, gcc version 5.4.0, compilation flags: -std=c++17 -pthread -Wall

This is my git repository with error.

  • fyi Docs note that `localtime` may not be thread safe. What happens if you move the call to `generateString` inside the lock? – Richard Critten Dec 05 '17 at 19:12
  • Segmentation faults don't come out of the blue. Did you inspect the stack trace in the debugger, where exactly from your code it came? – user0042 Dec 05 '17 at 19:15
  • 1
    Check your vectors? Remember vector will completely reallocate its storage if it grows, so the threads may be pointing at rubbish. Using reserve to pre-size the vectors can be a help. – Gem Taylor Dec 05 '17 at 19:29
  • @RichardCritten I tried to move generateString inside the lock. Nothing changed. – Ilya Galdin Dec 05 '17 at 19:29
  • @user0042 yes, I inspect the stacktrace. Debugger enter in LOG_MESSAGE in main() function. Correct generate meassge and fall on stringstream destructor. – Ilya Galdin Dec 05 '17 at 19:34
  • @GemTaylor Vectors is all right. Messages generate correct – Ilya Galdin Dec 05 '17 at 19:35
  • @IlyaGaldin You should probably protect access to your global `logger` variable with a mutex or another appropriate syncronization mechanism. – user0042 Dec 05 '17 at 19:36
  • @user0042 I included usage my global variable inside mutex lock now. Nothing changed. May be threads quantity influence on the error? – Ilya Galdin Dec 05 '17 at 19:50
  • Change this line `threadVector.push_back(std::thread(test, std::ref(timerResult[i])));` you cannot get reference to `timerResult[i]` because it is almost sure that reallocation memory in `timerResult` was done after calling 5x `push_back` method, and passed reference by `ref(timerResult[i])` is incorrect. – rafix07 Dec 05 '17 at 19:54
  • @rafix07 Thanks! Its work! I realized my fall. – Ilya Galdin Dec 05 '17 at 20:03
  • @GemTaylor Im sorry. You all right to. thanks – Ilya Galdin Dec 05 '17 at 20:03

1 Answers1

1

Problem solved. As it was said in the comments, line threadVector.push_back(std::thread(test, std::ref(timerResult[i]))); is not correct, because memory reallocation in timerResult was done after calling push_back 5 times, and passing reference by ref(timerResult[i]) is incorrect.

Correct code:

    int main(int argc, char** argv)
    {
      double time2;
      double time1;
      std::vector<double> timerResult (5); //<-- Create filling of vector
      std::vector<std::thread> threadVector;

      time1 = clock();
      for(int i = 0; i < 5; ++i)
      {
        //timerResult.push_back(0); //<-- incorrect filling of vector
        threadVector.push_back(std::thread(test, std::ref(timerResult[i])));
      }
      for(std::thread& t : threadVector)
        t.join();
      time2 = clock();
      ...
    }
Dev Null
  • 4,731
  • 1
  • 30
  • 46