[ 
https://issues.apache.org/jira/browse/HADOOP-17267?focusedWorklogId=489641&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-489641
 ]

ASF GitHub Bot logged work on HADOOP-17267:
-------------------------------------------

                Author: ASF GitHub Bot
            Created on: 23/Sep/20 15:57
            Start Date: 23/Sep/20 15:57
    Worklog Time Spent: 10m 
      Work Description: klcopp edited a comment on pull request #2321:
URL: https://github.com/apache/hadoop/pull/2321#issuecomment-697590522


   @steveloughran  Here's what TRACE-level logs (DEBUG-level included, of 
course) look like:
   
   ```
   closeAll:
   
   [main] DEBUG org.apache.hadoop.fs.FileSystem  - FileSystem.closeAll() called 
by method: 
org.apache.hadoop.fs.TestFileSystem.testFsCache(TestFileSystem.java:525); 
   [main] TRACE org.apache.hadoop.fs.FileSystem  - FileSystem.closeAll() full 
stack trace:
   java.lang.Throwable
        at 
org.apache.hadoop.fs.FileSystem.debugLogFileSystemClose(FileSystem.java:649)
        at org.apache.hadoop.fs.FileSystem.closeAll(FileSystem.java:625)
        at 
org.apache.hadoop.fs.TestFileSystem.testFsCache(TestFileSystem.java:525)
        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:50)
        at 
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
        at 
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
        at 
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
        at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
        at 
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
        at 
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
        at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
        at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
        at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
        at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
        at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
        at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
        at 
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
        at 
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
        at 
org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
        at 
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
   
   close:
   
   [main] DEBUG org.apache.hadoop.fs.FileSystem  - FileSystem.close() called by 
method: org.apache.hadoop.fs.FilterFileSystem.close(FilterFileSystem.java:524); 
Key: (foo (auth:SIMPLE))@file://; Object Identity Hash: 35645047
   [main] TRACE org.apache.hadoop.fs.FileSystem  - FileSystem.close() full 
stack trace:
   java.lang.Throwable
        at 
org.apache.hadoop.fs.FileSystem.debugLogFileSystemClose(FileSystem.java:649)
        at org.apache.hadoop.fs.FileSystem.close(FileSystem.java:2590)
        at 
org.apache.hadoop.fs.FilterFileSystem.close(FilterFileSystem.java:524)
        at org.apache.hadoop.fs.FileSystem$Cache.closeAll(FileSystem.java:3580)
        at org.apache.hadoop.fs.FileSystem$Cache.closeAll(FileSystem.java:3551)
        at org.apache.hadoop.fs.FileSystem.closeAll(FileSystem.java:627)
        at 
org.apache.hadoop.fs.TestFileSystem.testFsCache(TestFileSystem.java:525)
        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:50)
        at 
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
        at 
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
        at 
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
        at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
        at 
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
        at 
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
        at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
        at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
        at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
        at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
        at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
        at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
        at 
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
        at 
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
        at 
org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
        at 
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
   
   closeAllForUGI:
   
   [main] DEBUG org.apache.hadoop.fs.FileSystem  - FileSystem.closeAllForUGI() 
called by method: 
org.apache.hadoop.fs.TestFileSystemCaching.testCloseAllForUGI(TestFileSystemCaching.java:231);
 UGI: foo (auth:SIMPLE)
   [main] TRACE org.apache.hadoop.fs.FileSystem  - FileSystem.closeAllForUGI() 
full stack trace:
   java.lang.Throwable
        at 
org.apache.hadoop.fs.FileSystem.debugLogFileSystemClose(FileSystem.java:649)
        at org.apache.hadoop.fs.FileSystem.closeAllForUGI(FileSystem.java:639)
        at 
org.apache.hadoop.fs.TestFileSystemCaching.testCloseAllForUGI(TestFileSystemCaching.java:231)
        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:50)
        at 
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
        at 
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
        at 
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
        at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
        at 
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
        at 
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
        at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
        at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
        at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
        at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
        at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
        at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
        at 
org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
        at 
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
        at 
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
        at 
org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
        at 
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
   
   ```


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
[email protected]


Issue Time Tracking
-------------------

    Worklog Id:     (was: 489641)
    Time Spent: 2.5h  (was: 2h 20m)

> Add debug-level logs in Filesystem#close
> ----------------------------------------
>
>                 Key: HADOOP-17267
>                 URL: https://issues.apache.org/jira/browse/HADOOP-17267
>             Project: Hadoop Common
>          Issue Type: Improvement
>          Components: fs
>    Affects Versions: 3.3.0
>            Reporter: Karen Coppage
>            Priority: Minor
>              Labels: pull-request-available
>          Time Spent: 2.5h
>  Remaining Estimate: 0h
>
> HDFS reuses the same cached FileSystem object across the file system. If the 
> client calls FileSystem.close(), closeAllForUgi(), or closeAll() (if it 
> applies to the instance) anywhere in the system it purges the cache of that 
> FS instance, and trying to use the instance results in an IOException: 
> FileSystem closed.
> It would be a great help to clients to see where and when a given FS instance 
> was closed. I.e. in close(), closeAllForUgi(), or closeAll(), it would be 
> great to see a DEBUG-level log of
>  * calling method name, class, file name/line number
>  * FileSystem object's identity hash (FileSystem.close() only)



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to