test_sha256 from test_socket fails on ppc64le arch

[stratakis]

BPO	31705
Nosy	@vstinner, @tiran, @stratakis
PRs	bpo-31705: Skip test_socket.test_sha256() on ppc64 #4643 [3.6] bpo-31705: Skip test_socket.test_sha256() on linux < 4.5 (GH-4643) #4645
Files	trace trace2 trace_x86_64 strace_py3_7_0a2_test_sha256.log: strace log on CentOS 7.4

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2017-11-30.13:45:43.648>
created_at = <Date 2017-10-05.19:58:24.428>
labels = ['3.7', 'tests']
title = 'test_sha256 from test_socket fails on ppc64le arch'
updated_at = <Date 2017-11-30.14:25:56.579>
user = 'https://github.com/stratakis'

bugs.python.org fields:

activity = <Date 2017-11-30.14:25:56.579>
actor = 'cstratak'
assignee = 'none'
closed = True
closed_date = <Date 2017-11-30.13:45:43.648>
closer = 'vstinner'
components = ['Tests']
creation = <Date 2017-10-05.19:58:24.428>
creator = 'cstratak'
dependencies = []
files = ['47202', '47204', '47221', '47306']
hgrepos = []
issue_num = 31705
keywords = ['patch']
message_count = 18.0
messages = ['303783', '303974', '303975', '303989', '304036', '304037', '304044', '304051', '304353', '307282', '307288', '307289', '307290', '307304', '307308', '307310', '307312', '307315']
nosy_count = 5.0
nosy_names = ['vstinner', 'christian.heimes', 'cstratak', 'rdecker', 'Fomalhaut Weisszwerg']
pr_nums = ['4643', '4645']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue31705'
versions = ['Python 3.7']

[stratakis]

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

[vstinner]

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

[stratakis]

Forgot the mention the kernel version which is 3.10.0-693.2.1.el7.ppc64le

[stratakis]

Attaching the strace output.

[vstinner]

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

[vstinner]

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.

[stratakis]

Indeed the version of strace is 'strace-4.12-4.el7'.

I will try to provide output from the latest one.

[stratakis]

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).

[rdecker]

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

[FomalhautWeisszwerg]

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 +++
---

[vstinner]

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.

[vstinner]

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.

[vstinner]

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):
torvalds/linux@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 ;-)