test/system: Add test for journald log check in quadlet #22736

ypu · 2024-05-17T03:11:35Z

This test is used to ensure the default configuration for quadlets generated service files is sending stdout/stderr/syslog to the journald.

Does this PR introduce a user-facing change?

openshift-ci · 2024-05-17T03:11:41Z

[APPROVALNOTIFIER] This PR is NOT APPROVED

This pull-request has been approved by: ypu
Once this PR has been reviewed and has the lgtm label, please assign lsm5 for approval. For more information see the Kubernetes Code Review Process.

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

Needs approval from an approver in each of these files:

OWNERS

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

packit-as-a-service · 2024-05-17T03:15:57Z

Ephemeral COPR build failed. @containers/packit-build please check.

ypu · 2024-05-17T03:27:39Z

/release-note-none

Luap99 · 2024-05-17T09:06:58Z

test/system/252-quadlet.bats

+    cat > $quadlet_file <<EOF
+[Container]
+Image=$IMAGE
+Exec=sh -c "echo I AM AN OUTPUT; echo I AM AN ERROR 1>&2; sleep inf"


This test takes over 10s because sleep does not react to SIGTERM. please use a different command or set StopTimeout=0 in the quadlet file

Got it. Will update the command.

Luap99 · 2024-05-17T09:09:02Z

test/system/252-quadlet.bats

@@ -1542,4 +1542,27 @@ EOF
    service_cleanup $QUADLET_SERVICE_NAME inactive
    run_podman rmi $untagged_image:latest $built_image $(pause_image)
 }
+
+@test "quadlet - output and error message" {


We already check the journal in quadlet - oneshot, I suggest you add you stdout/err check in this test for timing reasons

Hi @Luap99 Thanks a lot for your advice. But in the oneshot case the point it write the logs to journald is a little different. In oneshot case the log is checked after the process is finished. But in this case want to check if we can get the logs during the process is still running just like a normal services. So I'd like to keep it a separated one.

Thank you for your PR. Can you clarify what the purpose of that testing would be? Is there some reason to believe that podman could possibly buffer journal output until a process terminates? There is buffering / time delay going on, but it is not podman's fault. And as @Luap99 mentioned, your test will flake due to this race condition.

This case want to check the services that started by the service file generated from quadlet can send stdout/stderr/syslog to the journal. Normally the services will keep running so from the user view there maybe have a slight different with the test case with oneshot. I am not saying there is problem exist in the podman write logs to journal during the process is running, but that is something that my test scenario want to covered and checked.

It is fine to cover that but I think it still makes more sense to just extend an existing test for that.
The quadlet tests are not exactly fast as they need to generate/daemon-reload/start unit every time so I think it would help if you just add the print to an existing unit

I still prefer this being added to an existing test, i.e. "quadlet - ContainerName.
quadlet tests are slow (around 2.5s), it does not sounds like much but in the sum this adds up quickly.
As person doing a lot of work to speed system test up (#22826, #22821) we really need to be more careful when adding new tests.

Just checked the “quadlet - ContainerName” I think it is OK to combine them to one test. Will update the steps to it.

Luap99 · 2024-05-17T09:10:41Z

test/system/252-quadlet.bats

+    run journalctl "--since=$STARTED_TIME" --unit="$QUADLET_SERVICE_NAME"
+    assert "$output" =~ 'I AM AN OUTPUT' "Output can be found with journalctl"
+    assert "$output" =~ 'I AM AN ERROR' "Error can be found with journalctl"
+    assert "$output" =~ "Starting $QUADLET_SERVICE_NAME" "Status information can be found with journalctl"
+
+    run journalctl "--since=$STARTED_TIME" -p 3 --unit="$QUADLET_SERVICE_NAME"
+    assert "$output" =~ 'I AM AN ERROR' "Error can be found with journalctl -p 3"
+    assert "$output" != .*"I AM AN OUTPUT".* "Output can not be found with journalctl -p 3"


This is racy you first have to wait for the output to be logged but I really suggest to add it to the other test instead where it already works without flakes

Understand it. Will add a wait for here to ignore that.

edsantiago

Thanks again for your PR. Please do clarify the perceived problem that this test addresses. A few comments inline should you wish to continue with this approach.

edsantiago · 2024-05-20T11:29:40Z

test/system/252-quadlet.bats

+    run_quadlet "$quadlet_file"
+    service_setup $QUADLET_SERVICE_NAME
+
+    run journalctl "--since=$STARTED_TIME" --unit="$QUADLET_SERVICE_NAME"


Due to the systemd race condition, this will have to be done in a while/timeout loop. (If you choose to continue with this testing approach).

edsantiago · 2024-05-20T11:32:37Z

test/system/252-quadlet.bats

+    assert "$output" =~ 'I AM AN ERROR' "Error can be found with journalctl"
+    assert "$output" =~ "Starting $QUADLET_SERVICE_NAME" "Status information can be found with journalctl"
+
+    run journalctl "--since=$STARTED_TIME" -p 3 --unit="$QUADLET_SERVICE_NAME"


No undocumented magic constants, please, those make it very hard for future maintainers. This might be better:

# log priority 3 == err run journalctl ... --priority 3 ...

Got it. Will update it. Thanks a lot for the advice.

ypu · 2024-05-29T08:11:32Z

Hi @edsantiago and @Luap99 Updated the tests based on your advices. Can you help to review it again? Thanks a lot!

Add some test steps into quadlet - ContainerName. These steps are used to ensure the default configuration for quadlets generated service files is sending stdout/stderr/syslog to the journald. Signed-off-by: Yiqiao Pu <ypu@redhat.com>

ypu · 2024-05-29T13:58:20Z

Hi @Luap99 commit updated to add steps to “quadlet - ContainerName” case. Please help to review it. Thanks a lot!

edsantiago

Thank you for adding to the existing test. A few suggestions inline, and one blocker.

edsantiago · 2024-05-30T21:31:19Z

test/system/252-quadlet.bats

+        sleep "$step"
+        count=$(( count - 1 ))
+    done
+    die "Wait for $expect_str shows up in journalctl output timeout"


Suggestion: "Timed out waiting for '$expect_str' in journal"

edsantiago · 2024-05-30T21:34:22Z

test/system/252-quadlet.bats

    local quadlet_file=$PODMAN_TMPDIR/containername_$(random_string).container
    cat > $quadlet_file <<EOF
 [Container]
 ContainerName=customcontainername
 Image=$IMAGE
-Exec=top"
+Exec=sh -c "echo I AM AN OUTPUT; echo I AM AN ERROR 1>&2; top -d 10"


Suggestion: define token_out="stdout$(random_string 10)" and token_err="stderr$(random_string 10)" above, then use them in the echo and test.

edsantiago · 2024-05-30T21:35:31Z

test/system/252-quadlet.bats

+    # log priority 3 in journalctl is err. This is documented in syslog(3)
+    run journalctl "--since=$STARTED_TIME" --priority=3 --unit="$QUADLET_SERVICE_NAME"
+    assert "$output" =~ 'I AM AN ERROR' "Error can be found with journalctl --priority=3"
+    assert "$output" != .*"I AM AN OUTPUT".* "Output can not be found with journalctl --priority=3"


Please use !~ instead and remove the .*s

openshift-ci bot added the do-not-merge/release-note-label-needed Enforce release-note requirement, even if just None label May 17, 2024

openshift-ci bot added release-note-none and removed do-not-merge/release-note-label-needed Enforce release-note requirement, even if just None labels May 17, 2024

Luap99 requested changes May 17, 2024

View reviewed changes

edsantiago requested changes May 20, 2024

View reviewed changes

ypu force-pushed the quadlet_journald branch from 5ea3bb7 to ad60988 Compare May 29, 2024 08:09

ypu force-pushed the quadlet_journald branch from ad60988 to 0ed4627 Compare May 29, 2024 13:56

edsantiago requested changes May 30, 2024

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

test/system: Add test for journald log check in quadlet #22736

test/system: Add test for journald log check in quadlet #22736

ypu commented May 17, 2024 •

edited

openshift-ci bot commented May 17, 2024

packit-as-a-service bot commented May 17, 2024

ypu commented May 17, 2024

Luap99 May 17, 2024

ypu May 20, 2024

Luap99 May 17, 2024

ypu May 20, 2024

edsantiago May 20, 2024

ypu May 20, 2024

Luap99 May 22, 2024

Luap99 May 29, 2024

ypu May 29, 2024

Luap99 May 17, 2024

ypu May 20, 2024

edsantiago left a comment

edsantiago May 20, 2024

edsantiago May 20, 2024

ypu May 20, 2024

ypu commented May 29, 2024

ypu commented May 29, 2024

edsantiago left a comment

edsantiago May 30, 2024

edsantiago May 30, 2024

edsantiago May 30, 2024

test/system: Add test for journald log check in quadlet #22736

Are you sure you want to change the base?

test/system: Add test for journald log check in quadlet #22736

Conversation

ypu commented May 17, 2024 • edited

Does this PR introduce a user-facing change?

openshift-ci bot commented May 17, 2024

packit-as-a-service bot commented May 17, 2024

ypu commented May 17, 2024

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

edsantiago left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ypu commented May 29, 2024

ypu commented May 29, 2024

edsantiago left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ypu commented May 17, 2024 •

edited