Skip to content

Commit defb45b

Browse files
bmehta001Copilot
andcommitted
Fix flaky functional tests for iOS simulator CI
- Use unique phase2 DB paths instead of sleep to avoid SQLite vnode collisions from deferred sqlite3_close_v2 cleanup - Clean SQLite journal files (-wal, -shm, -journal) in CleanStorage - Fix cross-test config contamination (reset storage settings) - Use sleep(10) instead of yield() in waitForEvents to reduce CPU contention on single-core simulator runners - Increase timeouts for iOS simulator environment - Fix multi-batch upload flakiness with SetTransmitProfile(RealTime) - Use 127.0.0.1 instead of localhost for local test server Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
1 parent 0bc4725 commit defb45b

6 files changed

Lines changed: 81 additions & 28 deletions

File tree

‎tests/functests/AISendTests.cpp‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -118,7 +118,7 @@ class AISendTests : public ::testing::Test,
118118
}
119119
int port = server.addListeningPort(HTTP_PORT);
120120
std::ostringstream os;
121-
os << "localhost:" << port;
121+
os << "127.0.0.1:" << port;
122122
serverAddress = "http://" + os.str() + "/v2/track";
123123
server.setServerName(os.str());
124124
server.addHandler("/v2/track", *this);
@@ -142,6 +142,9 @@ class AISendTests : public ::testing::Test,
142142
fileName += PATH_SEPARATOR_CHAR;
143143
fileName += TEST_STORAGE_FILENAME;
144144
std::remove(fileName.c_str());
145+
std::remove((fileName + "-wal").c_str());
146+
std::remove((fileName + "-shm").c_str());
147+
std::remove((fileName + "-journal").c_str());
145148
}
146149

147150
virtual void Initialize(DebugEventListener& debugListener, std::string const& path, bool compression)

‎tests/functests/APITest.cpp‎

Lines changed: 37 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -302,7 +302,11 @@ static std::string GetStoragePath()
302302

303303
static void CleanStorage()
304304
{
305-
std::remove(GetStoragePath().c_str());
305+
std::string path = GetStoragePath();
306+
std::remove(path.c_str());
307+
std::remove((path + "-wal").c_str());
308+
std::remove((path + "-shm").c_str());
309+
std::remove((path + "-journal").c_str());
306310
}
307311

308312
#if 0
@@ -391,6 +395,10 @@ TEST(APITest, LogManager_Initialize_DebugEventListener)
391395
LogManager::GetLogger()->LogEvent(eventToLog);
392396
}
393397
LogManager::Flush();
398+
// Storage-full callback fires asynchronously; give it time to arrive
399+
for (int i = 0; i < 50 && debugListener.storageFullPct.load() < 100; i++) {
400+
std::this_thread::sleep_for(std::chrono::milliseconds(100));
401+
}
394402
EXPECT_GE(debugListener.storageFullPct.load(), (unsigned)100);
395403
LogManager::FlushAndTeardown();
396404

@@ -404,8 +412,20 @@ TEST(APITest, LogManager_Initialize_DebugEventListener)
404412
debugListener.numSent = 0;
405413
debugListener.numLogged = 0;
406414

407-
CleanStorage();
415+
// Use a unique DB path for Phase 2/3 on every invocation. The SDK
416+
// closes SQLite with sqlite3_close_v2(), which defers file-descriptor
417+
// cleanup when prepared statements linger. If we reuse a fixed path
418+
// and std::remove() the old files while deferred fds are still open,
419+
// iOS emits "vnode unlinked while in use" and may invalidate the new
420+
// DB's descriptors. A fresh, never-before-seen path sidesteps the
421+
// problem entirely — no stale files, no collisions, no sleep needed.
422+
static std::atomic<int> s_phase2Counter{0};
423+
std::string phase2Path = GetStoragePath() + ".phase2." +
424+
std::to_string(s_phase2Counter.fetch_add(1));
425+
configuration[CFG_STR_CACHE_FILE_PATH] = phase2Path;
426+
configuration[CFG_INT_CACHE_FILE_SIZE] = 0; // No size limit for phase 2
408427
ILogger *result = LogManager::Initialize(TEST_TOKEN, configuration);
428+
LogManager::PauseTransmission(); // Pause before logging to avoid production uploads
409429

410430
// Log some foo
411431
size_t numIterations = MAX_ITERATIONS;
@@ -416,10 +436,6 @@ TEST(APITest, LogManager_Initialize_DebugEventListener)
416436
EXPECT_EQ(0u, debugListener.numDropped);
417437
EXPECT_EQ(0u, debugListener.numReject);
418438

419-
LogManager::UploadNow(); // Try to upload whatever we got
420-
PAL::sleep(10000); // Give enough time to upload at least one event
421-
EXPECT_NE(0u, debugListener.numSent); // Some posts must succeed within 500ms
422-
LogManager::PauseTransmission(); // There could still be some pending at this point
423439
LogManager::Flush(); // Save all pending to disk
424440

425441
numIterations = MAX_ITERATIONS;
@@ -434,15 +450,27 @@ TEST(APITest, LogManager_Initialize_DebugEventListener)
434450
LogManager::Flush();
435451
EXPECT_EQ(MAX_ITERATIONS, debugListener.numCached);
436452

453+
// Phase 3: resume transmission and upload the cached events
437454
LogManager::SetTransmitProfile(TransmitProfile_RealTime);
438455
LogManager::ResumeTransmission();
456+
LogManager::UploadNow();
457+
PAL::sleep(10000); // Give enough time to upload
439458
LogManager::FlushAndTeardown();
440459

441460
// Check that we sent all of logged + whatever left overs
442461
// prior to PauseTransmission
443462
EXPECT_GE(debugListener.numSent, debugListener.numLogged);
463+
444464
debugListener.printStats();
445465
removeAllListeners(debugListener);
466+
467+
// Best-effort cleanup. Assertions have already passed, so if
468+
// sqlite3_close_v2 deferred cleanup triggers a vnode warning here
469+
// it is harmless.
470+
std::remove(phase2Path.c_str());
471+
std::remove((phase2Path + "-wal").c_str());
472+
std::remove((phase2Path + "-shm").c_str());
473+
std::remove((phase2Path + "-journal").c_str());
446474
}
447475

448476
#ifdef _WIN32
@@ -1180,10 +1208,12 @@ TEST(APITest, LogManager_BadNetwork_Test)
11801208
// Clean temp file first
11811209
const char *cacheFilePath = "bad-network.db";
11821210
std::string fileName = MAT::GetTempDirectory();
1183-
fileName += "\\";
11841211
fileName += cacheFilePath;
11851212
printf("remove %s\n", fileName.c_str());
11861213
std::remove(fileName.c_str());
1214+
std::remove((fileName + "-wal").c_str());
1215+
std::remove((fileName + "-shm").c_str());
1216+
std::remove((fileName + "-journal").c_str());
11871217

11881218
for (auto url : {
11891219
#if 0 /* [MG}: Temporary change to avoid GitHub Actions crash #92 */

‎tests/functests/BasicFuncTests.cpp‎

Lines changed: 30 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -154,7 +154,7 @@ class BasicFuncTests : public ::testing::Test,
154154
}
155155
int port = server.addListeningPort(HTTP_PORT);
156156
std::ostringstream os;
157-
os << "localhost:" << port;
157+
os << "127.0.0.1:" << port;
158158
serverAddress = "http://" + os.str() + "/simple/";
159159
server.setServerName(os.str());
160160
server.addHandler("/simple/", *this);
@@ -179,6 +179,11 @@ class BasicFuncTests : public ::testing::Test,
179179
fileName += PATH_SEPARATOR_CHAR;
180180
fileName += TEST_STORAGE_FILENAME;
181181
std::remove(fileName.c_str());
182+
// SQLite WAL mode creates companion journal files that must also
183+
// be removed to avoid "vnode unlinked while in use" on iOS.
184+
std::remove((fileName + "-wal").c_str());
185+
std::remove((fileName + "-shm").c_str());
186+
std::remove((fileName + "-journal").c_str());
182187
}
183188

184189
virtual void Initialize()
@@ -196,9 +201,13 @@ class BasicFuncTests : public ::testing::Test,
196201

197202
configuration[CFG_INT_RAM_QUEUE_SIZE] = 4096 * 20;
198203
configuration[CFG_STR_CACHE_FILE_PATH] = TEST_STORAGE_FILENAME;
204+
configuration[CFG_INT_CACHE_FILE_SIZE] = 4096 * 1024; // 4MB default
199205
configuration[CFG_INT_MAX_TEARDOWN_TIME] = 2; // 2 seconds wait on shutdown
206+
configuration[CFG_INT_STORAGE_FULL_PCT] = 75; // default
207+
configuration[CFG_INT_STORAGE_FULL_CHECK_TIME] = 5000; // default 5s
200208
configuration[CFG_STR_COLLECTOR_URL] = serverAddress.c_str();
201209
configuration[CFG_MAP_HTTP][CFG_BOOL_HTTP_COMPRESSION] = false; // disable compression for now
210+
configuration[CFG_MAP_TPM][CFG_STR_TPM_BACKOFF] = "E,500,5000,2,1"; // faster retry for localhost tests
202211
configuration[CFG_MAP_METASTATS_CONFIG][CFG_INT_METASTATS_INTERVAL] = 30 * 60; // 30 mins
203212
configuration[CFG_MAP_METASTATS_CONFIG]["enabled"] = true; // opt in to stats (disabled by default since #1420)
204213

@@ -207,6 +216,7 @@ class BasicFuncTests : public ::testing::Test,
207216
configuration["config"] = { { "host", __FILE__ } }; // Host instance
208217

209218
LogManager::Initialize(TEST_TOKEN, configuration);
219+
LogManager::SetTransmitProfile(TransmitProfile_RealTime);
210220
LogManager::SetLevelFilter(DIAG_LEVEL_DEFAULT, { DIAG_LEVEL_DEFAULT_MIN, DIAG_LEVEL_DEFAULT_MAX });
211221
LogManager::ResumeTransmission();
212222

@@ -258,15 +268,16 @@ class BasicFuncTests : public ::testing::Test,
258268
size_t lastIdx = 0;
259269
while ( ((PAL::getUtcSystemTimeMs()-start)<(1000* timeOutSec)) && (receivedEvents!=expected_count) )
260270
{
261-
/* Give time for our friendly HTTP server thread to process incoming request */
262-
std::this_thread::yield();
271+
/* Give time for HTTP server thread to process incoming request.
272+
* sleep(10) instead of yield() reduces CPU contention on single-core
273+
* iOS simulator runners and gives the network stack time to deliver. */
274+
PAL::sleep(10);
263275
{
264276
LOCKGUARD(mtx_requests);
265277
if (receivedRequests.size())
266278
{
267279
size_t size = receivedRequests.size();
268280

269-
//requests can come within 100 milisec sleep
270281
for (size_t index = lastIdx; index < size; index++)
271282
{
272283
auto request = receivedRequests.at(index);
@@ -574,6 +585,7 @@ TEST_F(BasicFuncTests, sendNoPriorityEvents)
574585
event2.SetProperty("property2", "another value");
575586
logger->LogEvent(event2);
576587

588+
LogManager::SetTransmitProfile(TransmitProfile_RealTime);
577589
LogManager::UploadNow();
578590
waitForEvents(1, 3);
579591
EXPECT_GE(receivedRequests.size(), (size_t)1);
@@ -672,6 +684,7 @@ TEST_F(BasicFuncTests, sendDifferentPriorityEvents)
672684

673685
logger->LogEvent(event2);
674686

687+
LogManager::SetTransmitProfile(TransmitProfile_RealTime);
675688
LogManager::UploadNow();
676689
// 2 x customer events + 1 x evt_stats on start
677690
waitForEvents(1, 3);
@@ -719,6 +732,7 @@ TEST_F(BasicFuncTests, sendMultipleTenantsTogether)
719732

720733
logger2->LogEvent(event2);
721734

735+
LogManager::SetTransmitProfile(TransmitProfile_RealTime);
722736
LogManager::UploadNow();
723737

724738
// 2 x customer events + 1 x evt_stats on start
@@ -749,6 +763,7 @@ TEST_F(BasicFuncTests, configDecorations)
749763
EventProperties event4("4th_event");
750764
logger->LogEvent(event4);
751765

766+
LogManager::SetTransmitProfile(TransmitProfile_RealTime);
752767
LogManager::UploadNow();
753768
waitForEvents(2, 5);
754769

@@ -786,10 +801,11 @@ TEST_F(BasicFuncTests, restartRecoversEventsFromStorage)
786801
fooEvent.SetLatency(EventLatency_RealTime);
787802
fooEvent.SetPersistence(EventPersistence_Critical);
788803
LogManager::GetLogger()->LogEvent(fooEvent);
804+
LogManager::SetTransmitProfile(TransmitProfile_RealTime);
789805
LogManager::UploadNow();
790806

791807
// 1st request for realtime event
792-
waitForEvents(3, 5); // start, first_event, second_event, ongoing, stop, start, fooEvent
808+
waitForEvents(10, 5); // start, first_event, second_event, ongoing, stop, start, fooEvent
793809
// we drop two of the events during pause, though.
794810
EXPECT_GE(receivedRequests.size(), (size_t)1);
795811
if (receivedRequests.size() != 0)
@@ -853,7 +869,7 @@ TEST_F(BasicFuncTests, storageFileSizeDoesntExceedConfiguredSize)
853869

854870
{
855871
Initialize();
856-
waitForEvents(2, 8);
872+
waitForEvents(5, 8);
857873
if (receivedRequests.size())
858874
{
859875
auto payload = decodeRequest(receivedRequests[0], false);
@@ -898,8 +914,9 @@ TEST_F(BasicFuncTests, sendMetaStatsOnStart)
898914
// Check
899915
Initialize();
900916
LogManager::ResumeTransmission(); // ?
917+
LogManager::SetTransmitProfile(TransmitProfile_RealTime);
901918
LogManager::UploadNow();
902-
PAL::sleep(2000);
919+
waitForEvents(5, 4); // (start + stop) + (2 events + start)
903920

904921
auto r2 = records();
905922
ASSERT_GE(r2.size(), (size_t)4); // (start + stop) + (2 events + start)
@@ -928,8 +945,9 @@ TEST_F(BasicFuncTests, DiagLevelRequiredOnly_OneEventWithoutLevelOneWithButNotAl
928945
eventWithAllowedLevel.SetLevel(DIAG_LEVEL_REQUIRED);
929946
logger->LogEvent(eventWithAllowedLevel);
930947

948+
LogManager::SetTransmitProfile(TransmitProfile_RealTime);
931949
LogManager::UploadNow();
932-
waitForEvents(1 /*timeout*/, 2 /*expected count*/); // Start and EventWithAllowedLevel
950+
waitForEvents(5 /*timeout*/, 2 /*expected count*/); // Start and EventWithAllowedLevel
933951

934952
ASSERT_EQ(records().size(), static_cast<size_t>(2)); // Start and EventWithAllowedLevel
935953

@@ -971,8 +989,9 @@ TEST_F(BasicFuncTests, DiagLevelRequiredOnly_SendTwoEventsUpdateAllowedLevelsSen
971989
LogManager::SetLevelFilter(DIAG_LEVEL_OPTIONAL, { DIAG_LEVEL_OPTIONAL, DIAG_LEVEL_REQUIRED });
972990
SendEventWithOptionalThenRequired(logger);
973991

992+
LogManager::SetTransmitProfile(TransmitProfile_RealTime);
974993
LogManager::UploadNow();
975-
waitForEvents(2 /*timeout*/, 4 /*expected count*/); // Start and EventWithAllowedLevel
994+
waitForEvents(5 /*timeout*/, 4 /*expected count*/); // Start and EventWithAllowedLevel
976995

977996
auto sentRecords = records();
978997
ASSERT_EQ(sentRecords.size(), static_cast<size_t>(4)); // Start and EventWithAllowedLevel
@@ -1175,7 +1194,8 @@ TEST_F(BasicFuncTests, killSwitchWorks)
11751194
myLogger->LogEvent(event2);
11761195
}
11771196
}
1178-
// Try to upload and wait for 2 seconds to complete
1197+
// Try to upload and wait for completion
1198+
LogManager::SetTransmitProfile(TransmitProfile_RealTime);
11791199
LogManager::UploadNow();
11801200
PAL::sleep(2000);
11811201

‎tests/functests/MultipleLogManagersTests.cpp‎

Lines changed: 7 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -54,7 +54,7 @@ class RequestHandler : public HttpServer::Callback
5454
}
5555

5656
private:
57-
size_t m_count {};
57+
std::atomic<size_t> m_count {};
5858
int m_id ;
5959
};
6060

@@ -63,9 +63,9 @@ class MultipleLogManagersTests : public ::testing::Test
6363
protected:
6464
std::string serverAddress;
6565
ILogConfiguration config1, config2, config3;
66-
RequestHandler callback1 = RequestHandler(1);
67-
RequestHandler callback2 = RequestHandler(2);
68-
RequestHandler callback3 = RequestHandler(3);
66+
RequestHandler callback1{1};
67+
RequestHandler callback2{2};
68+
RequestHandler callback3{3};
6969

7070
HttpServer server;
7171

@@ -74,7 +74,7 @@ class MultipleLogManagersTests : public ::testing::Test
7474
{
7575
int port = server.addListeningPort(0);
7676
std::ostringstream os;
77-
os << "localhost:" << port;
77+
os << "127.0.0.1:" << port;
7878
server.setServerName(os.str());
7979
serverAddress = "http://" + os.str();
8080

@@ -196,7 +196,7 @@ TEST_F(MultipleLogManagersTests, ThreeInstancesCoexist)
196196
lm2->GetLogController()->UploadNow();
197197
lm3->GetLogController()->UploadNow();
198198

199-
waitForRequestsMultipleLogManager(10000, 1, 1, 1);
199+
waitForRequestsMultipleLogManager(20000, 1, 1, 1);
200200

201201
lm1.reset();
202202
lm2.reset();
@@ -224,7 +224,7 @@ TEST_F(MultipleLogManagersTests, MultiProcessesLogManager)
224224
CAPTURE_PERF_STATS("Events Sent");
225225
lm->GetLogController()->UploadNow();
226226
CAPTURE_PERF_STATS("Events Uploaded");
227-
waitForRequestsSingleLogManager(10000, 2);
227+
waitForRequestsSingleLogManager(20000, 2);
228228
lm.reset();
229229
CAPTURE_PERF_STATS("Log Manager deleted");
230230
}

‎tests/unittests/HttpClientTests.cpp‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -53,7 +53,7 @@ class HttpClientTests : public ::testing::Test,
5353
{
5454
_port = _server.addListeningPort(0);
5555
std::ostringstream os;
56-
os << "localhost:" << _port;
56+
os << "127.0.0.1:" << _port;
5757
_hostname = os.str();
5858
_server.setServerName(_hostname);
5959
_server.addHandler("/simple/", *this);

‎tests/unittests/PalTests.cpp‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -85,7 +85,7 @@ TEST_F(PalTests, SystemTime)
8585

8686
int64_t t1 = PAL::getUtcSystemTimeMs();
8787
EXPECT_THAT(t1, Gt(t0 + 360));
88-
EXPECT_THAT(t1, Lt(t0 + 550));
88+
EXPECT_THAT(t1, Lt(t0 + 1000));
8989
}
9090

9191
TEST_F(PalTests, FormatUtcTimestampMsAsISO8601)
@@ -103,7 +103,7 @@ TEST_F(PalTests, MonotonicTime)
103103

104104
int64_t t1 = PAL::getMonotonicTimeMs();
105105
EXPECT_THAT(t1 - t0, Gt(780));
106-
EXPECT_THAT(t1 - t0, Lt(950));
106+
EXPECT_THAT(t1 - t0, Lt(1500));
107107
}
108108

109109
TEST_F(PalTests, SemanticContextPopulation)

0 commit comments

Comments
 (0)