Iplog filled with |Server Query|

[DanZeal]

Just discovered that since 6.6 (or maybe 6.6a) the IPlog is filled with a lot of "|Server Query|". It would be nice if we could get the clean IPlog back.

[ShakerNL]

It started happening to me since I updated to Plus 6.4 in November on PN servers. I am guessing that Zeal Duels was still on 6.1 for a while, thus why he noticed it just recently.

[DanZeal]

Shaker is right. It seems like it started with 6.4.

[Violet CLM]

Okay! That was quite a bit of research, but I seem to have figured out what happened in 6.4, though I'm speculating with limited information in some places:

At some point prior to JJ2+ v4.0, which is the earliest that we have records of, BlurredD added some code to detect server queries, e.g. from GIP scripts. The code was intended to look at TCP packet 0x0E (https://www.jazz2online.com/wiki/TCP_Protocol/#h-3) and run if either of the following two conditions was true:
The numberOfPlayers byte equaled 0, OR
playerName began with the section character followed by the pipe character (|)
If either of those conditions was true, the code was meant to write the Server Query line to iplog001.txt (or whatever), send the client any useful information, and then kick the client.

I can see that both DJazz's SGIP script (https://djazz.se/apps/sgip/) and jj2multiplayer's fork (https://jj2multiplayer.com/sgip/) use names beginning in section-pipe, though neither of them sets numberOfPlayers to 0, so JJ2+ has to rely on just the player name. I'm assuming without evidence this has always been the case and the packet sent by SGIP has never changed.

(The SGIP packet is, incidentally, incorrectly formatted... it uses the packet format from JJ2+ v1.3 or earlier, but claims to be JJ2+ version 3.0. However, JJ2+'s code for reading packet 0x0E was also never updated for version 1.4, so JJ2+ was looking at the right byte all along.)

Crucially, at some point somebody accidentally used the wrong character encoding to save the JJ2+ source file that reads packet 0x0E and checks names for section-pipe. This was publicly visible in that, for a while, when players joined LRS servers and were automatically set to zero lives, they saw a green A (with a diacritic) at the start the following two lines, which was an artifact of using the wrong character encoding for that source file:
AYou joined late so you are out of the game.
APlease wait patiently for the next game to start.

This was later fixed by saving the file with the correct character encoding. Probably this happened in 6.4.

While the file's character encoding was wrong, instead of comparing player names to section-pipe, they were instead compared to A-section-pipe. That meant that the server query line stopped appearing for a while, although for many years before that, it had been reliably appearing in iplog files as intended.

In summary, 6.4 accidentally fixed an unknown bug that was preventing the server query line from appearing.

According to BlurredD in 2014,
Server queries are logged so that it's easier to find potential abuse (picture someone sending hundreds of queries a second)
However, according to stijn in 2023,
SGIP now uses the query packet (https://docs.jj2.plus/#integration) to query servers so one of the underlying reasons this became a problem is no longer there (though there may be other GIP lists out there that still emulate joining the server).
So that's puzzling! Did something change between 2023 and now that caused SGIP scripts to stop using the query packet and go back to using packet 0x0E? Or was stijn talking about a different SGIP than the djazz.se and jj2multiplayer.com pages?

I'm limited here without knowing how SGIP works, but I'm wondering if maybe SGIP is sending the query packet and packet 0x0E, but not actually using the response from 0x0E? Because if I'm reading the JJ2+ code right, trying to join a v4.0 (or above) server and pretending your client is v3.0 is not actually going to give you any useful information, assuming the server has /latestversiononly enabled, unless the server treats you as a server query.

[Violet CLM]

I also want to post Seren's idea from the last time we talked about the Server Query line internally (presumably from before it accidentally stopped working):
I think the primary purpose of IP logs is to provide IP addresses to ban or block from the firewall in case of malicious behavior. Under that assumption, it seems unwise to me to let any IP or type of request be left out from logging completely. I think a safer solution would be to group consecutive log messages that only differ by timestamp, i.e. instead of

[02:01:59] ID: 2 IP Address: 192.168.1.1 Name: Seren2
[02:02:34] ID: 2 IP Address: 192.168.1.1 Name: Seren2
[02:02:46] ID: 2 IP Address: 192.168.1.1 Name: Seren2
[02:03:23] ID: 2 IP Address: 192.168.1.1 Name: Seren2
[02:03:38] ID: 2 IP Address: 192.168.1.1 Name: Seren2

log

[02:01:59] ID: 2 IP Address: 192.168.1.1 Name: Seren2
+ 4 more times over a period of 00:01:39

[DanZeal]

I also want to post Seren's idea from the last time we talked about the Server Query line internally (presumably from before it accidentally stopped working):

That might be a good idea.

[Violet CLM]

I've implemented Seren's idea in 6.6c.

[DanZeal]

Thanks!