Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fatal error: concurrent map iteration and map write #2569

Closed
aminjam opened this issue Aug 28, 2020 · 1 comment · Fixed by #2570
Closed

fatal error: concurrent map iteration and map write #2569

aminjam opened this issue Aug 28, 2020 · 1 comment · Fixed by #2570

Comments

@aminjam
Copy link
Contributor

aminjam commented Aug 28, 2020

Describe the bug
We are running promtail with the stdin option and we are running into a condition that causes the above panic. This might be related to #2456, but we made sure that we are running the latest version with that fix (1.6.1).

To Reproduce
Steps to reproduce the behavior:

  1. Create a test log file and config.yml
mkdir -p /tmp/input-logs
printf '{"timestamp":"2020-08-25T13:58:11.123635073Z","level":"info","source":"this-source","message":"hello"}\n%.0s' {1..3000} > /tmp/input-logs/my.log

cat << EOF > /tmp/input-logs/config.yml
server:
  disable: true

positions:
  filename: /tmp/positions.yaml

clients:
  - url: http://loki:3100/loki/api/v1/push

scrape_configs:
- job_name: system
  pipeline_stages:
  - json:
      expressions:
        source:
        message:
        timestamp:
  - labels:
      source:
      message:
  - timestamp:
      source: timestamp
      format: RFC3339Nano
  static_configs:
  - targets:
      - localhost
    labels:
      job: "myjob"
EOF
  1. Apply the following patch to this repo
diff --git a/production/docker-compose.yaml b/production/docker-compose.yaml
index b045739d..456a2ea8 100644
--- a/production/docker-compose.yaml
+++ b/production/docker-compose.yaml
@@ -5,18 +5,18 @@ networks:
 
 services:
   loki:
-    image: grafana/loki:1.6.0
+    image: grafana/loki:1.6.1
     ports:
       - "3100:3100"
-    command: -config.file=/etc/loki/local-config.yaml
+    command: [ "-config.file=/etc/loki/local-config.yaml"]
     networks:
       - loki
 
   promtail:
-    image: grafana/promtail:1.6.0
+    image: grafana/promtail:1.6.1
     volumes:
-      - /var/log:/var/log
-    command: -config.file=/etc/promtail/docker-config.yaml
+      - /tmp/input-logs:/var/log
+    command: ["exit 0"]
     networks:
       - loki
  1. docker-compose up -d
  2. docker-compose run promtail -stdin -config.file=/var/log/config.yml -log.level=debug < /tmp/input-logs/my.log
  3. Repeat above step if it doesn't happen in the first try

Expected behavior
I expected not to see the following panic logs.

fatal error: concurrent map iteration and map write

goroutine 256 [running]:
runtime.throw(0x2877cf9, 0x26)
        /usr/local/go/src/runtime/panic.go:1116 +0x72 fp=0xc0008fd9f8 sp=0xc0008fd9c8 pc=0x437fc2
runtime.mapiternext(0xc0008fdb40)
        /usr/local/go/src/runtime/map.go:853 +0x552 fp=0xc0008fda78 sp=0xc0008fd9f8 pc=0x412e62
github.com/prometheus/common/model.LabelSet.String(0xc000929ef0, 0xc0008fdcb2, 0xc000001800)
        /src/loki/vendor/github.com/prometheus/common/model/labelset.go:134 +0xe4 fp=0xc0008fdbb0 sp=0xc0008fda78 pc=0x643754
github.com/grafana/loki/pkg/promtail/client.(*batch).add(0xc0008264e0, 0x0, 0x0, 0xc000929ef0, 0x75e8581, 0xed6d70ff3, 0x0, 0xc000d09ab0, 0x66)
        /src/loki/pkg/promtail/client/batch.go:42 +0x58 fp=0xc0008fdc50 sp=0xc0008fdbb0 pc=0xc7d2a8
github.com/grafana/loki/pkg/promtail/client.(*client).run(0xc0005d9c20)
        /src/loki/pkg/promtail/client/client.go:201 +0x595 fp=0xc0008fdfd8 sp=0xc0008fdc50 pc=0xc7e7d5
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1373 +0x1 fp=0xc0008fdfe0 sp=0xc0008fdfd8 pc=0x46afa1
created by github.com/grafana/loki/pkg/promtail/client.New
        /src/loki/pkg/promtail/client/client.go:147 +0x411

goroutine 1 [chan receive]:
github.com/grafana/loki/pkg/promtail/server.(*noopServer).Run(0xc0009317a0, 0x2287040, 0xc00093e001)
        /src/loki/pkg/promtail/server/server.go:260 +0xd2
github.com/grafana/loki/pkg/promtail.(*Promtail).Run(0xc000139f40, 0xc00092cbc0, 0x4)
        /src/loki/pkg/promtail/promtail.go:98 +0x9c
main.main()
        /src/loki/cmd/promtail/main.go:111 +0x51c

goroutine 19 [chan receive]:
k8s.io/klog.(*loggingT).flushDaemon(0x42b1e40)
        /src/loki/vendor/k8s.io/klog/klog.go:1010 +0x8b
created by k8s.io/klog.init.0
        /src/loki/vendor/k8s.io/klog/klog.go:411 +0xd6

goroutine 26 [select]:
go.opencensus.io/stats/view.(*worker).start(0xc00009e2d0)
        /src/loki/vendor/go.opencensus.io/stats/view/worker.go:154 +0x100
created by go.opencensus.io/stats/view.init.0
        /src/loki/vendor/go.opencensus.io/stats/view/worker.go:32 +0x57

goroutine 27 [chan receive]:
k8s.io/klog/v2.(*loggingT).flushDaemon(0x42b1f20)
        /src/loki/vendor/k8s.io/klog/v2/klog.go:1107 +0x8b
created by k8s.io/klog/v2.init.0
        /src/loki/vendor/k8s.io/klog/v2/klog.go:416 +0xd6

goroutine 76 [chan receive]:
go.etcd.io/etcd/pkg/logutil.(*MergeLogger).outputLoop(0xc0000a52a0)
        /src/loki/vendor/go.etcd.io/etcd/pkg/logutil/merge_logger.go:173 +0x3a5
created by go.etcd.io/etcd/pkg/logutil.NewMergeLogger
        /src/loki/vendor/go.etcd.io/etcd/pkg/logutil/merge_logger.go:91 +0x80

goroutine 141 [chan receive]:
go.etcd.io/etcd/pkg/logutil.(*MergeLogger).outputLoop(0xc0002b3fc0)
        /src/loki/vendor/go.etcd.io/etcd/pkg/logutil/merge_logger.go:173 +0x3a5
created by go.etcd.io/etcd/pkg/logutil.NewMergeLogger
        /src/loki/vendor/go.etcd.io/etcd/pkg/logutil/merge_logger.go:91 +0x80

goroutine 74 [chan receive]:
go.etcd.io/etcd/pkg/logutil.(*MergeLogger).outputLoop(0xc0000a5140)
        /src/loki/vendor/go.etcd.io/etcd/pkg/logutil/merge_logger.go:173 +0x3a5
created by go.etcd.io/etcd/pkg/logutil.NewMergeLogger
        /src/loki/vendor/go.etcd.io/etcd/pkg/logutil/merge_logger.go:91 +0x80

goroutine 259 [runnable]:
github.com/go-kit/kit/log.WithPrefix(0x2e79740, 0xc000929e90, 0xc000a01d88, 0x2, 0x2, 0x0, 0xc000a3cc90)
        /src/loki/vendor/github.com/go-kit/kit/log/log.go:69 +0x21d
github.com/go-kit/kit/log/level.Debug(...)
        /src/loki/vendor/github.com/go-kit/kit/log/level/level.go:22
github.com/grafana/loki/pkg/logentry/stages.(*Pipeline).Process(0xc00092cb40, 0xc000929ef0, 0xc000a3cba0, 0xc000879d80, 0xc000a420e0)
        /src/loki/pkg/logentry/stages/pipeline.go:107 +0x666
github.com/grafana/loki/pkg/logentry/stages.(*Pipeline).Wrap.func1(0xc000929ef0, 0xbfca662200434621, 0x224cd551, 0x42b0020, 0xc000d09ce0, 0x66, 0xc000434621, 0x35998d5e0e5c7)
        /src/loki/pkg/logentry/stages/pipeline.go:129 +0x10f
github.com/grafana/loki/pkg/promtail/api.EntryHandlerFunc.Handle(0xc000931760, 0xc000929ef0, 0xbfca662200434621, 0x224cd551, 0x42b0020, 0xc000d09ce0, 0x66, 0x0, 0x0)
        /src/loki/pkg/promtail/api/types.go:19 +0x65
github.com/grafana/loki/pkg/promtail/targets/stdin.(*readerTarget).read(0xc000940190)
        /src/loki/pkg/promtail/targets/stdin/stdin_target_manager.go:149 +0x20d
created by github.com/grafana/loki/pkg/promtail/targets/stdin.newReaderTarget
        /src/loki/pkg/promtail/targets/stdin/stdin_target_manager.go:125 +0x421

goroutine 260 [chan receive]:
github.com/grafana/loki/pkg/promtail/targets/stdin.NewStdinTargetManager.func1(0xc000940190, 0x2e79d80, 0xc000139f40)
        /src/loki/pkg/promtail/targets/stdin/stdin_target_manager.go:70 +0x4b
created by github.com/grafana/loki/pkg/promtail/targets/stdin.NewStdinTargetManager
        /src/loki/pkg/promtail/targets/stdin/stdin_target_manager.go:69 +0x1eb

goroutine 261 [syscall]:
os/signal.signal_recv(0x0)
        /usr/local/go/src/runtime/sigqueue.go:147 +0x9c
os/signal.loop()
        /usr/local/go/src/os/signal/signal_unix.go:23 +0x22
created by os/signal.Notify.func1
        /usr/local/go/src/os/signal/signal.go:127 +0x44

goroutine 275 [IO wait]:
internal/poll.runtime_pollWait(0x7f1d741d3e38, 0x72, 0xffffffffffffffff)
        /usr/local/go/src/runtime/netpoll.go:203 +0x55
internal/poll.(*pollDesc).wait(0xc000192198, 0x72, 0x1000, 0x1000, 0xffffffffffffffff)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000192180, 0xc0004e7000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
        /usr/local/go/src/internal/poll/fd_unix.go:169 +0x19b
net.(*netFD).Read(0xc000192180, 0xc0004e7000, 0x1000, 0x1000, 0xc000908b48, 0x408d0c, 0xc000001800)
        /usr/local/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc000133258, 0xc0004e7000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
        /usr/local/go/src/net/net.go:184 +0x8e
net/http.(*persistConn).Read(0xc000899680, 0xc0004e7000, 0x1000, 0x1000, 0xc000908eb0, 0x468240, 0xc000908eb0)
        /usr/local/go/src/net/http/transport.go:1825 +0x75
bufio.(*Reader).fill(0xc0000a8360)
        /usr/local/go/src/bufio/bufio.go:100 +0x103
bufio.(*Reader).Peek(0xc0000a8360, 0x1, 0x2, 0x0, 0x0, 0xc0001c4400, 0x0)
        /usr/local/go/src/bufio/bufio.go:138 +0x4f
net/http.(*persistConn).readLoop(0xc000899680)
        /usr/local/go/src/net/http/transport.go:1978 +0x1a8
created by net/http.(*Transport).dialConn
        /usr/local/go/src/net/http/transport.go:1647 +0xc56

goroutine 276 [select]:
net/http.(*persistConn).writeLoop(0xc000899680)
        /usr/local/go/src/net/http/transport.go:2277 +0x11c
created by net/http.(*Transport).dialConn
        /usr/local/go/src/net/http/transport.go:1648 +0xc7b

Environment:

  • Infrastructure: laptop
  • Deployment tool: docker-compose
  • Promtail/Loki version: 1.6.1
@slim-bean
Copy link
Collaborator

Thanks for the report @aminjam, looks like we missed applying the fix in #2456 to the stdin target manager. I opened a PR to fix this as well.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants