Jump to content
The simFlight Network Forums

COM handling preventing (?) Prepar3D clean shutdown


Recommended Posts

I've implemented some LUA scripts to handle extended button reads, and I've noticed that P3D isn't shutting down properly at times. Looking at my logs, it appears that my Lua shutdown function is terminating abnormally.

I call event.cancel() and then com.close() but it looks like one is failing and then the script is getting terminated by FSUIPC. The changelog for 6.1 suggests that there are some changes in com handling. Am I doing things incorrectly? Is there a conflict with the new button handling post-6.0.12?

Cheers!

Luke

FSUIPC6.log cs7x7ap.lua

Link to comment
Share on other sites

Hi Luke,

36 minutes ago, Luke Kolin said:

I call event.cancel() and then com.close() but it looks like one is failing and then the script is getting terminated by FSUIPC.

I'm not sure its failing - I think the com.close call is taking to long to finish and the script is being killed from the closing thread...

37 minutes ago, Luke Kolin said:

The changelog for 6.1 suggests that there are some changes in com handling.

Yes, there were some changes, but these were to increase some waits to give more time for the com threads to close down correctly.  Was it working in the previous FSUIPC6 release before these changes? If you don't know, could you try (I can give you the previous dll if needed).

Was that the complete log you posted? If so, then it does look like FSUIPC didn't shut-down correctly, which would prevent P3D from closing.

It could be killing the thread when its in com.close that is causing the issue. Try commenting-out the event.terminate call, and see if terminating the thread without this is more reliable.

Link to comment
Share on other sites

3 minutes ago, Luke Kolin said:

That's the complete log. I'll try commenting out the event.cancel and add some additional logging details to see if it makes a difference, and report back.

Not sure that will do much as its the com.close thats the issue. As I said, first try commenting out the event.terminate (which will prevent the event.cancel and com.close being called).

Link to comment
Share on other sites

So I changed the shutdown function to be this:

function HandleShutdown()

if (hidHandle ~= 0) then
  ipc.log("Shutting down USB device hnd=" .. hidHandle)
  com.close(hidHandle)
  ipc.log("USB Device disconnected")
  hidHandle = 0
  event.cancel("HID_Poll")
  ipc.log("Event canceled")
end

ipc.log("CS757/767 Button Handler shutdown")

end

So I'll close, log, then cancel. I didn't even get the log message:

    72484 -------------------- Starting everything now ----------------------
    72563 ASN active function link set
    72563 Ready for ActiveSky WX radar with additional data
    72563 LUA.1: USB Device Connected, hnd=1
    72563 LUA.1: Poll loop started
    72563 LUA.1: Registered CS757/767 Button Handler
    73641 Advanced Weather Interface Enabled
   103406 Sim stopped: average frame rate for last 39 secs = 34.8 fps
   103406    Max AI traffic was 5 aircraft
   103406 -------------------------------------------------------------------
   108984 === Closing session: waiting for DLLStop to be called ...
   119719 === DLLStop called ...
   119719 === Closing external processes we started ...
   120719 === About to kill any Lua plug-ins still running ...
   120719 LUA.1: Shutting down USB device hnd=1
   120875 Lua threads being terminated:
   120875       1 = "C:\Users\Luke\Documents\Prepar3D v4 Add-ons\FSUIPC6\cs7x7ap.lua"
   121172 **** DevCom read/write threads still running - will exit anyway but could cause issues...
   121313 LUA: "C:\Users\Luke\Documents\Prepar3D v4 Add-ons\FSUIPC6\cs7x7ap.lua": killed
   121766 **** DevCom read/write threads still running - will exit anyway but could cause issues...

... so I think you're correct about com.close() taking too long. Is there any possibility to increase the cleanup limit? 5ms seems awfully short.

Cheers

Link to comment
Share on other sites

1 minute ago, Luke Kolin said:

... so I think you're correct about com.close() taking too long. Is there any possibility to increase the cleanup limit? 5ms seems awfully short.

Possibly. But please try first without closing down first - just comment out your event.terminate call.

Link to comment
Share on other sites

You could also try increasing this parameter (with your event.terminate active):

Quote

TimeForLuaClosing=2 sets the time allowed for Lua plug-ins to close correctly before the FS is closed. The time starts
as soon as the event.terminate function has been called, assuming the plug-in uses it. The value in in seconds and can be
set from 1 to 20. A longer period might help those more complex plug-ins to tidy up properly

 

You can try increasing that....looks like this is maybe set to 1 in your ini (?), as from your log:

Quote

110968 === Closing external processes we started ...
111968 === About to kill any Lua plug-ins still running ...

Only a 1s difference between those messages....

Edited by John Dowson
Further info added
Link to comment
Share on other sites

11 minutes ago, John Dowson said:

You could also try increasing this parameter (with your event.terminate active): You can try increasing that....looks like this is maybe set to 1 in your ini (?), as from your log: Only a 1s difference between those messages....

Interestingly, I checked my INI and the parameter was already there... set to 2.

I'll try again with the event.terimate removed.

Cheers

Link to comment
Share on other sites

3 minutes ago, Luke Kolin said:
15 minutes ago, John Dowson said:

You could also try increasing this parameter (with your event.terminate active): You can try increasing that....looks like this is maybe set to 1 in your ini (?), as from your log: Only a 1s difference between those messages....

Interestingly, I checked my INI and the parameter was already there... set to 2.

Yes, interesting...

3 minutes ago, Luke Kolin said:

I'll try again with the event.terimate removed.

Ok. After you have done that, could you re-enable and change that parameter to something quite large, say 5 (seconds) to see if that makes a difference, and show me your log file afterwards (or the closing  extract) so I can see if that has any affect. If not, I will look into it....

Link to comment
Share on other sites

Doesn't appear to make a difference. I've attached the full log/ini files, and here is the relevant function:

function HandleShutdown()

if (hidHandle ~= 0) then
  ipc.log("Shutting down USB device hnd=" .. hidHandle)
  com.close(hidHandle)
  ipc.log("USB Device disconnected")
  hidHandle = 0
  -- event.cancel("HID_Poll")
  -- ipc.log("Event canceled")
end

ipc.log("CS757/767 Button Handler shutdown")

end

You can say for sure, but my uninformed guess is that the com.close is throwing an error that isn't getting caught or logged.

I'll try again with the parameter set to 5.

Cheers

FSUIPC6.log FSUIPC6.ini

Link to comment
Share on other sites

Just now, Luke Kolin said:

It definitely made a difference.  I got a warning, but the process terminated.

Yes, thats the new warning I added in 6.1. I would use this for now (i.e. no event.terminate), and I'll look into why that lua delay isn't working and get back to you.

Link to comment
Share on other sites

4 hours ago, John Dowson said:

No, not necessary. Please try the following instead: FSUIPC6.dll

Looks clean now! Interestingly the com.close appears to take a while... I've enclosed the log and the shutdown function (I've changed the logic a bit as we've been working and can't remember if you've seen it).

function HandleShutdown()

if (hidHandle ~= 0) then
  ipc.log("Shutting down USB device hnd=" .. hidHandle)
  com.close(hidHandle)
  ipc.log("USB Device disconnected")
  hidHandle = 0
  event.cancel("HID_Poll")
  ipc.log("Event canceled")
end

ipc.log("CS757/767 Button Handler shutdown")

end

 

FSUIPC6.log

Link to comment
Share on other sites

1 hour ago, Luke Kolin said:

Looks clean now! Interestingly the com.close appears to take a while...

Yes, but that maybe because you have TimeForLuaClosing=5 still set, which is the time betwwen these messages:
    90688 Waiting for lua threads to process termination event...
   ...
    95688 Lua threads being terminated:
The com.close is done hbetween these log messages:
    90688 LUA.1: Shutting down USB device hnd=1
    ...
    91328 LUA.1: USB Device disconnected
So is taking roughly 0.65 seconds. You can try reducing the  TimeForLuaClosing back to 2, or maybe even try 1. Also, for such issues, its also a good idea to enable logging for 'Extras', as this will then log the thread that is producing the message. Most shut-down issues are thread & timings related.

 

The thread is still being killed later though, which is a bit strange, but at least the com has closed so this isn't an issue. However, I did reduce another timing that may have caused this - I will increase again slightly when I release this.

Thanks for you help on this,

John

 

 

Link to comment
Share on other sites

So I turned on a lot of debugging (which seemed to cause some latency and interesting race conditions) and I've attached the log. Note at the end, even after event.cancel it looks like LUA is still waiting on an event, and perhaps the cancel() isn't working?

Attaching log and LUA so you can see the line numbers.

Cheers

FSUIPC6.log cs7x7ap.lua

Link to comment
Share on other sites

3 minutes ago, Luke Kolin said:

So I turned on a lot of debugging (which seemed to cause some latency and interesting race conditions) and I've attached the log. Note at the end, even after event.cancel it looks like LUA is still waiting on an event, and perhaps the cancel() isn't working?

Yes, if you debug it will increase the latency. But I'm not going to adjust for this - and it still closed down correctly anyway, so I don't see an issue.
 

Link to comment
Share on other sites

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
×
×
  • Create New...

Important Information

By using this site, you agree to our Terms of Use. Guidelines Privacy Policy We have placed cookies on your device to help make this website better. You can adjust your cookie settings, otherwise we'll assume you're okay to continue.