hedera-services icon indicating copy to clipboard operation
hedera-services copied to clipboard

Published 20 hours ago • verified publisher icon hashgraph

DataFileCommon: Failed to delete test directory

Open alex-kuzmin-hg opened this issue 6 months ago • 1 comments

Description

50 runs of VirtualMap benchmarks (passed, though) reported the following errors in a logs, output/swirlds.log:

grep -E 'ERROR EXCEPTION|WARN  EXCEPTION' swirlds.log | perl -ne 'print "$1\n" if /^.*((WARN|ERROR)\s+EXCEPTION\s.*)$/' | sort | uniq -c | sort -n -k 1 -r
     88 ERROR EXCEPTION        <<merkledb: Compacting #0>> CompactionTask: [vmObjectKeyToPath] Compaction failed
     63 ERROR EXCEPTION        <<benchmark: hasher #0>> CryptographyHolder: CryptographyHolder not initialized, using default config
     50 WARN  EXCEPTION        <<virtual-pipeline: lifecycle #0>> DataFileCommon: Failed to delete test directory [/home/alex.kuzmin/workspaces/hedera-services/platform-sdk/swirlds-benchmarks/./CryptoBench/transferPrefetch/merkledb*****
     18 ERROR EXCEPTION        <<virtual-pipeline: lifecycle #0>> VirtualRootNode: Could not close the dataSource after all copies were destroyed
     15 ERROR EXCEPTION        <com.swirlds.benchmark.CryptoBenchMerkleDb.transferPrefetch-jmh-worker-1> StreamDebugUtils: Deserialization stack trace:
     15 ERROR EXCEPTION        <com.swirlds.benchmark.CryptoBenchMerkleDb.transferPrefetch-jmh-worker-1> StreamDebugUtils: Deserialization re-attempt also encountered a failure.
     15 ERROR EXCEPTION        <com.swirlds.benchmark.CryptoBenchMerkleDb.transferPrefetch-jmh-worker-1> StreamDebugUtils: Deserialization failure. Will re-attempt deserialization with extra debug information.
     12 WARN  EXCEPTION        <<virtual-pipeline: lifecycle #0>> MerkleDbDataSource: Exception while closing Data Source [vm]

2024-08-06 19:59:00.319 1        INFO  STATE_TO_DISK    <com.swirlds.benchmark.CryptoBenchMerkleDb.transferPrefetch-jmh-worker-1> FileUtils: deleting directory /home/alex.kuzmin/workspaces/hedera-services/platform-sdk/swirlds-benchmarks/CryptoBench/tmp
2024-08-06 19:59:01.160 13       ERROR EXCEPTION        <<benchmark: hasher #0>> CryptographyHolder: CryptographyHolder not initialized, using default config
2024-08-06 19:59:02.811 59       WARN  EXCEPTION        <<virtual-pipeline: lifecycle #0>> DataFileCommon: Failed to delete test directory [/home/alex.kuzmin/workspaces/hedera-services/platform-sdk/swirlds-benchmarks/./CryptoBench/transferPrefetch/merkledb2/tables/vm-0]
java.io.UncheckedIOException: java.nio.file.NoSuchFileException: ./CryptoBench/transferPrefetch/merkledb2/tables/vm-0/objectKeyToPath/vm_objectkeytopath_2024-08-06_19-55-56-088_________59.pbj
	at java.base/java.nio.file.FileTreeIterator.fetchNextIfNeeded(FileTreeIterator.java:87) ~[?:?]
	at java.base/java.nio.file.FileTreeIterator.hasNext(FileTreeIterator.java:103) ~[?:?]
	at java.base/java.util.Iterator.forEachRemaining(Iterator.java:132) ~[?:?]
	at java.base/java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1939) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151) ~[?:?]
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[?:?]
	at com.swirlds.merkledb.files.DataFileCommon.deleteDirectoryAndContents(DataFileCommon.java:422) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
	at com.swirlds.merkledb.MerkleDb.closeDataSource(MerkleDb.java:498) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
	at com.swirlds.merkledb.MerkleDbDataSource.close(MerkleDbDataSource.java:736) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
	at com.swirlds.virtualmap.internal.merkle.VirtualRootNode.closeDataSource(VirtualRootNode.java:1015) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
	at com.swirlds.virtualmap.internal.merkle.VirtualRootNode.onShutdown(VirtualRootNode.java:1007) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
	at com.swirlds.virtualmap.internal.pipeline.VirtualPipeline.fireOnShutdown(VirtualPipeline.java:675) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
	at com.swirlds.virtualmap.internal.pipeline.VirtualPipeline.lambda$shutdown$3(VirtualPipeline.java:611) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) ~[?:?]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
	at java.base/java.lang.Thread.run(Thread.java:1583) [?:?]
Caused by: java.nio.file.NoSuchFileException: ./CryptoBench/transferPrefetch/merkledb2/tables/vm-0/objectKeyToPath/vm_objectkeytopath_2024-08-06_19-55-56-088_________59.pbj
	at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92) ~[?:?]
	at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106) ~[?:?]
	at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[?:?]
	at java.base/sun.nio.fs.UnixFileAttributeViews$Basic.readAttributes(UnixFileAttributeViews.java:55) ~[?:?]
	at java.base/sun.nio.fs.UnixFileSystemProvider.readAttributes(UnixFileSystemProvider.java:171) ~[?:?]
	at java.base/sun.nio.fs.LinuxFileSystemProvider.readAttributes(LinuxFileSystemProvider.java:99) ~[?:?]
	at java.base/java.nio.file.Files.readAttributes(Files.java:1853) ~[?:?]
	at java.base/java.nio.file.FileTreeWalker.getAttributes(FileTreeWalker.java:220) ~[?:?]
	at java.base/java.nio.file.FileTreeWalker.visit(FileTreeWalker.java:277) ~[?:?]
	at java.base/java.nio.file.FileTreeWalker.next(FileTreeWalker.java:374) ~[?:?]
	at java.base/java.nio.file.FileTreeIterator.fetchNextIfNeeded(FileTreeIterator.java:83) ~[?:?]
	... 21 more

2024-08-06 17:57:44.075 285      WARN  EXCEPTION        <<virtual-pipeline: lifecycle #0>> MerkleDbDataSource: Exception while closing Data Source [vm]
2024-08-06 17:57:44.075 286      ERROR EXCEPTION        <<virtual-pipeline: lifecycle #0>> VirtualRootNode: Could not close the dataSource after all copies were destroyed
java.io.UncheckedIOException: java.nio.file.NoSuchFileException: data/CryptoBench/transferPrefetch/merkledb30/database_metadata.pbj
        at com.swirlds.merkledb.MerkleDb.storeMetadata(MerkleDb.java:629) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.merkledb.MerkleDb.closeDataSource(MerkleDb.java:499) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.merkledb.MerkleDbDataSource.close(MerkleDbDataSource.java:736) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.virtualmap.internal.merkle.VirtualRootNode.closeDataSource(VirtualRootNode.java:1015) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.virtualmap.internal.merkle.VirtualRootNode.onShutdown(VirtualRootNode.java:1007) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.virtualmap.internal.pipeline.VirtualPipeline.fireOnShutdown(VirtualPipeline.java:675) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.virtualmap.internal.pipeline.VirtualPipeline.lambda$shutdown$3(VirtualPipeline.java:611) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) ~[?:?]
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
        at java.base/java.lang.Thread.run(Thread.java:1583) [?:?]
Caused by: java.nio.file.NoSuchFileException: data/CryptoBench/transferPrefetch/merkledb30/database_metadata.pbj
        at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92) ~[?:?]
        at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106) ~[?:?]
        at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[?:?]
        at java.base/sun.nio.fs.UnixFileSystemProvider.newByteChannel(UnixFileSystemProvider.java:261) ~[?:?]
        at java.base/java.nio.file.spi.FileSystemProvider.newOutputStream(FileSystemProvider.java:482) ~[?:?]
        at java.base/java.nio.file.Files.newOutputStream(Files.java:227) ~[?:?]
        at com.swirlds.merkledb.MerkleDb.storeMetadata(MerkleDb.java:622) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        ... 11 more

2024-08-06 18:34:43.498 211      ERROR EXCEPTION        <<merkledb: Compacting #0>> CompactionTask: [vmObjectKeyToPath] Compaction failed
java.nio.file.NoSuchFileException: ./CryptoBench/transferPrefetch/merkledb11/tables/vm-0/objectKeyToPath/vm_objectkeytopath_2024-08-06_18-34-43-133_________16.pbj
        at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92) ~[?:?]
        at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106) ~[?:?]
        at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[?:?]
        at java.base/sun.nio.fs.UnixFileSystemProvider.newFileChannel(UnixFileSystemProvider.java:224) ~[?:?]
        at java.base/java.nio.channels.FileChannel.open(FileChannel.java:309) ~[?:?]
        at java.base/java.nio.channels.FileChannel.open(FileChannel.java:369) ~[?:?]
        at com.swirlds.merkledb.files.DataFileWriter.finishWriting(DataFileWriter.java:245) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.merkledb.files.DataFileCompactor.finishCurrentCompactionFile(DataFileCompactor.java:332) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.merkledb.files.DataFileCompactor.compactFiles(DataFileCompactor.java:279) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.merkledb.files.DataFileCompactor.compact(DataFileCompactor.java:429) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.merkledb.MerkleDbCompactionCoordinator$CompactionTask.call(MerkleDbCompactionCoordinator.java:248) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.merkledb.MerkleDbCompactionCoordinator$CompactionTask.call(MerkleDbCompactionCoordinator.java:241) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
        at java.base/java.lang.Thread.run(Thread.java:1583) [?:?]

2024-08-06 19:59:25.503 4        ERROR EXCEPTION        <com.swirlds.benchmark.CryptoBenchMerkleDb.transferPrefetch-jmh-worker-1> StreamDebugUtils: Deserialization failure. Will re-attempt deserialization with extra debug information.
java.io.EOFException: null
        at java.base/java.io.DataInputStream.readFully(DataInputStream.java:210) ~[?:?]
        at java.base/java.io.DataInputStream.readLong(DataInputStream.java:407) ~[?:?]
        at com.swirlds.common.io.streams.AugmentedDataInputStream.readLong(AugmentedDataInputStream.java:174) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.common.io.streams.SerializableDataInputStream.readSerializable(SerializableDataInputStream.java:179) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.common.io.streams.SerializableDataInputStream.readSerializable(SerializableDataInputStream.java:88) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.common.io.streams.SerializableDataInputStream.readSerializable(SerializableDataInputStream.java:102) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.virtualmap.VirtualMap.lambda$loadFromFile$1(VirtualMap.java:367) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.common.io.streams.StreamDebugUtils.deserializeAndDebugOnFailure(StreamDebugUtils.java:82) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.virtualmap.VirtualMap.loadFromFile(VirtualMap.java:364) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.virtualmap.VirtualMap.deserialize(VirtualMap.java:345) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.benchmark.VirtualMapBaseBench.restoreMap(VirtualMapBaseBench.java:346) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.benchmark.VirtualMapBaseBench.createMap(VirtualMapBaseBench.java:122) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.benchmark.CryptoBench.transferPrefetch(CryptoBench.java:212) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.benchmark.jmh_generated.CryptoBenchMerkleDb_transferPrefetch_jmhTest.transferPrefetch_avgt_jmhStub(CryptoBenchMerkleDb_transferPrefetch_jmhTest.java:203) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.benchmark.jmh_generated.CryptoBenchMerkleDb_transferPrefetch_jmhTest.transferPrefetch_AverageTime(CryptoBenchMerkleDb_transferPrefetch_jmhTest.java:161) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ~[?:?]
        at java.base/java.lang.reflect.Method.invoke(Method.java:580) ~[?:?]
        at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:527) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:504) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) ~[?:?]
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
        at java.base/java.lang.Thread.run(Thread.java:1583) [?:?]
2024-08-06 19:59:25.509 5        ERROR EXCEPTION        <com.swirlds.benchmark.CryptoBenchMerkleDb.transferPrefetch-jmh-worker-1> StreamDebugUtils: Deserialization re-attempt also encountered a failure.
java.io.EOFException: null
        at java.base/java.io.DataInputStream.readFully(DataInputStream.java:210) ~[?:?]
        at java.base/java.io.DataInputStream.readLong(DataInputStream.java:407) ~[?:?]
        at com.swirlds.common.io.streams.AugmentedDataInputStream.readLong(AugmentedDataInputStream.java:174) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.common.io.streams.DebuggableMerkleDataInputStream.readLong(DebuggableMerkleDataInputStream.java:363) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.common.io.streams.SerializableDataInputStream.readSerializable(SerializableDataInputStream.java:179) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.common.io.streams.SerializableDataInputStream.readSerializable(SerializableDataInputStream.java:88) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.common.io.streams.SerializableDataInputStream.readSerializable(SerializableDataInputStream.java:102) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.common.io.streams.DebuggableMerkleDataInputStream.readSerializable(DebuggableMerkleDataInputStream.java:640) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.virtualmap.VirtualMap.lambda$loadFromFile$1(VirtualMap.java:367) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.common.io.streams.StreamDebugUtils.deserializeAndDebugOnFailure(StreamDebugUtils.java:93) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.virtualmap.VirtualMap.loadFromFile(VirtualMap.java:364) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.virtualmap.VirtualMap.deserialize(VirtualMap.java:345) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.benchmark.VirtualMapBaseBench.restoreMap(VirtualMapBaseBench.java:346) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.benchmark.VirtualMapBaseBench.createMap(VirtualMapBaseBench.java:122) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.benchmark.CryptoBench.transferPrefetch(CryptoBench.java:212) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.benchmark.jmh_generated.CryptoBenchMerkleDb_transferPrefetch_jmhTest.transferPrefetch_avgt_jmhStub(CryptoBenchMerkleDb_transferPrefetch_jmhTest.java:203) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at com.swirlds.benchmark.jmh_generated.CryptoBenchMerkleDb_transferPrefetch_jmhTest.transferPrefetch_AverageTime(CryptoBenchMerkleDb_transferPrefetch_jmhTest.java:161) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ~[?:?]
        at java.base/java.lang.reflect.Method.invoke(Method.java:580) ~[?:?]
        at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:527) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:504) ~[swirlds-benchmarks-0.53.0-jmh.jar:?]
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) ~[?:?]
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]

Steps to reproduce

java -jar build/libs/swirlds-benchmarks-0.53.0-jmh.jar --jvmArgs '-XX:+UseZGC -XX:+ZGenerational -XX:ZAllocationSpikeTolerance=2 -XX:ConcGCThreads=14 -XX:ZMarkStackSpaceLimit=16g -XX:MaxDirectMemorySize=64g -Xmx118g -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints -XX:+PreserveFramePointer' CryptoBenchMerkleDb.transferPrefetch -p maxKey=50 -p numRecords=10 -p keySize=24 -p recordSize=1024 -p numFiles=6

Additional context

Hedera network

other

Version

v0.53.0

Operating system

Linux

alex-kuzmin-hg avatar Aug 06 '24 21:08 alex-kuzmin-hg