Kapacitor: So sad deadlock

[R4scal]

Hi

Ubuntu 16.04 / Kapacitor 1.4.1

We encountered sadly locking in the AlertNode

Tick script to reproduce the problem:

// Dataframe
var data_A = stream
    |from()
        .database('telegraf')
        .measurement('disk')
    |default()
        .field('used_percent', -2147483648)
        .tag('env', '')
    |where(lambda: "env" == 'prod' AND "used_percent" != -2147483648)
    |groupBy('host', 'path')
    |window()
        .period(30s)
        .every(15s)
    |mean('used_percent')
        .as('value')

// Thresholds if data exist
data_A
    |alert()
        .warn(lambda: "value" > 0)
        .crit(lambda: "value" > 90)
        .stateChangesOnly(1m)

// Thresholds if no data exist
data_A
    |groupBy('host', 'path', 'alert_rule')
    |stats(30s)
        .align()
    |derivative('emitted')
        .unit(30s)
        .nonNegative()
    |stateCount(lambda: "emitted" <= 0.0)
    |alert()
        .stateChangesOnly(1m)
        .crit(lambda: "state_count" > 0)

What happens when I run the script:

digraph monitoring_alert_3 {
graph [throughput="237.00 points/s"];

stream0 [avg_exec_time_ns="0s" errors="0" working_cardinality="0" ];
stream0 -> from1 [processed="30353"];

from1 [avg_exec_time_ns="3.035µs" errors="0" working_cardinality="0" ];
from1 -> default2 [processed="30353"];

default2 [avg_exec_time_ns="73.723µs" errors="0" fields_defaulted="0" tags_defaulted="32713" working_cardinality="0" ];
default2 -> where3 [processed="30353"];

where3 [avg_exec_time_ns="3.287µs" errors="0" working_cardinality="1" ];
where3 -> groupby4 [processed="18659"];

groupby4 [avg_exec_time_ns="2.767µs" errors="0" working_cardinality="0" ];
groupby4 -> window5 [processed="18659"];

window5 [avg_exec_time_ns="5.108µs" errors="0" working_cardinality="1593" ];
window5 -> mean6 [processed="8181"];

mean6 [avg_exec_time_ns="13.121µs" errors="0" working_cardinality="1593" ];
mean6 -> groupby8 [processed="8181"];
mean6 -> alert7 [processed="8181"];

groupby8 [avg_exec_time_ns="390ns" errors="0" working_cardinality="0" ];
groupby8 -> noop10 [processed="8181"];

noop10 [avg_exec_time_ns="0s" errors="0" working_cardinality="0" ];

alert7 [alerts_triggered="3146" avg_exec_time_ns="87.409µs" crits_triggered="12" errors="0" infos_triggered="0" oks_triggered="0" warns_triggered="3134" working_cardinality="1593" ];

stats9 [avg_exec_time_ns="0s" errors="0" working_cardinality="0" ];
stats9 -> derivative11 [processed="5020"];

derivative11 [avg_exec_time_ns="2.451µs" errors="0" working_cardinality="1593" ];
derivative11 -> state_count12 [processed="3427"];

state_count12 [avg_exec_time_ns="8.759µs" errors="0" working_cardinality="1593" ];
state_count12 -> alert13 [processed="3427"];

alert13 [alerts_triggered="0" avg_exec_time_ns="14.917µs" crits_triggered="0" errors="0" infos_triggered="0" oks_triggered="0" warns_triggered="0" working_cardinality="1593" ];
}

1. All nodes get data
2. I can run an enable / disable kapacitor task.
3. Successfully received data on the /write endpoint

What happens when I run the script with action (log on ramdisk with this example, or slack, or post):

digraph monitoring_alert_3 {
graph [throughput="2.00 points/s"];

stream0 [avg_exec_time_ns="0s" errors="0" working_cardinality="0" ];
stream0 -> from1 [processed="18112"];

from1 [avg_exec_time_ns="1.284µs" errors="0" working_cardinality="0" ];
from1 -> default2 [processed="17111"];

default2 [avg_exec_time_ns="25.664µs" errors="0" fields_defaulted="0" tags_defaulted="17336" working_cardinality="0" ];
default2 -> where3 [processed="16110"];

where3 [avg_exec_time_ns="10.408µs" errors="0" working_cardinality="1" ];
where3 -> groupby4 [processed="9345"];

groupby4 [avg_exec_time_ns="3.017µs" errors="0" working_cardinality="0" ];
groupby4 -> window5 [processed="8344"];

window5 [avg_exec_time_ns="4.228µs" errors="0" working_cardinality="1593" ];
window5 -> mean6 [processed="2457"];

mean6 [avg_exec_time_ns="13.494µs" errors="0" working_cardinality="1397" ];
mean6 -> groupby8 [processed="1457"];
mean6 -> alert7 [processed="1456"];

groupby8 [avg_exec_time_ns="467ns" errors="0" working_cardinality="0" ];
groupby8 -> noop10 [processed="1457"];

noop10 [avg_exec_time_ns="0s" errors="0" working_cardinality="0" ];

alert7 [alerts_triggered="456" avg_exec_time_ns="277.933939ms" crits_triggered="4" errors="0" infos_triggered="0" oks_triggered="0" warns_triggered="452" working_cardinality="456" ];

stats9 [avg_exec_time_ns="10.929084ms" errors="0" working_cardinality="0" ];
stats9 -> derivative11 [processed="4575"];

derivative11 [avg_exec_time_ns="2.59µs" errors="0" working_cardinality="1293" ];
derivative11 -> state_count12 [processed="2281"];

state_count12 [avg_exec_time_ns="6.654µs" errors="0" working_cardinality="1034" ];
state_count12 -> alert13 [processed="1280"];

alert13 [alerts_triggered="272" avg_exec_time_ns="325.085892ms" crits_triggered="271" errors="0" infos_triggered="0" oks_triggered="1" warns_triggered="0" working_cardinality="280" ];
}

1. working_cardinality different from previos (on some data)
2. I can't run an enable / disable kapacitor task (timeout).
3. 499 status codes on /write endpoint, kapacitor don't receive new data

full goroutine stack dump with active deadlock

Perhaps related issues:
https://github.com/influxdata/kapacitor/issues/1149
https://github.com/influxdata/kapacitor/issues/1829

[R4scal]

Today I repeated the test with the latest version (1.5.0) of kapacitor. The problem is still relevant.

[morodest]

+1

[Lychangin]

+1

[dimakein]

+1