Diff of the two buildlogs: -- --- b1/build.log 2020-08-12 13:33:38.475076677 +0000 +++ b2/build.log 2020-08-12 13:45:51.756384468 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Wed Aug 12 01:25:27 -12 2020 -I: pbuilder-time-stamp: 1597238727 +I: Current time: Thu Aug 13 03:33:51 +14 2020 +I: pbuilder-time-stamp: 1597239231 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/buster-reproducible-base.tgz] I: copying local configuration @@ -17,7 +17,7 @@ I: Extracting source gpgv: unknown type of key resource 'trustedkeys.kbx' gpgv: keyblock resource '/root/.gnupg/trustedkeys.kbx': General error -gpgv: Signature made Tue Jan 1 10:44:16 2019 -12 +gpgv: Signature made Wed Jan 2 12:44:16 2019 +14 gpgv: using RSA key 08418BBE44720F2DBAC505ECBA7A2496DAE40D1C gpgv: issuer "debalance@debian.org" gpgv: Can't check signature: No public key @@ -29,136 +29,170 @@ dpkg-source: info: applying remove-deps.diff I: using fakeroot in build. I: Installing the build-deps -I: user script /srv/workspace/pbuilder/30913/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/24851/tmp/hooks/D01_modify_environment starting +debug: Running on jtk1a. +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/24851/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/24851/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 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]="0" [2]="3" [3]="1" [4]="release" [5]="arm-unknown-linux-gnueabihf") + BASH_VERSION='5.0.3(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 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='a478565c8a994638b78c0d672cdd1478' - 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='30913' - PS1='# ' - PS2='> ' + INVOCATION_ID=2e3fbfd5c40a467bb32155faab807726 + 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=24851 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.entYtZC6Yw/pbuilderrc_QAPl --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/buster-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/tmp.entYtZC6Yw/b1 --logfile b1/build.log erlang-lager_3.6.8-1.dsc' - SUDO_GID='111' - 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.entYtZC6Yw/pbuilderrc_h7wA --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/buster-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/tmp.entYtZC6Yw/b2 --logfile b2/build.log erlang-lager_3.6.8-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 jtx1c 4.19.0-10-arm64 #1 SMP Debian 4.19.132-1 (2020-07-24) aarch64 GNU/Linux + Linux i-capture-the-hostname 4.19.0-10-armmp-lpae #1 SMP Debian 4.19.132-1 (2020-07-24) armv7l GNU/Linux I: ls -l /bin total 3328 - -rwxr-xr-x 1 root root 767656 Apr 17 2019 bash - -rwxr-xr-x 3 root root 26052 Jul 10 2019 bunzip2 - -rwxr-xr-x 3 root root 26052 Jul 10 2019 bzcat - lrwxrwxrwx 1 root root 6 Jul 10 2019 bzcmp -> bzdiff - -rwxr-xr-x 1 root root 2227 Jul 10 2019 bzdiff - lrwxrwxrwx 1 root root 6 Jul 10 2019 bzegrep -> bzgrep - -rwxr-xr-x 1 root root 4877 Jun 24 2019 bzexe - lrwxrwxrwx 1 root root 6 Jul 10 2019 bzfgrep -> bzgrep - -rwxr-xr-x 1 root root 3641 Jul 10 2019 bzgrep - -rwxr-xr-x 3 root root 26052 Jul 10 2019 bzip2 - -rwxr-xr-x 1 root root 9636 Jul 10 2019 bzip2recover - lrwxrwxrwx 1 root root 6 Jul 10 2019 bzless -> bzmore - -rwxr-xr-x 1 root root 1297 Jul 10 2019 bzmore - -rwxr-xr-x 1 root root 22432 Feb 28 2019 cat - -rwxr-xr-x 1 root root 38868 Feb 28 2019 chgrp - -rwxr-xr-x 1 root root 38836 Feb 28 2019 chmod - -rwxr-xr-x 1 root root 42972 Feb 28 2019 chown - -rwxr-xr-x 1 root root 88376 Feb 28 2019 cp - -rwxr-xr-x 1 root root 75516 Jan 17 2019 dash - -rwxr-xr-x 1 root root 71648 Feb 28 2019 date - -rwxr-xr-x 1 root root 51212 Feb 28 2019 dd - -rwxr-xr-x 1 root root 55672 Feb 28 2019 df - -rwxr-xr-x 1 root root 88444 Feb 28 2019 dir - -rwxr-xr-x 1 root root 54872 Jan 9 2019 dmesg - lrwxrwxrwx 1 root root 8 Sep 26 2018 dnsdomainname -> hostname - lrwxrwxrwx 1 root root 8 Sep 26 2018 domainname -> hostname - -rwxr-xr-x 1 root root 22364 Feb 28 2019 echo - -rwxr-xr-x 1 root root 28 Jan 7 2019 egrep - -rwxr-xr-x 1 root root 18260 Feb 28 2019 false - -rwxr-xr-x 1 root root 28 Jan 7 2019 fgrep - -rwxr-xr-x 1 root root 47356 Jan 9 2019 findmnt - -rwsr-xr-x 1 root root 21980 Apr 22 07:38 fusermount - -rwxr-xr-x 1 root root 124508 Jan 7 2019 grep - -rwxr-xr-x 2 root root 2345 Jan 5 2019 gunzip - -rwxr-xr-x 1 root root 6375 Jan 5 2019 gzexe - -rwxr-xr-x 1 root root 64232 Jan 5 2019 gzip - -rwxr-xr-x 1 root root 13784 Sep 26 2018 hostname - -rwxr-xr-x 1 root root 43044 Feb 28 2019 ln - -rwxr-xr-x 1 root root 34932 Jul 26 2018 login - -rwxr-xr-x 1 root root 88444 Feb 28 2019 ls - -rwxr-xr-x 1 root root 67036 Jan 9 2019 lsblk - -rwxr-xr-x 1 root root 47168 Feb 28 2019 mkdir - -rwxr-xr-x 1 root root 43040 Feb 28 2019 mknod - -rwxr-xr-x 1 root root 26552 Feb 28 2019 mktemp - -rwxr-xr-x 1 root root 26024 Jan 9 2019 more - -rwsr-xr-x 1 root root 34268 Jan 9 2019 mount - -rwxr-xr-x 1 root root 9688 Jan 9 2019 mountpoint - -rwxr-xr-x 1 root root 84284 Feb 28 2019 mv - lrwxrwxrwx 1 root root 8 Sep 26 2018 nisdomainname -> hostname - lrwxrwxrwx 1 root root 14 Feb 14 2019 pidof -> /sbin/killall5 - -rwxr-xr-x 1 root root 22416 Feb 28 2019 pwd - lrwxrwxrwx 1 root root 4 Apr 17 2019 rbash -> bash - -rwxr-xr-x 1 root root 26504 Feb 28 2019 readlink - -rwxr-xr-x 1 root root 42968 Feb 28 2019 rm - -rwxr-xr-x 1 root root 26496 Feb 28 2019 rmdir - -rwxr-xr-x 1 root root 14136 Jan 21 2019 run-parts - -rwxr-xr-x 1 root root 76012 Dec 22 2018 sed - lrwxrwxrwx 1 root root 4 Aug 10 20:25 sh -> dash - -rwxr-xr-x 1 root root 22384 Feb 28 2019 sleep - -rwxr-xr-x 1 root root 51124 Feb 28 2019 stty - -rwsr-xr-x 1 root root 42472 Jan 9 2019 su - -rwxr-xr-x 1 root root 22392 Feb 28 2019 sync - -rwxr-xr-x 1 root root 283324 Apr 23 2019 tar - -rwxr-xr-x 1 root root 9808 Jan 21 2019 tempfile - -rwxr-xr-x 1 root root 63464 Feb 28 2019 touch - -rwxr-xr-x 1 root root 18260 Feb 28 2019 true - -rwxr-xr-x 1 root root 9636 Apr 22 07:38 ulockmgr_server - -rwsr-xr-x 1 root root 21976 Jan 9 2019 umount - -rwxr-xr-x 1 root root 22380 Feb 28 2019 uname - -rwxr-xr-x 2 root root 2345 Jan 5 2019 uncompress - -rwxr-xr-x 1 root root 88444 Feb 28 2019 vdir - -rwxr-xr-x 1 root root 21980 Jan 9 2019 wdctl - -rwxr-xr-x 1 root root 946 Jan 21 2019 which - lrwxrwxrwx 1 root root 8 Sep 26 2018 ypdomainname -> hostname - -rwxr-xr-x 1 root root 1983 Jan 5 2019 zcat - -rwxr-xr-x 1 root root 1677 Jan 5 2019 zcmp - -rwxr-xr-x 1 root root 5879 Jan 5 2019 zdiff - -rwxr-xr-x 1 root root 29 Jan 5 2019 zegrep - -rwxr-xr-x 1 root root 29 Jan 5 2019 zfgrep - -rwxr-xr-x 1 root root 2080 Jan 5 2019 zforce - -rwxr-xr-x 1 root root 7584 Jan 5 2019 zgrep - -rwxr-xr-x 1 root root 2205 Jan 5 2019 zless - -rwxr-xr-x 1 root root 1841 Jan 5 2019 zmore - -rwxr-xr-x 1 root root 4552 Jan 5 2019 znew -I: user script /srv/workspace/pbuilder/30913/tmp/hooks/D02_print_environment finished + -rwxr-xr-x 1 root root 767656 Apr 18 2019 bash + -rwxr-xr-x 3 root root 26052 Jul 11 2019 bunzip2 + -rwxr-xr-x 3 root root 26052 Jul 11 2019 bzcat + lrwxrwxrwx 1 root root 6 Jul 11 2019 bzcmp -> bzdiff + -rwxr-xr-x 1 root root 2227 Jul 11 2019 bzdiff + lrwxrwxrwx 1 root root 6 Jul 11 2019 bzegrep -> bzgrep + -rwxr-xr-x 1 root root 4877 Jun 25 2019 bzexe + lrwxrwxrwx 1 root root 6 Jul 11 2019 bzfgrep -> bzgrep + -rwxr-xr-x 1 root root 3641 Jul 11 2019 bzgrep + -rwxr-xr-x 3 root root 26052 Jul 11 2019 bzip2 + -rwxr-xr-x 1 root root 9636 Jul 11 2019 bzip2recover + lrwxrwxrwx 1 root root 6 Jul 11 2019 bzless -> bzmore + -rwxr-xr-x 1 root root 1297 Jul 11 2019 bzmore + -rwxr-xr-x 1 root root 22432 Mar 1 2019 cat + -rwxr-xr-x 1 root root 38868 Mar 1 2019 chgrp + -rwxr-xr-x 1 root root 38836 Mar 1 2019 chmod + -rwxr-xr-x 1 root root 42972 Mar 1 2019 chown + -rwxr-xr-x 1 root root 88376 Mar 1 2019 cp + -rwxr-xr-x 1 root root 75516 Jan 18 2019 dash + -rwxr-xr-x 1 root root 71648 Mar 1 2019 date + -rwxr-xr-x 1 root root 51212 Mar 1 2019 dd + -rwxr-xr-x 1 root root 55672 Mar 1 2019 df + -rwxr-xr-x 1 root root 88444 Mar 1 2019 dir + -rwxr-xr-x 1 root root 54872 Jan 10 2019 dmesg + lrwxrwxrwx 1 root root 8 Sep 27 2018 dnsdomainname -> hostname + lrwxrwxrwx 1 root root 8 Sep 27 2018 domainname -> hostname + -rwxr-xr-x 1 root root 22364 Mar 1 2019 echo + -rwxr-xr-x 1 root root 28 Jan 8 2019 egrep + -rwxr-xr-x 1 root root 18260 Mar 1 2019 false + -rwxr-xr-x 1 root root 28 Jan 8 2019 fgrep + -rwxr-xr-x 1 root root 47356 Jan 10 2019 findmnt + -rwsr-xr-x 1 root root 21980 Apr 23 09:38 fusermount + -rwxr-xr-x 1 root root 124508 Jan 8 2019 grep + -rwxr-xr-x 2 root root 2345 Jan 6 2019 gunzip + -rwxr-xr-x 1 root root 6375 Jan 6 2019 gzexe + -rwxr-xr-x 1 root root 64232 Jan 6 2019 gzip + -rwxr-xr-x 1 root root 13784 Sep 27 2018 hostname + -rwxr-xr-x 1 root root 43044 Mar 1 2019 ln + -rwxr-xr-x 1 root root 34932 Jul 27 2018 login + -rwxr-xr-x 1 root root 88444 Mar 1 2019 ls + -rwxr-xr-x 1 root root 67036 Jan 10 2019 lsblk + -rwxr-xr-x 1 root root 47168 Mar 1 2019 mkdir + -rwxr-xr-x 1 root root 43040 Mar 1 2019 mknod + -rwxr-xr-x 1 root root 26552 Mar 1 2019 mktemp + -rwxr-xr-x 1 root root 26024 Jan 10 2019 more + -rwsr-xr-x 1 root root 34268 Jan 10 2019 mount + -rwxr-xr-x 1 root root 9688 Jan 10 2019 mountpoint + -rwxr-xr-x 1 root root 84284 Mar 1 2019 mv + lrwxrwxrwx 1 root root 8 Sep 27 2018 nisdomainname -> hostname + lrwxrwxrwx 1 root root 14 Feb 15 2019 pidof -> /sbin/killall5 + -rwxr-xr-x 1 root root 22416 Mar 1 2019 pwd + lrwxrwxrwx 1 root root 4 Apr 18 2019 rbash -> bash + -rwxr-xr-x 1 root root 26504 Mar 1 2019 readlink + -rwxr-xr-x 1 root root 42968 Mar 1 2019 rm + -rwxr-xr-x 1 root root 26496 Mar 1 2019 rmdir + -rwxr-xr-x 1 root root 14136 Jan 22 2019 run-parts + -rwxr-xr-x 1 root root 76012 Dec 23 2018 sed + lrwxrwxrwx 1 root root 4 Aug 13 03:34 sh -> bash + lrwxrwxrwx 1 root root 4 Aug 12 22:27 sh.distrib -> dash + -rwxr-xr-x 1 root root 22384 Mar 1 2019 sleep + -rwxr-xr-x 1 root root 51124 Mar 1 2019 stty + -rwsr-xr-x 1 root root 42472 Jan 10 2019 su + -rwxr-xr-x 1 root root 22392 Mar 1 2019 sync + -rwxr-xr-x 1 root root 283324 Apr 24 2019 tar + -rwxr-xr-x 1 root root 9808 Jan 22 2019 tempfile + -rwxr-xr-x 1 root root 63464 Mar 1 2019 touch + -rwxr-xr-x 1 root root 18260 Mar 1 2019 true + -rwxr-xr-x 1 root root 9636 Apr 23 09:38 ulockmgr_server + -rwsr-xr-x 1 root root 21976 Jan 10 2019 umount + -rwxr-xr-x 1 root root 22380 Mar 1 2019 uname + -rwxr-xr-x 2 root root 2345 Jan 6 2019 uncompress + -rwxr-xr-x 1 root root 88444 Mar 1 2019 vdir + -rwxr-xr-x 1 root root 21980 Jan 10 2019 wdctl + -rwxr-xr-x 1 root root 946 Jan 22 2019 which + lrwxrwxrwx 1 root root 8 Sep 27 2018 ypdomainname -> hostname + -rwxr-xr-x 1 root root 1983 Jan 6 2019 zcat + -rwxr-xr-x 1 root root 1677 Jan 6 2019 zcmp + -rwxr-xr-x 1 root root 5879 Jan 6 2019 zdiff + -rwxr-xr-x 1 root root 29 Jan 6 2019 zegrep + -rwxr-xr-x 1 root root 29 Jan 6 2019 zfgrep + -rwxr-xr-x 1 root root 2080 Jan 6 2019 zforce + -rwxr-xr-x 1 root root 7584 Jan 6 2019 zgrep + -rwxr-xr-x 1 root root 2205 Jan 6 2019 zless + -rwxr-xr-x 1 root root 1841 Jan 6 2019 zmore + -rwxr-xr-x 1 root root 4552 Jan 6 2019 znew +I: user script /srv/workspace/pbuilder/24851/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -357,7 +391,7 @@ Get: 151 http://deb.debian.org/debian buster/main armhf rebar armhf 2.6.4-2 [205 kB] Get: 152 http://deb.debian.org/debian buster/main armhf dh-rebar all 0.0.4 [7298 B] Get: 153 http://deb.debian.org/debian buster/main armhf erlang-goldrush armhf 0.2.0-1 [62.7 kB] -Fetched 90.5 MB in 20s (4441 kB/s) +Fetched 90.5 MB in 10s (9181 kB/s) debconf: delaying package configuration, since apt-utils is not installed Selecting previously unselected package libbsd0:armhf. (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 ... 18932 files and directories currently installed.) @@ -1003,7 +1037,7 @@ fakeroot is already the newest version (1.23-1). 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. I: Building the package -I: Running cd /build/erlang-lager-3.6.8/ && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games" HOME="/nonexistent/first-build" dpkg-buildpackage -us -uc -b +I: Running cd /build/erlang-lager-3.6.8/ && 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 erlang-lager dpkg-buildpackage: info: source version 3.6.8-1 dpkg-buildpackage: info: source distribution unstable @@ -1113,27 +1147,27 @@ Compiled src/lager_transform.erl Compiled src/lager_rotator_behaviour.erl DEBUG: Starting 3 compile worker(s) -Compiled src/lager_handler_watcher_sup.erl -Compiled src/lager_msg.erl -Compiled src/lager_manager_killer.erl Compiled src/lager_rotator_default.erl -Compiled src/lager_common_test_backend.erl +Compiled src/lager_manager_killer.erl +Compiled src/lager_handler_watcher_sup.erl +Compiled src/lager_console_backend.erl +Compiled src/lager_default_formatter.erl Compiled src/lager_config.erl -Compiled src/lager_app.erl -Compiled src/lager_file_backend.erl -Compiled src/lager_backend_throttle.erl Compiled src/lager_handler_watcher.erl -Compiled src/error_logger_lager_h.erl -Compiled src/lager_trunc_io.erl -Compiled src/lager_default_formatter.erl Compiled src/lager_sup.erl -Compiled src/lager_stdlib.erl +Compiled src/lager_trunc_io.erl Compiled src/lager_format.erl +Compiled src/lager.erl +Compiled src/lager_msg.erl +Compiled src/lager_app.erl Compiled src/lager_crash_log.erl +Compiled src/lager_stdlib.erl +Compiled src/lager_common_test_backend.erl +Compiled src/lager_backend_throttle.erl DEBUG: Worker exited cleanly -Compiled src/lager_console_backend.erl +Compiled src/lager_file_backend.erl DEBUG: Worker exited cleanly -Compiled src/lager.erl +Compiled src/error_logger_lager_h.erl DEBUG: Worker exited cleanly INFO: No app_vars_file defined. DEBUG: Postdirs: [] @@ -1145,482 +1179,189 @@ Compiled src/lager_util.erl Compiled src/lager_transform.erl Compiled src/lager_rotator_behaviour.erl -Compiled src/lager_handler_watcher_sup.erl -Compiled src/lager_msg.erl -Compiled src/lager_manager_killer.erl -Compiled src/lager_config.erl Compiled src/lager_rotator_default.erl -Compiled src/lager_common_test_backend.erl -Compiled src/lager_app.erl -Compiled src/error_logger_lager_h.erl -Compiled src/lager_backend_throttle.erl -Compiled src/lager_handler_watcher.erl -Compiled src/lager_file_backend.erl -Compiled src/lager_stdlib.erl -Compiled src/lager_format.erl -Compiled src/lager_sup.erl +Compiled src/lager_manager_killer.erl +Compiled src/lager_handler_watcher_sup.erl src/lager_default_formatter.erl:493: Warning: a term is constructed, but never used src/lager_default_formatter.erl:493: Warning: a term is constructed, but never used Compiled src/lager_default_formatter.erl +Compiled src/lager_handler_watcher.erl +Compiled src/lager_config.erl +Compiled src/lager_console_backend.erl +Compiled src/lager_sup.erl +Compiled src/lager.erl +Compiled src/lager_stdlib.erl +Compiled src/lager_format.erl +Compiled src/lager_msg.erl +Compiled src/lager_app.erl Compiled src/lager_crash_log.erl +Compiled src/error_logger_lager_h.erl +Compiled src/lager_common_test_backend.erl Compiled src/lager_trunc_io.erl -Compiled test/lager_slow_backend.erl -Compiled test/lager_rotate.erl -Compiled src/lager.erl +Compiled src/lager_backend_throttle.erl Compiled test/special_process.erl -Compiled test/lager_manager_killer_test.erl -Compiled test/zzzz_gh280_crash.erl -Compiled test/lager_app_tests.erl -Compiled test/crash_fsm.erl -Compiled test/lager_crash_backend.erl -Compiled src/lager_console_backend.erl -Compiled test/lager_trace_test.erl -Compiled test/compress_pr_record_test.erl -Compiled test/pr_composite_test.erl -test/pr_stacktrace_test.erl:22: Warning: this expression will fail with a 'badarg' exception -test/pr_stacktrace_test.erl:22: Warning: this expression will fail with a 'badarg' exception -Compiled test/pr_stacktrace_test.erl -Compiled test/crash_statem.erl Compiled test/trunc_io_eqc.erl +Compiled test/pr_composite_test.erl +Compiled test/zzzz_gh280_crash.erl Compiled test/sync_error_logger.erl +Compiled test/lager_crash_backend.erl +Compiled test/lager_app_tests.erl +Compiled test/lager_test_function_transform.erl +Compiled test/lager_rotate.erl +Compiled src/lager_file_backend.erl test/crash.erl:27: Warning: invalid function call test/crash.erl:66: Warning: this expression will fail with a 'badarg' exception test/crash.erl:27: Warning: invalid function call test/crash.erl:66: Warning: this expression will fail with a 'badarg' exception Compiled test/crash.erl -Compiled test/lager_test_function_transform.erl +Compiled test/lager_trace_test.erl +Compiled test/lager_slow_backend.erl +test/pr_stacktrace_test.erl:22: Warning: this expression will fail with a 'badarg' exception +test/pr_stacktrace_test.erl:22: Warning: this expression will fail with a 'badarg' exception +Compiled test/pr_stacktrace_test.erl +Compiled test/crash_statem.erl +Compiled test/compress_pr_record_test.erl +Compiled test/crash_fsm.erl +Compiled test/lager_manager_killer_test.erl Compiled test/lager_test_backend.erl ======================== EUnit ======================== -module 'lager_slow_backend' -module 'lager_config' -module 'lager_rotator_default' - lager_rotator_default: rotate_file_test...[0.127 s] ok - lager_rotator_default: rotate_file_zero_count_test...[0.004 s] ok - lager_rotator_default: rotate_file_fail_test...[0.078 s] ok - [done in 0.221 s] -module 'crash' -module 'lager_rotate' - lager_rotate: rotate_test_ (Rotate single file)...[0.211 s] ok - lager_rotate: rotate_test_ (Rotate sink)...[0.119 s] ok - lager_rotate: rotate_test_ (Rotate all)...[0.148 s] ok - [done in 4.519 s] -module 'lager_default_formatter' - lager_default_formatter:232: basic_test_ (Default formatting test)...[0.001 s] ok - lager_default_formatter:241: basic_test_ (Basic Formatting)...ok - lager_default_formatter:250: basic_test_ (Default equivalent formatting test)...[0.001 s] ok - lager_default_formatter:260: basic_test_ (Non existent metadata can default to string)...ok - lager_default_formatter:270: basic_test_ (Non existent metadata can default to other metadata)...ok - lager_default_formatter:280: basic_test_ (Non existent metadata can default to a string2)...ok - lager_default_formatter:290: basic_test_ (Metadata can have extra formatting)...ok - lager_default_formatter:300: basic_test_ (Metadata can have extra formatting1)...ok - lager_default_formatter:310: basic_test_ (Metadata can have extra formatting2)...ok - lager_default_formatter:320: basic_test_ (Metadata can have extra formatting3)...ok - lager_default_formatter:330: basic_test_ (Metadata can be printed in its enterity)...ok - lager_default_formatter:340: basic_test_ (Metadata can be printed in its enterity with custom seperators)...ok - lager_default_formatter:350: basic_test_ (Metadata can have extra formatting with width 1)...ok - lager_default_formatter:364: basic_test_ (Metadata can have extra formatting with width 2)...ok - lager_default_formatter:374: basic_test_ (Metadata can have extra formatting with width 3)...ok - lager_default_formatter:384: basic_test_ (Metadata can have extra formatting with width 4)...ok - lager_default_formatter:394: basic_test_ (Metadata can have extra formatting with width 5)...ok - lager_default_formatter:404: basic_test_ (Metadata can have extra formatting with width 6)...[0.001 s] ok - lager_default_formatter:414: basic_test_ (Uppercase Severity Formatting - DEBUG)...ok - lager_default_formatter:423: basic_test_ (Uppercase Severity Formatting - INFO)...ok - lager_default_formatter:432: basic_test_ (Uppercase Severity Formatting - NOTICE)...ok - lager_default_formatter:441: basic_test_ (Uppercase Severity Formatting - WARNING)...ok - lager_default_formatter:450: basic_test_ (Uppercase Severity Formatting - ERROR)...ok - lager_default_formatter:459: basic_test_ (Uppercase Severity Formatting - CRITICAL)...ok - lager_default_formatter:468: basic_test_ (Uppercase Severity Formatting - ALERT)...ok - lager_default_formatter:477: basic_test_ (Uppercase Severity Formatting - EMERGENCY)...ok - lager_default_formatter:494: basic_test_ (node formatting basic)...ok - [done in 0.115 s] -module 'lager_stdlib' -module 'lager_rotator_behaviour' -module 'crash_statem' -module 'pr_composite_test' - pr_composite_test: nested_record_test...ok - pr_composite_test: list_field_test...ok - pr_composite_test: list_of_records_test...ok - pr_composite_test: improper_list_test...ok - [done in 0.016 s] -module 'lager' +module 'lager_test_function_transform' + lager_test_function_transform: not_running_test...ok + lager_test_function_transform: transform_function_test_ (observe that there is nothing up my sleeve)...[0.001 s] ok + lager_test_function_transform: transform_function_test_ (logging works)...[0.002 s] ok + lager_test_function_transform: transform_function_test_ (Testing calling a function returns the same content on emit)...[0.002 s] ok + lager_test_function_transform: transform_function_test_ (Testing calling a function which returns content which can change on emit)...[0.001 s] ok + lager_test_function_transform: transform_function_test_ (Testing a undefined function returns undefined on emit)...[0.002 s] ok + lager_test_function_transform: transform_function_test_ (Testing calling a function returns the same content on log)...[0.001 s] ok + lager_test_function_transform: transform_function_test_ (Testing calling a dynamic function on log which returns the same value)...[0.003 s] ok + lager_test_function_transform: transform_function_test_ (Testing differences in results for on_log vs on emit from dynamic function)...[0.001 s] ok + lager_test_function_transform: transform_function_test_ (Testing a function provided via metadata)...[0.001 s] ok + [done in 3.102 s] +module 'lager_format' module 'lager_trace_test' - lager_trace_test: trace_test_ (Trace combined with log_root)...[3.648 s] ok - [done in 3.663 s] -module 'lager_manager_killer' -module 'lager_handler_watcher' - lager_handler_watcher: reinstall_on_initial_failure_test_...[6.095 s] ok - lager_handler_watcher: reinstall_on_runtime_failure_test_...[6.182 s] ok - lager_handler_watcher: reinstall_handlers_after_killer_hwm_test_...[6.252 s] ok - [done in 18.550 s] -module 'lager_transform' -module 'lager_backend_throttle' + lager_trace_test: trace_test_ (Trace combined with log_root)...[4.281 s] ok + [done in 4.286 s] +module 'lager' +module 'lager_handler_watcher_sup' +module 'lager_rotator_default' + lager_rotator_default: rotate_file_test...[0.973 s] ok + lager_rotator_default: rotate_file_zero_count_test...[0.008 s] ok + lager_rotator_default: rotate_file_fail_test...[0.269 s] ok + [done in 1.272 s] +module 'crash_fsm' module 'lager_file_backend' - lager_file_backend: get_loglevel_test...ok - lager_file_backend: rotation_test_ (External rotation should work)...[0.004 s] ok - lager_file_backend: rotation_test_ (Internal rotation and delayed write)...[0.129 s] ok - lager_file_backend: filesystem_test_ (under normal circumstances, file should be opened)...[0.096 s] ok - lager_file_backend: filesystem_test_ (don't choke on unicode)...[0.008 s] ok - lager_file_backend: filesystem_test_ (don't choke on latin-1)...[0.008 s] ok - lager_file_backend: filesystem_test_ (file can't be opened on startup triggers an error message)...[0.020 s] ok - lager_file_backend: filesystem_test_ (file that becomes unavailable at runtime should trigger an error message)...[0.015 s] ok - lager_file_backend: filesystem_test_ (unavailable files that are fixed at runtime should start having log messages written)...[0.015 s] ok - lager_file_backend: filesystem_test_ (external logfile rotation/deletion should be handled)...[0.026 s] ok - lager_file_backend: filesystem_test_ (internal size rotation should work)...[0.020 s] ok - lager_file_backend: filesystem_test_ (internal time rotation should work)...[0.137 s] ok - lager_file_backend: filesystem_test_ (rotation call should work)...[0.019 s] ok - lager_file_backend: filesystem_test_ (sync_on option should work)...[0.054 s] ok - lager_file_backend: filesystem_test_ (sync_on none option should work (also tests sync_interval))...[2.057 s] ok - lager_file_backend: filesystem_test_ (sync_size option should work)...[0.024 s] ok - lager_file_backend: filesystem_test_ (runtime level changes)...[0.029 s] ok - lager_file_backend: filesystem_test_ (invalid runtime level changes)...[0.009 s] ok - lager_file_backend: filesystem_test_ (tracing should work)...[1.009 s] ok - lager_file_backend: filesystem_test_ (tracing should not duplicate messages)...[0.652 s] ok - lager_file_backend: filesystem_test_ (tracing to a dedicated file should work)...[0.169 s] ok - lager_file_backend: filesystem_test_ (tracing to a dedicated file should work even if root_log is set)...[0.284 s] ok - lager_file_backend: filesystem_test_ (tracing with options should work)...[0.216 s] ok - lager_file_backend: filesystem_test_ (no silent hwm drops)...[1.563 s] ok - lager_file_backend: trace_files_test_ (a trace using file backend set up in configuration should work)...[1.052 s] ok - lager_file_backend: formatting_test_ (Should have two log files, the second prefixed with 2>)...[0.040 s] ok - lager_file_backend:1097: config_validation_test_ (missing file)...ok + lager_file_backend: get_loglevel_test...[0.001 s] ok + lager_file_backend: rotation_test_ (External rotation should work)...[0.101 s] ok + lager_file_backend: rotation_test_ (Internal rotation and delayed write)...[0.074 s] ok + lager_file_backend: filesystem_test_ (under normal circumstances, file should be opened)...[0.043 s] ok + lager_file_backend: filesystem_test_ (don't choke on unicode)...[0.030 s] ok + lager_file_backend: filesystem_test_ (don't choke on latin-1)...[0.031 s] ok + lager_file_backend: filesystem_test_ (file can't be opened on startup triggers an error message)...[0.127 s] ok + lager_file_backend: filesystem_test_ (file that becomes unavailable at runtime should trigger an error message)...[0.062 s] ok + lager_file_backend: filesystem_test_ (unavailable files that are fixed at runtime should start having log messages written)...[0.101 s] ok + lager_file_backend: filesystem_test_ (external logfile rotation/deletion should be handled)...[0.171 s] ok + lager_file_backend: filesystem_test_ (internal size rotation should work)...[0.107 s] ok + lager_file_backend: filesystem_test_ (internal time rotation should work)...[0.067 s] ok + lager_file_backend: filesystem_test_ (rotation call should work)...[0.116 s] ok + lager_file_backend: filesystem_test_ (sync_on option should work)...[0.083 s] ok + lager_file_backend: filesystem_test_ (sync_on none option should work (also tests sync_interval))...[2.047 s] ok + lager_file_backend: filesystem_test_ (sync_size option should work)...[0.103 s] ok + lager_file_backend: filesystem_test_ (runtime level changes)...[0.163 s] ok + lager_file_backend: filesystem_test_ (invalid runtime level changes)...[0.021 s] ok + lager_file_backend: filesystem_test_ (tracing should work)...[1.152 s] ok + lager_file_backend: filesystem_test_ (tracing should not duplicate messages)...[0.604 s] ok + lager_file_backend: filesystem_test_ (tracing to a dedicated file should work)...[0.253 s] ok + lager_file_backend: filesystem_test_ (tracing to a dedicated file should work even if root_log is set)...[0.242 s] ok + lager_file_backend: filesystem_test_ (tracing with options should work)...[0.281 s] ok + lager_file_backend: filesystem_test_ (no silent hwm drops)...[1.274 s] ok + lager_file_backend: trace_files_test_ (a trace using file backend set up in configuration should work)...[1.115 s] ok + lager_file_backend: formatting_test_ (Should have two log files, the second prefixed with 2>)...[0.021 s] ok + lager_file_backend:1097: config_validation_test_ (missing file)...[0.001 s] ok lager_file_backend:1101: config_validation_test_ (bad level)...ok lager_file_backend:1105: config_validation_test_ (bad size)...ok lager_file_backend:1109: config_validation_test_ (bad count)...ok lager_file_backend:1113: config_validation_test_ (bad high water mark)...ok - lager_file_backend:1117: config_validation_test_ (bad date)...ok - lager_file_backend:1121: config_validation_test_ (blank date is ok)...ok - lager_file_backend:1125: config_validation_test_ (bad sync_interval)...ok - lager_file_backend:1129: config_validation_test_ (bad sync_size)...ok + lager_file_backend:1117: config_validation_test_ (bad date)...[0.001 s] ok + lager_file_backend:1121: config_validation_test_ (blank date is ok)...[0.001 s] ok + lager_file_backend:1125: config_validation_test_ (bad sync_interval)...[0.001 s] ok + lager_file_backend:1129: config_validation_test_ (bad sync_size)...[0.001 s] ok lager_file_backend:1133: config_validation_test_ (bad check_interval)...ok lager_file_backend:1137: config_validation_test_ (bad sync_on level)...ok lager_file_backend:1141: config_validation_test_ (bad formatter module)...ok - lager_file_backend:1145: config_validation_test_ (bad formatter config)...ok + lager_file_backend:1145: config_validation_test_ (bad formatter config)...[0.001 s] ok lager_file_backend:1149: config_validation_test_ (unknown option)...ok - [done in 11.707 s] + [done in 14.636 s] +compress_pr_record_test: nested_record_test (module 'compress_pr_record_test')...[0.001 s] ok module 'lager_crash_log' - lager_crash_log: filesystem_test_ (under normal circumstances, file should be opened)...[0.013 s] ok - lager_crash_log: filesystem_test_ (file can't be opened on startup triggers an error message)...[0.004 s] ok - lager_crash_log: filesystem_test_ (file that becomes unavailable at runtime should trigger an error message)...[0.011 s] ok - lager_crash_log: filesystem_test_ (unavailable files that are fixed at runtime should start having log messages written)...[0.006 s] ok - lager_crash_log: filesystem_test_ (external logfile rotation/deletion should be handled)...[0.008 s] ok - [done in 5.689 s] -module 'sync_error_logger' + lager_crash_log: filesystem_test_ (under normal circumstances, file should be opened)...[0.010 s] ok + lager_crash_log: filesystem_test_ (file can't be opened on startup triggers an error message)...[0.010 s] ok + lager_crash_log: filesystem_test_ (file that becomes unavailable at runtime should trigger an error message)...[0.026 s] ok + lager_crash_log: filesystem_test_ (unavailable files that are fixed at runtime should start having log messages written)...[0.024 s] ok + lager_crash_log: filesystem_test_ (external logfile rotation/deletion should be handled)...[0.043 s] ok + [done in 6.221 s] module 'lager_msg' -module 'lager_test_function_transform' - lager_test_function_transform: not_running_test...ok - lager_test_function_transform: transform_function_test_ (observe that there is nothing up my sleeve)...[0.001 s] ok - lager_test_function_transform: transform_function_test_ (logging works)...[0.001 s] ok - lager_test_function_transform: transform_function_test_ (Testing calling a function returns the same content on emit)...[0.001 s] ok - lager_test_function_transform: transform_function_test_ (Testing calling a function which returns content which can change on emit)...[0.001 s] ok - lager_test_function_transform: transform_function_test_ (Testing a undefined function returns undefined on emit)...[0.001 s] ok - lager_test_function_transform: transform_function_test_ (Testing calling a function returns the same content on log)...ok - lager_test_function_transform: transform_function_test_ (Testing calling a dynamic function on log which returns the same value)...[0.001 s] ok - lager_test_function_transform: transform_function_test_ (Testing differences in results for on_log vs on emit from dynamic function)...[0.001 s] ok - lager_test_function_transform: transform_function_test_ (Testing a function provided via metadata)...[0.001 s] ok - [done in 0.956 s] -module 'lager_common_test_backend' -module 'lager_handler_watcher_sup' -module 'lager_trunc_io' - lager_trunc_io: format_test...[0.002 s] ok - lager_trunc_io: atom_quoting_test...[0.001 s] ok - lager_trunc_io: sane_float_printing_test...[0.001 s] ok - lager_trunc_io: float_inside_list_test...[0.001 s] ok - lager_trunc_io: quote_strip_test...[0.001 s] ok - lager_trunc_io: binary_printing_test...[0.002 s] ok - lager_trunc_io: bitstring_printing_test...[0.001 s] ok - lager_trunc_io: list_printing_test...[0.002 s] ok - lager_trunc_io: iolist_printing_test...[0.001 s] ok - lager_trunc_io: tuple_printing_test...[0.001 s] ok - lager_trunc_io: map_printing_test...[0.002 s] ok - lager_trunc_io: unicode_test...ok - lager_trunc_io: depth_limit_test...[0.010 s] ok - lager_trunc_io: print_terms_without_format_string_test...ok - lager_trunc_io: improper_io_list_test...[0.001 s] ok - [done in 0.103 s] -module 'lager_crash_backend' -module 'pr_stacktrace_test' - pr_stacktrace_test: pr_stacktrace_throw_test...ok - pr_stacktrace_test: pr_stacktrace_bad_arg_test...[0.001 s] ok - pr_stacktrace_test: pr_stacktrace_bad_arity_test...ok - pr_stacktrace_test: pr_stacktrace_no_reverse_test...[0.001 s] ok - [done in 0.019 s] module 'lager_console_backend' lager_console_backend:242: console_config_validation_test_...ok lager_console_backend:243: console_config_validation_test_...ok lager_console_backend:244: console_config_validation_test_...ok lager_console_backend:245: console_config_validation_test_...ok - lager_console_backend: console_log_test_ (regular console logging)...[0.002 s] ok - lager_console_backend: console_log_test_ (verbose console logging)...[0.001 s] ok - lager_console_backend: console_log_test_ (custom format console logging)...[0.001 s] ok - lager_console_backend: console_log_test_ (tracing should work)...[0.595 s] ok - lager_console_backend: console_log_test_ (tracing doesn't duplicate messages)...[1.087 s] ok - lager_console_backend: console_log_test_ (blacklisting a loglevel works)...[0.508 s] ok - lager_console_backend: console_log_test_ (whitelisting a loglevel works)...[0.503 s] ok - lager_console_backend: console_log_test_ (console backend with custom group leader)...[0.607 s] ok - lager_console_backend: console_log_test_ (console backend with custom group leader using a trace and an ID)...[1.197 s] ok - lager_console_backend: set_loglevel_test_ (Get/set loglevel test)...[0.002 s] ok - lager_console_backend: set_loglevel_test_ (Get/set invalid loglevel test)...ok - [done in 5.689 s] -module 'lager_format' -module 'lager_test_backend' - lager_test_backend: not_running_test...ok - lager_test_backend: lager_test_ (observe that there is nothing up my sleeve)...[0.001 s] ok - lager_test_backend: lager_test_ (test sink not running)...ok - lager_test_backend: lager_test_ (logging works)...ok - lager_test_backend: lager_test_ (logging with macro works)...ok - lager_test_backend: lager_test_ (unsafe logging works)...ok - lager_test_backend: lager_test_ (logging with arguments works)...[0.001 s] ok - lager_test_backend: lager_test_ (logging with macro and arguments works)...[0.001 s] ok - lager_test_backend: lager_test_ (unsafe logging with args works)...[0.001 s] ok - lager_test_backend: lager_test_ (logging works from inside a begin/end block)...ok - lager_test_backend: lager_test_ (logging works from inside a list comprehension)...[0.002 s] ok - lager_test_backend: lager_test_ (logging works from a begin/end block inside a list comprehension)...[0.002 s] ok - lager_test_backend: lager_test_ (logging works from a nested list comprehension)...[0.022 s] ok - lager_test_backend: lager_test_ (logging with only metadata works)...[0.001 s] ok - lager_test_backend: lager_test_ (variables inplace of literals in logging statements work)...[0.003 s] ok - lager_test_backend: lager_test_ (list comprehension inplace of literals in logging statements work)...[0.002 s] ok - lager_test_backend: lager_test_ (function calls inplace of literals in logging statements work)...[0.002 s] ok - lager_test_backend: lager_test_ (record fields inplace of literals in logging statements work)...[0.002 s] ok - lager_test_backend: lager_test_ (log messages below the threshold are ignored)...[0.002 s] ok - lager_test_backend: lager_test_ (tracing works)...[0.078 s] ok - lager_test_backend: lager_test_ (tracing works with custom attributes)...[0.241 s] ok - lager_test_backend: lager_test_ (tracing works with custom attributes and event stream processing)...[0.985 s] ok - lager_test_backend: lager_test_ (tracing custom attributes works with event stream processing statistics and reductions)...[0.440 s] ok - lager_test_backend: lager_test_ (persistent traces work)...[0.129 s] ok - lager_test_backend: lager_test_ (tracing honors loglevel)...[0.126 s] ok - lager_test_backend: lager_test_ (stopped trace stops and removes its event handler - default sink (gh#267))...[0.275 s] ok - lager_test_backend: lager_test_ (record printing works)...[0.101 s] ok - lager_test_backend: lager_test_ (record printing fails gracefully)...[0.101 s] ok - lager_test_backend: lager_test_ (record printing fails gracefully when no lager_record attribute)...[0.101 s] ok - lager_test_backend: lager_test_ (record printing fails gracefully when input is not a tuple)...[0.104 s] ok - lager_test_backend: lager_test_ (record printing fails gracefully when module is invalid)...[1.003 s] ok - lager_test_backend: lager_test_ (installing a new handler adjusts the global loglevel if necessary)...[0.001 s] ok - lager_test_backend: lager_test_ (metadata in the process dictionary works)...[0.001 s] ok - lager_test_backend: lager_test_ (unsafe messages really are not truncated)...[0.004 s] ok - lager_test_backend: lager_test_ (can't store invalid metadata)...ok - lager_test_backend: lager_test_ (dates should be local by default)...[0.001 s] ok - lager_test_backend: lager_test_ (dates should be UTC if SASL is configured as UTC)...[0.001 s] ok - lager_test_backend: extra_sinks_test_ (observe that there is nothing up my sleeve)...ok - lager_test_backend: extra_sinks_test_ (logging works)...[0.001 s] ok - lager_test_backend: extra_sinks_test_ (logging with arguments works)...[0.001 s] ok - lager_test_backend: extra_sinks_test_ (variables inplace of literals in logging statements work)...[0.003 s] ok - lager_test_backend: extra_sinks_test_ (stopped trace stops and removes its event handler - test sink (gh#267))...[0.201 s] ok - lager_test_backend: extra_sinks_test_ (log messages below the threshold are ignored)...[0.001 s] ok - FSM crash output tests - Default sink - lager_test_backend: crash_fsm_test_ (again, there is nothing up my sleeve)...[0.001 s] ok - lager_test_backend: crash_fsm_test_ (gen_fsm crash)...test/lager_test_backend.erl:923:<0.3873.0>: Trailing data "8" following "gen_fsm crash_fsm in state state1 terminated with reason: call to undefined function crash_fsm:state1/3 from gen_fsm:handle_msg/" -[0.105 s] ok - lager_test_backend: crash_fsm_test_ (gen_statem crash)...test/lager_test_backend.erl:923:<0.3909.0>: Trailing data "_event({call,{<0.3911.0>,#Ref<0.2933298140.3036938242.71621>}}, boom, state1, undefined)" following "gen_statem crash_statem in state state1 terminated with reason: no function clause matching crash_statem:handle" -[0.101 s] ok - lager_test_backend: crash_fsm_test_ (gen_statem stop)...test/lager_test_backend.erl:923:<0.3945.0>: Trailing data " in gen_statem:loop_event_result/9" following "gen_statem crash_statem in state state1 terminated with reason: explode" -[0.105 s] ok - lager_test_backend: crash_fsm_test_ (gen_statem timeout)...test/lager_test_backend.erl:923:<0.3981.0>: Trailing data " in gen_statem:loop_event_result/9" following "gen_statem crash_statem in state state1 terminated with reason: timeout" -[0.101 s] ok - [done in 1.326 s] - Error logger sink - lager_test_backend: crash_fsm_test_ (again, there is nothing up my sleeve)...[0.001 s] ok - lager_test_backend: crash_fsm_test_ (gen_fsm crash)...test/lager_test_backend.erl:923:<0.4053.0>: Trailing data "8" following "gen_fsm crash_fsm in state state1 terminated with reason: call to undefined function crash_fsm:state1/3 from gen_fsm:handle_msg/" -[0.105 s] ok - lager_test_backend: crash_fsm_test_ (gen_statem crash)...test/lager_test_backend.erl:923:<0.4090.0>: Trailing data "_event({call,{<0.4092.0>,#Ref<0.2933298140.3036938242.72031>}}, boom, state1, undefined)" following "gen_statem crash_statem in state state1 terminated with reason: no function clause matching crash_statem:handle" -[0.101 s] ok - lager_test_backend: crash_fsm_test_ (gen_statem stop)...test/lager_test_backend.erl:923:<0.4127.0>: Trailing data " in gen_statem:loop_event_result/9" following "gen_statem crash_statem in state state1 terminated with reason: explode" -[0.105 s] ok - lager_test_backend: crash_fsm_test_ (gen_statem timeout)...test/lager_test_backend.erl:923:<0.4164.0>: Trailing data " in gen_statem:loop_event_result/9" following "gen_statem crash_statem in state state1 terminated with reason: timeout" -[0.105 s] ok - [done in 1.309 s] - [done in 2.635 s] - Error logger redirect crash - Redirect to default sink - lager_test_backend: error_logger_redirect_crash_test_ (again, there is nothing up my sleeve)...ok - lager_test_backend: error_logger_redirect_crash_test_ (bad return value)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad return value with string)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad return uncaught throw)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (case clause)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (case clause string)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (function clause)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (if clause)...[0.103 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (try clause)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (undefined function)...[0.104 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad math)...[0.102 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad match)...[0.102 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad arity)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad arg1)...[0.103 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad arg2)...[0.106 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad record)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (noproc)...test/lager_test_backend.erl:923:<0.4750.0>: Trailing data " in gen_event:call1/3" following "gen_server crash terminated with reason: no such process or port in call to gen_event:call(foo, bar, baz)" -[0.104 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (noproc_proc_lib)...[0.102 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (badfun)...[0.103 s] ok - [done in 3.312 s] - Redirect to error_logger_lager_event sink - lager_test_backend: error_logger_redirect_crash_test_ (again, there is nothing up my sleeve)...ok - lager_test_backend: error_logger_redirect_crash_test_ (bad return value)...[0.104 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad return value with string)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad return uncaught throw)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (case clause)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (case clause string)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (function clause)...[0.102 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (if clause)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (try clause)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (undefined function)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad math)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad match)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad arity)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad arg1)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad arg2)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (bad record)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (noproc)...test/lager_test_backend.erl:923:<0.5508.0>: Trailing data " in gen_event:call1/3" following "gen_server crash terminated with reason: no such process or port in call to gen_event:call(foo, bar, baz)" -[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (noproc_proc_lib)...[0.101 s] ok - lager_test_backend: error_logger_redirect_crash_test_ (badfun)...[0.101 s] ok - [done in 3.108 s] - [done in 6.420 s] - Error logger redirect - Redirect to default sink - lager_test_backend: error_logger_redirect_test_ (error reports are printed)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (string error reports are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (error messages are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (error messages with unicode characters in Args are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (error messages are truncated at 4096 characters)...[0.023 s] ok - lager_test_backend: error_logger_redirect_test_ (info reports are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (info reports are truncated at 4096 characters)...[0.067 s] ok - lager_test_backend: error_logger_redirect_test_ (single term info reports are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (single term error reports are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (string info reports are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (string info reports are truncated at 4096 characters)...[0.059 s] ok - lager_test_backend: error_logger_redirect_test_ (strings in a mixed report are printed as strings)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (info messages are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (info messages are truncated at 4096 characters)...[0.020 s] ok - lager_test_backend: error_logger_redirect_test_ (info messages with unicode characters in Args are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (warning messages with unicode characters in Args are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (warning messages are printed at the correct level)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (warning reports are printed at the correct level)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (single term warning reports are printed at the correct level)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (application stop reports)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor reports)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor reports with real error)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor reports with real error and pid)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor_bridge reports)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (application progress report)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor progress report)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor progress report with pid)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for emfile)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for system process limit)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for system process limit2)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for system port limit)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for system port limit)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for system ets table limit)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for unknown system limit should be truncated at 500 characters)...[0.009 s] ok - lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - function_clause)...[0.501 s] ok - lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - case_clause)...[0.501 s] ok - lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - exit)...[0.501 s] ok - lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - error)...[0.502 s] ok - lager_test_backend: error_logger_redirect_test_ (webmachine error reports)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 8 arg version)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 10 arg version)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 5 arg version)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 6 arg version)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (messages should not be generated if they don't satisfy the threshold)...[0.002 s] ok - [done in 49.513 s] - Redirect to error_logger_lager_event sink - lager_test_backend: error_logger_redirect_test_ (error reports are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (string error reports are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (error messages are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (error messages with unicode characters in Args are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (error messages are truncated at 4096 characters)...[0.020 s] ok - lager_test_backend: error_logger_redirect_test_ (info reports are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (info reports are truncated at 4096 characters)...[0.047 s] ok - lager_test_backend: error_logger_redirect_test_ (single term info reports are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (single term error reports are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (string info reports are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (string info reports are truncated at 4096 characters)...[0.062 s] ok - lager_test_backend: error_logger_redirect_test_ (strings in a mixed report are printed as strings)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (info messages are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (info messages are truncated at 4096 characters)...[0.028 s] ok - lager_test_backend: error_logger_redirect_test_ (info messages with unicode characters in Args are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (warning messages with unicode characters in Args are printed)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (warning messages are printed at the correct level)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (warning reports are printed at the correct level)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (single term warning reports are printed at the correct level)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (application stop reports)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor reports)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor reports with real error)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor reports with real error and pid)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor_bridge reports)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (application progress report)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor progress report)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (supervisor progress report with pid)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for emfile)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for system process limit)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for system process limit2)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for system port limit)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for system port limit)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for system ets table limit)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (crash report for unknown system limit should be truncated at 500 characters)...[0.004 s] ok - lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - function_clause)...[0.501 s] ok - lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - case_clause)...[0.501 s] ok - lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - exit)...[0.501 s] ok - lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - error)...[0.501 s] ok - lager_test_backend: error_logger_redirect_test_ (webmachine error reports)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 8 arg version)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 10 arg version)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 5 arg version)...[0.001 s] ok - lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 6 arg version)...[0.002 s] ok - lager_test_backend: error_logger_redirect_test_ (messages should not be generated if they don't satisfy the threshold)...[0.002 s] ok - [done in 49.788 s] - [done in 99.301 s] - lager_test_backend: safe_format_test...[0.001 s] ok - lager_test_backend: unsafe_format_test...[0.002 s] ok - lager_test_backend: async_threshold_test_ (async threshold works)...[1.507 s] ok - lager_test_backend: high_watermark_test_ (Nothing dropped when error_logger high watermark is undefined)...[0.603 s] ok - lager_test_backend: high_watermark_test_ (Mostly dropped according to error_logger high watermark)...[1.105 s] ok - lager_test_backend: high_watermark_test_ (Non-notifications are not dropped)...[1.154 s] ok - [done in 156.488 s] -module 'lager_util' - lager_util: parse_test...ok - lager_util: parse_fail_test...ok - lager_util: rotation_calculation_test...ok - lager_util: check_trace_test...=INFO REPORT==== 12-Aug-2020::01:33:04.972826 === - application: lager - exited: stopped - type: permanent -=INFO REPORT==== 12-Aug-2020::01:33:04.975551 === - application: goldrush - exited: stopped - type: permanent -[0.087 s] ok - lager_util:731: is_loggable_test_ (Loggable by severity only)...ok - lager_util:732: is_loggable_test_ (Not loggable by severity only)...ok - lager_util:733: is_loggable_test_ (Loggable by severity with destination)...ok - lager_util:734: is_loggable_test_ (Not loggable by severity with destination)...ok - lager_util:735: is_loggable_test_ (Loggable by destination overriding severity)...ok - lager_util:740: format_time_test_...ok - lager_util:745: format_time_test_...ok - lager_util:750: format_time_test_...ok - lager_util:755: format_time_test_...ok - lager_util:760: format_time_test_...ok - lager_util: config_to_levels_test...ok - lager_util: config_to_mask_test...ok - lager_util: mask_to_levels_test...ok - lager_util: expand_path_test...ok - lager_util:824: sink_name_test_...ok - lager_util:825: sink_name_test_...ok - [done in 0.147 s] -module 'trunc_io_eqc' + lager_console_backend: console_log_test_ (regular console logging)...[0.009 s] ok + lager_console_backend: console_log_test_ (verbose console logging)...[0.003 s] ok + lager_console_backend: console_log_test_ (custom format console logging)...[0.002 s] ok + lager_console_backend: console_log_test_ (tracing should work)...[0.693 s] ok + lager_console_backend: console_log_test_ (tracing doesn't duplicate messages)...[1.217 s] ok + lager_console_backend: console_log_test_ (blacklisting a loglevel works)...[0.507 s] ok + lager_console_backend: console_log_test_ (whitelisting a loglevel works)...[0.510 s] ok + lager_console_backend: console_log_test_ (console backend with custom group leader)...[0.609 s] ok + lager_console_backend: console_log_test_ (console backend with custom group leader using a trace and an ID)...*failed* +in function lager_console_backend:'-console_log_test_/0-fun-76-'/0 (src/lager_console_backend.erl, line 550) +in call from lager_console_backend:'-console_log_test_/0-fun-81-'/1 (src/lager_console_backend.erl, line 550) +in call from eunit_test:run_testfun/1 (eunit_test.erl, line 71) +in call from eunit_proc:run_test/1 (eunit_proc.erl, line 510) +in call from eunit_proc:with_timeout/3 (eunit_proc.erl, line 335) +in call from eunit_proc:handle_test/2 (eunit_proc.erl, line 493) +in call from eunit_proc:tests_inorder/3 (eunit_proc.erl, line 435) +in call from eunit_proc:with_timeout/3 (eunit_proc.erl, line 325) +**error:{assertEqual,[{module,lager_console_backend}, + {line,550}, + {expression,"lager_config : get ( { lager_event , loglevel } )"}, + {expected,{0,[]}}, + {value,{0, + [{{all,[{module,'=',lager_console_backend}]}, + {mask,255}, + {lager_console_backend,trace_test}}]}}]} + output:<<"">> + + lager_console_backend: set_loglevel_test_ (Get/set loglevel test)...[0.016 s] ok + lager_console_backend: set_loglevel_test_ (Get/set invalid loglevel test)...[0.001 s] ok + [done in 6.681 s] +module 'lager_stdlib' +module 'special_process' +zzzz_gh280_crash: gh280_crash_test (module 'zzzz_gh280_crash')...ok +module 'lager_manager_killer' +module 'crash' module 'lager_sup' +module 'trunc_io_eqc' module 'lager_manager_killer_test' - lager_manager_killer_test: overload_test_...=ERROR REPORT==== 12-Aug-2020::01:33:06.066755 === + lager_manager_killer_test: overload_test_...=ERROR REPORT==== 13-Aug-2020::03:40:17.685535 === +calling logger:remove_handler(default) failed: error {badmatch, + {error, + {not_found,default}}} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2099.0>,unlink,<0.2097.0>} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2097.0>,getting_unlinked,<0.2099.0>} +test/lager_manager_killer_test.erl:101:<0.683.0>: Manager <0.2097.0> killed +=ERROR REPORT==== 13-Aug-2020::03:40:18.691473 === ** gen_event handler lager_manager_killer crashed. ** Was installed in lager_event ** Last event was: {log,{lager_msg,[], - [{pid,<0.8911.0>}, + [{pid,<0.2103.0>}, {line,126}, {file,"src/lager_handler_watcher.erl"}, {module,lager_handler_watcher}], debug, - {["2020",45,"08",45,"12"], - ["01",58,"33",58,"05",46,"065"]}, - {1597,239185,65409}, + {["2020",45,"08",45,"13"], + ["03",58,"40",58,"17",46,"687"]}, + {1597,239617,687107}, [76,97,103,101,114,32,105,110,115,116,97, 108,108,101,100,32,104,97,110,100,108,101, 114,32,"error_logger_lager_h",32,105,110, @@ -1628,39 +1369,56 @@ ** When handler state == {state,10,1000} ** Reason == {kill_me,[10,1000]} -test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.8909.0>,unlink,<0.8907.0>} -test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.8907.0>,getting_unlinked,<0.8909.0>} -test/lager_manager_killer_test.erl:101:<0.683.0>: Manager <0.8907.0> killed -=ERROR REPORT==== 12-Aug-2020::01:33:06.068386 === +=ERROR REPORT==== 13-Aug-2020::03:40:18.696418 === Killing sink lager_event, current message_queue_len:11 -=INFO REPORT==== 12-Aug-2020::01:33:07.083596 === +=INFO REPORT==== 13-Aug-2020::03:40:19.730434 === application: lager exited: stopped type: temporary -[2.021 s] ok - lager_manager_killer_test: overload_alternate_sink_test_...test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.8907.0>,unregister,lager_event} -test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.8906.0>,getting_unlinked,<0.8907.0>} -test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.8909.0>,exit,normal} -test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.8906.0>,spawn,<0.8917.0>, +[2.060 s] ok + lager_manager_killer_test: overload_alternate_sink_test_...test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2097.0>,unregister,lager_event} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.65.0>,spawn,<0.2109.0>, + {proc_lib,init_p, + [kernel_safe_sup, + [kernel_sup,<0.46.0>], + gen,init_it, + [gen_server,<0.65.0>,<0.65.0>, + {local,timer_server}, + timer,[],[]]]}} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.65.0>,link,<0.2109.0>} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2109.0>,spawned,<0.65.0>, + {proc_lib,init_p, + [kernel_safe_sup, + [kernel_sup,<0.46.0>], + gen,init_it, + [gen_server,<0.65.0>,<0.65.0>, + {local,timer_server}, + timer,[],[]]]}} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2109.0>,getting_linked,<0.65.0>} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2096.0>,getting_unlinked,<0.2097.0>} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2100.0>,getting_unlinked,<0.2097.0>} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2109.0>,register,timer_server} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2096.0>,spawn,<0.2110.0>, {proc_lib,init_p, [lager_sup, - [<0.8905.0>], + [<0.2095.0>], gen,init_it, - [gen_event,<0.8906.0>,<0.8906.0>, + [gen_event,<0.2096.0>,<0.2096.0>, {local,lager_event}, 'no callback module',[],[]]]}} -test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.8906.0>,link,<0.8917.0>} -test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.8917.0>,spawned,<0.8906.0>, +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2096.0>,link,<0.2110.0>} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2110.0>,spawned,<0.2096.0>, {proc_lib,init_p, [lager_sup, - [<0.8905.0>], + [<0.2095.0>], gen,init_it, - [gen_event,<0.8906.0>,<0.8906.0>, + [gen_event,<0.2096.0>,<0.2096.0>, {local,lager_event}, 'no callback module',[],[]]]}} -test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.8917.0>,getting_linked,<0.8906.0>} -=ERROR REPORT==== 12-Aug-2020::01:33:08.138631 === +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2110.0>,getting_linked,<0.2096.0>} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2125.0>,unlink,<0.2124.0>} +=ERROR REPORT==== 13-Aug-2020::03:40:20.990521 === ** gen_event handler lager_manager_killer crashed. ** Was installed in '__lager_test_sink_lager_event' ** Last event was: {log,{lager_msg,[], @@ -1670,51 +1428,383 @@ {pid,"<0.683.0>"}, {node,nonode@nohost}], info, - {["2020",45,"08",45,"12"], - ["01",58,"33",58,"07",46,"135"]}, - {1597,239187,135692}, + {["2020",45,"08",45,"13"], + ["03",58,"40",58,"19",46,"971"]}, + {1597,239619,971560}, ["1",39,116,104,32,109,101,115,115,97,103, 101]}} ** When handler state == {state,10,1000} ** Reason == {kill_me,[10,1000]} -test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.8932.0>,unlink,<0.8931.0>} -test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.8931.0>,getting_unlinked,<0.8932.0>} -test/lager_manager_killer_test.erl:101:<0.683.0>: Manager <0.8931.0> killed -=ERROR REPORT==== 12-Aug-2020::01:33:08.139934 === +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2124.0>,getting_unlinked,<0.2125.0>} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2125.0>,exit,normal} +test/lager_manager_killer_test.erl:103:<0.683.0>: OTHER MSG: {trace,<0.2121.0>,getting_unlinked,<0.2125.0>} +test/lager_manager_killer_test.erl:101:<0.683.0>: Manager <0.2124.0> killed +=ERROR REPORT==== 13-Aug-2020::03:40:20.995315 === Killing sink '__lager_test_sink_lager_event', current message_queue_len:10 -=INFO REPORT==== 12-Aug-2020::01:33:09.154697 === +=INFO REPORT==== 13-Aug-2020::03:40:22.033115 === application: lager exited: stopped type: temporary -[2.067 s] ok - [done in 4.096 s] -module 'special_process' -error_logger_lager_h: no_silent_hwm_drops_test_ (module 'error_logger_lager_h')...[2.823 s] ok -compress_pr_record_test: nested_record_test (module 'compress_pr_record_test')...[0.001 s] ok -zzzz_gh280_crash: gh280_crash_test (module 'zzzz_gh280_crash')...ok -module 'crash_fsm' +[2.291 s] ok + [done in 4.375 s] +error_logger_lager_h: no_silent_hwm_drops_test_ (module 'error_logger_lager_h')...*failed* +in function lager_handler_watcher:try_backend_pop/3 (src/lager_handler_watcher.erl, line 233) +in call from error_logger_lager_h:'-no_silent_hwm_drops_test_/0-fun-3-'/0 (src/error_logger_lager_h.erl, line 633) +in call from eunit_test:run_testfun/1 (eunit_test.erl, line 71) +in call from eunit_proc:run_test/1 (eunit_proc.erl, line 510) +in call from eunit_proc:with_timeout/3 (eunit_proc.erl, line 335) +in call from eunit_proc:handle_test/2 (eunit_proc.erl, line 493) +in call from eunit_proc:tests_inorder/3 (eunit_proc.erl, line 435) +in call from eunit_proc:with_timeout/3 (eunit_proc.erl, line 325) +**throw:"Not found: lager_error_logger_h dropped 10 messages in the last second that exceeded the limit of 5 messages/sec" + output:<<"">> + +module 'lager_rotate' + lager_rotate: rotate_test_ (Rotate single file)...[0.151 s] ok + lager_rotate: rotate_test_ (Rotate sink)...[0.101 s] ok + lager_rotate: rotate_test_ (Rotate all)...[0.180 s] ok + [done in 3.980 s] +module 'pr_stacktrace_test' + pr_stacktrace_test: pr_stacktrace_throw_test...[0.003 s] ok + pr_stacktrace_test: pr_stacktrace_bad_arg_test...[0.002 s] ok + pr_stacktrace_test: pr_stacktrace_bad_arity_test...[0.001 s] ok + pr_stacktrace_test: pr_stacktrace_no_reverse_test...[0.002 s] ok + [done in 0.022 s] +module 'lager_default_formatter' + lager_default_formatter:232: basic_test_ (Default formatting test)...ok + lager_default_formatter:241: basic_test_ (Basic Formatting)...[0.001 s] ok + lager_default_formatter:250: basic_test_ (Default equivalent formatting test)...ok + lager_default_formatter:260: basic_test_ (Non existent metadata can default to string)...[0.001 s] ok + lager_default_formatter:270: basic_test_ (Non existent metadata can default to other metadata)...ok + lager_default_formatter:280: basic_test_ (Non existent metadata can default to a string2)...ok + lager_default_formatter:290: basic_test_ (Metadata can have extra formatting)...ok + lager_default_formatter:300: basic_test_ (Metadata can have extra formatting1)...[0.001 s] ok + lager_default_formatter:310: basic_test_ (Metadata can have extra formatting2)...ok + lager_default_formatter:320: basic_test_ (Metadata can have extra formatting3)...ok + lager_default_formatter:330: basic_test_ (Metadata can be printed in its enterity)...ok + lager_default_formatter:340: basic_test_ (Metadata can be printed in its enterity with custom seperators)...[0.001 s] ok + lager_default_formatter:350: basic_test_ (Metadata can have extra formatting with width 1)...[0.001 s] ok + lager_default_formatter:364: basic_test_ (Metadata can have extra formatting with width 2)...ok + lager_default_formatter:374: basic_test_ (Metadata can have extra formatting with width 3)...[0.001 s] ok + lager_default_formatter:384: basic_test_ (Metadata can have extra formatting with width 4)...ok + lager_default_formatter:394: basic_test_ (Metadata can have extra formatting with width 5)...ok + lager_default_formatter:404: basic_test_ (Metadata can have extra formatting with width 6)...[0.001 s] ok + lager_default_formatter:414: basic_test_ (Uppercase Severity Formatting - DEBUG)...ok + lager_default_formatter:423: basic_test_ (Uppercase Severity Formatting - INFO)...[0.001 s] ok + lager_default_formatter:432: basic_test_ (Uppercase Severity Formatting - NOTICE)...ok + lager_default_formatter:441: basic_test_ (Uppercase Severity Formatting - WARNING)...[0.001 s] ok + lager_default_formatter:450: basic_test_ (Uppercase Severity Formatting - ERROR)...ok + lager_default_formatter:459: basic_test_ (Uppercase Severity Formatting - CRITICAL)...ok + lager_default_formatter:468: basic_test_ (Uppercase Severity Formatting - ALERT)...ok + lager_default_formatter:477: basic_test_ (Uppercase Severity Formatting - EMERGENCY)...ok + lager_default_formatter:494: basic_test_ (node formatting basic)...ok + [done in 0.099 s] +module 'pr_composite_test' + pr_composite_test: nested_record_test...ok + pr_composite_test: list_field_test...[0.001 s] ok + pr_composite_test: list_of_records_test...ok + pr_composite_test: improper_list_test...ok + [done in 0.023 s] +module 'lager_util' + lager_util: parse_test...ok + lager_util: parse_fail_test...[0.001 s] ok + lager_util: rotation_calculation_test...[0.002 s] ok + lager_util: check_trace_test...=INFO REPORT==== 13-Aug-2020::03:40:28.856690 === + application: lager + exited: stopped + type: permanent +=INFO REPORT==== 13-Aug-2020::03:40:28.870674 === + application: goldrush + exited: stopped + type: permanent +[0.360 s] ok + lager_util:731: is_loggable_test_ (Loggable by severity only)...ok + lager_util:732: is_loggable_test_ (Not loggable by severity only)...ok + lager_util:733: is_loggable_test_ (Loggable by severity with destination)...ok + lager_util:734: is_loggable_test_ (Not loggable by severity with destination)...[0.001 s] ok + lager_util:735: is_loggable_test_ (Loggable by destination overriding severity)...ok + lager_util:740: format_time_test_...ok + lager_util:745: format_time_test_...ok + lager_util:750: format_time_test_...ok + lager_util:755: format_time_test_...ok + lager_util:760: format_time_test_...ok + lager_util: config_to_levels_test...[0.001 s] ok + lager_util: config_to_mask_test...[0.001 s] ok + lager_util: mask_to_levels_test...[0.001 s] ok + lager_util: expand_path_test...[0.001 s] ok + lager_util:824: sink_name_test_...ok + lager_util:825: sink_name_test_...ok + [done in 0.456 s] +module 'lager_trunc_io' + lager_trunc_io: format_test...[0.007 s] ok + lager_trunc_io: atom_quoting_test...[0.002 s] ok + lager_trunc_io: sane_float_printing_test...[0.001 s] ok + lager_trunc_io: float_inside_list_test...[0.001 s] ok + lager_trunc_io: quote_strip_test...[0.001 s] ok + lager_trunc_io: binary_printing_test...[0.008 s] ok + lager_trunc_io: bitstring_printing_test...[0.002 s] ok + lager_trunc_io: list_printing_test...[0.007 s] ok + lager_trunc_io: iolist_printing_test...[0.002 s] ok + lager_trunc_io: tuple_printing_test...[0.003 s] ok + lager_trunc_io: map_printing_test...[0.005 s] ok + lager_trunc_io: unicode_test...ok + lager_trunc_io: depth_limit_test...[0.015 s] ok + lager_trunc_io: print_terms_without_format_string_test...[0.001 s] ok + lager_trunc_io: improper_io_list_test...[0.001 s] ok + [done in 0.101 s] +module 'lager_common_test_backend' +module 'lager_config' +module 'lager_crash_backend' +module 'crash_statem' +module 'lager_rotator_behaviour' module 'lager_app' - lager_app:326: application_config_mangling_test_ (Explode the file backend handlers)...ok + lager_app:326: application_config_mangling_test_ (Explode the file backend handlers)...[0.001 s] ok lager_app:339: application_config_mangling_test_ (Explode the short form of backend file handlers)...ok lager_app:352: application_config_mangling_test_ (Explode with formatter info)...ok lager_app:363: application_config_mangling_test_ (Explode short form with short formatter info)...ok lager_app:374: application_config_mangling_test_ (New form needs no expansion)...ok - lager_app:408: check_handler_config_test_ (lager_file_backend_good)...ok - lager_app:411: check_handler_config_test_ (lager_file_backend_bad)...=ERROR REPORT==== 12-Aug-2020::01:33:12.097726 === + lager_app:408: check_handler_config_test_ (lager_file_backend_good)...[0.001 s] ok +=ERROR REPORT==== 13-Aug-2020::03:40:29.678271 === Cannot have same file ("same_file.log") in multiple file backends -ok + lager_app:411: check_handler_config_test_ (lager_file_backend_bad)...[0.001 s] ok lager_app:414: check_handler_config_test_ (Invalid config dies)...ok - lager_app:417: check_handler_config_test_ (Invalid config dies)...[0.014 s] ok + lager_app:417: check_handler_config_test_ (Invalid config dies)...[0.104 s] ok lager_app:420: check_handler_config_test_ (Old Lager config works)...ok lager_app:423: check_handler_config_test_ (New Config missing its list should fail)...ok lager_app_tests: get_env_test (module 'lager_app_tests')...ok - [done in 0.064 s] + [done in 0.245 s] +module 'sync_error_logger' +module 'lager_test_backend' + lager_test_backend: not_running_test...ok + lager_test_backend: lager_test_ (observe that there is nothing up my sleeve)...ok + lager_test_backend: lager_test_ (test sink not running)...[0.001 s] ok + lager_test_backend: lager_test_ (logging works)...[0.001 s] ok + lager_test_backend: lager_test_ (logging with macro works)...[0.002 s] ok + lager_test_backend: lager_test_ (unsafe logging works)...[0.001 s] ok + lager_test_backend: lager_test_ (logging with arguments works)...[0.001 s] ok + lager_test_backend: lager_test_ (logging with macro and arguments works)...[0.001 s] ok + lager_test_backend: lager_test_ (unsafe logging with args works)...[0.002 s] ok + lager_test_backend: lager_test_ (logging works from inside a begin/end block)...[0.001 s] ok + lager_test_backend: lager_test_ (logging works from inside a list comprehension)...[0.020 s] ok + lager_test_backend: lager_test_ (logging works from a begin/end block inside a list comprehension)...[0.014 s] ok + lager_test_backend: lager_test_ (logging works from a nested list comprehension)...[0.051 s] ok + lager_test_backend: lager_test_ (logging with only metadata works)...[0.001 s] ok + lager_test_backend: lager_test_ (variables inplace of literals in logging statements work)...[0.006 s] ok + lager_test_backend: lager_test_ (list comprehension inplace of literals in logging statements work)...[0.015 s] ok + lager_test_backend: lager_test_ (function calls inplace of literals in logging statements work)...[0.014 s] ok + lager_test_backend: lager_test_ (record fields inplace of literals in logging statements work)...[0.011 s] ok + lager_test_backend: lager_test_ (log messages below the threshold are ignored)...[0.008 s] ok + lager_test_backend: lager_test_ (tracing works)...[0.212 s] ok + lager_test_backend: lager_test_ (tracing works with custom attributes)...[0.723 s] ok + lager_test_backend: lager_test_ (tracing works with custom attributes and event stream processing)...[2.891 s] ok + lager_test_backend: lager_test_ (tracing custom attributes works with event stream processing statistics and reductions)...[1.945 s] ok + lager_test_backend: lager_test_ (persistent traces work)...[0.417 s] ok + lager_test_backend: lager_test_ (tracing honors loglevel)...[0.390 s] ok + lager_test_backend: lager_test_ (stopped trace stops and removes its event handler - default sink (gh#267))...[0.861 s] ok + lager_test_backend: lager_test_ (record printing works)...[0.104 s] ok + lager_test_backend: lager_test_ (record printing fails gracefully)...[0.104 s] ok + lager_test_backend: lager_test_ (record printing fails gracefully when no lager_record attribute)...[0.104 s] ok + lager_test_backend: lager_test_ (record printing fails gracefully when input is not a tuple)...[0.104 s] ok + lager_test_backend: lager_test_ (record printing fails gracefully when module is invalid)...[1.001 s] ok + lager_test_backend: lager_test_ (installing a new handler adjusts the global loglevel if necessary)...[0.001 s] ok + lager_test_backend: lager_test_ (metadata in the process dictionary works)...[0.002 s] ok + lager_test_backend: lager_test_ (unsafe messages really are not truncated)...[0.011 s] ok + lager_test_backend: lager_test_ (can't store invalid metadata)...ok + lager_test_backend: lager_test_ (dates should be local by default)...[0.001 s] ok + lager_test_backend: lager_test_ (dates should be UTC if SASL is configured as UTC)...[0.007 s] ok + lager_test_backend: extra_sinks_test_ (observe that there is nothing up my sleeve)...[0.003 s] ok + lager_test_backend: extra_sinks_test_ (logging works)...[0.001 s] ok + lager_test_backend: extra_sinks_test_ (logging with arguments works)...[0.008 s] ok + lager_test_backend: extra_sinks_test_ (variables inplace of literals in logging statements work)...[0.028 s] ok + lager_test_backend: extra_sinks_test_ (stopped trace stops and removes its event handler - test sink (gh#267))...[0.487 s] ok + lager_test_backend: extra_sinks_test_ (log messages below the threshold are ignored)...[0.012 s] ok + FSM crash output tests + Default sink + lager_test_backend: crash_fsm_test_ (again, there is nothing up my sleeve)...ok + lager_test_backend: crash_fsm_test_ (gen_fsm crash)...test/lager_test_backend.erl:923:<0.3829.0>: Trailing data "8" following "gen_fsm crash_fsm in state state1 terminated with reason: call to undefined function crash_fsm:state1/3 from gen_fsm:handle_msg/" +[0.107 s] ok + lager_test_backend: crash_fsm_test_ (gen_statem crash)...test/lager_test_backend.erl:923:<0.3866.0>: Trailing data "_event({call,{<0.3868.0>,#Ref<0.3870445322.1695809538.231926>}}, boom, state1, undefined)" following "gen_statem crash_statem in state state1 terminated with reason: no function clause matching crash_statem:handle" +[0.105 s] ok + lager_test_backend: crash_fsm_test_ (gen_statem stop)...test/lager_test_backend.erl:923:<0.3903.0>: Trailing data " in gen_statem:loop_event_result/9" following "gen_statem crash_statem in state state1 terminated with reason: explode" +[0.104 s] ok + lager_test_backend: crash_fsm_test_ (gen_statem timeout)...test/lager_test_backend.erl:923:<0.3940.0>: Trailing data " in gen_statem:loop_event_result/9" following "gen_statem crash_statem in state state1 terminated with reason: timeout" +[0.104 s] ok + [done in 2.672 s] + Error logger sink + lager_test_backend: crash_fsm_test_ (again, there is nothing up my sleeve)...ok + lager_test_backend: crash_fsm_test_ (gen_fsm crash)...test/lager_test_backend.erl:923:<0.4014.0>: Trailing data "8" following "gen_fsm crash_fsm in state state1 terminated with reason: call to undefined function crash_fsm:state1/3 from gen_fsm:handle_msg/" +[0.109 s] ok + lager_test_backend: crash_fsm_test_ (gen_statem crash)...test/lager_test_backend.erl:923:<0.4051.0>: Trailing data "_event({call,{<0.4053.0>,#Ref<0.3870445322.1695809537.236503>}}, boom, state1, undefined)" following "gen_statem crash_statem in state state1 terminated with reason: no function clause matching crash_statem:handle" +[0.105 s] ok + lager_test_backend: crash_fsm_test_ (gen_statem stop)...test/lager_test_backend.erl:923:<0.4088.0>: Trailing data " in gen_statem:loop_event_result/9" following "gen_statem crash_statem in state state1 terminated with reason: explode" +[0.104 s] ok + lager_test_backend: crash_fsm_test_ (gen_statem timeout)...test/lager_test_backend.erl:923:<0.4125.0>: Trailing data " in gen_statem:loop_event_result/9" following "gen_statem crash_statem in state state1 terminated with reason: timeout" +[0.118 s] ok + [done in 2.532 s] + [done in 5.204 s] + Error logger redirect crash + Redirect to default sink + lager_test_backend: error_logger_redirect_crash_test_ (again, there is nothing up my sleeve)...[0.001 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad return value)...[0.105 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad return value with string)...[0.102 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad return uncaught throw)...[0.102 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (case clause)...[0.105 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (case clause string)...[0.102 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (function clause)...[0.104 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (if clause)...[0.104 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (try clause)...[0.102 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (undefined function)...[0.106 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad math)...[0.109 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad match)...[0.103 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad arity)...[0.102 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad arg1)...[0.104 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad arg2)...[0.103 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad record)...[0.105 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (noproc)...test/lager_test_backend.erl:923:<0.4727.0>: Trailing data " in gen_event:call1/3" following "gen_server crash terminated with reason: no such process or port in call to gen_event:call(foo, bar, baz)" +[0.104 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (noproc_proc_lib)...[0.102 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (badfun)...[0.103 s] ok + [done in 6.339 s] + Redirect to error_logger_lager_event sink + lager_test_backend: error_logger_redirect_crash_test_ (again, there is nothing up my sleeve)...ok + lager_test_backend: error_logger_redirect_crash_test_ (bad return value)...[0.104 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad return value with string)...[0.105 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad return uncaught throw)...[0.103 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (case clause)...[0.105 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (case clause string)...[0.103 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (function clause)...[0.104 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (if clause)...[0.105 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (try clause)...[0.104 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (undefined function)...[0.103 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad math)...[0.103 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad match)...[0.107 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad arity)...[0.102 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad arg1)...[0.104 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad arg2)...[0.108 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (bad record)...[0.102 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (noproc)...test/lager_test_backend.erl:923:<0.5502.0>: Trailing data " in gen_event:call1/3" following "gen_server crash terminated with reason: no such process or port in call to gen_event:call(foo, bar, baz)" +[0.105 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (noproc_proc_lib)...[0.103 s] ok + lager_test_backend: error_logger_redirect_crash_test_ (badfun)...[0.103 s] ok + [done in 7.033 s] + [done in 13.373 s] + Error logger redirect + Redirect to default sink + lager_test_backend: error_logger_redirect_test_ (error reports are printed)...[0.006 s] ok + lager_test_backend: error_logger_redirect_test_ (string error reports are printed)...[0.003 s] ok + lager_test_backend: error_logger_redirect_test_ (error messages are printed)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (error messages with unicode characters in Args are printed)...[0.001 s] ok + lager_test_backend: error_logger_redirect_test_ (error messages are truncated at 4096 characters)...[0.089 s] ok + lager_test_backend: error_logger_redirect_test_ (info reports are printed)...[0.003 s] ok + lager_test_backend: error_logger_redirect_test_ (info reports are truncated at 4096 characters)...[0.227 s] ok + lager_test_backend: error_logger_redirect_test_ (single term info reports are printed)...[0.001 s] ok + lager_test_backend: error_logger_redirect_test_ (single term error reports are printed)...[0.003 s] ok + lager_test_backend: error_logger_redirect_test_ (string info reports are printed)...[0.003 s] ok + lager_test_backend: error_logger_redirect_test_ (string info reports are truncated at 4096 characters)...[0.467 s] ok + lager_test_backend: error_logger_redirect_test_ (strings in a mixed report are printed as strings)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (info messages are printed)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (info messages are truncated at 4096 characters)...[0.085 s] ok + lager_test_backend: error_logger_redirect_test_ (info messages with unicode characters in Args are printed)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (warning messages with unicode characters in Args are printed)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (warning messages are printed at the correct level)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (warning reports are printed at the correct level)...[0.008 s] ok + lager_test_backend: error_logger_redirect_test_ (single term warning reports are printed at the correct level)...[0.003 s] ok + lager_test_backend: error_logger_redirect_test_ (application stop reports)...[0.007 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor reports)...[0.008 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor reports with real error)...[0.010 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor reports with real error and pid)...[0.009 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor_bridge reports)...[0.013 s] ok + lager_test_backend: error_logger_redirect_test_ (application progress report)...[0.005 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor progress report)...[0.008 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor progress report with pid)...[0.003 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for emfile)...[0.003 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for system process limit)...[0.003 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for system process limit2)...[0.008 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for system port limit)...[0.011 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for system port limit)...[0.008 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for system ets table limit)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for unknown system limit should be truncated at 500 characters)...[0.016 s] ok + lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - function_clause)...[0.505 s] ok + lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - case_clause)...[0.504 s] ok + lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - exit)...[0.507 s] ok + lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - error)...[0.504 s] ok + lager_test_backend: error_logger_redirect_test_ (webmachine error reports)...[0.004 s] ok + lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 8 arg version)...[0.010 s] ok + lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 10 arg version)...[0.006 s] ok + lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 5 arg version)...[0.012 s] ok + lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 6 arg version)...[0.019 s] ok + lager_test_backend: error_logger_redirect_test_ (messages should not be generated if they don't satisfy the threshold)...[0.007 s] ok + [done in 55.843 s] + Redirect to error_logger_lager_event sink + lager_test_backend: error_logger_redirect_test_ (error reports are printed)...[0.003 s] ok + lager_test_backend: error_logger_redirect_test_ (string error reports are printed)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (error messages are printed)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (error messages with unicode characters in Args are printed)...[0.001 s] ok + lager_test_backend: error_logger_redirect_test_ (error messages are truncated at 4096 characters)...[0.072 s] ok + lager_test_backend: error_logger_redirect_test_ (info reports are printed)...[0.012 s] ok + lager_test_backend: error_logger_redirect_test_ (info reports are truncated at 4096 characters)...[0.209 s] ok + lager_test_backend: error_logger_redirect_test_ (single term info reports are printed)...[0.001 s] ok + lager_test_backend: error_logger_redirect_test_ (single term error reports are printed)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (string info reports are printed)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (string info reports are truncated at 4096 characters)...[0.610 s] ok + lager_test_backend: error_logger_redirect_test_ (strings in a mixed report are printed as strings)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (info messages are printed)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (info messages are truncated at 4096 characters)...[0.132 s] ok + lager_test_backend: error_logger_redirect_test_ (info messages with unicode characters in Args are printed)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (warning messages with unicode characters in Args are printed)...[0.010 s] ok + lager_test_backend: error_logger_redirect_test_ (warning messages are printed at the correct level)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (warning reports are printed at the correct level)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (single term warning reports are printed at the correct level)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (application stop reports)...[0.007 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor reports)...[0.009 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor reports with real error)...[0.021 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor reports with real error and pid)...[0.018 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor_bridge reports)...[0.005 s] ok + lager_test_backend: error_logger_redirect_test_ (application progress report)...[0.002 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor progress report)...[0.009 s] ok + lager_test_backend: error_logger_redirect_test_ (supervisor progress report with pid)...[0.009 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for emfile)...[0.003 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for system process limit)...[0.007 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for system process limit2)...[0.012 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for system port limit)...[0.013 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for system port limit)...[0.007 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for system ets table limit)...[0.003 s] ok + lager_test_backend: error_logger_redirect_test_ (crash report for unknown system limit should be truncated at 500 characters)...[0.026 s] ok + lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - function_clause)...[0.503 s] ok + lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - case_clause)...[0.503 s] ok + lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - exit)...[0.506 s] ok + lager_test_backend: error_logger_redirect_test_ (crash reports for 'special processes' should be handled right - error)...[0.504 s] ok + lager_test_backend: error_logger_redirect_test_ (webmachine error reports)...[0.011 s] ok + lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 8 arg version)...[0.029 s] ok + lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 10 arg version)...[0.010 s] ok + lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 5 arg version)...[0.009 s] ok + lager_test_backend: error_logger_redirect_test_ (Cowboy error reports, 6 arg version)...[0.006 s] ok + lager_test_backend: error_logger_redirect_test_ (messages should not be generated if they don't satisfy the threshold)...[0.023 s] ok + [done in 59.384 s] + [done in 115.228 s] + lager_test_backend: safe_format_test...[0.002 s] ok + lager_test_backend: unsafe_format_test...[0.010 s] ok + lager_test_backend: async_threshold_test_ (async threshold works)...[4.839 s] ok + lager_test_backend: high_watermark_test_ (Nothing dropped when error_logger high watermark is undefined)...[0.607 s] ok + lager_test_backend: high_watermark_test_ (Mostly dropped according to error_logger high watermark)...[1.125 s] ok + lager_test_backend: high_watermark_test_ (Non-notifications are not dropped)...[1.170 s] ok + [done in 196.972 s] +module 'lager_transform' +module 'lager_backend_throttle' +module 'lager_handler_watcher' + lager_handler_watcher: reinstall_on_initial_failure_test_...[6.230 s] ok + lager_handler_watcher: reinstall_on_runtime_failure_test_...[6.258 s] ok + lager_handler_watcher: reinstall_handlers_after_killer_hwm_test_...[6.479 s] ok + [done in 18.993 s] +module 'lager_slow_backend' ======================================================= - All 352 tests passed. + Failed: 2. Skipped: 0. Passed: 350. Cover analysis: /build/erlang-lager-3.6.8/.eunit/index.html +ERROR: One or more eunit tests failed. +ERROR: eunit failed while processing /build/erlang-lager-3.6.8: rebar_abort make[1]: Leaving directory '/build/erlang-lager-3.6.8' create-stamp debian/debhelper-build-stamp fakeroot debian/rules binary @@ -1843,12 +1933,14 @@ dpkg-source --after-build . dpkg-buildpackage: info: binary-only upload (no source included) I: copying local configuration +I: user script /srv/workspace/pbuilder/24851/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/24851/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/30913 and its subdirectories -I: Current time: Wed Aug 12 01:33:34 -12 2020 -I: pbuilder-time-stamp: 1597239214 +I: removing directory /srv/workspace/pbuilder/24851 and its subdirectories +I: Current time: Thu Aug 13 03:45:47 +14 2020 +I: pbuilder-time-stamp: 1597239947