dCache/dcache — pull request #1128 by gbehrmann (2014-11-27 10:08:55+00:00)
Title: pool: Fix ISE when flushing deleted file

Prior to flushing a file, the pool checks if the name space entry still exists. If
not, it deletes the replica rather than flushing it to tape. Release 2.10.7 introduced
a regression that causes this code path to throw an ISE:

11:41:01 [pool-28-thread-1] [1f45dec7-f415-4dea-80cb-57c825b51486] Flush of 000084C99C4AC70E4CC38279851A856FABB8 failed with: CacheException(rc=10001;msg=No such file or directory: 000084C99C4AC70E4CC38279851A856FABB8).
11:41:01 [pool-12-thread-2] [1f45dec7-f415-4dea-80cb-57c825b51486] remove entry for: 000084C99C4AC70E4CC38279851A856FABB8
11:41:02 [pool-10-thread-1] [door:GFTP-Gerds-MacBook-Pro-5-AAUHz0KyLFg GFTP-Gerds-MacBook-Pro-5-AAUHz0KyLFg PoolAcceptFile 000084C99C4AC70E4CC38279851A856FABB8] Unexpected failure during state change notificationjava.lang.IllegalStateException: Handle is closed
at org.dcache.pool.repository.v5.ReadHandleImpl.close(ReadHandleImpl.java:48) ~[dcache-core-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
at org.dcache.pool.nearline.NearlineStorageHandler$FlushRequestImpl.failed(NearlineStorageHandler.java:628) ~[dcache-core-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
at org.dcache.pool.nearline.AbstractBlockingNearlineStorage$Task.cancel(AbstractBlockingNearlineStorage.java:200) ~[dcache-core-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
at org.dcache.pool.nearline.AbstractBlockingNearlineStorage.cancel(AbstractBlockingNearlineStorage.java:71) ~[dcache-core-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
at org.dcache.pool.nearline.NearlineStorageHandler$AbstractRequest.cancel(NearlineStorageHandler.java:365) ~[dcache-core-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
at org.dcache.pool.nearline.NearlineStorageHandler$AbstractRequestContainer.cancel(NearlineStorageHandler.java:446) ~[dcache-core-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
at org.dcache.pool.nearline.NearlineStorageHandler.stateChanged(NearlineStorageHandler.java:279) ~[dcache-core-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
at org.dcache.pool.repository.v5.StateChangeListeners$1.run(StateChangeListeners.java:68) ~[dcache-core-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_25]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_25]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_25]

11:41:02 [pool-12-thread-2] [1f45dec7-f415-4dea-80cb-57c825b51486] File not found in name space; removed 000084C99C4AC70E4CC38279851A856FABB8.

This is caused by the pre-flush check deleting the replica followed by failing the flush
request. Deleting the replica subsequently causes a notification to be sent to the HSM
subsystem, which causes the same flush request to be cancelled. The script driver reports
a second failure, thus causing the replica handler to be closed twice - hence the ISE.

The patch fixes the regression.

The log message is also cleaned up to better state what happened:

12:07:39 [pool-28-thread-1] [84967682-8766-4e66-80c3-3199f047b6b2] Flush of 00005466F5DC5AEA4263B3FA8E6EECCCF045 failed with: CacheException(rc=10001;msg=File not found in name space during pre-flush check.).
12:07:39 [pool-12-thread-2] [84967682-8766-4e66-80c3-3199f047b6b2] remove entry for: 00005466F5DC5AEA4263B3FA8E6EECCCF045

Target: trunk
Request: 2.11
Request: 2.10
Require-notes: yes
Require-book: no
Acked-by: Karsten Schwank
Acked-by: Paul Millar
Patch: https://rb.dcache.org/r/7506/
(cherry picked from commit 61dfae7938bbb171d8ac777fb182ef512ff77f5f)