Odd behavior on my server (Brennan's Stead)

[shargash]

I've only seen this once, but I'm going to throw this out there in case it happens again on a "real" server.

Here is what I did:
1. I started the server.
2. I started the launchpad, selected Brennan's Stead, and clicked Play (Launchpad is configured to stay up)
3. I tabbed out of the client when it was on Character Select and did some other stuff.
4. I forgot I already had the client running and clicked launchpad Play again.
5. Remembering that I had an instance of the client up already, I got into the client as fast as I could and clicked Quit
6. The second instance of the client started up, and I logged into the game (on a character marked IsDev)
7. I ran around for a while, when I noticed that I was lagging, and the lag meter by the XP bar was red. Ping times were 10s of thousands of ms
8. I camped, hoping that would clear up the problem.
9. Then I saw this come up on the server:
[quote]
20:31:20.319 D Chunk 'Kaede' is bypassing camp timer since character is marked IsGM or IsDEV
20:31:20.320 D Char ToggleIsOnline: Setting player offline
20:31:20.331 D Char Saved successful for character 'Kaede' (4)
20:31:20.332 D Char ToggleIsOnline: Setting player offline
20:31:20.333 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.334 D Chunk Camp started for character 'Kaede'
20:31:20.389 I UDP New client connected from 192.168.144.21:53397
20:31:20.389 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.391 I UDP New client connected from 192.168.144.21:53397
20:31:20.391 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.393 I UDP New client connected from 192.168.144.21:53397
20:31:20.393 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.395 I UDP New client connected from 192.168.144.21:53397
20:31:20.395 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.397 I UDP New client connected from 192.168.144.21:53397
20:31:20.403 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.405 I UDP New client connected from 192.168.144.21:53397
20:31:20.406 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.408 I UDP New client connected from 192.168.144.21:53397
20:31:20.409 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.410 I UDP New client connected from 192.168.144.21:53397
20:31:20.415 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.417 I UDP New client connected from 192.168.144.21:53397
20:31:20.418 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.422 I UDP New client connected from 192.168.144.21:53397
20:31:20.422 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.424 I UDP New client connected from 192.168.144.21:53397
20:31:20.424 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.426 I UDP New client connected from 192.168.144.21:53397
20:31:20.426 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.428 I UDP New client connected from 192.168.144.21:53397
20:31:20.428 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.430 I UDP New client connected from 192.168.144.21:53397
20:31:20.430 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.432 I UDP New client connected from 192.168.144.21:53397
20:31:20.432 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.434 I UDP New client connected from 192.168.144.21:53397
20:31:20.434 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.436 I UDP New client connected from 192.168.144.21:53397
20:31:20.436 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.438 I UDP New client connected from 192.168.144.21:53397
20:31:20.438 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.440 I UDP New client connected from 192.168.144.21:53397
20:31:20.440 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.442 I UDP New client connected from 192.168.144.21:53397
20:31:20.442 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.444 I UDP New client connected from 192.168.144.21:53397
20:31:20.444 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.446 I UDP New client connected from 192.168.144.21:53397
20:31:20.446 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.448 I UDP New client connected from 192.168.144.21:53397
20:31:20.448 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.450 I UDP New client connected from 192.168.144.21:53397
20:31:20.450 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.452 I UDP New client connected from 192.168.144.21:53397
20:31:20.452 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.454 I UDP New client connected from 192.168.144.21:53397
20:31:20.454 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.456 I UDP New client connected from 192.168.144.21:53397
20:31:20.456 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.458 I UDP New client connected from 192.168.144.21:53397
20:31:20.458 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.460 I UDP New client connected from 192.168.144.21:53397
20:31:20.460 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.462 I UDP New client connected from 192.168.144.21:53397
20:31:20.462 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.464 I UDP New client connected from 192.168.144.21:53397
20:31:20.464 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.466 I UDP New client connected from 192.168.144.21:53397
20:31:20.466 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.468 I UDP New client connected from 192.168.144.21:53397
20:31:20.468 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.470 I UDP New client connected from 192.168.144.21:53397
20:31:20.471 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.473 I UDP New client connected from 192.168.144.21:53397
20:31:20.473 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.475 I UDP New client connected from 192.168.144.21:53397
20:31:20.475 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.477 I UDP New client connected from 192.168.144.21:53397
20:31:20.477 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.479 I UDP New client connected from 192.168.144.21:53397
20:31:20.479 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.481 I UDP New client connected from 192.168.144.21:53397
20:31:20.481 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.483 I UDP New client connected from 192.168.144.21:53397
20:31:20.483 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.485 I UDP New client connected from 192.168.144.21:53397
20:31:20.485 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.487 I UDP New client connected from 192.168.144.21:53397
20:31:20.487 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.489 I UDP New client connected from 192.168.144.21:53397
20:31:20.489 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.491 I UDP New client connected from 192.168.144.21:53397
20:31:20.491 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.493 I UDP New client connected from 192.168.144.21:53397
20:31:20.493 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.495 I UDP New client connected from 192.168.144.21:53397
20:31:20.495 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.497 I UDP New client connected from 192.168.144.21:53397
20:31:20.497 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.499 I UDP New client connected from 192.168.144.21:53397
20:31:20.499 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.501 I UDP New client connected from 192.168.144.21:53397
20:31:20.501 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.503 I UDP New client connected from 192.168.144.21:53397
20:31:20.503 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.505 I UDP New client connected from 192.168.144.21:53397
20:31:20.505 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.507 I UDP New client connected from 192.168.144.21:53397
20:31:20.507 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.509 I UDP New client connected from 192.168.144.21:53397
20:31:20.509 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:20.511 I UDP New client connected from 192.168.144.21:53397
20:31:20.511 I UDP Client from 192.168.144.21:53397 set to disconnect : Application
20:31:21.108 D Chunk In CampTimers::Check(): Removed timer with null character
20:31:21.607 D Char Loading 12 characters for account_id: 13
20:31:21.610 D Char Loaded 3 characters for account_id: 13
20:31:21.611 D Net Net:Loading character inventory for Shargash.
20:31:21.611 D Char Loading Inventory for character_id 1
20:31:21.616 I Char Loaded 44 items for character_id 1
20:31:21.616 D Net Net:Character inventory loaded.
20:31:21.619 D Net Net:Loading character inventory for Kaede.
20:31:21.620 D Char Loading Inventory for character_id 4
20:31:21.624 I Char Loaded 33 items for character_id 4
20:31:21.624 D Net Net:Character inventory loaded.
20:31:21.627 D Net Net:Loading character inventory for Harqush.
20:31:21.628 D Char Loading Inventory for character_id 10
20:31:21.630 I Char Loaded 19 items for character_id 10
20:31:21.630 D Net Net:Character inventory loaded.
20:31:22.044 D Char Loading 12 characters for account_id: 13
20:31:22.049 D Char Loaded 3 characters for account_id: 13
20:31:22.052 D Net Net:Loading character inventory for Shargash.
20:31:22.061 D Char Loading Inventory for character_id 1
20:31:22.067 I Char Loaded 44 items for character_id 1
20:31:22.069 D Net Net:Character inventory loaded.
20:31:22.072 D Net Net:Loading character inventory for Kaede.
20:31:22.072 D Char Loading Inventory for character_id 4
20:31:22.077 I Char Loaded 33 items for character_id 4
20:31:22.078 D Net Net:Character inventory loaded.
20:31:22.082 D Net Net:Loading character inventory for Harqush.
20:31:22.086 D Char Loading Inventory for character_id 10
20:31:22.090 I Char Loaded 19 items for character_id 10
20:31:22.091 D Net Net:Character inventory loaded.
20:31:23.210 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.350 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.351 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.352 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.353 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.356 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.357 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.369 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.370 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.374 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.375 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.379 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.379 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.383 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.384 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.388 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.389 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.393 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.393 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.396 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.397 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.401 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.402 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.406 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.410 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.411 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.415 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.416 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.419 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.420 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.437 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.438 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.441 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.442 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.443 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.444 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.447 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.448 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.451 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.452 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.456 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.457 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.460 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.461 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.464 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.465 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.466 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.466 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.469 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.470 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.474 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.475 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.476 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.488 I UDP Client from 192.168.144.21:53397 has been removed.
20:31:23.489 I UDP Client from 192.168.144.21:53397 has been removed.[/quote]

I stopped the server, but got the Windows crash dialog. I restarted the server and the client, but had the same thing happen again (not as many messages though, as I hadn't been logged on very long. I camped and quit the client, stopped the server (Windows crash dialog again), and killed the launchpad.

When I started everything back up again (server, launchpad, then client), everything was fine.

[John Adams]

Are you running your world from Visual Studio / Debug? If so, try it again and get the call stack. I'm betting we'll find a crash in the function that handles kicking duplicate clients. Our connect/reconnect code is very rudimentary, and my hope is it will grow more robust as we continue development. Right now, there's no developers familiar with the process as good as Scatman or Lokked so it's a very long trial and error process.

Thanks for the possible steps to reproduce though, if that is consistent, it's likely we can get closer to a solution.

[Xinux]

Also don't think he is running the current code where i adjusted kickdupeclient also.

[shargash]

Xinux, I'm running the public SVN (1521).

John, I was not running VS/debug. I have VS, so I can try that, though its not something I've done in a couple decades. I intend to try to reproduce the issue, but I have been insanely busy in RL, so I only have a few minutes here and there to get in the game. That should change after Sunday, at least for a bit.

[shargash]

I was able to recreate this after only a few tries. However, I think my debugging skills are not up to the job. I was able to attach VS to the process, but I wasn't sure how to get the call stack (I got nasty grams about not having the symbol tables), and I wasn't sure exactly when in the process you wanted the call stack from. So I guess I'm either going to need some instruction, or I can try to recreate the problem on someone else's server (or post detailed instructions so someone else can recreate it).

Thoughts?

[Xinux]

Can you get it happen on NT?

[shargash]

I don't know if I can do it on NT. I don't have access to the server log, so it will be difficult for me to know if I've succeeded or not. The first time I did it, I saw really bad packet lag (10,000+ ms), but the second time I did not. I thought I had failed until I camped and saw the multiple disconnect and removed messages. The second time I was online and running around for 10-15 minutes. I don't remember how long I was on the first time, when the packet lag was bad, but it was at least twice that long. It is something that appears to build over time, and maybe it doesn't cause lag until it has gone past a certain point.

Also, I didn't want to hose NT if no one was watching it.

[Moldew]

Followed his steps, cannot make NT crash. OK to close?

[shargash]

I've been very busy lately (lots of traveling). I should have some time this week to bang on it. However, if it hasn't happened to anyone else, I would say close it. Even if I can recreate it, I'm still running 1521 at home.

If I can recreate it at home, I'll see if I can break Targonor. The only problem with that is that I won't necessarily know if I broke it or not.