Skip to content

Conversation

@rhatdan
Copy link
Member

@rhatdan rhatdan commented Jun 11, 2021

Signed-off-by: Daniel J Walsh dwalsh@redhat.com

@openshift-ci openshift-ci bot added do-not-merge/work-in-progress Indicates that a PR should not merge because it is a work in progress. approved Indicates a PR has been approved by an approver from all required OWNERS files. labels Jun 11, 2021
@rhatdan rhatdan force-pushed the journal branch 2 times, most recently from 40183c9 to 6c7fabb Compare June 14, 2021 15:51
@openshift-ci openshift-ci bot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jun 20, 2021
@openshift-ci openshift-ci bot added needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. and removed needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. labels Jun 20, 2021
@openshift-ci openshift-ci bot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jun 23, 2021
@rhatdan rhatdan force-pushed the journal branch 6 times, most recently from 6752472 to ca54e6c Compare June 24, 2021 21:17
@openshift-ci openshift-ci bot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jun 25, 2021
@openshift-ci openshift-ci bot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jun 30, 2021
@rhatdan
Copy link
Member Author

rhatdan commented Jun 30, 2021

I'm stumped.

@nalind @vrothberg @giuseppe Any idea what is going wrong? Basically podman logs is failing with journald never becoming ready.

[+1194s] Error: initial journal cursor: failed to get cursor: cannot assign requested address

Only on one test and it is failing on 5 different test suites. Of course when I run it locally, it works fine. Other tests within the same test suite seem to be passing with podman logs.

[+1194s] Podman create 
[+1194s]   podman create --mount flag with multiple mounts
[+1194s]   /var/tmp/go/src/github.com/containers/podman/test/e2e/create_test.go:137
[+1194s] 
[+1194s] [BeforeEach] Podman create
[+1194s]   /var/tmp/go/src/github.com/containers/podman/test/e2e/create_test.go:24
[+1194s] [It] podman create --mount flag with multiple mounts
[+1194s]   /var/tmp/go/src/github.com/containers/podman/test/e2e/create_test.go:137
[+1194s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test729401940/crio --runroot /tmp/podman_test729401940/crio-run --runtime /usr/lib/cri-o-runc/sbin/runc --conmon /usr/libexec/podman/conmon --cni-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test729401940 --events-backend file --storage-driver vfs create --name test --mount type=bind,src=/tmp/podman_test729401940/vol-test1,target=/myvol1,z --mount type=bind,src=/tmp/podman_test729401940/vol-test2,target=/myvol2,z quay.io/libpod/alpine:latest touch /myvol2/foo.txt
[+1194s] 209d934d42d204a359db7d9c2c960884926a31a26c1f706738f65ae4be42d344
[+1194s] output: 209d934d42d204a359db7d9c2c960884926a31a26c1f706738f65ae4be42d344
[+1194s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test729401940/crio --runroot /tmp/podman_test729401940/crio-run --runtime /usr/lib/cri-o-runc/sbin/runc --conmon /usr/libexec/podman/conmon --cni-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test729401940 --events-backend file --storage-driver vfs start test
[+1194s] test
[+1194s] output: test
[+1194s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test729401940/crio --runroot /tmp/podman_test729401940/crio-run --runtime /usr/lib/cri-o-runc/sbin/runc --conmon /usr/libexec/podman/conmon --cni-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test729401940 --events-backend file --storage-driver vfs wait test
[+1194s] 0
[+1194s] output: 0
[+1194s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test729401940/crio --runroot /tmp/podman_test729401940/crio-run --runtime /usr/lib/cri-o-runc/sbin/runc --conmon /usr/libexec/podman/conmon --cni-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test729401940 --events-backend file --storage-driver vfs logs test
[+1194s] Error: initial journal cursor: failed to get cursor: cannot assign requested address
[+1194s] output: 
[+1194s] [AfterEach] Podman create
[+1194s]   /var/tmp/go/src/github.com/containers/podman/test/e2e/create_test.go:34
[+1194s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test729401940/crio --runroot /tmp/podman_test729401940/crio-run --runtime /usr/lib/cri-o-runc/sbin/runc --conmon /usr/libexec/podman/conmon --cni-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test729401940 --events-backend file --storage-driver vfs stop -a --time 0
[+1194s] 209d934d42d204a359db7d9c2c960884926a31a26c1f706738f65ae4be42d344
[+1194s] output: 209d934d42d204a359db7d9c2c960884926a31a26c1f706738f65ae4be42d344
[+1194s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test729401940/crio --runroot /tmp/podman_test729401940/crio-run --runtime /usr/lib/cri-o-runc/sbin/runc --conmon /usr/libexec/podman/conmon --cni-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test729401940 --events-backend file --storage-driver vfs pod stop -a -t 0
[+1194s] output: 
[+1194s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test729401940/crio --runroot /tmp/podman_test729401940/crio-run --runtime /usr/lib/cri-o-runc/sbin/runc --conmon /usr/libexec/podman/conmon --cni-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test729401940 --events-backend file --storage-driver vfs pod rm -fa
[+1194s] output: 
[+1194s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test729401940/crio --runroot /tmp/podman_test729401940/crio-run --runtime /usr/lib/cri-o-runc/sbin/runc --conmon /usr/libexec/podman/conmon --cni-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test729401940 --events-backend file --storage-driver vfs rm -fa
[+1194s] 209d934d42d204a359db7d9c2c960884926a31a26c1f706738f65ae4be42d344
[+1194s] output: 209d934d42d204a359db7d9c2c960884926a31a26c1f706738f65ae4be42d344
[+1194s] 
[+1194s] 
[+1194s] • Failure [2.407 seconds]
[+1194s] Podman create
[+1194s] /var/tmp/go/src/github.com/containers/podman/test/e2e/create_test.go:17
[+1194s]   podman create --mount flag with multiple mounts [It]
[+1194s]   /var/tmp/go/src/github.com/containers/podman/test/e2e/create_test.go:137
[+1194s] 
[+1194s]   Expected
[+1194s]       <int>: 125
[+1194s]   to equal
[+1194s]       <int>: 0
[+1194s] 
[+1194s]   /var/tmp/go/src/github.com/containers/podman/test/e2e/create_test.go:159
[+1194s] 

@vrothberg
Copy link
Member

Looking into it.

@vrothberg
Copy link
Member

@rhatdan, I did something stupid in the exponential backoff. Can you try with the following diff?

diff --git a/libpod/container_log_linux.go b/libpod/container_log_linux.go
index 269f61ece6eb..a2bf298ea4a2 100644
--- a/libpod/container_log_linux.go
+++ b/libpod/container_log_linux.go
@@ -73,9 +73,9 @@ func (c *Container) readFromJournal(ctx context.Context, options *logs.LogOption
        for i := 1; i <= 10; i++ {
                cursor, cursorError = journal.GetCursor()
                if err != nil {
+                       time.Sleep(time.Duration(i*100) * time.Millisecond)
                        continue
                }
-               time.Sleep(time.Duration(i*100) * time.Millisecond)
                break
        }
        if cursorError != nil {

@openshift-ci openshift-ci bot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jun 30, 2021
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you elaborate on why all the waits are needed?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I added them because of the inherent race condition or trying to read a log while a container is still running, each one of these containers is detatched, and we could read the log before the container has written the log.

@openshift-ci
Copy link
Contributor

openshift-ci bot commented Jun 30, 2021

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: rhatdan

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Details Needs approval from an approver in each of these files:

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@openshift-ci openshift-ci bot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jun 30, 2021
@rhatdan rhatdan force-pushed the journal branch 3 times, most recently from 2f3f7a9 to 6afa143 Compare July 16, 2021 17:24
@openshift-ci openshift-ci bot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jul 16, 2021
@openshift-ci openshift-ci bot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jul 16, 2021
@rhatdan rhatdan force-pushed the journal branch 3 times, most recently from ff66500 to bc43490 Compare July 29, 2021 10:40
@openshift-ci openshift-ci bot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Aug 3, 2021
@openshift-ci openshift-ci bot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Aug 3, 2021
@rhatdan rhatdan force-pushed the journal branch 6 times, most recently from e1e1bfe to 17abe45 Compare August 6, 2021 09:59
@rhatdan rhatdan changed the title [WIP] Switch eventlogger to journald by default Switch eventlogger to journald by default Aug 11, 2021
@openshift-ci openshift-ci bot removed the do-not-merge/work-in-progress Indicates that a PR should not merge because it is a work in progress. label Aug 11, 2021
@rhatdan rhatdan added the 3.4 label Aug 11, 2021
[NO TESTS NEEDED] Since we are just testing the default.

Signed-off-by: Daniel J Walsh <dwalsh@redhat.com>
@vrothberg
Copy link
Member

Closing in favor of #11263.

@vrothberg vrothberg closed this Aug 19, 2021
@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 22, 2023
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Sep 22, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Labels

approved Indicates a PR has been approved by an approver from all required OWNERS files. locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants