From 151e41ae43f66accd1dd684863ac942e361dfe2c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ferm=C3=ADn=20Gal=C3=A1n=20M=C3=A1rquez?= Date: Tue, 19 Dec 2023 16:17:40 +0100 Subject: [PATCH 01/10] FIX false positive in log deprecation logic when entity name (or other literal) includes the token v1 --- CHANGES_NEXT_RELEASE | 1 + src/lib/common/logTracing.cpp | 2 +- ...lse_positive_in_log_deprecation_logic.test | 98 +++++++++++++++++++ 3 files changed, 100 insertions(+), 1 deletion(-) create mode 100644 test/functionalTest/cases/4454_false_positive_in_log_deprecation_logic/false_positive_in_log_deprecation_logic.test diff --git a/CHANGES_NEXT_RELEASE b/CHANGES_NEXT_RELEASE index 0c8dcd255b..f65bd57a35 100644 --- a/CHANGES_NEXT_RELEASE +++ b/CHANGES_NEXT_RELEASE @@ -6,6 +6,7 @@ - Fix: improve error traces (#4387) - Add: CLI parameter -dbUri / env var ORION_MONGO_URI (#3794) - Fix: improve logs in MongoDB query logic +- Fix: false positive in log deprecation logic when entity name (or other literal) includes the token "v1" (#4454) - Upgrade Debian version from 11.6 to 12.1 in Dockerfile - Hardening: upgrade libmongoc dependency from 1.23.1 to 1.24.3 - Reference MongoDB version changed from 4.4 to 6.0 diff --git a/src/lib/common/logTracing.cpp b/src/lib/common/logTracing.cpp index 26904d5628..41539e2907 100644 --- a/src/lib/common/logTracing.cpp +++ b/src/lib/common/logTracing.cpp @@ -37,7 +37,7 @@ */ inline bool isNgsiV1Url(const char* url) { - return (strstr(url, "v1") || strcasestr(url, "ngsi10") || strcasestr(url, "ngsi9")); + return (strstr(url, "/v1/") || strcasestr(url, "/ngsi10/") || strcasestr(url, "/ngsi9/")); } diff --git a/test/functionalTest/cases/4454_false_positive_in_log_deprecation_logic/false_positive_in_log_deprecation_logic.test b/test/functionalTest/cases/4454_false_positive_in_log_deprecation_logic/false_positive_in_log_deprecation_logic.test new file mode 100644 index 0000000000..8a6212d562 --- /dev/null +++ b/test/functionalTest/cases/4454_false_positive_in_log_deprecation_logic/false_positive_in_log_deprecation_logic.test @@ -0,0 +1,98 @@ +# Copyright 2023 Telefonica Investigacion y Desarrollo, S.A.U +# +# This file is part of Orion Context Broker. +# +# Orion Context Broker is free software: you can redistribute it and/or +# modify it under the terms of the GNU Affero General Public License as +# published by the Free Software Foundation, either version 3 of the +# License, or (at your option) any later version. +# +# Orion Context Broker is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU Affero +# General Public License for more details. +# +# You should have received a copy of the GNU Affero General Public License +# along with Orion Context Broker. If not, see http://www.gnu.org/licenses/. +# +# For those usages not covered by this license please contact with +# iot_support at tid dot es + +# VALGRIND_READY - to mark the test ready for valgrindTestSuite.sh + +--NAME-- +Disable NGSIv1 CLI + +--SHELL-INIT-- +dbInit CB +brokerStart CB 0 IPV4 -logDeprecate + +--SHELL-- + +# +# 01. GET /v2/entities/glory_ev1 +# 02. GET /v1/contextEntities/glory_ev2/attributes/A +# 03. Get WARNING trace in logs corresponding only to the second case +# + +echo "01. GET /v2/entities/glory_ev1" +echo "==============================" +orionCurl --url /v2/entities/glory_ev1 +echo +echo + + +echo "02. GET /v1/contextEntities/glory_ev2/attributes/A" +echo "==================================================" +orionCurl --url /v1/contextEntities/glory_ev2/attributes/A +echo +echo + + +echo "03. Get WARNING trace in logs corresponding only to the second case" +echo "===================================================================" +cat /tmp/contextBroker.log | grep 'WARN' | awk -F 'msg=' '{print $2}' +echo +echo + + +--REGEXPECT-- +01. GET /v2/entities/glory_ev1 +============================== +HTTP/1.1 404 Not Found +Date: REGEX(.*) +Fiware-Correlator: REGEX([0-9a-f\-]{36}) +Content-Type: application/json +Content-Length: 95 + +{ + "description": "The requested entity has not been found. Check type and id", + "error": "NotFound" +} + + +02. GET /v1/contextEntities/glory_ev2/attributes/A +================================================== +HTTP/1.1 200 OK +Date: REGEX(.*) +Fiware-Correlator: REGEX([0-9a-f\-]{36}) +Content-Type: application/json +Content-Length: 106 + +{ + "statusCode": { + "code": "404", + "details": "Entity id: /glory_ev2/", + "reasonPhrase": "No context element found" + } +} + + +03. Get WARNING trace in logs corresponding only to the second case +=================================================================== +Deprecated NGSIv1 request received: GET /v1/contextEntities/glory_ev2/attributes/A, response code: 200 + + +--TEARDOWN-- +brokerStop CB +dbDrop CB From 314abdf97b6eaa70174e0678a41c3adfa79eea47 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ferm=C3=ADn=20Gal=C3=A1n=20M=C3=A1rquez?= Date: Tue, 19 Dec 2023 17:11:21 +0100 Subject: [PATCH 02/10] ADD notification payload in INFO log traces --- CHANGES_NEXT_RELEASE | 1 + src/lib/common/logTracing.cpp | 91 +++++++++++++------ src/lib/common/logTracing.h | 9 +- src/lib/ngsiNotify/doNotify.cpp | 6 +- .../log_deprecate_warning.test | 2 +- .../3001_mqtt_alarms/mqtt_alarms_none.test | 9 +- .../mqtt_alarms_raise_and_release.test | 6 +- .../mqtt_alarms_raise_repeat_and_release.test | 6 +- .../log_notifications.test | 31 +++---- 9 files changed, 101 insertions(+), 60 deletions(-) diff --git a/CHANGES_NEXT_RELEASE b/CHANGES_NEXT_RELEASE index 0c8dcd255b..d478714491 100644 --- a/CHANGES_NEXT_RELEASE +++ b/CHANGES_NEXT_RELEASE @@ -1,5 +1,6 @@ - Add: servicePath field to builtin attributes (#2877) - Add: notification.mqtt.retain and notification.mqttCustom.retain flag for MQTT retain in notifications (#4388) +- Add: notification payload in INFO log traces (#4449) - Fix: correctly detect JSON attribute and metadata value changes in subscription triggering logic (#4211, #4434, #643) - Fix: DateTime and geo:json types were not supported in custom notifications using ngsi patching (#4435) - Fix: logDeprecate not working correctly (`geo:json` wrongly considered as deprecated) diff --git a/src/lib/common/logTracing.cpp b/src/lib/common/logTracing.cpp index 26904d5628..3ecd573bf8 100644 --- a/src/lib/common/logTracing.cpp +++ b/src/lib/common/logTracing.cpp @@ -42,6 +42,28 @@ inline bool isNgsiV1Url(const char* url) +/* **************************************************************************** +* +* truncatePayload - +* +* NOTE: this function allocated dynamic memory, be careful with memory leaks! +*/ +static char* truncatePayload(const char* payload) +{ + // +5 due to "(...)" + // +1 due to '\0' + unsigned int truncatedPayloadLengh = logInfoPayloadMaxSize + 5 + 1; + + char* truncatedPayload = (char*) malloc(logInfoPayloadMaxSize + 5 + 1); + strncpy(truncatedPayload, payload, logInfoPayloadMaxSize); + strncpy(truncatedPayload + logInfoPayloadMaxSize, "(...)", 5); + truncatedPayload[truncatedPayloadLengh - 1] = '\0'; + + return truncatedPayload; +} + + + /* **************************************************************************** * * logInfoNotification - rc as int @@ -52,12 +74,13 @@ void logInfoHttpNotification const char* endpoint, const char* verb, const char* resource, + const char* payload, int rc ) { char buffer[STRING_SIZE_FOR_INT]; snprintf(buffer, sizeof(buffer), "%d", rc); - logInfoHttpNotification(subId, endpoint, verb, resource, buffer); + logInfoHttpNotification(subId, endpoint, verb, resource, payload, buffer); } @@ -72,10 +95,29 @@ void logInfoHttpNotification const char* endpoint, const char* verb, const char* resource, + const char* payload, const char* rc ) { - LM_I(("Notif delivered (subId: %s): %s %s%s, response code: %s", subId, verb, endpoint, resource, rc)); + bool cleanAfterUse = false; + char* effectivePayload; + + if (strlen(payload) > logInfoPayloadMaxSize) + { + effectivePayload = truncatePayload(payload); + cleanAfterUse = true; + } + else + { + effectivePayload = (char*) payload; + } + + LM_I(("Notif delivered (subId: %s): %s %s%s, payload (%d bytes): %s, response code: %s", subId, verb, endpoint, resource, strlen(payload), effectivePayload, rc)); + + if (cleanAfterUse) + { + free(effectivePayload); + } } @@ -88,10 +130,29 @@ void logInfoMqttNotification ( const char* subId, const char* endpoint, - const char* resource + const char* resource, + const char* payload ) { - LM_I(("MQTT Notif delivered (subId: %s): broker: %s, topic: %s", subId, endpoint, resource)); + bool cleanAfterUse = false; + char* effectivePayload; + + if (strlen(payload) > logInfoPayloadMaxSize) + { + effectivePayload = truncatePayload(payload); + cleanAfterUse = true; + } + else + { + effectivePayload = (char*) payload; + } + + LM_I(("MQTT Notif delivered (subId: %s): broker: %s, topic: %s, payload (%d bytes): %s", subId, endpoint, resource, strlen(payload), effectivePayload)); + + if (cleanAfterUse) + { + free(effectivePayload); + } } @@ -117,28 +178,6 @@ void logInfoRequestWithoutPayload -/* **************************************************************************** -* -* truncatePayload - -* -* NOTE: this function allocated dynamic memory, be careful with memory leaks! -*/ -static char* truncatePayload(const char* payload) -{ - // +5 due to "(...)" - // +1 due to '\0' - unsigned int truncatedPayloadLengh = logInfoPayloadMaxSize + 5 + 1; - - char* truncatedPayload = (char*) malloc(logInfoPayloadMaxSize + 5 + 1); - strncpy(truncatedPayload, payload, logInfoPayloadMaxSize); - strncpy(truncatedPayload + logInfoPayloadMaxSize, "(...)", 5); - truncatedPayload[truncatedPayloadLengh - 1] = '\0'; - - return truncatedPayload; -} - - - /* **************************************************************************** * * logInfoRequestWithPayload - diff --git a/src/lib/common/logTracing.h b/src/lib/common/logTracing.h index 4e3c7aac8c..939e2beb66 100644 --- a/src/lib/common/logTracing.h +++ b/src/lib/common/logTracing.h @@ -32,7 +32,7 @@ /* **************************************************************************** * -* logInfoNotification - rc as int +* logInfoHttpNotification - rc as int */ extern void logInfoHttpNotification ( @@ -40,6 +40,7 @@ extern void logInfoHttpNotification const char* endpoint, const char* verb, const char* resource, + const char* payload, int rc ); @@ -47,7 +48,7 @@ extern void logInfoHttpNotification /* **************************************************************************** * -* logInfoNotification - rc as string +* logInfoHttpNotification - rc as string */ extern void logInfoHttpNotification ( @@ -55,6 +56,7 @@ extern void logInfoHttpNotification const char* endpoint, const char* verb, const char* resource, + const char* payload, const char* rc ); @@ -68,7 +70,8 @@ extern void logInfoMqttNotification ( const char* subId, const char* endpoint, - const char* resource + const char* resource, + const char* payload ); diff --git a/src/lib/ngsiNotify/doNotify.cpp b/src/lib/ngsiNotify/doNotify.cpp index 7598643047..25f25b384f 100644 --- a/src/lib/ngsiNotify/doNotify.cpp +++ b/src/lib/ngsiNotify/doNotify.cpp @@ -127,11 +127,11 @@ static void doNotifyHttp(SenderThreadParams* params, CURL* curl, SyncQOverflowsubscriptionId.c_str(), endpoint.c_str(), params->verb.c_str(), params->resource.c_str(), statusCode); + logInfoHttpNotification(params->subscriptionId.c_str(), endpoint.c_str(), params->verb.c_str(), params->resource.c_str(), params->content.c_str(), statusCode); } else { - logInfoHttpNotification(params->subscriptionId.c_str(), endpoint.c_str(), params->verb.c_str(), params->resource.c_str(), out.c_str()); + logInfoHttpNotification(params->subscriptionId.c_str(), endpoint.c_str(), params->verb.c_str(), params->resource.c_str(), params->content.c_str(), out.c_str()); } } @@ -164,7 +164,7 @@ static void doNotifyMqtt(SenderThreadParams* params) // mqttOnPublishCallback is called (by the moment we are not doing nothing there, just printing in // DEBUG log level). Note however that even if mqttOnPublishCallback() is called there is no actual // guarantee if MQTT QoS is 0 - logInfoMqttNotification(params->subscriptionId.c_str(), endpoint.c_str(), params->resource.c_str()); + logInfoMqttNotification(params->subscriptionId.c_str(), endpoint.c_str(), params->resource.c_str(), params->content.c_str()); subNotificationErrorStatus(params->tenant, params->subscriptionId, false, -1, ""); } else diff --git a/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning.test b/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning.test index baf5d43988..a0a0704263 100644 --- a/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning.test +++ b/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning.test @@ -31,7 +31,7 @@ brokerStart CB 0 IPV4 -logDeprecate # # 01. Query E1-T1 -# 02. GET /v1/contextEntities/E +# 02. GET /v1/contextEntities/E/attributes/A # 03. Create entity using NGSIv1 metadata location # 04. Create entity using NGSIv1 and geo:point # 05. Create entity using NGSIv2 and geo:point diff --git a/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_none.test b/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_none.test index 00ad02a854..35ee20c7c3 100644 --- a/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_none.test +++ b/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_none.test @@ -61,6 +61,7 @@ orionCurl --url /v2/subscriptions --payload "$payload" echo echo +SUB_ID=$(echo "$_responseHeaders" | grep Location | awk -F/ '{ print $4 }' | tr -d "\r\n") echo "02. Upsert three times to trigger three MQTT notifications" echo "==========================================================" @@ -85,7 +86,7 @@ echo echo "03. Check logs and see three MQTT notifications and no alarms" echo "=============================================================" -cat /tmp/contextBroker.log | grep -v 'corr=N/A' | awk -F 'msg=' '{print $2}' +cat /tmp/contextBroker.log | grep -v 'corr=N/A' | awk -F 'msg=' '{print $2}' | sed -e "s/$SUB_ID/SUB_ID/g" echo echo @@ -129,11 +130,11 @@ Location: /v2/entities/E?type=T #SORT_START Request received: POST /v2/subscriptions, request payload (142 bytes): { "subject": { "entities": [ { "id": "E", "type": "T" } ] }, "notification": { "mqtt": { "url": "mqtt://localhost:1883", "topic": "sub1" } } }, response code: 201 Request received: POST /v2/entities?options=forcedUpdate,upsert, request payload (64 bytes): { "id": "E", "type": "T", "A": { "value": 1, "type": "Float" } }, response code: 204 -MQTT Notif delivered REGEX(.*): broker: localhost:1883, topic: sub1 +MQTT Notif delivered (subId: SUB_ID): broker: localhost:1883, topic: sub1, payload (121 bytes): {"subscriptionId":"SUB_ID","data":[{"id":"E","type":"T","A":{"type":"Float","value":1,"metadata":{}}}]} Request received: POST /v2/entities?options=forcedUpdate,upsert, request payload (64 bytes): { "id": "E", "type": "T", "A": { "value": 1, "type": "Float" } }, response code: 204 -MQTT Notif delivered REGEX(.*): broker: localhost:1883, topic: sub1 +MQTT Notif delivered (subId: SUB_ID): broker: localhost:1883, topic: sub1, payload (121 bytes): {"subscriptionId":"SUB_ID","data":[{"id":"E","type":"T","A":{"type":"Float","value":1,"metadata":{}}}]} Request received: POST /v2/entities?options=forcedUpdate,upsert, request payload (64 bytes): { "id": "E", "type": "T", "A": { "value": 1, "type": "Float" } }, response code: 204 -MQTT Notif delivered REGEX(.*): broker: localhost:1883, topic: sub1 +MQTT Notif delivered (subId: SUB_ID): broker: localhost:1883, topic: sub1, payload (121 bytes): {"subscriptionId":"SUB_ID","data":[{"id":"E","type":"T","A":{"type":"Float","value":1,"metadata":{}}}]} #SORT_END diff --git a/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_raise_and_release.test b/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_raise_and_release.test index 0877eb5d53..f531b4247f 100644 --- a/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_raise_and_release.test +++ b/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_raise_and_release.test @@ -162,7 +162,7 @@ echo echo "09. Check logs and see 1 raised alarm and 1 released alarm" echo "==========================================================" -cat /tmp/contextBroker.log | grep -v 'corr=N/A' | awk -F 'msg=' '{print $2}' +cat /tmp/contextBroker.log | grep -v 'corr=N/A' | awk -F 'msg=' '{print $2}' | sed -e "s/$SUB_ID/SUB_ID/g" echo echo @@ -360,10 +360,10 @@ Raising alarm MqttConnectionError mqtt.flespi.io:1883: Connection Refused: bad u Request received: GET /v2/subscriptions, response code: 200 Request received: POST /v2/entities?options=forcedUpdate,upsert, request payload (64 bytes): { "id": "E", "type": "T", "A": { "value": 1, "type": "Float" } }, response code: 204 Request received: GET /v2/subscriptions, response code: 200 -Request received: PATCH /v2/subscriptions/REGEX(.*): { "notification": { "mqtt": { "url": "mqtt://mqtt.flespi.io:1883", "user": "SeY7oD5XPa1UENBiOLPHqWXmj4r4OZHu4tsgWn1AmTkQuMW6lCDCmqMvi1oURVfJ", "passwd": "xxxx", "topic": "sub1" } } }, response code: 204 +Request received: PATCH /v2/subscriptions/SUB_ID, request payload (182 bytes): { "notification": { "mqtt": { "url": "mqtt://mqtt.flespi.io:1883", "user": "SeY7oD5XPa1UENBiOLPHqWXmj4r4OZHu4tsgWn1AmTkQuMW6lCDCmqMvi1oURVfJ", "passwd": "xxxx", "topic": "sub1" } } }, response code: 204 Request received: POST /v2/entities?options=forcedUpdate,upsert, request payload (64 bytes): { "id": "E", "type": "T", "A": { "value": 1, "type": "Float" } }, response code: 204 Releasing alarm MqttConnectionError mqtt.flespi.io:1883 -MQTT Notif delivered REGEX(.*): broker: mqtt.flespi.io:1883, topic: sub1 +MQTT Notif delivered (subId: SUB_ID): broker: mqtt.flespi.io:1883, topic: sub1, payload (121 bytes): {"subscriptionId":"SUB_ID","data":[{"id":"E","type":"T","A":{"type":"Float","value":1,"metadata":{}}}]} Request received: GET /v2/subscriptions, response code: 200 #SORT_END diff --git a/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_raise_repeat_and_release.test b/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_raise_repeat_and_release.test index caf1d9af57..c60bf280d5 100644 --- a/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_raise_repeat_and_release.test +++ b/test/functionalTest/cases/3001_mqtt_alarms/mqtt_alarms_raise_repeat_and_release.test @@ -162,7 +162,7 @@ echo echo "09. Check logs and see 1 raised alarm, 1 repeat alarm and 1 released alarm" echo "==========================================================================" -cat /tmp/contextBroker.log | grep -v 'corr=N/A' | awk -F 'msg=' '{print $2}' +cat /tmp/contextBroker.log | grep -v 'corr=N/A' | awk -F 'msg=' '{print $2}' | sed -e "s/$SUB_ID/SUB_ID/g" echo echo @@ -361,10 +361,10 @@ Request received: GET /v2/subscriptions, response code: 200 Request received: POST /v2/entities?options=forcedUpdate,upsert, request payload (64 bytes): { "id": "E", "type": "T", "A": { "value": 1, "type": "Float" } }, response code: 204 Request received: GET /v2/subscriptions, response code: 200 Repeated MqttConnectionError mqtt.flespi.io:1883: Connection Refused: bad user name or password. -Request received: PATCH /v2/subscriptions/REGEX(.*): { "notification": { "mqtt": { "url": "mqtt://mqtt.flespi.io:1883", "user": "SeY7oD5XPa1UENBiOLPHqWXmj4r4OZHu4tsgWn1AmTkQuMW6lCDCmqMvi1oURVfJ", "passwd": "xxxx", "topic": "sub1" } } }, response code: 204 +Request received: PATCH /v2/subscriptions/SUB_ID, request payload (182 bytes): { "notification": { "mqtt": { "url": "mqtt://mqtt.flespi.io:1883", "user": "SeY7oD5XPa1UENBiOLPHqWXmj4r4OZHu4tsgWn1AmTkQuMW6lCDCmqMvi1oURVfJ", "passwd": "xxxx", "topic": "sub1" } } }, response code: 204 Request received: POST /v2/entities?options=forcedUpdate,upsert, request payload (64 bytes): { "id": "E", "type": "T", "A": { "value": 1, "type": "Float" } }, response code: 204 Releasing alarm MqttConnectionError mqtt.flespi.io:1883 -MQTT Notif delivered REGEX(.*): broker: mqtt.flespi.io:1883, topic: sub1 +MQTT Notif delivered (subId: SUB_ID): broker: mqtt.flespi.io:1883, topic: sub1, payload (121 bytes): {"subscriptionId":"SUB_ID","data":[{"id":"E","type":"T","A":{"type":"Float","value":1,"metadata":{}}}]} Request received: GET /v2/subscriptions, response code: 200 #SORT_END diff --git a/test/functionalTest/cases/3694_logs_improvements/log_notifications.test b/test/functionalTest/cases/3694_logs_improvements/log_notifications.test index 8483b3f495..81a922c5bc 100644 --- a/test/functionalTest/cases/3694_logs_improvements/log_notifications.test +++ b/test/functionalTest/cases/3694_logs_improvements/log_notifications.test @@ -35,7 +35,7 @@ accumulatorStart --pretty-print localhost $LISTENER_PORT # 02. Create subscription SUB2 for E (to nowhere) # 03. Create E entity (triggering 2 notifications) # 04. POST /v2/op/update updating twice E (triggering 4 notifications) -# 05. Check notification logs (sorted by url) +# 05. Check notification logs (sorted by sub id) # 06. Check notification correlators (two blocks, corresponding to each update) # @@ -61,6 +61,7 @@ orionCurl --url /v2/subscriptions --payload "$payload" echo echo +SUB_ID1=$(echo "$_responseHeaders" | grep Location | awk -F/ '{ print $4 }' | tr -d "\r\n") echo "02. Create subscription SUB2 for E (to nowhere)" echo "===============================================" @@ -83,6 +84,7 @@ orionCurl --url /v2/subscriptions --payload "$payload" echo echo +SUB_ID2=$(echo "$_responseHeaders" | grep Location | awk -F/ '{ print $4 }' | tr -d "\r\n") echo "03. Create E entity (triggering 2 notifications)" echo "================================================" @@ -130,14 +132,9 @@ echo echo -# Example log trace for notifications (to help understanding the awk/cut stuff :) -# -# msg=Notif delivered (subId: 5f904fb3e970f217bde75f98): POST localhost:9997/notify, response code: 200 - - -echo "05. Check notification logs (sorted by url)" -echo "===========================================" -cat /tmp/contextBroker.log | grep INFO | grep 'Notif' | awk -F '|' '{print $10}' | cut -c 57- | sort +echo "05. Check notification logs (sorted by sub id)" +echo "==============================================" +cat /tmp/contextBroker.log | grep INFO | grep 'Notif' | awk -F '|' '{print $10}' | sed -e "s/$SUB_ID1/SUB_ID1/g" | sed -e "s/$SUB_ID2/SUB_ID2/g" | sort echo echo @@ -188,14 +185,14 @@ Fiware-Correlator: REGEX([0-9a-f\-]{36}) -05. Check notification logs (sorted by url) -=========================================== -POST localhost:12345/notify, response code: Couldn't connect to server -POST localhost:12345/notify, response code: Couldn't connect to server -POST localhost:12345/notify, response code: Couldn't connect to server -POST localhost:9997/notify, response code: 200 -POST localhost:9997/notify, response code: 200 -POST localhost:9997/notify, response code: 200 +05. Check notification logs (sorted by sub id) +============================================== + msg=Notif delivered (subId: SUB_ID1): POST localhost:9997/notify, payload (125 bytes): {"subscriptionId":"SUB_ID1","data":[{"id":"E","type":"T","A1":{"type":"Text","value":"foo","metadata":{}}}]}, response code: 200 + msg=Notif delivered (subId: SUB_ID1): POST localhost:9997/notify, payload (173 bytes): {"subscriptionId":"SUB_ID1","data":[{"id":"E","type":"T","A":{"type":"Text","value":"foo","metadata":{}},"A1":{"type":"Text","value":"foo","metadata":{}}}]}, response code: 200 + msg=Notif delivered (subId: SUB_ID1): POST localhost:9997/notify, payload (173 bytes): {"subscriptionId":"SUB_ID1","data":[{"id":"E","type":"T","A1":{"type":"Text","value":"foo","metadata":{}},"A":{"type":"Text","value":"foo","metadata":{}}}]}, response code: 200 + msg=Notif delivered (subId: SUB_ID2): POST localhost:12345/notify, payload (125 bytes): {"subscriptionId":"SUB_ID2","data":[{"id":"E","type":"T","A1":{"type":"Text","value":"foo","metadata":{}}}]}, response code: Couldn't connect to server + msg=Notif delivered (subId: SUB_ID2): POST localhost:12345/notify, payload (173 bytes): {"subscriptionId":"SUB_ID2","data":[{"id":"E","type":"T","A":{"type":"Text","value":"foo","metadata":{}},"A1":{"type":"Text","value":"foo","metadata":{}}}]}, response code: Couldn't connect to server + msg=Notif delivered (subId: SUB_ID2): POST localhost:12345/notify, payload (173 bytes): {"subscriptionId":"SUB_ID2","data":[{"id":"E","type":"T","A1":{"type":"Text","value":"foo","metadata":{}},"A":{"type":"Text","value":"foo","metadata":{}}}]}, response code: Couldn't connect to server 06. Check notification correlators (two blocks, corresponding to each update) From ca088da5c962f9568bb357168e7234d9925049b6 Mon Sep 17 00:00:00 2001 From: Kazuhito Suda Date: Wed, 20 Dec 2023 20:55:08 +0900 Subject: [PATCH 03/10] Fix typo --- doc/manuals/admin/build_source.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/doc/manuals/admin/build_source.md b/doc/manuals/admin/build_source.md index b534e0b2db..64064030e4 100644 --- a/doc/manuals/admin/build_source.md +++ b/doc/manuals/admin/build_source.md @@ -107,7 +107,7 @@ The Orion Context Broker comes with a suite of unit, valgrind and end-to-end tes In the case of the aarch64 architecture, install libxslt using apt-get, and run `./configure` with `--build=arm-linux` option. -* Install MongoDB (tests rely on mongod running in localhost). Check [the official MongoDB documentation](hhttps://www.mongodb.com/docs/manual/tutorial/install-mongodb-on-debian/) for details. Recommended version is 6.0 (it may work with previous versions, but we don't recommend it). +* Install MongoDB (tests rely on mongod running in localhost). Check [the official MongoDB documentation](https://www.mongodb.com/docs/manual/tutorial/install-mongodb-on-debian/) for details. Recommended version is 6.0 (it may work with previous versions, but we don't recommend it). * Run unit test From 1125baea1761406f4bc5ff127e476f048795101f Mon Sep 17 00:00:00 2001 From: Kazuhito Suda Date: Wed, 20 Dec 2023 21:00:59 +0900 Subject: [PATCH 04/10] (JP) Add documentation about MongoDB 6.0 (#4332) --- doc/manuals.jp/admin/build_source.md | 8 +------- doc/manuals.jp/admin/install.md | 4 ++-- doc/manuals.jp/admin/perf_tuning.md | 2 +- docker/README.jp.md | 6 +++--- docker/docker_swarm.jp.md | 2 +- docker/raspberry_pi.jp.md | 2 +- 6 files changed, 9 insertions(+), 15 deletions(-) diff --git a/doc/manuals.jp/admin/build_source.md b/doc/manuals.jp/admin/build_source.md index 8b6936c127..2797e3f5b3 100644 --- a/doc/manuals.jp/admin/build_source.md +++ b/doc/manuals.jp/admin/build_source.md @@ -108,13 +108,7 @@ Orion Context Broker には、次の手順に従って実行できる一連の aarch64 アーキテクチャの場合、apt-get を使用して libxslt をインストールし、`--build=arm-linux` オプションを指定して `/configure` を実行します。 -* MongoDB をインストールします (テストはローカル・ホストで実行されている mongod に依存します)。詳細については、[MongoDB の公式ドキュメント](hhttps://www.mongodb.com/docs/manual/tutorial/install-mongodb-on-debian/) を確認してください。推奨バージョンは 4.4 です (以前のバージョンでも動作する可能性がありますが、お勧めしません)。 - * mongo レガシー・シェル (`mongo` コマンド) は MongoDB 5 で非推奨となり、MongoDB 6 では新しいシェル (`mongosh` コマンド) が優先されて削除されたことに注意してください。一部の機能テスト (ftest) は、`mongosh` ではなく `mongo` を使用しているため、MongoDB 6 以降を使用している場合、これが原因で失敗します。 - * Debian 12 は libssl3 に移行しましたが、一部の MongoDB バージョンでは libssl1 が必要な場合があります。`Depends: libssl1.1 (>= 1.1.1) but it is not installable` エラーが発生した場合は、次のことをテストできます ([こちら](https://askubuntu.com/a/1421959) を参照)) - - wget http://archive.ubuntu.com/ubuntu/pool/main/o/openssl/libssl1.1_1.1.1f-1ubuntu2_amd64.deb - sudo dpkg -i libssl1.1_1.1.1f-1ubuntu2_amd64.deb - rm libssl1.1_1.1.1f-1ubuntu2_amd64.deb # optional, for cleanness +* MongoDB をインストールします (テストはローカルホストで実行されている mongod に依存します)。 詳細については、[MongoDB の公式ドキュメント](https://www.mongodb.com/docs/manual/tutorial/install-mongodb-on-debian/)を確認してください。推奨バージョンは 6.0 です (以前のバージョンでも動作する可能性がありますが、お勧めしません)。 * ユニット・テストを実行します diff --git a/doc/manuals.jp/admin/install.md b/doc/manuals.jp/admin/install.md index cd73b7ec67..eee8edb8f6 100644 --- a/doc/manuals.jp/admin/install.md +++ b/doc/manuals.jp/admin/install.md @@ -29,10 +29,10 @@ Docker hub で公式の Orion docker コンテナを使用してインストー * オペレーティングシステム: Debian。リファレンス・オペレーティングシステムは Debian 12.1 ですが、それ以降の Debian 12 バージョンでも動作するはずです * データベース: MongoDB は、Orion Context Broker がインストールされるのと同じホストで実行するか、ネットワーク経由で - アクセスできる別のホストで実行する必要があります。推奨される MongoDB バージョンは 4.4 です (Orion は古いバージョンで + アクセスできる別のホストで実行する必要があります。推奨される MongoDB バージョンは 6.0 です (Orion は古いバージョンで 動作する可能性がありますが、まったくお勧めしません!) -システムリソース (CPU, RAMなど) については、[これらの推奨事項](diagnosis.md#resource-availability) を参照してください。 +システムリソース (CPU, RAMなど) については、[これらの推奨事項](diagnosis.md#resource-availability) を参照してください。 ## 以前のバージョンからのアップグレード diff --git a/doc/manuals.jp/admin/perf_tuning.md b/doc/manuals.jp/admin/perf_tuning.md index 0ee6e55d15..bd5197dcf5 100644 --- a/doc/manuals.jp/admin/perf_tuning.md +++ b/doc/manuals.jp/admin/perf_tuning.md @@ -21,7 +21,7 @@ ## MongoDB の設定 -パフォーマンスの観点から、特に Update-Intensive シナリオでは、WireTiger で MongoDB 4.4 を使用することをお勧めします。 +パフォーマンスの観点から、特に Update-Intensive シナリオでは、WireTiger で MongoDB 6.0 を使用することをお勧めします。 さらに、パフォーマンスに影響を与える可能性があるため、公式の MongoDB のドキュメントから次の情報を考慮してください : diff --git a/docker/README.jp.md b/docker/README.jp.md index 72f32ac440..c36ae73140 100644 --- a/docker/README.jp.md +++ b/docker/README.jp.md @@ -36,7 +36,7 @@ Orion Context Broker を試してみたいし、データベースについて command: -dbhost mongo mongo: - image: mongo:4.4 + image: mongo:6.0 command: --nojournal 3. コマンドラインを使用して作成したディレクトリで、`sudo docker-compose up` を実行します @@ -75,7 +75,7 @@ Orion Context Broker を試してみたいし、データベースについて ### 2B. MongoDB が別の Docker コンテナで動作している場合 他のコンテナで MongoDB を実行したい場合は、次のように起動することができます - sudo docker run --name mongodb -d mongo:4.4 + sudo docker run --name mongodb -d mongo:6.0 そして、このコマンドで Orion を実行します @@ -109,7 +109,7 @@ Orion Context Broker を試してみたいし、データベースについて 4. Orion を実行 ... * docker-compose で自動化されたシナリオを使用し、新しいイメージを構築する : `sudo docker-compose up`。必要に応じて、提供されている `docker-compose.yml` ファイルを変更することもできます * 手動で MongoDB を別のコンテナで実行します : - 1. `sudo docker run --name mongodb -d mongo:4.4` + 1. `sudo docker run --name mongodb -d mongo:6.0` 2. `sudo docker build -t orion .` 3. `sudo docker run -d --name orion1 --link mongodb:mongodb -p 1026:1026 orion -dbhost mongodb`. * 手動で MongoDB ホストを見つける場所を指定します : diff --git a/docker/docker_swarm.jp.md b/docker/docker_swarm.jp.md index 9ef927b9d5..6b35f7920d 100644 --- a/docker/docker_swarm.jp.md +++ b/docker/docker_swarm.jp.md @@ -77,7 +77,7 @@ MongoDB ReplicaSet を Docker Swarm にデプロイする方法の詳細につ services: mongo: - image: mongo:4.4 + image: mongo:6.0 entrypoint: [ "/usr/bin/mongod", "--replSet", "rs", "--journal", "--smallfiles", "--bind_ip", "0.0.0.0"] volumes: - mongodata:/data/db diff --git a/docker/raspberry_pi.jp.md b/docker/raspberry_pi.jp.md index 2769483c76..6a2e961cc7 100644 --- a/docker/raspberry_pi.jp.md +++ b/docker/raspberry_pi.jp.md @@ -50,7 +50,7 @@ services: command: -dbhost mongo mongo: - image: mongo:4.4 + image: mongo:6.0 command: --nojournal ``` From 39aa16208648f433f88c6d6ed77b26dcd89c679a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ferm=C3=ADn=20Gal=C3=A1n=20M=C3=A1rquez?= Date: Wed, 20 Dec 2023 14:07:15 +0100 Subject: [PATCH 05/10] FIX typos in ftest names --- .../log_deprecate_warning_dynamic.test | 2 +- .../false_positive_in_log_deprecation_logic.test | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning_dynamic.test b/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning_dynamic.test index b7f1dfa95d..a71f1a27e1 100644 --- a/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning_dynamic.test +++ b/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning_dynamic.test @@ -21,7 +21,7 @@ # VALGRIND_READY - to mark the test ready for valgrindTestSuite.sh --NAME-- -Disable NGSIv1 CLI with dynamic changes done by management REST API +Log deprecate warnings with dynamic changes done by management REST API --SHELL-INIT-- dbInit CB diff --git a/test/functionalTest/cases/4454_false_positive_in_log_deprecation_logic/false_positive_in_log_deprecation_logic.test b/test/functionalTest/cases/4454_false_positive_in_log_deprecation_logic/false_positive_in_log_deprecation_logic.test index 8a6212d562..1ee335d350 100644 --- a/test/functionalTest/cases/4454_false_positive_in_log_deprecation_logic/false_positive_in_log_deprecation_logic.test +++ b/test/functionalTest/cases/4454_false_positive_in_log_deprecation_logic/false_positive_in_log_deprecation_logic.test @@ -21,7 +21,7 @@ # VALGRIND_READY - to mark the test ready for valgrindTestSuite.sh --NAME-- -Disable NGSIv1 CLI +False positive in log deprecation --SHELL-INIT-- dbInit CB From 8f9fac0d3be4c9a414b6873f52f1e063052a0399 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ferm=C3=ADn=20Gal=C3=A1n=20M=C3=A1rquez?= Date: Wed, 20 Dec 2023 14:38:42 +0100 Subject: [PATCH 06/10] FIX additional typos --- .../log_deprecate_warning_dynamic.test | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning_dynamic.test b/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning_dynamic.test index a71f1a27e1..df0025e539 100644 --- a/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning_dynamic.test +++ b/test/functionalTest/cases/0000_deprecated_checkings/log_deprecate_warning_dynamic.test @@ -32,15 +32,15 @@ brokerStart CB 0 IPV4 -logDeprecate # # 00. Check deprecate is true # 01. Query E1-T1 -# 02. GET /v1/contextEntities/E +# 02. GET /v1/contextEntities/E/attributes/A # 03. Disable logDeprecated by API # 04. Check deprecate is false # 05. Query E1-T1 (not logged) -# 06. GET /v1/contextEntities/E (not logged) +# 06. GET /v1/contextEntities/E/attributes/A (not logged) # 07. Enable logDeprecated by API # 08. Check deprecate is false # 09. Query E1-T1 -# 10. GET /v1/contextEntities/E +# 10. GET /v1/contextEntities/E/attributes/A # 11. Get WARNING trace in logs (see 4 traces) # From eb230405d3724ca33e9ec146580a4d29d3ad3bc7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ferm=C3=ADn=20Gal=C3=A1n=20M=C3=A1rquez?= Date: Wed, 20 Dec 2023 17:15:26 +0100 Subject: [PATCH 07/10] FIX additional ftest for 4449 case --- .../notification_payload_in_logs.test | 231 ++++++++++++++++++ 1 file changed, 231 insertions(+) create mode 100644 test/functionalTest/cases/4449_notification_payload_in_logs/notification_payload_in_logs.test diff --git a/test/functionalTest/cases/4449_notification_payload_in_logs/notification_payload_in_logs.test b/test/functionalTest/cases/4449_notification_payload_in_logs/notification_payload_in_logs.test new file mode 100644 index 0000000000..d9f7f692d3 --- /dev/null +++ b/test/functionalTest/cases/4449_notification_payload_in_logs/notification_payload_in_logs.test @@ -0,0 +1,231 @@ +# Copyright 2023 Telefonica Investigacion y Desarrollo, S.A.U +# +# This file is part of Orion Context Broker. +# +# Orion Context Broker is free software: you can redistribute it and/or +# modify it under the terms of the GNU Affero General Public License as +# published by the Free Software Foundation, either version 3 of the +# License, or (at your option) any later version. +# +# Orion Context Broker is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU Affero +# General Public License for more details. +# +# You should have received a copy of the GNU Affero General Public License +# along with Orion Context Broker. If not, see http://www.gnu.org/licenses/. +# +# For those usages not covered by this license please contact with +# iot_support at tid dot es + +# VALGRIND_READY - to mark the test ready for valgrindTestSuite.sh + +--NAME-- +Notification payload included in logs in several subscriptions types + +--SHELL-INIT-- +dbInit CB +brokerStart CB 0-255 IPV4 -multiservice +accumulatorStart --pretty-print localhost $LISTENER_PORT + +--SHELL-- + +# +# 01. Create subscription SUB1 (normalized) +# 02. Create subscription SUB2 (simplifiedKeyValues) +# 03. Create subscription SUB3 (custom text) +# 04. Create subscription SUB4 (empty payload) +# 05. Create E entity (triggering 4 notifications) +# 06. Check notification logs (sorted by sub id) +# + + +echo "01. Create subscription SUB1 (normalized)" +echo "=========================================" +payload=' +{ + "subject": { + "entities": [ + { + "id": "E", + "type": "T" + } + ] + }, + "notification": { + "http": {"url": "http://localhost:'$LISTENER_PORT'/notify"} + } +}' +orionCurl --url /v2/subscriptions --payload "$payload" +echo +echo + + +SUB_ID1=$(echo "$_responseHeaders" | grep Location | awk -F/ '{ print $4 }' | tr -d "\r\n") + + +echo "02. Create subscription SUB2 (simplifiedKeyValues)" +echo "==================================================" +payload=' +{ + "subject": { + "entities": [ + { + "id": "E", + "type": "T" + } + ] + }, + "notification": { + "http": {"url": "http://localhost:'$LISTENER_PORT'/notify"}, + "attrsFormat": "simplifiedKeyValues" + } +}' +orionCurl --url /v2/subscriptions --payload "$payload" +echo +echo + + +SUB_ID2=$(echo "$_responseHeaders" | grep Location | awk -F/ '{ print $4 }' | tr -d "\r\n") + + +echo "03. Create subscription SUB3 (custom text)" +echo "==========================================" +payload=' +{ + "subject": { + "entities": [ + { + "id": "E", + "type": "T" + } + ] + }, + "notification": { + "httpCustom": { + "url": "http://localhost:'$LISTENER_PORT'/notify", + "payload": "this is ${A}" + } + } +}' +orionCurl --url /v2/subscriptions --payload "$payload" +echo +echo + + +SUB_ID3=$(echo "$_responseHeaders" | grep Location | awk -F/ '{ print $4 }' | tr -d "\r\n") + + +echo "04. Create subscription SUB4 (empty payload)" +echo "============================================" +payload=' +{ + "subject": { + "entities": [ + { + "id": "E", + "type": "T" + } + ] + }, + "notification": { + "httpCustom": { + "url": "http://localhost:'$LISTENER_PORT'/notify", + "payload": null + } + } +}' +orionCurl --url /v2/subscriptions --payload "$payload" +echo +echo + + +SUB_ID4=$(echo "$_responseHeaders" | grep Location | awk -F/ '{ print $4 }' | tr -d "\r\n") + + +echo "05. Create E entity (triggering 4 notifications)" +echo "================================================" +payload=' +{ + "id":"E", + "type":"T", + "A":{ + "value": 42, + "type": "Number" + } +}' +orionCurl --url '/v2/entities' --payload "$payload" +echo +echo + + +echo "06. Check notification logs (sorted by sub id)" +echo "==============================================" +cat /tmp/contextBroker.log | grep INFO | grep 'Notif' | awk -F '|' '{print $10}' | sed -e "s/$SUB_ID1/SUB_ID1/g" | sed -e "s/$SUB_ID2/SUB_ID2/g" | sed -e "s/$SUB_ID3/SUB_ID3/g" | sed -e "s/$SUB_ID4/SUB_ID4/g" | sort +echo +echo + + +--REGEXPECT-- +01. Create subscription SUB1 (normalized) +========================================= +HTTP/1.1 201 Created +Date: REGEX(.*) +Fiware-Correlator: REGEX([0-9a-f\-]{36}) +Location: /v2/subscriptions/REGEX([0-9a-f\-]{24}) +Content-Length: 0 + + + +02. Create subscription SUB2 (simplifiedKeyValues) +================================================== +HTTP/1.1 201 Created +Date: REGEX(.*) +Fiware-Correlator: REGEX([0-9a-f\-]{36}) +Location: /v2/subscriptions/REGEX([0-9a-f\-]{24}) +Content-Length: 0 + + + +03. Create subscription SUB3 (custom text) +========================================== +HTTP/1.1 201 Created +Date: REGEX(.*) +Fiware-Correlator: REGEX([0-9a-f\-]{36}) +Location: /v2/subscriptions/REGEX([0-9a-f\-]{24}) +Content-Length: 0 + + + +04. Create subscription SUB4 (empty payload) +============================================ +HTTP/1.1 201 Created +Date: REGEX(.*) +Fiware-Correlator: REGEX([0-9a-f\-]{36}) +Location: /v2/subscriptions/REGEX([0-9a-f\-]{24}) +Content-Length: 0 + + + +05. Create E entity (triggering 4 notifications) +================================================ +HTTP/1.1 201 Created +Date: REGEX(.*) +Fiware-Correlator: REGEX([0-9a-f\-]{36}) +Location: /v2/entities/E?type=T +Content-Length: 0 + + + +06. Check notification logs (sorted by sub id) +============================================== + msg=Notif delivered (subId: SUB_ID1): POST localhost:9997/notify, payload (123 bytes): {"subscriptionId":"SUB_ID1","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]}, response code: 200 + msg=Notif delivered (subId: SUB_ID2): POST localhost:9997/notify, payload (28 bytes): {"id":"E","type":"T","A":42}, response code: 200 + msg=Notif delivered (subId: SUB_ID3): POST localhost:9997/notify, payload (10 bytes): this is 42, response code: 200 + msg=Notif delivered (subId: SUB_ID4): POST localhost:9997/notify, payload (0 bytes): , response code: 200 + + +--TEARDOWN-- +accumulatorStop +brokerStop CB +dbDrop CB From 2d032e35d9775559acf89735feba0400091743bb Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ferm=C3=ADn=20Gal=C3=A1n=20M=C3=A1rquez?= Date: Wed, 20 Dec 2023 17:19:52 +0100 Subject: [PATCH 08/10] FIX logs improvements --- doc/manuals/admin/logs.md | 22 +++++++++++----------- 1 file changed, 11 insertions(+), 11 deletions(-) diff --git a/doc/manuals/admin/logs.md b/doc/manuals/admin/logs.md index 192e835dbe..cffa9bb934 100644 --- a/doc/manuals/admin/logs.md +++ b/doc/manuals/admin/logs.md @@ -170,13 +170,13 @@ time=2020-10-26T10:32:41.724Z | lvl=INFO | corr=93bdc5b4-1776-11eb-954d-000c29df different value for the correlator. ``` -time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df7908; cbnotif=1 | trans=1603707992-318-00000000003 | from=0.0.0.0 | srv=s1| subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f914177334436ea590f6edb): POST localhost:1028/accumulate, response code: 200 +time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df7908; cbnotif=1 | trans=1603707992-318-00000000003 | from=0.0.0.0 | srv=s1| subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f914177334436ea590f6edb): POST localhost:1028/accumulate, payload (123 bytes): {"subscriptionId":"5f914177334436ea590f6edb","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]}, response code: 200 ``` * In the case of MQTT notifications the `msg` field of the above trace is slightly different: ``` -time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df7908; cbnotif=1 | trans=1603707992-318-00000000003 | from=0.0.0.0 | srv=s1| subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoMqttNotification | msg=MQTT Notif delivered (subId: 60ffea6c1bca454f9a64c96c): broker: localhost:1883, topic: sub2 +time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df7908; cbnotif=1 | trans=1603707992-318-00000000003 | from=0.0.0.0 | srv=s1| subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoMqttNotification | msg=MQTT Notif delivered (subId: 60ffea6c1bca454f9a64c96c): broker: localhost:1883, topic: sub2, payload (121 bytes): {"subscriptionId":"60ffea6c1bca454f9a64c96c","data":[{"id":"E","type":"T","A":{"type":"Float","value":1,"metadata":{}}}]} ``` * For each forwarded request to a [Context Provider](../user/context_providers.md) (either queries or updates), @@ -200,7 +200,7 @@ Some additional considerations: occurs. For instance: ``` -time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df7908; cbnotif=1 | trans=1603707992-318-00000000003 | from=0.0.0.0 | srv=s1| subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f914177334436ea590f6edb): POST localhost:1028/accumulate, response code: Couldn't connect to server +time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df7908; cbnotif=1 | trans=1603707992-318-00000000003 | from=0.0.0.0 | srv=s1| subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f914177334436ea590f6edb): POST localhost:1028/accumulate, payload (123 bytes): {"subscriptionId":"5f914177334436ea590f6edb","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]}, response code: Couldn't connect to server ``` * When a client request triggers forwarding to Context Providers, a `Starting forwarding for ` @@ -346,56 +346,56 @@ contextBroker -fg -httpTimeout 10000 -logLevel INFO -notificationMode threadpool Successful sent (response code 200): ``` -time=2020-10-26T14:48:37.192Z | lvl=INFO | corr=54393a44-179a-11eb-bb87-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000006 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e174b14e7532482ac794): POST localhost:1028/accumulate, response code: 200 +time=2020-10-26T14:48:37.192Z | lvl=INFO | corr=54393a44-179a-11eb-bb87-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000006 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e174b14e7532482ac794): POST localhost:1028/accumulate, payload (123 bytes): {"subscriptionId":"5f96e174b14e7532482ac794","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]}, response code: 200 ``` Notification endpoint response with 400 (a WARN trace is printed): ``` time=2020-10-26T14:49:34.619Z | lvl=WARN | corr=7689f6ba-179a-11eb-ac4c-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000009 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=httpRequestSend.cpp[583]:httpRequestSend | msg=Notification (subId: 5f96e1fdb14e7532482ac795) response NOT OK, http code: 400 -time=2020-10-26T14:49:34.619Z | lvl=INFO | corr=7689f6ba-179a-11eb-ac4c-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000009 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e1fdb14e7532482ac795): POST localhost:1028/giveme400, response code: 400 +time=2020-10-26T14:49:34.619Z | lvl=INFO | corr=7689f6ba-179a-11eb-ac4c-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000009 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e1fdb14e7532482ac795): POST localhost:1028/giveme400, payload (123 bytes): {"subscriptionId":"5f96e1fdb14e7532482ac795","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]}, response code: 400 ``` Notification endpoint response with 404 (a WARN trace is printed): ``` time=2020-10-26T14:51:40.764Z | lvl=WARN | corr=c1b8e9c0-179a-11eb-9edc-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000012 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=httpRequestSend.cpp[583]:httpRequestSend | msg=Notification (subId: 5f96e27cb14e7532482ac796) response NOT OK, http code: 404 -time=2020-10-26T14:51:40.764Z | lvl=INFO | corr=c1b8e9c0-179a-11eb-9edc-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000012 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e27cb14e7532482ac796): POST localhost:1028/giveme404, response code: 404 +time=2020-10-26T14:51:40.764Z | lvl=INFO | corr=c1b8e9c0-179a-11eb-9edc-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000012 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e27cb14e7532482ac796): POST localhost:1028/giveme404, payload (123 bytes): {"subscriptionId":"5f96e27cb14e7532482ac796","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]}, response code: 404 ``` Notification endpoint response with 500 (a WARN trace is printed) ``` time=2020-10-26T14:53:04.246Z | lvl=WARN | corr=f37b5024-179a-11eb-9ce6-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000015 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=httpRequestSend.cpp[583]:httpRequestSend | msg=Notification (subId: 5f96e2cfb14e7532482ac797) response NOT OK, http code: 500 -time=2020-10-26T14:53:04.247Z | lvl=INFO | corr=f37b5024-179a-11eb-9ce6-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000015 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e2cfb14e7532482ac797): POST localhost:1028/giveme500, response code: 500 +time=2020-10-26T14:53:04.247Z | lvl=INFO | corr=f37b5024-179a-11eb-9ce6-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000015 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e2cfb14e7532482ac797): POST localhost:1028/giveme500, payload (123 bytes): {"subscriptionId":"5f96e2cfb14e7532482ac797","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]}, response code: 500 ``` Endpoint not responding within 10 seconds timeout or some other connection error (alarm is raised in WARN level): ``` time=2020-10-26T14:54:15.996Z | lvl=WARN | corr=184b8b80-179b-11eb-9c52-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000018 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=AlarmManager.cpp[328]:notificationError | msg=Raising alarm NotificationError localhost:1028/givemeDelay: notification failure for queue worker: Timeout was reached -time=2020-10-26T14:54:15.996Z | lvl=INFO | corr=184b8b80-179b-11eb-9c52-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000018 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e30db14e7532482ac798): POST localhost:1028/givemeDelay, response code: Timeout was reached +time=2020-10-26T14:54:15.996Z | lvl=INFO | corr=184b8b80-179b-11eb-9c52-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000018 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e30db14e7532482ac798): POST localhost:1028/givemeDelay, payload (123 bytes): {"subscriptionId":"5f96e30db14e7532482ac798","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]}, response code: Timeout was reached ``` Endpoint in not responding port, e.g. localhost:9999 (alarm is raised in WARN log level): ``` time=2020-10-26T15:01:50.659Z | lvl=WARN | corr=2d3e4cfc-179c-11eb-b667-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000030 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=AlarmManager.cpp[328]:notificationError | msg=Raising alarm NotificationError localhost:9999/giveme: notification failure for queue worker: Couldn't connect to server -time=2020-10-26T15:01:50.659Z | lvl=INFO | corr=2d3e4cfc-179c-11eb-b667-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000030 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e4deb14e7532482ac79c): POST localhost:9999/giveme, response code: Couldn't connect to server +time=2020-10-26T15:01:50.659Z | lvl=INFO | corr=2d3e4cfc-179c-11eb-b667-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000030 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e4deb14e7532482ac79c): POST localhost:9999/giveme, payload (123 bytes): {"subscriptionId":"5f96e4deb14e7532482ac79c","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]}, response code: Couldn't connect to server ``` Endpoint in unresolvable name, e.g. foo.bar.bar.com (alarm is raised in WARN log level): ``` time=2020-10-26T15:03:54.258Z | lvl=WARN | corr=769f8d8e-179c-11eb-960f-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000033 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=AlarmManager.cpp[328]:notificationError | msg=Raising alarm NotificationError foo.bar.bar.com:9999/giveme: notification failure for queue worker: Couldn't resolve host name -time=2020-10-26T15:03:54.258Z | lvl=INFO | corr=769f8d8e-179c-11eb-960f-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000033 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e559b14e7532482ac79d): POST foo.bar.bar.com:9999/giveme, response code: Couldn't resolve host name +time=2020-10-26T15:03:54.258Z | lvl=INFO | corr=769f8d8e-179c-11eb-960f-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000033 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e559b14e7532482ac79d): POST foo.bar.bar.com:9999/giveme, payload (123 bytes): {"subscriptionId":"5f96e559b14e7532482ac79d","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]}, response code: Couldn't resolve host name ``` Endpoint in unreachable IP, e.g. 12.34.56.87 (alarm is raised in WARN log level): ``` time=2020-10-26T15:06:14.642Z | lvl=WARN | corr=c4a3192e-179c-11eb-ac8f-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000036 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=AlarmManager.cpp[328]:notificationError | msg=Raising alarm NotificationError 12.34.56.78:9999/giveme: notification failure for queue worker: Timeout was reached -time=2020-10-26T15:06:14.642Z | lvl=INFO | corr=c4a3192e-179c-11eb-ac8f-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000036 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e5dbb14e7532482ac79e): POST 12.34.56.78:9999/giveme, response code: Timeout was reached +time=2020-10-26T15:06:14.642Z | lvl=INFO | corr=c4a3192e-179c-11eb-ac8f-000c29df7908; cbnotif=1 | trans=1603722272-416-00000000036 | from=0.0.0.0 | srv=s1 | subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoHttpNotification | msg=Notif delivered (subId: 5f96e5dbb14e7532482ac79e): POST 12.34.56.78:9999/giveme, payload (123 bytes): {"subscriptionId":"5f96e5dbb14e7532482ac79e","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]}, response code: Timeout was reached ``` [Top](#top) From e0a3b4d664f12eaf7557ca7afb3303e6f8f1ac0c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ferm=C3=ADn=20Gal=C3=A1n=20M=C3=A1rquez?= Date: Wed, 20 Dec 2023 17:27:40 +0100 Subject: [PATCH 09/10] Update doc/manuals/admin/logs.md --- doc/manuals/admin/logs.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/doc/manuals/admin/logs.md b/doc/manuals/admin/logs.md index cffa9bb934..337016aea1 100644 --- a/doc/manuals/admin/logs.md +++ b/doc/manuals/admin/logs.md @@ -176,7 +176,7 @@ time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df * In the case of MQTT notifications the `msg` field of the above trace is slightly different: ``` -time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df7908; cbnotif=1 | trans=1603707992-318-00000000003 | from=0.0.0.0 | srv=s1| subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoMqttNotification | msg=MQTT Notif delivered (subId: 60ffea6c1bca454f9a64c96c): broker: localhost:1883, topic: sub2, payload (121 bytes): {"subscriptionId":"60ffea6c1bca454f9a64c96c","data":[{"id":"E","type":"T","A":{"type":"Float","value":1,"metadata":{}}}]} +time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df7908; cbnotif=1 | trans=1603707992-318-00000000003 | from=0.0.0.0 | srv=s1| subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoMqttNotification | msg=MQTT Notif delivered (subId: 60ffea6c1bca454f9a64c96c): broker: localhost:1883, topic: sub2, payload (123 bytes): {"subscriptionId":"5f914177334436ea590f6edb","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]} ``` * For each forwarded request to a [Context Provider](../user/context_providers.md) (either queries or updates), From 031ddf6d50267fa1fa04559623eb27b41b18266d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ferm=C3=ADn=20Gal=C3=A1n=20M=C3=A1rquez?= Date: Wed, 20 Dec 2023 17:28:31 +0100 Subject: [PATCH 10/10] Update doc/manuals/admin/logs.md --- doc/manuals/admin/logs.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/doc/manuals/admin/logs.md b/doc/manuals/admin/logs.md index 337016aea1..2f4020b79f 100644 --- a/doc/manuals/admin/logs.md +++ b/doc/manuals/admin/logs.md @@ -176,7 +176,7 @@ time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df * In the case of MQTT notifications the `msg` field of the above trace is slightly different: ``` -time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df7908; cbnotif=1 | trans=1603707992-318-00000000003 | from=0.0.0.0 | srv=s1| subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoMqttNotification | msg=MQTT Notif delivered (subId: 60ffea6c1bca454f9a64c96c): broker: localhost:1883, topic: sub2, payload (123 bytes): {"subscriptionId":"5f914177334436ea590f6edb","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]} +time=2020-10-26T10:32:22.145Z | lvl=INFO | corr=87f708a8-1776-11eb-b327-000c29df7908; cbnotif=1 | trans=1603707992-318-00000000003 | from=0.0.0.0 | srv=s1| subsrv=/A | comp=Orion | op=logTracing.cpp[63]:logInfoMqttNotification | msg=MQTT Notif delivered (subId: 60ffea6c1bca454f9a64c96c): broker: localhost:1883, topic: sub2, payload (123 bytes): {"subscriptionId":"60ffea6c1bca454f9a64c96c","data":[{"id":"E","type":"T","A":{"type":"Number","value":42,"metadata":{}}}]} ``` * For each forwarded request to a [Context Provider](../user/context_providers.md) (either queries or updates),