Skip to content

Commit

Permalink
Fix logging race condition (#242)
Browse files Browse the repository at this point in the history
* add timeout for when thread is blocked

* repeat ci tests with change commented out

* reduced blocking time to decrease test runtime

* testing WITH change

* clang format, still testing WITH fix

* test performance impact

* add comment for context in testing
  • Loading branch information
RogerZhongAWS authored Apr 22, 2022
1 parent 140913a commit 191c842
Show file tree
Hide file tree
Showing 4 changed files with 18 additions and 4 deletions.
1 change: 1 addition & 0 deletions .github/build.sh
Original file line number Diff line number Diff line change
Expand Up @@ -233,3 +233,4 @@ cmake --build . --target test-aws-iot-device-client

### Run Tests ###
env AWS_CRT_MEMORY_TRACING=1 ./test/test-aws-iot-device-client
./test/test-aws-iot-device-client --gtest_filter=LogQueueTest.notifyAllOnShutdown --gtest_repeat=1000
8 changes: 7 additions & 1 deletion source/logging/LogQueue.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -2,10 +2,14 @@
// SPDX-License-Identifier: Apache-2.0

#include "LogQueue.h"
#include <iostream>
#include <thread>

using namespace std;
using namespace Aws::Iot::DeviceClient::Logging;

constexpr int LogQueue::EMPTY_WAIT_TIME_MILLISECONDS;

void LogQueue::addLog(unique_ptr<LogMessage> log)
{
unique_lock<mutex> addLock(queueLock);
Expand All @@ -23,10 +27,12 @@ bool LogQueue::hasNextLog()
std::unique_ptr<LogMessage> LogQueue::getNextLog()
{
unique_lock<mutex> readLock(queueLock);

while (logQueue.empty() && !isShutdown)
{
newLogNotifier.wait(readLock);
newLogNotifier.wait_for(readLock, chrono::milliseconds(EMPTY_WAIT_TIME_MILLISECONDS));
}

if (logQueue.empty())
{
return NULL;
Expand Down
8 changes: 7 additions & 1 deletion source/logging/LogQueue.h
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
#define DEVICE_CLIENT_LOGQUEUE_H

#include "LogMessage.h"
#include <atomic>
#include <condition_variable>
#include <deque>
#include <mutex>
Expand All @@ -27,7 +28,12 @@ namespace Aws
/**
* \brief Whether the LogQueue has been shutdown or not.
*/
bool isShutdown = false;
std::atomic<bool> isShutdown{false};
/**
* \brief The default value in milliseconds for which Device client will wait after blocking when
* the queue is empty.
*/
static constexpr int EMPTY_WAIT_TIME_MILLISECONDS = 200;
/**
* \brief a Mutex used to control multi-threaded access to the LogQueue
*/
Expand Down
5 changes: 3 additions & 2 deletions test/logging/TestLogQueue.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -85,8 +85,9 @@ TEST_F(LogQueueTest, notifyAllOnShutdown)

logQueue->shutdown();

cv.wait_for(lock1, chrono::seconds(1));
cv2.wait_for(lock2, chrono::seconds(1));
// 400ms is 2 * EMPTY_WAIT_TIME_MILLISECONDS as defined in LogQueue.h
cv.wait_for(lock1, chrono::milliseconds(400));
cv2.wait_for(lock2, chrono::milliseconds(400));

ASSERT_TRUE(processed && processed2);
}
Expand Down

0 comments on commit 191c842

Please sign in to comment.