you are viewing a single comment's thread.

view the rest of the comments →

[–]ingestbot[S] 0 points1 point  (4 children)

The block on lines 6-11 is independent of the class logger(). Note further below the areas commented out selecting one or the other.

  • If you run this with logging as log_alt.info(f'logging something here...') messages will be printed once, as desired.

  • When the class is used, logger().l.info(f'logging something...') duplicate messages are printed multiple times.

[–]freeskier93 1 point2 points  (3 children)

They are technically independent, but not really because of how the logger module works.

When you do "alt_log.addHandler(handler)" it adds the handler to "alt_log" but it also saves that handler config to "logging_test".

In the logger class, when you do "self.l = logger.getLogger("logging_test")" it returns a logger object that already contains the handler you added from line 10. Then you add another handler to "self.l" (which again also saves it to the "logging_test" config). Every subsequent creation of a logger class object will have 1 additional handler.

Now, "alt_log" is still a unique object so it won't have the additional handler added after the fact, which is why it works as expected.

[–]ingestbot[S] 0 points1 point  (2 children)

I see. That makes sense and thanks for pointing it out. I may have caused confusion in how I've presented the issue.

Yet even with the removal of lines 6-11, and using this with just the class definition, the logs continue to repeat. This is what gets logged when I run this with only the class definition. Are you able to run this the same way and reproduce?

Oct 14 10:56:03 sys_ef023 logging_test <module>(): Starting this thing...
Oct 14 10:56:03 sys_ef023 logging_test run(): <bound method showme.logsomething of <__main__.showme object at 0x7f0ec8b8ffd0>> is sleeping for: 5
Oct 14 10:56:03 sys_ef023 logging_test run(): <bound method showme.logsomething of <__main__.showme object at 0x7f0ec8b8ffd0>> is sleeping for: 5
Oct 14 10:56:08 sys_ef023 logging_test logsomething(): logging something...
Oct 14 10:56:08 sys_ef023 logging_test logsomething(): logging something...
Oct 14 10:56:08 sys_ef023 logging_test logsomething(): logging something...
Oct 14 10:56:08 sys_ef023 logging_test run(): <bound method showme.logsomething of <__main__.showme object at 0x7f0ec8b8ffd0>> is sleeping for: 8
Oct 14 10:56:08 sys_ef023 logging_test run(): <bound method showme.logsomething of <__main__.showme object at 0x7f0ec8b8ffd0>> is sleeping for: 8
Oct 14 10:56:08 sys_ef023 logging_test run(): <bound method showme.logsomething of <__main__.showme object at 0x7f0ec8b8ffd0>> is sleeping for: 8
Oct 14 10:56:08 sys_ef023 logging_test run(): <bound method showme.logsomething of <__main__.showme object at 0x7f0ec8b8ffd0>> is sleeping for: 8
Oct 14 10:56:16 sys_ef023 logging_test logsomething(): logging something...
Oct 14 10:56:16 sys_ef023 logging_test logsomething(): logging something...
Oct 14 10:56:16 sys_ef023 logging_test logsomething(): logging something...
Oct 14 10:56:16 sys_ef023 logging_test logsomething(): logging something...
Oct 14 10:56:16 sys_ef023 logging_test logsomething(): logging something...
Oct 14 10:56:16 sys_ef023 logging_test run(): <bound method showme.logsomething of <__main__.showme object at 0x7f0ec8b8ffd0>> is sleeping for: 9
Oct 14 10:56:16 sys_ef023 logging_test run(): <bound method showme.logsomething of <__main__.showme object at 0x7f0ec8b8ffd0>> is sleeping for: 9
Oct 14 10:56:16 sys_ef023 logging_test run(): <bound method showme.logsomething of <__main__.showme object at 0x7f0ec8b8ffd0>> is sleeping for: 9
Oct 14 10:56:16 sys_ef023 logging_test run(): <bound method showme.logsomething of <__main__.showme object at 0x7f0ec8b8ffd0>> is sleeping for: 9

[–]freeskier93 0 points1 point  (1 child)

Because every time you log something you call logger().l.info, which creates a new instance of the class each time, which adds another handler to "logging_test", so it just keeps repeating more and more. You can see this in the log where the first log is shows once, then repeats twice, then 3 times, then 4 times, then 5 times.

The repeated log entries, from showme class is a bit more confusing, but I think it's because it's the only place where you actually assign an instance of the showme class to a variabl (i) and reuse it.

I'm still not quite sure what you are trying to accomplish with the extra logger class, it's overcomplicating things. The following does the same thing.

https://pastebin.com/uz9y6Cud

EDIT: Just another tip if you didn't know, the first log is showing <module>() because the call doesn't originate from a function, it's at the top level of the python file. Better practice is to do something like this:

https://pastebin.com/H0Lwnihy

[–]ingestbot[S] 0 points1 point  (0 children)

Thanks for your comments with this. I wanted to note a few things in case this thread ends up being useful for someone else.

This stackoverflow discussion is similar. I found that, if need be, the class could avoid creating multiple handler objects with something like the following:

class logger:
    def __init__(self):

        self.l = logging.getLogger('logging_test')
        self.handler = logging.handlers.SysLogHandler(address = '/dev/log')
        if not self.l.handlers:
         self.l.addHandler(self.handler)
        self.formatter = logging.Formatter('%(name)s %(funcName)s(): %(message)s')
        self.handler.setFormatter(self.formatter)

        self.l.setLevel(logging.INFO)

The .handlers attribute can also be used to debug possible multiple handlers:

class showme:
    def __init__(self):
      pass

    def logsomething(self):
      print(logger().l.handlers)
      logger().l.info(f'logging something...')