Skip to content

Conversation

@tynanford
Copy link
Contributor

This addresses #96

I've tried to get twisted logging to use the conf file loglevel but it hasn't been successful. These attempts mostly revolved around adding this logic to application.py

...

class LogLevelFilter(object):
    def __init__(self, level):
        self.level = level

    def __call__(self, event):
        return event if event.get('log_level') >= self.level else None

...

@implementer(service.IServiceMaker, plugin.IPlugin)
class Maker(object):

...

    lvlname = conf.get('loglevel', 'WARN')
    if lvlname == 'DEBUG':
        lvl = LogLevel.debug
    elif lvlname == 'INFO':
        lvl = LogLevel.info
    elif lvlname == 'WARN':
        lvl = LogLevel.warn
    elif lvlname == 'ERROR':
        lvl = LogLevel.error
    elif lvlname == 'CRITICAL':
        lvl = LogLevel.critical
    else:
        print("Invalid loglevel {}. Will default to level WARN".format(lvlname))
        lvl = LogLevel.warn

    globalLogPublisher.addObserver(LogLevelFilter(lvl))
...

It works fine for some log messages but certain log messages like _log.debug('announce to {s}'.format(s=A)) show up in the logs no matter what. So I suggest we revert back to the python logging module unless someone else can figure out the twisted logging since IMO this issue is a blocker to creating a new release.

@tynanford tynanford requested review from jacomago and shroffk November 8, 2024 22:41
@jacomago
Copy link
Contributor

I don't see any info logs with this change :/

Before:

2024-11-14T13:55:06+0000 [recceiver.processors#debug] Available plugin: show
2024-11-14T13:55:06+0000 [recceiver.processors#debug] Available plugin: db
2024-11-14T13:55:06+0000 [recceiver.processors#debug] Available plugin: cf
2024-11-14T13:55:06+0000 [recceiver.cfstore#info] CF_INIT cf
�2024-11-14T13:55:06+0000 [twisted.scripts._twistd_unix.UnixAppLogger#info] twistd 24.10.0 (/home/recceiver/venv/bin/python 3.11.10) starting up.
�2024-11-14T13:55:06+0000 [twisted.scripts._twistd_unix.UnixAppLogger#info] reactor class: twisted.internet.pollreactor.PollReactor.
2024-11-14T13:55:06+0000 [recceiver.application#info] Starting RecService
2024-11-14T13:55:06+0000 [-] CastFactory starting on 40447
�2024-11-14T13:55:06+0000 [recceiver.recast.CastFactory#info] Starting factory <recceiver.recast.CastFactory object at 0xffff8fc66690>
2024-11-14T13:55:06+0000 [-] CastFactory starting on 34243
�2024-11-14T13:55:06+0000 [recceiver.application#info] RecService listening on IPv4Address(type='TCP', host='0.0.0.0', port=34243)
2024-11-14T13:55:06+0000 [-] Announcer starting on 53258
2024-11-14T13:55:06+0000 [-] Starting protocol <recceiver.announce.Announcer object at 0xffff8fe6df90>
2024-11-14T13:55:06+0000 [recceiver.announce#info] Setup Announcer
2024-11-14T13:55:06+0000 [recceiver.cfstore#info] CF_START
2024-11-14T13:55:06+0000 [recceiver.cfstore#debug] Unable to format event {'log_logger': <Logger 'recceiver.cfstore'>, 'log_level': <LogLevel=debug>, 'log_namespace': 'recceiver.cfstore', 'log_source': None, 'log_format': "WHITELIST = {'archive', 'foo', 'bar', 'blah'}", 'log_time': 1731592506.797391}: "'archive', 'foo', 'bar', 'blah'"
2024-11-14T13:55:06+0000 [recceiver.cfstore#info] CF Clean Started
2024-11-14T13:55:06+0000 [recceiver.cfstore#info] CF Clean Completed

After:

recc1 standard logging

�2024-11-14T13:47:54+0000 [twisted.scripts._twistd_unix.UnixAppLogger#info] twistd 24.10.0 (/home/recceiver/venv/bin/python 3.11.10) starting up.
�2024-11-14T13:47:54+0000 [twisted.scripts._twistd_unix.UnixAppLogger#info] reactor class: twisted.internet.pollreactor.PollReactor.
2024-11-14T13:47:54+0000 [-] CastFactory starting on 42431
�2024-11-14T13:47:54+0000 [recceiver.recast.CastFactory#info] Starting factory <recceiver.recast.CastFactory object at 0xffffb2a08750>
2024-11-14T13:47:54+0000 [-] CastFactory starting on 35687
2024-11-14T13:47:54+0000 [-] Announcer starting on 55958
2024-11-14T13:47:54+0000 [-] Starting protocol <recceiver.announce.Announcer object at 0xffffb2a08a90>

@tynanford
Copy link
Contributor Author

Interesting. loglevel=INFO in your "after" logs?

This is when I set loglevel=WARN

2024-11-14T09:07:12-0800 [twisted.scripts._twistd_unix.UnixAppLogger#info] twistd 23.10.0 (/usr/bin/python3 3.12.7) starting up.
2024-11-14T09:07:12-0800 [twisted.scripts._twistd_unix.UnixAppLogger#info] reactor class: twisted.internet.pollreactor.PollReactor.
2024-11-14T09:07:12-0800 [-] CastFactory starting on 45722
2024-11-14T09:07:12-0800 [recceiver.recast.CastFactory#info] Starting factory <recceiver.recast.CastFactory object at 0x7f46c1da1640>
2024-11-14T09:07:12-0800 [-] Announcer starting on 45722
2024-11-14T09:07:12-0800 [-] Starting protocol <recceiver.announce.Announcer object at 0x7f46c19f35c0>

This is when I set loglevel=INFO

2024-11-14T09:07:41-0800 [twisted.scripts._twistd_unix.UnixAppLogger#info] twistd 23.10.0 (/usr/bin/python3 3.12.7) starting up.
2024-11-14T09:07:41-0800 [twisted.scripts._twistd_unix.UnixAppLogger#info] reactor class: twisted.internet.pollreactor.PollReactor.
2024-11-14T09:07:41-0800 [-] INFO:recceiver.application Starting RecService
2024-11-14T09:07:41-0800 [-] CastFactory starting on 45722
2024-11-14T09:07:41-0800 [recceiver.recast.CastFactory#info] Starting factory <recceiver.recast.CastFactory object at 0x7fb294242b70>
2024-11-14T09:07:41-0800 [-] INFO:recceiver.application RecService listening on IPv4Address(type='TCP', host='0.0.0.0', port=45722)
2024-11-14T09:07:41-0800 [-] Announcer starting on 45722
2024-11-14T09:07:41-0800 [-] Starting protocol <recceiver.announce.Announcer object at 0x7fb2942bff50>
2024-11-14T09:07:41-0800 [-] INFO:recceiver.announce Setup Announcer
2024-11-14T09:07:41-0800 [-] INFO:recceiver.cfstore CF_START
2024-11-14T09:07:41-0800 [-] INFO:recceiver.cfstore CF Clean Started
2024-11-14T09:07:41-0800 [-] INFO:recceiver.cfstore CF Clean Completed

@jacomago
Copy link
Contributor

Got it! WARN is default.

continue
pvInfoByName[info["pvName"]] = info
_log.debug("Add record: {rid}: {info}", rid=rid, info=info)
_log.debug("Add record: {rid}: {info}".warning(rid=rid, info=info))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

should be .format not .warning

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah yes, great catch! Fixed

properly escape curly brace in log message

Fix typo for string format call
@sonarqubecloud
Copy link

@shroffk shroffk merged commit 07b3685 into ChannelFinder:master Nov 19, 2024
7 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants