Strange behavior in logging (triggering and internal script logging) [Solved]

[James83]

Hi all,

Today i noticed that the logging is not complete anymore when dzVents scripts are triggered. latest beta 13149 and also in 13133 on RPI4.
Especially time-triggered scripts do not show anything in the logs anymore.
Other scripts do show their triggering but not the internal logging in the script (like dz.log)
However, the scripts get executed, exept for their logging

I believe it worked a few beta's ago (i used 12709 for a while) so i tried to go back to previous beta's but was not able to find a version with correct logging, also not 12709.
Is it something on my side thats wrong or did something changed in de logging? ( i could not find anything that says so)
All hardwaredevices have logging enabled.
I have dzVents logging "errrors-minimal execution info-generic info" enabled, as always was.

A temp triggered script show start and end of the scripts but nothing internal.
2021-04-11 16:05:29.845 Status: dzVents: Info: Handling events for: "RPi3B (T)", value: "52.1"
2021-04-11 16:05:29.845 Status: dzVents: Info: ------ Start internal script: Temp-Hum_events: Device: "RPi3B (T) (Domoticz Remote Server)", Index: 1389
2021-04-11 16:05:29.845 Status: dzVents: Info: ------ Finished Temp-Hum_events

This scripts gets triggered by a timer and gets an httpResponse. No sign of the triggered timer but the httpRespons is visible but no further actions of the script.
2021-04-11 16:06:02.254 Status: EventSystem: Script event triggered: /home/pi/domoticz/dzVents/runtime/dzVents.lua
2021-04-11 16:06:02.412 Status: dzVents: Info: Handling httpResponse-events for: "huetrigger"

Thx in advance
Jimmy

[waaren]

Today i noticed that the logging is not complete anymore when dzVents scripts are triggered. latest beta 13149 and also in 13133 on RPI4.
Especially time-triggered scripts do not show anything in the logs anymore.

Code: Select all

	logging = 
	{
	    level = domoticz.LOG_INFO,
	    marker = 'LOGGING',
	},

The trigger logging is also controlled by the logsetting in the script (See above). If it set to LOG_ERROR you won't see the Start and Finished as below.

Result when set as above in the script and with Errors + minimal execution info + generic info

Code: Select all

2021-04-11 18:07:00.671  Status: dzVents: Info: LOGGING: ------ Start internal script: dz 20210411 time logging:, trigger: "every minute at daytime"
2021-04-11 18:07:00.673  Status: dzVents: Info: LOGGING: ------ Finished dz 20210411 time logging

[James83]

Code: Select all

	logging = 
	{
	    level = domoticz.LOG_INFO,
	    marker = 'LOGGING',
	},

The trigger logging is also controlled by the logsetting in the script (See above). If it set to LOG_ERROR you won't see the Start and Finished as below.

Result when set as above in the script and with Errors + minimal execution info + generic info

Code: Select all

2021-04-11 18:07:00.671  Status: dzVents: Info: LOGGING: ------ Start internal script: dz 20210411 time logging:, trigger: "every minute at daytime"
2021-04-11 18:07:00.673  Status: dzVents: Info: LOGGING: ------ Finished dz 20210411 time logging

Thanks for that info. That did the trick. All my scripts have level = domoticz.LOG_FORCE (has always been like that)
I changed the scripts to level = domoticz.LOG_INFO and now everything shows up in the logging.
So something did change but don't know what.

Thanks a lot for your input! Much appreciated!

Jimmy