Diff of the two buildlogs: -- --- b1/build.log 2025-07-29 10:25:54.405550485 +0000 +++ b2/build.log 2025-07-29 10:29:17.777795900 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Mon Aug 31 04:43:42 -12 2026 -I: pbuilder-time-stamp: 1788194622 +I: Current time: Wed Jul 30 00:25:55 +14 2025 +I: pbuilder-time-stamp: 1753784755 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/trixie-reproducible-base.tgz] I: copying local configuration @@ -22,52 +22,84 @@ dpkg-source: info: unpacking alertmanager-irc-relay_0.5.1-3.debian.tar.xz I: Not using root during the build. I: Installing the build-deps -I: user script /srv/workspace/pbuilder/3876104/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/3891795/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 Jul 29 10:26 /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/3891795/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/3891795/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]="37" [3]="1" [4]="release" [5]="x86_64-pc-linux-gnu") + BASH_VERSION='5.2.37(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=40 ' + 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='d2ac535594d24fb28d2db66fcd47202e' - 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='3876104' - PS1='# ' - PS2='> ' + INVOCATION_ID=50d04dd5e9da4e838a16e87f5d3e1552 + 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=3891795 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.uNLYsqQ8/pbuilderrc_vHrF --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.uNLYsqQ8/b1 --logfile b1/build.log alertmanager-irc-relay_0.5.1-3.dsc' - SUDO_GID='110' - SUDO_UID='105' - 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.uNLYsqQ8/pbuilderrc_xIye --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.uNLYsqQ8/b2 --logfile b2/build.log alertmanager-irc-relay_0.5.1-3.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 ionos5-amd64 6.12.33+deb12-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.12.33-1~bpo12+1 (2025-07-09) x86_64 GNU/Linux + Linux i-capture-the-hostname 6.1.0-37-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.140-1 (2025-05-22) x86_64 GNU/Linux I: ls -l /bin - lrwxrwxrwx 1 root root 7 May 12 2025 /bin -> usr/bin -I: user script /srv/workspace/pbuilder/3876104/tmp/hooks/D02_print_environment finished + lrwxrwxrwx 1 root root 7 May 12 19:25 /bin -> usr/bin +I: user script /srv/workspace/pbuilder/3891795/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -343,7 +375,7 @@ Get: 222 http://deb.debian.org/debian trixie/main amd64 golang-protobuf-extensions-dev all 1.0.4-2 [29.7 kB] Get: 223 http://deb.debian.org/debian trixie/main amd64 golang-uber-automaxprocs-dev all 1.5.3-1 [22.3 kB] Get: 224 http://deb.debian.org/debian trixie/main amd64 golang-github-prometheus-alertmanager-dev all 0.28.1+ds-1 [1139 kB] -Fetched 155 MB in 22s (7014 kB/s) +Fetched 155 MB in 4s (36.2 MB/s) Preconfiguring packages ... 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 ... 19850 files and directories currently installed.) @@ -1074,8 +1106,8 @@ Setting up tzdata (2025b-4) ... Current default time zone: 'Etc/UTC' -Local time is now: Mon Aug 31 16:47:56 UTC 2026. -Universal Time is now: Mon Aug 31 16:47:56 UTC 2026. +Local time is now: Tue Jul 29 10:28:30 UTC 2025. +Universal Time is now: Tue Jul 29 10:28:30 UTC 2025. Run 'dpkg-reconfigure tzdata' if you wish to change it. Setting up golang-github-cespare-xxhash-dev (2.3.0-1) ... @@ -1260,7 +1292,11 @@ Building tag database... -> Finished parsing the build-deps I: Building the package -I: Running cd /build/reproducible-path/alertmanager-irc-relay-0.5.1/ && 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.5.1-3_source.changes +I: user script /srv/workspace/pbuilder/3891795/tmp/hooks/A99_set_merged_usr starting +Not re-configuring usrmerge for trixie +I: user script /srv/workspace/pbuilder/3891795/tmp/hooks/A99_set_merged_usr finished +hostname: Name or service not known +I: Running cd /build/reproducible-path/alertmanager-irc-relay-0.5.1/ && 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.5.1-3_source.changes dpkg-buildpackage: info: source package alertmanager-irc-relay dpkg-buildpackage: info: source version 0.5.1-3 dpkg-buildpackage: info: source distribution unstable @@ -1278,40 +1314,40 @@ 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 + cd obj-x86_64-linux-gnu && go install -trimpath -v -p 40 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging internal/goos -internal/msan -internal/coverage/rtcov -internal/profilerecord -vendor/golang.org/x/crypto/cryptobyte/asn1 -internal/asan -internal/nettrace -internal/unsafeheader -internal/godebugs unicode/utf8 -internal/itoa -log/internal -github.com/klauspost/compress/internal/le +internal/msan unicode/utf16 -internal/goexperiment -cmp -google.golang.org/protobuf/internal/flags +log/internal +internal/itoa +math/bits log/slog/internal +encoding +github.com/fluffle/goirc/logging +internal/runtime/atomic +unicode +internal/asan internal/byteorder +google.golang.org/protobuf/internal/flags +cmp +internal/godebugs internal/goarch +internal/nettrace +internal/coverage/rtcov +internal/unsafeheader +internal/runtime/syscall +internal/cpu container/list github.com/klauspost/compress/internal/cpuinfo +github.com/klauspost/compress/internal/le vendor/golang.org/x/crypto/internal/alias -internal/runtime/syscall -crypto/internal/fips140/alias -github.com/fluffle/goirc/logging crypto/internal/boring/sig -encoding -internal/cpu -math/bits -internal/runtime/atomic -unicode +vendor/golang.org/x/crypto/cryptobyte/asn1 +crypto/internal/fips140/alias +internal/profilerecord sync/atomic +internal/goexperiment crypto/internal/fips140/subtle internal/runtime/math internal/runtime/sys @@ -1321,18 +1357,18 @@ google.golang.org/protobuf/internal/set crypto/internal/fips140deps/cpu internal/bytealg -internal/runtime/exithook math +internal/runtime/exithook internal/stringslite internal/race +github.com/klauspost/compress internal/sync internal/runtime/maps -github.com/klauspost/compress runtime crypto/subtle -weak -internal/reflectlite iter +internal/reflectlite +weak runtime/metrics sync maps @@ -1342,9 +1378,9 @@ internal/bisect internal/testlog internal/singleflight +google.golang.org/protobuf/internal/pragma log/slog/internal/buffer unique -google.golang.org/protobuf/internal/pragma runtime/cgo internal/oserror path @@ -1352,156 +1388,156 @@ vendor/golang.org/x/net/dns/dnsmessage math/rand/v2 strconv -internal/godebug syscall +internal/godebug bytes golang.org/x/text/internal/tag -crypto/internal/randutil hash +crypto/internal/randutil github.com/beorn7/perks/quantile strings +net/netip hash/fnv -hash/crc32 crypto -net/netip +hash/crc32 reflect crypto/internal/fips140deps/godebug math/rand vendor/golang.org/x/text/transform golang.org/x/text/transform crypto/internal/impl -net/http/internal/ascii -crypto/internal/fips140 bufio +net/http/internal/ascii github.com/munnerz/goautoneg +crypto/internal/fips140 regexp/syntax html crypto/tls/internal/fips140tls -crypto/internal/fips140/sha512 crypto/internal/fips140/sha256 +crypto/internal/fips140/sha512 crypto/internal/fips140/sha3 +internal/syscall/execenv +time +internal/syscall/unix crypto/internal/fips140/hmac crypto/sha3 crypto/internal/fips140/check crypto/internal/fips140hash -internal/syscall/execenv -internal/syscall/unix -time -crypto/internal/fips140/aes crypto/internal/fips140/hkdf crypto/internal/fips140/tls12 crypto/internal/fips140/edwards25519/field crypto/internal/fips140/bigmod crypto/internal/fips140/nistec/fiat +crypto/internal/fips140/aes crypto/internal/fips140/tls13 -regexp crypto/internal/fips140/edwards25519 +regexp context io/fs internal/poll crypto/internal/fips140/nistec -embed internal/filepathlite +embed google.golang.org/protobuf/internal/editiondefaults +os internal/fmtsort encoding/binary -os -vendor/golang.org/x/crypto/internal/poly1305 encoding/base64 -github.com/cespare/xxhash +vendor/golang.org/x/crypto/internal/poly1305 github.com/klauspost/compress/internal/snapref +github.com/cespare/xxhash golang.org/x/sys/unix encoding/pem crypto/internal/sysrand -google.golang.org/protobuf/internal/detrand -io/ioutil github.com/prometheus/procfs/internal/util +google.golang.org/protobuf/internal/detrand path/filepath +io/ioutil fmt os/signal vendor/golang.org/x/sys/cpu -net crypto/internal/entropy crypto/internal/fips140/drbg +net crypto/internal/fips140/ed25519 +crypto/internal/fips140/mlkem crypto/internal/fips140only crypto/internal/fips140/ecdh -crypto/internal/fips140/ecdsa -crypto/internal/fips140/mlkem crypto/internal/fips140/rsa +crypto/internal/fips140/ecdsa crypto/internal/fips140/aes/gcm crypto/rc4 crypto/md5 crypto/cipher +crypto/internal/boring +crypto/des +vendor/golang.org/x/crypto/chacha20 +crypto/aes +crypto/sha256 +crypto/sha512 +crypto/hmac +crypto/ecdh +crypto/sha1 encoding/hex -github.com/golang/mock/gomock -flag net/url +flag log +github.com/golang/mock/gomock net/http/internal github.com/prometheus/procfs/internal/fs runtime/debug -google.golang.org/protobuf/internal/errors -compress/flate -google.golang.org/protobuf/internal/version -golang.org/x/text/internal/language text/template/parse -github.com/klauspost/compress/fse mime/quotedprintable vendor/golang.org/x/net/http2/hpack +google.golang.org/protobuf/internal/version go/token -math/big -golang.org/x/text/unicode/norm gopkg.in/yaml.v2 encoding/json +google.golang.org/protobuf/internal/errors vendor/golang.org/x/text/unicode/norm +github.com/klauspost/compress/fse +golang.org/x/text/internal/language +golang.org/x/text/unicode/norm mime +compress/flate +math/big google.golang.org/protobuf/encoding/protowire +vendor/golang.org/x/crypto/chacha20poly1305 google.golang.org/protobuf/reflect/protoreflect -crypto/des -crypto/internal/boring vendor/golang.org/x/text/unicode/bidi -vendor/golang.org/x/crypto/chacha20 -crypto/aes -crypto/hmac -crypto/sha512 -crypto/sha1 -crypto/sha256 -crypto/ecdh github.com/klauspost/compress/huff0 -github.com/fluffle/goirc/state github.com/google/alertmanager-irc-relay/logging -vendor/golang.org/x/crypto/chacha20poly1305 +github.com/fluffle/goirc/state compress/gzip -golang.org/x/text/internal/language/compact text/template +golang.org/x/text/internal/language/compact vendor/golang.org/x/text/secure/bidirule golang.org/x/text/language -vendor/golang.org/x/net/idna -google.golang.org/protobuf/internal/descopts google.golang.org/protobuf/internal/descfmt +google.golang.org/protobuf/internal/descopts google.golang.org/protobuf/internal/strs google.golang.org/protobuf/internal/encoding/messageset google.golang.org/protobuf/internal/order google.golang.org/protobuf/runtime/protoiface google.golang.org/protobuf/internal/genid +vendor/golang.org/x/net/idna google.golang.org/protobuf/internal/protolazy -google.golang.org/protobuf/internal/encoding/text google.golang.org/protobuf/reflect/protoregistry +google.golang.org/protobuf/internal/encoding/text log/slog -golang.org/x/text/internal -google.golang.org/protobuf/internal/encoding/defval -google.golang.org/protobuf/proto -golang.org/x/text/cases crypto/internal/boring/bbig -crypto/dsa crypto/rand -crypto/elliptic +crypto/dsa encoding/asn1 +crypto/elliptic +google.golang.org/protobuf/proto +golang.org/x/text/internal crypto/ed25519 crypto/internal/hpke crypto/rsa github.com/klauspost/compress/zstd +google.golang.org/protobuf/internal/encoding/defval +golang.org/x/text/cases html/template crypto/x509/pkix vendor/golang.org/x/crypto/cryptobyte @@ -1513,9 +1549,9 @@ crypto/ecdsa google.golang.org/protobuf/internal/encoding/tag google.golang.org/protobuf/internal/impl -vendor/golang.org/x/net/http/httpproxy golang.org/x/net/internal/socks net/textproto +vendor/golang.org/x/net/http/httpproxy crypto/x509 github.com/prometheus/procfs golang.org/x/net/proxy @@ -1527,36 +1563,36 @@ google.golang.org/protobuf/types/known/timestamppb github.com/prometheus/client_model/go github.com/prometheus/common/model -github.com/prometheus/common/helpers/templates github.com/prometheus/alertmanager/pkg/labels github.com/prometheus/client_golang/prometheus/internal +github.com/prometheus/common/helpers/templates github.com/prometheus/alertmanager/matcher/parse github.com/prometheus/alertmanager/matcher/compat net/http/httptrace github.com/fluffle/goirc/client net/http -github.com/prometheus/client_golang/internal/github.com/golang/gddo/httputil/header expvar +github.com/prometheus/client_golang/internal/github.com/golang/gddo/httputil/header github.com/gorilla/mux github.com/prometheus/common/expfmt github.com/prometheus/client_golang/internal/github.com/golang/gddo/httputil github.com/prometheus/client_golang/prometheus -github.com/prometheus/client_golang/prometheus/promauto github.com/prometheus/alertmanager/types +github.com/prometheus/client_golang/prometheus/promauto github.com/prometheus/client_golang/prometheus/promhttp 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 40 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging === RUN TestBackoffIncreasesAndReachesMax --- PASS: TestBackoffIncreasesAndReachesMax (0.00s) === RUN TestBackoffReset --- PASS: TestBackoffReset (0.00s) === RUN TestBackoffDelayContext -2026/08/31 04:48:35.313033 backoff.go:111: INFO Backoff for 0s starts -2026/08/31 04:48:35.313134 backoff.go:114: INFO Backoff for 0s ends -2026/08/31 04:48:35.313146 backoff.go:111: INFO Backoff for 2ms starts -2026/08/31 04:48:35.313162 backoff.go:116: INFO Backoff for 2ms canceled by context +2025/07/30 00:29:04.715063 backoff.go:111: INFO Backoff for 0s starts +2025/07/30 00:29:04.715132 backoff.go:114: INFO Backoff for 0s ends +2025/07/30 00:29:04.715144 backoff.go:111: INFO Backoff for 2ms starts +2025/07/30 00:29:04.715152 backoff.go:116: INFO Backoff for 2ms canceled by context --- PASS: TestBackoffDelayContext (0.00s) === RUN TestNoConfig --- PASS: TestNoConfig (0.00s) @@ -1575,10 +1611,10 @@ === RUN TestGivenTemplateNotOverwritten --- PASS: TestGivenTemplateNotOverwritten (0.00s) === RUN TestTemplateErrorsCreateRawAlertMsg -2026/08/31 04:48:35.315916 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"} -2026/08/31 04:48:35.315942 format.go:61: WARN Sending raw alert -2026/08/31 04:48:35.315982 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"} -2026/08/31 04:48:35.315994 format.go:61: WARN Sending raw alert +2025/07/30 00:29:04.717382 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/07/30 00:29:04.717402 format.go:61: WARN Sending raw alert +2025/07/30 00:29:04.717442 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/07/30 00:29:04.717451 format.go:61: WARN Sending raw alert --- PASS: TestTemplateErrorsCreateRawAlertMsg (0.00s) === RUN TestAlertsDispatchedOnce --- PASS: TestAlertsDispatchedOnce (0.00s) @@ -1589,480 +1625,481 @@ === RUN TestMultilineTemplates --- PASS: TestMultilineTemplates (0.00s) === RUN TestAlertsDispatched -2026/08/31 04:48:35.316772 http.go:132: INFO Starting HTTP server +2025/07/30 00:29:04.718348 http.go:132: INFO Starting HTTP server --- PASS: TestAlertsDispatched (0.00s) === RUN TestRootReturnsError -2026/08/31 04:48:35.317068 http.go:132: INFO Starting HTTP server +2025/07/30 00:29:04.718722 http.go:132: INFO Starting HTTP server --- PASS: TestRootReturnsError (0.00s) === RUN TestInvalidDataReturnsError -2026/08/31 04:48:35.317251 http.go:132: INFO Starting HTTP server -2026/08/31 04:48:35.317304 http.go:96: ERROR Could not decode request body (invalid character '}' looking for beginning of object key string): {"this is not": "a valid alert",} +2025/07/30 00:29:04.719017 http.go:132: INFO Starting HTTP server +2025/07/30 00:29:04.719072 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 -2026/08/31 04:48:35.317590 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33955 -2026/08/31 04:48:35.317626 irc.go:302: INFO Connecting to IRC 127.0.0.1:33955 -2026/08/31 04:48:35.317640 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.317648 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33955. -2026/08/31 04:48:35.317797 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:58588 -2026/08/31 04:48:35.317846 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/08/31 04:48:35.317972 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret -2026/08/31 04:48:35.318018 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping -2026/08/31 04:48:35.318025 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.318030 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.318037 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.318152 irc.go:146: INFO Session established -2026/08/31 04:48:35.318182 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.318190 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.318205 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.318256 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.318279 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.318283 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.318331 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join -2026/08/31 04:48:35.318328 irc.go:296: INFO IRC routine asked to terminate -2026/08/31 04:48:35.318373 irc.go:271: INFO IRC client connected, quitting -2026/08/31 04:48:35.318385 irc.go:274: INFO Wait for IRC disconnect to complete -2026/08/31 04:48:35.318457 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.318476 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.318525 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.318586 irc.go:152: INFO Disconnected from IRC -2026/08/31 04:48:35.318603 irc.go:282: INFO IRC shutdown complete -2026/08/31 04:48:35.318619 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.719419 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36441 +2025/07/30 00:29:04.719478 irc.go:302: INFO Connecting to IRC 127.0.0.1:36441 +2025/07/30 00:29:04.719498 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.719509 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36441. +2025/07/30 00:29:04.719764 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/07/30 00:29:04.719763 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:36440 +2025/07/30 00:29:04.719898 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret +2025/07/30 00:29:04.719930 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping +2025/07/30 00:29:04.719946 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.719955 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.719961 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.720077 irc.go:146: INFO Session established +2025/07/30 00:29:04.720122 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.720132 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.720143 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.720265 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.720293 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.720302 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.720337 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join +2025/07/30 00:29:04.720356 irc.go:296: INFO IRC routine asked to terminate +2025/07/30 00:29:04.720377 irc.go:271: INFO IRC client connected, quitting +2025/07/30 00:29:04.720396 irc.go:274: INFO Wait for IRC disconnect to complete +2025/07/30 00:29:04.720461 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.720487 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.720561 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.720685 irc.go:152: INFO Disconnected from IRC +2025/07/30 00:29:04.720717 irc.go:282: INFO IRC shutdown complete +2025/07/30 00:29:04.720752 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestServerPassword (0.00s) === RUN TestSendAlertOnPreJoinedChannel -2026/08/31 04:48:35.318691 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:45469 -2026/08/31 04:48:35.318719 irc.go:302: INFO Connecting to IRC 127.0.0.1:45469 -2026/08/31 04:48:35.318729 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.318738 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:45469. -2026/08/31 04:48:35.318850 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/08/31 04:48:35.318847 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:36116 -2026/08/31 04:48:35.318886 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.318907 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.318921 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.319140 irc.go:146: INFO Session established -2026/08/31 04:48:35.319201 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.319216 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.319229 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.319318 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.319339 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.319346 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.319435 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.319451 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.319477 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/08/31 04:48:35.319527 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message -2026/08/31 04:48:35.319558 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/08/31 04:48:35.319587 irc.go:296: INFO IRC routine asked to terminate -2026/08/31 04:48:35.319602 irc.go:271: INFO IRC client connected, quitting -2026/08/31 04:48:35.319614 irc.go:274: INFO Wait for IRC disconnect to complete -2026/08/31 04:48:35.319672 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.319695 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.319747 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.319826 irc.go:152: INFO Disconnected from IRC -2026/08/31 04:48:35.319851 irc.go:282: INFO IRC shutdown complete -2026/08/31 04:48:35.319876 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.720881 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42011 +2025/07/30 00:29:04.720932 irc.go:302: INFO Connecting to IRC 127.0.0.1:42011 +2025/07/30 00:29:04.720951 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.720964 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42011. +2025/07/30 00:29:04.721134 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:42104 +2025/07/30 00:29:04.721152 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/07/30 00:29:04.721192 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.721206 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.721218 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.721336 irc.go:146: INFO Session established +2025/07/30 00:29:04.721393 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.721410 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.721418 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.721496 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.721517 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.721525 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.721616 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.721632 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.721661 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/07/30 00:29:04.721708 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message +2025/07/30 00:29:04.721746 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/07/30 00:29:04.721764 irc.go:296: INFO IRC routine asked to terminate +2025/07/30 00:29:04.721774 irc.go:271: INFO IRC client connected, quitting +2025/07/30 00:29:04.721787 irc.go:274: INFO Wait for IRC disconnect to complete +2025/07/30 00:29:04.721847 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.721868 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.721925 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.721996 irc.go:152: INFO Disconnected from IRC +2025/07/30 00:29:04.722024 irc.go:282: INFO IRC shutdown complete +2025/07/30 00:29:04.722051 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertOnPreJoinedChannel (0.00s) === RUN TestUsePrivmsgToSendAlertOnPreJoinedChannel -2026/08/31 04:48:35.320043 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46041 -2026/08/31 04:48:35.320096 irc.go:302: INFO Connecting to IRC 127.0.0.1:46041 -2026/08/31 04:48:35.320115 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.320125 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46041. -2026/08/31 04:48:35.320347 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:52672 -2026/08/31 04:48:35.320362 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/08/31 04:48:35.320403 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.320422 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.320433 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.320538 irc.go:146: INFO Session established -2026/08/31 04:48:35.320595 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.320612 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.320627 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.320690 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.320707 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.320713 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.320771 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.320786 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.320813 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/08/31 04:48:35.320824 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message -2026/08/31 04:48:35.320845 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/08/31 04:48:35.320849 irc.go:296: INFO IRC routine asked to terminate -2026/08/31 04:48:35.320861 irc.go:271: INFO IRC client connected, quitting -2026/08/31 04:48:35.320868 irc.go:274: INFO Wait for IRC disconnect to complete -2026/08/31 04:48:35.320920 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.320938 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.320989 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.321053 irc.go:152: INFO Disconnected from IRC -2026/08/31 04:48:35.321077 irc.go:282: INFO IRC shutdown complete -2026/08/31 04:48:35.321119 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.722155 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46399 +2025/07/30 00:29:04.722209 irc.go:302: INFO Connecting to IRC 127.0.0.1:46399 +2025/07/30 00:29:04.722228 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.722237 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46399. +2025/07/30 00:29:04.722383 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:35324 +2025/07/30 00:29:04.722400 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/07/30 00:29:04.722452 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.722474 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.722487 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.722581 irc.go:146: INFO Session established +2025/07/30 00:29:04.722634 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.722653 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.722669 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.722729 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.722749 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.722770 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.722868 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.722886 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.722920 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/07/30 00:29:04.722954 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message +2025/07/30 00:29:04.722996 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/07/30 00:29:04.722997 irc.go:296: INFO IRC routine asked to terminate +2025/07/30 00:29:04.723016 irc.go:271: INFO IRC client connected, quitting +2025/07/30 00:29:04.723034 irc.go:274: INFO Wait for IRC disconnect to complete +2025/07/30 00:29:04.723104 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.723123 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.723167 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.723230 irc.go:152: INFO Disconnected from IRC +2025/07/30 00:29:04.723264 irc.go:282: INFO IRC shutdown complete +2025/07/30 00:29:04.723295 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestUsePrivmsgToSendAlertOnPreJoinedChannel (0.00s) === RUN TestSendAlertAndJoinChannel -2026/08/31 04:48:35.321219 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42789 -2026/08/31 04:48:35.321261 irc.go:302: INFO Connecting to IRC 127.0.0.1:42789 -2026/08/31 04:48:35.321276 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.321286 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42789. -2026/08/31 04:48:35.321439 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:47522 -2026/08/31 04:48:35.321470 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/08/31 04:48:35.321739 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.321764 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.321773 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.322137 irc.go:146: INFO Session established -2026/08/31 04:48:35.322269 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.322282 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.322301 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.322427 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.322448 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.322455 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.322491 reconciler.go:249: INFO Request to JOIN new channel #foobar -2026/08/31 04:48:35.322516 reconciler.go:105: INFO Channel #foobar monitor: waiting to join -2026/08/31 04:48:35.322524 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.322531 reconciler.go:114: INFO Channel #foobar monitor: join request sent -2026/08/31 04:48:35.322540 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.322555 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.322575 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/08/31 04:48:35.322600 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar -2026/08/31 04:48:35.322620 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.322625 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar -2026/08/31 04:48:35.322746 reconciler.go:205: INFO Received JOIN confirmation for channel #foobar -2026/08/31 04:48:35.322763 reconciler.go:79: INFO Setting JOIN state on channel #foobar -2026/08/31 04:48:35.322781 reconciler.go:118: INFO Channel #foobar monitor: join succeeded -2026/08/31 04:48:35.322845 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message -2026/08/31 04:48:35.322870 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/08/31 04:48:35.322877 reconciler.go:131: INFO Channel #foobar monitor: context canceled while monitoring -2026/08/31 04:48:35.322881 irc.go:296: INFO IRC routine asked to terminate -2026/08/31 04:48:35.322896 irc.go:271: INFO IRC client connected, quitting -2026/08/31 04:48:35.322909 irc.go:274: INFO Wait for IRC disconnect to complete -2026/08/31 04:48:35.322973 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.322987 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.323034 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.323102 irc.go:152: INFO Disconnected from IRC -2026/08/31 04:48:35.323126 irc.go:282: INFO IRC shutdown complete -2026/08/31 04:48:35.323152 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.723380 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43789 +2025/07/30 00:29:04.723418 irc.go:302: INFO Connecting to IRC 127.0.0.1:43789 +2025/07/30 00:29:04.723431 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.723440 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43789. +2025/07/30 00:29:04.723584 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:33566 +2025/07/30 00:29:04.723608 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/07/30 00:29:04.723750 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.723769 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.723775 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.724520 irc.go:146: INFO Session established +2025/07/30 00:29:04.724557 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.724576 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.724587 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.724655 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.724675 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.724682 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.724725 reconciler.go:249: INFO Request to JOIN new channel #foobar +2025/07/30 00:29:04.724763 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.724778 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.724792 reconciler.go:105: INFO Channel #foobar monitor: waiting to join +2025/07/30 00:29:04.724804 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/07/30 00:29:04.724808 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.724829 reconciler.go:114: INFO Channel #foobar monitor: join request sent +2025/07/30 00:29:04.724948 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar +2025/07/30 00:29:04.724973 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.724980 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar +2025/07/30 00:29:04.725037 reconciler.go:205: INFO Received JOIN confirmation for channel #foobar +2025/07/30 00:29:04.725052 reconciler.go:79: INFO Setting JOIN state on channel #foobar +2025/07/30 00:29:04.725070 reconciler.go:118: INFO Channel #foobar monitor: join succeeded +2025/07/30 00:29:04.725148 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message +2025/07/30 00:29:04.725191 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/07/30 00:29:04.725198 irc.go:296: INFO IRC routine asked to terminate +2025/07/30 00:29:04.725204 reconciler.go:131: INFO Channel #foobar monitor: context canceled while monitoring +2025/07/30 00:29:04.725208 irc.go:271: INFO IRC client connected, quitting +2025/07/30 00:29:04.725217 irc.go:274: INFO Wait for IRC disconnect to complete +2025/07/30 00:29:04.725282 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.725301 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.725344 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.725400 irc.go:152: INFO Disconnected from IRC +2025/07/30 00:29:04.725425 irc.go:282: INFO IRC shutdown complete +2025/07/30 00:29:04.725458 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertAndJoinChannel (0.00s) === RUN TestSendAlertDisconnected -2026/08/31 04:48:35.323268 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:44451 -2026/08/31 04:48:35.323345 irc.go:302: INFO Connecting to IRC 127.0.0.1:44451 -2026/08/31 04:48:35.323368 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.323378 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:44451. -2026/08/31 04:48:35.323535 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:42746 -2026/08/31 04:48:35.323657 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/08/31 04:48:35.323709 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.323730 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.323737 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.323745 irc_test.go:294: INFO =Server= Wait before completing session -2026/08/31 04:48:35.323751 irc_test.go:296: INFO =Server= Completing session -2026/08/31 04:48:35.323825 irc.go:146: INFO Session established -2026/08/31 04:48:35.323858 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.323879 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.323891 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.323934 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.323946 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.323959 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.324039 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.324054 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.324081 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/08/31 04:48:35.324123 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message -2026/08/31 04:48:35.324157 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/08/31 04:48:35.324196 irc.go:296: INFO IRC routine asked to terminate -2026/08/31 04:48:35.324209 irc.go:271: INFO IRC client connected, quitting -2026/08/31 04:48:35.324221 irc.go:274: INFO Wait for IRC disconnect to complete -2026/08/31 04:48:35.324264 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.324277 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.324314 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.324388 irc.go:152: INFO Disconnected from IRC -2026/08/31 04:48:35.324420 irc.go:282: INFO IRC shutdown complete -2026/08/31 04:48:35.324446 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.725579 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38191 +2025/07/30 00:29:04.725625 irc.go:302: INFO Connecting to IRC 127.0.0.1:38191 +2025/07/30 00:29:04.725643 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.725653 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38191. +2025/07/30 00:29:04.725835 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:57388 +2025/07/30 00:29:04.725860 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/07/30 00:29:04.725909 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.725934 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.725946 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.725956 irc_test.go:294: INFO =Server= Wait before completing session +2025/07/30 00:29:04.725965 irc_test.go:296: INFO =Server= Completing session +2025/07/30 00:29:04.726061 irc.go:146: INFO Session established +2025/07/30 00:29:04.726104 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.726127 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.726144 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.726222 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.726242 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.726249 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.726330 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.726347 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.726397 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/07/30 00:29:04.726415 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message +2025/07/30 00:29:04.726442 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/07/30 00:29:04.726451 irc.go:296: INFO IRC routine asked to terminate +2025/07/30 00:29:04.726460 irc.go:271: INFO IRC client connected, quitting +2025/07/30 00:29:04.726477 irc.go:274: INFO Wait for IRC disconnect to complete +2025/07/30 00:29:04.726524 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.726554 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.726603 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.726691 irc.go:152: INFO Disconnected from IRC +2025/07/30 00:29:04.726713 irc.go:282: INFO IRC shutdown complete +2025/07/30 00:29:04.726736 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertDisconnected (0.00s) === RUN TestReconnect -2026/08/31 04:48:35.324576 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41427 -2026/08/31 04:48:35.324763 irc.go:302: INFO Connecting to IRC 127.0.0.1:41427 -2026/08/31 04:48:35.324785 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.324828 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41427. -2026/08/31 04:48:35.324984 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:38838 -2026/08/31 04:48:35.325023 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/08/31 04:48:35.325149 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.325168 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.325176 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.325266 irc.go:146: INFO Session established -2026/08/31 04:48:35.325306 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.325319 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.325333 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.325417 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.325437 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.325444 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.325519 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.325571 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:38838: read tcp 127.0.0.1:41427->127.0.0.1:38838: use of closed network connection -2026/08/31 04:48:35.325606 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.325620 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.325646 irc.go:152: INFO Disconnected from IRC -2026/08/31 04:48:35.325646 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/08/31 04:48:35.325677 irc.go:302: INFO Connecting to IRC 127.0.0.1:41427 -2026/08/31 04:48:35.325686 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.325700 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41427. -2026/08/31 04:48:35.325878 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/08/31 04:48:35.325880 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:38846 -2026/08/31 04:48:35.325924 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.325940 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.325950 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.326032 irc.go:146: INFO Session established -2026/08/31 04:48:35.326063 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.326106 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.326128 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.326197 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.326212 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.326217 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.326267 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join -2026/08/31 04:48:35.326275 irc.go:296: INFO IRC routine asked to terminate -2026/08/31 04:48:35.326288 irc.go:271: INFO IRC client connected, quitting -2026/08/31 04:48:35.326295 irc.go:274: INFO Wait for IRC disconnect to complete -2026/08/31 04:48:35.326310 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.326327 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.326348 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.326367 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.326419 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.326483 irc.go:152: INFO Disconnected from IRC -2026/08/31 04:48:35.326501 irc.go:282: INFO IRC shutdown complete -2026/08/31 04:48:35.326533 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.726900 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46315 +2025/07/30 00:29:04.726949 irc.go:302: INFO Connecting to IRC 127.0.0.1:46315 +2025/07/30 00:29:04.726967 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.726978 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46315. +2025/07/30 00:29:04.727151 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:56850 +2025/07/30 00:29:04.727212 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/07/30 00:29:04.727269 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.727296 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.727310 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.727432 irc.go:146: INFO Session established +2025/07/30 00:29:04.727476 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.727494 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.727514 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.727587 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.727609 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.727617 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.727683 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.727696 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:56850: read tcp 127.0.0.1:46315->127.0.0.1:56850: use of closed network connection +2025/07/30 00:29:04.727746 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.727758 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.727773 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/07/30 00:29:04.727775 irc.go:152: INFO Disconnected from IRC +2025/07/30 00:29:04.727804 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/07/30 00:29:04.727821 irc.go:302: INFO Connecting to IRC 127.0.0.1:46315 +2025/07/30 00:29:04.727828 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.727842 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46315. +2025/07/30 00:29:04.727975 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:56866 +2025/07/30 00:29:04.727998 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/07/30 00:29:04.728052 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.728070 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.728079 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.728175 irc.go:146: INFO Session established +2025/07/30 00:29:04.728226 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.728242 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.728253 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.728326 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.728346 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.728354 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.728393 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join +2025/07/30 00:29:04.728402 irc.go:296: INFO IRC routine asked to terminate +2025/07/30 00:29:04.728414 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.728419 irc.go:271: INFO IRC client connected, quitting +2025/07/30 00:29:04.728422 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.728426 irc.go:274: INFO Wait for IRC disconnect to complete +2025/07/30 00:29:04.728473 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.728494 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.728549 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.728618 irc.go:152: INFO Disconnected from IRC +2025/07/30 00:29:04.728643 irc.go:282: INFO IRC shutdown complete +2025/07/30 00:29:04.728667 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestReconnect (0.00s) === RUN TestConnectErrorRetry -2026/08/31 04:48:35.326641 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39671 -2026/08/31 04:48:35.326685 irc.go:302: INFO Connecting to IRC 127.0.0.1:39671 -2026/08/31 04:48:35.326703 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.326709 fake_delayer.go:45: INFO Waiting StopDelay signal -2026/08/31 04:48:35.326715 fake_delayer.go:47: INFO Received StopDelay signal -2026/08/31 04:48:35.326725 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39671. -2026/08/31 04:48:35.326872 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34668 -2026/08/31 04:48:35.326913 irc_server_for_test.go:157: INFO =Server= Closing connection early -2026/08/31 04:48:35.326879 connection.go:399: INFO irc.Connect(): Performing SSL handshake. -2026/08/31 04:48:35.327230 irc.go:307: ERROR Could not connect to IRC: EOF -2026/08/31 04:48:35.327246 irc.go:302: INFO Connecting to IRC 127.0.0.1:39671 -2026/08/31 04:48:35.327250 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.327253 fake_delayer.go:45: INFO Waiting StopDelay signal -2026/08/31 04:48:35.327262 fake_delayer.go:47: INFO Received StopDelay signal -2026/08/31 04:48:35.327273 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39671. -2026/08/31 04:48:35.327419 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34672 -2026/08/31 04:48:35.327436 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/08/31 04:48:35.327479 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.327497 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.327507 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.327603 irc.go:146: INFO Session established -2026/08/31 04:48:35.327636 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.327653 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.327667 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.327738 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.327756 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.327762 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.327804 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join -2026/08/31 04:48:35.327815 irc.go:296: INFO IRC routine asked to terminate -2026/08/31 04:48:35.327819 irc.go:271: INFO IRC client connected, quitting -2026/08/31 04:48:35.327826 irc.go:274: INFO Wait for IRC disconnect to complete -2026/08/31 04:48:35.327877 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.327896 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.327918 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.327928 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.327966 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.328054 irc.go:152: INFO Disconnected from IRC -2026/08/31 04:48:35.328079 irc.go:282: INFO IRC shutdown complete -2026/08/31 04:48:35.328104 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.728789 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34699 +2025/07/30 00:29:04.728828 irc.go:302: INFO Connecting to IRC 127.0.0.1:34699 +2025/07/30 00:29:04.728845 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.728852 fake_delayer.go:45: INFO Waiting StopDelay signal +2025/07/30 00:29:04.728870 fake_delayer.go:47: INFO Received StopDelay signal +2025/07/30 00:29:04.728885 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34699. +2025/07/30 00:29:04.729043 connection.go:399: INFO irc.Connect(): Performing SSL handshake. +2025/07/30 00:29:04.729039 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:59920 +2025/07/30 00:29:04.729161 irc_server_for_test.go:157: INFO =Server= Closing connection early +2025/07/30 00:29:04.729361 irc.go:307: ERROR Could not connect to IRC: EOF +2025/07/30 00:29:04.729381 irc.go:302: INFO Connecting to IRC 127.0.0.1:34699 +2025/07/30 00:29:04.729386 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.729392 fake_delayer.go:45: INFO Waiting StopDelay signal +2025/07/30 00:29:04.729405 fake_delayer.go:47: INFO Received StopDelay signal +2025/07/30 00:29:04.729418 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34699. +2025/07/30 00:29:04.729529 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:59936 +2025/07/30 00:29:04.729573 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/07/30 00:29:04.729626 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.729639 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.729646 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.729734 irc.go:146: INFO Session established +2025/07/30 00:29:04.729768 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.729789 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.729805 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.729860 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.729878 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.729905 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.729946 irc.go:296: INFO IRC routine asked to terminate +2025/07/30 00:29:04.729961 irc.go:271: INFO IRC client connected, quitting +2025/07/30 00:29:04.729970 irc.go:274: INFO Wait for IRC disconnect to complete +2025/07/30 00:29:04.729948 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join +2025/07/30 00:29:04.729991 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.730009 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.730010 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.730031 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.730084 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.730165 irc.go:152: INFO Disconnected from IRC +2025/07/30 00:29:04.730190 irc.go:282: INFO IRC shutdown complete +2025/07/30 00:29:04.730220 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestConnectErrorRetry (0.00s) === RUN TestIdentify -2026/08/31 04:48:35.328213 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:45373 -2026/08/31 04:48:35.328250 irc.go:302: INFO Connecting to IRC 127.0.0.1:45373 -2026/08/31 04:48:35.328267 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.328276 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:45373. -2026/08/31 04:48:35.328429 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:40020 -2026/08/31 04:48:35.328440 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/08/31 04:48:35.328493 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.328537 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.328592 irc.go:167: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. -2026/08/31 04:48:35.328659 irc.go:191: INFO Handling NickServ request to IDENTIFY -2026/08/31 04:48:35.328796 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword -2026/08/31 04:48:35.328815 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.328799 irc.go:146: INFO Session established -2026/08/31 04:48:35.328842 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request -2026/08/31 04:48:35.328865 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.328880 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.328897 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.328967 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.328985 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.328994 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.329030 irc.go:296: INFO IRC routine asked to terminate -2026/08/31 04:48:35.329043 irc.go:271: INFO IRC client connected, quitting -2026/08/31 04:48:35.329050 irc.go:274: INFO Wait for IRC disconnect to complete -2026/08/31 04:48:35.329030 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join -2026/08/31 04:48:35.329105 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.329122 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.329126 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.329133 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.329183 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.329260 irc.go:152: INFO Disconnected from IRC -2026/08/31 04:48:35.329286 irc.go:282: INFO IRC shutdown complete -2026/08/31 04:48:35.329309 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.730333 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43367 +2025/07/30 00:29:04.730375 irc.go:302: INFO Connecting to IRC 127.0.0.1:43367 +2025/07/30 00:29:04.730392 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.730402 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43367. +2025/07/30 00:29:04.730550 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:43216 +2025/07/30 00:29:04.730569 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/07/30 00:29:04.730625 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.730674 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.730720 irc.go:167: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. +2025/07/30 00:29:04.730744 irc.go:191: INFO Handling NickServ request to IDENTIFY +2025/07/30 00:29:04.730781 irc.go:146: INFO Session established +2025/07/30 00:29:04.730810 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request +2025/07/30 00:29:04.730848 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.730868 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.730877 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.730816 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword +2025/07/30 00:29:04.730921 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.730949 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.730964 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.730975 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.731009 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join +2025/07/30 00:29:04.731015 irc.go:296: INFO IRC routine asked to terminate +2025/07/30 00:29:04.731030 irc.go:271: INFO IRC client connected, quitting +2025/07/30 00:29:04.731042 irc.go:274: INFO Wait for IRC disconnect to complete +2025/07/30 00:29:04.731041 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.731052 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.731080 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.731097 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.731149 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.731234 irc.go:152: INFO Disconnected from IRC +2025/07/30 00:29:04.731251 irc.go:282: INFO IRC shutdown complete +2025/07/30 00:29:04.731272 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestIdentify (0.00s) === RUN TestGhost -2026/08/31 04:48:35.329410 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46327 -2026/08/31 04:48:35.329448 irc.go:302: INFO Connecting to IRC 127.0.0.1:46327 -2026/08/31 04:48:35.329464 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.329476 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46327. -2026/08/31 04:48:35.329651 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:50762 -2026/08/31 04:48:35.329667 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/08/31 04:48:35.329747 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.329769 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.329880 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' -2026/08/31 04:48:35.329941 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ -2026/08/31 04:48:35.330023 irc.go:146: INFO Session established -2026/08/31 04:48:35.330049 irc.go:206: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' -2026/08/31 04:48:35.330065 irc.go:212: INFO Changing nick to 'foo' -2026/08/31 04:48:35.330076 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request -2026/08/31 04:48:35.330090 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.330105 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.330115 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.330151 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword -2026/08/31 04:48:35.330167 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.330185 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.330200 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.330206 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.330214 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.330252 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join -2026/08/31 04:48:35.330257 irc.go:296: INFO IRC routine asked to terminate -2026/08/31 04:48:35.330272 irc.go:271: INFO IRC client connected, quitting -2026/08/31 04:48:35.330282 irc.go:274: INFO Wait for IRC disconnect to complete -2026/08/31 04:48:35.330309 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.330335 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.330381 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.330453 irc.go:152: INFO Disconnected from IRC -2026/08/31 04:48:35.330484 irc.go:282: INFO IRC shutdown complete -2026/08/31 04:48:35.330510 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.731358 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41471 +2025/07/30 00:29:04.731385 irc.go:302: INFO Connecting to IRC 127.0.0.1:41471 +2025/07/30 00:29:04.731396 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.731402 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41471. +2025/07/30 00:29:04.731542 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/07/30 00:29:04.731538 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:36862 +2025/07/30 00:29:04.731578 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.731591 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.731656 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' +2025/07/30 00:29:04.731692 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ +2025/07/30 00:29:04.731741 irc.go:146: INFO Session established +2025/07/30 00:29:04.731758 irc.go:206: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' +2025/07/30 00:29:04.731765 irc.go:212: INFO Changing nick to 'foo' +2025/07/30 00:29:04.731772 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request +2025/07/30 00:29:04.731782 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.731791 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.731796 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.731839 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword +2025/07/30 00:29:04.731850 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.731855 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.731859 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.731863 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.731867 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.731883 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join +2025/07/30 00:29:04.731892 irc.go:296: INFO IRC routine asked to terminate +2025/07/30 00:29:04.731897 irc.go:271: INFO IRC client connected, quitting +2025/07/30 00:29:04.731901 irc.go:274: INFO Wait for IRC disconnect to complete +2025/07/30 00:29:04.731924 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.731935 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.731968 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.732035 irc.go:152: INFO Disconnected from IRC +2025/07/30 00:29:04.732055 irc.go:282: INFO IRC shutdown complete +2025/07/30 00:29:04.732070 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestGhost (0.00s) === RUN TestStopRunningWhenHalfConnected -2026/08/31 04:48:35.330606 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34663 -2026/08/31 04:48:35.330644 irc.go:302: INFO Connecting to IRC 127.0.0.1:34663 -2026/08/31 04:48:35.330661 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.330669 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34663. -2026/08/31 04:48:35.330844 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/08/31 04:48:35.330845 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:40740 -2026/08/31 04:48:35.330924 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.330943 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.330952 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.330959 irc_test.go:591: INFO =Server= NOT completing session -2026/08/31 04:48:35.330993 irc.go:323: INFO IRC routine asked to terminate -2026/08/31 04:48:35.330982 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.331019 irc.go:282: INFO IRC shutdown complete -2026/08/31 04:48:35.331080 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:40740 disconnected -2026/08/31 04:48:35.331077 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:40740->127.0.0.1:34663: use of closed network connection -2026/08/31 04:48:35.331114 irc.go:152: INFO Disconnected from IRC -2026/08/31 04:48:35.331144 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.732137 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34003 +2025/07/30 00:29:04.732163 irc.go:302: INFO Connecting to IRC 127.0.0.1:34003 +2025/07/30 00:29:04.732174 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.732180 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34003. +2025/07/30 00:29:04.732317 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/07/30 00:29:04.732316 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:56082 +2025/07/30 00:29:04.732346 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.732362 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.732373 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.732385 irc_test.go:591: INFO =Server= NOT completing session +2025/07/30 00:29:04.732401 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.732416 irc.go:323: INFO IRC routine asked to terminate +2025/07/30 00:29:04.732427 irc.go:282: INFO IRC shutdown complete +2025/07/30 00:29:04.732457 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:56082->127.0.0.1:34003: use of closed network connection +2025/07/30 00:29:04.732463 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:56082 disconnected +2025/07/30 00:29:04.732480 irc.go:152: INFO Disconnected from IRC +2025/07/30 00:29:04.732535 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestStopRunningWhenHalfConnected (0.00s) === RUN TestPreJoinChannels -2026/08/31 04:48:35.331268 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:45007 -2026/08/31 04:48:35.331308 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:45007. -2026/08/31 04:48:35.331484 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:41820 -2026/08/31 04:48:35.331534 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.331553 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.331567 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.331697 reconciler.go:105: INFO Channel #baz monitor: waiting to join -2026/08/31 04:48:35.331770 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.331783 reconciler.go:114: INFO Channel #baz monitor: join request sent -2026/08/31 04:48:35.331726 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.331832 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.331846 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.331853 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz -2026/08/31 04:48:35.331738 reconciler.go:105: INFO Channel #bar monitor: waiting to join -2026/08/31 04:48:35.331874 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.331887 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz -2026/08/31 04:48:35.331915 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.331928 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.331938 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.331935 reconciler.go:205: INFO Received JOIN confirmation for channel #baz -2026/08/31 04:48:35.331876 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.331961 reconciler.go:79: INFO Setting JOIN state on channel #baz -2026/08/31 04:48:35.331969 reconciler.go:114: INFO Channel #bar monitor: join request sent -2026/08/31 04:48:35.331972 reconciler.go:118: INFO Channel #baz monitor: join succeeded -2026/08/31 04:48:35.331996 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar -2026/08/31 04:48:35.332013 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.332050 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar -2026/08/31 04:48:35.332074 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.332088 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.332103 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/08/31 04:48:35.332127 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.332144 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.332200 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.332222 reconciler.go:205: INFO Received JOIN confirmation for channel #bar -2026/08/31 04:48:35.332241 reconciler.go:79: INFO Setting JOIN state on channel #bar -2026/08/31 04:48:35.332263 reconciler.go:118: INFO Channel #bar monitor: join succeeded -2026/08/31 04:48:35.332277 reconciler.go:131: INFO Channel #bar monitor: context canceled while monitoring -2026/08/31 04:48:35.332278 reconciler.go:131: INFO Channel #baz monitor: context canceled while monitoring -2026/08/31 04:48:35.332284 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/08/31 04:48:35.332320 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.732636 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42013 +2025/07/30 00:29:04.732667 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42013. +2025/07/30 00:29:04.732819 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:57592 +2025/07/30 00:29:04.732883 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.732898 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.732906 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.732974 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.732989 reconciler.go:105: INFO Channel #bar monitor: waiting to join +2025/07/30 00:29:04.733000 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.733015 reconciler.go:114: INFO Channel #bar monitor: join request sent +2025/07/30 00:29:04.732996 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.733067 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar +2025/07/30 00:29:04.733058 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.732975 reconciler.go:105: INFO Channel #baz monitor: waiting to join +2025/07/30 00:29:04.733102 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.733109 reconciler.go:114: INFO Channel #baz monitor: join request sent +2025/07/30 00:29:04.733091 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.733117 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar +2025/07/30 00:29:04.733154 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.733164 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.733169 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.733184 reconciler.go:205: INFO Received JOIN confirmation for channel #bar +2025/07/30 00:29:04.733198 reconciler.go:79: INFO Setting JOIN state on channel #bar +2025/07/30 00:29:04.733187 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz +2025/07/30 00:29:04.733209 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.733218 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz +2025/07/30 00:29:04.733230 reconciler.go:118: INFO Channel #bar monitor: join succeeded +2025/07/30 00:29:04.733222 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.733240 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.733252 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/07/30 00:29:04.733280 reconciler.go:205: INFO Received JOIN confirmation for channel #baz +2025/07/30 00:29:04.733292 reconciler.go:79: INFO Setting JOIN state on channel #baz +2025/07/30 00:29:04.733290 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.733302 reconciler.go:118: INFO Channel #baz monitor: join succeeded +2025/07/30 00:29:04.733307 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.733356 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.733427 reconciler.go:131: INFO Channel #bar monitor: context canceled while monitoring +2025/07/30 00:29:04.733427 reconciler.go:131: INFO Channel #baz monitor: context canceled while monitoring +2025/07/30 00:29:04.733433 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/07/30 00:29:04.733458 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestPreJoinChannels (0.00s) === RUN TestKeepJoining -2026/08/31 04:48:35.332432 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36371 -2026/08/31 04:48:35.332485 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36371. -2026/08/31 04:48:35.332634 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:53772 -2026/08/31 04:48:35.332684 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.332702 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.332713 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.332786 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.332807 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.332822 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.332875 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.332899 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.332910 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.332929 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2026/08/31 04:48:35.332941 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.332946 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.332958 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.333015 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.333033 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.333039 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.333062 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2026/08/31 04:48:35.333072 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.333078 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.333090 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.333138 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.333155 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.333161 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.333215 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.333228 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.333236 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.333236 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.333246 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/08/31 04:48:35.333270 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.333344 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/08/31 04:48:35.333380 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.733539 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46521 +2025/07/30 00:29:04.733567 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46521. +2025/07/30 00:29:04.733737 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:51624 +2025/07/30 00:29:04.733815 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.733840 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.733858 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.733981 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.734003 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.734019 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.734083 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.734104 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.734118 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.734145 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2025/07/30 00:29:04.734157 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.734161 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.734172 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.734233 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.734254 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.734262 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.734284 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2025/07/30 00:29:04.734295 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.734302 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.734322 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.734377 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.734397 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.734402 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.734454 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.734470 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.734485 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.734501 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.734518 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/07/30 00:29:04.734514 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.734600 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/07/30 00:29:04.734626 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestKeepJoining (0.00s) === RUN TestKickRejoin -2026/08/31 04:48:35.333482 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43801 -2026/08/31 04:48:35.333518 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43801. -2026/08/31 04:48:35.333660 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:39656 -2026/08/31 04:48:35.333759 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/08/31 04:48:35.333777 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/08/31 04:48:35.333790 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/08/31 04:48:35.333877 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.333896 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.333910 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.333987 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.334004 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.334011 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.334040 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! -2026/08/31 04:48:35.334114 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.334131 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.334155 reconciler.go:223: INFO Received KICK for channel #foo -2026/08/31 04:48:35.334167 reconciler.go:93: INFO Removing JOIN state on channel #foo -2026/08/31 04:48:35.334155 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/08/31 04:48:35.334181 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/08/31 04:48:35.334191 fake_delayer.go:43: INFO Faking Backoff -2026/08/31 04:48:35.334200 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/08/31 04:48:35.334278 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/08/31 04:48:35.334297 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/08/31 04:48:35.334308 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/08/31 04:48:35.334371 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/08/31 04:48:35.334387 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/08/31 04:48:35.334380 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/08/31 04:48:35.334409 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/08/31 04:48:35.334414 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/08/31 04:48:35.334473 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/08/31 04:48:35.334547 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/08/31 04:48:35.334579 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/07/30 00:29:04.734718 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40867 +2025/07/30 00:29:04.734744 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40867. +2025/07/30 00:29:04.734847 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:42176 +2025/07/30 00:29:04.734950 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/07/30 00:29:04.734967 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/07/30 00:29:04.734972 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/07/30 00:29:04.735040 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.735058 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.735072 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.735134 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.735168 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.735177 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.735211 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! +2025/07/30 00:29:04.735261 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.735277 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.735304 reconciler.go:223: INFO Received KICK for channel #foo +2025/07/30 00:29:04.735317 reconciler.go:93: INFO Removing JOIN state on channel #foo +2025/07/30 00:29:04.735304 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/07/30 00:29:04.735338 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/07/30 00:29:04.735350 fake_delayer.go:43: INFO Faking Backoff +2025/07/30 00:29:04.735363 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/07/30 00:29:04.735404 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/07/30 00:29:04.735420 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/07/30 00:29:04.735444 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/07/30 00:29:04.735509 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/07/30 00:29:04.735532 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/07/30 00:29:04.735553 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/07/30 00:29:04.735534 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/07/30 00:29:04.735606 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/07/30 00:29:04.735613 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/07/30 00:29:04.735684 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/07/30 00:29:04.735717 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.030s +ok github.com/google/alertmanager-irc-relay 0.029s ? github.com/google/alertmanager-irc-relay/logging [no test files] create-stamp debian/debhelper-build-stamp dh_testroot -O--buildsystem=golang @@ -2094,8 +2131,8 @@ dh_gencontrol -O--buildsystem=golang dh_md5sums -O--buildsystem=golang dh_builddeb -O--buildsystem=golang -dpkg-deb: building package 'alertmanager-irc-relay-dbgsym' in '../alertmanager-irc-relay-dbgsym_0.5.1-3_amd64.deb'. dpkg-deb: building package 'alertmanager-irc-relay' in '../alertmanager-irc-relay_0.5.1-3_amd64.deb'. +dpkg-deb: building package 'alertmanager-irc-relay-dbgsym' in '../alertmanager-irc-relay-dbgsym_0.5.1-3_amd64.deb'. dpkg-genbuildinfo --build=binary -O../alertmanager-irc-relay_0.5.1-3_amd64.buildinfo dpkg-genchanges --build=binary -O../alertmanager-irc-relay_0.5.1-3_amd64.changes dpkg-genchanges: info: binary-only upload (no source code included) @@ -2103,12 +2140,14 @@ dpkg-buildpackage: info: binary-only upload (no source included) dpkg-genchanges: info: not including original source code in upload I: copying local configuration +I: user script /srv/workspace/pbuilder/3891795/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/3891795/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/3876104 and its subdirectories -I: Current time: Mon Aug 31 04:48:53 -12 2026 -I: pbuilder-time-stamp: 1788194933 +I: removing directory /srv/workspace/pbuilder/3891795 and its subdirectories +I: Current time: Wed Jul 30 00:29:17 +14 2025 +I: pbuilder-time-stamp: 1753784957