[issue38780] SysLogHandler crash atexit

[Vinay Sajip]

Vinay Sajip  added the comment:

> As far as I know, this only happens during shutdown. During shutdown it has 
> already removed the attribute as part of the teardown process. In this case 
> adding the attribute at the begining will do no good.

Certainly, that's true - there are a number of issues that get laid at 
logging's door because of interpreter shutdown sometimes intersecting with 
asyncio, threads and error handling using logging to report, which then fails 
in turn because of inconsistent interpreter state during shutdown. That would 
then perhaps be a "wontfix" or "cantfix" because there is no good solution. But 
the missing socket attribute in SysLogHandler might cause other problems in the 
future - I'm just saying that the approach you suggested is, to me, preferable 
to the NullSocket approach to deal with a similar issue in this area.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Alan Robertson]

Alan Robertson  added the comment:

As far as I know, this only happens during shutdown. During shutdown it has 
already removed the attribute as part of the teardown process. In this case 
adding the attribute at the begining will do no good.

On Wed, Jan 6, 2021, at 10:30 AM, Vinay Sajip wrote:
> 
> Vinay Sajip  added the comment:
> 
> TBH as I said in the now-closed PR, using a NullSocket seems overkill. 
> As mentioned in msg359594, it seems to make more sense to assign a 
> socket attribute to None early in the constructor. If an error occurs 
> during socket creation, the socket attribute will remain at None. When 
> closing, just ensure the socket attribute isn't None before trying to 
> close it. This mirrors what SocketHandler does.
> 
> --
> 
> ___
> Python tracker 
> 
> ___
>

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Alan Robertson]

Alan Robertson  added the comment:

On Wed, Jan 6, 2021, at 10:30 AM, Vinay Sajip wrote:
> 
> Vinay Sajip  added the comment:
> 
> TBH as I said in the now-closed PR, using a NullSocket seems overkill. 
> As mentioned in msg359594, it seems to make more sense to assign a 
> socket attribute to None early in the constructor. If an error occurs 
> during socket creation, the socket attribute will remain at None. When 
> closing, just ensure the socket attribute isn't None before trying to 
> close it. This mirrors what SocketHandler does.
> 
> --
> 
> ___
> Python tracker 
> 
> ___
>

-- 
  Alan Robertson
  al...@unix.sh

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Vinay Sajip]

Vinay Sajip  added the comment:

TBH as I said in the now-closed PR, using a NullSocket seems overkill. As 
mentioned in msg359594, it seems to make more sense to assign a socket 
attribute to None early in the constructor. If an error occurs during socket 
creation, the socket attribute will remain at None. When closing, just ensure 
the socket attribute isn't None before trying to close it. This mirrors what 
SocketHandler does.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Erlend Egeberg Aasland]

Erlend Egeberg Aasland  added the comment:

Using a NullSocket fixes the test in commit 
f0f8ff8f06afd43947e268824aa4381add05ce8f

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Erlend Egeberg Aasland]

Erlend Egeberg Aasland  added the comment:

I've forked your work, Jason:
https://github.com/erlend-aasland/cpython/tree/bpo-38780-test

I added the test from msg356475, and I'm able to reproduce it by asserting that 
the `socket` attribute is present (commit 
f0f8ff8f06afd43947e268824aa4381add05ce8f)

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Change by Jason R. Coombs :


--
stage: patch review -> needs patch

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Change by Jason R. Coombs :


--
assignee: jaraco -> 

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Jason R. Coombs  added the comment:

I started work on a test in 
https://github.com/jaraco/cpython/tree/bugfix/bpo-38780-test, but (a) the test 
was failing to exhibit the expected failures, and (b) I realized that the fix 
isn't having the intended effect either, because for unix sockets, [self.socket 
is unconditionally 
set](https://github.com/python/cpython/blob/dfdca85dfa64e72df385b3a486f85b773fc0f135/Lib/logging/handlers.py#L872),
 overriding any NullSocket or None value.

The SysLogHandler code will need to be reorganized if self.socket is intended 
to model two modes (broken and initialized).

I'm not sure when I'll get another chance to take a look at this, but I'll not 
be able to wrap it up today, so I'm going to unassign it for now.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Erlend Egeberg Aasland]

Erlend Egeberg Aasland  added the comment:

Thanks, Jason! I won't have time to look at this until perhaps next week, 
however, feel free to add tests as you like.

N.B.: My patches might not be the best solution to the problem; it was just 
something I threw up based on my initial understanding of the problem.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Jason R. Coombs  added the comment:

Erlend, inspired by your patches, I created 
https://github.com/python/cpython/pull/23661/commits/e9723003d49c722d57a69e5016b442d4d752fc6d,
 which uses a NullSocket instance instead of None, allowing the 
behavior-suppression to be encapsulated in a single place and swapped out by 
creation of a proper socket instance.

I do believe this approach addresses the issue. Are you still willing to put 
together a test case or more?

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Change by Jason R. Coombs :


--
pull_requests: +22527
stage:  -> patch review
pull_request: https://github.com/python/cpython/pull/23661

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Change by Jason R. Coombs :


--
versions: +Python 3.10 -Python 2.7, Python 3.7

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Jason R. Coombs  added the comment:

I've applied the patches and pushed them to 
https://github.com/jaraco/cpython/tree/bugfix/bpo-38780.

```
cpython master $ http 
https://bugs.python.org/file48933/0001-bpo-38780-Harden-socket-use-in-logging.handlers.patch
 | git apply
cpython master $ git commit -a -m "bpo-38780: Initialize self.socket to None 
early in __init__() and check for None in close() and e
mit()" --author "Erlend E. Aasland " --date '28 Feb 
2020 22:38:12 +0100'
[master e05b7d6c52] bpo-38780: Initialize self.socket to None early in 
__init__() and check for None in close() and emit()
 Author: Erlend E. Aasland 
 Date: Fri Feb 28 22:38:12 2020 +0100
 1 file changed, 7 insertions(+), 2 deletions(-)
cpython master $ http https://bugs.python.org/file48934/0002-Improve-emit.patch 
| git apply
cpython master $ git commit -a -m "bpo-38780: Address uncertainty in handling 
of emit() case." --author "Erlend E. Aasland " --date '28 Feb 2020 23:22:58 +0100'
[master 045b6381b5] bpo-38780: Address uncertainty in handling of emit() case.
 Author: Erlend E. Aasland 
 Date: Fri Feb 28 23:22:58 2020 +0100
 1 file changed, 7 insertions(+), 5 deletions(-)
cpython master $ git checkout -b bugfix/bpo-38780
Switched to a new branch 'bugfix/bpo-38780'
cpython bugfix/bpo-38780 $ gpj
To https://github.com/jaraco/cpython
 * [new branch]bugfix/bpo-38780 -> bugfix/bpo-38780
 * [new tag]   v3.10.0a2 -> v3.10.0a2
Branch 'bugfix/bpo-38780' set up to track remote branch 'bugfix/bpo-38780' from 
'jaraco'.
```

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Jason R. Coombs  added the comment:

I'll take a look at the patch and convert it to a PR.

--
assignee:  -> jaraco

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Alessio Bogon]

Alessio Bogon  added the comment:

Is there any update on this issue? I'm experiencing the same problem on macos.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Alessio Bogon]

Change by Alessio Bogon :


--
nosy: +youtux

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Erlend Egeberg Aasland]

Erlend Egeberg Aasland  added the comment:

I'm a bit uncertain if the previous patch can handle the emit() case correctly. 
Proposed improvement in attached patch (0002-Improve-emit.patch).

--
Added file: https://bugs.python.org/file48934/0002-Improve-emit.patch

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Erlend Egeberg Aasland]

Change by Erlend Egeberg Aasland :


Added file: 
https://bugs.python.org/file48933/0001-bpo-38780-Harden-socket-use-in-logging.handlers.patch

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Erlend Egeberg Aasland]

Change by Erlend Egeberg Aasland :


Removed file: 
https://bugs.python.org/file48932/0001-bpo-38780-Harden-socket-use-in-logging.handlers.patch

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Erlend Egeberg Aasland]

Erlend Egeberg Aasland  added the comment:

Attached patch is based on Ronald Oussoren's and Alan Robertson's comments: 
Initialise self.socket to None early in __init()__, and then check for None in 
close() and emit(). Passes make test on 3.9, 3.8 and 3.7.

If this solution is ok I'll add a unit test for the case that triggered this 
report and prepare a PR.

--
keywords: +patch
nosy: +erlendaasland
Added file: 
https://bugs.python.org/file48932/0001-bpo-38780-Harden-socket-use-in-logging.handlers.patch

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Alan Robertson]

Alan Robertson  added the comment:

There are a variety of different reasons this can fail, not just on MacOS. You 
could give it a bad IP address of a server, etc. [That was my particular case].

The constructor should create an attribute 'socket' and initialize it to None 
early on. Then, the close function in logging/handlers.py should check for 
None. Or alternatively, it shouldn't register the object with atexit until it's 
been constructed "well-enough".

--
nosy: +alanr

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Ronald Oussoren]

Ronald Oussoren  added the comment:

As you noted /dev/log doesn't exist on macOS (the correct path is 
/var/run/syslog).

I guess the change that would be most in spirit of the comment is to set 
self.socket to None when the socket cannot be opened and test for that before 
closing the socket.  Likewise, emit() can test if self.socket is None and then 
attempt to open the socket (and not write to the log when the socket still is 
None)

This makes errors pass silently, but does match the spirit of the POSIX API 
(where the syslog function does not return an error).

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Jason R. Coombs  added the comment:

I could imagine extending the shutdown code to catch the reported error 
(https://github.com/python/cpython/blob/138ccbb02216ca086047c3139857fb44f3dab1f9/Lib/logging/__init__.py#L2130-L2135),
 but that wouldn't address the error in emit.

Similarly, the SysLogHandler could override shutdown to bypass the error if no 
socket attribute is present, but that again wouldn't address the emit case.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Jason R. Coombs  added the comment:

In the downstream issue, it's also reported that crashes occur in emit as well, 
suggesting that the comment is additionally wrong on that front.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Jason R. Coombs  added the comment:

The issue probably stems from 
https://github.com/python/cpython/blob/138ccbb02216ca086047c3139857fb44f3dab1f9/Lib/logging/handlers.py#L828-L835.
 I doubt the logic of that comment, as in the non-unix-socket case, the error 
is raised if a connection cannot be established. Fixing the issue by 
re-considering that comment would have backward-incompatible implications and 
would violate the intention of the comment's author.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Jason R. Coombs  added the comment:

For background, this issue originated from 
https://github.com/pytest-dev/pytest-services/issues/20.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Jason R. Coombs  added the comment:

I guess that makes sense, as `/dev/log` doesn't exist on macOS. So maybe this 
usage is invalid. But still I'd expect the handler to error early or at least 
not error on shutdown.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Ned Deily]

Change by Ned Deily :


--
nosy: +vinay.sajip

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Change by Jason R. Coombs :


--
components: +Library (Lib), macOS
nosy: +ned.deily, ronaldoussoren

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Jason R. Coombs  added the comment:

I only observe this issue on macOS. On Linux, the error doesn't occur.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

New submission from Jason R. Coombs :

On Python 3.8.0:

$ python -c "import logging.handlers, socket; handler = 
logging.handlers.SysLogHandler(facility=logging.handlers.SysLogHandler.LOG_LOCAL7,
 address='/dev/log', socktype=socket.SOCK_RAW)" 

Error in atexit._run_exitfuncs:
Traceback (most recent call last):
  File 
"/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/logging/__init__.py",
 line 2112, in shutdown
h.close()
  File 
"/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/logging/handlers.py",
 line 892, in close
self.socket.close()
AttributeError: 'SysLogHandler' object has no attribute 'socket'

Probably that shouldn't happen.

--
messages: 356475
nosy: jaraco
priority: normal
severity: normal
status: open
title: SysLogHandler crash atexit

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue38780] SysLogHandler crash atexit

[Jason R. Coombs]

Jason R. Coombs  added the comment:

Same error on Python 2.7 and 3.7

--
versions: +Python 2.7, Python 3.7, Python 3.8, Python 3.9

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com