Skip to content
This repository has been archived by the owner on Aug 23, 2023. It is now read-only.

panic on query like asPercent(summarize(#A, '1min'), #A) #1845

Closed
Dieterbe opened this issue Jun 8, 2020 · 3 comments · Fixed by #1849
Closed

panic on query like asPercent(summarize(#A, '1min'), #A) #1845

Dieterbe opened this issue Jun 8, 2020 · 3 comments · Fixed by #1849
Assignees
Labels
Milestone

Comments

@Dieterbe
Copy link
Contributor

Dieterbe commented Jun 8, 2020

Describe the bug

  • launch docker-dev
  • in Grafana, run this query against MT
#A stats.docker-env.response.200 (hidden)
#B asPercent(summarize(#A, '1min'), #A)

this results in a panic/http500:

<html> <head><title>PANIC: runtime error: index out of range [30] with length 30</title> <meta charset="utf-8" /> <style type="text/css"> html, body { font-family: "Roboto", sans-serif; color: #333333; background-color: #ea5343; margin: 0px; } h1 { color: #d04526; background-color: #ffffff; padding: 20px; border-bottom: 1px dashed #2b3848; } pre { margin: 20px; padding: 20px; border: 2px solid #2b3848; background-color: #ffffff; white-space: pre-wrap; /* css-3 */ white-space: -moz-pre-wrap; /* Mozilla, since 1999 */ white-space: -pre-wrap; /* Opera 4-6 */ white-space: -o-pre-wrap; /* Opera 7 */ word-wrap: break-word; /* Internet Explorer 5.5+ */ } </style> </head>
<body>
 <h1>PANIC</h1> <pre style="font-weight: bold;">runtime error: index out of range [30] with length 30</pre> <pre>/usr/lib/go/src/runtime/panic.go:88 (0x4326e2) 
$GOPATH/src/github.com/grafana/metrictank/expr/func_aspercent.go:221 (0xb8b6bb) 
$GOPATH/src/github.com/grafana/metrictank/expr/func_aspercent.go:90 (0xb880bb) 
$GOPATH/src/github.com/grafana/metrictank/expr/plan.go:309 (0xbae7f7) 
$GOPATH/src/github.com/grafana/metrictank/api/graphite.go:851 (0xc20597) 
$GOPATH/src/github.com/grafana/metrictank/api/graphite.go:270 (0xc19773)
/usr/lib/go/src/reflect/value.go:460 (0x4b6eca)
/usr/lib/go/src/reflect/value.go:321 (0x4b63d3) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:177 (0xab1dab) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:137 (0xab1789) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:121 (0xacc5e8) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:112 (0xc07691) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/raintank/gziper/gzip.go:100 (0xc07684) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:79 (0xacc490) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:157 (0xab1ad7) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:135 (0xab1878) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:121 (0xacc5e8) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:112 (0xadd0f5) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/recovery.go:161 (0xadd0e8) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/logger.go:40 (0xad0053) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:157 (0xab1ad7) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:135 (0xab1878) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:121 (0xacc5e8) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:112 (0xb31520) 
$GOPATH/src/github.com/grafana/metrictank/api/middleware/logger.go:45 (0xb31509)
/usr/lib/go/src/reflect/value.go:460 (0x4b6eca)
/usr/lib/go/src/reflect/value.go:321 (0x4b63d3) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:177 (0xab1dab) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:137 (0xab1789) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:121 (0xacc5e8) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:112 (0xb32dab) 
$GOPATH/src/github.com/grafana/metrictank/api/middleware/tracer.go:70 (0xb32d96) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:79 (0xacc490) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:157 (0xab1ad7) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:135 (0xab1878) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:121 (0xacc5e8) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:112 (0xb3248d) 
$GOPATH/src/github.com/grafana/metrictank/api/middleware/stats.go:76 (0xb32478) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:79 (0xacc490) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:157 (0xab1ad7) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:135 (0xab1878) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:121 (0xacc5e8) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:112 (0xadd0f5) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/recovery.go:161 (0xadd0e8) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/logger.go:40 (0xad0053) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:157 (0xab1ad7) 
$GOPATH/src/github.com/grafana/metrictank/vendor/github.com/go-macaron/inject/inject.go:135 (0xab1878) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/context.go:121 (0xacc5e8) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/router.go:187 (0xade306) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/router.go:294 (0xad876d) 
$GOPATH/src/github.com/grafana/metrictank/vendor/gopkg.in/macaron.v1/macaron.go:220 (0xad138a)
/usr/lib/go/src/net/http/server.go:2807 (0x742792)
/usr/lib/go/src/net/http/server.go:1895 (0x73e20b)
/usr/lib/go/src/runtime/asm_amd64.s:1373 (0x467780) </pre> 
</body> </html>"
message:"Internal Server Error"

Helpful Information
Metrictank Version: v0.13.1-800-g74ba401c

@Dieterbe Dieterbe added the bug label Jun 8, 2020
@Dieterbe Dieterbe added this to the sprint-13 milestone Jun 8, 2020
@Dieterbe
Copy link
Contributor Author

Dieterbe commented Jun 8, 2020

querying the last 3 minutes, and adding some print statements reveals this:

execWithoutNodes has these input slices:

metrictank_1    | IN len 1
metrictank_1    | > interval=60, 3 points: [{NaN 1591617900} {NaN 1591617960} {NaN 1591618020}]
metrictank_1    | TOTALS len 1
metrictank_1    | > interval=1, 120 points: [{NaN 1591617916} {NaN 1591617917} {NaN 1591617918} {NaN 1591617919} {NaN 1591617920} {NaN 1591617921} {NaN 1591617922} {NaN 1591617923} {NaN 1591617924} {NaN 1591617925} {NaN 1591617926} {NaN 1591617927} {NaN 1591617928} {NaN 1591617929} {NaN 1591617930} {NaN 1591617931} {NaN 1591617932} {NaN 1591617933} {NaN 1591617934} {NaN 1591617935} {NaN 1591617936} {NaN 1591617937} {NaN 1591617938} {NaN 1591617939} {NaN 1591617940} {NaN 1591617941} {NaN 1591617942} {NaN 1591617943} {NaN 1591617944} {NaN 1591617945} {NaN 1591617946} {NaN 1591617947} {NaN 1591617948} {NaN 1591617949} {NaN 1591617950} {NaN 1591617951} {NaN 1591617952} {NaN 1591617953} {NaN 1591617954} {NaN 1591617955} {NaN 1591617956} {NaN 1591617957} {NaN 1591617958} {NaN 1591617959} {NaN 1591617960} {NaN 1591617961} {NaN 1591617962} {NaN 1591617963} {NaN 1591617964} {NaN 1591617965} {NaN 1591617966} {NaN 1591617967} {NaN 1591617968} {NaN 1591617969} {NaN 1591617970} {NaN 1591617971} {NaN 1591617972} {NaN 1591617973} {NaN 1591617974} {NaN 1591617975} {NaN 1591617976} {NaN 1591617977} {NaN 1591617978} {NaN 1591617979} {NaN 1591617980} {NaN 1591617981} {NaN 1591617982} {NaN 1591617983} {NaN 1591617984} {NaN 1591617985} {NaN 1591617986} {NaN 1591617987} {NaN 1591617988} {NaN 1591617989} {NaN 1591617990} {NaN 1591617991} {NaN 1591617992} {NaN 1591617993} {NaN 1591617994} {NaN 1591617995} {NaN 1591617996} {NaN 1591617997} {NaN 1591617998} {NaN 1591617999} {NaN 1591618000} {NaN 1591618001} {NaN 1591618002} {NaN 1591618003} {NaN 1591618004} {NaN 1591618005} {NaN 1591618006} {NaN 1591618007} {NaN 1591618008} {NaN 1591618009} {NaN 1591618010} {NaN 1591618011} {NaN 1591618012} {NaN 1591618013} {NaN 1591618014} {NaN 1591618015} {NaN 1591618016} {NaN 1591618017} {NaN 1591618018} {NaN 1591618019} {NaN 1591618020} {NaN 1591618021} {NaN 1591618022} {NaN 1591618023} {NaN 1591618024} {NaN 1591618025} {NaN 1591618026} {NaN 1591618027} {NaN 1591618028} {NaN 1591618029} {NaN 1591618030} {NaN 1591618031} {NaN 1591618032} {NaN 1591618033} {NaN 1591618034} {NaN 1591618035}]

after calling serie, totalsSerie = NormalizeTwo(dataMap, serie, totalsSerie) these become:

metrictank_1    | serie interval=60, 3 points: [{NaN 1591617900} {NaN 1591617960} {NaN 1591618020}]
metrictank_1    | totalsSerie interval=60, 2 points: [{NaN 1591617960} {NaN 1591618020}]

@Dieterbe
Copy link
Contributor Author

this seems very similar to #1811

@Dieterbe
Copy link
Contributor Author

Dieterbe commented Jun 10, 2020

note that this query doesn't work consistently in graphite.
not sure why it's intermittent, perhaps a similar bug as in MT.
note that the series we query is a graphite requests metric which is null until we do a query, but this doesn't seem to be related. I have been able to produce and not produce it, when the series had data.

curl -v 'http://localhost:8080/render?target=perSecond(summarize(stats.docker-env.response.200,"1min"),stats.docker-env.response.200)&from=-3min&until=now&format=json&meta=true'
*   Trying ::1:8080...
* Connected to localhost (::1) port 8080 (#0)
> GET /render?target=perSecond(summarize(stats.docker-env.response.200,"1min"),stats.docker-env.response.200)&from=-3min&until=now&format=json&meta=true HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.70.0
> Accept: */*
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 500 Internal Server Error
< Date: Wed, 10 Jun 2020 11:56:17 GMT
< Server: Apache/2.4.18 (Ubuntu)
< Vary: Cookie,Accept-Encoding
< Content-Length: 2108
< X-Graphite-Timing: D=45621 t=1591790177632171
< X-Graphite-Hostname: graphite
< Connection: close
< Content-Type: text/html; charset=utf-8
< 
<body style="background-color: #666666; color: black;">
<center>
<h2 style='font-family: "Arial", sans-serif'>
<p>Graphite encountered an unexpected error while handling your request.</p>
<p>Please contact your site administrator if the problem persists.</p>
</h2>
<br/>
<div style="width: 50%; text-align: center; font-family: monospace; background-color: black; font-weight: bold; color: #ff4422;">

</div>

<div style="width: 70%; text-align: left; background-color: black; color: #44ff22; border: thin solid gray;">
<pre>
Traceback (most recent call last):
  File &quot;/opt/graphite/local/lib/python2.7/site-packages/django/core/handlers/exception.py&quot;, line 41, in inner
    response = get_response(request)
  File &quot;/opt/graphite/local/lib/python2.7/site-packages/django/core/handlers/base.py&quot;, line 187, in _get_response
    response = self.process_exception_by_middleware(e, request)
  File &quot;/opt/graphite/local/lib/python2.7/site-packages/django/core/handlers/base.py&quot;, line 185, in _get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  File &quot;/opt/graphite/webapp/graphite/render/views.py&quot;, line 118, in renderView
    data.extend(evaluateTarget(requestContext, targets))
  File &quot;/opt/graphite/webapp/graphite/render/evaluator.py&quot;, line 28, in evaluateTarget
    result = evaluateTokens(requestContext, target)
  File &quot;/opt/graphite/webapp/graphite/render/evaluator.py&quot;, line 57, in evaluateTokens
    return evaluateTokens(requestContext, tokens.expression, replacements)
  File &quot;/opt/graphite/webapp/graphite/render/evaluator.py&quot;, line 93, in evaluateTokens
    return func(requestContext, *args, **kwargs)
  File &quot;/opt/graphite/webapp/graphite/render/functions.py&quot;, line 2000, in perSecond
    delta, prev = _nonNegativeDelta(val, prev, maxValue)
  File &quot;/opt/graphite/webapp/graphite/render/functions.py&quot;, line 2206, in _nonNegativeDelta
    return maxValue + 1 + val - prev, val
TypeError: can only concatenate list (not &quot;int&quot;) to list

</pre>
</div>

</center>
* Closing connection 0

retrying the same query yields:

curl -v 'http://localhost:8080/render?target=perSecond(summarize(stats.docker-env.response.200,"1min"),stats.docker-env.response.200)&from=-3min&until=now&format=json&meta=true' ; echo
*   Trying ::1:8080...
* Connected to localhost (::1) port 8080 (#0)
> GET /render?target=perSecond(summarize(stats.docker-env.response.200,"1min"),stats.docker-env.response.200)&from=-3min&until=now&format=json&meta=true HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.70.0
> Accept: */*
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< Date: Wed, 10 Jun 2020 11:59:07 GMT
< Server: Apache/2.4.18 (Ubuntu)
< Vary: Accept-Encoding
< Expires: Wed, 10 Jun 2020 11:59:07 GMT
< Cache-Control: no-cache, no-store, must-revalidate, max-age=0
< Content-Length: 298
< X-Graphite-Timing: D=11175 t=1591790347012743
< X-Graphite-Hostname: graphite
< Content-Type: application/json
< 
* Connection #0 to host localhost left intact
[{"datapoints": [[null, 1591790160], [null, 1591790220], [null, 1591790280], [null, 1591790340]], "target": "perSecond(summarize(stats.docker-env.response.200, \"1min\", \"sum\"))", "tags": {"summarize": "1min", "perSecond": 1, "name": "stats.docker-env.response.200", "summarizeFunction": "sum"}}]

on MT it seems to work most of the time:

curl -v 'http://localhost:6060/render?target=perSecond(summarize(stats.docker-env.response.200,"1min"),stats.docker-env.response.200)&from=-3min&until=now&format=json&meta=true'
*   Trying ::1:6060...
* Connected to localhost (::1) port 6060 (#0)
> GET /render?target=perSecond(summarize(stats.docker-env.response.200,"1min"),stats.docker-env.response.200)&from=-3min&until=now&format=json&meta=true HTTP/1.1
> Host: localhost:6060
> User-Agent: curl/7.70.0
> Accept: */*
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< Content-Type: application/json
< Trace-Id: ba05eefe47833ba
< Vary: Origin
< Date: Wed, 10 Jun 2020 11:57:32 GMT
< Transfer-Encoding: chunked
< 
{"version":"v0.1","meta":{"stats":{"executeplan.resolve-series.ms":0,"executeplan.get-targets.ms":0,"executeplan.prepare-series.ms":0,"executeplan.plan-run.ms":0,"executeplan.series-fetch.count":2,"executeplan.points-fetch.count":360,"executeplan.points-return.count":184,"executeplan.cache-miss.count":0,"executeplan.cache-hit-partial.count":0,"executeplan.cache-hit.count":0,"executeplan.chunks-from-tank.count":2,"executeplan.chunks-from-cache.count":0,"executeplan.chunks-from-store.count":0}},"series":[{"target":"perSecond(summarize(stats.docker-env.response.200, \"1min\", \"sum\"))","tags":{"name":"stats.docker-env.response.200","summarize":"1min","summarizeFunction":"sum"},"datapoints":[[null,1591790040],[null,1591790100],[null,1591790160],[null,1591790220]],"meta":[{"schema-name":"default","schema-retentions":"1s:35d:10min:7","archive-read":0,"archive-interval":1,"aggnum-norm":1,"consolidator-normfetch":"AverageConsolidator","aggnum-rc":0,"consolidator-rc":"NoneConsolidator","count":2}]},{"target":"perSecond(stats.docker-env.response.200)","tags":{"name":"stats.docker-env.response.200"},"datapoints":[[null,1591790073],[null,1591790074],[null,1591790075],[null,1591790076],[null,1591790077],[null,1591790078],[null,1591790079],[null,1591790080],[null,1591790081],[null,1591790082],[null,1591790083],[null,1591790084],[null,1591790085],[null,1591790086],[null,1591790087],[null,1591790088],[null,1591790089],[null,1591790090],[null,1591790091],[null,1591790092],[null,1591790093],[null,1591790094],[null,1591790095],[null,1591790096],[null,1591790097],[null,1591790098],[null,1591790099],[null,1591790100],[null,1591790101],[null,1591790102],[null,1591790103],[null,1591790104],[null,1591790105],[null,1591790106],[null,1591790107],[null,1591790108],[null,1591790109],[null,1591790110],[null,1591790111],[null,1591790112],[null,1591790113],[null,1591790114],[null,1591790115],[null,1591790116],[null,1591790117],[null,1591790118],[null,1591790119],[null,1591790120],[null,1591790121],[null,1591790122],[null,1591790123],[null,1591790124],[null,1591790125],[null,1591790126],[null,1591790127],[null,1591790128],[null,1591790129],[null,1591790130],[null,1591790131],[null,1591790132],[null,1591790133],[null,1591790134],[null,1591790135],[null,1591790136],[null,1591790137],[null,1591790138],[null,1591790139],[null,1591790140],[null,1591790141],[null,1591790142],[null,1591790143],[null,1591790144],[null,1591790145],[null,1591790146],[null,1591790147],[null,1591790148],[null,1591790149],[null,1591790150],[null,1591790151],[null,1591790152],[null,1591790153],[null,1591790154],[null,1591790155],[null,1591790156],[null,1591790157],[null,1591790158],[null,1591790159],[null,1591790160],[null,1591790161],[null,1591790162],[null,1591790163],[null,1591790164],[null,1591790165],[null,1591790166],[null,1591790167],[null,1591790168],[null,1591790169],[null,1591790170],[null,1591790171],[null,1591790172],[null,1591790173],[null,1591790174],[null,1591790175],[null,1591790176],[null,1591790177],[null,1591790178],[null,1591790179],[null,1591790180],[null,1591790181],[null,1591790182],[null,1591790183],[null,1591790184],[null,1591790185],[null,1591790186],[null,1591790187],[null,1591790188],[null,1591790189],[null,1591790190],[null,1591790191],[null,1591790192],[null,1591790193],[null,1591790194],[null,1591790195],[null,1591790196],[null,1591790197],[null,1591790198],[null,1591790199],[null,1591790200],[null,1591790201],[null,1591790202],[null,1591790203],[null,1591790204],[null,1591790205],[null,1591790206],[null,1591790207],[null,1591790208],[null,1591790209],[null,1591790210],[null,1591790211],[null,1591790212],[null,1591790213],[null,1591790214],[null,1591790215],[null,1591790216],[null,1591790217],[null,1591790218],[null,1591790219],[null,1591790220],[null,1591790221],[null,1591790222],[null,1591790223],[null,1591790224],[null,1591790225],[null,1591790226],[null,1591790227],[null,1591790228],[null,1591790229],[null,1591790230],[null,1591790231],[null,1591790232],[null,1591790233],[null,1591790234],[null,1591790235],[null,1591790236],[null,1591790237],[null* Connection #0 to host localhost left intact
,1591790238],[null,1591790239],[null,1591790240],[null,1591790241],[null,1591790242],[null,1591790243],[null,1591790244],[null,1591790245],[null,1591790246],[null,1591790247],[null,1591790248],[null,1591790249],[null,1591790250],[null,1591790251],[null,1591790252]],"meta":[{"schema-name":"default","schema-retentions":"1s:35d:10min:7","archive-read":0,"archive-interval":1,"aggnum-norm":1,"consolidator-normfetch":"AverageConsolidator","aggnum-rc":0,"consolidator-rc":"NoneConsolidator","count":2}]}]}

Dieterbe added a commit that referenced this issue Jun 15, 2020
See #1811 for more details
Before, it was common for output to contain an extraneous point that
lies before 'from' (and wouldn't be rendered by Grafana in graph
panels), which made the output invalid.

This would result in trouble when

* combining such a series with another series
  (#1811)
* or when needing normalization
  (#1845)

This effectively slightly changes the output format, but is more robust.
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant