Add notification duration metrics (#4772) by orianar · Pull Request #4788 · telefonicaid/fiware-orion

orianar · 2026-05-23T05:09:01Z

…ature/4772-add-notification-duration-metrics_21_05

fgalan · 2026-06-04T11:37:06Z


+  if ((this->type != MqttNotification) && (this->type != KafkaNotification))
+  {
+    if ((this->lastNotification > 0) && (this->lastNotificationDuration >= 0))


Why the condition on lastNotification is > and the condition in lastNotificationDuration is >= ?

lastNotification > 0 is used because 0 means no notification has ever been sent.

For lastNotificationDuration, 0 ms is a valid duration, so the condition must be >= 0. Using > 0 caused flaky tests because very fast notifications could be measured as either 0 ms or at least 1 ms.

When the field is missing in MongoDB, it is initialized to -1, so >= 0 ensures that only real lastNotificationDuration are serialized.

So if the notification is too fast (less than 1ms) then it doesn't count for duration counters (and the lastNotificationDuration is not printed)? That's fine (just to confirm)

However, note this situation:

Notification 1: 10ms

Notification 2: 20ms

Notification 3: 0ms (too fast)

It's ok not printing lastNotificationDuration this time but accumulatedNotificationDuration would be printed with 30 value.

Thus, I understand each field should be checked individually.

If a notification takes 0 ms (less than 1 ms), it does count and both fields will be printed.

The serialization code checks:
if ((this->lastNotification > 0) && (this->lastNotificationDuration >= 0))

As 0 is >= 0, they are included in the JSON response. In fact, if we didn't print these metrics when they are 0, they gave me flaky tests. 0 is a valid measurement.

The fields are only omitted when lastNotificationDuration < 0 . The default value is -1 when no notification has been sent yet.

fgalan · 2026-06-04T11:37:34Z

+| `lastNotificationDuration`                                                                                                                                                                                                                                                                     | Only on retrieval | number  | Not editable, only present in GET operations. Duration of the last notification attempt in milliseconds.                                                                          |
+| `accumulatedNotificationDuration`                                                                                                                                                                                                                                                              | Only on retrieval | number  | Not editable, only present in GET operations. Sum of durations of all notification attempts in milliseconds.                                                                     |


They are incluced only in HTTP notifications or also in MQTT/KAFKA?

The duration metrics are only applicable to HTTP notifications. I’ve clarified this in the documentation.

fgalan · 2026-06-04T11:38:24Z

    if (cssP != NULL)
    {
-      if (cssP->lastNotificationTime > cSubP->lastNotificationTime)
+      if (cssP->lastNotificationTime >= cSubP->lastNotificationTime)


Seems to be duplicated in L1288... weird

It is not a duplicate line. The >= condition (cssP->lastNotificationTime >= cSubP->lastNotificationTime) is used to synchronize lastNotificationDuration . I have documented this in the code, and it is tested by 4772_notification_duration_metrics/duration_metrics_slow_sync.test and
4772_notification_duration_metrics/refresh_cache_notif_equal_timestamps.test (we can remove the latter if it seems too forced). The >= condition also handles the case where two notifications occur in the same second.

fgalan · 2026-06-04T11:51:32Z

        "description": "HTTP sub",
        "id": "REGEX([0-9a-f\-]{24})",
        "notification": {
+            "accumulatedNotificationDuration": REGEX(\d+),


In all places we have REGEX(\d+) for the new counters

I'd suggest to have some "real" tests using some delay endpoint in accumulator-server.py using the /givemeDelay endpoint (which imposes T seconds delay).

Thus, we could trigger three notifications so:

After the first notification lastNotificationDuration is T*1000 and accumulatedNotificationDuration is T

After the first notification lastNotificationDuration is T*1000 and accumulatedNotificationDuration is 2*T*1000

After the first notification lastNotificationDuration is T*1000 and accumulatedNotificationDuration is 3*T*1000

The miliseconds introduce some variability, but we would do some rouding based in REGEX(). Eg T=10

2*T*1000 = 2 * 10 * 10000 = 20000 => REGEX(20\d\d\d) (range 20000 to 20099, i.e. 20-21s)

Currently the /givemeDelay is like this:

@app.route("/givemeDelay", methods=['POST']) def givemeDelay(): sleep(60) return Response(status=200)

T = 60 seconds is probably too long for this kind of test. I'd suggest to make this configurable in accumulator-server.py, then use a shorter T (eg. T = 10)

Test added: 4772_notification_duration_metrics/duration_metrics_accumulator_delay.test

fgalan · 2026-06-04T11:54:53Z

        "description": "HTTP sub",
        "id": "REGEX([0-9a-f\-]{24})",
        "notification": {
+            "accumulatedNotificationDuration": REGEX(\d+),


If a subscription originally uses HTTP, then changed to MQTT/KAFKA (where I understand these new counters are not used but I have asked for confirmation in another comment), then changed back to HTTP, what happens with the counters? Are reseted or preserved?

I thinks it's better to reset (and specify it in documentation)

(This is a kind of corner case, as a subscription rarely changes its notification type, but we should have it covered)

I’ve added a test and the necessary changes to cover PATCH transitions from HTTP to MQTT/Kafka and back to HTTP. The changes will be included in the next commit : 0c5d6b1

Looking to the tests it seems that when we change HTTP -> MQTT/KAFKA -> HTTP the metrics are reseted (ie. lastDuration to 0 and accumulatedDuration to 0). Is my understanding correct?

When the protocol is switched from HTTP to MQTT/Kafka, the database fields lastNotificationDuration and accumulatedNotificationDuration are removed from the MongoDB using $unset .

fiware-orion/src/lib/mongoBackend/mongoUpdateSubscription.cpp

Lines 464 to 469 in 9edc6f4

if (subUp.notificationProvided)

{

if (subUp.notification.type != ngsiv2::HttpNotification)

{

unsetHttpNotificationDurationMetrics(&unsetB);

}

In cache, lastNotificationDuration is reset to -1 and notificationDurationDelta to 0 .

fiware-orion/src/lib/mongoBackend/mongoUpdateSubscription.cpp

Lines 332 to 337 in 9edc6f4

if (subUp.notificationProvided &&

subUp.notification.type != ngsiv2::HttpNotification)

{

lastNotificationDuration = -1;

notificationDurationDelta = 0;

}

As lastNotificationDuration is less than 0 , Orion does not include either of the two fields in the subscription response, and they will not appear again unless the subscription is switched back to HTTP and a new notification is sent.

fgalan · 2026-06-04T11:55:30Z

 A `condition` contains the following subfields:

 | Parameter    | Optional | Type  | Description                                                                                                                   |
 |--------------|----------|-------|-------------------------------------------------------------------------------------------------------------------------------|


CNR entry about the changes in this PR should be included

added CNR entry

…subCacheSync.

fgalan · 2026-06-12T07:18:17Z

+    "lastNotificationDuration": REGEX((9|10|11)\d\d\d),
+    "lastSuccess": REGEX(1[6-9]\d+),


Can you elaborate on this, pls?

lastNotificationDuration": REGEX((9|10|11)\d\d\d) the duration is expected to be around 10,000 milliseconds. the actual measured duration might fluctuate slightly (e.g., 9,988 ms or 10,018 ms ). Using (9|10|11)\d\d\d , preventing flaky test failures.

"lastSuccess": REGEX(1[6-9]\d+) In MongoDB this field is stored as a Unix timestamp (seconds since epoch). We use this expression in tests like these, e.g:

fiware-orion/test/functionalTest/cases/1048_subscription_cache/refresh_cache_wins_notif_disabled_with_update_in_the_middle.test

Line 436 in 3ccf9d7

"lastNotification": REGEX(1[6-9]\d+),

Co-authored-by: Fermín Galán Márquez <fgalan@users.noreply.github.com>

orianar · 2026-06-12T23:25:55Z

This commit adds the duration metrics to the existing MongoDB update: 9edc6f4

orianar added 10 commits May 12, 2026 20:21

Add notification duration metrics

e6935d1

add notification duration metrics to subscriptions

e38a42a

update test

76a0d1a

Fix Content-Length in tests

3c12cf7

Fix Content-Length in tests

6e92217

Fix non-existent standardized endpoint

f45d1a3

implement temporal guard for notification duration metrics

02c11a9

Aligned functional tests in 1048_subscription_cache

3b010ee

Fix refresh_db_wins_notif_success_with_update_in_the_middle.test

6472167

update documentation

8430f64

orianar changed the title ~~[WIP] Add notification duration metrics (#4772)~~ Add notification duration metrics (#4772) Jun 1, 2026

orianar mentioned this pull request Jun 1, 2026

Add Last Request Time to subscription data #4772

Open

3 tasks

orianar requested a review from fgalan June 1, 2026 03:38

Merge branch 'master' of github.com:telefonicaid/fiware-orion into fe…

1a146b7

…ature/4772-add-notification-duration-metrics_21_05

fgalan requested changes Jun 4, 2026

View reviewed changes

orianar added 7 commits June 9, 2026 10:50

add 4772_notification_duration_metrics tests

09ecedb

fix tests

ba969ab

Document the synchronization behavior of lastNotificationDuration in …

d66d4ae

…subCacheSync.

increase -subCacheIval in the refresh_cache_notif_equal_timestamps.test

8fdccee

reset duration metrics on protocol change

0c5d6b1

check DB metricis persistence in duration_metrics_accumulator_delay.test

eb05b99

Fix indentation

a2be7b0

orianar requested a review from fgalan June 10, 2026 21:57

fgalan reviewed Jun 12, 2026

View reviewed changes

Comment thread src/lib/cache/subCache.cpp Outdated

fgalan reviewed Jun 12, 2026

View reviewed changes

orianar and others added 2 commits June 12, 2026 05:44

Update src/lib/cache/subCache.cpp

30c28d1

Co-authored-by: Fermín Galán Márquez <fgalan@users.noreply.github.com>

refactor subNotificationOutcome

9edc6f4

orianar requested a review from fgalan June 12, 2026 23:26

		\| `lastNotificationDuration` \| Only on retrieval \| number \| Not editable, only present in GET operations. Duration of the last notification attempt in milliseconds. \|
		\| `accumulatedNotificationDuration` \| Only on retrieval \| number \| Not editable, only present in GET operations. Sum of durations of all notification attempts in milliseconds. \|

	if (subUp.notificationProvided)
	{
	if (subUp.notification.type != ngsiv2::HttpNotification)
	{
	unsetHttpNotificationDurationMetrics(&unsetB);
	}

	if (subUp.notificationProvided &&
	subUp.notification.type != ngsiv2::HttpNotification)
	{
	lastNotificationDuration = -1;
	notificationDurationDelta = 0;
	}

		"lastNotificationDuration": REGEX((9\|10\|11)\d\d\d),
		"lastSuccess": REGEX(1[6-9]\d+),

Conversation

orianar commented May 23, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

fgalan Jun 4, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

orianar Jun 13, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

orianar commented Jun 12, 2026

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

orianar commented May 23, 2026 •

edited

Loading

fgalan Jun 4, 2026 •

edited

Loading

orianar Jun 13, 2026 •

edited

Loading