Channels: runserver should log to "django.channels.server" instead of stderr

[robdoesstuff]

Django v1.10 switched to using "django.server" as the logger for runserver. My console is being spammed with stderr messages that I can't configure in development when using channels, and it's very difficult to see what I want to see, which is not the 200 requests. If you would please, follow suit with Django and set up a logger using "django.channels.server" and change the runserver stderr logging to use that logger instead. Even if it doesn't follow the 200 = INFO, 400+ = ERROR paradigm, it would be nice to be able to shut that off so I can see what I'm looking for in other dev logs.

[andrewgodwin]

The runserver command doesn't use the logging framework for the access log right now, so we also need to switch it over to that, and work out what category the WebSocket access messages fall into.

[robdoesstuff]

That would be super awesome. I'd be happy to create a PR for the changes if you can let me know a decision on what the category you want is.

[andrewgodwin]

I'd say put everything but disconnect into INFO, and disconnects as WARNING. That seems like the most reasonable mapping - you can see all the code in channels' runserver.py if you want to judge for yourself though, I'm open to ideas.

[approxit]

Same problem here!

Making disconnect as WARNING would be a little tricky with tools like Sentry. It would require a little work with filtering unneeded warning log entry. It's not actually django-like too. Django uses WARNING to log 4xx errors. Errors. WebSocket disconnect does not look like an error.

But actually WebSocket could log as default runserver. With ability to filter logs by it's channel type would do the job.

For example:

# part of django LOGGING dictionary
'filters': {
    'http_only': {
        '()': 'channels.logging.ChannelTypeFilter',
        'channel_type': 'http',
    },
    'ws_only': {
        '()': 'channels.logging.ChannelTypeFilter',
        'channel_type': 'ws',
    },
    'custom_only': {
        '()': 'channels.logging.ChannelTypeFilter',
        'channel_type': ['ws', 'custom'],
    }
},

[renatooliveira]

Hey, I started working on this.
Already replaced stderr with logging here

I think the next step here would be changing channels/logs.py to extend Django's default logging config. Am I going in the right way?

Thanks

[andrewgodwin]

Yes, that should be enough to get it displaying.

[renatooliveira]

@andrewgodwin what I'm trying to do right now is to update the DEFAULT_LOGGING with django channels logging configuration.

something like this:

def setup_logger(name, verbosity=1):
     """
     Basic logger for runserver etc.
     """

-    formatter = logging.Formatter(
-        fmt='%(asctime)s - %(levelname)s - %(module)s - %(message)s')
-
-    handler.setFormatter(formatter)
-
-    # Set up main logger
-    logger = logging.getLogger(name)
-    logger.setLevel(logging.INFO)
-    logger.addHandler(handler)
-    if verbosity > 1:
-        logger.setLevel(logging.DEBUG)
+    DEFAULT_LOGGING['formatters'].update({
+        'django.channels.server': {
+            '()': 'django.utils.log.ServerFormatter',
+            'format': '%(asctime)s - %(levelname)s - %(module)s - %(message)s',
+        }
+    })
+
+    DEFAULT_LOGGING['handlers'].update({
+        'django.channels.server': {
+            'level': 'INFO',
+            'class': 'logging.StreamHandler',
+            'formatter': 'django.channels.server',
+        }
+    })
+
+    DEFAULT_LOGGING['loggers'].update({
+        'django.channels.server': {
+            'handlers': ['django.channels.server'],
+            'level': 'INFO',
+            'propagate': False,
+        },
+    })

But I still couldn't think in a way to not repeat code from django.utils.log, any ideas here?

[andrewgodwin]

You probably will have to duplicate code, I don't know if overriding DEFAULT_LOGGING is going to work?

[renatooliveira]

No, it didn't work. I copied it instead, but I'm still having problems because it isn't recognizing django.utils.log as a package.

I'm going to take a deeper look into this, posting just to give a feedback.

Sorry about the delay on this.

[decentral1se]

@renatooliveira, any updates? Thanks so far :+1:

[renatooliveira]

hey @lwm, I've been struggling on how to make the DEFAULT_LOGGING dict compatible with all django versions, since formatters were just added on 1.10 I think. Was supposed to ask that here but procrastination and conference travels postponed that.

I'm really sorry about the delay, I'm planning to finish this issue this week

[torchingloom]

I waiting this fix very much ))
Thank you for your commits

[hzbd]

any update?

[andrewgodwin]

If there was an update it would be here. This won't get fixed unless someone works on it as it's low priority.

[Sgiath]

@andrewgodwin I created PR which fixes it ^^