robweber / xbmcbackup

Backup Addon for Kodi
MIT License
107 stars 48 forks source link

Log debug is used with a bad pratice, log spamming #159

Closed CastagnaIT closed 4 years ago

CastagnaIT commented 4 years ago

Describe the problem I don't use your app, but some users do and create problems with logging

clearly record too many things in the log, you can't have more than 40000 lines of file names operations to the backup! Currently, when debugging is enabled, it can generates logs up to 10mb! and that's not good.

You call the function xbmc.log too many times, this causes an unnecessary CPU load, even if kodi debugging is disabled (kodi api function is always called).

LibreELEC team warned me of this problem, that is a bad pratice, and now i'm telling you to add an option in your settings that the users can enable a verbose logging, so should be disabled by default.

you can take example from my PR, you can see my implementation here: https://github.com/CastagnaIT/plugin.video.netflix/pull/301

This is advice that i hope you will adopt, because it makes things difficult for any developer who needs to debug their addons

Link to Debug Log Example log: http://www.mediafire.com/file/y9pfa9hhoyvptnq/kodi_%25284%2529.log/file

robweber commented 4 years ago

Interesting, I'll consider it. The large log file is not really a concern to me, in fact it helps me debug this addon when people have issues with it. If Kodi debugging is enabled the addon will only put stuff in the log if it is actually being run. In practice people should turn on debug logging when they have a point to. By this I mean turn it on to get info from a particular addon or issue, and then turn it off. If you don't want a debug log from this addon, don't run the addon when you have the debug log enabled. This addon won't run unless you tell it to. Now that you can enable component specific logging in Kodi means you can debug a lot within the Kodi core without needing to turn the full debug log on at all.

The fact that the xbmc.log function gets executed even with the debug flag passed is not something that has occurred to me before. I can see how this would add extra overhead, although in actual running scenarios I've not seen it make a meaningful impact. Examining the code directly it appears that one of the very first things done when passing the log string up to the Kodi logger is to filter on log level, which is minimal processing really. Still the fact that the string needs to be processed and such does add some overhead to the overall process.

I'll give it some thought. Thanks for the info.

CastagnaIT commented 4 years ago

The problem is, as i see, your addon has an automatic backup schedule so without this change that i proposed to you, the user should at least should be informed of having to disable your addon before enabling Kodi debug otherwise your addon will create huge debug streams that create complications to other developers who have to debug other components

robweber commented 4 years ago

The commit I just pushed should take care of most of the really spammy log messages. I hid these under a Enable verbose logging setting. The remaining log messages are pretty minimal and very useful in the event someone does have a problem. They shouldn't interfere with anyone running a debug log for other purposes.

I think this will take care of the concern but still allow for more advanced logging if needed.

CastagnaIT commented 4 years ago

Thank you