2021-01-05 13:48:36

by Tom Cook

[permalink] [raw]
Subject: cBPF socket filters failing - inexplicably?

In the course of tracking down a defect in some existing software,
I've found the failure demonstrated by the short program below.
Essentially, a cBPF program that just rejects every frame (ie always
returns zero) and is attached to a socket using setsockopt(SOL_SOCKET,
SO_ATTACH_FILTER, ...) still occasionally lets frames through to
userspace.

The code is based on the first example in
Documentation/networking/filter.txt, except that I've changed the
content of the filter program and added a timeout on the socket.

To reproduce the problem:

# gcc test.c -o test
# sudo ./test
... and in another console start a large network operation.

In my case, I copied a ~300MB core file I had lying around to another
host on the LAN. The test code should print the string "Failed to
read from socket" 100 times. In practice, it produces about 10%
"Received packet with ethertype..." messages.

I've observed the same result on Ubuntu amd64 glibc system running a
5.9.0 kernel and also on Alpine arm64v8 muslc system running a 4.9.1
kernel. I've written test code in both C and Python. I'm fairly sure
this is not something I'm doing wrong - but very keen to have things
thrown at me if it is.

Regards,
Tom Cook


#include <stdio.h>
#include <sys/socket.h>
#include <sys/types.h>
#include <arpa/inet.h>
#include <linux/if_ether.h>
#include <linux/filter.h>
#include <stdint.h>
#include <unistd.h>

struct sock_filter code[] = {
{ 0x06, 0, 0, 0x00 } /* BPF_RET | BPF_K 0 0 0 */
};

struct sock_fprog bpf = {
.len = 1,
.filter = code,
};

void test() {
uint8_t buf[2048];

int sock = socket(PF_PACKET, SOCK_RAW, htons(ETH_P_ALL));
if (sock < 0) {
printf("Failed to open socket\n");
return;
}
int ret = setsockopt(sock, SOL_SOCKET, SO_ATTACH_FILTER, &bpf, sizeof(bpf));
if (ret < 0) {
printf("Failed to set socket filter\n");
return;
}
struct timeval tv = {
.tv_sec = 1
};

ret = setsockopt(sock, SOL_SOCKET, SO_RCVTIMEO, &tv, sizeof(tv));
if (ret < 0) {
printf("Failed to set socket timeout\n");
return;
}

ssize_t count = recv(sock, buf, 2048, 0);
if (count <= 0) {
printf("Failed to read from socket\n");
return;
}

close(sock);

uint16_t *ethertype = (short*)(buf + 12);
uint8_t *proto = (unsigned char *)(buf + 23);
uint16_t *dport = (uint16_t *)(buf + 14 + 20);

printf("Received packet with ethertype 0x%04hu, protocol 0x%02hhu
and dport 0x%04hu\n", *ethertype, *proto, *dport);
}

int main() {
for (size_t ii = 0; ii < 100; ++ii) {
test();
}
}


2021-01-06 10:09:35

by Tom Cook

[permalink] [raw]
Subject: Re: cBPF socket filters failing - inexplicably?

Just to note I have also reproduced this on a 5.10.0 kernel.

On Tue, Jan 5, 2021 at 1:42 PM Tom Cook <[email protected]> wrote:
>
> In the course of tracking down a defect in some existing software,
> I've found the failure demonstrated by the short program below.
> Essentially, a cBPF program that just rejects every frame (ie always
> returns zero) and is attached to a socket using setsockopt(SOL_SOCKET,
> SO_ATTACH_FILTER, ...) still occasionally lets frames through to
> userspace.
>
> The code is based on the first example in
> Documentation/networking/filter.txt, except that I've changed the
> content of the filter program and added a timeout on the socket.
>
> To reproduce the problem:
>
> # gcc test.c -o test
> # sudo ./test
> ... and in another console start a large network operation.
>
> In my case, I copied a ~300MB core file I had lying around to another
> host on the LAN. The test code should print the string "Failed to
> read from socket" 100 times. In practice, it produces about 10%
> "Received packet with ethertype..." messages.
>
> I've observed the same result on Ubuntu amd64 glibc system running a
> 5.9.0 kernel and also on Alpine arm64v8 muslc system running a 4.9.1
> kernel. I've written test code in both C and Python. I'm fairly sure
> this is not something I'm doing wrong - but very keen to have things
> thrown at me if it is.
>
> Regards,
> Tom Cook
>
>
> #include <stdio.h>
> #include <sys/socket.h>
> #include <sys/types.h>
> #include <arpa/inet.h>
> #include <linux/if_ether.h>
> #include <linux/filter.h>
> #include <stdint.h>
> #include <unistd.h>
>
> struct sock_filter code[] = {
> { 0x06, 0, 0, 0x00 } /* BPF_RET | BPF_K 0 0 0 */
> };
>
> struct sock_fprog bpf = {
> .len = 1,
> .filter = code,
> };
>
> void test() {
> uint8_t buf[2048];
>
> int sock = socket(PF_PACKET, SOCK_RAW, htons(ETH_P_ALL));
> if (sock < 0) {
> printf("Failed to open socket\n");
> return;
> }
> int ret = setsockopt(sock, SOL_SOCKET, SO_ATTACH_FILTER, &bpf, sizeof(bpf));
> if (ret < 0) {
> printf("Failed to set socket filter\n");
> return;
> }
> struct timeval tv = {
> .tv_sec = 1
> };
>
> ret = setsockopt(sock, SOL_SOCKET, SO_RCVTIMEO, &tv, sizeof(tv));
> if (ret < 0) {
> printf("Failed to set socket timeout\n");
> return;
> }
>
> ssize_t count = recv(sock, buf, 2048, 0);
> if (count <= 0) {
> printf("Failed to read from socket\n");
> return;
> }
>
> close(sock);
>
> uint16_t *ethertype = (short*)(buf + 12);
> uint8_t *proto = (unsigned char *)(buf + 23);
> uint16_t *dport = (uint16_t *)(buf + 14 + 20);
>
> printf("Received packet with ethertype 0x%04hu, protocol 0x%02hhu
> and dport 0x%04hu\n", *ethertype, *proto, *dport);
> }
>
> int main() {
> for (size_t ii = 0; ii < 100; ++ii) {
> test();
> }
> }

2021-01-06 14:55:08

by Tom Cook

[permalink] [raw]
Subject: Re: cBPF socket filters failing - inexplicably?

Another factoid to add to this: I captured all traffic on an
interface while the test program was running using

tcpdump -i wlo1 -w capture.pcap

observing that multiple packets got through the filter. I then built
the bpf_dbg program from the kernel source tree and ran the same
filter and capture file through it:

$ tools/bpf_dbg
> load bpf 1,6 0 0 0
> load pcap capture.pcap
> run
bpf passes:0 fails:269288

So bpf_dbg thinks the filter is correct; it's only when the filter is
attached to an actual socket that it fails occasionally.

Regards,
Tom

On Wed, Jan 6, 2021 at 10:07 AM Tom Cook <[email protected]> wrote:
>
> Just to note I have also reproduced this on a 5.10.0 kernel.
>
> On Tue, Jan 5, 2021 at 1:42 PM Tom Cook <[email protected]> wrote:
> >
> > In the course of tracking down a defect in some existing software,
> > I've found the failure demonstrated by the short program below.
> > Essentially, a cBPF program that just rejects every frame (ie always
> > returns zero) and is attached to a socket using setsockopt(SOL_SOCKET,
> > SO_ATTACH_FILTER, ...) still occasionally lets frames through to
> > userspace.
> >
> > The code is based on the first example in
> > Documentation/networking/filter.txt, except that I've changed the
> > content of the filter program and added a timeout on the socket.
> >
> > To reproduce the problem:
> >
> > # gcc test.c -o test
> > # sudo ./test
> > ... and in another console start a large network operation.
> >
> > In my case, I copied a ~300MB core file I had lying around to another
> > host on the LAN. The test code should print the string "Failed to
> > read from socket" 100 times. In practice, it produces about 10%
> > "Received packet with ethertype..." messages.
> >
> > I've observed the same result on Ubuntu amd64 glibc system running a
> > 5.9.0 kernel and also on Alpine arm64v8 muslc system running a 4.9.1
> > kernel. I've written test code in both C and Python. I'm fairly sure
> > this is not something I'm doing wrong - but very keen to have things
> > thrown at me if it is.
> >
> > Regards,
> > Tom Cook
> >
> >
> > #include <stdio.h>
> > #include <sys/socket.h>
> > #include <sys/types.h>
> > #include <arpa/inet.h>
> > #include <linux/if_ether.h>
> > #include <linux/filter.h>
> > #include <stdint.h>
> > #include <unistd.h>
> >
> > struct sock_filter code[] = {
> > { 0x06, 0, 0, 0x00 } /* BPF_RET | BPF_K 0 0 0 */
> > };
> >
> > struct sock_fprog bpf = {
> > .len = 1,
> > .filter = code,
> > };
> >
> > void test() {
> > uint8_t buf[2048];
> >
> > int sock = socket(PF_PACKET, SOCK_RAW, htons(ETH_P_ALL));
> > if (sock < 0) {
> > printf("Failed to open socket\n");
> > return;
> > }
> > int ret = setsockopt(sock, SOL_SOCKET, SO_ATTACH_FILTER, &bpf, sizeof(bpf));
> > if (ret < 0) {
> > printf("Failed to set socket filter\n");
> > return;
> > }
> > struct timeval tv = {
> > .tv_sec = 1
> > };
> >
> > ret = setsockopt(sock, SOL_SOCKET, SO_RCVTIMEO, &tv, sizeof(tv));
> > if (ret < 0) {
> > printf("Failed to set socket timeout\n");
> > return;
> > }
> >
> > ssize_t count = recv(sock, buf, 2048, 0);
> > if (count <= 0) {
> > printf("Failed to read from socket\n");
> > return;
> > }
> >
> > close(sock);
> >
> > uint16_t *ethertype = (short*)(buf + 12);
> > uint8_t *proto = (unsigned char *)(buf + 23);
> > uint16_t *dport = (uint16_t *)(buf + 14 + 20);
> >
> > printf("Received packet with ethertype 0x%04hu, protocol 0x%02hhu
> > and dport 0x%04hu\n", *ethertype, *proto, *dport);
> > }
> >
> > int main() {
> > for (size_t ii = 0; ii < 100; ++ii) {
> > test();
> > }
> > }

2021-01-15 10:43:31

by Alexei Starovoitov

[permalink] [raw]
Subject: Re: cBPF socket filters failing - inexplicably?

Adding appropriate mailing list to cc...

My wild guess is that as soon as socket got created:
socket(PF_PACKET, SOCK_RAW, htons(ETH_P_ALL));
the packets were already queued to it.
So later setsockopt() is too late to filter.

Eric, thoughts?

On Wed, Jan 6, 2021 at 6:55 AM Tom Cook <[email protected]> wrote:
>
> Another factoid to add to this: I captured all traffic on an
> interface while the test program was running using
>
> tcpdump -i wlo1 -w capture.pcap
>
> observing that multiple packets got through the filter. I then built
> the bpf_dbg program from the kernel source tree and ran the same
> filter and capture file through it:
>
> $ tools/bpf_dbg
> > load bpf 1,6 0 0 0
> > load pcap capture.pcap
> > run
> bpf passes:0 fails:269288
>
> So bpf_dbg thinks the filter is correct; it's only when the filter is
> attached to an actual socket that it fails occasionally.
>
> Regards,
> Tom
>
> On Wed, Jan 6, 2021 at 10:07 AM Tom Cook <[email protected]> wrote:
> >
> > Just to note I have also reproduced this on a 5.10.0 kernel.
> >
> > On Tue, Jan 5, 2021 at 1:42 PM Tom Cook <[email protected]> wrote:
> > >
> > > In the course of tracking down a defect in some existing software,
> > > I've found the failure demonstrated by the short program below.
> > > Essentially, a cBPF program that just rejects every frame (ie always
> > > returns zero) and is attached to a socket using setsockopt(SOL_SOCKET,
> > > SO_ATTACH_FILTER, ...) still occasionally lets frames through to
> > > userspace.
> > >
> > > The code is based on the first example in
> > > Documentation/networking/filter.txt, except that I've changed the
> > > content of the filter program and added a timeout on the socket.
> > >
> > > To reproduce the problem:
> > >
> > > # gcc test.c -o test
> > > # sudo ./test
> > > ... and in another console start a large network operation.
> > >
> > > In my case, I copied a ~300MB core file I had lying around to another
> > > host on the LAN. The test code should print the string "Failed to
> > > read from socket" 100 times. In practice, it produces about 10%
> > > "Received packet with ethertype..." messages.
> > >
> > > I've observed the same result on Ubuntu amd64 glibc system running a
> > > 5.9.0 kernel and also on Alpine arm64v8 muslc system running a 4.9.1
> > > kernel. I've written test code in both C and Python. I'm fairly sure
> > > this is not something I'm doing wrong - but very keen to have things
> > > thrown at me if it is.
> > >
> > > Regards,
> > > Tom Cook
> > >
> > >
> > > #include <stdio.h>
> > > #include <sys/socket.h>
> > > #include <sys/types.h>
> > > #include <arpa/inet.h>
> > > #include <linux/if_ether.h>
> > > #include <linux/filter.h>
> > > #include <stdint.h>
> > > #include <unistd.h>
> > >
> > > struct sock_filter code[] = {
> > > { 0x06, 0, 0, 0x00 } /* BPF_RET | BPF_K 0 0 0 */
> > > };
> > >
> > > struct sock_fprog bpf = {
> > > .len = 1,
> > > .filter = code,
> > > };
> > >
> > > void test() {
> > > uint8_t buf[2048];
> > >
> > > int sock = socket(PF_PACKET, SOCK_RAW, htons(ETH_P_ALL));
> > > if (sock < 0) {
> > > printf("Failed to open socket\n");
> > > return;
> > > }
> > > int ret = setsockopt(sock, SOL_SOCKET, SO_ATTACH_FILTER, &bpf, sizeof(bpf));
> > > if (ret < 0) {
> > > printf("Failed to set socket filter\n");
> > > return;
> > > }
> > > struct timeval tv = {
> > > .tv_sec = 1
> > > };
> > >
> > > ret = setsockopt(sock, SOL_SOCKET, SO_RCVTIMEO, &tv, sizeof(tv));
> > > if (ret < 0) {
> > > printf("Failed to set socket timeout\n");
> > > return;
> > > }
> > >
> > > ssize_t count = recv(sock, buf, 2048, 0);
> > > if (count <= 0) {
> > > printf("Failed to read from socket\n");
> > > return;
> > > }
> > >
> > > close(sock);
> > >
> > > uint16_t *ethertype = (short*)(buf + 12);
> > > uint8_t *proto = (unsigned char *)(buf + 23);
> > > uint16_t *dport = (uint16_t *)(buf + 14 + 20);
> > >
> > > printf("Received packet with ethertype 0x%04hu, protocol 0x%02hhu
> > > and dport 0x%04hu\n", *ethertype, *proto, *dport);
> > > }
> > >
> > > int main() {
> > > for (size_t ii = 0; ii < 100; ++ii) {
> > > test();
> > > }
> > > }

2021-01-15 14:19:10

by Eric Dumazet

[permalink] [raw]
Subject: Re: cBPF socket filters failing - inexplicably?

On Fri, Jan 15, 2021 at 7:52 AM Alexei Starovoitov
<[email protected]> wrote:
>
> Adding appropriate mailing list to cc...
>
> My wild guess is that as soon as socket got created:
> socket(PF_PACKET, SOCK_RAW, htons(ETH_P_ALL));
> the packets were already queued to it.
> So later setsockopt() is too late to filter.
>
> Eric, thoughts?

Exactly, this is what happens.

I do not know how tcpdump and other programs deal with this.

Maybe by setting a small buffer size, or draining the queue.

>
> On Wed, Jan 6, 2021 at 6:55 AM Tom Cook <[email protected]> wrote:
> >
> > Another factoid to add to this: I captured all traffic on an
> > interface while the test program was running using
> >
> > tcpdump -i wlo1 -w capture.pcap
> >
> > observing that multiple packets got through the filter. I then built
> > the bpf_dbg program from the kernel source tree and ran the same
> > filter and capture file through it:
> >
> > $ tools/bpf_dbg
> > > load bpf 1,6 0 0 0
> > > load pcap capture.pcap
> > > run
> > bpf passes:0 fails:269288
> >
> > So bpf_dbg thinks the filter is correct; it's only when the filter is
> > attached to an actual socket that it fails occasionally.
> >
> > Regards,
> > Tom
> >
> > On Wed, Jan 6, 2021 at 10:07 AM Tom Cook <[email protected]> wrote:
> > >
> > > Just to note I have also reproduced this on a 5.10.0 kernel.
> > >
> > > On Tue, Jan 5, 2021 at 1:42 PM Tom Cook <[email protected]> wrote:
> > > >
> > > > In the course of tracking down a defect in some existing software,
> > > > I've found the failure demonstrated by the short program below.
> > > > Essentially, a cBPF program that just rejects every frame (ie always
> > > > returns zero) and is attached to a socket using setsockopt(SOL_SOCKET,
> > > > SO_ATTACH_FILTER, ...) still occasionally lets frames through to
> > > > userspace.
> > > >
> > > > The code is based on the first example in
> > > > Documentation/networking/filter.txt, except that I've changed the
> > > > content of the filter program and added a timeout on the socket.
> > > >
> > > > To reproduce the problem:
> > > >
> > > > # gcc test.c -o test
> > > > # sudo ./test
> > > > ... and in another console start a large network operation.
> > > >
> > > > In my case, I copied a ~300MB core file I had lying around to another
> > > > host on the LAN. The test code should print the string "Failed to
> > > > read from socket" 100 times. In practice, it produces about 10%
> > > > "Received packet with ethertype..." messages.
> > > >
> > > > I've observed the same result on Ubuntu amd64 glibc system running a
> > > > 5.9.0 kernel and also on Alpine arm64v8 muslc system running a 4.9.1
> > > > kernel. I've written test code in both C and Python. I'm fairly sure
> > > > this is not something I'm doing wrong - but very keen to have things
> > > > thrown at me if it is.
> > > >
> > > > Regards,
> > > > Tom Cook
> > > >
> > > >
> > > > #include <stdio.h>
> > > > #include <sys/socket.h>
> > > > #include <sys/types.h>
> > > > #include <arpa/inet.h>
> > > > #include <linux/if_ether.h>
> > > > #include <linux/filter.h>
> > > > #include <stdint.h>
> > > > #include <unistd.h>
> > > >
> > > > struct sock_filter code[] = {
> > > > { 0x06, 0, 0, 0x00 } /* BPF_RET | BPF_K 0 0 0 */
> > > > };
> > > >
> > > > struct sock_fprog bpf = {
> > > > .len = 1,
> > > > .filter = code,
> > > > };
> > > >
> > > > void test() {
> > > > uint8_t buf[2048];
> > > >
> > > > int sock = socket(PF_PACKET, SOCK_RAW, htons(ETH_P_ALL));
> > > > if (sock < 0) {
> > > > printf("Failed to open socket\n");
> > > > return;
> > > > }
> > > > int ret = setsockopt(sock, SOL_SOCKET, SO_ATTACH_FILTER, &bpf, sizeof(bpf));
> > > > if (ret < 0) {
> > > > printf("Failed to set socket filter\n");
> > > > return;
> > > > }
> > > > struct timeval tv = {
> > > > .tv_sec = 1
> > > > };
> > > >
> > > > ret = setsockopt(sock, SOL_SOCKET, SO_RCVTIMEO, &tv, sizeof(tv));
> > > > if (ret < 0) {
> > > > printf("Failed to set socket timeout\n");
> > > > return;
> > > > }
> > > >
> > > > ssize_t count = recv(sock, buf, 2048, 0);
> > > > if (count <= 0) {
> > > > printf("Failed to read from socket\n");
> > > > return;
> > > > }
> > > >
> > > > close(sock);
> > > >
> > > > uint16_t *ethertype = (short*)(buf + 12);
> > > > uint8_t *proto = (unsigned char *)(buf + 23);
> > > > uint16_t *dport = (uint16_t *)(buf + 14 + 20);
> > > >
> > > > printf("Received packet with ethertype 0x%04hu, protocol 0x%02hhu
> > > > and dport 0x%04hu\n", *ethertype, *proto, *dport);
> > > > }
> > > >
> > > > int main() {
> > > > for (size_t ii = 0; ii < 100; ++ii) {
> > > > test();
> > > > }
> > > > }

2021-01-15 22:49:34

by Tom Cook

[permalink] [raw]
Subject: Re: cBPF socket filters failing - inexplicably?

On Fri, Jan 15, 2021 at 2:16 PM Eric Dumazet <[email protected]> wrote:
[snip]
> > My wild guess is that as soon as socket got created:
> > socket(PF_PACKET, SOCK_RAW, htons(ETH_P_ALL));
> > the packets were already queued to it.
> > So later setsockopt() is too late to filter.
> >
> > Eric, thoughts?
>
> Exactly, this is what happens.

I understand. Thanks for the explanation.

> I do not know how tcpdump and other programs deal with this.
>
> Maybe by setting a small buffer size, or draining the queue.

libpcap has its own cBPF implementation which it applies after it
receives the packets from the queue.

Thanks again,
Tom Cook