Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Temp folder on wrapper does not exist and synchronization bug in templatestorage #1294

Open
1 task done
DasBabyPixel opened this issue Aug 19, 2023 · 2 comments · May be fixed by #1298
Open
1 task done

Temp folder on wrapper does not exist and synchronization bug in templatestorage #1294

DasBabyPixel opened this issue Aug 19, 2023 · 2 comments · May be fixed by #1298
Labels
s: confirmed The described bug was reported multiple times and/or is reproduceable t: bug Something isn't working as intended v: 4.X This pull should be included in the 4.0 release

Comments

@DasBabyPixel
Copy link

DasBabyPixel commented Aug 19, 2023

Stacktrace

[19.08 22:16:09.618] INFO: [woolbattletest-1] [22:16:08 WARN]: java.nio.file.NoSuchFileException: temp/36a3d5b9-1500-47b6-b388-f7f17912c9fa
[19.08 22:16:09.619] INFO: [woolbattletest-1] [22:16:08 WARN]:  at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92)
[19.08 22:16:09.620] INFO: [woolbattletest-1] [22:16:08 WARN]:  at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106)
[19.08 22:16:09.620] INFO: [woolbattletest-1] [22:16:08 WARN]:  at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111)
[19.08 22:16:09.620] INFO: [woolbattletest-1] [22:16:08 WARN]:  at java.base/sun.nio.fs.UnixFileSystemProvider.newByteChannel(UnixFileSystemProvider.java:218)
[19.08 22:16:09.621] INFO: [woolbattletest-1] [22:16:08 WARN]:  at java.base/java.nio.file.Files.newByteChannel(Files.java:380)
[19.08 22:16:09.621] INFO: [woolbattletest-1] [22:16:08 WARN]:  at java.base/java.nio.file.Files.newByteChannel(Files.java:432)
[19.08 22:16:09.622] INFO: [woolbattletest-1] [22:16:08 WARN]:  at java.base/java.nio.file.spi.FileSystemProvider.newInputStream(FileSystemProvider.java:422)
[19.08 22:16:09.622] INFO: [woolbattletest-1] [22:16:08 WARN]:  at java.base/java.nio.file.Files.newInputStream(Files.java:160)
[19.08 22:16:09.622] INFO: [woolbattletest-1] [22:16:08 WARN]:  at eu.cloudnetservice.driver.template.defaults.RemoteTemplateStorage.zipTemplate(RemoteTemplateStorage.java:130)
[19.08 22:16:09.623] INFO: [woolbattletest-1] [22:16:08 WARN]:  at eu.cloudnetservice.driver.template.TemplateStorage.lambda$openZipInputStreamAsync$4(TemplateStorage.java:364)
[19.08 22:16:09.623] INFO: [woolbattletest-1] [22:16:08 WARN]:  at eu.cloudnetservice.common.concurrent.Task.lambda$supply$1(Task.java:71)
[19.08 22:16:09.623] INFO: [woolbattletest-1] [22:16:08 WARN]:  at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
[19.08 22:16:09.624] INFO: [woolbattletest-1] [22:16:08 WARN]:  at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[19.08 22:16:09.624] INFO: [woolbattletest-1] [22:16:08 WARN]:  at java.base/java.lang.Thread.run(Thread.java:833)
[19.08 22:16:09.624] INFO: [woolbattletest-1] [22:16:08 ERROR]: Exception whilst handling packet BasePacket(channel=2, dataBuf=eu.cloudnetservice.driver.network.netty.buffer.NettyImmutableDataBuf@5eed4a8b, prioritized=false, creationStamp=2023-08-19T20:16:08.834766040Z, uniqueId=null)
[19.08 22:16:09.625] INFO: [woolbattletest-1] java.lang.IllegalStateException: Exception posting packet from channel 2 to handler eu.cloudnetservice.driver.network.chunk.network.ChunkedPacketListener
[19.08 22:16:09.625] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.protocol.defaults.DefaultPacketListenerRegistry.handlePacket(DefaultPacketListenerRegistry.java:178) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.625] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.protocol.defaults.DefaultPacketListenerRegistry.handlePacket(DefaultPacketListenerRegistry.java:165) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.626] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.netty.NettyNetworkHandler.doHandlePacket(NettyNetworkHandler.java:123) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.626] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.netty.NettyNetworkHandler.lambda$messageReceived$0(NettyNetworkHandler.java:95) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.626] INFO: [woolbattletest-1]   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
[19.08 22:16:09.627] INFO: [woolbattletest-1]   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
[19.08 22:16:09.627] INFO: [woolbattletest-1]   at java.lang.Thread.run(Thread.java:833) [?:?]
[19.08 22:16:09.627] INFO: [woolbattletest-1] Caused by: eu.cloudnetservice.driver.event.EventListenerException: Error while invoking event listener handle in class eu.cloudnetservice.wrapper.network.chunk.TemplateStorageCallbackListener
[19.08 22:16:09.628] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.event.DefaultRegisteredEventListener.fireEvent(DefaultRegisteredEventListener.java:102) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.628] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.event.DefaultEventManager.callEvent(DefaultEventManager.java:80) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.628] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.event.EventManager.callEvent(EventManager.java:75) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.629] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.chunk.defaults.factory.EventChunkHandlerFactory.apply(EventChunkHandlerFactory.java:71) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.629] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.chunk.defaults.factory.EventChunkHandlerFactory.apply(EventChunkHandlerFactory.java:32) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.630] INFO: [woolbattletest-1]   at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1708) ~[?:?]
[19.08 22:16:09.630] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.chunk.network.ChunkedPacketListener.handle(ChunkedPacketListener.java:59) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.630] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.protocol.defaults.DefaultPacketListenerRegistry.handlePacket(DefaultPacketListenerRegistry.java:176) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.630] INFO: [woolbattletest-1]   ... 6 more
[19.08 22:16:09.631] INFO: [woolbattletest-1] Caused by: java.lang.AssertionError: Unable to open raf to temp file, this should not happen
[19.08 22:16:09.631] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.chunk.defaults.DefaultFileChunkedPacketHandler.<init>(DefaultFileChunkedPacketHandler.java:93) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.632] INFO: [woolbattletest-1]   at eu.cloudnetservice.wrapper.network.chunk.TemplateStorageCallbackListener.handle(TemplateStorageCallbackListener.java:33) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.632] INFO: [woolbattletest-1]   at dev.derklaro.reflexion.internal.handles.MethodHandleAccessorFactory$MethodHandleMethodAccessor.lambda$invoke$1(MethodHandleAccessorFactory.java:396) ~[reflexion-1.8.0.jar:?]
[19.08 22:16:09.633] INFO: [woolbattletest-1]   at dev.derklaro.reflexion.Result.tryExecute(Result.java:80) ~[reflexion-1.8.0.jar:?]
[19.08 22:16:09.633] INFO: [woolbattletest-1]   at dev.derklaro.reflexion.internal.handles.MethodHandleAccessorFactory$MethodHandleMethodAccessor.invoke(MethodHandleAccessorFactory.java:394) ~[reflexion-1.8.0.jar:?]
[19.08 22:16:09.633] INFO: [woolbattletest-1]   at dev.derklaro.reflexion.internal.handles.MethodHandleAccessorFactory$MethodHandleMethodAccessor.invokeWithArgs(MethodHandleAccessorFactory.java:380) ~[reflexion-1.8.0.jar:?]
[19.08 22:16:09.634] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.event.DefaultRegisteredEventListener.fireEvent(DefaultRegisteredEventListener.java:96) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.634] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.event.DefaultEventManager.callEvent(DefaultEventManager.java:80) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.635] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.event.EventManager.callEvent(EventManager.java:75) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.635] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.chunk.defaults.factory.EventChunkHandlerFactory.apply(EventChunkHandlerFactory.java:71) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.635] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.chunk.defaults.factory.EventChunkHandlerFactory.apply(EventChunkHandlerFactory.java:32) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.636] INFO: [woolbattletest-1]   at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1708) ~[?:?]
[19.08 22:16:09.636] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.chunk.network.ChunkedPacketListener.handle(ChunkedPacketListener.java:59) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.636] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.protocol.defaults.DefaultPacketListenerRegistry.handlePacket(DefaultPacketListenerRegistry.java:176) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.637] INFO: [woolbattletest-1]   ... 6 more
[19.08 22:16:09.637] INFO: [woolbattletest-1] Caused by: java.nio.file.NoSuchFileException: temp/36a3d5b9-1500-47b6-b388-f7f17912c9fa
[19.08 22:16:09.637] INFO: [woolbattletest-1]   at sun.nio.fs.UnixException.translateToIOException(UnixException.java:92) ~[?:?]
[19.08 22:16:09.638] INFO: [woolbattletest-1]   at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106) ~[?:?]
[19.08 22:16:09.638] INFO: [woolbattletest-1]   at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[?:?]
[19.08 22:16:09.638] INFO: [woolbattletest-1]   at sun.nio.fs.UnixFileSystemProvider.newByteChannel(UnixFileSystemProvider.java:218) ~[?:?]
[19.08 22:16:09.639] INFO: [woolbattletest-1]   at java.nio.file.Files.newByteChannel(Files.java:380) ~[?:?]
[19.08 22:16:09.639] INFO: [woolbattletest-1]   at java.nio.file.Files.createFile(Files.java:658) ~[?:?]
[19.08 22:16:09.640] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.chunk.defaults.DefaultFileChunkedPacketHandler.<init>(DefaultFileChunkedPacketHandler.java:88) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.640] INFO: [woolbattletest-1]   at eu.cloudnetservice.wrapper.network.chunk.TemplateStorageCallbackListener.handle(TemplateStorageCallbackListener.java:33) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.640] INFO: [woolbattletest-1]   at dev.derklaro.reflexion.internal.handles.MethodHandleAccessorFactory$MethodHandleMethodAccessor.lambda$invoke$1(MethodHandleAccessorFactory.java:396) ~[reflexion-1.8.0.jar:?]
[19.08 22:16:09.641] INFO: [woolbattletest-1]   at dev.derklaro.reflexion.Result.tryExecute(Result.java:80) ~[reflexion-1.8.0.jar:?]
[19.08 22:16:09.641] INFO: [woolbattletest-1]   at dev.derklaro.reflexion.internal.handles.MethodHandleAccessorFactory$MethodHandleMethodAccessor.invoke(MethodHandleAccessorFactory.java:394) ~[reflexion-1.8.0.jar:?]
[19.08 22:16:09.642] INFO: [woolbattletest-1]   at dev.derklaro.reflexion.internal.handles.MethodHandleAccessorFactory$MethodHandleMethodAccessor.invokeWithArgs(MethodHandleAccessorFactory.java:380) ~[reflexion-1.8.0.jar:?]
[19.08 22:16:09.642] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.event.DefaultRegisteredEventListener.fireEvent(DefaultRegisteredEventListener.java:96) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.643] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.event.DefaultEventManager.callEvent(DefaultEventManager.java:80) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.643] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.event.EventManager.callEvent(EventManager.java:75) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.644] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.chunk.defaults.factory.EventChunkHandlerFactory.apply(EventChunkHandlerFactory.java:71) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.644] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.chunk.defaults.factory.EventChunkHandlerFactory.apply(EventChunkHandlerFactory.java:32) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.644] INFO: [woolbattletest-1]   at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1708) ~[?:?]
[19.08 22:16:09.645] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.chunk.network.ChunkedPacketListener.handle(ChunkedPacketListener.java:59) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.645] INFO: [woolbattletest-1]   at eu.cloudnetservice.driver.network.protocol.defaults.DefaultPacketListenerRegistry.handlePacket(DefaultPacketListenerRegistry.java:176) ~[wrapper.jar:4.0.0-RC9-f6ca4c38]
[19.08 22:16:09.645] INFO: [woolbattletest-1]   ... 6 more

Actions to reproduce

Try to open a template as a ZipInputStream from a wrapper
templateStorageProvider.localTemplateStorage().openZipInputStreamAsync(ServiceTemplate.parse("proxy/default"))

CloudNet version

[19.08 22:10:36.283] INFO:
[19.08 22:10:36.283] INFO: CloudNet Blizzard 4.0.0-RC9 f6ca4c3
[19.08 22:10:36.283] INFO: Discord: https://discord.cloudnetservice.eu/
[19.08 22:10:36.283] INFO:
[19.08 22:10:36.284] INFO: ClusterId: 0cac9bb5--45dd--5d9b389b1b0f
[19.08 22:10:36.284] INFO: NodeId: Node-768d8079
[19.08 22:10:36.284] INFO: Head-NodeId: Node-768d8079
[19.08 22:10:36.284] INFO: CPU usage: (P/S) .23/7.21/100%
[19.08 22:10:36.284] INFO: Node services memory allocation (U/R/M): 2524/2524/6000 MB
[19.08 22:10:36.284] INFO: Threads: 50
[19.08 22:10:36.284] INFO: Heap usage: 40/256MB
[19.08 22:10:36.284] INFO: JVM: Eclipse Adoptium 17 (OpenJDK 64-Bit Server VM 17.0.6+10)
[19.08 22:10:36.285] INFO: Update Repo: CloudNetService/launchermeta, Update Branch: beta (development mode)
[19.08 22:10:36.285] INFO:

Other

Template might need to be a few MB in size, very small sizes might not trigger the synchronization bug, but for larger sizes it is triggered for sure and the first Exception gets called.
The second exception is a bug where the temp directory doesn't exist in the wrapper.

The two exceptions are in the same bug report because they go hand in hand here and here.

The synchronization bug I mean is that the ChannelMessage query returns before the upload/download has finished and the file has been released.

The first exception is before the second in the console. Order is kind of important here...

I need this kind of urgently which is why I would offer to make a PR.
Adding something like mkdirs for the temp folder should suffice for stacktrace 2.

For stacktrace 1 I'd probably redirect the future (after the received query use a future[callback?] from the DefaultFileChunkedPacketHandler. )
Another option I though of (to make it more future-proof) is some sort of confirmation from the receiving end of DefaultFileChunkedPacketSender.

Let me know if I should do this, or if the TemplateStorage API not working is enough to get this to the top of your guys' todo-list :)

Issue uniqueness

  • Yes, this issue is unique. There are no similar issues.
@DasBabyPixel DasBabyPixel added s: needs triage Issue waiting for triage t: bug Something isn't working as intended labels Aug 19, 2023
@0utplay 0utplay added v: 4.X This pull should be included in the 4.0 release s: confirmed The described bug was reported multiple times and/or is reproduceable and removed s: needs triage Issue waiting for triage labels Aug 20, 2023
@0utplay
Copy link
Member

0utplay commented Aug 20, 2023

Thanks for the issue. If you want to create a PR we would appreciate that

@DasBabyPixel
Copy link
Author

I have been investigating a little bit and it seems this issue occurs because there are multiple PacketDispatcher threads on the wrapper. Everything is sent in the right order from the node, but the channelmessage queryresult gets read on one packetdispatcher while a second packetdispatcher is still writing to the temporary file.
Btw: This issue should also apply to file transfers from wrapper to node.

The core issue is: The requesting ChannelMessage gets answered before writing to the file has finished

There are multiple options to solve this:

The future from #transferChunkedData may only return after the receiver has finished receiving the file, not the sender sending.
This requires the receiver to send a confirmation packet

The other option is for the receiver to cache the request in form of a future (similar to how ChannelMessage Queries work). The receiver then, after receiving the queryResult has to wait for the cached request.
The cached request is filled from the TemplateStorageCallbackListener. This options does not require any additional protocol (which is why I prefer it), however it might be a pain because the RemoteTemplateStorage is not in the wrapper, but in the driver (So the zipTemplate would have to store the cached request in a class in the driver)
To that end it might make sense to either move the RemoteTemplateStorage to the wrapper (because it is only used in there) or the TemplateStorageCallbackListener to the driver because they are both a part of the same API (And don't work without eachother).

Just wanted to ask if there is a preferred way of doing this before coding it and the PR getting rejected for sth.
Also if I overlooked sth or there is a better way you know please don't hold back

DasBabyPixel added a commit to DasBabyPixel/CloudNet-v3 that referenced this issue Aug 20, 2023
@DasBabyPixel DasBabyPixel linked a pull request Aug 20, 2023 that will close this issue
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
s: confirmed The described bug was reported multiple times and/or is reproduceable t: bug Something isn't working as intended v: 4.X This pull should be included in the 4.0 release
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants