Allow overriding twistd's logging options

[itamarst]

The use case of *adding* observers can be done simply by doing it in startService.
My suggestion is for replacing twistd's default - it checks for ILogging on
application. So, in the .tac we do:
from twisted.application.service import ILogging
class Logging:
    def initialize(self):
        log.startLoggingWithObserver(myObserver)
application.setComponent(ILogging, Logging())

[ralphm]

#1624 defers to here, but the comment by itamarst doesn't seem to be valid anymore. I see no reference of ILogger anywhere. Or is this a suggestion on how it could theoretically work and then used as shown?

[exarkun]

A suggestion about how it could work, I think.

[harshaw]

here are some patches to make this work.

[harshaw]

twistd patch

[harshaw]

twistd patch

[harshaw]

log.py patch (for the interface)

[harshaw]

disregard the second twistd.patch... sigh.

[therve]

I steel this, I've got a personal interest for this feature.

[itamarst]

.tac support is good, but twistd plugin support even more so. How are we going to do that? Presumably expand the plugin interface somehow.

[therve]

I tried something, that works for tac files, and also for plugins. It'd need lots of documentation, of course, but the real question is: how to test that?

[itamarst]

Comments:

1. ILogging could be better named. 2. The getLogFile method is redundant, it should just have getLogObserver. 3. getLogObserver shouldn't accept log file as argument; some observesrs will not use a file, e.g. syslog.

and there's the question of what happens when twistd options and the plugin/tac specify logging, which is probably the motivation for this version of ILogging.

[therve]

Replying to itamarst:

Comments: 1. ILogging could be better named.

Alright. Suggestions ? :)

2. The getLogFile method is redundant, it should just have getLogObserver.

I have a use case when I want to reuse default logfile. I want to customize both.

3. getLogObserver shouldn't accept log file as argument; some observesrs will not use a file, e.g. syslog.

syslog is not supported by this kind of customization.

and there's the question of what happens when twistd options and the plugin/tac specify logging, which is probably the motivation for this version of ILogging.

The only problem is when you want to use syslog, but it's stated as not supported, because I don't see how you could customize this. The file is specified in the options, and passed to getLogFile.

[itamarst]

Replying to therve:

1. ILogging could be better named.

Alright. Suggestions ? :)

ILoggerFactory or something.

2. The getLogFile method is redundant, it should just have getLogObserver.

I have a use case when I want to reuse default logfile. I want to customize both.

3. getLogObserver shouldn't accept log file as argument; some observesrs will not use a file, e.g. syslog.

syslog is not supported by this kind of customization.

Re-using twistd config is good, but the interface for doing so is not. "syslog is not supported by this kind of customization" doesn't make sense to me - why not?

seems to me your use-case is "pass twistd's logging options to the log observer factory, so it can override stuff." so:

def getLogObserver(logfile=None, syslog=False) will get called, with arguments based on whatever twistd options user provides. The implementation can choose to ignore one or both of these arguments. The default twistd behavior should be easily available to implementors so they can re-use it.

Obvious problem #1 with this proposal: what if we want to add more logging options to twistd?

[therve]

Replying to itamarst:

ILoggerFactory or something.

Looks good.

Re-using twistd config is good, but the interface for doing so is not. "syslog is not supported by this kind of customization" doesn't make sense to me - why not?

My main reason is because syslog seems to work well currently, with the existing options provided (and how can it be customized more ?). It doesn't bring nothing to use it in this system. The other reason is that I don't use syslog so I didn't care :). That's not a good reason though.

seems to me your use-case is "pass twistd's logging options to the log observer factory, so it can override stuff." so:

That's true.

def getLogObserver(logfile=None, syslog=False) will get called, with arguments based on whatever twistd options user provides. The implementation can choose to ignore one or both of these arguments. The default twistd behavior should be easily available to implementors so they can re-use it.

It seems fair. Although I still don't see the use case for syslog :).

Obvious problem 1 with this proposal: what if we want to add more logging options to twistd?

I'd say that we shouldn't, because if we bring this functionnality in tac/plugins, it's especially to not add another '--logclass=MySuperThing'. If the new system works good, there won't be more need for new options, as everything will be configurable with ILoggerFactory.

But the best way would be 'def getLogObserver(config, logfile=None)' ? This way we could add stuff into config without breaking anything.

Thanks a lot for your comments.

[itamarst]

(Adding Cory to the conversation, maybe he can help with NT Service info).

Replying to therve:

My main reason is because syslog seems to work well currently, with the existing options provided (and how can it be customized more ?). It doesn't bring nothing to use it in this system. The other reason is that I don't use syslog so I didn't care :). That's not a good reason though.

Perhaps one has a networked syslog implementation, but yes, it's not like most people will use it, but still...

I'd say that we shouldn't, because if we bring this functionnality in tac/plugins, it's especially to not add another '--logclass=MySuperThing'. If the new system works good, there won't be more need for new options, as everything will be configurable with ILoggerFactory.

Except that I can think of at least one logging system we will be adding sooner or later, Windows, when we finally get NT Service support going. Assuming I am remembering correctly and it's possible to use it for general logging, I might be wrong.

But the best way would be 'def getLogObserver(config, logfile=None)' ? This way we could add stuff into config without breaking anything.

If we pass config in there's probably no need for logfile, users can just do config["logfile"].

Even so, it seems like we still haven't really worked out a good way for twistd loging options to interoperate with plugin logging options. Here's an alternative proposal to think about: change getLogObserver to overrideLogObserver or some such, with config as argument. The developer can choose to call t.p.log.addLogObserver directly if they want. The method returns a boolean telling twistd whether or not it should add its own log observer. E.g.

def overrideLogObserver(config):
   twisted.python.log.addObserver(MyLogger(config["logfile"]).write)
   return True # suppress twistd's logging

Except... on Unix you might want to override, but perhaps on NT you'd want to add you logging in addition to NT Service log, and users shouldn't have to think about it. Maybe syslog option should be set to True on Windows for NT service thing and people can decide based on that, I dunno. Also you wouldn't be getting a logfile path on Windows. Anyone else have an idea?

Thanks a lot for your comments.

Thanks for working on this :)

[exarkun]

Replying to therve:

Replying to itamarst:

ILoggerFactory or something.

Looks good.

Re-using twistd config is good, but the interface for doing so is not. "syslog is not supported by this kind of customization" doesn't make sense to me - why not?

My main reason is because syslog seems to work well currently, with the existing options provided (and how can it be customized more ?). It doesn't bring nothing to use it in this system. The other reason is that I don't use syslog so I didn't care :). That's not a good reason though.

The advantage is reduction in code and complexity. Having two parallel systems which both do things to the logging system makes this area even hairier than it already is. Plus it introduces potential confusion to the user. What happens if you try to use the syslog options and provide an ILogger(/Factory?)? We should try to avoid the possibility for things like that.

seems to me your use-case is "pass twistd's logging options to the log observer factory, so it can override stuff." so:

That's true.

def getLogObserver(logfile=None, syslog=False) will get called, with arguments based on whatever twistd options user provides. The implementation can choose to ignore one or both of these arguments. The default twistd behavior should be easily available to implementors so they can re-use it.

It seems fair. Although I still don't see the use case for syslog :).

Obvious problem 1 with this proposal: what if we want to add more logging options to twistd?

I'd say that we shouldn't, because if we bring this functionnality in tac/plugins, it's especially to not add another '--logclass=MySuperThing'. If the new system works good, there won't be more need for new options, as everything will be configurable with ILoggerFactory. But the best way would be 'def getLogObserver(config, logfile=None)' ? This way we could add stuff into config without breaking anything.

Dictionaries of strings pretty much suck. :/ I think the case here is similar to the one trial's reporter plugins are dealing with. The existing logging options twistd offers are configuration for the existing log observer. They're not general logging options. Ideally, each logging plugin should be able to define and accept whatever options it wants, if we are going to allow options to be passed to logging plugins.

BTW, for anyone wondering, the code being discussed here is in improve-log-867

[exarkun]

Except not improve-log-867. Actually it's in twistd-logging-638.

[exarkun]

Some other comments now that I've actually looked at the code :)

• The docstring and whitespace cleanups in logfile.py and components.py should go in another branch, since they are actually the only changes in those files in this branch. It's fine to do cleanups near code that's changing anyway, but we should try to avoid going beyond that: it makes branches harder to review and makes looking back at changes which have been merged to trunk harder to understand.
• The changeLogging duplication between _twistw.py and _twistd_unix.py is pretty unfortunate. There should be some way to eliminate that.
• The only way to specify a custom log observer should not be via a custom subcommand! The application running is orthogonal to the log observer being used! Consider all of the existing twistd subcommands (web, words, conch, manhole, ftp, etc). We need to do something which is going to be usable with all of these.

[therve]

Replying to exarkun:

Some other comments now that I've actually looked at the code :) * The docstring and whitespace cleanups in logfile.py and components.py should go in another branch, since they are actually the only changes in those files in this branch. It's fine to do cleanups near code that's changing anyway, but we should try to avoid going beyond that: it makes branches harder to review and makes looking back at changes which have been merged to trunk harder to understand.

Agree. I've begin to make modifications to these files until I saw it wasn't necessary. I'll revert that.

* The changeLogging duplication between _twistw.py and _twistd_unix.py is pretty unfortunate. There should be some way to eliminate that.

The differences here are for syslog and daemon config. Apart that, much of the code is the same. ApplicationRunner should be a good place for this ?

* The only way to specify a custom log observer should not be via a custom subcommand! The application running is orthogonal to the log observer being used! Consider all of the existing twistd subcommands (web, words, conch, manhole, ftp, etc). We need to do something which is going to be usable with all of these.

Arg :). I knew the hack for plugins would be wrong somewhere. For this use case we need twistd options, because there's no user code. Here something like trial's reporters will be perfect I assume.

Side note: twistd seems untested, that's why I have such a pain to test this. Any pointers on how I could do this ?

[therve]

Replying to itamarst:

{{{ def overrideLogObserver(config): twisted.python.log.addObserver(MyLogger(configlogfile?).write) return True # suppress twistd's logging }}} Except... on Unix you might want to override, but perhaps on NT you'd want to add you logging in addition to NT Service log, and users shouldn't have to think about it. Maybe syslog option should be set to True on Windows for NT service thing and people can decide based on that, I dunno. Also you wouldn't be getting a logfile path on Windows. Anyone else have an idea?

That could be fine, but it's no very usable because the user has to do many things Twisted can do alone. Of course it's also more powerful, but we can already do that currently (I already do that in my application: remove the default log observer, and create a new one). But if I do that, I'll also have to handle SIGUSR1 rotate. I'll have to get the absolute path of the application to get full path to logfile. If we go like this the only thing we provide is a clean way to stop default logger.

What's my use case ? I want to customize the logFormat (for example, remove the date and just have H:M:S). So I need a custom LogObserver. And I want to customize how files are rotated (for example, daily), so I need a custom LogFile.

The need of something for subcommand goes in the same direction I think: the possibility to modify the LogObserver and the LogFile via twistd options.

[exarkun]

Replying to therve:

Replying to exarkun:

* The changeLogging duplication between _twistw.py and _twistd_unix.py is pretty unfortunate. There should be some way to eliminate that.

The differences here are for syslog and daemon config. Apart that, much of the code is the same. ApplicationRunner should be a good place for this ?

Yep, ApplicationRunner should be great.

* The only way to specify a custom log observer should not be via a custom subcommand! The application running is orthogonal to the log observer being used! Consider all of the existing twistd subcommands (web, words, conch, manhole, ftp, etc). We need to do something which is going to be usable with all of these.

Arg :). I knew the hack for plugins would be wrong somewhere. For this use case we need twistd options, because there's no user code. Here something like trial's reporters will be perfect I assume.

Oops, I guess I implied trial had already solved this problem :P But actually it suffers from exactly the same deficiency. What I meant to say was that both of these systems need a solution, and it's probably the same one. I'm not exactly sure what the best solution is yet, although I can think of a lot of kinda-okay solutions. For the sake of discussion, some of them are:

• Support a command line like twistd --logger=foo --logger-options='--bar baz' ...
• Support multiple subcommands somehow:
  • twistd logger --plugin foo web --path ...
  • twistd logger --plugin foo -- web --path ...

  • $ twistd commandline
    > logger --plugin foo
    > web --path ...
    > ^D
    

• Add config file support so logging options can be specified in a twistd.conf and don't need to be specified on the command line

But none of these really inspire me.

Side note: twistd seems untested, that's why I have such a pain to test this. Any pointers on how I could do this ?

Yea... Chris recently added the meager test coverage which does exist (twisted/test/test_twistd.py). Most twistd code predates the requirement for rigorous testing, which means it isn't factored to be easily testable at all. Do you think a test for the logging changes could fit into test_twistd.py? If not, I can try to take a harder look and see if I have any other ideas.

[therve]

Replying to exarkun:

* Add config file support so logging options can be specified in a twistd.conf and don't need to be specified on the command line

Yes, please. The twistd line is already looong, so if we need to add options I think it's a good mean. Furthermore, it will add configuration for all applications.

But it seems out of the scope of the ticket. Maybe we should add this feature before kicking logging ?

Side note: twistd seems untested, that's why I have such a pain to test this. Any pointers on how I could do this ?

Yea... Chris recently added the meager test coverage which does exist (twisted/test/test_twistd.py).

Thanks, I missed that one.

[exarkun]

Chris is great.

[itamarst]

We seem to have two use cases. To summarize:

1. Changing date format, log rotation policies, etc. on default twistd logging system. 2. Easy way to add and configure extra logging subsystems.

The current code is for #1, but seems too generalized in its current form; perhaps the interface should just expose settings/callback hooks for specific options related to default twistd logfiles. These would be less work for developers to implement, and the more general case would be served by #2.

For #2 UI is an issue. Perhaps the commandline plugin exarkun and I discussed would solve that problem (I will open a ticket soon, if exarkun does not). Perhaps we can leave #2 out of scope for this ticket.

[therve]

I've mixed harshaw's solution with mine, to have something that works with subcommands. I've added a sample plugin dailylogger, and some documentation to explain the functionality.

[exarkun]

I started to review this but I didn't get very far. Instead I wrote some more stuff on Specification/AdministrativeComponentSelection. I'll try to review this branch again soon, but if anyone wants to steal this ticket from me before I do it, please feel free.

[therve]

I've read the page you've setup. I'm a bit annoyed because you're concentrating on the part of the branch I don't care, around twistd command line options. I really think this is useless, because everything could be done inside the tac file. And most existing applications already have an external config file...

So if your point is that the options added is stupid, I'm not going to object: let's remove this. We could probably think about it later when we'll come with a good implementation in mind.

[glyph]

/over

[glyph]

The interface provided here, overrideLogObserver, has several problems.

• It invites abuse. Nothing prevents or discourages the user from manipulating non-logging-related options in the "config" object presented.
• It sets a precedent for other bad APIs. Are we going to have overrideUID? overrideSpewer? overrideReactor?
• It has no explicit channel for its own information. The documented example also encourages developers to change the meaning of existing logging options without providing any documentation or explanation of the fact that their plugin does this.

If we want plugins and tac files to be able to manipulate the options to twistd in a structured way, then twistd should first be converting its options into a structured object. I've filed a new ticket, #2571, for this task, which should be separated (and may in fact be broken down further).

[radix]

Here's what it should be:

application.setComponent(ILogObserver, o)

where 'o' implements the log observer interface; specifically, it is a callable of one dictionary argument.

[radix]

(In [24302]) Branching to 'configure-log-observer-638'

[radix]

ready for review

[itamar]

The branch doesn't document how I'd set logging in a twistd plugin, which one hopes will be more commonly used than .tac files... In particular, how do I get access to the all-important application object?

[radix]

Never mind, this sucks.

[therve]

I don't think we need the application object. Something like that in createOrGetApplication should do the trick:

if ILogObserver.providedBy(plg):
    application.setComponent(ILogObserver, plg)

[radix]

Alright, how about now?

[exarkun]

(In [24422]) Branching to 'configure-log-observer-638-2'

[exarkun]

• twisted/python/log.py
  • update copyright date
  • ILogObserver.__call__ incorrectly includes self in the parameter list
  • In the list of often available keys, the keys should probably be strings, yes?

I think there could be better user-facing behavior if a name supplied to --logger doesn't actually give a valid FQPN. Might also be worth mentioning --logger also overrides --syslog?