Diff of the two buildlogs: -- --- b1/build.log 2024-04-29 12:36:27.278809068 +0000 +++ b2/build.log 2024-04-29 12:40:32.688349249 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Sun Jun 1 06:56:17 -12 2025 -I: pbuilder-time-stamp: 1748804177 +I: Current time: Tue Apr 30 02:36:31 +14 2024 +I: pbuilder-time-stamp: 1714394191 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/trixie-reproducible-base.tgz] I: copying local configuration @@ -26,52 +26,84 @@ dpkg-source: info: unpacking alertmanager-irc-relay_0.4.2-1.debian.tar.xz I: using fakeroot in build. I: Installing the build-deps -I: user script /srv/workspace/pbuilder/1438012/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/2722649/tmp/hooks/D01_modify_environment starting +debug: Running on ionos1-amd64. +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 +'/bin/sh' -> '/bin/bash' +lrwxrwxrwx 1 root root 9 Apr 29 12:36 /bin/sh -> /bin/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/2722649/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/2722649/tmp/hooks/D02_print_environment starting I: set - BUILDDIR='/build/reproducible-path' - BUILDUSERGECOS='first user,first room,first work-phone,first home-phone,first other' - BUILDUSERNAME='pbuilder1' - BUILD_ARCH='amd64' - DEBIAN_FRONTEND='noninteractive' - DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=42 ' - DISTRIBUTION='trixie' - HOME='/root' - HOST_ARCH='amd64' + BASH=/bin/sh + BASHOPTS=checkwinsize:cmdhist:complete_fullquote:extquote:force_fignore:globasciiranges:globskipdots:hostcomplete:interactive_comments:patsub_replacement:progcomp:promptvars:sourcepath + BASH_ALIASES=() + BASH_ARGC=() + BASH_ARGV=() + BASH_CMDS=() + BASH_LINENO=([0]="12" [1]="0") + BASH_LOADABLES_PATH=/usr/local/lib/bash:/usr/lib/bash:/opt/local/lib/bash:/usr/pkg/lib/bash:/opt/pkg/lib/bash:. + BASH_SOURCE=([0]="/tmp/hooks/D02_print_environment" [1]="/tmp/hooks/D02_print_environment") + BASH_VERSINFO=([0]="5" [1]="2" [2]="21" [3]="1" [4]="release" [5]="x86_64-pc-linux-gnu") + BASH_VERSION='5.2.21(1)-release' + BUILDDIR=/build/reproducible-path + BUILDUSERGECOS='second user,second room,second work-phone,second home-phone,second other' + BUILDUSERNAME=pbuilder2 + BUILD_ARCH=amd64 + DEBIAN_FRONTEND=noninteractive + DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=20 ' + DIRSTACK=() + DISTRIBUTION=trixie + EUID=0 + FUNCNAME=([0]="Echo" [1]="main") + GROUPS=() + HOME=/root + HOSTNAME=i-capture-the-hostname + HOSTTYPE=x86_64 + HOST_ARCH=amd64 IFS=' ' - INVOCATION_ID='d978ceb0a2954f2890132682e0096e79' - 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='1438012' - PS1='# ' - PS2='> ' + INVOCATION_ID=cb858806a6524df79acedea0e015c05f + LANG=C + LANGUAGE=et_EE:et + LC_ALL=C + MACHTYPE=x86_64-pc-linux-gnu + MAIL=/var/mail/root + OPTERR=1 + OPTIND=1 + OSTYPE=linux-gnu + PATH=/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/i/capture/the/path + PBCURRENTCOMMANDLINEOPERATION=build + PBUILDER_OPERATION=build + PBUILDER_PKGDATADIR=/usr/share/pbuilder + PBUILDER_PKGLIBDIR=/usr/lib/pbuilder + PBUILDER_SYSCONFDIR=/etc + PIPESTATUS=([0]="0") + POSIXLY_CORRECT=y + PPID=2722649 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/r-b-build.zNT1B5dc/pbuilderrc_AjbI --distribution trixie --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/trixie-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.zNT1B5dc/b1 --logfile b1/build.log alertmanager-irc-relay_0.4.2-1.dsc' - SUDO_GID='111' - SUDO_UID='106' - SUDO_USER='jenkins' - TERM='unknown' - TZ='/usr/share/zoneinfo/Etc/GMT+12' - USER='root' - _='/usr/bin/systemd-run' - http_proxy='http://213.165.73.152:3128' + PWD=/ + SHELL=/bin/bash + SHELLOPTS=braceexpand:errexit:hashall:interactive-comments:posix + SHLVL=3 + SUDO_COMMAND='/usr/bin/timeout -k 24.1h 24h /usr/bin/ionice -c 3 /usr/bin/nice -n 11 /usr/bin/unshare --uts -- /usr/sbin/pbuilder --build --configfile /srv/reproducible-results/rbuild-debian/r-b-build.zNT1B5dc/pbuilderrc_bCGw --distribution trixie --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/trixie-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.zNT1B5dc/b2 --logfile b2/build.log alertmanager-irc-relay_0.4.2-1.dsc' + SUDO_GID=110 + SUDO_UID=105 + SUDO_USER=jenkins + TERM=unknown + TZ=/usr/share/zoneinfo/Etc/GMT-14 + UID=0 + USER=root + _='I: set' + http_proxy=http://46.16.76.132:3128 I: uname -a - Linux ionos15-amd64 6.6.13+bpo-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.6.13-1~bpo12+1 (2024-02-15) x86_64 GNU/Linux + Linux i-capture-the-hostname 6.1.0-20-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.85-1 (2024-04-11) x86_64 GNU/Linux I: ls -l /bin - lrwxrwxrwx 1 root root 7 May 27 17:46 /bin -> usr/bin -I: user script /srv/workspace/pbuilder/1438012/tmp/hooks/D02_print_environment finished + lrwxrwxrwx 1 root root 7 Apr 22 13:10 /bin -> usr/bin +I: user script /srv/workspace/pbuilder/2722649/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -84,7 +116,7 @@ Depends: debhelper (>= 11), dh-golang, dh-exec, golang-any, golang-github-fluffle-goirc-dev (>= 1.1.1+ds-1), golang-github-gorilla-mux-dev, golang-github-prometheus-alertmanager-dev, golang-yaml.v2-dev dpkg-deb: building package 'pbuilder-satisfydepends-dummy' in '/tmp/satisfydepends-aptitude/pbuilder-satisfydepends-dummy.deb'. Selecting previously unselected package pbuilder-satisfydepends-dummy. -(Reading database ... 19725 files and directories currently installed.) +(Reading database ... 19901 files and directories currently installed.) Preparing to unpack .../pbuilder-satisfydepends-dummy.deb ... Unpacking pbuilder-satisfydepends-dummy (0.invalid.0) ... dpkg: pbuilder-satisfydepends-dummy: dependency problems, but configuring anyway as you requested: @@ -473,20 +505,21 @@ Get: 188 http://deb.debian.org/debian trixie/main amd64 golang-gopkg-telebot.v3-dev all 3.2.1-1 [95.0 kB] Get: 189 http://deb.debian.org/debian trixie/main amd64 golang-protobuf-extensions-dev all 1.0.4-2 [29.7 kB] Get: 190 http://deb.debian.org/debian trixie/main amd64 golang-github-prometheus-alertmanager-dev all 0.27.0+ds-2 [1116 kB] -Fetched 140 MB in 4s (31.2 MB/s) +Fetched 140 MB in 4s (32.6 MB/s) debconf: delaying package configuration, since apt-utils is not installed dpkg: libssl3:amd64: dependency problems, but removing anyway as you requested: + libkrb5-3:amd64 depends on libssl3 (>= 3.0.0). coreutils depends on libssl3 (>= 3.0.0). -(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 ... 19725 files and directories currently installed.) +(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 ... 19901 files and directories currently installed.) Removing libssl3:amd64 (3.1.5-1) ... Selecting previously unselected package libssl3t64:amd64. -(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 ... 19712 files and directories currently installed.) +(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 ... 19888 files and directories currently installed.) Preparing to unpack .../libssl3t64_3.2.1-3_amd64.deb ... Unpacking libssl3t64:amd64 (3.2.1-3) ... Setting up libssl3t64:amd64 (3.2.1-3) ... Selecting previously unselected package tzdata. -(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 ... 19727 files and directories currently installed.) +(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 ... 19903 files and directories currently installed.) Preparing to unpack .../000-tzdata_2024a-3_all.deb ... Unpacking tzdata (2024a-3) ... Selecting previously unselected package sensible-utils. @@ -1103,8 +1136,8 @@ Setting up tzdata (2024a-3) ... Current default time zone: 'Etc/UTC' -Local time is now: Sun Jun 1 18:57:51 UTC 2025. -Universal Time is now: Sun Jun 1 18:57:51 UTC 2025. +Local time is now: Mon Apr 29 12:39:07 UTC 2024. +Universal Time is now: Mon Apr 29 12:39:07 UTC 2024. Run 'dpkg-reconfigure tzdata' if you wish to change it. Setting up golang-github-cespare-xxhash-dev (2.1.1-2) ... @@ -1265,7 +1298,11 @@ fakeroot is already the newest version (1.33-1). 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. I: Building the package -I: Running cd /build/reproducible-path/alertmanager-irc-relay-0.4.2/ && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games" HOME="/nonexistent/first-build" dpkg-buildpackage -us -uc -b && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games" HOME="/nonexistent/first-build" dpkg-genchanges -S > ../alertmanager-irc-relay_0.4.2-1_source.changes +I: user script /srv/workspace/pbuilder/2722649/tmp/hooks/A99_set_merged_usr starting +Not re-configuring usrmerge for trixie +I: user script /srv/workspace/pbuilder/2722649/tmp/hooks/A99_set_merged_usr finished +hostname: Name or service not known +I: Running cd /build/reproducible-path/alertmanager-irc-relay-0.4.2/ && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/i/capture/the/path" HOME="/nonexistent/second-build" dpkg-buildpackage -us -uc -b && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/i/capture/the/path" HOME="/nonexistent/second-build" dpkg-genchanges -S > ../alertmanager-irc-relay_0.4.2-1_source.changes dpkg-buildpackage: info: source package alertmanager-irc-relay dpkg-buildpackage: info: source version 0.4.2-1 dpkg-buildpackage: info: source distribution unstable @@ -1283,208 +1320,208 @@ dh_autoreconf -O--buildsystem=golang dh_auto_configure -O--buildsystem=golang dh_auto_build -O--buildsystem=golang - cd obj-x86_64-linux-gnu && go install -trimpath -v -p 42 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging -internal/unsafeheader -internal/godebugs -internal/goos -internal/itoa -internal/coverage/rtcov + cd obj-x86_64-linux-gnu && go install -trimpath -v -p 20 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging +internal/race +crypto/internal/alias +math/bits internal/goarch +internal/godebugs internal/goexperiment +internal/itoa +cmp +internal/goos +sync/atomic +unicode +crypto/subtle container/list -math/bits -crypto/internal/alias unicode/utf8 -cmp +internal/unsafeheader +internal/coverage/rtcov +internal/cpu +runtime/internal/syscall +runtime/internal/atomic +crypto/internal/boring/sig unicode/utf16 +vendor/golang.org/x/crypto/cryptobyte/asn1 +internal/abi +internal/chacha8rand +runtime/internal/math internal/nettrace vendor/golang.org/x/crypto/internal/alias -vendor/golang.org/x/crypto/cryptobyte/asn1 +runtime/internal/sys encoding github.com/fluffle/goirc/logging log/internal -crypto/subtle google.golang.org/protobuf/internal/flags -sync/atomic -internal/race -runtime/internal/syscall -unicode -runtime/internal/atomic -crypto/internal/boring/sig -internal/cpu -runtime/internal/math -runtime/internal/sys -internal/abi -internal/chacha8rand google.golang.org/protobuf/internal/set slices internal/bytealg math runtime +internal/reflectlite runtime/metrics sync -internal/reflectlite internal/testlog -internal/singleflight internal/bisect +internal/singleflight google.golang.org/protobuf/internal/pragma runtime/cgo internal/godebug -sort errors -io +sort internal/oserror -strconv +io +math/rand path +internal/intern +strconv crypto/internal/nistec/fiat internal/safefilepath -math/rand vendor/golang.org/x/net/dns/dnsmessage -internal/intern syscall -bytes -hash -crypto/internal/randutil github.com/beorn7/perks/quantile golang.org/x/text/internal/tag +hash +bytes strings -hash/crc32 +crypto/internal/randutil hash/fnv +hash/crc32 +crypto crypto/rc4 -reflect net/netip -crypto +reflect vendor/golang.org/x/text/transform golang.org/x/text/transform +bufio net/http/internal/ascii github.com/prometheus/common/internal/bitbucket.org/ww/goautoneg -bufio regexp/syntax html -internal/syscall/unix -internal/syscall/execenv -time regexp +time +internal/syscall/execenv +internal/syscall/unix context io/fs internal/poll -encoding/binary internal/fmtsort +encoding/binary embed google.golang.org/protobuf/internal/editiondefaults -os crypto/cipher -crypto/internal/edwards25519/field -crypto/internal/nistec crypto/md5 encoding/base64 -vendor/golang.org/x/crypto/internal/poly1305 +os +crypto/internal/edwards25519/field +crypto/internal/nistec github.com/cespare/xxhash +vendor/golang.org/x/crypto/internal/poly1305 golang.org/x/sys/unix encoding/pem crypto/internal/edwards25519 crypto/internal/boring crypto/des vendor/golang.org/x/crypto/chacha20 -crypto/hmac -crypto/sha1 crypto/aes crypto/sha512 +crypto/hmac +crypto/sha1 crypto/sha256 vendor/golang.org/x/crypto/hkdf +fmt path/filepath -vendor/golang.org/x/sys/cpu +google.golang.org/protobuf/internal/detrand io/ioutil github.com/prometheus/procfs/internal/util -google.golang.org/protobuf/internal/detrand +vendor/golang.org/x/sys/cpu os/signal -fmt net crypto/ecdh vendor/golang.org/x/crypto/chacha20poly1305 +math/big +log encoding/hex +net/url +flag +github.com/golang/mock/gomock encoding/json +net/http/internal +mime/quotedprintable vendor/golang.org/x/net/http2/hpack -math/big +github.com/go-logfmt/logfmt google.golang.org/protobuf/internal/errors -google.golang.org/protobuf/internal/version -github.com/prometheus/procfs/internal/fs +mime go/token -golang.org/x/text/internal/language +google.golang.org/protobuf/internal/version vendor/golang.org/x/text/unicode/norm -golang.org/x/text/unicode/norm -flag -log -github.com/golang/mock/gomock compress/flate -github.com/go-logfmt/logfmt -net/http/internal -text/template/parse runtime/debug -net/url -mime/quotedprintable -mime -gopkg.in/yaml.v2 -google.golang.org/protobuf/encoding/protowire -google.golang.org/protobuf/reflect/protoreflect +github.com/prometheus/procfs/internal/fs vendor/golang.org/x/text/unicode/bidi +golang.org/x/text/internal/language +text/template/parse +google.golang.org/protobuf/encoding/protowire +gopkg.in/yaml.v2 +golang.org/x/text/unicode/norm github.com/google/alertmanager-irc-relay/logging -github.com/fluffle/goirc/state +google.golang.org/protobuf/reflect/protoreflect compress/gzip -google.golang.org/protobuf/internal/descfmt -google.golang.org/protobuf/internal/strs -google.golang.org/protobuf/internal/encoding/messageset -google.golang.org/protobuf/internal/genid -google.golang.org/protobuf/internal/order -google.golang.org/protobuf/internal/descopts -google.golang.org/protobuf/runtime/protoiface -text/template -golang.org/x/text/internal/language/compact -google.golang.org/protobuf/internal/encoding/text -google.golang.org/protobuf/reflect/protoregistry +github.com/fluffle/goirc/state vendor/golang.org/x/text/secure/bidirule -golang.org/x/text/language -github.com/go-kit/log -google.golang.org/protobuf/proto vendor/golang.org/x/net/idna -google.golang.org/protobuf/internal/encoding/defval -github.com/go-kit/log/level -github.com/prometheus/alertmanager/featurecontrol -crypto/rand -encoding/asn1 -crypto/dsa +github.com/go-kit/log +crypto/elliptic crypto/internal/bigmod crypto/internal/boring/bbig -crypto/elliptic -google.golang.org/protobuf/encoding/prototext -google.golang.org/protobuf/encoding/protodelim -google.golang.org/protobuf/internal/filedesc -golang.org/x/text/internal -golang.org/x/text/cases +encoding/asn1 +crypto/rand +crypto/dsa +golang.org/x/text/internal/language/compact crypto/ed25519 +github.com/go-kit/log/level +golang.org/x/text/language +text/template crypto/rsa -html/template -crypto/x509/pkix +github.com/prometheus/alertmanager/featurecontrol +google.golang.org/protobuf/internal/descfmt +google.golang.org/protobuf/internal/descopts +google.golang.org/protobuf/internal/encoding/messageset +google.golang.org/protobuf/runtime/protoiface +google.golang.org/protobuf/internal/order +google.golang.org/protobuf/internal/strs +google.golang.org/protobuf/internal/genid +google.golang.org/protobuf/reflect/protoregistry +google.golang.org/protobuf/internal/encoding/text vendor/golang.org/x/crypto/cryptobyte +crypto/x509/pkix +golang.org/x/text/internal +google.golang.org/protobuf/proto +golang.org/x/text/cases crypto/ecdsa +google.golang.org/protobuf/internal/encoding/defval +html/template +google.golang.org/protobuf/internal/filedesc +google.golang.org/protobuf/encoding/protodelim +google.golang.org/protobuf/encoding/prototext google.golang.org/protobuf/internal/encoding/tag google.golang.org/protobuf/internal/impl -crypto/x509 golang.org/x/net/internal/socks vendor/golang.org/x/net/http/httpproxy net/textproto +crypto/x509 +google.golang.org/protobuf/internal/filetype github.com/prometheus/procfs golang.org/x/net/proxy +google.golang.org/protobuf/runtime/protoimpl vendor/golang.org/x/net/http/httpguts mime/multipart -google.golang.org/protobuf/internal/filetype -google.golang.org/protobuf/runtime/protoimpl google.golang.org/protobuf/types/known/timestamppb github.com/prometheus/client_model/go github.com/prometheus/common/model -crypto/tls github.com/prometheus/alertmanager/pkg/labels github.com/prometheus/client_golang/prometheus/internal +crypto/tls github.com/prometheus/alertmanager/matchers/parse github.com/prometheus/alertmanager/matchers/compat net/http/httptrace @@ -1500,17 +1537,17 @@ github.com/prometheus/alertmanager/template github.com/google/alertmanager-irc-relay dh_auto_test -O--buildsystem=golang - cd obj-x86_64-linux-gnu && go test -vet=off -v -p 42 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging + cd obj-x86_64-linux-gnu && go test -vet=off -v -p 20 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging ? github.com/google/alertmanager-irc-relay/logging [no test files] === RUN TestBackoffIncreasesAndReachesMax --- PASS: TestBackoffIncreasesAndReachesMax (0.00s) === RUN TestBackoffReset --- PASS: TestBackoffReset (0.00s) === RUN TestBackoffDelayContext -2025/06/01 06:58:59.176721 backoff.go:111: INFO Backoff for 0s starts -2025/06/01 06:58:59.181475 backoff.go:114: INFO Backoff for 0s ends -2025/06/01 06:58:59.181486 backoff.go:111: INFO Backoff for 2ms starts -2025/06/01 06:58:59.181492 backoff.go:116: INFO Backoff for 2ms canceled by context +2024/04/30 02:40:11.694778 backoff.go:111: INFO Backoff for 0s starts +2024/04/30 02:40:11.694953 backoff.go:114: INFO Backoff for 0s ends +2024/04/30 02:40:11.694964 backoff.go:111: INFO Backoff for 2ms starts +2024/04/30 02:40:11.694984 backoff.go:116: INFO Backoff for 2ms canceled by context --- PASS: TestBackoffDelayContext (0.00s) === RUN TestNoConfig --- PASS: TestNoConfig (0.00s) @@ -1529,10 +1566,10 @@ === RUN TestGivenTemplateNotOverwritten --- PASS: TestGivenTemplateNotOverwritten (0.00s) === RUN TestTemplateErrorsCreateRawAlertMsg -2025/06/01 06:58:59.183902 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at : nil is not a command): {"status":"resolved","labels":{"alertname":"airDown","instance":"instance1:3456","job":"air","service":"prometheus","severity":"ticket","zone":"global"},"annotations":{"DESCRIPTION":"service /prometheus has irc gateway down on instance1","SUMMARY":"service /prometheus air down on instance1"},"startsAt":"2017-05-15T13:49:37.834Z","endsAt":"2017-05-15T13:50:37.835Z","generatorURL":"https://prometheus.example.com/prometheus/...","fingerprint":"66214a361160fb6f"} -2025/06/01 06:58:59.183920 format.go:61: WARN Sending raw alert -2025/06/01 06:58:59.183951 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at : nil is not a command): {"status":"resolved","labels":{"alertname":"airDown","instance":"instance2:7890","job":"air","service":"prometheus","severity":"ticket","zone":"global"},"annotations":{"DESCRIPTION":"service /prometheus has irc gateway down on instance2","SUMMARY":"service /prometheus air down on instance2"},"startsAt":"2017-05-15T11:47:37.834Z","endsAt":"2017-05-15T11:48:37.834Z","generatorURL":"https://prometheus.example.com/prometheus/...","fingerprint":"25a874c99325d1ce"} -2025/06/01 06:58:59.183960 format.go:61: WARN Sending raw alert +2024/04/30 02:40:11.699492 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at : nil is not a command): {"status":"resolved","labels":{"alertname":"airDown","instance":"instance1:3456","job":"air","service":"prometheus","severity":"ticket","zone":"global"},"annotations":{"DESCRIPTION":"service /prometheus has irc gateway down on instance1","SUMMARY":"service /prometheus air down on instance1"},"startsAt":"2017-05-15T13:49:37.834Z","endsAt":"2017-05-15T13:50:37.835Z","generatorURL":"https://prometheus.example.com/prometheus/...","fingerprint":"66214a361160fb6f"} +2024/04/30 02:40:11.699519 format.go:61: WARN Sending raw alert +2024/04/30 02:40:11.699605 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at : nil is not a command): {"status":"resolved","labels":{"alertname":"airDown","instance":"instance2:7890","job":"air","service":"prometheus","severity":"ticket","zone":"global"},"annotations":{"DESCRIPTION":"service /prometheus has irc gateway down on instance2","SUMMARY":"service /prometheus air down on instance2"},"startsAt":"2017-05-15T11:47:37.834Z","endsAt":"2017-05-15T11:48:37.834Z","generatorURL":"https://prometheus.example.com/prometheus/...","fingerprint":"25a874c99325d1ce"} +2024/04/30 02:40:11.699629 format.go:61: WARN Sending raw alert --- PASS: TestTemplateErrorsCreateRawAlertMsg (0.00s) === RUN TestAlertsDispatchedOnce --- PASS: TestAlertsDispatchedOnce (0.00s) @@ -1541,485 +1578,481 @@ === RUN TestUrlFunctions --- PASS: TestUrlFunctions (0.00s) === RUN TestAlertsDispatched -2025/06/01 06:58:59.184588 http.go:132: INFO Starting HTTP server +2024/04/30 02:40:11.700922 http.go:132: INFO Starting HTTP server --- PASS: TestAlertsDispatched (0.00s) === RUN TestRootReturnsError -2025/06/01 06:58:59.184920 http.go:132: INFO Starting HTTP server +2024/04/30 02:40:11.701589 http.go:132: INFO Starting HTTP server --- PASS: TestRootReturnsError (0.00s) === RUN TestInvalidDataReturnsError -2025/06/01 06:58:59.185118 http.go:132: INFO Starting HTTP server -2025/06/01 06:58:59.185160 http.go:96: ERROR Could not decode request body (invalid character '}' looking for beginning of object key string): {"this is not": "a valid alert",} +2024/04/30 02:40:11.701982 http.go:132: INFO Starting HTTP server +2024/04/30 02:40:11.702107 http.go:96: ERROR Could not decode request body (invalid character '}' looking for beginning of object key string): {"this is not": "a valid alert",} --- PASS: TestInvalidDataReturnsError (0.00s) === RUN TestServerPassword -2025/06/01 06:58:59.185541 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37987 -2025/06/01 06:58:59.185637 irc.go:300: INFO Connecting to IRC 127.0.0.1:37987 -2025/06/01 06:58:59.185659 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.185675 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37987. -2025/06/01 06:58:59.185945 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:45376 -2025/06/01 06:58:59.186009 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.186087 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret -2025/06/01 06:58:59.186117 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping -2025/06/01 06:58:59.186127 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.186135 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.186140 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.186244 irc.go:144: INFO Session established -2025/06/01 06:58:59.186275 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.186286 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.186296 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.186340 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.186363 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.186383 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.186413 irc.go:294: INFO IRC routine asked to terminate -2025/06/01 06:58:59.186425 irc.go:269: INFO IRC client connected, quitting -2025/06/01 06:58:59.186433 irc.go:272: INFO Wait for IRC disconnect to complete -2025/06/01 06:58:59.186471 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.186493 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.186541 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.186620 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.186646 irc.go:280: INFO IRC shutdown complete -2025/06/01 06:58:59.186668 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.702832 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:35925 +2024/04/30 02:40:11.703029 irc.go:300: INFO Connecting to IRC 127.0.0.1:35925 +2024/04/30 02:40:11.703060 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.703108 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:35925. +2024/04/30 02:40:11.703601 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/30 02:40:11.703585 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:53006 +2024/04/30 02:40:11.704769 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret +2024/04/30 02:40:11.704877 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping +2024/04/30 02:40:11.704901 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.704914 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.704930 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.705500 irc.go:144: INFO Session established +2024/04/30 02:40:11.705617 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.705672 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.705699 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.705844 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.705993 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.706017 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.706098 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/04/30 02:40:11.706113 irc.go:294: INFO IRC routine asked to terminate +2024/04/30 02:40:11.706153 irc.go:269: INFO IRC client connected, quitting +2024/04/30 02:40:11.706180 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/30 02:40:11.706325 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.706363 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.706443 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.706606 irc.go:150: INFO Disconnected from IRC +2024/04/30 02:40:11.706671 irc.go:280: INFO IRC shutdown complete +2024/04/30 02:40:11.706792 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestServerPassword (0.00s) === RUN TestSendAlertOnPreJoinedChannel -2025/06/01 06:58:59.186767 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36431 -2025/06/01 06:58:59.186799 irc.go:300: INFO Connecting to IRC 127.0.0.1:36431 -2025/06/01 06:58:59.186813 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.186821 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36431. -2025/06/01 06:58:59.186956 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:37230 -2025/06/01 06:58:59.186961 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.187019 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.186409 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2025/06/01 06:58:59.187035 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.187043 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.187114 irc.go:144: INFO Session established -2025/06/01 06:58:59.187139 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.187153 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.187162 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.187196 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.187209 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.187225 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.187274 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.187286 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.187320 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2025/06/01 06:58:59.187333 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message -2025/06/01 06:58:59.187357 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2025/06/01 06:58:59.187367 irc.go:294: INFO IRC routine asked to terminate -2025/06/01 06:58:59.187374 irc.go:269: INFO IRC client connected, quitting -2025/06/01 06:58:59.187381 irc.go:272: INFO Wait for IRC disconnect to complete -2025/06/01 06:58:59.187423 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.187441 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.187479 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.187539 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.187560 irc.go:280: INFO IRC shutdown complete -2025/06/01 06:58:59.187577 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.707146 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34475 +2024/04/30 02:40:11.707341 irc.go:300: INFO Connecting to IRC 127.0.0.1:34475 +2024/04/30 02:40:11.707372 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.707433 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34475. +2024/04/30 02:40:11.707813 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:58834 +2024/04/30 02:40:11.707867 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/30 02:40:11.708064 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.708116 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.708134 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.708310 irc.go:144: INFO Session established +2024/04/30 02:40:11.708455 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.708540 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.708570 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.708670 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.708695 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.708705 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.708800 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.708825 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.708888 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/30 02:40:11.708997 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message +2024/04/30 02:40:11.709056 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/30 02:40:11.709065 irc.go:294: INFO IRC routine asked to terminate +2024/04/30 02:40:11.709082 irc.go:269: INFO IRC client connected, quitting +2024/04/30 02:40:11.709096 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/30 02:40:11.709206 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.709241 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.709313 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.709426 irc.go:150: INFO Disconnected from IRC +2024/04/30 02:40:11.709462 irc.go:280: INFO IRC shutdown complete +2024/04/30 02:40:11.709500 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertOnPreJoinedChannel (0.00s) === RUN TestUsePrivmsgToSendAlertOnPreJoinedChannel -2025/06/01 06:58:59.187663 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33377 -2025/06/01 06:58:59.187694 irc.go:300: INFO Connecting to IRC 127.0.0.1:33377 -2025/06/01 06:58:59.187708 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.187718 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33377. -2025/06/01 06:58:59.187853 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:52264 -2025/06/01 06:58:59.187879 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.187890 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.187900 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.187853 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.187946 irc.go:144: INFO Session established -2025/06/01 06:58:59.187973 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.187984 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.187992 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.188023 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.188037 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.188053 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.188099 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.188113 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.188144 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2025/06/01 06:58:59.188155 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message -2025/06/01 06:58:59.188172 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2025/06/01 06:58:59.188183 irc.go:294: INFO IRC routine asked to terminate -2025/06/01 06:58:59.188189 irc.go:269: INFO IRC client connected, quitting -2025/06/01 06:58:59.188195 irc.go:272: INFO Wait for IRC disconnect to complete -2025/06/01 06:58:59.188234 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.188251 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.188296 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.188340 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.188361 irc.go:280: INFO IRC shutdown complete -2025/06/01 06:58:59.188379 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.709691 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41115 +2024/04/30 02:40:11.709755 irc.go:300: INFO Connecting to IRC 127.0.0.1:41115 +2024/04/30 02:40:11.709779 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.709802 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41115. +2024/04/30 02:40:11.710077 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/30 02:40:11.710102 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:38102 +2024/04/30 02:40:11.710197 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.710241 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.710256 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.710532 irc.go:144: INFO Session established +2024/04/30 02:40:11.710607 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.710638 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.710658 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.710790 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.710845 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.710858 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.710983 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.711003 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.711033 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/30 02:40:11.711073 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message +2024/04/30 02:40:11.711122 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/30 02:40:11.711132 irc.go:294: INFO IRC routine asked to terminate +2024/04/30 02:40:11.711146 irc.go:269: INFO IRC client connected, quitting +2024/04/30 02:40:11.711168 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/30 02:40:11.711260 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.711301 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.711407 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.711598 irc.go:150: INFO Disconnected from IRC +2024/04/30 02:40:11.711628 irc.go:280: INFO IRC shutdown complete +2024/04/30 02:40:11.711665 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestUsePrivmsgToSendAlertOnPreJoinedChannel (0.00s) === RUN TestSendAlertAndJoinChannel -2025/06/01 06:58:59.188463 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:44753 -2025/06/01 06:58:59.188490 irc.go:300: INFO Connecting to IRC 127.0.0.1:44753 -2025/06/01 06:58:59.188500 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.188509 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:44753. -2025/06/01 06:58:59.188620 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:46284 -2025/06/01 06:58:59.188663 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.188722 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.188733 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.188738 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.188783 irc.go:144: INFO Session established -2025/06/01 06:58:59.188805 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.188814 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.188821 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.188856 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.188866 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.188871 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.188890 reconciler.go:245: INFO Request to JOIN new channel #foobar -2025/06/01 06:58:59.188899 reconciler.go:103: INFO Channel #foobar monitor: waiting to join -2025/06/01 06:58:59.188909 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.188916 reconciler.go:112: INFO Channel #foobar monitor: join request sent -2025/06/01 06:58:59.188955 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar -2025/06/01 06:58:59.188965 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.188970 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar -2025/06/01 06:58:59.188976 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.188985 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.188995 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2025/06/01 06:58:59.189007 reconciler.go:201: INFO Received JOIN confirmation for channel #foobar -2025/06/01 06:58:59.189015 reconciler.go:77: INFO Setting JOIN state on channel #foobar -2025/06/01 06:58:59.189025 reconciler.go:116: INFO Channel #foobar monitor: join succeeded -2025/06/01 06:58:59.189060 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message -2025/06/01 06:58:59.189075 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2025/06/01 06:58:59.189081 irc.go:294: INFO IRC routine asked to terminate -2025/06/01 06:58:59.189086 irc.go:269: INFO IRC client connected, quitting -2025/06/01 06:58:59.189092 irc.go:272: INFO Wait for IRC disconnect to complete -2025/06/01 06:58:59.189116 reconciler.go:129: INFO Channel #foobar monitor: context canceled while monitoring -2025/06/01 06:58:59.189134 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.189144 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.189184 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.189239 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.189256 irc.go:280: INFO IRC shutdown complete -2025/06/01 06:58:59.189272 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.711928 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43847 +2024/04/30 02:40:11.712015 irc.go:300: INFO Connecting to IRC 127.0.0.1:43847 +2024/04/30 02:40:11.712037 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.712127 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43847. +2024/04/30 02:40:11.712395 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:37166 +2024/04/30 02:40:11.712599 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/30 02:40:11.712692 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.712735 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.712740 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.712899 irc.go:144: INFO Session established +2024/04/30 02:40:11.712966 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.713002 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.713032 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.713128 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.713152 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.713161 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.713229 reconciler.go:245: INFO Request to JOIN new channel #foobar +2024/04/30 02:40:11.713262 reconciler.go:103: INFO Channel #foobar monitor: waiting to join +2024/04/30 02:40:11.713280 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.713295 reconciler.go:112: INFO Channel #foobar monitor: join request sent +2024/04/30 02:40:11.713304 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.713326 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.713366 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/30 02:40:11.713389 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar +2024/04/30 02:40:11.713478 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.713505 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar +2024/04/30 02:40:11.713723 reconciler.go:201: INFO Received JOIN confirmation for channel #foobar +2024/04/30 02:40:11.713751 reconciler.go:77: INFO Setting JOIN state on channel #foobar +2024/04/30 02:40:11.713778 reconciler.go:116: INFO Channel #foobar monitor: join succeeded +2024/04/30 02:40:11.713897 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message +2024/04/30 02:40:11.714014 irc.go:294: INFO IRC routine asked to terminate +2024/04/30 02:40:11.714033 irc.go:269: INFO IRC client connected, quitting +2024/04/30 02:40:11.714014 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/30 02:40:11.714044 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/30 02:40:11.714051 reconciler.go:129: INFO Channel #foobar monitor: context canceled while monitoring +2024/04/30 02:40:11.714148 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.714213 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.714419 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.714671 irc.go:150: INFO Disconnected from IRC +2024/04/30 02:40:11.714744 irc.go:280: INFO IRC shutdown complete +2024/04/30 02:40:11.714812 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertAndJoinChannel (0.00s) === RUN TestSendAlertDisconnected -2025/06/01 06:58:59.189345 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:45883 -2025/06/01 06:58:59.189373 irc.go:300: INFO Connecting to IRC 127.0.0.1:45883 -2025/06/01 06:58:59.189384 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.189391 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:45883. -2025/06/01 06:58:59.189531 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.189536 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:50728 -2025/06/01 06:58:59.189562 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.189576 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.189584 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.189593 irc_test.go:292: INFO =Server= Wait before completing session -2025/06/01 06:58:59.189598 irc_test.go:294: INFO =Server= Completing session -2025/06/01 06:58:59.193462 irc.go:144: INFO Session established -2025/06/01 06:58:59.193490 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.193503 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.193512 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.193562 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.193582 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.193588 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.197459 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.197473 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.197494 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2025/06/01 06:58:59.197521 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message -2025/06/01 06:58:59.197539 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2025/06/01 06:58:59.197550 irc.go:294: INFO IRC routine asked to terminate -2025/06/01 06:58:59.197556 irc.go:269: INFO IRC client connected, quitting -2025/06/01 06:58:59.197563 irc.go:272: INFO Wait for IRC disconnect to complete -2025/06/01 06:58:59.197625 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.197652 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.197691 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.197753 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.197776 irc.go:280: INFO IRC shutdown complete -2025/06/01 06:58:59.197793 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections ---- PASS: TestSendAlertDisconnected (0.01s) +2024/04/30 02:40:11.714997 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33523 +2024/04/30 02:40:11.715067 irc.go:300: INFO Connecting to IRC 127.0.0.1:33523 +2024/04/30 02:40:11.715093 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.715109 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33523. +2024/04/30 02:40:11.715392 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:50088 +2024/04/30 02:40:11.715478 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/30 02:40:11.715551 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.715580 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.715595 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.715608 irc_test.go:292: INFO =Server= Wait before completing session +2024/04/30 02:40:11.715618 irc_test.go:294: INFO =Server= Completing session +2024/04/30 02:40:11.715775 irc.go:144: INFO Session established +2024/04/30 02:40:11.715854 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.715877 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.715902 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.716050 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.716097 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.716123 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.716249 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.716269 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.716321 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/30 02:40:11.716379 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message +2024/04/30 02:40:11.716430 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/30 02:40:11.716458 irc.go:294: INFO IRC routine asked to terminate +2024/04/30 02:40:11.716500 irc.go:269: INFO IRC client connected, quitting +2024/04/30 02:40:11.716527 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/30 02:40:11.716575 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.716630 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.716663 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.716856 irc.go:150: INFO Disconnected from IRC +2024/04/30 02:40:11.716894 irc.go:280: INFO IRC shutdown complete +2024/04/30 02:40:11.716928 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +--- PASS: TestSendAlertDisconnected (0.00s) === RUN TestReconnect -2025/06/01 06:58:59.197875 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37597 -2025/06/01 06:58:59.197904 irc.go:300: INFO Connecting to IRC 127.0.0.1:37597 -2025/06/01 06:58:59.197918 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.197925 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37597. -2025/06/01 06:58:59.198053 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.198055 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:37146 -2025/06/01 06:58:59.198119 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.198135 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.198143 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.198219 irc.go:144: INFO Session established -2025/06/01 06:58:59.198259 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.198272 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.198281 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.198320 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.198337 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.198355 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.198402 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.198415 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.198416 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:37146: read tcp 127.0.0.1:37597->127.0.0.1:37146: use of closed network connection -2025/06/01 06:58:59.198426 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2025/06/01 06:58:59.198437 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.198501 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.198528 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2025/06/01 06:58:59.198537 irc.go:300: INFO Connecting to IRC 127.0.0.1:37597 -2025/06/01 06:58:59.198543 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.198557 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37597. -2025/06/01 06:58:59.198691 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:37148 -2025/06/01 06:58:59.198787 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.198863 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.198925 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.198932 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.198987 irc.go:144: INFO Session established -2025/06/01 06:58:59.199015 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.199025 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.199033 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.199092 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.199106 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.199111 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.199140 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2025/06/01 06:58:59.199152 irc.go:294: INFO IRC routine asked to terminate -2025/06/01 06:58:59.199158 irc.go:269: INFO IRC client connected, quitting -2025/06/01 06:58:59.199164 irc.go:272: INFO Wait for IRC disconnect to complete -2025/06/01 06:58:59.199213 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.199225 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.199237 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.199249 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.199294 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.199340 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.199361 irc.go:280: INFO IRC shutdown complete -2025/06/01 06:58:59.199377 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.717155 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46575 +2024/04/30 02:40:11.717212 irc.go:300: INFO Connecting to IRC 127.0.0.1:46575 +2024/04/30 02:40:11.717245 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.717266 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46575. +2024/04/30 02:40:11.717549 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/30 02:40:11.717549 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:59500 +2024/04/30 02:40:11.717727 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.717773 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.717802 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.717959 irc.go:144: INFO Session established +2024/04/30 02:40:11.718008 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.718024 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.718046 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.718172 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.718212 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.718224 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.718345 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.718439 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.718467 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.718525 irc.go:150: INFO Disconnected from IRC +2024/04/30 02:40:11.718562 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/30 02:40:11.718595 irc.go:300: INFO Connecting to IRC 127.0.0.1:46575 +2024/04/30 02:40:11.718617 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.718576 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:59500: read tcp 127.0.0.1:46575->127.0.0.1:59500: use of closed network connection +2024/04/30 02:40:11.718643 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46575. +2024/04/30 02:40:11.718887 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:59504 +2024/04/30 02:40:11.718888 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/30 02:40:11.719036 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.719063 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.719081 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.719270 irc.go:144: INFO Session established +2024/04/30 02:40:11.719329 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.719357 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.719378 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.719474 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.719546 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.719555 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.719632 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/04/30 02:40:11.719655 irc.go:294: INFO IRC routine asked to terminate +2024/04/30 02:40:11.719674 irc.go:269: INFO IRC client connected, quitting +2024/04/30 02:40:11.719693 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/30 02:40:11.719724 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.719743 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.719779 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.719807 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.719874 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.719996 irc.go:150: INFO Disconnected from IRC +2024/04/30 02:40:11.720028 irc.go:280: INFO IRC shutdown complete +2024/04/30 02:40:11.720071 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestReconnect (0.00s) === RUN TestConnectErrorRetry -2025/06/01 06:58:59.199455 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33901 -2025/06/01 06:58:59.199485 irc.go:300: INFO Connecting to IRC 127.0.0.1:33901 -2025/06/01 06:58:59.199499 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.199504 fake_delayer.go:45: INFO Waiting StopDelay signal -2025/06/01 06:58:59.199509 fake_delayer.go:47: INFO Received StopDelay signal -2025/06/01 06:58:59.199517 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33901. -2025/06/01 06:58:59.199625 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:38200 -2025/06/01 06:58:59.199632 irc_server_for_test.go:157: INFO =Server= Closing connection early -2025/06/01 06:58:59.199694 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.199752 connection.go:444: ERROR irc.send(): write tcp 127.0.0.1:38200->127.0.0.1:33901: write: broken pipe -2025/06/01 06:58:59.199764 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.199783 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:38200->127.0.0.1:33901: use of closed network connection -2025/06/01 06:58:59.199803 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.199818 irc.go:319: WARN Receiving a session down before the session is up, this is odd -2025/06/01 06:58:59.199825 irc.go:300: INFO Connecting to IRC 127.0.0.1:33901 -2025/06/01 06:58:59.199830 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.199834 fake_delayer.go:45: INFO Waiting StopDelay signal -2025/06/01 06:58:59.199840 fake_delayer.go:47: INFO Received StopDelay signal -2025/06/01 06:58:59.199847 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33901. -2025/06/01 06:58:59.199949 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.199951 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:38212 -2025/06/01 06:58:59.199996 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.200004 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.200014 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.200091 irc.go:144: INFO Session established -2025/06/01 06:58:59.200112 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.200121 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.200129 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.200733 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.200751 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.200777 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.200811 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2025/06/01 06:58:59.200816 irc.go:294: INFO IRC routine asked to terminate -2025/06/01 06:58:59.200823 irc.go:269: INFO IRC client connected, quitting -2025/06/01 06:58:59.200830 irc.go:272: INFO Wait for IRC disconnect to complete -2025/06/01 06:58:59.200856 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.200869 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.200871 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.200899 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.200912 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.200960 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.200975 irc.go:280: INFO IRC shutdown complete -2025/06/01 06:58:59.200995 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.720215 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43125 +2024/04/30 02:40:11.720271 irc.go:300: INFO Connecting to IRC 127.0.0.1:43125 +2024/04/30 02:40:11.720293 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.720302 fake_delayer.go:45: INFO Waiting StopDelay signal +2024/04/30 02:40:11.720312 fake_delayer.go:47: INFO Received StopDelay signal +2024/04/30 02:40:11.720326 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43125. +2024/04/30 02:40:11.720584 connection.go:399: INFO irc.Connect(): Performing SSL handshake. +2024/04/30 02:40:11.720594 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:59102 +2024/04/30 02:40:11.720633 irc_server_for_test.go:157: INFO =Server= Closing connection early +2024/04/30 02:40:11.721107 irc.go:305: ERROR Could not connect to IRC: EOF +2024/04/30 02:40:11.721130 irc.go:300: INFO Connecting to IRC 127.0.0.1:43125 +2024/04/30 02:40:11.721142 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.721153 fake_delayer.go:45: INFO Waiting StopDelay signal +2024/04/30 02:40:11.721176 fake_delayer.go:47: INFO Received StopDelay signal +2024/04/30 02:40:11.721200 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43125. +2024/04/30 02:40:11.721430 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/30 02:40:11.721457 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:59110 +2024/04/30 02:40:11.721568 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.721600 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.721615 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.721797 irc.go:144: INFO Session established +2024/04/30 02:40:11.721858 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.721898 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.721931 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.722049 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.722078 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.722088 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.722174 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/04/30 02:40:11.722209 irc.go:294: INFO IRC routine asked to terminate +2024/04/30 02:40:11.722228 irc.go:269: INFO IRC client connected, quitting +2024/04/30 02:40:11.722228 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.722276 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.722284 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/30 02:40:11.722371 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.722408 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.722566 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.722897 irc.go:150: INFO Disconnected from IRC +2024/04/30 02:40:11.722940 irc.go:280: INFO IRC shutdown complete +2024/04/30 02:40:11.722984 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestConnectErrorRetry (0.00s) === RUN TestIdentify -2025/06/01 06:58:59.201065 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37335 -2025/06/01 06:58:59.201091 irc.go:300: INFO Connecting to IRC 127.0.0.1:37335 -2025/06/01 06:58:59.201101 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.201112 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37335. -2025/06/01 06:58:59.201225 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:42896 -2025/06/01 06:58:59.201282 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.201343 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.201368 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.201428 irc.go:165: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. -2025/06/01 06:58:59.201445 irc.go:189: INFO Handling NickServ request to IDENTIFY -2025/06/01 06:58:59.201471 irc.go:144: INFO Session established -2025/06/01 06:58:59.201503 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request -2025/06/01 06:58:59.201515 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.201525 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.201533 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.201569 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword -2025/06/01 06:58:59.201579 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.201583 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.201589 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.201594 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.201615 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2025/06/01 06:58:59.201622 irc.go:294: INFO IRC routine asked to terminate -2025/06/01 06:58:59.201628 irc.go:269: INFO IRC client connected, quitting -2025/06/01 06:58:59.201633 irc.go:272: INFO Wait for IRC disconnect to complete -2025/06/01 06:58:59.201660 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.201672 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.201717 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.201762 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.201770 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.201782 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.201797 irc.go:280: INFO IRC shutdown complete -2025/06/01 06:58:59.201812 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.723194 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42647 +2024/04/30 02:40:11.723266 irc.go:300: INFO Connecting to IRC 127.0.0.1:42647 +2024/04/30 02:40:11.723290 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.723306 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42647. +2024/04/30 02:40:11.723635 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:33036 +2024/04/30 02:40:11.723820 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/30 02:40:11.723906 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.723984 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.724042 irc.go:165: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. +2024/04/30 02:40:11.724075 irc.go:189: INFO Handling NickServ request to IDENTIFY +2024/04/30 02:40:11.724126 irc.go:144: INFO Session established +2024/04/30 02:40:11.724157 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request +2024/04/30 02:40:11.724187 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.724207 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.724221 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.724232 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword +2024/04/30 02:40:11.724252 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.724298 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.724370 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.724387 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.724456 irc.go:294: INFO IRC routine asked to terminate +2024/04/30 02:40:11.724473 irc.go:269: INFO IRC client connected, quitting +2024/04/30 02:40:11.724466 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/04/30 02:40:11.724498 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.724485 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/30 02:40:11.724511 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.724546 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.724620 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.724722 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.724860 irc.go:150: INFO Disconnected from IRC +2024/04/30 02:40:11.724904 irc.go:280: INFO IRC shutdown complete +2024/04/30 02:40:11.724957 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestIdentify (0.00s) === RUN TestGhost -2025/06/01 06:58:59.201880 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36381 -2025/06/01 06:58:59.201908 irc.go:300: INFO Connecting to IRC 127.0.0.1:36381 -2025/06/01 06:58:59.201918 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.201925 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36381. -2025/06/01 06:58:59.202030 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:49076 -2025/06/01 06:58:59.202075 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.202134 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.202145 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.202200 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' -2025/06/01 06:58:59.202224 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ -2025/06/01 06:58:59.202264 irc.go:144: INFO Session established -2025/06/01 06:58:59.202280 irc.go:204: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' -2025/06/01 06:58:59.202288 irc.go:210: INFO Changing nick to 'foo' -2025/06/01 06:58:59.202295 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request -2025/06/01 06:58:59.202310 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.202318 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.202326 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.202376 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword -2025/06/01 06:58:59.202386 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.202391 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.202399 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.202407 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.202411 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.202434 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2025/06/01 06:58:59.202441 irc.go:294: INFO IRC routine asked to terminate -2025/06/01 06:58:59.202446 irc.go:269: INFO IRC client connected, quitting -2025/06/01 06:58:59.202452 irc.go:272: INFO Wait for IRC disconnect to complete -2025/06/01 06:58:59.202481 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.202491 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.202524 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.202580 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.202599 irc.go:280: INFO IRC shutdown complete -2025/06/01 06:58:59.202616 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.725126 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33501 +2024/04/30 02:40:11.725186 irc.go:300: INFO Connecting to IRC 127.0.0.1:33501 +2024/04/30 02:40:11.725211 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.725227 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33501. +2024/04/30 02:40:11.725518 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:51130 +2024/04/30 02:40:11.725528 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/30 02:40:11.725633 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.725659 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.725829 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' +2024/04/30 02:40:11.725907 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ +2024/04/30 02:40:11.726076 irc.go:144: INFO Session established +2024/04/30 02:40:11.726230 irc.go:204: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' +2024/04/30 02:40:11.726275 irc.go:210: INFO Changing nick to 'foo' +2024/04/30 02:40:11.726298 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request +2024/04/30 02:40:11.726373 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.726408 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.726413 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword +2024/04/30 02:40:11.726433 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.726449 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.726449 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.726585 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.726616 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.726653 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.726728 irc.go:294: INFO IRC routine asked to terminate +2024/04/30 02:40:11.726749 irc.go:269: INFO IRC client connected, quitting +2024/04/30 02:40:11.726764 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/30 02:40:11.726730 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/04/30 02:40:11.726830 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.726867 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.726975 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.727105 irc.go:150: INFO Disconnected from IRC +2024/04/30 02:40:11.727139 irc.go:280: INFO IRC shutdown complete +2024/04/30 02:40:11.727172 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestGhost (0.00s) === RUN TestStopRunningWhenHalfConnected -2025/06/01 06:58:59.202690 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37653 -2025/06/01 06:58:59.202723 irc.go:300: INFO Connecting to IRC 127.0.0.1:37653 -2025/06/01 06:58:59.202735 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.202742 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37653. -2025/06/01 06:58:59.202895 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:44942 -2025/06/01 06:58:59.203016 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.203028 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.205429 irc.go:308: INFO Connected to IRC server, waiting to establish session -2025/06/01 06:58:59.205478 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.205494 irc_test.go:589: INFO =Server= NOT completing session -2025/06/01 06:58:59.205508 irc.go:321: INFO IRC routine asked to terminate -2025/06/01 06:58:59.205515 irc.go:280: INFO IRC shutdown complete -2025/06/01 06:58:59.205536 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.205574 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:44942->127.0.0.1:37653: use of closed network connection -2025/06/01 06:58:59.205595 irc.go:150: INFO Disconnected from IRC -2025/06/01 06:58:59.205596 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:44942 disconnected -2025/06/01 06:58:59.205661 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.727327 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43025 +2024/04/30 02:40:11.727385 irc.go:300: INFO Connecting to IRC 127.0.0.1:43025 +2024/04/30 02:40:11.727404 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.727417 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43025. +2024/04/30 02:40:11.727639 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:59782 +2024/04/30 02:40:11.727672 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/30 02:40:11.727776 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.727808 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.727819 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.727834 irc_test.go:589: INFO =Server= NOT completing session +2024/04/30 02:40:11.727866 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.727901 irc.go:321: INFO IRC routine asked to terminate +2024/04/30 02:40:11.727927 irc.go:280: INFO IRC shutdown complete +2024/04/30 02:40:11.727969 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:59782 disconnected +2024/04/30 02:40:11.727972 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:59782->127.0.0.1:43025: use of closed network connection +2024/04/30 02:40:11.728041 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestStopRunningWhenHalfConnected (0.00s) === RUN TestPreJoinChannels -2025/06/01 06:58:59.205779 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37449 -2025/06/01 06:58:59.205817 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37449. -2025/06/01 06:58:59.205951 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:51412 -2025/06/01 06:58:59.206066 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.206083 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.206091 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.206165 reconciler.go:103: INFO Channel #baz monitor: waiting to join -2025/06/01 06:58:59.206185 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.206195 reconciler.go:112: INFO Channel #baz monitor: join request sent -2025/06/01 06:58:59.206237 reconciler.go:103: INFO Channel #bar monitor: waiting to join -2025/06/01 06:58:59.206241 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz -2025/06/01 06:58:59.206250 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.206255 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.206262 reconciler.go:112: INFO Channel #bar monitor: join request sent -2025/06/01 06:58:59.206280 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.206290 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.206298 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.206297 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz -2025/06/01 06:58:59.206358 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar -2025/06/01 06:58:59.206389 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.206391 reconciler.go:201: INFO Received JOIN confirmation for channel #baz -2025/06/01 06:58:59.206395 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar -2025/06/01 06:58:59.206400 reconciler.go:77: INFO Setting JOIN state on channel #baz -2025/06/01 06:58:59.206417 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.206436 reconciler.go:201: INFO Received JOIN confirmation for channel #bar -2025/06/01 06:58:59.206449 reconciler.go:77: INFO Setting JOIN state on channel #bar -2025/06/01 06:58:59.206454 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.206458 reconciler.go:116: INFO Channel #bar monitor: join succeeded -2025/06/01 06:58:59.206460 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.206410 reconciler.go:116: INFO Channel #baz monitor: join succeeded -2025/06/01 06:58:59.206520 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.206529 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.206539 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2025/06/01 06:58:59.206553 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.206563 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.206604 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.206664 reconciler.go:129: INFO Channel #bar monitor: context canceled while monitoring -2025/06/01 06:58:59.206678 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2025/06/01 06:58:59.206685 reconciler.go:129: INFO Channel #baz monitor: context canceled while monitoring -2025/06/01 06:58:59.206701 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.728036 irc.go:150: INFO Disconnected from IRC +2024/04/30 02:40:11.728228 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37089 +2024/04/30 02:40:11.728303 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37089. +2024/04/30 02:40:11.728568 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:48102 +2024/04/30 02:40:11.728716 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.728764 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.728777 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.728978 reconciler.go:103: INFO Channel #baz monitor: waiting to join +2024/04/30 02:40:11.729004 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.729017 reconciler.go:112: INFO Channel #baz monitor: join request sent +2024/04/30 02:40:11.729002 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.729059 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.729058 reconciler.go:103: INFO Channel #bar monitor: waiting to join +2024/04/30 02:40:11.729081 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.729087 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.729096 reconciler.go:112: INFO Channel #bar monitor: join request sent +2024/04/30 02:40:11.729104 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz +2024/04/30 02:40:11.729126 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.729138 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz +2024/04/30 02:40:11.729204 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.729227 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.729328 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.729351 reconciler.go:201: INFO Received JOIN confirmation for channel #baz +2024/04/30 02:40:11.729372 reconciler.go:77: INFO Setting JOIN state on channel #baz +2024/04/30 02:40:11.729377 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar +2024/04/30 02:40:11.729398 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.729414 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar +2024/04/30 02:40:11.729421 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.729435 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.729459 reconciler.go:116: INFO Channel #baz monitor: join succeeded +2024/04/30 02:40:11.729477 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/30 02:40:11.729500 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.729527 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.729603 reconciler.go:201: INFO Received JOIN confirmation for channel #bar +2024/04/30 02:40:11.729655 reconciler.go:77: INFO Setting JOIN state on channel #bar +2024/04/30 02:40:11.729616 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.729747 reconciler.go:116: INFO Channel #bar monitor: join succeeded +2024/04/30 02:40:11.729894 reconciler.go:129: INFO Channel #baz monitor: context canceled while monitoring +2024/04/30 02:40:11.729941 reconciler.go:129: INFO Channel #bar monitor: context canceled while monitoring +2024/04/30 02:40:11.729954 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/30 02:40:11.730006 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestPreJoinChannels (0.00s) === RUN TestKeepJoining -2025/06/01 06:58:59.206781 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37359 -2025/06/01 06:58:59.206809 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37359. -2025/06/01 06:58:59.206928 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:36382 -2025/06/01 06:58:59.206949 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.206959 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.206967 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.207044 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.207064 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.207073 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.207110 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.207124 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.207141 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.207158 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2025/06/01 06:58:59.207165 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.207171 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.207180 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.207214 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.207231 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.207248 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.207265 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2025/06/01 06:58:59.207272 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.207278 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.207285 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.207314 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.207329 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.207346 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.207397 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.207406 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.207409 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.207414 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.207424 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2025/06/01 06:58:59.207435 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.207491 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2025/06/01 06:58:59.207514 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.730288 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34077 +2024/04/30 02:40:11.730439 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34077. +2024/04/30 02:40:11.730799 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:37466 +2024/04/30 02:40:11.730954 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.730984 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.731003 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.731153 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.731178 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.731202 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.731297 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.731338 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.731350 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.731393 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2024/04/30 02:40:11.731413 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.731424 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.731456 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.731547 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.731649 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.731667 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.731732 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2024/04/30 02:40:11.731758 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.731773 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.731808 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.731919 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.731946 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.731958 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.732124 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.732127 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.732148 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.732164 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.732182 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/30 02:40:11.732278 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.732420 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/30 02:40:11.732463 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestKeepJoining (0.00s) === RUN TestKickRejoin -2025/06/01 06:58:59.207587 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38513 -2025/06/01 06:58:59.207614 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38513. -2025/06/01 06:58:59.207732 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:38184 -2025/06/01 06:58:59.207754 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2025/06/01 06:58:59.207765 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2025/06/01 06:58:59.207774 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2025/06/01 06:58:59.207837 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.207857 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.207866 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.207897 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.207913 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.207928 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.207959 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! -2025/06/01 06:58:59.207977 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.207991 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.208010 reconciler.go:219: INFO Received KICK for channel #foo -2025/06/01 06:58:59.208020 reconciler.go:91: INFO Removing JOIN state on channel #foo -2025/06/01 06:58:59.208029 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2025/06/01 06:58:59.208038 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2025/06/01 06:58:59.208042 fake_delayer.go:43: INFO Faking Backoff -2025/06/01 06:58:59.208050 reconciler.go:112: INFO Channel #foo monitor: join request sent -2025/06/01 06:58:59.208078 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2025/06/01 06:58:59.208093 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2025/06/01 06:58:59.208109 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2025/06/01 06:58:59.208155 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2025/06/01 06:58:59.208163 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2025/06/01 06:58:59.208167 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2025/06/01 06:58:59.208171 reconciler.go:77: INFO Setting JOIN state on channel #foo -2025/06/01 06:58:59.208180 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2025/06/01 06:58:59.208192 connection.go:577: INFO irc.Close(): Disconnected from server. -2025/06/01 06:58:59.208248 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2025/06/01 06:58:59.208270 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/30 02:40:11.732686 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34057 +2024/04/30 02:40:11.732747 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34057. +2024/04/30 02:40:11.733092 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34548 +2024/04/30 02:40:11.735720 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/30 02:40:11.735839 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/30 02:40:11.735848 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/30 02:40:11.736125 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.736159 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.736184 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.736317 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.736360 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.736379 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.736493 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! +2024/04/30 02:40:11.736567 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.736597 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.736640 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/30 02:40:11.736669 reconciler.go:219: INFO Received KICK for channel #foo +2024/04/30 02:40:11.736692 reconciler.go:91: INFO Removing JOIN state on channel #foo +2024/04/30 02:40:11.736733 reconciler.go:127: INFO Channel #foo monitor: channel no longer joined +2024/04/30 02:40:11.736750 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/30 02:40:11.736759 fake_delayer.go:43: INFO Faking Backoff +2024/04/30 02:40:11.736780 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/30 02:40:11.736845 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/30 02:40:11.736944 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/30 02:40:11.736956 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/30 02:40:11.737101 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/30 02:40:11.737137 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/30 02:40:11.737156 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/30 02:40:11.737159 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/30 02:40:11.737197 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/30 02:40:11.737269 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/30 02:40:11.737411 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/30 02:40:11.737461 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestKickRejoin (0.00s) PASS -ok github.com/google/alertmanager-irc-relay 0.045s +ok github.com/google/alertmanager-irc-relay 0.057s create-stamp debian/debhelper-build-stamp fakeroot debian/rules binary dh binary --buildsystem=golang --with=golang @@ -2052,8 +2085,8 @@ dpkg-gencontrol: warning: package alertmanager-irc-relay: substitution variable ${misc:Static-Built-Using} unused, but is defined dh_md5sums -O--buildsystem=golang dh_builddeb -O--buildsystem=golang -dpkg-deb: building package 'alertmanager-irc-relay' in '../alertmanager-irc-relay_0.4.2-1_amd64.deb'. dpkg-deb: building package 'alertmanager-irc-relay-dbgsym' in '../alertmanager-irc-relay-dbgsym_0.4.2-1_amd64.deb'. +dpkg-deb: building package 'alertmanager-irc-relay' in '../alertmanager-irc-relay_0.4.2-1_amd64.deb'. dpkg-genbuildinfo --build=binary -O../alertmanager-irc-relay_0.4.2-1_amd64.buildinfo dpkg-genchanges --build=binary -O../alertmanager-irc-relay_0.4.2-1_amd64.changes dpkg-genchanges: info: binary-only upload (no source code included) @@ -2061,12 +2094,14 @@ dpkg-buildpackage: info: binary-only upload (no source included) dpkg-genchanges: info: including full source code in upload I: copying local configuration +I: user script /srv/workspace/pbuilder/2722649/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/2722649/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/1438012 and its subdirectories -I: Current time: Sun Jun 1 06:59:25 -12 2025 -I: pbuilder-time-stamp: 1748804365 +I: removing directory /srv/workspace/pbuilder/2722649 and its subdirectories +I: Current time: Tue Apr 30 02:40:31 +14 2024 +I: pbuilder-time-stamp: 1714394431