Package: torsocks Version: 2.4.0-1 Severity: important Tags: upstream X-Debbugs-Cc: debbug.torso...@sideload.33mail.com
After upgrading from Bullseye to Bookworm, this is what happens in the logs when sending a Tor-routed message: (/var/log/mail.log) ===8<---------------------------------------- 2024-04-25T13:10:25.165542+02:00 MannysHost postfix/smtpd[*]: connect from localhost[127.0.0.1] 2024-04-25T13:10:25.186729+02:00 MannysHost postfix/smtpd[*]: 2D6EFE313A: client=localhost[127.0.0.1] 2024-04-25T13:10:25.232021+02:00 MannysHost postfix/cleanup[*]: 2D6EFE313A: message-id=<timestamp.yadayada@MannysHost> 2024-04-25T13:10:25.236765+02:00 MannysHost postfix/qmgr[*]: 2D6EFE313A: from=<debbug.1069...@sideload.33mail.com>, size=1181, nrcpt=1 (queue active) 2024-04-25T13:10:25.236875+02:00 MannysHost postfix/smtpd[*]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5 2024-04-25T13:10:25.298945+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:26.357045+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:27.444922+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:28.533021+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:29.636915+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:30.694143+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:31.808365+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:32.921259+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:34.026594+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:35.140735+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:36.234895+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:37.352079+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:38.440755+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented 2024-04-25T13:10:39.549476+02:00 MannysHost postfix/smtp[*]: fatal: socket: Function not implemented … ===8<---------------------------------------- This is what the log looked like in Bullseye just before the upgrade, when sending over Tor still worked correctly: (/var/log/mail.log) ===8<---------------------------------------- Apr 24 09:37:17 MannysHost postfix/postfix-script[2130]: refreshing the Postfix mail system Apr 24 09:37:17 MannysHost postfix/master[1026]: reload -- version 3.5.24, configuration /etc/postfix Apr 24 09:37:17 MannysHost postfix/postfix-script[2168]: refreshing the Postfix mail system Apr 24 09:37:17 MannysHost postfix/master[1026]: reload -- version 3.5.24, configuration /etc/postfix Apr 24 12:32:42 MannysHost postfix/submission/smtpd[27946]: connect from localhost[127.0.0.1] Apr 24 12:32:42 MannysHost postfix/submission/smtpd[27946]: 3C344E3262: client=localhost[127.0.0.1] Apr 24 12:32:42 MannysHost postfix/submission/cleanup/cleanup[27949]: 3C344E3262: message-id=<timestamp.yadayada@MannysHost> Apr 24 12:32:42 MannysHost postfix/submission/smtpd[27946]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5 Apr 24 12:32:42 MannysHost postfix/qmgr[2173]: 3C344E3262: from=<manny’s...@email.addy>, size=1126, nrcpt=1 (queue active) Apr 24 12:32:50 MannysHost postfix/smtptor/smtp[27956]: 3C344E3262: to=<t...@recipient.addy>, relay=recipient.mx.server[1.2.3.4]:587, delay=8.1, delays=0.07/0.13/5.8/2.1, dsn=2.0.0, status=sent (250 OK id=yadayada) ===8<---------------------------------------- Sending over clearnet has no issues in any version. It’s only when a message must go over the Tor network that there is a problem. The configuration consists of the following: (/etc/postfix/master.cf) ===8<---------------------------------------- # The syslog_name option is not needed. It can be set to # anything. It’s just to add distinction in mail.log between clearnet # and Tor mail (otherwise both kinds of transmission are prefixed as # “postfix/smtp”). # smtptor unix - - n - - smtp_tor -o smtp_address_preference=ipv4 -o smtp_dns_support_level=disabled -o smtp_tls_security_level=none -o debug_peer_level=2 -o syslog_name=postfix/smtptor ===8<---------------------------------------- (/usr/lib/postfix/sbin/smtp_tor) ===8<---------------------------------------- !/bin/bash typeset -r dir_cmd=$(/usr/sbin/postconf -h command_directory) typeset -r exec_smtp=$("$dir_cmd"/postconf -h daemon_directory)/smtp setx_output() { if [[ $1 ]]; then exec 4>>"$1" BASH_XTRACEFD=4 PS4='\D{+%F}T\t $LINENO: ' set -x else set +x #BASH_XTRACEFD=2 exec 4>&- fi } setx_output /var/log/mail_${0##*/}.log torsocks "$exec_smtp" "$@" setx_output ===8<---------------------------------------- To setup routing, the transport db is used. (/etc/postfix/tor_transport) ===8<---------------------------------------- … .onion smtptor: ===8<---------------------------------------- (/etc/postfix/main.cf) ===8<---------------------------------------- … transport_maps = regexp:/etc/postfix/tor_transport_regexp, hash:/etc/postfix/tor_transport, hash:/etc/postfix/transport ===8<---------------------------------------- This is what appears in the separate logfile for the smtp wrapper in both the success and failure cases: (/var/log/mail_smtp_tor.log) ===8<---------------------------------------- … 77: torsocks /usr/lib/postfix/sbin/smtp -n smtptor -t unix -u -o smtp_address_preference=ipv4 -o smtp_dns_support_level=disabled -o smtp_tls_security_level=none -o debug_peer_level=2 -o syslog_name=postfix/smtptor ===8<---------------------------------------- The fatal error began after upgrading to Bookworm. Two recent postfix versions were tried in Bookworm. Then Postfix was downgraded back to the known working version and the fatal error persisted. So the sequence of tests went like this: Debian release -- Postfix ver -- kernel ver -- torsocks ver -- state Bullseye -- 3.5.24-0+deb11u1 -- 5.10.0-28 -- 2.3.0-3 -- worked (for years, likely spanning older versions as well) Bookworm -- 3.7.10-0+deb12u1 -- 6.1.0-20 -- 2.4.0-1 -- fatal error Bookworm -- 3.7.6-0+deb12u2 -- 6.1.0-20 -- 2.4.0-1 -- fatal error Bookworm -- 3.5.24-0+deb11u1 -- 6.1.0-20 -- 2.4.0-1 -- fatal error Bookworm -- 3.5.24-0+deb11u1 -- 5.10.0-28 -- 2.4.0-1 -- fatal error Bookworm -- 3.5.24-0+deb11u1 -- 5.10.0-28 -- 2.3.0-3 -- works Bookworm -- 3.7.10-0+deb12u1 -- 5.10.0-28 -- 2.3.0-3 -- works It’s evident from all the combinations of versions that torsocks version 2.4.0-1 is the problem, which must have been introduced after version 2.3.0-3. This is a catastrophic failure for four reasons: ① service is denied without workaround ② the bug is also very hard to detect because Postfix is the primary suspect and the kernel was the 2nd most likely culprit for the given clues. The log file showed “postfix/smtp” not “postfix/smtptor” in the failure case, making it (falsely) appear as if Postfix was not even running the Tor sending wrapper script. But the nature of the failure causes Postfix to log the wrong syslog_name. We also would not quickly expect a relatively simple package like torsocks to cause this failure. All of this made the bug hunt costly. ③ Postfix also does not behave well in this case. It reattempts to send the message endlessly, copious times per second, causing log files to be trashed with copious output. ④ Debugging Postfix is complex and cumbersome. You apparently cannot simply run “torsocks smtp” on the commandline. The smtp program was not designed for that and depends on other Postfix facilities to be in place. So either complex stubs and drivers would be needed for testing or we must resort to debugging using a mail client with all the Postfix framework in play. -- System Information: Debian Release: 12.5 APT prefers stable-updates APT policy: (990, 'stable-updates'), (990, 'stable-security'), (990, 'stable'), (500, 'oldstable') Architecture: amd64 (x86_64) Foreign Architectures: i386 Kernel: Linux 5.10.0-28-amd64 (SMP w/2 CPU threads) Kernel taint flags: TAINT_OOT_MODULE, TAINT_UNSIGNED_MODULE Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE not set Shell: /bin/sh linked to /usr/bin/dash Init: systemd (via /run/systemd/system) LSM: AppArmor: enabled Versions of packages torsocks depends on: ii libc6 2.36-9+deb12u6 Versions of packages torsocks recommends: ii tor 0.4.7.16-1 torsocks suggests no packages. -- no debconf information