openhab / openhab-js

openHAB JavaScript Library for JavaScript Scripting Automation
https://www.openhab.org/addons/automation/jsscripting/
Eclipse Public License 2.0
38 stars 31 forks source link

Library is using the same logging namespace as scripts #185

Closed florian-h05 closed 1 year ago

florian-h05 commented 1 year ago

As reported in the community (https://community.openhab.org/t/openhab-3-4-milestone-discussion/138093/113), openhab-js debug logging can confuse users:

2022-11-28 01:07:18.997 [DEBUG] [rg.openhab.automation.script.actions] - Successfully activated action org.openhab.core.model.script.internal.engine.action.AudioActionService@67265b as Audio
2022-11-28 01:07:19.001 [DEBUG] [rg.openhab.automation.script.actions] - Successfully activated action org.openhab.core.model.script.internal.engine.action.EphemerisActionService@1a930af as Ephemeris
2022-11-28 01:07:19.004 [DEBUG] [rg.openhab.automation.script.actions] - Successfully activated action org.openhab.core.model.script.internal.engine.action.PersistenceActionService@e19f3f as PersistenceExtensions
2022-11-28 01:07:19.008 [DEBUG] [rg.openhab.automation.script.actions] - Successfully activated action org.openhab.core.model.script.internal.engine.action.SemanticsActionService@4226b8 as Semantics
2022-11-28 01:07:19.012 [DEBUG] [rg.openhab.automation.script.actions] - Successfully activated action org.openhab.core.model.script.internal.engine.action.TransformationActionService@5d9009 as Transformation
2022-11-28 01:07:19.015 [DEBUG] [rg.openhab.automation.script.actions] - Successfully activated action org.openhab.core.model.script.internal.engine.action.ScriptExecutionActionService@106db89 as ScriptExecution
2022-11-28 01:07:19.018 [DEBUG] [rg.openhab.automation.script.actions] - Successfully activated action org.openhab.core.model.script.internal.engine.action.ThingActionService@1e7753a as Things
2022-11-28 01:07:19.022 [DEBUG] [rg.openhab.automation.script.actions] - Successfully activated action org.openhab.core.model.script.internal.engine.action.VoiceActionService@1e26244 as Voice
2022-11-28 01:07:19.025 [DEBUG] [rg.openhab.automation.script.actions] - Successfully activated action org.openhab.io.openhabcloud.internal.CloudService@1c21c3 as NotificationAction
2022-11-28 01:07:19.029 [DEBUG] [rg.openhab.automation.script.actions] - Successfully activated action org.openhab.ui.habot.notification.WebPushNotificationAction@199f06 as WebPushNotificationAction

The problem we have, is that openhab-js is logging to the same logger prefix as user scripts, so we cannot reduce logging from debug to info, because we then would „break“ console.debug for the user scripts.

I propose to change the logger prefix for our library and the log4j2 configuration:

@digitaldan Why did you revert your addition of such a logger prefix in https://github.com/openhab/openhab-distro/pull/1364?

digitaldan commented 1 year ago

The reason is linked in that PR, see https://github.com/openhab/openhab-distro/issues/1362 , I would need to re-read that conversation as well to remember as it was almost a year ago.

florian-h05 commented 1 year ago

Thx for the link. After reading the conversation, I got the point of the decision. So, as we keeporg.openhab.automation.script on INFO, I’ll add a note about enabling console.debug and console.trace to the README.

Anyway, IMO we should change the logger prefix for openhab-js to something that makes clear that the message comes from openhab-js.

I will change the library’s logger prefix to org.openhab.automation.openhab-js.

@digitaldan Are you fine with those two changes?

digitaldan commented 1 year ago

yeah, i'm good with those!