influxdata / influxdata/influxdb

Execute source panic after some time, panic: runtime error: invalid memory address or nil pointer dereference

Open
#22,992 5 comments 0 reactions 0 assignees View on GitHub
Dominant language
Rust
Stars
31.7k
Forks
3.7k
Avg merge
13h 37m
Merged PRs (30d)
8

Description

__Steps to reproduce:__
Really haven't found any way to reproduce the behavior but I'll try to keep an eye on it and add information as I good around it

1. Use Telegraf with OPC UA plugin for data collection
2. Wait some time

__Expected behavior:__
Most of the time everything is working fine and all the values can be written, retrieved, and such. We're really happy using InfluxDB.

__Actual behavior:__
We stumbled across missing points in our measurements.
A small investigation revealed the following error in the InfluxDB systemd service:

```
Dec 14 10:08:12 chub.localdomain influxd-systemd-start.sh[77435]: ts=2021-12-14T15:08:12.267358Z lvl=info msg="Execute source panic" log_id=0XR0e8O0000 service=storage-reads error="panic: runtime error: invalid memory address or nil pointer dereference" stacktrace="goroutine 64756223 [running]:
runtime/debug.Stack()
/home/circleci/.tools/go/src/runtime/debug/stack.go:24 +0x65
github.com/influxdata/flux/execute.(*executionState).do.func1.1()
/home/circleci/go/pkg/mod/github.com/influxdata/flux@v0.131.0/execute/executor.go:286 +0x205
panic({0x35c9e00, 0x49e7930})
/home/circleci/.tools/go/src/runtime/panic.go:1038 +0x215
github.com/influxdata/influxdb/v2/v1/services/storage.(*Store).measurementFields.func1()
/home/circleci/go/src/github.com/influxdata/influxdb/v1/services/storage/store.go:546 +0x1c
panic({0x35e57c0, 0xc006f52a80})
/home/circleci/.tools/go/src/runtime/panic.go:1038 +0x215
github.com/influxdata/influxdb/v2/v1/services/storage.(*Store).measurementFields(0xc0031cc060, {0x39711d8, 0xc00208a000}, 0xc000f45bd0)
/home/circleci/go/src/github.com/influxdata/influxdb/v1/services/storage/store.go:549 +0x33f
github.com/influxdata/influxdb/v2/v1/services/storage.(*Store).TagValues(0x394bf00, {0x39711d8, 0xc00208a000}, 0xc006f526c0)
/home/circleci/go/src/github.com/influxdata/influxdb/v1/services/storage/store.go:406 +0x390
github.com/influxdata/influxdb/v2/storage/flux.(*tagValuesIterator).Do(0xc001fe7600, 0x61b8b35c)
/home/circleci/go/src/github.com/influxdata/influxdb/storage/flux/reader.go:970 +0x1c6
github.com/influxdata/influxdb/v2/query/stdlib/influxdata/influxdb.(*Source).processTables(0xc0053c4680, {0x39711d8, 0xc00208a000}, {0x3942728, 0xc001fe7600}, 0xc004ca4fe0)
/home/circleci/go/src/github.com/influxdata/influxdb/query/stdlib/influxdata/influxdb/source.go:76 +0xbf
github.com/influxdata/influxdb/v2/query/stdlib/influxdata/influxdb.(*readTagValuesSource).run(0xc0053c4680, {0x39711d8, 0xc00208a000})
/home/circleci/go/src/github.com/influxdata/influxdb/query/stdlib/influxdata/influxdb/source.go:492 +0x114
github.com/influxdata/influxdb/v2/query/stdlib/influxdata/influxdb.(*Source).Run(0xc0053c4680, {0x39711d8, 0xc00208a000})
/home/circleci/go/src/github.com/influxdata/influxdb/query/stdlib/influxdata/influxdb/source.go:56 +0x168
github.com/influxdata/flux/execute.(*executionState).do.func1({0x3972cc0, 0xc0053c4680})
/home/circleci/go/pkg/mod/github.com/influxdata/flux@v0.131.0/execute/executor.go:291 +0x20e
created by github.com/influxdata/flux/execute.(*executionState).do
/home/circleci/go/pkg/mod/github.com/influxdata/flux@v0.131.0/execute/executor.go:261 +0x228
"
```

But it was running with `active` state and hasn't fully crashed. The Data Explorer was fully functional, for example.
Creating a new bucket, letting Telegraf write in the new one and switching back to the old bucket after some minutes allowed Telegraf to write in the first bucket again. The mentioned `Execute source panic` error did not appear.

__Environment info:__

* System info: Run `uname -srm` and copy the output here
* InfluxDB version: Run `influxd version` and copy the output here
* Other relevant environment details: Container runtime, disk info, etc

* `Linux 4.18.0-301.1.el8.x86_64 x86_64`
* `InfluxDB 2.0.9 (git: d1233b7951) build_date: 2021-10-01T21:09:53Z`
* running on bare metal without any Docker or such, enough disk space, using an SSD here, server with a Intel(R) Xeon(R) E-2136 CPU @ 3.30GHz

__Config:__
All default, nothing changed.

__Logs:__
See Actual behavior section.

__Performance:__
Going to execute the following lines next time the bug happens.

```sh
# Commands should be run when the bug is actively happening.
# Note: This command will run for ~30 seconds.
curl -o profiles.tar.gz "http://localhost:8086/debug/pprof/all?cpu=30s"
iostat -xd 1 30 > iostat.txt
# Attach the `profiles.tar.gz` and `iostat.txt` output files.
```

Is there any other way to get a little bit more into the details and trace the bug down? Where could I start?

Contributor guide

Open the contributing guide

Research direction

Start with v1/services/storage/store.go at measurementFields and TagValues, then follow the stack through storage/flux/reader.go and query/stdlib/influxdata/influxdb/source.go. Use the reported InfluxDB 2.0.9 environment and tag-values query path to investigate the nil dereference; done means the path no longer panics and the missing-point behavior has a regression test.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
databases
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
30/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.