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

(process:10533): OSTree-CRITICAL **: ostree_repo_commit_transaction: assertion 'self->in_transaction == TRUE' failed #1196

Closed
miabbott opened this issue Sep 20, 2017 · 4 comments
Assignees
Labels

Comments

@miabbott
Copy link
Collaborator

In a recent FAHC compose (26.312), installing an etcd system container blew up and the trace seems to point to ostree

# rpm-ostree deploy 26776f17b576a7b6b4e71572850c2c0b643b859ff560036da0eda189e7bd7dbe                                                                                                   
Validating checksum '26776f17b576a7b6b4e71572850c2c0b643b859ff560036da0eda189e7bd7dbe'
2 metadata, 0 content objects fetched; 852 B transferred in 0 seconds
21 metadata, 0 content objects fetched; 8 KiB transferred in 0 seconds

779 metadata, 3193 content objects fetched; 161006 KiB transferred in 10 seconds                                                                                                                                   
Copying /etc changes: 24 modified, 0 removed, 78 added
Transaction complete; bootconfig swap: yes deployment count change: 0
Upgraded:
  bubblewrap 0.1.8.21-8ee3ca50e7c943ba4c99cdd5741857ecad244a60.b5b2429fefc4662c2cfedfb377a22e3480d261f6.fc26 -> 0.1.8.23-e98443065f9abc3c5e2ee52320ace88340a33108.b5b2429fefc4662c2cfedfb377a22e3480d261f6.fc26
  container-storage-setup 0.6.0-1.giteb688d4.fc26 -> 0.7.0-1.git4ca59c5.fc26
  emacs-filesystem 1:25.3-1.fc26 -> 1:25.3-3.fc26
  kernel 4.12.12-300.fc26 -> 4.12.13-300.fc26
  kernel-core 4.12.12-300.fc26 -> 4.12.13-300.fc26
  kernel-modules 4.12.12-300.fc26 -> 4.12.13-300.fc26
  libgcc 7.1.1-3.fc26 -> 7.2.1-2.fc26
  libgomp 7.1.1-3.fc26 -> 7.2.1-2.fc26
  libstdc++ 7.1.1-3.fc26 -> 7.2.1-2.fc26
  ostree 2017.11.6-2f22e5b3599a216f557c9c63eab5494ccd9e2a06.5f781f21a11ef652a476cc05c2923c1e08204b2b.fc26 -> 2017.11.20-e3c3ec5dd91492e82c79223052443d038c60f41c.5f781f21a11ef652a476cc05c2923c1e08204b2b.fc26
  ostree-grub2 2017.11.6-2f22e5b3599a216f557c9c63eab5494ccd9e2a06.5f781f21a11ef652a476cc05c2923c1e08204b2b.fc26 -> 2017.11.20-e3c3ec5dd91492e82c79223052443d038c60f41c.5f781f21a11ef652a476cc05c2923c1e08204b2b.fc26
  ostree-libs 2017.11.6-2f22e5b3599a216f557c9c63eab5494ccd9e2a06.5f781f21a11ef652a476cc05c2923c1e08204b2b.fc26 -> 2017.11.20-e3c3ec5dd91492e82c79223052443d038c60f41c.5f781f21a11ef652a476cc05c2923c1e08204b2b.fc26
  rpm-ostree 2017.8.68-80de17623f522676fd4a91689f6c0c9713580676.90722b718c87a3a86b5cb434a0c1471f094bfa4d.fc26 -> 2017.8.70-25ba196c275b7d6aa513082ba715e7e48f1e57b1.90722b718c87a3a86b5cb434a0c1471f094bfa4d.fc26
  rpm-ostree-libs 2017.8.68-80de17623f522676fd4a91689f6c0c9713580676.90722b718c87a3a86b5cb434a0c1471f094bfa4d.fc26 -> 2017.8.70-25ba196c275b7d6aa513082ba715e7e48f1e57b1.90722b718c87a3a86b5cb434a0c1471f094bfa4d.fc26
  skopeo 0.1.23.34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba.c815f9808f287a484d9a7e85480b36569e0b6a62.fc26 -> 0.1.23.34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba.70546e0d9558b5d2df5727b41aba396e632fada7.fc26
  skopeo-containers 0.1.23.34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba.c815f9808f287a484d9a7e85480b36569e0b6a62.fc26 -> 0.1.23.34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba.70546e0d9558b5d2df5727b41aba396e632fada7.fc26
Run "systemctl reboot" to start a reboot
# systemctl reboot

...

# rpm-ostree status
State: idle
Deployments:
● custom:fahc/26/x86_64/buildmaster
                   Version: 26.312 (2017-09-20 02:48:59)
                    Commit: 26776f17b576a7b6b4e71572850c2c0b643b859ff560036da0eda189e7bd7dbe

  custom:fahc/26/x86_64/buildmaster
                   Version: 26.311 (2017-09-16 06:00:39)
                    Commit: 4aa880309b07e7689f87f03de4bf60282dab05ff7b7f285e0ee350089a891932

# atomic install --system --name=etcd registry.fedoraproject.org/f25/etcd
Getting image source signatures
Copying blob sha256:4bb8f91f516d147a10606d8c7ae90e655d5a63a80af4c5185cda9fbae8bc8b03
 75.09 MB / 75.89 MB [=========================================================]
Copying blob sha256:ab397bafa67fa322671cfcdf43fb9612f0e0b7fd40fe450d3420905e6d4d9406
 11.69 MB / 11.99 MB [=======================================================>-]
Copying config sha256:8b0bcd195172c7ce8ebe45af46f92fa27b56f8163b65a19910e7da6e88a4c0be
 0 B / 4.45 KB [---------------------------------------------------------------]
Writing manifest to image destination
Storing signatures
 4.45 KB / 4.45 KB [===========================================================]
(process:1449): OSTree-CRITICAL **: ostree_repo_commit_transaction: assertion 'self->in_transaction == TRUE' failed
**
ERROR:/builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/github.com/ostreedev/ostree-go/pkg/glibobject/glibobject.go.h:6:_g_error_get_message: assertion failed: (error !=
 NULL)
SIGABRT: abort
PC=0x7f9ecaa8769b m=5 sigcode=18446744073709551610
signal arrived during cgo execution

goroutine 1 [syscall, locked to thread]:
runtime.cgocall(0x952900, 0xc420684c90, 0xc420684cb8)
        /usr/lib/golang/src/runtime/cgocall.go:131 +0xe2 fp=0xc420684c60 sp=0xc420684c20
github.com/ostreedev/ostree-go/pkg/glibobject._Cfunc__g_error_get_message(0x0, 0x0)
        github.com/ostreedev/ostree-go/pkg/glibobject/_obj/_cgo_gotypes.go:151 +0x4a fp=0xc420684c90 sp=0xc420684c60
github.com/ostreedev/ostree-go/pkg/glibobject.ConvertGError.func2(0x0, 0xac64b8)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/github.com/ostreedev/ostree-go/pkg/glibobject/gerror.go:70 +0x60 fp=0xc420684cc8 sp=0xc420684c90
github.com/ostreedev/ostree-go/pkg/glibobject.ConvertGError(0x0, 0x0, 0x0)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/github.com/ostreedev/ostree-go/pkg/glibobject/gerror.go:70 +0x82 fp=0xc420684d08 sp=0xc420684cc8
github.com/ostreedev/ostree-go/pkg/otbuiltin.generateError(0x0, 0xc420341140, 0x0)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/github.com/ostreedev/ostree-go/pkg/otbuiltin/builtin.go:86 +0x40 fp=0xc420684dc8 sp=0xc420684d08
github.com/ostreedev/ostree-go/pkg/otbuiltin.(*Repo).CommitTransaction(0xc42000e458, 0xc42000e458, 0xc4200caa00, 0x39)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/github.com/ostreedev/ostree-go/pkg/otbuiltin/commit.go:86 +0xd2 fp=0xc420684e10 sp=0xc420684dc8
github.com/containers/image/ostree.(*ostreeImageDestination).Commit(0xc42015a3f0, 0xfd7ab0, 0x0)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/github.com/containers/image/ostree/ostree_dest.go:310 +0x41c fp=0xc420684f08 sp=0xc420684e10
github.com/containers/image/copy.Image(0xc42000c5c0, 0xf868e0, 0xc420017290, 0xf865e0, 0xc420015380, 0xc4205394b8, 0x0, 0x0)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/github.com/containers/image/copy/copy.go:277 +0x10cd fp=0xc4206853d0 sp=0xc420684f08
main.copyHandler(0xc420441900, 0x0, 0x0)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/cmd/skopeo/copy.go:64 +0x654 fp=0xc420685510 sp=0xc4206853d0
runtime.call32(0xc42048cd20, 0xac67d0, 0xc4204a0da0, 0x800000018)
        /usr/lib/golang/src/runtime/asm_amd64.s:514 +0x48 fp=0xc420685540 sp=0xc420685510
reflect.Value.call(0x9ce420, 0xac67d0, 0x13, 0xa9d8c4, 0x4, 0xc420143970, 0x1, 0x1, 0xc4201438f8, 0xa89f60, ...)
        /usr/lib/golang/src/reflect/value.go:434 +0x91f fp=0xc420685888 sp=0xc420685540
reflect.Value.Call(0x9ce420, 0xac67d0, 0x13, 0xc420143970, 0x1, 0x1, 0x140, 0xc420441900, 0x0)
        /usr/lib/golang/src/reflect/value.go:302 +0xa4 fp=0xc4206858f0 sp=0xc420685888
github.com/urfave/cli.HandleAction(0x9ce420, 0xac67d0, 0xc420441900, 0x0, 0x0)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/github.com/urfave/cli/app.go:480 +0x198 fp=0xc4206859b8 sp=0xc4206858f0
github.com/urfave/cli.Command.Run(0xa9da44, 0x4, 0x0, 0x0, 0x0, 0x0, 0x0, 0xab8495, 0x2f, 0x0, ...)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/github.com/urfave/cli/command.go:186 +0xab8 fp=0xc420685d78 sp=0xc4206859b8
github.com/urfave/cli.(*App).Run(0xc420494180, 0xc420010120, 0x6, 0x6, 0x0, 0x0)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/github.com/urfave/cli/app.go:236 +0x5d6 fp=0xc420685f38 sp=0xc420685d78
main.main()
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/cmd/skopeo/main.go:81 +0x68 fp=0xc420685f88 sp=0xc420685f38
runtime.main()
        /usr/lib/golang/src/runtime/proc.go:185 +0x20a fp=0xc420685fe0 sp=0xc420685f88
runtime.goexit()
        /usr/lib/golang/src/runtime/asm_amd64.s:2197 +0x1 fp=0xc420685fe8 sp=0xc420685fe0

goroutine 17 [syscall, locked to thread]:
runtime.goexit()
        /usr/lib/golang/src/runtime/asm_amd64.s:2197 +0x1

goroutine 5 [syscall]:
os/signal.signal_recv(0x0)
        /usr/lib/golang/src/runtime/sigqueue.go:116 +0x104
os/signal.loop()
        /usr/lib/golang/src/os/signal/signal_unix.go:22 +0x22
created by os/signal.init.1
        /usr/lib/golang/src/os/signal/signal_unix.go:28 +0x41

goroutine 82 [select]:
gopkg.in/cheggaaa/pb%2ev1.(*ProgressBar).refresher(0xc420558640)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/gopkg.in/cheggaaa/pb.v1/pb.go:423 +0x109
created by gopkg.in/cheggaaa/pb%2ev1.(*ProgressBar).Start
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/gopkg.in/cheggaaa/pb.v1/pb.go:123 +0xbe

goroutine 81 [select]:
gopkg.in/cheggaaa/pb%2ev1.(*ProgressBar).refresher(0xc420558500)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/gopkg.in/cheggaaa/pb.v1/pb.go:423 +0x109
created by gopkg.in/cheggaaa/pb%2ev1.(*ProgressBar).Start
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/gopkg.in/cheggaaa/pb.v1/pb.go:123 +0xbe

goroutine 62 [select]:
gopkg.in/cheggaaa/pb%2ev1.(*ProgressBar).refresher(0xc4204c37c0)
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/gopkg.in/cheggaaa/pb.v1/pb.go:423 +0x109
created by gopkg.in/cheggaaa/pb%2ev1.(*ProgressBar).Start
        /builddir/build/BUILD/skopeo-v0.1.23-34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba/vendor/src/gopkg.in/cheggaaa/pb.v1/pb.go:123 +0xbe

rax    0x0
rbx    0x7f9eb03190a0
rcx    0x7f9ecaa8769b
rdx    0x0
rdi    0x2
rsi    0x7f9ec1da9930
rbp    0xda
rsp    0x7f9ec1da9930
r8     0x0
r9     0x7f9ec1da9930
r10    0x8
r11    0x246
r12    0x7f9ecb387d20
r13    0x7f9ec1da9b80
r14    0xb07830
r15    0x200
rip    0x7f9ecaa8769b
rflags 0x246
cs     0x33
fs     0x0
gs     0x0

# rpm -q atomic ostree skopeo
atomic-1.19.1.33-b39a7831b50391a04afc3512a8e94a7f6df26e79.263fbc997aacbf275215d32c2361cbb39d65b56a.fc26.x86_64
ostree-2017.11.20-e3c3ec5dd91492e82c79223052443d038c60f41c.5f781f21a11ef652a476cc05c2923c1e08204b2b.fc26.x86_64
skopeo-0.1.23.34-875dd2e7a965adb92dfc97c69eaceba9d33b27ba.70546e0d9558b5d2df5727b41aba396e632fada7.fc26.x86_64

@miabbott
Copy link
Collaborator Author

Unfortunately, the delta between ostree commits is significant; it looks like we went from 2f22e5b to e3c3ec5

By my estimation, the only commit in that delta that was mucking around ostree_repo_commit_transaction() was d0b0578

@cgwalters
Copy link
Member

Hmm...looking at the skopeo-ostree code I see that it's not calling abort_transaction() if something fails, but that's the opposite of this bug.

@cgwalters cgwalters added the bug label Sep 20, 2017
@cgwalters cgwalters self-assigned this Sep 21, 2017
@cgwalters
Copy link
Member

Confirmed that going back to:

26.300 (2017-09-14 22:07:04) Commit: 1e111f95dc5d6511775004758bf0c49d9a672240be569d478eb9bdf33d4e36c6

works, then

ostree admin unlock
rpm -Uvh http://artifacts.ci.centos.org/sig-atomic/fahc/rdgo/build/ostree-2017.11.23-75150fe04a5dd830de87abfde99ce66ab9feb5a7.5f781f21a11ef652a476cc05c2923c1e08204b2b/ostree-{,grub2-,libs-}2017.11.23-75150fe04a5dd830de87abfde99ce66ab9feb5a7.5f781f21a11ef652a476cc05c2923c1e08204b2b.fc26.x86_64.rpm

causes the failure again.

@cgwalters
Copy link
Member

Starting some notes/patches in ostreedev/ostree-go#12

cgwalters added a commit to cgwalters/ostree that referenced this issue Sep 21, 2017
Such an evil bug 🙈. I was just reading an strace trying to figure out what was
going on, and noticed we had the `XXXXXX` in the lockfile name. It was only
after that I realized that that this might *be* the cause of the skopeo issue.

This is another case where we definitely need more test coverage of things that
actually use the API multiple times in process; might look at dusting off the
work for the rpm-ostree test.

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

No branches or pull requests

2 participants