Diff of the two buildlogs: -- --- b1/build.log 2021-07-22 11:29:41.192530178 +0000 +++ b2/build.log 2021-07-22 11:30:38.622362722 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Wed Jul 21 23:23:45 -12 2021 -I: pbuilder-time-stamp: 1626953025 +I: Current time: Thu Aug 25 07:52:42 +14 2022 +I: pbuilder-time-stamp: 1661363562 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/bullseye-reproducible-base.tgz] I: copying local configuration @@ -17,8 +17,8 @@ I: copying [./chasquid_1.6-1.debian.tar.xz] I: Extracting source gpgv: unknown type of key resource 'trustedkeys.kbx' -gpgv: keyblock resource '/tmp/dpkg-verify-sig.md9jJGuC/trustedkeys.kbx': General error -gpgv: Signature made Sun Jan 17 02:04:15 2021 -12 +gpgv: keyblock resource '/tmp/dpkg-verify-sig.h3FCrSja/trustedkeys.kbx': General error +gpgv: Signature made Mon Jan 18 04:04:15 2021 +14 gpgv: using RSA key DAA6EFF1C627EA1C26B1A692AA230FC45F8C27B1 gpgv: Can't check signature: No public key dpkg-source: warning: failed to verify signature on ./chasquid_1.6-1.dsc @@ -32,137 +32,171 @@ dpkg-source: info: applying 0004-test-Ignore-fexp-in-the-regular-Go-build.patch I: Not using root during the build. I: Installing the build-deps -I: user script /srv/workspace/pbuilder/25417/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/19975/tmp/hooks/D01_modify_environment starting +debug: Running on ionos16-i386. +I: Changing host+domainname to test build reproducibility +I: Adding a custom variable just for the fun of it... +I: Changing /bin/sh to bash +Removing 'diversion of /bin/sh to /bin/sh.distrib by dash' +Adding 'diversion of /bin/sh to /bin/sh.distrib by bash' +Removing 'diversion of /usr/share/man/man1/sh.1.gz to /usr/share/man/man1/sh.distrib.1.gz by dash' +Adding 'diversion of /usr/share/man/man1/sh.1.gz to /usr/share/man/man1/sh.distrib.1.gz by bash' +I: Setting pbuilder2's login shell to /bin/bash +I: Setting pbuilder2's GECOS to second user,second room,second work-phone,second home-phone,second other +I: user script /srv/workspace/pbuilder/19975/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/19975/tmp/hooks/D02_print_environment starting I: set - BUILDDIR='/build' - BUILDUSERGECOS='first user,first room,first work-phone,first home-phone,first other' - BUILDUSERNAME='pbuilder1' - BUILD_ARCH='i386' - DEBIAN_FRONTEND='noninteractive' - DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all,-fixfilepath parallel=8' - DISTRIBUTION='' - HOME='/root' - HOST_ARCH='i386' + BASH=/bin/sh + BASHOPTS=checkwinsize:cmdhist:complete_fullquote:extquote:force_fignore:globasciiranges:hostcomplete:interactive_comments:progcomp:promptvars:sourcepath + BASH_ALIASES=() + BASH_ARGC=() + BASH_ARGV=() + BASH_CMDS=() + BASH_LINENO=([0]="12" [1]="0") + BASH_SOURCE=([0]="/tmp/hooks/D02_print_environment" [1]="/tmp/hooks/D02_print_environment") + BASH_VERSINFO=([0]="5" [1]="1" [2]="4" [3]="1" [4]="release" [5]="i686-pc-linux-gnu") + BASH_VERSION='5.1.4(1)-release' + BUILDDIR=/build + BUILDUSERGECOS='second user,second room,second work-phone,second home-phone,second other' + BUILDUSERNAME=pbuilder2 + BUILD_ARCH=i386 + DEBIAN_FRONTEND=noninteractive + DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all,-fixfilepath parallel=15' + DIRSTACK=() + DISTRIBUTION= + EUID=0 + FUNCNAME=([0]="Echo" [1]="main") + GROUPS=() + HOME=/root + HOSTNAME=i-capture-the-hostname + HOSTTYPE=i686 + HOST_ARCH=i386 IFS=' ' - INVOCATION_ID='a6e8dea4f61045739490cea374e3f971' - LANG='C' - LANGUAGE='en_US:en' - LC_ALL='C' - LD_LIBRARY_PATH='/usr/lib/libeatmydata' - LD_PRELOAD='libeatmydata.so' - MAIL='/var/mail/root' - OPTIND='1' - PATH='/usr/sbin:/usr/bin:/sbin:/bin:/usr/games' - PBCURRENTCOMMANDLINEOPERATION='build' - PBUILDER_OPERATION='build' - PBUILDER_PKGDATADIR='/usr/share/pbuilder' - PBUILDER_PKGLIBDIR='/usr/lib/pbuilder' - PBUILDER_SYSCONFDIR='/etc' - PPID='25417' - PS1='# ' - PS2='> ' + INVOCATION_ID=46b5de42f4cd4ed79b534f3ae1817146 + LANG=C + LANGUAGE=de_CH:de + LC_ALL=C + LD_LIBRARY_PATH=/usr/lib/libeatmydata + LD_PRELOAD=libeatmydata.so + MACHTYPE=i686-pc-linux-gnu + MAIL=/var/mail/root + OPTERR=1 + OPTIND=1 + OSTYPE=linux-gnu + PATH=/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/i/capture/the/path + PBCURRENTCOMMANDLINEOPERATION=build + PBUILDER_OPERATION=build + PBUILDER_PKGDATADIR=/usr/share/pbuilder + PBUILDER_PKGLIBDIR=/usr/lib/pbuilder + PBUILDER_SYSCONFDIR=/etc + PIPESTATUS=([0]="0") + POSIXLY_CORRECT=y + PPID=19975 PS4='+ ' - PWD='/' - SHELL='/bin/bash' - SHLVL='2' - SUDO_COMMAND='/usr/bin/timeout -k 18.1h 18h /usr/bin/ionice -c 3 /usr/bin/nice /usr/sbin/pbuilder --build --configfile /srv/reproducible-results/rbuild-debian/tmp.wNkKhmH0aR/pbuilderrc_vjzI --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/bullseye-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/tmp.wNkKhmH0aR/b1 --logfile b1/build.log chasquid_1.6-1.dsc' - SUDO_GID='112' - SUDO_UID='107' - SUDO_USER='jenkins' - TERM='unknown' - TZ='/usr/share/zoneinfo/Etc/GMT+12' - USER='root' - _='/usr/bin/systemd-run' - http_proxy='http://78.137.99.97:3128' + PWD=/ + SHELL=/bin/bash + SHELLOPTS=braceexpand:errexit:hashall:interactive-comments:posix + SHLVL=3 + SUDO_COMMAND='/usr/bin/timeout -k 24.1h 24h /usr/bin/ionice -c 3 /usr/bin/nice -n 11 /usr/bin/unshare --uts -- /usr/sbin/pbuilder --build --configfile /srv/reproducible-results/rbuild-debian/tmp.wNkKhmH0aR/pbuilderrc_YY9m --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/bullseye-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/tmp.wNkKhmH0aR/b2 --logfile b2/build.log --extrapackages usrmerge chasquid_1.6-1.dsc' + SUDO_GID=112 + SUDO_UID=107 + SUDO_USER=jenkins + TERM=unknown + TZ=/usr/share/zoneinfo/Etc/GMT-14 + UID=0 + USER=root + _='I: set' + http_proxy=http://85.184.249.68:3128 I: uname -a - Linux ionos2-i386 4.19.0-17-686-pae #1 SMP Debian 4.19.194-3 (2021-07-18) i686 GNU/Linux + Linux i-capture-the-hostname 4.19.0-17-amd64 #1 SMP Debian 4.19.194-3 (2021-07-18) x86_64 GNU/Linux I: ls -l /bin - total 5788 - -rwxr-xr-x 1 root root 1367848 Jun 21 14:25 bash - -rwxr-xr-x 3 root root 38280 Jul 20 2020 bunzip2 - -rwxr-xr-x 3 root root 38280 Jul 20 2020 bzcat - lrwxrwxrwx 1 root root 6 Jul 20 2020 bzcmp -> bzdiff - -rwxr-xr-x 1 root root 2225 Jul 20 2020 bzdiff - lrwxrwxrwx 1 root root 6 Jul 20 2020 bzegrep -> bzgrep - -rwxr-xr-x 1 root root 4877 Sep 4 2019 bzexe - lrwxrwxrwx 1 root root 6 Jul 20 2020 bzfgrep -> bzgrep - -rwxr-xr-x 1 root root 3775 Jul 20 2020 bzgrep - -rwxr-xr-x 3 root root 38280 Jul 20 2020 bzip2 - -rwxr-xr-x 1 root root 17768 Jul 20 2020 bzip2recover - lrwxrwxrwx 1 root root 6 Jul 20 2020 bzless -> bzmore - -rwxr-xr-x 1 root root 1297 Jul 20 2020 bzmore - -rwxr-xr-x 1 root root 38824 Sep 22 2020 cat - -rwxr-xr-x 1 root root 71624 Sep 22 2020 chgrp - -rwxr-xr-x 1 root root 67528 Sep 22 2020 chmod - -rwxr-xr-x 1 root root 75752 Sep 22 2020 chown - -rwxr-xr-x 1 root root 157960 Sep 22 2020 cp - -rwxr-xr-x 1 root root 128724 Dec 10 2020 dash - -rwxr-xr-x 1 root root 124904 Sep 22 2020 date - -rwxr-xr-x 1 root root 92172 Sep 22 2020 dd - -rwxr-xr-x 1 root root 100752 Sep 22 2020 df - -rwxr-xr-x 1 root root 153964 Sep 22 2020 dir - -rwxr-xr-x 1 root root 83644 Feb 7 02:38 dmesg - lrwxrwxrwx 1 root root 8 Nov 6 2019 dnsdomainname -> hostname - lrwxrwxrwx 1 root root 8 Nov 6 2019 domainname -> hostname - -rwxr-xr-x 1 root root 34664 Sep 22 2020 echo - -rwxr-xr-x 1 root root 28 Nov 9 2020 egrep - -rwxr-xr-x 1 root root 34664 Sep 22 2020 false - -rwxr-xr-x 1 root root 28 Nov 9 2020 fgrep - -rwxr-xr-x 1 root root 71928 Feb 7 02:38 findmnt - -rwsr-xr-x 1 root root 30112 Feb 26 04:12 fusermount - -rwxr-xr-x 1 root root 210488 Nov 9 2020 grep - -rwxr-xr-x 2 root root 2346 Mar 2 11:30 gunzip - -rwxr-xr-x 1 root root 6376 Mar 2 11:30 gzexe - -rwxr-xr-x 1 root root 100952 Mar 2 11:30 gzip - -rwxr-xr-x 1 root root 21916 Nov 6 2019 hostname - -rwxr-xr-x 1 root root 83980 Sep 22 2020 ln - -rwxr-xr-x 1 root root 55572 Feb 7 2020 login - -rwxr-xr-x 1 root root 153964 Sep 22 2020 ls - -rwxr-xr-x 1 root root 153124 Feb 7 02:38 lsblk - -rwxr-xr-x 1 root root 96328 Sep 22 2020 mkdir - -rwxr-xr-x 1 root root 79912 Sep 22 2020 mknod - -rwxr-xr-x 1 root root 47048 Sep 22 2020 mktemp - -rwxr-xr-x 1 root root 58920 Feb 7 02:38 more - -rwsr-xr-x 1 root root 50720 Feb 7 02:38 mount - -rwxr-xr-x 1 root root 13856 Feb 7 02:38 mountpoint - -rwxr-xr-x 1 root root 157996 Sep 22 2020 mv - lrwxrwxrwx 1 root root 8 Nov 6 2019 nisdomainname -> hostname - lrwxrwxrwx 1 root root 14 Apr 18 03:38 pidof -> /sbin/killall5 - -rwxr-xr-x 1 root root 38824 Sep 22 2020 pwd - lrwxrwxrwx 1 root root 4 Jun 21 14:25 rbash -> bash - -rwxr-xr-x 1 root root 46984 Sep 22 2020 readlink - -rwxr-xr-x 1 root root 75720 Sep 22 2020 rm - -rwxr-xr-x 1 root root 46984 Sep 22 2020 rmdir - -rwxr-xr-x 1 root root 22292 Sep 27 2020 run-parts - -rwxr-xr-x 1 root root 125036 Dec 22 2018 sed - lrwxrwxrwx 1 root root 4 Jul 21 21:26 sh -> dash - -rwxr-xr-x 1 root root 34696 Sep 22 2020 sleep - -rwxr-xr-x 1 root root 83880 Sep 22 2020 stty - -rwsr-xr-x 1 root root 79396 Feb 7 02:38 su - -rwxr-xr-x 1 root root 34696 Sep 22 2020 sync - -rwxr-xr-x 1 root root 602584 Feb 16 21:55 tar - -rwxr-xr-x 1 root root 13860 Sep 27 2020 tempfile - -rwxr-xr-x 1 root root 108520 Sep 22 2020 touch - -rwxr-xr-x 1 root root 34664 Sep 22 2020 true - -rwxr-xr-x 1 root root 17768 Feb 26 04:12 ulockmgr_server - -rwsr-xr-x 1 root root 30236 Feb 7 02:38 umount - -rwxr-xr-x 1 root root 34664 Sep 22 2020 uname - -rwxr-xr-x 2 root root 2346 Mar 2 11:30 uncompress - -rwxr-xr-x 1 root root 153964 Sep 22 2020 vdir - -rwxr-xr-x 1 root root 63024 Feb 7 02:38 wdctl - lrwxrwxrwx 1 root root 8 Nov 6 2019 ypdomainname -> hostname - -rwxr-xr-x 1 root root 1984 Mar 2 11:30 zcat - -rwxr-xr-x 1 root root 1678 Mar 2 11:30 zcmp - -rwxr-xr-x 1 root root 5880 Mar 2 11:30 zdiff - -rwxr-xr-x 1 root root 29 Mar 2 11:30 zegrep - -rwxr-xr-x 1 root root 29 Mar 2 11:30 zfgrep - -rwxr-xr-x 1 root root 2081 Mar 2 11:30 zforce - -rwxr-xr-x 1 root root 7585 Mar 2 11:30 zgrep - -rwxr-xr-x 1 root root 2206 Mar 2 11:30 zless - -rwxr-xr-x 1 root root 1842 Mar 2 11:30 zmore - -rwxr-xr-x 1 root root 4553 Mar 2 11:30 znew -I: user script /srv/workspace/pbuilder/25417/tmp/hooks/D02_print_environment finished + total 5776 + -rwxr-xr-x 1 root root 1367848 Jun 22 2021 bash + -rwxr-xr-x 3 root root 38280 Jul 21 2020 bunzip2 + -rwxr-xr-x 3 root root 38280 Jul 21 2020 bzcat + lrwxrwxrwx 1 root root 6 Jul 21 2020 bzcmp -> bzdiff + -rwxr-xr-x 1 root root 2225 Jul 21 2020 bzdiff + lrwxrwxrwx 1 root root 6 Jul 21 2020 bzegrep -> bzgrep + -rwxr-xr-x 1 root root 4877 Sep 5 2019 bzexe + lrwxrwxrwx 1 root root 6 Jul 21 2020 bzfgrep -> bzgrep + -rwxr-xr-x 1 root root 3775 Jul 21 2020 bzgrep + -rwxr-xr-x 3 root root 38280 Jul 21 2020 bzip2 + -rwxr-xr-x 1 root root 17768 Jul 21 2020 bzip2recover + lrwxrwxrwx 1 root root 6 Jul 21 2020 bzless -> bzmore + -rwxr-xr-x 1 root root 1297 Jul 21 2020 bzmore + -rwxr-xr-x 1 root root 38824 Sep 23 2020 cat + -rwxr-xr-x 1 root root 71624 Sep 23 2020 chgrp + -rwxr-xr-x 1 root root 67528 Sep 23 2020 chmod + -rwxr-xr-x 1 root root 75752 Sep 23 2020 chown + -rwxr-xr-x 1 root root 157960 Sep 23 2020 cp + -rwxr-xr-x 1 root root 128724 Dec 11 2020 dash + -rwxr-xr-x 1 root root 124904 Sep 23 2020 date + -rwxr-xr-x 1 root root 92172 Sep 23 2020 dd + -rwxr-xr-x 1 root root 100752 Sep 23 2020 df + -rwxr-xr-x 1 root root 153964 Sep 23 2020 dir + -rwxr-xr-x 1 root root 83644 Feb 8 2021 dmesg + lrwxrwxrwx 1 root root 8 Nov 8 2019 dnsdomainname -> hostname + lrwxrwxrwx 1 root root 8 Nov 8 2019 domainname -> hostname + -rwxr-xr-x 1 root root 34664 Sep 23 2020 echo + -rwxr-xr-x 1 root root 28 Nov 10 2020 egrep + -rwxr-xr-x 1 root root 34664 Sep 23 2020 false + -rwxr-xr-x 1 root root 28 Nov 10 2020 fgrep + -rwxr-xr-x 1 root root 71928 Feb 8 2021 findmnt + -rwsr-xr-x 1 root root 30112 Feb 27 2021 fusermount + -rwxr-xr-x 1 root root 210488 Nov 10 2020 grep + -rwxr-xr-x 2 root root 2346 Mar 3 2021 gunzip + -rwxr-xr-x 1 root root 6376 Mar 3 2021 gzexe + -rwxr-xr-x 1 root root 100952 Mar 3 2021 gzip + -rwxr-xr-x 1 root root 21916 Nov 8 2019 hostname + -rwxr-xr-x 1 root root 83980 Sep 23 2020 ln + -rwxr-xr-x 1 root root 55572 Feb 8 2020 login + -rwxr-xr-x 1 root root 153964 Sep 23 2020 ls + -rwxr-xr-x 1 root root 153124 Feb 8 2021 lsblk + -rwxr-xr-x 1 root root 96328 Sep 23 2020 mkdir + -rwxr-xr-x 1 root root 79912 Sep 23 2020 mknod + -rwxr-xr-x 1 root root 47048 Sep 23 2020 mktemp + -rwxr-xr-x 1 root root 58920 Feb 8 2021 more + -rwsr-xr-x 1 root root 50720 Feb 8 2021 mount + -rwxr-xr-x 1 root root 13856 Feb 8 2021 mountpoint + -rwxr-xr-x 1 root root 157996 Sep 23 2020 mv + lrwxrwxrwx 1 root root 8 Nov 8 2019 nisdomainname -> hostname + lrwxrwxrwx 1 root root 14 Apr 19 2021 pidof -> /sbin/killall5 + -rwxr-xr-x 1 root root 38824 Sep 23 2020 pwd + lrwxrwxrwx 1 root root 4 Jun 22 2021 rbash -> bash + -rwxr-xr-x 1 root root 46984 Sep 23 2020 readlink + -rwxr-xr-x 1 root root 75720 Sep 23 2020 rm + -rwxr-xr-x 1 root root 46984 Sep 23 2020 rmdir + -rwxr-xr-x 1 root root 22292 Sep 28 2020 run-parts + -rwxr-xr-x 1 root root 125036 Dec 23 2018 sed + lrwxrwxrwx 1 root root 4 Aug 25 07:52 sh -> bash + lrwxrwxrwx 1 root root 4 Aug 25 05:46 sh.distrib -> dash + -rwxr-xr-x 1 root root 34696 Sep 23 2020 sleep + -rwxr-xr-x 1 root root 83880 Sep 23 2020 stty + -rwsr-xr-x 1 root root 79396 Feb 8 2021 su + -rwxr-xr-x 1 root root 34696 Sep 23 2020 sync + -rwxr-xr-x 1 root root 602584 Feb 17 2021 tar + -rwxr-xr-x 1 root root 13860 Sep 28 2020 tempfile + -rwxr-xr-x 1 root root 108520 Sep 23 2020 touch + -rwxr-xr-x 1 root root 34664 Sep 23 2020 true + -rwxr-xr-x 1 root root 17768 Feb 27 2021 ulockmgr_server + -rwsr-xr-x 1 root root 30236 Feb 8 2021 umount + -rwxr-xr-x 1 root root 34664 Sep 23 2020 uname + -rwxr-xr-x 2 root root 2346 Mar 3 2021 uncompress + -rwxr-xr-x 1 root root 153964 Sep 23 2020 vdir + -rwxr-xr-x 1 root root 63024 Feb 8 2021 wdctl + lrwxrwxrwx 1 root root 8 Nov 8 2019 ypdomainname -> hostname + -rwxr-xr-x 1 root root 1984 Mar 3 2021 zcat + -rwxr-xr-x 1 root root 1678 Mar 3 2021 zcmp + -rwxr-xr-x 1 root root 5880 Mar 3 2021 zdiff + -rwxr-xr-x 1 root root 29 Mar 3 2021 zegrep + -rwxr-xr-x 1 root root 29 Mar 3 2021 zfgrep + -rwxr-xr-x 1 root root 2081 Mar 3 2021 zforce + -rwxr-xr-x 1 root root 7585 Mar 3 2021 zgrep + -rwxr-xr-x 1 root root 2206 Mar 3 2021 zless + -rwxr-xr-x 1 root root 1842 Mar 3 2021 zmore + -rwxr-xr-x 1 root root 4553 Mar 3 2021 znew +I: user script /srv/workspace/pbuilder/19975/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -271,7 +305,7 @@ Get: 47 http://deb.debian.org/debian bullseye/main i386 golang-blitiri-go-log-dev all 1.1.0-1 [6724 B] Get: 48 http://deb.debian.org/debian bullseye/main i386 golang-blitiri-go-spf-dev all 1.1.0-1 [84.8 kB] Get: 49 http://deb.debian.org/debian bullseye/main i386 golang-blitiri-go-systemd-dev all 1.1.0-1 [6952 B] -Fetched 85.8 MB in 10s (9028 kB/s) +Fetched 85.8 MB in 1s (71.6 MB/s) debconf: delaying package configuration, since apt-utils is not installed Selecting previously unselected package bsdextrautils. (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 19675 files and directories currently installed.) @@ -482,8 +516,44 @@ Writing extended state information... Building tag database... -> Finished parsing the build-deps +Reading package lists... +Building dependency tree... +Reading state information... +The following additional packages will be installed: + libfile-find-rule-perl libnumber-compare-perl libtext-glob-perl +The following NEW packages will be installed: + libfile-find-rule-perl libnumber-compare-perl libtext-glob-perl usrmerge +0 upgraded, 4 newly installed, 0 to remove and 0 not upgraded. +Need to get 59.5 kB of archives. +After this operation, 157 kB of additional disk space will be used. +Get:1 http://deb.debian.org/debian bullseye/main i386 libnumber-compare-perl all 0.03-1.1 [6956 B] +Get:2 http://deb.debian.org/debian bullseye/main i386 libtext-glob-perl all 0.11-1 [8888 B] +Get:3 http://deb.debian.org/debian bullseye/main i386 libfile-find-rule-perl all 0.34-1 [30.6 kB] +Get:4 http://deb.debian.org/debian bullseye/main i386 usrmerge all 25 [13.0 kB] +debconf: delaying package configuration, since apt-utils is not installed +Fetched 59.5 kB in 0s (4311 kB/s) +Selecting previously unselected package libnumber-compare-perl. +(Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 35633 files and directories currently installed.) +Preparing to unpack .../libnumber-compare-perl_0.03-1.1_all.deb ... +Unpacking libnumber-compare-perl (0.03-1.1) ... +Selecting previously unselected package libtext-glob-perl. +Preparing to unpack .../libtext-glob-perl_0.11-1_all.deb ... +Unpacking libtext-glob-perl (0.11-1) ... +Selecting previously unselected package libfile-find-rule-perl. +Preparing to unpack .../libfile-find-rule-perl_0.34-1_all.deb ... +Unpacking libfile-find-rule-perl (0.34-1) ... +Selecting previously unselected package usrmerge. +Preparing to unpack .../archives/usrmerge_25_all.deb ... +Unpacking usrmerge (25) ... +Setting up libtext-glob-perl (0.11-1) ... +Setting up libnumber-compare-perl (0.03-1.1) ... +Setting up libfile-find-rule-perl (0.34-1) ... +Setting up usrmerge (25) ... +The system has been successfully converted. +Processing triggers for man-db (2.9.4-2) ... +Not building database; man-db/auto-update is not 'true'. I: Building the package -I: Running cd /build/chasquid-1.6/ && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games" HOME="/nonexistent/first-build" dpkg-buildpackage -us -uc -b +I: Running cd /build/chasquid-1.6/ && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/i/capture/the/path" HOME="/nonexistent/second-build" dpkg-buildpackage -us -uc -b dpkg-buildpackage: info: source package chasquid dpkg-buildpackage: info: source version 1.6-1 dpkg-buildpackage: info: source distribution unstable @@ -503,216 +573,216 @@ debian/rules override_dh_auto_build make[1]: Entering directory '/build/chasquid-1.6' dh_auto_build -- -ldflags " -X main.version=1.6-1 -X main.sourceDateTs=1606046569" - cd obj-i686-linux-gnu && go install -trimpath -v -p 8 -ldflags " -X main.version=1.6-1 -X main.sourceDateTs=1606046569" blitiri.com.ar/go/chasquid blitiri.com.ar/go/chasquid/cmd/chasquid-util blitiri.com.ar/go/chasquid/cmd/mda-lmtp blitiri.com.ar/go/chasquid/cmd/smtp-check blitiri.com.ar/go/chasquid/internal/aliases blitiri.com.ar/go/chasquid/internal/auth blitiri.com.ar/go/chasquid/internal/config blitiri.com.ar/go/chasquid/internal/courier blitiri.com.ar/go/chasquid/internal/domaininfo blitiri.com.ar/go/chasquid/internal/dovecot blitiri.com.ar/go/chasquid/internal/envelope blitiri.com.ar/go/chasquid/internal/expvarom blitiri.com.ar/go/chasquid/internal/haproxy blitiri.com.ar/go/chasquid/internal/maillog blitiri.com.ar/go/chasquid/internal/normalize blitiri.com.ar/go/chasquid/internal/protoio blitiri.com.ar/go/chasquid/internal/protoio/testpb blitiri.com.ar/go/chasquid/internal/queue blitiri.com.ar/go/chasquid/internal/safeio blitiri.com.ar/go/chasquid/internal/set blitiri.com.ar/go/chasquid/internal/smtp blitiri.com.ar/go/chasquid/internal/smtpsrv blitiri.com.ar/go/chasquid/internal/sts blitiri.com.ar/go/chasquid/internal/testlib blitiri.com.ar/go/chasquid/internal/tlsconst blitiri.com.ar/go/chasquid/internal/trace blitiri.com.ar/go/chasquid/internal/userdb -internal/unsafeheader + cd obj-i686-linux-gnu && go install -trimpath -v -p 15 -ldflags " -X main.version=1.6-1 -X main.sourceDateTs=1606046569" blitiri.com.ar/go/chasquid blitiri.com.ar/go/chasquid/cmd/chasquid-util blitiri.com.ar/go/chasquid/cmd/mda-lmtp blitiri.com.ar/go/chasquid/cmd/smtp-check blitiri.com.ar/go/chasquid/internal/aliases blitiri.com.ar/go/chasquid/internal/auth blitiri.com.ar/go/chasquid/internal/config blitiri.com.ar/go/chasquid/internal/courier blitiri.com.ar/go/chasquid/internal/domaininfo blitiri.com.ar/go/chasquid/internal/dovecot blitiri.com.ar/go/chasquid/internal/envelope blitiri.com.ar/go/chasquid/internal/expvarom blitiri.com.ar/go/chasquid/internal/haproxy blitiri.com.ar/go/chasquid/internal/maillog blitiri.com.ar/go/chasquid/internal/normalize blitiri.com.ar/go/chasquid/internal/protoio blitiri.com.ar/go/chasquid/internal/protoio/testpb blitiri.com.ar/go/chasquid/internal/queue blitiri.com.ar/go/chasquid/internal/safeio blitiri.com.ar/go/chasquid/internal/set blitiri.com.ar/go/chasquid/internal/smtp blitiri.com.ar/go/chasquid/internal/smtpsrv blitiri.com.ar/go/chasquid/internal/sts blitiri.com.ar/go/chasquid/internal/testlib blitiri.com.ar/go/chasquid/internal/tlsconst blitiri.com.ar/go/chasquid/internal/trace blitiri.com.ar/go/chasquid/internal/userdb internal/race -unicode +unicode/utf16 unicode/utf8 -math/bits +container/list internal/cpu -sync/atomic -runtime/internal/atomic -runtime/internal/sys +unicode +math/bits +encoding internal/nettrace runtime/cgo -google.golang.org/protobuf/internal/flags -internal/testlog -runtime/internal/math -unicode/utf16 -math -google.golang.org/protobuf/internal/set -encoding -container/list +internal/unsafeheader +sync/atomic crypto/internal/subtle -internal/bytealg crypto/subtle +runtime/internal/sys +google.golang.org/protobuf/internal/flags vendor/golang.org/x/crypto/cryptobyte/asn1 +runtime/internal/atomic +vendor/golang.org/x/crypto/internal/subtle blitiri.com.ar/go/chasquid/internal/set +internal/bytealg +google.golang.org/protobuf/internal/set +runtime/internal/math golang.org/x/sys/internal/unsafeheader -vendor/golang.org/x/crypto/internal/subtle +internal/testlog +math runtime internal/reflectlite sync internal/singleflight -math/rand google.golang.org/protobuf/internal/pragma +math/rand errors sort -vendor/golang.org/x/net/dns/dnsmessage +io internal/oserror strconv -io +vendor/golang.org/x/net/dns/dnsmessage syscall golang.org/x/text/internal/tag -hash strings -bytes +hash crypto/internal/randutil +bytes text/tabwriter hash/fnv hash/crc32 -reflect -crypto crypto/hmac -crypto/rc4 -vendor/golang.org/x/text/transform -golang.org/x/text/transform vendor/golang.org/x/crypto/hkdf golang.org/x/crypto/pbkdf2 -path +crypto/rc4 +crypto +golang.org/x/text/transform +vendor/golang.org/x/text/transform +reflect +bufio regexp/syntax html -bufio +path golang.org/x/text/runes golang.org/x/text/width -regexp internal/syscall/unix internal/syscall/execenv time +regexp +context +internal/poll internal/fmtsort encoding/binary +os encoding/base64 -crypto/sha512 crypto/cipher +crypto/sha512 crypto/md5 -crypto/sha1 -crypto/sha256 crypto/ed25519/internal/edwards25519 -internal/poll -context -encoding/pem vendor/golang.org/x/crypto/poly1305 +crypto/sha1 +crypto/sha256 golang.org/x/sys/unix -crypto/des -crypto/aes -vendor/golang.org/x/crypto/chacha20 -golang.org/x/crypto/scrypt -os -vendor/golang.org/x/crypto/chacha20poly1305 -google.golang.org/protobuf/internal/detrand +encoding/pem path/filepath +google.golang.org/protobuf/internal/detrand os/signal -fmt runtime/debug +fmt +crypto/aes +vendor/golang.org/x/crypto/chacha20 +crypto/des +golang.org/x/crypto/scrypt net +vendor/golang.org/x/crypto/chacha20poly1305 io/ioutil os/exec blitiri.com.ar/go/chasquid/internal/safeio +google.golang.org/protobuf/internal/errors flag log go/token -google.golang.org/protobuf/internal/errors -compress/flate -encoding/json -google.golang.org/protobuf/encoding/protowire google.golang.org/protobuf/internal/version -google.golang.org/protobuf/reflect/protoreflect +encoding/json net/url -golang.org/x/net/internal/timeseries text/template/parse -math/big -encoding/hex -compress/gzip vendor/golang.org/x/crypto/curve25519 -vendor/golang.org/x/text/unicode/bidi -vendor/golang.org/x/text/unicode/norm +compress/flate +encoding/hex vendor/golang.org/x/net/http2/hpack +google.golang.org/protobuf/encoding/protowire +math/big +vendor/golang.org/x/text/unicode/norm +golang.org/x/net/internal/timeseries +vendor/golang.org/x/text/unicode/bidi mime +google.golang.org/protobuf/reflect/protoreflect +net/http/internal +blitiri.com.ar/go/chasquid/internal/envelope +mime/quotedprintable +golang.org/x/text/unicode/bidi +golang.org/x/text/unicode/norm +golang.org/x/text/internal/language +compress/gzip +blitiri.com.ar/go/chasquid/internal/tlsconst +runtime/trace +vendor/golang.org/x/text/secure/bidirule +golang.org/x/term +github.com/docopt/docopt-go +internal/profile +runtime/pprof +testing +golang.org/x/text/secure/bidirule +golang.org/x/crypto/ssh/terminal +text/template +vendor/golang.org/x/net/idna google.golang.org/protobuf/internal/encoding/messageset google.golang.org/protobuf/internal/strs -google.golang.org/protobuf/internal/genid google.golang.org/protobuf/internal/order -google.golang.org/protobuf/reflect/protoregistry -google.golang.org/protobuf/internal/encoding/text +google.golang.org/protobuf/internal/genid google.golang.org/protobuf/runtime/protoiface google.golang.org/protobuf/internal/descfmt google.golang.org/protobuf/internal/descopts -text/template -vendor/golang.org/x/text/secure/bidirule -mime/quotedprintable -google.golang.org/protobuf/proto -google.golang.org/protobuf/internal/encoding/defval -vendor/golang.org/x/net/idna -net/http/internal +golang.org/x/text/internal/language/compact +google.golang.org/protobuf/reflect/protoregistry +google.golang.org/protobuf/internal/encoding/text +golang.org/x/net/idna crypto/rand -crypto/elliptic -encoding/asn1 crypto/dsa +golang.org/x/text/language +encoding/asn1 +crypto/elliptic +google.golang.org/protobuf/proto crypto/ed25519 crypto/rsa -blitiri.com.ar/go/chasquid/internal/envelope -golang.org/x/text/unicode/bidi -golang.org/x/text/unicode/norm -golang.org/x/text/internal/language -blitiri.com.ar/go/chasquid/internal/tlsconst -google.golang.org/protobuf/encoding/prototext +google.golang.org/protobuf/internal/encoding/defval html/template -google.golang.org/protobuf/internal/filedesc -vendor/golang.org/x/crypto/cryptobyte crypto/x509/pkix -golang.org/x/text/secure/bidirule +vendor/golang.org/x/crypto/cryptobyte +golang.org/x/text/internal +golang.org/x/text/cases +google.golang.org/protobuf/encoding/prototext +google.golang.org/protobuf/internal/filedesc crypto/ecdsa +golang.org/x/text/secure/precis blitiri.com.ar/go/chasquid/internal/protoio -internal/profile -golang.org/x/text/internal/language/compact -golang.org/x/net/idna -runtime/pprof -runtime/trace -github.com/docopt/docopt-go -golang.org/x/text/language -golang.org/x/term -testing -golang.org/x/crypto/ssh/terminal +blitiri.com.ar/go/chasquid/internal/normalize +blitiri.com.ar/go/chasquid/internal/auth google.golang.org/protobuf/internal/encoding/tag -golang.org/x/text/internal -golang.org/x/text/cases google.golang.org/protobuf/internal/impl log/syslog +blitiri.com.ar/go/chasquid/internal/haproxy vendor/golang.org/x/net/http/httpproxy +blitiri.com.ar/go/systemd +blitiri.com.ar/go/chasquid/internal/testlib +blitiri.com.ar/go/spf net/textproto -blitiri.com.ar/go/chasquid/internal/haproxy crypto/x509 -blitiri.com.ar/go/spf -blitiri.com.ar/go/systemd blitiri.com.ar/go/log -blitiri.com.ar/go/chasquid/internal/testlib -golang.org/x/text/secure/precis +blitiri.com.ar/go/chasquid/internal/dovecot vendor/golang.org/x/net/http/httpguts mime/multipart -blitiri.com.ar/go/chasquid/internal/dovecot -blitiri.com.ar/go/chasquid/cmd/mda-lmtp net/mail -blitiri.com.ar/go/chasquid/internal/normalize -blitiri.com.ar/go/chasquid/internal/auth +blitiri.com.ar/go/chasquid/cmd/mda-lmtp crypto/tls google.golang.org/protobuf/internal/filetype net/http/httptrace net/smtp google.golang.org/protobuf/runtime/protoimpl net/http +blitiri.com.ar/go/chasquid/internal/config blitiri.com.ar/go/chasquid/internal/protoio/testpb blitiri.com.ar/go/chasquid/internal/userdb -blitiri.com.ar/go/chasquid/internal/config blitiri.com.ar/go/chasquid/internal/smtp golang.org/x/net/context/ctxhttp expvar -golang.org/x/net/trace net/http/pprof +golang.org/x/net/trace blitiri.com.ar/go/chasquid/internal/expvarom blitiri.com.ar/go/chasquid/internal/trace -blitiri.com.ar/go/chasquid/internal/maillog blitiri.com.ar/go/chasquid/internal/domaininfo -blitiri.com.ar/go/chasquid/internal/aliases +blitiri.com.ar/go/chasquid/internal/maillog blitiri.com.ar/go/chasquid/internal/sts +blitiri.com.ar/go/chasquid/internal/aliases blitiri.com.ar/go/chasquid/cmd/chasquid-util -blitiri.com.ar/go/chasquid/internal/courier blitiri.com.ar/go/chasquid/cmd/smtp-check +blitiri.com.ar/go/chasquid/internal/courier blitiri.com.ar/go/chasquid/internal/queue blitiri.com.ar/go/chasquid/internal/smtpsrv blitiri.com.ar/go/chasquid make[1]: Leaving directory '/build/chasquid-1.6' dh_auto_test -O--buildsystem=golang - cd obj-i686-linux-gnu && go test -vet=off -v -p 8 blitiri.com.ar/go/chasquid blitiri.com.ar/go/chasquid/cmd/chasquid-util blitiri.com.ar/go/chasquid/cmd/mda-lmtp blitiri.com.ar/go/chasquid/cmd/smtp-check blitiri.com.ar/go/chasquid/internal/aliases blitiri.com.ar/go/chasquid/internal/auth blitiri.com.ar/go/chasquid/internal/config blitiri.com.ar/go/chasquid/internal/courier blitiri.com.ar/go/chasquid/internal/domaininfo blitiri.com.ar/go/chasquid/internal/dovecot blitiri.com.ar/go/chasquid/internal/envelope blitiri.com.ar/go/chasquid/internal/expvarom blitiri.com.ar/go/chasquid/internal/haproxy blitiri.com.ar/go/chasquid/internal/maillog blitiri.com.ar/go/chasquid/internal/normalize blitiri.com.ar/go/chasquid/internal/protoio blitiri.com.ar/go/chasquid/internal/protoio/testpb blitiri.com.ar/go/chasquid/internal/queue blitiri.com.ar/go/chasquid/internal/safeio blitiri.com.ar/go/chasquid/internal/set blitiri.com.ar/go/chasquid/internal/smtp blitiri.com.ar/go/chasquid/internal/smtpsrv blitiri.com.ar/go/chasquid/internal/sts blitiri.com.ar/go/chasquid/internal/testlib blitiri.com.ar/go/chasquid/internal/tlsconst blitiri.com.ar/go/chasquid/internal/trace blitiri.com.ar/go/chasquid/internal/userdb + cd obj-i686-linux-gnu && go test -vet=off -v -p 15 blitiri.com.ar/go/chasquid blitiri.com.ar/go/chasquid/cmd/chasquid-util blitiri.com.ar/go/chasquid/cmd/mda-lmtp blitiri.com.ar/go/chasquid/cmd/smtp-check blitiri.com.ar/go/chasquid/internal/aliases blitiri.com.ar/go/chasquid/internal/auth blitiri.com.ar/go/chasquid/internal/config blitiri.com.ar/go/chasquid/internal/courier blitiri.com.ar/go/chasquid/internal/domaininfo blitiri.com.ar/go/chasquid/internal/dovecot blitiri.com.ar/go/chasquid/internal/envelope blitiri.com.ar/go/chasquid/internal/expvarom blitiri.com.ar/go/chasquid/internal/haproxy blitiri.com.ar/go/chasquid/internal/maillog blitiri.com.ar/go/chasquid/internal/normalize blitiri.com.ar/go/chasquid/internal/protoio blitiri.com.ar/go/chasquid/internal/protoio/testpb blitiri.com.ar/go/chasquid/internal/queue blitiri.com.ar/go/chasquid/internal/safeio blitiri.com.ar/go/chasquid/internal/set blitiri.com.ar/go/chasquid/internal/smtp blitiri.com.ar/go/chasquid/internal/smtpsrv blitiri.com.ar/go/chasquid/internal/sts blitiri.com.ar/go/chasquid/internal/testlib blitiri.com.ar/go/chasquid/internal/tlsconst blitiri.com.ar/go/chasquid/internal/trace blitiri.com.ar/go/chasquid/internal/userdb ? blitiri.com.ar/go/chasquid [no test files] ? blitiri.com.ar/go/chasquid/cmd/chasquid-util [no test files] ? blitiri.com.ar/go/chasquid/cmd/mda-lmtp [no test files] @@ -732,7 +802,7 @@ === RUN TestManyFiles --- PASS: TestManyFiles (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/aliases 0.016s +ok blitiri.com.ar/go/chasquid/internal/aliases 0.006s === RUN TestDecodeResponse auth_test.go:54: OK: "" failed with response pieces != 3, as per RFC auth_test.go:54: OK: "\x00" failed with response pieces != 3, as per RFC @@ -746,52 +816,52 @@ auth_test.go:54: OK: "\xffa@b\x00\xffa@b\x00pass" failed with bidirule: failed Bidi Rule --- PASS: TestDecodeResponse (0.00s) === RUN TestAuthenticate ---- PASS: TestAuthenticate (0.69s) +--- PASS: TestAuthenticate (0.42s) === RUN TestInterfaces --- PASS: TestInterfaces (0.00s) === RUN TestMultipleBackends ---- PASS: TestMultipleBackends (0.20s) +--- PASS: TestMultipleBackends (0.18s) === RUN TestErrors --- PASS: TestErrors (0.00s) === RUN TestReload --- PASS: TestReload (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/auth 0.915s +ok blitiri.com.ar/go/chasquid/internal/auth 0.602s === RUN TestEmptyConfig - testlib.go:26: test directory: "/tmp/testlib_569512087" ---- PASS: TestEmptyConfig (0.01s) + testlib.go:26: test directory: "/tmp/testlib_624506477" +--- PASS: TestEmptyConfig (0.00s) === RUN TestFullConfig - testlib.go:26: test directory: "/tmp/testlib_953314570" + testlib.go:26: test directory: "/tmp/testlib_852349672" --- PASS: TestFullConfig (0.00s) === RUN TestErrorLoading --- PASS: TestErrorLoading (0.00s) === RUN TestBrokenConfig - testlib.go:26: test directory: "/tmp/testlib_165853921" + testlib.go:26: test directory: "/tmp/testlib_178836263" --- PASS: TestBrokenConfig (0.00s) === RUN TestBrokenOverride - testlib.go:26: test directory: "/tmp/testlib_398871756" + testlib.go:26: test directory: "/tmp/testlib_390756442" --- PASS: TestBrokenOverride (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/config 0.045s +ok blitiri.com.ar/go/chasquid/internal/config 0.006s === RUN TestMDA - testlib.go:26: test directory: "/tmp/testlib_282688672" ---- PASS: TestMDA (0.02s) + testlib.go:26: test directory: "/tmp/testlib_549786069" +--- PASS: TestMDA (0.00s) === RUN TestMDATimeout _ mda.go:67 Courier.MDA to@local: error: operation timed out --- PASS: TestMDATimeout (0.10s) === RUN TestMDABadCommandLine _ mda.go:80 Courier.MDA to: error: MDA delivery failed: exec: \"thisdoesnotexist\": executable file not found in $PATH - \"\" _ mda.go:80 Courier.MDA to: error: MDA delivery failed: exit status 1 - \"cat: unrecognized option '--fail_unknown_option'\\nTry 'cat --help' for more information.\\n\" ---- PASS: TestMDABadCommandLine (0.01s) +--- PASS: TestMDABadCommandLine (0.00s) === RUN TestExitCode mda_test.go:72: util/exitcode not found, running from outside repo? --- SKIP: TestExitCode (0.00s) === RUN TestSanitize --- PASS: TestSanitize (0.00s) === RUN TestSMTP - testlib.go:26: test directory: "/tmp/testlib_852151679" -_ smtp.go:130 Courier.SMTP to@to: error: Could not dial: dial tcp: address ::::38251: too many colons in address -_ smtp.go:100 Courier.SMTP to@to: error: \":::\" returned transient error: Could not dial: dial tcp: address ::::38251: too many colons in address + testlib.go:26: test directory: "/tmp/testlib_902214960" +_ smtp.go:130 Courier.SMTP to@to: error: Could not dial: dial tcp: address ::::42879: too many colons in address +_ smtp.go:100 Courier.SMTP to@to: error: \":::\" returned transient error: Could not dial: dial tcp: address ::::42879: too many colons in address smtp_test.go:62: fakeServer got connection smtp_test.go:73: fakeServer read: "EHLO hello" smtp_test.go:73: fakeServer read: "MAIL FROM:" @@ -801,38 +871,38 @@ smtp_test.go:69: fakeServer exiting: EOF --- PASS: TestSMTP (0.00s) === RUN TestSMTPErrors - testlib.go:26: test directory: "/tmp/testlib_231962121" + testlib.go:26: test directory: "/tmp/testlib_289904098" smtp_test.go:62: fakeServer got connection -_ smtp.go:141 Courier.SMTP to@to: error: Error saying hello: write tcp 127.0.0.1:60638->127.0.0.1:45445: i/o timeout -_ smtp.go:100 Courier.SMTP to@to: error: \"127.0.0.1\" returned transient error: Error saying hello: write tcp 127.0.0.1:60638->127.0.0.1:45445: i/o timeout -_ smtp.go:104 Courier.SMTP to@to: error: all MXs returned transient failures (last: Error saying hello: write tcp 127.0.0.1:60638->127.0.0.1:45445: i/o timeout) - smtp_test.go:188: failed as expected: all MXs returned transient failures (last: Error saying hello: write tcp 127.0.0.1:60638->127.0.0.1:45445: i/o timeout) +_ smtp.go:141 Courier.SMTP to@to: error: Error saying hello: write tcp 127.0.0.1:49314->127.0.0.1:36747: i/o timeout +_ smtp.go:100 Courier.SMTP to@to: error: \"127.0.0.1\" returned transient error: Error saying hello: write tcp 127.0.0.1:49314->127.0.0.1:36747: i/o timeout +_ smtp.go:104 Courier.SMTP to@to: error: all MXs returned transient failures (last: Error saying hello: write tcp 127.0.0.1:49314->127.0.0.1:36747: i/o timeout) smtp_test.go:69: fakeServer exiting: EOF - testlib.go:26: test directory: "/tmp/testlib_088353236" + smtp_test.go:188: failed as expected: all MXs returned transient failures (last: Error saying hello: write tcp 127.0.0.1:49314->127.0.0.1:36747: i/o timeout) + testlib.go:26: test directory: "/tmp/testlib_006520793" smtp_test.go:62: fakeServer got connection smtp_test.go:73: fakeServer read: "EHLO hello" smtp_test.go:73: fakeServer read: "MAIL FROM:" _ smtp.go:198 Courier.SMTP to@to: error: MAIL+RCPT 501 mail error smtp_test.go:188: failed as expected: MAIL+RCPT 501 mail error smtp_test.go:69: fakeServer exiting: EOF - testlib.go:26: test directory: "/tmp/testlib_027450406" + testlib.go:26: test directory: "/tmp/testlib_052744051" smtp_test.go:62: fakeServer got connection smtp_test.go:73: fakeServer read: "EHLO hello" smtp_test.go:73: fakeServer read: "MAIL FROM:" smtp_test.go:73: fakeServer read: "RCPT TO:" _ smtp.go:198 Courier.SMTP to@to: error: MAIL+RCPT 501 rcpt error - smtp_test.go:188: failed as expected: MAIL+RCPT 501 rcpt error smtp_test.go:69: fakeServer exiting: EOF - testlib.go:26: test directory: "/tmp/testlib_475958856" + smtp_test.go:188: failed as expected: MAIL+RCPT 501 rcpt error + testlib.go:26: test directory: "/tmp/testlib_964624413" smtp_test.go:62: fakeServer got connection smtp_test.go:73: fakeServer read: "EHLO hello" smtp_test.go:73: fakeServer read: "MAIL FROM:" smtp_test.go:73: fakeServer read: "RCPT TO:" smtp_test.go:73: fakeServer read: "DATA" _ smtp.go:203 Courier.SMTP to@to: error: DATA 554 data error - smtp_test.go:188: failed as expected: DATA 554 data error smtp_test.go:79: fakeServer exiting: unexpected EOF - testlib.go:26: test directory: "/tmp/testlib_493380282" + smtp_test.go:188: failed as expected: DATA 554 data error + testlib.go:26: test directory: "/tmp/testlib_874212951" smtp_test.go:62: fakeServer got connection smtp_test.go:73: fakeServer read: "EHLO hello" smtp_test.go:73: fakeServer read: "MAIL FROM:" @@ -841,9 +911,9 @@ _ smtp.go:212 Courier.SMTP to@to: error: DATA closing 551 data response error smtp_test.go:188: failed as expected: DATA closing 551 data response error smtp_test.go:69: fakeServer exiting: EOF ---- PASS: TestSMTPErrors (1.01s) +--- PASS: TestSMTPErrors (1.00s) === RUN TestNoMXServer - testlib.go:26: test directory: "/tmp/testlib_606241788" + testlib.go:26: test directory: "/tmp/testlib_500800161" _ smtp.go:81 Courier.SMTP to@to: error: Could not find mail server: smtp_test.go:206: got permanent failure, as expected: Could not find mail server: --- PASS: TestNoMXServer (0.00s) @@ -858,52 +928,52 @@ === RUN TestLookupInvalidDomain --- PASS: TestLookupInvalidDomain (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/courier 1.152s +ok blitiri.com.ar/go/chasquid/internal/courier 1.184s === RUN TestBasic - testlib.go:26: test directory: "/tmp/testlib_718594289" -_ domaininfo.go:107 DomainInfo /tmp/testlib_718594289: d1 incoming level raised: TLS_SECURE > PLAIN -_ domaininfo.go:99 DomainInfo /tmp/testlib_718594289: error: d1 incoming denied: TLS_INSECURE < TLS_SECURE -_ domaininfo.go:99 DomainInfo /tmp/testlib_718594289: error: d1 incoming denied: TLS_INSECURE < TLS_SECURE ---- PASS: TestBasic (0.00s) + testlib.go:26: test directory: "/tmp/testlib_819579015" +_ domaininfo.go:107 DomainInfo /tmp/testlib_819579015: d1 incoming level raised: TLS_SECURE > PLAIN +_ domaininfo.go:99 DomainInfo /tmp/testlib_819579015: error: d1 incoming denied: TLS_INSECURE < TLS_SECURE +_ domaininfo.go:99 DomainInfo /tmp/testlib_819579015: error: d1 incoming denied: TLS_INSECURE < TLS_SECURE +--- PASS: TestBasic (0.19s) === RUN TestNewDomain - testlib.go:26: test directory: "/tmp/testlib_261559598" -_ domaininfo.go:107 DomainInfo /tmp/testlib_261559598: insecure incoming level raised: TLS_INSECURE > PLAIN -_ domaininfo.go:139 DomainInfo /tmp/testlib_261559598: insecure outgoing level raised: TLS_INSECURE > PLAIN -_ domaininfo.go:107 DomainInfo /tmp/testlib_261559598: secure incoming level raised: TLS_SECURE > PLAIN -_ domaininfo.go:139 DomainInfo /tmp/testlib_261559598: secure outgoing level raised: TLS_SECURE > PLAIN ---- PASS: TestNewDomain (0.01s) + testlib.go:26: test directory: "/tmp/testlib_054189948" +_ domaininfo.go:107 DomainInfo /tmp/testlib_054189948: insecure incoming level raised: TLS_INSECURE > PLAIN +_ domaininfo.go:139 DomainInfo /tmp/testlib_054189948: insecure outgoing level raised: TLS_INSECURE > PLAIN +_ domaininfo.go:107 DomainInfo /tmp/testlib_054189948: secure incoming level raised: TLS_SECURE > PLAIN +_ domaininfo.go:139 DomainInfo /tmp/testlib_054189948: secure outgoing level raised: TLS_SECURE > PLAIN +--- PASS: TestNewDomain (0.17s) === RUN TestProgressions - testlib.go:26: test directory: "/tmp/testlib_248800964" -_ domaininfo.go:107 DomainInfo /tmp/testlib_248800964: pisis incoming level raised: TLS_INSECURE > PLAIN -_ domaininfo.go:139 DomainInfo /tmp/testlib_248800964: pisis outgoing level raised: TLS_INSECURE > PLAIN -_ domaininfo.go:107 DomainInfo /tmp/testlib_248800964: pisis incoming level raised: TLS_SECURE > TLS_INSECURE -_ domaininfo.go:139 DomainInfo /tmp/testlib_248800964: pisis outgoing level raised: TLS_SECURE > TLS_INSECURE -_ domaininfo.go:99 DomainInfo /tmp/testlib_248800964: error: pisis incoming denied: TLS_INSECURE < TLS_SECURE -_ domaininfo.go:131 DomainInfo /tmp/testlib_248800964: error: pisis outgoing denied: TLS_INSECURE < TLS_SECURE -_ domaininfo.go:107 DomainInfo /tmp/testlib_248800964: ssip incoming level raised: TLS_SECURE > PLAIN -_ domaininfo.go:139 DomainInfo /tmp/testlib_248800964: ssip outgoing level raised: TLS_SECURE > PLAIN -_ domaininfo.go:99 DomainInfo /tmp/testlib_248800964: error: ssip incoming denied: TLS_INSECURE < TLS_SECURE -_ domaininfo.go:131 DomainInfo /tmp/testlib_248800964: error: ssip outgoing denied: TLS_INSECURE < TLS_SECURE -_ domaininfo.go:99 DomainInfo /tmp/testlib_248800964: error: ssip incoming denied: PLAIN < TLS_SECURE -_ domaininfo.go:131 DomainInfo /tmp/testlib_248800964: error: ssip outgoing denied: PLAIN < TLS_SECURE ---- PASS: TestProgressions (0.00s) + testlib.go:26: test directory: "/tmp/testlib_069532450" +_ domaininfo.go:107 DomainInfo /tmp/testlib_069532450: pisis incoming level raised: TLS_INSECURE > PLAIN +_ domaininfo.go:139 DomainInfo /tmp/testlib_069532450: pisis outgoing level raised: TLS_INSECURE > PLAIN +_ domaininfo.go:107 DomainInfo /tmp/testlib_069532450: pisis incoming level raised: TLS_SECURE > TLS_INSECURE +_ domaininfo.go:139 DomainInfo /tmp/testlib_069532450: pisis outgoing level raised: TLS_SECURE > TLS_INSECURE +_ domaininfo.go:99 DomainInfo /tmp/testlib_069532450: error: pisis incoming denied: TLS_INSECURE < TLS_SECURE +_ domaininfo.go:131 DomainInfo /tmp/testlib_069532450: error: pisis outgoing denied: TLS_INSECURE < TLS_SECURE +_ domaininfo.go:107 DomainInfo /tmp/testlib_069532450: ssip incoming level raised: TLS_SECURE > PLAIN +_ domaininfo.go:139 DomainInfo /tmp/testlib_069532450: ssip outgoing level raised: TLS_SECURE > PLAIN +_ domaininfo.go:99 DomainInfo /tmp/testlib_069532450: error: ssip incoming denied: TLS_INSECURE < TLS_SECURE +_ domaininfo.go:131 DomainInfo /tmp/testlib_069532450: error: ssip outgoing denied: TLS_INSECURE < TLS_SECURE +_ domaininfo.go:99 DomainInfo /tmp/testlib_069532450: error: ssip incoming denied: PLAIN < TLS_SECURE +_ domaininfo.go:131 DomainInfo /tmp/testlib_069532450: error: ssip outgoing denied: PLAIN < TLS_SECURE +--- PASS: TestProgressions (0.29s) === RUN TestErrors - testlib.go:26: test directory: "/tmp/testlib_174844140" -_ domaininfo.go:107 DomainInfo /tmp/testlib_174844140: d1 incoming level raised: TLS_SECURE > PLAIN ---- PASS: TestErrors (0.00s) + testlib.go:26: test directory: "/tmp/testlib_011263242" +_ domaininfo.go:107 DomainInfo /tmp/testlib_011263242: d1 incoming level raised: TLS_SECURE > PLAIN +--- PASS: TestErrors (0.02s) PASS -ok blitiri.com.ar/go/chasquid/internal/domaininfo 0.033s +ok blitiri.com.ar/go/chasquid/internal/domaininfo 0.682s === RUN TestUsernameNotSafe --- PASS: TestUsernameNotSafe (0.00s) === RUN TestAutodetect - testlib.go:26: test directory: "/tmp/testlib_056729091" + testlib.go:26: test directory: "/tmp/testlib_197999382" --- PASS: TestAutodetect (0.00s) === RUN TestReload --- PASS: TestReload (0.00s) === RUN TestNotASocket ---- PASS: TestNotASocket (0.01s) +--- PASS: TestNotASocket (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/dovecot 0.047s +ok blitiri.com.ar/go/chasquid/internal/dovecot 0.004s === RUN TestSplit --- PASS: TestSplit (0.00s) === RUN TestDomainIn @@ -911,13 +981,13 @@ === RUN TestAddHeader --- PASS: TestAddHeader (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/envelope 0.019s +ok blitiri.com.ar/go/chasquid/internal/envelope 0.004s === RUN TestHandler --- PASS: TestHandler (0.00s) === RUN TestMapLabelAccident --- PASS: TestMapLabelAccident (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/expvarom 0.030s +ok blitiri.com.ar/go/chasquid/internal/expvarom 0.007s === RUN TestNoNewline --- PASS: TestNoNewline (0.00s) === RUN TestBasic @@ -942,7 +1012,7 @@ haproxy_test.go:69: testing 18: PROXY TCP6 5::5 6::6 7777 8888 --- PASS: TestBasic (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/haproxy 0.035s +ok blitiri.com.ar/go/chasquid/internal/haproxy 0.007s === RUN TestLogger --- PASS: TestLogger (0.00s) === RUN TestDefault @@ -950,7 +1020,7 @@ === RUN TestFailedLogger --- PASS: TestFailedLogger (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/maillog 0.010s +ok blitiri.com.ar/go/chasquid/internal/maillog 0.009s === RUN TestUser --- PASS: TestUser (0.00s) === RUN TestDomain @@ -960,41 +1030,41 @@ === RUN TestDomainToUnicode --- PASS: TestDomainToUnicode (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/normalize 0.018s +ok blitiri.com.ar/go/chasquid/internal/normalize 0.005s === RUN TestBin - testlib.go:26: test directory: "/tmp/testlib_498093095" + testlib.go:26: test directory: "/tmp/testlib_227023790" --- PASS: TestBin (0.00s) === RUN TestText - testlib.go:26: test directory: "/tmp/testlib_106350833" + testlib.go:26: test directory: "/tmp/testlib_193538320" --- PASS: TestText (0.00s) === RUN TestStore - testlib.go:26: test directory: "/tmp/testlib_219094091" + testlib.go:26: test directory: "/tmp/testlib_111190722" --- PASS: TestStore (0.00s) === RUN TestFileErrors - testlib.go:26: test directory: "/tmp/testlib_207780533" + testlib.go:26: test directory: "/tmp/testlib_484120900" --- PASS: TestFileErrors (0.00s) === RUN TestMarshalErrors - testlib.go:26: test directory: "/tmp/testlib_641963586" + testlib.go:26: test directory: "/tmp/testlib_326427517" --- PASS: TestMarshalErrors (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/protoio 0.014s +ok blitiri.com.ar/go/chasquid/internal/protoio 0.006s ? blitiri.com.ar/go/chasquid/internal/protoio/testpb [no test files] === RUN TestDSN dsn_test.go:49: From: Mail Delivery System To: Subject: Mail delivery failed: returning message to sender - Message-ID: - Date: Thu, 22 Jul 2021 11:28:59 +0000 + Message-ID: + Date: Wed, 24 Aug 2022 17:53:20 +0000 In-Reply-To: References: X-Failed-Recipients: pepe@africa.org, ñaca@africa.org, Auto-Submitted: auto-replied MIME-Version: 1.0 Content-Type: multipart/report; report-type=delivery-status; - boundary="CywPQZ4VP70" + boundary="qgY5qsrjGcA" - --CywPQZ4VP70 + --qgY5qsrjGcA Content-Type: text/plain; charset="utf-8" Content-Disposition: inline Content-Description: Notification @@ -1019,7 +1089,7 @@ oh! the humanity! - --CywPQZ4VP70 + --qgY5qsrjGcA Content-Type: message/global-delivery-status Content-Description: Delivery Report Content-Transfer-Encoding: 8bit @@ -1050,7 +1120,7 @@ - --CywPQZ4VP70 + --qgY5qsrjGcA Content-Type: message/rfc822 Content-Description: Undelivered Message Content-Transfer-Encoding: 8bit @@ -1060,72 +1130,77 @@ Data ñaca. - --CywPQZ4VP70-- + --qgY5qsrjGcA-- --- PASS: TestDSN (0.00s) === RUN TestBasic - testlib.go:26: test directory: "/tmp/testlib_366484764" -_ queue.go:302 Queue.SendLoop k-ljhMvWzWM: from from -_ queue.go:361 Queue.SendLoop k-ljhMvWzWM: nodomain sent -_ queue.go:361 Queue.SendLoop k-ljhMvWzWM: am@loco sent -_ queue.go:361 Queue.SendLoop k-ljhMvWzWM: x@remote sent -_ queue.go:336 Queue.SendLoop k-ljhMvWzWM: all done ---- PASS: TestBasic (0.02s) + testlib.go:26: test directory: "/tmp/testlib_661086233" +_ queue.go:302 Queue.SendLoop nRAkO1ES3G4: from from +_ queue.go:361 Queue.SendLoop nRAkO1ES3G4: am@loco sent +_ queue.go:361 Queue.SendLoop nRAkO1ES3G4: nodomain sent +_ queue.go:361 Queue.SendLoop nRAkO1ES3G4: x@remote sent +_ queue.go:336 Queue.SendLoop nRAkO1ES3G4: all done +--- PASS: TestBasic (0.22s) === RUN TestDSNOnTimeout - testlib.go:26: test directory: "/tmp/testlib_479140911" -_ queue.go:302 Queue.SendLoop 3cCMdQcZgq8: from from@loco -_ queue.go:459 Queue.SendLoop 3cCMdQcZgq8: queued DSN: iXp0zzoLFPw -_ queue.go:336 Queue.SendLoop 3cCMdQcZgq8: all done -_ queue.go:302 Queue.SendLoop iXp0zzoLFPw: from <> -_ queue.go:361 Queue.SendLoop iXp0zzoLFPw: from@loco sent -_ queue.go:336 Queue.SendLoop iXp0zzoLFPw: all done + testlib.go:26: test directory: "/tmp/testlib_958678552" +_ queue.go:302 Queue.SendLoop tDTEv7gCgbY: from from@loco +_ queue.go:459 Queue.SendLoop tDTEv7gCgbY: queued DSN: Nf2SpHSs1vE +_ queue.go:336 Queue.SendLoop tDTEv7gCgbY: all done +_ queue.go:302 Queue.SendLoop Nf2SpHSs1vE: from <> +_ queue.go:361 Queue.SendLoop Nf2SpHSs1vE: from@loco sent --- PASS: TestDSNOnTimeout (0.00s) === RUN TestAliases - testlib.go:26: test directory: "/tmp/testlib_088246995" -_ queue.go:302 Queue.SendLoop QmnPnxsi45k: from from -_ queue.go:361 Queue.SendLoop QmnPnxsi45k: ata@hualpa sent -_ queue.go:361 Queue.SendLoop QmnPnxsi45k: pq@loco sent -_ queue.go:361 Queue.SendLoop QmnPnxsi45k: rs@loco sent -_ queue.go:336 Queue.SendLoop QmnPnxsi45k: all done +_ queue.go:336 Queue.SendLoop Nf2SpHSs1vE: all done + testlib.go:26: test directory: "/tmp/testlib_399240908" +_ queue.go:302 Queue.SendLoop xEKbbiaIgik: from from +_ queue.go:361 Queue.SendLoop xEKbbiaIgik: ata@hualpa sent --- PASS: TestAliases (0.00s) === RUN TestFullQueue - testlib.go:26: test directory: "/tmp/testlib_174640042" +_ queue.go:369 Queue.SendLoop xEKbbiaIgik: error: failed to write: rename /tmp/testlib_399240908/.m:xEKbbiaIgik720425438 /tmp/testlib_399240908/m:xEKbbiaIgik: no such file or directory +_ queue.go:361 Queue.SendLoop xEKbbiaIgik: rs@loco sent + testlib.go:26: test directory: "/tmp/testlib_707113381" +_ queue.go:369 Queue.SendLoop xEKbbiaIgik: error: failed to write: open /tmp/testlib_399240908/.m:xEKbbiaIgik105282752: no such file or directory +_ queue.go:361 Queue.SendLoop xEKbbiaIgik: pq@loco sent +_ queue.go:369 Queue.SendLoop xEKbbiaIgik: error: failed to write: open /tmp/testlib_399240908/.m:xEKbbiaIgik531065631: no such file or directory +_ queue.go:336 Queue.SendLoop xEKbbiaIgik: all done +E queue.go:224 failed to remove queue file "/tmp/testlib_399240908/m:xEKbbiaIgik": remove /tmp/testlib_399240908/m:xEKbbiaIgik: no such file or directory +_ queue.go:302 Queue.SendLoop cJVfTJ-9P1c: from from --- PASS: TestFullQueue (0.00s) +_ queue.go:361 Queue.SendLoop cJVfTJ-9P1c: to sent === RUN TestPipes - testlib.go:26: test directory: "/tmp/testlib_653449435" -_ queue.go:302 Queue.SendLoop TSI5kCClfd0: from from -_ queue.go:361 Queue.SendLoop TSI5kCClfd0: to sent -_ queue.go:369 Queue.SendLoop TSI5kCClfd0: error: failed to write: open /tmp/testlib_174640042/.m:TSI5kCClfd0020888702: no such file or directory -_ queue.go:336 Queue.SendLoop TSI5kCClfd0: all done -E queue.go:224 failed to remove queue file "/tmp/testlib_174640042/m:TSI5kCClfd0": remove /tmp/testlib_174640042/m:TSI5kCClfd0: no such file or directory ---- PASS: TestPipes (0.01s) +_ queue.go:369 Queue.SendLoop cJVfTJ-9P1c: error: failed to write: open /tmp/testlib_707113381/.m:cJVfTJ-9P1c502544067: no such file or directory + testlib.go:26: test directory: "/tmp/testlib_318875636" +_ queue.go:336 Queue.SendLoop cJVfTJ-9P1c: all done +E queue.go:224 failed to remove queue file "/tmp/testlib_707113381/m:cJVfTJ-9P1c": remove /tmp/testlib_707113381/m:cJVfTJ-9P1c: no such file or directory +--- PASS: TestPipes (0.00s) === RUN TestBadPath --- PASS: TestBadPath (0.00s) === RUN TestNextDelay --- PASS: TestNextDelay (0.00s) === RUN TestSerialization - testlib.go:26: test directory: "/tmp/testlib_020339653" -_ queue.go:302 Queue.SendLoop 9FKxPkF3mro: from from@loco -_ queue.go:361 Queue.SendLoop 9FKxPkF3mro: to@to sent -_ queue.go:336 Queue.SendLoop 9FKxPkF3mro: all done ---- PASS: TestSerialization (0.01s) + testlib.go:26: test directory: "/tmp/testlib_756523846" +_ queue.go:302 Queue.SendLoop Tepq8qcePBE: from from@loco +_ queue.go:361 Queue.SendLoop Tepq8qcePBE: to@to sent +_ queue.go:336 Queue.SendLoop Tepq8qcePBE: all done +E queue.go:224 failed to remove queue file "/tmp/testlib_756523846/m:Tepq8qcePBE": remove /tmp/testlib_756523846/m:Tepq8qcePBE: no such file or directory +--- PASS: TestSerialization (0.17s) PASS -ok blitiri.com.ar/go/chasquid/internal/queue 0.056s +ok blitiri.com.ar/go/chasquid/internal/queue 0.402s === RUN TestWriteFile - testlib.go:26: test directory: "/tmp/testlib_595664020" ---- PASS: TestWriteFile (0.01s) + testlib.go:26: test directory: "/tmp/testlib_465167764" +--- PASS: TestWriteFile (0.00s) === RUN TestWriteFileWithOp - testlib.go:26: test directory: "/tmp/testlib_098496264" + testlib.go:26: test directory: "/tmp/testlib_176354312" --- PASS: TestWriteFileWithOp (0.00s) === RUN TestWriteFileWithFailingOp - testlib.go:26: test directory: "/tmp/testlib_296256890" + testlib.go:26: test directory: "/tmp/testlib_733729402" --- PASS: TestWriteFileWithFailingOp (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/safeio 0.040s +ok blitiri.com.ar/go/chasquid/internal/safeio 0.012s === RUN TestString --- PASS: TestString (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/set 0.034s +ok blitiri.com.ar/go/chasquid/internal/set 0.004s === RUN TestIsPermanent --- PASS: TestIsPermanent (0.00s) === RUN TestIsASCII @@ -1139,20 +1214,20 @@ === RUN TestFallbackToIDNA --- PASS: TestFallbackToIDNA (0.00s) === RUN TestLineTooLong ---- PASS: TestLineTooLong (0.12s) +--- PASS: TestLineTooLong (0.03s) PASS -ok blitiri.com.ar/go/chasquid/internal/smtp 0.145s -_ server.go:221 Server listening on 127.0.0.1:44217 (SMTP) -2021-07-22 11:28:59.592814 daemon listening on 127.0.0.1:44217 -_ server.go:221 Server listening on 127.0.0.1:34841 (submission) -2021-07-22 11:28:59.592913 daemon listening on 127.0.0.1:34841 -_ server.go:221 Server listening on 127.0.0.1:39263 (submission+TLS) -2021-07-22 11:28:59.592965 daemon listening on 127.0.0.1:39263 +ok blitiri.com.ar/go/chasquid/internal/smtp 0.036s +_ server.go:221 Server listening on 127.0.0.1:37203 (submission) +2022-08-24 17:53:21.207287 daemon listening on 127.0.0.1:37203 +_ server.go:221 Server listening on 127.0.0.1:41149 (submission+TLS) +2022-08-24 17:53:21.207359 daemon listening on 127.0.0.1:41149 +_ server.go:221 Server listening on 127.0.0.1:44999 (SMTP) +2022-08-24 17:53:21.207389 daemon listening on 127.0.0.1:44999 === RUN TestSecLevel - testlib.go:26: test directory: "/tmp/testlib_528807329" -_ conn.go:191 SMTP.Conn 127.0.0.1:38064: error: error completing TLS handshake: EOF -_ domaininfo.go:107 DomainInfo /tmp/testlib_528807329: slc incoming level raised: TLS_CLIENT > PLAIN -_ domaininfo.go:99 DomainInfo /tmp/testlib_528807329: error: slc incoming denied: PLAIN < TLS_CLIENT +_ conn.go:191 SMTP.Conn 127.0.0.1:53882: error: error completing TLS handshake: EOF + testlib.go:26: test directory: "/tmp/testlib_633099356" +_ domaininfo.go:107 DomainInfo /tmp/testlib_633099356: slc incoming level raised: TLS_CLIENT > PLAIN +_ domaininfo.go:99 DomainInfo /tmp/testlib_633099356: error: slc incoming denied: PLAIN < TLS_CLIENT _ conn.go:520 testconn testconn: error: security level check for slc failed (PLAIN) --- PASS: TestSecLevel (0.02s) === RUN TestIsHeader @@ -1189,163 +1264,159 @@ === RUN TestSanitizeEHLODomain --- PASS: TestSanitizeEHLODomain (0.00s) === RUN TestSimple -_ conn.go:664 SMTP.Conn 127.0.0.1:51496: Queued from from@from to [to@localhost] - NxES_i6agjI -2021-07-22 11:28:59.718043 NxES_i6agjI from=from@from queued ip=127.0.0.1:51496 to=[to@localhost] -_ queue.go:302 Queue.SendLoop NxES_i6agjI: from from@from -_ queue.go:361 Queue.SendLoop NxES_i6agjI: testuser@localhost sent -2021-07-22 11:28:59.718385 NxES_i6agjI from=from@from to=testuser@localhost sent ---- PASS: TestSimple (0.01s) +_ conn.go:664 SMTP.Conn 127.0.0.1:34132: Queued from from@from to [to@localhost] - -FfyxTzlJp8 +2022-08-24 17:53:21.330587 -FfyxTzlJp8 from=from@from queued ip=127.0.0.1:34132 to=[to@localhost] +_ queue.go:302 Queue.SendLoop -FfyxTzlJp8: from from@from +_ queue.go:361 Queue.SendLoop -FfyxTzlJp8: testuser@localhost sent +2022-08-24 17:53:21.330693 -FfyxTzlJp8 from=from@from to=testuser@localhost sent +--- PASS: TestSimple (0.00s) === RUN TestSimpleTLS -_ conn.go:664 SMTP.Conn 127.0.0.1:51498: Queued from from@from to [to@localhost] - VIxWmUWmKVc -2021-07-22 11:28:59.729735 VIxWmUWmKVc from=from@from queued ip=127.0.0.1:51498 to=[to@localhost] -_ queue.go:336 Queue.SendLoop NxES_i6agjI: all done -2021-07-22 11:28:59.729767 NxES_i6agjI from=from@from all done -_ queue.go:302 Queue.SendLoop VIxWmUWmKVc: from from@from -_ queue.go:361 Queue.SendLoop VIxWmUWmKVc: testuser@localhost sent -2021-07-22 11:28:59.730007 VIxWmUWmKVc from=from@from to=testuser@localhost sent +_ queue.go:336 Queue.SendLoop -FfyxTzlJp8: all done +2022-08-24 17:53:21.330899 -FfyxTzlJp8 from=from@from all done +_ conn.go:664 SMTP.Conn 127.0.0.1:34136: Queued from from@from to [to@localhost] - smLBSu5cqjo +2022-08-24 17:53:21.337243 smLBSu5cqjo from=from@from queued ip=127.0.0.1:34136 to=[to@localhost] +_ queue.go:302 Queue.SendLoop smLBSu5cqjo: from from@from +_ queue.go:361 Queue.SendLoop smLBSu5cqjo: testuser@localhost sent +2022-08-24 17:53:21.337352 smLBSu5cqjo from=from@from to=testuser@localhost sent --- PASS: TestSimpleTLS (0.01s) -_ queue.go:336 Queue.SendLoop VIxWmUWmKVc: all done === RUN TestManyEmails -2021-07-22 11:28:59.730298 VIxWmUWmKVc from=from@from all done -_ conn.go:664 SMTP.Conn 127.0.0.1:51500: Queued from from@from to [to@localhost] - klIRSYTNiD0 -2021-07-22 11:28:59.748474 klIRSYTNiD0 from=from@from queued ip=127.0.0.1:51500 to=[to@localhost] -_ queue.go:302 Queue.SendLoop klIRSYTNiD0: from from@from -_ queue.go:361 Queue.SendLoop klIRSYTNiD0: testuser@localhost sent -2021-07-22 11:28:59.748681 klIRSYTNiD0 from=from@from to=testuser@localhost sent -_ queue.go:336 Queue.SendLoop klIRSYTNiD0: all done -2021-07-22 11:28:59.749467 klIRSYTNiD0 from=from@from all done -_ conn.go:664 SMTP.Conn 127.0.0.1:51500: Queued from from@from to [to@localhost] - vY8hv8vjrnI -2021-07-22 11:28:59.749630 vY8hv8vjrnI from=from@from queued ip=127.0.0.1:51500 to=[to@localhost] -_ queue.go:302 Queue.SendLoop vY8hv8vjrnI: from from@from -_ queue.go:361 Queue.SendLoop vY8hv8vjrnI: testuser@localhost sent -2021-07-22 11:28:59.749737 vY8hv8vjrnI from=from@from to=testuser@localhost sent -_ conn.go:664 SMTP.Conn 127.0.0.1:51500: Queued from from@from to [to@localhost] - InYg259mTCc -2021-07-22 11:28:59.751582 InYg259mTCc from=from@from queued ip=127.0.0.1:51500 to=[to@localhost] -_ queue.go:302 Queue.SendLoop InYg259mTCc: from from@from -_ queue.go:361 Queue.SendLoop InYg259mTCc: testuser@localhost sent -2021-07-22 11:28:59.751786 InYg259mTCc from=from@from to=testuser@localhost sent ---- PASS: TestManyEmails (0.02s) +_ queue.go:336 Queue.SendLoop smLBSu5cqjo: all done +2022-08-24 17:53:21.375429 smLBSu5cqjo from=from@from all done +_ conn.go:664 SMTP.Conn 127.0.0.1:34144: Queued from from@from to [to@localhost] - 2DDzhy6d6Ok +2022-08-24 17:53:21.375533 2DDzhy6d6Ok from=from@from queued ip=127.0.0.1:34144 to=[to@localhost] +_ queue.go:302 Queue.SendLoop 2DDzhy6d6Ok: from from@from +_ queue.go:361 Queue.SendLoop 2DDzhy6d6Ok: testuser@localhost sent +2022-08-24 17:53:21.375666 2DDzhy6d6Ok from=from@from to=testuser@localhost sent +_ queue.go:336 Queue.SendLoop 2DDzhy6d6Ok: all done +2022-08-24 17:53:21.375858 2DDzhy6d6Ok from=from@from all done +_ conn.go:664 SMTP.Conn 127.0.0.1:34144: Queued from from@from to [to@localhost] - wVcdC9BFi2Q +2022-08-24 17:53:21.376232 wVcdC9BFi2Q from=from@from queued ip=127.0.0.1:34144 to=[to@localhost] +_ queue.go:302 Queue.SendLoop wVcdC9BFi2Q: from from@from +_ queue.go:361 Queue.SendLoop wVcdC9BFi2Q: testuser@localhost sent +2022-08-24 17:53:21.376384 wVcdC9BFi2Q from=from@from to=testuser@localhost sent +_ queue.go:336 Queue.SendLoop wVcdC9BFi2Q: all done +2022-08-24 17:53:21.376578 wVcdC9BFi2Q from=from@from all done +_ conn.go:664 SMTP.Conn 127.0.0.1:34144: Queued from from@from to [to@localhost] - XT27qz2Ncxc +2022-08-24 17:53:21.376977 XT27qz2Ncxc from=from@from queued ip=127.0.0.1:34144 to=[to@localhost] +_ queue.go:302 Queue.SendLoop XT27qz2Ncxc: from from@from +_ queue.go:361 Queue.SendLoop XT27qz2Ncxc: testuser@localhost sent +2022-08-24 17:53:21.377056 XT27qz2Ncxc from=from@from to=testuser@localhost sent +--- PASS: TestManyEmails (0.04s) === RUN TestAuth -_ queue.go:336 Queue.SendLoop InYg259mTCc: all done -2021-07-22 11:28:59.752737 InYg259mTCc from=from@from all done -_ queue.go:336 Queue.SendLoop vY8hv8vjrnI: all done -2021-07-22 11:28:59.757819 vY8hv8vjrnI from=from@from all done -2021-07-22 11:28:59.903330 127.0.0.1:46198 auth succeeded for testuser@localhost -_ conn.go:664 SMTP.Conn 127.0.0.1:46198: Queued from testuser@localhost to [to@localhost] - _upsGXLvnpM -2021-07-22 11:28:59.906633 _upsGXLvnpM from=testuser@localhost queued ip=127.0.0.1:46198 to=[to@localhost] -_ queue.go:302 Queue.SendLoop _upsGXLvnpM: from testuser@localhost -_ queue.go:361 Queue.SendLoop _upsGXLvnpM: testuser@localhost sent -2021-07-22 11:28:59.906803 _upsGXLvnpM from=testuser@localhost to=testuser@localhost sent -_ queue.go:336 Queue.SendLoop _upsGXLvnpM: all done -2021-07-22 11:28:59.907085 _upsGXLvnpM from=testuser@localhost all done ---- PASS: TestAuth (0.16s) +_ queue.go:336 Queue.SendLoop XT27qz2Ncxc: all done +2022-08-24 17:53:21.377225 XT27qz2Ncxc from=from@from all done +2022-08-24 17:53:21.485763 127.0.0.1:44084 auth succeeded for testuser@localhost +_ conn.go:664 SMTP.Conn 127.0.0.1:44084: Queued from testuser@localhost to [to@localhost] - E33AN-oJyFw +2022-08-24 17:53:21.486559 E33AN-oJyFw from=testuser@localhost queued ip=127.0.0.1:44084 to=[to@localhost] +_ queue.go:302 Queue.SendLoop E33AN-oJyFw: from testuser@localhost +_ queue.go:361 Queue.SendLoop E33AN-oJyFw: testuser@localhost sent +2022-08-24 17:53:21.486709 E33AN-oJyFw from=testuser@localhost to=testuser@localhost sent +--- PASS: TestAuth (0.11s) === RUN TestSubmissionWithoutAuth -_ conn.go:292 SMTP.Conn 127.0.0.1:46200: error: MAIL failed: 550 5.7.9 Mail to submission port must be authenticated +_ queue.go:336 Queue.SendLoop E33AN-oJyFw: all done +2022-08-24 17:53:21.490571 E33AN-oJyFw from=testuser@localhost all done +_ conn.go:292 SMTP.Conn 127.0.0.1:44086: error: MAIL failed: 550 5.7.9 Mail to submission port must be authenticated --- PASS: TestSubmissionWithoutAuth (0.01s) === RUN TestAuthOnTLS -2021-07-22 11:29:00.067570 127.0.0.1:38076 auth succeeded for testuser@localhost -_ conn.go:664 SMTP.Conn 127.0.0.1:38076: Queued from testuser@localhost to [to@localhost] - MjlVi4mLOtk -2021-07-22 11:29:00.068506 MjlVi4mLOtk from=testuser@localhost queued ip=127.0.0.1:38076 to=[to@localhost] -_ queue.go:302 Queue.SendLoop MjlVi4mLOtk: from testuser@localhost -_ queue.go:361 Queue.SendLoop MjlVi4mLOtk: testuser@localhost sent -2021-07-22 11:29:00.068789 MjlVi4mLOtk from=testuser@localhost to=testuser@localhost sent ---- PASS: TestAuthOnTLS (0.15s) +2022-08-24 17:53:21.598535 127.0.0.1:53902 auth succeeded for testuser@localhost +_ conn.go:664 SMTP.Conn 127.0.0.1:53902: Queued from testuser@localhost to [to@localhost] - n6navUM3-A8 +2022-08-24 17:53:21.599301 n6navUM3-A8 from=testuser@localhost queued ip=127.0.0.1:53902 to=[to@localhost] +_ queue.go:302 Queue.SendLoop n6navUM3-A8: from testuser@localhost +_ queue.go:361 Queue.SendLoop n6navUM3-A8: testuser@localhost sent +2022-08-24 17:53:21.599444 n6navUM3-A8 from=testuser@localhost to=testuser@localhost sent +--- PASS: TestAuthOnTLS (0.11s) === RUN TestAuthOnSMTP -_ queue.go:336 Queue.SendLoop MjlVi4mLOtk: all done -2021-07-22 11:29:00.069194 MjlVi4mLOtk from=testuser@localhost all done -2021-07-22 11:29:00.199598 127.0.0.1:51508 auth succeeded for testuser@localhost -_ conn.go:664 SMTP.Conn 127.0.0.1:51508: Queued from testuser@localhost to [to@localhost] - iXI7-UTitlA -2021-07-22 11:29:00.203324 iXI7-UTitlA from=testuser@localhost queued ip=127.0.0.1:51508 to=[to@localhost] -_ queue.go:302 Queue.SendLoop iXI7-UTitlA: from testuser@localhost -_ queue.go:361 Queue.SendLoop iXI7-UTitlA: testuser@localhost sent -2021-07-22 11:29:00.203514 iXI7-UTitlA from=testuser@localhost to=testuser@localhost sent -_ queue.go:336 Queue.SendLoop iXI7-UTitlA: all done -2021-07-22 11:29:00.204120 iXI7-UTitlA from=testuser@localhost all done ---- PASS: TestAuthOnSMTP (0.14s) +_ queue.go:336 Queue.SendLoop n6navUM3-A8: all done +2022-08-24 17:53:21.608332 n6navUM3-A8 from=testuser@localhost all done +2022-08-24 17:53:21.706165 127.0.0.1:34152 auth succeeded for testuser@localhost +_ conn.go:664 SMTP.Conn 127.0.0.1:34152: Queued from testuser@localhost to [to@localhost] - vY9QJfi-2o8 +2022-08-24 17:53:21.706900 vY9QJfi-2o8 from=testuser@localhost queued ip=127.0.0.1:34152 to=[to@localhost] +_ queue.go:302 Queue.SendLoop vY9QJfi-2o8: from testuser@localhost +_ queue.go:361 Queue.SendLoop vY9QJfi-2o8: testuser@localhost sent +2022-08-24 17:53:21.707052 vY9QJfi-2o8 from=testuser@localhost to=testuser@localhost sent +--- PASS: TestAuthOnSMTP (0.11s) === RUN TestBrokenAuth -_ conn.go:1060 SMTP.Conn 127.0.0.1:46206: error: error authenticating \"user\"@\"broken\": failed to auth -2021-07-22 11:29:00.333188 127.0.0.1:46206 auth failed for user@broken -_ conn.go:292 SMTP.Conn 127.0.0.1:46206: error: AUTH failed: 454 4.7.0 Temporary authentication failure -_ conn.go:292 SMTP.Conn 127.0.0.1:46206: error: unknown<*> failed: 500 5.5.1 Unknown command ---- PASS: TestBrokenAuth (0.13s) +_ queue.go:336 Queue.SendLoop vY9QJfi-2o8: all done +2022-08-24 17:53:21.735587 vY9QJfi-2o8 from=testuser@localhost all done +_ conn.go:1060 SMTP.Conn 127.0.0.1:44092: error: error authenticating \"user\"@\"broken\": failed to auth +2022-08-24 17:53:21.817965 127.0.0.1:44092 auth failed for user@broken +_ conn.go:292 SMTP.Conn 127.0.0.1:44092: error: AUTH failed: 454 4.7.0 Temporary authentication failure +_ conn.go:292 SMTP.Conn 127.0.0.1:44092: error: unknown<*> failed: 500 5.5.1 Unknown command +--- PASS: TestBrokenAuth (0.11s) === RUN TestWrongMailParsing -_ conn.go:292 SMTP.Conn 127.0.0.1:51520: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51520: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51520: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51520: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51520: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51520: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51520: error: RCPT failed: 501 5.1.3 Malformed destination address -_ conn.go:292 SMTP.Conn 127.0.0.1:51520: error: RCPT failed: 501 5.1.3 Malformed destination address -_ conn.go:292 SMTP.Conn 127.0.0.1:51520: error: RCPT failed: 501 5.1.3 Malformed destination address -_ conn.go:292 SMTP.Conn 127.0.0.1:51520: error: RCPT failed: 501 5.1.3 Malformed destination address -_ conn.go:292 SMTP.Conn 127.0.0.1:51520: error: RCPT failed: 501 5.1.3 Malformed destination address -_ conn.go:297 SMTP.Conn 127.0.0.1:51520: error: too many errors, breaking connection +_ conn.go:292 SMTP.Conn 127.0.0.1:34156: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34156: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34156: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34156: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34156: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34156: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34156: error: RCPT failed: 501 5.1.3 Malformed destination address +_ conn.go:292 SMTP.Conn 127.0.0.1:34156: error: RCPT failed: 501 5.1.3 Malformed destination address +_ conn.go:292 SMTP.Conn 127.0.0.1:34156: error: RCPT failed: 501 5.1.3 Malformed destination address +_ conn.go:292 SMTP.Conn 127.0.0.1:34156: error: RCPT failed: 501 5.1.3 Malformed destination address +_ conn.go:292 SMTP.Conn 127.0.0.1:34156: error: RCPT failed: 501 5.1.3 Malformed destination address +_ conn.go:297 SMTP.Conn 127.0.0.1:34156: error: too many errors, breaking connection --- PASS: TestWrongMailParsing (0.00s) === RUN TestNullMailFrom --- PASS: TestNullMailFrom (0.00s) === RUN TestRcptBeforeMail -_ conn.go:292 SMTP.Conn 127.0.0.1:51524: error: RCPT failed: 503 5.5.1 Sender not yet given +_ conn.go:292 SMTP.Conn 127.0.0.1:34160: error: RCPT failed: 503 5.5.1 Sender not yet given --- PASS: TestRcptBeforeMail (0.00s) === RUN TestRcptOption --- PASS: TestRcptOption (0.01s) === RUN TestRelayForbidden -2021-07-22 11:29:00.355610 127.0.0.1:51528 rejected from=from@somewhere to=[to@somewhere] - relay not allowed -_ conn.go:292 SMTP.Conn 127.0.0.1:51528: error: RCPT failed: 503 5.7.1 Relay not allowed +2022-08-24 17:53:21.826287 127.0.0.1:34164 rejected from=from@somewhere to=[to@somewhere] - relay not allowed +_ conn.go:292 SMTP.Conn 127.0.0.1:34164: error: RCPT failed: 503 5.7.1 Relay not allowed --- PASS: TestRelayForbidden (0.00s) === RUN TestTooManyRecipients -2021-07-22 11:29:00.502844 127.0.0.1:46226 auth succeeded for testuser@localhost -_ conn.go:292 SMTP.Conn 127.0.0.1:46226: error: RCPT failed: 452 4.5.3 Too many recipients ---- PASS: TestTooManyRecipients (0.16s) +2022-08-24 17:53:21.937575 127.0.0.1:44104 auth succeeded for testuser@localhost +_ conn.go:292 SMTP.Conn 127.0.0.1:44104: error: RCPT failed: 452 4.5.3 Too many recipients +--- PASS: TestTooManyRecipients (0.12s) === RUN TestRcptFailsExistsCheck -_ conn.go:1098 SMTP.Conn 127.0.0.1:51532: error: error checking if user \"to@broken\" exists: failed to check if user exists -2021-07-22 11:29:00.519451 127.0.0.1:51532 rejected from=from@localhost to=[to@broken] - local user does not exist -_ conn.go:292 SMTP.Conn 127.0.0.1:51532: error: RCPT failed: 550 5.1.1 Destination address is unknown (user does not exist) +_ conn.go:1098 SMTP.Conn 127.0.0.1:34168: error: error checking if user \"to@broken\" exists: failed to check if user exists +2022-08-24 17:53:21.949975 127.0.0.1:34168 rejected from=from@localhost to=[to@broken] - local user does not exist +_ conn.go:292 SMTP.Conn 127.0.0.1:34168: error: RCPT failed: 550 5.1.1 Destination address is unknown (user does not exist) --- PASS: TestRcptFailsExistsCheck (0.01s) === RUN TestTooMuchData -_ conn.go:664 SMTP.Conn 127.0.0.1:51534: Queued from from@from to [to@localhost] - oEb87kR-8Ug -2021-07-22 11:29:01.110613 oEb87kR-8Ug from=from@from queued ip=127.0.0.1:51534 to=[to@localhost] -_ queue.go:302 Queue.SendLoop oEb87kR-8Ug: from from@from -_ queue.go:361 Queue.SendLoop oEb87kR-8Ug: testuser@localhost sent -2021-07-22 11:29:01.110887 oEb87kR-8Ug from=from@from to=testuser@localhost sent -_ queue.go:336 Queue.SendLoop oEb87kR-8Ug: all done -2021-07-22 11:29:01.268355 oEb87kR-8Ug from=from@from all done -_ conn.go:664 SMTP.Conn 127.0.0.1:51534: Queued from from@from to [to@localhost] - YXViGVgQhfE -2021-07-22 11:29:02.126474 YXViGVgQhfE from=from@from queued ip=127.0.0.1:51534 to=[to@localhost] -_ queue.go:302 Queue.SendLoop YXViGVgQhfE: from from@from -_ queue.go:361 Queue.SendLoop YXViGVgQhfE: testuser@localhost sent -2021-07-22 11:29:02.126647 YXViGVgQhfE from=from@from to=testuser@localhost sent -_ queue.go:336 Queue.SendLoop YXViGVgQhfE: all done -2021-07-22 11:29:02.273383 YXViGVgQhfE from=from@from all done -_ conn.go:292 SMTP.Conn 127.0.0.1:51534: error: DATA failed: 552 5.3.4 Message too big -_ queue.go:302 Queue.SendLoop Rwo9QHeAu_U: from from@from -_ queue.go:361 Queue.SendLoop Rwo9QHeAu_U: testuser@localhost sent -2021-07-22 11:29:03.050064 Rwo9QHeAu_U from=from@from to=testuser@localhost sent -_ conn.go:664 SMTP.Conn 127.0.0.1:51534: Queued from from@from to [to@localhost] - Rwo9QHeAu_U -2021-07-22 11:29:03.050180 Rwo9QHeAu_U from=from@from queued ip=127.0.0.1:51534 to=[to@localhost] ---- PASS: TestTooMuchData (2.53s) +_ conn.go:664 SMTP.Conn 127.0.0.1:34178: Queued from from@from to [to@localhost] - -cUHxi7iTYY +2022-08-24 17:53:22.149241 -cUHxi7iTYY from=from@from queued ip=127.0.0.1:34178 to=[to@localhost] +_ queue.go:302 Queue.SendLoop -cUHxi7iTYY: from from@from +_ queue.go:361 Queue.SendLoop -cUHxi7iTYY: testuser@localhost sent +2022-08-24 17:53:22.149357 -cUHxi7iTYY from=from@from to=testuser@localhost sent +_ queue.go:336 Queue.SendLoop -cUHxi7iTYY: all done +2022-08-24 17:53:22.211301 -cUHxi7iTYY from=from@from all done +_ conn.go:664 SMTP.Conn 127.0.0.1:34178: Queued from from@from to [to@localhost] - f-qpPda7dO4 +2022-08-24 17:53:22.360987 f-qpPda7dO4 from=from@from queued ip=127.0.0.1:34178 to=[to@localhost] +_ queue.go:302 Queue.SendLoop f-qpPda7dO4: from from@from +_ queue.go:361 Queue.SendLoop f-qpPda7dO4: testuser@localhost sent +2022-08-24 17:53:22.361069 f-qpPda7dO4 from=from@from to=testuser@localhost sent +_ queue.go:336 Queue.SendLoop f-qpPda7dO4: all done +2022-08-24 17:53:22.482541 f-qpPda7dO4 from=from@from all done +_ conn.go:292 SMTP.Conn 127.0.0.1:34178: error: DATA failed: 552 5.3.4 Message too big +_ conn.go:664 SMTP.Conn 127.0.0.1:34178: Queued from from@from to [to@localhost] - kN-vms4znlc +2022-08-24 17:53:22.767718 kN-vms4znlc from=from@from queued ip=127.0.0.1:34178 to=[to@localhost] +_ queue.go:302 Queue.SendLoop kN-vms4znlc: from from@from +_ queue.go:361 Queue.SendLoop kN-vms4znlc: testuser@localhost sent +2022-08-24 17:53:22.767820 kN-vms4znlc from=from@from to=testuser@localhost sent +--- PASS: TestTooMuchData (0.82s) === RUN TestSimpleCommands -_ conn.go:292 SMTP.Conn 127.0.0.1:51536: error: VRFY failed: 502 5.5.1 You have a strange feeling for a moment, then it passes. -_ conn.go:292 SMTP.Conn 127.0.0.1:51536: error: EXPN failed: 502 5.5.1 You feel disoriented for a moment. +_ conn.go:292 SMTP.Conn 127.0.0.1:34180: error: VRFY failed: 502 5.5.1 You have a strange feeling for a moment, then it passes. +_ conn.go:292 SMTP.Conn 127.0.0.1:34180: error: EXPN failed: 502 5.5.1 You feel disoriented for a moment. --- PASS: TestSimpleCommands (0.00s) === RUN TestLongLines -_ conn.go:292 SMTP.Conn 127.0.0.1:51538: error: unknown<> failed: 500 5.5.1 Unknown command -_ conn.go:314 SMTP.Conn 127.0.0.1:51538: error: exiting with error: line too long +_ conn.go:292 SMTP.Conn 127.0.0.1:34182: error: unknown<> failed: 500 5.5.1 Unknown command +_ conn.go:314 SMTP.Conn 127.0.0.1:34182: error: exiting with error: line too long --- PASS: TestLongLines (0.00s) === RUN TestReset --- PASS: TestReset (0.00s) === RUN TestRepeatedStartTLS -_ conn.go:292 SMTP.Conn 127.0.0.1:51542: error: STARTTLS failed: 503 5.5.1 You are already wearing that! ---- PASS: TestRepeatedStartTLS (0.02s) +_ conn.go:292 SMTP.Conn 127.0.0.1:34186: error: STARTTLS failed: 503 5.5.1 You are already wearing that! +--- PASS: TestRepeatedStartTLS (0.01s) === RUN TestStartTLSOnTLS -_ conn.go:292 SMTP.Conn 127.0.0.1:38114: error: STARTTLS failed: 503 5.5.1 You are already wearing that! +_ conn.go:292 SMTP.Conn 127.0.0.1:53940: error: STARTTLS failed: 503 5.5.1 You are already wearing that! --- PASS: TestStartTLSOnTLS (0.01s) PASS -_ queue.go:369 Queue.SendLoop Rwo9QHeAu_U: error: failed to write: rename /tmp/chasquid_test:329649866/queue/.m:Rwo9QHeAu_U302065657 /tmp/chasquid_test:329649866/queue/m:Rwo9QHeAu_U: no such file or directory -_ queue.go:336 Queue.SendLoop Rwo9QHeAu_U: all done -2021-07-22 11:29:03.214551 Rwo9QHeAu_U from=from@from all done -E queue.go:224 failed to remove queue file "/tmp/chasquid_test:329649866/queue/m:Rwo9QHeAu_U": remove /tmp/chasquid_test:329649866/queue/m:Rwo9QHeAu_U: no such file or directory -ok blitiri.com.ar/go/chasquid/internal/smtpsrv 3.913s +ok blitiri.com.ar/go/chasquid/internal/smtpsrv 1.777s === RUN TestParsePolicy sts_test.go:90: pol1: &{Version:STSv1 Mode:enforce MXs:[*.mail.example.com] MaxAge:34h17m36s} --- PASS: TestParsePolicy (0.00s) @@ -1363,31 +1434,31 @@ --- PASS: TestFetch (0.00s) === RUN TestPolicyTooBig sts_test.go:242: got error as expected: MTA-STS TXT record missing ---- PASS: TestPolicyTooBig (0.02s) +--- PASS: TestPolicyTooBig (0.01s) === RUN TestCacheBasics - testlib.go:26: test directory: "/tmp/testlib_952383088" + testlib.go:26: test directory: "/tmp/testlib_289799809" sts_test.go:277: cache fetched domain.com: &{STSv1 enforce [*.mail.domain.com] 1h0m0s} sts_test.go:286: cache fetched domain.com: &{STSv1 enforce [*.mail.domain.com] 1h0m0s} sts_test.go:300: cache fetched domain.com: &{STSv1 enforce [*.mail.domain.com] 1h0m0s} sts_test.go:309: cache fetched domErr: ---- PASS: TestCacheBasics (0.00s) +--- PASS: TestCacheBasics (0.17s) === RUN TestCacheBadData - testlib.go:26: test directory: "/tmp/testlib_618361369" + testlib.go:26: test directory: "/tmp/testlib_107088894" sts_test.go:349: cache fetched domain.com: &{STSv1 enforce [*.mail.domain.com] 1h0m0s} sts_test.go:363: cache fetched domain.com: &{STSv1 enforce [*.mail.domain.com] 1h0m0s} sts_test.go:372: cache fetched domain.com: &{STSv1 enforce [*.mail.domain.com] 1h0m0s} sts_test.go:349: cache fetched domain.com: &{STSv1 enforce [*.mail.domain.com] 1h0m0s} sts_test.go:363: cache fetched domain.com: &{STSv1 enforce [*.mail.domain.com] 1h0m0s} sts_test.go:372: cache fetched domain.com: &{STSv1 enforce [*.mail.domain.com] 1h0m0s} ---- PASS: TestCacheBadData (0.00s) +--- PASS: TestCacheBadData (0.33s) === RUN TestCacheRefresh - testlib.go:26: test directory: "/tmp/testlib_997825048" + testlib.go:26: test directory: "/tmp/testlib_515397193" sts_test.go:389: Fetch "refresh-test": &{STSv1 enforce [mx] 1m40s} sts_test.go:389: Fetch "refresh-test": &{STSv1 enforce [mx] 1m40s} sts_test.go:389: Fetch "refresh-test": &{STSv1 enforce [mx] 3m20s} ---- PASS: TestCacheRefresh (0.01s) +--- PASS: TestCacheRefresh (0.16s) === RUN TestCacheSlashSafe - testlib.go:26: test directory: "/tmp/testlib_748407521" + testlib.go:26: test directory: "/tmp/testlib_749485926" sts_test.go:464: recovered: domain contains slash --- PASS: TestCacheSlashSafe (0.00s) === RUN TestURLForDomain @@ -1397,9 +1468,9 @@ === RUN TestHTTPGet --- PASS: TestHTTPGet (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/sts 0.057s +ok blitiri.com.ar/go/chasquid/internal/sts 0.673s === RUN TestBasic - testlib.go:26: test directory: "/tmp/testlib_014930310" + testlib.go:26: test directory: "/tmp/testlib_702971833" --- PASS: TestBasic (0.00s) === RUN TestRemoveCheck testlib_test.go:34: recovered: invalid/dangerous directory @@ -1410,47 +1481,47 @@ testlib_test.go:61: recovered: invalid/dangerous path --- PASS: TestRewriteSafeguard (0.00s) === RUN TestRewrite - testlib.go:26: test directory: "/tmp/testlib_323526312" + testlib.go:26: test directory: "/tmp/testlib_440282195" --- PASS: TestRewrite (0.00s) === RUN TestGetFreePort --- PASS: TestGetFreePort (0.00s) === RUN TestWaitFor --- PASS: TestWaitFor (0.02s) PASS -ok blitiri.com.ar/go/chasquid/internal/testlib 0.073s +ok blitiri.com.ar/go/chasquid/internal/testlib 0.037s === RUN TestVersionName --- PASS: TestVersionName (0.00s) === RUN TestCipherSuiteName --- PASS: TestCipherSuiteName (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/tlsconst 0.016s +ok blitiri.com.ar/go/chasquid/internal/tlsconst 0.022s ? blitiri.com.ar/go/chasquid/internal/trace [no test files] === RUN TestEmptyLoad - userdb_test.go:38: file: "/tmp/userdb_test655293182" - userdb_test.go:38: file: "/tmp/userdb_test377214533" + userdb_test.go:38: file: "/tmp/userdb_test675325945" + userdb_test.go:38: file: "/tmp/userdb_test285960964" --- PASS: TestEmptyLoad (0.00s) === RUN TestWrite - userdb_test.go:38: file: "/tmp/userdb_test139477728" ---- PASS: TestWrite (1.08s) + userdb_test.go:38: file: "/tmp/userdb_test271427731" +--- PASS: TestWrite (0.64s) === RUN TestNew ---- PASS: TestNew (0.14s) +--- PASS: TestNew (0.07s) === RUN TestInvalidUsername - userdb_test.go:38: file: "/tmp/userdb_test445392916" + userdb_test.go:38: file: "/tmp/userdb_test991736695" --- PASS: TestInvalidUsername (0.00s) === RUN TestPlainScheme - userdb_test.go:38: file: "/tmp/userdb_test467544675" ---- PASS: TestPlainScheme (0.01s) + userdb_test.go:38: file: "/tmp/userdb_test229965418" +--- PASS: TestPlainScheme (0.00s) === RUN TestReload - userdb_test.go:38: file: "/tmp/userdb_test634696845" + userdb_test.go:38: file: "/tmp/userdb_test355770668" --- PASS: TestReload (0.00s) === RUN TestRemoveUser - userdb_test.go:38: file: "/tmp/userdb_test522826888" ---- PASS: TestRemoveUser (0.17s) + userdb_test.go:38: file: "/tmp/userdb_test763285659" +--- PASS: TestRemoveUser (0.09s) === RUN TestExists - userdb_test.go:38: file: "/tmp/userdb_test489769543" ---- PASS: TestExists (0.15s) + userdb_test.go:38: file: "/tmp/userdb_test123254078" +--- PASS: TestExists (0.08s) PASS -ok blitiri.com.ar/go/chasquid/internal/userdb 1.569s +ok blitiri.com.ar/go/chasquid/internal/userdb 0.893s create-stamp debian/debhelper-build-stamp dh_testroot -O--buildsystem=golang dh_prep -O--buildsystem=golang @@ -1495,10 +1566,10 @@ dh_fixperms -O--buildsystem=golang dh_missing -O--buildsystem=golang dh_strip -a -O--buildsystem=golang -dh_strip: warning: Could not find the BuildID in debian/chasquid/usr/bin/chasquid -dh_strip: warning: Could not find the BuildID in debian/chasquid/usr/bin/mda-lmtp -dh_strip: warning: Could not find the BuildID in debian/chasquid/usr/bin/smtp-check dh_strip: warning: Could not find the BuildID in debian/chasquid/usr/bin/chasquid-util +dh_strip: warning: Could not find the BuildID in debian/chasquid/usr/bin/smtp-check +dh_strip: warning: Could not find the BuildID in debian/chasquid/usr/bin/mda-lmtp +dh_strip: warning: Could not find the BuildID in debian/chasquid/usr/bin/chasquid dh_makeshlibs -a -O--buildsystem=golang dh_shlibdeps -a -O--buildsystem=golang dh_installdeb -O--buildsystem=golang @@ -1513,12 +1584,14 @@ dpkg-source --after-build . dpkg-buildpackage: info: binary-only upload (no source included) I: copying local configuration +I: user script /srv/workspace/pbuilder/19975/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/19975/tmp/hooks/B01_cleanup finished I: unmounting dev/ptmx filesystem I: unmounting dev/pts filesystem I: unmounting dev/shm filesystem I: unmounting proc filesystem I: unmounting sys filesystem I: cleaning the build env -I: removing directory /srv/workspace/pbuilder/25417 and its subdirectories -I: Current time: Wed Jul 21 23:29:40 -12 2021 -I: pbuilder-time-stamp: 1626953380 +I: removing directory /srv/workspace/pbuilder/19975 and its subdirectories +I: Current time: Thu Aug 25 07:53:37 +14 2022 +I: pbuilder-time-stamp: 1661363617