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

Fix statsd Logging in Python 3 #1010

Merged
merged 1 commit into from
Apr 30, 2015
Merged

Conversation

krallin
Copy link
Contributor

@krallin krallin commented Apr 20, 2015

statsd logging appears to be (silently) broken in Python 3, because it passes it passes unicode (i.e. not bytes) to the sock.send method.

This PR:

  • Ensures bytes are used
  • Adds tests that actually go through an actual (UNIX) socket to ensure those errors can be caught in uni testing in the future.
  • Logs statsd errors as warnings (the exceptions being silently swallowed made them difficult to troubleshoot)

@@ -224,8 +224,8 @@ def info(self, msg, *args, **kwargs):
def debug(self, msg, *args, **kwargs):
self.error_log.debug(msg, *args, **kwargs)

def exception(self, msg, *args):
self.error_log.exception(msg, *args)
def exception(self, msg, *args, **kwargs):
Copy link
Collaborator

Choose a reason for hiding this comment

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

Good catch!

@krallin
Copy link
Contributor Author

krallin commented Apr 21, 2015

@berkerpeksag ,

Fixed the two issues you pointed out. Note that if server.bind(sock_file) or client.connect(sock_file) fail, the tests might end up closing a socket that was never open, but that shouldn't raise an exception anyway.

Cheers,

@berkerpeksag
Copy link
Collaborator

LGTM (thanks for squashing commits by the way!).

My only question is that if we test the statsd logging against a real socket, shouldn't we use a different class since the class' name is "MockSocket"? In theory, we should be able to test whether the input is str or not by tweaking the MockSocket.send() method (without creating a real socket).

Ping @benoitc @tilgovi.

@krallin
Copy link
Contributor Author

krallin commented Apr 21, 2015

@berkerpeksag

The idea behind using an actual socket is to catch similar errors in unit tests in the future (if they can even exist).

This time, it was a text vs bytes issue, but maybe another issue will crop up some day (I have no idea what that issue might be, but after all that's why we write tests!).

I'm fine with renaming the class, though — let me know!

Cheers,

try:
if isinstance(msg, six.text_type):
msg = msg.encode("ascii")
Copy link
Owner

Choose a reason for hiding this comment

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

why not reusing the bytes_to_str function from the _compat module instead?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@benoitc

I think we'd need str_to_bytes instead, wouldn't we?

Looking at the definition for bytes_to_str, I'm a bit unclear on what it's supposed to returns. It looks like it gives you bytes on Py2 and text Py3? I'm probably misreading though.

Cheers,

Copy link
Owner

Choose a reason for hiding this comment

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

mmm you're right should probably be the reverse in your case. anyway could be useful to have it in a _compat module, so we don't have to do such things on python 2.x. thoughts?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Makes sense. Can you just confirm what those methods should return to clear up the confusion above?

Copy link
Collaborator

Choose a reason for hiding this comment

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

If we are going to add a function like this, we need to make it more general(e.g. you can pass different encodings and error handlers). util.to_bytestring is another alternative, but it uses the UTF-8 encoding by default. I'd say merge this now and create a new issue or PR to discuss details.

Copy link
Owner

Choose a reason for hiding this comment

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

+1 let's merge now and handle the rest separately.
On Thu 30 Apr 2015 at 12:44 Berker Peksag [email protected] wrote:

In gunicorn/instrument/statsd.py
#1010 (comment):

     try:
  •        if isinstance(msg, six.text_type):
    
  •            msg = msg.encode("ascii")
    

If we are going to add a function like this, we need to make it more
general(e.g. you can pass different encodings and error handlers).
util.to_bytestring is another alternative, but it uses the UTF-8 encoding
by default. I'd say merge this now and create a new issue or PR to discuss
details.


Reply to this email directly or view it on GitHub
https://github.com/benoitc/gunicorn/pull/1010/files#r29419336.

@krallin
Copy link
Contributor Author

krallin commented Apr 30, 2015

Do you guys need me to rebase or squash further or anything? Just let me know : )

@berkerpeksag
Copy link
Collaborator

@krallin if you have time, please squash the commits. If not, I can do it today :) Thanks!

Bytes must be passed to socket.send.

Update tests to ensure an actual socket is used, so that errors like
this can be caught in unit tests in the future.
@krallin
Copy link
Contributor Author

krallin commented Apr 30, 2015

@berkerpeksag Sure — done

berkerpeksag added a commit that referenced this pull request Apr 30, 2015
Fix statsd Logging in Python 3
@berkerpeksag berkerpeksag merged commit a7354cf into benoitc:master Apr 30, 2015
@berkerpeksag
Copy link
Collaborator

Thanks!

@krallin krallin deleted the fix-statsd-py3 branch May 1, 2015 13:10
@urbaniak urbaniak mentioned this pull request Jun 29, 2015
wking added a commit to wking/gunicorn that referenced this pull request Nov 3, 2017
The argument is documented in [1], and we've been using it in some
cases since 410bcfa (Fix statsd logging to work on Python 3,
2015-04-20, benoitc#1010).  This commit goes through all of our log calls and
makes sure we're using it consistently.

For more examples of using exc_info instead of direct traceback calls,
see 0acfb55 (Let logging module handle traceback printing,
2016-02-05, benoitc#1201).  The traceback call I'm removing snuck in later
with f4842a5 (Log exception occurring during worker exit, 2016-05-04,
benoitc#1254).

I'm removing the "Error processing SSL request" debug messages,
because those will be handled by the subsequent handle_error call.
We've had them, for reasons that I'm not clear on, since 1198cc2
(handle ssl connections, 2012-12-14).

I've restored logging in the URI-less Worker.handle_error 500 case,
since that was broken in 79011d0 (Include request URL in error
message, 2015-07-08, benoitc#1071) but not restored in 1ccebab (prevent
crash when reporting an error, 2016-03-22, benoitc#1231).

[1]: https://docs.python.org/2/library/logging.html#logging.Logger.debug
wking added a commit to wking/gunicorn that referenced this pull request Nov 3, 2017
The argument is documented in [1], and we've been using it in some
cases since 410bcfa (Fix statsd logging to work on Python 3,
2015-04-20, benoitc#1010).  This commit goes through all of our log calls and
makes sure we're using it consistently.

For more examples of using exc_info instead of direct traceback calls,
see 0acfb55 (Let logging module handle traceback printing,
2016-02-05, benoitc#1201).  The traceback call I'm removing snuck in later
with f4842a5 (Log exception occurring during worker exit, 2016-05-04,
benoitc#1254).

I'm removing the "Error processing SSL request" debug messages,
because those will be handled by the subsequent handle_error call.
We've had them, for reasons that I'm not clear on, since 1198cc2
(handle ssl connections, 2012-12-14).

I've restored logging in the URI-less Worker.handle_error 500 case,
since that was broken in 79011d0 (Include request URL in error
message, 2015-07-08, benoitc#1071) but not restored in 1ccebab (prevent
crash when reporting an error, 2016-03-22, benoitc#1231).

Tests for the lines I've touched may be more trouble than they're
worth.  I've worked up one for a broken worker_exit hook to show what
they look like, but left the others untested for now.

[1]: https://docs.python.org/2/library/logging.html#logging.Logger.debug
wking added a commit to wking/gunicorn that referenced this pull request Nov 3, 2017
The argument is documented in [1], and we've been using it in some
cases since 410bcfa (Fix statsd logging to work on Python 3,
2015-04-20, benoitc#1010).  This commit goes through all of our log calls and
makes sure we're using it consistently.

For more examples of using exc_info instead of direct traceback calls,
see 0acfb55 (Let logging module handle traceback printing,
2016-02-05, benoitc#1201).  The traceback call I'm removing snuck in later
with f4842a5 (Log exception occurring during worker exit, 2016-05-04,
benoitc#1254).

I'm removing the "Error processing SSL request" debug messages,
because those will be handled by the subsequent handle_error call.
We've had them, for reasons that I'm not clear on, since 1198cc2
(handle ssl connections, 2012-12-14).

I've restored logging in the URI-less Worker.handle_error 500 case,
since that was broken in 79011d0 (Include request URL in error
message, 2015-07-08, benoitc#1071) but not restored in 1ccebab (prevent
crash when reporting an error, 2016-03-22, benoitc#1231).

Tests for the lines I've touched may be more trouble than they're
worth.  I've worked up one for a broken worker_exit hook to show what
they look like, but left the others untested for now.

[1]: https://docs.python.org/2/library/logging.html#logging.Logger.debug
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