HADOOP-17670. S3AFS and ABFS to log IOStats at DEBUG mode or optionally at INFO level in close() #2963

mehakmeet · 2021-04-27T17:54:16Z

Tested on S3AFS and ABFS.
Region for S3AFS: ap-south-1
Region for ABFS: East US

Don't know if we need any tests for these?

S3A(trunk also) showed these errors I haven't seen before:

[ERROR] testListEmptyRootDirectory(org.apache.hadoop.fs.contract.s3a.ITestS3AContractRootDir)  Time elapsed: 16.79 s  <<< FAILURE!
java.lang.AssertionError: Deleted file: unexpectedly found s3a://mehakmeet-singh-data/Users as  S3AFileStatus{path=s3a://mehakmeet-singh-data/Users; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null
	at org.junit.Assert.fail(Assert.java:89)
	at org.apache.hadoop.fs.contract.ContractTestUtils.assertPathDoesNotExist(ContractTestUtils.java:1004)
	at org.apache.hadoop.fs.contract.ContractTestUtils.assertDeleted(ContractTestUtils.java:733)
	at org.apache.hadoop.fs.contract.AbstractContractRootDirectoryTest.testListEmptyRootDirectory(AbstractContractRootDirectoryTest.java:196)
	at org.apache.hadoop.fs.contract.s3a.ITestS3AContractRootDir.testListEmptyRootDirectory(ITestS3AContractRootDir.java:82)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:61)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:288)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:282)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:748)

[ERROR] testRmEmptyRootDirNonRecursive(org.apache.hadoop.fs.contract.s3a.ITestS3AContractRootDir)  Time elapsed: 30.584 s  <<< FAILURE!
java.lang.AssertionError:
After 12 attempts: listing after rm /* not empty
final [00] S3AFileStatus{path=s3a://mehakmeet-singh-data/Users; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null
[01] S3AFileStatus{path=s3a://mehakmeet-singh-data/user; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null

deleted [00] S3AFileStatus{path=s3a://mehakmeet-singh-data/Users; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null
[01] S3AFileStatus{path=s3a://mehakmeet-singh-data/user; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null

original [00] S3AFileStatus{path=s3a://mehakmeet-singh-data/file.txt; isDirectory=false; length=0; replication=1; blocksize=33554432; modification_time=1619544154000; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rw-rw-rw-; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=d41d8cd98f00b204e9800998ecf8427e versionId=null
[01] S3AFileStatus{path=s3a://mehakmeet-singh-data/Users; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null
[02] S3AFileStatus{path=s3a://mehakmeet-singh-data/fork-0001; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null
[03] S3AFileStatus{path=s3a://mehakmeet-singh-data/fork-0002; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null
[04] S3AFileStatus{path=s3a://mehakmeet-singh-data/path; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null
[05] S3AFileStatus{path=s3a://mehakmeet-singh-data/test; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null
[06] S3AFileStatus{path=s3a://mehakmeet-singh-data/tests3ascale; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null
[07] S3AFileStatus{path=s3a://mehakmeet-singh-data/user; isDirectory=true; modification_time=0; access_time=0; owner=mehakmeet.singh; group=mehakmeet.singh; permission=rwxrwxrwx; isSymlink=false; hasAcl=false; isEncrypted=true; isErasureCoded=false} isEmptyDirectory=FALSE eTag=null versionId=null

	at org.junit.Assert.fail(Assert.java:89)
	at org.apache.hadoop.fs.contract.AbstractContractRootDirectoryTest$1.call(AbstractContractRootDirectoryTest.java:109)

…ly at INFO level in close()

mehakmeet · 2021-05-05T11:09:55Z

Don't know if we need any tests for these?

@steveloughran

steveloughran

looks ok, some suggested changes. Key one is supporting error and warn too, in case we ever need them.

...ools/hadoop-azure/src/main/java/org/apache/hadoop/fs/azurebfs/services/AbfsOutputStream.java

hadoop-tools/hadoop-azure/src/main/java/org/apache/hadoop/fs/azurebfs/AzureBlobFileSystem.java

...project/hadoop-common/src/main/java/org/apache/hadoop/fs/statistics/IOStatisticsLogging.java

hadoop-yetus · 2021-05-21T06:32:56Z

🎊 +1 overall

Vote	Subsystem	Runtime	Logfile	Comment
+0 🆗	reexec	0m 34s		Docker mode activated.
			_ Prechecks _
+1 💚	dupname	0m 0s		No case conflicting files found.
+0 🆗	codespell	0m 1s		codespell was not available.
+1 💚	@author	0m 0s		The patch does not contain any @author tags.
+1 💚	test4tests	0m 0s		The patch appears to include 1 new or modified test files.
			_ trunk Compile Tests _
+0 🆗	mvndep	16m 16s		Maven dependency ordering for branch
+1 💚	mvninstall	20m 22s		trunk passed
+1 💚	compile	20m 48s		trunk passed with JDK Ubuntu-11.0.10+9-Ubuntu-0ubuntu1.20.04
+1 💚	compile	18m 6s		trunk passed with JDK Private Build-1.8.0_282-8u282-b08-0ubuntu1~20.04-b08
+1 💚	checkstyle	3m 50s		trunk passed
+1 💚	mvnsite	3m 21s		trunk passed
+1 💚	javadoc	2m 25s		trunk passed with JDK Ubuntu-11.0.10+9-Ubuntu-0ubuntu1.20.04
+1 💚	javadoc	3m 7s		trunk passed with JDK Private Build-1.8.0_282-8u282-b08-0ubuntu1~20.04-b08
+1 💚	spotbugs	4m 47s		trunk passed
+1 💚	shadedclient	14m 34s		branch has no errors when building and testing our client artifacts.
			_ Patch Compile Tests _
+0 🆗	mvndep	0m 26s		Maven dependency ordering for patch
+1 💚	mvninstall	1m 57s		the patch passed
+1 💚	compile	20m 6s		the patch passed with JDK Ubuntu-11.0.10+9-Ubuntu-0ubuntu1.20.04
+1 💚	javac	20m 6s		the patch passed
+1 💚	compile	18m 7s		the patch passed with JDK Private Build-1.8.0_282-8u282-b08-0ubuntu1~20.04-b08
+1 💚	javac	18m 7s		the patch passed
+1 💚	blanks	0m 0s		The patch has no blanks issues.
+1 💚	checkstyle	3m 40s		the patch passed
+1 💚	mvnsite	3m 19s		the patch passed
+1 💚	javadoc	2m 22s		the patch passed with JDK Ubuntu-11.0.10+9-Ubuntu-0ubuntu1.20.04
+1 💚	javadoc	3m 1s		the patch passed with JDK Private Build-1.8.0_282-8u282-b08-0ubuntu1~20.04-b08
+1 💚	spotbugs	5m 23s		the patch passed
+1 💚	shadedclient	14m 51s		patch has no errors when building and testing our client artifacts.
			_ Other Tests _
+1 💚	unit	17m 5s		hadoop-common in the patch passed.
+1 💚	unit	2m 2s		hadoop-aws in the patch passed.
+1 💚	unit	2m 15s		hadoop-azure in the patch passed.
+1 💚	asflicense	0m 51s		The patch does not generate ASF License warnings.
		207m 31s

Subsystem	Report/Notes
Docker	ClientAPI=1.41 ServerAPI=1.41 base: https://ci-hadoop.apache.org/job/hadoop-multibranch/job/PR-2963/5/artifact/out/Dockerfile
GITHUB PR	#2963
Optional Tests	dupname asflicense compile javac javadoc mvninstall mvnsite unit shadedclient spotbugs checkstyle codespell
uname	Linux 0d821a6b2076 4.15.0-58-generic #64-Ubuntu SMP Tue Aug 6 11:12:41 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
Build tool	maven
Personality	dev-support/bin/hadoop.sh
git revision	trunk / `8d6c2a6`
Default Java	Private Build-1.8.0_282-8u282-b08-0ubuntu1~20.04-b08
Multi-JDK versions	/usr/lib/jvm/java-11-openjdk-amd64:Ubuntu-11.0.10+9-Ubuntu-0ubuntu1.20.04 /usr/lib/jvm/java-8-openjdk-amd64:Private Build-1.8.0_282-8u282-b08-0ubuntu1~20.04-b08
Test Results	https://ci-hadoop.apache.org/job/hadoop-multibranch/job/PR-2963/5/testReport/
Max. process+thread count	1297 (vs. ulimit of 5500)
modules	C: hadoop-common-project/hadoop-common hadoop-tools/hadoop-aws hadoop-tools/hadoop-azure U: .
Console output	https://ci-hadoop.apache.org/job/hadoop-multibranch/job/PR-2963/5/console
versions	git=2.25.1 maven=3.6.3 spotbugs=4.2.2
Powered by	Apache Yetus 0.14.0-SNAPSHOT https://yetus.apache.org

This message was automatically generated.

steveloughran

I think a log4j ref has crept into the IOStatistics code. We have to keep log4j stuff restricted to unit tests only (and there it complicates the plan to move to log4j 2)

steveloughran · 2021-05-24T11:30:05Z

...project/hadoop-common/src/main/java/org/apache/hadoop/fs/statistics/IOStatisticsLogging.java

 import org.apache.hadoop.classification.InterfaceAudience;
 import org.apache.hadoop.classification.InterfaceStability;
 import org.apache.hadoop.fs.statistics.impl.IOStatisticsBinding;
+import org.apache.log4j.Level;


needs to use SLF4J. Is this an accidental import?

Accidentally added it, removed it in the latest commit.

steveloughran · 2021-05-24T11:55:11Z

sorry, thought I was reviewing the combined changes not the first one.

+1, merging

…ly at INFO level in close() (#2963) When the S3A and ABFS filesystems are closed, their IOStatistics are logged at debug in the log: org.apache.hadoop.fs.statistics.IOStatisticsLogging Set `fs.iostatistics.logging.level` to `info` for the statistics to be logged at info. (also: `warn` or `error` for even higher log levels). Contributed by: Mehakmeet Singh Change-Id: I56d44ad89fc1c0dd4baf701681834e7fd96c544f

…ly at INFO level in close() (apache#2963) When the S3A and ABFS filesystems are closed, their IOStatistics are logged at debug in the log: org.apache.hadoop.fs.statistics.IOStatisticsLogging Set `fs.iostatistics.logging.level` to `info` for the statistics to be logged at info. (also: `warn` or `error` for even higher log levels). Contributed by: Mehakmeet Singh

… or optionally at INFO level in close() (apache#2963) When the S3A and ABFS filesystems are closed, their IOStatistics are logged at debug in the log: org.apache.hadoop.fs.statistics.IOStatisticsLogging Set `fs.iostatistics.logging.level` to `info` for the statistics to be logged at info. (also: `warn` or `error` for even higher log levels). Contributed by: Mehakmeet Singh Conflicts: hadoop-tools/hadoop-azure/src/main/java/org/apache/hadoop/fs/azurebfs/AzureBlobFileSystem.java hadoop-tools/hadoop-azure/src/main/java/org/apache/hadoop/fs/azurebfs/services/AbfsOutputStream.java Change-Id: I08212a127c2b7a053b2842e15c95ba16a378d663

…ly at INFO level in close() (apache#2963) When the S3A and ABFS filesystems are closed, their IOStatistics are logged at debug in the log: org.apache.hadoop.fs.statistics.IOStatisticsLogging Set `fs.iostatistics.logging.level` to `info` for the statistics to be logged at info. (also: `warn` or `error` for even higher log levels). Contributed by: Mehakmeet Singh Change-Id: I56d44ad89fc1c0dd4baf701681834e7fd96c544f

Mehakmeet Singh added 2 commits April 27, 2021 19:33

HADOOP-17670. S3AFS and ABFS to log IOStats at DEBUG mode or optional…

26b24ed

…ly at INFO level in close()

HADOOP-17670. checkstyle fix

ade21c7

steveloughran requested changes May 14, 2021

View reviewed changes

Mehakmeet Singh added 2 commits May 20, 2021 14:26

HADOOP-17670. Adding error and warn log levels + steve comments

42cbaf8

HADOOP-17670. checkstyles

8d6c2a6

mehakmeet requested a review from steveloughran May 24, 2021 05:22

apache deleted a comment from hadoop-yetus May 24, 2021

steveloughran requested changes May 24, 2021

View reviewed changes

steveloughran merged commit c665ab0 into apache:trunk May 24, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

HADOOP-17670. S3AFS and ABFS to log IOStats at DEBUG mode or optionally at INFO level in close() #2963

HADOOP-17670. S3AFS and ABFS to log IOStats at DEBUG mode or optionally at INFO level in close() #2963

Uh oh!

mehakmeet commented Apr 27, 2021

Uh oh!

mehakmeet commented May 5, 2021

Uh oh!

steveloughran left a comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

hadoop-yetus commented May 21, 2021

Uh oh!

steveloughran left a comment

Uh oh!

steveloughran May 24, 2021

Uh oh!

mehakmeet May 24, 2021

Uh oh!

steveloughran commented May 24, 2021

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

HADOOP-17670. S3AFS and ABFS to log IOStats at DEBUG mode or optionally at INFO level in close() #2963

HADOOP-17670. S3AFS and ABFS to log IOStats at DEBUG mode or optionally at INFO level in close() #2963

Uh oh!

Conversation

mehakmeet commented Apr 27, 2021

Uh oh!

mehakmeet commented May 5, 2021

Uh oh!

steveloughran left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

hadoop-yetus commented May 21, 2021

Uh oh!

steveloughran left a comment

Choose a reason for hiding this comment

Uh oh!

steveloughran May 24, 2021

Choose a reason for hiding this comment

Uh oh!

mehakmeet May 24, 2021

Choose a reason for hiding this comment

Uh oh!

steveloughran commented May 24, 2021

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants