refactor(agent): improve logging when adding named tracers

agent/php_user_instrument.c

@@ -545,6 +545,7 @@ static inline bool nr_php_user_instrument_is_name_valid(const char* namestr,
 nruserfn_t* nr_php_add_custom_tracer_named(const char* namestr,
                                            size_t namestrlen) {
   nruserfn_t* wraprec;
+  bool is_new_wraprec = true;
 
   if (!nr_php_user_instrument_is_name_valid(namestr, namestrlen)) {
     return NULL;
@@ -571,10 +572,11 @@ nruserfn_t* nr_php_add_custom_tracer_named(const char* namestr,
     }
   }
 #else
-  wraprec = nr_php_user_instrument_wraprec_hashmap_add(namestr, namestrlen);
+  wraprec = nr_php_user_instrument_wraprec_hashmap_add(namestr, namestrlen, &is_new_wraprec);
 #endif
   nrl_verbosedebug(
-      NRL_INSTRUMENT, "adding custom for '" NRP_FMT_UQ "%.5s" NRP_FMT_UQ "'",
+      NRL_INSTRUMENT, "%s custom for '" NRP_FMT_UQ "%.5s" NRP_FMT_UQ "'",
+      is_new_wraprec ? "adding" : "reusing",
       NRP_PHP(wraprec->classname),
       (0 == wraprec->classname) ? "" : "::", NRP_PHP(wraprec->funcname));
 

agent/php_user_instrument_wraprec_hashmap.c

@@ -394,7 +394,7 @@ void nr_php_user_instrument_wraprec_hashmap_init(void) {
  * - namestrlen be greater than 0
  * - namestr must not be NULL and must not end with `:` (colon) . */
 
-nruserfn_t* nr_php_user_instrument_wraprec_hashmap_add(const char* namestr, size_t namestrlen) {
+nruserfn_t* nr_php_user_instrument_wraprec_hashmap_add(const char* namestr, size_t namestrlen, bool *is_new_wraprec_ptr) {
   nr_scope_hashmap_key_t scope_key = {0};
   nr_func_hashmap_key_t func_key = {0};
   nr_func_hashmap_t* funcs_ht = NULL;
@@ -437,8 +437,10 @@ nruserfn_t* nr_php_user_instrument_wraprec_hashmap_add(const char* namestr, size
 
     wraprec->supportability_metric = nr_txn_create_fn_supportability_metric(
         wraprec->funcname, wraprec->classname);
-  } else {
-    nrl_verbosedebug(NRL_INSTRUMENT, "reusing custom wrapper for '%s'", namestr);
+  }
+
+  if (NULL != is_new_wraprec_ptr) {
+    *is_new_wraprec_ptr = is_new_wraprec;
   }
 
   return wraprec;

agent/php_user_instrument_wraprec_hashmap.h

@@ -11,7 +11,7 @@
 // clang-format off
 
 extern void nr_php_user_instrument_wraprec_hashmap_init(void);
-extern nruserfn_t* nr_php_user_instrument_wraprec_hashmap_add(const char* namestr, size_t namestrlen);
+extern nruserfn_t* nr_php_user_instrument_wraprec_hashmap_add(const char* namestr, size_t namestrlen, bool *is_new_wraprec_ptr);
 extern nruserfn_t* nr_php_user_instrument_wraprec_hashmap_get(zend_string *func_name, zend_string *scope_name);
 extern void nr_php_user_instrument_wraprec_hashmap_destroy(void);
 

agent/tests/test_user_instrument_wraprec_hashmap.c

@@ -20,49 +20,129 @@ tlib_parallel_info_t parallel_info
 #define FUNCTION_NAME "global_function"
 
 static void test_wraprecs_hashmap() {
-  nruserfn_t *wraprec, *found_wraprec;
-  zend_string *func_name, *scope_name, *method_name;
+  nruserfn_t *wraprec, *another_method_wraprec, *yet_another_method_wraprec, *found_wraprec;
+  zend_string *func_name, *scope_name, *method_name, *scope, *method;
+  bool is_new_wraprec = false;
+  bool *is_new_wraprec_tests[] = {NULL, &is_new_wraprec};
 
   func_name = zend_string_init(NR_PSTR(FUNCTION_NAME), 0);
   scope_name = zend_string_init(NR_PSTR(SCOPE_NAME), 0);
   method_name = zend_string_init(NR_PSTR(METHOD_NAME), 0);
 
-  // user_instrument_wraprec_hashmap is initialized at minit
-  // destroy it to test agent's behavior when it is not initialized
-  nr_php_user_instrument_wraprec_hashmap_destroy();
-
-  // Test valid operations before initializing the hashmap
-  wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(FUNCTION_NAME));
-  tlib_pass_if_null("adding valid function before init", wraprec);
-  wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(SCOPED_METHOD_NAME));
-  tlib_pass_if_null("adding valid method before init", wraprec);
-
-  // Initialize the hashmap
-  nr_php_user_instrument_wraprec_hashmap_init();
-
-  // Test valid operations after initializing the hashmap
-  wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(FUNCTION_NAME));
-  tlib_pass_if_not_null("adding valid global function", wraprec);
-
-  found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(func_name, NULL);
-  tlib_pass_if_ptr_equal("getting valid global function", wraprec, found_wraprec);
-
-  found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(func_name, scope_name);
-  tlib_pass_if_null("getting global function with scope", found_wraprec);
-
-  wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(SCOPED_METHOD_NAME));
-  tlib_pass_if_not_null("adding valid scoped method", wraprec);
-
-  found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(method_name, scope_name);
-  tlib_pass_if_ptr_equal("getting scoped method", wraprec, found_wraprec);
-
-  found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(NULL, scope_name);
-  tlib_pass_if_null("getting scoped method without method name", found_wraprec);
-
-  found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(method_name, NULL);
-  tlib_pass_if_null("getting scoped method without scope", found_wraprec);
-
-  nr_php_user_instrument_wraprec_hashmap_destroy();
+  for (size_t i = 0; i < sizeof(is_new_wraprec_tests) / sizeof(is_new_wraprec_tests[0]); i++) {
+    bool *is_new_wraprec_ptr = is_new_wraprec_tests[i];
+    // user_instrument_wraprec_hashmap is initialized at minit
+    // destroy it to test agent's behavior when it is not initialized
+    nr_php_user_instrument_wraprec_hashmap_destroy();
+
+    // Test valid operations before initializing the hashmap
+    wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(FUNCTION_NAME),
+                                                        is_new_wraprec_ptr);
+    tlib_pass_if_null("adding valid function before init", wraprec);
+    if (NULL != is_new_wraprec_ptr) {
+    tlib_pass_if_false("adding valid function before init", *is_new_wraprec_ptr,
+                      "expected false for is_new_wraprec");
+    }
+    wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(SCOPED_METHOD_NAME),
+                                                        is_new_wraprec_ptr);
+    tlib_pass_if_null("adding valid method before init", wraprec);
+    if (NULL != is_new_wraprec_ptr) {
+    tlib_pass_if_false("adding valid function before init", *is_new_wraprec_ptr,
+                      "expected false for is_new_wraprec");
+    }
+
+    // Initialize the hashmap
+    nr_php_user_instrument_wraprec_hashmap_init();
+
+    // Test valid operations after initializing the hashmap
+    wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(FUNCTION_NAME),
+                                                        is_new_wraprec_ptr);
+    tlib_pass_if_not_null("adding valid global function", wraprec);
+    if (NULL != is_new_wraprec_ptr) {
+      tlib_pass_if_true("adding valid global function", *is_new_wraprec_ptr,
+                        "expected true for is_new_wraprec");
+    }
+
+    found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(func_name, NULL);
+    tlib_pass_if_ptr_equal("getting valid global function", wraprec, found_wraprec);
+
+    wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(FUNCTION_NAME),
+                                                        is_new_wraprec_ptr);
+    tlib_pass_if_not_null("adding valid global function one more time", wraprec);
+    if (NULL != is_new_wraprec_ptr) {
+      tlib_pass_if_false("adding valid global function one more time", *is_new_wraprec_ptr,
+                        "expected false for is_new_wraprec");
+    }
+    tlib_pass_if_ptr_equal("getting valid global function one more time", wraprec, found_wraprec);
+
+    found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(func_name, scope_name);
+    tlib_pass_if_null("getting global function with scope", found_wraprec);
+
+    wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(SCOPED_METHOD_NAME),
+                                                        is_new_wraprec_ptr);
+    tlib_pass_if_not_null("adding valid scoped method", wraprec);
+    if (NULL != is_new_wraprec_ptr) {
+      tlib_pass_if_true("adding valid scoped function", *is_new_wraprec_ptr,
+                        "expected true for is_new_wraprec");
+    }
+
+    found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(method_name, scope_name);
+    tlib_pass_if_ptr_equal("getting scoped method", wraprec, found_wraprec);
+
+    wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(SCOPED_METHOD_NAME),
+                                                        is_new_wraprec_ptr);
+    tlib_pass_if_not_null("adding valid scoped method one more time", wraprec);
+    if (NULL != is_new_wraprec_ptr) {
+      tlib_pass_if_false("adding valid scoped method one more time", *is_new_wraprec_ptr,
+                        "expected false for is_new_wraprec");
+    }
+    tlib_pass_if_ptr_equal("getting valid scoped method one more time", wraprec, found_wraprec);
+
+    found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(NULL, scope_name);
+    tlib_pass_if_null("getting scoped method without method name", found_wraprec);
+
+    found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(method_name, NULL);
+    tlib_pass_if_null("getting scoped method without scope", found_wraprec);
+
+    another_method_wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(SCOPE_NAME "::anotherMethod"),
+                                                                        is_new_wraprec_ptr);
+    tlib_pass_if_not_null("adding another scoped method", another_method_wraprec);
+    if (NULL != is_new_wraprec_ptr) {
+      tlib_pass_if_true("adding another scoped method", *is_new_wraprec_ptr,
+                        "expected true for is_new_wraprec");
+    }
+    scope = zend_string_init_fast(NR_PSTR(SCOPE_NAME));
+    method = zend_string_init_fast(NR_PSTR("anotherMethod"));
+    found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(method, scope);
+    tlib_pass_if_ptr_equal("getting another scoped method", another_method_wraprec, found_wraprec);
+
+    another_method_wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(SCOPE_NAME "::anotherMethod"),
+                                                                        is_new_wraprec_ptr);
+    tlib_pass_if_not_null("adding another scoped method one more time", another_method_wraprec);
+    if (NULL != is_new_wraprec_ptr) {
+      tlib_pass_if_false("adding another scoped method one more time", *is_new_wraprec_ptr,
+                         "expected false for is_new_wraprec");
+    }
+    tlib_pass_if_ptr_equal("getting another scoped method one more time", another_method_wraprec, found_wraprec);
+    zend_string_free(method);
+    zend_string_free(scope);
+
+    yet_another_method_wraprec = nr_php_user_instrument_wraprec_hashmap_add(NR_PSTR(SCOPE_NAME "::anotherMethodStill"),
+                                                                            is_new_wraprec_ptr);
+    tlib_pass_if_not_null("adding yet another scoped method", yet_another_method_wraprec);
+    if (NULL != is_new_wraprec_ptr) {
+      tlib_pass_if_true("adding yet another scoped method", *is_new_wraprec_ptr,
+                        "expected true for is_new_wraprec");
+    }
+    scope = zend_string_init_fast(NR_PSTR(SCOPE_NAME));
+    method = zend_string_init_fast(NR_PSTR("anotherMethodStill"));
+    found_wraprec = nr_php_user_instrument_wraprec_hashmap_get(method, scope);
+    tlib_pass_if_ptr_equal("getting another scoped method", yet_another_method_wraprec, found_wraprec);
+    zend_string_free(method);
+    zend_string_free(scope);
+
+    nr_php_user_instrument_wraprec_hashmap_destroy();
+  }
 
   zend_string_free(func_name);
   zend_string_free(scope_name);