Mittels eines „manuellen“ Canary-Releases habe ich vor einer Woche einen meiner Linux-Server hier im Haus von Debian 9 „Stretch“ auf Debian 10 „Buster“ migriert.

Wie es zu erwarten war, klappte das nicht ganz ohne Schluckauf. Beispielsweise schaltet sich der Monitor meines Lenovo ThinkPads X201 (P/N 3626GN7) nicht mehr automatisch aus. Leider habe ich die Lösung im Internet noch nicht gefunden.

Das beunruhigendste Problem war aber folgende Fehlermeldung von monit, die nach der Neukompilierung von pixelserv-tls mit Debian 10 „Buster“ in meinem Postfach landete:

Connection failed Service pixelserv-tls 

	Date:        Mon, 15 Jul 2019 22:44:25
	Action:      restart
	Host:        ADBLOCKER
	Description: failed protocol test [HTTP] at [10.1.2.3]:443 [TCP/IP TLS] -- SSL connection error: error:14094438:SSL routines:ssl3_read_bytes:tlsv1 alert internal error

Your faithful employee,
Monit

Der Aufruf der Statusseite unter http://10.1.2.3/servstats funktionierte ebenfalls nicht.

Am letzten Freitag fand ich nun etwas Zeit, um das Problem genauer anzuschauen.

Software-Versionen

pixelserv-tls hat seit Monaten keine Anpassung mehr erfahren — beim Abgleich meiner Sourcen mit denjenigen auf GitHub gab es nur in cert.c eine Anpassung, die ich einspielte, aber eigentlich nichts mit dem hier beschriebenen Problem zu tun hat.

Eine Ursache für das Problem war aber, dass die OpenSSL-Library, gegen welche pixelserv-tls kompiliert wird, aktualisiert worden war. Auf einem System mit Stretch (stable) waren installiert …

# dpkg --list | grep -i ssl
ii  libcurl3:amd64                       7.52.1-5+deb9u9                   amd64        easy-to-use client-side URL transfer library (OpenSSL flavour)
ii  libcurl4-openssl-dev:amd64           7.52.1-5+deb9u9                   amd64        development files and documentation for libcurl (OpenSSL flavour)
ii  libflac8:amd64                       1.3.2-1                           amd64        Free Lossless Audio Codec - runtime C library
ii  libgnutls-openssl27:amd64            3.5.8-5+deb9u4                    amd64        GNU TLS library - OpenSSL wrapper
ii  libio-socket-ssl-perl                2.044-1                           all          Perl module implementing object oriented interface to SSL sockets
ii  libnet-smtp-ssl-perl                 1.04-1                            all          Perl module providing SSL support to Net::SMTP
ii  libnet-ssleay-perl                   1.80-1                            amd64        Perl module for Secure Sockets Layer (SSL)
ii  libssl-dev:amd64                     1.1.0j-1~deb9u1                   amd64        Secure Sockets Layer toolkit - development files
ii  libssl-doc                           1.1.0j-1~deb9u1                   all          Secure Sockets Layer toolkit - development documentation
ii  libssl1.0.0:amd64                    1.0.1t-1+deb8u6                   amd64        Secure Sockets Layer toolkit - shared libraries
ii  libssl1.0.2:amd64                    1.0.2r-1~deb9u1                   amd64        Secure Sockets Layer toolkit - shared libraries
ii  libssl1.1:amd64                      1.1.0j-1~deb9u1                   amd64        Secure Sockets Layer toolkit - shared libraries
ii  mitmproxy                            0.18.2-6                          all          SSL-capable man-in-the-middle HTTP proxy
ii  openssl                              1.1.0j-1~deb9u1                   amd64        Secure Sockets Layer toolkit - cryptographic utility
ii  perl-openssl-defaults:amd64          3                                 amd64        version compatibility baseline for Perl OpenSSL packages
ii  python-backports.ssl-match-hostname  3.5.0.1-1                         all          Backport of the Python 3.5 SSL hostname checking function
ii  python-brotli                        0.5.2+dfsg-2                      amd64        lossless compression algorithm and format (Python 2 version)
ii  python-certifi                       2016.2.28-1                       all          root certificates for validating SSL certs and verifying TLS hosts
ii  python-openssl                       16.2.0-1                          all          Python 2 wrapper around the OpenSSL library
ii  python-passlib                       1.7.0-2                           all          comprehensive password hashing framework
ii  python-service-identity              16.0.0-2                          all          Service identity verification for pyOpenSSL (Python 2 module)
ii  ssl-cert                             1.0.39                            all          simple debconf wrapper for OpenSSL

… auf dem neuen System war hingegen installiert:

# dpkg --list | grep -i ssl
ii  libcurl4:amd64                 7.64.0-4                     amd64        easy-to-use client-side URL transfer library (OpenSSL flavour)
ii  libgnutls-openssl27:amd64      3.6.7-4                      amd64        GNU TLS library - OpenSSL wrapper
ii  libio-socket-ssl-perl          2.060-3                      all          Perl module implementing object oriented interface to SSL sockets
ii  libnet-smtp-ssl-perl           1.04-1                       all          Perl module providing SSL support to Net::SMTP
ii  libnet-ssleay-perl             1.85-2+b1                    amd64        Perl module for Secure Sockets Layer (SSL)
ii  libssl-dev:amd64               1.1.1c-1                     amd64        Secure Sockets Layer toolkit - development files
ii  libssl-doc                     1.1.1c-1                     all          Secure Sockets Layer toolkit - development documentation
ii  libssl1.0.0:amd64              1.0.1t-1+deb8u7              amd64        Secure Sockets Layer toolkit - shared libraries
ii  libssl1.1:amd64                1.1.1c-1                     amd64        Secure Sockets Layer toolkit - shared libraries
ii  libzstd1:amd64                 1.3.8+dfsg-3                 amd64        fast lossless compression algorithm
ii  mitmproxy                      4.0.4-5                      all          SSL-capable man-in-the-middle HTTP proxy
ii  openssl                        1.1.1c-1                     amd64        Secure Sockets Layer toolkit - cryptographic utility
ii  perl-openssl-defaults:amd64    3                            amd64        version compatibility baseline for Perl OpenSSL packages
ii  python3-brotli                 1.0.7-2                      amd64        lossless compression algorithm and format (Python 3 version)
ii  python3-certifi                2018.8.24-1                  all          root certificates for validating SSL certs and verifying TLS hosts (python3)
ii  python3-openssl                19.0.0-1                     all          Python 3 wrapper around the OpenSSL library
ii  python3-passlib                1.7.1-1                      all          comprehensive password hashing framework
ii  ssl-cert                       1.0.39                       all          simple debconf wrapper for OpenSSL

Relevant ist das Paket libssl-dev — auf Stretch war die Library 1.1.0j-1~deb9u1, in Buster 1.1.1c-1. Gegen diese kompiliert pixelserv-tls.

TLSv1.3?

Um Probleme mit TLSv1.3 auszuschliessen, hackte ich util.h und stellte das Script so ein, dass TLSv1.3-Support nie einkompiliert wird:

...
# ifdef TLS1_3_VERSION
#   define FEAT_TLS1_3  " no_tls1_3"
# else
#   define FEAT_TLS1_3  " no_tls1_3"
# endif
...

Leider half dies nichts zur Lösung des Problems.

Indem man pixelserv-tls ausführt, erfährt man, ob TLSv1.3 einkompiliert ist oder nicht:

$ pixelserv-tls --help
pixelserv-tls 2.2.1 (compiled: Jul 15 2019 22:34:41 flags: tfo tls1_3)
...

Respektive:

$ pixelserv-tls --help
pixelserv-tls 2.2.1 (compiled: Jul 15 2019 22:48:04 flags: tfo no_tls1_3)
...

Dasselbe erfährt man auch in error.log, wenn pixelserv-tls gestartet wird:

...
Jul 19 19:52:46 localhost pixelserv-tls[28352]: pixelserv-tls 2.2.1 (compiled: Jul 19 2019 19:51:13 flags: tfo no_tls1_3) options: 10.1.2.3 -u root -p 80 -k 443 -l 5 -z /tmp/pixelserv
...

AppArmor?

Zuerst vermutete ich ein Problem mit AppArmor, welches in Debian 10 out-of-the-box aktiviert ist und läuft. Doch nachdem ich mich ein wenig eingelesen hatte, war mir klar, dass AppArmor nur dann zur Anwendung kommt, wenn ein entsprechendes Applikationsprofil erstellt wurde. Auch scheint es keine Standardeinstellungen zu geben, die auf alle Prozesse angewendet werden.

Log-Analyse

Basierend auf den lokalen Einstellungen loggt pixelserv-tls mehr oder weniger hilfreiche Informationen in das syslog. Auf Grund der von mir temporär gewählten Kommandozeilenoption -l 4 („4“ steht für den Loglevel „info“) las ich dort:

$ tail -f /var/log/error.log
...
Jul 19 19:04:00 localhost pixelserv-tls[22361]: create_child_sslctx: cannot find or use $CERTDIR/_.google-analytics.com
Jul 19 19:04:00 localhost pixelserv-tls[22361]: tls_clienthello_cb: fail to create sslctx or cache _.google-analytics.com
...

Fragezeichen über Fragezeichen — haben wir ein Problem mit den Zertifikatsdateien?

Datei- und Verzeichnisberechtigungen

Dann vermutete ich Probleme beim Lesen und Schreiben der Zertifikate, obwohl ich an der Ordnerstruktur und den Ordner- und Dateiberechtigungen nichts geändert hatte. Sowohl das Starten von pixelserv-tls mit der Option -u root (normalerweise läuft pixelserv-tls unter „nobody“ — Sicherheitstechnisch eine sehr weise Einstellung, da die Software wie auch OpenSSL Schwachstellen aufweisen könnten, die dann jeder im lokalen Netzwerk ausnützen könnte) als auch das Verschieben des Zertifikatsordner nach /tmp/pixelserv lösten das Problem nicht.

Mit strace die Syscalls auf das Dateisystem anschauen

Auch die Verwendung von strace — einem Werkzeug, das ich nur bei ganz hartnäckigen Problemen zur Anwendung kommen lasse, zeigte keinen Hinweis, der mich auf die richtige Fährte gebracht hätte. Was ich lernte: Mittels der Option -p kann man sich bei strace in einen bereits laufenden Prozess „einklinken“. Hier das Resultat

# strace -p %PID%
...
select(8, [5 6 7], NULL, NULL, NULL)    = 1 (in [6])
accept(6, {sa_family=AF_INET, sin_port=htons(64242), sin_addr=inet_addr("10.0.1.102")}, [16]) = 9
fcntl(9, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(9, F_SETFL, O_RDWR)               = 0
setsockopt(9, SOL_TCP, TCP_NODELAY, [1], 4) = 0
setsockopt(9, SOL_SOCKET, SO_RCVTIMEO, "\0\0\0\0\0\0\0\0\360I\2\0\0\0\0\0", 16) = 0
getsockname(9, {sa_family=AF_INET, sin_port=htons(443), sin_addr=inet_addr("10.1.2.3")}, [128->16]) = 0
read(9, "\26\3\1\0\353", 5)             = 5
read(9, "\1\0\0\347\3\3n\277\307zl\26\2155A\257@\nFK\272\326x:Z\320\32:\347\32\2\217"..., 235) = 235
stat("/usr/local/apps/pixelserv/certs/_.optimizely.com", {st_mode=S_IFREG|0644, st_size=1596, ...}) = 0
openat(AT_FDCWD, "/usr/local/apps/pixelserv/certs/_.optimizely.com", O_RDONLY) = 10
fstat(10, {st_mode=S_IFREG|0644, st_size=1596, ...}) = 0
read(10, "-----BEGIN CERTIFICATE-----\nMIIB"..., 4096) = 1596
close(10)                               = 0
getpid()                                = 23461
sendto(3, "<27>Jul 19 19:21:47 pixelserv-tl"..., 131, MSG_NOSIGNAL, NULL, 0) = 131
getpid()                                = 23461
sendto(3, "<27>Jul 19 19:21:47 pixelserv-tl"..., 109, MSG_NOSIGNAL, NULL, 0) = 109
write(9, "\25\3\3\0\2\2P", 7)           = 7
getpid()                                = 23461
sendto(3, "<28>Jul 19 19:21:47 pixelserv-tl"..., 141, MSG_NOSIGNAL, NULL, 0) = 141
shutdown(9, SHUT_RDWR)                  = 0
close(9)

Da sah alles Bestens aus — das Zertifikat kann gelesen werden, wie die erste Zeile read(10, "-----BEGIN CERTIFICATE-----\nMIIB"..., 4096) = 1596
verdeutlicht.

Quellcode-Analyse

Als nächstes muss man sich in solchen hartnäckigen Fällen mit dem Source-Code auseinandersetzen. Ich durchsuchte das GitHub-Repository nach folgender Fehlermeldung: „cannot find or use“. Fündig wurde ich dazu in cert.c, ab Zeile 814:

...
if(SSL_CTX_use_certificate_file(sslctx, full_pem_path, SSL_FILETYPE_PEM) <= 0
       || SSL_CTX_use_PrivateKey_file(sslctx, full_pem_path, SSL_FILETYPE_PEM) <= 0)
    {
        SSL_CTX_free(sslctx);
        log_msg(LGG_ERR, "%s: cannot find or use %s\n", __FUNCTION__, full_pem_path);
        return NULL;
    }
...

Na toll! Die Log-Meldung wird somit generiert, wenn die OpenSSL-nativen-Funktionen SSL_CTX_use_certificate_file() oder SSL_CTX_use_PrivateKey_file() einen Wert zurückgeben, der kleiner gleich 0 ist. Gemäss Dokumentation der quelloffenen Library meldet ein Rückgabewert von 1, dass die Funktion erfolgreich ausgeführt wurde.

Quellcode hacken

Ich bin kein C-Programmierer, aber mir gefiel die Programmlogik aus folgenden Gründen nicht:

1. Wenn eine der beiden Funktionen einen Fehler zurückgibt, bricht der Programmcode ab. Schön, dass man den Code damit komprimiert hat, aber beim Debugging wäre es noch nett zu wissen, welche der beiden Funktionen den Fehler generiert.
2. Die Fehlermeldung "%s: cannot find or use %s\n" mit den zwei Variablen "Funktion" sowie dem Pfad zum Zertifikat sagt rein gar nichts darüber, was denn nun konkret schiefgegangen ist.
3. <= 0 empfinde ich als den falschen Ansatz: Ich würde stattdessen prüfen, ob der Rückgabewert NICHT 1 entspricht (an dem sind wir interessiert).

Um dem Problem näher zu kommen war es deshalb nötig, dass ich selbst Hand an den Code anlegte, die Logik entzwirnte sowie die in OpenSSL intern vorhandenen detaillierten Fehlermeldungen in das Log ausgab. Natürlich fand ich über etwas Googlen heraus, wie man OpenSSL diese Fehlermeldung entlockt. Dies führte zu folgendem Code:

...
    if(!SSL_CTX_use_certificate_file(sslctx, full_pem_path, SSL_FILETYPE_PEM)) {
        log_msg(LGG_ERR, "%s: SSL_CTX_use_certificate_file error for file %s with error %s\n", __FUNCTION__, full_pem_path, ERR_error_string( ERR_get_error(), NULL ));
    }
    if(!SSL_CTX_use_PrivateKey_file(sslctx, full_pem_path, SSL_FILETYPE_PEM)) {
        log_msg(LGG_ERR, "%s: SSL_CTX_use_PrivateKey_file error for file %s with error %s\n", __FUNCTION__, full_pem_path, ERR_error_string( ERR_get_error(), NULL ));
    }
...

Die wahre Fehlermeldung

Neu kompiliert, installiert und gestartet, dann die Werbeschleuder SPIEGEL Online angesurft und das Log überprüft:

$ tail -f /var/log/error.loa
...
create_child_sslctx: SSL_CTX_use_certificate_file error for file /tmp/pixelserv/_.ioam.de with error error:140AB18F:SSL routines:SSL_CTX_use_certificate:ee key too small
...

"ee key too small"? Now we're talking! Eine erneute Google-Suche ergab, dass sich OpenSSL 1.1.1 (im Gegensatz zu 1.1.0) weigert, ein Zertifikat zu verarbeiten, dessen RSA-Schlüssellänge kleiner als 2048 Bit ist.

Die Lösung des Problems

Ich nahm deshalb folgende zwei Anpassungen vor:

Zuerst einmal generierte ich eine neue ca.key mit einer Schlüssellänge von 2048 Bits:

$ openssl genrsa -out $CERTDIR/ca.key 2048

Anschliessend passte ich auch noch cert.c an, da dort die mittlerweile als schwach erachtete Schlüssellänge (1024) hartkodiert ist:

...
if (RSA_generate_key_ex(rsa, 2048, e, NULL) < 0)
...

Seit ich pixelserv-tls ein letztes Mal neu kompiliert und installiert habe, funktioniert das Schwarze Loch für alle Arten von Web-basierten Trackern wieder einwandfrei.

Verifikation

Überprüfen kann man das ... natürlich auch mit openssl auf einem separaten Client:

pixelserv-tls funktioniert nicht (richtig)

$ openssl s_client -connect www.googleadservices.com:443
CONNECTED(00000003)
140735858492360:error:14077438:SSL routines:SSL23_GET_SERVER_HELLO:tlsv1 alert internal error:s23_clnt.c:802:
---
no peer certificate available
---
No client certificate CA names sent
---
SSL handshake has read 7 bytes and written 308 bytes
---
New, (NONE), Cipher is (NONE)
Secure Renegotiation IS NOT supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
SSL-Session:
    Protocol  : TLSv1.2
    Cipher    : 0000
    Session-ID: 
    Session-ID-ctx: 
    Master-Key: 
    Key-Arg   : None
    PSK identity: None
    PSK identity hint: None
    SRP username: None
    Start Time: 1563537109
    Timeout   : 300 (sec)
    Verify return code: 0 (ok)
---

pixelserv-tls funktioniert (richtig)

Und jetzt:

CONNECTED(00000003)
depth=1 CN = Pixelserv CA
verify error:num=19:self signed certificate in certificate chain
---
Certificate chain
 0 s:/CN=10.1.2.3
   i:/CN=Pixelserv CA
 1 s:/CN=Pixelserv CA
   i:/CN=Pixelserv CA
---
Server certificate
-----BEGIN CERTIFICATE-----
MII...=
-----END CERTIFICATE-----
subject=/CN=10.1.2.3
issuer=/CN=Pixelserv CA
---
No client certificate CA names sent
Peer signing digest: SHA256
Server Temp Key: ECDH, P-256, 256 bits
---
SSL handshake has read 2148 bytes and written 434 bytes
---
New, TLSv1/SSLv3, Cipher is ECDHE-RSA-AES128-GCM-SHA256
Server public key is 2048 bit
Secure Renegotiation IS supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
SSL-Session:
    Protocol  : TLSv1.2
    Cipher    : ECDHE-RSA-AES128-GCM-SHA256
    Session-ID: F66E6966BF7CE8F970AF4834A1CC45FE396D1F7B041F512CA5B3F65419EACD24
    Session-ID-ctx: 
    Master-Key: 7EE1C54219A4CABF0BEB73BB420C93DD4F51F5F319897937137B9C1093045B4EB91B0FD50F30154DF5A7D18AD95A493C
    Key-Arg   : None
    PSK identity: None
    PSK identity hint: None
    SRP username: None
    TLS session ticket lifetime hint: 3600 (seconds)
    TLS session ticket:
    0000 - e8 63 17 bb 31 c0 91 7d-95 eb f8 b4 78 dc a6 89   .c..1..}....x...
    0010 - be 14 43 2c ac cc 4c dd-f3 e9 9d f5 cb 36 46 a4   ..C,..L......6F.
    0020 - c6 9a 67 7c fb 83 a1 a6-6d 74 6b 62 4e b5 60 33   ..g|....mtkbN.`3
    0030 - 8b 1b 5f 1f cf ba c6 bf-73 c0 8a 7d 31 db 8a 75   .._.....s..}1..u
    0040 - 81 8b b3 c3 e5 76 1e 34-c3 3d 2e 11 e4 58 a3 fc   .....v.4.=...X..
    0050 - 73 5b 2e 9c 13 f5 64 4e-c3 26 10 98 96 e1 64 aa   s[....dN.&....d.
    0060 - ce 41 aa cd 54 68 12 a1-87 10 98 cc f0 e5 e9 d9   .A..Th..........
    0070 - de ec e6 2e 83 80 8f 51-71 ff 07 eb a7 b2 66 ae   .......Qq.....f.
    0080 - ad b5 44 c0 47 06 eb b7-5f 19 c2 74 5d 1f 47 20   ..D.G..._..t].G 
    0090 - 5d 93 0f 57 c4 ee 86 b7-7e 7f e3 2a ed 57 27 43   ]..W....~..*.W'C

    Start Time: 1563745313
    Timeout   : 300 (sec)
    Verify return code: 19 (self signed certificate in certificate chain)
---

Das Problem habe ich nun auch im GitHub Issue-Tracker des Projekts beschrieben ("Use 2048-bit RSA key to make pixelserv-tls work on Debian 10 "Buster""). Eigentlich hätte ich den Patch ja auch gleich selber als Pull Request hochladen können, doch diese Funktion von Git verstehe ich immer noch nicht wirklich richtig ... hoffen wir, dass der Maintainer die Ursache des Problems deshalb selber bald beseitigt.