Diff of the two buildlogs:
--
--- b1/build.log 2025-03-22 05:48:18.124359438 +0000
+++ b2/build.log 2025-03-22 05:51:28.971755480 +0000
@@ -1,6 +1,6 @@
I: pbuilder: network access will be disabled during build
-I: Current time: Fri Apr 24 00:08:29 -12 2026
-I: pbuilder-time-stamp: 1777032509
+I: Current time: Sat Mar 22 19:48:21 +14 2025
+I: pbuilder-time-stamp: 1742622501
I: Building the build Environment
I: extracting base tarball [/var/cache/pbuilder/trixie-reproducible-base.tgz]
I: copying local configuration
@@ -22,52 +22,84 @@
dpkg-source: info: unpacking alertmanager-irc-relay_0.5.1-3.debian.tar.xz
I: Not using root during the build.
I: Installing the build-deps
-I: user script /srv/workspace/pbuilder/1374347/tmp/hooks/D02_print_environment starting
+I: user script /srv/workspace/pbuilder/3082384/tmp/hooks/D01_modify_environment starting
+debug: Running on codethink04-arm64.
+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 Mar 22 05:48 /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/3082384/tmp/hooks/D01_modify_environment finished
+I: user script /srv/workspace/pbuilder/3082384/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='arm64'
- DEBIAN_FRONTEND='noninteractive'
+ BASH=/bin/sh
+ BASHOPTS=checkwinsize:cmdhist:complete_fullquote:extquote:force_fignore:globasciiranges:globskipdots:hostcomplete:interactive_comments:patsub_replacement:progcomp:promptvars:sourcepath
+ BASH_ALIASES=()
+ BASH_ARGC=()
+ BASH_ARGV=()
+ BASH_CMDS=()
+ BASH_LINENO=([0]="12" [1]="0")
+ BASH_LOADABLES_PATH=/usr/local/lib/bash:/usr/lib/bash:/opt/local/lib/bash:/usr/pkg/lib/bash:/opt/pkg/lib/bash:.
+ BASH_SOURCE=([0]="/tmp/hooks/D02_print_environment" [1]="/tmp/hooks/D02_print_environment")
+ BASH_VERSINFO=([0]="5" [1]="2" [2]="37" [3]="1" [4]="release" [5]="aarch64-unknown-linux-gnu")
+ BASH_VERSION='5.2.37(1)-release'
+ BUILDDIR=/build/reproducible-path
+ BUILDUSERGECOS='second user,second room,second work-phone,second home-phone,second other'
+ BUILDUSERNAME=pbuilder2
+ BUILD_ARCH=arm64
+ DEBIAN_FRONTEND=noninteractive
DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=12 '
- DISTRIBUTION='trixie'
- HOME='/root'
- HOST_ARCH='arm64'
+ DIRSTACK=()
+ DISTRIBUTION=trixie
+ EUID=0
+ FUNCNAME=([0]="Echo" [1]="main")
+ GROUPS=()
+ HOME=/root
+ HOSTNAME=i-capture-the-hostname
+ HOSTTYPE=aarch64
+ HOST_ARCH=arm64
IFS='
'
- INVOCATION_ID='c0248fef12944d0eb8f2d5bc888b4f86'
- 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='1374347'
- PS1='# '
- PS2='> '
+ INVOCATION_ID=3cea25d4d7184194a043cea4f78173f3
+ LANG=C
+ LANGUAGE=nl_BE:nl
+ LC_ALL=C
+ MACHTYPE=aarch64-unknown-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=3082384
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.gqBsZDj9/pbuilderrc_4g6d --distribution trixie --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/trixie-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.gqBsZDj9/b1 --logfile b1/build.log alertmanager-irc-relay_0.5.1-3.dsc'
- SUDO_GID='109'
- SUDO_UID='104'
- SUDO_USER='jenkins'
- TERM='unknown'
- TZ='/usr/share/zoneinfo/Etc/GMT+12'
- USER='root'
- _='/usr/bin/systemd-run'
- http_proxy='http://192.168.101.4:3128'
+ PWD=/
+ SHELL=/bin/bash
+ SHELLOPTS=braceexpand:errexit:hashall:interactive-comments:posix
+ SHLVL=3
+ SUDO_COMMAND='/usr/bin/timeout -k 24.1h 24h /usr/bin/ionice -c 3 /usr/bin/nice -n 11 /usr/bin/unshare --uts -- /usr/sbin/pbuilder --build --configfile /srv/reproducible-results/rbuild-debian/r-b-build.gqBsZDj9/pbuilderrc_V1Fb --distribution trixie --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/trixie-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.gqBsZDj9/b2 --logfile b2/build.log alertmanager-irc-relay_0.5.1-3.dsc'
+ SUDO_GID=109
+ SUDO_UID=104
+ SUDO_USER=jenkins
+ TERM=unknown
+ TZ=/usr/share/zoneinfo/Etc/GMT-14
+ UID=0
+ USER=root
+ _='I: set'
+ http_proxy=http://192.168.101.4:3128
I: uname -a
- Linux codethink03-arm64 6.1.0-32-cloud-arm64 #1 SMP Debian 6.1.129-1 (2025-03-06) aarch64 GNU/Linux
+ Linux i-capture-the-hostname 6.1.0-32-cloud-arm64 #1 SMP Debian 6.1.129-1 (2025-03-06) aarch64 GNU/Linux
I: ls -l /bin
- lrwxrwxrwx 1 root root 7 Mar 4 2025 /bin -> usr/bin
-I: user script /srv/workspace/pbuilder/1374347/tmp/hooks/D02_print_environment finished
+ lrwxrwxrwx 1 root root 7 Mar 4 11:20 /bin -> usr/bin
+I: user script /srv/workspace/pbuilder/3082384/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 trixie/main arm64 golang-protobuf-extensions-dev all 1.0.4-2 [29.7 kB]
Get: 226 http://deb.debian.org/debian trixie/main arm64 golang-uber-automaxprocs-dev all 1.5.3-1 [22.3 kB]
Get: 227 http://deb.debian.org/debian trixie/main arm64 golang-github-prometheus-alertmanager-dev all 0.28.1+ds-1 [1139 kB]
-Fetched 161 MB in 1s (119 MB/s)
+Fetched 161 MB in 2s (102 MB/s)
Preconfiguring packages ...
Selecting previously unselected package tzdata.
(Reading database ...
(Reading database ... 5%
(Reading database ... 10%
(Reading database ... 15%
(Reading database ... 20%
(Reading database ... 25%
(Reading database ... 30%
(Reading database ... 35%
(Reading database ... 40%
(Reading database ... 45%
(Reading database ... 50%
(Reading database ... 55%
(Reading database ... 60%
(Reading database ... 65%
(Reading database ... 70%
(Reading database ... 75%
(Reading database ... 80%
(Reading database ... 85%
(Reading database ... 90%
(Reading database ... 95%
(Reading database ... 100%
(Reading database ... 19899 files and directories currently installed.)
@@ -1088,8 +1120,8 @@
Setting up tzdata (2025a-2) ...
Current default time zone: 'Etc/UTC'
-Local time is now: Fri Apr 24 12:09:47 UTC 2026.
-Universal Time is now: Fri Apr 24 12:09:47 UTC 2026.
+Local time is now: Sat Mar 22 05:49:42 UTC 2025.
+Universal Time is now: Sat Mar 22 05:49:42 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/3082384/tmp/hooks/A99_set_merged_usr starting
+Not re-configuring usrmerge for trixie
+I: user script /srv/workspace/pbuilder/3082384/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
@@ -1294,33 +1330,33 @@
dh_auto_configure -O--buildsystem=golang
dh_auto_build -O--buildsystem=golang
cd obj-aarch64-linux-gnu && go install -trimpath -v -p 12 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging
-internal/godebugs
-internal/goexperiment
internal/goarch
-internal/coverage/rtcov
-internal/profilerecord
-internal/asan
-internal/goos
internal/byteorder
+internal/godebugs
internal/unsafeheader
+internal/coverage/rtcov
+internal/runtime/math
internal/msan
-internal/cpu
-math/bits
internal/runtime/syscall
sync/atomic
-internal/itoa
-unicode/utf8
+internal/cpu
+internal/goos
internal/abi
+math/bits
+internal/profilerecord
+internal/goexperiment
+internal/asan
+internal/chacha8rand
unicode
-internal/runtime/math
+unicode/utf8
+internal/itoa
container/list
-internal/chacha8rand
crypto/internal/fips140/alias
crypto/internal/fips140deps/byteorder
-math
cmp
-crypto/internal/boring/sig
crypto/internal/fips140/subtle
+math
+crypto/internal/boring/sig
unicode/utf16
vendor/golang.org/x/crypto/cryptobyte/asn1
vendor/golang.org/x/crypto/internal/alias
@@ -1330,74 +1366,71 @@
log/internal
log/slog/internal
google.golang.org/protobuf/internal/flags
-internal/bytealg
+google.golang.org/protobuf/internal/set
+github.com/klauspost/compress/internal/le
internal/runtime/atomic
internal/runtime/sys
+internal/bytealg
crypto/internal/fips140deps/cpu
-google.golang.org/protobuf/internal/set
-github.com/klauspost/compress/internal/le
internal/runtime/exithook
-internal/stringslite
-github.com/klauspost/compress
internal/race
+internal/stringslite
internal/runtime/maps
internal/sync
+github.com/klauspost/compress
runtime
internal/reflectlite
+sync
iter
crypto/subtle
-sync
weak
runtime/metrics
slices
maps
-internal/bisect
-internal/testlog
-internal/singleflight
-unique
-log/slog/internal/buffer
-google.golang.org/protobuf/internal/pragma
errors
sort
-runtime/cgo
-io
internal/oserror
+io
+internal/bisect
strconv
+internal/singleflight
+unique
+internal/testlog
path
-internal/godebug
math/rand/v2
vendor/golang.org/x/net/dns/dnsmessage
syscall
+log/slog/internal/buffer
+google.golang.org/protobuf/internal/pragma
+runtime/cgo
bytes
-hash
-math/rand
-reflect
-net/netip
-crypto/internal/fips140deps/godebug
strings
+hash
crypto/internal/randutil
-crypto
+internal/godebug
hash/crc32
hash/fnv
-golang.org/x/text/internal/tag
github.com/beorn7/perks/quantile
-vendor/golang.org/x/text/transform
-golang.org/x/text/transform
+golang.org/x/text/internal/tag
+crypto
+crypto/internal/fips140deps/godebug
crypto/internal/fips140
-crypto/internal/impl
-bufio
+net/netip
+regexp/syntax
+reflect
+math/rand
net/http/internal/ascii
+bufio
+vendor/golang.org/x/text/transform
+crypto/internal/impl
+github.com/munnerz/goautoneg
crypto/internal/fips140/sha3
crypto/internal/fips140/sha256
crypto/internal/fips140/sha512
crypto/tls/internal/fips140tls
-regexp/syntax
-github.com/munnerz/goautoneg
+golang.org/x/text/transform
html
crypto/sha3
-time
-internal/syscall/unix
-internal/syscall/execenv
crypto/internal/fips140hash
crypto/internal/fips140/hmac
crypto/internal/fips140/check
@@ -1407,122 +1440,125 @@
crypto/internal/fips140/bigmod
crypto/internal/fips140/hkdf
crypto/internal/fips140/tls12
-regexp
+time
+internal/syscall/unix
+internal/syscall/execenv
crypto/internal/fips140/tls13
+regexp
crypto/internal/fips140/edwards25519
+crypto/internal/fips140/nistec
context
io/fs
internal/poll
internal/filepathlite
embed
google.golang.org/protobuf/internal/editiondefaults
-crypto/internal/fips140/nistec
os
internal/fmtsort
encoding/binary
+vendor/golang.org/x/crypto/internal/poly1305
+encoding/base64
+github.com/cespare/xxhash
+github.com/klauspost/compress/internal/snapref
+golang.org/x/sys/unix
+encoding/pem
crypto/internal/sysrand
fmt
path/filepath
+google.golang.org/protobuf/internal/detrand
+github.com/prometheus/procfs/internal/util
io/ioutil
+net
os/signal
-github.com/prometheus/procfs/internal/util
crypto/internal/entropy
-vendor/golang.org/x/crypto/internal/poly1305
-golang.org/x/sys/unix
-encoding/base64
-google.golang.org/protobuf/internal/detrand
-github.com/cespare/xxhash
crypto/internal/fips140/drbg
-github.com/klauspost/compress/internal/snapref
crypto/internal/fips140/aes/gcm
crypto/internal/fips140only
-crypto/internal/fips140/ecdh
crypto/internal/fips140/mlkem
-crypto/internal/fips140/ecdsa
-crypto/internal/fips140/ed25519
-encoding/pem
+crypto/internal/fips140/ecdh
crypto/internal/fips140/rsa
+crypto/internal/fips140/ed25519
+crypto/internal/fips140/ecdsa
crypto/md5
crypto/rc4
crypto/cipher
math/big
encoding/hex
-net/url
encoding/json
flag
github.com/golang/mock/gomock
log
-net
compress/flate
vendor/golang.org/x/text/unicode/norm
-vendor/golang.org/x/net/http2/hpack
+net/url
crypto/internal/boring
-crypto/aes
crypto/des
+crypto/aes
crypto/ecdh
crypto/sha512
crypto/hmac
vendor/golang.org/x/crypto/chacha20
crypto/sha1
crypto/sha256
+compress/gzip
vendor/golang.org/x/text/unicode/bidi
+vendor/golang.org/x/net/http2/hpack
github.com/fluffle/goirc/state
-mime
-compress/gzip
github.com/google/alertmanager-irc-relay/logging
+mime
vendor/golang.org/x/crypto/chacha20poly1305
mime/quotedprintable
net/http/internal
google.golang.org/protobuf/internal/errors
-google.golang.org/protobuf/encoding/protowire
go/token
google.golang.org/protobuf/internal/version
runtime/debug
github.com/prometheus/procfs/internal/fs
+google.golang.org/protobuf/encoding/protowire
golang.org/x/text/internal/language
-google.golang.org/protobuf/reflect/protoreflect
golang.org/x/text/unicode/norm
+google.golang.org/protobuf/reflect/protoreflect
vendor/golang.org/x/text/secure/bidirule
text/template/parse
-github.com/klauspost/compress/fse
vendor/golang.org/x/net/idna
+github.com/klauspost/compress/fse
gopkg.in/yaml.v2
-crypto/elliptic
-crypto/internal/boring/bbig
-encoding/asn1
-crypto/rand
-crypto/dsa
+github.com/klauspost/compress/huff0
log/slog
-crypto/ed25519
-crypto/internal/hpke
-crypto/rsa
golang.org/x/text/internal/language/compact
-github.com/klauspost/compress/huff0
google.golang.org/protobuf/internal/descfmt
google.golang.org/protobuf/internal/descopts
google.golang.org/protobuf/internal/strs
google.golang.org/protobuf/internal/encoding/messageset
google.golang.org/protobuf/internal/genid
google.golang.org/protobuf/internal/order
+crypto/elliptic
+crypto/internal/boring/bbig
+encoding/asn1
+crypto/rand
+crypto/dsa
google.golang.org/protobuf/internal/encoding/text
-vendor/golang.org/x/crypto/cryptobyte
-crypto/x509/pkix
-google.golang.org/protobuf/runtime/protoiface
google.golang.org/protobuf/reflect/protoregistry
+google.golang.org/protobuf/runtime/protoiface
golang.org/x/text/language
-text/template
+crypto/ed25519
+crypto/internal/hpke
+crypto/rsa
google.golang.org/protobuf/internal/protolazy
+text/template
github.com/klauspost/compress/zstd
google.golang.org/protobuf/proto
google.golang.org/protobuf/internal/encoding/defval
-crypto/ecdsa
-github.com/prometheus/alertmanager/featurecontrol
github.com/prometheus/common/promslog
+github.com/prometheus/alertmanager/featurecontrol
golang.org/x/text/internal
+vendor/golang.org/x/crypto/cryptobyte
+crypto/x509/pkix
golang.org/x/text/cases
google.golang.org/protobuf/internal/filedesc
google.golang.org/protobuf/encoding/prototext
google.golang.org/protobuf/encoding/protodelim
+crypto/ecdsa
html/template
google.golang.org/protobuf/internal/encoding/tag
google.golang.org/protobuf/internal/impl
@@ -1534,10 +1570,10 @@
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
-crypto/tls
github.com/prometheus/client_model/go
github.com/prometheus/common/model
github.com/prometheus/alertmanager/pkg/labels
@@ -1566,10 +1602,10 @@
=== RUN TestBackoffReset
--- PASS: TestBackoffReset (0.00s)
=== RUN TestBackoffDelayContext
-2026/04/24 00:10:50.480759 backoff.go:111: INFO Backoff for 0s starts
-2026/04/24 00:10:50.481238 backoff.go:114: INFO Backoff for 0s ends
-2026/04/24 00:10:50.481243 backoff.go:111: INFO Backoff for 2ms starts
-2026/04/24 00:10:50.481246 backoff.go:116: INFO Backoff for 2ms canceled by context
+2025/03/22 19:51:03.211151 backoff.go:111: INFO Backoff for 0s starts
+2025/03/22 19:51:03.211839 backoff.go:114: INFO Backoff for 0s ends
+2025/03/22 19:51:03.211843 backoff.go:111: INFO Backoff for 2ms starts
+2025/03/22 19:51:03.211846 backoff.go:116: INFO Backoff for 2ms canceled by context
--- PASS: TestBackoffDelayContext (0.00s)
=== RUN TestNoConfig
--- PASS: TestNoConfig (0.00s)
@@ -1588,10 +1624,10 @@
=== RUN TestGivenTemplateNotOverwritten
--- PASS: TestGivenTemplateNotOverwritten (0.00s)
=== RUN TestTemplateErrorsCreateRawAlertMsg
-2026/04/24 00:10:50.482761 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at <nil>: 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/04/24 00:10:50.482773 format.go:61: WARN Sending raw alert
-2026/04/24 00:10:50.482794 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at <nil>: 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/04/24 00:10:50.482797 format.go:61: WARN Sending raw alert
+2025/03/22 19:51:03.213924 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at <nil>: 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/03/22 19:51:03.213937 format.go:61: WARN Sending raw alert
+2025/03/22 19:51:03.213957 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at <nil>: 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/03/22 19:51:03.213960 format.go:61: WARN Sending raw alert
--- PASS: TestTemplateErrorsCreateRawAlertMsg (0.00s)
=== RUN TestAlertsDispatchedOnce
--- PASS: TestAlertsDispatchedOnce (0.00s)
@@ -1602,479 +1638,479 @@
=== RUN TestMultilineTemplates
--- PASS: TestMultilineTemplates (0.00s)
=== RUN TestAlertsDispatched
-2026/04/24 00:10:50.483350 http.go:132: INFO Starting HTTP server
+2025/03/22 19:51:03.214508 http.go:132: INFO Starting HTTP server
--- PASS: TestAlertsDispatched (0.00s)
=== RUN TestRootReturnsError
-2026/04/24 00:10:50.488067 http.go:132: INFO Starting HTTP server
+2025/03/22 19:51:03.214723 http.go:132: INFO Starting HTTP server
--- PASS: TestRootReturnsError (0.00s)
=== RUN TestInvalidDataReturnsError
-2026/04/24 00:10:50.488187 http.go:132: INFO Starting HTTP server
-2026/04/24 00:10:50.488210 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/03/22 19:51:03.214825 http.go:132: INFO Starting HTTP server
+2025/03/22 19:51:03.214846 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/04/24 00:10:50.488830 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:44115
-2026/04/24 00:10:50.488863 irc.go:302: INFO Connecting to IRC 127.0.0.1:44115
-2026/04/24 00:10:50.488874 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.488881 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:44115.
-2026/04/24 00:10:50.489111 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:42006
-2026/04/24 00:10:50.491841 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.495761 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret
-2026/04/24 00:10:50.495799 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping
-2026/04/24 00:10:50.495804 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.495808 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.495811 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.499852 irc.go:146: INFO Session established
-2026/04/24 00:10:50.499909 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.499915 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.499922 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.499989 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.499998 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.500002 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.500012 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
-2026/04/24 00:10:50.500016 irc.go:296: INFO IRC routine asked to terminate
-2026/04/24 00:10:50.500021 irc.go:271: INFO IRC client connected, quitting
-2026/04/24 00:10:50.500025 irc.go:274: INFO Wait for IRC disconnect to complete
-2026/04/24 00:10:50.500037 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.500045 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.500089 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.500131 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.500137 irc.go:282: INFO IRC shutdown complete
-2026/04/24 00:10:50.500156 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
---- PASS: TestServerPassword (0.01s)
+2025/03/22 19:51:03.215195 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33115
+2025/03/22 19:51:03.215242 irc.go:302: INFO Connecting to IRC 127.0.0.1:33115
+2025/03/22 19:51:03.215333 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.215341 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33115.
+2025/03/22 19:51:03.215907 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:44710
+2025/03/22 19:51:03.217198 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.217349 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret
+2025/03/22 19:51:03.217360 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping
+2025/03/22 19:51:03.217364 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.217369 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.217371 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.217448 irc.go:146: INFO Session established
+2025/03/22 19:51:03.217479 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.217483 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.217489 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.217524 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.217530 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.217533 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.217544 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
+2025/03/22 19:51:03.217548 irc.go:296: INFO IRC routine asked to terminate
+2025/03/22 19:51:03.217552 irc.go:271: INFO IRC client connected, quitting
+2025/03/22 19:51:03.217555 irc.go:274: INFO Wait for IRC disconnect to complete
+2025/03/22 19:51:03.217566 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.217573 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.217613 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.217654 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.217660 irc.go:282: INFO IRC shutdown complete
+2025/03/22 19:51:03.217671 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+--- PASS: TestServerPassword (0.00s)
=== RUN TestSendAlertOnPreJoinedChannel
-2026/04/24 00:10:50.500242 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41149
-2026/04/24 00:10:50.500280 irc.go:302: INFO Connecting to IRC 127.0.0.1:41149
-2026/04/24 00:10:50.500287 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.500293 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41149.
-2026/04/24 00:10:50.500406 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:38404
-2026/04/24 00:10:50.500440 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.500481 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.500488 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.500492 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.500524 irc.go:146: INFO Session established
-2026/04/24 00:10:50.500540 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.500543 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.500548 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.500566 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.500571 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.500573 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.500595 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
-2026/04/24 00:10:50.500599 reconciler.go:79: INFO Setting JOIN state on channel #foo
-2026/04/24 00:10:50.500619 reconciler.go:118: INFO Channel #foo monitor: join succeeded
-2026/04/24 00:10:50.500627 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message
-2026/04/24 00:10:50.500635 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
-2026/04/24 00:10:50.500638 irc.go:296: INFO IRC routine asked to terminate
-2026/04/24 00:10:50.500642 irc.go:271: INFO IRC client connected, quitting
-2026/04/24 00:10:50.500645 irc.go:274: INFO Wait for IRC disconnect to complete
-2026/04/24 00:10:50.500658 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.500664 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.500688 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.500716 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.500723 irc.go:282: INFO IRC shutdown complete
-2026/04/24 00:10:50.500733 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+2025/03/22 19:51:03.217784 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46141
+2025/03/22 19:51:03.217808 irc.go:302: INFO Connecting to IRC 127.0.0.1:46141
+2025/03/22 19:51:03.217815 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.217820 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46141.
+2025/03/22 19:51:03.217937 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:48456
+2025/03/22 19:51:03.217967 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.218012 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.218019 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.218022 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.218057 irc.go:146: INFO Session established
+2025/03/22 19:51:03.218073 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.218076 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.218080 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.218099 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.218104 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.218107 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.218138 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
+2025/03/22 19:51:03.218142 reconciler.go:79: INFO Setting JOIN state on channel #foo
+2025/03/22 19:51:03.218162 reconciler.go:118: INFO Channel #foo monitor: join succeeded
+2025/03/22 19:51:03.218174 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message
+2025/03/22 19:51:03.218181 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
+2025/03/22 19:51:03.218186 irc.go:296: INFO IRC routine asked to terminate
+2025/03/22 19:51:03.218189 irc.go:271: INFO IRC client connected, quitting
+2025/03/22 19:51:03.218192 irc.go:274: INFO Wait for IRC disconnect to complete
+2025/03/22 19:51:03.218204 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.218210 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.218235 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.218265 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.218270 irc.go:282: INFO IRC shutdown complete
+2025/03/22 19:51:03.218279 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
--- PASS: TestSendAlertOnPreJoinedChannel (0.00s)
=== RUN TestUsePrivmsgToSendAlertOnPreJoinedChannel
-2026/04/24 00:10:50.500785 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42817
-2026/04/24 00:10:50.500801 irc.go:302: INFO Connecting to IRC 127.0.0.1:42817
-2026/04/24 00:10:50.500807 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.500811 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42817.
-2026/04/24 00:10:50.500881 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:58444
-2026/04/24 00:10:50.500916 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.500951 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.500957 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.500961 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.500987 irc.go:146: INFO Session established
-2026/04/24 00:10:50.501000 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.501003 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.501007 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.501024 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.501029 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.501032 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.501056 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
-2026/04/24 00:10:50.501066 reconciler.go:79: INFO Setting JOIN state on channel #foo
-2026/04/24 00:10:50.501081 reconciler.go:118: INFO Channel #foo monitor: join succeeded
-2026/04/24 00:10:50.501087 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message
-2026/04/24 00:10:50.501094 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
-2026/04/24 00:10:50.501098 irc.go:296: INFO IRC routine asked to terminate
-2026/04/24 00:10:50.501102 irc.go:271: INFO IRC client connected, quitting
-2026/04/24 00:10:50.501105 irc.go:274: INFO Wait for IRC disconnect to complete
-2026/04/24 00:10:50.501118 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.501123 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.501146 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.501174 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.501179 irc.go:282: INFO IRC shutdown complete
-2026/04/24 00:10:50.501187 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+2025/03/22 19:51:03.218329 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33077
+2025/03/22 19:51:03.218345 irc.go:302: INFO Connecting to IRC 127.0.0.1:33077
+2025/03/22 19:51:03.218351 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.218364 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33077.
+2025/03/22 19:51:03.218436 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:33392
+2025/03/22 19:51:03.218472 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.218512 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.218518 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.218521 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.218554 irc.go:146: INFO Session established
+2025/03/22 19:51:03.218567 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.218570 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.218574 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.218592 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.218596 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.218599 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.218618 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
+2025/03/22 19:51:03.218629 reconciler.go:79: INFO Setting JOIN state on channel #foo
+2025/03/22 19:51:03.218643 reconciler.go:118: INFO Channel #foo monitor: join succeeded
+2025/03/22 19:51:03.218648 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message
+2025/03/22 19:51:03.218655 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
+2025/03/22 19:51:03.218665 irc.go:296: INFO IRC routine asked to terminate
+2025/03/22 19:51:03.218668 irc.go:271: INFO IRC client connected, quitting
+2025/03/22 19:51:03.218671 irc.go:274: INFO Wait for IRC disconnect to complete
+2025/03/22 19:51:03.218684 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.218689 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.218712 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.218739 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.218744 irc.go:282: INFO IRC shutdown complete
+2025/03/22 19:51:03.218752 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
--- PASS: TestUsePrivmsgToSendAlertOnPreJoinedChannel (0.00s)
=== RUN TestSendAlertAndJoinChannel
-2026/04/24 00:10:50.501232 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36883
-2026/04/24 00:10:50.501248 irc.go:302: INFO Connecting to IRC 127.0.0.1:36883
-2026/04/24 00:10:50.501253 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.501257 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36883.
-2026/04/24 00:10:50.501322 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:58044
-2026/04/24 00:10:50.501346 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.501377 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.501383 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.501386 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.501411 irc.go:146: INFO Session established
-2026/04/24 00:10:50.501425 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.501430 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.501434 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.501451 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.501456 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.501459 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.501469 reconciler.go:249: INFO Request to JOIN new channel #foobar
-2026/04/24 00:10:50.501477 reconciler.go:105: INFO Channel #foobar monitor: waiting to join
-2026/04/24 00:10:50.501480 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.501483 reconciler.go:114: INFO Channel #foobar monitor: join request sent
-2026/04/24 00:10:50.501516 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar
-2026/04/24 00:10:50.501522 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.501524 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar
-2026/04/24 00:10:50.501548 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
-2026/04/24 00:10:50.501552 reconciler.go:79: INFO Setting JOIN state on channel #foo
-2026/04/24 00:10:50.501561 reconciler.go:205: INFO Received JOIN confirmation for channel #foobar
-2026/04/24 00:10:50.501564 reconciler.go:79: INFO Setting JOIN state on channel #foobar
-2026/04/24 00:10:50.501568 reconciler.go:118: INFO Channel #foo monitor: join succeeded
-2026/04/24 00:10:50.501573 reconciler.go:118: INFO Channel #foobar monitor: join succeeded
-2026/04/24 00:10:50.501590 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message
-2026/04/24 00:10:50.501598 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
-2026/04/24 00:10:50.501601 irc.go:296: INFO IRC routine asked to terminate
-2026/04/24 00:10:50.501604 irc.go:271: INFO IRC client connected, quitting
-2026/04/24 00:10:50.501607 irc.go:274: INFO Wait for IRC disconnect to complete
-2026/04/24 00:10:50.501616 reconciler.go:131: INFO Channel #foobar monitor: context canceled while monitoring
-2026/04/24 00:10:50.501623 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.501629 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.501652 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.501678 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.501683 irc.go:282: INFO IRC shutdown complete
-2026/04/24 00:10:50.501692 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+2025/03/22 19:51:03.218807 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43865
+2025/03/22 19:51:03.218821 irc.go:302: INFO Connecting to IRC 127.0.0.1:43865
+2025/03/22 19:51:03.218827 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.218831 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43865.
+2025/03/22 19:51:03.218901 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:42526
+2025/03/22 19:51:03.218927 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.218967 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.218973 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.218976 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.219011 irc.go:146: INFO Session established
+2025/03/22 19:51:03.219027 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.219029 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.219033 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.219050 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.219055 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.219057 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.219067 reconciler.go:249: INFO Request to JOIN new channel #foobar
+2025/03/22 19:51:03.219075 reconciler.go:105: INFO Channel #foobar monitor: waiting to join
+2025/03/22 19:51:03.219078 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.219081 reconciler.go:114: INFO Channel #foobar monitor: join request sent
+2025/03/22 19:51:03.219111 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar
+2025/03/22 19:51:03.219116 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.219119 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar
+2025/03/22 19:51:03.219154 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
+2025/03/22 19:51:03.219158 reconciler.go:79: INFO Setting JOIN state on channel #foo
+2025/03/22 19:51:03.219166 reconciler.go:205: INFO Received JOIN confirmation for channel #foobar
+2025/03/22 19:51:03.219169 reconciler.go:79: INFO Setting JOIN state on channel #foobar
+2025/03/22 19:51:03.219174 reconciler.go:118: INFO Channel #foo monitor: join succeeded
+2025/03/22 19:51:03.219177 reconciler.go:118: INFO Channel #foobar monitor: join succeeded
+2025/03/22 19:51:03.219193 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message
+2025/03/22 19:51:03.219201 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
+2025/03/22 19:51:03.219205 irc.go:296: INFO IRC routine asked to terminate
+2025/03/22 19:51:03.219208 irc.go:271: INFO IRC client connected, quitting
+2025/03/22 19:51:03.219211 irc.go:274: INFO Wait for IRC disconnect to complete
+2025/03/22 19:51:03.219219 reconciler.go:131: INFO Channel #foobar monitor: context canceled while monitoring
+2025/03/22 19:51:03.219227 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.219232 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.219257 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.219283 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.219288 irc.go:282: INFO IRC shutdown complete
+2025/03/22 19:51:03.219297 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
--- PASS: TestSendAlertAndJoinChannel (0.00s)
=== RUN TestSendAlertDisconnected
-2026/04/24 00:10:50.501754 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34511
-2026/04/24 00:10:50.501768 irc.go:302: INFO Connecting to IRC 127.0.0.1:34511
-2026/04/24 00:10:50.501774 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.501781 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34511.
-2026/04/24 00:10:50.501845 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:41878
-2026/04/24 00:10:50.501870 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.501903 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.501908 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.501911 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.501916 irc_test.go:294: INFO =Server= Wait before completing session
-2026/04/24 00:10:50.501919 irc_test.go:296: INFO =Server= Completing session
-2026/04/24 00:10:50.501944 irc.go:146: INFO Session established
-2026/04/24 00:10:50.501964 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.501967 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.501974 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.501993 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.501999 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.502001 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.502021 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
-2026/04/24 00:10:50.502025 reconciler.go:79: INFO Setting JOIN state on channel #foo
-2026/04/24 00:10:50.502038 reconciler.go:118: INFO Channel #foo monitor: join succeeded
-2026/04/24 00:10:50.502044 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message
-2026/04/24 00:10:50.502051 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
-2026/04/24 00:10:50.502054 irc.go:296: INFO IRC routine asked to terminate
-2026/04/24 00:10:50.502057 irc.go:271: INFO IRC client connected, quitting
-2026/04/24 00:10:50.502060 irc.go:274: INFO Wait for IRC disconnect to complete
-2026/04/24 00:10:50.502073 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.502078 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.502100 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.502126 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.502131 irc.go:282: INFO IRC shutdown complete
-2026/04/24 00:10:50.502140 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+2025/03/22 19:51:03.219342 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:35175
+2025/03/22 19:51:03.219369 irc.go:302: INFO Connecting to IRC 127.0.0.1:35175
+2025/03/22 19:51:03.219374 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.219379 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:35175.
+2025/03/22 19:51:03.219461 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:60404
+2025/03/22 19:51:03.219489 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.219528 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.219533 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.219536 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.219540 irc_test.go:294: INFO =Server= Wait before completing session
+2025/03/22 19:51:03.219544 irc_test.go:296: INFO =Server= Completing session
+2025/03/22 19:51:03.219573 irc.go:146: INFO Session established
+2025/03/22 19:51:03.219586 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.219588 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.219598 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.219615 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.219620 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.219623 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.219641 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
+2025/03/22 19:51:03.219644 reconciler.go:79: INFO Setting JOIN state on channel #foo
+2025/03/22 19:51:03.219657 reconciler.go:118: INFO Channel #foo monitor: join succeeded
+2025/03/22 19:51:03.219663 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message
+2025/03/22 19:51:03.219669 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
+2025/03/22 19:51:03.219675 irc.go:296: INFO IRC routine asked to terminate
+2025/03/22 19:51:03.219678 irc.go:271: INFO IRC client connected, quitting
+2025/03/22 19:51:03.219680 irc.go:274: INFO Wait for IRC disconnect to complete
+2025/03/22 19:51:03.219693 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.219698 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.219721 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.219747 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.219753 irc.go:282: INFO IRC shutdown complete
+2025/03/22 19:51:03.219761 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
--- PASS: TestSendAlertDisconnected (0.00s)
=== RUN TestReconnect
-2026/04/24 00:10:50.502180 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43865
-2026/04/24 00:10:50.502195 irc.go:302: INFO Connecting to IRC 127.0.0.1:43865
-2026/04/24 00:10:50.502200 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.502204 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43865.
-2026/04/24 00:10:50.502263 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:56940
-2026/04/24 00:10:50.502287 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.502317 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.502323 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.502325 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.502349 irc.go:146: INFO Session established
-2026/04/24 00:10:50.502361 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.502364 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.502368 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.502386 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.502393 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.502396 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.502428 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:56940: read tcp 127.0.0.1:43865->127.0.0.1:56940: use of closed network connection
-2026/04/24 00:10:50.502443 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.502469 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
-2026/04/24 00:10:50.502473 reconciler.go:79: INFO Setting JOIN state on channel #foo
-2026/04/24 00:10:50.502481 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.502487 reconciler.go:118: INFO Channel #foo monitor: join succeeded
-2026/04/24 00:10:50.502493 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
-2026/04/24 00:10:50.502496 irc.go:302: INFO Connecting to IRC 127.0.0.1:43865
-2026/04/24 00:10:50.502499 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.502506 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43865.
-2026/04/24 00:10:50.502579 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.502618 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:56944
-2026/04/24 00:10:50.502626 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.502631 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.502633 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.502667 irc.go:146: INFO Session established
-2026/04/24 00:10:50.502680 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.502683 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.502687 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.502705 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.502710 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.502713 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.502724 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
-2026/04/24 00:10:50.502728 irc.go:296: INFO IRC routine asked to terminate
-2026/04/24 00:10:50.502731 irc.go:271: INFO IRC client connected, quitting
-2026/04/24 00:10:50.502735 irc.go:274: INFO Wait for IRC disconnect to complete
-2026/04/24 00:10:50.502937 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.502955 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.502996 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.503032 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
-2026/04/24 00:10:50.503036 reconciler.go:79: INFO Setting JOIN state on channel #foo
-2026/04/24 00:10:50.503047 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.503053 irc.go:282: INFO IRC shutdown complete
-2026/04/24 00:10:50.503063 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
---- PASS: TestReconnect (0.00s)
+2025/03/22 19:51:03.219803 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37729
+2025/03/22 19:51:03.219823 irc.go:302: INFO Connecting to IRC 127.0.0.1:37729
+2025/03/22 19:51:03.219828 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.219832 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37729.
+2025/03/22 19:51:03.219895 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:39474
+2025/03/22 19:51:03.219921 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.219969 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.219975 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.219978 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.220013 irc.go:146: INFO Session established
+2025/03/22 19:51:03.220026 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.220029 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.220033 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.220054 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.220064 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.220066 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.220095 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:39474: read tcp 127.0.0.1:37729->127.0.0.1:39474: use of closed network connection
+2025/03/22 19:51:03.220112 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.220139 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
+2025/03/22 19:51:03.220143 reconciler.go:79: INFO Setting JOIN state on channel #foo
+2025/03/22 19:51:03.220152 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.220156 reconciler.go:118: INFO Channel #foo monitor: join succeeded
+2025/03/22 19:51:03.220161 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
+2025/03/22 19:51:03.220175 irc.go:302: INFO Connecting to IRC 127.0.0.1:37729
+2025/03/22 19:51:03.220178 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.220181 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37729.
+2025/03/22 19:51:03.220271 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.220417 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:39482
+2025/03/22 19:51:03.220467 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.220486 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.220493 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.237250 irc.go:146: INFO Session established
+2025/03/22 19:51:03.237302 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.237307 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.237314 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.237385 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.237393 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.237397 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.237414 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
+2025/03/22 19:51:03.237418 irc.go:296: INFO IRC routine asked to terminate
+2025/03/22 19:51:03.237422 irc.go:271: INFO IRC client connected, quitting
+2025/03/22 19:51:03.237426 irc.go:274: INFO Wait for IRC disconnect to complete
+2025/03/22 19:51:03.237442 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.237451 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.237496 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.237541 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
+2025/03/22 19:51:03.237546 reconciler.go:79: INFO Setting JOIN state on channel #foo
+2025/03/22 19:51:03.237559 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.237565 irc.go:282: INFO IRC shutdown complete
+2025/03/22 19:51:03.237577 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+--- PASS: TestReconnect (0.02s)
=== RUN TestConnectErrorRetry
-2026/04/24 00:10:50.503115 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41363
-2026/04/24 00:10:50.503133 irc.go:302: INFO Connecting to IRC 127.0.0.1:41363
-2026/04/24 00:10:50.503138 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.503141 fake_delayer.go:45: INFO Waiting StopDelay signal
-2026/04/24 00:10:50.503144 fake_delayer.go:47: INFO Received StopDelay signal
-2026/04/24 00:10:50.503148 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41363.
-2026/04/24 00:10:50.503222 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:35464
-2026/04/24 00:10:50.503226 irc_server_for_test.go:157: INFO =Server= Closing connection early
-2026/04/24 00:10:50.503293 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.503337 connection.go:444: ERROR irc.send(): write tcp 127.0.0.1:35464->127.0.0.1:41363: write: broken pipe
-2026/04/24 00:10:50.503344 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.503358 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:35464->127.0.0.1:41363: use of closed network connection
-2026/04/24 00:10:50.503372 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.503377 irc.go:321: WARN Receiving a session down before the session is up, this is odd
-2026/04/24 00:10:50.503381 irc.go:302: INFO Connecting to IRC 127.0.0.1:41363
-2026/04/24 00:10:50.503384 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.503386 fake_delayer.go:45: INFO Waiting StopDelay signal
-2026/04/24 00:10:50.503389 fake_delayer.go:47: INFO Received StopDelay signal
-2026/04/24 00:10:50.503393 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41363.
-2026/04/24 00:10:50.503534 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.503587 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:35480
-2026/04/24 00:10:50.503609 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.503615 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.503618 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.503648 irc.go:146: INFO Session established
-2026/04/24 00:10:50.503662 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.503665 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.503669 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.503688 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.503787 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.503797 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.503830 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
-2026/04/24 00:10:50.503835 irc.go:296: INFO IRC routine asked to terminate
-2026/04/24 00:10:50.503838 irc.go:271: INFO IRC client connected, quitting
-2026/04/24 00:10:50.503842 irc.go:274: INFO Wait for IRC disconnect to complete
-2026/04/24 00:10:50.507778 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.507819 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.507919 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.507984 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
-2026/04/24 00:10:50.507992 reconciler.go:79: INFO Setting JOIN state on channel #foo
-2026/04/24 00:10:50.508009 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.508017 irc.go:282: INFO IRC shutdown complete
-2026/04/24 00:10:50.508032 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+2025/03/22 19:51:03.237664 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40283
+2025/03/22 19:51:03.237687 irc.go:302: INFO Connecting to IRC 127.0.0.1:40283
+2025/03/22 19:51:03.237694 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.237697 fake_delayer.go:45: INFO Waiting StopDelay signal
+2025/03/22 19:51:03.237700 fake_delayer.go:47: INFO Received StopDelay signal
+2025/03/22 19:51:03.237706 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40283.
+2025/03/22 19:51:03.237838 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:44336
+2025/03/22 19:51:03.237844 irc_server_for_test.go:157: INFO =Server= Closing connection early
+2025/03/22 19:51:03.237890 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.237933 connection.go:444: ERROR irc.send(): write tcp 127.0.0.1:44336->127.0.0.1:40283: write: broken pipe
+2025/03/22 19:51:03.237941 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.237954 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:44336->127.0.0.1:40283: use of closed network connection
+2025/03/22 19:51:03.237972 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.237978 irc.go:321: WARN Receiving a session down before the session is up, this is odd
+2025/03/22 19:51:03.237984 irc.go:302: INFO Connecting to IRC 127.0.0.1:40283
+2025/03/22 19:51:03.237986 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.237988 fake_delayer.go:45: INFO Waiting StopDelay signal
+2025/03/22 19:51:03.237991 fake_delayer.go:47: INFO Received StopDelay signal
+2025/03/22 19:51:03.237995 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40283.
+2025/03/22 19:51:03.238075 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.238122 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:44346
+2025/03/22 19:51:03.238132 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.238138 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.238141 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.238173 irc.go:146: INFO Session established
+2025/03/22 19:51:03.238190 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.238195 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.238199 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.238220 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.238225 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.238228 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.238240 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
+2025/03/22 19:51:03.238244 irc.go:296: INFO IRC routine asked to terminate
+2025/03/22 19:51:03.238246 irc.go:271: INFO IRC client connected, quitting
+2025/03/22 19:51:03.238250 irc.go:274: INFO Wait for IRC disconnect to complete
+2025/03/22 19:51:03.238335 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.238344 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.238373 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.238405 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
+2025/03/22 19:51:03.238410 reconciler.go:79: INFO Setting JOIN state on channel #foo
+2025/03/22 19:51:03.238420 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.238425 irc.go:282: INFO IRC shutdown complete
+2025/03/22 19:51:03.238435 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
--- PASS: TestConnectErrorRetry (0.00s)
=== RUN TestIdentify
-2026/04/24 00:10:50.508126 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34573
-2026/04/24 00:10:50.508146 irc.go:302: INFO Connecting to IRC 127.0.0.1:34573
-2026/04/24 00:10:50.508154 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.508161 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34573.
-2026/04/24 00:10:50.508271 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:37698
-2026/04/24 00:10:50.511917 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.516014 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.516095 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.516174 irc.go:167: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye.
-2026/04/24 00:10:50.516188 irc.go:191: INFO Handling NickServ request to IDENTIFY
-2026/04/24 00:10:50.516214 irc.go:146: INFO Session established
-2026/04/24 00:10:50.516233 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request
-2026/04/24 00:10:50.516256 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.516260 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.516266 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.516287 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword
-2026/04/24 00:10:50.516293 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.516297 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.516301 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.516303 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.516317 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
-2026/04/24 00:10:50.516322 irc.go:296: INFO IRC routine asked to terminate
-2026/04/24 00:10:50.516326 irc.go:271: INFO IRC client connected, quitting
-2026/04/24 00:10:50.516330 irc.go:274: INFO Wait for IRC disconnect to complete
-2026/04/24 00:10:50.516347 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.516355 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.516405 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.516447 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
-2026/04/24 00:10:50.516452 reconciler.go:79: INFO Setting JOIN state on channel #foo
-2026/04/24 00:10:50.516462 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.516468 irc.go:282: INFO IRC shutdown complete
-2026/04/24 00:10:50.516482 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
---- PASS: TestIdentify (0.01s)
+2025/03/22 19:51:03.238494 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41569
+2025/03/22 19:51:03.238511 irc.go:302: INFO Connecting to IRC 127.0.0.1:41569
+2025/03/22 19:51:03.238517 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.238524 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41569.
+2025/03/22 19:51:03.238603 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:50882
+2025/03/22 19:51:03.238630 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.238666 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.238678 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.238702 irc.go:167: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye.
+2025/03/22 19:51:03.238711 irc.go:191: INFO Handling NickServ request to IDENTIFY
+2025/03/22 19:51:03.238727 irc.go:146: INFO Session established
+2025/03/22 19:51:03.238740 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request
+2025/03/22 19:51:03.238751 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.238753 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.238758 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.238775 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword
+2025/03/22 19:51:03.238781 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.238784 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.238788 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.238790 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.238800 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
+2025/03/22 19:51:03.238804 irc.go:296: INFO IRC routine asked to terminate
+2025/03/22 19:51:03.238807 irc.go:271: INFO IRC client connected, quitting
+2025/03/22 19:51:03.238810 irc.go:274: INFO Wait for IRC disconnect to complete
+2025/03/22 19:51:03.238897 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.238906 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.238938 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.238970 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
+2025/03/22 19:51:03.238974 reconciler.go:79: INFO Setting JOIN state on channel #foo
+2025/03/22 19:51:03.238983 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.238988 irc.go:282: INFO IRC shutdown complete
+2025/03/22 19:51:03.238998 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+--- PASS: TestIdentify (0.00s)
=== RUN TestGhost
-2026/04/24 00:10:50.516573 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38005
-2026/04/24 00:10:50.516597 irc.go:302: INFO Connecting to IRC 127.0.0.1:38005
-2026/04/24 00:10:50.516604 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.516611 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38005.
-2026/04/24 00:10:50.516719 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:47002
-2026/04/24 00:10:50.516752 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.516791 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.516799 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.516830 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use'
-2026/04/24 00:10:50.516842 irc_server_for_test.go:119: INFO =Server= Received NICK foo^
-2026/04/24 00:10:50.516867 irc.go:146: INFO Session established
-2026/04/24 00:10:50.516874 irc.go:206: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo'
-2026/04/24 00:10:50.516880 irc.go:212: INFO Changing nick to 'foo'
-2026/04/24 00:10:50.516884 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request
-2026/04/24 00:10:50.516895 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.516898 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.516903 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.516929 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword
-2026/04/24 00:10:50.516937 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.516940 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.516944 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.516947 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.516949 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.516960 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
-2026/04/24 00:10:50.516964 irc.go:296: INFO IRC routine asked to terminate
-2026/04/24 00:10:50.516967 irc.go:271: INFO IRC client connected, quitting
-2026/04/24 00:10:50.516971 irc.go:274: INFO Wait for IRC disconnect to complete
-2026/04/24 00:10:50.516995 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.517001 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.517031 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.517065 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.517071 irc.go:282: INFO IRC shutdown complete
-2026/04/24 00:10:50.517081 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+2025/03/22 19:51:03.239050 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43645
+2025/03/22 19:51:03.239066 irc.go:302: INFO Connecting to IRC 127.0.0.1:43645
+2025/03/22 19:51:03.239072 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.239078 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43645.
+2025/03/22 19:51:03.239149 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:58824
+2025/03/22 19:51:03.239175 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.239209 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.239216 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.239244 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use'
+2025/03/22 19:51:03.239255 irc_server_for_test.go:119: INFO =Server= Received NICK foo^
+2025/03/22 19:51:03.239278 irc.go:146: INFO Session established
+2025/03/22 19:51:03.239285 irc.go:206: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo'
+2025/03/22 19:51:03.239289 irc.go:212: INFO Changing nick to 'foo'
+2025/03/22 19:51:03.239293 irc.go:226: INFO Waiting for NickServ to notice us and issue an identify request
+2025/03/22 19:51:03.239302 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.239305 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.239309 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.239335 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword
+2025/03/22 19:51:03.239340 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.239343 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.239347 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.239350 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.239352 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.239363 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
+2025/03/22 19:51:03.239367 irc.go:296: INFO IRC routine asked to terminate
+2025/03/22 19:51:03.239369 irc.go:271: INFO IRC client connected, quitting
+2025/03/22 19:51:03.239372 irc.go:274: INFO Wait for IRC disconnect to complete
+2025/03/22 19:51:03.239606 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.239616 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.239652 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.239688 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.239694 irc.go:282: INFO IRC shutdown complete
+2025/03/22 19:51:03.239704 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
--- PASS: TestGhost (0.00s)
=== RUN TestStopRunningWhenHalfConnected
-2026/04/24 00:10:50.517135 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40655
-2026/04/24 00:10:50.517153 irc.go:302: INFO Connecting to IRC 127.0.0.1:40655
-2026/04/24 00:10:50.517158 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.517162 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40655.
-2026/04/24 00:10:50.517237 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:42972
-2026/04/24 00:10:50.517265 irc.go:310: INFO Connected to IRC server, waiting to establish session
-2026/04/24 00:10:50.517300 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.517306 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.517309 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.517313 irc_test.go:591: INFO =Server= NOT completing session
-2026/04/24 00:10:50.517320 irc.go:323: INFO IRC routine asked to terminate
-2026/04/24 00:10:50.517324 irc.go:282: INFO IRC shutdown complete
-2026/04/24 00:10:50.517337 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.517354 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:42972->127.0.0.1:40655: use of closed network connection
-2026/04/24 00:10:50.517364 irc.go:152: INFO Disconnected from IRC
-2026/04/24 00:10:50.517371 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:42972 disconnected
-2026/04/24 00:10:50.517389 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+2025/03/22 19:51:03.239755 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37207
+2025/03/22 19:51:03.239775 irc.go:302: INFO Connecting to IRC 127.0.0.1:37207
+2025/03/22 19:51:03.239781 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.239785 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37207.
+2025/03/22 19:51:03.239857 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:53768
+2025/03/22 19:51:03.239885 irc.go:310: INFO Connected to IRC server, waiting to establish session
+2025/03/22 19:51:03.239918 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.239924 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.239927 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.239931 irc_test.go:591: INFO =Server= NOT completing session
+2025/03/22 19:51:03.239938 irc.go:323: INFO IRC routine asked to terminate
+2025/03/22 19:51:03.239942 irc.go:282: INFO IRC shutdown complete
+2025/03/22 19:51:03.239954 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.239972 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:53768->127.0.0.1:37207: use of closed network connection
+2025/03/22 19:51:03.239983 irc.go:152: INFO Disconnected from IRC
+2025/03/22 19:51:03.239990 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:53768 disconnected
+2025/03/22 19:51:03.240007 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
--- PASS: TestStopRunningWhenHalfConnected (0.00s)
=== RUN TestPreJoinChannels
-2026/04/24 00:10:50.517432 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39587
-2026/04/24 00:10:50.517444 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39587.
-2026/04/24 00:10:50.517502 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:47816
-2026/04/24 00:10:50.517553 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.517558 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.517561 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.517599 reconciler.go:105: INFO Channel #baz monitor: waiting to join
-2026/04/24 00:10:50.517603 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.517607 reconciler.go:114: INFO Channel #baz monitor: join request sent
-2026/04/24 00:10:50.517623 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.517629 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.517633 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.517648 reconciler.go:105: INFO Channel #bar monitor: waiting to join
-2026/04/24 00:10:50.517651 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.517654 reconciler.go:114: INFO Channel #bar monitor: join request sent
-2026/04/24 00:10:50.517674 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz
-2026/04/24 00:10:50.517679 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.517681 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz
-2026/04/24 00:10:50.517690 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.517694 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.517698 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.517705 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar
-2026/04/24 00:10:50.517709 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.517711 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar
-2026/04/24 00:10:50.517739 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.517746 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.517773 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.517801 reconciler.go:205: INFO Received JOIN confirmation for channel #baz
-2026/04/24 00:10:50.517806 reconciler.go:79: INFO Setting JOIN state on channel #baz
-2026/04/24 00:10:50.517815 reconciler.go:118: INFO Channel #baz monitor: join succeeded
-2026/04/24 00:10:50.517821 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
-2026/04/24 00:10:50.517825 reconciler.go:131: INFO Channel #baz monitor: context canceled while monitoring
-2026/04/24 00:10:50.517829 reconciler.go:122: INFO Channel #bar monitor: context canceled while waiting for join
-2026/04/24 00:10:50.517838 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+2025/03/22 19:51:03.240046 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33659
+2025/03/22 19:51:03.240059 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33659.
+2025/03/22 19:51:03.240120 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:59510
+2025/03/22 19:51:03.240170 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.240176 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.240178 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.240212 reconciler.go:105: INFO Channel #baz monitor: waiting to join
+2025/03/22 19:51:03.240215 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.240219 reconciler.go:114: INFO Channel #baz monitor: join request sent
+2025/03/22 19:51:03.240235 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.240238 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.240241 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.240256 reconciler.go:105: INFO Channel #bar monitor: waiting to join
+2025/03/22 19:51:03.240259 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.240264 reconciler.go:114: INFO Channel #bar monitor: join request sent
+2025/03/22 19:51:03.240283 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz
+2025/03/22 19:51:03.240289 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.240292 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz
+2025/03/22 19:51:03.240300 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.240304 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.240306 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.240313 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar
+2025/03/22 19:51:03.240317 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.240320 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar
+2025/03/22 19:51:03.240421 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.240429 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.240464 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.240495 reconciler.go:205: INFO Received JOIN confirmation for channel #baz
+2025/03/22 19:51:03.240500 reconciler.go:79: INFO Setting JOIN state on channel #baz
+2025/03/22 19:51:03.240510 reconciler.go:118: INFO Channel #baz monitor: join succeeded
+2025/03/22 19:51:03.240517 reconciler.go:122: INFO Channel #foo monitor: context canceled while waiting for join
+2025/03/22 19:51:03.240520 reconciler.go:131: INFO Channel #baz monitor: context canceled while monitoring
+2025/03/22 19:51:03.240524 reconciler.go:122: INFO Channel #bar monitor: context canceled while waiting for join
+2025/03/22 19:51:03.240532 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
--- PASS: TestPreJoinChannels (0.00s)
=== RUN TestKeepJoining
-2026/04/24 00:10:50.517881 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:44493
-2026/04/24 00:10:50.517894 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:44493.
-2026/04/24 00:10:50.517957 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:54250
-2026/04/24 00:10:50.518008 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.518014 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.518016 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.518047 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.518050 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.518055 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.518072 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.518077 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.518080 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.518087 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry
-2026/04/24 00:10:50.518090 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.518092 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.518096 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.518112 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.518119 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.518123 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.518128 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry
-2026/04/24 00:10:50.518131 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.518133 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.518138 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.518152 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.518157 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.518160 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.518279 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.518286 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.518320 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.518351 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
-2026/04/24 00:10:50.518356 reconciler.go:79: INFO Setting JOIN state on channel #foo
-2026/04/24 00:10:50.518365 reconciler.go:118: INFO Channel #foo monitor: join succeeded
-2026/04/24 00:10:50.518371 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
-2026/04/24 00:10:50.518380 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+2025/03/22 19:51:03.240580 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40825
+2025/03/22 19:51:03.240600 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40825.
+2025/03/22 19:51:03.240669 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:56368
+2025/03/22 19:51:03.240722 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.240729 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.240732 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.240765 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.240769 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.240773 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.240792 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.240797 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.240799 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.240806 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry
+2025/03/22 19:51:03.240809 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.240813 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.240817 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.240832 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.240837 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.240840 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.240845 reconciler.go:120: WARN Channel #foo monitor: could not join after 10 seconds, will retry
+2025/03/22 19:51:03.240847 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.240850 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.240853 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.240868 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.240873 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.240876 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.240962 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.240968 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.240999 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.241029 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
+2025/03/22 19:51:03.241034 reconciler.go:79: INFO Setting JOIN state on channel #foo
+2025/03/22 19:51:03.241042 reconciler.go:118: INFO Channel #foo monitor: join succeeded
+2025/03/22 19:51:03.241048 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
+2025/03/22 19:51:03.241056 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
--- PASS: TestKeepJoining (0.00s)
=== RUN TestKickRejoin
-2026/04/24 00:10:50.518424 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34591
-2026/04/24 00:10:50.518438 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34591.
-2026/04/24 00:10:50.518509 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:43940
-2026/04/24 00:10:50.518567 irc_server_for_test.go:119: INFO =Server= Received NICK foo
-2026/04/24 00:10:50.518573 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
-2026/04/24 00:10:50.518576 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
-2026/04/24 00:10:50.518611 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.518614 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.518619 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.518641 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.518646 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.518649 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.518659 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye!
-2026/04/24 00:10:50.518679 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
-2026/04/24 00:10:50.518682 reconciler.go:79: INFO Setting JOIN state on channel #foo
-2026/04/24 00:10:50.518691 reconciler.go:223: INFO Received KICK for channel #foo
-2026/04/24 00:10:50.518696 reconciler.go:93: INFO Removing JOIN state on channel #foo
-2026/04/24 00:10:50.518701 reconciler.go:118: INFO Channel #foo monitor: join succeeded
-2026/04/24 00:10:50.518705 reconciler.go:105: INFO Channel #foo monitor: waiting to join
-2026/04/24 00:10:50.518707 fake_delayer.go:43: INFO Faking Backoff
-2026/04/24 00:10:50.518711 reconciler.go:114: INFO Channel #foo monitor: join request sent
-2026/04/24 00:10:50.518728 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
-2026/04/24 00:10:50.518733 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
-2026/04/24 00:10:50.518735 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
-2026/04/24 00:10:50.518847 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
-2026/04/24 00:10:50.518855 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
-2026/04/24 00:10:50.518891 connection.go:577: INFO irc.Close(): Disconnected from server.
-2026/04/24 00:10:50.518922 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
-2026/04/24 00:10:50.518926 reconciler.go:79: INFO Setting JOIN state on channel #foo
-2026/04/24 00:10:50.518935 reconciler.go:118: INFO Channel #foo monitor: join succeeded
-2026/04/24 00:10:50.518941 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
-2026/04/24 00:10:50.518949 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections
+2025/03/22 19:51:03.241202 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40353
+2025/03/22 19:51:03.241229 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40353.
+2025/03/22 19:51:03.241314 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:37458
+2025/03/22 19:51:03.245313 irc_server_for_test.go:119: INFO =Server= Received NICK foo
+2025/03/22 19:51:03.245342 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping
+2025/03/22 19:51:03.245347 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * :
+2025/03/22 19:51:03.245400 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.245405 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.245411 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.245432 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.245438 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.245440 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.245456 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye!
+2025/03/22 19:51:03.245480 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
+2025/03/22 19:51:03.245484 reconciler.go:79: INFO Setting JOIN state on channel #foo
+2025/03/22 19:51:03.245496 reconciler.go:223: INFO Received KICK for channel #foo
+2025/03/22 19:51:03.245500 reconciler.go:93: INFO Removing JOIN state on channel #foo
+2025/03/22 19:51:03.245506 reconciler.go:118: INFO Channel #foo monitor: join succeeded
+2025/03/22 19:51:03.245509 reconciler.go:105: INFO Channel #foo monitor: waiting to join
+2025/03/22 19:51:03.245511 fake_delayer.go:43: INFO Faking Backoff
+2025/03/22 19:51:03.245515 reconciler.go:114: INFO Channel #foo monitor: join request sent
+2025/03/22 19:51:03.245534 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo
+2025/03/22 19:51:03.245540 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping
+2025/03/22 19:51:03.245543 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo
+2025/03/22 19:51:03.245567 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya
+2025/03/22 19:51:03.245573 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate
+2025/03/22 19:51:03.245622 connection.go:577: INFO irc.Close(): Disconnected from server.
+2025/03/22 19:51:03.245658 reconciler.go:205: INFO Received JOIN confirmation for channel #foo
+2025/03/22 19:51:03.245663 reconciler.go:79: INFO Setting JOIN state on channel #foo
+2025/03/22 19:51:03.245672 reconciler.go:118: INFO Channel #foo monitor: join succeeded
+2025/03/22 19:51:03.245678 reconciler.go:131: INFO Channel #foo monitor: context canceled while monitoring
+2025/03/22 19:51:03.245689 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.193s
+ok github.com/google/alertmanager-irc-relay 0.088s
? github.com/google/alertmanager-irc-relay/logging [no test files]
create-stamp debian/debhelper-build-stamp
dh_testroot -O--buildsystem=golang
@@ -2106,8 +2142,8 @@
dh_gencontrol -O--buildsystem=golang
dh_md5sums -O--buildsystem=golang
dh_builddeb -O--buildsystem=golang
-dpkg-deb: building package 'alertmanager-irc-relay-dbgsym' in '../alertmanager-irc-relay-dbgsym_0.5.1-3_arm64.deb'.
dpkg-deb: building package 'alertmanager-irc-relay' in '../alertmanager-irc-relay_0.5.1-3_arm64.deb'.
+dpkg-deb: building package 'alertmanager-irc-relay-dbgsym' in '../alertmanager-irc-relay-dbgsym_0.5.1-3_arm64.deb'.
dpkg-genbuildinfo --build=binary -O../alertmanager-irc-relay_0.5.1-3_arm64.buildinfo
dpkg-genchanges --build=binary -O../alertmanager-irc-relay_0.5.1-3_arm64.changes
dpkg-genchanges: info: binary-only upload (no source code included)
@@ -2115,12 +2151,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/3082384/tmp/hooks/B01_cleanup starting
+I: user script /srv/workspace/pbuilder/3082384/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/1374347 and its subdirectories
-I: Current time: Fri Apr 24 00:11:16 -12 2026
-I: pbuilder-time-stamp: 1777032676
+I: removing directory /srv/workspace/pbuilder/3082384 and its subdirectories
+I: Current time: Sat Mar 22 19:51:26 +14 2025
+I: pbuilder-time-stamp: 1742622686