HDDS-1956. Aged IO Thread exits on first read #1287

adoroszlai · 2019-08-13T08:35:41Z

What changes were proposed in this pull request?

Aged IO thread exits on first read due to ArrayIndexOutOfBoundsException. This is caused by using index as the key name, while readKey expects a string separated by _.
After fixing the above, it randomly exits due to OMException: Key not found. This is an off-by-one error. The first key written has index=1, but the test randomly attempts to read index=0.
Add trace level message for read/write/delete operations.
Include thread name in log output pattern for integration-test.
Fix some log messages in MiniOzoneChaosCluster

https://issues.apache.org/jira/browse/HDDS-1956

How was this patch tested?

Manually ran TestMiniChaosOzoneCluster:

mvn -Phdds -pl :hadoop-ozone-integration-test -Dtest=TestMiniChaosOzoneCluster test

Stopped it after a few minutes (see HDDS-1952).

Verified that aged IO thread was writing and reading keys (until it started failing due to chaos):

2019-08-13 10:19:18,307 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:writeData(138)) - LOADGEN: Writing key pool-245-thread-1_0
2019-08-13 10:19:18,433 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:writeData(143)) - LOADGEN: Written key pool-245-thread-1_0
2019-08-13 10:19:22,473 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(154)) - LOADGEN: Reading key pool-245-thread-1_0
2019-08-13 10:19:22,992 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(176)) - LOADGEN: Read key pool-245-thread-1_0
...
2019-08-13 10:19:23,837 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(154)) - LOADGEN: Reading key pool-245-thread-1_0
2019-08-13 10:19:23,866 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(176)) - LOADGEN: Read key pool-245-thread-1_0
2019-08-13 10:19:23,866 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:writeData(138)) - LOADGEN: Writing key pool-245-thread-1_1
2019-08-13 10:19:23,870 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:writeData(143)) - LOADGEN: Written key pool-245-thread-1_1
2019-08-13 10:19:23,891 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(154)) - LOADGEN: Reading key pool-245-thread-1_1
2019-08-13 10:19:23,933 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(176)) - LOADGEN: Read key pool-245-thread-1_1
2019-08-13 10:19:23,933 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(154)) - LOADGEN: Reading key pool-245-thread-1_0
2019-08-13 10:19:23,960 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(176)) - LOADGEN: Read key pool-245-thread-1_0
2019-08-13 10:19:23,960 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(154)) - LOADGEN: Reading key pool-245-thread-1_0
2019-08-13 10:19:23,974 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(176)) - LOADGEN: Read key pool-245-thread-1_0
2019-08-13 10:19:23,974 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(154)) - LOADGEN: Reading key pool-245-thread-1_0
2019-08-13 10:19:24,017 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(176)) - LOADGEN: Read key pool-245-thread-1_0
2019-08-13 10:19:24,017 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(154)) - LOADGEN: Reading key pool-245-thread-1_1
2019-08-13 10:19:24,044 [pool-245-thread-1] TRACE ozone.MiniOzoneLoadGenerator (MiniOzoneLoadGenerator.java:readData(176)) - LOADGEN: Read key pool-245-thread-1_1

adoroszlai · 2019-08-13T08:35:53Z

@mukul1987

hadoop-yetus · 2019-08-13T10:40:32Z

💔 -1 overall

Vote	Subsystem	Runtime	Comment
0	reexec	42	Docker mode activated.
		_ Prechecks _
+1	dupname	0	No case conflicting files found.
+1	@author	0	The patch does not contain any @author tags.
+1	test4tests	0	The patch appears to include 3 new or modified test files.
		_ trunk Compile Tests _
+1	mvninstall	614	trunk passed
+1	compile	368	trunk passed
+1	checkstyle	65	trunk passed
+1	mvnsite	0	trunk passed
+1	shadedclient	842	branch has no errors when building and testing our client artifacts.
+1	javadoc	167	trunk passed
0	spotbugs	427	Used deprecated FindBugs config; considering switching to SpotBugs.
+1	findbugs	626	trunk passed
		_ Patch Compile Tests _
+1	mvninstall	560	the patch passed
+1	compile	376	the patch passed
+1	javac	376	the patch passed
+1	checkstyle	80	the patch passed
+1	mvnsite	0	the patch passed
+1	whitespace	0	The patch has no whitespace issues.
+1	shadedclient	684	patch has no errors when building and testing our client artifacts.
+1	javadoc	171	the patch passed
+1	findbugs	651	the patch passed
		_ Other Tests _
+1	unit	290	hadoop-hdds in the patch passed.
-1	unit	1660	hadoop-ozone in the patch failed.
+1	asflicense	52	The patch does not generate ASF License warnings.
		7432

Reason	Tests
Failed junit tests	hadoop.ozone.client.rpc.TestOzoneAtRestEncryption
	hadoop.ozone.client.rpc.TestOzoneRpcClient
	hadoop.ozone.client.rpc.TestSecureOzoneRpcClient
	hadoop.ozone.client.rpc.TestBlockOutputStreamWithFailures

Subsystem	Report/Notes
Docker	Client=19.03.1 Server=19.03.1 base: https://builds.apache.org/job/hadoop-multibranch/job/PR-1287/1/artifact/out/Dockerfile
GITHUB PR	#1287
Optional Tests	dupname asflicense compile javac javadoc mvninstall mvnsite unit shadedclient findbugs checkstyle
uname	Linux abd4695b6acf 4.4.0-157-generic #185-Ubuntu SMP Tue Jul 23 09:17:01 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
Build tool	maven
Personality	personality/hadoop.sh
git revision	trunk / 454420e
Default Java	1.8.0_212
unit	https://builds.apache.org/job/hadoop-multibranch/job/PR-1287/1/artifact/out/patch-unit-hadoop-ozone.txt
Test Results	https://builds.apache.org/job/hadoop-multibranch/job/PR-1287/1/testReport/
Max. process+thread count	5125 (vs. ulimit of 5500)
modules	C: hadoop-ozone/integration-test U: hadoop-ozone/integration-test
Console output	https://builds.apache.org/job/hadoop-multibranch/job/PR-1287/1/console
versions	git=2.7.4 maven=3.3.9 findbugs=3.1.0-RC1
Powered by	Apache Yetus 0.10.0 http://yetus.apache.org

This message was automatically generated.

mukul1987

Thanks for working on this @adoroszlai, The patch generally looks good to me.

hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java

mukul1987

+1, the patch looks good to me pending jenkins.

hadoop-yetus · 2019-08-13T18:30:21Z

💔 -1 overall

Vote	Subsystem	Runtime	Comment
0	reexec	41	Docker mode activated.
		_ Prechecks _
+1	dupname	0	No case conflicting files found.
+1	@author	0	The patch does not contain any @author tags.
+1	test4tests	0	The patch appears to include 3 new or modified test files.
		_ trunk Compile Tests _
+1	mvninstall	639	trunk passed
+1	compile	389	trunk passed
+1	checkstyle	66	trunk passed
+1	mvnsite	0	trunk passed
-1	shadedclient	864	branch has errors when building and testing our client artifacts.
+1	javadoc	166	trunk passed
0	spotbugs	465	Used deprecated FindBugs config; considering switching to SpotBugs.
+1	findbugs	670	trunk passed
		_ Patch Compile Tests _
+1	mvninstall	567	the patch passed
+1	compile	374	the patch passed
+1	javac	374	the patch passed
+1	checkstyle	73	the patch passed
+1	mvnsite	0	the patch passed
+1	whitespace	0	The patch has no whitespace issues.
+1	shadedclient	691	patch has no errors when building and testing our client artifacts.
+1	javadoc	153	the patch passed
-1	findbugs	320	hadoop-ozone in the patch failed.
		_ Other Tests _
-1	unit	13	hadoop-hdds in the patch failed.
-1	unit	31	hadoop-ozone in the patch failed.
0	asflicense	31	ASF License check generated no output?
		5461

Subsystem	Report/Notes
Docker	Client=19.03.1 Server=19.03.1 base: https://builds.apache.org/job/hadoop-multibranch/job/PR-1287/2/artifact/out/Dockerfile
GITHUB PR	#1287
Optional Tests	dupname asflicense compile javac javadoc mvninstall mvnsite unit shadedclient findbugs checkstyle
uname	Linux 512599488faa 4.4.0-138-generic #164-Ubuntu SMP Tue Oct 2 17:16:02 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
Build tool	maven
Personality	personality/hadoop.sh
git revision	trunk / 2ac029b
Default Java	1.8.0_212
findbugs	https://builds.apache.org/job/hadoop-multibranch/job/PR-1287/2/artifact/out/patch-findbugs-hadoop-ozone.txt
unit	https://builds.apache.org/job/hadoop-multibranch/job/PR-1287/2/artifact/out/patch-unit-hadoop-hdds.txt
unit	https://builds.apache.org/job/hadoop-multibranch/job/PR-1287/2/artifact/out/patch-unit-hadoop-ozone.txt
Test Results	https://builds.apache.org/job/hadoop-multibranch/job/PR-1287/2/testReport/
Max. process+thread count	447 (vs. ulimit of 5500)
modules	C: hadoop-ozone/integration-test U: hadoop-ozone/integration-test
Console output	https://builds.apache.org/job/hadoop-multibranch/job/PR-1287/2/console
versions	git=2.7.4 maven=3.3.9 findbugs=3.1.0-RC1
Powered by	Apache Yetus 0.10.0 http://yetus.apache.org

This message was automatically generated.

avijayanhwx · 2019-08-13T22:38:59Z

/label ozone

adoroszlai · 2019-08-14T05:33:41Z

Thanks @mukul1987 for the review, and @anuengineer for commiting it.

adoroszlai added 5 commits August 13, 2019 09:52

HDDS-1956. Aged IO Thread exits on first read

1e40bf9

HDDS-1956. Aged IO thread randomly exits due to key not found

76a21b3

HDDS-1956. Log key operations at trace level

435a5c0

HDDS-1956. Include thread name in log pattern

efd431b

HDDS-1956. Improve log in MiniOzoneChaosCluster

e1152e0

mukul1987 reviewed Aug 13, 2019

View reviewed changes

hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java Outdated Show resolved Hide resolved

hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/MiniOzoneLoadGenerator.java Show resolved Hide resolved

HDDS-1956. Pass index to readData to avoid splitting

22d03e7

mukul1987 approved these changes Aug 13, 2019

View reviewed changes

elek added the ozone label Aug 13, 2019

anuengineer closed this Aug 14, 2019

adoroszlai deleted the HDDS-1956 branch August 14, 2019 05:28

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

HDDS-1956. Aged IO Thread exits on first read #1287

HDDS-1956. Aged IO Thread exits on first read #1287

Uh oh!

adoroszlai commented Aug 13, 2019

Uh oh!

adoroszlai commented Aug 13, 2019

Uh oh!

hadoop-yetus commented Aug 13, 2019

Uh oh!

mukul1987 left a comment

Uh oh!

Uh oh!

Uh oh!

mukul1987 left a comment

Uh oh!

hadoop-yetus commented Aug 13, 2019

Uh oh!

avijayanhwx commented Aug 13, 2019

Uh oh!

adoroszlai commented Aug 14, 2019

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

6 participants

HDDS-1956. Aged IO Thread exits on first read #1287

HDDS-1956. Aged IO Thread exits on first read #1287

Uh oh!

Conversation

adoroszlai commented Aug 13, 2019

What changes were proposed in this pull request?

How was this patch tested?

Uh oh!

adoroszlai commented Aug 13, 2019

Uh oh!

hadoop-yetus commented Aug 13, 2019

Uh oh!

mukul1987 left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

mukul1987 left a comment

Choose a reason for hiding this comment

Uh oh!

hadoop-yetus commented Aug 13, 2019

Uh oh!

avijayanhwx commented Aug 13, 2019

Uh oh!

adoroszlai commented Aug 14, 2019

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

6 participants