widefs delay

pdpo · March 9, 2011

Hi Peter,

I was trying out LUA and made a script called Initial.LUA in the widefs directory.

Reading only the parking brake offset for 100 times and then stopping the lua script.

Between each read action I wait 500msecs. I expect 32767 for the value but I read 0 for the first 20 seconds.

After this 20 secs the value is 32767. Is it normal it takes soo long?

I handled it for now by putting a while loop which ends when the FS day of year is different to 0 (offset 0x23E).

Greetz Peter

Pete Dowson · March 14, 2011

I was trying out LUA and made a script called Initial.LUA in the widefs directory.

Reading only the parking brake offset for 100 times and then stopping the lua script.

Between each read action I wait 500msecs. I expect 32767 for the value but I read 0 for the first 20 seconds.

After this 20 secs the value is 32767. Is it normal it takes soo long?

No. Once the data has arrived in the WideClient memory it is read directly from memory. The updating of the WideClient memory is done asynchronously, when it changes, so once things are running everything is very fast indeed.

The first seconds after WideClient connects are always taken up by administrative operations. There's a 500 mSec imposed wait for data until that part of the initialisation is finished. The 500 mSecs can be adjusted by a documented parameter, but it usually isn't worth it -- you would only be slowing down the initialisation sequences.

Regards

Pete

pdpo · March 16, 2011

Any idea then what could be the cause that I see it taking up 20secs to get the data?

After this 20secs the updates are indeed very fast but this initial delay is what worries me?

Greetings Peter

No. Once the data has arrived in the WideClient memory it is read directly from memory. The updating of the WideClient memory is done asynchronously, when it changes, so once things are running everything is very fast indeed.

The first seconds after WideClient connects are always taken up by administrative operations. There's a 500 mSec imposed wait for data until that part of the initialisation is finished. The 500 mSecs can be adjusted by a documented parameter, but it usually isn't worth it -- you would only be slowing down the initialisation sequences.

Regards

Pete

Pete Dowson · March 16, 2011

Any idea then what could be the cause that I see it taking up 20secs to get the data?

After this 20secs the updates are indeed very fast but this initial delay is what worries me?

I thought I explained? Why is it worrying? If you really want to know the complete ins and outs of what it is doing, please set "Log=DebugAll" in the [user] section of the client INI file, and wade through the first 20 seconds of the resulting Log file.

Incidentally, it isn't anywhere near 20 seconds on any of my systems, so it must be very system dependent, and probably more controlled by what is happening in the FS side of the equation.

Regards

Pete

pdpo · March 17, 2011

Peter,

the fact that on your systems it doesnt take so long and on my system it take 20 seconds is exactly why I call it worrying.

My FS PC is a core I7 running at 3.2Ghz and running only FS2004. So that Pc should be even overkill. The PC on which i was trying out

this LUA script is my laptop which is also a 2.3Ghz dual core...so also not that slow right?

And in the logfile I looked upon I saw the lua values and eacht time I tried it it took always about 20 seconds for the value of the

parking brake to be correct.

For this I was asking what I could do to debug to find out why it takes soo long as I think there must be something in my side I guess.

Thanks for your time.

Greetings Peter Depoortere

Added some info :

initial.log (logfile of the LUA script)

********* LUA: "Initial" Log [from WideClient] *********

Date (dmy): 17/03/11, Time 17:10:48.921: Client name is BEANTN0L019704

328 LUA: beginning "D:\Poorterp_nbu\AviationInfo\Fsuipc-WideFs\Initial.LUA"

328 LUA: Starting my script ACCELL.LUA reading 0x23E until diff to 0

328 LUA: 0x23E is still 0

1328 LUA: 0x23E is still 0

2344 LUA: 0x23E is still 0

3344 LUA: 0x23E is still 0

4344 LUA: 0x23E is still 0

5344 LUA: 0x23E is still 0

6344 LUA: 0x23E is still 0

7344 LUA: 0x23E is still 0

8344 LUA: 0x23E is still 0

9344 LUA: 0x23E is still 0

10360 LUA: 0x23E is still 0

11360 LUA: 0x23E is still 0

12360 LUA: 0x23E is still 0

13360 LUA: 0x23E is still 0

14360 LUA: 0x23E is still 0

15360 LUA: 0x23E is still 0

16360 LUA: 0x23E is still 0

17360 LUA: 0x23E is still 0

18375 LUA: 0x23E is still 0

19375 LUA: 0x23E is still 0

20375 LUA: 0x23E is still 0

21500 LUA: 0x23E is now different to 0

********* LUA execution terminated: Log Closed *********

from this I deduct that it took 21500 milliseconds until the correct value is received. correct?

I have also enabled the log=DebugAll (of course this is quite a lot of info)

********* WideClient Log [version 6.841] Class=FS98MAIN *********

Date (dmy): 17/03/11, Time 17:10:48.625: Client name is BEANTN0L019704

250 Timing Thread Started <M1:L0:C0>

313 KeyHook added: 259=0,0,FS98MAIN, <M0:L0:C0>

313 KeyHook added: 260=0,0,FS98MAIN, <M0:L0:C0>

328 In MessageLoop <M0:L1:C0>

328 SendReq Thread Started <M0:L1:C0>

328 Attempting to connect now <M0:L1:C0>

328 Trying UDP/IP addr 10.0.0.9, port 8002 ... <M0:L1:C0>

328 UDP connectionless mode set up okay! <M0:L1:C0>

328 In MessageLoop <M0:L0:C3>

328 WSA_READ Entry <M0:L1:C3>

328 WSA_READ FD_WRITE <M0:L1:C3>

328 WSA_READ Exit1 <M0:L1:C3>

328 In MessageLoop <M0:L1:C3>

328 In MessageLoop <M0:L0:C3>

375 WM_MYTIMER still okay in LAN thread <M0:L1:C3>

375 In MessageLoop <M0:L0:C3>

375 WSA_READ Entry <M0:L1:C3>

375 WSA_READ FD_READ <M0:L1:C3>

375 WSA_READ recv() <M0:L1:C3>

375 GetRecv() done, zero <M0:L1:C3>

375 WSA_READ free buffer <M0:L1:C3>

375 WSA_READ Exit2 <M0:L1:C3>

406 In MessageLoop <M0:L0:C3>

500 WM_MYTIMER still okay in main thread <M1:L0:C3>

500 Sending computer name and requesting base data ... <M1:L0:C3>

500 Button Thread Started <M1:L0:C2>

531 In MessageLoop <M0:L0:C2>

531 MYSENDREQ Entry <M0:L0:C2>

531 MYSENDREQ [ok=1] send() done: 296 of 296 bytes <M0:L0:C2>

531 MYSENDREQ Exit <M0:L0:C2>

531 In MessageLoop <M0:L0:C2>

531 WSA_READ Entry <M0:L1:C2>

531 WSA_READ FD_WRITE <M0:L1:C2>

531 WSA_READ Exit1 <M0:L1:C2>

547 In MessageLoop <M0:L0:C2>

547 WSA_READ Entry <M0:L1:C2>

547 WSA_READ FD_READ <M0:L1:C2>

547 WSA_READ recv() <M0:L1:C2>

547 GetRecv() gets 329 <M0:L1:C2>

547 GetRecv() packet 329 <M0:L1:C2>

547 WSA_READ ProcessResponse <M0:L1:C2>

547 LAN data received: <M0:L1:C2>

PREQ ulSize=318, ulTime=0, uSum=23010, fUsed=0

98 05 00 FC 03 00 AA 00 17 71 03 00 FE 01 00 00 .........q......

0C 32 00 FC 04 00 38 AA 00 E2 FC 32 00 FE 02 00 .2....8....2....

01 00 04 33 00 FE 0A 00 17 00 89 39 07 00 DE FA ...3.......9....

06 00 20 33 00 FE 02 00 01 00 00 3E 00 FC 1F 00 .. 3.......>....

5C 5C 46 53 46 43 55 5C 46 53 32 30 30 34 5C 00 \\FSFCU\FS2004\.

53 00 46 53 55 49 50 43 2E 69 6E 69 AA 00 E3 02 S.FSUIPC.ini....

3F 00 FE 02 00 01 00 00 54 00 FE 06 00 48 01 48 ?.......T....H.H

01 48 01 00 5B 00 FC 10 00 5C 5C 46 43 55 5C 6E .H..[....\\FCU\n

65 74 64 69 72 5C AA 00 72 FF 81 00 FC 04 00 AA etdir\..r.......

00 FF 00 04 CC 00 FC 42 00 AA 00 0E 20 AA AA 00 .......B.... ...

34 4B 40 00 00 00 60 4C 68 48 40 AA 00 03 FC 6C 4K@...`LhH@....l

0B 00 53 3F 00 00 DC 11 24 FA 70 17 00 00 01 AA ..S?....$.p.....

00 04 0F 00 03 00 05 AA 00 B8 01 00 00 00 A3 02 ................

AA 00 FF AA 00 FF AA 00 FF 00 00 00 3D 00 FC 25 ............=..%

00 50 72 6F 6A 65 63 74 20 41 69 72 62 75 73 20 .Project Airbus

41 33 32 30 20 43 46 4D 20 50 41 32 20 53 61 62 A320 CFM PA2 Sab

65 6E 61 AA 00 DD 24 C8 00 FC 03 00 AA 00 03 F0 ena...$.........

0F 00 FC 03 00 AA 00 0B FC 0F 00 FC 06 00 AA 00 ................

FF AA 00 03 00 D0 00 FC 03 00 AA 00 07 D2 3B 00 ..............;.

FE 02 00 00 00 08 D0 00 FC 03 00 AA 00 0B ..............

547 --> Size and sumcheck okay <M0:L1:C2>

547 DeCompressed: Orig Size = 3, Full size = 24 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 00598:

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 00 00 00 00 ........

547 DeCompressed: Orig Size = 4, Full size = 228 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 0320C:

38 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 8...............

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 ....

547 DeCompressed: Orig Size = 31, Full size = 256 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 03E00:

5C 5C 46 53 46 43 55 5C 46 53 32 30 30 34 5C 00 \\FSFCU\FS2004\.

53 00 46 53 55 49 50 43 2E 69 6E 69 00 00 00 00 S.FSUIPC.ini....

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

547 DeCompressed: Orig Size = 16, Full size = 128 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 05B00:

5C 5C 46 43 55 5C 6E 65 74 64 69 72 5C 00 00 00 \\FCU\netdir\...

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

547 DeCompressed: Orig Size = 4, Full size = 257 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 081FF:

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 .

547 DeCompressed: Orig Size = 66, Full size = 1020 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 0CC04:

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 20 ...............

AA 34 4B 40 00 00 00 60 4C 68 48 40 00 00 00 00 .4K@...`LhH@....

FC 6C 0B 00 53 3F 00 00 DC 11 24 FA 70 17 00 00 .l..S?....$.p...

01 00 00 00 00 00 0F 00 03 00 05 00 00 00 00 00 ................

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 01 00 00 00 A3 02 00 00 00 00 00 00 ................

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 00 00 00 00 00 00 00 00 ............

547 DeCompressed: Orig Size = 37, Full size = 256 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 03D00:

50 72 6F 6A 65 63 74 20 41 69 72 62 75 73 20 41 Project Airbus A

33 32 30 20 43 46 4D 20 50 41 32 20 53 61 62 65 320 CFM PA2 Sabe

6E 61 00 00 00 00 00 00 00 00 00 00 00 00 00 00 na..............

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

547 DeCompressed: Orig Size = 3, Full size = 4 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 0C824:

00 00 00 00 ....

547 DeCompressed: Orig Size = 3, Full size = 12 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 00FF0:

00 00 00 00 00 00 00 00 00 00 00 00 ............

547 DeCompressed: Orig Size = 6, Full size = 260 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 00FFC:

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 ....

547 DeCompressed: Orig Size = 3, Full size = 8 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 0D000:

00 00 00 00 00 00 00 00 ........

547 DeCompressed: Orig Size = 3, Full size = 12 <M0:L1:C2>

547 Expanded data: <M0:L1:C2>

Offset 0D008:

00 00 00 00 00 00 00 00 00 00 00 00 ............

547 Connection made: receiving okay! <M0:L1:C2>

547 WSA_READ recv() <M0:L1:C1>

547 GetRecv() done, zero <M0:L1:C1>

547 WSA_READ free buffer <M0:L1:C1>

547 WSA_READ Exit2 <M0:L1:C1>

578 In MessageLoop <M0:L0:C1>

781 WSA_READ Entry <M0:L1:C1>

781 WSA_READ FD_READ <M0:L1:C1>

781 WSA_READ recv() <M0:L1:C1>

781 GetRecv() gets 19 <M0:L1:C1>

781 GetRecv() packet 19 <M0:L1:C1>

781 WSA_READ ProcessResponse <M0:L1:C1>

781 LAN data received: <M0:L1:C1>

PREQ ulSize=8, ulTime=1, uSum=613, fUsed=0

24 CC 00 FE 02 00 04 71 $......q

781 --> Size and sumcheck okay <M0:L1:C1>

781 WSA_READ recv() <M0:L1:C1>

781 GetRecv() done, zero <M0:L1:C1>

797 WSA_READ free buffer <M0:L1:C1>

797 WSA_READ Exit2 <M0:L1:C1>

... like this it continues .........

20235 WSA_READ Entry <M0:L1:C1>

20235 WSA_READ FD_READ <M0:L1:C1>

20235 WSA_READ recv() <M0:L1:C1>

20235 GetRecv() gets 19 <M0:L1:C1>

20235 GetRecv() packet 19 <M0:L1:C1>

20235 WSA_READ ProcessResponse <M0:L1:C1>

20235 LAN data received: <M0:L1:C1>

PREQ ulSize=8, ulTime=28, uSum=748, fUsed=0

24 CC 00 FE 02 00 3F BD $.....?.

20235 --> Size and sumcheck okay <M0:L1:C1>

20235 WSA_READ recv() <M0:L1:C1>

20235 GetRecv() done, zero <M0:L1:C1>

20250 In MessageLoop <M0:L1:C1>

20250 WSA_READ free buffer <M0:L1:C1>

20250 WSA_READ Exit2 <M0:L1:C1>

20281 In MessageLoop <M0:L0:C1>

20422 WSA_READ Entry <M0:L1:C1>

20422 WSA_READ FD_READ <M0:L1:C1>

20422 WSA_READ recv() <M0:L1:C1>

20422 GetRecv() gets 102 <M0:L1:C1>

20422 GetRecv() packet 102 <M0:L1:C1>

20422 WSA_READ ProcessResponse <M0:L1:C1>

20422 LAN data received: <M0:L1:C1>

PREQ ulSize=91, ulTime=29, uSum=6704, fUsed=0

0F 33 00 FC 05 00 AA 00 10 01 00 00 3E 00 FC 1F .3..........>...

00 5C 5C 46 53 46 43 55 5C 46 53 32 30 30 34 5C .\\FSFCU\FS2004\

00 53 00 46 53 55 49 50 43 2E 69 6E 69 AA 00 E3 .S.FSUIPC.ini...

00 3D 00 FC 25 00 50 72 6F 6A 65 63 74 20 41 69 .=..%.Project Ai

72 62 75 73 20 41 33 32 30 20 43 46 4D 20 50 41 rbus A320 CFM PA

32 20 53 61 62 65 6E 61 AA 00 DD 2 Sabena...

20422 --> Size and sumcheck okay <M0:L1:C1>

20422 DeCompressed: Orig Size = 5, Full size = 19 <M0:L1:C1>

20422 Expanded data: <M0:L1:C1>

Offset 0330F:

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 01 00 ...

20422 DeCompressed: Orig Size = 31, Full size = 256 <M0:L1:C1>

20422 Expanded data: <M0:L1:C1>

Offset 03E00:

5C 5C 46 53 46 43 55 5C 46 53 32 30 30 34 5C 00 \\FSFCU\FS2004\.

53 00 46 53 55 49 50 43 2E 69 6E 69 00 00 00 00 S.FSUIPC.ini....

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

20422 DeCompressed: Orig Size = 37, Full size = 256 <M0:L1:C1>

20422 Expanded data: <M0:L1:C1>

Offset 03D00:

50 72 6F 6A 65 63 74 20 41 69 72 62 75 73 20 41 Project Airbus A

33 32 30 20 43 46 4D 20 50 41 32 20 53 61 62 65 320 CFM PA2 Sabe

6E 61 00 00 00 00 00 00 00 00 00 00 00 00 00 00 na..............

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

20422 WSA_READ recv() <M0:L1:C1>

20422 GetRecv() done, zero <M0:L1:C1>

20422 WSA_READ free buffer <M0:L1:C1>

20422 WSA_READ Exit2 <M0:L1:C1>

20438 In MessageLoop <M0:L0:C1>

20485 WM_MYTIMER still okay in LAN thread <M0:L1:C1>

20531 In MessageLoop <M0:L0:C1>

20813 WM_MYTIMER still okay in main thread <M1:L0:C1>

20844 In MessageLoop <M0:L0:C1>

20938 WSA_READ Entry <M0:L1:C1>

20938 WSA_READ FD_READ <M0:L1:C1>

20938 WSA_READ recv() <M0:L1:C1>

20938 GetRecv() done, zero <M0:L1:C1>

20938 WSA_READ free buffer <M0:L1:C1>

20938 WSA_READ Exit2 <M0:L1:C1>

20969 In MessageLoop <M0:L0:C1>

21250 WSA_READ Entry <M0:L1:C1>

21250 WSA_READ FD_READ <M0:L1:C1>

21250 WSA_READ recv() <M0:L1:C1>

21250 GetRecv() gets 19 <M0:L1:C1>

21250 GetRecv() packet 19 <M0:L1:C1>

21250 WSA_READ ProcessResponse <M0:L1:C1>

21250 LAN data received: <M0:L1:C1>

PREQ ulSize=8, ulTime=30, uSum=822, fUsed=0

24 CC 00 FE 02 00 85 C1 $.......

21250 --> Size and sumcheck okay <M0:L1:C1>

21250 WSA_READ recv() <M0:L1:C1>

21250 GetRecv() done, zero <M0:L1:C1>

21250 WSA_READ free buffer <M0:L1:C1>

21250 WSA_READ Exit2 <M0:L1:C1>

21250 In MessageLoop <M0:L0:C1>

21344 MYSENDREQ Entry <M0:L0:C1>

21344 MYSENDREQ [ok=1] send() done: 43 of 43 bytes <M0:L0:C1>

21344 MYSENDREQ Exit <M0:L0:C1>

21344 In MessageLoop <M0:L0:C1>

21344 WSA_READ Entry <M0:L1:C1>

21344 WSA_READ FD_WRITE <M0:L1:C1>

21344 WSA_READ Exit1 <M0:L1:C1>

21375 In MessageLoop <M0:L0:C1>

21375 LocalReadWrite Entry <M1:L0:C1>

21375 Local message entry <M1:L0:C1>

21375 Processing request now ... <M1:L0:C1>

21375 ProcessRequest: processing the request <M1:L0:C1>

21375 Exiting ProcessRequestData <M1:L0:C1>

21375 ProcessRequest: dealing with response <M1:L0:C1>

21375 MakeSmaller: Orig Size = 64 <M1:L0:C1>

here I see the first time something about processing of offset 23E

21375 FS6IPC Data Processed <M1:L0:C1>

PREQ ulSize=53, ulTime=21375, uSum=672, fUsed=1

01 00 00 00 3E 02 00 00 02 00 00 00 2C 74 61 73 ....>.......,tas

2C 67 01 00 00 00 0F 33 00 00 13 00 00 00 00 00 ,g.....3........

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 00 .....

21375 ProcessRequestData: Need read at offset 023F <M1:L0:C1>

21375 Removed unneeded entry Offset 330F, Size 19 <M1:L0:C1>

21375 MakeSmaller: New Size = 27 <M1:L0:C1>

21375 LAN Data sent <M1:L0:C1>

PREQ ulSize=16, ulTime=21375, uSum=551, fUsed=1

01 70 00 00 3E 02 00 00 02 00 00 00 2C 74 61 73

21375 READNEEDED: Offset 023F, p=008F9E80, p2=008F9E80, nslot=0, p->fDone=x80, p->dwOffNeeded=023F <M1:L0:C1>

21375 Adding Request Block now ... <M1:L0:C1>

21406 MYSENDREQ Entry <M1:L0:C1>

21406 In MessageLoop <M1:L0:C1>

21406 MYSENDREQ [ok=1] send() done: 27 of 27 bytes <M1:L0:C1>

21406 MYSENDREQ Exit <M1:L0:C1>

21406 In MessageLoop <M1:L0:C1>

21406 WSA_READ Entry <M1:L1:C1>

21406 WSA_READ FD_WRITE <M1:L1:C1>

21406 WSA_READ Exit1 <M1:L1:C1>

21453 In MessageLoop <M1:L0:C1>

21500 WSA_READ Entry <M1:L1:C1>

21500 WSA_READ FD_READ <M1:L1:C1>

21500 WSA_READ recv() <M1:L1:C1>

21500 GetRecv() gets 19 <M1:L1:C1>

21500 GetRecv() packet 19 <M1:L1:C1>

21500 WSA_READ ProcessResponse <M1:L1:C1>

21500 LAN data received: <M1:L1:C1>

PREQ ulSize=8, ulTime=31, uSum=396, fUsed=0

3E 02 00 FE 02 00 4C 00 >.....L.

21500 --> Size and sumcheck okay <M1:L1:C1>

21500 ProcessResponse: Read needed offset 023F <M1:L1:C1>

21500 WSA_READ recv() <M1:L1:C1>

21500 GetRecv() done, zero <M1:L1:C1>

21500 ProcessRequest: needed read accomplished <M1:L1:C1>

21500 ProcessRequest: preparing results <M1:L1:C1>

21500 125 ReadOk: Offset=023E, Size=0002

4C 00

21500 Exiting ProcessRequestData <M1:L1:C1>

21500 ProcessRequest: Exit <M1:L1:C1>

21500 FS6IPC message Exit2 <M1:L1:C1>

21500 LocalReadWrite Entry <M1:L1:C1>

21500 Local message entry <M1:L1:C1>

21500 Processing request now ... <M1:L1:C1>

21500 ProcessRequest: processing the request <M1:L1:C1>

21500 Exiting ProcessRequestData <M1:L1:C1>

21500 ProcessRequest: dealing with response <M1:L1:C1>

21500 MakeSmaller: Orig Size = 64 <M1:L1:C1>

21500 FS6IPC Data Processed <M1:L1:C1>

PREQ ulSize=53, ulTime=21500, uSum=748, fUsed=1

01 00 00 00 C8 0B 00 00 02 00 00 00 2C 74 61 73 ............,tas

4C 00 01 00 00 00 0F 33 00 00 13 00 00 00 00 00 L......3........

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 00 .....

21500 ProcessRequestData: Need read at offset 0BC9 <M1:L1:C1>

21500 Removed unneeded entry Offset 330F, Size 19 <M1:L1:C1>

21500 MakeSmaller: New Size = 27 <M1:L1:C1>

21500 LAN Data sent <M1:L1:C1>

PREQ ulSize=16, ulTime=21500, uSum=698, fUsed=1

01 70 00 00 C8 0B 00 00 02 00 00 00 2C 74 61 73

21500 READNEEDED: Offset 0BC9, p=008F9E80, p2=008F9E80, nslot=0, p->fDone=x80, p->dwOffNeeded=0BC9 <M1:L1:C1>

21500 Adding Request Block now ... <M1:L1:C1>

21500 WSA_READ free buffer <M1:L1:C1>

21500 WSA_READ Exit2 <M1:L1:C1>

I thought I explained? Why is it worrying? If you really want to know the complete ins and outs of what it is doing, please set "Log=DebugAll" in the [user] section of the client INI file, and wade through the first 20 seconds of the resulting Log file.

Incidentally, it isn't anywhere near 20 seconds on any of my systems, so it must be very system dependent, and probably more controlled by what is happening in the FS side of the equation.

Regards

Pete

Pete Dowson · March 17, 2011

the fact that on your systems it doesnt take so long and on my system it take 20 seconds is exactly why I call it worrying.

My FS PC is a core I7 running at 3.2Ghz and running only FS2004. So that Pc should be even overkill. The PC on which i was trying out

this LUA script is my laptop which is also a 2.3Ghz dual core...so also not that slow right?

Sorry, I can't really make a true comparison. I'm using FSX and it's a long time since I used FS2004 on a network.

And in the logfile I looked upon I saw the lua values and eacht time I tried it it took always about 20 seconds for the value of the
parking brake to be correct.

That's for first time -- it is fast when the initial housekeeping is over, right? What exactly is the problem you want to resolve? If it runs okay when it is running, what is the worry?

For this I was asking what I could do to debug to find out why it takes soo long as I think there must be something in my side I guess.

I really don't know. Did you do the full log and plough through it as I suggested? It tells you exactly what WideCloient is getting up to.

Regards

Pete

pdpo · March 17, 2011

Peter,

checkout my previous post... i have added there the debug logs (partly of course)

your reply must have crossed my update of the posting

If you would need more of the wideclient log then you need to give me an email where I can send it to.

Is a bit large to get it into a post I think...

Greetings Peter

Sorry, I can't really make a true comparison. I'm using FSX and it's a long time since I used FS2004 on a network.

That's for first time -- it is fast when the initial housekeeping is over, right? What exactly is the problem you want to resolve? If it runs okay when it is running, what is the worry?

I really don't know. Did you do the full log and plough through it as I suggested? It tells you exactly what WideCloient is getting up to.

Regards

Pete

Pete Dowson · March 17, 2011

checkout my previous post... i have added there the debug logs (partly of course)

Sorry, I missed those.I actually suggested logging for YOU to look at, not me. Things are working. You wanted an explanation. The explanation is in the log, it tells you what it is doing. I don't want to see it unless there's a problem.

BUT ... I now see that you called your Lua "initial.lua". That is not good at all. You should NEVER use "initial" lua for doing anything with data from FS. I suspect this is the main problem. INITIAL.LUA is started when WideClient is started. You should call it anything BUT "initial" so it starts when WideClient is connected and actually ready to handle offset requests!

Additionally such plug-ins can be changed whilst Wideclient is running and they will be automatically reloaded. That is not the case with INITIAL.

I think you must have missed this part of the documentation?

WideClient will look for a Lua program called "Initial.lua" when it first starts up. This will run immediately, before any access to FS and FSUIPC is obtained, so it should not be used for anything dependent upon valid offset values. It can run other Lua programs, using the "ipc.runlua" function, but they will need to be located elsewhere—not in the WideClient folder—or else they will be restarted when FS is connected. The INITIAL.LUA program is not re-run later and is the only exception.

Even the process of trying to access offset values will mess up the initialisation sequence where WideClient is trying to exchange only essential information to the environment it provides on the client PC.

Regards

Pete

pdpo · March 17, 2011

Hi Pete,

I have now renamed my script to FlightAnalyser.LUA

I was under the impression that you a script was only started when you assign a key to it to start it and

I wanted to let the script run form the beginning...but OK after my change now to FlightAnalyser.LUA i see

in the logs It cant find initial.LUA anymore and it starts to run my FlightAnalyser.

But the same delay of 20 secs remains. Well to be correct, the delay is reduced from 21500 msecs to 20600 msecs.

The logfile... well I looked upon it ... but I cant make out what is wrong you know? I see WSA_READ etc ... and I see

that after this 20600msec the respons after the WSA_READ changes ans shows the following :

20890 LocalReadWrite Entry <M1:L0:C1>

20890 Local message entry <M1:L0:C1>

20890 Processing request now ... <M1:L0:C1>

20890 ProcessRequest: processing the request <M1:L0:C1>

20890 Exiting ProcessRequestData <M1:L0:C1>

20890 ProcessRequest: dealing with response <M1:L0:C1>

20890 MakeSmaller: Orig Size = 64 <M1:L0:C1>

20890 FS6IPC Data Processed <M1:L0:C1>

PREQ ulSize=53, ulTime=20890, uSum=645, fUsed=1

01 00 00 00 3E 02 00 00 02 00 00 00 CC 00 FE 02 ....>...........

00 20 01 00 00 00 0F 33 00 00 13 00 00 00 00 00 . .....3........

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................

00 00 00 00 00 .....

20890 ProcessRequestData: Need read at offset 023F <M1:L0:C1>

20890 Removed unneeded entry Offset 330F, Size 19 <M1:L0:C1>

20890 MakeSmaller: New Size = 27 <M1:L0:C1>

20890 LAN Data sent <M1:L0:C1>

PREQ ulSize=16, ulTime=20890, uSum=639, fUsed=1

which indicates to me that only now the read operation is happening

But why this doesnt happen before this point I cannot know....

My best regards and thanks for the time...

Sorry, I missed those.I actually suggested logging for YOU to look at, not me. Things are working. You wanted an explanation. The explanation is in the log, it tells you what it is doing. I don't want to see it unless there's a problem.

BUT ... I now see that you called your Lua "initial.lua". That is not good at all. You should NEVER use "initial" lua for doing anything with data from FS. I suspect this is the main problem. INITIAL.LUA is started when WideClient is started. You should call it anything BUT "initial" so it starts when WideClient is connected and actually ready to handle offset requests!

Additionally such plug-ins can be changed whilst Wideclient is running and they will be automatically reloaded. That is not the case with INITIAL.

I think you must have missed this part of the documentation?

Even the process of trying to access offset values will mess up the initialisation sequence where WideClient is trying to exchange only essential information to the environment it provides on the client PC.

Regards

Pete

Pete Dowson · March 17, 2011

I was under the impression that you a script was only started when you assign a key to it to start it

Not in WideClient because it generally doesn't process keys, and client PCs are normally unmanned, part of a cockpit somewhere very often. So all wideclient Lua's are loaded automatically, and re-loaded whenever changed (except for Initial, which is really intended to assist initialising attached hardware).

But the same delay of 20 secs remains. Well to be correct, the delay is reduced from 21500 msecs to 20600 msecs.

The delay from WideClient saying "connected", or from your program being loaded? Or do you just mean the time from loading WideClient? you need to be specific. If you are reading the time in the WideClient log file, of course that won't change very much. It still has a lot to do. Yes, 20 seconds from "connected" is strange -- if that's how you are measuring it. 20 seconds from loading is longer than I would expect. But without being at your sysdtem to see why I couldn't really advise.

I didn't expect you to understand the log, only to see how much it has to do!

Can you explain why this is such a big problem for you? Surely you only load up things once or twice a day. Why is the start-up time so critical?

Regards

Pete

pdpo · March 17, 2011

Hi Peter,

wow such fast respons you are offering me... if other designers would be the same progress would be so much greater...

anyway, the delay of 20 secs that I see, I see it in my LUA script itself. As soon as the script starts it reads on offset 0x23E

which is normally non-zero in FS but the first 20 times that I read this offset widefs returns 0. I read with an interval of 1000msecs.

There comes the 20 seconds from.

Actually its not really a problem. Just something which I found strange and might be a symptom of something wrong in my setup.

I found it a long time to wait (in computer time) before data from FS arrives in a widefs client.

I stumbled upon this as I wrote the script which reads a value and when the value is 0 it triggers a stop in logging.

So my logging never started as the value returned was 0 and I expected it to be 32767.

I have now made in my LUA script a loop which reads a value which is always non-zero. But as long as widefs returns 0 the loop continues.

Just wanna understand what could cause this.

Thnaks Peter

Not in WideClient because it generally doesn't process keys, and client PCs are normally unmanned, part of a cockpit somewhere very often. So all wideclient Lua's are loaded automatically, and re-loaded whenever changed (except for Initial, which is really intended to assist initialising attached hardware).

The delay from WideClient saying "connected", or from your program being loaded? Or do you just mean the time from loading WideClient? you need to be specific. If you are reading the time in the WideClient log file, of course that won't change very much. It still has a lot to do. Yes, 20 seconds from "connected" is strange -- if that's how you are measuring it. 20 seconds from loading is longer than I would expect. But without being at your sysdtem to see why I couldn't really advise.

I didn't expect you to understand the log, only to see how much it has to do!

Can you explain why this is such a big problem for you? Surely you only load up things once or twice a day. Why is the start-up time so critical?

Regards

Pete

Pete Dowson · March 17, 2011

... the delay of 20 secs that I see, I see it in my LUA script itself. As soon as the script starts it reads on offset 0x23E

which is normally non-zero in FS but the first 20 times that I read this offset widefs returns 0. I read with an interval of 1000msecs.

Hmmm. In that case there certainly seems to be something wrong -- 20 seconds from WideClient starting is almost okay, 20 seconds after FS is ready and connected is wrong.

Can you paste you Lua into a message here, and I'll try it?

Just wanna understand what could cause this.

Okay.

Paste your Lua. I'll try it later. Dinner time here, then I relax a couple of hours or so, so i won't be back now for a few hours (I always do a bit of work before bed-time).

Regards

Pete

pdpo · March 17, 2011

Hi Peter,

here is the small LUA script that shows what I do :

this LUA script is still under development and I am not sure

it will work completely so dont shoot me ...

the beginning of the script shows in the log this delay I am experiencing

greetz peter

-- Loop until our Flag 0 is set (by assigned FSUIPC control)

ipc.log("Starting my script ACCELL.LUA reading 0x23E until diff to 0")

while (ipc.readUW(0x23E) == 0) do

ipc.log("0x23E is still 0")

ipc.sleep(1000)

end

ipc.log("0x23E is now different to 0")

run = 0

running = 1

flightstate = "none"

while running == 1 do

parking_brake = ipc.readUW(0xBC8)

FS_lights = ipc.readUW(0xD0C)

FS_onground = ipc.readUW(0x366)

gs, tas = ipc.readStruct(0x02B4, "2UD")

gs = (gs * 3600) / (65536 * 1852)

tas = tas / 128

alt = ipc.readDD(0x570)

alt = alt * 3.28084 / (65536 * 65536)

if (parking_brake == 0) and (FS_lights ~= 275) and (FS_onground == 1) then

flightstate = "takeoff"

end

if (flightstate == "takeoff") and (alt > 3000) then

flightstate = "climb"

end

if (flightstate == "climb") and (alt > 38500) then

flightstate = "cuise"

end

if (flightstate == "cruise") and (alt < 38500) then

flightstate = "descend"

end

if (flightstate == "descend") and (alt < 1500) then

flightstate = "landing"

end

if (flightstate == "landing") and (FS_onground == 1) and (gs <= 20) then

flightstate = "done"

end

ipc.log("flight state is " .. flightstate)

end

Hmmm. In that case there certainly seems to be something wrong -- 20 seconds from WideClient starting is almost okay, 20 seconds after FS is ready and connected is wrong.

Can you paste you Lua into a message here, and I'll try it?

Okay.

Paste your Lua. I'll try it later. Dinner time here, then I relax a couple of hours or so, so i won't be back now for a few hours (I always do a bit of work before bed-time).

Regards

Pete

Pete Dowson · March 17, 2011

here is the small LUA script that shows what I do :

Okay.

I was wrong! I have about 20 seconds too -- even when running WideClient on the same PC as FS!

And this is the same for ALL Lua programs, not just yours. And I believe it is the same for all external client applications too.

It is a consequence of the huge list of exchanges which WideClient has to perform these days before it has truly established a worthy "FSUIPC-like" environment for applications. This has grown over the years. Quite honestly, I was surprised when you started this question because I'd never even noticed it. And I'd never noticed it because it really doesn't matter. It is actually a trivial time compared to the actual loading of FS to the point where it is fully flyable, so surrounding programs never looked slow in starting by comparison.

I am pleased, in fact, to note that trying to read offset data whilst WideClient is still initialising doesn't interfere as much as I feared. As you measured, it makes a mere 2 seconds difference over the 20.

I expect I could shave off some seconds here and there, maybe by contriving to spread some of the initialisation out over a longer period thus allowing a lot more gaps for applications and Lua plug-ins. But this would surely adversely affect those programs which do depend on those "essentials" which are being initialised (things like timestamps for data read and write protocols, using in weather setting and reading and the like). So I'm reluctant to meddle. And it has been this way now for many years without anyone, before yourself, even noticing particularly.

Please just be satisfied that there's nothing wrong with your system. Okay?

Regards

Pete

pdpo · March 18, 2011

Hi Pete,

well, thanks for looking into it. Good to know that its not my setup.

Anyway, its not really a problem as long as you know that this is happening.

This means that LUA scripts who run immediately should be carefull as non-zero

values in FS will result in 0 for this first 20secs. So if you make a script

which depends on value to be non-zero caution is needed and the beginning of the script

could be like this :

while (ipc.readUW(0x23E) == 0) do

ipc.sleep(500)

end

as 0x23E is the day of the year it can never be 0 so waiting until this is non-zero

and then continuing ensures that widefs is fully ready

Greetz Peter and thanks a lot for the time spent .... :-)

Okay.

I was wrong! I have about 20 seconds too -- even when running WideClient on the same PC as FS!

And this is the same for ALL Lua programs, not just yours. And I believe it is the same for all external client applications too.

It is a consequence of the huge list of exchanges which WideClient has to perform these days before it has truly established a worthy "FSUIPC-like" environment for applications. This has grown over the years. Quite honestly, I was surprised when you started this question because I'd never even noticed it. And I'd never noticed it because it really doesn't matter. It is actually a trivial time compared to the actual loading of FS to the point where it is fully flyable, so surrounding programs never looked slow in starting by comparison.

I am pleased, in fact, to note that trying to read offset data whilst WideClient is still initialising doesn't interfere as much as I feared. As you measured, it makes a mere 2 seconds difference over the 20.

I expect I could shave off some seconds here and there, maybe by contriving to spread some of the initialisation out over a longer period thus allowing a lot more gaps for applications and Lua plug-ins. But this would surely adversely affect those programs which do depend on those "essentials" which are being initialised (things like timestamps for data read and write protocols, using in weather setting and reading and the like). So I'm reluctant to meddle. And it has been this way now for many years without anyone, before yourself, even noticing particularly.

Please just be satisfied that there's nothing wrong with your system. Okay?

Regards

Pete

Pete Dowson · March 18, 2011

This means that LUA scripts who run immediately should be carefull as non-zero

values in FS will result in 0 for this first 20secs. So if you make a script

which depends on value to be non-zero caution is needed and the beginning of the script

could be like this :

while (ipc.readUW(0x23E) == 0) do

ipc.sleep(500)

end

as 0x23E is the day of the year it can never be 0 so waiting until this is non-zero

and then continuing ensures that widefs is fully ready

Yes, but the better offset for checking is 333C. This contains the official "connected" indication. It will 'come alive' at the same time. (9In the latest update to WideClient it will also clear to zero should the connection break or FS hang).

To save such bother, which I admit I hadn't realised occurred quite so significantly, I think I will change the loading of Lua plug-ins so they don't even run until 333C shows connected. There's still the "initial.lua" option should you need to get in BEFORE connection in order to initialise local things.

Look out for a WideClient update in the Download Links subforum. Maybe version 6.847 will do it that way ...

Regards

Pete

pdpo · March 18, 2011

Peter,

just a question (did not try this yet)...

I think also the Run / RunDelay parameters form the ini file are started as soon as the widefs is connected.

Maybe also an idea to delay those until the data transfer is actually ok

Greetz Peter

Yes, but the better offset for checking is 333C. This contains the official "connected" indication. It will 'come alive' at the same time. (9In the latest update to WideClient it will also clear to zero should the connection break or FS hang).

To save such bother, which I admit I hadn't realised occurred quite so significantly, I think I will change the loading of Lua plug-ins so they don't even run until 333C shows connected. There's still the "initial.lua" option should you need to get in BEFORE connection in order to initialise local things.

Look out for a WideClient update in the Download Links subforum. Maybe version 6.847 will do it that way ...

Regards

Pete

Pete Dowson · March 18, 2011

I think also the Run / RunDelay parameters form the ini file are started as soon as the widefs is connected.

Maybe also an idea to delay those until the data transfer is actually ok

No, you should use RunReady for programs to be started only when FS is ready. I have lots of apps which are best started directly instead. That's why there's a separate RunReady.

BTW please try the revised WideClient which loads Lua's later, when they can read offsets safely. WideClient 6.847

Regards

Pete

pdpo · March 21, 2011

Hi Pete,

I'll try this new version.

I am using also RunReady but that was just my point of the post.

RunReady is also based upon connected to FS state, right?

Would it not be useful to to start the RunReady when the data transfer

is ready?

Greetings Peter

No, you should use RunReady for programs to be started only when FS is ready. I have lots of apps which are best started directly instead. That's why there's a separate RunReady.

BTW please try the revised WideClient which loads Lua's later, when they can read offsets safely. WideClient 6.847

Regards

Pete

Pete Dowson · March 21, 2011

I am using also RunReady but that was just my point of the post.

RunReady is also based upon connected to FS state, right?

Would it not be useful to to start the RunReady when the data transfer

is ready?

External data transfers are dealt with properly already. The only problem was with your Lua plug-in, because their offset requests aren't "held off" like those from external applications. I don't want to delay the start of applications unnecessarily because many take a while to initialise, unlike Lua plug-ins. It works fine as it is.

Regards

Pete

pdpo · March 22, 2011

Hi peter,

perfect then....

Greetings peter

External data transfers are dealt with properly already. The only problem was with your Lua plug-in, because their offset requests aren't "held off" like those from external applications. I don't want to delay the start of applications unnecessarily because many take a while to initialise, unlike Lua plug-ins. It works fine as it is.

Regards

Pete

widefs delay

Recommended Posts

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Link to comment

Share on other sites

Create an account or sign in to comment

Create an account

Sign in

Important Information