Diff of the two buildlogs: -- --- b1/build.log 2024-05-22 18:33:21.399186528 +0000 +++ b2/build.log 2024-05-22 18:34:54.759211644 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Wed May 22 06:30:30 -12 2024 -I: pbuilder-time-stamp: 1716402630 +I: Current time: Wed Jun 25 14:56:23 +14 2025 +I: pbuilder-time-stamp: 1750812983 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/unstable-reproducible-base.tgz] I: copying local configuration @@ -26,52 +26,84 @@ dpkg-source: info: unpacking alertmanager-irc-relay_0.4.2-1.debian.tar.xz I: using fakeroot in build. I: Installing the build-deps -I: user script /srv/workspace/pbuilder/1561046/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/1148507/tmp/hooks/D01_modify_environment starting +debug: Running on ionos5-amd64. +I: Changing host+domainname to test build reproducibility +I: Adding a custom variable just for the fun of it... +I: Changing /bin/sh to bash +'/bin/sh' -> '/bin/bash' +lrwxrwxrwx 1 root root 9 Jun 25 00:56 /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/1148507/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/1148507/tmp/hooks/D02_print_environment starting I: set - BUILDDIR='/build/reproducible-path' - BUILDUSERGECOS='first user,first room,first work-phone,first home-phone,first other' - BUILDUSERNAME='pbuilder1' - BUILD_ARCH='amd64' - DEBIAN_FRONTEND='noninteractive' - DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=20 ' - DISTRIBUTION='unstable' - HOME='/root' - HOST_ARCH='amd64' + BASH=/bin/sh + BASHOPTS=checkwinsize:cmdhist:complete_fullquote:extquote:force_fignore:globasciiranges:globskipdots:hostcomplete:interactive_comments:patsub_replacement:progcomp:promptvars:sourcepath + BASH_ALIASES=() + BASH_ARGC=() + BASH_ARGV=() + BASH_CMDS=() + BASH_LINENO=([0]="12" [1]="0") + BASH_LOADABLES_PATH=/usr/local/lib/bash:/usr/lib/bash:/opt/local/lib/bash:/usr/pkg/lib/bash:/opt/pkg/lib/bash:. + BASH_SOURCE=([0]="/tmp/hooks/D02_print_environment" [1]="/tmp/hooks/D02_print_environment") + BASH_VERSINFO=([0]="5" [1]="2" [2]="21" [3]="1" [4]="release" [5]="x86_64-pc-linux-gnu") + BASH_VERSION='5.2.21(1)-release' + BUILDDIR=/build/reproducible-path + BUILDUSERGECOS='second user,second room,second work-phone,second home-phone,second other' + BUILDUSERNAME=pbuilder2 + BUILD_ARCH=amd64 + DEBIAN_FRONTEND=noninteractive + DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=42 ' + DIRSTACK=() + DISTRIBUTION=unstable + EUID=0 + FUNCNAME=([0]="Echo" [1]="main") + GROUPS=() + HOME=/root + HOSTNAME=i-capture-the-hostname + HOSTTYPE=x86_64 + HOST_ARCH=amd64 IFS=' ' - INVOCATION_ID='c3f61aa222a0415f811b2c566e780cdc' - 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='1561046' - PS1='# ' - PS2='> ' + INVOCATION_ID=5fa94acd3606496996d3f44ab421ce02 + LANG=C + LANGUAGE=et_EE:et + LC_ALL=C + MACHTYPE=x86_64-pc-linux-gnu + MAIL=/var/mail/root + OPTERR=1 + OPTIND=1 + OSTYPE=linux-gnu + PATH=/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/i/capture/the/path + PBCURRENTCOMMANDLINEOPERATION=build + PBUILDER_OPERATION=build + PBUILDER_PKGDATADIR=/usr/share/pbuilder + PBUILDER_PKGLIBDIR=/usr/lib/pbuilder + PBUILDER_SYSCONFDIR=/etc + PIPESTATUS=([0]="0") + POSIXLY_CORRECT=y + PPID=1148507 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.LEC7HPZo/pbuilderrc_KTCi --distribution unstable --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/unstable-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.LEC7HPZo/b1 --logfile b1/build.log alertmanager-irc-relay_0.4.2-1.dsc' - SUDO_GID='111' - SUDO_UID='106' - SUDO_USER='jenkins' - TERM='unknown' - TZ='/usr/share/zoneinfo/Etc/GMT+12' - USER='root' - _='/usr/bin/systemd-run' - http_proxy='http://46.16.76.132: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.LEC7HPZo/pbuilderrc_JH9T --distribution unstable --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/unstable-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.LEC7HPZo/b2 --logfile b2/build.log alertmanager-irc-relay_0.4.2-1.dsc' + SUDO_GID=110 + SUDO_UID=105 + SUDO_USER=jenkins + TERM=unknown + TZ=/usr/share/zoneinfo/Etc/GMT-14 + UID=0 + USER=root + _='I: set' + http_proxy=http://213.165.73.152:3128 I: uname -a - Linux ionos11-amd64 6.1.0-21-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.90-1 (2024-05-03) x86_64 GNU/Linux + Linux i-capture-the-hostname 6.7.12+bpo-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.7.12-1~bpo12+1 (2024-05-06) x86_64 GNU/Linux I: ls -l /bin - lrwxrwxrwx 1 root root 7 May 21 07:42 /bin -> usr/bin -I: user script /srv/workspace/pbuilder/1561046/tmp/hooks/D02_print_environment finished + lrwxrwxrwx 1 root root 7 Jun 23 14:06 /bin -> usr/bin +I: user script /srv/workspace/pbuilder/1148507/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -315,7 +347,7 @@ Get: 192 http://deb.debian.org/debian unstable/main amd64 golang-gopkg-telebot.v3-dev all 3.2.1-1 [95.0 kB] Get: 193 http://deb.debian.org/debian unstable/main amd64 golang-protobuf-extensions-dev all 1.0.4-2 [29.7 kB] Get: 194 http://deb.debian.org/debian unstable/main amd64 golang-github-prometheus-alertmanager-dev all 0.27.0+ds-2 [1116 kB] -Fetched 138 MB in 2s (58.4 MB/s) +Fetched 138 MB in 2s (68.7 MB/s) debconf: delaying package configuration, since apt-utils is not installed 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 ... 19718 files and directories currently installed.) @@ -951,8 +983,8 @@ Setting up tzdata (2024a-4) ... Current default time zone: 'Etc/UTC' -Local time is now: Wed May 22 18:32:03 UTC 2024. -Universal Time is now: Wed May 22 18:32:03 UTC 2024. +Local time is now: Wed Jun 25 00:57:16 UTC 2025. +Universal Time is now: Wed Jun 25 00:57:16 UTC 2025. Run 'dpkg-reconfigure tzdata' if you wish to change it. Setting up golang-github-cespare-xxhash-dev (2.1.1-2) ... @@ -1117,7 +1149,11 @@ fakeroot is already the newest version (1.34-1). 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. I: Building the package -I: Running cd /build/reproducible-path/alertmanager-irc-relay-0.4.2/ && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games" HOME="/nonexistent/first-build" dpkg-buildpackage -us -uc -b && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games" HOME="/nonexistent/first-build" dpkg-genchanges -S > ../alertmanager-irc-relay_0.4.2-1_source.changes +I: user script /srv/workspace/pbuilder/1148507/tmp/hooks/A99_set_merged_usr starting +Not re-configuring usrmerge for unstable +I: user script /srv/workspace/pbuilder/1148507/tmp/hooks/A99_set_merged_usr finished +hostname: Name or service not known +I: Running cd /build/reproducible-path/alertmanager-irc-relay-0.4.2/ && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/i/capture/the/path" HOME="/nonexistent/second-build" dpkg-buildpackage -us -uc -b && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/i/capture/the/path" HOME="/nonexistent/second-build" dpkg-genchanges -S > ../alertmanager-irc-relay_0.4.2-1_source.changes dpkg-buildpackage: info: source package alertmanager-irc-relay dpkg-buildpackage: info: source version 0.4.2-1 dpkg-buildpackage: info: source distribution unstable @@ -1135,37 +1171,37 @@ dh_autoreconf -O--buildsystem=golang dh_auto_configure -O--buildsystem=golang dh_auto_build -O--buildsystem=golang - cd obj-x86_64-linux-gnu && go install -trimpath -v -p 20 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging + cd obj-x86_64-linux-gnu && go install -trimpath -v -p 42 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging +log/internal +internal/godebugs +encoding +google.golang.org/protobuf/internal/flags +github.com/fluffle/goirc/logging internal/unsafeheader internal/goos -internal/goarch +unicode/utf16 +cmp +vendor/golang.org/x/crypto/cryptobyte/asn1 internal/goexperiment -internal/godebugs -internal/coverage/rtcov -math/bits +internal/nettrace +vendor/golang.org/x/crypto/internal/alias +runtime/internal/syscall internal/race -container/list -unicode/utf8 -sync/atomic +internal/coverage/rtcov crypto/internal/boring/sig -cmp crypto/internal/alias -internal/itoa -internal/cpu +container/list crypto/subtle +internal/itoa +math/bits +unicode/utf8 +internal/goarch runtime/internal/atomic -runtime/internal/syscall +sync/atomic +internal/cpu unicode -unicode/utf16 -vendor/golang.org/x/crypto/cryptobyte/asn1 -internal/nettrace -vendor/golang.org/x/crypto/internal/alias -encoding -github.com/fluffle/goirc/logging runtime/internal/math internal/chacha8rand -log/internal -google.golang.org/protobuf/internal/flags runtime/internal/sys internal/abi google.golang.org/protobuf/internal/set @@ -1173,9 +1209,9 @@ internal/bytealg math runtime +runtime/metrics internal/reflectlite sync -runtime/metrics internal/testlog internal/bisect internal/singleflight @@ -1187,142 +1223,142 @@ io internal/godebug path -strconv internal/safefilepath -github.com/beorn7/perks/quantile vendor/golang.org/x/net/dns/dnsmessage +strconv crypto/internal/nistec/fiat -golang.org/x/text/internal/tag -bytes -hash syscall -crypto/internal/randutil internal/intern math/rand +golang.org/x/text/internal/tag +github.com/beorn7/perks/quantile +hash +crypto/internal/randutil +bytes strings hash/fnv hash/crc32 crypto -reflect crypto/rc4 net/netip +reflect vendor/golang.org/x/text/transform golang.org/x/text/transform -bufio net/http/internal/ascii -regexp/syntax github.com/prometheus/common/internal/bitbucket.org/ww/goautoneg +bufio +regexp/syntax html -regexp internal/syscall/execenv -time internal/syscall/unix +time +regexp +context +io/fs +internal/poll internal/fmtsort encoding/binary +embed +google.golang.org/protobuf/internal/editiondefaults +os +encoding/base64 crypto/cipher +vendor/golang.org/x/crypto/internal/poly1305 crypto/md5 -crypto/internal/edwards25519/field -encoding/base64 github.com/cespare/xxhash -vendor/golang.org/x/crypto/internal/poly1305 +crypto/internal/edwards25519/field +crypto/internal/nistec +golang.org/x/sys/unix encoding/pem -crypto/internal/boring -crypto/des -vendor/golang.org/x/crypto/chacha20 crypto/internal/edwards25519 -crypto/aes +vendor/golang.org/x/crypto/chacha20 +crypto/des +crypto/internal/boring crypto/hmac -crypto/sha1 crypto/sha512 +crypto/sha1 +crypto/aes crypto/sha256 -context -io/fs -internal/poll -golang.org/x/sys/unix vendor/golang.org/x/crypto/hkdf -embed -google.golang.org/protobuf/internal/editiondefaults -crypto/internal/nistec -os crypto/ecdh -vendor/golang.org/x/sys/cpu -path/filepath google.golang.org/protobuf/internal/detrand -fmt -io/ioutil github.com/prometheus/procfs/internal/util +path/filepath os/signal +io/ioutil +fmt +vendor/golang.org/x/sys/cpu net vendor/golang.org/x/crypto/chacha20poly1305 encoding/hex +log flag -github.com/golang/mock/gomock net/url -log -encoding/json -mime/quotedprintable -vendor/golang.org/x/net/http2/hpack -compress/flate +github.com/prometheus/procfs/internal/fs net/http/internal -mime -github.com/go-logfmt/logfmt -math/big google.golang.org/protobuf/internal/errors google.golang.org/protobuf/internal/version -go/token +vendor/golang.org/x/net/http2/hpack +text/template/parse +encoding/json +github.com/go-logfmt/logfmt +github.com/golang/mock/gomock +mime +mime/quotedprintable runtime/debug -vendor/golang.org/x/text/unicode/norm -github.com/prometheus/procfs/internal/fs +go/token +compress/flate golang.org/x/text/internal/language -vendor/golang.org/x/text/unicode/bidi golang.org/x/text/unicode/norm -text/template/parse +vendor/golang.org/x/text/unicode/norm gopkg.in/yaml.v2 +math/big google.golang.org/protobuf/encoding/protowire -github.com/fluffle/goirc/state -github.com/google/alertmanager-irc-relay/logging google.golang.org/protobuf/reflect/protoreflect +vendor/golang.org/x/text/unicode/bidi +github.com/google/alertmanager-irc-relay/logging +github.com/fluffle/goirc/state compress/gzip vendor/golang.org/x/text/secure/bidirule -github.com/go-kit/log -golang.org/x/text/internal/language/compact -vendor/golang.org/x/net/idna text/template -google.golang.org/protobuf/internal/descfmt -golang.org/x/text/language +golang.org/x/text/internal/language/compact google.golang.org/protobuf/internal/descopts google.golang.org/protobuf/internal/strs google.golang.org/protobuf/internal/encoding/messageset -google.golang.org/protobuf/internal/order google.golang.org/protobuf/internal/genid +google.golang.org/protobuf/internal/descfmt +google.golang.org/protobuf/internal/order google.golang.org/protobuf/runtime/protoiface -github.com/go-kit/log/level +google.golang.org/protobuf/reflect/protoregistry google.golang.org/protobuf/internal/encoding/text +golang.org/x/text/language +vendor/golang.org/x/net/idna +github.com/go-kit/log +google.golang.org/protobuf/proto +github.com/go-kit/log/level +google.golang.org/protobuf/internal/encoding/defval github.com/prometheus/alertmanager/featurecontrol -google.golang.org/protobuf/reflect/protoregistry -crypto/elliptic crypto/internal/boring/bbig +crypto/elliptic crypto/internal/bigmod encoding/asn1 crypto/rand crypto/dsa -crypto/ed25519 -crypto/rsa golang.org/x/text/internal -google.golang.org/protobuf/proto -google.golang.org/protobuf/internal/encoding/defval -crypto/x509/pkix -vendor/golang.org/x/crypto/cryptobyte golang.org/x/text/cases +crypto/ed25519 html/template -crypto/ecdsa +crypto/rsa google.golang.org/protobuf/encoding/protodelim google.golang.org/protobuf/encoding/prototext google.golang.org/protobuf/internal/filedesc +crypto/x509/pkix +vendor/golang.org/x/crypto/cryptobyte +crypto/ecdsa google.golang.org/protobuf/internal/encoding/tag google.golang.org/protobuf/internal/impl -crypto/x509 golang.org/x/net/internal/socks +crypto/x509 vendor/golang.org/x/net/http/httpproxy net/textproto github.com/prometheus/procfs @@ -1346,28 +1382,28 @@ github.com/gorilla/mux github.com/prometheus/common/expfmt github.com/prometheus/client_golang/prometheus -github.com/prometheus/alertmanager/types -github.com/prometheus/client_golang/prometheus/promhttp github.com/prometheus/client_golang/prometheus/promauto +github.com/prometheus/client_golang/prometheus/promhttp +github.com/prometheus/alertmanager/types github.com/prometheus/alertmanager/template github.com/google/alertmanager-irc-relay dh_auto_test -O--buildsystem=golang - cd obj-x86_64-linux-gnu && go test -vet=off -v -p 20 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging + cd obj-x86_64-linux-gnu && go test -vet=off -v -p 42 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging ? github.com/google/alertmanager-irc-relay/logging [no test files] === RUN TestBackoffIncreasesAndReachesMax --- PASS: TestBackoffIncreasesAndReachesMax (0.00s) === RUN TestBackoffReset --- PASS: TestBackoffReset (0.00s) === RUN TestBackoffDelayContext -2024/05/22 06:32:59.232854 backoff.go:111: INFO Backoff for 0s starts -2024/05/22 06:32:59.232943 backoff.go:114: INFO Backoff for 0s ends -2024/05/22 06:32:59.232955 backoff.go:111: INFO Backoff for 2ms starts -2024/05/22 06:32:59.232960 backoff.go:116: INFO Backoff for 2ms canceled by context +2025/06/25 14:57:43.069925 backoff.go:111: INFO Backoff for 0s starts +2025/06/25 14:57:43.069983 backoff.go:114: INFO Backoff for 0s ends +2025/06/25 14:57:43.069989 backoff.go:111: INFO Backoff for 2ms starts +2025/06/25 14:57:43.069993 backoff.go:116: INFO Backoff for 2ms canceled by context --- PASS: TestBackoffDelayContext (0.00s) === RUN TestNoConfig --- PASS: TestNoConfig (0.00s) === RUN TestLoadGoodConfig ---- PASS: TestLoadGoodConfig (0.13s) +--- PASS: TestLoadGoodConfig (0.00s) === RUN TestLoadWithEnvironmentVariables --- PASS: TestLoadWithEnvironmentVariables (0.00s) === RUN TestLoadBadFile @@ -1381,10 +1417,10 @@ === RUN TestGivenTemplateNotOverwritten --- PASS: TestGivenTemplateNotOverwritten (0.00s) === RUN TestTemplateErrorsCreateRawAlertMsg -2024/05/22 06:32:59.366708 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at : nil is not a command): {"status":"resolved","labels":{"alertname":"airDown","instance":"instance1:3456","job":"air","service":"prometheus","severity":"ticket","zone":"global"},"annotations":{"DESCRIPTION":"service /prometheus has irc gateway down on instance1","SUMMARY":"service /prometheus air down on instance1"},"startsAt":"2017-05-15T13:49:37.834Z","endsAt":"2017-05-15T13:50:37.835Z","generatorURL":"https://prometheus.example.com/prometheus/...","fingerprint":"66214a361160fb6f"} -2024/05/22 06:32:59.366728 format.go:61: WARN Sending raw alert -2024/05/22 06:32:59.366759 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at : nil is not a command): {"status":"resolved","labels":{"alertname":"airDown","instance":"instance2:7890","job":"air","service":"prometheus","severity":"ticket","zone":"global"},"annotations":{"DESCRIPTION":"service /prometheus has irc gateway down on instance2","SUMMARY":"service /prometheus air down on instance2"},"startsAt":"2017-05-15T11:47:37.834Z","endsAt":"2017-05-15T11:48:37.834Z","generatorURL":"https://prometheus.example.com/prometheus/...","fingerprint":"25a874c99325d1ce"} -2024/05/22 06:32:59.366770 format.go:61: WARN Sending raw alert +2025/06/25 14:57:43.071840 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at : nil is not a command): {"status":"resolved","labels":{"alertname":"airDown","instance":"instance1:3456","job":"air","service":"prometheus","severity":"ticket","zone":"global"},"annotations":{"DESCRIPTION":"service /prometheus has irc gateway down on instance1","SUMMARY":"service /prometheus air down on instance1"},"startsAt":"2017-05-15T13:49:37.834Z","endsAt":"2017-05-15T13:50:37.835Z","generatorURL":"https://prometheus.example.com/prometheus/...","fingerprint":"66214a361160fb6f"} +2025/06/25 14:57:43.071855 format.go:61: WARN Sending raw alert +2025/06/25 14:57:43.071878 format.go:59: ERROR Could not apply msg template on alert (template: msg:1:18: executing "msg" at : nil is not a command): {"status":"resolved","labels":{"alertname":"airDown","instance":"instance2:7890","job":"air","service":"prometheus","severity":"ticket","zone":"global"},"annotations":{"DESCRIPTION":"service /prometheus has irc gateway down on instance2","SUMMARY":"service /prometheus air down on instance2"},"startsAt":"2017-05-15T11:47:37.834Z","endsAt":"2017-05-15T11:48:37.834Z","generatorURL":"https://prometheus.example.com/prometheus/...","fingerprint":"25a874c99325d1ce"} +2025/06/25 14:57:43.071885 format.go:61: WARN Sending raw alert --- PASS: TestTemplateErrorsCreateRawAlertMsg (0.00s) === RUN TestAlertsDispatchedOnce --- PASS: TestAlertsDispatchedOnce (0.00s) @@ -1393,482 +1429,481 @@ === RUN TestUrlFunctions --- PASS: TestUrlFunctions (0.00s) === RUN TestAlertsDispatched -2024/05/22 06:32:59.367609 http.go:132: INFO Starting HTTP server +2025/06/25 14:57:43.072434 http.go:132: INFO Starting HTTP server --- PASS: TestAlertsDispatched (0.00s) === RUN TestRootReturnsError -2024/05/22 06:32:59.368015 http.go:132: INFO Starting HTTP server +2025/06/25 14:57:43.072789 http.go:132: INFO Starting HTTP server --- PASS: TestRootReturnsError (0.00s) === RUN TestInvalidDataReturnsError -2024/05/22 06:32:59.368223 http.go:132: INFO Starting HTTP server -2024/05/22 06:32:59.368260 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/06/25 14:57:43.072987 http.go:132: INFO Starting HTTP server +2025/06/25 14:57:43.073012 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 -2024/05/22 06:32:59.368567 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41207 -2024/05/22 06:32:59.368635 irc.go:300: INFO Connecting to IRC 127.0.0.1:41207 -2024/05/22 06:32:59.368654 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.368671 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41207. -2024/05/22 06:32:59.368958 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:49916 -2024/05/22 06:32:59.369169 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/05/22 06:32:59.369305 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret -2024/05/22 06:32:59.369327 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping -2024/05/22 06:32:59.369337 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.369349 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.369355 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.369501 irc.go:144: INFO Session established -2024/05/22 06:32:59.369559 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.369576 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.369590 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.369664 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.369675 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.369685 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.369716 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/05/22 06:32:59.369733 irc.go:294: INFO IRC routine asked to terminate -2024/05/22 06:32:59.369768 irc.go:269: INFO IRC client connected, quitting -2024/05/22 06:32:59.369823 irc.go:272: INFO Wait for IRC disconnect to complete -2024/05/22 06:32:59.369886 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.369914 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.369976 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.370060 irc.go:150: INFO Disconnected from IRC -2024/05/22 06:32:59.370098 irc.go:280: INFO IRC shutdown complete -2024/05/22 06:32:59.370122 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.073272 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:35305 +2025/06/25 14:57:43.073330 irc.go:300: INFO Connecting to IRC 127.0.0.1:35305 +2025/06/25 14:57:43.073346 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.073355 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:35305. +2025/06/25 14:57:43.073563 irc.go:308: INFO Connected to IRC server, waiting to establish session +2025/06/25 14:57:43.073579 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:54704 +2025/06/25 14:57:43.073623 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret +2025/06/25 14:57:43.073637 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping +2025/06/25 14:57:43.073646 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.073653 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.073657 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.073795 irc.go:144: INFO Session established +2025/06/25 14:57:43.073836 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.073844 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.073854 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.073929 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.073946 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.073951 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.073980 irc.go:294: INFO IRC routine asked to terminate +2025/06/25 14:57:43.073991 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2025/06/25 14:57:43.074012 irc.go:269: INFO IRC client connected, quitting +2025/06/25 14:57:43.074027 irc.go:272: INFO Wait for IRC disconnect to complete +2025/06/25 14:57:43.074094 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.074115 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.074156 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.074244 irc.go:150: INFO Disconnected from IRC +2025/06/25 14:57:43.074270 irc.go:280: INFO IRC shutdown complete +2025/06/25 14:57:43.074300 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestServerPassword (0.00s) === RUN TestSendAlertOnPreJoinedChannel -2024/05/22 06:32:59.370211 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37641 -2024/05/22 06:32:59.370256 irc.go:300: INFO Connecting to IRC 127.0.0.1:37641 -2024/05/22 06:32:59.370273 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.370282 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37641. -2024/05/22 06:32:59.370429 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34350 -2024/05/22 06:32:59.370522 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/05/22 06:32:59.370596 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.370620 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.370633 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.370794 irc.go:144: INFO Session established -2024/05/22 06:32:59.370879 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.370902 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.370924 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.370992 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.371007 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.371015 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.371107 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.371124 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.371175 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/05/22 06:32:59.371211 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message -2024/05/22 06:32:59.371249 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/05/22 06:32:59.371262 irc.go:294: INFO IRC routine asked to terminate -2024/05/22 06:32:59.371274 irc.go:269: INFO IRC client connected, quitting -2024/05/22 06:32:59.371292 irc.go:272: INFO Wait for IRC disconnect to complete -2024/05/22 06:32:59.371366 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.371382 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.371430 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.371509 irc.go:150: INFO Disconnected from IRC -2024/05/22 06:32:59.371531 irc.go:280: INFO IRC shutdown complete -2024/05/22 06:32:59.371560 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.074386 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38661 +2025/06/25 14:57:43.074417 irc.go:300: INFO Connecting to IRC 127.0.0.1:38661 +2025/06/25 14:57:43.074428 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.074436 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38661. +2025/06/25 14:57:43.074549 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:35028 +2025/06/25 14:57:43.074563 irc.go:308: INFO Connected to IRC server, waiting to establish session +2025/06/25 14:57:43.074680 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.074696 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.074701 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.074772 irc.go:144: INFO Session established +2025/06/25 14:57:43.074805 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.074821 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.074831 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.074892 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.074905 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.074909 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.074967 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.074990 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.075004 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2025/06/25 14:57:43.075038 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message +2025/06/25 14:57:43.075057 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2025/06/25 14:57:43.075066 irc.go:294: INFO IRC routine asked to terminate +2025/06/25 14:57:43.075072 irc.go:269: INFO IRC client connected, quitting +2025/06/25 14:57:43.075077 irc.go:272: INFO Wait for IRC disconnect to complete +2025/06/25 14:57:43.075118 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.075134 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.075166 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.075224 irc.go:150: INFO Disconnected from IRC +2025/06/25 14:57:43.075247 irc.go:280: INFO IRC shutdown complete +2025/06/25 14:57:43.075279 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertOnPreJoinedChannel (0.00s) === RUN TestUsePrivmsgToSendAlertOnPreJoinedChannel -2024/05/22 06:32:59.371725 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40525 -2024/05/22 06:32:59.371771 irc.go:300: INFO Connecting to IRC 127.0.0.1:40525 -2024/05/22 06:32:59.371789 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.371805 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40525. -2024/05/22 06:32:59.372024 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:36732 -2024/05/22 06:32:59.372065 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.372080 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.372091 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.372028 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/05/22 06:32:59.372229 irc.go:144: INFO Session established -2024/05/22 06:32:59.372284 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.372301 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.372323 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.372374 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.372390 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.372414 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.372505 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.372521 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.372571 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/05/22 06:32:59.372584 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message -2024/05/22 06:32:59.372621 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/05/22 06:32:59.372627 irc.go:294: INFO IRC routine asked to terminate -2024/05/22 06:32:59.372639 irc.go:269: INFO IRC client connected, quitting -2024/05/22 06:32:59.372659 irc.go:272: INFO Wait for IRC disconnect to complete -2024/05/22 06:32:59.372855 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.372878 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.372934 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.373007 irc.go:150: INFO Disconnected from IRC -2024/05/22 06:32:59.373034 irc.go:280: INFO IRC shutdown complete -2024/05/22 06:32:59.373060 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.075390 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40019 +2025/06/25 14:57:43.075421 irc.go:300: INFO Connecting to IRC 127.0.0.1:40019 +2025/06/25 14:57:43.075433 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.075442 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40019. +2025/06/25 14:57:43.075583 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:33278 +2025/06/25 14:57:43.075601 irc.go:308: INFO Connected to IRC server, waiting to establish session +2025/06/25 14:57:43.076351 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.076365 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.076369 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.076439 irc.go:144: INFO Session established +2025/06/25 14:57:43.076470 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.076485 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.076497 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.076538 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.076550 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.076554 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.076610 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.076622 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.076647 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2025/06/25 14:57:43.076669 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message +2025/06/25 14:57:43.076694 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2025/06/25 14:57:43.076705 irc.go:294: INFO IRC routine asked to terminate +2025/06/25 14:57:43.076715 irc.go:269: INFO IRC client connected, quitting +2025/06/25 14:57:43.076723 irc.go:272: INFO Wait for IRC disconnect to complete +2025/06/25 14:57:43.076767 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.076780 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.076816 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.076863 irc.go:150: INFO Disconnected from IRC +2025/06/25 14:57:43.076882 irc.go:280: INFO IRC shutdown complete +2025/06/25 14:57:43.076901 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestUsePrivmsgToSendAlertOnPreJoinedChannel (0.00s) === RUN TestSendAlertAndJoinChannel -2024/05/22 06:32:59.373163 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37943 -2024/05/22 06:32:59.373208 irc.go:300: INFO Connecting to IRC 127.0.0.1:37943 -2024/05/22 06:32:59.373226 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.373244 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37943. -2024/05/22 06:32:59.373418 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/05/22 06:32:59.373427 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:54160 -2024/05/22 06:32:59.373464 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.373479 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.373498 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.373620 irc.go:144: INFO Session established -2024/05/22 06:32:59.373653 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.373666 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.373687 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.373762 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.373783 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.373821 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.373874 reconciler.go:245: INFO Request to JOIN new channel #foobar -2024/05/22 06:32:59.373903 reconciler.go:103: INFO Channel #foobar monitor: waiting to join -2024/05/22 06:32:59.373923 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.373930 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.373945 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.373936 reconciler.go:112: INFO Channel #foobar monitor: join request sent -2024/05/22 06:32:59.373976 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/05/22 06:32:59.374014 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar -2024/05/22 06:32:59.374035 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.374043 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar -2024/05/22 06:32:59.374127 reconciler.go:201: INFO Received JOIN confirmation for channel #foobar -2024/05/22 06:32:59.374144 reconciler.go:77: INFO Setting JOIN state on channel #foobar -2024/05/22 06:32:59.374177 reconciler.go:116: INFO Channel #foobar monitor: join succeeded -2024/05/22 06:32:59.374236 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message -2024/05/22 06:32:59.374273 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/05/22 06:32:59.374285 reconciler.go:129: INFO Channel #foobar monitor: context canceled while monitoring -2024/05/22 06:32:59.374284 irc.go:294: INFO IRC routine asked to terminate -2024/05/22 06:32:59.374298 irc.go:269: INFO IRC client connected, quitting -2024/05/22 06:32:59.374324 irc.go:272: INFO Wait for IRC disconnect to complete -2024/05/22 06:32:59.374395 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.374416 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.374474 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.374556 irc.go:150: INFO Disconnected from IRC -2024/05/22 06:32:59.374575 irc.go:280: INFO IRC shutdown complete -2024/05/22 06:32:59.374595 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.076975 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42193 +2025/06/25 14:57:43.077000 irc.go:300: INFO Connecting to IRC 127.0.0.1:42193 +2025/06/25 14:57:43.077011 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.077022 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42193. +2025/06/25 14:57:43.077142 irc.go:308: INFO Connected to IRC server, waiting to establish session +2025/06/25 14:57:43.077147 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:54230 +2025/06/25 14:57:43.077176 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.077188 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.077196 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.077260 irc.go:144: INFO Session established +2025/06/25 14:57:43.077292 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.077306 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.077316 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.077355 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.077365 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.077370 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.077394 reconciler.go:245: INFO Request to JOIN new channel #foobar +2025/06/25 14:57:43.077412 reconciler.go:103: INFO Channel #foobar monitor: waiting to join +2025/06/25 14:57:43.077422 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.077429 reconciler.go:112: INFO Channel #foobar monitor: join request sent +2025/06/25 14:57:43.077451 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.077464 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.077468 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar +2025/06/25 14:57:43.077475 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.077488 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar +2025/06/25 14:57:43.077476 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2025/06/25 14:57:43.077541 reconciler.go:201: INFO Received JOIN confirmation for channel #foobar +2025/06/25 14:57:43.077551 reconciler.go:77: INFO Setting JOIN state on channel #foobar +2025/06/25 14:57:43.077562 reconciler.go:116: INFO Channel #foobar monitor: join succeeded +2025/06/25 14:57:43.077600 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message +2025/06/25 14:57:43.077616 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2025/06/25 14:57:43.077625 irc.go:294: INFO IRC routine asked to terminate +2025/06/25 14:57:43.077630 irc.go:269: INFO IRC client connected, quitting +2025/06/25 14:57:43.077635 irc.go:272: INFO Wait for IRC disconnect to complete +2025/06/25 14:57:43.077640 reconciler.go:129: INFO Channel #foobar monitor: context canceled while monitoring +2025/06/25 14:57:43.077665 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.077680 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.077710 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.077761 irc.go:150: INFO Disconnected from IRC +2025/06/25 14:57:43.077776 irc.go:280: INFO IRC shutdown complete +2025/06/25 14:57:43.077796 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertAndJoinChannel (0.00s) === RUN TestSendAlertDisconnected -2024/05/22 06:32:59.374686 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:35775 -2024/05/22 06:32:59.374729 irc.go:300: INFO Connecting to IRC 127.0.0.1:35775 -2024/05/22 06:32:59.374744 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.374754 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:35775. -2024/05/22 06:32:59.374957 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:53056 -2024/05/22 06:32:59.374957 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/05/22 06:32:59.375007 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.375023 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.375036 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.375056 irc_test.go:292: INFO =Server= Wait before completing session -2024/05/22 06:32:59.375066 irc_test.go:294: INFO =Server= Completing session -2024/05/22 06:32:59.375172 irc.go:144: INFO Session established -2024/05/22 06:32:59.375238 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.375265 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.375284 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.375391 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.375412 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.375422 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.375521 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.375539 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.375585 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/05/22 06:32:59.375621 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message -2024/05/22 06:32:59.375657 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/05/22 06:32:59.375666 irc.go:294: INFO IRC routine asked to terminate -2024/05/22 06:32:59.375677 irc.go:269: INFO IRC client connected, quitting -2024/05/22 06:32:59.375693 irc.go:272: INFO Wait for IRC disconnect to complete -2024/05/22 06:32:59.375760 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.375777 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.375824 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.375912 irc.go:150: INFO Disconnected from IRC -2024/05/22 06:32:59.375951 irc.go:280: INFO IRC shutdown complete -2024/05/22 06:32:59.376005 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.077868 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38447 +2025/06/25 14:57:43.077896 irc.go:300: INFO Connecting to IRC 127.0.0.1:38447 +2025/06/25 14:57:43.077907 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.077912 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38447. +2025/06/25 14:57:43.078020 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:38486 +2025/06/25 14:57:43.078028 irc.go:308: INFO Connected to IRC server, waiting to establish session +2025/06/25 14:57:43.078063 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.078075 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.078082 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.078088 irc_test.go:292: INFO =Server= Wait before completing session +2025/06/25 14:57:43.078092 irc_test.go:294: INFO =Server= Completing session +2025/06/25 14:57:43.078155 irc.go:144: INFO Session established +2025/06/25 14:57:43.078183 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.078196 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.078202 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.078246 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.078260 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.078264 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.078331 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.078341 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.078360 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2025/06/25 14:57:43.078383 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message +2025/06/25 14:57:43.078404 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2025/06/25 14:57:43.078409 irc.go:294: INFO IRC routine asked to terminate +2025/06/25 14:57:43.078415 irc.go:269: INFO IRC client connected, quitting +2025/06/25 14:57:43.078423 irc.go:272: INFO Wait for IRC disconnect to complete +2025/06/25 14:57:43.078453 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.078465 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.078492 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.078550 irc.go:150: INFO Disconnected from IRC +2025/06/25 14:57:43.078567 irc.go:280: INFO IRC shutdown complete +2025/06/25 14:57:43.078590 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertDisconnected (0.00s) === RUN TestReconnect -2024/05/22 06:32:59.376190 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37573 -2024/05/22 06:32:59.376240 irc.go:300: INFO Connecting to IRC 127.0.0.1:37573 -2024/05/22 06:32:59.376260 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.376272 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37573. -2024/05/22 06:32:59.376524 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:49960 -2024/05/22 06:32:59.376581 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/05/22 06:32:59.376642 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.376661 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.376674 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.376763 irc.go:144: INFO Session established -2024/05/22 06:32:59.376811 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.376829 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.376851 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.376945 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.376961 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.376968 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.377057 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.377076 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:49960: read tcp 127.0.0.1:37573->127.0.0.1:49960: use of closed network connection -2024/05/22 06:32:59.377150 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.377165 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.377192 irc.go:150: INFO Disconnected from IRC -2024/05/22 06:32:59.377201 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/05/22 06:32:59.377226 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/05/22 06:32:59.377237 irc.go:300: INFO Connecting to IRC 127.0.0.1:37573 -2024/05/22 06:32:59.377252 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.377263 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37573. -2024/05/22 06:32:59.377398 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:49970 -2024/05/22 06:32:59.377421 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/05/22 06:32:59.377481 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.377501 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.377515 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.377639 irc.go:144: INFO Session established -2024/05/22 06:32:59.377695 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.377716 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.377727 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.377824 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.377842 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.377851 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.377898 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/05/22 06:32:59.377901 irc.go:294: INFO IRC routine asked to terminate -2024/05/22 06:32:59.377920 irc.go:269: INFO IRC client connected, quitting -2024/05/22 06:32:59.377931 irc.go:272: INFO Wait for IRC disconnect to complete -2024/05/22 06:32:59.377947 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.377959 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.377994 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.378019 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.378081 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.378163 irc.go:150: INFO Disconnected from IRC -2024/05/22 06:32:59.378190 irc.go:280: INFO IRC shutdown complete -2024/05/22 06:32:59.378216 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.078659 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38755 +2025/06/25 14:57:43.078687 irc.go:300: INFO Connecting to IRC 127.0.0.1:38755 +2025/06/25 14:57:43.078698 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.078704 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38755. +2025/06/25 14:57:43.078811 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:54586 +2025/06/25 14:57:43.078818 irc.go:308: INFO Connected to IRC server, waiting to establish session +2025/06/25 14:57:43.078852 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.078866 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.078873 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.078923 irc.go:144: INFO Session established +2025/06/25 14:57:43.078948 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.078960 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.078970 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.079016 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.079028 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.079042 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.079080 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.079106 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:54586: read tcp 127.0.0.1:38755->127.0.0.1:54586: use of closed network connection +2025/06/25 14:57:43.079147 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.079160 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.079172 irc.go:150: INFO Disconnected from IRC +2025/06/25 14:57:43.079179 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2025/06/25 14:57:43.079191 irc.go:300: INFO Connecting to IRC 127.0.0.1:38755 +2025/06/25 14:57:43.079201 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.079208 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38755. +2025/06/25 14:57:43.079299 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:54588 +2025/06/25 14:57:43.079324 irc.go:308: INFO Connected to IRC server, waiting to establish session +2025/06/25 14:57:43.079384 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.079396 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.079403 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.079462 irc.go:144: INFO Session established +2025/06/25 14:57:43.079495 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.079505 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.079515 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.079560 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.079570 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.079574 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.079606 irc.go:294: INFO IRC routine asked to terminate +2025/06/25 14:57:43.079614 irc.go:269: INFO IRC client connected, quitting +2025/06/25 14:57:43.079619 irc.go:272: INFO Wait for IRC disconnect to complete +2025/06/25 14:57:43.079616 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2025/06/25 14:57:43.079626 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.079636 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.079643 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.079656 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.079689 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.079740 irc.go:150: INFO Disconnected from IRC +2025/06/25 14:57:43.079755 irc.go:280: INFO IRC shutdown complete +2025/06/25 14:57:43.079776 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestReconnect (0.00s) === RUN TestConnectErrorRetry -2024/05/22 06:32:59.378312 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46233 -2024/05/22 06:32:59.378354 irc.go:300: INFO Connecting to IRC 127.0.0.1:46233 -2024/05/22 06:32:59.378372 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.378375 fake_delayer.go:45: INFO Waiting StopDelay signal -2024/05/22 06:32:59.378385 fake_delayer.go:47: INFO Received StopDelay signal -2024/05/22 06:32:59.378392 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46233. -2024/05/22 06:32:59.378525 connection.go:399: INFO irc.Connect(): Performing SSL handshake. -2024/05/22 06:32:59.378549 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:36926 -2024/05/22 06:32:59.378567 irc_server_for_test.go:157: INFO =Server= Closing connection early -2024/05/22 06:32:59.378832 irc.go:305: ERROR Could not connect to IRC: EOF -2024/05/22 06:32:59.378843 irc.go:300: INFO Connecting to IRC 127.0.0.1:46233 -2024/05/22 06:32:59.378853 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.378858 fake_delayer.go:45: INFO Waiting StopDelay signal -2024/05/22 06:32:59.378872 fake_delayer.go:47: INFO Received StopDelay signal -2024/05/22 06:32:59.378888 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46233. -2024/05/22 06:32:59.378990 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:36928 -2024/05/22 06:32:59.379002 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/05/22 06:32:59.379054 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.379073 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.379087 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.379183 irc.go:144: INFO Session established -2024/05/22 06:32:59.379231 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.379248 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.379267 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.379330 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.379350 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.379360 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.379411 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/05/22 06:32:59.379440 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.379411 irc.go:294: INFO IRC routine asked to terminate -2024/05/22 06:32:59.379457 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.379464 irc.go:269: INFO IRC client connected, quitting -2024/05/22 06:32:59.379475 irc.go:272: INFO Wait for IRC disconnect to complete -2024/05/22 06:32:59.379538 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.379565 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.379621 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.379705 irc.go:150: INFO Disconnected from IRC -2024/05/22 06:32:59.379741 irc.go:280: INFO IRC shutdown complete -2024/05/22 06:32:59.379793 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.079853 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36203 +2025/06/25 14:57:43.079880 irc.go:300: INFO Connecting to IRC 127.0.0.1:36203 +2025/06/25 14:57:43.079891 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.079894 fake_delayer.go:45: INFO Waiting StopDelay signal +2025/06/25 14:57:43.079899 fake_delayer.go:47: INFO Received StopDelay signal +2025/06/25 14:57:43.079905 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36203. +2025/06/25 14:57:43.080006 connection.go:399: INFO irc.Connect(): Performing SSL handshake. +2025/06/25 14:57:43.080012 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34228 +2025/06/25 14:57:43.080019 irc_server_for_test.go:157: INFO =Server= Closing connection early +2025/06/25 14:57:43.080214 irc.go:305: ERROR Could not connect to IRC: EOF +2025/06/25 14:57:43.080229 irc.go:300: INFO Connecting to IRC 127.0.0.1:36203 +2025/06/25 14:57:43.080233 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.080236 fake_delayer.go:45: INFO Waiting StopDelay signal +2025/06/25 14:57:43.080246 fake_delayer.go:47: INFO Received StopDelay signal +2025/06/25 14:57:43.080252 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36203. +2025/06/25 14:57:43.080364 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34240 +2025/06/25 14:57:43.080365 irc.go:308: INFO Connected to IRC server, waiting to establish session +2025/06/25 14:57:43.080398 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.080412 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.080419 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.080480 irc.go:144: INFO Session established +2025/06/25 14:57:43.080507 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.080517 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.080523 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.080560 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.080570 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.080574 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.080595 irc.go:294: INFO IRC routine asked to terminate +2025/06/25 14:57:43.080603 irc.go:269: INFO IRC client connected, quitting +2025/06/25 14:57:43.080608 irc.go:272: INFO Wait for IRC disconnect to complete +2025/06/25 14:57:43.080594 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2025/06/25 14:57:43.080624 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.080634 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.080652 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.080667 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.080707 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.080772 irc.go:150: INFO Disconnected from IRC +2025/06/25 14:57:43.080794 irc.go:280: INFO IRC shutdown complete +2025/06/25 14:57:43.080820 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestConnectErrorRetry (0.00s) === RUN TestIdentify -2024/05/22 06:32:59.379978 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42529 -2024/05/22 06:32:59.380025 irc.go:300: INFO Connecting to IRC 127.0.0.1:42529 -2024/05/22 06:32:59.380042 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.380053 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42529. -2024/05/22 06:32:59.380235 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:43626 -2024/05/22 06:32:59.380275 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.380245 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/05/22 06:32:59.380328 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.380368 irc.go:165: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. -2024/05/22 06:32:59.380394 irc.go:189: INFO Handling NickServ request to IDENTIFY -2024/05/22 06:32:59.380430 irc.go:144: INFO Session established -2024/05/22 06:32:59.380452 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request -2024/05/22 06:32:59.380473 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword -2024/05/22 06:32:59.380480 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.380491 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.380493 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.380515 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.380611 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.380633 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.380643 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.380701 irc.go:294: INFO IRC routine asked to terminate -2024/05/22 06:32:59.380705 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/05/22 06:32:59.380718 irc.go:269: INFO IRC client connected, quitting -2024/05/22 06:32:59.380727 irc.go:272: INFO Wait for IRC disconnect to complete -2024/05/22 06:32:59.380772 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.380794 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.380844 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.381904 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.381931 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.381957 irc.go:150: INFO Disconnected from IRC -2024/05/22 06:32:59.381992 irc.go:280: INFO IRC shutdown complete -2024/05/22 06:32:59.382055 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.080903 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38415 +2025/06/25 14:57:43.080930 irc.go:300: INFO Connecting to IRC 127.0.0.1:38415 +2025/06/25 14:57:43.080940 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.080946 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38415. +2025/06/25 14:57:43.081068 irc.go:308: INFO Connected to IRC server, waiting to establish session +2025/06/25 14:57:43.081070 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:47260 +2025/06/25 14:57:43.081097 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.081130 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.081154 irc.go:165: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. +2025/06/25 14:57:43.081168 irc.go:189: INFO Handling NickServ request to IDENTIFY +2025/06/25 14:57:43.081192 irc.go:144: INFO Session established +2025/06/25 14:57:43.081212 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request +2025/06/25 14:57:43.081222 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword +2025/06/25 14:57:43.081230 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.081231 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.081241 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.081252 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.081301 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.081315 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.081322 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.081351 irc.go:294: INFO IRC routine asked to terminate +2025/06/25 14:57:43.081359 irc.go:269: INFO IRC client connected, quitting +2025/06/25 14:57:43.081365 irc.go:272: INFO Wait for IRC disconnect to complete +2025/06/25 14:57:43.081352 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2025/06/25 14:57:43.081375 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.081390 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.081388 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.081404 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.081438 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.081498 irc.go:150: INFO Disconnected from IRC +2025/06/25 14:57:43.081516 irc.go:280: INFO IRC shutdown complete +2025/06/25 14:57:43.081532 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestIdentify (0.00s) === RUN TestGhost -2024/05/22 06:32:59.382212 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:35217 -2024/05/22 06:32:59.382267 irc.go:300: INFO Connecting to IRC 127.0.0.1:35217 -2024/05/22 06:32:59.382290 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.382303 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:35217. -2024/05/22 06:32:59.382515 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:52264 -2024/05/22 06:32:59.382544 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/05/22 06:32:59.382639 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.382681 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.382864 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' -2024/05/22 06:32:59.382935 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ -2024/05/22 06:32:59.383060 irc.go:144: INFO Session established -2024/05/22 06:32:59.383096 irc.go:204: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' -2024/05/22 06:32:59.383131 irc.go:210: INFO Changing nick to 'foo' -2024/05/22 06:32:59.383156 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request -2024/05/22 06:32:59.383196 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.383216 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.383236 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.383243 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword -2024/05/22 06:32:59.383270 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.383285 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.383313 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.383328 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.383337 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.383388 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/05/22 06:32:59.383395 irc.go:294: INFO IRC routine asked to terminate -2024/05/22 06:32:59.383411 irc.go:269: INFO IRC client connected, quitting -2024/05/22 06:32:59.383421 irc.go:272: INFO Wait for IRC disconnect to complete -2024/05/22 06:32:59.383484 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.383503 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.383575 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.383673 irc.go:150: INFO Disconnected from IRC -2024/05/22 06:32:59.383698 irc.go:280: INFO IRC shutdown complete -2024/05/22 06:32:59.383724 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.081609 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40345 +2025/06/25 14:57:43.081639 irc.go:300: INFO Connecting to IRC 127.0.0.1:40345 +2025/06/25 14:57:43.081650 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.081658 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40345. +2025/06/25 14:57:43.081759 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:49930 +2025/06/25 14:57:43.081767 irc.go:308: INFO Connected to IRC server, waiting to establish session +2025/06/25 14:57:43.081795 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.081809 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.081867 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' +2025/06/25 14:57:43.081896 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ +2025/06/25 14:57:43.081951 irc.go:144: INFO Session established +2025/06/25 14:57:43.081970 irc.go:204: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' +2025/06/25 14:57:43.081981 irc.go:210: INFO Changing nick to 'foo' +2025/06/25 14:57:43.081988 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request +2025/06/25 14:57:43.081998 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.082007 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.082013 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.082017 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword +2025/06/25 14:57:43.082024 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.082037 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.082046 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.082050 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.082054 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.082077 irc.go:294: INFO IRC routine asked to terminate +2025/06/25 14:57:43.082087 irc.go:269: INFO IRC client connected, quitting +2025/06/25 14:57:43.082093 irc.go:272: INFO Wait for IRC disconnect to complete +2025/06/25 14:57:43.082077 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2025/06/25 14:57:43.082125 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.082137 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.082171 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.082222 irc.go:150: INFO Disconnected from IRC +2025/06/25 14:57:43.082241 irc.go:280: INFO IRC shutdown complete +2025/06/25 14:57:43.082256 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestGhost (0.00s) === RUN TestStopRunningWhenHalfConnected -2024/05/22 06:32:59.383823 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:45467 -2024/05/22 06:32:59.383863 irc.go:300: INFO Connecting to IRC 127.0.0.1:45467 -2024/05/22 06:32:59.383881 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.383895 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:45467. -2024/05/22 06:32:59.384040 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:37788 -2024/05/22 06:32:59.384085 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.384104 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.384047 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/05/22 06:32:59.384120 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.384139 irc_test.go:589: INFO =Server= NOT completing session -2024/05/22 06:32:59.384165 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.384189 irc.go:321: INFO IRC routine asked to terminate -2024/05/22 06:32:59.384201 irc.go:280: INFO IRC shutdown complete -2024/05/22 06:32:59.384241 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:37788->127.0.0.1:45467: use of closed network connection -2024/05/22 06:32:59.384254 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:37788 disconnected -2024/05/22 06:32:59.384268 irc.go:150: INFO Disconnected from IRC -2024/05/22 06:32:59.384334 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.082317 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41181 +2025/06/25 14:57:43.082343 irc.go:300: INFO Connecting to IRC 127.0.0.1:41181 +2025/06/25 14:57:43.082353 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.082360 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41181. +2025/06/25 14:57:43.082457 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:48708 +2025/06/25 14:57:43.082474 irc.go:308: INFO Connected to IRC server, waiting to establish session +2025/06/25 14:57:43.082512 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.082526 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.082533 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.082539 irc_test.go:589: INFO =Server= NOT completing session +2025/06/25 14:57:43.082555 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.082561 irc.go:321: INFO IRC routine asked to terminate +2025/06/25 14:57:43.082570 irc.go:280: INFO IRC shutdown complete +2025/06/25 14:57:43.082596 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:48708->127.0.0.1:41181: use of closed network connection +2025/06/25 14:57:43.082594 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:48708 disconnected +2025/06/25 14:57:43.082635 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestStopRunningWhenHalfConnected (0.00s) === RUN TestPreJoinChannels -2024/05/22 06:32:59.384528 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41491 -2024/05/22 06:32:59.384576 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41491. -2024/05/22 06:32:59.384806 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:53780 -2024/05/22 06:32:59.384887 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.384910 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.384925 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.385052 reconciler.go:103: INFO Channel #baz monitor: waiting to join -2024/05/22 06:32:59.385077 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.385094 reconciler.go:112: INFO Channel #baz monitor: join request sent -2024/05/22 06:32:59.385144 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz -2024/05/22 06:32:59.385142 reconciler.go:103: INFO Channel #bar monitor: waiting to join -2024/05/22 06:32:59.385132 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.385170 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.385188 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.385217 reconciler.go:112: INFO Channel #bar monitor: join request sent -2024/05/22 06:32:59.385163 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.385273 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz -2024/05/22 06:32:59.385217 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.385327 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar -2024/05/22 06:32:59.385342 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.385351 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar -2024/05/22 06:32:59.385367 reconciler.go:201: INFO Received JOIN confirmation for channel #baz -2024/05/22 06:32:59.385380 reconciler.go:77: INFO Setting JOIN state on channel #baz -2024/05/22 06:32:59.385393 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.385402 reconciler.go:116: INFO Channel #baz monitor: join succeeded -2024/05/22 06:32:59.385409 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.385419 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.385452 reconciler.go:201: INFO Received JOIN confirmation for channel #bar -2024/05/22 06:32:59.385472 reconciler.go:77: INFO Setting JOIN state on channel #bar -2024/05/22 06:32:59.385491 reconciler.go:116: INFO Channel #bar monitor: join succeeded -2024/05/22 06:32:59.385519 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.385541 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.385552 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.385569 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.385595 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/05/22 06:32:59.385594 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.385706 reconciler.go:129: INFO Channel #baz monitor: context canceled while monitoring -2024/05/22 06:32:59.385727 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/05/22 06:32:59.385740 reconciler.go:129: INFO Channel #bar monitor: context canceled while monitoring -2024/05/22 06:32:59.385782 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.082660 irc.go:150: INFO Disconnected from IRC +2025/06/25 14:57:43.082697 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40221 +2025/06/25 14:57:43.082723 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40221. +2025/06/25 14:57:43.082804 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:38722 +2025/06/25 14:57:43.082851 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.082862 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.082868 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.082935 reconciler.go:103: INFO Channel #baz monitor: waiting to join +2025/06/25 14:57:43.082942 reconciler.go:103: INFO Channel #bar monitor: waiting to join +2025/06/25 14:57:43.082954 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.082960 reconciler.go:112: INFO Channel #bar monitor: join request sent +2025/06/25 14:57:43.082948 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.082999 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar +2025/06/25 14:57:43.083008 reconciler.go:112: INFO Channel #baz monitor: join request sent +2025/06/25 14:57:43.083012 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.082935 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.083023 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.083031 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.083035 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar +2025/06/25 14:57:43.083060 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz +2025/06/25 14:57:43.083068 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.083072 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz +2025/06/25 14:57:43.083083 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.083091 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.083095 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.083083 reconciler.go:201: INFO Received JOIN confirmation for channel #bar +2025/06/25 14:57:43.083109 reconciler.go:77: INFO Setting JOIN state on channel #bar +2025/06/25 14:57:43.083128 reconciler.go:201: INFO Received JOIN confirmation for channel #baz +2025/06/25 14:57:43.083133 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.083134 reconciler.go:116: INFO Channel #bar monitor: join succeeded +2025/06/25 14:57:43.083136 reconciler.go:77: INFO Setting JOIN state on channel #baz +2025/06/25 14:57:43.083142 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.083157 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.083167 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.083157 reconciler.go:116: INFO Channel #baz monitor: join succeeded +2025/06/25 14:57:43.083172 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.083174 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2025/06/25 14:57:43.083229 reconciler.go:129: INFO Channel #bar monitor: context canceled while monitoring +2025/06/25 14:57:43.083236 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2025/06/25 14:57:43.083240 reconciler.go:129: INFO Channel #baz monitor: context canceled while monitoring +2025/06/25 14:57:43.083261 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestPreJoinChannels (0.00s) === RUN TestKeepJoining -2024/05/22 06:32:59.385949 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40819 -2024/05/22 06:32:59.385991 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40819. -2024/05/22 06:32:59.386144 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34194 -2024/05/22 06:32:59.386245 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.386272 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.386289 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.386416 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.386457 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.386480 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.386556 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.386581 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.386589 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.386618 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2024/05/22 06:32:59.386632 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.386639 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.386658 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.386739 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.386759 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.386769 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.386805 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2024/05/22 06:32:59.386820 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.386828 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.386853 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.386939 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.386963 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.386972 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.387053 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.387079 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.387086 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.387100 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.387122 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/05/22 06:32:59.387142 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.387259 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/05/22 06:32:59.387294 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.083325 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42665 +2025/06/25 14:57:43.083351 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42665. +2025/06/25 14:57:43.083446 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:43666 +2025/06/25 14:57:43.083488 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.083500 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.083506 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.083567 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.083580 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.083587 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.083615 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.083628 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.083642 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.083659 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2025/06/25 14:57:43.083666 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.083670 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.083679 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.083714 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.083726 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.083731 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.083744 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2025/06/25 14:57:43.083752 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.083755 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.083764 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.083803 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.083814 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.083828 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.083869 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.083881 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.083889 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.083900 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.083909 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.083912 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2025/06/25 14:57:43.083967 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2025/06/25 14:57:43.083985 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestKeepJoining (0.00s) === RUN TestKickRejoin -2024/05/22 06:32:59.387394 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38163 -2024/05/22 06:32:59.387436 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38163. -2024/05/22 06:32:59.387592 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:54598 -2024/05/22 06:32:59.387707 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/05/22 06:32:59.387727 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/05/22 06:32:59.387741 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/05/22 06:32:59.387857 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.387880 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.387904 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.387983 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.388005 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.388015 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.388061 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! -2024/05/22 06:32:59.388089 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.388108 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.388126 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/05/22 06:32:59.388177 reconciler.go:219: INFO Received KICK for channel #foo -2024/05/22 06:32:59.388195 reconciler.go:91: INFO Removing JOIN state on channel #foo -2024/05/22 06:32:59.388217 reconciler.go:127: INFO Channel #foo monitor: channel no longer joined -2024/05/22 06:32:59.388232 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/05/22 06:32:59.388241 fake_delayer.go:43: INFO Faking Backoff -2024/05/22 06:32:59.388263 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/05/22 06:32:59.388324 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/05/22 06:32:59.388343 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/05/22 06:32:59.388368 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/05/22 06:32:59.388443 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/05/22 06:32:59.388469 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/05/22 06:32:59.388490 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/05/22 06:32:59.388506 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/05/22 06:32:59.388521 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/05/22 06:32:59.388522 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/05/22 06:32:59.388617 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/05/22 06:32:59.388651 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2025/06/25 14:57:43.084049 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36167 +2025/06/25 14:57:43.084074 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36167. +2025/06/25 14:57:43.084188 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:48884 +2025/06/25 14:57:43.084213 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2025/06/25 14:57:43.084222 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2025/06/25 14:57:43.084228 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2025/06/25 14:57:43.084294 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.084308 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.084318 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.084359 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.084370 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.084373 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.084399 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! +2025/06/25 14:57:43.084422 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.084433 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.084441 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2025/06/25 14:57:43.084455 reconciler.go:219: INFO Received KICK for channel #foo +2025/06/25 14:57:43.084465 reconciler.go:91: INFO Removing JOIN state on channel #foo +2025/06/25 14:57:43.084473 reconciler.go:127: INFO Channel #foo monitor: channel no longer joined +2025/06/25 14:57:43.084482 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2025/06/25 14:57:43.084485 fake_delayer.go:43: INFO Faking Backoff +2025/06/25 14:57:43.084496 reconciler.go:112: INFO Channel #foo monitor: join request sent +2025/06/25 14:57:43.084538 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2025/06/25 14:57:43.084550 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2025/06/25 14:57:43.084555 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2025/06/25 14:57:43.084603 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2025/06/25 14:57:43.084610 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2025/06/25 14:57:43.084614 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2025/06/25 14:57:43.084617 reconciler.go:77: INFO Setting JOIN state on channel #foo +2025/06/25 14:57:43.084633 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2025/06/25 14:57:43.084645 connection.go:577: INFO irc.Close(): Disconnected from server. +2025/06/25 14:57:43.084705 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2025/06/25 14:57:43.084725 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.361s +ok github.com/google/alertmanager-irc-relay 0.021s create-stamp debian/debhelper-build-stamp fakeroot debian/rules binary dh binary --buildsystem=golang --with=golang @@ -1910,12 +1945,14 @@ dpkg-buildpackage: info: binary-only upload (no source included) dpkg-genchanges: info: including full source code in upload I: copying local configuration +I: user script /srv/workspace/pbuilder/1148507/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/1148507/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/1561046 and its subdirectories -I: Current time: Wed May 22 06:33:20 -12 2024 -I: pbuilder-time-stamp: 1716402800 +I: removing directory /srv/workspace/pbuilder/1148507 and its subdirectories +I: Current time: Wed Jun 25 14:57:53 +14 2025 +I: pbuilder-time-stamp: 1750813073