Pre-release build v5.05-pre fails to receive text sometimes

Posted by Worstje on Wed 01 Feb 2017 11:20 PM — 23 posts, 92,648 views.

Netherlands #0
Continued from the WindowMenu suggestion topic to unclutter things. (http://mushclient.com/forum/?id=13909&page=999)

Sorry about being unclear in my last response. I had some people renovating my house and pretty much didn't sleep, so I was rather tired and I mostly just wanted to get the information out to you guys to the point where I didn't re-read and try to make sense of my own post.

The Fiendish-automated build is the only one to exhibit the issue. I send text to it, but text stops coming back after logging in. But some game messages do show sometimes, it is rather inconsistent.

Nick's 5.05-pre build (lacks the '-pre' marker code-wise but that is no doubt a silly build-related detail) works just fine for as far I can tell.

My testing method was exactly the same: world has all triggers off, no script file and no plugins loaded. Opened straight after starting MUSHclient. Go through the autologin, and do an @emit command for testing purposes, which then either shows output or does not depending on which build I'm using.


@Nick: I didn't have your e-mail stored anywhere, nor did I want to spam you with logs you didn't ask for. (I sorta figured it was an issue with Fiendish build system at that point.) Since I separated the logs into two separate files for diffing purposes I didn't really consider using the forums for it.

But since the logs aren't long, I'll probably just message you both in a few minutes.

Edit: Actually, I can't. The forums decided there's too many bytes even for a single packet log. Sorry. :-/
Amended on Wed 01 Feb 2017 11:23 PM by Worstje
USA Global Moderator #1
Quote:
Nick's 5.05-pre build (lacks the '-pre' marker code-wise but that is no doubt a silly build-related detail) works just fine for as far I can tell.

GOOD! (But also wtf?)


Quote:
@Nick: I didn't have your e-mail stored anywhere, nor did I want to spam you with logs you didn't ask for. (I sorta figured it was an issue with Fiendish build system at that point.) Since I separated the logs into two separate files for diffing purposes I didn't really consider using the forums for it.

Don't worry. I emailed it to him just now.


Nick, first test what say we undo the switch to fp:fast? (delete '<FloatingPointModel>Fast</FloatingPointModel>')

https://github.com/nickgammon/mushclient/commit/89606e97f02e033d18492330be96df3bd7ab3793#diff-b79a31ac6bbc21f184eeebb57dc4bffcR140
Amended on Wed 01 Feb 2017 11:28 PM by Fiendish
Australia Forum Administrator #2
Quote:

GOOD! (But also wtf?)


I just renamed the file, it wouldn't have had the "-pre" in the version embedded in the code.

I removed that line, and it is recompiling as we speak.

(I doubt this is the issue, but whatever).
Australia Forum Administrator #3
Quote:

Text stops coming in. Some stuff does show.


I'm not sure what you mean by "stuff" there.

Anyway, I have had a trickle of reports about data not arriving, in the past. I would say, from memory, two or three.

Obviously things normally work or the client would be unusable.

It is possible the more recent libraries do something a bit differently that is triggering an underlying bug in the code.

First, the basic comms routines were one of the first things I wrote (naturally) and possibly there is some misunderstanding of how the code is supposed to interface with the underlying Windows messages.

Second, data reception is event-triggered, so basically the client waits for incoming data (plus of course key presses and mouse movements).


If the event for a new packet is not sent (or somehow lost) then the client will not realize there is something to do. Possibly you get larger, or smaller, packets than normal due to some router configuration. This might trigger some issue that the code should handle, but does not.

Since the code is open-source anyone is welcome to browse it and make suggestions for things they think might be wrong.

In particular the file worldsock.cpp would be a place to look at.

The code to actually receive incoming data is very small:


void CWorldSocket::OnReceive(int nErrorCode)
{

  // CSocket::OnReceive(nErrorCode);

	m_pDoc->ProcessPendingRead();
}


Maybe the error code needs looking at? Maybe if there is an error something should be sent to "clear" the error? I'm open to suggestions.

BTW - maybe make a new post under Bug Reports to keep this subject away from the stuff about menu alignment.
Australia Forum Administrator #4
I see from your trace you got *something* back:



Incoming packet: 4 (1 bytes) at woensdag, februari 01, 2017, 8:59:29 

<                  3c

Incoming packet: 4 (1 bytes) at woensdag, februari 01, 2017, 8:59:29 

>                  3e

Sent  packet: 10 (19 bytes) at woensdag, februari 01, 2017, 8:59:36 

@emit YO DE LA L   40 65 6d 69 74 20 59 4f 20 44 45 20 4c 41 20 4c
A..                41 0d 0a

Incoming packet: 5 (2 bytes) at woensdag, februari 01, 2017, 8:59:58 

ÿñ                 ff f1



That last packet is IAC NOP.
Australia Forum Administrator #5
I've pushed another pre-release. This time it loops getting data from the socket until there isn't any more. This may or may not fix things (it might make them worse). See how that goes.

Get it from the GitHub pre-release place:

https://github.com/nickgammon/mushclient/releases
Amended on Thu 02 Feb 2017 05:06 AM by Nick Gammon
Netherlands #6
Sad to say, that did not fix it.

I have simplified my testing method to completely rule out my World file.


New simplified testcase:

1. Connection -> Quick Connect.

2a. Server: play.arxmush.org
2b. Port: 3000
2c. OK

3. Login by typing 'guest'.

If fixed? Lots of welcome text for newbies appears.
If bug? No output whatsoever.

Honestly, the difference is pretty dang obvious.


Hopefully that will help you guys figure it out with the aid of a debugger, since I realize relying on me non-stop isn't the most useful thing ever.
USA Global Moderator #7
Packet debug diff: https://www.diffchecker.com/qixzpsbx
Netherlands #8
Yay for reproduction. :D
Australia Forum Administrator #9
Did you try the release built from the same source but compiled by me with the old compiler?


http://gammon.com.au/files/mushclient/MUSHclient_5.05-pre.zip
Australia Forum Administrator #10
Worstje said:

Yay for reproduction. :D


I can reproduce it too. That's odd. I can't use the debugger though because the in-house compiled one works.
Australia Forum Administrator #11
I reverted my recent changes to the way I handle comms, after all that worked for about 20 years.

Still no difference. Clearly it's something to do with the newer libraries. (I mean, there isn't a compile-option: "don't make Windows Sockets work" is there?).

Anyway you can test the menu alignment with the version I posted a couple of replies back but compiled by me directly.
Australia Forum Administrator #12
I thought maybe "packet size". I recompiled with a packet buffer of 9000 bytes (compared to 1000 before) as one of your packets was 1024, but no difference. Besides, the 1024 byte packet is not the first one that is not received.

From Fiendish's diff this is the first missing data:


Incoming packet: 4 (6 bytes) at Thursday, February 02, 2017, 3:09:54 PM
			
			ÿú..ÿð             ff fa 18 01 ff f0
			
			Sent  packet: 9 (10 bytes) at Thursday, February 02, 2017, 3:09:54 PM
			
			ÿú..ANSIÿð         ff fa 18 00 41 4e 53 49 ff f0
			
			Incoming packet: 5 (6 bytes) at Thursday, February 02, 2017, 3:09:54 PM
			
			ÿú..ÿð             ff fa 18 01 ff f0
			
			Sent  packet: 10 (12 bytes) at Thursday, February 02, 2017, 3:09:54 PM
			
			ÿú..MTTS 9ÿð       ff fa 18 00 4d 54 54 53 20 39 ff f0
			
			Sent  packet: 11 (7 bytes) at Thursday, February 02, 2017, 3:09:57 PM
Australia Forum Administrator #13
Here's some more weird stuff. In fact I am receiving things. If you let the packet debug run for a while you get IAC NOP from time to time:


Incoming packet: 4 (2 bytes) at Friday, February 03, 2017, 9:16:21 AM

ÿñ                 ff f1

Incoming packet: 5 (2 bytes) at Friday, February 03, 2017, 9:16:51 AM

ÿñ                 ff f1

Sent  packet: 10 (7 bytes) at Friday, February 03, 2017, 9:17:04 AM

guest..            67 75 65 73 74 0d 0a   <-- I tried again

Incoming packet: 6 (2 bytes) at Friday, February 03, 2017, 9:17:21 AM

ÿñ                 ff f1


It looks like my attempt to send "guest" has failed, hence the server is waiting for me to reply. However I fired up Wireshark and it looks like sends are in fact working.
Australia Forum Administrator #14
So it could be a server issue - they are not processing the "guest" login. However the packet debug from Fiendish is identical up to that point, so the server has received exactly the same stuff.
Australia Forum Administrator #15
Looking more closely at the Wireshark packet, it does not agree with the packet debug. I think I have found a bug in the sending routine. Recompiling now.
Australia Forum Administrator #16
It seems that the sending routine was not 8-bit clean, in particular it failed sending 0x00. For some reason that worked with the older compiler.

The latest pre-release now works with arxmush.org.

In particular, this commit fixed it:

https://github.com/nickgammon/mushclient/commit/3607fe183afa57bcd73a0

If you are affected by this you can get the pre-release executable from here:

https://github.com/nickgammon/mushclient/releases/download/latest_commit/MUSHclient.exe

Note that this file has to be copied over MUSHclient.exe in your MUSHclient install directory.

Once version 5.05 (or higher) of MUSHclient is released the fix will be in the official release.
Amended on Fri 03 Feb 2017 12:21 AM by Nick Gammon
Australia Forum Administrator #17
Thanks for reporting this BTW. I think I've had a couple of similar reports in the past, where people would send something and it wouldn't be received.

I think the explanation is that once the 0x00 byte gets into the output buffer it effectively terminated the string, so matter what additional things you typed, they were appended after the 0x00, and thus ignored.

In this particular case, the 0x00 was part of the telnet negotiation for the terminal type.

In particular, this packet:


Sent  packet: 8 (16 bytes) at Thursday, February 02, 2017, 3:07:56 PM					
	ÿú..mushclientÿð   ff fa 18 00 6d 75 73 68 63 6c 69 65 6e 74 ff f0


Note the "00" there? It is obvious once you look at it.
Netherlands #18
Patch confirmed. Latest pre-release works as it ought to. :-)

My apologies for getting you guys to dig through such a pre-release specific bug!
Australia Forum Administrator #19
What threw me out a bit was the bug report "Pre-release build v5.05-pre fails to receive text sometimes" - actually that was a symptom of a missing send - had the username been sent, then the server would have responded with the greeting text.

Hence all the mucking around checking what the problem was with the sending routine.

The fact that the IAC NOP still arrived was a bit of a tip that data was in fact still being received.
Australia Forum Administrator #20
Worstje said:

My apologies for getting you guys to dig through such a pre-release specific bug!


Not at all. It was a genuine bug. Sometimes genuine bugs survive for a while because of idiosyncrasies of memory layout (for example, uninitialized memory).
Netherlands #21
Honestly, I had seen the IAC NOP before I submitted. (You learn to recognise an IAC code after you've implemented a few telnet parsers.)

I wasn't sure if that was sent by the game (I never saw a game send that one before!) or a side-effect from the bug somehow misinterpreting the wrong byte for its telnet state machine, but at the time I was tired and just getting the two packet debugs I did out was all the time I could spend on it.

The IAC NOP was the reason why I wrote 'text' when describing the bug; clearly not everything went lost and I had a feeling the difference was incoming text vs (sub)negotiation stuff. And if everything had gone lost, I figured there would be an outright connection reset at some point. :-)

Thanks very much for the sleuthing!
Australia Forum Administrator #22
I suspect they send that to keep the connection alive.