Skip to content

Commit ebaa1ca

Browse files
authored
Improve pcntl tests stability (#2841)
* Improve pcntl tests stability * Simplify code * Throw an exception when expected request is not found * Increase sleep time + make test easier to debug * Work around race conditions leading to different orders or numbers of requests * Remove custom DD_TRACE_SHUTDOWN_TIMEOUT value for most pcntl tests * Give a bit more time to Circle CI * Assert trace by trace because the SpanChecker does not support having multiple spans matching
1 parent 186011f commit ebaa1ca

11 files changed

Lines changed: 126 additions & 84 deletions

File tree

.gitlab-ci.yml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -50,7 +50,7 @@ download_artifacts:
5050
tags: [ "runner:main", "size:large" ]
5151
script:
5252
- |
53-
sleep 1m # Let time for the CircleCI pipeline to start
53+
sleep 2m # Let time for the CircleCI pipeline to start
5454
source .gitlab/download-circleci_artifact.sh
5555
5656
download_circleci_artifact "gh/DataDog/dd-trace-php" "build_packages" "package extension" "dd-library-php-ssi-.*-x86_64-linux.tar.gz" "dd-library-php-ssi-x86_64-linux.tar.gz"

tests/Common/SpanChecker.php

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -195,7 +195,7 @@ private function findOne(array $graph, SpanAssertion $expectedNodeRoot, $parentN
195195
// Not using a TestCase::markTestAsIncomplete() because it exits immediately,
196196
// while with an error log we are still able to proceed with tests.
197197
error_log(sprintf(
198-
"WARNING: More then one candidate found for '%s' at the same level. "
198+
"WARNING: More than one candidate found for '%s' at the same level. "
199199
. "Proceeding in the order they appears. "
200200
. "This might not work if this span is not a leaf span.",
201201
$expectedNodeRoot

tests/Common/TracerTestTrait.php

Lines changed: 70 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -216,12 +216,12 @@ public function inWebServer($fn, $rootPath, $envs = [], $inis = [], &$curlInfo =
216216
/**
217217
* This method executes a single script with the provided configuration.
218218
*/
219-
public function inCli($scriptPath, $customEnvs = [], $customInis = [], $arguments = '', $withOutput = false)
219+
public function inCli($scriptPath, $customEnvs = [], $customInis = [], $arguments = '', $withOutput = false, $until = null, $throw = true)
220220
{
221221
$this->resetRequestDumper();
222222
$output = $this->executeCli($scriptPath, $customEnvs, $customInis, $arguments, $withOutput);
223223
usleep(100000); // Add a slight delay to give the request-replayer time to handle and store all requests.
224-
$out = [$this->parseTracesFromDumpedData()];
224+
$out = [$this->parseTracesFromDumpedData($until, $throw)];
225225
if ($withOutput) {
226226
$out[] = $output;
227227
}
@@ -387,9 +387,9 @@ private function parseRawDumpedSpans($rawSpans)
387387
* @return array
388388
* @throws \Exception
389389
*/
390-
private function parseTracesFromDumpedData(callable $until = null)
390+
private function parseTracesFromDumpedData(callable $until = null, $throw = false)
391391
{
392-
$loaded = $this->retrieveDumpedTraceData($until);
392+
$loaded = $this->retrieveDumpedTraceData($until, $throw);
393393
if (!$loaded) {
394394
return [];
395395
}
@@ -443,12 +443,6 @@ public function parseMultipleRequestsFromDumpedData()
443443
*/
444444
public function retrieveDumpedData(callable $until = null, $throw = false)
445445
{
446-
if (!$until) {
447-
$until = function ($request) {
448-
return (strpos($request["uri"] ?? "", "/telemetry/") !== 0);
449-
};
450-
}
451-
452446
return $this->retrieveAnyDumpedData($until, $throw);
453447
}
454448

@@ -457,16 +451,12 @@ public function retrieveDumpedData(callable $until = null, $throw = false)
457451
*/
458452
public function retrieveDumpedMetrics(callable $until = null, $throw = false)
459453
{
460-
if (!$until) {
461-
$until = function ($request) {
462-
return (strpos($request["uri"] ?? "", "/telemetry/") !== 0);
463-
};
464-
}
465-
466454
return $this->retrieveAnyDumpedData($until, $throw, true);
467455
}
468456

469-
public function retrieveAnyDumpedData(callable $until, $throw, $metrics = false) {
457+
public function retrieveAnyDumpedData(callable $until = null, $throw, $metrics = false) {
458+
$until = $until ?? $this->untilFirstTraceRequest();
459+
470460
$allResponses = [];
471461

472462
// When tests run with the background sender enabled, there might be some delay between when a trace is flushed
@@ -495,7 +485,7 @@ public function retrieveAnyDumpedData(callable $until, $throw, $metrics = false)
495485
return $allResponses;
496486
}
497487
}
498-
\usleep(1000);
488+
\usleep(10000);
499489
}
500490
}
501491

@@ -506,17 +496,69 @@ public function retrieveAnyDumpedData(callable $until, $throw, $metrics = false)
506496
return $allResponses;
507497
}
508498

509-
public function retrieveDumpedTraceData(callable $until = null)
499+
public function retrieveDumpedTraceData(callable $until = null, $throw = false)
510500
{
511-
if ($until) {
512-
return array_values(array_filter($this->retrieveDumpedData($until), function ($request) use ($until) {
513-
return $until($request);
514-
}));
515-
} else {
516-
return array_values(array_filter($this->retrieveDumpedData(), function ($request) {
517-
return strpos($request["uri"] ?? "", "/telemetry/") !== 0;
518-
}));
519-
}
501+
return array_values(array_filter($this->retrieveDumpedData($until, $throw), function ($request) {
502+
// Filter telemetry requests
503+
return strpos($request["uri"] ?? "", "/telemetry/") !== 0;
504+
}));
505+
}
506+
507+
function untilNumberOfTraces($number) {
508+
$count = 0;
509+
return function ($request) use (&$count, $number) {
510+
$count += $request['headers']['X-Datadog-Trace-Count'] ?? 0;
511+
return $count >= $number;
512+
};
513+
}
514+
515+
function untilFirstTraceRequest() {
516+
return function ($request) {
517+
return (strpos($request["uri"] ?? "", "/v0.4/traces") === 0)
518+
|| (strpos($request["uri"] ?? "", "/v0.7/traces") === 0)
519+
;
520+
};
521+
}
522+
523+
function untilTelemetryRequest($metricName) {
524+
return function ($request) use ($metricName) {
525+
return (strpos($request["uri"] ?? "", "/telemetry/") === 0)
526+
&& (strpos($request["body"] ?? "", $metricName) !== false)
527+
;
528+
};
529+
}
530+
531+
function untilSpan(SpanAssertion $assertion) {
532+
return function ($request) use ($assertion) {
533+
if (strpos($request["uri"] ?? "", "/telemetry/") === 0 || !isset($request['body'])) {
534+
return false;
535+
}
536+
$traces = $this->parseRawDumpedTraces(json_decode($request['body'], true));
537+
538+
foreach ($traces as $trace) {
539+
try {
540+
(new SpanChecker())->assertFlameGraph([$trace], [$assertion]);
541+
} catch (\Exception $e) {
542+
continue;
543+
}
544+
545+
return true;
546+
}
547+
548+
return false;
549+
};
550+
}
551+
552+
function until(...$expectations) {
553+
return function ($request) use (&$expectations) {
554+
foreach ($expectations as $key => $expect) {
555+
if ($expect($request)) {
556+
unset($expectations[$key]);
557+
}
558+
}
559+
560+
return !count($expectations);
561+
};
520562
}
521563

522564
/**

tests/Integrations/CLI/Symfony/V4_4/CommonScenariosTest.php

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -153,7 +153,7 @@ public function testLongRunningCommandWithoutRootSpan()
153153
'DD_TRACE_GENERATE_ROOT_SPAN' => 'false',
154154
'DD_TRACE_AUTO_FLUSH_ENABLED' => 'true',
155155
'DD_TRACE_EXEC_ENABLED' => 'false',
156-
], [], 'about');
156+
], [], 'about', false, null, false);
157157

158158
$this->assertFlameGraph(
159159
$traces,

tests/Integrations/CLI/Symfony/V5_2/CommonScenariosTest.php

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -153,7 +153,7 @@ public function testLongRunningCommandWithoutRootSpan()
153153
'DD_TRACE_GENERATE_ROOT_SPAN' => 'false',
154154
'DD_TRACE_AUTO_FLUSH_ENABLED' => 'true',
155155
'DD_TRACE_EXEC_ENABLED' => 'false',
156-
], [], 'about');
156+
], [], 'about', false, null, false);
157157

158158
$this->assertFlameGraph(
159159
$traces,

tests/Integrations/CLI/Symfony/V6_2/CommonScenariosTest.php

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -153,7 +153,7 @@ public function testLongRunningCommandWithoutRootSpan()
153153
'DD_TRACE_GENERATE_ROOT_SPAN' => 'false',
154154
'DD_TRACE_AUTO_FLUSH_ENABLED' => 'true',
155155
'DD_TRACE_EXEC_ENABLED' => 'false',
156-
], [], 'about');
156+
], [], 'about', false, null, false);
157157

158158
$this->assertFlameGraph(
159159
$traces,

tests/Integrations/Custom/Autoloaded/InstrumentationTest.php

Lines changed: 1 addition & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -53,11 +53,7 @@ public function testInstrumentation()
5353
$this->resetRequestDumper();
5454

5555
$this->call(GetSpec::create("autoloaded", "/simple"));
56-
$response = $this->retrieveDumpedData(function ($request) {
57-
return (strpos($request["uri"] ?? "", "/telemetry/") === 0)
58-
&& (strpos($request["body"] ?? "", "spans_created") !== false)
59-
;
60-
}, true);
56+
$response = $this->retrieveDumpedData($this->untilTelemetryRequest("spans_created"));
6157

6258
$this->assertGreaterThanOrEqual(3, $response);
6359
$payloads = $this->readTelemetryPayloads($response);

tests/Integrations/PCNTL/PCNTLTest.php

Lines changed: 42 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -84,9 +84,12 @@ public function testCliShortRunningTracingWhenEnabled()
8484
__DIR__ . '/scripts/synthetic.php',
8585
[
8686
'DD_TRACE_CLI_ENABLED' => 'true',
87-
'DD_TRACE_SHUTDOWN_TIMEOUT' => 5000,
8887
'DD_TRACE_GENERATE_ROOT_SPAN' => 'true',
89-
]
88+
],
89+
[],
90+
'',
91+
false,
92+
$this->untilNumberOfTraces(2)
9093
);
9194

9295
$this->assertCount(2, $requests);
@@ -112,7 +115,6 @@ public function testAccessingTracerAfterForkIsUnproblematic()
112115
__DIR__ . '/scripts/access-tracer-after-fork.php',
113116
[
114117
'DD_TRACE_CLI_ENABLED' => 'true',
115-
'DD_TRACE_SHUTDOWN_TIMEOUT' => 5000,
116118
'DD_TRACE_GENERATE_ROOT_SPAN' => 'true',
117119
'DD_TRACE_DEBUG' => 'false',
118120
],
@@ -137,9 +139,12 @@ public function testCliShortRunningMainSpanAreGenerateBeforeAndAfter()
137139
__DIR__ . '/scripts/short-running.php',
138140
[
139141
'DD_TRACE_CLI_ENABLED' => 'true',
140-
'DD_TRACE_SHUTDOWN_TIMEOUT' => 5000,
141142
'DD_TRACE_GENERATE_ROOT_SPAN' => 'true',
142-
]
143+
],
144+
[],
145+
'',
146+
false,
147+
$this->untilNumberOfTraces(2)
143148
);
144149

145150
$this->assertCount(2, $requests);
@@ -165,9 +170,12 @@ public function testCliShortRunningMultipleForks()
165170
__DIR__ . '/scripts/short-running-multiple.php',
166171
[
167172
'DD_TRACE_CLI_ENABLED' => 'true',
168-
'DD_TRACE_SHUTDOWN_TIMEOUT' => 5000,
169173
'DD_TRACE_GENERATE_ROOT_SPAN' => 'true',
170-
]
174+
],
175+
[],
176+
'',
177+
false,
178+
$this->untilNumberOfTraces(6)
171179
);
172180

173181
$this->assertCount(6, $requests);
@@ -204,7 +212,6 @@ public function testCliShortRunningMultipleNestedForks()
204212
__DIR__ . '/scripts/short-running-multiple-nested.php',
205213
[
206214
'DD_TRACE_CLI_ENABLED' => 'true',
207-
'DD_TRACE_SHUTDOWN_TIMEOUT' => 5000,
208215
'DD_TRACE_GENERATE_ROOT_SPAN' => 'true',
209216
]
210217
);
@@ -238,32 +245,34 @@ public function testCliShortRunningMultipleNestedForks()
238245

239246
public function testCliLongRunningMultipleForksAutoFlush()
240247
{
241-
list($requests) = $this->inCli(
248+
$this->inCli(
242249
__DIR__ . '/scripts/long-running-autoflush.php',
243250
[
244251
'DD_TRACE_CLI_ENABLED' => 'true',
245252
'DD_TRACE_AUTO_FLUSH_ENABLED' => 'true',
246253
'DD_TRACE_GENERATE_ROOT_SPAN' => 'false',
247-
'DD_TRACE_AGENT_FLUSH_INTERVAL' => 0,
248-
'DD_TRACE_SHUTDOWN_TIMEOUT' => 5000,
249-
]
250-
);
251-
$this->assertCount(4, $requests);
252-
253-
for ($i = 0; $i < 4; $i += 2) {
254-
$this->assertFlameGraph([$requests[$i]], [
255-
SpanAssertion::exists('curl_exec', '/httpbin_integration/ip'),
256-
]);
257-
258-
$this->assertFlameGraph([$requests[$i + 1]], [
259-
SpanAssertion::exists('long_running_entry_point')->withChildren([
260-
SpanAssertion::exists('curl_exec', '/httpbin_integration/get'),
261-
SpanAssertion::exists('curl_exec', '/httpbin_integration/headers'),
262-
SpanAssertion::exists('curl_exec', '/httpbin_integration/user-agent'),
254+
'DD_TRACE_AGENT_FLUSH_INTERVAL' => 333,
255+
],
256+
[],
257+
'',
258+
false,
259+
$this->until(
260+
$this->untilSpan(SpanAssertion::exists('curl_exec', '/httpbin_integration/child-0')),
261+
$this->untilSpan(SpanAssertion::exists('curl_exec', '/httpbin_integration/child-1')),
262+
$this->untilSpan(SpanAssertion::exists('long_running_entry_point')->withChildren([
263+
SpanAssertion::exists('curl_exec', '/httpbin_integration/entry_point-0'),
264+
SpanAssertion::exists('curl_exec', '/httpbin_integration/main_process-0'),
265+
SpanAssertion::exists('curl_exec', '/httpbin_integration/end_entry_point-0'),
263266
SpanAssertion::exists('pcntl_fork'),
264-
]),
265-
]);
266-
}
267+
])),
268+
$this->untilSpan(SpanAssertion::exists('long_running_entry_point')->withChildren([
269+
SpanAssertion::exists('curl_exec', '/httpbin_integration/entry_point-1'),
270+
SpanAssertion::exists('curl_exec', '/httpbin_integration/main_process-1'),
271+
SpanAssertion::exists('curl_exec', '/httpbin_integration/end_entry_point-1'),
272+
SpanAssertion::exists('pcntl_fork'),
273+
]))
274+
)
275+
);
267276
}
268277

269278
public function testCliLongRunningMultipleForksManualFlush()
@@ -278,8 +287,11 @@ public function testCliLongRunningMultipleForksManualFlush()
278287
'DD_TRACE_CLI_ENABLED' => 'true',
279288
'DD_TRACE_AUTO_FLUSH_ENABLED' => 'false',
280289
'DD_TRACE_GENERATE_ROOT_SPAN' => 'false',
281-
'DD_TRACE_SHUTDOWN_TIMEOUT' => 5000,
282-
]
290+
],
291+
[],
292+
'',
293+
false,
294+
$this->untilNumberOfTraces(6)
283295
);
284296
$this->assertCount(6, $requests);
285297

tests/Integrations/PCNTL/scripts/long-running-autoflush.php

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -10,26 +10,26 @@
1010
});
1111

1212
for ($iteration = 0; $iteration < ITERATIONS; $iteration++) {
13-
long_running_entry_point();
13+
long_running_entry_point($iteration);
1414
}
1515

16-
function long_running_entry_point()
16+
function long_running_entry_point($iteration)
1717
{
18-
call_httpbin('get');
18+
call_httpbin('entry_point-'.$iteration);
1919

2020
$forkPid = pcntl_fork();
2121

2222
if ($forkPid > 0) {
2323
// Main
24-
call_httpbin('headers');
24+
call_httpbin('main_process-'.$iteration);
2525
} else if ($forkPid === 0) {
2626
// Child
27-
call_httpbin('ip');
27+
call_httpbin('child-'.$iteration);
2828
exit(0);
2929
} else {
3030
error_log('Error');
3131
exit(-1);
3232
}
33-
call_httpbin('user-agent');
33+
call_httpbin('end_entry_point-'.$iteration);
3434
pcntl_waitpid($forkPid, $childStatus);
3535
}

tests/OpenTelemetry/Integration/InternalTelemetryTest.php

Lines changed: 1 addition & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -56,11 +56,7 @@ public function testInternalMetricWithOpenTelemetry()
5656

5757
$this->executeCommand();
5858

59-
$requests = $this->retrieveDumpedData(function ($request) {
60-
return (strpos($request["uri"] ?? "", "/telemetry/") === 0)
61-
&& (strpos($request["body"] ?? "", "spans_created") !== false)
62-
;
63-
}, true);
59+
$requests = $this->retrieveDumpedData($this->untilTelemetryRequest("spans_created"));
6460

6561
$payloads = $this->readTelemetryPayloads($requests);
6662
$isMetric = function (array $payload) {

0 commit comments

Comments
 (0)