Issue 11907: SysLogHandler can't send long messages (original) (raw)

Created on 2011-04-22 13:52 by lukas.lalinsky, last changed 2022-04-11 14:57 by admin. This issue is now closed.

Messages (14)
msg134265 - (view) Author: Lukáš Lalinský (lukas.lalinsky) Date: 2011-04-22 13:52
It seems that logging.handlers.SysLogHandler can't handle messages that can't be passed atomically via the socket. I'm not sure what is the right behavior (the syslog() function truncates the message), but I think it shouldn't propagate the exception to the application. Python 2.7.1 (r271:86832, Apr 18 2011, 08:47:29) [GCC 4.2.1 20070719 [FreeBSD]] on freebsd8 Type "help", "copyright", "credits" or "license" for more information. >>> import logging.handlers >>> handler = logging.handlers.SysLogHandler('/dev/log') >>> logger = logging.getLogger() >>> logger.addHandler(handler) >>> logger.warn('x' * 4096) Traceback (most recent call last): File "/usr/local/lib/python2.7/logging/handlers.py", line 808, in emit self.socket.send(msg) error: [Errno 40] Message too long Logged from file , line 1
msg134298 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2011-04-23 10:24
The entire part of emit() which sends to the socket is wrapped in an except: which should catch all except KeyboardInterrupt and SystemExit. The except clause calls the handleError method of the handler. See http://hg.python.org/cpython/file/fa277cbd66bb/Lib/logging/handlers.py#l804 So I can't see exactly what's happening, and moreover I can't reproduce this on Linux even when sending messages of > 16384 on the Unix socket. I don't have access to a FreeBSD system. Can you do a little more investigation, since I'm not sure what your source says? (The line nos. don't seem to match up exactly - in Mercurial, line 808 is an except socket.error clause).
msg134312 - (view) Author: Lukáš Lalinský (lukas.lalinsky) Date: 2011-04-23 18:24
It seems that I was wrong, the exception is indeed not propagated to the application, but handled by the handleError() method. I was confused by seeing the traceback in my uWSGI log file. I'm unable to find a way to determine the maximum allowed syslog message size, otherwise the proper behavior would be probably to truncate the message. Specifically on FreeBSD, the clib source code seems to be using a buffer with 2048 bytes for the whole syslog line and 1024 bytes for the message formatting, so they are just arbitrary numbers. :( There probably isn't a way to solve this cleanly. Truncating the message would be much preferable to dropping it, but I really don't know what would be the right size. I'll write a LocalSysLogHandler for me that uses the syslog module. Regarding the line numbers, this is the version corresponding to the 2.7.1 release - http://hg.python.org/cpython/file/5395f96588d4/Lib/logging/handlers.py#l808
msg134313 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2011-04-23 19:07
I've managed to get access to a FreeBSD system and done some investigation. The system is working as designed, and the error message is being printed by the handleError() method of the handler. To handle the exception differently, you either set logging.raiseExceptions to False (which will cause logging to swallow the exception) or you need to implement your own handler which takes appropriate action (e.g truncates the message). Closing as invalid.
msg134324 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2011-04-24 05:26
> I'll write a LocalSysLogHandler for me that uses the syslog module. Sure, but bear in mind that on some Linux systems at least, the syslog module has thread safety issues because the underlying C APIs are not thread-safe. (I'm not sure of the situation on FreeBSD.) This shouldn't be a problem if the only calls to the module are from the handler, since logging has handler locks - but it could be a problem if other code in your process calls syslog APIs directly.
msg134325 - (view) Author: Lukáš Lalinský (lukas.lalinsky) Date: 2011-04-24 06:18
It will be called only from the handler, so I think it should be fine. The reason why I started using syslog was that I need to log into a single file from multiple processes, but it seems to be showing up as too much trouble.
msg134454 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2011-04-26 12:30
For other options you might like to consider, see: http://plumberjack.blogspot.com/2010/09/improved-queuehandler-queuelistener.html which refers to QueueHandler and QueueListener classes. These were added in 3.2 but are available for Python 2.x: http://code.google.com/p/logutils/
msg134455 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2011-04-26 12:31
Also: http://plumberjack.blogspot.com/2010/09/using-logging-with-multiprocessing.html
msg219909 - (view) Author: Enji Cooper (ngie) * Date: 2014-06-07 03:34
The code doesn't appear to be conforming to RFC-3164 or RFC-5424: (From RFC-3164): 4.1 syslog Message Parts The full format of a syslog message seen on the wire has three discernable parts. The first part is called the PRI, the second part is the HEADER, and the third part is the MSG. The total length of the packet MUST be 1024 bytes or less. There is no minimum length of the syslog message although sending a syslog packet with no contents is worthless and SHOULD NOT be transmitted. (From RFC-5424) The reason syslog transport receivers need only support receiving up to and including 480 octets has, among other things, to do with difficult delivery problems in a broken network. Syslog messages may use a UDP transport mapping with this 480 octet restriction to avoid session overhead and message fragmentation. In a network with problems, the likelihood of getting one single-packet message delivered successfully is higher than getting two message fragments delivered successfully. Therefore, using a larger size may prevent the operator from getting some critical information about the problem, whereas using small messages might get that information to the operator. It is recommended that messages intended for troubleshooting purposes should not be larger than 480 octets. To further strengthen this point, it has also been observed that some UDP implementations generally do not support message sizes of more than 480 octets. This behavior is very rare and may no longer be an issue. ... It must be noted that the IPv6 MTU is about 2.5 times 480. An implementation targeted towards an IPv6-only environment might thus assume this as a larger minimum size. With MTUs being what they are by default with ethernet, using an MTU <1500 with UDP when jumbo frames aren't available seems like a foolhardy thing to do. I believe part of the problem is that the socket send buffer size is not being set in the SysLogHandler via socket.setsockopt and it's trying to jam as much information as it can down the pipe and failing, but I need to do more digging...
msg219911 - (view) Author: Enji Cooper (ngie) * Date: 2014-06-07 03:37
Please note that when I said "the code" I was looking at python 3.3 on OSX (compiled with MacPorts): $ python3.3 Python 3.3.5 (default, Mar 11 2014, 15:08:59) [GCC 4.2.1 Compatible Apple LLVM 5.0 (clang-500.2.79)] on darwin Type "help", "copyright", "credits" or "license" for more information. It's of course similar in lineage (BSD-foundation), but not the same of course.. I have a couple FreeBSD systems I can test this out on as well..
msg230967 - (view) Author: Domen Kožar (iElectric) Date: 2014-11-10 17:19
Note: same bug is relevant to DatagramHandler since it uses UDP transport.
msg254223 - (view) Author: Harsh Patel (Harsh Patel) Date: 2015-11-06 21:30
I know this has been closed as "Not a bug" but it would have been convenient if the message was broken down into multiple packets and transmitted, should it exceed the packet limit. Raising an exception [Errno 40 or Errno 90] or silently ignoring the packet (by setting logging.raiseExceptions to False) doesn't help much in terms of robustness and reliability. I eventually ended up extending these Handler classes and overriding the send to accomplish breaking messages into multiple parts
msg254226 - (view) Author: R. David Murray (r.david.murray) * (Python committer) Date: 2015-11-06 21:35
Writing your own handler is what Vinay recommended. Is it even possible to determine the maximum message size? If we can't do that reliably, then the best we can do is recommend writing your own exception handler using local knowledge. If it can be determined reliably, you could open a new issue with that feature request.
msg254229 - (view) Author: Stéphane Wirtel (matrixise) * (Python committer) Date: 2015-11-06 21:44
This issue will stay closed, BUT I propose you to create a new issue with a new title: Feature: Support message over 1024 bytes for the SysLogHandler. and propose a patch for this feature.
History
Date User Action Args
2022-04-11 14:57:16 admin set github: 56116
2015-11-06 21:44:16 matrixise set nosy: + matrixisemessages: +
2015-11-06 21:35:16 r.david.murray set nosy: + r.david.murraymessages: +
2015-11-06 21:30:20 Harsh Patel set nosy: + Harsh Patelmessages: +
2014-11-10 17:19:07 iElectric set nosy: + iElectricmessages: +
2014-06-07 03:37:06 ngie set messages: +
2014-06-07 03:34:59 ngie set nosy: + ngiemessages: +
2011-04-26 12:31:25 vinay.sajip set messages: +
2011-04-26 12:30:35 vinay.sajip set messages: +
2011-04-24 06🔞22 lukas.lalinsky set messages: +
2011-04-24 05:26:16 vinay.sajip set messages: +
2011-04-23 19:07:02 vinay.sajip set status: open -> closedresolution: not a bugmessages: +
2011-04-23 18:24:47 lukas.lalinsky set status: pending -> openmessages: +
2011-04-23 10:24:34 vinay.sajip set status: open -> pendingversions: - Python 3.2, Python 3.3messages: + components: + Library (Lib)type: crash -> behavior
2011-04-23 09:14:40 vinay.sajip set assignee: vinay.sajipnosy: + vinay.sajipversions: + Python 3.2, Python 3.3
2011-04-22 13:52:16 lukas.lalinsky create