# Logging does not work as expected

**URL:** <https://forum.djangoproject.com/t/logging-does-not-work-as-expected/30479>\
**Category:** Forms & APIs\
**Created:** [April 23, 2024, 9:06pm UTC](https://forum.djangoproject.com/t/logging-does-not-work-as-expected/30479 "2024-04-23T21:06:07Z")\
**Posts on this page:** 9\
**Page:** 1

<div class="post-metadata">

**Author:** ![doom](https://avatars.discourse-cdn.com/v4/letter/d/a587f6/32.png) [@doom](https://forum.djangoproject.com/u/doom)\
**Post date:** [April 23, 2024, 9:06pm UTC](https://forum.djangoproject.com/t/logging-does-not-work-as-expected/30479/1 "2024-04-23T21:06:08Z")

</div>

Hi,

I’m trying to understand logging. I’m following [How to configure and use logging | Django documentation | Django](https://docs.djangoproject.com/en/5.0/howto/logging/#create-a-logging-dictionary) and it shows there how to configure a logger that logs everything (logger `""`) to a file.

I tried that and added the setting below to my settings.py, which made me notice some unexpected behaviour.

```auto
LOGGING = {
    "version": 1, # the dictConfig format version
    "disable_existing_loggers": False, # retain the default loggers
    "formatters": {
        "verbose": {
            "format": "{asctime} {levelname:<8} {module:<12} | {message}",
            "style": "{",
        },
        "simple": {
            "format": "{levelname} {message}",
            "style": "{",
        },
    },
    "handlers": {
        "file": {
            "class": "logging.FileHandler",
            "filename": "general.log",
            "formatter": "verbose",
        },
    },
    "loggers": {
        "": {
            "handlers": ["file"],
            "level": "DEBUG",
        },
    },
}

```

In my view I am logging the following.

```auto
import logging
logger = logging.getLogger( __name__ )
logger.debug("MY LOGGER: DEBUG")
logger.info("MY LOGGER: INFO")
logger.warning("MY LOGGER: WARNING")
logger.error("MY LOGGER: ERROR")
logger.critical("MY LOGGER: CRITICAL")

```

* * *

**Without** the setting, the following gets logged:

**Console**

```auto
MY LOGGER: WARNING
MY LOGGER: ERROR
MY LOGGER: CRITICAL
[23/Apr/2024 22:57:17] "GET / HTTP/1.1" 200 9515

```

**general.log**

```auto

```

* * *

But **with the setting** , the following gets logged:

**Console**

```auto
[23/Apr/2024 22:58:43] "GET / HTTP/1.1" 200 9515

```

**general.log**

```auto
2024-04-23 22:58:43,653 DEBUG views | MY LOGGER: DEBUG
2024-04-23 22:58:43,653 INFO views | MY LOGGER: INFO
2024-04-23 22:58:43,653 WARNING views | MY LOGGER: WARNING
2024-04-23 22:58:43,653 ERROR views | MY LOGGER: ERROR
2024-04-23 22:58:43,653 CRITICAL views | MY LOGGER: CRITICAL

```

* * *

Now my understanding is that the setting I added is _additive_. The docs state that _“a logger can forward messages to multiple handlers, so the relation between loggers and handlers is many-to-many.”_ And the logger name does not override an existing named logger, such as `django.server`.

So why does my setting remove the logs from the console logger? I was expecting my five test log messages to appear in both, the console and the file.

---

<div class="post-metadata">

**Author:** ![leandrodesouzadev](https://sea2.discourse-cdn.com/flex026/user_avatar/forum.djangoproject.com/leandrodesouzadev/32/8981_2.png) [@leandrodesouzadev](https://forum.djangoproject.com/u/leandrodesouzadev)\
**Post date:** [April 24, 2024, 11:37am UTC](https://forum.djangoproject.com/t/logging-does-not-work-as-expected/30479/2 "2024-04-24T11:37:30Z")

</div>

Maybe try to set `propagate` on your `""` logger.

```python
"loggers": {
        "": {
            "handlers": ["file"],
            "level": "DEBUG",
            "propagate": True,
        },
    },

```

Also, there’s this excellent [video by mCoding about setting up logging](https://youtu.be/9L77QExPmI0?si=puEL3w_s43T-73N_), this video helped me a lot to better understand the inner behavior of the python’s logging module.

---

<div class="post-metadata">

**Author:** ![doom](https://avatars.discourse-cdn.com/v4/letter/d/a587f6/32.png) [@doom](https://forum.djangoproject.com/u/doom)\
**Post date:** [April 24, 2024, 4:00pm UTC](https://forum.djangoproject.com/t/logging-does-not-work-as-expected/30479/3 "2024-04-24T16:00:33Z")

</div>

Thanks for the suggestion. The video does not reveal any new information, that was not discussed in the docs.

The propagation does not change anything, and why would it? It’s a top-level logger. A message cannot be propagated any higher than “”.

---

<div class="post-metadata">

**Author:** ![KenWhitesell](https://sea2.discourse-cdn.com/flex026/user_avatar/forum.djangoproject.com/kenwhitesell/32/280_2.png) [@KenWhitesell](https://forum.djangoproject.com/u/KenWhitesell)\
**Post date:** [April 24, 2024, 8:31pm UTC](https://forum.djangoproject.com/t/logging-does-not-work-as-expected/30479/4 "2024-04-24T20:31:06Z")

</div>

What logger are you testing? (What’s the ` __name__ ` being used in your tests?)

The only loggers defined by name by default are for “django” and “django.server”. If ` __name__ ` is not either of those, then it would be logged using the implicit `""` default - and _that’s_ what you’re overriding with your configuration.

---

<div class="post-metadata">

**Author:** ![doom](https://avatars.discourse-cdn.com/v4/letter/d/a587f6/32.png) [@doom](https://forum.djangoproject.com/u/doom)\
**Post date:** [April 29, 2024, 7:41pm UTC](https://forum.djangoproject.com/t/logging-does-not-work-as-expected/30479/5 "2024-04-29T19:41:27Z")

</div>

> [@KenWhitesell](#):
>
> and _that’s_ what you’re overriding with your configuration.

` __name__ ` is `myapp.views`. Your note about the name helps. What I don’t get is the sentence I quoted. The default [logging definition](https://docs.djangoproject.com/en/5.0/ref/logging/#default-logging-definition) does not have a logger `""` configured, so there’s nothing there that I could override.

---

<div class="post-metadata">

**Author:** ![KenWhitesell](https://sea2.discourse-cdn.com/flex026/user_avatar/forum.djangoproject.com/kenwhitesell/32/280_2.png) [@KenWhitesell](https://forum.djangoproject.com/u/KenWhitesell)\
**Post date:** [April 29, 2024, 10:43pm UTC](https://forum.djangoproject.com/t/logging-does-not-work-as-expected/30479/6 "2024-04-29T22:43:44Z")

</div>

It doesn’t need to be defined. It’s the implict default (root) used in the absence of an explicit logger being referenced.

If you use the logging facility without providing _any_ definitions, you will still get logs, regardless of the name being used.

As you note, the DEFAULT\_LOGGING only defines loggers for `"django"` and `"django.server"`. If there wasn’t an implicit default, then those would be the only names causing logs to be written.

So by adding the null string key, “”, you’re overriding the default root.

Note: You’ll see the docs referencing a top-level key named “root”. It is an effective synonym to the blank key in the “loggers” dict.

---

<div class="post-metadata">

**Author:** ![doom](https://avatars.discourse-cdn.com/v4/letter/d/a587f6/32.png) [@doom](https://forum.djangoproject.com/u/doom)\
**Post date:** [April 30, 2024, 6:45am UTC](https://forum.djangoproject.com/t/logging-does-not-work-as-expected/30479/7 "2024-04-30T06:45:38Z")

</div>

Well, it _should_ be defined! There is a default config showing me what is configured by default. Why is the root logger and it’s configuration not included in there? How is it better to have it implicit instead of explicit? How am I supposed to know that I am overwriting something, if nothing - not even the docs tells me this?

And nowhere is written that the unnamed logger “” is the same as “root” (which is on the same level as “loggers”). That’s not only very confusing,but also in transparent. I also find that atypical on how loggers are defined.

Thanks, Ken. I may raise an issue in the Bug tracker about this.

---

<div class="post-metadata">

**Author:** ![KenWhitesell](https://sea2.discourse-cdn.com/flex026/user_avatar/forum.djangoproject.com/kenwhitesell/32/280_2.png) [@KenWhitesell](https://forum.djangoproject.com/u/KenWhitesell)\
**Post date:** [April 30, 2024, 11:34am UTC](https://forum.djangoproject.com/t/logging-does-not-work-as-expected/30479/8 "2024-04-30T11:34:14Z")

</div>

> [@doom](#):
>
> Why is the root logger and it’s configuration not included in there?

Because it’s part of the underlying Python logging module. Quoting directly from [Logging | Django documentation | Django](https://docs.djangoproject.com/en/5.0/topics/logging/)

> Django uses and extends Python’s builtin [`logging`](https://docs.python.org/3/library/logging.html#module-logging) module to perform system logging. This module is discussed in detail in Python’s own documentation; this section provides a quick overview.

The LOGGING configuration is passed directly to the Python logging module. All the implications of how things are used is based solely on it.

Having said that, I definitely agree that the Python docs for this could be made more clear. I definitely get the impression that not only is the Python logger “styled” in a manner similar to Java’s `log4j`, but it also presumes some knowledge of it

---

<div class="post-metadata">

**Author:** ![doom](https://avatars.discourse-cdn.com/v4/letter/d/a587f6/32.png) [@doom](https://forum.djangoproject.com/u/doom)\
**Post date:** [May 6, 2024, 4:28pm UTC](https://forum.djangoproject.com/t/logging-does-not-work-as-expected/30479/9 "2024-05-06T16:28:10Z")

</div>

> [@KenWhitesell](#):
>
> The LOGGING configuration is passed directly to the Python logging module. All the implications of how things are used is based solely on it.

Hmm, got it. I didn’t grasp the importance of that statement. It sounded more like a deep-dive, that would not be important to know for basic logging setups. I guess it is…

Will look at this when I have time, but thanks already for making that clear.