Shopkeepers

Shopkeepers

2M Downloads

The server has not responded for 10 seconds by trade log

DahunDev opened this issue ยท 4 comments

commented

Preliminaries: trading log occansinally causes severe lag.

  • Shopkeepers version: ` 2.2.2
  • Spigot version: `

Paper version git-Paper-1618 (MC: 1.12.2) (Implementing API
version 1.12.2-R0.1-SNAPSHOT)


[22:54:34] [Paper Watchdog Thread/ERROR]: --- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH ---
[22:54:34] [Paper Watchdog Thread/ERROR]: The server has not responded for 10 seconds! Creating thread dump
[22:54:34] [Paper Watchdog Thread/ERROR]: ------------------------------
[22:54:34] [Paper Watchdog Thread/ERROR]: Server thread dump (Look for plugins here before reporting to Paper!):
[22:54:34] [Paper Watchdog Thread/ERROR]: ------------------------------
[22:54:34] [Paper Watchdog Thread/ERROR]: Current Thread: Server thread
[22:54:34] [Paper Watchdog Thread/ERROR]: PID: 19 | Suspended: false | Native: true | State: RUNNABLE
[22:54:34] [Paper Watchdog Thread/ERROR]: Stack:
[22:54:34] [Paper Watchdog Thread/ERROR]: java.io.FileOutputStream.writeBytes(Native Method)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.io.FileOutputStream.write(Unknown Source)
[22:54:34] [Paper Watchdog Thread/ERROR]: sun.nio.cs.StreamEncoder.writeBytes(Unknown Source)
[22:54:34] [Paper Watchdog Thread/ERROR]: sun.nio.cs.StreamEncoder.implClose(Unknown Source)
[22:54:34] [Paper Watchdog Thread/ERROR]: sun.nio.cs.StreamEncoder.close(Unknown Source)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.io.OutputStreamWriter.close(Unknown Source)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.io.BufferedWriter.close(Unknown Source)
[22:54:34] [Paper Watchdog Thread/ERROR]: com.nisovin.shopkeepers.tradelogging.TradeFileLogger.onTradeCompleted(TradeFileLogger.java:79)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.lang.invoke.LambdaForm$DMH/846072718.invokeVirtual_LL_V(LambdaForm$DMH)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.lang.invoke.LambdaForm$BMH/1290266887.reinvoke(LambdaForm$BMH)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.lang.invoke.LambdaForm$MH/1242251180.invoke_MT(LambdaForm$MH)
[22:54:34] [Paper Watchdog Thread/ERROR]: com.destroystokyo.paper.event.executor.MethodHandleEventExecutor.execute(MethodHandleEventExecutor.java:35)
[22:54:34] [Paper Watchdog Thread/ERROR]: co.aikar.timings.TimedEventExecutor.execute(TimedEventExecutor.java:78)
[22:54:34] [Paper Watchdog Thread/ERROR]: org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62)
[22:54:34] [Paper Watchdog Thread/ERROR]: org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:513)
[22:54:34] [Paper Watchdog Thread/ERROR]: com.nisovin.shopkeepers.ui.defaults.TradingHandler.handleTrade(TradingHandler.java:469)
[22:54:34] [Paper Watchdog Thread/ERROR]: com.nisovin.shopkeepers.ui.defaults.TradingHandler.onInventoryClick(TradingHandler.java:288)
[22:54:34] [Paper Watchdog Thread/ERROR]: com.nisovin.shopkeepers.ui.UIListener.onInventoryClick(UIListener.java:79)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.lang.invoke.LambdaForm$DMH/846072718.invokeVirtual_LL_V(LambdaForm$DMH)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.lang.invoke.LambdaForm$BMH/372854525.reinvoke(LambdaForm$BMH)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.lang.invoke.LambdaForm$MH/1242251180.invoke_MT(LambdaForm$MH)
[22:54:34] [Paper Watchdog Thread/ERROR]: com.destroystokyo.paper.event.executor.MethodHandleEventExecutor.execute(MethodHandleEventExecutor.java:35)
[22:54:34] [Paper Watchdog Thread/ERROR]: co.aikar.timings.TimedEventExecutor.execute(TimedEventExecutor.java:78)
[22:54:34] [Paper Watchdog Thread/ERROR]: org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62)
[22:54:34] [Paper Watchdog Thread/ERROR]: org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:513)
[22:54:34] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_12_R1.PlayerConnection.a(PlayerConnection.java:2002)
[22:54:34] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_12_R1.PacketPlayInWindowClick.a(SourceFile:33)
[22:54:34] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_12_R1.PacketPlayInWindowClick.a(SourceFile:10)
[22:54:34] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_12_R1.PlayerConnectionUtils.lambda$ensureMainThread$0(PlayerConnectionUtils.java:14)
[22:54:34] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_12_R1.PlayerConnectionUtils$$Lambda$420/1377178872.run(Unknown Source)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.util.concurrent.FutureTask.run(Unknown Source)
[22:54:34] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_12_R1.SystemUtils.a(SourceFile:46)
[22:54:34] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_12_R1.MinecraftServer.D(MinecraftServer.java:850)
[22:54:34] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_12_R1.DedicatedServer.D(DedicatedServer.java:423)
[22:54:34] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_12_R1.MinecraftServer.C(MinecraftServer.java:774)
[22:54:34] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_12_R1.MinecraftServer.run(MinecraftServer.java:666)
[22:54:34] [Paper Watchdog Thread/ERROR]: java.lang.Thread.run(Unknown Source)
[22:54:34] [Paper Watchdog Thread/ERROR]: ------------------------------
[22:54:34] [Paper Watchdog Thread/ERROR]: --- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH ---
[22:54:34] [Paper Watchdog Thread/ERROR]: ------------------------------
[22:54:39] [Paper Watchdog Thread/ERROR]: --- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH ---
[22:54:39] [Paper Watchdog Thread/ERROR]: The server has not responded for 15 seconds! Creating thread dump
[22:54:39] [Paper Watchdog Thread/ERROR]: ------------------------------
[22:54:39] [Paper Watchdog Thread/ERROR]: Server thread dump (Look for plugins here before reporting to Paper!):
[22:54:39] [Paper Watchdog Thread/ERROR]: ------------------------------
[22:54:39] [Paper Watchdog Thread/ERROR]: Current Thread: Server thread
[22:54:39] [Paper Watchdog Thread/ERROR]: PID: 19 | Suspended: false | Native: true | State: RUNNABLE
[22:54:39] [Paper Watchdog Thread/ERROR]: Stack:
[22:54:39] [Paper Watchdog Thread/ERROR]: java.io.FileOutputStream.writeBytes(Native Method)
[22:54:39] [Paper Watchdog Thread/ERROR]: java.io.FileOutputStream.write(Unknown Source)
[22:54:39] [Paper Watchdog Thread/ERROR]: sun.nio.cs.StreamEncoder.writeBytes(Unknown Source)
[22:54:39] [Paper Watchdog Thread/ERROR]: sun.nio.cs.StreamEncoder.implClose(Unknown Source)
[22:54:39] [Paper Watchdog Thread/ERROR]: sun.nio.cs.StreamEncoder.close(Unknown Source)
[22:54:39] [Paper Watchdog Thread/ERROR]: java.io.OutputStreamWriter.close(Unknown Source)
[22:54:39] [Paper Watchdog Thread/ERROR]: java.io.BufferedWriter.close(Unknown Source)
[22:54:39] [Paper Watchdog Thread/ERROR]: com.nisovin.shopkeepers.tradelogging.TradeFileLogger.onTradeCompleted(TradeFileLogger.java:79)
[22:54:39] [Paper Watchdog Thread/ERROR]: java.lang.invoke.LambdaForm$DMH/846072718.invokeVirtual_LL_V(LambdaForm$DMH)
[22:54:39] [Paper Watchdog Thread/ERROR]: java.lang.invoke.LambdaForm$BMH/1290266887.reinvoke(LambdaForm$BMH)
[22:54:39] [Paper Watchdog Thread/ERROR]: java.lang.invoke.LambdaForm$MH/1242251180.invoke_MT(LambdaForm$MH)

commented

I am not really sure what's going on. Are you able to reproduce this issue? How many players do you have on your server potentially trading with shopkeepers when this happens? How large are your trading log files?

My guess is that something else on your system is locking the trade log file. In windows, if you have the file explorer open, it will sometimes lock files in it preventing other programs from writing to them. Or some other program (backup, file viewer, ..) might locking the file. However, so far I was not able to reproduce this.

If you regularly run into this you could also increase the timeout inside the spigot.yml config, so that the server at least does not crash..
Other than that I don't really know how to help, since I do not know for sure what the problem here is or how to reproduce this. And if it is a file locking issues, I do not know what else is going on your server, potentially accessing and thereby locking this file.

commented

There have been some improvements to the CSV trade logging in v2.13.0: Among other improvements, writting to the CSV files is now done asynchronously. However, although this might then no longer block the main thread, this won't help if some other process is locking the save file.
Anyways, I consider this issue to be resolved with these changes.

commented

Is 2.13.0 work for 1.12.2?
It shows only works above 1.13.2

commented

Is 2.13.0 work for 1.12.2?
It shows only works above 1.13.2

It only works on 1.14.4 and above.