linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* cBPF socket filters failing - inexplicably?
@ 2021-01-05 13:42 Tom Cook
  2021-01-06 10:07 ` Tom Cook
  0 siblings, 1 reply; 6+ messages in thread
From: Tom Cook @ 2021-01-05 13:42 UTC (permalink / raw)
  To: linux-kernel

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();
    }
}

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: cBPF socket filters failing - inexplicably?
  2021-01-05 13:42 cBPF socket filters failing - inexplicably? Tom Cook
@ 2021-01-06 10:07 ` Tom Cook
  2021-01-06 14:51   ` Tom Cook
  0 siblings, 1 reply; 6+ messages in thread
From: Tom Cook @ 2021-01-06 10:07 UTC (permalink / raw)
  To: linux-kernel

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 <tom.k.cook@gmail.com> 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();
>     }
> }

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: cBPF socket filters failing - inexplicably?
  2021-01-06 10:07 ` Tom Cook
@ 2021-01-06 14:51   ` Tom Cook
  2021-01-15  6:52     ` Alexei Starovoitov
  0 siblings, 1 reply; 6+ messages in thread
From: Tom Cook @ 2021-01-06 14:51 UTC (permalink / raw)
  To: linux-kernel

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 <tom.k.cook@gmail.com> 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 <tom.k.cook@gmail.com> 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();
> >     }
> > }

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: cBPF socket filters failing - inexplicably?
  2021-01-06 14:51   ` Tom Cook
@ 2021-01-15  6:52     ` Alexei Starovoitov
  2021-01-15 14:16       ` Eric Dumazet
  0 siblings, 1 reply; 6+ messages in thread
From: Alexei Starovoitov @ 2021-01-15  6:52 UTC (permalink / raw)
  To: Tom Cook, bpf, Network Development, Eric Dumazet; +Cc: LKML

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 <tom.k.cook@gmail.com> 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 <tom.k.cook@gmail.com> 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 <tom.k.cook@gmail.com> 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();
> > >     }
> > > }

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: cBPF socket filters failing - inexplicably?
  2021-01-15  6:52     ` Alexei Starovoitov
@ 2021-01-15 14:16       ` Eric Dumazet
  2021-01-15 22:45         ` Tom Cook
  0 siblings, 1 reply; 6+ messages in thread
From: Eric Dumazet @ 2021-01-15 14:16 UTC (permalink / raw)
  To: Alexei Starovoitov; +Cc: Tom Cook, bpf, Network Development, LKML

On Fri, Jan 15, 2021 at 7:52 AM Alexei Starovoitov
<alexei.starovoitov@gmail.com> 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 <tom.k.cook@gmail.com> 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 <tom.k.cook@gmail.com> 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 <tom.k.cook@gmail.com> 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();
> > > >     }
> > > > }

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: cBPF socket filters failing - inexplicably?
  2021-01-15 14:16       ` Eric Dumazet
@ 2021-01-15 22:45         ` Tom Cook
  0 siblings, 0 replies; 6+ messages in thread
From: Tom Cook @ 2021-01-15 22:45 UTC (permalink / raw)
  To: Eric Dumazet; +Cc: Alexei Starovoitov, bpf, Network Development, LKML

On Fri, Jan 15, 2021 at 2:16 PM Eric Dumazet <edumazet@google.com> 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

^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2021-01-15 22:47 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-01-05 13:42 cBPF socket filters failing - inexplicably? Tom Cook
2021-01-06 10:07 ` Tom Cook
2021-01-06 14:51   ` Tom Cook
2021-01-15  6:52     ` Alexei Starovoitov
2021-01-15 14:16       ` Eric Dumazet
2021-01-15 22:45         ` Tom Cook

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