Add 'library_entrypoint.start' metric (#3009)

Author: iamluc

loader/dd_library_loader.c

@@ -233,6 +233,7 @@ static void ddloader_telemetryf(telemetry_reason reason, const char *error, cons
         case REASON_INCOMPATIBLE_RUNTIME:
             LOG(ERROR, "Aborting application instrumentation due to an incompatible runtime");
             break;
+        case REASON_START:
         case REASON_COMPLETE:
         case REASON_ALREADY_LOADED:
             level = INFO;
@@ -268,6 +269,13 @@ static void ddloader_telemetryf(telemetry_reason reason, const char *error, cons
     char points_buf[256] = {0};
     char *points = points_buf;
     switch (reason) {
+        case REASON_START:
+            points =
+                "\
+                {\"name\": \"library_entrypoint.start\", \"tags\": []}\
+            ";
+            break;
+
         case REASON_ERROR:
             snprintf(points_buf, sizeof(points_buf), "\
                     {\"name\": \"library_entrypoint.error\", \"tags\": [\"error_type:%s\"]}\
@@ -654,6 +662,8 @@ static int ddloader_api_no_check(int api_no) {
 
     ddloader_configure();
 
+    TELEMETRY(REASON_START, NULL, "Starting injection");
+
     switch (api_no) {
         case 220040412:
             runtime_version = "5.0";

loader/php_dd_library_loader.h

@@ -21,6 +21,7 @@ void ddloader_logv(log_level level, const char *format, va_list va);
 void ddloader_logf(log_level level, const char *format, ...);
 
 typedef enum {
+    REASON_START,
     REASON_ERROR,
     REASON_EOL_RUNTIME,
     REASON_INCOMPATIBLE_RUNTIME,

loader/tests/functional/includes/assert.php

@@ -1,8 +1,11 @@
 <?php
 
-function assertEquals($actual, $expected) {
+function assertEquals($actual, $expected, $msg = null) {
     if ($actual !== $expected) {
-        throw new \Exception(sprintf('Cannot assert "%s" equals "%s"', $actual, $expected));
+        if (!$msg) {
+            $msg = sprintf('Cannot assert "%s" equals "%s"', $actual, $expected);
+        }
+        throw new \Exception($msg);
     }
 }
 
@@ -68,3 +71,41 @@ function assertMatchesFormat($output, $wanted_re) {
         throw new \Exception("Output does not match the format\n".$output);
     }
 }
+
+function assertTelemetry($telemetryLogPath, $format) {
+    $lines = file($telemetryLogPath);
+    assertEquals(count($lines), 2, "2 metrics were expected, but got ".count($lines));
+
+    $start = $lines[0];
+    $end = $lines[1];
+
+    // The order is not guaranteed
+    if (strpos($start, 'library_entrypoint.start') === false) {
+        $start = $lines[1];
+        $end = $lines[0];
+    }
+
+    $payload = json_decode($start, true);
+    $startFormat = <<<EOS
+{
+    "metadata": {
+        "runtime_name": "php",
+        "runtime_version": "unknown",
+        "language_name": "php",
+        "language_version": "unknown",
+        "tracer_version": "unknown",
+        "pid": %d
+    },
+    "points": [
+        {
+            "name": "library_entrypoint.start",
+            "tags": []
+        }
+    ]
+}
+EOS;
+    assertMatchesFormat(json_encode($payload, JSON_PRETTY_PRINT), $startFormat);
+
+    $payload = json_decode($end, true);
+    assertMatchesFormat(json_encode($payload, JSON_PRETTY_PRINT), $format);
+}

loader/tests/functional/includes/autoload.php

@@ -6,10 +6,17 @@
     $trace = $ex->getTrace();
     $file = $trace[0]['file'] ?: '';
     $line = $trace[0]['line'] ?: '';
+    $stackTrace = basename($file).':'.$line;
+
+    if (basename($file) === 'assert.php') {
+        $file2 = $trace[1]['file'] ?: '';
+        $line2 = $trace[1]['line'] ?: '';
+        $stackTrace = basename($file2).':'.$line2.' > '.$stackTrace;
+    }
 
     echo "------------------------------------\n";
     if ($file) {
-        echo 'Error in test '.basename($file).':'.$line."\n";
+        echo 'Error in test '.$stackTrace."\n";
         echo "------------------------------------\n";
     }
     echo $ex->getMessage()."\n";

loader/tests/functional/test_ddtrace_already_loaded.php

@@ -27,9 +27,6 @@
 // Let time to the fork to write the telemetry log
 usleep(5000);
 
-$raw = file_get_contents($telemetryLogPath);
-$payload = json_decode($raw, true);
-
 $format = <<<EOS
 {
     "metadata": {
@@ -50,5 +47,4 @@
     ]
 }
 EOS;
-
-assertMatchesFormat(json_encode($payload, JSON_PRETTY_PRINT), $format);
+assertTelemetry($telemetryLogPath, $format);

loader/tests/functional/test_telemetry_complete.php

@@ -13,9 +13,6 @@
 // Let time to the fork to write the telemetry log
 usleep(5000);
 
-$raw = file_get_contents($telemetryLogPath);
-$payload = json_decode($raw, true);
-
 $format = <<<EOS
 {
     "metadata": {
@@ -36,5 +33,4 @@
     ]
 }
 EOS;
-
-assertMatchesFormat(json_encode($payload, JSON_PRETTY_PRINT), $format);
+assertTelemetry($telemetryLogPath, $format);

loader/tests/functional/test_telemetry_error.php

@@ -14,9 +14,6 @@
 // Let time to the fork to write the telemetry log
 usleep(5000);
 
-$raw = file_get_contents($telemetryLogPath);
-$payload = json_decode($raw, true);
-
 $format = <<<EOS
 {
     "metadata": {
@@ -37,5 +34,4 @@
     ]
 }
 EOS;
-
-assertMatchesFormat(json_encode($payload, JSON_PRETTY_PRINT), $format);
+assertTelemetry($telemetryLogPath, $format);

loader/tests/functional/test_telemetry_php5.php

@@ -13,9 +13,6 @@
 // Let time to the fork to write the telemetry log
 usleep(5000);
 
-$raw = file_get_contents($telemetryLogPath);
-$payload = json_decode($raw, true);
-
 $format = <<<EOS
 {
     "metadata": {
@@ -39,5 +36,4 @@
     ]
 }
 EOS;
-
-assertMatchesFormat(json_encode($payload, JSON_PRETTY_PRINT), $format);
+assertTelemetry($telemetryLogPath, $format);