COM handling preventing (?) Prepar3D clean shutdown

[Luke Kolin]

Sorry, I'm not worried about the latency - I understand why that happens. This is the part that is interesting to me:

   112578 LUA.1: Event canceled
   112578 LUA.1: ...ke\Documents\Prepar3D v4 Add-ons\FSUIPC6\cs7x7ap.lua:101
   112578 LUA.1: CS757/767 Button Handler shutdown
   112578 LUA.1: ...ke\Documents\Prepar3D v4 Add-ons\FSUIPC6\cs7x7ap.lua:103
   112578 LUA.1: Waiting for an event in "C:\Users\Luke\Documents\Prepar3D v4 Add-ons\FSUIPC6\cs7x7ap.lua"
   113750 Lua threads being terminated:
   113750       1 = "C:\Users\Luke\Documents\Prepar3D v4 Add-ons\FSUIPC6\cs7x7ap.lua"
   113922 LUA: "C:\Users\Luke\Documents\Prepar3D v4 Add-ons\FSUIPC6\cs7x7ap.lua": killed
   113922 === Closing global Lua thread

By line 103, I've already called event.cancel() so why is it waiting for an event right afterwards?

Cheers

[John Dowson]

Note that when you see this: in the log:

Quote

  112203 **** DevCom read/write threads still running - will exit anyway but could cause issues...

This indicates that the thread didn't close correctly, and the initial termination code didn't stop the thread, and so was eventually killed by the main thread (or the DLLStop thread). This can cause issues if the com thread is not fully closed, but I haven't seen such an issue (with the updates in 6.1) so far....

 

[John Dowson]

3 minutes ago, Luke Kolin said:

By line 103, I've already called event.cancel() so why is it waiting for an event right afterwards?

It has the same timestamp, so is just something that occurred around the same time, before the cancel completed. Its not an issue.

[John Dowson]

You could also explicitly  terminate the thread yourself in your HandleShutdown function - just add an ipc.exit() call to the end. 

[Luke Kolin]

That makes sense. I'll try that.

Cheers

[Pete Dowson]

12 minutes ago, Luke Kolin said:

I've already called event.cancel() so why is it waiting for an event right afterwards?

The event.terminate hasn't been cancelled.  Maybe its canellation should be assumed, but as it is all events are treated equally.

Pete

 

[John Dowson]

7 minutes ago, Pete Dowson said:

The event.terminate hasn't been cancelled.

And neither the event.param

[Luke Kolin]

I made some changes and I think I got them all (param, poll, and terminate) but I'm still getting the termination warning. I'm not going to sweat it since it seems to clean up OK. Thanks for your help in understanding the Lua system better.

Cheers!

[John Dowson]

3 minutes ago, Luke Kolin said:

but I'm still getting the termination warning.

Normally, or when in debug? 

[Luke Kolin]

Normally. I turned off all of the debug messaging because it was changing the timings too much.

Cheers!

[John Dowson]

4 minutes ago, Luke Kolin said:

Normally. I turned off all of the debug messaging because it was changing the timings too much.

But in normal shutdown, there are only termination messages. The "warnings" are only in your debug log:
   112203 **** DevCom read/write threads still running - will exit anyway but could cause issues...
   112500 **** DevCom Read thread terminated
 

Anyway, I think things are ok as they re for now.... Cheers,

John

[Luke Kolin]

So, another interesting data point. I have a key binding set in FSUIPC to restart my LUA scripts which is helpful when debugging and updating them. It just runs LUA <script> which starts it if it has terminated, or kills the existing script if running. Now, it seems to hang P3D... perhaps I'm not cleaning up properly?

here's the log.

Cheers!

 

FSUIPC6.log

[John Dowson]

4 hours ago, Luke Kolin said:

So, another interesting data point. I have a key binding set in FSUIPC to restart my LUA scripts which is helpful when debugging and updating them. It just runs LUA <script> which starts it if it has terminated, or kills the existing script if running. Now, it seems to hang P3D... perhaps I'm not cleaning up properly?

It shouldn't hang P3D. But you have errors in the script you should address first:

Quote

   110000 *** LUA Error: ...ke\Documents\Prepar3D v4 Add-ons\FSUIPC6\cs7x7ap.lua:221: attempt to call field 'readShort' (a nil value)
   125453 *** LUA Error: ...ke\Documents\Prepar3D v4 Add-ons\FSUIPC6\cs7x7ap.lua:226: attempt to call field 'readShort' (a nil value)

Also, as I said, could you please activate logging for 'Extras' for such issues, as the thread id is useful. If you correct those errors and still have the same problem, show me the log again (with the Extras logging enabled) as well as the script.

[Luke Kolin]

19 hours ago, John Dowson said:

It shouldn't hang P3D. But you have errors in the script you should address first:

Yes, that's actually why I needed to restart - when debugging to fix silly mistakes like that one. 😄

I'm enclosing two logs. The first is with a hang, the second without. The only difference is again the com.close() - for some reason that is making things unhappy. I don't have a problem keeping it commented out, but the old programmer in me still feels a little unclean at not cleaning things up when I'm done.

(My wife says that doesn't stop me around the house.)

Cheers!

 

FSUIPC6.log FSUIPC6_prev.log

[John Dowson]

What is you TimeForLuaClosing set to? I'm not sure where the 'Poll loop stopped' message comes from (can I see your latest version of the lua script please?)
I ask because there doesn't seem to be much of delay between these messages:

Quote

   150031 LUA.1: Poll loop stopped
   150578 LUA: "C:\Users\Luke\Documents\Prepar3D v4 Add-ons\FSUIPC6\cs7x7ap.lua": killed

Maybe there is another section of code that is killing in this situation and i need to add the delay there, I'll check,. But, please activate Extras logging before you show me any more log files. And if your script is changing, its helpful to see that.

[John Dowson]

22 minutes ago, John Dowson said:

Maybe there is another section of code that is killing in this situation and i need to add the delay there, I'll check

Yes, there was another section of code that was killing the lua but only had a 100ms delay to wait for the termination procedure to complete. I've changed this to use the TimeForLuaClosing instead, when there is a termination function. Could you try this version please, v6.1.1f: FSUIPC6.dll

[Luke Kolin]

Things look good here. I'm enclosing the log, INI, and Lua script in case you need them.

(FWIW right when the script starts it takes focus away and then refuses to give it back for 3-5s, but that's been there for a while.)

Cheers!

 

cs7x7ap.lua FSUIPC6.ini FSUIPC6.log

[John Dowson]

Still a bit strange - not sure why you are still getting the DevCom thread termination messages...

And looks like the 'Extras' logging is not logging the thread info....I thought I had already added that to FSUIPC6, but maybe its only in FSUIPC7. I'll check and add it to FSUIPC6. Helps a lot for this type of thing as there are various threads interacting with lua / devcomms.
Once thats done, I'll do a few more tests here on killing/restarting luas that use coms, but it will probably take a while before I get time for this....

John