Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

optimization of log string generation #2292

Open
wants to merge 5 commits into
base: master
Choose a base branch
from

Conversation

agav99
Copy link
Contributor

@agav99 agav99 commented Nov 15, 2024

serialization of objects via JSON.stringify method may consume unnecessary resources.
This is especially noticed for the PIVO firmware, where the serialized "entity" object takes up to 90 kbytes. and it is called very often

lib/statescontroller.js Fixed Show fixed Hide fixed
main.js Fixed Show fixed Hide fixed
@asgothian
Copy link
Collaborator

Thank you for the pull request. I have a number of questions and requests:

  • Please fix the two notices given by the GitHub advanced security bot.
  • Please explain the reasoning behind the changes to the onLog function in main.js. It seems to me that it will generate a lot of messages with 'Data unavailable, check log level'
  • Please explain the reasoning for including large static structures in the elevated log messages - this defeats the general idea behind the device specific debug - tracking handling of messages through the logic, while assuming that the logic itself is ok. (present in main.js - publish from state)
  • Please remove the elevated source logging for calls to getDevStates. It defeats the purpose of the elevated messages (see comment above).
  • please move the check for debug mode into the checkDebugDevice function in a way that it always returns false if the adapter is running in debug or silly mode.
  • Please remove the commented checks for debug device presence since that functionality was moved.

Please note that I am aware of the fact that the PTVO implementation with dynamic states is an outlier as far as integration goes - an elevated logging good for the PTVO type devices will generate far too much data for 'standard' devices, but PTVO devices make less than 1% of the active devices.

A.

@agav99
Copy link
Contributor Author

agav99 commented Nov 16, 2024

  1. Please fix the two notices given by the GitHub advanced security bot. (Avoid automated semicolon insertion (93% of all statements in have an explicit semicolon).)
    to be honest, I do not understand the specified requirement. please show me an example where you don't need a semicolon

  2. Please explain the reasoning behind the changes to the onLog function in main.js.
    Мethod safeJsonStringify can serialize a huge object, using the resources of the system.
    There is no need to call this method, if the current logging level still does not show the data

  3. Please explain the reasoning for including large static structures in the elevated log messages
    I understood the checkDebugDevice function as a means of detailed debugging of a specific device. By analogy with statescontroller.js such logs contain the constant "ELEVATED". if you think that some of the logs are superfluous, comment them out
    image

4.Please remove the elevated source logging for calls to getDevStates.
Done. I have profiled the reason for the frequent calling of the AAA method, which for some devices (PRO 16 channels) performs quite a lot of processing

  1. please move the check for debug mode into the checkDebugDevice function in a way that it always returns false if the adapter is running in debug or silly mode.
    "MOVE" (from main.js onLog()) or Add the same checking?
    Deleting from main.js onLog() will result in a suboptimal safeJsonStringify call (See point 2)
    If Add checking then use condition this.adapter.log.level =='debug'
    I dont know what it means "silly mode"

@asgothian
Copy link
Collaborator

  1. Please fix the two notices given by the GitHub advanced security bot. (Avoid automated semicolon insertion (93% of all statements in have an explicit semicolon).)
    to be honest, I do not understand the specified requirement. please show me an example where you don't need a semicolon

I think the bot has an issue with missing ;, especially in if then else constructs. But I am not sure about it. As it is not that easy for me to modify the files, I'd thought to ask you to look into this and fix it.

  1. Please explain the reasoning for including large static structures in the elevated log messages
    I understood the checkDebugDevice function as a means of detailed debugging of a specific device. By analogy with statescontroller.js such logs contain the constant "ELEVATED". if you think that some of the logs are superfluous, comment them out

This is a misconception. The device debug was explicitly introduced to allow tracking data sent to and from a device without putting the entire adapter in debug mode. As such, it should generate as few messages as sensible, not as detailed as possible, in order for us to be able to document the expected message flow and pinpoint issues to people who have no experience with the entire process. Any detailed analysis still requires for the adapter to be run in debug mode.
I will do a review of the elevated messages when going through them to update this document later. I just pinpointed messages to be removed which I could already recognise from the pull request.

  1. please move the check for debug mode into the checkDebugDevice function in a way that it always returns false if the adapter is running in debug or silly mode.
    "MOVE" (from main.js onLog()) or Add the same checking?
    Deleting from main.js onLog() will result in a suboptimal safeJsonStringify call (See point 2)
    If Add checking then use condition this.adapter.log.level =='debug'
    I dont know what it means "silly mode"
    If you check the possible debug-mode settings in the iobroker admin, they are 'error', 'warn', 'info', 'debug', 'silly'

My idea was to move the check, ensuring that the elevated messages only come when debug messages do not come. This removes the need to check for each message if to send it to the elevated warning or debug message, and the code can simply call the debug message function without any additional check. Now this does not mean that the existing check must be removed - but it is no longer required in such a scenario.

A.

agav99 added 2 commits January 2, 2025 20:57
 - Change log level for "handleDeviceJoined" message
devStates.states.filter(statedesc => payload.hasOwnProperty(statedesc.prop || statedesc.id))
);
if (!devStates) {
if (has_debug) this.error(`ELEVATED IE2 (publishToState): no device states for device ${devId} type '${model}'`)

Check notice

Code scanning / CodeQL

Semicolon insertion Note

Avoid automated semicolon insertion (96% of all statements in
the enclosing function
have an explicit semicolon).
@@ -1090,7 +1108,12 @@
if (typeof data === 'string') {
logger(`${msg}. ${data}`);
} else {
logger(`${msg}. ${safeJsonStringify(data)}`);
if ((this.log.level==level) ||
((this.log.level='warn')&&(level='error')) ||

Check warning

Code scanning / CodeQL

Useless conditional Warning

This expression always evaluates to true.
This logical 'and' expression can be replaced with a comma expression.
@@ -1090,7 +1108,12 @@
if (typeof data === 'string') {
logger(`${msg}. ${data}`);
} else {
logger(`${msg}. ${safeJsonStringify(data)}`);
if ((this.log.level==level) ||
((this.log.level='warn')&&(level='error')) ||

Check warning

Code scanning / CodeQL

Useless conditional Warning

This expression always evaluates to true.
@@ -1090,7 +1108,12 @@
if (typeof data === 'string') {
logger(`${msg}. ${data}`);
} else {
logger(`${msg}. ${safeJsonStringify(data)}`);
if ((this.log.level==level) ||
((this.log.level='warn')&&(level='error')) ||

Check warning

Code scanning / CodeQL

Useless conditional Warning

This expression always evaluates to true.
logger(`${msg}. ${safeJsonStringify(data)}`);
if ((this.log.level==level) ||
((this.log.level='warn')&&(level='error')) ||
((this.log.level='info')&&(level='error' || level=='warn'))

Check warning

Code scanning / CodeQL

Useless conditional Warning

This logical 'and' expression can be replaced with a comma expression.
logger(`${msg}. ${safeJsonStringify(data)}`);
if ((this.log.level==level) ||
((this.log.level='warn')&&(level='error')) ||
((this.log.level='info')&&(level='error' || level=='warn'))

Check warning

Code scanning / CodeQL

Useless conditional Warning

This expression always evaluates to true.
((this.log.level='warn')&&(level='error')) ||
((this.log.level='info')&&(level='error' || level=='warn'))
)
logger(`${msg}. ${safeJsonStringify(data)}`)

Check notice

Code scanning / CodeQL

Semicolon insertion Note

Avoid automated semicolon insertion (93% of all statements in
the enclosing function
have an explicit semicolon).
@asgothian
Copy link
Collaborator

In this form, I am unwilling to merge the PR:

Please consider the following requests:

  • fix the open issues from the check-and-lint test.
  • evaluate the 'Useless condition' warning, and either remove the code or explain why the warning is wrong.
  • remove the non-tagged (I.. IE.. O.., OE.. Messages). Alternatively, retag them (see below). In this case please evaluate how much data will be logged, especially in cases where enumerations come into play. A prime example on how not to do it is the message in processConverters. There may be a several converters passed to the function, so the identical message may be generated multiple times with no added benefit to the user, as the actual data (id, payload) are already available in other messages
  • If new messages are added, please expand the tagging system to give each message a unique ID. Please also consider that repeated posting of identical data is limited, especially in any cases where elevated messages are posted from array/object enumeration System for tagging: Anything triggered by incoming messages gets an Ixx tag, where xx is a 2 digit number which should increase as the message is handled. Errors during handling receive an IExx tag. Anything relating to messages to be sent to the device receive an O Tag, with the same rules as above.

Note that work is in progress to generate a debug interface in the adapter which both displays these messages as well as allows interactive tagging of devices for debug in order to make this more accessible to end users. Also note that the ID's attached to the messages are (at this time) not fixed so you are free to reassign them as long as the general rule that messages should appear with increasing numbers in the log remains heeded.

In the end, ALL elevated messages will be required to have a tag for easy identification.

A.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants