Diff of the two buildlogs: -- --- b1/build.log 2025-10-06 18:26:05.584761805 +0000 +++ b2/build.log 2025-10-06 18:32:32.021233957 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Sun Nov 8 12:42:58 -12 2026 -I: pbuilder-time-stamp: 1794184978 +I: Current time: Tue Oct 7 08:26:07 +14 2025 +I: pbuilder-time-stamp: 1759775167 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/forky-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/4172889/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/4007292/tmp/hooks/D01_modify_environment starting +debug: Running on infom01-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 Oct 6 18: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/4007292/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/4007292/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=16 ' - DISTRIBUTION='forky' - 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]="3" [2]="3" [3]="1" [4]="release" [5]="x86_64-pc-linux-gnu") + BASH_VERSION='5.3.3(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=12 ' + DIRSTACK=() + DISTRIBUTION=forky + EUID=0 + FUNCNAME=([0]="Echo" [1]="main") + GROUPS=() + HOME=/root + HOSTNAME=i-capture-the-hostname + HOSTTYPE=x86_64 + HOST_ARCH=amd64 IFS=' ' - INVOCATION_ID='1aaee322c24049049b4e3f9843bd074a' - 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='4172889' - PS1='# ' - PS2='> ' + INVOCATION_ID=989dfc8d330d4b7182fa783881910b9d + 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=4007292 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.ijvOWsjI/pbuilderrc_VsWy --distribution forky --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/forky-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.ijvOWsjI/b1 --logfile b1/build.log alertmanager-irc-relay_0.5.1-3.dsc' - SUDO_GID='109' - SUDO_HOME='/var/lib/jenkins' - SUDO_UID='104' - SUDO_USER='jenkins' - TERM='unknown' - TZ='/usr/share/zoneinfo/Etc/GMT+12' - USER='root' - _='/usr/bin/systemd-run' + 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.ijvOWsjI/pbuilderrc_haE5 --distribution forky --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/forky-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.ijvOWsjI/b2 --logfile b2/build.log alertmanager-irc-relay_0.5.1-3.dsc' + SUDO_GID=109 + SUDO_HOME=/var/lib/jenkins + SUDO_UID=104 + SUDO_USER=jenkins + TERM=unknown + TZ=/usr/share/zoneinfo/Etc/GMT-14 + UID=0 + USER=root + _='I: set' I: uname -a - Linux infom02-amd64 6.12.48+deb13-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.12.48-1 (2025-09-20) x86_64 GNU/Linux + Linux i-capture-the-hostname 6.12.48+deb13-cloud-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.12.48-1 (2025-09-20) x86_64 GNU/Linux I: ls -l /bin - lrwxrwxrwx 1 root root 7 Aug 10 2025 /bin -> usr/bin -I: user script /srv/workspace/pbuilder/4172889/tmp/hooks/D02_print_environment finished + lrwxrwxrwx 1 root root 7 Aug 10 12:30 /bin -> usr/bin +I: user script /srv/workspace/pbuilder/4007292/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -346,7 +378,7 @@ Get: 225 http://deb.debian.org/debian forky/main amd64 golang-protobuf-extensions-dev all 1.0.4-3 [29.9 kB] Get: 226 http://deb.debian.org/debian forky/main amd64 golang-uber-automaxprocs-dev all 1.5.3-1 [22.3 kB] Get: 227 http://deb.debian.org/debian forky/main amd64 golang-github-prometheus-alertmanager-dev all 0.28.1+ds-2 [1138 kB] -Fetched 171 MB in 15s (11.3 MB/s) +Fetched 171 MB in 25s (6770 kB/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 ... 19898 files and directories currently installed.) @@ -1088,8 +1120,8 @@ Setting up tzdata (2025b-5) ... Current default time zone: 'Etc/UTC' -Local time is now: Mon Nov 9 00:48:09 UTC 2026. -Universal Time is now: Mon Nov 9 00:48:09 UTC 2026. +Local time is now: Mon Oct 6 18:31:39 UTC 2025. +Universal Time is now: Mon Oct 6 18:31:39 UTC 2025. Run 'dpkg-reconfigure tzdata' if you wish to change it. Setting up golang-github-cespare-xxhash-dev (2.3.0-1) ... @@ -1275,7 +1307,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/4007292/tmp/hooks/A99_set_merged_usr starting +Not re-configuring usrmerge for forky +I: user script /srv/workspace/pbuilder/4007292/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 @@ -1293,235 +1329,244 @@ 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 16 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging -internal/godebugs -internal/unsafeheader + cd obj-x86_64-linux-gnu && go install -trimpath -v -p 12 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging +internal/goos +internal/asan internal/goarch -math/bits -internal/coverage/rtcov -internal/byteorder internal/msan -internal/asan -internal/profilerecord -unicode -internal/goos +internal/coverage/rtcov +internal/godebugs internal/goexperiment -sync/atomic -internal/cpu +internal/profilerecord +internal/byteorder +internal/unsafeheader internal/runtime/atomic -internal/runtime/syscall -internal/runtime/math -internal/abi unicode/utf8 +internal/runtime/syscall internal/itoa +unicode +math/bits +sync/atomic +internal/abi +internal/runtime/math +internal/cpu +internal/runtime/sys +internal/chacha8rand container/list crypto/internal/fips140/alias -internal/runtime/sys +crypto/internal/fips140deps/byteorder cmp crypto/internal/boring/sig -internal/chacha8rand -crypto/internal/fips140deps/byteorder +crypto/internal/fips140/subtle unicode/utf16 vendor/golang.org/x/crypto/cryptobyte/asn1 vendor/golang.org/x/crypto/internal/alias -crypto/internal/fips140/subtle +internal/runtime/exithook internal/nettrace +internal/bytealg +crypto/internal/fips140deps/cpu +math encoding github.com/fluffle/goirc/logging log/internal log/slog/internal google.golang.org/protobuf/internal/flags google.golang.org/protobuf/internal/set -internal/runtime/exithook -crypto/internal/fips140deps/cpu -internal/bytealg -math -internal/race internal/stringslite +internal/race internal/sync internal/runtime/maps runtime internal/reflectlite -iter weak +iter crypto/subtle -sync runtime/metrics -slices +sync maps -internal/bisect -internal/testlog +slices +errors +sort internal/singleflight unique +internal/bisect +internal/testlog log/slog/internal/buffer google.golang.org/protobuf/internal/pragma -runtime/cgo -errors -sort -internal/godebug internal/oserror +runtime/cgo +io +strconv path math/rand/v2 -github.com/beorn7/perks/quantile +syscall vendor/golang.org/x/net/dns/dnsmessage -io -strconv +internal/godebug hash -golang.org/x/text/internal/tag +crypto/internal/randutil +github.com/beorn7/perks/quantile +strings bytes -syscall crypto +github.com/prometheus/client_golang/prometheus/promhttp/internal +golang.org/x/text/internal/tag +reflect net/netip -vendor/golang.org/x/text/transform hash/crc32 -hash/fnv -golang.org/x/text/transform -github.com/prometheus/client_golang/prometheus/promhttp/internal -crypto/internal/randutil crypto/internal/fips140deps/godebug -strings -reflect math/rand -crypto/internal/impl +hash/fnv +golang.org/x/text/transform +vendor/golang.org/x/text/transform crypto/internal/fips140 -net/http/internal/ascii +crypto/internal/impl bufio +net/http/internal/ascii github.com/munnerz/goautoneg -html regexp/syntax -crypto/tls/internal/fips140tls +html crypto/internal/fips140/sha256 crypto/internal/fips140/sha512 +crypto/tls/internal/fips140tls crypto/internal/fips140/sha3 -internal/syscall/execenv -internal/syscall/unix time -crypto/sha3 +internal/syscall/unix +internal/syscall/execenv crypto/internal/fips140/hmac +crypto/sha3 crypto/internal/fips140/check crypto/internal/fips140hash -regexp -crypto/internal/fips140/hkdf -crypto/internal/fips140/tls12 +crypto/internal/fips140/nistec/fiat crypto/internal/fips140/edwards25519/field crypto/internal/fips140/bigmod +crypto/internal/fips140/hkdf crypto/internal/fips140/aes -crypto/internal/fips140/nistec/fiat +crypto/internal/fips140/tls12 crypto/internal/fips140/tls13 crypto/internal/fips140/edwards25519 +regexp context -io/fs internal/poll +io/fs +crypto/internal/fips140/nistec internal/filepathlite embed google.golang.org/protobuf/internal/editiondefaults os -crypto/internal/fips140/nistec internal/fmtsort encoding/binary encoding/base64 vendor/golang.org/x/crypto/internal/poly1305 github.com/cespare/xxhash golang.org/x/sys/unix -crypto/internal/sysrand encoding/pem +crypto/internal/sysrand +path/filepath google.golang.org/protobuf/internal/detrand fmt -path/filepath github.com/prometheus/procfs/internal/util -io/ioutil vendor/golang.org/x/sys/cpu os/signal +io/ioutil +net crypto/internal/entropy crypto/internal/fips140/drbg -crypto/internal/fips140/aes/gcm crypto/internal/fips140only +crypto/internal/fips140/ecdh +crypto/internal/fips140/aes/gcm crypto/internal/fips140/ed25519 +crypto/internal/fips140/ecdsa crypto/internal/fips140/mlkem crypto/internal/fips140/rsa crypto/rc4 crypto/md5 crypto/cipher -crypto/internal/fips140/ecdh -crypto/internal/fips140/ecdsa encoding/hex -flag net/url -github.com/golang/mock/gomock +flag log encoding/json -vendor/golang.org/x/net/http2/hpack -mime +github.com/golang/mock/gomock +vendor/golang.org/x/text/unicode/norm math/big compress/flate -vendor/golang.org/x/text/unicode/norm -mime/quotedprintable -net/http/internal crypto/internal/boring crypto/des -vendor/golang.org/x/crypto/chacha20 crypto/aes crypto/ecdh crypto/sha512 crypto/hmac +vendor/golang.org/x/crypto/chacha20 crypto/sha1 +vendor/golang.org/x/crypto/chacha20poly1305 crypto/sha256 +github.com/fluffle/goirc/state vendor/golang.org/x/text/unicode/bidi +compress/gzip github.com/google/alertmanager-irc-relay/logging +vendor/golang.org/x/net/http2/hpack +mime +mime/quotedprintable +net/http/internal google.golang.org/protobuf/internal/errors go/token -vendor/golang.org/x/crypto/chacha20poly1305 -github.com/fluffle/goirc/state google.golang.org/protobuf/encoding/protowire google.golang.org/protobuf/internal/version runtime/debug -compress/gzip github.com/prometheus/procfs/internal/fs +vendor/golang.org/x/text/secure/bidirule golang.org/x/text/internal/language -google.golang.org/protobuf/reflect/protoreflect golang.org/x/text/unicode/norm +google.golang.org/protobuf/reflect/protoreflect text/template/parse gopkg.in/yaml.v2 -vendor/golang.org/x/text/secure/bidirule vendor/golang.org/x/net/idna +log/slog golang.org/x/text/internal/language/compact text/template -crypto/internal/boring/bbig crypto/elliptic +crypto/internal/boring/bbig encoding/asn1 -crypto/rand crypto/dsa -google.golang.org/protobuf/internal/descfmt -log/slog -google.golang.org/protobuf/internal/strs +crypto/rand google.golang.org/protobuf/internal/descopts +google.golang.org/protobuf/internal/strs +google.golang.org/protobuf/internal/descfmt google.golang.org/protobuf/internal/encoding/messageset google.golang.org/protobuf/internal/genid -google.golang.org/protobuf/internal/order crypto/ed25519 crypto/internal/hpke crypto/rsa -google.golang.org/protobuf/reflect/protoregistry google.golang.org/protobuf/internal/encoding/text +google.golang.org/protobuf/internal/order +google.golang.org/protobuf/reflect/protoregistry google.golang.org/protobuf/runtime/protoiface golang.org/x/text/language google.golang.org/protobuf/internal/protolazy google.golang.org/protobuf/proto -crypto/x509/pkix -vendor/golang.org/x/crypto/cryptobyte +github.com/prometheus/alertmanager/featurecontrol +github.com/prometheus/common/promslog google.golang.org/protobuf/internal/encoding/defval +vendor/golang.org/x/crypto/cryptobyte +crypto/x509/pkix golang.org/x/text/internal golang.org/x/text/cases -github.com/prometheus/alertmanager/featurecontrol -github.com/prometheus/common/promslog -crypto/ecdsa html/template -net -google.golang.org/protobuf/internal/filedesc -google.golang.org/protobuf/encoding/prototext +crypto/ecdsa google.golang.org/protobuf/encoding/protodelim +google.golang.org/protobuf/encoding/prototext +google.golang.org/protobuf/internal/filedesc google.golang.org/protobuf/internal/encoding/tag google.golang.org/protobuf/internal/impl +golang.org/x/net/internal/socks +vendor/golang.org/x/net/http/httpproxy +net/textproto +crypto/x509 +github.com/prometheus/procfs +golang.org/x/net/proxy +vendor/golang.org/x/net/http/httpguts +mime/multipart +crypto/tls google.golang.org/protobuf/internal/filetype google.golang.org/protobuf/runtime/protoimpl google.golang.org/protobuf/types/known/timestamppb @@ -1530,23 +1575,14 @@ github.com/prometheus/alertmanager/pkg/labels github.com/prometheus/common/helpers/templates github.com/prometheus/client_golang/prometheus/internal -github.com/prometheus/alertmanager/matcher/parse -github.com/prometheus/alertmanager/matcher/compat -golang.org/x/net/internal/socks -net/textproto -vendor/golang.org/x/net/http/httpproxy -crypto/x509 -github.com/prometheus/procfs -vendor/golang.org/x/net/http/httpguts -mime/multipart -golang.org/x/net/proxy -crypto/tls net/http/httptrace github.com/fluffle/goirc/client +github.com/prometheus/alertmanager/matcher/parse net/http +github.com/prometheus/alertmanager/matcher/compat expvar -github.com/prometheus/client_golang/internal/github.com/golang/gddo/httputil/header github.com/gorilla/mux +github.com/prometheus/client_golang/internal/github.com/golang/gddo/httputil/header github.com/prometheus/common/expfmt github.com/prometheus/client_golang/internal/github.com/golang/gddo/httputil github.com/prometheus/client_golang/prometheus @@ -1556,16 +1592,16 @@ 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 16 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 12 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/11/08 12:48:49.737479 backoff.go:111: INFO Backoff for 0s starts -2026/11/08 12:48:49.737548 backoff.go:114: INFO Backoff for 0s ends -2026/11/08 12:48:49.737556 backoff.go:111: INFO Backoff for 2ms starts -2026/11/08 12:48:49.737561 backoff.go:116: INFO Backoff for 2ms canceled by context +2025/10/07 08:32:20.137876 backoff.go:111: INFO Backoff for 0s starts +2025/10/07 08:32:20.137934 backoff.go:114: INFO Backoff for 0s ends +2025/10/07 08:32:20.137948 backoff.go:111: INFO Backoff for 2ms starts +2025/10/07 08:32:20.137955 backoff.go:116: INFO Backoff for 2ms canceled by context --- PASS: TestBackoffDelayContext (0.00s) === RUN TestNoConfig --- PASS: TestNoConfig (0.00s) @@ -1584,10 +1620,10 @@ === RUN TestGivenTemplateNotOverwritten --- PASS: TestGivenTemplateNotOverwritten (0.00s) === RUN TestTemplateErrorsCreateRawAlertMsg -2026/11/08 12:48:49.739860 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/11/08 12:48:49.739913 format.go:61: WARN Sending raw alert -2026/11/08 12:48:49.739940 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/11/08 12:48:49.739945 format.go:61: WARN Sending raw alert +2025/10/07 08:32:20.139502 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/10/07 08:32:20.139515 format.go:61: WARN Sending raw alert +2025/10/07 08:32:20.139533 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/10/07 08:32:20.139540 format.go:61: WARN Sending raw alert --- PASS: TestTemplateErrorsCreateRawAlertMsg (0.00s) === RUN TestAlertsDispatchedOnce --- PASS: TestAlertsDispatchedOnce (0.00s) @@ -1598,482 +1634,481 @@ === RUN TestMultilineTemplates --- PASS: TestMultilineTemplates (0.00s) === RUN TestAlertsDispatched -2026/11/08 12:48:49.740639 http.go:132: INFO Starting HTTP server +2025/10/07 08:32:20.140063 http.go:132: INFO Starting HTTP server --- PASS: TestAlertsDispatched (0.00s) === RUN TestRootReturnsError -2026/11/08 12:48:49.740954 http.go:132: INFO Starting HTTP server +2025/10/07 08:32:20.140258 http.go:132: INFO Starting HTTP server --- PASS: TestRootReturnsError (0.00s) === RUN TestInvalidDataReturnsError -2026/11/08 12:48:49.741161 http.go:132: INFO Starting HTTP server -2026/11/08 12:48:49.741208 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/10/07 08:32:20.140411 http.go:132: INFO Starting HTTP server +2025/10/07 08:32:20.140450 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/11/08 12:48:49.741439 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:35687 -2026/11/08 12:48:49.741484 irc.go:302: INFO Connecting to IRC 127.0.0.1:35687 -2026/11/08 12:48:49.741499 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.741509 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:35687. -2026/11/08 12:48:49.741738 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:36512 -2026/11/08 12:48:49.741794 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/11/08 12:48:49.741949 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret -2026/11/08 12:48:49.741986 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping -2026/11/08 12:48:49.741994 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.742001 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.742006 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.742173 irc.go:146: INFO Session established -2026/11/08 12:48:49.742221 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.742232 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.742250 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.742372 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.742393 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.742399 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.742449 irc.go:296: INFO IRC routine asked to terminate -2026/11/08 12:48:49.742466 irc.go:271: INFO IRC client connected, quitting -2026/11/08 12:48:49.742471 irc.go:274: INFO Wait for IRC disconnect to complete -2026/11/08 12:48:49.742452 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join -2026/11/08 12:48:49.742516 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.742539 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.742586 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.742682 irc.go:152: INFO Disconnected from IRC -2026/11/08 12:48:49.742706 irc.go:282: INFO IRC shutdown complete -2026/11/08 12:48:49.742725 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.140628 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42611 +2025/10/07 08:32:20.140663 irc.go:302: INFO Connecting to IRC 127.0.0.1:42611 +2025/10/07 08:32:20.140674 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.140685 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42611. +2025/10/07 08:32:20.140883 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/10/07 08:32:20.140913 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:48702 +2025/10/07 08:32:20.141134 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret +2025/10/07 08:32:20.141184 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping +2025/10/07 08:32:20.141189 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.141193 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.141200 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.141441 irc.go:146: INFO Session established +2025/10/07 08:32:20.141525 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.141535 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.141547 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.141610 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.141623 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.141627 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.141650 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join +2025/10/07 08:32:20.141653 irc.go:296: INFO IRC routine asked to terminate +2025/10/07 08:32:20.141661 irc.go:271: INFO IRC client connected, quitting +2025/10/07 08:32:20.141669 irc.go:274: INFO Wait for IRC disconnect to complete +2025/10/07 08:32:20.141731 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.141783 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.141868 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.141950 irc.go:152: INFO Disconnected from IRC +2025/10/07 08:32:20.141969 irc.go:282: INFO IRC shutdown complete +2025/10/07 08:32:20.141984 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestServerPassword (0.00s) === RUN TestSendAlertOnPreJoinedChannel -2026/11/08 12:48:49.742813 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37719 -2026/11/08 12:48:49.742857 irc.go:302: INFO Connecting to IRC 127.0.0.1:37719 -2026/11/08 12:48:49.742875 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.742883 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37719. -2026/11/08 12:48:49.743018 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:38664 -2026/11/08 12:48:49.743060 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/11/08 12:48:49.743121 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.743144 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.743150 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.743226 irc.go:146: INFO Session established -2026/11/08 12:48:49.743257 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.743265 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.743274 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.743306 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.743322 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.743339 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.743398 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.743415 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.743424 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/11/08 12:48:49.743491 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message -2026/11/08 12:48:49.743536 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/11/08 12:48:49.743544 irc.go:296: INFO IRC routine asked to terminate -2026/11/08 12:48:49.743554 irc.go:271: INFO IRC client connected, quitting -2026/11/08 12:48:49.743564 irc.go:274: INFO Wait for IRC disconnect to complete -2026/11/08 12:48:49.743601 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.743621 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.743659 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.743716 irc.go:152: INFO Disconnected from IRC -2026/11/08 12:48:49.743735 irc.go:282: INFO IRC shutdown complete -2026/11/08 12:48:49.743750 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.142104 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34345 +2025/10/07 08:32:20.142159 irc.go:302: INFO Connecting to IRC 127.0.0.1:34345 +2025/10/07 08:32:20.142171 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.142185 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34345. +2025/10/07 08:32:20.142303 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/10/07 08:32:20.142317 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:47454 +2025/10/07 08:32:20.142439 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.142458 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.142463 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.142542 irc.go:146: INFO Session established +2025/10/07 08:32:20.142592 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.142602 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.142614 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.142661 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.142674 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.142678 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.142757 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.142771 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.142779 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/10/07 08:32:20.142874 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message +2025/10/07 08:32:20.142898 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/10/07 08:32:20.142908 irc.go:296: INFO IRC routine asked to terminate +2025/10/07 08:32:20.142921 irc.go:271: INFO IRC client connected, quitting +2025/10/07 08:32:20.142929 irc.go:274: INFO Wait for IRC disconnect to complete +2025/10/07 08:32:20.142983 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.142996 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.143053 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.143108 irc.go:152: INFO Disconnected from IRC +2025/10/07 08:32:20.143144 irc.go:282: INFO IRC shutdown complete +2025/10/07 08:32:20.143158 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertOnPreJoinedChannel (0.00s) === RUN TestUsePrivmsgToSendAlertOnPreJoinedChannel -2026/11/08 12:48:49.743822 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34971 -2026/11/08 12:48:49.743854 irc.go:302: INFO Connecting to IRC 127.0.0.1:34971 -2026/11/08 12:48:49.743899 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.743916 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34971. -2026/11/08 12:48:49.744074 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/11/08 12:48:49.744095 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:40290 -2026/11/08 12:48:49.744120 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.744135 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.744143 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.744222 irc.go:146: INFO Session established -2026/11/08 12:48:49.744258 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.744268 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.744281 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.744323 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.744339 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.744355 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.744419 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.744432 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.744455 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/11/08 12:48:49.744493 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message -2026/11/08 12:48:49.744522 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/11/08 12:48:49.744533 irc.go:296: INFO IRC routine asked to terminate -2026/11/08 12:48:49.744541 irc.go:271: INFO IRC client connected, quitting -2026/11/08 12:48:49.744555 irc.go:274: INFO Wait for IRC disconnect to complete -2026/11/08 12:48:49.744605 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.744621 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.744666 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.744740 irc.go:152: INFO Disconnected from IRC -2026/11/08 12:48:49.744770 irc.go:282: INFO IRC shutdown complete -2026/11/08 12:48:49.744793 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.143254 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39137 +2025/10/07 08:32:20.143296 irc.go:302: INFO Connecting to IRC 127.0.0.1:39137 +2025/10/07 08:32:20.143307 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.143313 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39137. +2025/10/07 08:32:20.143461 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:58486 +2025/10/07 08:32:20.143483 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/10/07 08:32:20.143527 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.143539 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.143553 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.143605 irc.go:146: INFO Session established +2025/10/07 08:32:20.143634 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.143644 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.143652 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.143701 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.143720 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.143727 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.143794 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.143805 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.143826 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/10/07 08:32:20.143842 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message +2025/10/07 08:32:20.143865 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/10/07 08:32:20.143871 irc.go:296: INFO IRC routine asked to terminate +2025/10/07 08:32:20.143876 irc.go:271: INFO IRC client connected, quitting +2025/10/07 08:32:20.143884 irc.go:274: INFO Wait for IRC disconnect to complete +2025/10/07 08:32:20.143924 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.143935 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.143972 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.144016 irc.go:152: INFO Disconnected from IRC +2025/10/07 08:32:20.144034 irc.go:282: INFO IRC shutdown complete +2025/10/07 08:32:20.144051 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestUsePrivmsgToSendAlertOnPreJoinedChannel (0.00s) === RUN TestSendAlertAndJoinChannel -2026/11/08 12:48:49.744891 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42743 -2026/11/08 12:48:49.744925 irc.go:302: INFO Connecting to IRC 127.0.0.1:42743 -2026/11/08 12:48:49.744940 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.744947 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42743. -2026/11/08 12:48:49.745082 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:33038 -2026/11/08 12:48:49.745104 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/11/08 12:48:49.745152 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.745168 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.745176 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.745254 irc.go:146: INFO Session established -2026/11/08 12:48:49.745283 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.745293 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.745310 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.745363 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.745378 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.745382 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.745419 reconciler.go:249: INFO Request to JOIN new channel #foobar -2026/11/08 12:48:49.745444 reconciler.go:105: INFO Channel #foobar monitor: waiting to join -2026/11/08 12:48:49.745449 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.745455 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.745458 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.745463 reconciler.go:114: INFO Channel #foobar monitor: join request sent -2026/11/08 12:48:49.745465 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/11/08 12:48:49.745537 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar -2026/11/08 12:48:49.745561 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.745566 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar -2026/11/08 12:48:49.745635 reconciler.go:205: INFO Received JOIN confirmation for channel #foobar -2026/11/08 12:48:49.745651 reconciler.go:79: INFO Setting JOIN state on channel #foobar -2026/11/08 12:48:49.745667 reconciler.go:118: INFO Channel #foobar monitor: join succeeded -2026/11/08 12:48:49.745735 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message -2026/11/08 12:48:49.745770 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/11/08 12:48:49.745777 irc.go:296: INFO IRC routine asked to terminate -2026/11/08 12:48:49.745782 irc.go:271: INFO IRC client connected, quitting -2026/11/08 12:48:49.745787 irc.go:274: INFO Wait for IRC disconnect to complete -2026/11/08 12:48:49.745794 reconciler.go:131: INFO Channel #foobar monitor: context canceled while monitoring -2026/11/08 12:48:49.745832 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.745850 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.745895 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.745969 irc.go:152: INFO Disconnected from IRC -2026/11/08 12:48:49.745992 irc.go:282: INFO IRC shutdown complete -2026/11/08 12:48:49.746011 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.144128 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:35919 +2025/10/07 08:32:20.144177 irc.go:302: INFO Connecting to IRC 127.0.0.1:35919 +2025/10/07 08:32:20.144186 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.144201 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:35919. +2025/10/07 08:32:20.144308 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:55836 +2025/10/07 08:32:20.144358 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/10/07 08:32:20.144413 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.144425 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.144429 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.144477 irc.go:146: INFO Session established +2025/10/07 08:32:20.144499 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.144507 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.144516 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.144560 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.144569 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.144573 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.144605 reconciler.go:249: INFO Request to JOIN new channel #foobar +2025/10/07 08:32:20.144628 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.144631 reconciler.go:105: INFO Channel #foobar monitor: waiting to join +2025/10/07 08:32:20.144636 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.144638 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.144645 reconciler.go:114: INFO Channel #foobar monitor: join request sent +2025/10/07 08:32:20.144649 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/10/07 08:32:20.144686 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar +2025/10/07 08:32:20.144698 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.144702 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar +2025/10/07 08:32:20.144742 reconciler.go:205: INFO Received JOIN confirmation for channel #foobar +2025/10/07 08:32:20.144752 reconciler.go:79: INFO Setting JOIN state on channel #foobar +2025/10/07 08:32:20.144762 reconciler.go:118: INFO Channel #foobar monitor: join succeeded +2025/10/07 08:32:20.144801 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message +2025/10/07 08:32:20.144820 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/10/07 08:32:20.144828 reconciler.go:131: INFO Channel #foobar monitor: context canceled while monitoring +2025/10/07 08:32:20.144829 irc.go:296: INFO IRC routine asked to terminate +2025/10/07 08:32:20.144835 irc.go:271: INFO IRC client connected, quitting +2025/10/07 08:32:20.144848 irc.go:274: INFO Wait for IRC disconnect to complete +2025/10/07 08:32:20.144870 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.144879 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.144908 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.144949 irc.go:152: INFO Disconnected from IRC +2025/10/07 08:32:20.144961 irc.go:282: INFO IRC shutdown complete +2025/10/07 08:32:20.144972 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertAndJoinChannel (0.00s) === RUN TestSendAlertDisconnected -2026/11/08 12:48:49.746096 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46313 -2026/11/08 12:48:49.746143 irc.go:302: INFO Connecting to IRC 127.0.0.1:46313 -2026/11/08 12:48:49.746157 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.746166 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46313. -2026/11/08 12:48:49.746358 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:41166 -2026/11/08 12:48:49.746379 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/11/08 12:48:49.746445 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.746468 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.746474 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.746482 irc_test.go:294: INFO =Server= Wait before completing session -2026/11/08 12:48:49.746488 irc_test.go:296: INFO =Server= Completing session -2026/11/08 12:48:49.746562 irc.go:146: INFO Session established -2026/11/08 12:48:49.746593 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.746601 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.746610 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.746685 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.746702 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.746706 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.746768 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.746778 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.746798 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/11/08 12:48:49.746830 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message -2026/11/08 12:48:49.746857 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/11/08 12:48:49.746869 irc.go:296: INFO IRC routine asked to terminate -2026/11/08 12:48:49.746883 irc.go:271: INFO IRC client connected, quitting -2026/11/08 12:48:49.746892 irc.go:274: INFO Wait for IRC disconnect to complete -2026/11/08 12:48:49.746938 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.746956 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.746990 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.747068 irc.go:152: INFO Disconnected from IRC -2026/11/08 12:48:49.747088 irc.go:282: INFO IRC shutdown complete -2026/11/08 12:48:49.747107 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.145031 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:44595 +2025/10/07 08:32:20.145049 irc.go:302: INFO Connecting to IRC 127.0.0.1:44595 +2025/10/07 08:32:20.145058 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.145063 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:44595. +2025/10/07 08:32:20.145140 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:33818 +2025/10/07 08:32:20.145173 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.145147 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/10/07 08:32:20.145182 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.145188 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.145197 irc_test.go:294: INFO =Server= Wait before completing session +2025/10/07 08:32:20.145201 irc_test.go:296: INFO =Server= Completing session +2025/10/07 08:32:20.145242 irc.go:146: INFO Session established +2025/10/07 08:32:20.145256 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.145267 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.145274 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.145312 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.145334 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.145338 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.145372 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.145380 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.145396 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/10/07 08:32:20.145429 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message +2025/10/07 08:32:20.145448 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/10/07 08:32:20.145455 irc.go:296: INFO IRC routine asked to terminate +2025/10/07 08:32:20.145460 irc.go:271: INFO IRC client connected, quitting +2025/10/07 08:32:20.145467 irc.go:274: INFO Wait for IRC disconnect to complete +2025/10/07 08:32:20.145499 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.145510 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.145541 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.145585 irc.go:152: INFO Disconnected from IRC +2025/10/07 08:32:20.145598 irc.go:282: INFO IRC shutdown complete +2025/10/07 08:32:20.145611 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertDisconnected (0.00s) === RUN TestReconnect -2026/11/08 12:48:49.747187 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41671 -2026/11/08 12:48:49.747222 irc.go:302: INFO Connecting to IRC 127.0.0.1:41671 -2026/11/08 12:48:49.747231 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.747238 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41671. -2026/11/08 12:48:49.747361 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:48602 -2026/11/08 12:48:49.747390 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/11/08 12:48:49.747436 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.747452 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.747457 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.747514 irc.go:146: INFO Session established -2026/11/08 12:48:49.747536 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.747543 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.747548 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.747596 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.747612 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.747616 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.747671 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.747702 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:48602: read tcp 127.0.0.1:41671->127.0.0.1:48602: use of closed network connection -2026/11/08 12:48:49.747734 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.747745 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.747762 irc.go:152: INFO Disconnected from IRC -2026/11/08 12:48:49.747772 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/11/08 12:48:49.747779 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/11/08 12:48:49.747792 irc.go:302: INFO Connecting to IRC 127.0.0.1:41671 -2026/11/08 12:48:49.747797 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.747802 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41671. -2026/11/08 12:48:49.747989 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/11/08 12:48:49.748031 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:48618 -2026/11/08 12:48:49.748158 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.748177 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.748182 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.748498 irc.go:146: INFO Session established -2026/11/08 12:48:49.748540 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.748552 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.748564 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.748624 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.748645 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.748649 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.748687 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join -2026/11/08 12:48:49.748703 irc.go:296: INFO IRC routine asked to terminate -2026/11/08 12:48:49.748713 irc.go:271: INFO IRC client connected, quitting -2026/11/08 12:48:49.748710 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.748721 irc.go:274: INFO Wait for IRC disconnect to complete -2026/11/08 12:48:49.748722 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.748759 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.748779 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.748827 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.748921 irc.go:152: INFO Disconnected from IRC -2026/11/08 12:48:49.748947 irc.go:282: INFO IRC shutdown complete -2026/11/08 12:48:49.748974 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.145669 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41185 +2025/10/07 08:32:20.145687 irc.go:302: INFO Connecting to IRC 127.0.0.1:41185 +2025/10/07 08:32:20.145696 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.145700 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41185. +2025/10/07 08:32:20.145778 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:45872 +2025/10/07 08:32:20.145794 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/10/07 08:32:20.145822 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.145833 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.145841 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.145898 irc.go:146: INFO Session established +2025/10/07 08:32:20.145915 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.145925 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.145934 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.145969 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.145978 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.145981 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.146015 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.146038 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:45872: read tcp 127.0.0.1:41185->127.0.0.1:45872: use of closed network connection +2025/10/07 08:32:20.146064 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.146072 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.146085 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/10/07 08:32:20.146086 irc.go:152: INFO Disconnected from IRC +2025/10/07 08:32:20.146102 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/10/07 08:32:20.146110 irc.go:302: INFO Connecting to IRC 127.0.0.1:41185 +2025/10/07 08:32:20.146114 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.146119 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41185. +2025/10/07 08:32:20.146200 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:45882 +2025/10/07 08:32:20.146222 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/10/07 08:32:20.146270 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.146283 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.146301 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.146343 irc.go:146: INFO Session established +2025/10/07 08:32:20.146358 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.146364 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.146373 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.146412 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.146428 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.146431 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.146454 irc.go:296: INFO IRC routine asked to terminate +2025/10/07 08:32:20.146457 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join +2025/10/07 08:32:20.146460 irc.go:271: INFO IRC client connected, quitting +2025/10/07 08:32:20.146465 irc.go:274: INFO Wait for IRC disconnect to complete +2025/10/07 08:32:20.146496 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.146516 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.146499 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.146554 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.146559 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.146609 irc.go:152: INFO Disconnected from IRC +2025/10/07 08:32:20.146628 irc.go:282: INFO IRC shutdown complete +2025/10/07 08:32:20.146650 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestReconnect (0.00s) === RUN TestConnectErrorRetry -2026/11/08 12:48:49.749055 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43459 -2026/11/08 12:48:49.749086 irc.go:302: INFO Connecting to IRC 127.0.0.1:43459 -2026/11/08 12:48:49.749095 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.749100 fake_delayer.go:45: INFO Waiting StopDelay signal -2026/11/08 12:48:49.749105 fake_delayer.go:47: INFO Received StopDelay signal -2026/11/08 12:48:49.749112 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43459. -2026/11/08 12:48:49.749238 connection.go:399: INFO irc.Connect(): Performing SSL handshake. -2026/11/08 12:48:49.749237 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:53494 -2026/11/08 12:48:49.749358 irc_server_for_test.go:157: INFO =Server= Closing connection early -2026/11/08 12:48:49.749534 irc.go:307: ERROR Could not connect to IRC: EOF -2026/11/08 12:48:49.749551 irc.go:302: INFO Connecting to IRC 127.0.0.1:43459 -2026/11/08 12:48:49.749556 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.749560 fake_delayer.go:45: INFO Waiting StopDelay signal -2026/11/08 12:48:49.749575 fake_delayer.go:47: INFO Received StopDelay signal -2026/11/08 12:48:49.749583 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43459. -2026/11/08 12:48:49.749711 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:53498 -2026/11/08 12:48:49.749717 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/11/08 12:48:49.749775 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.749792 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.749798 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.749866 irc.go:146: INFO Session established -2026/11/08 12:48:49.749893 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.749903 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.749912 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.749978 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.749998 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.750003 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.750038 irc.go:296: INFO IRC routine asked to terminate -2026/11/08 12:48:49.750049 irc.go:271: INFO IRC client connected, quitting -2026/11/08 12:48:49.750037 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join -2026/11/08 12:48:49.750055 irc.go:274: INFO Wait for IRC disconnect to complete -2026/11/08 12:48:49.750070 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.750081 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.750085 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.750090 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.750147 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.750252 irc.go:152: INFO Disconnected from IRC -2026/11/08 12:48:49.750284 irc.go:282: INFO IRC shutdown complete -2026/11/08 12:48:49.750360 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.146713 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41363 +2025/10/07 08:32:20.146733 irc.go:302: INFO Connecting to IRC 127.0.0.1:41363 +2025/10/07 08:32:20.146742 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.146745 fake_delayer.go:45: INFO Waiting StopDelay signal +2025/10/07 08:32:20.146748 fake_delayer.go:47: INFO Received StopDelay signal +2025/10/07 08:32:20.146753 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41363. +2025/10/07 08:32:20.146834 connection.go:399: INFO irc.Connect(): Performing SSL handshake. +2025/10/07 08:32:20.146836 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:42502 +2025/10/07 08:32:20.146845 irc_server_for_test.go:157: INFO =Server= Closing connection early +2025/10/07 08:32:20.147030 irc.go:307: ERROR Could not connect to IRC: EOF +2025/10/07 08:32:20.147039 irc.go:302: INFO Connecting to IRC 127.0.0.1:41363 +2025/10/07 08:32:20.147042 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.147045 fake_delayer.go:45: INFO Waiting StopDelay signal +2025/10/07 08:32:20.147051 fake_delayer.go:47: INFO Received StopDelay signal +2025/10/07 08:32:20.147056 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41363. +2025/10/07 08:32:20.147126 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:42506 +2025/10/07 08:32:20.147142 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/10/07 08:32:20.147201 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.147210 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.147213 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.147280 irc.go:146: INFO Session established +2025/10/07 08:32:20.147303 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.147308 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.147318 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.147374 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.147384 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.147387 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.147409 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join +2025/10/07 08:32:20.147417 irc.go:296: INFO IRC routine asked to terminate +2025/10/07 08:32:20.147420 irc.go:271: INFO IRC client connected, quitting +2025/10/07 08:32:20.147424 irc.go:274: INFO Wait for IRC disconnect to complete +2025/10/07 08:32:20.147442 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.147447 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.147452 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.147452 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.147475 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.147520 irc.go:152: INFO Disconnected from IRC +2025/10/07 08:32:20.147531 irc.go:282: INFO IRC shutdown complete +2025/10/07 08:32:20.147543 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestConnectErrorRetry (0.00s) === RUN TestIdentify -2026/11/08 12:48:49.750446 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39065 -2026/11/08 12:48:49.750473 irc.go:302: INFO Connecting to IRC 127.0.0.1:39065 -2026/11/08 12:48:49.750481 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.750487 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39065. -2026/11/08 12:48:49.750607 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:50842 -2026/11/08 12:48:49.750623 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/11/08 12:48:49.750678 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.750731 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.750783 irc.go:167: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. -2026/11/08 12:48:49.750806 irc.go:191: INFO Handling NickServ request to IDENTIFY -2026/11/08 12:48:49.750839 irc.go:146: INFO Session established -2026/11/08 12:48:49.750857 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request -2026/11/08 12:48:49.750870 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword -2026/11/08 12:48:49.750873 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.750879 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.750881 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.750899 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.750966 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.750986 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.750995 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.751037 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join -2026/11/08 12:48:49.751052 irc.go:296: INFO IRC routine asked to terminate -2026/11/08 12:48:49.751057 irc.go:271: INFO IRC client connected, quitting -2026/11/08 12:48:49.751063 irc.go:274: INFO Wait for IRC disconnect to complete -2026/11/08 12:48:49.751067 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.751079 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.751092 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.751104 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.751156 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.751227 irc.go:152: INFO Disconnected from IRC -2026/11/08 12:48:49.751244 irc.go:282: INFO IRC shutdown complete -2026/11/08 12:48:49.751261 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.147603 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40101 +2025/10/07 08:32:20.147622 irc.go:302: INFO Connecting to IRC 127.0.0.1:40101 +2025/10/07 08:32:20.147630 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.147634 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40101. +2025/10/07 08:32:20.147717 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:43286 +2025/10/07 08:32:20.147746 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/10/07 08:32:20.147793 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.147824 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.147867 irc.go:167: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. +2025/10/07 08:32:20.147889 irc.go:191: INFO Handling NickServ request to IDENTIFY +2025/10/07 08:32:20.147907 irc.go:146: INFO Session established +2025/10/07 08:32:20.147920 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request +2025/10/07 08:32:20.147930 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.147938 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.147937 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword +2025/10/07 08:32:20.147942 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.147946 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.147978 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.147989 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.147992 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.148017 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join +2025/10/07 08:32:20.148019 irc.go:296: INFO IRC routine asked to terminate +2025/10/07 08:32:20.148028 irc.go:271: INFO IRC client connected, quitting +2025/10/07 08:32:20.148032 irc.go:274: INFO Wait for IRC disconnect to complete +2025/10/07 08:32:20.148046 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.148052 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.148057 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.148064 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.148092 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.148138 irc.go:152: INFO Disconnected from IRC +2025/10/07 08:32:20.148150 irc.go:282: INFO IRC shutdown complete +2025/10/07 08:32:20.148184 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestIdentify (0.00s) === RUN TestGhost -2026/11/08 12:48:49.751322 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46461 -2026/11/08 12:48:49.751348 irc.go:302: INFO Connecting to IRC 127.0.0.1:46461 -2026/11/08 12:48:49.751358 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.751364 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46461. -2026/11/08 12:48:49.751499 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/11/08 12:48:49.751506 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:35748 -2026/11/08 12:48:49.751529 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.751544 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.751628 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' -2026/11/08 12:48:49.751672 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ -2026/11/08 12:48:49.751738 irc.go:146: INFO Session established -2026/11/08 12:48:49.751758 irc.go:206: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' -2026/11/08 12:48:49.751771 irc.go:212: INFO Changing nick to 'foo' -2026/11/08 12:48:49.751779 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request -2026/11/08 12:48:49.751796 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.751806 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.751818 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.751834 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword -2026/11/08 12:48:49.751847 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.751853 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.751911 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.751920 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.751924 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.751961 irc.go:296: INFO IRC routine asked to terminate -2026/11/08 12:48:49.751959 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join -2026/11/08 12:48:49.751972 irc.go:271: INFO IRC client connected, quitting -2026/11/08 12:48:49.751978 irc.go:274: INFO Wait for IRC disconnect to complete -2026/11/08 12:48:49.752011 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.752024 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.752091 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.752194 irc.go:152: INFO Disconnected from IRC -2026/11/08 12:48:49.752222 irc.go:282: INFO IRC shutdown complete -2026/11/08 12:48:49.752243 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.148290 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41165 +2025/10/07 08:32:20.148345 irc.go:302: INFO Connecting to IRC 127.0.0.1:41165 +2025/10/07 08:32:20.148354 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.148368 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41165. +2025/10/07 08:32:20.148467 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/10/07 08:32:20.148478 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:49892 +2025/10/07 08:32:20.148502 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.148508 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.148660 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' +2025/10/07 08:32:20.148702 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ +2025/10/07 08:32:20.148752 irc.go:146: INFO Session established +2025/10/07 08:32:20.148770 irc.go:206: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' +2025/10/07 08:32:20.148784 irc.go:212: INFO Changing nick to 'foo' +2025/10/07 08:32:20.148788 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request +2025/10/07 08:32:20.148804 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.148812 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.148816 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.148854 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword +2025/10/07 08:32:20.148862 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.148866 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.148870 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.148873 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.148879 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.148906 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join +2025/10/07 08:32:20.148913 irc.go:296: INFO IRC routine asked to terminate +2025/10/07 08:32:20.148916 irc.go:271: INFO IRC client connected, quitting +2025/10/07 08:32:20.148920 irc.go:274: INFO Wait for IRC disconnect to complete +2025/10/07 08:32:20.148942 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.148954 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.148986 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.149025 irc.go:152: INFO Disconnected from IRC +2025/10/07 08:32:20.149049 irc.go:282: INFO IRC shutdown complete +2025/10/07 08:32:20.149068 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestGhost (0.00s) === RUN TestStopRunningWhenHalfConnected -2026/11/08 12:48:49.752330 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43499 -2026/11/08 12:48:49.752363 irc.go:302: INFO Connecting to IRC 127.0.0.1:43499 -2026/11/08 12:48:49.752377 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.752384 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43499. -2026/11/08 12:48:49.752514 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:46900 -2026/11/08 12:48:49.752542 irc.go:310: INFO Connected to IRC server, waiting to establish session -2026/11/08 12:48:49.752578 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.752597 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.752605 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.752613 irc_test.go:591: INFO =Server= NOT completing session -2026/11/08 12:48:49.752630 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.752636 irc.go:323: INFO IRC routine asked to terminate -2026/11/08 12:48:49.752648 irc.go:282: INFO IRC shutdown complete -2026/11/08 12:48:49.752692 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:46900->127.0.0.1:43499: use of closed network connection -2026/11/08 12:48:49.752701 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:46900 disconnected -2026/11/08 12:48:49.752712 irc.go:152: INFO Disconnected from IRC -2026/11/08 12:48:49.752745 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.149128 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:32827 +2025/10/07 08:32:20.149149 irc.go:302: INFO Connecting to IRC 127.0.0.1:32827 +2025/10/07 08:32:20.149157 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.149162 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:32827. +2025/10/07 08:32:20.149254 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:57922 +2025/10/07 08:32:20.149281 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.149293 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.149302 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.149309 irc_test.go:591: INFO =Server= NOT completing session +2025/10/07 08:32:20.149318 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.149349 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:57922 disconnected +2025/10/07 08:32:20.149260 irc.go:310: INFO Connected to IRC server, waiting to establish session +2025/10/07 08:32:20.149373 irc.go:323: INFO IRC routine asked to terminate +2025/10/07 08:32:20.149406 irc.go:282: INFO IRC shutdown complete +2025/10/07 08:32:20.149357 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:57922->127.0.0.1:32827: use of closed network connection +2025/10/07 08:32:20.149437 irc.go:152: INFO Disconnected from IRC +2025/10/07 08:32:20.149441 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestStopRunningWhenHalfConnected (0.00s) === RUN TestPreJoinChannels -2026/11/08 12:48:49.752825 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:45669 -2026/11/08 12:48:49.752847 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:45669. -2026/11/08 12:48:49.752950 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:45386 -2026/11/08 12:48:49.752994 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.753013 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.753021 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.753096 reconciler.go:105: INFO Channel #baz monitor: waiting to join -2026/11/08 12:48:49.753106 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.753110 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.753116 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.753119 reconciler.go:114: INFO Channel #baz monitor: join request sent -2026/11/08 12:48:49.753123 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.753123 reconciler.go:105: INFO Channel #bar monitor: waiting to join -2026/11/08 12:48:49.753133 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.753139 reconciler.go:114: INFO Channel #bar monitor: join request sent -2026/11/08 12:48:49.753154 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz -2026/11/08 12:48:49.753163 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.753168 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz -2026/11/08 12:48:49.753189 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.753199 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.753203 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.753217 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar -2026/11/08 12:48:49.753223 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.753226 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar -2026/11/08 12:48:49.753236 reconciler.go:205: INFO Received JOIN confirmation for channel #baz -2026/11/08 12:48:49.753245 reconciler.go:79: INFO Setting JOIN state on channel #baz -2026/11/08 12:48:49.753250 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.753263 reconciler.go:118: INFO Channel #baz monitor: join succeeded -2026/11/08 12:48:49.753270 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.753313 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.753261 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.753330 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.753350 reconciler.go:205: INFO Received JOIN confirmation for channel #bar -2026/11/08 12:48:49.753354 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/11/08 12:48:49.753363 reconciler.go:79: INFO Setting JOIN state on channel #bar -2026/11/08 12:48:49.753369 reconciler.go:118: INFO Channel #bar monitor: join succeeded -2026/11/08 12:48:49.753379 reconciler.go:131: INFO Channel #baz monitor: context canceled while monitoring -2026/11/08 12:48:49.753386 reconciler.go:131: INFO Channel #bar monitor: context canceled while monitoring -2026/11/08 12:48:49.753391 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/11/08 12:48:49.753409 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.149514 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42029 +2025/10/07 08:32:20.149531 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42029. +2025/10/07 08:32:20.149616 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:52692 +2025/10/07 08:32:20.149650 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.149661 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.149666 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.149737 reconciler.go:105: INFO Channel #baz monitor: waiting to join +2025/10/07 08:32:20.149747 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.149755 reconciler.go:114: INFO Channel #baz monitor: join request sent +2025/10/07 08:32:20.149777 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.149783 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz +2025/10/07 08:32:20.149790 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.149787 reconciler.go:105: INFO Channel #bar monitor: waiting to join +2025/10/07 08:32:20.149784 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.149796 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.149800 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.149793 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz +2025/10/07 08:32:20.149801 reconciler.go:114: INFO Channel #bar monitor: join request sent +2025/10/07 08:32:20.149828 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.149831 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.149834 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.149853 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar +2025/10/07 08:32:20.149859 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.149864 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar +2025/10/07 08:32:20.149866 reconciler.go:205: INFO Received JOIN confirmation for channel #baz +2025/10/07 08:32:20.149871 reconciler.go:79: INFO Setting JOIN state on channel #baz +2025/10/07 08:32:20.149882 reconciler.go:118: INFO Channel #baz monitor: join succeeded +2025/10/07 08:32:20.149885 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.149888 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.149894 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/10/07 08:32:20.149914 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.149924 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.149930 reconciler.go:205: INFO Received JOIN confirmation for channel #bar +2025/10/07 08:32:20.149940 reconciler.go:79: INFO Setting JOIN state on channel #bar +2025/10/07 08:32:20.149946 reconciler.go:118: INFO Channel #bar monitor: join succeeded +2025/10/07 08:32:20.149953 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.150021 reconciler.go:131: INFO Channel #baz monitor: context canceled while monitoring +2025/10/07 08:32:20.150031 reconciler.go:131: INFO Channel #bar monitor: context canceled while monitoring +2025/10/07 08:32:20.150036 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/10/07 08:32:20.150049 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestPreJoinChannels (0.00s) === RUN TestKeepJoining -2026/11/08 12:48:49.753486 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34563 -2026/11/08 12:48:49.753514 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34563. -2026/11/08 12:48:49.753622 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:37918 -2026/11/08 12:48:49.753684 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.753697 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.753706 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.753774 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.753787 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.753792 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.753828 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.753837 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.753841 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.753855 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2026/11/08 12:48:49.753862 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.753866 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.753875 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.753912 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.753927 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.753931 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.753945 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2026/11/08 12:48:49.753952 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.753956 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.753966 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.754001 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.754014 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.754018 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.754079 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.754080 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.754093 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.754101 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.754107 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/11/08 12:48:49.754134 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.754203 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/11/08 12:48:49.754231 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.150164 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39975 +2025/10/07 08:32:20.150189 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39975. +2025/10/07 08:32:20.150291 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34070 +2025/10/07 08:32:20.150349 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.150359 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.150362 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.150432 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.150445 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.150452 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.150487 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.150496 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.150500 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.150520 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2025/10/07 08:32:20.150527 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.150529 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.150539 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.150571 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.150581 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.150585 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.150603 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2025/10/07 08:32:20.150610 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.150613 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.150621 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.150649 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.150657 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.150660 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.150687 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.150694 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.150704 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.150711 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.150716 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/10/07 08:32:20.150721 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.150779 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/10/07 08:32:20.150804 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestKeepJoining (0.00s) === RUN TestKickRejoin -2026/11/08 12:48:49.754342 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34447 -2026/11/08 12:48:49.754370 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34447. -2026/11/08 12:48:49.754501 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:46446 -2026/11/08 12:48:49.754528 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2026/11/08 12:48:49.754537 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2026/11/08 12:48:49.754545 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2026/11/08 12:48:49.754636 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.754651 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.754661 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.754704 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.754720 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.754725 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.754770 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! -2026/11/08 12:48:49.754779 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.754803 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.754820 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/11/08 12:48:49.754858 reconciler.go:223: INFO Received KICK for channel #foo -2026/11/08 12:48:49.754870 reconciler.go:93: INFO Removing JOIN state on channel #foo -2026/11/08 12:48:49.754882 reconciler.go:129: INFO Channel #foo monitor: channel no longer joined -2026/11/08 12:48:49.754886 reconciler.go:105: INFO Channel #foo monitor: waiting to join -2026/11/08 12:48:49.754890 fake_delayer.go:43: INFO Faking Backoff -2026/11/08 12:48:49.754900 reconciler.go:114: INFO Channel #foo monitor: join request sent -2026/11/08 12:48:49.755147 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2026/11/08 12:48:49.755163 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2026/11/08 12:48:49.755167 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2026/11/08 12:48:49.755235 reconciler.go:205: INFO Received JOIN confirmation for channel #foo -2026/11/08 12:48:49.755237 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2026/11/08 12:48:49.755246 reconciler.go:79: INFO Setting JOIN state on channel #foo -2026/11/08 12:48:49.755253 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2026/11/08 12:48:49.755257 reconciler.go:118: INFO Channel #foo monitor: join succeeded -2026/11/08 12:48:49.755288 connection.go:577: INFO irc.Close(): Disconnected from server. -2026/11/08 12:48:49.755363 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring -2026/11/08 12:48:49.755387 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/10/07 08:32:20.150877 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46321 +2025/10/07 08:32:20.150908 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46321. +2025/10/07 08:32:20.150990 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:57956 +2025/10/07 08:32:20.151026 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/10/07 08:32:20.151035 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/10/07 08:32:20.151042 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/10/07 08:32:20.151129 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.151142 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.151152 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.151194 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.151202 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.151205 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.151227 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! +2025/10/07 08:32:20.151239 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.151244 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.151261 reconciler.go:223: INFO Received KICK for channel #foo +2025/10/07 08:32:20.151263 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/10/07 08:32:20.151268 reconciler.go:93: INFO Removing JOIN state on channel #foo +2025/10/07 08:32:20.151274 reconciler.go:105: INFO Channel #foo monitor: waiting to join +2025/10/07 08:32:20.151284 fake_delayer.go:43: INFO Faking Backoff +2025/10/07 08:32:20.151289 reconciler.go:114: INFO Channel #foo monitor: join request sent +2025/10/07 08:32:20.151350 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/10/07 08:32:20.151362 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/10/07 08:32:20.151366 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/10/07 08:32:20.151412 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/10/07 08:32:20.151423 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/10/07 08:32:20.151427 reconciler.go:205: INFO Received JOIN confirmation for channel #foo +2025/10/07 08:32:20.151434 reconciler.go:79: INFO Setting JOIN state on channel #foo +2025/10/07 08:32:20.151441 reconciler.go:118: INFO Channel #foo monitor: join succeeded +2025/10/07 08:32:20.151453 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/10/07 08:32:20.151507 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring +2025/10/07 08:32:20.151531 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.025s +ok github.com/google/alertmanager-irc-relay 0.019s ? github.com/google/alertmanager-irc-relay/logging [no test files] create-stamp debian/debhelper-build-stamp dh_testroot -O--buildsystem=golang @@ -2114,12 +2149,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/4007292/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/4007292/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/4172889 and its subdirectories -I: Current time: Sun Nov 8 12:49:04 -12 2026 -I: pbuilder-time-stamp: 1794185344 +I: removing directory /srv/workspace/pbuilder/4007292 and its subdirectories +I: Current time: Tue Oct 7 08:32:31 +14 2025 +I: pbuilder-time-stamp: 1759775551