Opened 3 years ago

Last modified 3 years ago

#7549 enhancement new

t.p.syslog doesn't support logLevel (reprise)

Reported by: Roberto Polli Owned by:
Priority: normal Milestone:
Component: core Keywords:
Cc: Branch: branches/syslog-levels-7549-2
branch-diff, diff-cov, branch-cov, buildbot
Author: adiroiban

Description

This thread seems to date back to 2009, so I'll retry.

Running an application using logLevel in twistd doesn't preserve logLevels

Reproduce:

  1. run #twistd --syslog ...
  2. wait for an event with logLevel=WARNING

I expect:

  1. the log has syslogSeverity = LOG_WARNING

Instead

  1. the syslogSeverity = DEFAULT == LOG_INFO

This is quite annoying because filtering logs via syslog could lead to losing important log informations.

The following code reproduces the issue. If you're interested in I'll provide a patch.

https://github.com/twisted/twisted/pull/44

Attachments (5)

syslog-loglevels-7549.patch (5.4 KB) - added by Roberto Polli 3 years ago.
logLevel support in t.p.syslog
syslog-loglevels-7549-1.patch​ (5.8 KB) - added by Roberto Polli 3 years ago.
syslog.py and newsfile
syslog-loglevels-7549-2.patch (5.6 KB) - added by Roberto Polli 3 years ago.
Accepted part of the first adiroban review
syslog-loglevels-7549-3.patch (5.7 KB) - added by Roberto Polli 3 years ago.
syslog log level support: added epydoc in test-helper method
syslog-loglevels-7549-4.patch (5.2 KB) - added by Roberto Polli 3 years ago.
Accepted twistedchecker complaints

Download all attachments as: .zip

Change History (34)

comment:1 Changed 3 years ago by Roberto Polli

Ticket #3300 proposed adding

  • priority
  • levels

to t.p.syslog.

It seems that only priorities have been added, but not levels.

comment:2 Changed 3 years ago by Glyph

Keywords: review removed
Owner: set to Roberto Polli

Thank you for your contribution, ioggstream.

Levels have been added. You probably want to have a look at the new twisted.python.logger package that will be in the next release. You might just want to fix this code as-is first though, because that code is not well integrated into the twistd command line yet. (Although if you wanted to fix twistd --syslog to use it, that would be great :-)).

Most importantly though, when I look at https://github.com/twisted/twisted/pull/44/files I see only a single test case, which obviously would not address this issue. Did you mean that PR to point at a different branch?

comment:3 Changed 3 years ago by Roberto Polli

Keywords: review added
Owner: changed from Roberto Polli to Glyph

Hi glyph.

  1. I just added the test-case because I didn't know how you wanted to address this issue, so I avoid polluting the post.
  2. iiuc t.p.logger. doesn't seem to support syslog.
  3. As you suggested I started watching twistd + t.p.logger integration and there's some work to do: is anybody playing on that? Actually twistd doesn't use t.p.logger. and twistd tests doesn't cover very much the logging part.

So, if you agree:

  1. I'll write some twistd + t.p.log tests and wait for your review
  2. Then I'll switch twistd to t.p.logging, eventually modifying t.p.logging
  3. Finally I'll start t.p.logging.syslog tests and wait for your review
  4. At Last twistd+t.p.logging.syslog.

Feedback (or insults ;)) welcome!

Peace, R.

comment:4 Changed 3 years ago by Glyph

Keywords: review removed

Adding the "review" keyword is a workflow indication that you believe the changes should be landed and would like a formal pass at review. If you'd just like some people to look at the code, to see if you're on the right track, the best way to go about that is to raise it as a thread on the mailing list and discuss implementation approaches there. Are you subscribed, and can you post there instead?

Given that we have over 50 tickets in this state I would just like to keep the count down to make sure reviewers don't get burned out looking at a lot of high-level design questions :-).

That test does look like a good place to start. I'm tempted to discuss lots of other logging issues as well, but let's head to the mailing list.

Changed 3 years ago by Roberto Polli

Attachment: syslog-loglevels-7549.patch added

logLevel support in t.p.syslog

comment:5 Changed 3 years ago by Roberto Polli

The attached patch, with the linked rsyslog configuration file allows rsyslog to split twistd logs per-loglevel.

comment:6 Changed 3 years ago by Roberto Polli

Keywords: review added

This patch have been working for a while on v.14.

I just reapplied it on trunk and it's still working...

Let me know

comment:7 Changed 3 years ago by Adi Roiban

Keywords: review removed
Owner: changed from Glyph to Roberto Polli

Hi and thanks for the work on this!

This patch have been working for a while on v.14.

Which patch? I see that last patch is syslog-loglevels-7549.patch​ and was submitted 2 months ago.

Is this the right patch or you forgot to attach a new one?


Patches also need a news file as described here https://twistedmatrix.com/trac/wiki/ReviewProcess#Newsfiles - to be used for the release notes.

In case syslog-loglevels-7549.patch is the right patch, please update it with a newsfile.

Thanks!

Changed 3 years ago by Roberto Polli

syslog.py and newsfile

comment:8 Changed 3 years ago by Roberto Polli

Keywords: review added

Hi adiroiban,

attached syslog-loglevels-7549-1.patch​​ with the newsfile.

Thanks for your support + Peace, R.

comment:9 Changed 3 years ago by Adi Roiban

Keywords: review removed

Hi,

Thanks for the patch.

Please note that this is just a first level review as I am just starting to help with reviews and I am not a senior reviewer.

I might comment stupid things, so if you don't agree with something feel free to ignore and wait for a new review :)


No need to include (#7549) in the news file. It will be automatically generated at release time.

Is this comment needed # Mappings to Python's syslog module ? The variable names are good enough for me and I can see that mapping is to and from Python - Syslog.

Where is fromSyslogLevelMapping used? Why do we need it here?

Do we need toSyslogLevelMapping as public code? I see it is only called from one place. I prefer to start it as private (ie name it _toSyslogLevelMapping) and make it public only if other code from other modules needs it.

# custom priority ovverrides isError it look like this comment is for the wrong block.


I don't know what to say about this code

expected, actual = stdsyslog.LOG_INFO, {'logLevel': 'INVALID'}
self.logLevelHarness(expected, actual)

I prefer

self.logLevelHarness(stdsyslog.LOG_INFO, 'NO-SUCH-LEVEL')

as no unpacking is done ..

but the code is wrong from another reason :)

expected, actual = stdsyslog.LOG_ALERT, {'isError': False,
                                         'logLevel': logging.INFO,
                                         'syslogPriority': stdsyslog.LOG_ALERT}

I have a WTF moment while reading the code. How do you expect the expected to be actual when it is easy to read that they differ?

I think that

def logLevelHarness(self, expected, actual):
    """
    Raises exception if the evaluated syslogPriority
    does not match the expected value.
    """

is in fact

def assertPriorityMapping(self, expected, event):
    """
    Check that when emitted, event is translated into expected syslog level.
    """

Please note that my example docstring is just to state the content. It will need to be formated using epydoc and you need to document the expected / event values.


Duplicate docstrings in tests are for me a code smell that they are testing the same code branch and duplicated tests could be removed or merged into a single test.

We should test that mapping take place not the exact result of each mapping. We have to review to check that mapping is correctly define and test to check that once define, the mapping works.


in logLevelHarness 'message': ('hello,\nworld\n\n',) look like is also testing that each line from the message will emit a dedicated syslog event, but is not reflected in the docstring.

I prefer check this aspect this in a separate test and keep the test focused on a single feature.


I think that current code needs a bit of cleanup before the merge. Please check my comments and resubmitt a new patch.

I will send your latest patch to buildbot so that you can see twistedchecker errors and test results on all builders.

Thanks again for your work on this!

comment:10 Changed 3 years ago by Adi Roiban

Author: adiroiban
Branch: branches/syslog-levels-7549

(In [43909]) Branching to syslog-levels-7549.

comment:11 Changed 3 years ago by Roberto Polli

Replying on point:

  1. comments and private attributes: done
  2. renamed logLevelHarness to assertPriorityMapping and relate variables: done
  3. renamed parameters expected, actual to expected, event: I prefer calling the assertPriorityMapping with variables and I don't think it's worth the time to refactor to call inline
  4. testing the result of the mapping: I wrote the tests before the mapping :DDD In any case I'd prefer to write a single parametric test for that, or - if it's better for you - an iteration with a set of [ (expected, events), ... ]
  5. testing a multiline message in logLevelHarness: I tested the most complex case... in any way there are plenty of test cases with single and multiline tests. If you prefer we can just duplicate the test with a single and a multiline just adding a parameter to logLevelHarness

Let me know:

  • should I refactor the "duplicated" using an iteration?
  • should I replace the multiline message with a single line-one?

Thx again, R.

Changed 3 years ago by Roberto Polli

Accepted part of the first adiroban review

comment:12 Changed 3 years ago by Roberto Polli

Keywords: review added

comment:13 Changed 3 years ago by Adi Roiban

Owner: Roberto Polli deleted

Sorry for being a PITA, but we need to follow the review process.

When asking for a review, be explicit about the branch/diff that needs review

I assume you are asking a review for this diff:

https://github.com/ioggstream/twisted/compare/twisted:trunk...syslog-7549-1

https://github.com/ioggstream/twisted/compare/twisted:trunk...syslog-7549-1.diff

Thanks!

Changed 3 years ago by Roberto Polli

syslog log level support: added epydoc in test-helper method

comment:14 Changed 3 years ago by Roberto Polli

Accepted almost all the adiroiban considerations, and added epydoc to test helper method.

The patch link is the following.

https://twistedmatrix.com/trac/attachment/ticket/7549/syslog-loglevels-7549-3.patch

Thanks again to Adi for the patience ;D

comment:15 Changed 3 years ago by Adi Roiban

Thanks for the patch.

# Mappings from/to Python's syslog module 

as predicted... the comment will get out of sync with the code and you will have a WTF :) ... Mappings from/to ... where is the from part?

I maintain all my previous comments regarding duplicate docstring in tests and the fact that assertPriorityMapping is checking more than the mapping.

Some code is not formatted according to Twisted standard but I don't blame you... we are working to improve the tools.

Docstring should be proper sentences with full stop at the end... again, I don't blame you... we are working at improving the coding/doc standards documents.

I will send the latest patch to the buildbot so that you can see the errors... it would be a good test to see what errors are caught and help improving the automated checkers.

comment:16 Changed 3 years ago by Adi Roiban

Keywords: review removed
Owner: set to Roberto Polli

Only these errors are reported by twistechecker builder

************* Module twisted.python.syslog
W9012: 61,0: Expected 2 blank lines, found 1
W9013:111,0: Expected 3 blank lines, found 2
************* Module twisted.python.test.test_syslog
C0301:244,0: Line too long (87/79)

# Set priority by loglevel and eventually 
#  override it if isError or syslogPriority is defined 

should be

# Set priority by loglevel and eventually 
# override it if isError or syslogPriority is defined.

Docstring should be full sentences with full stop at the end.

ex

Check that when emitted, C{event} is translated into C{expected} syslog priority.

we need green builders before merging this.

Thanks!

Changed 3 years ago by Roberto Polli

Accepted twistedchecker complaints

comment:17 Changed 3 years ago by Roberto Polli

Keywords: review added
Resolution: fixed
Status: newclosed

Accepted twistedchecker complaints.

If there's a link to the full set of complaints let me know.

Thx++Peace, R.

comment:18 Changed 3 years ago by Adi Roiban

Resolution: fixed
Status: closedreopened

I think that this should be still open

comment:19 Changed 3 years ago by Adi Roiban

Branch: branches/syslog-levels-7549branches/syslog-levels-7549-2

(In [44316]) Branching to syslog-levels-7549-2.

comment:20 Changed 3 years ago by Adi Roiban

Owner: Roberto Polli deleted
Status: reopenednew

I have applied the latest patch on a new branch and trigger a buildbot build.

Maybe wsanchez should take a look as he is working on the new logger and could check how these changes integrate with the new logger.

comment:21 Changed 3 years ago by Wilfredo Sánchez Vega

Owner: set to Wilfredo Sánchez Vega
Status: newassigned

comment:22 Changed 3 years ago by Wilfredo Sánchez Vega

As to how this relates to the new logging stuff… my inclination is to say that it does not.

The new logging API does not have syslog support, and we have not removed or even deprecated (yet) the old API, and this is just a fix to the old API, which is fine.

I considered whether we should write syslog support for the new module and maybe t.p.syslog could forward to that, but that's not this ticket, and this ticket should not block on that.

comment:23 Changed 3 years ago by Wilfredo Sánchez Vega

Owner: Wilfredo Sánchez Vega deleted
Status: assignednew

On the branch I see a bunch of code that does this:

  a, b = X, Y.
  foo(a, b)

I don't understand why that is a good idea over:

  foo(X, Y)

or, if the variable names are good for documentation/readability, which seems like the goal:

  a = X
  b = Y
  foo(a, b)

The first form, used in this code, seems at least as undesirable as "multiple imports on one line". So I'm -1 on it, myself.

I see Adi made a similar note above, so I guess if he got around to being OK with it, I don't need to bounce the review. The code otherwise looks sounds.

comment:24 Changed 3 years ago by Wilfredo Sánchez Vega

Keywords: review removed

Actually, Adi doesn't say he's OK with it above, so I'll bouncing the review. Please don't use that style.

Last edited 3 years ago by Wilfredo Sánchez Vega (previous) (diff)

comment:25 Changed 3 years ago by Wilfredo Sánchez Vega

Keywords: review added

r44471 cleans up some stuff my linter was complaining about. r44472 cleans up the above code convention.

Back to review.

comment:26 Changed 3 years ago by Wilfredo Sánchez Vega

kicked builders

comment:27 Changed 3 years ago by Adi Roiban

Keywords: review removed
Owner: set to Wilfredo Sánchez Vega

Thanks for the changes. They are better.

Can you please check these comments:

https://github.com/twisted/twisted/compare/trunk...syslog-levels-7549-2#diff-0e338632fe9220ded8490b78c3c1f849R216

I don't like the fact that they link to a specific 14.0.0 version and not to current... and also I don't like the fact that the docstring is duplicated.

Maybe they can be merged into a single test.

Very minor comments:

There is an extra space here https://github.com/twisted/twisted/compare/trunk...syslog-levels-7549-2#diff-0e338632fe9220ded8490b78c3c1f849R185

Double spaces after comment https://github.com/twisted/twisted/compare/trunk...syslog-levels-7549-2#diff-7a3c226435eda7542f820181838d16feR85

In case the variale name is hard to read maybe we should use a different name rather than putting this comment https://github.com/twisted/twisted/compare/trunk...syslog-levels-7549-2#diff-7a3c226435eda7542f820181838d16feR20

So I think that the branch is good to land.

wsanchez, please take a look and above comment and if nothing is critical please merge.

Thanks!

comment:28 Changed 3 years ago by Wilfredo Sánchez Vega

Owner: Wilfredo Sánchez Vega deleted

Note that the logLevel key in t.p.log's world can contain either a numeric constant (such as logging.DEBUG) or a string (debug).

This code (specifically, _toSyslogLevelMapping) seems to only handle the numeric values. I ran into this in the new logging code. You might want to check out twisted.logger._stdlib.fromStdlibLogLevelMapping, which maps both into it's LogLevel constants, which are similar.

It's also possible to define additional log levels, but I punted on that.

I'm not sure linking to the HOWTO works well at all. Using a current link means that if we make a release and then the current docs change, they might no longer be relevant. Using a 14.0.0 link means you have to update the links in the docs every release. Both kinda suck. I guess I'd pick current between the two, but I'm not convinced the link here is necessary.

I also agree it could be one test, but that's pretty minor, I guess.

ioggstream: I think we should probably fix the _toSyslogLevelMapping. The rest seems optional, but I'd encourage you to remove the HOWTO links at least.

comment:29 Changed 3 years ago by Roberto Polli

Hi W.

  • removed link to documentation
  • added some tests for string logLevel
  • add support for string logLevel

I restarted from your branch to avoid messing with your work: the patch is here. https://github.com/ioggstream/twisted/commit/c9b262a146319fb9279fba8ad492c598f5ee6d9d

Let me know if it works for you.

Note: See TracTickets for help on using tickets.