Feature proposal: SP-wide logging -- the python logging module

Submit modules/packages for inclusion with Source.Python.
Omega_K2
Senior Member
Posts: 227
Joined: Sat Jul 07, 2012 3:05 am
Location: Europe
Contact:

Feature proposal: SP-wide logging -- the python logging module

Postby Omega_K2 » Tue Jul 17, 2012 12:44 am

I think it would be quite useful to implement SP wide logging though the logging libary. Right now, we only have printing to console using the print() function, but implementation of logging these things though the logging module would take everything multiple steps further.

If you don't know about the logging module, you can find the docs here:
http://docs.python.org/py3k/library/logging.html
http://docs.python.org/py3k/library/logging.config.html
http://docs.python.org/py3k/library/logging.handlers.html

I think this would a great way to provide logging besides the normal server log. Since scripts can access the sp.py or the logging module, they could their own logging handlers - for example, a custom addon may specific logging all SP events with a certain level to a file or even send those logs over the network to a server - for example, this could be useful for admins wanting to monitor what is going on their server (-- module loads, errors etc).

Also, this would allow for the addition of log levels for the particular messages sent to the server console. Again, this would be helpful since people can set the logging level to filter out messages you don't want or want to see in the server console (for example, you may not want to see errors or debugging info in console to improve usability [everyone who tried to do something in SRCDS when the console is getting spammed knows what I means :P], but still want them logged to the harddrive)

It also allows the implementation for module level logging, so modules can also use their own logging handlers/formats. If they don't, they just use the SP defaults - this way printing to console for example can be done in a very convinient and consistent way; for example, if we suddenly want to change the format from [SP] msg to [{time}] [SP] msg that would require replacing the print functions [and essentially writing sp's own logger, though in a more simple form].

This may have some performance impact, but I assume that most logging messages are not occuring on a tick lister so performance impacts should be neligble [also string formatting generally only occurs wtih the logging function if the message is valid for the specifid logging level].
User avatar
satoon101
Project Leader
Posts: 2697
Joined: Sat Jul 07, 2012 1:59 am

Postby satoon101 » Tue Jul 17, 2012 1:01 am

We will have to discuss this further internally at a later time. If you wish to work on an API for this on your own, and submit it, we have no issue with that. That would also help us get a better feel for whether or not it is something we would wish to implement. If we decide one way or the other in the meantime, we will be sure to let you know.

I will comment on one point at this time, though:

Having logging levels to the server console has already been discussed. We intend to hook Developer Messaging and utilize the -deveoper command line parameter for this purpose.

Satoon
Omega_K2
Senior Member
Posts: 227
Joined: Sat Jul 07, 2012 3:05 am
Location: Europe
Contact:

Postby Omega_K2 » Tue Jul 17, 2012 9:25 pm

Well, I can create a patch based on the current version of the source that uses the logging module and possibly an example addon that adds logging to file. How does that sound?
User avatar
satoon101
Project Leader
Posts: 2697
Joined: Sat Jul 07, 2012 1:59 am

Postby satoon101 » Tue Jul 17, 2012 9:46 pm

Sounds good. Post either here or in the Module/Package Submissions forum when you have something working.

Thanks,
Satoon
Omega_K2
Senior Member
Posts: 227
Joined: Sat Jul 07, 2012 3:05 am
Location: Europe
Contact:

Postby Omega_K2 » Wed Jul 18, 2012 3:37 pm

Done. Zip including new/changed files: [ATTACH]38[/ATTACH]

If you have any questions let me know.

Notes:
file-logging is just an example how addons could extend the logging system [I suppose a decent addon would be better!]
I added a log folder; seems to make sense ( log/source-python/ )
Attachments
sp.zip
(8.23 KiB) Downloaded 833 times
Omega_K2
Senior Member
Posts: 227
Joined: Sat Jul 07, 2012 3:05 am
Location: Europe
Contact:

Postby Omega_K2 » Fri Jul 20, 2012 9:42 pm

Have you taken a look at the files?
User avatar
satoon101
Project Leader
Posts: 2697
Joined: Sat Jul 07, 2012 1:59 am

Postby satoon101 » Sat Jul 21, 2012 12:07 am

I have not really had too much time, and I am also preparing for a week long trip I leave for on Monday. Once I do get the chance, I will let you know what I think.

Satoon
User avatar
satoon101
Project Leader
Posts: 2697
Joined: Sat Jul 07, 2012 1:59 am

Postby satoon101 » Tue Aug 07, 2012 4:24 am

I still have not had a lot of time to look into this or had a chance test it out yet, but I have come to the conclusion that I wish for this functionality to be included. The plan, currently, is to use a base settings file (possibly located at ../cfg/source-python/core_settings.ini) that will house basic configurations for Source.Python. One of the sections in the configuration will be for logging, and might look something like:

Code: Select all

[LOGGING_SETTINGS]
Logging_Level=0

# Available Logging Types:
#   Console
#   Log File
Logging_Type="Console"
This file will only be parsed when the server is booted. Though, I do intend on possibly adding console commands to set each of these while the server is running. I have moved this to the Module/Package Submission forum, since that forum seems more appropriate for it at this time.

As far as the makeup of the logging module itself, I would basically like to see something like this:
  • Text is passed to the logger with its logging level
  • If the level is greater than the current value of Source.Python's logging level, it simply returns and does nothing
  • Otherwise, if the logging type is set to console (we could also use 1/0 for this value instead), the text is printed to the console.
  • If logging type is log to file, it logs it to the appropriate file

Satoon
Omega_K2
Senior Member
Posts: 227
Joined: Sat Jul 07, 2012 3:05 am
Location: Europe
Contact:

Postby Omega_K2 » Wed Aug 08, 2012 2:33 pm

The python module pretty much does all that and more; the good thing is that we can do module-level logging (and also module-based logging levels), so one module can run in debugging mode while the normal SP thing just runs in normal logging mode.
Again one of the good things here is as soon the logging objects are exposed any script can just import the file and add their own logging handler. Python itself comes with about 14 different logging handler that can be used.

But anyway, since I think it makes sense to have some logging setup on init that config file makes sense, so at the very least file and console logging should be included. Though what I see here is that some people may want to extend that functionality, so going with both should work.
Omega_K2
Senior Member
Posts: 227
Joined: Sat Jul 07, 2012 3:05 am
Location: Europe
Contact:

Postby Omega_K2 » Fri Aug 10, 2012 4:02 pm

Should I create a new version of the sp files with the logging included?

The old one probably might have some problems with merging. Mostly it's just replacing prints anyway.
It's just a question of how you want it to be set up; I think some of the normal output should be logged aswell such as addon load/onload, though only by default to console, not to file. With the python thing is not a problem to setup, as the logging level for a handler can be different to the logging level of another one (basically, console should run on a INFO level and file logging for warnings /errors)
User avatar
satoon101
Project Leader
Posts: 2697
Joined: Sat Jul 07, 2012 1:59 am

Postby satoon101 » Sat Aug 11, 2012 12:37 am

As of right now, I am going to put an internal freeze on modifying any of the _libs/addons/ and _libs/events directories, as well as the current functions currently within sp.py. Feel free to modify those any way you wish, as we will not be modifying them ourselves.

The normal output stuff will always be set at level 0, so they should always be logged (whether to console or to file), though, I guess we could make level 0 also always print to console regardless of the log_to_file setting.

I guess my question would be about how you mentioned having some modules log while others do not. How do you propose we go about setting that up so that the logger knows what to log and not to log? I don't want to make this needlessly overly complicated, so if this type of feature is going to cause that to happen, I say we can do without. Having an API to log for scripts, though, is definitely something I would like to look into.

I cannot wait to see what you come up with. Also, please include proper documentation in your script.

Satoon
Omega_K2
Senior Member
Posts: 227
Joined: Sat Jul 07, 2012 3:05 am
Location: Europe
Contact:

Postby Omega_K2 » Sat Aug 11, 2012 1:20 pm

Based it on the way how it works, it is really easy to implent module based logging. I just made it so that by default, everything gets logged to console. Once the config is made, this can be adjusted accordingly (along with the default levels).
Logging more at the module level can be done by adding a handler with a higher log level or adding a filter to lower level modules.


Note that I did not include file logging so far, (but it just works in a similar way - create a FileHandler object and add it to the logging stuff basically). Also, with the filters cool things could be done,like logging everything but errors to source-python/general.log and exceptions to soruce-python/exceptions.log
Attachments
log.zip
(5.86 KiB) Downloaded 834 times

Return to “Module/Package Submissions”

Who is online

Users browsing this forum: No registered users and 8 guests