NIFI-9233 - Improve reliability of system integration tests #5787

greyp9 · 2022-02-22T18:53:02Z

Description of PR

Various code fixes related to Github/CI system test failures.

Capture troubleshooting data on job timeout.
Capture maven-failsafe-plugin output on job failure.
System test timing adjustments to reduce diagnostic noise.
Log PID on startup / shutdown to identify source of orphaned processes.
Fix for LoadBalanceSession handshake failure (which causes test timeouts).
Fix for LoadBalanceSession session wrapup (which can cause test timeouts).
Logging allowing for identification of load balance failures.
Retry NiFi process shutdown if needed during system test case teardown.
Fix logging typo.
Log IDs of both ends of LoadBalance connections (to help identify failure cases).
Retry ReportingTask query on incomplete response.
Do not mask InterruptedException while waiting for system test actions to complete.
Retry service queries until expected state is verified.
Short waits between actions (when needed) to allow FlowManager state to become consistent.
Comment out ReportingTask system test failures to allow NIFI-9717 to be addressed asynchronously.
Adjust system test cluster configuration to avoid test failure condition.
Adjust logback logging for system test profile (include timestamps).

In order to streamline the review of the contribution we ask you
to ensure the following steps have been taken:

For all changes:

Is there a JIRA ticket associated with this PR? Is it referenced
in the commit message?
Does your PR title start with NIFI-XXXX where XXXX is the JIRA number you are trying to resolve? Pay particular attention to the hyphen "-" character.
Has your PR been rebased against the latest commit within the target branch (typically main)?
Is your initial contribution a single, squashed commit? Additional commits in response to PR reviewer feedback should be made on this branch and pushed to allow change tracking. Do not squash or use --force when pushing to allow for clean monitoring of changes.

For code changes:

Have you ensured that the full suite of tests is executed via mvn -Pcontrib-check clean install at the root nifi folder?
Have you written or updated unit tests to verify your changes?
Have you verified that the full build is successful on JDK 8?
Have you verified that the full build is successful on JDK 11?
If adding new dependencies to the code, are these dependencies licensed in a way that is compatible for inclusion under ASF 2.0?
If applicable, have you updated the LICENSE file, including the main LICENSE file under nifi-assembly?
If applicable, have you updated the NOTICE file, including the main NOTICE file found under nifi-assembly?
If adding new Properties, have you added .displayName in addition to .name (programmatic access) for each of the new properties?

For documentation related changes:

Have you ensured that format looks appropriate for the output in which it is rendered?

Note:

Please ensure that once the PR is submitted, you check GitHub Actions CI for build issues and submit an update to your PR as soon as possible.

exceptionfactory

Thanks for working through the system test issues @greyp9! I will defer to @markap14 for further review, but I noted couple minor things.

At a high level, it might be helpful to separate logging improvements into a separate pull request. Since some of the changes impact runtime code, and others are focused on the integration tests, some changes appear to be targeted toward general logging improvements, versus test stability updates. If the system integration stability improvements are still in process, it might be better to submit the logging changes separately for review.

exceptionfactory · 2022-02-25T04:26:08Z

...main/java/org/apache/nifi/controller/queue/clustered/server/ConnectionLoadBalanceServer.java

                    if (socket != null) {
                        try {
+                            logger.debug("closing socket");


This logging statement should include more details about the connection.

removed (leftover debugging)

exceptionfactory · 2022-02-25T04:29:46Z

.../org/apache/nifi/tests/system/verification/ClusteredVerifiableControllerServiceSystemIT.java

@@ -57,6 +57,6 @@ public void testDifferentResultsFromDifferentNodes() throws InterruptedException
        // Second verification result will be verification results
        assertEquals(Outcome.SUCCESSFUL.name(), resultList.get(1).getOutcome());
        // Third verification result is for Fail On Primary Node
-        assertEquals(Outcome.FAILED.name(), resultList.get(2).getOutcome());
+        // assertEquals(Outcome.FAILED.name(), resultList.get(2).getOutcome());  // NIFI-9717


Rather than commenting out this assertion, it seems like it should be removed, then evaluated in the ticket mentioned.

My overarching goal has been to get the system tests green. Commenting out the assertion and removal are two strategies that both work toward this goal.

Another aspect of this is that this assertion passes upwards of 95% of the time. So when the issue is resolved, we would want to reinstate the assertion. My opinion is the "lift" required to do that is slightly easier using the "comment out" strategy.

There is some interesting discussion here:

https://stackoverflow.com/questions/2501519/delete-or-comment-out-non-working-junit-tests

Thanks for the response @greyp9, that is helpful. I have seen a number of ignored tests here and there, so that was the initial reason for flagging the commented lines. Given that you already created a specific Jira issue and mentioned it in the comment, it seems acceptable to leave the commented line for now. Hopefully that issue can be addressed soon after resolving the general system test stability issues.

…eftover logging statement

exceptionfactory

@greyp9, in order to continue progress on this pull request, what do you think about separating the nifi-bootstrap changes into a separate PR? Including the Process ID looks like a useful runtime adjustment, regardless of system integration tests. Those changes could be reviewed and incorporated separately from the integration test improvements.

The runtime change to LoadBalanceSession also seems worth considering separately, but in that case, I'm not sure that hard-coding a one second read timeout makes sense in all cases.

exceptionfactory · 2022-03-02T13:37:19Z

nifi-bootstrap/src/main/java/org/apache/nifi/bootstrap/RunNiFi.java

@@ -1056,7 +1056,7 @@ private void waitForShutdown(final String pid, final Logger logger, final File s
            logger.error("Failed to delete pid file {}; this file should be cleaned up manually", pidFile);
        }

-        logger.info("NiFi has finished shutting down.");
+        logger.info("NiFi has finished shutting down. (PID={})", pid);


References to the Process ID appear differently in this class versus ShutdownHook. Recommend keeping PID capitalized and adjusting the log as follows:

Suggested change

logger.info("NiFi has finished shutting down. (PID={})", pid);

logger.info("NiFi process [{}] shutdown completed", pid);

exceptionfactory · 2022-03-02T13:39:30Z

nifi-bootstrap/src/main/java/org/apache/nifi/bootstrap/ShutdownHook.java

@@ -51,7 +53,7 @@ public void run() {
        runner.setAutoRestartNiFi(false);
        final int ccPort = runner.getNiFiCommandControlPort();
        if (ccPort > 0) {
-            System.out.println("Initiating Shutdown of NiFi...");
+            System.out.println("Initiating Shutdown of NiFi... pid=" + pid);


Recommend the following in relationship to the comment on RunNiFi, as well as adjusting the method call to use printf() for formatting:

Suggested change

System.out.println("Initiating Shutdown of NiFi... pid=" + pid);

System.out.printf("NiFi process [%d] shutdown started%n", pid);

exceptionfactory · 2022-03-02T13:41:20Z

nifi-bootstrap/src/main/java/org/apache/nifi/bootstrap/RunNiFi.java

@@ -116,7 +116,7 @@
    public static final String PID_KEY = "pid";

    public static final int STARTUP_WAIT_SECONDS = 60;
-    public static final long GRACEFUL_SHUTDOWN_RETRY_MILLIS = 2000L;
+    public static final long GRACEFUL_SHUTDOWN_RETRY_MILLIS = 1000L;


Is there a particular reason for reducing retry interval?

exceptionfactory · 2022-03-02T13:46:34Z

nifi-bootstrap/src/main/java/org/apache/nifi/bootstrap/ShutdownHook.java

@@ -66,7 +68,7 @@ public void run() {
        }

        runner.notifyStop();
-        System.out.println("Waiting for Apache NiFi to finish shutting down...");
+        System.out.println("Waiting for Apache NiFi to finish shutting down... pid=" + pid);


Also recommend adjusting this message:

Suggested change

System.out.println("Waiting for Apache NiFi to finish shutting down... pid=" + pid);

System.out.printf("NiFi process [%d] shutdown in progress...%n", pid);

greyp9 · 2022-03-02T23:40:54Z

@greyp9, in order to continue progress on this pull request, what do you think about separating the nifi-bootstrap changes into a separate PR? Including the Process ID looks like a useful runtime adjustment, regardless of system integration tests. Those changes could be reviewed and incorporated separately from the integration test improvements.

Thanks @exceptionfactory for the feedback. Looking at this PR as a whole, I agree that it should be broken out, and I'm in the process of doing that. I'll close this PR in favor of those.

The runtime change to LoadBalanceSession also seems worth considering separately, but in that case, I'm not sure that hard-coding a one second read timeout makes sense in all cases.

Yep. The one second timeout only affects the server ACK part of LoadBalance protocol. I tried it out in response to direct evidence of an issue with that part of the protocol, and things ran much better on the github CI machines. But I agree it looks icky. Something is going on there that needs further investigation.

greyp9 · 2022-03-03T00:12:32Z

Closing this PR; many of these changes are included in PRs: 5826, 5827, 5828, 5829.

NIFI-9233 - Improve reliability of system integration tests

2a19020

greyp9 marked this pull request as ready for review February 22, 2022 21:16

greyp9 marked this pull request as draft February 23, 2022 00:00

NIFI-9233 - Improve reliability of system integration tests

c82e99c

greyp9 marked this pull request as ready for review February 23, 2022 14:27

exceptionfactory reviewed Feb 25, 2022

View reviewed changes

NIFI-9233 - Improve reliability of system integration tests; remove l…

6b3b54b

…eftover logging statement

exceptionfactory reviewed Mar 2, 2022

View reviewed changes

greyp9 closed this Mar 3, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

NIFI-9233 - Improve reliability of system integration tests #5787

NIFI-9233 - Improve reliability of system integration tests #5787

greyp9 commented Feb 22, 2022

exceptionfactory left a comment

exceptionfactory Feb 25, 2022

greyp9 Feb 25, 2022

exceptionfactory Feb 25, 2022

greyp9 Feb 25, 2022

exceptionfactory Feb 25, 2022

exceptionfactory left a comment

exceptionfactory Mar 2, 2022

exceptionfactory Mar 2, 2022 •

edited

Loading

exceptionfactory Mar 2, 2022

exceptionfactory Mar 2, 2022

greyp9 commented Mar 2, 2022

greyp9 commented Mar 3, 2022

	logger.info("NiFi has finished shutting down. (PID={})", pid);
	logger.info("NiFi process [{}] shutdown completed", pid);

	System.out.println("Initiating Shutdown of NiFi... pid=" + pid);
	System.out.printf("NiFi process [%d] shutdown started%n", pid);

	System.out.println("Waiting for Apache NiFi to finish shutting down... pid=" + pid);
	System.out.printf("NiFi process [%d] shutdown in progress...%n", pid);

NIFI-9233 - Improve reliability of system integration tests #5787

NIFI-9233 - Improve reliability of system integration tests #5787

Conversation

greyp9 commented Feb 22, 2022

Description of PR

For all changes:

For code changes:

For documentation related changes:

Note:

exceptionfactory 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

Choose a reason for hiding this comment

Choose a reason for hiding this comment

exceptionfactory left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

exceptionfactory Mar 2, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

greyp9 commented Mar 2, 2022

greyp9 commented Mar 3, 2022

exceptionfactory Mar 2, 2022 •

edited

Loading