www.fabiankeil.de/blog-surrogat/2020/06/09/openbsd-libc-bug-und-privoxy.html

Privoxy-Abstürze mit OpenBSD 6.7

Vor ein paar Wochen wurde ich auf eine Mail aufmerksam, derzufolge Privoxy auf einem OpenBSD-System nicht stabil lief.

Um das Problem nachvollziehen zu können habe ich mir daher vor etwa einer Woche OpenBSD 6.7 amd64 zum Testen installiert.

Bereits beim Ausführen von Privoxy-Regression-Test stürzte Privoxy reproduzierbar ab.

Privoxy-Regression-Test in Konsole 1

fk@openbsd ~ $~/git/privoxy/tools/privoxy-regression-test.pl --privoxy-address http://192.168.3.101:8118/
2020-06-03 13:21:53: Asking Privoxy for the number of action files available ...
2020-06-03 13:21:54: Gathering regression tests from 4 action file(s) delivered by Privoxy 3.0.29.
2020-06-03 13:21:56: Executing regression tests ...
2020-06-03 13:27:19: Fetch failure: 'curl: (52) Empty reply from server'
2020-06-03 13:27:20: Fetch failure: 'curl: (7) Failed to connect to 192.168.3.101 port 8118: Connection refused'
2020-06-03 13:27:20: Oh noes. Running curl failed 1 times in a row. Last error: 'curl: (7) Failed to connect to 192.168.3.101 port 8118: Connection refused'. Fatal error. Exiting.

Privoxy in Konsole 2

fk@openbsd ~/git/privoxy $./privoxy --no-daemon ~/privoxy/config
[...]
2020-06-03 13:27:19.421 ef6eb681570 Connect: Waiting for the next client connection. Currently active threads: 1
2020-06-03 13:27:19.423 ef6e0e3ba40 Connect: Accepted connection from 192.168.3.101 on socket 4
2020-06-03 13:27:19.437 ef6e0e3ba40 Connect: Complete client request received.
2020-06-03 13:27:19.439 ef6e0e3ba40 Header: scan: GET http://oh-dear-this-hostname-is-short-enough-but-there-is-no-socks4-server-listening.example/ HTTP/1.1
2020-06-03 13:27:19.440 ef6e0e3ba40 Header: scan: Host: oh-dear-this-hostname-is-short-enough-but-there-is-no-socks4-server-listening.example
2020-06-03 13:27:19.440 ef6e0e3ba40 Header: scan: User-Agent: Privoxy-Regression-Test 0.7.1
2020-06-03 13:27:19.440 ef6e0e3ba40 Header: scan: Accept: */*
2020-06-03 13:27:19.440 ef6e0e3ba40 Header: scan: Proxy-Connection: Keep-Alive
2020-06-03 13:27:19.440 ef6e0e3ba40 Header: scan: Connection: close
2020-06-03 13:27:19.441 ef6e0e3ba40 Header: crumble crunched: Proxy-Connection: Keep-Alive!
2020-06-03 13:27:19.441 ef6e0e3ba40 Header: Removing 'Connection: close' to imply keep-alive.
[...]
2020-06-03 13:27:19.442 ef6e0e3ba40 Connect: Overriding forwarding settings based on 'forward-socks4 127.0.0.1:12345 .'
2020-06-03 13:27:19.442 ef6e0e3ba40 Request: oh-dear-this-hostname-is-short-enough-but-there-is-no-socks4-server-listening.example/
2020-06-03 13:27:19.442 ef6e0e3ba40 Header: New HTTP Request-Line: GET / HTTP/1.1
2020-06-03 13:27:19.442 ef6e0e3ba40 Connect: to oh-dear-this-hostname-is-short-enough-but-there-is-no-socks4-server-listening.example
Segmentation fault (core dumped)

Der Test soll hauptsächlich das Verhalten testen, wenn ein Socks4-Server nicht ansprechbar ist, führt aber als Nebeneffekt auch zum Auflösen eines Hostnamens.

Crash-Analyse mit gdb

fk@openbsd ~/git/privoxy $egdb privoxy privoxy.core
GNU gdb (GDB) 7.12.1
Copyright (C) 2017 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-unknown-openbsd6.7".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from privoxy...done.
[New process 534706]
[New process 289915]
Core was generated by `privoxy'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00000ef6eb61196d in unpack_data (p=0xef73e0d2740, data=0xef73e0d2770, len=12) at /usr/src/lib/libc/asr/asr_utils.c:193
193     /usr/src/lib/libc/asr/asr_utils.c: No such file or directory.
[Current thread is 1 (process 534706)]
(gdb) where
#0  0x00000ef6eb61196d in unpack_data (p=0xef73e0d2740, data=0xef73e0d2770, len=12) at /usr/src/lib/libc/asr/asr_utils.c:193
#1  _asr_unpack_header (p=0xef73e0d2740, h=0xef73e0d2770) at /usr/src/lib/libc/asr/asr_utils.c:257
#2  0x00000ef6eb5dc944 in hostent_from_packet (reqtype=3, family=2, pkt=<optimized out>, pktlen=<optimized out>) at /usr/src/lib/libc/asr/gethostnamadr_async.c:463
#3  gethostnamadr_async_run (as=<optimized out>, ar=<optimized out>) at /usr/src/lib/libc/asr/gethostnamadr_async.c:305
#4  0x00000ef6eb5ef368 in _libc_asr_run (as=0xef6fcf2c000, ar=0xef73e0d2870) at /usr/src/lib/libc/asr/asr.c:176
#5  _libc_asr_run_sync (as=0xef6fcf2c000, ar=0xef73e0d2870) at /usr/src/lib/libc/asr/asr.c:223
#6  0x00000ef6eb65204e in _gethostbyname (name=0xef7c2ea9480 "oh-dear-this-hostname-is-short-enough-but-there-is-no-socks4-server-listening.example", af=2, ret=<optimized out>, buflen=4096, h_errnop=<optimized out>, 
    buf=<optimized out>) at /usr/src/lib/libc/asr/gethostnamadr.c:119
#7  _libc_gethostbyname2 (name=0xef7c2ea9480 "oh-dear-this-hostname-is-short-enough-but-there-is-no-socks4-server-listening.example", af=2) at /usr/src/lib/libc/asr/gethostnamadr.c:154
#8  0x00000ef4deef30bc in resolve_hostname_to_ip (host=0xef7c2ea9480 "oh-dear-this-hostname-is-short-enough-but-there-is-no-socks4-server-listening.example") at jbsockets.c:1580
#9  0x00000ef4deeefe48 in socks4_connect (fwd=0xef76e475980, target_host=0xef7c2ea9480 "oh-dear-this-hostname-is-short-enough-but-there-is-no-socks4-server-listening.example", target_port=80, csp=0xef750e2d5e8)
    at gateway.c:758
#10 0x00000ef4deeef9bc in forwarded_connect (fwd=0xef76e475980, http=0xef750e2d880, csp=0xef750e2d5e8) at gateway.c:621
#11 0x00000ef4deef589d in chat (csp=0xef750e2d5e8) at jcc.c:3784
#12 0x00000ef4deef4b21 in serve (csp=0xef750e2d5e8) at jcc.c:4204
#13 0x00000ef7743a40d1 in _rthread_start (v=<optimized out>) at /usr/src/lib/librthread/rthread.c:96
#14 0x00000ef6eb5dc5e8 in __tfork_thread () at /usr/src/lib/libc/arch/amd64/sys/tfork_thread.S:77
#15 0x0000000000000000 in ?? ()

Die Speicherverletzung trat also auf, als ein Privoxy-Thread versuchte einen vergleichbar langen Hostnamen in eine IP-Adresse aufzulösen. Kürzere Hostnamen wie zum Beispiel www.openbsd.org führten nicht zu einem Absturz.

Privoxys Unschuld bewiesen

Ein schnell geschriebenes Testprogramm ohne Privoxy-Code führte zu einem vergleichbarem Crash, wenn der Hostname lang genug war:

openbsd$ cat resolve.c 
#include <netdb.h>
#include <pthread.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>

pthread_mutex_t mutex;

void resolve(char *host) {
    int error;
    error = pthread_mutex_lock(&mutex);
    if (error) {
        printf("Locking failed: %s", strerror(error));
        exit(1);
    }
    printf("Calling gethostbyname with %s\n", host);
    gethostbyname(host);
    pthread_mutex_unlock(&mutex);
}

int main(int argc, char **argv) {
    pthread_t the_thread;
    pthread_attr_t attrs;
    int i;

    if (!argc) {
        printf("No argument to resolve given\n");
        exit(1);
    }

    pthread_attr_init(&attrs);
    pthread_attr_setdetachstate(&attrs, PTHREAD_CREATE_DETACHED);

    pthread_mutex_init(&mutex, NULL);

    for (i = 0; i < 3; i++) {
        pthread_create(&the_thread, &attrs, (void * (*)(void *))resolve, argv[1]);
    }

    sleep(1);

    exit(0);
}
openbsd$ clang -pthread -ggdb -Wall -o resolve resolve.c 
openbsd$ ./resolve AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA.example.org
Calling gethostbyname with AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA.example.org
Calling gethostbyname with AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA.example.org
Calling gethostbyname with AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA.example.org
openbsd$ ./resolve AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA.example.org
Calling gethostbyname with AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA.example.org
Segmentation fault (core dumped) 
openbsd$ egdb resolve resolve.core
GNU gdb (GDB) 7.12.1
Copyright (C) 2017 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-unknown-openbsd6.7".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from resolve...done.
[New process 616459]
[New process 145207]
[New process 578084]
[New process 517316]
Core was generated by `resolve'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x0000031a025d201d in unpack_data (p=0x31a6a754b40, data=0x31a6a754b70, len=12) at /usr/src/lib/libc/asr/asr_utils.c:193
193	/usr/src/lib/libc/asr/asr_utils.c: No such file or directory.
[Current thread is 1 (process 616459)]
(gdb) where
#0  0x0000031a025d201d in unpack_data (p=0x31a6a754b40, data=0x31a6a754b70, len=12) at /usr/src/lib/libc/asr/asr_utils.c:193
#1  _asr_unpack_header (p=0x31a6a754b40, h=0x31a6a754b70) at /usr/src/lib/libc/asr/asr_utils.c:257
#2  0x0000031a0265db34 in hostent_from_packet (reqtype=3, family=2, pkt=<optimized out>, pktlen=<optimized out>) at /usr/src/lib/libc/asr/gethostnamadr_async.c:463
#3  gethostnamadr_async_run (as=<optimized out>, ar=<optimized out>) at /usr/src/lib/libc/asr/gethostnamadr_async.c:305
#4  0x0000031a02603308 in _libc_asr_run (as=0x319e01a2e00, ar=0x31a6a754c70) at /usr/src/lib/libc/asr/asr.c:176
#5  _libc_asr_run_sync (as=0x319e01a2e00, ar=0x31a6a754c70) at /usr/src/lib/libc/asr/asr.c:223
#6  0x0000031a025f994e in _gethostbyname (name=0x7f7ffffd01ba 'A' <repeats 64 times>, ".example.org", af=2, ret=<optimized out>, buflen=4096, h_errnop=<optimized out>, buf=<optimized out>)
    at /usr/src/lib/libc/asr/gethostnamadr.c:119
#7  _libc_gethostbyname2 (name=0x7f7ffffd01ba 'A' <repeats 64 times>, ".example.org", af=2) at /usr/src/lib/libc/asr/gethostnamadr.c:154
#8  0x00000317d0a323c4 in resolve (host=0x7f7ffffd01ba 'A' <repeats 64 times>, ".example.org") at resolve.c:18
#9  0x0000031ab56970d1 in _rthread_start (v=<optimized out>) at /usr/src/lib/librthread/rthread.c:96
#10 0x0000031a0264cdb8 in __tfork_thread () at /usr/src/lib/libc/arch/amd64/sys/tfork_thread.S:77
#11 0x0000000000000000 in ?? ()

Damit war klar, dass der Bug kein Fehler in Privoxy war. Daher habe ich den Test-Code an misc@openbsd.org geschickt und die weitere Analyse vertagt.

Bereits fünf Tage später haben die OpenBSD-Entwickler den Fehler selbst behoben und OpenBSD 6.7 errata 009 veröffentlicht. Die Commit-Meldung enthält geringfügig mehr Details.

Patchen mit syspatch

Ich hatte schon eine Weile kein OpenBSD mehr administriert, syspatch war mir daher neu. Es erlaubt recht komfortabel das Einspielen von Binär-Patches:

fk@openbsd ~ $ doas syspatch -c
001_wscons
002_rpki
003_ssh
004_libssl
005_unbound
006_smtpd_sockaddr
007_perl
008_hid
009_asr
fk@openbsd ~ $ doas syspatch   
Get/Verify syspatch67-001_wscons.tgz 100% |********************************************************|   128 KB    00:00    
Installing patch 001_wscons
Get/Verify syspatch67-002_rpki.tgz 100% |**********************************************************| 41490       00:00    
Installing patch 002_rpki
Get/Verify syspatch67-003_ssh.tgz 100% |***********************************************************|   187 KB    00:00    
Installing patch 003_ssh
Get/Verify syspatch67-004_libssl.tgz 100% |********************************************************|  4442 KB    00:03    
Installing patch 004_libssl
Get/Verify syspatch67-005_unbound... 100% |********************************************************|  3411 KB    00:03    
Installing patch 005_unbound
Get/Verify syspatch67-006_smtpd_s... 100% |********************************************************|   228 KB    00:00    
Installing patch 006_smtpd_sockaddr
Get/Verify syspatch67-007_perl.tgz 100% |**********************************************************|  6220 KB    00:04    
Installing patch 007_perl
Get/Verify syspatch67-008_hid.tgz 100% |***********************************************************| 25268       00:00    
Installing patch 008_hid
Get/Verify syspatch67-009_asr.tgz 100% |***********************************************************| 12504 KB    00:09    
Installing patch 009_asr
Relinking to create unique kernel... done; reboot to load the new kernel
Errata can be reviewed under /var/syspatch

Da könnte sich ElectroBSD eine Scheibe von abschneiden ...

Mit dem Einspielen von 009_asr war der Fehler behoben und die Privoxy-Regression-Tests konnten bis zum Schluss ausgeführt werden:

fk@openbsd ~ $~/git/privoxy/tools/privoxy-regression-test.pl --privoxy-address http://192.168.3.101:8118/
2020-06-09 14:01:03: Asking Privoxy for the number of action files available ...
2020-06-09 14:01:04: Gathering regression tests from 4 action file(s) delivered by Privoxy 3.0.29.
2020-06-09 14:01:07: Executing regression tests ...
2020-06-09 14:06:50: Executed 701 regression tests. Skipped 45. 701 successes, 0 failures.

Dass die Tests so lange brauchen liegt an Qemu ...