Wideclient/Server Problem

[StuJ]

Pete,

I would be grateful if you have any suggestions as to the following.

I have 3 computers on the network (Laptop, PFD, EICAS) connecting through WideFS.

I have attached a Wideserver log which shows what happens typically -

Laptop and EICAS connect fine, but for some reason the PFD computer keeps reconnecting even though Wideserver reports a connection has been established.

It's reproducible every time, but the number of attempts it makes varies (or I get too many connections and shut down Wideclient on the PFD computer manually) - in the case below it stopped at 5 connections.

I use a shutdown hotkey and the Wideclients on the respective computers to close applications as well - again you can see in the log file that the Laptop and EICAS connections are reported disconnected at the end of the session, but the connection to PFD (which I presume was the one on skt 1896 in this case) is not reported disconnected (although it was working as I had been flying with my PM PFD on it).

This also fits in with the applications - they do shut down on Laptop and EICAS, but not on the PFD computer.

I have tried with both TCP and IPX on the PFD machine but it does not seem to make any difference.

The interesting thing in all of this is that I do get a WideFS connection - and it obviously works, but I have to restart so many times on so many occasions to get a low enough number of connections to make it useable that it's driving me nuts!

Are there any Wideserver / Wideclient settings that I can change to try and troubleshoot what's happening?

Thanks,

Stuart

********* WideServer.DLL Log [version 6.41] *********

Blocksize guide = 4096 (double allowed)

Date (dmy): 12/11/04, Time 18:19:00.937: Server name is MAINCOMPUTER

130375 Initialising TCP/IP server

130375 Initialising IPX/SPX server

130375 ServerNode=13330.61389.0.0.512

142531 Restarting service due to total lack of use

532531 Incoming connection Accepted ok (skt=5472)

532953 Connected to computer "LAPTOP" (skt=5472)

664672 Incoming connection Accepted ok (skt=4804)

664734 Connected to computer "PFD" (skt=4804)

684750 Incoming connection Accepted ok (skt=5124)

688625 Connected to computer "PFD" (skt=5124)

709890 Incoming connection Accepted ok (skt=2272)

709906 Connected to computer "PFD" (skt=2272)

729906 Incoming connection Accepted ok (skt=5268)

729969 Connected to computer "PFD" (skt=5268)

750000 Incoming connection Accepted ok (skt=1896)

750062 Connected to computer "PFD" (skt=1896)

850109 Incoming connection Accepted ok (skt=5464)

850375 Connected to computer "EICAS" (skt=5464)

8143375 Shutdown broadcast requested by hotkey!

8143437 Shutdown request received!

8145500 Error 10054: client socket disconnected at Client: removing (skt=5464)

8149375 Error 10053: client socket disconnected at Client: removing (skt=5472)

8151547 Closing down now ...

Memory managed: Offset records: 457 alloc, 457 free

Throughput maximum achieved: 69 frames/sec, 17245 bytes/sec

Throughput average achieved for complete session: 25 frames/sec, 4043 bytes/sec

********* Log file closed *********

[Pete Dowson]

I have attached a Wideserver log which shows what happens typically -

Laptop and EICAS connect fine, but for some reason the PFD computer keeps reconnecting even though Wideserver reports a connection has been established.

Since it is the client which is reconnecting, there will obviously be more useful information in the Client log file. There's none here. Perhaps I may be able to advise more if you showed me the relevant log?

Also, try a process of elimination -- try the PFD on a different PC, to see if it's that PC or something to do with the PFD program.

If the problem moves with the PFD then it is likely to be related to the OpenGL drivers. It may be related to them even if it doesn't move, supposing you have different video cards or drivers on each PC.

Otherwise, it may be a bad network card, cable, port on a hub or switch, or something not set up right in Windows. It may be conflicting IRQscheck through the complete list of potential problems provided in the WideFS documentation.

But the first step is to look at the apropriate Log to see what the errors are which are causing reconnections.

Regards

Pete

[StuJ]

Pete,

Also, try a process of elimination -- try the PFD on a different PC, to see if it's that PC or something to do with the PFD program.

The PFD runs fine on the other PC's - it is definitely only this PC which is the problem.

Otherwise, it may be a bad network card, cable, port on a hub or switch, or something not set up right in Windows

I'm confident it is not - if it is I have no idea what could be wrong. I can run everything else on the network fine - share files / browse folders / use the internet / run other applications on this PC.

But the first step is to look at the apropriate Log

Below is the client log from the same event. Again, what I can't understand is why WideClient says "Connection made okay!" and then tries to connect again.

Regards,

Stuart

********* WideClient.DLL Log [version 6.41] Class=FS98MAIN *********

Date (dmy): 12/11/04, Time 18:30:00.796: Client name is PFD

421 Attempting to connect now

593 Trying TCP/IP host "Maincomputer" port 8002 ...

593Okay, IP Address = 192.168.1.101

593 Connection made okay!

7218 New Client Application: "pfd" (Id=1752)

20625 Timed out response: connection assumed lost!

20640 Ready to try connection again

20656 Attempting to connect now

20671 Connection made okay!

45718 Timed out response: connection assumed lost!

45734 Ready to try connection again

45796 Attempting to connect now

45812 Connection made okay!

65843 Timed out response: connection assumed lost!

65843 Ready to try connection again

65859 Attempting to connect now

65859 Connection made okay!

85906 Timed out response: connection assumed lost!

85906 Ready to try connection again

85937 Attempting to connect now

85937 Connection made okay!

7491828 Error on client post-Connection Select() [Error=10053] Software caused connection abort

7491843 Ready to try connection again

7491843 Attempting to connect now

7493031 Error on client pre-Connection Select() [Error=10061] Connection refused

7493031 Ready to try connection again

7493078 Attempting to connect now

7515750 READSTATEDATA received with bad data size!

7515750 0 ReadLocal: Offset=8C000000, Size=0008

7521031 0 ReadLocal: Offset=8C000000, Size=0008

7523687 0 ReadLocal: Offset=8C000000, Size=0008

7526343 0 ReadLocal: Offset=8C000000, Size=0008

7531734 0 ReadLocal: Offset=8C000000, Size=0008

7534390 0 ReadLocal: Offset=8C000000, Size=0008

7537062 0 ReadLocal: Offset=8C000000, Size=0008

7539703 0 ReadLocal: Offset=8C000000, Size=0008

7542359 0 ReadLocal: Offset=8C000000, Size=0008

7547750 0 ReadLocal: Offset=8C000000, Size=0008

7550406 0 ReadLocal: Offset=8C000000, Size=0008

7553109 0 ReadLocal: Offset=8C000000, Size=0008

7555812 0 ReadLocal: Offset=8C000000, Size=0008

7561234 0 ReadLocal: Offset=8C000000, Size=0008

7566640 0 ReadLocal: Offset=8C000000, Size=0008

7569296 0 ReadLocal: Offset=8C000000, Size=0008

7572000 0 ReadLocal: Offset=8C000000, Size=0008

7574671 0 ReadLocal: Offset=8C000000, Size=0008

7577343 0 ReadLocal: Offset=8C000000, Size=0008

7580015 0 ReadLocal: Offset=8C000000, Size=0008

7582703 0 ReadLocal: Offset=8C000000, Size=0008

7584578 Shutdown request received!

7585187 Reception maximum achieved: 0 frames/sec, 0 bytes/sec

7585187 Max receive buffer = 2710, Max send depth = 2

7585187 ********* Log file closed (Buffers: MaxUsed 3, Alloc 241726 Freed 241726 Refused 0) *********

[StuJ]

Pete,

I started a new topic on the Server node as I did not want to over-complicate things here. I don't know if it is also related to this issue or not.

Thanks for any help.

Regards,

Stuart

[Pete Dowson]

I'm confident it is not - if it is I have no idea what could be wrong. I can run everything else on the network fine - share files / browse folders / use the internet / run other applications on this PC.

Nevertheless, the Log simply shows a total inability of this PC to be used for WideFS together with PFD. Something is wrong on that PC, but what it could be is going to be a problem isolating.

Below is the client log from the same event. Again, what I can't understand is why WideClient says "Connection made okay!" and then tries to connect again.

...

20625 Timed out response: connection assumed lost!

20640 Ready to try connection again

20656 Attempting to connect now

20671 Connection made okay!

That sort of sequence is normal once or twice whilst FS is loading on the Server. It just means WideServer isn't getting enough time to send responses to clients in a timely manner. Though why you have a series of 4 of these at 20/25 second intervals is indeed rather strange. Something is stopping the traffic for several seconds every 20/25 seconds. That doesn't sound very FS-like -- especially if the other Clients don't show a similar pattern. Check what other processes you have running on that client.

After that, however, there are no reported errors for over two HOURS! Did you have a good flight for those two hours? What was happening? Or have you merely deleted a large part of the log because it was repetitive?

Then the rest of the sequence looks like FS was closed so the service disappeared. Did it?

7491828 Error on client post-Connection Select() [Error=10053] Software caused connection abort

7491843 Ready to try connection again

7491843 Attempting to connect now

7493031 Error on client pre-Connection Select() [Error=10061] Connection refused

7493031 Ready to try connection again

7493078 Attempting to connect now

These next errors are from the Client program (PFD), and show that it was in an odd state:

7515750 READSTATEDATA received with bad data size!

7515750 0 ReadLocal: Offset=8C000000, Size=0008

7521031 0 ReadLocal: Offset=8C000000, Size=0008

7523687 0 ReadLocal: Offset=8C000000, Size=0008

7526343 0 ReadLocal: Offset=8C000000, Size=0008

7531734 0 ReadLocal: Offset=8C000000, Size=0008

7534390 0 ReadLocal: Offset=8C000000, Size=0008

7537062 0 ReadLocal: Offset=8C000000, Size=0008

7539703 0 ReadLocal: Offset=8C000000, Size=0008

7542359 0 ReadLocal: Offset=8C000000, Size=0008

7547750 0 ReadLocal: Offset=8C000000, Size=0008

7550406 0 ReadLocal: Offset=8C000000, Size=0008

7553109 0 ReadLocal: Offset=8C000000, Size=0008

7555812 0 ReadLocal: Offset=8C000000, Size=0008

7561234 0 ReadLocal: Offset=8C000000, Size=0008

7566640 0 ReadLocal: Offset=8C000000, Size=0008

7569296 0 ReadLocal: Offset=8C000000, Size=0008

7572000 0 ReadLocal: Offset=8C000000, Size=0008

7574671 0 ReadLocal: Offset=8C000000, Size=0008

7577343 0 ReadLocal: Offset=8C000000, Size=0008

7580015 0 ReadLocal: Offset=8C000000, Size=0008

7582703 0 ReadLocal: Offset=8C000000, Size=0008

Finally, a shutdown actually gets seen? Not sure how that got through here:

7584578 Shutdown request received!

and the performance figures actually show that almost nothing was ever received from the Server:

7585187 Reception maximum achieved: 0 frames/sec, 0 bytes/sec

7585187 Max receive buffer = 2710, Max send depth = 2

My first suspicions would actually fall upon the PFD program's use of OpenGL on that PC. See if you can run something else on WideFS on that PC instead, whether another non-OpenGL part of PM or some utility -- like my own TrafficLook and WeatherSet2 programs, for instance. If they run fine, with no problems, then you need to start looking at video drivers and checking out OpenGL and IRQ clashes in particular. PM support should be able to help with that.

If you get problems with any and all WideFS client programs, then it is going to be a matter of elimination of each potential contributor, one at a time -- driver and Windows settings (compare with other PCs), Network card, cable, connection at hub/switch.

Regards,

Pete

[Pete Dowson]

I started a new topic on the Server node as I did not want to over-complicate things here. I don't know if it is also related to this issue or not.

Not related, no, but it is a silly WideServer bug. Thanks for spotting it!

Pete

[StuJ]

Pete,

Thanks for your replies -

Nevertheless, the Log simply shows a total inability of this PC to be used for WideFS together with PFD

Sorry may have given you the wrong idea here - may be because I've made references to both the PC (named "PFD" on the network) and the software running on it (which is PM's - also "PFD").

I'm not looking to solve a problem with the PFD software (when Wideclient evetually connects everything works fine) - so you can discount this.

I have tried it out this morning by just starting up Wideclient without running anything else - the same thing happens regardless of whether I run software or not i.e it goes to 5,6,7,8 connections before finally stopping. When I say stopping I mean that Wideclient has become "stable" and does not try to connect anymore.

Whatever software I use through Wideclient after that point works fine.

After that, however, there are no reported errors for over two HOURS! Did you have a good flight for those two hours? What was happening? Or have you merely deleted a large part of the log because it was repetitive?

Yes - confirmed, everthing is OK after this.

Once Wideclient "stabilizes" then there's no problem and everything works fine.

I'm just trying to solve why Wideclient opens several connections on initial startup which I do not understand why it is doing when it says connection made okay.

The number of actual connections made can vary each time I start it up - it's never been only 1, occassionaly seems to be happy after only 2, commonly is 5 or 6 but occassionally just keeps going opening more connections).

Then the rest of the sequence looks like FS was closed so the service disappeared. Did it?

Yes - after the flight I use a shutdown hotkey through Wideserver.

The other 2 PC's close down the applications as expected.

On the "problematic" PC (PFD), the application stays open for several minutes - I think until Wideclient realises FS has gone and then quits.

and the performance figures actually show that almost nothing was ever received from the Server:

7585187 Reception maximum achieved: 0 frames/sec, 0 bytes/sec

7585187 Max receive buffer = 2710, Max send depth = 2

I may be wrong but I think this is the most interesting bit.

On which connection is it reporting the performance? Or is it an average over all of them?

If it's the one which it thinks is "active" at the time - then this doesn't surprise me. There HAD been data exchanged because I'd been using the PM PFD (on the "PFD" PC) for the last hour and a half. However I suspect that this was all through the very first connection made by Wideclient (which it did report OK when it was initially made).

It seems to me that Wideclient is establishing a connection successfully - for some reason it just keeps opening more of them before it is "happy".

I hope this explains the problem a little better. In summary, this is what I THINK seems to be happening with my comments below. Am probably completely wrong but here we go......

********* WideClient.DLL Log [version 6.41] Class=FS98MAIN *********

Date (dmy): 12/11/04, Time 18:30:00.796: Client name is PFD

421 Attempting to connect now

593 Trying TCP/IP host "Maincomputer" port 8002 ...

593Okay, IP Address = 192.168.1.101

593 Connection made okay!

Wideclient has started on the PFD computer and made a connection

7218 New Client Application: "pfd" (Id=1752)

The PM PFD.EXE has been started successfully by Wideclient. At this point I have functioning software.

20625 Timed out response: connection assumed lost!

20640 Ready to try connection again

20656 Attempting to connect now

20671 Connection made okay!

For some reason Wideclient says the connection has been lost and starts another one (but PFD.EXE is still running happily and talking to FS. FS title bar now reports 2 connections)

45718 Timed out response: connection assumed lost!

45734 Ready to try connection again

45796 Attempting to connect now

45812 Connection made okay!

Same thing again - now FS reports 3 connections

65843 Timed out response: connection assumed lost!

65843 Ready to try connection again

65859 Attempting to connect now

65859 Connection made okay!

and again - 4 connections

85906 Timed out response: connection assumed lost!

85906 Ready to try connection again

85937 Attempting to connect now

85937 Connection made okay!

and again - 5 connections

Now it stops - I am calling this "wideclient stabilized".

I can continue flying - everthing works fine.

BUT - I think the data exchange is actually taking place over the very first connection made at line 7218.

Is this possible?

Finally - just to confirm - if I do not run the PFD.exe and just leave it as Wideclient running, the same thing happens (except for line 7218 obviously) - repeated connections at approx 20 second intervals until it becomes "stable".

Thanks again for your time, much appreciated.

Regards,

Stuart

[Pete Dowson]

I have tried it out this morning by just starting up Wideclient without running anything else - the same thing happens regardless of whether I run software or not i.e it goes to 5,6,7,8 connections before finally stopping. When I say stopping I mean that Wideclient has become "stable" and does not try to connect anymore.

Whatever software I use through Wideclient after that point works fine.

Well, yes, I evidently completely misunderstood you.

If those reconnections are recurring every 20-25 seconds then something, some process somewhere, is somehow getting in the way. How or why it gets out of the way, I've no idea. Sorry.

I'm just trying to solve why Wideclient opens several connections on initial startup which I do not understand why it is doing when it says connection made okay.

You misunderstand. It is not opening several connections. It opens one, gets no response, times out, assumed that connection is bad, closes it and opens another. The only reason the Server records more than one is that its timeout, before closing its end, is longer than the clients. If I had both timeouts the same things would go wrong. It is better that the Server is more tolerant than the Client.

This business of apparent multiple connections is explained clearly in the WideFS document.

Yes - after the flight I use a shutdown hotkey through Wideserver.

The other 2 PC's close down the applications as expected.

On the "problematic" PC (PFD), the application stays open for several minutes - I think until Wideclient realises FS has gone and then quits.

No, there is no mechanism in WideClient for "realising FS has gone". In fact it should stay running during any number of FS close-reopens. It does here. In my case it saves me reloading everything when I'm running successive tests on a developing FSUIPC.

The log clearly shows that WideClient did, in fact, receive the shutdown request and it is that which caused it to close. Why there's a delay I don't know -- usually it is the client applications taking their time closing that causes this.

I may be wrong but I think this is the most interesting bit.

On which connection is it reporting the performance? Or is it an average over all of them?

There is only ever one connection at a time as far as the client is concerned. Please peruse the WideFS document some time, it does explain the apparent multiple connections at the server. I also explained it above.

It seems to me that Wideclient is establishing a connection successfully - for some reason it just keeps opening more of them before it is "happy".

No, there is no such mechanism. It will close one connection and open another if there's a timeout. The server is not informed of a client connection closing. There is no mechanism for that in the Winsock server-client protocols. The server just serves anything that comes. I keep records internally so I can recognise the same client if it comes back. If it doesn't I can only wait a long time then assume it died.

For some reason Wideclient says the connection has been lost and starts another one

It isn't "for some reason". It clearly states the reason. That's what the part saying "Timed out response" is for!!! Did you miss that?

(but PFD.EXE is still running happily and talking to FS. FS title bar now reports 2 connections)

PFD.EXE does not talk to FS, it talks to WideClient. That part is always maintained. There would be a jerk/stutter in any dials or reading whilst the connection is re-made. As you can see from the times on the left of the log (they are in milliseconds), the disruption each time is only about a tenth of a second. Enough for a stutter, but nothing else.

I explained the multiple connections reported by the Server, and it is also explained in the WideFS.doc, which I urge you to read sometime, please.

BUT - I think the data exchange is actually taking place over the very first connection made at line 7218.

Is this possible?

No, there is only one connection at a time. The data is being exchanged, but for some reason it is very slow to start with. Why, I have no idea. Something is going on in that PC which is doing it.

Regards,

Pete

[StuJ]

Pete,

Thanks again - this helps a lot.

I did read the WideFS documents (again) - honest! but it still wasn't clear to me what was happening. Now I have a much better understanding over the "multiple connections" not actually being duplicates.

I have done more testing this afternoon and have found a workaround - if I start the "PFD" Wideclient first then all is well and I don't get the timeouts.

If I start it after one of the other two have already started (one runs the CDU and the other runs the EICAS), then I get the timeouts back.

It never used to be this way, and I'm still no closer to why it's started doing this in the last few weeks - but at least I know what to do to make it work again for now!

Thanks,

Stuart