Diff of the two buildlogs: -- --- b1/build.log 2021-07-18 06:48:34.467070226 +0000 +++ b2/build.log 2021-07-18 07:06:44.409757588 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Sat Jul 17 18:45:03 -12 2021 -I: pbuilder-time-stamp: 1626590703 +I: Current time: Sun Jul 18 20:48:57 +14 2021 +I: pbuilder-time-stamp: 1626590937 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/bullseye-reproducible-base.tgz] I: copying local configuration @@ -16,8 +16,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.oYol7Qus/trustedkeys.kbx': General error -gpgv: Signature made Sun Jan 17 02:04:15 2021 -12 +gpgv: keyblock resource '/tmp/dpkg-verify-sig.kDc1JEGN/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 @@ -31,135 +31,169 @@ 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/28549/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/30427/tmp/hooks/D01_modify_environment starting +debug: Running on wbq0. +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/30427/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/30427/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='armhf' - DEBIAN_FRONTEND='noninteractive' - DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all,-fixfilepath parallel=3' - DISTRIBUTION='' - HOME='/root' - HOST_ARCH='armhf' + 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]="arm-unknown-linux-gnueabihf") + 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=armhf + DEBIAN_FRONTEND=noninteractive + DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all,-fixfilepath parallel=4' + DIRSTACK=() + DISTRIBUTION= + EUID=0 + FUNCNAME=([0]="Echo" [1]="main") + GROUPS=() + HOME=/root + HOSTNAME=i-capture-the-hostname + HOSTTYPE=arm + HOST_ARCH=armhf IFS=' ' - INVOCATION_ID='596de03fd0a14ffdb432bee518df079e' - LANG='C' - LANGUAGE='en_US:en' - LC_ALL='C' - 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='28549' - PS1='# ' - PS2='> ' + INVOCATION_ID=b9663f1c862746aab4de5c893ff1957f + LANG=C + LANGUAGE=it_CH:it + LC_ALL=C + MACHTYPE=arm-unknown-linux-gnueabihf + MAIL=/var/mail/root + OPTERR=1 + OPTIND=1 + OSTYPE=linux-gnueabihf + 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=30427 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.Gx5c1Ltakt/pbuilderrc_MUjC --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/bullseye-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/tmp.Gx5c1Ltakt/b1 --logfile b1/build.log chasquid_1.6-1.dsc' - SUDO_GID='113' - SUDO_UID='107' - SUDO_USER='jenkins' - TERM='unknown' - TZ='/usr/share/zoneinfo/Etc/GMT+12' - USER='root' - _='/usr/bin/systemd-run' - http_proxy='http://10.0.0.15:8000/' + 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.Gx5c1Ltakt/pbuilderrc_OBdy --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/bullseye-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/tmp.Gx5c1Ltakt/b2 --logfile b2/build.log --extrapackages usrmerge chasquid_1.6-1.dsc' + SUDO_GID=113 + SUDO_UID=107 + SUDO_USER=jenkins + TERM=unknown + TZ=/usr/share/zoneinfo/Etc/GMT-14 + UID=0 + USER=root + _='I: set' + http_proxy=http://10.0.0.15:8000/ I: uname -a - Linux virt64c 5.10.0-8-arm64 #1 SMP Debian 5.10.46-1 (2021-06-24) aarch64 GNU/Linux + Linux i-capture-the-hostname 5.10.0-7-armmp #1 SMP Debian 5.10.40-1 (2021-05-28) armv7l GNU/Linux I: ls -l /bin total 3580 - -rwxr-xr-x 1 root root 816764 Jun 21 14:26 bash - -rwxr-xr-x 3 root root 26052 Jul 20 2020 bunzip2 - -rwxr-xr-x 3 root root 26052 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 26052 Jul 20 2020 bzip2 - -rwxr-xr-x 1 root root 9636 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 26668 Sep 22 2020 cat - -rwxr-xr-x 1 root root 43104 Sep 22 2020 chgrp - -rwxr-xr-x 1 root root 38984 Sep 22 2020 chmod - -rwxr-xr-x 1 root root 43112 Sep 22 2020 chown - -rwxr-xr-x 1 root root 92616 Sep 22 2020 cp - -rwxr-xr-x 1 root root 75524 Dec 10 2020 dash - -rwxr-xr-x 1 root root 75880 Sep 22 2020 date - -rwxr-xr-x 1 root root 55436 Sep 22 2020 dd - -rwxr-xr-x 1 root root 59912 Sep 22 2020 df - -rwxr-xr-x 1 root root 96764 Sep 22 2020 dir - -rwxr-xr-x 1 root root 55012 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 22508 Sep 22 2020 echo - -rwxr-xr-x 1 root root 28 Nov 9 2020 egrep - -rwxr-xr-x 1 root root 22496 Sep 22 2020 false - -rwxr-xr-x 1 root root 28 Nov 9 2020 fgrep - -rwxr-xr-x 1 root root 47492 Feb 7 02:38 findmnt - -rwsr-xr-x 1 root root 26076 Feb 26 04:12 fusermount - -rwxr-xr-x 1 root root 124508 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 64212 Mar 2 11:30 gzip - -rwxr-xr-x 1 root root 13784 Nov 6 2019 hostname - -rwxr-xr-x 1 root root 43180 Sep 22 2020 ln - -rwxr-xr-x 1 root root 35068 Feb 7 2020 login - -rwxr-xr-x 1 root root 96764 Sep 22 2020 ls - -rwxr-xr-x 1 root root 99940 Feb 7 02:38 lsblk - -rwxr-xr-x 1 root root 51408 Sep 22 2020 mkdir - -rwxr-xr-x 1 root root 43184 Sep 22 2020 mknod - -rwxr-xr-x 1 root root 30780 Sep 22 2020 mktemp - -rwxr-xr-x 1 root root 34408 Feb 7 02:38 more - -rwsr-xr-x 1 root root 34400 Feb 7 02:38 mount - -rwxr-xr-x 1 root root 9824 Feb 7 02:38 mountpoint - -rwxr-xr-x 1 root root 88524 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 26652 Sep 22 2020 pwd - lrwxrwxrwx 1 root root 4 Jun 21 14:26 rbash -> bash - -rwxr-xr-x 1 root root 30740 Sep 22 2020 readlink - -rwxr-xr-x 1 root root 43104 Sep 22 2020 rm - -rwxr-xr-x 1 root root 30732 Sep 22 2020 rmdir - -rwxr-xr-x 1 root root 14144 Sep 27 2020 run-parts - -rwxr-xr-x 1 root root 76012 Dec 22 2018 sed - lrwxrwxrwx 1 root root 4 Jul 13 21:26 sh -> dash - -rwxr-xr-x 1 root root 22532 Sep 22 2020 sleep - -rwxr-xr-x 1 root root 55360 Sep 22 2020 stty - -rwsr-xr-x 1 root root 46704 Feb 7 02:38 su - -rwxr-xr-x 1 root root 22532 Sep 22 2020 sync - -rwxr-xr-x 1 root root 340872 Feb 16 21:55 tar - -rwxr-xr-x 1 root root 9808 Sep 27 2020 tempfile - -rwxr-xr-x 1 root root 67696 Sep 22 2020 touch - -rwxr-xr-x 1 root root 22496 Sep 22 2020 true - -rwxr-xr-x 1 root root 9636 Feb 26 04:12 ulockmgr_server - -rwsr-xr-x 1 root root 22108 Feb 7 02:38 umount - -rwxr-xr-x 1 root root 22520 Sep 22 2020 uname - -rwxr-xr-x 2 root root 2346 Mar 2 11:30 uncompress - -rwxr-xr-x 1 root root 96764 Sep 22 2020 vdir - -rwxr-xr-x 1 root root 38512 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/28549/tmp/hooks/D02_print_environment finished + -rwxr-xr-x 1 root root 816764 Jun 22 16:26 bash + -rwxr-xr-x 3 root root 26052 Jul 21 2020 bunzip2 + -rwxr-xr-x 3 root root 26052 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 26052 Jul 21 2020 bzip2 + -rwxr-xr-x 1 root root 9636 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 26668 Sep 23 2020 cat + -rwxr-xr-x 1 root root 43104 Sep 23 2020 chgrp + -rwxr-xr-x 1 root root 38984 Sep 23 2020 chmod + -rwxr-xr-x 1 root root 43112 Sep 23 2020 chown + -rwxr-xr-x 1 root root 92616 Sep 23 2020 cp + -rwxr-xr-x 1 root root 75524 Dec 11 2020 dash + -rwxr-xr-x 1 root root 75880 Sep 23 2020 date + -rwxr-xr-x 1 root root 55436 Sep 23 2020 dd + -rwxr-xr-x 1 root root 59912 Sep 23 2020 df + -rwxr-xr-x 1 root root 96764 Sep 23 2020 dir + -rwxr-xr-x 1 root root 55012 Feb 8 04:38 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 22508 Sep 23 2020 echo + -rwxr-xr-x 1 root root 28 Nov 10 2020 egrep + -rwxr-xr-x 1 root root 22496 Sep 23 2020 false + -rwxr-xr-x 1 root root 28 Nov 10 2020 fgrep + -rwxr-xr-x 1 root root 47492 Feb 8 04:38 findmnt + -rwsr-xr-x 1 root root 26076 Feb 27 06:12 fusermount + -rwxr-xr-x 1 root root 124508 Nov 10 2020 grep + -rwxr-xr-x 2 root root 2346 Mar 3 13:30 gunzip + -rwxr-xr-x 1 root root 6376 Mar 3 13:30 gzexe + -rwxr-xr-x 1 root root 64212 Mar 3 13:30 gzip + -rwxr-xr-x 1 root root 13784 Nov 8 2019 hostname + -rwxr-xr-x 1 root root 43180 Sep 23 2020 ln + -rwxr-xr-x 1 root root 35068 Feb 8 2020 login + -rwxr-xr-x 1 root root 96764 Sep 23 2020 ls + -rwxr-xr-x 1 root root 99940 Feb 8 04:38 lsblk + -rwxr-xr-x 1 root root 51408 Sep 23 2020 mkdir + -rwxr-xr-x 1 root root 43184 Sep 23 2020 mknod + -rwxr-xr-x 1 root root 30780 Sep 23 2020 mktemp + -rwxr-xr-x 1 root root 34408 Feb 8 04:38 more + -rwsr-xr-x 1 root root 34400 Feb 8 04:38 mount + -rwxr-xr-x 1 root root 9824 Feb 8 04:38 mountpoint + -rwxr-xr-x 1 root root 88524 Sep 23 2020 mv + lrwxrwxrwx 1 root root 8 Nov 8 2019 nisdomainname -> hostname + lrwxrwxrwx 1 root root 14 Apr 19 05:38 pidof -> /sbin/killall5 + -rwxr-xr-x 1 root root 26652 Sep 23 2020 pwd + lrwxrwxrwx 1 root root 4 Jun 22 16:26 rbash -> bash + -rwxr-xr-x 1 root root 30740 Sep 23 2020 readlink + -rwxr-xr-x 1 root root 43104 Sep 23 2020 rm + -rwxr-xr-x 1 root root 30732 Sep 23 2020 rmdir + -rwxr-xr-x 1 root root 14144 Sep 28 2020 run-parts + -rwxr-xr-x 1 root root 76012 Dec 23 2018 sed + lrwxrwxrwx 1 root root 4 Jul 18 20:50 sh -> bash + lrwxrwxrwx 1 root root 4 Jul 17 23:27 sh.distrib -> dash + -rwxr-xr-x 1 root root 22532 Sep 23 2020 sleep + -rwxr-xr-x 1 root root 55360 Sep 23 2020 stty + -rwsr-xr-x 1 root root 46704 Feb 8 04:38 su + -rwxr-xr-x 1 root root 22532 Sep 23 2020 sync + -rwxr-xr-x 1 root root 340872 Feb 17 23:55 tar + -rwxr-xr-x 1 root root 9808 Sep 28 2020 tempfile + -rwxr-xr-x 1 root root 67696 Sep 23 2020 touch + -rwxr-xr-x 1 root root 22496 Sep 23 2020 true + -rwxr-xr-x 1 root root 9636 Feb 27 06:12 ulockmgr_server + -rwsr-xr-x 1 root root 22108 Feb 8 04:38 umount + -rwxr-xr-x 1 root root 22520 Sep 23 2020 uname + -rwxr-xr-x 2 root root 2346 Mar 3 13:30 uncompress + -rwxr-xr-x 1 root root 96764 Sep 23 2020 vdir + -rwxr-xr-x 1 root root 38512 Feb 8 04:38 wdctl + lrwxrwxrwx 1 root root 8 Nov 8 2019 ypdomainname -> hostname + -rwxr-xr-x 1 root root 1984 Mar 3 13:30 zcat + -rwxr-xr-x 1 root root 1678 Mar 3 13:30 zcmp + -rwxr-xr-x 1 root root 5880 Mar 3 13:30 zdiff + -rwxr-xr-x 1 root root 29 Mar 3 13:30 zegrep + -rwxr-xr-x 1 root root 29 Mar 3 13:30 zfgrep + -rwxr-xr-x 1 root root 2081 Mar 3 13:30 zforce + -rwxr-xr-x 1 root root 7585 Mar 3 13:30 zgrep + -rwxr-xr-x 1 root root 2206 Mar 3 13:30 zless + -rwxr-xr-x 1 root root 1842 Mar 3 13:30 zmore + -rwxr-xr-x 1 root root 4553 Mar 3 13:30 znew +I: user script /srv/workspace/pbuilder/30427/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -268,7 +302,7 @@ Get: 47 http://deb.debian.org/debian bullseye/main armhf golang-blitiri-go-log-dev all 1.1.0-1 [6724 B] Get: 48 http://deb.debian.org/debian bullseye/main armhf golang-blitiri-go-spf-dev all 1.1.0-1 [84.8 kB] Get: 49 http://deb.debian.org/debian bullseye/main armhf golang-blitiri-go-systemd-dev all 1.1.0-1 [6952 B] -Fetched 81.8 MB in 6s (13.0 MB/s) +Fetched 81.8 MB in 14s (5748 kB/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 ... 19398 files and directories currently installed.) @@ -479,8 +513,45 @@ 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 armhf libnumber-compare-perl all 0.03-1.1 [6956 B] +Get:2 http://deb.debian.org/debian bullseye/main armhf libtext-glob-perl all 0.11-1 [8888 B] +Get:3 http://deb.debian.org/debian bullseye/main armhf libfile-find-rule-perl all 0.34-1 [30.6 kB] +Get:4 http://deb.debian.org/debian bullseye/main armhf usrmerge all 25 [13.0 kB] +debconf: delaying package configuration, since apt-utils is not installed +Fetched 59.5 kB in 1s (106 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 ... 35355 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 && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games" HOME="/nonexistent/first-build" dpkg-genchanges -S > ../chasquid_1.6-1_source.changes +hostname: Name or service not known +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 && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/i/capture/the/path" HOME="/nonexistent/second-build" dpkg-genchanges -S > ../chasquid_1.6-1_source.changes dpkg-buildpackage: info: source package chasquid dpkg-buildpackage: info: source version 1.6-1 dpkg-buildpackage: info: source distribution unstable @@ -500,23 +571,23 @@ 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-arm-linux-gnueabihf && go install -trimpath -v -p 3 -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 -runtime/internal/sys -internal/cpu + cd obj-arm-linux-gnueabihf && go install -trimpath -v -p 4 -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 +internal/cpu math/bits -runtime/internal/math +runtime/internal/sys unicode/utf8 -internal/bytealg -runtime/internal/atomic -math +runtime/internal/math internal/race +runtime/internal/atomic sync/atomic -runtime +internal/bytealg +math unicode internal/testlog internal/nettrace runtime/cgo +runtime google.golang.org/protobuf/internal/flags unicode/utf16 google.golang.org/protobuf/internal/set @@ -530,36 +601,64 @@ golang.org/x/sys/internal/unsafeheader internal/reflectlite sync +google.golang.org/protobuf/internal/pragma internal/singleflight math/rand -google.golang.org/protobuf/internal/pragma errors sort +internal/oserror io strconv -internal/oserror syscall +vendor/golang.org/x/net/dns/dnsmessage strings reflect -vendor/golang.org/x/net/dns/dnsmessage -internal/syscall/unix -time -internal/syscall/execenv hash hash/fnv bytes regexp/syntax +bufio +internal/syscall/unix +time +internal/syscall/execenv +hash/crc32 +path +regexp +html +crypto +crypto/internal/randutil +crypto/hmac internal/poll -os -internal/fmtsort context +crypto/rc4 +vendor/golang.org/x/crypto/hkdf +vendor/golang.org/x/text/transform +text/tabwriter +internal/fmtsort encoding/binary -regexp +golang.org/x/text/transform +os +golang.org/x/text/internal/tag +golang.org/x/crypto/pbkdf2 +golang.org/x/text/runes +golang.org/x/text/width +encoding/base64 +crypto/cipher +crypto/sha512 +crypto/ed25519/internal/edwards25519 +crypto/md5 +crypto/aes fmt -net path/filepath +net google.golang.org/protobuf/internal/detrand -bufio +io/ioutil +crypto/des +blitiri.com.ar/go/chasquid/internal/safeio +crypto/sha1 +crypto/sha256 +encoding/pem +vendor/golang.org/x/crypto/chacha20 flag log google.golang.org/protobuf/internal/errors @@ -567,7 +666,8 @@ google.golang.org/protobuf/encoding/protowire google.golang.org/protobuf/reflect/protoreflect compress/flate -hash/crc32 +encoding/json +compress/gzip google.golang.org/protobuf/internal/encoding/messageset google.golang.org/protobuf/internal/strs google.golang.org/protobuf/internal/genid @@ -576,140 +676,111 @@ google.golang.org/protobuf/reflect/protoregistry google.golang.org/protobuf/runtime/protoiface google.golang.org/protobuf/internal/descfmt -google.golang.org/protobuf/proto google.golang.org/protobuf/internal/descopts google.golang.org/protobuf/internal/encoding/defval -compress/gzip -encoding/base64 -google.golang.org/protobuf/encoding/prototext -google.golang.org/protobuf/internal/filedesc -encoding/json -google.golang.org/protobuf/internal/encoding/tag -log/syslog -io/ioutil +google.golang.org/protobuf/proto google.golang.org/protobuf/internal/version -path -blitiri.com.ar/go/log -google.golang.org/protobuf/internal/impl -blitiri.com.ar/go/chasquid/internal/safeio -golang.org/x/net/internal/timeseries net/url -html -blitiri.com.ar/go/chasquid/internal/protoio +golang.org/x/net/internal/timeseries text/template/parse -crypto/cipher -crypto/aes math/big +google.golang.org/protobuf/encoding/prototext +google.golang.org/protobuf/internal/filedesc +blitiri.com.ar/go/chasquid/internal/protoio text/template -html/template -crypto -crypto/des -crypto/internal/randutil -crypto/sha512 -crypto/ed25519/internal/edwards25519 -google.golang.org/protobuf/internal/filetype -google.golang.org/protobuf/runtime/protoimpl crypto/rand crypto/elliptic +google.golang.org/protobuf/internal/encoding/tag +html/template +google.golang.org/protobuf/internal/impl encoding/asn1 -blitiri.com.ar/go/chasquid/internal/config +log/syslog +blitiri.com.ar/go/log crypto/ed25519 -crypto/hmac -crypto/md5 -crypto/rc4 -crypto/rsa vendor/golang.org/x/crypto/cryptobyte -crypto/sha1 -crypto/sha256 -crypto/ecdsa +crypto/rsa crypto/dsa encoding/hex -encoding/pem -crypto/x509/pkix -vendor/golang.org/x/crypto/chacha20 vendor/golang.org/x/crypto/poly1305 -vendor/golang.org/x/crypto/curve25519 +crypto/x509/pkix +crypto/ecdsa vendor/golang.org/x/crypto/chacha20poly1305 -vendor/golang.org/x/crypto/hkdf -vendor/golang.org/x/text/transform +vendor/golang.org/x/crypto/curve25519 vendor/golang.org/x/text/unicode/bidi +crypto/x509 vendor/golang.org/x/text/unicode/norm vendor/golang.org/x/text/secure/bidirule net/textproto vendor/golang.org/x/net/http2/hpack -crypto/x509 mime +crypto/tls vendor/golang.org/x/net/idna mime/quotedprintable +mime/multipart vendor/golang.org/x/net/http/httpguts -crypto/tls vendor/golang.org/x/net/http/httpproxy -mime/multipart net/http/internal -text/tabwriter blitiri.com.ar/go/chasquid/internal/envelope -golang.org/x/text/transform golang.org/x/text/unicode/bidi golang.org/x/text/unicode/norm +google.golang.org/protobuf/internal/filetype golang.org/x/text/secure/bidirule os/exec +google.golang.org/protobuf/runtime/protoimpl +blitiri.com.ar/go/chasquid/internal/config blitiri.com.ar/go/chasquid/internal/dovecot -golang.org/x/text/internal/tag golang.org/x/net/idna golang.org/x/text/internal/language -golang.org/x/text/runes -net/http/httptrace -net/smtp -net/http -golang.org/x/text/internal/language/compact -blitiri.com.ar/go/chasquid/internal/smtp -golang.org/x/text/language -golang.org/x/text/width blitiri.com.ar/go/chasquid/internal/haproxy net/mail -golang.org/x/text/internal -golang.org/x/text/cases blitiri.com.ar/go/chasquid/internal/tlsconst -golang.org/x/crypto/pbkdf2 +net/http/httptrace +net/smtp golang.org/x/crypto/scrypt blitiri.com.ar/go/spf +net/http +golang.org/x/text/internal/language/compact +blitiri.com.ar/go/chasquid/internal/smtp blitiri.com.ar/go/systemd +golang.org/x/text/language internal/profile -golang.org/x/text/secure/precis runtime/pprof -blitiri.com.ar/go/chasquid/internal/normalize -blitiri.com.ar/go/chasquid/internal/auth -blitiri.com.ar/go/chasquid/internal/userdb +golang.org/x/text/internal +golang.org/x/text/cases runtime/trace os/signal github.com/docopt/docopt-go golang.org/x/sys/unix +golang.org/x/text/secure/precis blitiri.com.ar/go/chasquid/cmd/mda-lmtp +blitiri.com.ar/go/chasquid/internal/normalize +blitiri.com.ar/go/chasquid/internal/auth +blitiri.com.ar/go/chasquid/internal/userdb +blitiri.com.ar/go/chasquid/internal/protoio/testpb +runtime/debug +testing golang.org/x/term -golang.org/x/net/trace -expvar +blitiri.com.ar/go/chasquid/internal/testlib +golang.org/x/crypto/ssh/terminal golang.org/x/net/context/ctxhttp -blitiri.com.ar/go/chasquid/internal/trace -blitiri.com.ar/go/chasquid/internal/expvarom +expvar +golang.org/x/net/trace net/http/pprof -blitiri.com.ar/go/chasquid/internal/domaininfo -blitiri.com.ar/go/chasquid/internal/sts +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/aliases -golang.org/x/crypto/ssh/terminal -blitiri.com.ar/go/chasquid/internal/protoio/testpb -blitiri.com.ar/go/chasquid/internal/courier +blitiri.com.ar/go/chasquid/internal/domaininfo +blitiri.com.ar/go/chasquid/internal/sts blitiri.com.ar/go/chasquid/cmd/chasquid-util 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 -runtime/debug blitiri.com.ar/go/chasquid -testing -blitiri.com.ar/go/chasquid/internal/testlib make[1]: Leaving directory '/build/chasquid-1.6' dh_auto_test -O--buildsystem=golang - cd obj-arm-linux-gnueabihf && go test -vet=off -v -p 3 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-arm-linux-gnueabihf && go test -vet=off -v -p 4 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] @@ -719,17 +790,17 @@ === RUN TestAddrRewrite --- PASS: TestAddrRewrite (0.00s) === RUN TestExistsRewrite ---- PASS: TestExistsRewrite (0.00s) +--- PASS: TestExistsRewrite (0.01s) === RUN TestTooMuchRecursion --- PASS: TestTooMuchRecursion (0.00s) === RUN TestAddFile ---- PASS: TestAddFile (0.01s) +--- PASS: TestAddFile (0.05s) === RUN TestRichFile ---- PASS: TestRichFile (0.00s) +--- PASS: TestRichFile (0.01s) === RUN TestManyFiles ---- PASS: TestManyFiles (0.00s) +--- PASS: TestManyFiles (0.01s) PASS -ok blitiri.com.ar/go/chasquid/internal/aliases 0.027s +ok blitiri.com.ar/go/chasquid/internal/aliases 0.258s === 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 @@ -743,52 +814,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.67s) +--- PASS: TestAuthenticate (5.13s) === RUN TestInterfaces --- PASS: TestInterfaces (0.00s) === RUN TestMultipleBackends ---- PASS: TestMultipleBackends (0.18s) +--- PASS: TestMultipleBackends (0.19s) === RUN TestErrors --- PASS: TestErrors (0.00s) === RUN TestReload --- PASS: TestReload (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/auth 0.873s +ok blitiri.com.ar/go/chasquid/internal/auth 5.547s === RUN TestEmptyConfig - testlib.go:26: test directory: "/tmp/testlib_467965730" ---- PASS: TestEmptyConfig (0.00s) + testlib.go:26: test directory: "/tmp/testlib_258475733" +--- PASS: TestEmptyConfig (0.04s) === RUN TestFullConfig - testlib.go:26: test directory: "/tmp/testlib_480896537" ---- PASS: TestFullConfig (0.00s) + testlib.go:26: test directory: "/tmp/testlib_243435056" +--- PASS: TestFullConfig (0.02s) === RUN TestErrorLoading --- PASS: TestErrorLoading (0.00s) === RUN TestBrokenConfig - testlib.go:26: test directory: "/tmp/testlib_216797348" + testlib.go:26: test directory: "/tmp/testlib_398953935" --- PASS: TestBrokenConfig (0.00s) === RUN TestBrokenOverride - testlib.go:26: test directory: "/tmp/testlib_006907315" ---- PASS: TestBrokenOverride (0.00s) + testlib.go:26: test directory: "/tmp/testlib_357656290" +--- PASS: TestBrokenOverride (0.02s) PASS -ok blitiri.com.ar/go/chasquid/internal/config 0.018s +ok blitiri.com.ar/go/chasquid/internal/config 0.244s === RUN TestMDA - testlib.go:26: test directory: "/tmp/testlib_039089276" ---- PASS: TestMDA (0.01s) + testlib.go:26: test directory: "/tmp/testlib_582733058" +--- PASS: TestMDA (0.05s) === RUN TestMDATimeout _ mda.go:67 Courier.MDA to@local: error: operation timed out ---- PASS: TestMDATimeout (0.10s) +--- PASS: TestMDATimeout (0.11s) === 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.03s) === 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_379538859" -_ smtp.go:130 Courier.SMTP to@to: error: Could not dial: dial tcp: address ::::38715: too many colons in address -_ smtp.go:100 Courier.SMTP to@to: error: \":::\" returned transient error: Could not dial: dial tcp: address ::::38715: too many colons in address + testlib.go:26: test directory: "/tmp/testlib_012144249" +_ smtp.go:130 Courier.SMTP to@to: error: Could not dial: dial tcp: address ::::43613: too many colons in address +_ smtp.go:100 Courier.SMTP to@to: error: \":::\" returned transient error: Could not dial: dial tcp: address ::::43613: 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:" @@ -796,23 +867,23 @@ smtp_test.go:73: fakeServer read: "DATA" smtp_test.go:73: fakeServer read: "QUIT" smtp_test.go:69: fakeServer exiting: EOF ---- PASS: TestSMTP (0.01s) +--- PASS: TestSMTP (0.05s) === RUN TestSMTPErrors - testlib.go:26: test directory: "/tmp/testlib_503022869" + testlib.go:26: test directory: "/tmp/testlib_769008403" smtp_test.go:62: fakeServer got connection -_ smtp.go:141 Courier.SMTP to@to: error: Error saying hello: write tcp 127.0.0.1:55978->127.0.0.1:43597: 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:55978->127.0.0.1:43597: 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:55978->127.0.0.1:43597: 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:55978->127.0.0.1:43597: i/o timeout) +_ smtp.go:141 Courier.SMTP to@to: error: Error saying hello: write tcp 127.0.0.1:55132->127.0.0.1:33553: 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:55132->127.0.0.1:33553: 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:55132->127.0.0.1:33553: 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:55132->127.0.0.1:33553: i/o timeout) smtp_test.go:69: fakeServer exiting: EOF - testlib.go:26: test directory: "/tmp/testlib_079040368" + testlib.go:26: test directory: "/tmp/testlib_536248150" 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_800664098" + testlib.go:26: test directory: "/tmp/testlib_744191736" smtp_test.go:62: fakeServer got connection smtp_test.go:73: fakeServer read: "EHLO hello" smtp_test.go:73: fakeServer read: "MAIL FROM:" @@ -820,7 +891,7 @@ _ 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_270020004" + testlib.go:26: test directory: "/tmp/testlib_973660394" smtp_test.go:62: fakeServer got connection smtp_test.go:73: fakeServer read: "EHLO hello" smtp_test.go:73: fakeServer read: "MAIL FROM:" @@ -829,7 +900,7 @@ _ 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_437447286" + testlib.go:26: test directory: "/tmp/testlib_019970988" smtp_test.go:62: fakeServer got connection smtp_test.go:73: fakeServer read: "EHLO hello" smtp_test.go:73: fakeServer read: "MAIL FROM:" @@ -838,12 +909,12 @@ _ 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.02s) +--- PASS: TestSMTPErrors (1.12s) === RUN TestNoMXServer - testlib.go:26: test directory: "/tmp/testlib_872403736" + testlib.go:26: test directory: "/tmp/testlib_361618878" _ 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) +--- PASS: TestNoMXServer (0.01s) === RUN TestTooManyMX --- PASS: TestTooManyMX (0.00s) === RUN TestFallbackToA @@ -853,54 +924,54 @@ === RUN TestMXLookupError --- PASS: TestMXLookupError (0.00s) === RUN TestLookupInvalidDomain ---- PASS: TestLookupInvalidDomain (0.00s) +--- PASS: TestLookupInvalidDomain (0.02s) PASS -ok blitiri.com.ar/go/chasquid/internal/courier 1.170s +ok blitiri.com.ar/go/chasquid/internal/courier 1.548s === RUN TestBasic - testlib.go:26: test directory: "/tmp/testlib_930723008" -_ domaininfo.go:107 DomainInfo /tmp/testlib_930723008: d1 incoming level raised: TLS_SECURE > PLAIN -_ domaininfo.go:99 DomainInfo /tmp/testlib_930723008: error: d1 incoming denied: TLS_INSECURE < TLS_SECURE -_ domaininfo.go:99 DomainInfo /tmp/testlib_930723008: error: d1 incoming denied: TLS_INSECURE < TLS_SECURE ---- PASS: TestBasic (0.00s) + testlib.go:26: test directory: "/tmp/testlib_070256659" +_ domaininfo.go:107 DomainInfo /tmp/testlib_070256659: d1 incoming level raised: TLS_SECURE > PLAIN +_ domaininfo.go:99 DomainInfo /tmp/testlib_070256659: error: d1 incoming denied: TLS_INSECURE < TLS_SECURE +_ domaininfo.go:99 DomainInfo /tmp/testlib_070256659: error: d1 incoming denied: TLS_INSECURE < TLS_SECURE +--- PASS: TestBasic (0.02s) === RUN TestNewDomain - testlib.go:26: test directory: "/tmp/testlib_809309865" -_ domaininfo.go:107 DomainInfo /tmp/testlib_809309865: insecure incoming level raised: TLS_INSECURE > PLAIN -_ domaininfo.go:139 DomainInfo /tmp/testlib_809309865: insecure outgoing level raised: TLS_INSECURE > PLAIN -_ domaininfo.go:107 DomainInfo /tmp/testlib_809309865: secure incoming level raised: TLS_SECURE > PLAIN -_ domaininfo.go:139 DomainInfo /tmp/testlib_809309865: secure outgoing level raised: TLS_SECURE > PLAIN ---- PASS: TestNewDomain (0.01s) + testlib.go:26: test directory: "/tmp/testlib_279485432" +_ domaininfo.go:107 DomainInfo /tmp/testlib_279485432: insecure incoming level raised: TLS_INSECURE > PLAIN +_ domaininfo.go:139 DomainInfo /tmp/testlib_279485432: insecure outgoing level raised: TLS_INSECURE > PLAIN +_ domaininfo.go:107 DomainInfo /tmp/testlib_279485432: secure incoming level raised: TLS_SECURE > PLAIN +_ domaininfo.go:139 DomainInfo /tmp/testlib_279485432: secure outgoing level raised: TLS_SECURE > PLAIN +--- PASS: TestNewDomain (0.02s) === RUN TestProgressions - testlib.go:26: test directory: "/tmp/testlib_986747047" -_ domaininfo.go:107 DomainInfo /tmp/testlib_986747047: pisis incoming level raised: TLS_INSECURE > PLAIN -_ domaininfo.go:139 DomainInfo /tmp/testlib_986747047: pisis outgoing level raised: TLS_INSECURE > PLAIN -_ domaininfo.go:107 DomainInfo /tmp/testlib_986747047: pisis incoming level raised: TLS_SECURE > TLS_INSECURE -_ domaininfo.go:139 DomainInfo /tmp/testlib_986747047: pisis outgoing level raised: TLS_SECURE > TLS_INSECURE -_ domaininfo.go:99 DomainInfo /tmp/testlib_986747047: error: pisis incoming denied: TLS_INSECURE < TLS_SECURE -_ domaininfo.go:131 DomainInfo /tmp/testlib_986747047: error: pisis outgoing denied: TLS_INSECURE < TLS_SECURE -_ domaininfo.go:107 DomainInfo /tmp/testlib_986747047: ssip incoming level raised: TLS_SECURE > PLAIN -_ domaininfo.go:139 DomainInfo /tmp/testlib_986747047: ssip outgoing level raised: TLS_SECURE > PLAIN -_ domaininfo.go:99 DomainInfo /tmp/testlib_986747047: error: ssip incoming denied: TLS_INSECURE < TLS_SECURE -_ domaininfo.go:131 DomainInfo /tmp/testlib_986747047: error: ssip outgoing denied: TLS_INSECURE < TLS_SECURE -_ domaininfo.go:99 DomainInfo /tmp/testlib_986747047: error: ssip incoming denied: PLAIN < TLS_SECURE -_ domaininfo.go:131 DomainInfo /tmp/testlib_986747047: error: ssip outgoing denied: PLAIN < TLS_SECURE ---- PASS: TestProgressions (0.01s) + testlib.go:26: test directory: "/tmp/testlib_490342078" +_ domaininfo.go:107 DomainInfo /tmp/testlib_490342078: pisis incoming level raised: TLS_INSECURE > PLAIN +_ domaininfo.go:139 DomainInfo /tmp/testlib_490342078: pisis outgoing level raised: TLS_INSECURE > PLAIN +_ domaininfo.go:107 DomainInfo /tmp/testlib_490342078: pisis incoming level raised: TLS_SECURE > TLS_INSECURE +_ domaininfo.go:139 DomainInfo /tmp/testlib_490342078: pisis outgoing level raised: TLS_SECURE > TLS_INSECURE +_ domaininfo.go:99 DomainInfo /tmp/testlib_490342078: error: pisis incoming denied: TLS_INSECURE < TLS_SECURE +_ domaininfo.go:131 DomainInfo /tmp/testlib_490342078: error: pisis outgoing denied: TLS_INSECURE < TLS_SECURE +_ domaininfo.go:107 DomainInfo /tmp/testlib_490342078: ssip incoming level raised: TLS_SECURE > PLAIN +_ domaininfo.go:139 DomainInfo /tmp/testlib_490342078: ssip outgoing level raised: TLS_SECURE > PLAIN +_ domaininfo.go:99 DomainInfo /tmp/testlib_490342078: error: ssip incoming denied: TLS_INSECURE < TLS_SECURE +_ domaininfo.go:131 DomainInfo /tmp/testlib_490342078: error: ssip outgoing denied: TLS_INSECURE < TLS_SECURE +_ domaininfo.go:99 DomainInfo /tmp/testlib_490342078: error: ssip incoming denied: PLAIN < TLS_SECURE +_ domaininfo.go:131 DomainInfo /tmp/testlib_490342078: error: ssip outgoing denied: PLAIN < TLS_SECURE +--- PASS: TestProgressions (0.03s) === RUN TestErrors - testlib.go:26: test directory: "/tmp/testlib_657636143" -_ domaininfo.go:107 DomainInfo /tmp/testlib_657636143: d1 incoming level raised: TLS_SECURE > PLAIN ---- PASS: TestErrors (0.00s) + testlib.go:26: test directory: "/tmp/testlib_105875494" +_ domaininfo.go:107 DomainInfo /tmp/testlib_105875494: d1 incoming level raised: TLS_SECURE > PLAIN +--- PASS: TestErrors (0.01s) PASS -ok blitiri.com.ar/go/chasquid/internal/domaininfo 0.039s +ok blitiri.com.ar/go/chasquid/internal/domaininfo 0.178s === RUN TestUsernameNotSafe --- PASS: TestUsernameNotSafe (0.00s) === RUN TestAutodetect - testlib.go:26: test directory: "/tmp/testlib_492992954" ---- PASS: TestAutodetect (0.00s) + testlib.go:26: test directory: "/tmp/testlib_040633325" +--- PASS: TestAutodetect (0.03s) === RUN TestReload --- PASS: TestReload (0.00s) === RUN TestNotASocket --- PASS: TestNotASocket (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/dovecot 0.018s +ok blitiri.com.ar/go/chasquid/internal/dovecot 0.234s === RUN TestSplit --- PASS: TestSplit (0.00s) === RUN TestDomainIn @@ -908,13 +979,13 @@ === RUN TestAddHeader --- PASS: TestAddHeader (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/envelope 0.017s +ok blitiri.com.ar/go/chasquid/internal/envelope 0.072s === RUN TestHandler ---- PASS: TestHandler (0.00s) +--- PASS: TestHandler (0.01s) === RUN TestMapLabelAccident --- PASS: TestMapLabelAccident (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/expvarom 0.013s +ok blitiri.com.ar/go/chasquid/internal/expvarom 0.189s === RUN TestNoNewline --- PASS: TestNoNewline (0.00s) === RUN TestBasic @@ -937,61 +1008,61 @@ haproxy_test.go:69: testing 16: PROXY TCP6 5::5 6::6 c d haproxy_test.go:69: testing 17: PROXY TCP6 5::5 6::6 7777 d haproxy_test.go:69: testing 18: PROXY TCP6 5::5 6::6 7777 8888 ---- PASS: TestBasic (0.00s) +--- PASS: TestBasic (0.01s) PASS -ok blitiri.com.ar/go/chasquid/internal/haproxy 0.016s +ok blitiri.com.ar/go/chasquid/internal/haproxy 0.085s === RUN TestLogger ---- PASS: TestLogger (0.00s) +--- PASS: TestLogger (0.01s) === RUN TestDefault ---- PASS: TestDefault (0.00s) +--- PASS: TestDefault (0.01s) === RUN TestFailedLogger --- PASS: TestFailedLogger (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/maillog 0.014s +ok blitiri.com.ar/go/chasquid/internal/maillog 0.120s === RUN TestUser --- PASS: TestUser (0.00s) === RUN TestDomain ---- PASS: TestDomain (0.00s) +--- PASS: TestDomain (0.02s) === RUN TestAddr --- PASS: TestAddr (0.00s) === RUN TestDomainToUnicode --- PASS: TestDomainToUnicode (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/normalize 0.025s +ok blitiri.com.ar/go/chasquid/internal/normalize 0.093s === RUN TestBin - testlib.go:26: test directory: "/tmp/testlib_853797682" ---- PASS: TestBin (0.00s) + testlib.go:26: test directory: "/tmp/testlib_205122070" +--- PASS: TestBin (0.01s) === RUN TestText - testlib.go:26: test directory: "/tmp/testlib_214636852" ---- PASS: TestText (0.00s) + testlib.go:26: test directory: "/tmp/testlib_886356408" +--- PASS: TestText (0.02s) === RUN TestStore - testlib.go:26: test directory: "/tmp/testlib_855776902" ---- PASS: TestStore (0.01s) + testlib.go:26: test directory: "/tmp/testlib_374052778" +--- PASS: TestStore (0.03s) === RUN TestFileErrors - testlib.go:26: test directory: "/tmp/testlib_948185000" + testlib.go:26: test directory: "/tmp/testlib_632474732" --- PASS: TestFileErrors (0.00s) === RUN TestMarshalErrors - testlib.go:26: test directory: "/tmp/testlib_203379121" ---- PASS: TestMarshalErrors (0.00s) + testlib.go:26: test directory: "/tmp/testlib_342342085" +--- PASS: TestMarshalErrors (0.01s) PASS -ok blitiri.com.ar/go/chasquid/internal/protoio 0.068s +ok blitiri.com.ar/go/chasquid/internal/protoio 0.191s ? 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: Sun, 18 Jul 2021 06:47:41 +0000 + Message-ID: + Date: Sun, 18 Jul 2021 07:02:22 +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="Mpu92xCTfzU" + boundary="_nIYP8G6NXk" - --Mpu92xCTfzU + --_nIYP8G6NXk Content-Type: text/plain; charset="utf-8" Content-Disposition: inline Content-Description: Notification @@ -1016,7 +1087,7 @@ oh! the humanity! - --Mpu92xCTfzU + --_nIYP8G6NXk Content-Type: message/global-delivery-status Content-Description: Delivery Report Content-Transfer-Encoding: 8bit @@ -1047,7 +1118,7 @@ - --Mpu92xCTfzU + --_nIYP8G6NXk Content-Type: message/rfc822 Content-Description: Undelivered Message Content-Transfer-Encoding: 8bit @@ -1057,78 +1128,75 @@ Data ñaca. - --Mpu92xCTfzU-- + --_nIYP8G6NXk-- ---- PASS: TestDSN (0.00s) +--- PASS: TestDSN (0.01s) === RUN TestBasic - testlib.go:26: test directory: "/tmp/testlib_318676064" -_ queue.go:302 Queue.SendLoop z1x8eF4oPD0: from from -_ queue.go:361 Queue.SendLoop z1x8eF4oPD0: nodomain sent -_ queue.go:361 Queue.SendLoop z1x8eF4oPD0: am@loco sent -_ queue.go:361 Queue.SendLoop z1x8eF4oPD0: x@remote sent -_ queue.go:336 Queue.SendLoop z1x8eF4oPD0: all done ---- PASS: TestBasic (0.02s) + testlib.go:26: test directory: "/tmp/testlib_533460754" +_ queue.go:302 Queue.SendLoop mafyit3aqPo: from from +_ queue.go:361 Queue.SendLoop mafyit3aqPo: nodomain sent +_ queue.go:361 Queue.SendLoop mafyit3aqPo: am@loco sent +_ queue.go:361 Queue.SendLoop mafyit3aqPo: x@remote sent +_ queue.go:336 Queue.SendLoop mafyit3aqPo: all done +--- PASS: TestBasic (0.04s) === RUN TestDSNOnTimeout - testlib.go:26: test directory: "/tmp/testlib_149220835" -_ queue.go:302 Queue.SendLoop cIAfnzgnmgQ: from from@loco -_ queue.go:459 Queue.SendLoop cIAfnzgnmgQ: queued DSN: 79kn-foxzkg -_ queue.go:336 Queue.SendLoop cIAfnzgnmgQ: all done -_ queue.go:302 Queue.SendLoop 79kn-foxzkg: from <> -_ queue.go:361 Queue.SendLoop 79kn-foxzkg: from@loco sent -_ queue.go:369 Queue.SendLoop 79kn-foxzkg: error: failed to write: rename /tmp/testlib_149220835/.m:79kn-foxzkg325371912 /tmp/testlib_149220835/m:79kn-foxzkg: no such file or directory -_ queue.go:336 Queue.SendLoop 79kn-foxzkg: all done ---- PASS: TestDSNOnTimeout (0.00s) + testlib.go:26: test directory: "/tmp/testlib_307846285" +_ queue.go:302 Queue.SendLoop V0KXSbS5Yds: from from@loco +_ queue.go:459 Queue.SendLoop V0KXSbS5Yds: queued DSN: X90IIJP3wy0 +_ queue.go:336 Queue.SendLoop V0KXSbS5Yds: all done +_ queue.go:302 Queue.SendLoop X90IIJP3wy0: from <> +_ queue.go:361 Queue.SendLoop X90IIJP3wy0: from@loco sent +--- PASS: TestDSNOnTimeout (0.04s) === RUN TestAliases -E queue.go:224 failed to remove queue file "/tmp/testlib_149220835/m:79kn-foxzkg": remove /tmp/testlib_149220835/m:79kn-foxzkg: no such file or directory - testlib.go:26: test directory: "/tmp/testlib_449168327" -_ queue.go:302 Queue.SendLoop o9oAy9ciOcw: from from -_ queue.go:361 Queue.SendLoop o9oAy9ciOcw: ata@hualpa sent ---- PASS: TestAliases (0.00s) -_ queue.go:369 Queue.SendLoop o9oAy9ciOcw: error: failed to write: open /tmp/testlib_449168327/.m:o9oAy9ciOcw834201489: no such file or directory + testlib.go:26: test directory: "/tmp/testlib_707014673" +_ queue.go:369 Queue.SendLoop X90IIJP3wy0: error: failed to write: rename /tmp/testlib_307846285/.m:X90IIJP3wy0298973434 /tmp/testlib_307846285/m:X90IIJP3wy0: no such file or directory +_ queue.go:336 Queue.SendLoop X90IIJP3wy0: all done +E queue.go:224 failed to remove queue file "/tmp/testlib_307846285/m:X90IIJP3wy0": remove /tmp/testlib_307846285/m:X90IIJP3wy0: no such file or directory +_ queue.go:302 Queue.SendLoop Q_NmcnEE0Wk: from from +_ queue.go:361 Queue.SendLoop Q_NmcnEE0Wk: ata@hualpa sent +_ queue.go:361 Queue.SendLoop Q_NmcnEE0Wk: pq@loco sent +_ queue.go:361 Queue.SendLoop Q_NmcnEE0Wk: rs@loco sent +--- PASS: TestAliases (0.03s) === RUN TestFullQueue -_ queue.go:361 Queue.SendLoop o9oAy9ciOcw: pq@loco sent -_ queue.go:369 Queue.SendLoop o9oAy9ciOcw: error: failed to write: open /tmp/testlib_449168327/.m:o9oAy9ciOcw114742251: no such file or directory -_ queue.go:361 Queue.SendLoop o9oAy9ciOcw: rs@loco sent - testlib.go:26: test directory: "/tmp/testlib_414021564" -_ queue.go:369 Queue.SendLoop o9oAy9ciOcw: error: failed to write: open /tmp/testlib_449168327/.m:o9oAy9ciOcw667098702: no such file or directory -_ queue.go:336 Queue.SendLoop o9oAy9ciOcw: all done -E queue.go:224 failed to remove queue file "/tmp/testlib_449168327/m:o9oAy9ciOcw": remove /tmp/testlib_449168327/m:o9oAy9ciOcw: no such file or directory ---- PASS: TestFullQueue (0.00s) + testlib.go:26: test directory: "/tmp/testlib_792232917" +_ queue.go:369 Queue.SendLoop Q_NmcnEE0Wk: error: failed to write: open /tmp/testlib_707014673/.m:Q_NmcnEE0Wk945748784: no such file or directory +_ queue.go:336 Queue.SendLoop Q_NmcnEE0Wk: all done +E queue.go:224 failed to remove queue file "/tmp/testlib_707014673/m:Q_NmcnEE0Wk": remove /tmp/testlib_707014673/m:Q_NmcnEE0Wk: no such file or directory +_ queue.go:302 Queue.SendLoop -IEaA42BulQ: from from +_ queue.go:361 Queue.SendLoop -IEaA42BulQ: to sent +--- PASS: TestFullQueue (0.04s) === RUN TestPipes -_ queue.go:302 Queue.SendLoop dhdy66qwY-Q: from from -_ queue.go:361 Queue.SendLoop dhdy66qwY-Q: to sent - testlib.go:26: test directory: "/tmp/testlib_345313871" -_ queue.go:369 Queue.SendLoop dhdy66qwY-Q: error: failed to write: open /tmp/testlib_414021564/.m:dhdy66qwY-Q370742626: no such file or directory -_ queue.go:336 Queue.SendLoop dhdy66qwY-Q: all done -E queue.go:224 failed to remove queue file "/tmp/testlib_414021564/m:dhdy66qwY-Q": remove /tmp/testlib_414021564/m:dhdy66qwY-Q: no such file or directory ---- PASS: TestPipes (0.00s) + testlib.go:26: test directory: "/tmp/testlib_685424484" +_ queue.go:369 Queue.SendLoop -IEaA42BulQ: error: failed to write: open /tmp/testlib_792232917/.m:-IEaA42BulQ512793561: no such file or directory +_ queue.go:336 Queue.SendLoop -IEaA42BulQ: all done +E queue.go:224 failed to remove queue file "/tmp/testlib_792232917/m:-IEaA42BulQ": remove /tmp/testlib_792232917/m:-IEaA42BulQ: no such file or directory +--- PASS: TestPipes (0.04s) === RUN TestBadPath --- PASS: TestBadPath (0.00s) === RUN TestNextDelay --- PASS: TestNextDelay (0.00s) === RUN TestSerialization - testlib.go:26: test directory: "/tmp/testlib_726923609" -_ queue.go:302 Queue.SendLoop Z5Z8khQqjtc: from from@loco -_ queue.go:361 Queue.SendLoop Z5Z8khQqjtc: to@to sent -_ queue.go:336 Queue.SendLoop Z5Z8khQqjtc: all done ---- PASS: TestSerialization (0.00s) + testlib.go:26: test directory: "/tmp/testlib_054593395" +_ queue.go:302 Queue.SendLoop lIv7TNl1k2U: from from@loco +_ queue.go:361 Queue.SendLoop lIv7TNl1k2U: to@to sent +--- PASS: TestSerialization (0.01s) PASS -ok blitiri.com.ar/go/chasquid/internal/queue 0.073s +ok blitiri.com.ar/go/chasquid/internal/queue 0.371s === RUN TestWriteFile - testlib.go:26: test directory: "/tmp/testlib_668826909" ---- PASS: TestWriteFile (0.00s) + testlib.go:26: test directory: "/tmp/testlib_454933675" +--- PASS: TestWriteFile (0.02s) === RUN TestWriteFileWithOp - testlib.go:26: test directory: "/tmp/testlib_259223969" + testlib.go:26: test directory: "/tmp/testlib_720827151" --- PASS: TestWriteFileWithOp (0.00s) === RUN TestWriteFileWithFailingOp - testlib.go:26: test directory: "/tmp/testlib_038160507" ---- PASS: TestWriteFileWithFailingOp (0.01s) + testlib.go:26: test directory: "/tmp/testlib_699614745" +--- PASS: TestWriteFileWithFailingOp (0.03s) PASS -ok blitiri.com.ar/go/chasquid/internal/safeio 0.073s +ok blitiri.com.ar/go/chasquid/internal/safeio 0.203s === RUN TestString --- PASS: TestString (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/set 0.023s +ok blitiri.com.ar/go/chasquid/internal/set 0.073s === RUN TestIsPermanent --- PASS: TestIsPermanent (0.00s) === RUN TestIsASCII @@ -1142,22 +1210,22 @@ === RUN TestFallbackToIDNA --- PASS: TestFallbackToIDNA (0.00s) === RUN TestLineTooLong ---- PASS: TestLineTooLong (0.09s) +--- PASS: TestLineTooLong (0.78s) PASS -ok blitiri.com.ar/go/chasquid/internal/smtp 0.117s -_ server.go:221 Server listening on 127.0.0.1:33221 (SMTP) -2021-07-18 06:47:42.004202 daemon listening on 127.0.0.1:33221 -_ server.go:221 Server listening on 127.0.0.1:37259 (submission) -2021-07-18 06:47:42.004453 daemon listening on 127.0.0.1:37259 -_ server.go:221 Server listening on 127.0.0.1:40781 (submission+TLS) -2021-07-18 06:47:42.004558 daemon listening on 127.0.0.1:40781 -_ conn.go:191 SMTP.Conn 127.0.0.1:34536: error: error completing TLS handshake: EOF +ok blitiri.com.ar/go/chasquid/internal/smtp 0.966s +_ server.go:221 Server listening on 127.0.0.1:38543 (SMTP) +2021-07-18 07:02:29.685240 daemon listening on 127.0.0.1:38543 +_ server.go:221 Server listening on 127.0.0.1:43319 (submission) +2021-07-18 07:02:29.686234 daemon listening on 127.0.0.1:43319 +_ server.go:221 Server listening on 127.0.0.1:37019 (submission+TLS) +2021-07-18 07:02:29.686584 daemon listening on 127.0.0.1:37019 +_ conn.go:191 SMTP.Conn 127.0.0.1:32950: error: error completing TLS handshake: EOF === RUN TestSecLevel - testlib.go:26: test directory: "/tmp/testlib_024793047" -_ domaininfo.go:107 DomainInfo /tmp/testlib_024793047: slc incoming level raised: TLS_CLIENT > PLAIN -_ domaininfo.go:99 DomainInfo /tmp/testlib_024793047: error: slc incoming denied: PLAIN < TLS_CLIENT + testlib.go:26: test directory: "/tmp/testlib_352565671" +_ domaininfo.go:107 DomainInfo /tmp/testlib_352565671: slc incoming level raised: TLS_CLIENT > PLAIN +_ domaininfo.go:99 DomainInfo /tmp/testlib_352565671: error: slc incoming denied: PLAIN < TLS_CLIENT _ conn.go:520 testconn testconn: error: security level check for slc failed (PLAIN) ---- PASS: TestSecLevel (0.00s) +--- PASS: TestSecLevel (0.02s) === RUN TestIsHeader --- PASS: TestIsHeader (0.00s) === RUN TestReadUntilDot @@ -1186,172 +1254,172 @@ conn_test.go:126: testing "\n.\n12345678901234567890" conn_test.go:126: testing "\n.\n1234567890123456789012345678901234567890" conn_test.go:126: testing "\n.\n.\n" ---- PASS: TestReadUntilDot (0.00s) +--- PASS: TestReadUntilDot (0.01s) === RUN TestAddrLiteral --- PASS: TestAddrLiteral (0.00s) === RUN TestSanitizeEHLODomain --- PASS: TestSanitizeEHLODomain (0.00s) === RUN TestSimple -_ conn.go:664 SMTP.Conn 127.0.0.1:51906: Queued from from@from to [to@localhost] - uzMgq-FICwY -2021-07-18 06:47:42.112642 uzMgq-FICwY from=from@from queued ip=127.0.0.1:51906 to=[to@localhost] -_ queue.go:302 Queue.SendLoop uzMgq-FICwY: from from@from -_ queue.go:361 Queue.SendLoop uzMgq-FICwY: testuser@localhost sent -2021-07-18 06:47:42.112837 uzMgq-FICwY from=from@from to=testuser@localhost sent ---- PASS: TestSimple (0.00s) +_ conn.go:664 SMTP.Conn 127.0.0.1:34764: Queued from from@from to [to@localhost] - 6BmGnBswY04 +_ queue.go:302 Queue.SendLoop 6BmGnBswY04: from from@from +_ queue.go:361 Queue.SendLoop 6BmGnBswY04: testuser@localhost sent +2021-07-18 07:02:29.863633 6BmGnBswY04 from=from@from to=testuser@localhost sent +_ queue.go:336 Queue.SendLoop 6BmGnBswY04: all done +2021-07-18 07:02:29.866030 6BmGnBswY04 from=from@from all done +2021-07-18 07:02:29.866733 6BmGnBswY04 from=from@from queued ip=127.0.0.1:34764 to=[to@localhost] +--- PASS: TestSimple (0.03s) === RUN TestSimpleTLS -_ queue.go:336 Queue.SendLoop uzMgq-FICwY: all done -2021-07-18 06:47:42.113969 uzMgq-FICwY from=from@from all done -_ conn.go:664 SMTP.Conn 127.0.0.1:51908: Queued from from@from to [to@localhost] - gITj69sAAHU -2021-07-18 06:47:42.134413 gITj69sAAHU from=from@from queued ip=127.0.0.1:51908 to=[to@localhost] -_ queue.go:302 Queue.SendLoop gITj69sAAHU: from from@from -_ queue.go:361 Queue.SendLoop gITj69sAAHU: testuser@localhost sent -2021-07-18 06:47:42.134682 gITj69sAAHU from=from@from to=testuser@localhost sent ---- PASS: TestSimpleTLS (0.02s) +_ conn.go:664 SMTP.Conn 127.0.0.1:34766: Queued from from@from to [to@localhost] - TpBbK_Yd80E +2021-07-18 07:02:30.003812 TpBbK_Yd80E from=from@from queued ip=127.0.0.1:34766 to=[to@localhost] +_ queue.go:302 Queue.SendLoop TpBbK_Yd80E: from from@from +_ queue.go:361 Queue.SendLoop TpBbK_Yd80E: testuser@localhost sent +2021-07-18 07:02:30.004776 TpBbK_Yd80E from=from@from to=testuser@localhost sent +--- PASS: TestSimpleTLS (0.14s) === RUN TestManyEmails -_ queue.go:336 Queue.SendLoop gITj69sAAHU: all done -2021-07-18 06:47:42.136435 gITj69sAAHU from=from@from all done -_ conn.go:664 SMTP.Conn 127.0.0.1:51910: Queued from from@from to [to@localhost] - wtCMCCn_BqI -2021-07-18 06:47:42.154154 wtCMCCn_BqI from=from@from queued ip=127.0.0.1:51910 to=[to@localhost] -_ queue.go:302 Queue.SendLoop wtCMCCn_BqI: from from@from -_ queue.go:361 Queue.SendLoop wtCMCCn_BqI: testuser@localhost sent -2021-07-18 06:47:42.154396 wtCMCCn_BqI from=from@from to=testuser@localhost sent -_ queue.go:336 Queue.SendLoop wtCMCCn_BqI: all done -2021-07-18 06:47:42.155468 wtCMCCn_BqI from=from@from all done -_ conn.go:664 SMTP.Conn 127.0.0.1:51910: Queued from from@from to [to@localhost] - hHX78LyzHo4 -2021-07-18 06:47:42.156493 hHX78LyzHo4 from=from@from queued ip=127.0.0.1:51910 to=[to@localhost] -_ queue.go:302 Queue.SendLoop hHX78LyzHo4: from from@from -_ queue.go:361 Queue.SendLoop hHX78LyzHo4: testuser@localhost sent -2021-07-18 06:47:42.156670 hHX78LyzHo4 from=from@from to=testuser@localhost sent -_ queue.go:336 Queue.SendLoop hHX78LyzHo4: all done -2021-07-18 06:47:42.157442 hHX78LyzHo4 from=from@from all done -_ conn.go:664 SMTP.Conn 127.0.0.1:51910: Queued from from@from to [to@localhost] - tI32jOHeOSQ -2021-07-18 06:47:42.159253 tI32jOHeOSQ from=from@from queued ip=127.0.0.1:51910 to=[to@localhost] -_ queue.go:302 Queue.SendLoop tI32jOHeOSQ: from from@from -_ queue.go:361 Queue.SendLoop tI32jOHeOSQ: testuser@localhost sent -2021-07-18 06:47:42.159495 tI32jOHeOSQ from=from@from to=testuser@localhost sent ---- PASS: TestManyEmails (0.02s) +_ queue.go:336 Queue.SendLoop TpBbK_Yd80E: all done +2021-07-18 07:02:30.011521 TpBbK_Yd80E from=from@from all done +_ conn.go:664 SMTP.Conn 127.0.0.1:34768: Queued from from@from to [to@localhost] - r6BJUDVrYvc +2021-07-18 07:02:30.172387 r6BJUDVrYvc from=from@from queued ip=127.0.0.1:34768 to=[to@localhost] +_ queue.go:302 Queue.SendLoop r6BJUDVrYvc: from from@from +_ queue.go:361 Queue.SendLoop r6BJUDVrYvc: testuser@localhost sent +2021-07-18 07:02:30.173161 r6BJUDVrYvc from=from@from to=testuser@localhost sent +_ queue.go:336 Queue.SendLoop r6BJUDVrYvc: all done +2021-07-18 07:02:30.183575 r6BJUDVrYvc from=from@from all done +_ conn.go:664 SMTP.Conn 127.0.0.1:34768: Queued from from@from to [to@localhost] - sQAd-NcXzdA +2021-07-18 07:02:30.188333 sQAd-NcXzdA from=from@from queued ip=127.0.0.1:34768 to=[to@localhost] +_ queue.go:302 Queue.SendLoop sQAd-NcXzdA: from from@from +_ queue.go:361 Queue.SendLoop sQAd-NcXzdA: testuser@localhost sent +2021-07-18 07:02:30.189179 sQAd-NcXzdA from=from@from to=testuser@localhost sent +_ queue.go:336 Queue.SendLoop sQAd-NcXzdA: all done +2021-07-18 07:02:30.199654 sQAd-NcXzdA from=from@from all done +_ conn.go:664 SMTP.Conn 127.0.0.1:34768: Queued from from@from to [to@localhost] - RA06hE-3NAk +2021-07-18 07:02:30.204329 RA06hE-3NAk from=from@from queued ip=127.0.0.1:34768 to=[to@localhost] +_ queue.go:302 Queue.SendLoop RA06hE-3NAk: from from@from +_ queue.go:361 Queue.SendLoop RA06hE-3NAk: testuser@localhost sent +2021-07-18 07:02:30.205205 RA06hE-3NAk from=from@from to=testuser@localhost sent +--- PASS: TestManyEmails (0.20s) === RUN TestAuth -_ queue.go:336 Queue.SendLoop tI32jOHeOSQ: all done -2021-07-18 06:47:42.160936 tI32jOHeOSQ from=from@from all done -2021-07-18 06:47:42.349048 127.0.0.1:54412 auth succeeded for testuser@localhost -_ conn.go:664 SMTP.Conn 127.0.0.1:54412: Queued from testuser@localhost to [to@localhost] - qSblmyY1XM0 -2021-07-18 06:47:42.352104 qSblmyY1XM0 from=testuser@localhost queued ip=127.0.0.1:54412 to=[to@localhost] -_ queue.go:302 Queue.SendLoop qSblmyY1XM0: from testuser@localhost -_ queue.go:361 Queue.SendLoop qSblmyY1XM0: testuser@localhost sent -2021-07-18 06:47:42.352336 qSblmyY1XM0 from=testuser@localhost to=testuser@localhost sent ---- PASS: TestAuth (0.19s) +_ queue.go:336 Queue.SendLoop RA06hE-3NAk: all done +2021-07-18 07:02:30.219837 RA06hE-3NAk from=from@from all done +2021-07-18 07:02:31.511532 127.0.0.1:48280 auth succeeded for testuser@localhost +_ conn.go:664 SMTP.Conn 127.0.0.1:48280: Queued from testuser@localhost to [to@localhost] - w37K96iKT0c +2021-07-18 07:02:31.528325 w37K96iKT0c from=testuser@localhost queued ip=127.0.0.1:48280 to=[to@localhost] +_ queue.go:302 Queue.SendLoop w37K96iKT0c: from testuser@localhost +_ queue.go:361 Queue.SendLoop w37K96iKT0c: testuser@localhost sent +2021-07-18 07:02:31.529176 w37K96iKT0c from=testuser@localhost to=testuser@localhost sent +--- PASS: TestAuth (1.32s) === RUN TestSubmissionWithoutAuth -_ queue.go:336 Queue.SendLoop qSblmyY1XM0: all done -2021-07-18 06:47:42.353749 qSblmyY1XM0 from=testuser@localhost all done -_ conn.go:292 SMTP.Conn 127.0.0.1:54414: error: MAIL failed: 550 5.7.9 Mail to submission port must be authenticated ---- PASS: TestSubmissionWithoutAuth (0.02s) +_ queue.go:336 Queue.SendLoop w37K96iKT0c: all done +2021-07-18 07:02:31.539645 w37K96iKT0c from=testuser@localhost all done +_ conn.go:292 SMTP.Conn 127.0.0.1:48282: error: MAIL failed: 550 5.7.9 Mail to submission port must be authenticated +--- PASS: TestSubmissionWithoutAuth (0.14s) === RUN TestAuthOnTLS -2021-07-18 06:47:42.562003 127.0.0.1:34548 auth succeeded for testuser@localhost -_ conn.go:664 SMTP.Conn 127.0.0.1:34548: Queued from testuser@localhost to [to@localhost] - wkPzkM1VDtM -2021-07-18 06:47:42.564903 wkPzkM1VDtM from=testuser@localhost queued ip=127.0.0.1:34548 to=[to@localhost] -_ queue.go:302 Queue.SendLoop wkPzkM1VDtM: from testuser@localhost -_ queue.go:361 Queue.SendLoop wkPzkM1VDtM: testuser@localhost sent -2021-07-18 06:47:42.565217 wkPzkM1VDtM from=testuser@localhost to=testuser@localhost sent ---- PASS: TestAuthOnTLS (0.19s) +2021-07-18 07:02:33.136233 127.0.0.1:32962 auth succeeded for testuser@localhost +_ conn.go:664 SMTP.Conn 127.0.0.1:32962: Queued from testuser@localhost to [to@localhost] - DrGLK-d48Jc +2021-07-18 07:02:33.152798 DrGLK-d48Jc from=testuser@localhost queued ip=127.0.0.1:32962 to=[to@localhost] +_ queue.go:302 Queue.SendLoop DrGLK-d48Jc: from testuser@localhost +_ queue.go:361 Queue.SendLoop DrGLK-d48Jc: testuser@localhost sent +2021-07-18 07:02:33.153653 DrGLK-d48Jc from=testuser@localhost to=testuser@localhost sent +--- PASS: TestAuthOnTLS (1.48s) === RUN TestAuthOnSMTP -_ queue.go:336 Queue.SendLoop wkPzkM1VDtM: all done -2021-07-18 06:47:42.566993 wkPzkM1VDtM from=testuser@localhost all done -2021-07-18 06:47:42.759993 127.0.0.1:51918 auth succeeded for testuser@localhost -_ conn.go:664 SMTP.Conn 127.0.0.1:51918: Queued from testuser@localhost to [to@localhost] - Ccva7i-__-g -2021-07-18 06:47:42.762412 Ccva7i-__-g from=testuser@localhost queued ip=127.0.0.1:51918 to=[to@localhost] -_ queue.go:302 Queue.SendLoop Ccva7i-__-g: from testuser@localhost -_ queue.go:361 Queue.SendLoop Ccva7i-__-g: testuser@localhost sent -2021-07-18 06:47:42.762630 Ccva7i-__-g from=testuser@localhost to=testuser@localhost sent ---- PASS: TestAuthOnSMTP (0.20s) +_ queue.go:336 Queue.SendLoop DrGLK-d48Jc: all done +2021-07-18 07:02:33.172254 DrGLK-d48Jc from=testuser@localhost all done +2021-07-18 07:02:34.290036 127.0.0.1:34776 auth succeeded for testuser@localhost +_ conn.go:664 SMTP.Conn 127.0.0.1:34776: Queued from testuser@localhost to [to@localhost] - UJR0IYaroBA +2021-07-18 07:02:34.304985 UJR0IYaroBA from=testuser@localhost queued ip=127.0.0.1:34776 to=[to@localhost] +_ queue.go:302 Queue.SendLoop UJR0IYaroBA: from testuser@localhost +_ queue.go:361 Queue.SendLoop UJR0IYaroBA: testuser@localhost sent +2021-07-18 07:02:34.305825 UJR0IYaroBA from=testuser@localhost to=testuser@localhost sent +--- PASS: TestAuthOnSMTP (1.15s) === RUN TestBrokenAuth -_ queue.go:336 Queue.SendLoop Ccva7i-__-g: all done -2021-07-18 06:47:42.763647 Ccva7i-__-g from=testuser@localhost all done -_ conn.go:1060 SMTP.Conn 127.0.0.1:54420: error: error authenticating \"user\"@\"broken\": failed to auth -2021-07-18 06:47:42.898942 127.0.0.1:54420 auth failed for user@broken -_ conn.go:292 SMTP.Conn 127.0.0.1:54420: error: AUTH failed: 454 4.7.0 Temporary authentication failure -_ conn.go:292 SMTP.Conn 127.0.0.1:54420: error: unknown<*> failed: 500 5.5.1 Unknown command ---- PASS: TestBrokenAuth (0.14s) +_ queue.go:336 Queue.SendLoop UJR0IYaroBA: all done +2021-07-18 07:02:34.324546 UJR0IYaroBA from=testuser@localhost all done +_ conn.go:1060 SMTP.Conn 127.0.0.1:48288: error: error authenticating \"user\"@\"broken\": failed to auth +2021-07-18 07:02:34.567427 127.0.0.1:48288 auth failed for user@broken +_ conn.go:292 SMTP.Conn 127.0.0.1:48288: error: AUTH failed: 454 4.7.0 Temporary authentication failure +_ conn.go:292 SMTP.Conn 127.0.0.1:48288: error: unknown<*> failed: 500 5.5.1 Unknown command +--- PASS: TestBrokenAuth (0.27s) === RUN TestWrongMailParsing -_ conn.go:292 SMTP.Conn 127.0.0.1:51922: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51922: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51922: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51922: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51922: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51922: error: MAIL failed: 501 5.1.7 Sender address malformed -_ conn.go:292 SMTP.Conn 127.0.0.1:51922: error: RCPT failed: 501 5.1.3 Malformed destination address -_ conn.go:292 SMTP.Conn 127.0.0.1:51922: error: RCPT failed: 501 5.1.3 Malformed destination address -_ conn.go:292 SMTP.Conn 127.0.0.1:51922: error: RCPT failed: 501 5.1.3 Malformed destination address -_ conn.go:292 SMTP.Conn 127.0.0.1:51922: error: RCPT failed: 501 5.1.3 Malformed destination address -_ conn.go:292 SMTP.Conn 127.0.0.1:51922: error: RCPT failed: 501 5.1.3 Malformed destination address -_ conn.go:297 SMTP.Conn 127.0.0.1:51922: error: too many errors, breaking connection ---- PASS: TestWrongMailParsing (0.00s) +_ conn.go:292 SMTP.Conn 127.0.0.1:34780: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34780: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34780: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34780: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34780: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34780: error: MAIL failed: 501 5.1.7 Sender address malformed +_ conn.go:292 SMTP.Conn 127.0.0.1:34780: error: RCPT failed: 501 5.1.3 Malformed destination address +_ conn.go:292 SMTP.Conn 127.0.0.1:34780: error: RCPT failed: 501 5.1.3 Malformed destination address +_ conn.go:292 SMTP.Conn 127.0.0.1:34780: error: RCPT failed: 501 5.1.3 Malformed destination address +_ conn.go:292 SMTP.Conn 127.0.0.1:34780: error: RCPT failed: 501 5.1.3 Malformed destination address +_ conn.go:292 SMTP.Conn 127.0.0.1:34780: error: RCPT failed: 501 5.1.3 Malformed destination address +_ conn.go:297 SMTP.Conn 127.0.0.1:34780: error: too many errors, breaking connection +--- PASS: TestWrongMailParsing (0.05s) === RUN TestNullMailFrom ---- PASS: TestNullMailFrom (0.00s) +--- PASS: TestNullMailFrom (0.01s) === RUN TestRcptBeforeMail -_ conn.go:292 SMTP.Conn 127.0.0.1:51926: error: RCPT failed: 503 5.5.1 Sender not yet given ---- PASS: TestRcptBeforeMail (0.00s) +_ conn.go:292 SMTP.Conn 127.0.0.1:34784: error: RCPT failed: 503 5.5.1 Sender not yet given +--- PASS: TestRcptBeforeMail (0.01s) === RUN TestRcptOption ---- PASS: TestRcptOption (0.02s) +--- PASS: TestRcptOption (0.13s) === RUN TestRelayForbidden -2021-07-18 06:47:42.933175 127.0.0.1:51930 rejected from=from@somewhere to=[to@somewhere] - relay not allowed -_ conn.go:292 SMTP.Conn 127.0.0.1:51930: error: RCPT failed: 503 5.7.1 Relay not allowed ---- PASS: TestRelayForbidden (0.00s) +2021-07-18 07:02:34.793372 127.0.0.1:34788 rejected from=from@somewhere to=[to@somewhere] - relay not allowed +_ conn.go:292 SMTP.Conn 127.0.0.1:34788: error: RCPT failed: 503 5.7.1 Relay not allowed +--- PASS: TestRelayForbidden (0.02s) === RUN TestTooManyRecipients -2021-07-18 06:47:43.099599 127.0.0.1:54432 auth succeeded for testuser@localhost -_ conn.go:292 SMTP.Conn 127.0.0.1:54432: error: RCPT failed: 452 4.5.3 Too many recipients ---- PASS: TestTooManyRecipients (0.19s) +2021-07-18 07:02:36.198426 127.0.0.1:48300 auth succeeded for testuser@localhost +_ conn.go:292 SMTP.Conn 127.0.0.1:48300: error: RCPT failed: 452 4.5.3 Too many recipients +--- PASS: TestTooManyRecipients (1.61s) === RUN TestRcptFailsExistsCheck -_ conn.go:1098 SMTP.Conn 127.0.0.1:51934: error: error checking if user \"to@broken\" exists: failed to check if user exists -2021-07-18 06:47:43.149501 127.0.0.1:51934 rejected from=from@localhost to=[to@broken] - local user does not exist -_ conn.go:292 SMTP.Conn 127.0.0.1:51934: error: RCPT failed: 550 5.1.1 Destination address is unknown (user does not exist) ---- PASS: TestRcptFailsExistsCheck (0.02s) +_ conn.go:1098 SMTP.Conn 127.0.0.1:34792: error: error checking if user \"to@broken\" exists: failed to check if user exists +2021-07-18 07:02:36.552904 127.0.0.1:34792 rejected from=from@localhost to=[to@broken] - local user does not exist +_ conn.go:292 SMTP.Conn 127.0.0.1:34792: error: RCPT failed: 550 5.1.1 Destination address is unknown (user does not exist) +--- PASS: TestRcptFailsExistsCheck (0.15s) === RUN TestTooMuchData -_ conn.go:664 SMTP.Conn 127.0.0.1:51936: Queued from from@from to [to@localhost] - lteukikbYfE -2021-07-18 06:47:43.559137 lteukikbYfE from=from@from queued ip=127.0.0.1:51936 to=[to@localhost] -_ queue.go:302 Queue.SendLoop lteukikbYfE: from from@from -_ queue.go:361 Queue.SendLoop lteukikbYfE: testuser@localhost sent -2021-07-18 06:47:43.559301 lteukikbYfE from=from@from to=testuser@localhost sent -_ queue.go:336 Queue.SendLoop lteukikbYfE: all done -2021-07-18 06:47:43.599211 lteukikbYfE from=from@from all done -_ conn.go:664 SMTP.Conn 127.0.0.1:51936: Queued from from@from to [to@localhost] - ySWayo0lDzI -2021-07-18 06:47:43.996360 ySWayo0lDzI from=from@from queued ip=127.0.0.1:51936 to=[to@localhost] -_ queue.go:302 Queue.SendLoop ySWayo0lDzI: from from@from -_ queue.go:361 Queue.SendLoop ySWayo0lDzI: testuser@localhost sent -2021-07-18 06:47:44.004796 ySWayo0lDzI from=from@from to=testuser@localhost sent -_ queue.go:336 Queue.SendLoop ySWayo0lDzI: all done -2021-07-18 06:47:44.259896 ySWayo0lDzI from=from@from all done -_ conn.go:292 SMTP.Conn 127.0.0.1:51936: error: DATA failed: 552 5.3.4 Message too big -_ queue.go:302 Queue.SendLoop X13hG025J5I: from from@from -_ conn.go:664 SMTP.Conn 127.0.0.1:51936: Queued from from@from to [to@localhost] - X13hG025J5I -2021-07-18 06:47:44.985200 X13hG025J5I from=from@from queued ip=127.0.0.1:51936 to=[to@localhost] -_ queue.go:361 Queue.SendLoop X13hG025J5I: testuser@localhost sent -2021-07-18 06:47:44.985274 X13hG025J5I from=from@from to=testuser@localhost sent ---- PASS: TestTooMuchData (1.84s) +_ conn.go:664 SMTP.Conn 127.0.0.1:34794: Queued from from@from to [to@localhost] - iSi6YhUuX3k +2021-07-18 07:02:39.728677 iSi6YhUuX3k from=from@from queued ip=127.0.0.1:34794 to=[to@localhost] +_ queue.go:302 Queue.SendLoop iSi6YhUuX3k: from from@from +_ queue.go:361 Queue.SendLoop iSi6YhUuX3k: testuser@localhost sent +2021-07-18 07:02:39.729462 iSi6YhUuX3k from=from@from to=testuser@localhost sent +_ queue.go:336 Queue.SendLoop iSi6YhUuX3k: all done +2021-07-18 07:02:40.333868 iSi6YhUuX3k from=from@from all done +_ conn.go:664 SMTP.Conn 127.0.0.1:34794: Queued from from@from to [to@localhost] - dBwDdluqjg0 +2021-07-18 07:02:42.736003 dBwDdluqjg0 from=from@from queued ip=127.0.0.1:34794 to=[to@localhost] +_ queue.go:302 Queue.SendLoop dBwDdluqjg0: from from@from +_ queue.go:361 Queue.SendLoop dBwDdluqjg0: testuser@localhost sent +2021-07-18 07:02:42.736812 dBwDdluqjg0 from=from@from to=testuser@localhost sent +_ queue.go:336 Queue.SendLoop dBwDdluqjg0: all done +2021-07-18 07:02:43.459011 dBwDdluqjg0 from=from@from all done +_ conn.go:292 SMTP.Conn 127.0.0.1:34794: error: DATA failed: 552 5.3.4 Message too big +_ conn.go:664 SMTP.Conn 127.0.0.1:34794: Queued from from@from to [to@localhost] - Uy2mw8i513Y +2021-07-18 07:02:49.535184 Uy2mw8i513Y from=from@from queued ip=127.0.0.1:34794 to=[to@localhost] +_ queue.go:302 Queue.SendLoop Uy2mw8i513Y: from from@from +_ queue.go:361 Queue.SendLoop Uy2mw8i513Y: testuser@localhost sent +2021-07-18 07:02:49.536317 Uy2mw8i513Y from=from@from to=testuser@localhost sent +--- PASS: TestTooMuchData (12.99s) === RUN TestSimpleCommands -_ conn.go:292 SMTP.Conn 127.0.0.1:51938: 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:51938: error: EXPN failed: 502 5.5.1 You feel disoriented for a moment. ---- PASS: TestSimpleCommands (0.00s) +_ conn.go:292 SMTP.Conn 127.0.0.1:34796: 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:34796: error: EXPN failed: 502 5.5.1 You feel disoriented for a moment. +--- PASS: TestSimpleCommands (0.01s) === RUN TestLongLines -_ conn.go:292 SMTP.Conn 127.0.0.1:51940: error: unknown<> failed: 500 5.5.1 Unknown command -_ conn.go:314 SMTP.Conn 127.0.0.1:51940: error: exiting with error: line too long +_ conn.go:292 SMTP.Conn 127.0.0.1:34798: error: unknown<> failed: 500 5.5.1 Unknown command +_ conn.go:314 SMTP.Conn 127.0.0.1:34798: error: exiting with error: line too long --- PASS: TestLongLines (0.01s) === RUN TestReset ---- PASS: TestReset (0.00s) +--- PASS: TestReset (0.01s) === RUN TestRepeatedStartTLS -_ conn.go:292 SMTP.Conn 127.0.0.1:51944: 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:34802: error: STARTTLS failed: 503 5.5.1 You are already wearing that! +--- PASS: TestRepeatedStartTLS (0.13s) === RUN TestStartTLSOnTLS -_ conn.go:292 SMTP.Conn 127.0.0.1:34578: error: STARTTLS failed: 503 5.5.1 You are already wearing that! ---- PASS: TestStartTLSOnTLS (0.02s) +_ conn.go:292 SMTP.Conn 127.0.0.1:32992: error: STARTTLS failed: 503 5.5.1 You are already wearing that! +--- PASS: TestStartTLSOnTLS (0.13s) PASS -ok blitiri.com.ar/go/chasquid/internal/smtpsrv 3.511s +ok blitiri.com.ar/go/chasquid/internal/smtpsrv 25.007s === RUN TestParsePolicy sts_test.go:90: pol1: &{Version:STSv1 Mode:enforce MXs:[*.mail.example.com] MaxAge:34h17m36s} --- PASS: TestParsePolicy (0.00s) === RUN TestCheckPolicy --- PASS: TestCheckPolicy (0.00s) === RUN TestMatchDomain ---- PASS: TestMatchDomain (0.00s) +--- PASS: TestMatchDomain (0.04s) === RUN TestMXIsAllowed --- PASS: TestMXIsAllowed (0.00s) === RUN TestFetch @@ -1359,34 +1427,34 @@ sts_test.go:210: policy404: got error as expected: HTTP response status code: 404 sts_test.go:218: version99: got expected error: unknown policy version sts_test.go:226: domErr: got expected error: error for testing purposes ---- PASS: TestFetch (0.00s) +--- PASS: TestFetch (0.04s) === RUN TestPolicyTooBig sts_test.go:242: got error as expected: MTA-STS TXT record missing ---- PASS: TestPolicyTooBig (0.04s) +--- PASS: TestPolicyTooBig (0.65s) === RUN TestCacheBasics - testlib.go:26: test directory: "/tmp/testlib_616621601" + testlib.go:26: test directory: "/tmp/testlib_299975080" 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.04s) === RUN TestCacheBadData - testlib.go:26: test directory: "/tmp/testlib_067158046" + testlib.go:26: test directory: "/tmp/testlib_622714801" 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.01s) +--- PASS: TestCacheBadData (0.06s) === RUN TestCacheRefresh - testlib.go:26: test directory: "/tmp/testlib_222046185" + testlib.go:26: test directory: "/tmp/testlib_289131600" 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.04s) === RUN TestCacheSlashSafe - testlib.go:26: test directory: "/tmp/testlib_278574982" + testlib.go:26: test directory: "/tmp/testlib_119453049" sts_test.go:464: recovered: domain contains slash --- PASS: TestCacheSlashSafe (0.00s) === RUN TestURLForDomain @@ -1394,62 +1462,62 @@ === RUN TestHasSTSRecord --- PASS: TestHasSTSRecord (0.00s) === RUN TestHTTPGet ---- PASS: TestHTTPGet (0.01s) +--- PASS: TestHTTPGet (0.05s) PASS -ok blitiri.com.ar/go/chasquid/internal/sts 0.100s +ok blitiri.com.ar/go/chasquid/internal/sts 1.146s === RUN TestBasic - testlib.go:26: test directory: "/tmp/testlib_002419409" + testlib.go:26: test directory: "/tmp/testlib_508406062" --- PASS: TestBasic (0.00s) === RUN TestRemoveCheck testlib_test.go:34: recovered: invalid/dangerous directory --- PASS: TestRemoveCheck (0.00s) === RUN TestLeaveDirOnError ---- PASS: TestLeaveDirOnError (0.00s) +--- PASS: TestLeaveDirOnError (0.02s) === RUN TestRewriteSafeguard testlib_test.go:61: recovered: invalid/dangerous path --- PASS: TestRewriteSafeguard (0.00s) === RUN TestRewrite - testlib.go:26: test directory: "/tmp/testlib_877455147" ---- PASS: TestRewrite (0.00s) + testlib.go:26: test directory: "/tmp/testlib_433493648" +--- PASS: TestRewrite (0.02s) === RUN TestGetFreePort ---- PASS: TestGetFreePort (0.00s) +--- PASS: TestGetFreePort (0.01s) === RUN TestWaitFor --- PASS: TestWaitFor (0.02s) PASS -ok blitiri.com.ar/go/chasquid/internal/testlib 0.063s +ok blitiri.com.ar/go/chasquid/internal/testlib 0.220s === RUN TestVersionName --- PASS: TestVersionName (0.00s) === RUN TestCipherSuiteName --- PASS: TestCipherSuiteName (0.00s) PASS -ok blitiri.com.ar/go/chasquid/internal/tlsconst 0.018s +ok blitiri.com.ar/go/chasquid/internal/tlsconst 0.100s ? blitiri.com.ar/go/chasquid/internal/trace [no test files] === RUN TestEmptyLoad - userdb_test.go:38: file: "/tmp/userdb_test520025058" - userdb_test.go:38: file: "/tmp/userdb_test734138329" + userdb_test.go:38: file: "/tmp/userdb_test090960270" + userdb_test.go:38: file: "/tmp/userdb_test304707989" --- PASS: TestEmptyLoad (0.00s) === RUN TestWrite - userdb_test.go:38: file: "/tmp/userdb_test779860836" ---- PASS: TestWrite (1.64s) + userdb_test.go:38: file: "/tmp/userdb_test765343728" +--- PASS: TestWrite (9.59s) === RUN TestNew ---- PASS: TestNew (0.17s) +--- PASS: TestNew (1.37s) === RUN TestInvalidUsername - userdb_test.go:38: file: "/tmp/userdb_test144266456" ---- PASS: TestInvalidUsername (0.00s) + userdb_test.go:38: file: "/tmp/userdb_test259193892" +--- PASS: TestInvalidUsername (0.01s) === RUN TestPlainScheme - userdb_test.go:38: file: "/tmp/userdb_test428625495" ---- PASS: TestPlainScheme (0.00s) + userdb_test.go:38: file: "/tmp/userdb_test967135027" +--- PASS: TestPlainScheme (0.01s) === RUN TestReload - userdb_test.go:38: file: "/tmp/userdb_test934341281" + userdb_test.go:38: file: "/tmp/userdb_test486982109" --- PASS: TestReload (0.01s) === RUN TestRemoveUser - userdb_test.go:38: file: "/tmp/userdb_test381009292" ---- PASS: TestRemoveUser (0.18s) + userdb_test.go:38: file: "/tmp/userdb_test644680600" +--- PASS: TestRemoveUser (1.41s) === RUN TestExists - userdb_test.go:38: file: "/tmp/userdb_test174276475" ---- PASS: TestExists (0.16s) + userdb_test.go:38: file: "/tmp/userdb_test669649431" +--- PASS: TestExists (2.15s) PASS -ok blitiri.com.ar/go/chasquid/internal/userdb 2.182s +ok blitiri.com.ar/go/chasquid/internal/userdb 14.744s create-stamp debian/debhelper-build-stamp dh_testroot -O--buildsystem=golang dh_prep -O--buildsystem=golang @@ -1494,10 +1562,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/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-util +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_makeshlibs -a -O--buildsystem=golang dh_shlibdeps -a -O--buildsystem=golang dh_installdeb -O--buildsystem=golang @@ -1513,12 +1581,14 @@ dpkg-buildpackage: info: binary-only upload (no source included) dpkg-genchanges: info: including full source code in upload I: copying local configuration +I: user script /srv/workspace/pbuilder/30427/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/30427/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/28549 and its subdirectories -I: Current time: Sat Jul 17 18:48:31 -12 2021 -I: pbuilder-time-stamp: 1626590911 +I: removing directory /srv/workspace/pbuilder/30427 and its subdirectories +I: Current time: Sun Jul 18 21:06:40 +14 2021 +I: pbuilder-time-stamp: 1626592000