Uploaded image for project: 'Kafka'
  1. Kafka
  2. KAFKA-8172

FileSystemException: The process cannot access the file because it is being used by another process

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Patch Available
    • Major
    • Resolution: Unresolved
    • 1.1.1, 2.2.0, 2.1.1
    • 1.1.1, 2.2.0, 2.1.1
    • core
    • None
    • Windows
    • Patch, Important

    Description

      Fix to close file handlers before renaming files / directories and open them back if required

      Following are the file renaming scenarios:

      • Files are renamed to .deleted so they can be deleted
      • .cleaned files are renamed to .swap as part of Log.replaceSegments flow
      • .swap files are renamed to original files as part of Log.replaceSegments flow

      Following are the folder renaming scenarios:

      • When a topic is marked for deletion, folder is renamed
      • As part of replacing current logs with future logs in LogManager

      In above scenarios, if file handles are not closed, we get file access violation exception

      Idea is to close the logs and file segments before doing a rename and open them back up if required.

      Segments Deletion Scenario

      [2018-06-01 17:00:07,566] ERROR Error while deleting segments for test4-1 in dir D:\data\Kafka\kafka-logs (kafka.server.LogDirFailureChannel)

      java.nio.file.FileSystemException: D:\data\Kafka\kafka-logs\test4-1\00000000000000000000.log -> D:\data\Kafka\kafka-logs\test4-1\00000000000000000000.log.deleted: The process cannot access the file because it is being used by another process.

      at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:86)
      at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
      at sun.nio.fs.WindowsFileCopy.move(WindowsFileCopy.java:387)
      at sun.nio.fs.WindowsFileSystemProvider.move(WindowsFileSystemProvider.java:287)
      at java.nio.file.Files.move(Files.java:1395)
      at org.apache.kafka.common.utils.Utils.atomicMoveWithFallback(Utils.java:697)
      at org.apache.kafka.common.record.FileRecords.renameTo(FileRecords.java:212)
      at kafka.log.LogSegment.changeFileSuffixes(LogSegment.scala:415)
      at kafka.log.Log.kafka$log$Log$$asyncDeleteSegment(Log.scala:1601)
      at kafka.log.Log.kafka$log$Log$$deleteSegment(Log.scala:1588)
      at kafka.log.Log$$anonfun$deleteSegments$1$$anonfun$apply$mcI$sp$1.apply(Log.scala:1170)
      at kafka.log.Log$$anonfun$deleteSegments$1$$anonfun$apply$mcI$sp$1.apply(Log.scala:1170)
      at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59)
      at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48)
      at kafka.log.Log$$anonfun$deleteSegments$1.apply$mcI$sp(Log.scala:1170)
      at kafka.log.Log$$anonfun$deleteSegments$1.apply(Log.scala:1161)
      at kafka.log.Log$$anonfun$deleteSegments$1.apply(Log.scala:1161)
      at kafka.log.Log.maybeHandleIOException(Log.scala:1678)
      at kafka.log.Log.deleteSegments(Log.scala:1161)
      at kafka.log.Log.deleteOldSegments(Log.scala:1156)
      at kafka.log.Log.deleteRetentionMsBreachedSegments(Log.scala:1228)
      at kafka.log.Log.deleteOldSegments(Log.scala:1222)
      at kafka.log.LogManager$$anonfun$cleanupLogs$3.apply(LogManager.scala:854)
      at kafka.log.LogManager$$anonfun$cleanupLogs$3.apply(LogManager.scala:852)
      at scala.collection.TraversableLike$WithFilter$$anonfun$foreach$1.apply(TraversableLike.scala:733)
      at scala.collection.immutable.List.foreach(List.scala:392)
      at scala.collection.TraversableLike$WithFilter.foreach(TraversableLike.scala:732)
      at kafka.log.LogManager.cleanupLogs(LogManager.scala:852)
      at kafka.log.LogManager$$anonfun$startup$1.apply$mcV$sp(LogManager.scala:385)
      at kafka.utils.KafkaScheduler$$anonfun$1.apply$mcV$sp(KafkaScheduler.scala:110)
      at kafka.utils.CoreUtils$$anon$1.run(CoreUtils.scala:62)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)
      Suppressed: java.nio.file.FileSystemException: D:\data\Kafka\kafka-logs\test4-1\00000000000000000000.log -> D:\data\Kafka\kafka-logs\test4-1\00000000000000000000.log.deleted: The process cannot access the file because it is being used by another process.

      at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:86)
      at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
      at sun.nio.fs.WindowsFileCopy.move(WindowsFileCopy.java:301)
      at sun.nio.fs.WindowsFileSystemProvider.move(WindowsFileSystemProvider.java:287)
      at java.nio.file.Files.move(Files.java:1395)
      at org.apache.kafka.common.utils.Utils.atomicMoveWithFallback(Utils.java:694)
      ... 32 more

       

      Topic deletion scenario

      2018-06-07 15:05:17,805] ERROR Error while renaming dir for test5-1 in log dir D:\data\Kafka\kafka-logs (kafka.server.LogDirFailureChannel)
      java.nio.file.AccessDeniedException: D:\data\Kafka\kafka-logs\test5-1 -> D:\data\Kafka\kafka-logs\test5-1.87985bad40e441e1a4d08af4541db7ce-delete
      at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:83)
      at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
      at sun.nio.fs.WindowsFileCopy.move(WindowsFileCopy.java:387)
      at sun.nio.fs.WindowsFileSystemProvider.move(WindowsFileSystemProvider.java:287)
      at java.nio.file.Files.move(Files.java:1395)
      at org.apache.kafka.common.utils.Utils.atomicMoveWithFallback(Utils.java:697)
      at kafka.log.Log$$anonfun$renameDir$1.apply$mcV$sp(Log.scala:579)
      at kafka.log.Log$$anonfun$renameDir$1.apply(Log.scala:577)
      at kafka.log.Log$$anonfun$renameDir$1.apply(Log.scala:577)
      at kafka.log.Log.maybeHandleIOException(Log.scala:1678)
      at kafka.log.Log.renameDir(Log.scala:577)
      at kafka.log.LogManager.asyncDelete(LogManager.scala:813)
      at kafka.cluster.Partition$$anonfun$delete$1.apply(Partition.scala:240)

      at kafka.cluster.Partition$$anonfun$delete$1.apply(Partition.scala:235)
      at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:250)
      at kafka.utils.CoreUtils$.inWriteLock(CoreUtils.scala:258)
      at kafka.cluster.Partition.delete(Partition.scala:235)
      at kafka.server.ReplicaManager.stopReplica(ReplicaManager.scala:347)
      at kafka.server.ReplicaManager$$anonfun$stopReplicas$2.apply(ReplicaManager.scala:377)
      at kafka.server.ReplicaManager$$anonfun$stopReplicas$2.apply(ReplicaManager.scala:375)
      at scala.collection.Iterator$class.foreach(Iterator.scala:891)
      at scala.collection.AbstractIterator.foreach(Iterator.scala:1334)
      at scala.collection.IterableLike$class.foreach(IterableLike.scala:72)
      at scala.collection.AbstractIterable.foreach(Iterable.scala:54)
      at kafka.server.ReplicaManager.stopReplicas(ReplicaManager.scala:375)
      at kafka.server.KafkaApis.handleStopReplicaRequest(KafkaApis.scala:198)
      at kafka.server.KafkaApis.handle(KafkaApis.scala:109)
      at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:69)
      at java.lang.Thread.run(Thread.java:748)
      Suppressed: java.nio.file.AccessDeniedException: D:\data\Kafka\kafka-logs\test5-1 -> D:\data\Kafka\kafka-logs\test5-1.87985bad40e441e1a4d08af4541db7ce-delete
      at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:83)
      at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
      at sun.nio.fs.WindowsFileCopy.move(WindowsFileCopy.java:301)
      at sun.nio.fs.WindowsFileSystemProvider.move(WindowsFileSystemProvider.java:287)
      at java.nio.file.Files.move(Files.java:1395)
      at org.apache.kafka.common.utils.Utils.atomicMoveWithFallback(Utils.java:694)
      ... 23 more

       

      File Compaction Scenario

       [2019-03-11 16:02:00,021] ERROR Error while loading log dir D:\data\Kafka\kafka-datalogs (kafka.log.LogManager)

      java.nio.file.FileSystemException: D:\data\Kafka\kafka-datalogs\kattesttopic-23\00000000000003505795.log: The process cannot access the file because it is being used by another process.

      at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:86)
      at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
      at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:102)
      at sun.nio.fs.WindowsFileCopy.move(WindowsFileCopy.java:376)
      at sun.nio.fs.WindowsFileSystemProvider.move(WindowsFileSystemProvider.java:287)
      at java.nio.file.Files.move(Files.java:1395)
      at org.apache.kafka.common.utils.Utils.atomicMoveWithFallback(Utils.java:697)
      at org.apache.kafka.common.record.FileRecords.renameTo(FileRecords.java:223)
      at kafka.log.LogSegment.changeFileSuffixes(LogSegment.scala:415)
      at kafka.log.Log.replaceSegments(Log.scala:1697)
      at kafka.log.Log$$anonfun$completeSwapOperations$1.apply(Log.scala:391)
      at kafka.log.Log$$anonfun$completeSwapOperations$1.apply(Log.scala:380)
      at scala.collection.immutable.Set$Set1.foreach(Set.scala:94)
      at kafka.log.Log.completeSwapOperations(Log.scala:380)
      at kafka.log.Log.loadSegments(Log.scala:408)
      at kafka.log.Log.<init>(Log.scala:216)
      at kafka.log.Log$.apply(Log.scala:1788)
      at kafka.log.LogManager.kafka$log$LogManager$$loadLog(LogManager.scala:260)
      at kafka.log.LogManager$$anonfun$loadLogs$2$$anonfun$11$$anonfun$apply$15$$anonfun$apply$2.apply$mcV$sp(LogManager.scala:340)
      at kafka.utils.CoreUtils$$anon$1.run(CoreUtils.scala:62)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)
      Suppressed: java.nio.file.AccessDeniedException: D:\data\Kafka\kafka-datalogs\kattesttopic-23\00000000000003505795.log.swap -> D:\data\Kafka\kafka-datalogs\kattesttopic-23\00000000000003505795.log
      at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:83)
      at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
      at sun.nio.fs.WindowsFileCopy.move(WindowsFileCopy.java:301)
      at sun.nio.fs.WindowsFileSystemProvider.move(WindowsFileSystemProvider.java:287)
      at java.nio.file.Files.move(Files.java:1395)
      at org.apache.kafka.common.utils.Utils.atomicMoveWithFallback(Utils.java:694)
      ... 18 more

       

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              kondetibharat Bharat Kondeti
              Votes:
              2 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated: