Connection failure to Redis results in all commands failing

persistence/RedisDataSource.java と、スタックトレースに示されている Jedis の接続経路から開始し、その後、障害がどのように PersistenceNetwork と UserManager に到達するかを追跡します。persistance.ini の Redis 設定を使用してタイムアウトを再現し、最初の JedisConnectionException と後続の ClassCastException を比較します。Redis 接続が失われても後続のコマンドが妨げられず、手動で /reloadaliases を実行しなくても接続の復旧が処理されれば完了です。

CMDHELPER-2954 - Reported by TerrorBite

==Issue==
Initially a {{JedisConnectionException}} is thrown when the connection is lost (for whatever reason). There is apparently no attempt made to reestablish connection. Subsequently, any and all access to Redis attempted by CommandHelper (including automatic access to the {{user.**}} namespace) raises a {{ClassCastException}}.

Due to the above, this error prevents all commands from being run, not just aliases, and therefore is a serious issue (workaround would be to edit persistance.ini to direct requests for {{user.**}} to another database format such as sqlite or ser).

CMDHELPER-2829 has now been open for six months. However, the issue continues to occur even in recent builds. This is build 2705, and there have been no Redis-related commits since that build. I am opening this as a new bug since the codebase has changed since CMDHELPER-2829 was submitted.

==Details==
Server version: 1.7.9-R0.3-SNAPSHOT;
CommandHelper version: 3.3.1-SNAPSHOT:2705-136485b,master;
Loaded extensions and versions:
Core (version 3.3.1);
Redis server version: 2.4.10 (00000000:0)

yaml|title=persistance.ini contains**=redis://localhost:6379?timeout=90

==Observations==

• If the {{user.**}} namespace is configured for storage via Redis), then exceptions are thrown for all commands run, not just aliases. As a result, no commands can be run successfully by players.
• The Redis connection is not re-established automatically - manual intervention is required.

==Possible Workarounds==

• Run {{/reloadaliases}} whenever these errors occur to re-establish normal server operation.
• Attempt to use a higher timeout for Redis to reduce the probability of the Redis server closing the connection for idleness. This will not prevent the issue from occurring if the connection fails for a different reason.
• Map the {{user.**}} namespace to non-Redis storage in {{persistance.ini}}. This should prevent normal commands from generating exceptions when the Redis connection fails, however any aliases that use {{get_value()}} will still fail.
• Don't use Redis at all - this negates the advantages of using Redis, which is probably the most suitable storage backend for the CommandHelper Persistance Network when large volumes of data are being stored and accessed.
• A watchdog script could be written in MScript {color:SaddleBrown}[''Edit: this has now been implemented, see comments'']{color}, running code similar to {{try(get_value('test'), ...)}} on a timer in an attempt to detect a failed connection and run {{/reloadaliases}} automatically. The initial JedisConnectionException raises an MScript {{IOException}}, allowing it to be caught by {{try()}}. It should be possible for this code to also catch the subsequent {{CastException}}s, if these are also converted into their MScript equivalent.

==Case Study / Server Logs==
In this case study, a user's attempt to run a CommandHelper alias containing a {{get_value()}} call fails as the Redis connection has timed out. [http://puu.sh/9lu1C/ebfafe1615.jpg Screenshot from the user's point of view]. Subsequently, another user's attempt to run /back (a regular command) generates a {{ClassCastException}} from CommandHelper's {{onPlayerCommandPreprocess()}} handler, presumably while attempting to access {{user.Greekktofreakk2.aliases.back}} to look for a user alias.

{cut Server log}```

[16:29:00 INFO]: aequoris issued server command: /vanilla
[16:29:00 INFO]: CH: Running original command on player aequoris ----> /vanilla
[16:29:00 INFO]: IOException: com.laytonsmith.libs.redis.clients.jedis.exceptions.JedisConnectionException: java.net.SocketTimeoutException: Read timed out
proc _import_get:/data/minecraft/1.7-survival/plugins/CommandHelper/auto_include.ms:249
proc _changeserver:/data/minecraft/1.7-survival/plugins/CommandHelper/LocalPackages/bungee/auto_include.ms:20
<

>:/data/minecraft/1.7-survival/plugins/CommandHelper/LocalPackages/bungee/bungee.msa:36
[16:29:00 INFO]: [D]~Greekk: I'm actually crying
[16:29:02 INFO]: Greekktofreakk2 issued server command: /back
[16:29:02 WARN]:
java.lang.ClassCastException: [B cannot be cast to java.util.List
at com.laytonsmith.libs.redis.clients.jedis.Connection.getBinaryMultiBulkReply(Connection.java:202)
at com.laytonsmith.libs.redis.clients.jedis.Jedis.keys(Jedis.java:171)
at com.laytonsmith.persistence.RedisDataSource.keySet(RedisDataSource.java:161)
at com.laytonsmith.persistence.AbstractDataSource.stringKeySet(AbstractDataSource.java:156)
at com.laytonsmith.persistence.AbstractDataSource.getNamespace(AbstractDataSource.java:166)
at com.laytonsmith.persistence.AbstractDataSource.getValues0(AbstractDataSource.java:89)
at com.laytonsmith.persistence.AbstractDataSource.getValues(AbstractDataSource.java:79)
at com.laytonsmith.persistence.ThreadsafeDataSource.getValues(ThreadsafeDataSource.java:75)
at com.laytonsmith.persistence.PersistenceNetwork.getNamespace(PersistenceNetwork.java:169)
at com.laytonsmith.core.UserManager.getAllScripts(UserManager.java:131)
at com.laytonsmith.commandhelper.CommandHelperListener.runAlias(CommandHelperListener.java:90)
at com.laytonsmith.commandhelper.CommandHelperListener.onPlayerCommandPreprocess(CommandHelperListener.java:137)
at sun.reflect.GeneratedMethodAccessor292.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.bukkit.plugin.java.JavaPluginLoader$1.execute(JavaPluginLoader.java:292)
at org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62)
at org.bukkit.plugin.TimedRegisteredListener.callEvent(TimedRegisteredListener.java:47)
at org.bukkit.plugin.SimplePluginManager.fireEvent(SimplePluginManager.java:502)
at org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:487)
at net.minecraft.server.v1_7_R3.PlayerConnection.handleCommand(PlayerConnection.java:991)
at net.minecraft.server.v1_7_R3.PlayerConnection.a(PlayerConnection.java:830)
at net.minecraft.server.v1_7_R3.PacketPlayInChat.a(PacketPlayInChat.java:28)
at net.minecraft.server.v1_7_R3.PacketPlayInChat.handle(PacketPlayInChat.java:65)
at net.minecraft.server.v1_7_R3.NetworkManager.a(NetworkManager.java:180)
at net.minecraft.server.v1_7_R3.ServerConnection.c(ServerConnection.java:81)
at net.minecraft.server.v1_7_R3.MinecraftServer.v(MinecraftServer.java:720)
at net.minecraft.server.v1_7_R3.DedicatedServer.v(DedicatedServer.java:283)
at net.minecraft.server.v1_7_R3.MinecraftServer.u(MinecraftServer.java:583)
at net.minecraft.server.v1_7_R3.MinecraftServer.run(MinecraftServer.java:489)
at net.minecraft.server.v1_7_R3.ThreadServerApplication.run(SourceFile:628)

From here on, many commands throw similar exceptions and fail to execute when run.

The original user again attempts to run the alias, generating a more detailed error:
{cut Server log}```

[16:29:50 INFO]: aequoris issued server command: /vanilla
[16:29:50 INFO]: CH: Running original command on player aequoris ----> /vanilla
[16:29:50 ERROR]: Uh oh! You've found an error in Core.
This is an error caused while running your code, so you may be able to find a workaround, but is ultimately an error in Core itself.
The line of code that caused the error was this:
@key = 'vanilla.whitelist.aequoris'
get_value(@key)
on or around /data/minecraft/1.7-survival/plugins/CommandHelper/auto_include.ms:249.
Please report this error to the developers, and be sure to include the version numbers:
Server version: 1.7.9-R0.3-SNAPSHOT;
CommandHelper version: 3.3.1-SNAPSHOT:2705-136485b,master;
Loaded extensions and versions:
Core (version 3.3.1);
Here's the stacktrace:
java.lang.ClassCastException: java.util.ArrayList cannot be cast to [B
        at com.laytonsmith.libs.redis.clients.jedis.Connection.getBinaryBulkReply(Connection.java:185)
        at com.laytonsmith.libs.redis.clients.jedis.Connection.getBulkReply(Connection.java:174)
        at com.laytonsmith.libs.redis.clients.jedis.Jedis.get(Jedis.java:77)
        at com.laytonsmith.persistence.RedisDataSource.get0(RedisDataSource.java:143)
        at com.laytonsmith.persistence.AbstractDataSource.get(AbstractDataSource.java:73)
        at com.laytonsmith.persistence.ThreadsafeDataSource.get(ThreadsafeDataSource.java:70)
        at com.laytonsmith.persistence.PersistenceNetwork.get(PersistenceNetwork.java:104)
        at com.laytonsmith.core.functions.Persistence$get_value.exec(Persistence.java:176)
        at com.laytonsmith.core.Script.eval(Script.java:352)
        at com.laytonsmith.core.Script.eval(Script.java:321)
        at com.laytonsmith.core.Script.eval(Script.java:321)
        at com.laytonsmith.core.functions.BasicLogic$ifelse.execs(BasicLogic.java:690)
        at com.laytonsmith.core.Script.eval(Script.java:311)
        at com.laytonsmith.core.Procedure.execute(Procedure.java:201)
        at com.laytonsmith.core.Procedure.cexecute(Procedure.java:158)
        at com.laytonsmith.core.Script.eval(Script.java:280)
        at com.laytonsmith.core.Script.eval(Script.java:321)
        at com.laytonsmith.core.Script.eval(Script.java:321)
        at com.laytonsmith.core.functions.BasicLogic$ifelse.execs(BasicLogic.java:690)
        at com.laytonsmith.core.Script.eval(Script.java:311)
        at com.laytonsmith.core.Procedure.execute(Procedure.java:201)
        at com.laytonsmith.core.Procedure.cexecute(Procedure.java:158)
        at com.laytonsmith.core.Script.eval(Script.java:280)
        at com.laytonsmith.core.Script.eval(Script.java:321)
        at com.laytonsmith.core.MethodScriptCompiler.execute(MethodScriptCompiler.java:1857)
        at com.laytonsmith.core.MethodScriptCompiler.execute(MethodScriptCompiler.java:1814)
        at com.laytonsmith.core.Script.run(Script.java:193)
        at com.laytonsmith.core.AliasCore.alias(AliasCore.java:167)
        at com.laytonsmith.commandhelper.CommandHelperListener.runAlias(CommandHelperListener.java:92)
        at com.laytonsmith.commandhelper.CommandHelperListener.onPlayerCommandPreprocess(CommandHelperListener.java:137)
        at sun.reflect.GeneratedMethodAccessor292.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
        at java.lang.reflect.Method.invoke(Unknown Source)
        at org.bukkit.plugin.java.JavaPluginLoader$1.execute(JavaPluginLoader.java:292)
        at org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62)
        at org.bukkit.plugin.TimedRegisteredListener.callEvent(TimedRegisteredListener.java:47)
        at org.bukkit.plugin.SimplePluginManager.fireEvent(SimplePluginManager.java:502)
        at org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:487)
        at net.minecraft.server.v1_7_R3.PlayerConnection.handleCommand(PlayerConnection.java:991)
        at net.minecraft.server.v1_7_R3.PlayerConnection.a(PlayerConnection.java:830)
        at net.minecraft.server.v1_7_R3.PacketPlayInChat.a(PacketPlayInChat.java:28)
        at net.minecraft.server.v1_7_R3.PacketPlayInChat.handle(PacketPlayInChat.java:65)
        at net.minecraft.server.v1_7_R3.NetworkManager.a(NetworkManager.java:180)
        at net.minecraft.server.v1_7_R3.ServerConnection.c(ServerConnection.java:81)
        at net.minecraft.server.v1_7_R3.MinecraftServer.v(MinecraftServer.java:720)
        at net.minecraft.server.v1_7_R3.DedicatedServer.v(DedicatedServer.java:283)
        at net.minecraft.server.v1_7_R3.MinecraftServer.u(MinecraftServer.java:583)
        at net.minecraft.server.v1_7_R3.MinecraftServer.run(MinecraftServer.java:489)
        at net.minecraft.server.v1_7_R3.ThreadServerApplication.run(SourceFile:628)

```{cut}

An exception is thrown for a typo'd command that does not exist, demonstrating that the issue affects all commands.
{cut Server log}```

[16:46:15 INFO]: redworm668 issued server command: /waep rhelp
[16:46:15 WARN]:
java.lang.ClassCastException: java.lang.Long cannot be cast to java.util.List
       at com.laytonsmith.libs.redis.clients.jedis.Connection.getBinaryMultiBulkReply(Connection.java:202)
       at com.laytonsmith.libs.redis.clients.jedis.Jedis.keys(Jedis.java:171)
       at com.laytonsmith.persistence.RedisDataSource.keySet(RedisDataSource.java:161)
       at com.laytonsmith.persistence.AbstractDataSource.stringKeySet(AbstractDataSource.java:156)
       at com.laytonsmith.persistence.AbstractDataSource.getNamespace(AbstractDataSource.java:166)
       at com.laytonsmith.persistence.AbstractDataSource.getValues0(AbstractDataSource.java:89)
       at com.laytonsmith.persistence.AbstractDataSource.getValues(AbstractDataSource.java:79)
       at com.laytonsmith.persistence.ThreadsafeDataSource.getValues(ThreadsafeDataSource.java:75)
       at com.laytonsmith.persistence.PersistenceNetwork.getNamespace(PersistenceNetwork.java:169)
       at com.laytonsmith.core.UserManager.getAllScripts(UserManager.java:131)
       at com.laytonsmith.commandhelper.CommandHelperListener.runAlias(CommandHelperListener.java:90)
       at com.laytonsmith.commandhelper.CommandHelperListener.onPlayerCommandPreprocess(CommandHelperListener.java:137)
       at sun.reflect.GeneratedMethodAccessor292.invoke(Unknown Source)
       at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
       at java.lang.reflect.Method.invoke(Unknown Source)
       at org.bukkit.plugin.java.JavaPluginLoader$1.execute(JavaPluginLoader.java:292)
       at org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62)
       at org.bukkit.plugin.TimedRegisteredListener.callEvent(TimedRegisteredListener.java:47)
       at org.bukkit.plugin.SimplePluginManager.fireEvent(SimplePluginManager.java:502)
       at org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:487)
       at net.minecraft.server.v1_7_R3.PlayerConnection.handleCommand(PlayerConnection.java:991)
       at net.minecraft.server.v1_7_R3.PlayerConnection.a(PlayerConnection.java:830)
       at net.minecraft.server.v1_7_R3.PacketPlayInChat.a(PacketPlayInChat.java:28)
       at net.minecraft.server.v1_7_R3.PacketPlayInChat.handle(PacketPlayInChat.java:65)
       at net.minecraft.server.v1_7_R3.NetworkManager.a(NetworkManager.java:180)
       at net.minecraft.server.v1_7_R3.ServerConnection.c(ServerConnection.java:81)
       at net.minecraft.server.v1_7_R3.MinecraftServer.v(MinecraftServer.java:720)
       at net.minecraft.server.v1_7_R3.DedicatedServer.v(DedicatedServer.java:283)
       at net.minecraft.server.v1_7_R3.MinecraftServer.u(MinecraftServer.java:583)
       at net.minecraft.server.v1_7_R3.MinecraftServer.run(MinecraftServer.java:489)
       at net.minecraft.server.v1_7_R3.ThreadServerApplication.run(SourceFile:628)

```{cut}

Exceptions continue to be thrown until {{/reloadaliases}} is run, whereupon CommandHelper reloads itself and in the process, the Redis connection is reestablished.