Merge pull request #543 from newrelic/dev

Release 10.2.0

VERSION

@@ -1 +1 @@
-10.1.0
+10.2.0

agent/fw_drupal.c

@@ -230,20 +230,6 @@ NR_PHP_WRAPPER(nr_drupal_http_request_exec) {
         = {.library = "Drupal",
            .uri = nr_strndup(Z_STRVAL_P(arg1), Z_STRLEN_P(arg1))};
 
-    segment = nr_segment_start(NRPRG(txn), NULL, NULL);
-
-    /*
-     * Our wrapper for drupal_http_request (which we installed in
-     * nr_drupal_replace_http_request()) will take care of adding the request
-     * headers, so let's just go ahead and call the function.
-     */
-    NR_PHP_WRAPPER_CALL;
-
-    external_params.encoded_response_header
-        = nr_drupal_http_request_get_response_header(return_value TSRMLS_CC);
-
-    external_params.status
-        = nr_drupal_http_request_get_response_code(return_value TSRMLS_CC);
     /*
      * Drupal 6 will have a third argument with the method, Drupal 7 will not
      * have a third argument it must be parsed from the second.
@@ -269,6 +255,20 @@ NR_PHP_WRAPPER(nr_drupal_http_request_exec) {
       external_params.procedure = nr_strdup("GET");
     }
 
+    segment = nr_segment_start(NRPRG(txn), NULL, NULL);
+
+    /*
+     * Our wrapper for drupal_http_request (which we installed in
+     * nr_drupal_replace_http_request()) will take care of adding the request
+     * headers, so let's just go ahead and call the function.
+     */
+    NR_PHP_WRAPPER_CALL;
+
+    external_params.encoded_response_header
+        = nr_drupal_http_request_get_response_header(return_value TSRMLS_CC);
+
+    external_params.status
+        = nr_drupal_http_request_get_response_code(return_value TSRMLS_CC);
     if (NRPRG(txn) && NRTXN(special_flags.debug_cat)) {
       nrl_verbosedebug(
           NRL_CAT, "CAT: outbound response: transport='Drupal 6-7' %s=" NRP_FMT,

agent/php_environment.c

@@ -479,8 +479,8 @@ static void nr_php_get_environment_variables(TSRMLS_D) {
    * it.
    */
   if (NULL == environ) {
-    nrl_warning(NRL_AGENT, "%s: Unable to access environmental variables.",
-                __func__);
+    nrl_verbosedebug(NRL_AGENT, "%s: Unable to access environmental variables.",
+                     __func__);
     return;
   }
 

agent/php_nrini.c

@@ -1825,10 +1825,11 @@ static PHP_INI_MH(nr_log_forwarding_log_level_mh) {
     nrl_debug(NRL_INIT, "Log Level (PSR-3): %s", NEW_VALUE);
 
     log_level = nr_log_level_str_to_int(NEW_VALUE);
-    if (LOG_LEVEL_UNKNOWN ==  log_level) {
+    if (LOG_LEVEL_UNKNOWN == log_level) {
       log_level = LOG_LEVEL_DEFAULT;
-      nrl_warning(NRL_INIT, "Unknown log forwarding level %s, using %s instead.",
-      NEW_VALUE, nr_log_level_rfc_to_psr(log_level));
+      nrl_warning(NRL_INIT,
+                  "Unknown log forwarding level %s, using %s instead.",
+                  NEW_VALUE, nr_log_level_rfc_to_psr(log_level));
     }
     p->value = log_level;
     p->where = stage;
@@ -2872,15 +2873,15 @@ STD_PHP_INI_ENTRY_EX("newrelic.application_logging.enabled",
                      logging_enabled,
                      zend_newrelic_globals,
                      newrelic_globals,
-                     0)
+                     nr_enabled_disabled_dh)
 STD_PHP_INI_ENTRY_EX("newrelic.application_logging.forwarding.enabled",
                      "0",
                      NR_PHP_REQUEST,
                      nr_boolean_mh,
                      log_forwarding_enabled,
                      zend_newrelic_globals,
                      newrelic_globals,
-                     0)
+                     nr_enabled_disabled_dh)
 STD_PHP_INI_ENTRY_EX(
     "newrelic.application_logging.forwarding.max_samples_stored",
     NR_STR2(NR_DEFAULT_LOG_EVENTS_MAX_SAMPLES_STORED),
@@ -2905,7 +2906,7 @@ STD_PHP_INI_ENTRY_EX("newrelic.application_logging.metrics.enabled",
                      log_metrics_enabled,
                      zend_newrelic_globals,
                      newrelic_globals,
-                     0)
+                     nr_enabled_disabled_dh)
 
 PHP_INI_END() /* } */
 

axiom/nr_log_event.c

@@ -37,6 +37,18 @@ void nr_log_event_destroy(nr_log_event_t** ptr) {
   nr_realfree((void**)ptr);
 }
 
+/*
+ * Purpose : Adds a field to jsonified log event
+ *
+ * Params  :
+ *           1. Pointer to buffer (nrbuf_t*)
+ *           2. Name of the field (JSON key)
+ *           3. Value of the field (JSON value)
+ *           4. Boolean indicating if this is the first field
+ *           5. Boolean indicating if this field is required
+ *
+ * Returns : True is data was added to buf.
+ */
 static bool add_log_field_to_buf(nrbuf_t* buf,
                                  const char* field_name,
                                  const char* field_value,
@@ -63,9 +75,7 @@ static bool add_log_field_to_buf(nrbuf_t* buf,
   nr_buffer_add(buf, field_name, nr_strlen(field_name));
   nr_buffer_add(buf, NR_PSTR("\""));
   nr_buffer_add(buf, NR_PSTR(":"));
-  nr_buffer_add(buf, NR_PSTR("\""));
-  nr_buffer_add(buf, final_value, nr_strlen(final_value));
-  nr_buffer_add(buf, NR_PSTR("\""));
+  nr_buffer_add_escape_json(buf, final_value);
 
   return true;
 }

axiom/nr_version.c

@@ -31,8 +31,9 @@
  *   allium             14Mar2022 (9.20)
  *   buttercup          26Apr2022 (9.21)
  *   cosmos		29Jun2022 (10.0)
+ *   dahlia		19Sep2022 (10.1)
  */
-#define NR_CODENAME "dahlia"
+#define NR_CODENAME "echinacea"
 
 const char* nr_version(void) {
   return NR_STR2(NR_VERSION);

axiom/tests/test_log_event.c

@@ -77,6 +77,44 @@ static void test_log_event_to_json(void) {
                          json);
   nr_free(json);
   nr_log_event_destroy(&log);
+
+  /*
+   * Test message with characters which require JSON escaping
+   * "
+   * \
+   * /
+   * \b
+   * \f
+   * \n
+   * \r
+   * \t
+   * GB pound sign (example of unicode)
+   */
+  log = nr_log_event_create();
+  nr_log_event_set_log_level(log, "LOG_LEVEL_TEST_ERROR");
+  nr_log_event_set_message(log, "\" \\ / \b \f \n \r \t GBP sign \xc2\xa3xxx");
+  nr_log_event_set_timestamp(log, 12345000);
+  nr_log_event_set_trace_id(log, "test id 1");
+  nr_log_event_set_span_id(log, "test id 2");
+  nr_log_event_set_guid(log, "test id 3");
+  nr_log_event_set_entity_name(log, "entity name here");
+  nr_log_event_set_hostname(log, "host name here");
+  json = nr_log_event_to_json(log);
+  tlib_pass_if_str_equal(
+      "requires escaping for JSON event",
+      "{"
+      "\"message\":\"\\\" \\\\ \\/ \\b \\f \\n \\r \\t GBP sign \\u00a3xxx\","
+      "\"level\":\"LOG_LEVEL_TEST_ERROR\","
+      "\"trace.id\":\"test id 1\","
+      "\"span.id\":\"test id 2\","
+      "\"entity.guid\":\"test id 3\","
+      "\"entity.name\":\"entity name here\","
+      "\"hostname\":\"host name here\","
+      "\"timestamp\":12345"
+      "}",
+      json);
+  nr_free(json);
+  nr_log_event_destroy(&log);
 }
 
 static void test_log_event_to_json_buffer(void) {

src/newrelic/limits/limits.go

@@ -16,7 +16,13 @@ import (
 const (
 	// AppLimit is the maximum number of applications that the daemon will
 	// support.  The agent's limit is in nr_app.h.
+	// AppLimitNotifyHigh is the limit at which a notification will be output that
+	// the number of applications connected has reached this value from below.
+	// AppLimitNotifyLow is the lower limit at which a notification will be
+	// output that the number of applications has dropped to this point.
 	AppLimit                 = 250
+	AppLimitNotifyHigh       = 200
+	AppLimitNotifyLow        = 25
 	AppConnectAttemptBackoff = 30 * time.Second
 
 	// DefaultAppTimeout specifies the elapsed time after which an application

src/newrelic/processor.go

@@ -365,10 +365,14 @@ func (p *Processor) processAppInfo(m AppInfoMessage) {
 		return
 	}
 
-	if len(p.apps) > limits.AppLimit {
+	numapps := len(p.apps)
+	if numapps > limits.AppLimit {
 		log.Errorf("unable to add app '%s', limit of %d applications reached",
 			m.Info, limits.AppLimit)
 		return
+	} else if numapps == limits.AppLimitNotifyHigh {
+		log.Infof("approaching app limit of %d, current number of apps is %d",
+			limits.AppLimit, limits.AppLimitNotifyHigh)
 	}
 
 	app = NewApp(m.Info)
@@ -697,7 +701,6 @@ func harvestByType(ah *AppHarvest, args *harvestArgs, ht HarvestType) {
 		logEvents := harvest.LogEvents
 		harvest.LogEvents = NewLogEvents(eventConfigs.LogEventConfig.Limit)
 		considerHarvestPayload(logEvents, args)
-
 	}
 }
 
@@ -709,6 +712,10 @@ func (p *Processor) doHarvest(ph ProcessorHarvest) {
 	if p.cfg.AppTimeout > 0 && app.Inactive(p.cfg.AppTimeout) {
 		log.Infof("removing %q with run id %q for lack of activity within %v",
 			app, id, p.cfg.AppTimeout)
+		if len(p.apps) == limits.AppLimitNotifyLow {
+			log.Infof("current number of apps is %d",
+				limits.AppLimitNotifyLow)
+		}
 		p.shutdownAppHarvest(id)
 		delete(p.apps, app.Key())
 

tests/integration/logging/monolog2/test_monolog_escape_chars.php

@@ -0,0 +1,94 @@
+<?php
+/*
+ * Copyright 2022 New Relic Corporation. All rights reserved.
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+/*DESCRIPTION
+Test that Monolog2 instrumentation escapes characters
+properly when encoding to JSON
+*/
+
+/*SKIPIF
+<?php
+require('skipif.inc');
+*/
+
+/*INI
+newrelic.loglevel = verbosedebug
+newrelic.application_logging.enabled = true
+newrelic.application_logging.forwarding.enabled = true
+newrelic.application_logging.metrics.enabled = true
+newrelic.application_logging.forwarding.max_samples_stored = 10
+newrelic.application_logging.forwarding.log_level = DEBUG
+*/
+
+/*EXPECT_METRICS
+[
+  "?? agent run id",
+  "?? timeframe start",
+  "?? timeframe stop",
+  [
+    [{"name": "DurationByCaller/Unknown/Unknown/Unknown/Unknown/all"},            [1, "??", "??", "??", "??", "??"]],
+    [{"name": "DurationByCaller/Unknown/Unknown/Unknown/Unknown/allOther"},       [1, "??", "??", "??", "??", "??"]],
+    [{"name": "Logging/lines"},                                                   [1, "??", "??", "??", "??", "??"]],
+    [{"name": "Logging/lines/DEBUG"},                                             [1, "??", "??", "??", "??", "??"]],
+    [{"name": "OtherTransaction/all"},                                            [1, "??", "??", "??", "??", "??"]],
+    [{"name": "OtherTransaction/php__FILE__"},                                    [1, "??", "??", "??", "??", "??"]],
+    [{"name": "OtherTransactionTotalTime"},                                       [1, "??", "??", "??", "??", "??"]],
+    [{"name": "OtherTransactionTotalTime/php__FILE__"},                           [1, "??", "??", "??", "??", "??"]],
+    [{"name": "Supportability/Logging/PHP/Monolog/enabled"},                      [1, "??", "??", "??", "??", "??"]],
+    [{"name": "Supportability/library/Monolog/detected"},                         [1, "??", "??", "??", "??", "??"]],
+    [{"name": "Supportability/Logging/Forwarding/PHP/enabled"},                   [1, "??", "??", "??", "??", "??"]],
+    [{"name": "Supportability/Logging/Metrics/PHP/enabled"},                      [1, "??", "??", "??", "??", "??"]]
+  ]
+]
+*/
+
+
+/*EXPECT_LOG_EVENTS
+[
+    {
+      "common": {
+        "attributes": {}
+      },
+      "logs": [   
+        {
+          "message": "This string has some characters which should be escaped: \" \\ \/ \b \f \n \r \t GBP sign \u00a3xxx",
+          "level": "DEBUG",
+          "timestamp": "??",
+          "trace.id": "??",
+          "span.id": "??",
+          "entity.guid": "??",
+          "entity.name": "tests/integration/logging/monolog2__FILE__",
+          "hostname": "__HOST__"
+        }
+      ]
+    }
+  ]
+ */
+
+require_once(realpath(dirname(__FILE__)) . '/../../../include/config.php');
+require_once(realpath(dirname(__FILE__)) . '/../../../include/monolog.php');
+require_monolog(2);
+
+use Monolog\Logger;
+use Monolog\Handler\StreamHandler;
+use Monolog\Formatter\LineFormatter;
+
+
+function test_logging() {
+    $logger = new Logger('monolog2');
+
+    $logfmt = "%channel%.%level_name%: %message% %context%\n";
+    $formatter = new LineFormatter($logfmt);
+
+    $stdoutHandler = new StreamHandler('php://stdout', Logger::DEBUG);
+    $stdoutHandler->setFormatter($formatter);
+
+    $logger->pushHandler($stdoutHandler);
+
+    $logger->debug("This string has some characters which should be escaped: \" \\ / \x08 \f \n \r \t GBP sign \xc2\xa3xxx");
+}
+
+test_logging();