influxdata / influxdata/kapacitor
"panic: invalid timer state" - httpOut() node for batch task crashes kapacitor
- Dominant language
- Go
- Stars
- 2.4k
- Forks
- 479
- Avg merge
- 4d 16h
- Merged PRs (30d)
- 4
Description
Hi,
i am running:
`~ ❯❯❯ kapacitor version
Kapacitor v1.3.3 (git: ce586f35e89e75a1779e2b493caba15d66295a15)`
And i had a batch that worked fine, now since i added an `|httpOut` node i can reproducibly crash kapacitor. I tried moving the httpOut before the influx out and now into an individual variable, still the same error. I am running on Mac OSX 10.12.6
Your help is appreciated.
**Query and Data**
`SELECT count("event_id") AS "count_event_id" FROM "azeti"."autogen"."State" WHERE time > now() - 1d GROUP BY time(4h) `
```
date,count_event_id
11/5/2017 1:00:00 PM,43
11/5/2017 5:00:00 PM,52
11/5/2017 9:00:00 PM,57
11/6/2017 1:00:00 AM,51
11/6/2017 5:00:00 AM,31
11/6/2017 9:00:00 AM,31
11/6/2017 1:00:00 PM,9
```
**Tick Script**
```
var measurement = 'event_trend2'
var period = 1d
var every = 4h
var data = batch
|query('SELECT count(event_id) as alert_count FROM "azeti"."autogen".State')
.period(period)
.every(every)
.groupBy(time(every), *)
.fill(0)
var mean_data = data
|mean('alert_count')
.as('mean')
var deriv_data = data
|derivative('alert_count')
.unit(every)
.nonNegative()
.as('derivative')
|last('derivative')
.as('derivative')
mean_data
|join(deriv_data)
.as('mean', 'deriv')
|influxDBOut()
.database('_azeti_analytics')
.measurement(measurement)
mean_data
|httpOut('result')
```
**Record & Replay**
```
~ ❯❯❯ rec=$(kapacitor record batch -task test2 -past 1d); echo "Recording: $rec\n-----------"; kapacitor replay -task test2 -recording $rec
Recording: d3aa2652-ea35-457d-abf2-a12dc9d3bce5
-----------
Get http://localhost:9092/kapacitor/v1/replays/c9985d17-fdcf-42fb-8730-6211b04f7214: dial tcp [::1]:9092: getsockopt: connection refused
```
**Log Output**
```
[httpd] ::1 - - [06/Nov/2017:13:55:06 +0100] "POST /kapacitor/v1/recordings/batch HTTP/1.1" 201 212 "-" "KapacitorClient" b6bafc93-c2f1-11e7-8001-000000000000 23289
[replay] 2017/11/06 13:55:06 D! Runing batch query for replay SELECT count(event_id) AS alert_count FROM azeti.autogen.State WHERE time >= '2017-11-04T16:55:06.664463724Z' AND time < '2017-11-05T16:55:06.664463724Z' GROUP BY time(4h, 0s), * fill(0)
[replay] 2017/11/06 13:55:07 D! Runing batch query for replay SELECT count(event_id) AS alert_count FROM azeti.autogen.State WHERE time >= '2017-11-04T20:55:06.664463724Z' AND time < '2017-11-05T20:55:06.664463724Z' GROUP BY time(4h, 0s), * fill(0)
[httpd] ::1 - - [06/Nov/2017:13:55:07 +0100] "GET /kapacitor/v1/recordings/d3aa2652-ea35-457d-abf2-a12dc9d3bce5 HTTP/1.1" 202 212 "-" "KapacitorClient" b70bdaad-c2f1-11e7-8002-000000000000 4885
[replay] 2017/11/06 13:55:07 D! Runing batch query for replay SELECT count(event_id) AS alert_count FROM azeti.autogen.State WHERE time >= '2017-11-05T00:55:06.664463724Z' AND time < '2017-11-06T00:55:06.664463724Z' GROUP BY time(4h, 0s), * fill(0)
[httpd] ::1 - - [06/Nov/2017:13:55:07 +0100] "GET /kapacitor/v1/recordings/d3aa2652-ea35-457d-abf2-a12dc9d3bce5 HTTP/1.1" 202 212 "-" "KapacitorClient" b7596e9d-c2f1-11e7-8003-000000000000 495
[replay] 2017/11/06 13:55:08 D! Runing batch query for replay SELECT count(event_id) AS alert_count FROM azeti.autogen.State WHERE time >= '2017-11-05T04:55:06.664463724Z' AND time < '2017-11-06T04:55:06.664463724Z' GROUP BY time(4h, 0s), * fill(0)
[httpd] ::1 - - [06/Nov/2017:13:55:08 +0100] "GET /kapacitor/v1/recordings/d3aa2652-ea35-457d-abf2-a12dc9d3bce5 HTTP/1.1" 202 212 "-" "KapacitorClient" b7a65c35-c2f1-11e7-8004-000000000000 2087
[replay] 2017/11/06 13:55:08 D! Runing batch query for replay SELECT count(event_id) AS alert_count FROM azeti.autogen.State WHERE time >= '2017-11-05T08:55:06.664463724Z' AND time < '2017-11-06T08:55:06.664463724Z' GROUP BY time(4h, 0s), * fill(0)
[httpd] ::1 - - [06/Nov/2017:13:55:08 +0100] "GET /kapacitor/v1/recordings/d3aa2652-ea35-457d-abf2-a12dc9d3bce5 HTTP/1.1" 202 212 "-" "KapacitorClient" b7f3d732-c2f1-11e7-8005-000000000000 1232
[replay] 2017/11/06 13:55:09 D! Runing batch query for replay SELECT count(event_id) AS alert_count FROM azeti.autogen.State WHERE time >= '2017-11-05T12:55:06.664463724Z' AND time < '2017-11-06T12:55:06.664463724Z' GROUP BY time(4h, 0s), * fill(0)
[httpd] ::1 - - [06/Nov/2017:13:55:09 +0100] "GET /kapacitor/v1/recordings/d3aa2652-ea35-457d-abf2-a12dc9d3bce5 HTTP/1.1" 202 212 "-" "KapacitorClient" b840bc1a-c2f1-11e7-8006-000000000000 1569
[httpd] ::1 - - [06/Nov/2017:13:55:09 +0100] "GET /kapacitor/v1/recordings/d3aa2652-ea35-457d-abf2-a12dc9d3bce5 HTTP/1.1" 200 214 "-" "KapacitorClient" b88dca86-c2f1-11e7-8007-000000000000 1169
[task_master:c9985d17-fdcf-42fb-8730-6211b04f7214] 2017/11/06 13:55:09 I! opened
[task_master:c9985d17-fdcf-42fb-8730-6211b04f7214] 2017/11/06 13:55:09 D! Starting task: test2
[httpd] ::1 - - [06/Nov/2017:13:55:09 +0100] "POST /kapacitor/v1/replays HTTP/1.1" 201 258 "-" "KapacitorClient" b890475a-c2f1-11e7-8008-000000000000 16099
[task_master:c9985d17-fdcf-42fb-8730-6211b04f7214] 2017/11/06 13:55:09 I! Started task: test2
[task_master:c9985d17-fdcf-42fb-8730-6211b04f7214] 2017/11/06 13:55:09 D! digraph test2 {
query1 -> mean2;
query1 -> derivative3;
derivative3 -> last4;
last4 -> http_out5;
last4 -> join7;
mean2 -> join7;
join7 -> influxdb_out8;
}
[edge:test2|last4->http_out5] 2017/11/06 13:55:09 I! aborting c: 0 e: 0
[test2:http_out5] 2017/11/06 13:55:09 E! http: multiple registrations for /kapacitor/v1/tasks/test2/events
[test2:last4] 2017/11/06 13:55:09 E! failed to emit batch: edged aborted
[test2:last4] 2017/11/06 13:55:09 E! failed to emit batch: edged aborted
[test2:last4] 2017/11/06 13:55:09 E! failed to emit batch: edged aborted
[test2:last4] 2017/11/06 13:55:09 E! failed to emit batch: edged aborted
[test2:last4] 2017/11/06 13:55:09 E! failed to emit batch: edged aborted
[test2:last4] 2017/11/06 13:55:09 E! failed to emit batch: edged aborted
[test2:last4] 2017/11/06 13:55:09 E! failed to emit batch: edged aborted
[test2:last4] 2017/11/06 13:55:09 E! failed to emit batch: edged aborted
[test2:last4] 2017/11/06 13:55:09 E! failed to emit batch: edged aborted
[edge:test2|last4->http_out5] 2017/11/06 13:55:09 D! closing c: 20 e: 0
[edge:test2|last4->join7] 2017/11/06 13:55:09 D! closing c: 11 e: 11
```
**Kapacitor Panic Output**
```
2017/11/06 13:50:32 Using configuration at: /usr/local/etc/kapacitor.conf
panic: invalid timer state
goroutine 892 [running]:
github.com/influxdata/kapacitor/timer.(*timer).Start(0xc4206cb500)
/private/tmp/kapacitor-20170923-39941-6hwsf8/src/github.com/influxdata/kapacitor/timer/timer.go:68 +0xc3
github.com/influxdata/kapacitor.(*InfluxQLNode).runBatchInfluxQL(0xc42016df00, 0x0, 0xc420025900)
/private/tmp/kapacitor-20170923-39941-6hwsf8/src/github.com/influxdata/kapacitor/influxql.go:176 +0x172
github.com/influxdata/kapacitor.(*InfluxQLNode).runInfluxQLs(0xc42016df00, 0x0, 0x0, 0x0, 0xc420881780, 0x4)
/private/tmp/kapacitor-20170923-39941-6hwsf8/src/github.com/influxdata/kapacitor/influxql.go:45 +0x4a
github.com/influxdata/kapacitor.(*InfluxQLNode).(github.com/influxdata/kapacitor.runInfluxQLs)-fm(0x0, 0x0, 0x0, 0xc4208817a0, 0xc4208d6fc0)
/private/tmp/kapacitor-20170923-39941-6hwsf8/src/github.com/influxdata/kapacitor/influxql.go:36 +0x48
github.com/influxdata/kapacitor.(*node).start.func1(0xc42016df00, 0x0, 0x0, 0x0)
/private/tmp/kapacitor-20170923-39941-6hwsf8/src/github.com/influxdata/kapacitor/node.go:140 +0x8e
created by github.com/influxdata/kapacitor.(*node).start
/private/tmp/kapacitor-20170923-39941-6hwsf8/src/github.com/influxdata/kapacitor/node.go:119 +0x5d
```
Contributor guide
Research direction
Start with timer/timer.go:68 and influxql.go:176, then trace the batch execution path through influxql.go and node.go. Reproduce the crash with the supplied batch task, httpOut node, and record/replay commands. Done means the task no longer panics or aborts with the reported invalid timer state while the duplicate HTTP registration behavior is addressed.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- backend
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 38/100