P3D 5.2 - LUA event handling not reliable

[aua668]

Hi,

I am running P3D 5.2 HF 1 (version 5.2.22.27615) and FSUIPC 6.1.2 on WIN 10 with the latest updates. I have connected to my simulator several GoFlight hardware devices. I use them since already FSX days. I handle the input from these devices via LUA modules using the event.button function.

Since switching to 5.2 from 5.1 I have the problem, that few of the registered event.button functions (and sometimes also the event.offset functions) don't fire. Most of the buttons are working normally. The buttons themselves are recognized by FSUIPC, which I can check on the buttons page in the FSUIPC UI. And there are always some different buttons, where the events are not detected by LUA. Completely random.

The FSUIPC logfile shows no errors and I didn't change anything during the upgrade. If I manually restart the single module, where one or more event.button functions are not firing, via ipc.runlua(), the module works then as expected.

I start all my modules per ipc.runlua() out of a loop in a start module. This always worked fine in the past. The table AC.GF holds the specific modules for the current aircraft.

local k=0
local j=0
local v=""

for  k in pairs(AC.GF) do

	for j,v in ipairs(AC.GF[k]) do
		ipc.runlua ( v )
		ipc.sleep(1000)
		ipc.log (v.." initialized")
	end

end

As the error is randomly occuring, I have no idea, how to find the reason. The only common thing is, that it has todo with the handling of events in LUA. When I upgraded to P3D 5.2 there was also a WIN 10 update provided at the same time (2021-06 Windows 10 21H1). Not sure if it is P3D 5.2 or maybe the WIN 10 update producing this random errors. . Anyhow since that time I can't be sure, that all of my programmed events are really working. And it's independent of the plane I am using.

Maybe you have an idea, what might have changed with the event handling in 5.2.

Best regards
Reinhard

 

FSUIPC6.log

[John Dowson]

Hi Reinhard.

this seems rather strange. I don't understand how a P3D or windows update could affect the lua event handling. There was no change in the FSUIPC6 version you were using, no? Its also strange that is affecting both event.offset and event.button functions.
Are you sure that you luas are actually still running when this occurs?

Maybe you can activate logging for buttons and keys, as well as lua plugins (but not Lua plugins separately), and show me the log file produced when your issue occurs.

John

 

 

[aua668]

John,

Yes these modules are running (partially). I have for example a LUA module for handling NAV1 on a GF module. Most of the events are handled correctly (inc/dec frequency for example) and few events in that module are not reacting (e.g. swapping frequencies). And the real strange thing is, that if I check via the FSUIPC UI on the button page, the same button is recognized. I run this code already very long from FSX over several P3D versions. Until my upgrade to 5.2 (and 5.2 with HF1) it worked without any problem. And another strange thing: One time it's NAV1, the other time it might be another button from a completely other module.

I know, that you don't have any chance to reproduce - even I am not able to have a scenarion, where it always happens. My hope is, that others might experience the same and that we can come to a pattern.

Rgds
Reinhard

 

[John Dowson]

It is strange that this issue started after a P3D update, but I really can't see how that can affect something like event.button, which is completely independent of P3D (i.e. P3D is not involved at all).

Anyway, try activating the suggested logging, as this may show you something when this happens again - i.e. if the button presses are received, and if anything is picked up by your lua scripts.

 

Cheers,

Joihn

[aua668]

Hi,

I did deeper analysis with one module, where this phenomenon did happen more often than at others. For handling COM1 (or COM2) via my GoFlight module I use the following module:

 

-- Q400_GF_COM1.lua
-- V1.3
-- Q400 implementation of the GF COM1


-- include GF variables
require "GF_Variables"

local GF_Model = GF166								-- name of device
local GF_Unit = GFHW.GF_166_1						-- Id (default=0)
local GF_JoyLetter = GFHW.GF_166_Joy_1				-- Joy-Letter of switch/button
local GF_Button = GFHW.GF_166_Sel_1
local GF_JoyButtonSwap = GFHW.GF_166_But_1			-- Joy-Button of toggle switch/button
local GF_JoyButtonID1 = GF_JoyButtonSwap + 1		-- Joy-Button of switch/button
local GF_JoyButtonID2 = GF_JoyButtonSwap + 2		-- Joy-Button of switch/button
local GF_Id_COM11 = 0								-- Id of COM11
local GF_Id_COM12 = 1								-- Id of COM12
local GF_Id_ID1 = 1									-- Id of LED 1
local GF_Id_ID2 = 2									-- Id of LED 2

-- define P3D controls
require "P3D_Controls"

-- define XML interface
require "Q400_Write_XML_IF"



function IncDecCOM1 (pStep)

	local lValue2 = string.format( "%04X", ipc.readUW(0x311A) )
	local lCOM1 = lValue2 * 10 + 100000
	local lFract = 0
	local lCorr = 0

	lCOM1 = lCOM1 + pStep

	if lCOM1 < 118000 then
		lCOM1 = 118000
	end

	if lCOM1 > 136975 then
		lCOM1 = 136975
	end

	lFract = lCOM1 % 100

	if lFract == 25 or lFract == 75 then
		lCorr = -5
	end

	if lFract == 45 or lFract == 95 then
		lCorr = 5
	end

	lValue2="0x"..math.floor( (lCOM1+lCorr-100000) / 10 )

	ipc.writeUW(0x311A, lValue2+0)
	writeXMLIF ( Q400_XML.ARCDUCOM1StbyFreq , lCOM1+lCorr - 100000 )

end

function IncCOM10 (joynum, button, downup)	
	IncDecCOM1 (25)
end

function IncCOM11 (joynum, button, downup)	
	IncDecCOM1 (100)
end

function IncCOM12 (joynum, button, downup)	
	IncDecCOM1 (1000)
end

function IncCOM13 (joynum, button, downup)	
	IncDecCOM1 (1000)
end

function DecCOM10 (joynum, button, downup)	
	IncDecCOM1 (-25)
end

function DecCOM11 (joynum, button, downup)	
	IncDecCOM1 (-100)
end

function DecCOM12 (joynum, button, downup)	
	IncDecCOM1 (-1000)
end

function DecCOM13 (joynum, button, downup)	
	IncDecCOM1 (-1000)
end


function readCOM1 ()

	local lValue2 = string.format( "%04X", ipc.readUW(0x034E) )
	local lCOM1 = lValue2 * 10
	local lFract = 0
	local lCorr = 0

	lFract = lCOM1 % 100

	if lFract == 20 or lFract == 70 then
		lCorr = 5
	end

	lValue2 = lCOM1 + lCorr

	return lValue2
	
end

function readCOM1Stby ()

	local lValue2 = string.format( "%04X", ipc.readUW(0x311A) )
	local lCOM1 = lValue2 * 10
	local lFract = 0
	local lCorr = 0

	lFract = lCOM1 % 100

	if lFract == 20 or lFract == 70 then
		lCorr = 5
	end

	lValue2 = lCOM1 + lCorr

	return lValue2
	
end


function DispCOM1(offset, value)		-- react on P3D Input

	gfd.SetDisplay( GF_Model, GF_Unit, GF_Id_COM11, string.format( "1%02X.%02X", math.floor( ipc.readUW(0x034E)/256 ) , ipc.readUW(0x034E) % 256 ) )
	
end


function DispCOM1Stby(offset, value)		-- react on P3D Input

	gfd.SetDisplay( GF_Model, GF_Unit, GF_Id_COM12, string.format( "1%02X.%02X", math.floor( ipc.readUW(0x311A)/256 ) , ipc.readUW(0x311A) % 256 ) )
	
end


function DispCOM1Id(offset, value)		-- react on P3D Input
	
	if logic.And(value, 0x80) == 0x80 then
		gfd.SetLight( GF_Model, GF_Unit, GF_Id_ID1 )
	else
		gfd.ClearLight( GF_Model, GF_Unit, GF_Id_ID1 )
	end
	
	if logic.And(value, 0xA0) ~= 0x00 then
		gfd.SetLight( GF_Model, GF_Unit, GF_Id_ID2 )
	else
		gfd.ClearLight( GF_Model, GF_Unit, GF_Id_ID2 )
	end
		
end


function SetCOM1Swap(joynum, button, downup)	-- react on GF Input

	P3D_Ctrl.P3D_COM_STBY_RADIO_SWAP ( 0 )
	ipc.sleep(100)
	
	writeXMLIF ( Q400_XML.ARCDUCOM1Freq , readCOM1 () )
	writeXMLIF ( Q400_XML.ARCDUCOM1StbyFreq , readCOM1Stby () )

end


function SetCOM1ID1(joynum, button, downup)	-- react on GF Input

	writeXMLIF ( Q400_XML.ARCDUMicSelector , 1 )

	ipc.clearbitsUB(0x3122, 0x60)
	ipc.setbitsUB(0x3122, 0x80)

end


function SetCOM1ID2(joynum, button, downup)	-- react on GF Input

	ipc.togglebitsUB(0x3122, 0x20)

end


-- initialize COM1
writeXMLIF ( Q400_XML.ARCDUCOM1Freq , readCOM1 () )
writeXMLIF ( Q400_XML.ARCDUCOM1StbyFreq , readCOM1Stby () )

-- track every change of the P3D offsets
event.offset( 0x034E, "UW", "DispCOM1" )
event.offset( 0x311A, "UW", "DispCOM1Stby" )			
event.offset( 0x3122, "UB", "DispCOM1Id" )

-- Swap COM1 frequencies
event.button( GF_JoyLetter , GF_JoyButtonSwap , 1 , "SetCOM1Swap" )
event.button( GF_JoyLetter , GF_JoyButtonID1 , 1 , "SetCOM1ID1" )
event.button( GF_JoyLetter , GF_JoyButtonID2 , 1 , "SetCOM1ID2" )

-- register button events up/down
event.button(GF_JoyLetter, GF_Button,   3, "DecCOM13")
event.button(GF_JoyLetter, GF_Button+1, 3, "DecCOM12")
event.button(GF_JoyLetter, GF_Button+2, 3, "IncCOM12")
event.button(GF_JoyLetter, GF_Button+3, 3, "IncCOM13")
event.button(GF_JoyLetter, GF_Button+4, 3, "DecCOM11")
event.button(GF_JoyLetter, GF_Button+5, 3, "DecCOM10")
event.button(GF_JoyLetter, GF_Button+6, 3, "IncCOM10")
event.button(GF_JoyLetter, GF_Button+7, 3, "IncCOM11")

COM2, NAV1 and NAV2 are implemented in a similar way. When I start my modules, quite often one of the event.offset triggers will not work. Sometimes it's the one for COM1 , sometimes it's the event for the COM1 standby frequency. And sometimes they work normally. And sometimes it's happening at COM2, NAV1 and NAV2.

What I have found is the fact, that's always one of the event.offset triggers, which are not firing. I checked with FSInterrogate, that the offse IS changing so the event normally must fire. And the code wasn't changed since all versions of P3D. This strange behaviour started with P3D 5.2.

For me there is no reason, why one of these events should not work, while all the others in the module are working. Of course there is no error in the logfile and the offset is changing, which I checked by logging and by FSinterrogate.

I start about 40 modules for my hardware components all of similar complexity like this one. Other modules show the same random behaviour - but not so often as the radio modules.

I really have no idea, what I should change, that all events are trapped. And I have no idea, how I could support you to reproduce this issue.

Rgds
Reinhard

 

 

[aua668]

Hi,

After writing this post, I started my modules again with logging enabled as suggested. I incremented the standby frequency, the button event was trapped and the offset for the standby frequency of COM1 changed - but the event.offset trigger never fired:

  3338203 LUA.58: Waiting for an event in "C:\Users\Reinhard\Documents\Prepar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_COM1.lua"
  3338437 JoystickValues PCnum=0, dwCount=1, data[2]={0000008f 00000000}
  3338437 LUA.58: Button event: calling "IncCOM10" in "C:\Users\Reinhard\Documents\Prepar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_COM1.lua"
  3338453 Monitor IPC:311A (U16) = 6512
  3338500 LUA.58: Waiting for an event in "C:\Users\Reinhard\Documents\Prepar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_COM1.lua"
  3338734 LUA.58: Button event: calling "IncCOM10" in "C:\Users\Reinhard\Documents\Prepar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_COM1.lua"
  3338734 JoystickValues PCnum=0, dwCount=1, data[2]={0000008f 00004000}
  3338734 Monitor IPC:311A (U16) = 6514
  3338797 LUA.58: Waiting for an event in "C:\Users\Reinhard\Documents\Prepar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_COM1.lua"
  3339078 JoystickValues PCnum=0, dwCount=1, data[2]={0000008f 00000000}
  3339078 LUA.58: Button event: calling "IncCOM10" in "C:\Users\Reinhard\Documents\Prepar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_COM1.lua"
  3339109 Monitor IPC:311A (U16) = 6517
  3339172 LUA.58: Waiting for an event in "C:\Users\Reinhard\Documents\Prepar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_COM1.lua"

All the other offset triggers worked as expected. Here the swap of frequencies, which changes the offset of COM1:

  4199766 JoystickValues PCnum=0, dwCount=1, data[2]={0000008f 00004001}
  4199781 LUA.58: Button event: calling "SetCOM1Swap" in "C:\Users\Reinhard\Documents\Prepar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_COM1.lua"
  4199797 FS Control Sent: Ctrl=66372, Param=0 COM_STBY_RADIO_SWAP
  4199828 Monitor IPC:034E (U16) = 6519
  4199828 SimRead: 034E="COM ACTIVE FREQUENCY:1"
            INT32: 6519 (0x00001977)
  4199828 Monitor IPC:311A (U16) = 8544
  4199828 SimRead: 311A="COM STANDBY FREQUENCY:1"
            INT32: 8544 (0x00002160)
  4200016 LUA.58: Waiting for an event in "C:\Users\Reinhard\Documents\Prepar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_COM1.lua"
  4200016 LUA.58: Offset Change event: calling "DispCOM1" in "C:\Users\Reinhard\Documents\Prepar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_COM1.lua"
  4200016 LUA.58: Waiting for an event in "C:\Users\Reinhard\Documents\Prepar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_COM1.lua"

Both offsets changed, but only DispCOM1 was executed while DispCOM1Stby never was triggered.

Rgds
Reinhard

 

[aua668]

Hi,

Another strange finding: I added debugging info to the module above, as I found, that starting of the module increased my standby frequency. So I added simple logging code to the modules:

function IncCOM10 (joynum, button, downup)	
	ipc.log("IncCOM10")
	IncDecCOM1 (25)
end

function IncCOM11 (joynum, button, downup)	
	ipc.log("IncCOM11")
	IncDecCOM1 (100)
end

function IncCOM12 (joynum, button, downup)	
	ipc.log("IncCOM12")
	IncDecCOM1 (1000)
end

function IncCOM13 (joynum, button, downup)	
	ipc.log("IncCOM13")
	IncDecCOM1 (1000)
end

function DecCOM10 (joynum, button, downup)	
	ipc.log("DecCOM10")
	IncDecCOM1 (-25)
end

function DecCOM11 (joynum, button, downup)	
	ipc.log("DecCOM11")
	IncDecCOM1 (-100)
end

function DecCOM12 (joynum, button, downup)	
	ipc.log("DecCOM12")
	IncDecCOM1 (-1000)
end

function DecCOM13 (joynum, button, downup)	
	ipc.log("DecCOM13")
	IncDecCOM1 (-1000)
end

When I registered the buttons:

-- register button events up/down
event.button(GF_JoyLetter, GF_Button,   3, "DecCOM13")
event.button(GF_JoyLetter, GF_Button+1, 3, "DecCOM12")
event.button(GF_JoyLetter, GF_Button+2, 3, "IncCOM12")
event.button(GF_JoyLetter, GF_Button+3, 3, "IncCOM13")
event.button(GF_JoyLetter, GF_Button+4, 3, "DecCOM11")
event.button(GF_JoyLetter, GF_Button+5, 3, "DecCOM10")
event.button(GF_JoyLetter, GF_Button+6, 3, "IncCOM10")
event.button(GF_JoyLetter, GF_Button+7, 3, "IncCOM11")

One of the routines fired during registering the event. But only one. No other modules have been running. So this is the only module active at that time:

  5608297 LUA: "GF_Test.lua": killed
  5626125 LUA.69: IncCOM10

It's getting even more strange.

Rgds
Reinhard

[John Dowson]

Hi Reinhard,

18 hours ago, aua668 said:

I incremented the standby frequency, the button event was trapped and the offset for the standby frequency of COM1 changed - but the event.offset trigger never fired:

that does look strange, but I need to see the full log, not just an extract. Can you a;ways attach the full log  as well in future please (and keep logging for Buttons & Keys, Events and Lua Plugins active, as well as monitoring the offsets to which you have attached an event.offset call). Also useful if you attach the actual lua script (so the logged line numbers correspond).

17 hours ago, aua668 said:

One of the routines fired during registering the event. But only one. No other modules have been running. So this is the only module active at that time:

  5608297 LUA: "GF_Test.lua": killed
  5626125 LUA.69: IncCOM10

Not sure I understand that log extract - could the button have been triggered (did you have button logging activated)? Again, please attach your full .log file.

18 hours ago, aua668 said:

I start about 40 modules for my hardware components all of similar complexity like this one. Other modules show the same random behaviour - but not so often as the radio modules.

Did you test with just running this one module? If not, try to do that (i.e. exclude other modules for now) and, if the problem still persists when running just the one module it should be easier to track down.

I'll do some tests here with multiple button and offset events registered in a lua (using one of my GF devices as well), to see if I can replicate any of this behavior.

John

[John Dowson]

Btw, I've just noticed this in the original log file you posted:

Quote

    95281 Exception 3 "UNRECOGNIZED_ID", Ref 2890, Index param 1 on write SetData for "RECIP ENG FUEL FLOW:1"
    95281 Exception 3 "UNRECOGNIZED_ID", Ref 2891, Index param 1 on write SetData for "RECIP ENG FUEL FLOW:2"
    95281 Exception 3 "UNRECOGNIZED_ID", Ref 2892, Index param 1 on write SetData for "RECIP ENG FUEL FLOW:3"

Are you still getting these errors with the latest version of fSUIPC6, v6.1.4? If so, you should re-install the P3Dv5.2 client as this is usually a sign of some corruption somewhere.

Also maybe try the attached lua to see if it suffers from the same issue. Its a pretty basic script that tries to reproduce your issue without any added complexity. You need to change the event,button call parameters for your GF device and button numbers.

On my system, this script runs as expected....

eventTest.lua

If that script also works on your system, I'll use that as a staring point and add more complexity until it can replicate the behavior you see, either on your system but hopefully (also) on mine, if there is an issue, so that I can investigate further. For the next iterations of the script, I will:
   - update to use multiple button and offset functions rather than the same function
   - update an offset in a button function to verify that the offset functions are triggered in such a scenario

John

Edited August 30, 2021 by John Dowson

[aua668]

Quote

    95281 Exception 3 "UNRECOGNIZED_ID", Ref 2890, Index param 1 on write SetData for "RECIP ENG FUEL FLOW:1"
    95281 Exception 3 "UNRECOGNIZED_ID", Ref 2891, Index param 1 on write SetData for "RECIP ENG FUEL FLOW:2"
    95281 Exception 3 "UNRECOGNIZED_ID", Ref 2892, Index param 1 on write SetData for "RECIP ENG FUEL FLOW:3"

Are you still getting these errors with the latest version of fSUIPC6, v6.1.4? If so, you should re-install the P3Dv5.2 client as this is usually a sign of some corruption somewhere.

These errors are only raised, if I use the Majestic Q400. These errors are shown since all versions of the Q400 for P3D (and as far as I remember even with FSX). I did a fresh installation for all major versions of P3D and always install the updates according to the proposed procedure.

Other planes don't show these errors. Also other users have these errors in the logfile, if they use the Q400:
https://forum.simflight.com/topic/91564-have-to-hit-reload-all-buttons-every-time/

Rgds
Reinhard

 

[aua668]

Quote

that does look strange, but I need to see the full log, not just an extract. Can you a;ways attach the full log  as well in future please (and keep logging for Buttons & Keys, Events and Lua Plugins active, as well as monitoring the offsets to which you have attached an event.offset call). Also useful if you attach the actual lua script (so the logged line numbers correspond).

One of my plugins use the event.timer function and runs some code every second. By that the logfile get's quite big and cluttered and it's hard to read. But I will do as advised.

Quote

Not sure I understand that log extract - could the button have been triggered (did you have button logging activated)? Again, please attach your full .log file.

I added for one single module to each of the button event functions a simple ipc.log line and I started only this single module (Q400_GF_COM1 from above). So there was only one module running. The logfile extract simply shows, that one of the functions (IncCOM10) fired during the event registrations, although buttons never should fire the function during event registration. At several runs I even got two or three functions firing without touching any button.

I will test your script, when I return to home. Many thanks for taking care.

Best regards
Reinhard

[John Dowson]

21 minutes ago, aua668 said:

One of my plugins use the event.timer function and runs some code every second. By that the logfile get's quite big and cluttered and it's hard to read. But I will do as advised.

It is better to stop everything else and try to reproduce the issue with the minimum number of luas running - hopefully just the one.
Did you not try stopping most or all of your other luas and just leave the Q400_GF_COM1.lua running? If not, please try that first and let me know if you still get issues.
If not, then try adding things back, one-by-one, until the issue occurs.

30 minutes ago, aua668 said:

I added for one single module to each of the button event functions a simple ipc.log line and I started only this single module (Q400_GF_COM1 from above). So there was only one module running.

Ah, so the issue occurs with only one module running? So the event.timer function that runs every second shouldn't have been running, no? But even if it was and the log was huge, please zip it up and attach. I really do need to see the whole log, not just extracts.
And no need to add such logging statements - you should just enable lua debug logging, as this will log each line executed. 

33 minutes ago, aua668 said:

The logfile extract simply shows, that one of the functions (IncCOM10) fired during the event registrations, although buttons never should fire the function during event registration.

Yes, but I cannot tell if the button was triggered or not when you post selected extracts, which is one reason why I need to see the full log. From that extract, I do not know what logging was activated, for example.

I would like to see a full log file of your issue with the simplest possible set-up, hopefully with just one lua running. And then reproduce here so I can investigate.

John

 

[aua668]

2 hours ago, John Dowson said:

It is better to stop everything else and try to reproduce the issue with the minimum number of luas running - hopefully just the one.
Did you not try stopping most or all of your other luas and just leave the Q400_GF_COM1.lua running? If not, please try that first and let me know if you still get issues.
If not, then try adding things back, one-by-one, until the issue occurs.

Ah, so the issue occurs with only one module running? So the event.timer function that runs every second shouldn't have been running, no? But even if it was and the log was huge, please zip it up and attach. I really do need to see the whole log, not just extracts.
And no need to add such logging statements - you should just enable lua debug logging, as this will log each line executed. 

Yes, but I cannot tell if the button was triggered or not when you post selected extracts, which is one reason why I need to see the full log. From that extract, I do not know what logging was activated, for example.

I would like to see a full log file of your issue with the simplest possible set-up, hopefully with just one lua running. And then reproduce here so I can investigate.

John

 

Yes - the issue in the trace above occured with only one module running. Although th probality, that it happens, increases with the number of modules running. I run a similar module setup for the AS Twin Otter (with less modules) and there it was not happening so far. With the AS320 it also happens.

I did some more tests and add the logfiles here.

FSUIPC6_your_module.log

I started only your module (I changed the name to GF_Test, as I have already a button assignment to start this specific module for test purposes). I also changed the button to trace to the GoFlight rotary for COM1 (143/8..15 instead of 175/0..7).

With logging enabled it always worked and I could not reproduce.

FSUIPC6_all_modules_started.log

I started all my modules (but omitted the one with the event.timer function) with the full logging turned on. And I was not able to reproduce the error in that mode.

FSUIPC6_normal.log

I started all my modules including the one with the event.timer trigger but with only logging the COM1 offsets. I was not able to reproduce the error.

FSUIPC6_COM1_error.log

I started the test with all my modules a second time and in that run COM1 event functions, which should display the frequencies have not been triggered.

In the log you see in that line, that I started the module out of my loop across all modules:

202375 LUA.8: LUA\Q400\Q400_GF_COM1 started

 After detecting, that COM1 was not working as expected, I enabled full logging again (see line 265609). By enabling the logging for the LUA modules, it showed, that COM1 did not show up in the list of modules waiting for an event (like all other modules), although the module was started and there are definitely event triggers defined.

Shutting down the simulator closes all modules. But COM1 also never showed up in the logfile during shutdown. So it must have been in a type of inactive state.

Very strange.

Reinhard

 

 

 

 

 

 

 

 

FSUIPC6_your_module.log FSUIPC6_all_modules_started.log FSUIPC6_normal.log FSUIPC6_COM1_error.log

[John Dowson]

13 hours ago, aua668 said:

After detecting, that COM1 was not working as expected, I enabled full logging again (see line 265609). By enabling the logging for the LUA modules, it showed, that COM1 did not show up in the list of modules waiting for an event (like all other modules), although the module was started and there are definitely event triggers defined.

Shutting down the simulator closes all modules. But COM1 also never showed up in the logfile during shutdown. So it must have been in a type of inactive state.

Yes, it looks like the Q400_GF_COM1.lua exited for some reason, but BEFORE you activated debug logging.
Could you try and repeat this test but with lua debug logging activated from the start?  If you can generate such a log file it should hopefully show what is happening in that module and why/when it is exiting.

Also, it seems its  only occurring with certain aircraft, when you have many modules/lua scripts running, no?
Maybe its hitting some inbuilt/hard-coded limit somewhere. Does this issue always occur in the same module (Q400_GF_COM1.lua)? If so, maybe also try re-ordering the order that the lua scripts are started to see if the error occurs in the same or a different module.

 

[John Dowson]

Can you also use this version instead - it has extra logging enabled around running luas: FSUIPC6.dll

[aua668]

Hi,

I also thought, that I hit a  hard coded limit, but this must have been introduced with P3D 5.2. Until this version this never happened. I use this method to start my necessary modules per aircraft since FSX times already. And yes - if more modules are loaded, the probability, that it occurs, raises. If I enable logging from the beginning, I was not yet able to reproduce it until so far. Maybe the monitoring/logging influence the startup. But I will continue to try to reproduce it. I also did some experiments by delaying the start. I extended the ipc.sleep call between each ipc.runlua call in my starting loop. But even if I waited 5 seconds between each single ipc.run call, it happened sometimes.

The Q400_GF_COM1.lua is one of the modules which are loaded quite late in sequence. And with that module it happens quite often compared to others. So a lot of other modules and events monitored are already active during start. The other modules COM2, NAV1 and NAV2 are also candidates. For these modules it's easy to detect, because in most cases the event.offset triggers are effected and in that case my displays on the GoFlight hardware stay dark.

Yesterday I had similar problems in the Q400_GF_EFIS.lua, where all events have been working but the one for increasing the QNH did not trigger the function. I manually restarted the module and in the 3rd attempt I got it working normally. So it's randomly occuring in different modules.

I plan also to reinstall all Microsoft Visual C++ runtimes completely new, as at the time of my upgrade to 5.2 there was also a major Windows update (2021-06 Windows 10 21H1) to be sure, that this isn't the reason. This cleaning helped in the past with several problems.

My system is stable and I have frames limited to have enough CPU capacity available. I assigned cores with enough headroom of capacity to LUA and FSUIPC via an affinity mask. My sim is running completely stutter free. So load should not be a problem.

At the moment I am only able to fly the MD 530 helicopter or similar simple aircrafts. Q400 or A320 are always a challenge, if you detect that one button is not working as expected 😉

Rgds
Reinhard

 

 

 

[aua668]

30 minutes ago, John Dowson said:

Can you also use this version instead - it has extra logging enabled around running luas: FSUIPC6.dll

I will try with this version - Thanks!

Rgds
Reinhard

 

[aua668]

Hi,

I did two test runs with the attached DLL. The first run was done without extra debugging. And COM1 and NAV1 did not execute the event.offset triggers. But the log looks normal. Then I started with full logging enabled. COM1 was working here normally. But some other modules (like GF_BAT.lua) did not completely work as expected, although they show normal behaviour in the log file. I did disable the module with the event.timer function, as otherwise the log would have exploded.

I am the next two days on a conference. So I will continue testing on the weekend.

Rgds
Reinhard

FSUIPC6_COM1_NAV_error.log FSUIPC6_Full.log

[John Dowson]

On 8/31/2021 at 10:49 PM, aua668 said:

I did two test runs with the attached DLL. The first run was done without extra debugging. And COM1 and NAV1 did not execute the event.offset triggers. But the log looks normal.

Yes, the lua's were running as they were killed when you quit. Strange.

On 8/31/2021 at 10:49 PM, aua668 said:

But some other modules (like GF_BAT.lua) did not completely work as expected,

What do you mean by this? The log should show each line of the lua being executed, so what wasn't expected?

On 8/31/2021 at 10:49 PM, aua668 said:

I am the next two days on a conference. So I will continue testing on the weekend.

I've done further tests here and I can occasionally get an event.button not firing, but its very random, and never occurs when I step through in the debugger. I also can't get it to happen when I add additional logging to try and work out what is happening. Its very strange. - I'm thinking it could be a timing issue between different threads. I will keep investigating...

John
 

[John Dowson]

Could you also try the attached version please: FSUIPC6.dll

[aua668]

4 hours ago, John Dowson said:

What do you mean by this? The log should show each line of the lua being executed, so what wasn't expected?

As in other modules: I have several events registered - the event.button triggers are firing (i see, that the switches are operated in the cockpit) but the event.offset, which should tun on the LED on the GF module, when the battery switch is on, did not fire, although the offset did change, which I verified by FSInterrogate.

So it's always the same scenarion: The module is running - most of the events are handled as expected - and one or two out of them are not working, although the trigger should fire them.

Quote

I've done further tests here and I can occasionally get an event.button not firing, but its very random, and never occurs when I step through in the debugger. I also can't get it to happen when I add additional logging to try and work out what is happening. Its very strange. - I'm thinking it could be a timing issue between different threads. I will keep investigating...

That's exactly what I am observing: debugging and logging makes it impossible to reproduce. And also it's occuring randomly and in different modules. My observation is, that it occurs more often in modules, which are sterted later, when other modules are already running and a lot of events are alredy actively monitoring the trigger condition.

I observerd the phenomen most likely with event.offset and event.offsetmask triggers.

I will try with the new DLL this evening. I am happy, that you also had a chance to see it. I was alredy seriously thinking of a complet new setup of my machine, what would be an enourmous effort with all the sceneries and planes. As I am typically very carefully with my installations, I never had to do this step in the past. Of course for new major versions of the sim I did it anyhow.

Best regards
Reinhard

 

 

[aua668]

6 hours ago, John Dowson said:

Could you also try the attached version please: FSUIPC6.dll

Hi,

I am sorry - but this version does not start at all on my machine. It's simply not loaded, when I replace the original DLL by your version. There is no error generated. But FSUIPC menu is not appearing and no log is generated. Replacing this file again with the original DLL it's working again and FSUIPC is started.

Rgds
Reinhard

 

[John Dowson]

14 hours ago, aua668 said:

I am sorry - but this version does not start at all on my machine. It's simply not loaded, when I replace the original DLL by your version. There is no error generated. But FSUIPC menu is not appearing and no log is generated. Replacing this file again with the original DLL it's working again and FSUIPC is started.

Ah, sorry - I attached a debug build rather than a release build so you will be missing some windows dlls to run that. I'm going to add some more logging and I'll post a correct build later today for you to try.

[John Dowson]

Please try with this version: FSUIPC6.dll

17 hours ago, aua668 said:

I observerd the phenomen most likely with event.offset and event.offsetmask triggers.

I can only see it occasionally in event.button, but I've added some extra logging around event.offset in the dll above.

[aua668]

John,

Success - I used now this version and started my modules with the Q400. And in the log #1 I find now errors exactly for those modules, which did only partially work:

   216484 LUA.7: LUA\Q400\Q400_GF_NAV2 started
   216656 *** LUA Error: ...repar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_NAV2.lua:180: Coudn't enter critical section!

Then I did a second run, where also these errors occured. But with different modules. You find the result in log #2. Before closing the simulator I turned on LUA debugging. Then I started run #3. With debugging turned on, the error only occured for a single module: Q400_GF_PanelLt.lua

203906 *** LUA Error: ...ar3D v5 Add-ons\FSUIPC6\LUA\Q400\Q400_GF_PanelLt.lua:87: Coudn't enter critical section!

If you need more logs, please let me know. I attached also the Q400_GF_PanelLt.lua and NAV1 and NAV2 for your reference.

Best regards
Reinhard

FSUIPC6_1.log FSUIPC6_2.log FSUIPC6_3.log Q400_GF_PanelLt.luaQ400_GF_NAV2.luaQ400_GF_NAV1.lua