* Regression in unix stream sockets with the Smack LSM [not found] <a507efa7-066b-decf-8605-89cdb0ac1951.ref@schaufler-ca.com> @ 2021-09-13 22:50 ` Casey Schaufler 2021-09-13 23:47 ` Paul Moore 0 siblings, 1 reply; 10+ messages in thread From: Casey Schaufler @ 2021-09-13 22:50 UTC (permalink / raw) To: Jiang Wang, Andrii Nakryiko, Jakub Sitnicki, John Fastabend, LKML, Linux Security Module list Cc: Casey Schaufler Commit 77462de14a43f4d98dbd8de0f5743a4e02450b1d af_unix: Add read_sock for stream socket types introduced a regression in UDS socket connections for the Smack LSM. I have not tracked done the details of why the change broke the code, but this is where bisecting the kernel indicates the problem lies, and I have verified that reverting this change repairs the problem. You can verify the problem with the Smack test suite: https://github.com/smack-team/smack-testsuite.git The failing test is tests/uds-access.sh. I have not looked to see if there's a similar problem with SELinux. There may be, but if there isn't it doesn't matter, there's still a bug. Thank you. ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Regression in unix stream sockets with the Smack LSM 2021-09-13 22:50 ` Regression in unix stream sockets with the Smack LSM Casey Schaufler @ 2021-09-13 23:47 ` Paul Moore 2021-09-14 0:16 ` Casey Schaufler ` (2 more replies) 0 siblings, 3 replies; 10+ messages in thread From: Paul Moore @ 2021-09-13 23:47 UTC (permalink / raw) To: Casey Schaufler Cc: Jiang Wang, Andrii Nakryiko, Jakub Sitnicki, John Fastabend, LKML, Linux Security Module list On Mon, Sep 13, 2021 at 6:53 PM Casey Schaufler <casey@schaufler-ca.com> wrote: > > Commit 77462de14a43f4d98dbd8de0f5743a4e02450b1d > > af_unix: Add read_sock for stream socket types > > introduced a regression in UDS socket connections for the Smack LSM. > I have not tracked done the details of why the change broke the code, > but this is where bisecting the kernel indicates the problem lies, and > I have verified that reverting this change repairs the problem. > > You can verify the problem with the Smack test suite: > > https://github.com/smack-team/smack-testsuite.git > > The failing test is tests/uds-access.sh. > > I have not looked to see if there's a similar problem with SELinux. > There may be, but if there isn't it doesn't matter, there's still a > bug. FWIW, the selinux-testsuite tests ran clean today with v5.15-rc1 (it looks like this code is only in v5.15) but as Casey said, a regression is a regression. Casey, what actually fails on the Smack system with this commit? -- paul moore www.paul-moore.com ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Regression in unix stream sockets with the Smack LSM 2021-09-13 23:47 ` Paul Moore @ 2021-09-14 0:16 ` Casey Schaufler 2021-09-14 22:14 ` Casey Schaufler 2021-09-15 16:51 ` Casey Schaufler 2 siblings, 0 replies; 10+ messages in thread From: Casey Schaufler @ 2021-09-14 0:16 UTC (permalink / raw) To: Paul Moore Cc: Jiang Wang, Andrii Nakryiko, Jakub Sitnicki, John Fastabend, LKML, Linux Security Module list On 9/13/2021 4:47 PM, Paul Moore wrote: > On Mon, Sep 13, 2021 at 6:53 PM Casey Schaufler <casey@schaufler-ca.com> wrote: >> Commit 77462de14a43f4d98dbd8de0f5743a4e02450b1d >> >> af_unix: Add read_sock for stream socket types >> >> introduced a regression in UDS socket connections for the Smack LSM. >> I have not tracked done the details of why the change broke the code, >> but this is where bisecting the kernel indicates the problem lies, and >> I have verified that reverting this change repairs the problem. >> >> You can verify the problem with the Smack test suite: >> >> https://github.com/smack-team/smack-testsuite.git >> >> The failing test is tests/uds-access.sh. >> >> I have not looked to see if there's a similar problem with SELinux. >> There may be, but if there isn't it doesn't matter, there's still a >> bug. > FWIW, the selinux-testsuite tests ran clean today with v5.15-rc1 (it > looks like this code is only in v5.15) but as Casey said, a regression > is a regression. > > Casey, what actually fails on the Smack system with this commit? It's a simple "socat - UNIX-LISTEN:path" "socat - UNIX-CONNECT:path" In one case the processes have the same Smack label, and that usually succeeds. I'm trying to track down exactly when it doesn't. The case where the processes have different Smack labels but a rule allows them mutual write access always fails. I *think* that's because the underlying UDS code is now requiring read access it didn't used to. I'm trying to track that down, too. ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Regression in unix stream sockets with the Smack LSM 2021-09-13 23:47 ` Paul Moore 2021-09-14 0:16 ` Casey Schaufler @ 2021-09-14 22:14 ` Casey Schaufler 2021-09-15 16:51 ` Casey Schaufler 2 siblings, 0 replies; 10+ messages in thread From: Casey Schaufler @ 2021-09-14 22:14 UTC (permalink / raw) To: Paul Moore Cc: Jiang Wang, Andrii Nakryiko, Jakub Sitnicki, John Fastabend, LKML, Linux Security Module list, netdev On 9/13/2021 4:47 PM, Paul Moore wrote: > On Mon, Sep 13, 2021 at 6:53 PM Casey Schaufler <casey@schaufler-ca.com> wrote: >> Commit 77462de14a43f4d98dbd8de0f5743a4e02450b1d >> >> af_unix: Add read_sock for stream socket types >> >> introduced a regression in UDS socket connections for the Smack LSM. >> I have not tracked done the details of why the change broke the code, >> but this is where bisecting the kernel indicates the problem lies, and >> I have verified that reverting this change repairs the problem. >> >> You can verify the problem with the Smack test suite: >> >> https://github.com/smack-team/smack-testsuite.git >> >> The failing test is tests/uds-access.sh. >> >> I have not looked to see if there's a similar problem with SELinux. >> There may be, but if there isn't it doesn't matter, there's still a >> bug. > FWIW, the selinux-testsuite tests ran clean today with v5.15-rc1 (it > looks like this code is only in v5.15) but as Casey said, a regression > is a regression. > > Casey, what actually fails on the Smack system with this commit? I reran the bisection and got a different answer, but the same set of suspects. The change: commit 94531cfcbe79c3598acf96806627b2137ca32eb9 af_unix: Add unix_stream_proto for sockmap came up this time. The two suspect patches are related. The Smack access check on UDS stream sockets is behaving erratically, as if it's using random data to make its checks. I can run the same test on the same system with the same kernel and get different results. The trivial test, where the Smack labels are the same, sometimes fails. But not always. ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Regression in unix stream sockets with the Smack LSM 2021-09-13 23:47 ` Paul Moore 2021-09-14 0:16 ` Casey Schaufler 2021-09-14 22:14 ` Casey Schaufler @ 2021-09-15 16:51 ` Casey Schaufler 2021-09-15 17:29 ` Jiang Wang . 2021-09-20 22:35 ` Jiang Wang . 2 siblings, 2 replies; 10+ messages in thread From: Casey Schaufler @ 2021-09-15 16:51 UTC (permalink / raw) To: Paul Moore Cc: Jiang Wang, Andrii Nakryiko, Jakub Sitnicki, John Fastabend, LKML, Linux Security Module list, netdev, Casey Schaufler On 9/13/2021 4:47 PM, Paul Moore wrote: > On Mon, Sep 13, 2021 at 6:53 PM Casey Schaufler <casey@schaufler-ca.com> wrote: >> Commit 77462de14a43f4d98dbd8de0f5743a4e02450b1d >> >> af_unix: Add read_sock for stream socket types >> >> introduced a regression in UDS socket connections for the Smack LSM. >> I have not tracked done the details of why the change broke the code, >> but this is where bisecting the kernel indicates the problem lies, and >> I have verified that reverting this change repairs the problem. >> >> You can verify the problem with the Smack test suite: >> >> https://github.com/smack-team/smack-testsuite.git >> >> The failing test is tests/uds-access.sh. >> >> I have not looked to see if there's a similar problem with SELinux. >> There may be, but if there isn't it doesn't matter, there's still a >> bug. > FWIW, the selinux-testsuite tests ran clean today with v5.15-rc1 (it > looks like this code is only in v5.15) but as Casey said, a regression > is a regression. > > Casey, what actually fails on the Smack system with this commit? This problem occurs with security=none as well as with security=smack. There isn't a problem with connect, that always works correctly. The problem is an unexpected read() failure in the connecting process. This doesn't occur all the time, and sometimes happens in the first of my two tests, sometimes the second, sometimes neither and, you guessed it, sometimes both. Here's a sample socat log demonstrating the problem. The first run, ending at "uds-access RC=0" behaves as expected. The second, ending at "uds-access RC=1", demonstrates the read failure. This case was run with Smack enabled, but I see the same problem with the same unpredictability on the same kernel with security=none. I've tried to convince myself that there's a flaw in the way I've set up the scripts. They've been pretty robust and I've never seen socat behaving erratically before. I've instrumented the kernel code and all the security checks are behaving as expected. Plus, as I mentioned above, the problem also occurs without an LSM. 2021/09/15 08:49:50 socat[2215] D getpid() 2021/09/15 08:49:50 socat[2215] D getpid() -> 2215 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PID", "2215", 1) 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PPID", "2215", 1) 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 2021/09/15 08:49:50 socat[2215] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org 2021/09/15 08:49:50 socat[2215] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) 2021/09/15 08:49:50 socat[2215] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) 2021/09/15 08:49:50 socat[2215] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_VERSION", "1.7.4.1", 1) 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 2021/09/15 08:49:50 socat[2215] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 2021/09/15 08:49:50 socat[2215] D argv[0]: "socat" 2021/09/15 08:49:50 socat[2215] D argv[1]: "-d" 2021/09/15 08:49:50 socat[2215] D argv[2]: "-d" 2021/09/15 08:49:50 socat[2215] D argv[3]: "-d" 2021/09/15 08:49:50 socat[2215] D argv[4]: "-d" 2021/09/15 08:49:50 socat[2215] D argv[5]: "-" 2021/09/15 08:49:50 socat[2215] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" 2021/09/15 08:49:50 socat[2215] D sigaction(1, 0x7fffaec50b50, 0x0) 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 2021/09/15 08:49:50 socat[2215] D sigaction(2, 0x7fffaec50b50, 0x0) 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 2021/09/15 08:49:50 socat[2215] D sigaction(3, 0x7fffaec50b50, 0x0) 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 2021/09/15 08:49:50 socat[2215] D sigaction(4, 0x7fffaec50b50, 0x0) 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 2021/09/15 08:49:50 socat[2215] D sigaction(6, 0x7fffaec50b50, 0x0) 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 2021/09/15 08:49:50 socat[2215] D sigaction(7, 0x7fffaec50b50, 0x0) 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 2021/09/15 08:49:50 socat[2215] D sigaction(8, 0x7fffaec50b50, 0x0) 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 2021/09/15 08:49:50 socat[2215] D sigaction(11, 0x7fffaec50b50, 0x0) 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 2021/09/15 08:49:50 socat[2215] D sigaction(15, 0x7fffaec50b50, 0x0) 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 2021/09/15 08:49:50 socat[2215] D signal(13, 0x1) 2021/09/15 08:49:50 socat[2215] D signal() -> 0x0 2021/09/15 08:49:50 socat[2215] D atexit(0x55aa5d645110) 2021/09/15 08:49:50 socat[2215] D atexit() -> 0 2021/09/15 08:49:50 socat[2215] D xioopen("-") 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f0139d0 2021/09/15 08:49:50 socat[2215] D malloc(1024) 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f013d30 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014140 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014bc0 2021/09/15 08:49:50 socat[2215] D isatty(0) 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 2021/09/15 08:49:50 socat[2215] D isatty(1) 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 2021/09/15 08:49:50 socat[2215] D malloc(128) 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f00 2021/09/15 08:49:50 socat[2215] D malloc(128) 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f90 2021/09/15 08:49:50 socat[2215] N reading from and writing to stdio 2021/09/15 08:49:50 socat[2215] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f015020 2021/09/15 08:49:50 socat[2215] D malloc(1024) 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015360 2021/09/15 08:49:50 socat[2215] D malloc(128) 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015770 2021/09/15 08:49:50 socat[2215] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" 2021/09/15 08:49:50 socat[2215] D socket(1, 1, 0) 2021/09/15 08:49:50 socat[2215] I socket(1, 1, 0) -> 5 2021/09/15 08:49:50 socat[2215] D fcntl(5, 2, 1) 2021/09/15 08:49:50 socat[2215] D fcntl() -> 0 2021/09/15 08:49:50 socat[2215] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) 2021/09/15 08:49:50 socat[2215] D connect() -> 0 2021/09/15 08:49:50 socat[2215] D getsockname(5, 0x7fffaec50580, 0x7fffaec50564{112}) 2021/09/15 08:49:50 socat[2215] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 2021/09/15 08:49:50 socat[2215] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" 2021/09/15 08:49:50 socat[2215] I resolved and opened all sock addresses 2021/09/15 08:49:50 socat[2215] D posix_memalign(0x7fffaec50b28, 4096, 16385) 2021/09/15 08:49:50 socat[2215] D posix_memalign(...) -> 0 2021/09/15 08:49:50 socat[2215] N starting data transfer loop with FDs [0,1] and [5,5] 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) 2021/09/15 08:49:50 socat[2215] D read -> 4 2021/09/15 08:49:50 socat[2215] D write(5, 0x55aa5f016000, 4) Pop 2021/09/15 08:49:50 socat[2215] D write -> 4 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 0 to 5 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) 2021/09/15 08:49:50 socat[2215] D read -> 4 2021/09/15 08:49:50 socat[2215] D write(1, 0x55aa5f016000, 4) Pop 2021/09/15 08:49:50 socat[2215] D write -> 4 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 5 to 1 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) 2021/09/15 08:49:50 socat[2215] D read -> 0 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) 2021/09/15 08:49:50 socat[2215] D read -> 0 2021/09/15 08:49:50 socat[2215] N socket 1 (fd 0) is at EOF 2021/09/15 08:49:50 socat[2215] I shutdown(5, 1) 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 2021/09/15 08:49:50 socat[2215] N socket 2 (fd 5) is at EOF 2021/09/15 08:49:50 socat[2215] I shutdown(5, 2) 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 2021/09/15 08:49:50 socat[2215] N exiting with status 0 2021/09/15 08:49:50 socat[2215] D exit(0) 2021/09/15 08:49:50 socat[2215] D starting xioexit() 2021/09/15 08:49:50 socat[2215] D finished xioexit() uds-access RC=0 2021/09/15 08:49:52 socat[2240] D getpid() 2021/09/15 08:49:52 socat[2240] D getpid() -> 2240 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PID", "2240", 1) 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PPID", "2240", 1) 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 2021/09/15 08:49:52 socat[2240] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org 2021/09/15 08:49:52 socat[2240] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) 2021/09/15 08:49:52 socat[2240] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) 2021/09/15 08:49:52 socat[2240] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_VERSION", "1.7.4.1", 1) 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 2021/09/15 08:49:52 socat[2240] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 2021/09/15 08:49:52 socat[2240] D argv[0]: "socat" 2021/09/15 08:49:52 socat[2240] D argv[1]: "-d" 2021/09/15 08:49:52 socat[2240] D argv[2]: "-d" 2021/09/15 08:49:52 socat[2240] D argv[3]: "-d" 2021/09/15 08:49:52 socat[2240] D argv[4]: "-d" 2021/09/15 08:49:52 socat[2240] D argv[5]: "-" 2021/09/15 08:49:52 socat[2240] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" 2021/09/15 08:49:52 socat[2240] D sigaction(1, 0x7ffcca7e26c0, 0x0) 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 2021/09/15 08:49:52 socat[2240] D sigaction(2, 0x7ffcca7e26c0, 0x0) 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 2021/09/15 08:49:52 socat[2240] D sigaction(3, 0x7ffcca7e26c0, 0x0) 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 2021/09/15 08:49:52 socat[2240] D sigaction(4, 0x7ffcca7e26c0, 0x0) 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 2021/09/15 08:49:52 socat[2240] D sigaction(6, 0x7ffcca7e26c0, 0x0) 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 2021/09/15 08:49:52 socat[2240] D sigaction(7, 0x7ffcca7e26c0, 0x0) 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 2021/09/15 08:49:52 socat[2240] D sigaction(8, 0x7ffcca7e26c0, 0x0) 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 2021/09/15 08:49:52 socat[2240] D sigaction(11, 0x7ffcca7e26c0, 0x0) 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 2021/09/15 08:49:52 socat[2240] D sigaction(15, 0x7ffcca7e26c0, 0x0) 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 2021/09/15 08:49:52 socat[2240] D signal(13, 0x1) 2021/09/15 08:49:52 socat[2240] D signal() -> 0x0 2021/09/15 08:49:52 socat[2240] D atexit(0x560590a15110) 2021/09/15 08:49:52 socat[2240] D atexit() -> 0 2021/09/15 08:49:52 socat[2240] D xioopen("-") 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e899d0 2021/09/15 08:49:52 socat[2240] D malloc(1024) 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e89d30 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8a140 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8abc0 2021/09/15 08:49:52 socat[2240] D isatty(0) 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 2021/09/15 08:49:52 socat[2240] D isatty(1) 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 2021/09/15 08:49:52 socat[2240] D malloc(128) 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af00 2021/09/15 08:49:52 socat[2240] D malloc(128) 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af90 2021/09/15 08:49:52 socat[2240] N reading from and writing to stdio 2021/09/15 08:49:52 socat[2240] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8b020 2021/09/15 08:49:52 socat[2240] D malloc(1024) 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b360 2021/09/15 08:49:52 socat[2240] D malloc(128) 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b770 2021/09/15 08:49:52 socat[2240] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" 2021/09/15 08:49:52 socat[2240] D socket(1, 1, 0) 2021/09/15 08:49:52 socat[2240] I socket(1, 1, 0) -> 5 2021/09/15 08:49:52 socat[2240] D fcntl(5, 2, 1) 2021/09/15 08:49:52 socat[2240] D fcntl() -> 0 2021/09/15 08:49:52 socat[2240] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) 2021/09/15 08:49:52 socat[2240] D connect() -> 0 2021/09/15 08:49:52 socat[2240] D getsockname(5, 0x7ffcca7e20f0, 0x7ffcca7e20d4{112}) 2021/09/15 08:49:52 socat[2240] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 2021/09/15 08:49:52 socat[2240] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" 2021/09/15 08:49:52 socat[2240] I resolved and opened all sock addresses 2021/09/15 08:49:52 socat[2240] D posix_memalign(0x7ffcca7e2698, 4096, 16385) 2021/09/15 08:49:52 socat[2240] D posix_memalign(...) -> 0 2021/09/15 08:49:52 socat[2240] N starting data transfer loop with FDs [0,1] and [5,5] 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x22, 0x0, NULL/0.000000), 3 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) 2021/09/15 08:49:52 socat[2240] D read -> 5 2021/09/15 08:49:52 socat[2240] D write(5, 0x560591e8c000, 5) 2021/09/15 08:49:52 socat[2240] D write -> 5 2021/09/15 08:49:52 socat[2240] I transferred 5 bytes from 0 to 5 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x20, &0x0, NULL/0.000000) 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x20, 0x0, NULL/0.000000), 2 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) 2021/09/15 08:49:52 socat[2240] D read -> 0 2021/09/15 08:49:52 socat[2240] N socket 1 (fd 0) is at EOF 2021/09/15 08:49:52 socat[2240] I shutdown(5, 1) 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=3, sock2->eof=0, closing=1, wasaction=1, total_to={0.000000} 2021/09/15 08:49:52 socat[2240] D select(6, &0x20, &0x0, &0x0, &0.500000) Snap 2021/09/15 08:49:52 socat[2240] D select -> (, 0x20, 0x0, 0x0, &0.500000), 1 2021/09/15 08:49:52 socat[2240] D read(5, 0x560591e8c000, 8192) 2021/09/15 08:49:52 socat[2240] D read -> -1 2021/09/15 08:49:52 socat[2240] E read(5, 0x560591e8c000, 8192): Invalid argument 2021/09/15 08:49:52 socat[2240] N exit(1) 2021/09/15 08:49:52 socat[2240] D starting xioexit() 2021/09/15 08:49:52 socat[2240] I shutdown(5, 2) 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 2021/09/15 08:49:52 socat[2240] D finished xioexit() uds-access RC=1 ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Re: Regression in unix stream sockets with the Smack LSM 2021-09-15 16:51 ` Casey Schaufler @ 2021-09-15 17:29 ` Jiang Wang . 2021-09-20 22:35 ` Jiang Wang . 1 sibling, 0 replies; 10+ messages in thread From: Jiang Wang . @ 2021-09-15 17:29 UTC (permalink / raw) To: Casey Schaufler Cc: Paul Moore, Andrii Nakryiko, Jakub Sitnicki, John Fastabend, LKML, Linux Security Module list, netdev Hi Casey, Thanks for the detailed report. I will check what causes the read to fail. Regards, Jiang On Wed, Sep 15, 2021 at 9:52 AM Casey Schaufler <casey@schaufler-ca.com> wrote: > > On 9/13/2021 4:47 PM, Paul Moore wrote: > > On Mon, Sep 13, 2021 at 6:53 PM Casey Schaufler <casey@schaufler-ca.com> wrote: > >> Commit 77462de14a43f4d98dbd8de0f5743a4e02450b1d > >> > >> af_unix: Add read_sock for stream socket types > >> > >> introduced a regression in UDS socket connections for the Smack LSM. > >> I have not tracked done the details of why the change broke the code, > >> but this is where bisecting the kernel indicates the problem lies, and > >> I have verified that reverting this change repairs the problem. > >> > >> You can verify the problem with the Smack test suite: > >> > >> https://github.com/smack-team/smack-testsuite.git > >> > >> The failing test is tests/uds-access.sh. > >> > >> I have not looked to see if there's a similar problem with SELinux. > >> There may be, but if there isn't it doesn't matter, there's still a > >> bug. > > FWIW, the selinux-testsuite tests ran clean today with v5.15-rc1 (it > > looks like this code is only in v5.15) but as Casey said, a regression > > is a regression. > > > > Casey, what actually fails on the Smack system with this commit? > > This problem occurs with security=none as well as with security=smack. > > There isn't a problem with connect, that always works correctly. > The problem is an unexpected read() failure in the connecting process. > This doesn't occur all the time, and sometimes happens in the first > of my two tests, sometimes the second, sometimes neither and, you guessed > it, sometimes both. > > Here's a sample socat log demonstrating the problem. The first run, > ending at "uds-access RC=0" behaves as expected. The second, ending > at "uds-access RC=1", demonstrates the read failure. This case was > run with Smack enabled, but I see the same problem with the same > unpredictability on the same kernel with security=none. > > I've tried to convince myself that there's a flaw in the way I've > set up the scripts. They've been pretty robust and I've never seen > socat behaving erratically before. I've instrumented the kernel > code and all the security checks are behaving as expected. Plus, > as I mentioned above, the problem also occurs without an LSM. > > 2021/09/15 08:49:50 socat[2215] D getpid() > 2021/09/15 08:49:50 socat[2215] D getpid() -> 2215 > 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PID", "2215", 1) > 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 > 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PPID", "2215", 1) > 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 > 2021/09/15 08:49:50 socat[2215] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org > 2021/09/15 08:49:50 socat[2215] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) > 2021/09/15 08:49:50 socat[2215] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) > 2021/09/15 08:49:50 socat[2215] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 > 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_VERSION", "1.7.4.1", 1) > 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 > 2021/09/15 08:49:50 socat[2215] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 > > 2021/09/15 08:49:50 socat[2215] D argv[0]: "socat" > 2021/09/15 08:49:50 socat[2215] D argv[1]: "-d" > 2021/09/15 08:49:50 socat[2215] D argv[2]: "-d" > 2021/09/15 08:49:50 socat[2215] D argv[3]: "-d" > 2021/09/15 08:49:50 socat[2215] D argv[4]: "-d" > 2021/09/15 08:49:50 socat[2215] D argv[5]: "-" > 2021/09/15 08:49:50 socat[2215] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" > 2021/09/15 08:49:50 socat[2215] D sigaction(1, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(2, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(3, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(4, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(6, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(7, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(8, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(11, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(15, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D signal(13, 0x1) > 2021/09/15 08:49:50 socat[2215] D signal() -> 0x0 > 2021/09/15 08:49:50 socat[2215] D atexit(0x55aa5d645110) > 2021/09/15 08:49:50 socat[2215] D atexit() -> 0 > 2021/09/15 08:49:50 socat[2215] D xioopen("-") > 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f0139d0 > 2021/09/15 08:49:50 socat[2215] D malloc(1024) > 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f013d30 > 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014140 > 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014bc0 > 2021/09/15 08:49:50 socat[2215] D isatty(0) > 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 > 2021/09/15 08:49:50 socat[2215] D isatty(1) > 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 > 2021/09/15 08:49:50 socat[2215] D malloc(128) > 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f00 > 2021/09/15 08:49:50 socat[2215] D malloc(128) > 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f90 > 2021/09/15 08:49:50 socat[2215] N reading from and writing to stdio > 2021/09/15 08:49:50 socat[2215] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") > 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f015020 > 2021/09/15 08:49:50 socat[2215] D malloc(1024) > 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015360 > 2021/09/15 08:49:50 socat[2215] D malloc(128) > 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015770 > 2021/09/15 08:49:50 socat[2215] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" > 2021/09/15 08:49:50 socat[2215] D socket(1, 1, 0) > 2021/09/15 08:49:50 socat[2215] I socket(1, 1, 0) -> 5 > 2021/09/15 08:49:50 socat[2215] D fcntl(5, 2, 1) > 2021/09/15 08:49:50 socat[2215] D fcntl() -> 0 > 2021/09/15 08:49:50 socat[2215] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) > 2021/09/15 08:49:50 socat[2215] D connect() -> 0 > 2021/09/15 08:49:50 socat[2215] D getsockname(5, 0x7fffaec50580, 0x7fffaec50564{112}) > 2021/09/15 08:49:50 socat[2215] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 > 2021/09/15 08:49:50 socat[2215] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" > 2021/09/15 08:49:50 socat[2215] I resolved and opened all sock addresses > 2021/09/15 08:49:50 socat[2215] D posix_memalign(0x7fffaec50b28, 4096, 16385) > 2021/09/15 08:49:50 socat[2215] D posix_memalign(...) -> 0 > 2021/09/15 08:49:50 socat[2215] N starting data transfer loop with FDs [0,1] and [5,5] > 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) > 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 > 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) > 2021/09/15 08:49:50 socat[2215] D read -> 4 > 2021/09/15 08:49:50 socat[2215] D write(5, 0x55aa5f016000, 4) > Pop > 2021/09/15 08:49:50 socat[2215] D write -> 4 > 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 0 to 5 > 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) > 2021/09/15 08:49:50 socat[2215] D read -> 4 > 2021/09/15 08:49:50 socat[2215] D write(1, 0x55aa5f016000, 4) > Pop > 2021/09/15 08:49:50 socat[2215] D write -> 4 > 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 5 to 1 > 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) > 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 > 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) > 2021/09/15 08:49:50 socat[2215] D read -> 0 > 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) > 2021/09/15 08:49:50 socat[2215] D read -> 0 > 2021/09/15 08:49:50 socat[2215] N socket 1 (fd 0) is at EOF > 2021/09/15 08:49:50 socat[2215] I shutdown(5, 1) > 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 > 2021/09/15 08:49:50 socat[2215] N socket 2 (fd 5) is at EOF > 2021/09/15 08:49:50 socat[2215] I shutdown(5, 2) > 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 > 2021/09/15 08:49:50 socat[2215] N exiting with status 0 > 2021/09/15 08:49:50 socat[2215] D exit(0) > 2021/09/15 08:49:50 socat[2215] D starting xioexit() > 2021/09/15 08:49:50 socat[2215] D finished xioexit() > uds-access RC=0 > 2021/09/15 08:49:52 socat[2240] D getpid() > 2021/09/15 08:49:52 socat[2240] D getpid() -> 2240 > 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PID", "2240", 1) > 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 > 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PPID", "2240", 1) > 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 > 2021/09/15 08:49:52 socat[2240] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org > 2021/09/15 08:49:52 socat[2240] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) > 2021/09/15 08:49:52 socat[2240] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) > 2021/09/15 08:49:52 socat[2240] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 > 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_VERSION", "1.7.4.1", 1) > 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 > 2021/09/15 08:49:52 socat[2240] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 > > 2021/09/15 08:49:52 socat[2240] D argv[0]: "socat" > 2021/09/15 08:49:52 socat[2240] D argv[1]: "-d" > 2021/09/15 08:49:52 socat[2240] D argv[2]: "-d" > 2021/09/15 08:49:52 socat[2240] D argv[3]: "-d" > 2021/09/15 08:49:52 socat[2240] D argv[4]: "-d" > 2021/09/15 08:49:52 socat[2240] D argv[5]: "-" > 2021/09/15 08:49:52 socat[2240] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" > 2021/09/15 08:49:52 socat[2240] D sigaction(1, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(2, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(3, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(4, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(6, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(7, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(8, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(11, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(15, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D signal(13, 0x1) > 2021/09/15 08:49:52 socat[2240] D signal() -> 0x0 > 2021/09/15 08:49:52 socat[2240] D atexit(0x560590a15110) > 2021/09/15 08:49:52 socat[2240] D atexit() -> 0 > 2021/09/15 08:49:52 socat[2240] D xioopen("-") > 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e899d0 > 2021/09/15 08:49:52 socat[2240] D malloc(1024) > 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e89d30 > 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8a140 > 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8abc0 > 2021/09/15 08:49:52 socat[2240] D isatty(0) > 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 > 2021/09/15 08:49:52 socat[2240] D isatty(1) > 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 > 2021/09/15 08:49:52 socat[2240] D malloc(128) > 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af00 > 2021/09/15 08:49:52 socat[2240] D malloc(128) > 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af90 > 2021/09/15 08:49:52 socat[2240] N reading from and writing to stdio > 2021/09/15 08:49:52 socat[2240] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") > 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8b020 > 2021/09/15 08:49:52 socat[2240] D malloc(1024) > 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b360 > 2021/09/15 08:49:52 socat[2240] D malloc(128) > 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b770 > 2021/09/15 08:49:52 socat[2240] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" > 2021/09/15 08:49:52 socat[2240] D socket(1, 1, 0) > 2021/09/15 08:49:52 socat[2240] I socket(1, 1, 0) -> 5 > 2021/09/15 08:49:52 socat[2240] D fcntl(5, 2, 1) > 2021/09/15 08:49:52 socat[2240] D fcntl() -> 0 > 2021/09/15 08:49:52 socat[2240] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) > 2021/09/15 08:49:52 socat[2240] D connect() -> 0 > 2021/09/15 08:49:52 socat[2240] D getsockname(5, 0x7ffcca7e20f0, 0x7ffcca7e20d4{112}) > 2021/09/15 08:49:52 socat[2240] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 > 2021/09/15 08:49:52 socat[2240] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" > 2021/09/15 08:49:52 socat[2240] I resolved and opened all sock addresses > 2021/09/15 08:49:52 socat[2240] D posix_memalign(0x7ffcca7e2698, 4096, 16385) > 2021/09/15 08:49:52 socat[2240] D posix_memalign(...) -> 0 > 2021/09/15 08:49:52 socat[2240] N starting data transfer loop with FDs [0,1] and [5,5] > 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) > 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x22, 0x0, NULL/0.000000), 3 > 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) > 2021/09/15 08:49:52 socat[2240] D read -> 5 > 2021/09/15 08:49:52 socat[2240] D write(5, 0x560591e8c000, 5) > 2021/09/15 08:49:52 socat[2240] D write -> 5 > 2021/09/15 08:49:52 socat[2240] I transferred 5 bytes from 0 to 5 > 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x20, &0x0, NULL/0.000000) > 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x20, 0x0, NULL/0.000000), 2 > 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) > 2021/09/15 08:49:52 socat[2240] D read -> 0 > 2021/09/15 08:49:52 socat[2240] N socket 1 (fd 0) is at EOF > 2021/09/15 08:49:52 socat[2240] I shutdown(5, 1) > 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 > 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=3, sock2->eof=0, closing=1, wasaction=1, total_to={0.000000} > 2021/09/15 08:49:52 socat[2240] D select(6, &0x20, &0x0, &0x0, &0.500000) > Snap > 2021/09/15 08:49:52 socat[2240] D select -> (, 0x20, 0x0, 0x0, &0.500000), 1 > 2021/09/15 08:49:52 socat[2240] D read(5, 0x560591e8c000, 8192) > 2021/09/15 08:49:52 socat[2240] D read -> -1 > 2021/09/15 08:49:52 socat[2240] E read(5, 0x560591e8c000, 8192): Invalid argument > 2021/09/15 08:49:52 socat[2240] N exit(1) > 2021/09/15 08:49:52 socat[2240] D starting xioexit() > 2021/09/15 08:49:52 socat[2240] I shutdown(5, 2) > 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 > 2021/09/15 08:49:52 socat[2240] D finished xioexit() > uds-access RC=1 > > > > ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Re: Regression in unix stream sockets with the Smack LSM 2021-09-15 16:51 ` Casey Schaufler 2021-09-15 17:29 ` Jiang Wang . @ 2021-09-20 22:35 ` Jiang Wang . 2021-09-20 23:44 ` Casey Schaufler 1 sibling, 1 reply; 10+ messages in thread From: Jiang Wang . @ 2021-09-20 22:35 UTC (permalink / raw) To: Casey Schaufler Cc: Paul Moore, Andrii Nakryiko, Jakub Sitnicki, John Fastabend, LKML, Linux Security Module list, netdev On Wed, Sep 15, 2021 at 9:52 AM Casey Schaufler <casey@schaufler-ca.com> wrote: > > On 9/13/2021 4:47 PM, Paul Moore wrote: > > On Mon, Sep 13, 2021 at 6:53 PM Casey Schaufler <casey@schaufler-ca.com> wrote: > >> Commit 77462de14a43f4d98dbd8de0f5743a4e02450b1d > >> > >> af_unix: Add read_sock for stream socket types > >> > >> introduced a regression in UDS socket connections for the Smack LSM. > >> I have not tracked done the details of why the change broke the code, > >> but this is where bisecting the kernel indicates the problem lies, and > >> I have verified that reverting this change repairs the problem. > >> > >> You can verify the problem with the Smack test suite: > >> > >> https://github.com/smack-team/smack-testsuite.git > >> > >> The failing test is tests/uds-access.sh. > >> I tried to reproduce with tests/uds-access.sh, but the first two test cases always failed. I tried different kernels with and without my unix-stream sockmap patches. Also tried standard debian 4.19 kernel and they all have the same result. What distro did you use? centos? Fedora? Have you tested on debian based distros? failing log: root@gitlab-runner-stretch:~/smack-testsuite# tests/uds-access.sh -v mkdir: cannot create directory ‘./targets/uds-notroot’: File exists tests/uds-access.sh:71 FAIL tests/uds-access.sh:76 FAIL tests/uds-access.sh:81 PASS tests/uds-access.sh:86 PASS tests/uds-access.sh:91 PASS tests/uds-access.sh PASS=3 FAIL=2 root@gitlab-runner-stretch:~/smack-testsuite# uname -a Linux gitlab-runner-stretch 5.14.0-rc5.bm.1-amd64+ #6 SMP Mon Sep 20 22:01:10 UTC 2021 x86_64 GNU/Linux root@gitlab-runner-stretch:~/smack-testsuite# > >> I have not looked to see if there's a similar problem with SELinux. > >> There may be, but if there isn't it doesn't matter, there's still a > >> bug. > > FWIW, the selinux-testsuite tests ran clean today with v5.15-rc1 (it > > looks like this code is only in v5.15) but as Casey said, a regression > > is a regression. > > > > Casey, what actually fails on the Smack system with this commit? > > This problem occurs with security=none as well as with security=smack. > > There isn't a problem with connect, that always works correctly. > The problem is an unexpected read() failure in the connecting process. > This doesn't occur all the time, and sometimes happens in the first > of my two tests, sometimes the second, sometimes neither and, you guessed > it, sometimes both. > > Here's a sample socat log demonstrating the problem. The first run, > ending at "uds-access RC=0" behaves as expected. The second, ending > at "uds-access RC=1", demonstrates the read failure. This case was I tried to compare logs between RC=0 and RC=1, but they look to me not apple to apple comparison? The read syscall have different parameters and the syscall sequences are different. I am not sure which syscall is the first failure. See more comments below. > run with Smack enabled, but I see the same problem with the same > unpredictability on the same kernel with security=none. > > I've tried to convince myself that there's a flaw in the way I've > set up the scripts. They've been pretty robust and I've never seen > socat behaving erratically before. I've instrumented the kernel > code and all the security checks are behaving as expected. Plus, > as I mentioned above, the problem also occurs without an LSM. > > 2021/09/15 08:49:50 socat[2215] D getpid() > 2021/09/15 08:49:50 socat[2215] D getpid() -> 2215 > 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PID", "2215", 1) > 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 > 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PPID", "2215", 1) > 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 > 2021/09/15 08:49:50 socat[2215] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org > 2021/09/15 08:49:50 socat[2215] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) > 2021/09/15 08:49:50 socat[2215] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) > 2021/09/15 08:49:50 socat[2215] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 > 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_VERSION", "1.7.4.1", 1) > 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 > 2021/09/15 08:49:50 socat[2215] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 > > 2021/09/15 08:49:50 socat[2215] D argv[0]: "socat" > 2021/09/15 08:49:50 socat[2215] D argv[1]: "-d" > 2021/09/15 08:49:50 socat[2215] D argv[2]: "-d" > 2021/09/15 08:49:50 socat[2215] D argv[3]: "-d" > 2021/09/15 08:49:50 socat[2215] D argv[4]: "-d" > 2021/09/15 08:49:50 socat[2215] D argv[5]: "-" > 2021/09/15 08:49:50 socat[2215] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" > 2021/09/15 08:49:50 socat[2215] D sigaction(1, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(2, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(3, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(4, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(6, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(7, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(8, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(11, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D sigaction(15, 0x7fffaec50b50, 0x0) > 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > 2021/09/15 08:49:50 socat[2215] D signal(13, 0x1) > 2021/09/15 08:49:50 socat[2215] D signal() -> 0x0 > 2021/09/15 08:49:50 socat[2215] D atexit(0x55aa5d645110) > 2021/09/15 08:49:50 socat[2215] D atexit() -> 0 > 2021/09/15 08:49:50 socat[2215] D xioopen("-") > 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f0139d0 > 2021/09/15 08:49:50 socat[2215] D malloc(1024) > 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f013d30 > 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014140 > 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014bc0 > 2021/09/15 08:49:50 socat[2215] D isatty(0) > 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 > 2021/09/15 08:49:50 socat[2215] D isatty(1) > 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 > 2021/09/15 08:49:50 socat[2215] D malloc(128) > 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f00 > 2021/09/15 08:49:50 socat[2215] D malloc(128) > 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f90 > 2021/09/15 08:49:50 socat[2215] N reading from and writing to stdio > 2021/09/15 08:49:50 socat[2215] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") > 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f015020 > 2021/09/15 08:49:50 socat[2215] D malloc(1024) > 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015360 > 2021/09/15 08:49:50 socat[2215] D malloc(128) > 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015770 > 2021/09/15 08:49:50 socat[2215] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" > 2021/09/15 08:49:50 socat[2215] D socket(1, 1, 0) > 2021/09/15 08:49:50 socat[2215] I socket(1, 1, 0) -> 5 > 2021/09/15 08:49:50 socat[2215] D fcntl(5, 2, 1) > 2021/09/15 08:49:50 socat[2215] D fcntl() -> 0 > 2021/09/15 08:49:50 socat[2215] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) > 2021/09/15 08:49:50 socat[2215] D connect() -> 0 > 2021/09/15 08:49:50 socat[2215] D getsockname(5, 0x7fffaec50580, 0x7fffaec50564{112}) > 2021/09/15 08:49:50 socat[2215] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 > 2021/09/15 08:49:50 socat[2215] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" > 2021/09/15 08:49:50 socat[2215] I resolved and opened all sock addresses > 2021/09/15 08:49:50 socat[2215] D posix_memalign(0x7fffaec50b28, 4096, 16385) > 2021/09/15 08:49:50 socat[2215] D posix_memalign(...) -> 0 > 2021/09/15 08:49:50 socat[2215] N starting data transfer loop with FDs [0,1] and [5,5] > 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) > 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 > 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) > 2021/09/15 08:49:50 socat[2215] D read -> 4 > 2021/09/15 08:49:50 socat[2215] D write(5, 0x55aa5f016000, 4) > Pop > 2021/09/15 08:49:50 socat[2215] D write -> 4 > 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 0 to 5 > 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) > 2021/09/15 08:49:50 socat[2215] D read -> 4 > 2021/09/15 08:49:50 socat[2215] D write(1, 0x55aa5f016000, 4) > Pop > 2021/09/15 08:49:50 socat[2215] D write -> 4 > 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 5 to 1 > 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) > 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 > 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) > 2021/09/15 08:49:50 socat[2215] D read -> 0 > 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) > 2021/09/15 08:49:50 socat[2215] D read -> 0 > 2021/09/15 08:49:50 socat[2215] N socket 1 (fd 0) is at EOF > 2021/09/15 08:49:50 socat[2215] I shutdown(5, 1) > 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 > 2021/09/15 08:49:50 socat[2215] N socket 2 (fd 5) is at EOF > 2021/09/15 08:49:50 socat[2215] I shutdown(5, 2) > 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 > 2021/09/15 08:49:50 socat[2215] N exiting with status 0 > 2021/09/15 08:49:50 socat[2215] D exit(0) > 2021/09/15 08:49:50 socat[2215] D starting xioexit() > 2021/09/15 08:49:50 socat[2215] D finished xioexit() > uds-access RC=0 > 2021/09/15 08:49:52 socat[2240] D getpid() > 2021/09/15 08:49:52 socat[2240] D getpid() -> 2240 > 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PID", "2240", 1) > 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 > 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PPID", "2240", 1) > 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 > 2021/09/15 08:49:52 socat[2240] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org > 2021/09/15 08:49:52 socat[2240] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) > 2021/09/15 08:49:52 socat[2240] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) > 2021/09/15 08:49:52 socat[2240] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 > 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_VERSION", "1.7.4.1", 1) > 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 > 2021/09/15 08:49:52 socat[2240] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 > > 2021/09/15 08:49:52 socat[2240] D argv[0]: "socat" > 2021/09/15 08:49:52 socat[2240] D argv[1]: "-d" > 2021/09/15 08:49:52 socat[2240] D argv[2]: "-d" > 2021/09/15 08:49:52 socat[2240] D argv[3]: "-d" > 2021/09/15 08:49:52 socat[2240] D argv[4]: "-d" > 2021/09/15 08:49:52 socat[2240] D argv[5]: "-" > 2021/09/15 08:49:52 socat[2240] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" > 2021/09/15 08:49:52 socat[2240] D sigaction(1, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(2, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(3, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(4, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(6, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(7, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(8, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(11, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D sigaction(15, 0x7ffcca7e26c0, 0x0) > 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > 2021/09/15 08:49:52 socat[2240] D signal(13, 0x1) > 2021/09/15 08:49:52 socat[2240] D signal() -> 0x0 > 2021/09/15 08:49:52 socat[2240] D atexit(0x560590a15110) > 2021/09/15 08:49:52 socat[2240] D atexit() -> 0 > 2021/09/15 08:49:52 socat[2240] D xioopen("-") > 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e899d0 > 2021/09/15 08:49:52 socat[2240] D malloc(1024) > 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e89d30 > 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8a140 > 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8abc0 > 2021/09/15 08:49:52 socat[2240] D isatty(0) > 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 > 2021/09/15 08:49:52 socat[2240] D isatty(1) > 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 > 2021/09/15 08:49:52 socat[2240] D malloc(128) > 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af00 > 2021/09/15 08:49:52 socat[2240] D malloc(128) > 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af90 > 2021/09/15 08:49:52 socat[2240] N reading from and writing to stdio > 2021/09/15 08:49:52 socat[2240] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") > 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8b020 > 2021/09/15 08:49:52 socat[2240] D malloc(1024) > 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b360 > 2021/09/15 08:49:52 socat[2240] D malloc(128) > 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b770 > 2021/09/15 08:49:52 socat[2240] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" > 2021/09/15 08:49:52 socat[2240] D socket(1, 1, 0) > 2021/09/15 08:49:52 socat[2240] I socket(1, 1, 0) -> 5 > 2021/09/15 08:49:52 socat[2240] D fcntl(5, 2, 1) > 2021/09/15 08:49:52 socat[2240] D fcntl() -> 0 > 2021/09/15 08:49:52 socat[2240] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) > 2021/09/15 08:49:52 socat[2240] D connect() -> 0 > 2021/09/15 08:49:52 socat[2240] D getsockname(5, 0x7ffcca7e20f0, 0x7ffcca7e20d4{112}) > 2021/09/15 08:49:52 socat[2240] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 > 2021/09/15 08:49:52 socat[2240] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" > 2021/09/15 08:49:52 socat[2240] I resolved and opened all sock addresses > 2021/09/15 08:49:52 socat[2240] D posix_memalign(0x7ffcca7e2698, 4096, 16385) > 2021/09/15 08:49:52 socat[2240] D posix_memalign(...) -> 0 > 2021/09/15 08:49:52 socat[2240] N starting data transfer loop with FDs [0,1] and [5,5] > 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) > 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x22, 0x0, NULL/0.000000), 3 > 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) > 2021/09/15 08:49:52 socat[2240] D read -> 5 > 2021/09/15 08:49:52 socat[2240] D write(5, 0x560591e8c000, 5) > 2021/09/15 08:49:52 socat[2240] D write -> 5 > 2021/09/15 08:49:52 socat[2240] I transferred 5 bytes from 0 to 5 > 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x20, &0x0, NULL/0.000000) > 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x20, 0x0, NULL/0.000000), 2 > 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) > 2021/09/15 08:49:52 socat[2240] D read -> 0 > 2021/09/15 08:49:52 socat[2240] N socket 1 (fd 0) is at EOF > 2021/09/15 08:49:52 socat[2240] I shutdown(5, 1) > 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 Is this shutdown expected? > 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=3, sock2->eof=0, closing=1, wasaction=1, total_to={0.000000} > 2021/09/15 08:49:52 socat[2240] D select(6, &0x20, &0x0, &0x0, &0.500000) > Snap > 2021/09/15 08:49:52 socat[2240] D select -> (, 0x20, 0x0, 0x0, &0.500000), 1 > 2021/09/15 08:49:52 socat[2240] D read(5, 0x560591e8c000, 8192) > 2021/09/15 08:49:52 socat[2240] D read -> -1 This read failure seems due to the previous shutdown, right? > 2021/09/15 08:49:52 socat[2240] E read(5, 0x560591e8c000, 8192): Invalid argument > 2021/09/15 08:49:52 socat[2240] N exit(1) > 2021/09/15 08:49:52 socat[2240] D starting xioexit() > 2021/09/15 08:49:52 socat[2240] I shutdown(5, 2) > 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 > 2021/09/15 08:49:52 socat[2240] D finished xioexit() > uds-access RC=1 > > > > ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Regression in unix stream sockets with the Smack LSM 2021-09-20 22:35 ` Jiang Wang . @ 2021-09-20 23:44 ` Casey Schaufler 2021-09-29 15:43 ` Casey Schaufler 0 siblings, 1 reply; 10+ messages in thread From: Casey Schaufler @ 2021-09-20 23:44 UTC (permalink / raw) To: Jiang Wang . Cc: Paul Moore, Andrii Nakryiko, Jakub Sitnicki, John Fastabend, LKML, Linux Security Module list, netdev, Casey Schaufler On 9/20/2021 3:35 PM, Jiang Wang . wrote: > On Wed, Sep 15, 2021 at 9:52 AM Casey Schaufler <casey@schaufler-ca.com> wrote: >> On 9/13/2021 4:47 PM, Paul Moore wrote: >>> On Mon, Sep 13, 2021 at 6:53 PM Casey Schaufler <casey@schaufler-ca.com> wrote: >>>> Commit 77462de14a43f4d98dbd8de0f5743a4e02450b1d >>>> >>>> af_unix: Add read_sock for stream socket types >>>> >>>> introduced a regression in UDS socket connections for the Smack LSM. >>>> I have not tracked done the details of why the change broke the code, >>>> but this is where bisecting the kernel indicates the problem lies, and >>>> I have verified that reverting this change repairs the problem. >>>> >>>> You can verify the problem with the Smack test suite: >>>> >>>> https://github.com/smack-team/smack-testsuite.git >>>> >>>> The failing test is tests/uds-access.sh. >>>> > I tried to reproduce with tests/uds-access.sh, but the first two test > cases always failed. That was my initial impression as well. However, when I started running the tests outside the routine "make test-results" I started observing that they succeeded irregularly. My biggest concern is that the test ever fails. The uds-access test has not failed in several releases. The erratic behavior just adds spice to the problem. > I tried different kernels with and without my > unix-stream sockmap patches. Also tried standard debian 4.19 > kernel and they all have the same result. What distro did you use? centos? > Fedora? I have been testing on Fedora32 and Fedora34. > Have you tested on debian based distros? Ubuntu 20.04.3 with a 5.15-rc1 kernel is exhibiting the same behavior. The Ubuntu system fails the test more regularly, but does succeed on occasion. > failing log: > root@gitlab-runner-stretch:~/smack-testsuite# tests/uds-access.sh -v # tools/clean-targets.sh # tests/uds-access.sh -v will remove the UDS filesystem entry before the test runs. > mkdir: cannot create directory ‘./targets/uds-notroot’: File exists > tests/uds-access.sh:71 FAIL > tests/uds-access.sh:76 FAIL > tests/uds-access.sh:81 PASS > tests/uds-access.sh:86 PASS > tests/uds-access.sh:91 PASS > tests/uds-access.sh PASS=3 FAIL=2 > root@gitlab-runner-stretch:~/smack-testsuite# uname -a > Linux gitlab-runner-stretch 5.14.0-rc5.bm.1-amd64+ #6 SMP Mon Sep 20 > 22:01:10 UTC 2021 x86_64 GNU/Linux > root@gitlab-runner-stretch:~/smack-testsuite# > >>>> I have not looked to see if there's a similar problem with SELinux. >>>> There may be, but if there isn't it doesn't matter, there's still a >>>> bug. >>> FWIW, the selinux-testsuite tests ran clean today with v5.15-rc1 (it >>> looks like this code is only in v5.15) but as Casey said, a regression >>> is a regression. >>> >>> Casey, what actually fails on the Smack system with this commit? >> This problem occurs with security=none as well as with security=smack. >> >> There isn't a problem with connect, that always works correctly. >> The problem is an unexpected read() failure in the connecting process. >> This doesn't occur all the time, and sometimes happens in the first >> of my two tests, sometimes the second, sometimes neither and, you guessed >> it, sometimes both. >> >> Here's a sample socat log demonstrating the problem. The first run, >> ending at "uds-access RC=0" behaves as expected. The second, ending >> at "uds-access RC=1", demonstrates the read failure. This case was > I tried to compare logs between RC=0 and RC=1, but they look to me > not apple to apple comparison? The read syscall have different parameters > and the syscall sequences are different. I am not sure which syscall > is the first failure. See more comments below. The data being feed to socat is the Smack label, so the data passed across the socket will be of different length ("Pop" vs. "Snap") between the two test cases, but that should be the only difference. >> run with Smack enabled, but I see the same problem with the same >> unpredictability on the same kernel with security=none. >> >> I've tried to convince myself that there's a flaw in the way I've >> set up the scripts. They've been pretty robust and I've never seen >> socat behaving erratically before. I've instrumented the kernel >> code and all the security checks are behaving as expected. Plus, >> as I mentioned above, the problem also occurs without an LSM. >> >> 2021/09/15 08:49:50 socat[2215] D getpid() >> 2021/09/15 08:49:50 socat[2215] D getpid() -> 2215 >> 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PID", "2215", 1) >> 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 >> 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PPID", "2215", 1) >> 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 >> 2021/09/15 08:49:50 socat[2215] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org >> 2021/09/15 08:49:50 socat[2215] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) >> 2021/09/15 08:49:50 socat[2215] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) >> 2021/09/15 08:49:50 socat[2215] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 >> 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_VERSION", "1.7.4.1", 1) >> 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 >> 2021/09/15 08:49:50 socat[2215] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 >> >> 2021/09/15 08:49:50 socat[2215] D argv[0]: "socat" >> 2021/09/15 08:49:50 socat[2215] D argv[1]: "-d" >> 2021/09/15 08:49:50 socat[2215] D argv[2]: "-d" >> 2021/09/15 08:49:50 socat[2215] D argv[3]: "-d" >> 2021/09/15 08:49:50 socat[2215] D argv[4]: "-d" >> 2021/09/15 08:49:50 socat[2215] D argv[5]: "-" >> 2021/09/15 08:49:50 socat[2215] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" >> 2021/09/15 08:49:50 socat[2215] D sigaction(1, 0x7fffaec50b50, 0x0) >> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >> 2021/09/15 08:49:50 socat[2215] D sigaction(2, 0x7fffaec50b50, 0x0) >> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >> 2021/09/15 08:49:50 socat[2215] D sigaction(3, 0x7fffaec50b50, 0x0) >> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >> 2021/09/15 08:49:50 socat[2215] D sigaction(4, 0x7fffaec50b50, 0x0) >> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >> 2021/09/15 08:49:50 socat[2215] D sigaction(6, 0x7fffaec50b50, 0x0) >> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >> 2021/09/15 08:49:50 socat[2215] D sigaction(7, 0x7fffaec50b50, 0x0) >> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >> 2021/09/15 08:49:50 socat[2215] D sigaction(8, 0x7fffaec50b50, 0x0) >> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >> 2021/09/15 08:49:50 socat[2215] D sigaction(11, 0x7fffaec50b50, 0x0) >> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >> 2021/09/15 08:49:50 socat[2215] D sigaction(15, 0x7fffaec50b50, 0x0) >> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >> 2021/09/15 08:49:50 socat[2215] D signal(13, 0x1) >> 2021/09/15 08:49:50 socat[2215] D signal() -> 0x0 >> 2021/09/15 08:49:50 socat[2215] D atexit(0x55aa5d645110) >> 2021/09/15 08:49:50 socat[2215] D atexit() -> 0 >> 2021/09/15 08:49:50 socat[2215] D xioopen("-") >> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) >> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f0139d0 >> 2021/09/15 08:49:50 socat[2215] D malloc(1024) >> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f013d30 >> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) >> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014140 >> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) >> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014bc0 >> 2021/09/15 08:49:50 socat[2215] D isatty(0) >> 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 >> 2021/09/15 08:49:50 socat[2215] D isatty(1) >> 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 >> 2021/09/15 08:49:50 socat[2215] D malloc(128) >> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f00 >> 2021/09/15 08:49:50 socat[2215] D malloc(128) >> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f90 >> 2021/09/15 08:49:50 socat[2215] N reading from and writing to stdio >> 2021/09/15 08:49:50 socat[2215] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") >> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) >> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f015020 >> 2021/09/15 08:49:50 socat[2215] D malloc(1024) >> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015360 >> 2021/09/15 08:49:50 socat[2215] D malloc(128) >> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015770 >> 2021/09/15 08:49:50 socat[2215] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" >> 2021/09/15 08:49:50 socat[2215] D socket(1, 1, 0) >> 2021/09/15 08:49:50 socat[2215] I socket(1, 1, 0) -> 5 >> 2021/09/15 08:49:50 socat[2215] D fcntl(5, 2, 1) >> 2021/09/15 08:49:50 socat[2215] D fcntl() -> 0 >> 2021/09/15 08:49:50 socat[2215] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) >> 2021/09/15 08:49:50 socat[2215] D connect() -> 0 >> 2021/09/15 08:49:50 socat[2215] D getsockname(5, 0x7fffaec50580, 0x7fffaec50564{112}) >> 2021/09/15 08:49:50 socat[2215] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 >> 2021/09/15 08:49:50 socat[2215] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" >> 2021/09/15 08:49:50 socat[2215] I resolved and opened all sock addresses >> 2021/09/15 08:49:50 socat[2215] D posix_memalign(0x7fffaec50b28, 4096, 16385) >> 2021/09/15 08:49:50 socat[2215] D posix_memalign(...) -> 0 >> 2021/09/15 08:49:50 socat[2215] N starting data transfer loop with FDs [0,1] and [5,5] >> 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} >> 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) >> 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 >> 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) >> 2021/09/15 08:49:50 socat[2215] D read -> 4 >> 2021/09/15 08:49:50 socat[2215] D write(5, 0x55aa5f016000, 4) >> Pop >> 2021/09/15 08:49:50 socat[2215] D write -> 4 >> 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 0 to 5 >> 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) >> 2021/09/15 08:49:50 socat[2215] D read -> 4 >> 2021/09/15 08:49:50 socat[2215] D write(1, 0x55aa5f016000, 4) >> Pop >> 2021/09/15 08:49:50 socat[2215] D write -> 4 >> 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 5 to 1 >> 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} >> 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) >> 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 >> 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) >> 2021/09/15 08:49:50 socat[2215] D read -> 0 >> 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) >> 2021/09/15 08:49:50 socat[2215] D read -> 0 >> 2021/09/15 08:49:50 socat[2215] N socket 1 (fd 0) is at EOF >> 2021/09/15 08:49:50 socat[2215] I shutdown(5, 1) >> 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 >> 2021/09/15 08:49:50 socat[2215] N socket 2 (fd 5) is at EOF >> 2021/09/15 08:49:50 socat[2215] I shutdown(5, 2) >> 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 >> 2021/09/15 08:49:50 socat[2215] N exiting with status 0 >> 2021/09/15 08:49:50 socat[2215] D exit(0) >> 2021/09/15 08:49:50 socat[2215] D starting xioexit() >> 2021/09/15 08:49:50 socat[2215] D finished xioexit() >> uds-access RC=0 >> 2021/09/15 08:49:52 socat[2240] D getpid() >> 2021/09/15 08:49:52 socat[2240] D getpid() -> 2240 >> 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PID", "2240", 1) >> 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 >> 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PPID", "2240", 1) >> 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 >> 2021/09/15 08:49:52 socat[2240] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org >> 2021/09/15 08:49:52 socat[2240] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) >> 2021/09/15 08:49:52 socat[2240] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) >> 2021/09/15 08:49:52 socat[2240] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 >> 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_VERSION", "1.7.4.1", 1) >> 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 >> 2021/09/15 08:49:52 socat[2240] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 >> >> 2021/09/15 08:49:52 socat[2240] D argv[0]: "socat" >> 2021/09/15 08:49:52 socat[2240] D argv[1]: "-d" >> 2021/09/15 08:49:52 socat[2240] D argv[2]: "-d" >> 2021/09/15 08:49:52 socat[2240] D argv[3]: "-d" >> 2021/09/15 08:49:52 socat[2240] D argv[4]: "-d" >> 2021/09/15 08:49:52 socat[2240] D argv[5]: "-" >> 2021/09/15 08:49:52 socat[2240] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" >> 2021/09/15 08:49:52 socat[2240] D sigaction(1, 0x7ffcca7e26c0, 0x0) >> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >> 2021/09/15 08:49:52 socat[2240] D sigaction(2, 0x7ffcca7e26c0, 0x0) >> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >> 2021/09/15 08:49:52 socat[2240] D sigaction(3, 0x7ffcca7e26c0, 0x0) >> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >> 2021/09/15 08:49:52 socat[2240] D sigaction(4, 0x7ffcca7e26c0, 0x0) >> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >> 2021/09/15 08:49:52 socat[2240] D sigaction(6, 0x7ffcca7e26c0, 0x0) >> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >> 2021/09/15 08:49:52 socat[2240] D sigaction(7, 0x7ffcca7e26c0, 0x0) >> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >> 2021/09/15 08:49:52 socat[2240] D sigaction(8, 0x7ffcca7e26c0, 0x0) >> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >> 2021/09/15 08:49:52 socat[2240] D sigaction(11, 0x7ffcca7e26c0, 0x0) >> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >> 2021/09/15 08:49:52 socat[2240] D sigaction(15, 0x7ffcca7e26c0, 0x0) >> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >> 2021/09/15 08:49:52 socat[2240] D signal(13, 0x1) >> 2021/09/15 08:49:52 socat[2240] D signal() -> 0x0 >> 2021/09/15 08:49:52 socat[2240] D atexit(0x560590a15110) >> 2021/09/15 08:49:52 socat[2240] D atexit() -> 0 >> 2021/09/15 08:49:52 socat[2240] D xioopen("-") >> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) >> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e899d0 >> 2021/09/15 08:49:52 socat[2240] D malloc(1024) >> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e89d30 >> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) >> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8a140 >> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) >> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8abc0 >> 2021/09/15 08:49:52 socat[2240] D isatty(0) >> 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 >> 2021/09/15 08:49:52 socat[2240] D isatty(1) >> 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 >> 2021/09/15 08:49:52 socat[2240] D malloc(128) >> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af00 >> 2021/09/15 08:49:52 socat[2240] D malloc(128) >> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af90 >> 2021/09/15 08:49:52 socat[2240] N reading from and writing to stdio >> 2021/09/15 08:49:52 socat[2240] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") >> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) >> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8b020 >> 2021/09/15 08:49:52 socat[2240] D malloc(1024) >> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b360 >> 2021/09/15 08:49:52 socat[2240] D malloc(128) >> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b770 >> 2021/09/15 08:49:52 socat[2240] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" >> 2021/09/15 08:49:52 socat[2240] D socket(1, 1, 0) >> 2021/09/15 08:49:52 socat[2240] I socket(1, 1, 0) -> 5 >> 2021/09/15 08:49:52 socat[2240] D fcntl(5, 2, 1) >> 2021/09/15 08:49:52 socat[2240] D fcntl() -> 0 >> 2021/09/15 08:49:52 socat[2240] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) >> 2021/09/15 08:49:52 socat[2240] D connect() -> 0 >> 2021/09/15 08:49:52 socat[2240] D getsockname(5, 0x7ffcca7e20f0, 0x7ffcca7e20d4{112}) >> 2021/09/15 08:49:52 socat[2240] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 >> 2021/09/15 08:49:52 socat[2240] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" >> 2021/09/15 08:49:52 socat[2240] I resolved and opened all sock addresses >> 2021/09/15 08:49:52 socat[2240] D posix_memalign(0x7ffcca7e2698, 4096, 16385) >> 2021/09/15 08:49:52 socat[2240] D posix_memalign(...) -> 0 >> 2021/09/15 08:49:52 socat[2240] N starting data transfer loop with FDs [0,1] and [5,5] >> 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} >> 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) >> 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x22, 0x0, NULL/0.000000), 3 >> 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) >> 2021/09/15 08:49:52 socat[2240] D read -> 5 >> 2021/09/15 08:49:52 socat[2240] D write(5, 0x560591e8c000, 5) >> 2021/09/15 08:49:52 socat[2240] D write -> 5 >> 2021/09/15 08:49:52 socat[2240] I transferred 5 bytes from 0 to 5 >> 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} >> 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x20, &0x0, NULL/0.000000) >> 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x20, 0x0, NULL/0.000000), 2 >> 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) >> 2021/09/15 08:49:52 socat[2240] D read -> 0 >> 2021/09/15 08:49:52 socat[2240] N socket 1 (fd 0) is at EOF >> 2021/09/15 08:49:52 socat[2240] I shutdown(5, 1) >> 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 > Is this shutdown expected? I'm not an expert on the internals of socat, but I don't think it is expected. > 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=3, sock2->eof=0, closing=1, wasaction=1, total_to={0.000000} > 2021/09/15 08:49:52 socat[2240] D select(6, &0x20, &0x0, &0x0, &0.500000) > Snap > 2021/09/15 08:49:52 socat[2240] D select -> (, 0x20, 0x0, 0x0, &0.500000), 1 > 2021/09/15 08:49:52 socat[2240] D read(5, 0x560591e8c000, 8192) > 2021/09/15 08:49:52 socat[2240] D read -> -1 > This read failure seems due to the previous shutdown, right? Again, I'm not the socat expert, but that would seem reasonable to me. >> 2021/09/15 08:49:52 socat[2240] E read(5, 0x560591e8c000, 8192): Invalid argument >> 2021/09/15 08:49:52 socat[2240] N exit(1) >> 2021/09/15 08:49:52 socat[2240] D starting xioexit() >> 2021/09/15 08:49:52 socat[2240] I shutdown(5, 2) >> 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 >> 2021/09/15 08:49:52 socat[2240] D finished xioexit() >> uds-access RC=1 >> >> >> >> ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Regression in unix stream sockets with the Smack LSM 2021-09-20 23:44 ` Casey Schaufler @ 2021-09-29 15:43 ` Casey Schaufler 2021-09-29 18:36 ` [External] " Jiang Wang . 0 siblings, 1 reply; 10+ messages in thread From: Casey Schaufler @ 2021-09-29 15:43 UTC (permalink / raw) To: Jiang Wang . Cc: Paul Moore, Andrii Nakryiko, Jakub Sitnicki, John Fastabend, LKML, Linux Security Module list, netdev, Casey Schaufler On 9/20/2021 4:44 PM, Casey Schaufler wrote: > On 9/20/2021 3:35 PM, Jiang Wang . wrote: >> On Wed, Sep 15, 2021 at 9:52 AM Casey Schaufler <casey@schaufler-ca.com> wrote: >>> On 9/13/2021 4:47 PM, Paul Moore wrote: >>>> On Mon, Sep 13, 2021 at 6:53 PM Casey Schaufler <casey@schaufler-ca.com> wrote: >>>>> Commit 77462de14a43f4d98dbd8de0f5743a4e02450b1d >>>>> >>>>> af_unix: Add read_sock for stream socket types >>>>> >>>>> introduced a regression in UDS socket connections for the Smack LSM. >>>>> I have not tracked done the details of why the change broke the code, >>>>> but this is where bisecting the kernel indicates the problem lies, and >>>>> I have verified that reverting this change repairs the problem. >>>>> >>>>> You can verify the problem with the Smack test suite: >>>>> >>>>> https://github.com/smack-team/smack-testsuite.git >>>>> >>>>> The failing test is tests/uds-access.sh. >>>>> >> I tried to reproduce with tests/uds-access.sh, but the first two test >> cases always failed. Just piping in that the behavior hasn't changed in 5.15-rc3. It still usually fails, with the occasional success. These tests used to succeed. > That was my initial impression as well. However, when I started > running the tests outside the routine "make test-results" I started > observing that they succeeded irregularly. > > My biggest concern is that the test ever fails. The uds-access test > has not failed in several releases. The erratic behavior just adds > spice to the problem. > >> I tried different kernels with and without my >> unix-stream sockmap patches. Also tried standard debian 4.19 >> kernel and they all have the same result. What distro did you use? centos? >> Fedora? > I have been testing on Fedora32 and Fedora34. > >> Have you tested on debian based distros? > Ubuntu 20.04.3 with a 5.15-rc1 kernel is exhibiting the same > behavior. The Ubuntu system fails the test more regularly, but > does succeed on occasion. > >> failing log: >> root@gitlab-runner-stretch:~/smack-testsuite# tests/uds-access.sh -v > # tools/clean-targets.sh > # tests/uds-access.sh -v > > will remove the UDS filesystem entry before the test runs. > > >> mkdir: cannot create directory ‘./targets/uds-notroot’: File exists >> tests/uds-access.sh:71 FAIL >> tests/uds-access.sh:76 FAIL >> tests/uds-access.sh:81 PASS >> tests/uds-access.sh:86 PASS >> tests/uds-access.sh:91 PASS >> tests/uds-access.sh PASS=3 FAIL=2 >> root@gitlab-runner-stretch:~/smack-testsuite# uname -a >> Linux gitlab-runner-stretch 5.14.0-rc5.bm.1-amd64+ #6 SMP Mon Sep 20 >> 22:01:10 UTC 2021 x86_64 GNU/Linux >> root@gitlab-runner-stretch:~/smack-testsuite# >> >>>>> I have not looked to see if there's a similar problem with SELinux. >>>>> There may be, but if there isn't it doesn't matter, there's still a >>>>> bug. >>>> FWIW, the selinux-testsuite tests ran clean today with v5.15-rc1 (it >>>> looks like this code is only in v5.15) but as Casey said, a regression >>>> is a regression. >>>> >>>> Casey, what actually fails on the Smack system with this commit? >>> This problem occurs with security=none as well as with security=smack. >>> >>> There isn't a problem with connect, that always works correctly. >>> The problem is an unexpected read() failure in the connecting process. >>> This doesn't occur all the time, and sometimes happens in the first >>> of my two tests, sometimes the second, sometimes neither and, you guessed >>> it, sometimes both. >>> >>> Here's a sample socat log demonstrating the problem. The first run, >>> ending at "uds-access RC=0" behaves as expected. The second, ending >>> at "uds-access RC=1", demonstrates the read failure. This case was >> I tried to compare logs between RC=0 and RC=1, but they look to me >> not apple to apple comparison? The read syscall have different parameters >> and the syscall sequences are different. I am not sure which syscall >> is the first failure. See more comments below. > The data being feed to socat is the Smack label, so the data passed across > the socket will be of different length ("Pop" vs. "Snap") between the > two test cases, but that should be the only difference. > > >>> run with Smack enabled, but I see the same problem with the same >>> unpredictability on the same kernel with security=none. >>> >>> I've tried to convince myself that there's a flaw in the way I've >>> set up the scripts. They've been pretty robust and I've never seen >>> socat behaving erratically before. I've instrumented the kernel >>> code and all the security checks are behaving as expected. Plus, >>> as I mentioned above, the problem also occurs without an LSM. >>> >>> 2021/09/15 08:49:50 socat[2215] D getpid() >>> 2021/09/15 08:49:50 socat[2215] D getpid() -> 2215 >>> 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PID", "2215", 1) >>> 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PPID", "2215", 1) >>> 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 >>> 2021/09/15 08:49:50 socat[2215] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org >>> 2021/09/15 08:49:50 socat[2215] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) >>> 2021/09/15 08:49:50 socat[2215] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) >>> 2021/09/15 08:49:50 socat[2215] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 >>> 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_VERSION", "1.7.4.1", 1) >>> 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 >>> >>> 2021/09/15 08:49:50 socat[2215] D argv[0]: "socat" >>> 2021/09/15 08:49:50 socat[2215] D argv[1]: "-d" >>> 2021/09/15 08:49:50 socat[2215] D argv[2]: "-d" >>> 2021/09/15 08:49:50 socat[2215] D argv[3]: "-d" >>> 2021/09/15 08:49:50 socat[2215] D argv[4]: "-d" >>> 2021/09/15 08:49:50 socat[2215] D argv[5]: "-" >>> 2021/09/15 08:49:50 socat[2215] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" >>> 2021/09/15 08:49:50 socat[2215] D sigaction(1, 0x7fffaec50b50, 0x0) >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D sigaction(2, 0x7fffaec50b50, 0x0) >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D sigaction(3, 0x7fffaec50b50, 0x0) >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D sigaction(4, 0x7fffaec50b50, 0x0) >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D sigaction(6, 0x7fffaec50b50, 0x0) >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D sigaction(7, 0x7fffaec50b50, 0x0) >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D sigaction(8, 0x7fffaec50b50, 0x0) >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D sigaction(11, 0x7fffaec50b50, 0x0) >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D sigaction(15, 0x7fffaec50b50, 0x0) >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D signal(13, 0x1) >>> 2021/09/15 08:49:50 socat[2215] D signal() -> 0x0 >>> 2021/09/15 08:49:50 socat[2215] D atexit(0x55aa5d645110) >>> 2021/09/15 08:49:50 socat[2215] D atexit() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D xioopen("-") >>> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) >>> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f0139d0 >>> 2021/09/15 08:49:50 socat[2215] D malloc(1024) >>> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f013d30 >>> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) >>> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014140 >>> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) >>> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014bc0 >>> 2021/09/15 08:49:50 socat[2215] D isatty(0) >>> 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D isatty(1) >>> 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D malloc(128) >>> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f00 >>> 2021/09/15 08:49:50 socat[2215] D malloc(128) >>> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f90 >>> 2021/09/15 08:49:50 socat[2215] N reading from and writing to stdio >>> 2021/09/15 08:49:50 socat[2215] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") >>> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) >>> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f015020 >>> 2021/09/15 08:49:50 socat[2215] D malloc(1024) >>> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015360 >>> 2021/09/15 08:49:50 socat[2215] D malloc(128) >>> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015770 >>> 2021/09/15 08:49:50 socat[2215] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" >>> 2021/09/15 08:49:50 socat[2215] D socket(1, 1, 0) >>> 2021/09/15 08:49:50 socat[2215] I socket(1, 1, 0) -> 5 >>> 2021/09/15 08:49:50 socat[2215] D fcntl(5, 2, 1) >>> 2021/09/15 08:49:50 socat[2215] D fcntl() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) >>> 2021/09/15 08:49:50 socat[2215] D connect() -> 0 >>> 2021/09/15 08:49:50 socat[2215] D getsockname(5, 0x7fffaec50580, 0x7fffaec50564{112}) >>> 2021/09/15 08:49:50 socat[2215] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 >>> 2021/09/15 08:49:50 socat[2215] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" >>> 2021/09/15 08:49:50 socat[2215] I resolved and opened all sock addresses >>> 2021/09/15 08:49:50 socat[2215] D posix_memalign(0x7fffaec50b28, 4096, 16385) >>> 2021/09/15 08:49:50 socat[2215] D posix_memalign(...) -> 0 >>> 2021/09/15 08:49:50 socat[2215] N starting data transfer loop with FDs [0,1] and [5,5] >>> 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} >>> 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) >>> 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 >>> 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) >>> 2021/09/15 08:49:50 socat[2215] D read -> 4 >>> 2021/09/15 08:49:50 socat[2215] D write(5, 0x55aa5f016000, 4) >>> Pop >>> 2021/09/15 08:49:50 socat[2215] D write -> 4 >>> 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 0 to 5 >>> 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) >>> 2021/09/15 08:49:50 socat[2215] D read -> 4 >>> 2021/09/15 08:49:50 socat[2215] D write(1, 0x55aa5f016000, 4) >>> Pop >>> 2021/09/15 08:49:50 socat[2215] D write -> 4 >>> 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 5 to 1 >>> 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} >>> 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) >>> 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 >>> 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) >>> 2021/09/15 08:49:50 socat[2215] D read -> 0 >>> 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) >>> 2021/09/15 08:49:50 socat[2215] D read -> 0 >>> 2021/09/15 08:49:50 socat[2215] N socket 1 (fd 0) is at EOF >>> 2021/09/15 08:49:50 socat[2215] I shutdown(5, 1) >>> 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 >>> 2021/09/15 08:49:50 socat[2215] N socket 2 (fd 5) is at EOF >>> 2021/09/15 08:49:50 socat[2215] I shutdown(5, 2) >>> 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 >>> 2021/09/15 08:49:50 socat[2215] N exiting with status 0 >>> 2021/09/15 08:49:50 socat[2215] D exit(0) >>> 2021/09/15 08:49:50 socat[2215] D starting xioexit() >>> 2021/09/15 08:49:50 socat[2215] D finished xioexit() >>> uds-access RC=0 >>> 2021/09/15 08:49:52 socat[2240] D getpid() >>> 2021/09/15 08:49:52 socat[2240] D getpid() -> 2240 >>> 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PID", "2240", 1) >>> 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PPID", "2240", 1) >>> 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 >>> 2021/09/15 08:49:52 socat[2240] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org >>> 2021/09/15 08:49:52 socat[2240] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) >>> 2021/09/15 08:49:52 socat[2240] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) >>> 2021/09/15 08:49:52 socat[2240] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 >>> 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_VERSION", "1.7.4.1", 1) >>> 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 >>> >>> 2021/09/15 08:49:52 socat[2240] D argv[0]: "socat" >>> 2021/09/15 08:49:52 socat[2240] D argv[1]: "-d" >>> 2021/09/15 08:49:52 socat[2240] D argv[2]: "-d" >>> 2021/09/15 08:49:52 socat[2240] D argv[3]: "-d" >>> 2021/09/15 08:49:52 socat[2240] D argv[4]: "-d" >>> 2021/09/15 08:49:52 socat[2240] D argv[5]: "-" >>> 2021/09/15 08:49:52 socat[2240] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" >>> 2021/09/15 08:49:52 socat[2240] D sigaction(1, 0x7ffcca7e26c0, 0x0) >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D sigaction(2, 0x7ffcca7e26c0, 0x0) >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D sigaction(3, 0x7ffcca7e26c0, 0x0) >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D sigaction(4, 0x7ffcca7e26c0, 0x0) >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D sigaction(6, 0x7ffcca7e26c0, 0x0) >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D sigaction(7, 0x7ffcca7e26c0, 0x0) >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D sigaction(8, 0x7ffcca7e26c0, 0x0) >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D sigaction(11, 0x7ffcca7e26c0, 0x0) >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D sigaction(15, 0x7ffcca7e26c0, 0x0) >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D signal(13, 0x1) >>> 2021/09/15 08:49:52 socat[2240] D signal() -> 0x0 >>> 2021/09/15 08:49:52 socat[2240] D atexit(0x560590a15110) >>> 2021/09/15 08:49:52 socat[2240] D atexit() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D xioopen("-") >>> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) >>> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e899d0 >>> 2021/09/15 08:49:52 socat[2240] D malloc(1024) >>> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e89d30 >>> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) >>> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8a140 >>> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) >>> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8abc0 >>> 2021/09/15 08:49:52 socat[2240] D isatty(0) >>> 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D isatty(1) >>> 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D malloc(128) >>> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af00 >>> 2021/09/15 08:49:52 socat[2240] D malloc(128) >>> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af90 >>> 2021/09/15 08:49:52 socat[2240] N reading from and writing to stdio >>> 2021/09/15 08:49:52 socat[2240] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") >>> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) >>> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8b020 >>> 2021/09/15 08:49:52 socat[2240] D malloc(1024) >>> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b360 >>> 2021/09/15 08:49:52 socat[2240] D malloc(128) >>> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b770 >>> 2021/09/15 08:49:52 socat[2240] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" >>> 2021/09/15 08:49:52 socat[2240] D socket(1, 1, 0) >>> 2021/09/15 08:49:52 socat[2240] I socket(1, 1, 0) -> 5 >>> 2021/09/15 08:49:52 socat[2240] D fcntl(5, 2, 1) >>> 2021/09/15 08:49:52 socat[2240] D fcntl() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) >>> 2021/09/15 08:49:52 socat[2240] D connect() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D getsockname(5, 0x7ffcca7e20f0, 0x7ffcca7e20d4{112}) >>> 2021/09/15 08:49:52 socat[2240] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 >>> 2021/09/15 08:49:52 socat[2240] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" >>> 2021/09/15 08:49:52 socat[2240] I resolved and opened all sock addresses >>> 2021/09/15 08:49:52 socat[2240] D posix_memalign(0x7ffcca7e2698, 4096, 16385) >>> 2021/09/15 08:49:52 socat[2240] D posix_memalign(...) -> 0 >>> 2021/09/15 08:49:52 socat[2240] N starting data transfer loop with FDs [0,1] and [5,5] >>> 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} >>> 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) >>> 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x22, 0x0, NULL/0.000000), 3 >>> 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) >>> 2021/09/15 08:49:52 socat[2240] D read -> 5 >>> 2021/09/15 08:49:52 socat[2240] D write(5, 0x560591e8c000, 5) >>> 2021/09/15 08:49:52 socat[2240] D write -> 5 >>> 2021/09/15 08:49:52 socat[2240] I transferred 5 bytes from 0 to 5 >>> 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} >>> 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x20, &0x0, NULL/0.000000) >>> 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x20, 0x0, NULL/0.000000), 2 >>> 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) >>> 2021/09/15 08:49:52 socat[2240] D read -> 0 >>> 2021/09/15 08:49:52 socat[2240] N socket 1 (fd 0) is at EOF >>> 2021/09/15 08:49:52 socat[2240] I shutdown(5, 1) >>> 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 >> Is this shutdown expected? > I'm not an expert on the internals of socat, but I don't think it > is expected. > >> 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=3, sock2->eof=0, closing=1, wasaction=1, total_to={0.000000} >> 2021/09/15 08:49:52 socat[2240] D select(6, &0x20, &0x0, &0x0, &0.500000) >> Snap >> 2021/09/15 08:49:52 socat[2240] D select -> (, 0x20, 0x0, 0x0, &0.500000), 1 >> 2021/09/15 08:49:52 socat[2240] D read(5, 0x560591e8c000, 8192) >> 2021/09/15 08:49:52 socat[2240] D read -> -1 >> This read failure seems due to the previous shutdown, right? > Again, I'm not the socat expert, but that would seem reasonable > to me. > > >>> 2021/09/15 08:49:52 socat[2240] E read(5, 0x560591e8c000, 8192): Invalid argument >>> 2021/09/15 08:49:52 socat[2240] N exit(1) >>> 2021/09/15 08:49:52 socat[2240] D starting xioexit() >>> 2021/09/15 08:49:52 socat[2240] I shutdown(5, 2) >>> 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 >>> 2021/09/15 08:49:52 socat[2240] D finished xioexit() >>> uds-access RC=1 >>> >>> >>> >>> ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [External] Re: Regression in unix stream sockets with the Smack LSM 2021-09-29 15:43 ` Casey Schaufler @ 2021-09-29 18:36 ` Jiang Wang . 0 siblings, 0 replies; 10+ messages in thread From: Jiang Wang . @ 2021-09-29 18:36 UTC (permalink / raw) To: Casey Schaufler Cc: Paul Moore, Andrii Nakryiko, Jakub Sitnicki, John Fastabend, LKML, Linux Security Module list, netdev, Cong Wang On Wed, Sep 29, 2021 at 8:44 AM Casey Schaufler <casey@schaufler-ca.com> wrote: > > On 9/20/2021 4:44 PM, Casey Schaufler wrote: > > On 9/20/2021 3:35 PM, Jiang Wang . wrote: > >> On Wed, Sep 15, 2021 at 9:52 AM Casey Schaufler <casey@schaufler-ca.com> wrote: > >>> On 9/13/2021 4:47 PM, Paul Moore wrote: > >>>> On Mon, Sep 13, 2021 at 6:53 PM Casey Schaufler <casey@schaufler-ca.com> wrote: > >>>>> Commit 77462de14a43f4d98dbd8de0f5743a4e02450b1d > >>>>> > >>>>> af_unix: Add read_sock for stream socket types > >>>>> > >>>>> introduced a regression in UDS socket connections for the Smack LSM. > >>>>> I have not tracked done the details of why the change broke the code, > >>>>> but this is where bisecting the kernel indicates the problem lies, and > >>>>> I have verified that reverting this change repairs the problem. > >>>>> > >>>>> You can verify the problem with the Smack test suite: > >>>>> > >>>>> https://github.com/smack-team/smack-testsuite.git > >>>>> > >>>>> The failing test is tests/uds-access.sh. > >>>>> > >> I tried to reproduce with tests/uds-access.sh, but the first two test > >> cases always failed. > > Just piping in that the behavior hasn't changed in 5.15-rc3. > It still usually fails, with the occasional success. These > tests used to succeed. > Got it. I am still working on it. I noticed that I did not enable smack related kernel configs in my previous tests. I will try again. Also, just to make sure, could you send me your kernel config? I think there is a chance that other commits break the test, but I will test more to make sure. Thanks. > > That was my initial impression as well. However, when I started > > running the tests outside the routine "make test-results" I started > > observing that they succeeded irregularly. > > > > My biggest concern is that the test ever fails. The uds-access test > > has not failed in several releases. The erratic behavior just adds > > spice to the problem. > > > >> I tried different kernels with and without my > >> unix-stream sockmap patches. Also tried standard debian 4.19 > >> kernel and they all have the same result. What distro did you use? centos? > >> Fedora? > > I have been testing on Fedora32 and Fedora34. > > > >> Have you tested on debian based distros? > > Ubuntu 20.04.3 with a 5.15-rc1 kernel is exhibiting the same > > behavior. The Ubuntu system fails the test more regularly, but > > does succeed on occasion. > > > >> failing log: > >> root@gitlab-runner-stretch:~/smack-testsuite# tests/uds-access.sh -v > > # tools/clean-targets.sh > > # tests/uds-access.sh -v > > > > will remove the UDS filesystem entry before the test runs. > > > > > >> mkdir: cannot create directory ‘./targets/uds-notroot’: File exists > >> tests/uds-access.sh:71 FAIL > >> tests/uds-access.sh:76 FAIL > >> tests/uds-access.sh:81 PASS > >> tests/uds-access.sh:86 PASS > >> tests/uds-access.sh:91 PASS > >> tests/uds-access.sh PASS=3 FAIL=2 > >> root@gitlab-runner-stretch:~/smack-testsuite# uname -a > >> Linux gitlab-runner-stretch 5.14.0-rc5.bm.1-amd64+ #6 SMP Mon Sep 20 > >> 22:01:10 UTC 2021 x86_64 GNU/Linux > >> root@gitlab-runner-stretch:~/smack-testsuite# > >> > >>>>> I have not looked to see if there's a similar problem with SELinux. > >>>>> There may be, but if there isn't it doesn't matter, there's still a > >>>>> bug. > >>>> FWIW, the selinux-testsuite tests ran clean today with v5.15-rc1 (it > >>>> looks like this code is only in v5.15) but as Casey said, a regression > >>>> is a regression. > >>>> > >>>> Casey, what actually fails on the Smack system with this commit? > >>> This problem occurs with security=none as well as with security=smack. > >>> > >>> There isn't a problem with connect, that always works correctly. > >>> The problem is an unexpected read() failure in the connecting process. > >>> This doesn't occur all the time, and sometimes happens in the first > >>> of my two tests, sometimes the second, sometimes neither and, you guessed > >>> it, sometimes both. > >>> > >>> Here's a sample socat log demonstrating the problem. The first run, > >>> ending at "uds-access RC=0" behaves as expected. The second, ending > >>> at "uds-access RC=1", demonstrates the read failure. This case was > >> I tried to compare logs between RC=0 and RC=1, but they look to me > >> not apple to apple comparison? The read syscall have different parameters > >> and the syscall sequences are different. I am not sure which syscall > >> is the first failure. See more comments below. > > The data being feed to socat is the Smack label, so the data passed across > > the socket will be of different length ("Pop" vs. "Snap") between the > > two test cases, but that should be the only difference. > > > > > >>> run with Smack enabled, but I see the same problem with the same > >>> unpredictability on the same kernel with security=none. > >>> > >>> I've tried to convince myself that there's a flaw in the way I've > >>> set up the scripts. They've been pretty robust and I've never seen > >>> socat behaving erratically before. I've instrumented the kernel > >>> code and all the security checks are behaving as expected. Plus, > >>> as I mentioned above, the problem also occurs without an LSM. > >>> > >>> 2021/09/15 08:49:50 socat[2215] D getpid() > >>> 2021/09/15 08:49:50 socat[2215] D getpid() -> 2215 > >>> 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PID", "2215", 1) > >>> 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_PPID", "2215", 1) > >>> 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org > >>> 2021/09/15 08:49:50 socat[2215] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) > >>> 2021/09/15 08:49:50 socat[2215] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) > >>> 2021/09/15 08:49:50 socat[2215] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 > >>> 2021/09/15 08:49:50 socat[2215] D setenv("SOCAT_VERSION", "1.7.4.1", 1) > >>> 2021/09/15 08:49:50 socat[2215] D setenv() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 > >>> > >>> 2021/09/15 08:49:50 socat[2215] D argv[0]: "socat" > >>> 2021/09/15 08:49:50 socat[2215] D argv[1]: "-d" > >>> 2021/09/15 08:49:50 socat[2215] D argv[2]: "-d" > >>> 2021/09/15 08:49:50 socat[2215] D argv[3]: "-d" > >>> 2021/09/15 08:49:50 socat[2215] D argv[4]: "-d" > >>> 2021/09/15 08:49:50 socat[2215] D argv[5]: "-" > >>> 2021/09/15 08:49:50 socat[2215] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" > >>> 2021/09/15 08:49:50 socat[2215] D sigaction(1, 0x7fffaec50b50, 0x0) > >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D sigaction(2, 0x7fffaec50b50, 0x0) > >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D sigaction(3, 0x7fffaec50b50, 0x0) > >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D sigaction(4, 0x7fffaec50b50, 0x0) > >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D sigaction(6, 0x7fffaec50b50, 0x0) > >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D sigaction(7, 0x7fffaec50b50, 0x0) > >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D sigaction(8, 0x7fffaec50b50, 0x0) > >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D sigaction(11, 0x7fffaec50b50, 0x0) > >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D sigaction(15, 0x7fffaec50b50, 0x0) > >>> 2021/09/15 08:49:50 socat[2215] D sigaction() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D signal(13, 0x1) > >>> 2021/09/15 08:49:50 socat[2215] D signal() -> 0x0 > >>> 2021/09/15 08:49:50 socat[2215] D atexit(0x55aa5d645110) > >>> 2021/09/15 08:49:50 socat[2215] D atexit() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D xioopen("-") > >>> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > >>> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f0139d0 > >>> 2021/09/15 08:49:50 socat[2215] D malloc(1024) > >>> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f013d30 > >>> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > >>> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014140 > >>> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > >>> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f014bc0 > >>> 2021/09/15 08:49:50 socat[2215] D isatty(0) > >>> 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D isatty(1) > >>> 2021/09/15 08:49:50 socat[2215] D isatty() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D malloc(128) > >>> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f00 > >>> 2021/09/15 08:49:50 socat[2215] D malloc(128) > >>> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f014f90 > >>> 2021/09/15 08:49:50 socat[2215] N reading from and writing to stdio > >>> 2021/09/15 08:49:50 socat[2215] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") > >>> 2021/09/15 08:49:50 socat[2215] D calloc(1, 824) > >>> 2021/09/15 08:49:50 socat[2215] D calloc() -> 0x55aa5f015020 > >>> 2021/09/15 08:49:50 socat[2215] D malloc(1024) > >>> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015360 > >>> 2021/09/15 08:49:50 socat[2215] D malloc(128) > >>> 2021/09/15 08:49:50 socat[2215] D malloc() -> 0x55aa5f015770 > >>> 2021/09/15 08:49:50 socat[2215] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" > >>> 2021/09/15 08:49:50 socat[2215] D socket(1, 1, 0) > >>> 2021/09/15 08:49:50 socat[2215] I socket(1, 1, 0) -> 5 > >>> 2021/09/15 08:49:50 socat[2215] D fcntl(5, 2, 1) > >>> 2021/09/15 08:49:50 socat[2215] D fcntl() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) > >>> 2021/09/15 08:49:50 socat[2215] D connect() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D getsockname(5, 0x7fffaec50580, 0x7fffaec50564{112}) > >>> 2021/09/15 08:49:50 socat[2215] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 > >>> 2021/09/15 08:49:50 socat[2215] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" > >>> 2021/09/15 08:49:50 socat[2215] I resolved and opened all sock addresses > >>> 2021/09/15 08:49:50 socat[2215] D posix_memalign(0x7fffaec50b28, 4096, 16385) > >>> 2021/09/15 08:49:50 socat[2215] D posix_memalign(...) -> 0 > >>> 2021/09/15 08:49:50 socat[2215] N starting data transfer loop with FDs [0,1] and [5,5] > >>> 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > >>> 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) > >>> 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 > >>> 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) > >>> 2021/09/15 08:49:50 socat[2215] D read -> 4 > >>> 2021/09/15 08:49:50 socat[2215] D write(5, 0x55aa5f016000, 4) > >>> Pop > >>> 2021/09/15 08:49:50 socat[2215] D write -> 4 > >>> 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 0 to 5 > >>> 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) > >>> 2021/09/15 08:49:50 socat[2215] D read -> 4 > >>> 2021/09/15 08:49:50 socat[2215] D write(1, 0x55aa5f016000, 4) > >>> Pop > >>> 2021/09/15 08:49:50 socat[2215] D write -> 4 > >>> 2021/09/15 08:49:50 socat[2215] I transferred 4 bytes from 5 to 1 > >>> 2021/09/15 08:49:50 socat[2215] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > >>> 2021/09/15 08:49:50 socat[2215] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) > >>> 2021/09/15 08:49:50 socat[2215] D select -> (, 0x21, 0x22, 0x0, NULL/0.000000), 4 > >>> 2021/09/15 08:49:50 socat[2215] D read(0, 0x55aa5f016000, 8192) > >>> 2021/09/15 08:49:50 socat[2215] D read -> 0 > >>> 2021/09/15 08:49:50 socat[2215] D read(5, 0x55aa5f016000, 8192) > >>> 2021/09/15 08:49:50 socat[2215] D read -> 0 > >>> 2021/09/15 08:49:50 socat[2215] N socket 1 (fd 0) is at EOF > >>> 2021/09/15 08:49:50 socat[2215] I shutdown(5, 1) > >>> 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] N socket 2 (fd 5) is at EOF > >>> 2021/09/15 08:49:50 socat[2215] I shutdown(5, 2) > >>> 2021/09/15 08:49:50 socat[2215] D shutdown() -> 0 > >>> 2021/09/15 08:49:50 socat[2215] N exiting with status 0 > >>> 2021/09/15 08:49:50 socat[2215] D exit(0) > >>> 2021/09/15 08:49:50 socat[2215] D starting xioexit() > >>> 2021/09/15 08:49:50 socat[2215] D finished xioexit() > >>> uds-access RC=0 > >>> 2021/09/15 08:49:52 socat[2240] D getpid() > >>> 2021/09/15 08:49:52 socat[2240] D getpid() -> 2240 > >>> 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PID", "2240", 1) > >>> 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_PPID", "2240", 1) > >>> 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] I socat by Gerhard Rieger and contributors - see www.dest-unreach.org > >>> 2021/09/15 08:49:52 socat[2240] I This product includes software developed by the OpenSSL Project for use in the OpenSSL Toolkit. (http://www.openssl.org/) > >>> 2021/09/15 08:49:52 socat[2240] I This product includes software written by Tim Hudson (tjh@cryptsoft.com) > >>> 2021/09/15 08:49:52 socat[2240] D socat version 1.7.4.1 on Jan 27 2021 00:00:00 > >>> 2021/09/15 08:49:52 socat[2240] D setenv("SOCAT_VERSION", "1.7.4.1", 1) > >>> 2021/09/15 08:49:52 socat[2240] D setenv() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D running on Linux version #58 SMP Wed Sep 15 08:40:38 PDT 2021, release 5.15.0-rc1bisect, machine x86_64 > >>> > >>> 2021/09/15 08:49:52 socat[2240] D argv[0]: "socat" > >>> 2021/09/15 08:49:52 socat[2240] D argv[1]: "-d" > >>> 2021/09/15 08:49:52 socat[2240] D argv[2]: "-d" > >>> 2021/09/15 08:49:52 socat[2240] D argv[3]: "-d" > >>> 2021/09/15 08:49:52 socat[2240] D argv[4]: "-d" > >>> 2021/09/15 08:49:52 socat[2240] D argv[5]: "-" > >>> 2021/09/15 08:49:52 socat[2240] D argv[6]: "UNIX-CONNECT:./targets/uds-notroot/uds-access-socket" > >>> 2021/09/15 08:49:52 socat[2240] D sigaction(1, 0x7ffcca7e26c0, 0x0) > >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D sigaction(2, 0x7ffcca7e26c0, 0x0) > >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D sigaction(3, 0x7ffcca7e26c0, 0x0) > >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D sigaction(4, 0x7ffcca7e26c0, 0x0) > >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D sigaction(6, 0x7ffcca7e26c0, 0x0) > >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D sigaction(7, 0x7ffcca7e26c0, 0x0) > >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D sigaction(8, 0x7ffcca7e26c0, 0x0) > >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D sigaction(11, 0x7ffcca7e26c0, 0x0) > >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D sigaction(15, 0x7ffcca7e26c0, 0x0) > >>> 2021/09/15 08:49:52 socat[2240] D sigaction() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D signal(13, 0x1) > >>> 2021/09/15 08:49:52 socat[2240] D signal() -> 0x0 > >>> 2021/09/15 08:49:52 socat[2240] D atexit(0x560590a15110) > >>> 2021/09/15 08:49:52 socat[2240] D atexit() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D xioopen("-") > >>> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > >>> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e899d0 > >>> 2021/09/15 08:49:52 socat[2240] D malloc(1024) > >>> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e89d30 > >>> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > >>> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8a140 > >>> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > >>> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8abc0 > >>> 2021/09/15 08:49:52 socat[2240] D isatty(0) > >>> 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D isatty(1) > >>> 2021/09/15 08:49:52 socat[2240] D isatty() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D malloc(128) > >>> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af00 > >>> 2021/09/15 08:49:52 socat[2240] D malloc(128) > >>> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8af90 > >>> 2021/09/15 08:49:52 socat[2240] N reading from and writing to stdio > >>> 2021/09/15 08:49:52 socat[2240] D xioopen("UNIX-CONNECT:./targets/uds-notroot/uds-access-socket") > >>> 2021/09/15 08:49:52 socat[2240] D calloc(1, 824) > >>> 2021/09/15 08:49:52 socat[2240] D calloc() -> 0x560591e8b020 > >>> 2021/09/15 08:49:52 socat[2240] D malloc(1024) > >>> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b360 > >>> 2021/09/15 08:49:52 socat[2240] D malloc(128) > >>> 2021/09/15 08:49:52 socat[2240] D malloc() -> 0x560591e8b770 > >>> 2021/09/15 08:49:52 socat[2240] N opening connection to AF=1 "./targets/uds-notroot/uds-access-socket" > >>> 2021/09/15 08:49:52 socat[2240] D socket(1, 1, 0) > >>> 2021/09/15 08:49:52 socat[2240] I socket(1, 1, 0) -> 5 > >>> 2021/09/15 08:49:52 socat[2240] D fcntl(5, 2, 1) > >>> 2021/09/15 08:49:52 socat[2240] D fcntl() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D connect(5, {1,AF=1 "./targets/uds-notroot/uds-access-socket"}, 41) > >>> 2021/09/15 08:49:52 socat[2240] D connect() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D getsockname(5, 0x7ffcca7e20f0, 0x7ffcca7e20d4{112}) > >>> 2021/09/15 08:49:52 socat[2240] D getsockname(, {AF=1 "<anon>"}, {2}) -> 0 > >>> 2021/09/15 08:49:52 socat[2240] N successfully connected from local address AF=1 "uds-notroot/ud\xEE\xEE\xEE\xEEcess-socket")\n" > >>> 2021/09/15 08:49:52 socat[2240] I resolved and opened all sock addresses > >>> 2021/09/15 08:49:52 socat[2240] D posix_memalign(0x7ffcca7e2698, 4096, 16385) > >>> 2021/09/15 08:49:52 socat[2240] D posix_memalign(...) -> 0 > >>> 2021/09/15 08:49:52 socat[2240] N starting data transfer loop with FDs [0,1] and [5,5] > >>> 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > >>> 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x22, &0x0, NULL/0.000000) > >>> 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x22, 0x0, NULL/0.000000), 3 > >>> 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) > >>> 2021/09/15 08:49:52 socat[2240] D read -> 5 > >>> 2021/09/15 08:49:52 socat[2240] D write(5, 0x560591e8c000, 5) > >>> 2021/09/15 08:49:52 socat[2240] D write -> 5 > >>> 2021/09/15 08:49:52 socat[2240] I transferred 5 bytes from 0 to 5 > >>> 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=0, sock2->eof=0, closing=0, wasaction=1, total_to={0.000000} > >>> 2021/09/15 08:49:52 socat[2240] D select(6, &0x21, &0x20, &0x0, NULL/0.000000) > >>> 2021/09/15 08:49:52 socat[2240] D select -> (, 0x1, 0x20, 0x0, NULL/0.000000), 2 > >>> 2021/09/15 08:49:52 socat[2240] D read(0, 0x560591e8c000, 8192) > >>> 2021/09/15 08:49:52 socat[2240] D read -> 0 > >>> 2021/09/15 08:49:52 socat[2240] N socket 1 (fd 0) is at EOF > >>> 2021/09/15 08:49:52 socat[2240] I shutdown(5, 1) > >>> 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 > >> Is this shutdown expected? > > I'm not an expert on the internals of socat, but I don't think it > > is expected. > > > >> 2021/09/15 08:49:52 socat[2240] D data loop: sock1->eof=3, sock2->eof=0, closing=1, wasaction=1, total_to={0.000000} > >> 2021/09/15 08:49:52 socat[2240] D select(6, &0x20, &0x0, &0x0, &0.500000) > >> Snap > >> 2021/09/15 08:49:52 socat[2240] D select -> (, 0x20, 0x0, 0x0, &0.500000), 1 > >> 2021/09/15 08:49:52 socat[2240] D read(5, 0x560591e8c000, 8192) > >> 2021/09/15 08:49:52 socat[2240] D read -> -1 > >> This read failure seems due to the previous shutdown, right? > > Again, I'm not the socat expert, but that would seem reasonable > > to me. > > > > > >>> 2021/09/15 08:49:52 socat[2240] E read(5, 0x560591e8c000, 8192): Invalid argument > >>> 2021/09/15 08:49:52 socat[2240] N exit(1) > >>> 2021/09/15 08:49:52 socat[2240] D starting xioexit() > >>> 2021/09/15 08:49:52 socat[2240] I shutdown(5, 2) > >>> 2021/09/15 08:49:52 socat[2240] D shutdown() -> 0 > >>> 2021/09/15 08:49:52 socat[2240] D finished xioexit() > >>> uds-access RC=1 > >>> > >>> > >>> > >>> ^ permalink raw reply [flat|nested] 10+ messages in thread
end of thread, other threads:[~2021-09-29 18:36 UTC | newest] Thread overview: 10+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- [not found] <a507efa7-066b-decf-8605-89cdb0ac1951.ref@schaufler-ca.com> 2021-09-13 22:50 ` Regression in unix stream sockets with the Smack LSM Casey Schaufler 2021-09-13 23:47 ` Paul Moore 2021-09-14 0:16 ` Casey Schaufler 2021-09-14 22:14 ` Casey Schaufler 2021-09-15 16:51 ` Casey Schaufler 2021-09-15 17:29 ` Jiang Wang . 2021-09-20 22:35 ` Jiang Wang . 2021-09-20 23:44 ` Casey Schaufler 2021-09-29 15:43 ` Casey Schaufler 2021-09-29 18:36 ` [External] " Jiang Wang .
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).