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:
- 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.
- 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.
- <= 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.
Ein Kommentar Kommentare
Hallo Mario,
danke für den interessanten und ausführlichen Bericht zu diesem Thema.
Ich habe noch eine grundsätzliche Frage/Anmerkung zum Ad-Blocking: Wäre es nicht noch schneller, wenn anstatt eines Webserver, einfach das Betriebssystem die umgeleitete Anfrage mit einem TCP-Reset beantwortet. So wären es nur zwei TCP-Pakete anstatt mindestens fünf (bei HTTP/2 ggf. drei).
Grüße,
Patrick