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.

Sign up for GitHub

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

Jump to bottom

Recovering from API handler panic: runtime error: index out of range [58] with length 58, goroutine 805 [running] #11487

Closed
arottigni-te opened this issue Sep 8, 2021 · 9 comments
Closed

Recovering from API handler panic: runtime error: index out of range [58] with length 58, goroutine 805 [running] #11487

arottigni-te opened this issue Sep 8, 2021 · 9 comments
Assignees
@vrothberg
Labels
kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments.

Comments

@arottigni-te
Copy link

Is this a BUG REPORT or FEATURE REQUEST? (leave only one on its own line)

/kind bug

Description
I'm creating and removing containers frequently using the podman's REST api. Sometimes creating a container fails with the following error:
Recovering from API handler panic: runtime error: index out of range [58] with length 58, goroutine 805 [running]
This is for podman 3.2.3 on ubuntu 20.04. I haven't tested on RHEL.

Steps to reproduce the issue:

  1. Create a container using the REST api
  2. Start the container
  3. Wait on the container
  4. Remove the container
  5. go to step 1

Describe the results you received:
If you're unlucky you're gonna get:

"Recovering from API handler panic: runtime error: index out of range [58] with length 58, goroutine 805 [running]:
github.com/containers/podman/pkg/api/server.(*APIServer).APIHandler.func1.1(0x5558180acea0, 0xc000a22b60)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/api/server/handler_api.go:24 +0xba
panic(0x555817f50400, 0xc0007caae0)
  /usr/lib/go-1.15/src/runtime/panic.go:969 +0x175
github.com/containers/podman/vendor/github.com/containers/storage.(*layerStore).Layers(0xc00057d110, 0x0, 0x0, 0x0, 0x0, 0x555817d2d360)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/layers.go:319 +0x185
github.com/containers/podman/vendor/github.com/containers/storage.(*store).Layers(0xc0002ae160, 0x0, 0x0, 0x0, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/store.go:3047 +0xd0
github.com/containers/podman/vendor/github.com/containers/common/libimage.(*Runtime).layerTree(0xc00000c3c0, 0x5558180c99c0, 0xc000ae8720, 0xc00000c3c0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/common/libimage/layer_tree.go:76 +0x51
github.com/containers/podman/vendor/github.com/containers/common/libimage.(*Image).Parent(0xc000a86500, 0x5558180b8620, 0xc000a98450, 0xc0004f8b40, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/common/libimage/image.go:174 +0x34
github.com/containers/podman/vendor/github.com/containers/common/libimage.(*Image).Inspect(0xc000a86500, 0x5558180b8620, 0xc000a98450, 0xc000b7d300, 0xc000a86500, 0xc00085c700, 0x31)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/common/libimage/inspect.go:79 +0x25c
github.com/containers/podman/pkg/specgen/generate.CompleteSpec(0x5558180b8620, 0xc000a98450, 0xc000029c00, 0xc000a05800, 0x0, 0x5558165da9d0, 0xc0003b4c40, 0x10, 0x10)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/specgen/generate/container.go:33 +0x13a6
github.com/containers/podman/pkg/api/handlers/libpod.CreateContainer(0x5558180acea0, 0xc000a22b60, 0xc0005f8b00)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/api/handlers/libpod/containers_create.go:25 +0x1a5
github.com/containers/podman/pkg/api/server.(*APIServer).APIHandler.func1.2(0x5558180acea0, 0xc000a22b60, 0xc0005f8a00)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/api/server/handler_api.go:66 +0xfc4
github.com/containers/podman/pkg/api/server.(*APIServer).APIHandler.func1(0x5558180acea0, 0xc000a22b60, 0xc0005f8a00)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/api/server/handler_api.go:69 +0xa8
net/http.HandlerFunc.ServeHTTP(0xc0005866c0, 0x5558180acea0, 0xc000a22b60, 0xc0005f8a00)
  /usr/lib/go-1.15/src/net/http/server.go:2042 +0x46
github.com/containers/podman/vendor/github.com/gorilla/mux.(*Router).ServeHTTP(0xc0005723c0, 0x5558180acea0, 0xc000a22b60, 0xc0005e8500)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/gorilla/mux/mux.go:210 +0xd3
net/http.serverHandler.ServeHTTP(0xc000128900, 0x5558180acea0, 0xc000a22b60, 0xc0005e8500)
  /usr/lib/go-1.15/src/net/http/server.go:2843 +0xa5
net/http.(*conn).serve(0xc00058a820, 0x5558180b8560, 0xc0009115c0)
  /usr/lib/go-1.15/src/net/http/server.go:1925 +0x8ad
created by net/http.(*Server).Serve
  /usr/lib/go-1.15/src/net/http/server.go:2969 +0x36c

goroutine 1 [chan receive, 8 minutes]:
github.com/containers/podman/pkg/api/server.(*APIServer).Serve(0xc000128900, 0x0, 0xc000525c40)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/api/server/server.go:227 +0x174
github.com/containers/podman/cmd/podman/system.restService(0x7ffcb0f2eeae, 0x21, 0x0, 0x555818c05d00, 0xc000238300, 0x555818c950a0, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/cmd/podman/system/service_abi.go:85 +0x247
github.com/containers/podman/cmd/podman/system.service(0x555818c05d00, 0xc00022c380, 0x1, 0x7, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/cmd/podman/system/service.go:98 +0x1b1
github.com/containers/podman/vendor/github.com/spf13/cobra.(*Command).execute(0x555818c05d00, 0xc00003c0d0, 0x7, 0x7, 0x555818c05d00, 0xc00003c0d0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/spf13/cobra/command.go:852 +0x47c
github.com/containers/podman/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0x555818c09680, 0xc000040058, 0x555817e17d00, 0x555818cc9760)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/spf13/cobra/command.go:960 +0x375
github.com/containers/podman/vendor/github.com/spf13/cobra.(*Command).Execute(...)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/spf13/cobra/command.go:897
github.com/containers/podman/vendor/github.com/spf13/cobra.(*Command).ExecuteContext(...)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/spf13/cobra/command.go:890
main.Execute()
  /usr/src/packages/BUILD/src/github.com/containers/podman/cmd/podman/root.go:90 +0xee
main.main()
  /usr/src/packages/BUILD/src/github.com/containers/podman/cmd/podman/main.go:38 +0x94

goroutine 10 [chan receive]:
github.com/containers/podman/vendor/k8s.io/klog/v2.(*loggingT).flushDaemon(0x555818c953a0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/k8s.io/klog/v2/klog.go:1164 +0x8d
created by github.com/containers/podman/vendor/k8s.io/klog/v2.init.0
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/k8s.io/klog/v2/klog.go:418 +0xdf

goroutine 12 [syscall, 8 minutes]:
os/signal.signal_recv(0x0)
  /usr/lib/go-1.15/src/runtime/sigqueue.go:147 +0x9e
os/signal.loop()
  /usr/lib/go-1.15/src/os/signal/signal_unix.go:23 +0x25
created by os/signal.Notify.func1.1
  /usr/lib/go-1.15/src/os/signal/signal.go:150 +0x46

goroutine 18 [select, 8 minutes]:
github.com/containers/podman/libpod/shutdown.Start.func1()
  /usr/src/packages/BUILD/src/github.com/containers/podman/libpod/shutdown/handler.go:45 +0xcd
created by github.com/containers/podman/libpod/shutdown.Start
  /usr/src/packages/BUILD/src/github.com/containers/podman/libpod/shutdown/handler.go:44 +0x116

goroutine 20 [sleep]:
time.Sleep(0x5f5e100)
  /usr/lib/go-1.15/src/runtime/time.go:188 +0xbf
github.com/containers/podman/libpod.(*Runtime).libimageEvents.func2(0xc000029c00, 0x555818048788)
  /usr/src/packages/BUILD/src/github.com/containers/podman/libpod/runtime.go:740 +0x292
created by github.com/containers/podman/libpod.(*Runtime).libimageEvents
  /usr/src/packages/BUILD/src/github.com/containers/podman/libpod/runtime.go:715 +0x4d

goroutine 1106 [chan receive, locked to thread]:
github.com/containers/podman/vendor/github.com/containers/storage.(*store).DeleteContainer(0xc0002ae160, 0xc000762540, 0x40, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/store.go:2514 +0x785
github.com/containers/podman/libpod.(*storageService).DeleteContainer(0xc000331240, 0xc000a89380, 0x40, 0x0, 0x8f)
  /usr/src/packages/BUILD/src/github.com/containers/podman/libpod/storage.go:185 +0xa9
github.com/containers/podman/libpod.(*Container).teardownStorage(0xc00058a280, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/libpod/container_internal.go:539 +0x18f
github.com/containers/podman/libpod.(*Runtime).removeContainer(0xc000029c00, 0x5558180b8620, 0xc000828f90, 0xc00058a280, 0x7f231c000001, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/libpod/runtime_ctr.go:625 +0x2bd
github.com/containers/podman/libpod.(*Runtime).RemoveContainer(0xc000029c00, 0x5558180b8620, 0xc000828f90, 0xc00058a280, 0x1, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/libpod/runtime_ctr.go:475 +0xbe
github.com/containers/podman/pkg/domain/infra/abi.(*ContainerEngine).ContainerRm.func1(0xc00058a280, 0x4, 0xc00043b740)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/domain/infra/abi/containers.go:321 +0x85
github.com/containers/podman/pkg/parallel/ctr.ContainerOp.func1(0xc00050c640, 0x5558180b8620)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/parallel/ctr/ctr.go:28 +0x30
github.com/containers/podman/pkg/parallel.Enqueue.func1(0xc000516240, 0x5558180b8620, 0xc000828f90, 0xc000800d40)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/parallel/parallel.go:66 +0x198
created by github.com/containers/podman/pkg/parallel.Enqueue
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/parallel/parallel.go:55 +0x78

goroutine 67 [IO wait]:
internal/poll.runtime_pollWait(0x7f231c5d2038, 0x72, 0x0)
  /usr/lib/go-1.15/src/runtime/netpoll.go:220 +0x65
internal/poll.(*pollDesc).wait(0xc000298598, 0x72, 0x0, 0x0, 0x5558179df333)
  /usr/lib/go-1.15/src/internal/poll/fd_poll_runtime.go:87 +0x47
internal/poll.(*pollDesc).waitRead(...)
  /usr/lib/go-1.15/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc000298580, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
  /usr/lib/go-1.15/src/internal/poll/fd_unix.go:394 +0x1fc
net.(*netFD).accept(0xc000298580, 0x555818c479c8, 0x555817d85780, 0x555818c479c0)
  /usr/lib/go-1.15/src/net/fd_unix.go:172 +0x45
net.(*UnixListener).accept(0xc0002ef890, 0xc00006be20, 0x5558179ab6ea, 0xc00056f9b0)
  /usr/lib/go-1.15/src/net/unixsock_posix.go:162 +0x34
net.(*UnixListener).Accept(0xc0002ef890, 0xc00006be70, 0x18, 0xc0002fb380, 0x55581692eb8c)
  /usr/lib/go-1.15/src/net/unixsock.go:260 +0x66
net/http.(*Server).Serve(0xc000128900, 0x5558180acc20, 0xc0002ef890, 0x0, 0x0)
  /usr/lib/go-1.15/src/net/http/server.go:2937 +0x266
github.com/containers/podman/pkg/api/server.(*APIServer).Serve.func4(0xc000128900, 0xc00069ec00)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/api/server/server.go:219 +0x49
created by github.com/containers/podman/pkg/api/server.(*APIServer).Serve
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/api/server/server.go:218 +0x154

goroutine 33 [chan receive, 8 minutes]:
github.com/containers/podman/pkg/domain/infra.StartWatcher.func1(0xc00033c240, 0xc000029c00)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/domain/infra/runtime_libpod.go:369 +0x7c
created by github.com/containers/podman/pkg/domain/infra.StartWatcher
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/domain/infra/runtime_libpod.go:365 +0xb7

goroutine 826 [chan receive]:
github.com/containers/podman/pkg/parallel/ctr.ContainerOp(0x5558180b8620, 0xc000828f90, 0xc0006de248, 0x1, 0x1, 0xc000829920, 0x1, 0x1, 0xc000331e40)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/parallel/ctr/ctr.go:35 +0x2e5
github.com/containers/podman/pkg/domain/infra/abi.(*ContainerEngine).ContainerRm(0xc0006de198, 0x5558180b8620, 0xc000828f90, 0xc0009b3680, 0x1, 0x1, 0x100, 0x10, 0x555817d93c40, 0x14, ...)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/domain/infra/abi/containers.go:320 +0x8e5
github.com/containers/podman/pkg/api/handlers/compat.RemoveContainer(0x5558180acea0, 0xc000a222a0, 0xc0006d6500)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/api/handlers/compat/containers.go:71 +0x2c5
github.com/containers/podman/pkg/api/server.(*APIServer).APIHandler.func1.2(0x5558180acea0, 0xc000a222a0, 0xc0006d6400)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/api/server/handler_api.go:66 +0xfc4
github.com/containers/podman/pkg/api/server.(*APIServer).APIHandler.func1(0x5558180acea0, 0xc000a222a0, 0xc0006d6400)
  /usr/src/packages/BUILD/src/github.com/containers/podman/pkg/api/server/handler_api.go:69 +0xa8
net/http.HandlerFunc.ServeHTTP(0xc000586b40, 0x5558180acea0, 0xc000a222a0, 0xc0006d6400)
  /usr/lib/go-1.15/src/net/http/server.go:2042 +0x46
github.com/containers/podman/vendor/github.com/gorilla/mux.(*Router).ServeHTTP(0xc0005723c0, 0x5558180acea0, 0xc000a222a0, 0xc0006d6200)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/gorilla/mux/mux.go:210 +0xd3
net/http.serverHandler.ServeHTTP(0xc000128900, 0x5558180acea0, 0xc000a222a0, 0xc0006d6200)
  /usr/lib/go-1.15/src/net/http/server.go:2843 +0xa5
net/http.(*conn).serve(0xc0006c6780, 0x5558180b8560, 0xc000c0f680)
  /usr/lib/go-1.15/src/net/http/server.go:1925 +0x8ad
created by net/http.(*Server).Serve
  /usr/lib/go-1.15/src/net/http/server.go:2969 +0x36c

goroutine 1107 [IO wait]:
internal/poll.runtime_pollWait(0x7f231c5d1f58, 0x72, 0x55581807e220)
  /usr/lib/go-1.15/src/runtime/netpoll.go:220 +0x65
internal/poll.(*pollDesc).wait(0xc000a96c18, 0x72, 0xc000819400, 0x1, 0x1)
  /usr/lib/go-1.15/src/internal/poll/fd_poll_runtime.go:87 +0x47
internal/poll.(*pollDesc).waitRead(...)
  /usr/lib/go-1.15/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000a96c00, 0xc0008194b1, 0x1, 0x1, 0x0, 0x0, 0x0)
  /usr/lib/go-1.15/src/internal/poll/fd_unix.go:159 +0x1b1
net.(*netFD).Read(0xc000a96c00, 0xc0008194b1, 0x1, 0x1, 0x1, 0x0, 0x0)
  /usr/lib/go-1.15/src/net/fd_posix.go:55 +0x51
net.(*conn).Read(0xc0006deb10, 0xc0008194b1, 0x1, 0x1, 0x0, 0x0, 0x0)
  /usr/lib/go-1.15/src/net/net.go:182 +0x90
net/http.(*connReader).backgroundRead(0xc0008194a0)
  /usr/lib/go-1.15/src/net/http/server.go:690 +0x5a
created by net/http.(*connReader).startBackgroundRead
  /usr/lib/go-1.15/src/net/http/server.go:686 +0xd5

goroutine 1112 [semacquire]:
sync.runtime_Semacquire(0xc000366818)
  /usr/lib/go-1.15/src/runtime/sema.go:56 +0x45
sync.(*WaitGroup).Wait(0xc000366810)
  /usr/lib/go-1.15/src/sync/waitgroup.go:130 +0x66
github.com/containers/podman/vendor/github.com/containers/storage.(*store).DeleteContainer.func5(0xc000366810, 0xc0005163c0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/store.go:2507 +0x2d
created by github.com/containers/podman/vendor/github.com/containers/storage.(*store).DeleteContainer
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/store.go:2506 +0x72b

goroutine 1108 [runnable]:
syscall.Syscall(0x4b, 0xf, 0x0, 0x0, 0x0, 0x0, 0x0)
  /usr/lib/go-1.15/src/syscall/asm_linux_amd64.s:18 +0x5
github.com/containers/podman/vendor/golang.org/x/sys/unix.Fdatasync(0xf, 0x0, 0xc000a99b00)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/golang.org/x/sys/unix/zsyscall_linux.go:667 +0x45
github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils.fdatasync(0xc0006de968, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils/fswriters_linux.go:10 +0x45
github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils.(*atomicFileWriter).Close(0xc000a99b00, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils/fswriters.go:97 +0x209
github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils.AtomicWriteFile(0xc00095b950, 0x43, 0xc0008a8a80, 0x65b5, 0x65b5, 0x180, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils/fswriters.go:68 +0xd9
github.com/containers/podman/vendor/github.com/containers/storage.(*layerStore).saveLayers(0xc00057d110, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/layers.go:487 +0x218
github.com/containers/podman/vendor/github.com/containers/storage.(*layerStore).Save(0xc00057d110, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/layers.go:465 +0x9c
github.com/containers/podman/vendor/github.com/containers/storage.(*layerStore).Delete(0xc00057d110, 0xc0005efbc0, 0x40, 0xc00050ca50, 0x7f231c3e8b78)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/layers.go:1249 +0x265
github.com/containers/podman/vendor/github.com/containers/storage.(*store).DeleteContainer.func1(0xc0005163c0, 0x5558180ddc60, 0xc00057d110, 0xc00057d860, 0xc000366810)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/store.go:2481 +0x4e
created by github.com/containers/podman/vendor/github.com/containers/storage.(*store).DeleteContainer
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/store.go:2480 +0x97b

goroutine 1110 [runnable]:
syscall.Syscall(0x107, 0x12, 0xc000234760, 0x200, 0x0, 0x200, 0x0)
  /usr/lib/go-1.15/src/syscall/asm_linux_amd64.s:18 +0x5
internal/syscall/unix.Unlinkat(0x12, 0xc000234360, 0x8, 0x200, 0x0, 0x0)
  /usr/lib/go-1.15/src/internal/syscall/unix/at.go:21 +0x8f
os.removeAllFrom(0xc0006de9d0, 0xc000234360, 0x8, 0x1, 0x400)
  /usr/lib/go-1.15/src/os/removeall_at.go:154 +0x3f8
os.removeAllFrom(0xc0006de9c0, 0xc000bd8dbc, 0x40, 0xc00004a100, 0xc0006de900)
  /usr/lib/go-1.15/src/os/removeall_at.go:121 +0x5e5
os.removeAll(0xc000bd8d80, 0x7c, 0x0, 0x0)
  /usr/lib/go-1.15/src/os/removeall_at.go:48 +0x2b5
os.RemoveAll(...)
  /usr/lib/go-1.15/src/os/path.go:67
github.com/containers/podman/vendor/github.com/containers/storage.(*store).DeleteContainer.func3(0xc0005163c0, 0xc000bd8d80, 0x7c, 0xc000366810)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/store.go:2495 +0x37
created by github.com/containers/podman/vendor/github.com/containers/storage.(*store).DeleteContainer
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/store.go:2494 +0x5e5

goroutine 1089 [IO wait]:
internal/poll.runtime_pollWait(0x7f231c5d22d8, 0x72, 0x55581807e220)
  /usr/lib/go-1.15/src/runtime/netpoll.go:220 +0x65
internal/poll.(*pollDesc).wait(0xc000913218, 0x72, 0xc0003a6e00, 0x1, 0x1)
  /usr/lib/go-1.15/src/internal/poll/fd_poll_runtime.go:87 +0x47
internal/poll.(*pollDesc).waitRead(...)
  /usr/lib/go-1.15/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000913200, 0xc0003a6eb1, 0x1, 0x1, 0x0, 0x0, 0x0)
  /usr/lib/go-1.15/src/internal/poll/fd_unix.go:159 +0x1b1
net.(*netFD).Read(0xc000913200, 0xc0003a6eb1, 0x1, 0x1, 0xc000c0f718, 0xc000b6c768, 0x55581665197e)
  /usr/lib/go-1.15/src/net/fd_posix.go:55 +0x51
net.(*conn).Read(0xc000011160, 0xc0003a6eb1, 0x1, 0x1, 0x0, 0x0, 0x0)
  /usr/lib/go-1.15/src/net/net.go:182 +0x90
net/http.(*connReader).backgroundRead(0xc0003a6ea0)
  /usr/lib/go-1.15/src/net/http/server.go:690 +0x5a
created by net/http.(*connReader).startBackgroundRead
  /usr/lib/go-1.15/src/net/http/server.go:686 +0xd5

goroutine 1109 [runnable]:
syscall.Syscall(0x4b, 0x10, 0x0, 0x0, 0x0, 0x0, 0x0)
  /usr/lib/go-1.15/src/syscall/asm_linux_amd64.s:18 +0x5
github.com/containers/podman/vendor/golang.org/x/sys/unix.Fdatasync(0x10, 0x0, 0xc000a99e00)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/golang.org/x/sys/unix/zsyscall_linux.go:667 +0x45
github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils.fdatasync(0xc0006de9a8, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils/fswriters_linux.go:10 +0x45
github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils.(*atomicFileWriter).Close(0xc000a99e00, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils/fswriters.go:97 +0x209
github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils.AtomicWriteFile(0xc00095b9a0, 0x4b, 0xc0005c2480, 0x221, 0x221, 0x180, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/pkg/ioutils/fswriters.go:68 +0xd9
github.com/containers/podman/vendor/github.com/containers/storage.(*containerStore).Save(0xc000340720, 0x0, 0x0)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/containers.go:239 +0x1ef
github.com/containers/podman/vendor/github.com/containers/storage.(*containerStore).Delete(0xc000340720, 0xc000762540, 0x40, 0x55581660d6f8, 0x55581804d008)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/containers.go:419 +0x285
github.com/containers/podman/vendor/github.com/containers/storage.(*store).DeleteContainer.func2(0xc0005163c0, 0x5558180da440, 0xc000340720, 0xc000762540, 0x40, 0xc000366810)
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/store.go:2487 +0x4b
created by github.com/containers/podman/vendor/github.com/containers/storage.(*store).DeleteContainer
  /usr/src/packages/BUILD/src/github.com/containers/podman/vendor/github.com/containers/storage/store.go:2486 +0x488
"

Describe the results you expected:
The container should be created successfully.

Additional information you deem important (e.g. issue happens only occasionally):
The issue only happens occasionally and I couldn't find a way to reproduce it reliably.
Output of podman version:

Version:      3.2.3
API Version:  3.2.3
Go Version:   go1.15.2
Built:        Thu Jan  1 00:00:00 1970
OS/Arch:      linux/amd64

Output of podman info --debug:

host:
  arch: amd64
  buildahVersion: 1.21.3
  cgroupControllers: []
  cgroupManager: cgroupfs
  cgroupVersion: v1
  conmon:
    package: 'conmon: /usr/libexec/podman/conmon'
    path: /usr/libexec/podman/conmon
    version: 'conmon version 2.0.27, commit: '
  cpus: 2
  distribution:
    distribution: ubuntu
    version: "20.04"
  eventLogger: journald
  hostname: vps12-nrt.stg.v6.ag1.thousandeyes.com
  idMappings:
    gidmap:
    - container_id: 0
      host_id: 1006
      size: 1
    - container_id: 1
      host_id: 427680
      size: 65536
    uidmap:
    - container_id: 0
      host_id: 1005
      size: 1
    - container_id: 1
      host_id: 427680
      size: 65536
  kernel: 5.4.0-72-generic
  linkmode: dynamic
  memFree: 237260800
  memTotal: 4127285248
  ociRuntime:
    name: crun
    package: 'crun: /usr/bin/crun'
    path: /usr/bin/crun
    version: |-
      crun version 0.20.1.5-925d-dirty
      commit: 0d42f1109fd73548f44b01b3e84d04a279e99d2e
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +CRIU +YAJL
  os: linux
  remoteSocket:
    path: /run/user/1005/podman/podman.sock
  security:
    apparmorEnabled: false
    capabilities: CAP_CHOWN,CAP_DAC_OVERRIDE,CAP_FOWNER,CAP_FSETID,CAP_KILL,CAP_NET_BIND_SERVICE,CAP_SETFCAP,CAP_SETGID,CAP_SETPCAP,CAP_SETUID,CAP_SYS_CHROOT
    rootless: true
    seccompEnabled: true
    seccompProfilePath: /usr/share/containers/seccomp.json
    selinuxEnabled: false
  serviceIsRemote: false
  slirp4netns:
    executable: /usr/bin/slirp4netns
    package: 'slirp4netns: /usr/bin/slirp4netns'
    version: |-
      slirp4netns version 1.1.8
      commit: unknown
      libslirp: 4.3.1-git
      SLIRP_CONFIG_VERSION_MAX: 3
      libseccomp: 2.4.3
  swapFree: 486621184
  swapTotal: 536866816
  uptime: 1844h 12m 33.02s (Approximately 76.83 days)
registries:
  search:
  - docker.io
  - quay.io
store:
  configFile: /home/arottigni/.config/containers/storage.conf
  containerStore:
    number: 0
    paused: 0
    running: 0
    stopped: 0
  graphDriverName: overlay
  graphOptions:
    overlay.mount_program:
      Executable: /usr/bin/fuse-overlayfs
      Package: 'fuse-overlayfs: /usr/bin/fuse-overlayfs'
      Version: |-
        fusermount3 version: 3.9.0
        fuse-overlayfs: version 0.7.6
        FUSE library version 3.9.0
        using FUSE kernel interface version 7.31
  graphRoot: /home/arottigni/.local/share/containers/storage
  graphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "false"
    Supports d_type: "true"
    Using metacopy: "false"
  imageStore:
    number: 0
  runRoot: /run/user/1005/containers
  volumePath: /home/arottigni/.local/share/containers/storage/volumes
version:
  APIVersion: 3.2.3
  Built: 0
  BuiltTime: Thu Jan  1 00:00:00 1970
  GitCommit: ""
  GoVersion: go1.15.2
  OsArch: linux/amd64
  Version: 3.2.3

Package info (e.g. output of rpm -q podman or apt list podman):

Listing... Done
podman/unknown,now 100:3.2.3-1 amd64 [installed,automatic]
podman/unknown 100:3.2.3-1 arm64
podman/unknown 100:3.2.3-1 armhf
podman/unknown 100:3.2.3-1 s390x

Have you tested with the latest version of Podman and have you checked the Podman Troubleshooting Guide? (https://github.com/containers/podman/blob/master/troubleshooting.md)

Yes

Additional environment details (AWS, VirtualBox, physical, etc.):
vps on aws
@openshift-ci openshift-ci bot added the kind/bug Categorizes issue or PR as related to a bug. label Sep 8, 2021
@mheon
Copy link
Member

mheon commented Sep 8, 2021

@vrothberg PTAL. This does go down into c/storage, though, so I'll tag @nalind as well.

@vrothberg
Copy link
Member

I have never seen that happening. The layer store is lock-protected.

@arottigni-te, can you share an exact reproducer (i.e., the exact commands) if possible?

@nalind
Copy link
Member

nalind commented Sep 9, 2021

At the point where store.Layers() calls lstore.Layers() (store.go:3047 in podman 3.2.3 corresponds to store.go:3060 in the containers/storage main branch), the lock is not held.

@vrothberg
Copy link
Member

At the point where store.Layers() calls lstore.Layers() (store.go:3047 in podman 3.2.3 corresponds to store.go:3060 in the containers/storage main branch), the lock is not held.

Ouch ... sounds like it should be held?

@nalind
Copy link
Member

nalind commented Sep 9, 2021

Yes, we should probably be acquiring a read lock on the store before reading its layers list.

vrothberg added a commit to vrothberg/storage that referenced this issue Sep 9, 2021
@vrothberg
(*Store)Layer(): fix race when loading layers
5902e59 
Make sure that the layer store is locked when loading the layers.

Reported-in: github.com/containers/podman/issues/11487
Signed-off-by: Valentin Rothberg <rothberg@redhat.com>
@vrothberg vrothberg mentioned this issue Sep 9, 2021
Merged
vrothberg added a commit to vrothberg/storage that referenced this issue Sep 9, 2021
@vrothberg
(*Store)Layer(): fix race when loading layers
6f10616 
Make sure that the layer store is locked when loading the layers.

Reported-in: github.com/containers/podman/issues/11487
Signed-off-by: Valentin Rothberg <rothberg@redhat.com>
@vrothberg vrothberg self-assigned this Sep 9, 2021
@vrothberg
Copy link
Member

The fix merged into c/storage (containers/storage#1014) and will make it into Podman 3.4.
@rhatdan @TomSweeneyRedHat time to start vendor dancing? Feel free to ping me today; I can spare some cycles before PTO.

@arottigni-te
Copy link
Author

arottigni-te commented Sep 10, 2021 •
edited

thanks :)
Do you when 3.4 will become the stable version?

@manderson-te
Copy link

Any chance this could make it into Podman 3.3? :)

@vrothberg
Copy link
Member

Any chance this could make it into Podman 3.3? :)

Not upstream. In case you're using an enterprise Linux (e.g., RHEL or SLES), please open a bug there to trigger request backports.

@github-actions github-actions bot added the locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. label Sep 21, 2023
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Sep 21, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@vrothberg vrothberg

Labels
kind/bug Categorizes issue or PR as related to a bug. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@nalind @mheon @vrothberg @arottigni-te @manderson-te