Chronograf: tickscript logs errors on missing data

[benschweizer]

The generatd tickscript logs a lot of errors when values are missing in the series. Though, this is the case for many Telegraf modules like win_disk e.g..

The error is like:
ts=2018-02-27T08:51:10.208+01:00 lvl=error msg="error evaluating expression" service=kapacitor task_master=main task=chronograf-v1-142ac251-1b87-4fcf-bf17-ab9b50df533b node=eval2 err="missing value: \"Percent_Free_Space\""

The generated tick script is like:

var db = 'dst_telegraf'

var rp = 'autogen'

var measurement = 'win_disk'

var groupBy = ['host', 'instance']

var whereFilter = lambda: TRUE

var name = 'dst-win/disk-free_space_in_%'

var idVar = name + ':{{.Group}}'

var message = 'Service {{ index .Tags "host" }}/{{.Name}} is  {{.Level}}
{{ index .Tags "path" }} is at {{ index .Fields "value" }} '

var idTag = 'alertID'

var levelTag = 'level'

var messageField = 'message'

var durationField = 'duration'

var outputDB = 'chronograf'

var outputRP = 'autogen'

var outputMeasurement = 'alerts'

var triggerType = 'threshold'

var crit = 15

var data = stream
    |from()
        .database(db)
        .retentionPolicy(rp)
        .measurement(measurement)
        .groupBy(groupBy)
        .where(whereFilter)
    |eval(lambda: "Percent_Free_Space")
        .as('value')

var trigger = data
    |alert()
        .crit(lambda: "value" < crit)
        .stateChangesOnly()
        .message(message)
        .id(idVar)
        .idTag(idTag)
        .levelTag(levelTag)
        .messageField(messageField)
        .durationField(durationField)
        .stateChangesOnly()
        .post('https://<hostname>:8443/api/v1/kapacitor')

trigger
    |eval(lambda: float("value"))
        .as('value')
        .keep()
    |influxDBOut()
        .create()
        .database(outputDB)
        .retentionPolicy(outputRP)
        .measurement(outputMeasurement)
        .tag('alertName', name)
        .tag('triggerType', triggerType)

trigger
    |httpOut('output')

Ideas towards a solution:

• use batch processing; see https://github.com/influxdata/kapacitor/issues/1604 ; this is probably not what we want?
• use defaults or filter if this value is existent

[russorat]

@cxcv this seems like more of a kapacitor issue, correct? sounds like what you're asking for is that kapacitor shouldn't consider "missing values" as an error.

[benschweizer]

@russorat well, it's a combination of everything in the stack; telegraf is sending a stream with gaps (which is ok, imho), and kapacitor which compains about missing values, which is caused by the "broken" script generated from chronograf. If kapacitor works as designed, the best would be to have chronograf create a proper tick script?

[russorat]

@cxcv thanks for the feedback. Have you seen the proposal in https://github.com/influxdata/kapacitor/issues/1561 ? Would adding a .quiet() option to each node type solve this issue?

[benschweizer]

@russorat that sounds good to me, Ill test it manually on the affected scripts and report here.

[benschweizer]

Hello @russorat,

supressing the errors works in some cases, but I've found more situations where Chronograf-generated scripts spam the error log.

Case 1 (eval node):

Log:

var whereFilter = lambda: TRUE
[...]
ts=2018-03-08T08:27:03.374+01:00 lvl=error msg="error evaluating expression" service=kapacitor task_master=main task=chronograf-v1-142ac251-1b87-4fcf-bf17-ab9b50df533b node=eval2 err="missing value: \"Percent_Free_Space\""

Code:

var data = stream
    |from()
        .database(db)
        .retentionPolicy(rp)
        .measurement(measurement)
        .groupBy(groupBy)
        .where(whereFilter)
    |eval(lambda: "load1")
        .as('value')

Fix:

    |eval(lambda: "load1")
        .quiet()
        .as('value')

Case 2a (from node)

Log:

ts=2018-03-08T08:49:00.356+01:00 lvl=error msg="failed to evaluate WHERE expression" service=kapacitor task_master=main task=chronograf-v1-69b471b1-f7d2-4267-a769-78fee1bdb23f node=from1 err="left reference value \"mode\" is missing value"

Code:

var whereFilter = lambda: ("fstype" == 'btrfs' OR "fstype" == 'ext2' OR "fstype" == 'ext3' OR "fstype" == 'ext4' OR "fstype" == 'nfs4' OR "fstype" == 'ufs' OR "fstype" == 'vfat' OR "fstype" == 'xfs' OR "fstype" == 'zfs') AND ("mode" == 'ro')
[...]
var data = stream
    |from()
        .database(db)
        .retentionPolicy(rp)
        .measurement(measurement)
        .groupBy(groupBy)
        .where(whereFilter)
    |eval(lambda: "total")
        .as('value')

Fix?
The from node has no quiet function, but I guess the where filter could be tweaked somehow. I've tried isPresent() and is looks right:

var whereFilter = lambda: isPresent("mode") AND ("fstype" == 'btrfs' OR "fstype" == 'ext2' OR "fstype" == 'ext3' OR "fstype" == 'ext4' OR "fstype" == 'nfs4' OR "fstype" == 'ufs' OR "fstype" == 'vfat' OR "fstype" == 'xfs' OR "fstype" == 'zfs') AND ("mode" == 'ro')

Case 2b (from node)

Log:

ts=2018-03-08T08:57:03.839+01:00 lvl=error msg="failed to realize reduce context from fields" service=kapacitor task_master=main task=chronograf-v1-e2b2f063-9cc9-40d8-bc39-70b24a303714 node=mean3 err="field \"Page_Faults_persec\" missing from point"

Code:

var whereFilter = lambda: TRUE
[...]
var data = stream
    |from()
        .database(db)
        .retentionPolicy(rp)
        .measurement(measurement)
        .groupBy(groupBy)
        .where(whereFilter)
    |window()
        .period(period)
        .every(every)
        .align()
    |mean('Page_Faults_persec')
        .as('value')

Fix?
The mean function is part of the from node, so this looks similar to case 2a. Though, it throws the error at a later stage. Looks like a similar fix works:

var whereFilter = lambda: isPresent("Page_Faults_persec")

What do you think?
Cheers
Benjamin

[russorat]

thanks @cxcv. we will look into making those changes to improve our tickscript generator for the alert builder.

[snewbie]

I get the same issue with Threshold Alerts trying to set the whereFilter; I found if the field or tag is enclosed in single values then the error goes away but of course the alert will not work. Is this confirmed to be a kapacitor issue or is there a workaround? In my case the field is always populated going into influxdb.

[egee-irl]

I'm having the same issue as snewbie. It's filling up my logs and making it very difficult to find _real_ errors.

In my case, the error is being thrown with Chronograf:

lvl=error msg="failed to evaluate WHERE expression" service=kapacitor task_master=main task=chronograf-v1-855715 node=from1 err="left reference value \"com.amazonaws.ecs.container-name\" is missing value"

Every tick script I create throws the same error, however everything is working fine with Kapacitor, Chronograf, and InfluxDB. Even my alerts work.

[dataviruset]

I'm having the same issue as snewbie. It's filling up my logs and making it very difficult to find _real_ errors.

In my case, the error is being thrown with Chronograf:

lvl=error msg="failed to evaluate WHERE expression" service=kapacitor task_master=main task=chronograf-v1-855715 node=from1 err="left reference value \"com.amazonaws.ecs.container-name\" is missing value"

Every tick script I create throws the same error, however everything is working fine with Kapacitor, Chronograf, and InfluxDB. Even my alerts work.

It's because some data points you're sending to InfluxDB are missing these tags or fields. You can use isPresent("com.amazonaws.ecs.container-name") in your TICKscript to only continue evaluating the lambda statement if the tag/field is present. But yeah, would be good if Chronograf could deal with this in some way. Maybe by adding a checkbox in the alert generator to not require that the tag/field exists.

[egee-irl]

Well hot diggidy dog, @dataviruset your suggestion fixed it. Here's how I implemented it:

var serviceName = "metadata-scraper"
var tag = 'com.amazonaws.ecs.container-name'

var whereFilter = lambda: (isPresent("metadata-scraper") AND "metadata-scraper" == serviceName)

EDIT: This solution didn't work. Check my response below.

[snewbie]

Well, I forgot to include that this was also in chronograf. Thank you @dataviruset for the workaround and @egee-irl for the sample.

[dataviruset]

Actually @cxcv also mentioned this workaround in his post. But you're welcome ;)

[egee-irl]

Ok so I made a grave mistake - the solution didn't fix my problem at all!

First off, you can't use variables inside lambdas like I showed in my example. And second, using the isPresent() function resulted in my alert not working at all because the filter was no longer matching.

I don't fuller understand this because the Kapacitor logs are complaining that there are not matches.. But there are clearly matches because the alert works (sends messages to Slack) and the metrics show up when I look at the alert in Chronograf.

However what DID work was using the quiet() function where my filter is being used. Inside my tickscript I've got a stream that uses the where filter. I added quiet() to it and that appears to have fixed it:

var data = stream
    | from()
        .database(db)
        .retentionPolicy(rp)
        .measurement(measurement)
        .groupBy(groupBy)
        .where(whereFilter)
        .quiet() //Here it is
    | window()
        .period(period)
        .every(every)
        .align()
    | mean('usage_percent')
        .as('value')

[snewbie]

@egee-irl - After I edited the tickscript using the variables the alert and tickscript disappeared from the list of alerts and scripts. But I did recreate and try using your suggestion of the quiet() but it comes back with error no method or property on from pipeline.

[egee-irl]

After I edited the tickscript using the variables the alert and tickscript disappeared from the list of alerts and scripts.

Yes, this is what I fought with today! It's because you cannot references variables inside lambdas. Even though the tickscript parses correctly, the lambda is invalid and does not generate an alert. I've updated my comment accordingly.. Sorry about that!

But yes, the quiet() function resolves the warning spam and makes the Kapacitor logs readable again.

[fhriley]

It's because you cannot references variables inside lambdas.

I don't believe this is correct, mainly because I have tickscripts that are doing exactly that and they work fine. For example, your code above

var serviceName = 'some_val'
var whereFilter = lambda: (isPresent("metadata-scraper") AND "metadata-scraper" == serviceName)

should work fine. What you can't do is have the field name in a variable, like this:

lambda: var_containing_field_name == 123

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[stale[bot]]

This issue has been automatically closed because it has not had recent activity. Feel free to reopen if this issue is still important to you. Thank you for your contributions.