Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Game intermittently softlocks. Online protocol suspect. #40

Open
HamaIndustries opened this issue Apr 20, 2016 · 25 comments
Open

Game intermittently softlocks. Online protocol suspect. #40

HamaIndustries opened this issue Apr 20, 2016 · 25 comments
Assignees

Comments

@HamaIndustries
Copy link
Owner

HamaIndustries commented Apr 20, 2016

Issue type: feature request

Description:

As it is, instruction packets are sent once and only once, resulting in tied up games when packets are dropped. I propose that we allow for tcp-style communications -- that is, to make sure the programs confirm they have sent after sending.

@ghost
Copy link

ghost commented Apr 20, 2016

That reminds me, enclosed in the .zip are the server logs. "server_log41526522.log" is from v1.2.1, whereas "server_log30266500.log" is from v1.3 "non-x86"
logs.zip

This is a consistent issue when playing with opponents who use a wireless connection, as my connection is wired. Should I add this is a bug / problem as well?

@HamaIndustries
Copy link
Owner Author

@SapphireTactician no, just keep it here. I want to make this a priority so that games will be playable on worse connections.

@ghost
Copy link

ghost commented May 15, 2016

After what happened tonight during the tournament, this needs to become our absolute top priority alongside the fatals in FEServer that were just uncovered, as I warned you this would happen. :-(

@HamaIndustries
Copy link
Owner Author

Who was hosting, was it just you? We've never had the problem be this big in the past, and it alos may have been due to my experimentation with filesize.

Nevertheless, this will be a top priority.

@ghost
Copy link

ghost commented May 15, 2016

I was hosting. I was also the only wired connection, removing my PC from being the point of failure packet wise. I'll procure logs when I have a free moment hopefully tonight.

@rayrobdod
Copy link
Collaborator

There are two things that I've found. One: datagrams correspond to UDP and sockets correspond to TCP, and FEMP uses sockets. Two: volatile and final are mutually exclusive by definition, and quite a few variables that FEMP declares volatile are effectively final.

@HamaIndustries
Copy link
Owner Author

How hard is it looking from your perspective?

@rayrobdod
Copy link
Collaborator

Between this, #22, #80, #61, that the overworld and lobby chats being completely separate, that a late-joining spectator stays in the lobby instead of spectating, that anyone leaving kicks everyone and, well, canto; I keep getting distracted with wanting to re-architect the entire network package. But that just feels like something I shouldn't do, for all the reasons that redoing something especially with no automated testing is wrong.

The other thing is that I can point at specific things that are code smells, but I don't know whether fixing those is just a change or actually a fix. Or rather they're things that are bound to blow up, but I don't know if they're this blowing up. The only time I've actually experienced this issue was during last weekend's tournament; I can't trigger this at will. And the whole "top priority" thing makes it sound like if the fix is "adjacent to" the top priority and not actually the top priority, then I shouldn't do it at all.

@HamaIndustries
Copy link
Owner Author

Well, if we want an ordered list of priorities, I can go through all the issues, if that would help. i just keep forgetting where top priorities are and I just call them all top priority. for now, I'd say this is definitely our biggest issue, since it was partly Sapphiretactician's faulty internet that led to several crashes. We can save features for after we fix this, or I can focus on those if you need time to restructure whatever parts of the code you would like.

@ghost
Copy link

ghost commented May 20, 2016

since it was partly Sapphiretactician's faulty internet that led to several crashes.

Excuse me, but I take great offense to that blatantly false statement when I'm using a wired connection with 50 mbps up and down internet. I've never had a disconnect in any other online game. When pinging my own router and several other websites, I have 0% packet loss. Sarah's internet is faulty I know which would explain her's, and every other player had wireless - making them FAR more liable to be POF (Point Of Failure) in regards to dropping packets. However, in light of #42 , #61 , #91 , #92 , #93 and #94 , among others that result in FEServer and / or FEMP crashing (or softlocking or turn skipping), if anything is faulty (aside from the inherent nature of wi-fi), it's your / Chu's code - not my internet. Don't go pointing fingers unless you have evidence to back up such claims, thank you. -_- (End rant)

@HamaIndustries
Copy link
Owner Author

ok mb bb. I remember hearing the internet thing and thought you were talking about your internet. It is probably the code, but what I'm also worried about is that a lot of the bugs we "uncovered" a bunch of bugs after I had secretly trimmed the server files.

@ghost
Copy link

ghost commented May 20, 2016

Well, #91 #92 #93 and #94 persist in v1.4.1 and I'm 99.9% confident they've been around since Day 1. Depending on how sensitive player's keyboards are, these could be lending to some issues.

I'm not even sure if it is packet loss (though we should have a verification system and sanity checks anyways) This specific bug has still been a thing ever since I stumbled upon /r/femp back when v1.2.1 was still showing as latest. I'm not sure what to call it anymore, but if you study the logs, in affected games, the log is only recording one instance of the RCVE and SEND portions of ENDTURN.

[RCVE]1 ENDTURN::
[SEND]1 ENDTURN::
[RCVE]1 COMMANDMESSAGE::[]
[SEND]1 COMMANDMESSAGE::[]

Instead of:

[RCVE]1 ENDTURN::
[SEND]1 ENDTURN::
[RCVE]2 COMMANDMESSAGE::[]
[SEND]2 COMMANDMESSAGE::[]
[RCVE]1 COMMANDMESSAGE::[]
[SEND]1 COMMANDMESSAGE::[]

Below is a server_log excerpt from an affected game with Sarah (for the record, her wi-fi can't even sustain a Skype call for very long on that note without her stream freezing, and is prone to disconnects)


Example:

Pay close attention to the RCVE and SEND portions of COMMANDMESSAGE::[] after ENDTURN.

I'm the player identified as 2, she's the player identified as 1. Sarah (1) uses Erk to attack me (2), claims to end turn, but I'm still stuck in Enemy Phase. What's confusing is while the log shows her RCVE and SEND (if I'm reading this correctly) portion of COMMANDMESSAGE::[] after ENDTURN, mine is either refusing to respond or is responding back, but not logging it due to her failure to receive and / or send back something - I have no idea what given how confusingly this log is written.

[RCVE]1 COMMANDMESSAGE::Erk move (3, 3):[EQUIP, Erk, 0, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 0, EQUIP, Erk, 0, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 0, EQUIP, Erk, 0, EQUIP, Erk, 0, EQUIP, Erk, 0, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 1, ATTACK, Oswin]
[BATL]0 BATTLESTART::
[BATL]0 HP::Erk HP36 Oswin HP49
[BATL]0 ATTACKRECORD::Attack: Erk, Oswin, 18, 0 (drain)
[BATL]0 ATTACKRECORD::Attack: Oswin, Erk, 29, 0 (drain)
[BATL]0 ATTACKRECORD::Attack: Erk, Oswin, 18, 0 (drain)
[BATL]0 HP::Erk HP7 Oswin HP13
[BATL]0 BATTLEEND::
[SEND]1 COMMANDMESSAGE::Erk move (3, 3):[EQUIP, Erk, 0, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 0, EQUIP, Erk, 0, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 0, EQUIP, Erk, 0, EQUIP, Erk, 0, EQUIP, Erk, 0, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 1, EQUIP, Erk, 1, ATTACK, Oswin]
[RCVE]1 ENDTURN::
[SEND]1 ENDTURN::
[RCVE]1 COMMANDMESSAGE::[]
[SEND]1 COMMANDMESSAGE::[]
[RCVE]2 CHATMESSAGE::Did you end turn?
[SEND]2 CHATMESSAGE::Did you end turn?
[RCVE]1 CHATMESSAGE::yes
[SEND]1 CHATMESSAGE::yes
[RCVE]2 CHATMESSAGE::Still shows as Enemy Phase. :'-(
[SEND]2 CHATMESSAGE::Still shows as Enemy Phase. :'-(
[RCVE]1 CHATMESSAGE::said so on my end too :<
[SEND]1 CHATMESSAGE::said so on my end too :<
[RCVE]2 CHATMESSAGE::And your castle was about to fall too. FML
[SEND]2 CHATMESSAGE::And your castle was about to fall too. FML

Example 2:

In this excerpt, you see us having Raven dittos, again Sarah (this time shown as 3 for some reason) ends her turn but the game softlocks.

[RCVE]3 COMMANDMESSAGE::Raven move (1, -3):[EQUIP, Raven, 0, ATTACK, Raven]
[BATL]0 BATTLESTART::
[BATL]0 HP::Raven HP53 Raven HP53
[BATL]0 ATTACKRECORD::Attack: Raven, Raven, 23, 0 (drain)
[BATL]0 ATTACKRECORD::Attack Miss: Raven, Raven, 0, 0 (drain)
[BATL]0 ATTACKRECORD::Attack: Raven, Raven, 20, 0 (drain)
[BATL]0 HP::Raven HP33 Raven HP30
[BATL]0 BATTLEEND::
[SEND]3 COMMANDMESSAGE::Raven move (1, -3):[EQUIP, Raven, 0, ATTACK, Raven]
[RCVE]3 ENDTURN::
[SEND]3 ENDTURN::
[RCVE]3 COMMANDMESSAGE::[]
[SEND]3 COMMANDMESSAGE::[]
[RCVE]2 CHATMESSAGE::Did you End Turn yet?
[SEND]2 CHATMESSAGE::Did you End Turn yet?
[RCVE]3 CHATMESSAGE::yes
[SEND]3 CHATMESSAGE::yes
[RCVE]2 CHATMESSAGE::This packet loss thing seems rather
[SEND]2 CHATMESSAGE::This packet loss thing seems rather
[RCVE]2 CHATMESSAGE::consistant
[SEND]2 CHATMESSAGE::consistant
[RCVE]2 CHATMESSAGE::FML
[SEND]2 CHATMESSAGE::FML
[RCVE]2 CHATMESSAGE::Looks like we're tied in units, so it's a draw
[SEND]2 CHATMESSAGE::Looks like we're tied in units, so it's a draw
[RCVE]2 CHATMESSAGE::GG
[SEND]2 CHATMESSAGE::GG
[RCVE]3 CHATMESSAGE::welp
[SEND]3 CHATMESSAGE::welp
[RCVE]2 QUITMESSAGE::
[SEND]2 QUITMESSAGE::
[SEND]ENDGAME:: winner = 3

Just out of curiosity, what does COMMANDMESSAGE::[] mean? Does it log attempts, or only successes? While we can see what the failure is, it's hard to pinpoint the exact point of failure because nothing is saying something along the lines of who dropped the ball and where.


Expected Behavior:

Meanwhile, in games that complete successfully, where I was labeled as 2 every turn ends / begins with either of the following server_log excerpt:

[RCVE]2 ENDTURN::
[SEND]2 ENDTURN::
[RCVE]2 COMMANDMESSAGE::[]
[SEND]2 COMMANDMESSAGE::[]
[RCVE]1 COMMANDMESSAGE::[]
[SEND]1 COMMANDMESSAGE::[]

OR

[RCVE]1 ENDTURN::
[SEND]1 ENDTURN::
[RCVE]2 COMMANDMESSAGE::[]
[SEND]2 COMMANDMESSAGE::[]
[RCVE]1 COMMANDMESSAGE::[]
[SEND]1 COMMANDMESSAGE::[]

I'm not sure what to make of this cause the wording is rather disorienting and makes it seem like it's my fault, but that's impossible when some of these failures occurred the moment her txt'd me saying her wi-fi cut out. I feel we need more verbose logging. Also, why do the logs not reference the actual items brought into battle? It also seems to very funkily logs tons of extra stuff while cycling through weapons to check various forecasts.

@ghost
Copy link

ghost commented May 20, 2016

EDIT: Clairifcation / Elaboration. Wasn't sure if you're notified about updates so I figured I'd make a new comment indicating this.

@rayrobdod
Copy link
Collaborator

As far as I can tell, COMMANDMESSAGE::[] is a no-op. "Order no one to do nothing". But if its' the difference between the success and failure, it's obviously doing something.

@ghost
Copy link

ghost commented May 20, 2016

"Order no one to do nothing"

You mean "Order everyone to do nothing"? Otherwise that double-negative alone is a recipe for disaster.

@rayrobdod
Copy link
Collaborator

COMMANDMESSAGE::Raven move (1, -3):[EQUIP, Raven, 0, ATTACK, Raven] has a unit (Raven) and a bunch of commands (Move four spaces, equip the first item in inventory, attack the other raven).

COMMANDMESSAGE::[] Has no unit so the commands aren't ordered at anyone, and it has no commands to order even if there was a unit to order at.

@HamaIndustries
Copy link
Owner Author

So would that mean that instead of an endturn message, the client is sending blank messages?

@ghost
Copy link

ghost commented May 20, 2016

@eliatlarge I think @rayrobdod is just explaining to me something I asked about in regards to what a particular message meant.

@ghost
Copy link

ghost commented Jun 12, 2016

@rayrobdod thanks for fixing (if not overhauling) a mammoth chunk of the network and game code. I know you must be exhausted from that epic patchwork but do you think we can put this bug to bed now by having some kind of system to verify when commands are successfully sent / received (if it's not already in there and I just forgot to test it) to ensure that if a player's wi-fi hiccups mid-match, that the game won't softlock or desync?

Since you redid most of the networking code, you'd be able to assist with this better than anyone else without compromising the work already put in.

@ghost ghost added the bug label Jan 22, 2017
@ghost ghost changed the title Allow for tcp-style packet sending Game intermittently softlocks. Online protocol suspect. Jan 23, 2017
@ghost ghost added critical bug and removed bug labels Jan 23, 2017
@ghost
Copy link

ghost commented Jan 23, 2017

It strikes again @eliatlarge @rayrobdod @Purplemandown @Zogzer

Let's send this bug to hell so A.) this edition of the game can have some closure and B.) so we don't fall victim to it in the new edition.

Happened again in a match between me and Pwntagonist. Can someone explain what happened and what a broken pipe is? And more importantly why the server was able to capture information that the client didn't when I was running both?


Details:

I ended my turn, it was now Enemy Phase. After a few moments I receive a message from Pwntagonist asking if I was still thinking. I told him I ended turn, then he said that was odd because so did he. I then sent the following screenshot as proof.

2017-01-22--180326_1600x900

Upon examining the logs, I noticed that my client experienced java.net.SocketException: Broken pipe (Write failed) error with each move I made that turn. I was also hosting that game, and the elephant in the room here is that the server's logs recorded Pwntagonist's and even in-game chat messages which failed to display on my end. He then left the game, which also never occurred on my client but again was reflected in the server log.

This occurred after it became my turn:

INFO: CLIENT: Read 2 ENDTURN::
Jan 22, 2017 5:59:17 PM net.fe.network.Client sendMessage
INFO: CLIENT: Sent message [1 COMMANDMESSAGE::Oswin[Move[5,0], Wait[]]]
Jan 22, 2017 5:59:17 PM net.fe.network.Client$1 run
WARNING: CLIENT: EXIT
Jan 22, 2017 5:59:17 PM ClientNetworkingReader run
FINER: THROW
java.net.SocketException: Connection reset
    at java.net.SocketInputStream.read(SocketInputStream.java:209)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at java.net.SocketInputStream.read(SocketInputStream.java:223)
    at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2321)
    at java.io.ObjectInputStream$BlockDataInputStream.peek(ObjectInputStream.java:2614)
    at java.io.ObjectInputStream$BlockDataInputStream.peekByte(ObjectInputStream.java:2624)
    at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1321)
    at java.io.ObjectInputStream.readObject(ObjectInputStream.java:373)
    at net.fe.network.Client$1.run(Client.java:102)
    at java.lang.Thread.run(Thread.java:745)

Jan 22, 2017 5:59:29 PM net.fe.network.Client sendMessage
SEVERE: CLIENT Unable to send message: [1 COMMANDMESSAGE::Raven[Move[6,0], Wait[]]]
Jan 22, 2017 5:59:29 PM Client sendMessage
FINER: THROW
java.net.SocketException: Broken pipe (Write failed)
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109)
    at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
    at java.io.ObjectOutputStream$BlockDataOutputStream.drain(ObjectOutputStream.java:1877)
    at java.io.ObjectOutputStream$BlockDataOutputStream.setBlockDataMode(ObjectOutputStream.java:1786)
    at java.io.ObjectOutputStream.writeNonProxyDesc(ObjectOutputStream.java:1286)
    at java.io.ObjectOutputStream.writeClassDesc(ObjectOutputStream.java:1231)
    at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1427)
    at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1178)
    at java.io.ObjectOutputStream.writeFatalException(ObjectOutputStream.java:1577)
    at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:351)
    at net.fe.network.Client.sendMessage(Client.java:211)
    at net.fe.FEMultiplayer.send(FEMultiplayer.java:363)
    at net.fe.overworldStage.ClientOverworldStage.send(ClientOverworldStage.java:568)
    at net.fe.overworldStage.context.UnitMoved.onSelect(UnitMoved.java:92)
    at net.fe.overworldStage.context.UnitMoved.onSelect(UnitMoved.java:26)
    at net.fe.overworldStage.MenuContext.onSelect(MenuContext.java:52)
    at net.fe.overworldStage.ClientOverworldStage.beginStep(ClientOverworldStage.java:310)
    at net.fe.FEMultiplayer.loop(FEMultiplayer.java:333)
    at net.fe.FEMultiplayer.main(FEMultiplayer.java:97)

Yet my server was able to capture this, something which never was reflected on my client:

FINE: [RECV]2 ENDTURN::
Jan 22, 2017 5:58:43 PM net.fe.network.Server broadcastMessage
FINER: [SEND]2 ENDTURN::
Jan 22, 2017 5:58:43 PM net.fe.network.ServerListener sendMessage
FINE: SERVER sent message: [2 ENDTURN::]
Jan 22, 2017 5:58:43 PM net.fe.network.ServerListener sendMessage
FINE: SERVER sent message: [2 ENDTURN::]
Jan 22, 2017 6:01:25 PM net.fe.network.ServerListener run
FINE: [RECV]2 CHATMESSAGE::u there?
Jan 22, 2017 6:01:25 PM net.fe.network.Server broadcastMessage
FINER: [SEND]2 CHATMESSAGE::u there?
Jan 22, 2017 6:01:25 PM net.fe.network.ServerListener sendMessage
FINE: SERVER sent message: [2 CHATMESSAGE::u there?]
Jan 22, 2017 6:01:25 PM net.fe.network.ServerListener sendMessage
FINE: SERVER sent message: [2 CHATMESSAGE::u there?]
Jan 22, 2017 6:03:28 PM net.fe.network.ServerListener run
FINE: [RECV]2 QUITMESSAGE::
Jan 22, 2017 6:03:28 PM net.fe.network.ServerListener run
FINE: LISTENER: Exit
Jan 22, 2017 6:03:28 PM net.fe.network.Server broadcastMessage
FINER: [SEND]2 QUITMESSAGE::
Jan 22, 2017 6:03:28 PM net.fe.network.Server broadcastMessage
FINER: [SEND]ENDGAME:: winner = 1

For reference, I was using a wired connection, so bad wi-fi isn't a factor. Also in case it matters, I connected to my own game using my external IP instead of localhost.


Logs:

Softlock_Again.zip

@ghost ghost assigned Purplemandown Jan 23, 2017
@ghost
Copy link

ghost commented Jan 24, 2017

@eliatlarge @rayrobdod @Purplemandown Happened again, this time with Lip Alm aka BChezza. Includes his logs too. Same error, broken pipe.


Logs:

YetAnotherSoftlock_BrokenPipe.zip

@rayrobdod
Copy link
Collaborator

FINE: SERVER sent message: [2 CHATMESSAGE::me too]
Jan 24, 2017 3:23:57 PM net.fe.network.ServerListener sendMessage
FINE: SERVER sent message: [2 CHATMESSAGE::me too]
Jan 24, 2017 3:24:05 PM net.fe.network.ServerListener run
FINE: [RECV]2 CHATMESSAGE::i think youve won though
Jan 24, 2017 3:24:05 PM net.fe.network.Server broadcastMessage
FINER: [SEND]2 CHATMESSAGE::i think youve won though
Jan 24, 2017 3:24:05 PM net.fe.network.ServerListener sendMessage
FINE: SERVER sent message: [2 CHATMESSAGE::i think youve won though]
Jan 24, 2017 3:24:05 PM net.fe.network.ServerListener sendMessage
FINE: SERVER sent message: [2 CHATMESSAGE::i think youve won though]
Jan 24, 2017 3:25:41 PM net.fe.network.ServerListener run
FINE: [RECV]2 COMMANDMESSAGE::Sain[Move[-1,0], Equip[Eirika, 0], Equip[Eirika, 0], Equip[Tana, 0], Equip[L'Arachel, 2], Equip[Raven, 0], Equip[Rebecca, 2], Equip[Sain, 0], Equip[Sain, 1], Equip[Sain, 2], Equip[Sain, 1], Equip[Rebecca, 0], Equip[Rebecca, 0], Equip[Rebecca, 0], Equip[Rebecca, 0], Equip[Sain, 2], Equip[Sain, 0], Wait[]]
Jan 24, 2017 3:25:41 PM net.fe.network.Server broadcastMessage
FINER: [SEND]2 COMMANDMESSAGE::Sain[Move[-1,0], Equip[Eirika, 0], Equip[Eirika, 0], Equip[Tana, 0], Equip[L'Arachel, 2], Equip[Raven, 0], Equip[Rebecca, 2], Equip[Sain, 0], Equip[Sain, 1], Equip[Sain, 2], Equip[Sain, 1], Equip[Rebecca, 0], Equip[Rebecca, 0], Equip[Rebecca, 0], Equip[Rebecca, 0], Equip[Sain, 2], Equip[Sain, 0], Wait[]]
Jan 24, 2017 3:25:41 PM net.fe.network.ServerListener sendMessage
FINE: SERVER sent message: [2 COMMANDMESSAGE::Sain[Move[-1,0], Equip[Eirika, 0], Equip[Eirika, 0], Equip[Tana, 0], Equip[L'Arachel, 2], Equip[Raven, 0], Equip[Rebecca, 2], Equip[Sain, 0], Equip[Sain, 1], Equip[Sain, 2], Equip[Sain, 1], Equip[Rebecca, 0], Equip[Rebecca, 0], Equip[Rebecca, 0], Equip[Rebecca, 0], Equip[Sain, 2], Equip[Sain, 0], Wait[]]]
Jan 24, 2017 3:25:44 PM net.fe.network.ServerListener run
FINE: [RECV]2 COMMANDMESSAGE::Raven[Move[-1,0], Equip[Raven, 0], Wait[]]
Jan 24, 2017 3:25:44 PM net.fe.network.Server broadcastMessage
FINER: [SEND]2 COMMANDMESSAGE::Raven[Move[-1,0], Equip[Raven, 0], Wait[]]
Jan 24, 2017 3:25:44 PM net.fe.network.ServerListener sendMessage
FINE: SERVER sent message: [2 COMMANDMESSAGE::Raven[Move[-1,0], Equip[Raven, 0], Wait[]]]
Jan 24, 2017 3:26:40 PM net.fe.network.ServerListener run
FINE: [RECV]2 COMMANDMESSAGE::Ewan[Move[0,-1], Wait[]]
Jan 24, 2017 3:26:40 PM net.fe.network.Server broadcastMessage
FINER: [SEND]2 COMMANDMESSAGE::Ewan[Move[0,-1], Wait[]]

-- YetAnotherBrokenPipe.zip/server_log….zip#line=984-1009

One of the ServerListeners exits somewhere between the "i think youve won" message and the "Command:Sain" message. If it exited gracefully, there'd be a second LISTENER: Exit line in the logs, but there also doesn't seem to be any indication of a crash.


In Softlock_Again.zip, it appears that both ServerListeners died at the same time, and they have indications of a crash - it's just that they claim that they exited since the Client closed the connection first. Even though the clients claim that the server closed the connection first.

@ghost
Copy link

ghost commented Jan 26, 2017

@rayrobdod I have no idea what to make of it, honestly. Nothing crashed, nothing froze. However there's this which has a modified date exactly at the time you indicate which I somehow forgot to include (edit: this was from after I closed my client due to discovering it softlocked):

error_log_server_listener89445040.log.txt

java.net.SocketException: Connection reset
	at java.net.SocketInputStream.read(SocketInputStream.java:209)
	at java.net.SocketInputStream.read(SocketInputStream.java:141)
	at java.net.SocketInputStream.read(SocketInputStream.java:223)
	at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2321)
	at java.io.ObjectInputStream$BlockDataInputStream.peek(ObjectInputStream.java:2614)
	at java.io.ObjectInputStream$BlockDataInputStream.peekByte(ObjectInputStream.java:2624)
	at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1321)
	at java.io.ObjectInputStream.readObject(ObjectInputStream.java:373)
	at net.fe.network.ServerListener.run(ServerListener.java:87)

I didn't receive anything after "me too" though, so I it was just me closing the client after we confirmed it was a softlock, but as you can see, from the logs, I still had the game open at the time he sent "I think you won though" - a message I never got. Here's a screenshot that might help you line things up more.

2017-01-24--152542_1600x900

@ghost
Copy link

ghost commented Jan 27, 2017

Jan 24, 2017 3:24:05 PM net.fe.network.ServerListener run
FINE: [RECV]2 CHATMESSAGE::i think youve won though
Jan 24, 2017 3:24:05 PM net.fe.network.Server broadcastMessage
FINER: [SEND]2 CHATMESSAGE::i think youve won though

@rayrobdod Notice the timestamp in the log, and then notice the times on both Discord and the system clock in the above screenshot. Also notice the task bar where both the client and FEServer are still running. Yet the server listener log lines up with a modified date of 3:24:05 PM, the exact same second the messages I didn't receive on my client were sent. Is this fixable in the foreseeable future? Any ideas?

@ghost
Copy link

ghost commented Feb 5, 2017

@wellme I'm pretty sure I sent you a link to this bug, but I'm tagging you anyways so you have easy access to this discussion.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants