Two copies of metric returned after ,mtail file update

[ctc...@gmail.com]

Hi,

I am using puppet to manage my .mtail files, and I just found out that mtail should notice changes to .mtail files without having to be restarted, which seems a nice feature.
However, when I tried this out, with puppet updating a .mtail file and adding a new metric, mtail started returning the new metric as expected, but also returned two copies of some existing metrics.
My mtail program was like this:

hidden gauge start_processing_time by pid
counter processing_time_total

/^(?P<date>\w+\s+\d+\s+\d+:\d+:\d+) <some pattern> [(?P<pid>\d+)\]: / {
    strptime($date, "Jan _2 15:04:05")

    /Starting/ {
        start_processing_time[$pid] = timestamp()
    }

    /Finished/ {
        start_processing_time[$pid] > 0 {
            processing_time_total += timestamp() - start_processing_time[$pid]
            del start_processing_time[$pid]
        }
    }
}

and after the update like this:

hidden gauge start_processing_time by pid
gauge processing_time
counter processing_time_total

/^(?P<date>\w+\s+\d+\s+\d+:\d+:\d+) <some pattern> [(?P<pid>\d+)\]: / {
    strptime($date, "Jan _2 15:04:05")

    /Starting/ {
        start_processing_time[$pid] = timestamp()
    }

    /Finished/ {
        start_processing_time[$pid] > 0 {
            processing_time = timestamp() - start_processing_time[$pid]
            processing_time_total += timestamp() - start_processing_time[$pid]
            del start_processing_time[$pid]
        }
    }
}

After the update mtail returned two copies of the processing_time_total metric.

Is this a feature, or a known issue?

Chris

[Jamie Wilkinson]

It's not a feature, there should only be one metric. Can you paste the metric page from the webserver before and after and also if you can run with the flag --vmodule=metric=2,mcp=2 and send the log when the program is reloaded that would be helpful. Also what version are you runnin?

--
You received this message because you are subscribed to the Google Groups "mtail-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mtail-users...@googlegroups.com.
To post to this group, send email to mtail...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/mtail-users/0c92c279-88be-48c0-86f0-cf07de1639db%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[ctc...@gmail.com]

Here is the before and after output of the metric page:
Before:

# TYPE processing_time_total counter
# processing_time_total defined at test.mtail:4:9-46
processing_time_total{prog="test.mtail"} 0

After:

# TYPE processing_time_total counter
# processing_time_total defined at test.mtail:4:9-46
processing_time_total{prog="test.mtail"} 0
# processing_time_total defined at test.mtail:5:9-46
processing_time_total{prog="test.mtail"} 0
# TYPE processing_time gauge
# processing_time defined at test.mtail:4:7-38
processing_time{prog="test.mtail"} 0

I'm using version: "mtail version v3.0.0-rc16 git revision 77eeba903db0ffd90e29c1ee778fdefb0112bfab go version go1.11"

The only things I can see in the log that looks relevant are lines like this:

I1210 09:40:44.914459   20382 mcp.go:437] Remove watch on /etc/sysconfig/mtail/test/4913 failed: can't remove non-existent inotify watch for: /etc/sysconfig/mtail/test/4913
I1210 09:40:44.914667   20382 mcp.go:437] Remove watch on /etc/sysconfig/mtail/test/test.mtail failed: can't remove non-existent inotify watch for: /etc/sysconfig/mtail/test/test.mtail

Chris