Strange Errors

[trianglehead]

I have noticed these logs and it's made the server unstable during these times. It's happen a couple of times since I upgraded to Smartfox 2.16 from 2.13. Not sure if that's coincidence. I also moved from Amazon to Linode. Other than that, I haven't changed anything.

One of them looks like a repeated Discord UDP due to packet truncated....this truncated message goes on for an hour or so in the logs.
Then after that finally ends it looks like the log is telling me that same IP is trying to send 773866597 bytes to the server, all sample logs are below.
Not sure what to do. Please advice. Thank you!


User disconnects.. then 3 minutes later it happens:

Code: Select all

21 Jun 2020 | 22:13:33,307 | INFO  | SocketReader | bitswarm.sessions.DefaultSessionManager |     | Session removed: { Id: 1909158, Type: DEFAULT, Logged: Yes, IP: 136.34.145.163:46794 }
21 Jun 2020 | 22:13:33,307 | INFO  | SFSWorker:Sys:1 | v2.api.SFSApi |     | User disconnected: { Zone: [sensored]}, ( User Name: [sensored], Id: 1779068, Priv: 0, Sess: 136.34.145.163:46794 ) , SessionLen: 263095, Type: Unity / .Net
21 Jun 2020 | 22:16:38,583 | WARN  | SFSWorker:Sys:3 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64538, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,583 | WARN  | SFSWorker:Sys:1 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,584 | WARN  | SFSWorker:Sys:1 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64538, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:1 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:2 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:3 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:1 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:3 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64538, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:3 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:3 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:2 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64538, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:3 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:1 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64538, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:2 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64538, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:3 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:1 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64538, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:2 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:3 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:2 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:1 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:2 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64538, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:3 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64538, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:2 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:3 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:1 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64538, reason: Packet truncated. Expected: 8291, only got: 29
21 Jun 2020 | 22:16:38,585 | WARN  | SFSWorker:Sys:2 | v2.protocol.SFSIoHandler |     | Discard UDP packet from 136.34.145.163:64539, reason: Packet truncated. Expected: 8291, only got: 29


Then After that I notice these related logs to the IP.

Code: Select all

21 Jun 2020 | 23:31:53,521 | WARN  | SocketReader | protocol.binary.BinaryIoHandler |     | java.util.zip.DataFormatException:
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
Exception: java.util.zip.DataFormatException
Message: incorrect header check
Sender: { Id: 1934697, Type: DEFAULT, Logged: No, IP: 136.34.145.163:48442 }
+--- --- ---+
Stack Trace:
+--- --- ---+
java.util.zip.Inflater.inflateBytes(Native Method)
java.util.zip.Inflater.inflate(Inflater.java:259)
java.util.zip.Inflater.inflate(Inflater.java:280)
com.smartfoxserver.v2.protocol.binary.DefaultPacketCompressor.uncompress(DefaultPacketCompressor.java:109)
com.smartfoxserver.v2.protocol.binary.BinaryIoHandler.handlePacketData(BinaryIoHandler.java:420)
com.smartfoxserver.v2.protocol.binary.BinaryIoHandler.handleRead(BinaryIoHandler.java:197)
com.smartfoxserver.v2.protocol.SFSIoHandler.onDataRead(SFSIoHandler.java:143)
com.smartfoxserver.bitswarm.core.SocketReader.readTcpData(SocketReader.java:336)
com.smartfoxserver.bitswarm.core.SocketReader.readIncomingSocketData(SocketReader.java:220)
com.smartfoxserver.bitswarm.core.SocketReader.run(SocketReader.java:171)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

21 Jun 2020 | 23:31:53,526 | INFO  | SocketReader | bitswarm.sessions.DefaultSessionManager |     | Session removed: { Id: 1934697, Type: DEFAULT, Logged: No, IP: 136.34.145.163:48442 }
21 Jun 2020 | 23:31:53,527 | WARN  | SocketReader | protocol.binary.BinaryIoHandler |     | java.lang.IllegalArgumentException:
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
Exception: java.lang.IllegalArgumentException
Message: Incoming request size too large: 773866597, Current limit: 500000, From: { Id: 1934697, Type: DEFAULT, Logged: No, IP: 136.34.145.163:48442 }
Sender: { Id: 1934697, Type: DEFAULT, Logged: No, IP: 136.34.145.163:48442 }
+--- --- ---+
Stack Trace:
+--- --- ---+
com.smartfoxserver.v2.protocol.binary.BinaryIoHandler.validateIncomingDataSize(BinaryIoHandler.java:527)
com.smartfoxserver.v2.protocol.binary.BinaryIoHandler.handleDataSize(BinaryIoHandler.java:295)
com.smartfoxserver.v2.protocol.binary.BinaryIoHandler.handleRead(BinaryIoHandler.java:183)
com.smartfoxserver.v2.protocol.SFSIoHandler.onDataRead(SFSIoHandler.java:143)
com.smartfoxserver.bitswarm.core.SocketReader.readTcpData(SocketReader.java:336)
com.smartfoxserver.bitswarm.core.SocketReader.readIncomingSocketData(SocketReader.java:220)
com.smartfoxserver.bitswarm.core.SocketReader.run(SocketReader.java:171)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::


Code: Select all

21 Jun 2020 | 23:31:53,273 | WARN  | SocketReader | protocol.binary.BinaryIoHandler |     | java.lang.IllegalStateException:
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
Exception: java.lang.IllegalStateException
Message: Session does not support encryption: { Id: 1934500, Type: DEFAULT, Logged: No, IP: 136.34.145.163:48418 }
Sender: { Id: 1934500, Type: DEFAULT, Logged: No, IP: 136.34.145.163:48418 }
+--- --- ---+
Stack Trace:
+--- --- ---+
com.smartfoxserver.v2.protocol.binary.DefaultPacketEncrypter.execute(DefaultPacketEncrypter.java:42)
com.smartfoxserver.v2.protocol.binary.DefaultPacketEncrypter.decrypt(DefaultPacketEncrypter.java:22)
com.smartfoxserver.v2.protocol.binary.BinaryIoHandler.handlePacketData(BinaryIoHandler.java:410)
com.smartfoxserver.v2.protocol.binary.BinaryIoHandler.handleRead(BinaryIoHandler.java:197)
com.smartfoxserver.v2.protocol.SFSIoHandler.onDataRead(SFSIoHandler.java:143)
com.smartfoxserver.bitswarm.core.SocketReader.readTcpData(SocketReader.java:336)
com.smartfoxserver.bitswarm.core.SocketReader.readIncomingSocketData(SocketReader.java:220)
com.smartfoxserver.bitswarm.core.SocketReader.run(SocketReader.java:171)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

[Lapo]

Hi,
it looks like someone was spamming bad UDP packets to the server, which rejected them.

Cheers

[trianglehead]

But the server grinded to a halt and most players could not play. What can I do?

Also this

Code: Select all

Exception: java.lang.IllegalArgumentException
Message: Incoming request size too large: 773866597, Current limit: 500000, From: { Id: 1934697, Type: DEFAULT, Logged: No, IP: 136.34.145.163:48442 }

That's a large size, how to prevent that?

[Lapo]

What was going on exactly? Too much CPU usage? Did you check with the AdminTool?

A packet flood can overwhelm the server capacity to keep up, it's called a DDoS. I can't say if this is the case, but from your report it seems a possible explanation.

Has it happened once? Or is it recurring?

Thanks

[trianglehead]

1.) I have atop and sar and longview and the smartfox console. The CPU is not that much affected, if I look on a graph it's only slightly above normal. Just that people are all experiencing massive lag and can't play anymore and disconnect. Only thing I see is that during that hour the disk space usage went up by 10 gigs as you can see in the logs, there's a line in every milliseconds. But the disk ops/s wasn't really affected either. So I can't say it's the CPU, Disk, nor network that's being affected. All I know is there's a "Discard UDP packet from 136.34.145.163" line every milliseconds and people are having connection issues.

2.) It has happened at least 2 times that I'm aware of. I haven't found the logs for the first time yet so don't know if it's the same cause.

3.) Can the flood filter in smartfox help with this particular case? If so what exactly should I do?

Thanks,