Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

logging.config.dictConfig with file handler leaks resources #78159

Closed
maggyero mannequin opened this issue Jun 27, 2018 · 8 comments
Closed

logging.config.dictConfig with file handler leaks resources #78159

maggyero mannequin opened this issue Jun 27, 2018 · 8 comments
Labels
performance Performance or resource usage stdlib Python modules in the Lib dir

Comments

@maggyero
Copy link
Mannequin

maggyero mannequin commented Jun 27, 2018

BPO 33978
Nosy @vsajip, @maggyero, @tirkarthi
PRs
  • bpo-33978: close resources before deletion of logging handlers #8008
  • [3.7] bpo-33978: Close existing handlers before logging (re-)configuration. (GH-8008) #8044
  • [3.6] bpo-33978: Close existing handlers before logging (re-)configuration. (GH-8008) #8045
  • Files
  • 33978.patch
  • Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.

    Show more details

    GitHub fields:

    assignee = None
    closed_at = <Date 2018-07-02.09:36:28.065>
    created_at = <Date 2018-06-27.09:29:16.048>
    labels = ['library', 'performance']
    title = 'logging.config.dictConfig with file handler leaks resources'
    updated_at = <Date 2018-07-02.11:36:33.218>
    user = 'https://github.com/maggyero'

    bugs.python.org fields:

    activity = <Date 2018-07-02.11:36:33.218>
    actor = 'maggyero'
    assignee = 'none'
    closed = True
    closed_date = <Date 2018-07-02.09:36:28.065>
    closer = 'vinay.sajip'
    components = ['Library (Lib)']
    creation = <Date 2018-06-27.09:29:16.048>
    creator = 'maggyero'
    dependencies = []
    files = ['47656']
    hgrepos = []
    issue_num = 33978
    keywords = ['patch']
    message_count = 8.0
    messages = ['320560', '320652', '320653', '320856', '320859', '320860', '320861', '320873']
    nosy_count = 3.0
    nosy_names = ['vinay.sajip', 'maggyero', 'xtreak']
    pr_nums = ['8008', '8044', '8045']
    priority = 'normal'
    resolution = 'fixed'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = 'resource usage'
    url = 'https://bugs.python.org/issue33978'
    versions = ['Python 3.6']

    @maggyero
    Copy link
    Mannequin Author

    maggyero mannequin commented Jun 27, 2018

    Calling logging.config.dictConfig several times with a file handler in the same Python process leaks resources.

    INPUT:

    $ python3 -Wall <<EOF
    import logging.config
    config = {
        "version": 1,
        "handlers": {
            "file": {
                "class": "logging.FileHandler",
                "filename": "test.log"
            }
        },
        "root": {
            "handlers": ["file"]
        }
    }
    logging.config.dictConfig(config)
    logging.config.dictConfig(config)
    EOF

    OUTPUT:

    /usr/lib/python3.6/logging/config.py:789: ResourceWarning: unclosed file <_io.TextIOWrapper name='/home/maggyero/test.log' mode='a' encoding='UTF-8'>
    self.common_logger_config(root, config, incremental)

    @maggyero maggyero mannequin added stdlib Python modules in the Lib dir performance Performance or resource usage labels Jun 27, 2018
    @tirkarthi
    Copy link
    Member

    I think while initializing it on the second call we just delete the handlers list variable which contains references to the file handlers instead of properly closing them like it's done in shutdown. handlers is a list of weakreferences and I don't know if they will close file handlers or other resources automatically as they are deleted. If the initialization is done in a loop involving threads then there might be others who are using the handlers as we delete them. The attached patch tries to close the handlers before deletion thus removing the warning. The same is observed in FileConfig too where handlers list is deleted before removal.

    shutdown method : https://github.com/python/cpython/blob/master/Lib/logging/__init__.py#L1994
    deletion of handlers before closing them : https://github.com/python/cpython/blob/master/Lib/logging/config.py#L528

    I think this is merged from Python 2.7 with commit 00ee7ba 12 years back but doesn't produce any effect on Python 2.7 does -W all or -Wall have any effect ?

    Thanks

    @tirkarthi
    Copy link
    Member

    This seems to be a related issue https://bugs.python.org/issue23010 and fix attached but I think it's more towards file handler to be not opened until it's required.

    Thanks

    @vsajip
    Copy link
    Member

    vsajip commented Jul 2, 2018

    New changeset 087570a by Vinay Sajip (Xtreak) in branch 'master':
    bpo-33978: Close existing handlers before logging (re-)configuration. (GH-8008)
    087570a

    @vsajip
    Copy link
    Member

    vsajip commented Jul 2, 2018

    New changeset 6f49afc by Vinay Sajip (Miss Islington (bot)) in branch '3.7':
    bpo-33978: Close existing handlers before logging (re-)configuration. (GH-8008) (GH-8044)
    6f49afc

    @vsajip
    Copy link
    Member

    vsajip commented Jul 2, 2018

    New changeset b6c1989 by Vinay Sajip (Xtreak) in branch '3.6':
    [3.6] bpo-33978: Close existing handlers before logging (re-)configuration. (GH-8008). (GH-8045)
    b6c1989

    @vsajip vsajip added 3.7 (EOL) end of life 3.8 only security fixes labels Jul 2, 2018
    @vsajip vsajip closed this as completed Jul 2, 2018
    @tirkarthi
    Copy link
    Member

    Thanks much @maggyero for the original report and sample test case this was my first non-easy bug fix. Thanks @vinay.sajip for the guidance on logging module implementation.

    Thanks

    @tirkarthi tirkarthi removed 3.7 (EOL) end of life 3.8 only security fixes labels Jul 2, 2018
    @maggyero
    Copy link
    Mannequin Author

    maggyero mannequin commented Jul 2, 2018

    Thanks @XTreak and @vinay.sajip for the fix.

    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    performance Performance or resource usage stdlib Python modules in the Lib dir
    Projects
    None yet
    Development

    No branches or pull requests

    2 participants