influxdata / influxdata/kapacitor

alert() node is slow in processing

Open
#1,956 1 comment 0 reactions 0 assignees View on GitHub
Dominant language
Go
Stars
2.4k
Forks
479
Avg merge
4d 16h
Merged PRs (30d)
4

Description

Seems like alert() node is slow in processing.

```
ID: teakwood-g_teakwood_interfaces_state_state
Error:
Template:
Type: batch
Status: enabled
Executing: true
Created: 06 Jun 18 14:27 UTC
Modified: 06 Jun 18 16:53 UTC
LastEnabled: 06 Jun 18 16:53 UTC
Databases Retention Policies: ["teakwood-g_teakwood"."autogen" "Native"."autogen"]
TICKscript:
var from_database = 'teakwood-g_teakwood'

var to_database = 'teakwood-g_teakwood'

var var_term1_query = batch
|query(''' select * from "teakwood-g_teakwood"."autogen"."interfaces/state" order by desc''')
.period(1m)
.every(10s)
.groupBy(*)
|log()
.prefix('beforealert')

var var_green_then_status = var_term1_query
|alert()
.info(lambda: "oper" == 'down')
.message('DEVICE: teakwood-g_teakwood, TAGS: {{ .Tags}}, TRIGGER: state')
.topic('interfaces__state__state')
|log()
.prefix('afteralert')
|influxDBOut()
.measurement('interfaces/state/state')
.database(to_database)

DOT:
digraph teakwood-g_teakwood_interfaces_state_state {
graph [throughput="24.00 batches/s"];

query1 [avg_exec_time_ns="599.968603ms" batches_queried="5962" errors="0" points_queried="188094" working_cardinality="0" ];
query1 -> log2 [processed="4960"];

log2 [avg_exec_time_ns="1.474954ms" errors="0" working_cardinality="0" ];
log2 -> alert3 [processed="3959"];

alert3 [alerts_triggered="2959" avg_exec_time_ns="80.111889ms" crits_triggered="0" errors="0" infos_triggered="2959" oks_triggered="0" warns_triggered="0" working_cardinality="600" ];
alert3 -> log4 [processed="2958"];

log4 [avg_exec_time_ns="2.10357ms" errors="0" working_cardinality="0" ];
log4 -> influxdb_out5 [processed="2958"];

influxdb_out5 [avg_exec_time_ns="28.72µs" errors="0" points_written="96794" working_cardinality="0" write_errors="0" ];
}
```

As you can see from the above show output, log2 has processed 3959 points where as alert3 has only processed 2958 and send it to log4.

With the alert() node removed, points are processed faster.

```
D: teakwood-g_teakwood_interfaces_state_state
Error:
Template:
Type: batch
Status: enabled
Executing: true
Created: 06 Jun 18 17:49 UTC
Modified: 06 Jun 18 17:49 UTC
LastEnabled: 06 Jun 18 17:49 UTC
Databases Retention Policies: ["teakwood-g_teakwood"."autogen" "Native"."autogen"]
TICKscript:
var from_database = 'teakwood-g_teakwood'

var to_database = 'teakwood-g_teakwood'

var var_term1_query = batch
|query(''' select * from "teakwood-g_teakwood"."autogen"."interfaces/state" order by desc''')
.period(1m)
.every(10s)
.groupBy(*)
|log()
.prefix('beforealert')

var var_green_then_status = var_term1_query
// |alert()
// .info(lambda: "oper" == 'down')
// .message('DEVICE: teakwood-g_teakwood, TAGS: {{ .Tags}}, TRIGGER: state')
// .topic('interfaces__state__state')
|log()
.prefix('afteralert')
|influxDBOut()
.measurement('interfaces/state/state')
.database(to_database)

DOT:
digraph teakwood-g_teakwood_interfaces_state_state {
graph [throughput="0.00 batches/s"];

query1 [avg_exec_time_ns="696.159735ms" batches_queried="4900" errors="0" points_queried="90684" working_cardinality="0" ];
query1 -> log2 [processed="4900"];

log2 [avg_exec_time_ns="834.936µs" errors="0" working_cardinality="0" ];
log2 -> log3 [processed="4900"];

log3 [avg_exec_time_ns="791.471µs" errors="0" working_cardinality="0" ];
log3 -> influxdb_out4 [processed="4900"];

influxdb_out4 [avg_exec_time_ns="367.659µs" errors="0" points_written="90502" working_cardinality="0" write_errors="0" ];
}
```

As you can use 4900 points are passed from log2 to log3.

Any clue on why alert() node is slow? This causes delay for us in writing the processed data back into influxdb.

Following python script can be used to generate the interface/state measurement.

```python

#!/usr/bin/env python3
from influxdb import InfluxDBClient
import datetime
import sys
import time

client = InfluxDBClient('localhost', 8086,
database='teakwood-g_teakwood')

while True:
for x in range(0, 600):
dd = datetime.datetime.utcnow()
point_date = datetime.datetime.fromtimestamp(
int(dd.strftime('%s'))).strftime(
'%Y-%m-%dT%H:%M:%SZ')
print(point_date)
name = 'et' + str(x)
points = [
{
"measurement": "interfaces/state",
"time": point_date,
"tags": {
"name": name,
},
"fields": {
"oper": "down",
}
}
]
print("Write points: {0}".format(points))
print(client.write_points(points))

```

Below are the setup details:
OS: Ubuntu 16.04.2
RAM: 128 GB
Kapacitor version: 1.4.1 (Tested scenarios of pre-built package directly on host and on docker)

Contributor guide

Open the contributing guide

Research direction

No source files or tests are named. Start by reproducing the alert() versus no-alert() comparison with the provided Python InfluxDB generator, then inspect the alert() node using the DOT execution statistics. Done means the cause is addressed and the two paths no longer show the reported processing gap under the reproduction.

Written by the indexing model from the issue text.

Assessment

Tech stack
go, python
Domain
observability, stream-processing
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
28/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.