classification
Title: test_sha256 from test_socket fails on ppc64le arch
Type: Stage: resolved
Components: Tests Versions: Python 3.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: Fomalhaut Weisszwerg, christian.heimes, cstratak, rdecker, vstinner
Priority: normal Keywords: patch

Created on 2017-10-05 19:58 by cstratak, last changed 2017-11-30 14:25 by cstratak. This issue is now closed.

Files
File name Uploaded Description Edit
trace cstratak, 2017-10-09 18:11
trace2 cstratak, 2017-10-10 15:08
trace_x86_64 rdecker, 2017-10-13 19:58
strace_py3_7_0a2_test_sha256.log Fomalhaut Weisszwerg, 2017-11-30 09:31 strace log on CentOS 7.4
Pull Requests
URL Status Linked Edit
PR 4643 merged vstinner, 2017-11-30 11:09
PR 4645 merged python-dev, 2017-11-30 12:58
Messages (18)
msg303783 - (view) Author: Charalampos Stratakis (cstratak) * Date: 2017-10-05 19:58
The issue is reproducible on a CentOS 7.4 on ppc64le architecture. It passes successfully on other arch's (however the other power pc arch's might also be affected).

How to reproduce:

Compile python 3.6 from source.

Run ./python3 -m test --verbose test_socket

And it fails with:

ERROR: test_sha256 (test.test_socket.LinuxKernelCryptoAPI)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/root/test/cpython/Lib/test/test_socket.py", line 5424, in test_sha256
    op.sendall(b"abc")
OSError: [Errno 126] Required key not available
msg303974 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-09 15:23
> The issue is reproducible on a CentOS 7.4 on ppc64le architecture.

What is the kernel version?

It would be nice to have the strace output. Example:

strace -o trace ./python -m test -v test_socket -m test_sha256
# then get the trace file

I'm surprised because it seems like ENOKEY (error 126) can only be get on accept(), not on send():
http://elixir.free-electrons.com/linux/latest/source/crypto/af_alg.c#L295
msg303975 - (view) Author: Charalampos Stratakis (cstratak) * Date: 2017-10-09 15:25
Forgot the mention the kernel version which is 3.10.0-693.2.1.el7.ppc64le
msg303989 - (view) Author: Charalampos Stratakis (cstratak) * Date: 2017-10-09 18:11
Attaching the strace output.
msg304036 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-10 13:12
Charalampos Stratakis: "Attaching the strace output."

Oh thanks! I guess tha the interesting syscalls are:

socket(AF_ALG, SOCK_SEQPACKET|SOCK_CLOEXEC, 0) = 3
bind(3, {sa_family=AF_ALG, sa_data="hash\0\0\0\0\0\0\0\0\0\0"}, 88) = 0
accept4(3, NULL, NULL, SOCK_CLOEXEC)    = 4
send(4, "abc", 3, 0)                    = -1 ENOKEY (Required key not available)
close(4)                                = 0

test_socket calls bind() with typ='hash', name='sha256', but in the strace, I only see 'hash'.

strace is maybe outdated and fails to display the full bind() address, or Python doesn't serialize correctly the address.

--

On my Fedora 26, I see sha256 in the bind call:

socket(AF_ALG, SOCK_SEQPACKET|SOCK_CLOEXEC, 0) = 3
bind(3, {sa_family=AF_ALG, sa_data="hash\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0sha256\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"}, 88) = 0
accept4(3, NULL, NULL, SOCK_CLOEXEC)    = 4
sendto(4, "abc", 3, 0, NULL, 0)         = 3
recvfrom(4, "\272x\26\277\217\1\317\352AA@\336]\256\"#\260\3a\243\226\27z\234\264\20\377a\362\0\25\255", 512, 0, NULL, NULL) = 32
close(4)                                = 0
accept4(3, NULL, NULL, SOCK_CLOEXEC)    = 4
sendto(4, "a", 1, MSG_MORE, NULL, 0)    = 1
sendto(4, "b", 1, MSG_MORE, NULL, 0)    = 1
sendto(4, "c", 1, MSG_MORE, NULL, 0)    = 1
sendto(4, "", 0, 0, NULL, 0)            = 0
recvfrom(4, "\272x\26\277\217\1\317\352AA@\336]\256\"#\260\3a\243\226\27z\234\264\20\377a\362\0\25\255", 512, 0, NULL, NULL) = 32
close(4)                                = 0
close(3)                                = 0
msg304037 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-10 13:13
> strace is maybe outdated and fails to display the full bind() address,

I vote for this option since I see addrlen=88 in both examples.
msg304044 - (view) Author: Charalampos Stratakis (cstratak) * Date: 2017-10-10 13:45
Indeed the version of strace is 'strace-4.12-4.el7'.

I will try to provide output from the latest one.
msg304051 - (view) Author: Charalampos Stratakis (cstratak) * Date: 2017-10-10 15:08
Attaching the output of:

strace -s 128 -e trace=%network -o trace ./python3 -m test -v test_socket -m test_sha256

using the latest version of strace (4.19).
msg304353 - (view) Author: Ryan Decker (rdecker) Date: 2017-10-13 19:58
I seem to be having this issue on CentOS 7.4 but running on x86_64 instead of ppc64le. I have attached an strace using version 4.17 (the lastest version from scl) created as follows:

strace -s 128 -e trace=%network -o trace ./python -m test -v test_socket -m test_sha256


== CPython 3.6.3 (default, Oct 13 2017, 11:16:36) [GCC 4.8.5 20150623 (Red Hat 4.8.5-16)]
== Linux-3.10.0-693.2.2.el7.x86_64-x86_64-with-centos-7.4.1708-Core little-endian
== cwd: /home/ryan/Downloads/Python-3.6.3/build/test_python_4140
== CPU count: 8
== encodings: locale=UTF-8, FS=utf-8
Run tests sequentially
0:00:00 load avg: 0.13 [1/1] test_socket
test_sha256 (test.test_socket.LinuxKernelCryptoAPI) ... ERROR

======================================================================
ERROR: test_sha256 (test.test_socket.LinuxKernelCryptoAPI)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/ryan/Downloads/Python-3.6.3/Lib/test/test_socket.py", line 5424, in test_sha256
    op.sendall(b"abc")
OSError: [Errno 126] Required key not available

----------------------------------------------------------------------
Ran 1 test in 0.001s

FAILED (errors=1)
test test_socket failed
test_socket failed

1 test failed:
    test_socket

Total duration: 39 ms
Tests result: FAILURE
msg307282 - (view) Author: Fomalhaut Weisszwerg (Fomalhaut Weisszwerg) Date: 2017-11-30 09:31
I've got the same error on CentOS 7.4 on x86_64.

---
$ cat /etc/redhat-release 
CentOS Linux release 7.4.1708 (Core) 
$ uname -a
Linux localhost.localdomain 3.10.0-693.5.2.el7.x86_64 #1 SMP Fri Oct 20 20:32:50 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
$ strace -V
strace -- version 4.20
Copyright (c) 1991-2017 The strace developers <https://strace.io>.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

Optional features enabled: (none)
$ cd Python-3.7.0a2
$ strace -v -s 128 -e trace=%network -o strace_py3_7_0a2_test_sha256.log ./python -m test -v test_socket -m test_sha256
== CPython 3.7.0a2 (default, Nov 28 2017, 16:16:49) [GCC 6.4.0]
== Linux-3.10.0-693.5.2.el7.x86_64-x86_64-with-centos-7.4.1708-Core little-endian
== cwd: /home/vagrant/sources/Python-3.7.0a2/build/test_python_10627
== CPU count: 4
== encodings: locale=UTF-8, FS=utf-8
Run tests sequentially
0:00:00 load avg: 0.00 [1/1] test_socket
test_sha256 (test.test_socket.LinuxKernelCryptoAPI) ... ERROR

======================================================================
ERROR: test_sha256 (test.test_socket.LinuxKernelCryptoAPI)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/vagrant/sources/Python-3.7.0a2/Lib/test/test_socket.py", line 5580, in test_sha256
    op.sendall(b"abc")
OSError: [Errno 126] Required key not available

----------------------------------------------------------------------
Ran 1 test in 0.006s

FAILED (errors=1)
test test_socket failed
test_socket failed

1 test failed:
    test_socket

Total duration: 98 ms
Tests result: FAILURE
$ cat strace_py3_7_0a2_test_sha256.log 
socket(AF_INET6, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
bind(3, {sa_family=AF_INET6, sin6_port=htons(0), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=htonl(0), sin6_scope_id=0}, 28) = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=10628, si_uid=501, si_status=0, si_utime=0, si_stime=0} ---
socket(AF_CAN, SOCK_RAW|SOCK_CLOEXEC, 1) = 3
socket(AF_CAN, SOCK_DGRAM|SOCK_CLOEXEC, 6) = -1 EPROTONOSUPPORT (Protocol not supported)
socket(AF_RDS, SOCK_SEQPACKET|SOCK_CLOEXEC, 0) = -1 EAFNOSUPPORT (Address family not supported by protocol)
socket(AF_ALG, SOCK_SEQPACKET|SOCK_CLOEXEC, 0) = 3
socket(AF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
socket(AF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
socket(AF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
socket(AF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
socket(AF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
socket(AF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_SCTP) = 3
socket(AF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_SCTP) = 3
socket(AF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_SCTP) = 3
socket(AF_ALG, SOCK_SEQPACKET|SOCK_CLOEXEC, 0) = 3
bind(3, {sa_family=AF_ALG, sa_data="hash\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0sha256\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"}, 88) = 0
accept4(3, NULL, NULL, SOCK_CLOEXEC)    = 4
sendto(4, "abc", 3, 0, NULL, 0)         = -1 ENOKEY (Required key not available)
+++ exited with 2 +++
---


By contrast, I can get a expected result on Debian:

---
$ uname -a
Linux debian-server 4.13.0-1-amd64 #1 SMP Debian 4.13.13-1 (2017-11-16) x86_64 GNU/Linux
$ cd Python-3.7.0a2
$ strace -v -s 128 -e trace=%network -o strace.log ./python -m test -v test_socket -m test_sha256
== CPython 3.7.0a2 (default, Nov 29 2017, 18:47:33) [GCC 7.2.0]
== Linux-4.13.0-1-amd64-x86_64-with-debian-buster-sid little-endian
== cwd: /home/working/Python-3.7.0a2/build/test_python_21000
== CPU count: 24
== encodings: locale=UTF-8, FS=utf-8
Run tests sequentially
0:00:00 load avg: 0.07 [1/1] test_socket
test_sha256 (test.test_socket.LinuxKernelCryptoAPI) ... ok

----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
1 test OK.

Total duration: 43 ms
Tests result: SUCCESS
$ cat strace.log
socket(AF_INET6, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
bind(3, {sa_family=AF_INET6, sin6_port=htons(0), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=htonl(0), sin6_scope_id=0}, 28) = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=21041, si_uid=1000, si_status=0, si_utime=0, si_stime=0} ---
socket(AF_CAN, SOCK_RAW|SOCK_CLOEXEC, 1) = 3
socket(AF_CAN, SOCK_DGRAM|SOCK_CLOEXEC, 6) = -1 EPROTONOSUPPORT (Protocol not supported)
socket(AF_RDS, SOCK_SEQPACKET|SOCK_CLOEXEC, 0) = -1 EAFNOSUPPORT (Address family not supported by protocol)
socket(AF_ALG, SOCK_SEQPACKET|SOCK_CLOEXEC, 0) = 3
socket(AF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
socket(AF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
socket(AF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
socket(AF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
socket(AF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 3
socket(AF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_SCTP) = 3
socket(AF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_SCTP) = 3
socket(AF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_SCTP) = 3
socket(AF_ALG, SOCK_SEQPACKET|SOCK_CLOEXEC, 0) = 3
bind(3, {sa_family=AF_ALG, sa_data="hash\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0sha256\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"}, 88) = 0
accept4(3, NULL, NULL, SOCK_CLOEXEC)    = 4
sendto(4, "abc", 3, 0, NULL, 0)         = 3
recvfrom(4, "\272x\26\277\217\1\317\352AA@\336]\256\"#\260\3a\243\226\27z\234\264\20\377a\362\0\25\255", 512, 0, NULL, NULL) = 32
accept4(3, NULL, NULL, SOCK_CLOEXEC)    = 4
sendto(4, "a", 1, MSG_MORE, NULL, 0)    = 1
sendto(4, "b", 1, MSG_MORE, NULL, 0)    = 1
sendto(4, "c", 1, MSG_MORE, NULL, 0)    = 1
sendto(4, "", 0, 0, NULL, 0)            = 0
recvfrom(4, "\272x\26\277\217\1\317\352AA@\336]\256\"#\260\3a\243\226\27z\234\264\20\377a\362\0\25\255", 512, 0, NULL, NULL) = 32
+++ exited with 0 +++
---
msg307288 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-30 10:56
Charalampos Stratakis told me that the test pass on kernel 4.11.

The bug comes from the kernel, there is nothing that Python can do to workarond this kernel bug. So I suggest to skip the test on kernel < 4.11, or at least skip it on ppc64 with kernel < 4.11.
msg307289 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-30 11:13
Charalampos Stratakis, Ryan Decker, Fomalhaut Weisszwerg:

* What is the value of os.uname().machine on ppc64le? 'ppc64le'? Is there a 'ppcbe' architecture?
* Can you please try attached PR 4643 on a kernel 3.10 and confirms that the test is skipped, and maybe also test it on a kernel 4.11 and newer and confirms that the test pass?

To test the PR, you can download the PR as a patch and apply it using "patch -p1 < 4643.patch":

https://github.com/python/cpython/pull/4643.patch

It would be nice to get the exact version in which sha256 was fixed on ppc64, but it's not a requirements.
msg307290 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-30 11:23
> It would be nice to get the exact version in which sha256 was fixed on ppc64, but it's not a requirements.

Ah, I think that I found the bugfix (8 Jan 2016):
https://github.com/torvalds/linux/commit/6de62f15b581

So it was fixed in the kernel 4.5.

I found also https://access.redhat.com/errata/RHSA-2017:2437 :

"The lrw_crypt() function in 'crypto/lrw.c' in the Linux kernel before 4.5 allows local users to cause a system crash and a denial of service by the NULL pointer dereference via accept(2) system call for AF_ALG socket without calling setkey() first to set a cipher key. (CVE-2015-8970, Moderate)"

So I will simply skip test_sha256() on all architectures for kernel older than 4.5. You can now ignore my questions in my previous comment ;-)
msg307304 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-30 12:58
New changeset 86afc1f2a7fb3afe00779c6426bc141bc795d9a3 by Victor Stinner in branch 'master':
Skip test_socket.test_sha256() on linux < 4.5 (#4643)
https://github.com/python/cpython/commit/86afc1f2a7fb3afe00779c6426bc141bc795d9a3
msg307308 - (view) Author: Fomalhaut Weisszwerg (Fomalhaut Weisszwerg) Date: 2017-11-30 13:36
STINNER Victor

Thank you for your info.

And this issue occurs not only ppc64le but also x86_64.
`uname -a` on my CentOS returns following:

Linux localhost.localdomain 3.10.0-693.5.2.el7.x86_64 #1 SMP Fri Oct 20 20:32:50 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

I think that this issue does not depend on arch.
msg307310 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-30 13:43
New changeset 92a2c07b71aefc01f84ba4b0eda8e2a45c1a6b65 by Victor Stinner (Miss Islington (bot)) in branch '3.6':
Skip test_socket.test_sha256() on linux < 4.5 (GH-4643) (#4645)
https://github.com/python/cpython/commit/92a2c07b71aefc01f84ba4b0eda8e2a45c1a6b65
msg307312 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-30 13:45
"And this issue occurs not only ppc64le but also x86_64. (...) I think that this issue does not depend on arch."

Thanks for the confirmation. This is what I understood from the Red Hat report, but also the kernel bugfix.

test_sha256() is now skipped on all architectures on kernel < 4.5.

Thank you for the bug report Charalampos Stratakis! Sorry for the delay, I wasn't sure how to fix it. I didn't know which kernels were impacted, which architectures, and if it was a Python or a kernel bug. (It's definitively a kernel bug.)
msg307315 - (view) Author: Charalampos Stratakis (cstratak) * Date: 2017-11-30 14:25
Thanks for the fix Victor!
History
Date User Action Args
2017-11-30 14:25:56cstrataksetmessages: + msg307315
2017-11-30 13:45:43vstinnersetstatus: open -> closed
resolution: fixed
messages: + msg307312

stage: patch review -> resolved
2017-11-30 13:43:45vstinnersetmessages: + msg307310
2017-11-30 13:36:49Fomalhaut Weisszwergsetmessages: + msg307308
2017-11-30 12:58:59python-devsetpull_requests: + pull_request4560
2017-11-30 12:58:50vstinnersetmessages: + msg307304
2017-11-30 11:23:03vstinnersetmessages: + msg307290
2017-11-30 11:13:47vstinnersetmessages: + msg307289
2017-11-30 11:09:40vstinnersetkeywords: + patch
stage: patch review
pull_requests: + pull_request4557
2017-11-30 10:56:44vstinnersetmessages: + msg307288
2017-11-30 09:31:19Fomalhaut Weisszwergsetfiles: + strace_py3_7_0a2_test_sha256.log
versions: - Python 3.6
nosy: + Fomalhaut Weisszwerg

messages: + msg307282
2017-10-13 19:58:38rdeckersetfiles: + trace_x86_64
nosy: + rdecker
messages: + msg304353

2017-10-10 15:08:41cstrataksetfiles: + trace2

messages: + msg304051
2017-10-10 13:45:40cstrataksetmessages: + msg304044
2017-10-10 13:13:34vstinnersetmessages: + msg304037
2017-10-10 13:12:05vstinnersetmessages: + msg304036
2017-10-09 18:11:25cstrataksetfiles: + trace

messages: + msg303989
2017-10-09 15:25:14cstrataksetmessages: + msg303975
2017-10-09 15:23:28vstinnersetnosy: + vstinner
messages: + msg303974
2017-10-05 19:58:44cstrataksetnosy: + christian.heimes
2017-10-05 19:58:24cstratakcreate