Diff of the two buildlogs: -- --- b1/build.log 2024-03-25 08:31:42.043241329 +0000 +++ b2/build.log 2024-03-25 08:36:31.274835853 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Sun Mar 24 20:26:56 -12 2024 -I: pbuilder-time-stamp: 1711355216 +I: Current time: Mon Mar 25 22:31:55 +14 2024 +I: pbuilder-time-stamp: 1711355515 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/trixie-reproducible-base.tgz] I: copying local configuration @@ -26,52 +26,84 @@ dpkg-source: info: unpacking alertmanager-irc-relay_0.4.2-1.debian.tar.xz I: using fakeroot in build. I: Installing the build-deps -I: user script /srv/workspace/pbuilder/10757/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/27731/tmp/hooks/D01_modify_environment starting +debug: Running on virt32c. +I: Changing host+domainname to test build reproducibility +I: Adding a custom variable just for the fun of it... +I: Changing /bin/sh to bash +'/bin/sh' -> '/bin/bash' +lrwxrwxrwx 1 root root 9 Mar 25 08:32 /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/27731/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/27731/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='armhf' - DEBIAN_FRONTEND='noninteractive' - DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=3 ' - DISTRIBUTION='trixie' - HOME='/root' - HOST_ARCH='armhf' + 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]="arm-unknown-linux-gnueabihf") + 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=armhf + DEBIAN_FRONTEND=noninteractive + DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=4 ' + DIRSTACK=() + DISTRIBUTION=trixie + EUID=0 + FUNCNAME=([0]="Echo" [1]="main") + GROUPS=() + HOME=/root + HOSTNAME=i-capture-the-hostname + HOSTTYPE=arm + HOST_ARCH=armhf IFS=' ' - INVOCATION_ID='0d1da2413b9a49f1adb666489e6e6159' - 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='10757' - PS1='# ' - PS2='> ' + INVOCATION_ID=c0abf606cde245008df12a3741e750a6 + LANG=C + LANGUAGE=it_CH:it + LC_ALL=C + MACHTYPE=arm-unknown-linux-gnueabihf + MAIL=/var/mail/root + OPTERR=1 + OPTIND=1 + OSTYPE=linux-gnueabihf + 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=27731 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.lKzbANcI/pbuilderrc_olhP --distribution trixie --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/trixie-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.lKzbANcI/b1 --logfile b1/build.log alertmanager-irc-relay_0.4.2-1.dsc' - SUDO_GID='114' - SUDO_UID='108' - SUDO_USER='jenkins' - TERM='unknown' - TZ='/usr/share/zoneinfo/Etc/GMT+12' - USER='root' - _='/usr/bin/systemd-run' - http_proxy='http://10.0.0.15:3142/' + 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.lKzbANcI/pbuilderrc_Kzgw --distribution trixie --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/trixie-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.lKzbANcI/b2 --logfile b2/build.log alertmanager-irc-relay_0.4.2-1.dsc' + SUDO_GID=113 + SUDO_UID=107 + SUDO_USER=jenkins + TERM=unknown + TZ=/usr/share/zoneinfo/Etc/GMT-14 + UID=0 + USER=root + _='I: set' + http_proxy=http://10.0.0.15:3142/ I: uname -a - Linux virt64a 6.1.0-18-arm64 #1 SMP Debian 6.1.76-1 (2024-02-01) aarch64 GNU/Linux + Linux i-capture-the-hostname 6.1.0-18-armmp-lpae #1 SMP Debian 6.1.76-1 (2024-02-01) armv7l GNU/Linux I: ls -l /bin - lrwxrwxrwx 1 root root 7 Mar 23 11:25 /bin -> usr/bin -I: user script /srv/workspace/pbuilder/10757/tmp/hooks/D02_print_environment finished + lrwxrwxrwx 1 root root 7 Mar 24 11:24 /bin -> usr/bin +I: user script /srv/workspace/pbuilder/27731/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -310,7 +342,7 @@ Get: 187 http://deb.debian.org/debian trixie/main armhf golang-gopkg-telebot.v3-dev all 3.2.1-1 [95.0 kB] Get: 188 http://deb.debian.org/debian trixie/main armhf golang-protobuf-extensions-dev all 1.0.4-2 [29.7 kB] Get: 189 http://deb.debian.org/debian trixie/main armhf golang-github-prometheus-alertmanager-dev all 0.27.0+ds-2 [1116 kB] -Fetched 133 MB in 4s (36.5 MB/s) +Fetched 133 MB in 3s (39.3 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 ... 19577 files and directories currently installed.) @@ -927,8 +959,8 @@ Setting up tzdata (2024a-1) ... Current default time zone: 'Etc/UTC' -Local time is now: Mon Mar 25 08:29:05 UTC 2024. -Universal Time is now: Mon Mar 25 08:29:05 UTC 2024. +Local time is now: Mon Mar 25 08:33:37 UTC 2024. +Universal Time is now: Mon Mar 25 08:33:37 UTC 2024. Run 'dpkg-reconfigure tzdata' if you wish to change it. Setting up golang-github-cespare-xxhash-dev (2.1.1-2) ... @@ -1092,7 +1124,11 @@ fakeroot is already the newest version (1.33-1). 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. I: Building the package -I: Running cd /build/reproducible-path/alertmanager-irc-relay-0.4.2/ && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games" HOME="/nonexistent/first-build" dpkg-buildpackage -us -uc -b && env PATH="/usr/sbin:/usr/bin:/sbin:/bin:/usr/games" HOME="/nonexistent/first-build" dpkg-genchanges -S > ../alertmanager-irc-relay_0.4.2-1_source.changes +I: user script /srv/workspace/pbuilder/27731/tmp/hooks/A99_set_merged_usr starting +Not re-configuring usrmerge for trixie +I: user script /srv/workspace/pbuilder/27731/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 @@ -1110,34 +1146,34 @@ dh_autoreconf -O--buildsystem=golang dh_auto_configure -O--buildsystem=golang dh_auto_build -O--buildsystem=golang - cd obj-arm-linux-gnueabihf && go install -trimpath -v -p 3 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging + cd obj-arm-linux-gnueabihf && go install -trimpath -v -p 4 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging internal/goarch -internal/unsafeheader internal/cpu internal/coverage/rtcov -internal/abi -internal/chacha8rand -internal/bytealg +internal/unsafeheader internal/godebugs internal/goexperiment +internal/abi +internal/chacha8rand internal/goos -runtime/internal/atomic runtime/internal/math runtime/internal/sys +internal/bytealg runtime/internal/syscall +runtime/internal/atomic internal/race sync/atomic unicode unicode/utf8 internal/itoa container/list -runtime math/bits -math crypto/internal/alias +math crypto/internal/boring/sig cmp slices +runtime unicode/utf16 vendor/golang.org/x/crypto/cryptobyte/asn1 internal/nettrace @@ -1147,194 +1183,194 @@ log/internal google.golang.org/protobuf/internal/flags google.golang.org/protobuf/internal/set -crypto/subtle internal/reflectlite sync +crypto/subtle runtime/metrics internal/testlog internal/bisect internal/singleflight +google.golang.org/protobuf/internal/pragma runtime/cgo -internal/godebug errors +sort +internal/godebug io internal/oserror syscall +strconv bytes hash -strconv +crypto/internal/nistec/fiat crypto reflect time -crypto/internal/nistec/fiat context crypto/internal/randutil -sort internal/syscall/unix internal/poll +crypto/internal/nistec encoding/binary internal/fmtsort internal/safefilepath internal/syscall/execenv +path crypto/cipher crypto/internal/edwards25519/field -path +io/fs crypto/internal/boring crypto/des -crypto/aes -io/fs -crypto/internal/nistec math/rand +crypto/aes +crypto/ecdh os strings -crypto/ecdh crypto/sha512 crypto/internal/edwards25519 crypto/hmac crypto/md5 -fmt crypto/rc4 crypto/sha1 crypto/sha256 encoding/base64 vendor/golang.org/x/net/dns/dnsmessage -encoding/pem internal/intern net/netip -math/big -encoding/hex -net -net/url +encoding/pem +fmt path/filepath vendor/golang.org/x/crypto/chacha20 vendor/golang.org/x/crypto/internal/poly1305 -vendor/golang.org/x/crypto/chacha20poly1305 +net vendor/golang.org/x/crypto/hkdf +vendor/golang.org/x/crypto/chacha20poly1305 +bufio +hash/crc32 +math/big +encoding/hex +net/url encoding/json +flag +github.com/golang/mock/gomock +log +github.com/google/alertmanager-irc-relay/logging crypto/elliptic crypto/internal/bigmod crypto/internal/boring/bbig encoding/asn1 crypto/rand +crypto/dsa crypto/ed25519 -vendor/golang.org/x/crypto/cryptobyte crypto/rsa -crypto/dsa -crypto/ecdsa -crypto/x509/pkix -flag -bufio -github.com/golang/mock/gomock -log -github.com/google/alertmanager-irc-relay/logging github.com/fluffle/goirc/state +vendor/golang.org/x/crypto/cryptobyte +crypto/x509/pkix compress/flate -hash/crc32 vendor/golang.org/x/text/transform -compress/gzip +crypto/ecdsa vendor/golang.org/x/text/unicode/bidi +compress/gzip vendor/golang.org/x/text/unicode/norm -vendor/golang.org/x/text/secure/bidirule vendor/golang.org/x/net/http2/hpack +vendor/golang.org/x/text/secure/bidirule mime -vendor/golang.org/x/net/idna mime/quotedprintable net/http/internal net/http/internal/ascii regexp/syntax github.com/go-logfmt/logfmt -crypto/x509 -golang.org/x/net/internal/socks -golang.org/x/net/proxy -net/textproto -vendor/golang.org/x/net/http/httpproxy -regexp -vendor/golang.org/x/net/http/httpguts -mime/multipart hash/fnv -github.com/go-kit/log -crypto/tls google.golang.org/protobuf/internal/detrand +vendor/golang.org/x/net/idna google.golang.org/protobuf/internal/errors google.golang.org/protobuf/encoding/protowire -github.com/go-kit/log/level -google.golang.org/protobuf/internal/pragma -github.com/prometheus/alertmanager/featurecontrol google.golang.org/protobuf/reflect/protoreflect +regexp go/token +github.com/go-kit/log io/ioutil -google.golang.org/protobuf/internal/version -runtime/debug -github.com/beorn7/perks/quantile google.golang.org/protobuf/internal/descfmt google.golang.org/protobuf/internal/descopts google.golang.org/protobuf/internal/strs +github.com/go-kit/log/level google.golang.org/protobuf/internal/encoding/text +github.com/prometheus/alertmanager/featurecontrol google.golang.org/protobuf/internal/encoding/messageset google.golang.org/protobuf/internal/genid google.golang.org/protobuf/internal/order google.golang.org/protobuf/reflect/protoregistry -google.golang.org/protobuf/internal/encoding/defval google.golang.org/protobuf/runtime/protoiface -github.com/cespare/xxhash +google.golang.org/protobuf/internal/version +runtime/debug +google.golang.org/protobuf/internal/encoding/defval google.golang.org/protobuf/proto +github.com/beorn7/perks/quantile +github.com/cespare/xxhash github.com/prometheus/common/internal/bitbucket.org/ww/goautoneg github.com/prometheus/procfs/internal/fs github.com/prometheus/procfs/internal/util golang.org/x/sys/unix +golang.org/x/text/internal/tag +golang.org/x/text/internal/language google.golang.org/protobuf/internal/filedesc -github.com/fluffle/goirc/client -net/http/httptrace -net/http +crypto/x509 +golang.org/x/net/internal/socks +golang.org/x/net/proxy +net/textproto +vendor/golang.org/x/net/http/httpproxy google.golang.org/protobuf/encoding/prototext +vendor/golang.org/x/net/http/httpguts +mime/multipart google.golang.org/protobuf/internal/encoding/tag -google.golang.org/protobuf/internal/impl +crypto/tls google.golang.org/protobuf/encoding/protodelim -github.com/prometheus/procfs -golang.org/x/text/internal/tag -golang.org/x/text/internal/language +google.golang.org/protobuf/internal/impl golang.org/x/text/internal/language/compact +github.com/prometheus/procfs golang.org/x/text/language -google.golang.org/protobuf/internal/filetype golang.org/x/text/internal -google.golang.org/protobuf/runtime/protoimpl golang.org/x/text/transform -google.golang.org/protobuf/types/known/timestamppb golang.org/x/text/unicode/norm -github.com/prometheus/client_model/go -github.com/prometheus/common/model -github.com/gorilla/mux -expvar golang.org/x/text/cases -github.com/prometheus/alertmanager/pkg/labels -github.com/prometheus/client_golang/prometheus/internal -github.com/prometheus/alertmanager/matchers/parse -github.com/prometheus/common/expfmt -github.com/prometheus/alertmanager/matchers/compat html text/template/parse gopkg.in/yaml.v2 -github.com/prometheus/client_golang/prometheus +github.com/fluffle/goirc/client +net/http/httptrace +net/http text/template -html/template +google.golang.org/protobuf/internal/filetype +google.golang.org/protobuf/runtime/protoimpl +google.golang.org/protobuf/types/known/timestamppb +github.com/prometheus/client_model/go os/signal +html/template +github.com/prometheus/common/model +github.com/prometheus/client_golang/prometheus/internal +github.com/prometheus/alertmanager/pkg/labels +github.com/prometheus/alertmanager/matchers/parse +github.com/prometheus/alertmanager/matchers/compat +expvar +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/promauto github.com/prometheus/client_golang/prometheus/promhttp +github.com/prometheus/client_golang/prometheus/promauto github.com/prometheus/alertmanager/template github.com/google/alertmanager-irc-relay dh_auto_test -O--buildsystem=golang - cd obj-arm-linux-gnueabihf && go test -vet=off -v -p 3 github.com/google/alertmanager-irc-relay github.com/google/alertmanager-irc-relay/logging + cd obj-arm-linux-gnueabihf && go test -vet=off -v -p 4 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/03/24 20:30:57.497320 backoff.go:111: INFO Backoff for 0s starts -2024/03/24 20:30:57.497520 backoff.go:114: INFO Backoff for 0s ends -2024/03/24 20:30:57.497549 backoff.go:111: INFO Backoff for 2ms starts -2024/03/24 20:30:57.497575 backoff.go:116: INFO Backoff for 2ms canceled by context +2024/03/25 22:35:43.685932 backoff.go:111: INFO Backoff for 0s starts +2024/03/25 22:35:43.686110 backoff.go:114: INFO Backoff for 0s ends +2024/03/25 22:35:43.686140 backoff.go:111: INFO Backoff for 2ms starts +2024/03/25 22:35:43.686167 backoff.go:116: INFO Backoff for 2ms canceled by context --- PASS: TestBackoffDelayContext (0.00s) === RUN TestNoConfig --- PASS: TestNoConfig (0.00s) @@ -1353,10 +1389,10 @@ === RUN TestGivenTemplateNotOverwritten --- PASS: TestGivenTemplateNotOverwritten (0.00s) === RUN TestTemplateErrorsCreateRawAlertMsg -2024/03/24 20:30:57.503369 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/03/24 20:30:57.503427 format.go:61: WARN Sending raw alert -2024/03/24 20:30:57.503508 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/03/24 20:30:57.503538 format.go:61: WARN Sending raw alert +2024/03/25 22:35:43.692021 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/03/25 22:35:43.692080 format.go:61: WARN Sending raw alert +2024/03/25 22:35:43.692164 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/03/25 22:35:43.692196 format.go:61: WARN Sending raw alert --- PASS: TestTemplateErrorsCreateRawAlertMsg (0.00s) === RUN TestAlertsDispatchedOnce --- PASS: TestAlertsDispatchedOnce (0.00s) @@ -1365,482 +1401,482 @@ === RUN TestUrlFunctions --- PASS: TestUrlFunctions (0.00s) === RUN TestAlertsDispatched -2024/03/24 20:30:57.505223 http.go:132: INFO Starting HTTP server +2024/03/25 22:35:43.693885 http.go:132: INFO Starting HTTP server --- PASS: TestAlertsDispatched (0.00s) === RUN TestRootReturnsError -2024/03/24 20:30:57.506157 http.go:132: INFO Starting HTTP server +2024/03/25 22:35:43.694832 http.go:132: INFO Starting HTTP server --- PASS: TestRootReturnsError (0.00s) === RUN TestInvalidDataReturnsError -2024/03/24 20:30:57.506757 http.go:132: INFO Starting HTTP server -2024/03/24 20:30:57.506863 http.go:96: ERROR Could not decode request body (invalid character '}' looking for beginning of object key string): {"this is not": "a valid alert",} +2024/03/25 22:35:43.695392 http.go:132: INFO Starting HTTP server +2024/03/25 22:35:43.695494 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/03/24 20:30:57.507458 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42903 -2024/03/24 20:30:57.507591 irc.go:300: INFO Connecting to IRC 127.0.0.1:42903 -2024/03/24 20:30:57.507619 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.507645 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42903. -2024/03/24 20:30:57.508086 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34444 -2024/03/24 20:30:57.508187 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/03/24 20:30:57.508292 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret -2024/03/24 20:30:57.508353 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping -2024/03/24 20:30:57.508384 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.508421 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.508443 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.508688 irc.go:144: INFO Session established -2024/03/24 20:30:57.508765 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.508791 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.508816 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.508974 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.509020 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.509041 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.509113 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/03/24 20:30:57.509125 irc.go:294: INFO IRC routine asked to terminate -2024/03/24 20:30:57.509157 irc.go:269: INFO IRC client connected, quitting -2024/03/24 20:30:57.509188 irc.go:272: INFO Wait for IRC disconnect to complete -2024/03/24 20:30:57.509320 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.509412 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.509551 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.509733 irc.go:150: INFO Disconnected from IRC -2024/03/24 20:30:57.509782 irc.go:280: INFO IRC shutdown complete -2024/03/24 20:30:57.509837 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections ---- PASS: TestServerPassword (0.00s) +2024/03/25 22:35:43.697399 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43775 +2024/03/25 22:35:43.698752 irc.go:300: INFO Connecting to IRC 127.0.0.1:43775 +2024/03/25 22:35:43.698804 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.698847 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43775. +2024/03/25 22:35:43.701728 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:43962 +2024/03/25 22:35:43.701753 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.701989 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret +2024/03/25 22:35:43.702040 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping +2024/03/25 22:35:43.702059 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.702079 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.702093 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.702329 irc.go:144: INFO Session established +2024/03/25 22:35:43.702425 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.702450 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.702476 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.702625 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.702660 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.702678 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.702745 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/03/25 22:35:43.702943 irc.go:294: INFO IRC routine asked to terminate +2024/03/25 22:35:43.702977 irc.go:269: INFO IRC client connected, quitting +2024/03/25 22:35:43.702997 irc.go:272: INFO Wait for IRC disconnect to complete +2024/03/25 22:35:43.703113 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.703152 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.703291 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.703439 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.703478 irc.go:280: INFO IRC shutdown complete +2024/03/25 22:35:43.703537 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +--- PASS: TestServerPassword (0.01s) === RUN TestSendAlertOnPreJoinedChannel -2024/03/24 20:30:57.510091 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:45251 -2024/03/24 20:30:57.510190 irc.go:300: INFO Connecting to IRC 127.0.0.1:45251 -2024/03/24 20:30:57.510216 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.510237 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:45251. -2024/03/24 20:30:57.510527 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34292 -2024/03/24 20:30:57.510661 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/03/24 20:30:57.510791 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.510857 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.510881 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.511018 irc.go:144: INFO Session established -2024/03/24 20:30:57.511089 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.511118 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.511146 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.511248 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.511309 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.511363 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.511523 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.511567 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.511668 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/03/24 20:30:57.511729 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message -2024/03/24 20:30:57.511794 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/03/24 20:30:57.511805 irc.go:294: INFO IRC routine asked to terminate -2024/03/24 20:30:57.511841 irc.go:269: INFO IRC client connected, quitting -2024/03/24 20:30:57.511872 irc.go:272: INFO Wait for IRC disconnect to complete -2024/03/24 20:30:57.511998 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.512050 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.512147 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.512320 irc.go:150: INFO Disconnected from IRC -2024/03/24 20:30:57.512372 irc.go:280: INFO IRC shutdown complete -2024/03/24 20:30:57.512439 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.703774 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36235 +2024/03/25 22:35:43.703854 irc.go:300: INFO Connecting to IRC 127.0.0.1:36235 +2024/03/25 22:35:43.703872 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.703898 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36235. +2024/03/25 22:35:43.704158 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:36404 +2024/03/25 22:35:43.704306 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.704448 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.704486 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.704502 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.704620 irc.go:144: INFO Session established +2024/03/25 22:35:43.704676 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.704694 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.704716 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.704815 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.704842 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.704859 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.704950 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.704973 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.705081 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/03/25 22:35:43.705123 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message +2024/03/25 22:35:43.705167 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/03/25 22:35:43.705188 irc.go:294: INFO IRC routine asked to terminate +2024/03/25 22:35:43.705204 irc.go:269: INFO IRC client connected, quitting +2024/03/25 22:35:43.705220 irc.go:272: INFO Wait for IRC disconnect to complete +2024/03/25 22:35:43.705290 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.705321 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.705414 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.705624 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.705662 irc.go:280: INFO IRC shutdown complete +2024/03/25 22:35:43.705714 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertOnPreJoinedChannel (0.00s) === RUN TestUsePrivmsgToSendAlertOnPreJoinedChannel -2024/03/24 20:30:57.512708 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43807 -2024/03/24 20:30:57.512826 irc.go:300: INFO Connecting to IRC 127.0.0.1:43807 -2024/03/24 20:30:57.512861 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.512886 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43807. -2024/03/24 20:30:57.513201 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:46658 -2024/03/24 20:30:57.513248 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/03/24 20:30:57.513335 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.513384 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.513415 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.513574 irc.go:144: INFO Session established -2024/03/24 20:30:57.513648 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.513675 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.513702 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.513805 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.513841 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.513895 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.514049 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.514088 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.514129 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/03/24 20:30:57.514199 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message -2024/03/24 20:30:57.514288 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/03/24 20:30:57.514292 irc.go:294: INFO IRC routine asked to terminate -2024/03/24 20:30:57.514320 irc.go:269: INFO IRC client connected, quitting -2024/03/24 20:30:57.514339 irc.go:272: INFO Wait for IRC disconnect to complete -2024/03/24 20:30:57.514487 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.514542 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.514644 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.514810 irc.go:150: INFO Disconnected from IRC -2024/03/24 20:30:57.514855 irc.go:280: INFO IRC shutdown complete -2024/03/24 20:30:57.514917 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.705895 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38807 +2024/03/25 22:35:43.705962 irc.go:300: INFO Connecting to IRC 127.0.0.1:38807 +2024/03/25 22:35:43.705979 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.705999 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38807. +2024/03/25 22:35:43.706228 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:45126 +2024/03/25 22:35:43.706322 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.706468 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.706518 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.706541 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.706768 irc.go:144: INFO Session established +2024/03/25 22:35:43.706830 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.706856 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.706880 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.706973 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.707015 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.707063 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.707277 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.707328 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.707422 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/03/25 22:35:43.707514 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message +2024/03/25 22:35:43.707620 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/03/25 22:35:43.707645 irc.go:294: INFO IRC routine asked to terminate +2024/03/25 22:35:43.707684 irc.go:269: INFO IRC client connected, quitting +2024/03/25 22:35:43.707713 irc.go:272: INFO Wait for IRC disconnect to complete +2024/03/25 22:35:43.707871 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.707959 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.708088 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.708242 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.708291 irc.go:280: INFO IRC shutdown complete +2024/03/25 22:35:43.708348 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestUsePrivmsgToSendAlertOnPreJoinedChannel (0.00s) === RUN TestSendAlertAndJoinChannel -2024/03/24 20:30:57.515129 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33139 -2024/03/24 20:30:57.515222 irc.go:300: INFO Connecting to IRC 127.0.0.1:33139 -2024/03/24 20:30:57.515247 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.515269 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33139. -2024/03/24 20:30:57.515543 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:41432 -2024/03/24 20:30:57.515630 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/03/24 20:30:57.515749 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.515794 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.515811 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.515986 irc.go:144: INFO Session established -2024/03/24 20:30:57.516073 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.516097 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.516143 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.516285 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.516330 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.516348 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.516427 reconciler.go:245: INFO Request to JOIN new channel #foobar -2024/03/24 20:30:57.516483 reconciler.go:103: INFO Channel #foobar monitor: waiting to join -2024/03/24 20:30:57.516491 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.516513 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.516522 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.516548 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/03/24 20:30:57.516554 reconciler.go:112: INFO Channel #foobar monitor: join request sent -2024/03/24 20:30:57.516690 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar -2024/03/24 20:30:57.516734 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.516757 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar -2024/03/24 20:30:57.516882 reconciler.go:201: INFO Received JOIN confirmation for channel #foobar -2024/03/24 20:30:57.516918 reconciler.go:77: INFO Setting JOIN state on channel #foobar -2024/03/24 20:30:57.516995 reconciler.go:116: INFO Channel #foobar monitor: join succeeded -2024/03/24 20:30:57.517086 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message -2024/03/24 20:30:57.517180 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/03/24 20:30:57.517212 reconciler.go:129: INFO Channel #foobar monitor: context canceled while monitoring -2024/03/24 20:30:57.517209 irc.go:294: INFO IRC routine asked to terminate -2024/03/24 20:30:57.517238 irc.go:269: INFO IRC client connected, quitting -2024/03/24 20:30:57.517275 irc.go:272: INFO Wait for IRC disconnect to complete -2024/03/24 20:30:57.517399 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.517447 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.517546 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.517708 irc.go:150: INFO Disconnected from IRC -2024/03/24 20:30:57.517747 irc.go:280: INFO IRC shutdown complete -2024/03/24 20:30:57.517805 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.708613 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33395 +2024/03/25 22:35:43.708724 irc.go:300: INFO Connecting to IRC 127.0.0.1:33395 +2024/03/25 22:35:43.708751 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.708775 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33395. +2024/03/25 22:35:43.709059 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:44836 +2024/03/25 22:35:43.709151 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.709226 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.709261 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.709290 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.709506 irc.go:144: INFO Session established +2024/03/25 22:35:43.709617 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.709657 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.709709 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.709834 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.709880 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.709950 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.710033 reconciler.go:245: INFO Request to JOIN new channel #foobar +2024/03/25 22:35:43.710089 reconciler.go:103: INFO Channel #foobar monitor: waiting to join +2024/03/25 22:35:43.710114 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.710138 reconciler.go:112: INFO Channel #foobar monitor: join request sent +2024/03/25 22:35:43.710167 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.710202 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.710245 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/03/25 22:35:43.710319 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar +2024/03/25 22:35:43.710367 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.710394 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar +2024/03/25 22:35:43.710529 reconciler.go:201: INFO Received JOIN confirmation for channel #foobar +2024/03/25 22:35:43.710574 reconciler.go:77: INFO Setting JOIN state on channel #foobar +2024/03/25 22:35:43.710611 reconciler.go:116: INFO Channel #foobar monitor: join succeeded +2024/03/25 22:35:43.710739 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message +2024/03/25 22:35:43.710827 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/03/25 22:35:43.710865 reconciler.go:129: INFO Channel #foobar monitor: context canceled while monitoring +2024/03/25 22:35:43.710860 irc.go:294: INFO IRC routine asked to terminate +2024/03/25 22:35:43.710908 irc.go:269: INFO IRC client connected, quitting +2024/03/25 22:35:43.710946 irc.go:272: INFO Wait for IRC disconnect to complete +2024/03/25 22:35:43.711106 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.711156 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.711280 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.711472 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.711527 irc.go:280: INFO IRC shutdown complete +2024/03/25 22:35:43.711602 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertAndJoinChannel (0.00s) === RUN TestSendAlertDisconnected -2024/03/24 20:30:57.518032 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34733 -2024/03/24 20:30:57.518125 irc.go:300: INFO Connecting to IRC 127.0.0.1:34733 -2024/03/24 20:30:57.518152 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.518174 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34733. -2024/03/24 20:30:57.518448 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:54308 -2024/03/24 20:30:57.518549 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/03/24 20:30:57.518627 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.518692 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.518729 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.518752 irc_test.go:292: INFO =Server= Wait before completing session -2024/03/24 20:30:57.518773 irc_test.go:294: INFO =Server= Completing session -2024/03/24 20:30:57.518917 irc.go:144: INFO Session established -2024/03/24 20:30:57.518992 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.519021 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.519046 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.519202 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.519253 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.519270 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.519439 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.519480 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.519524 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/03/24 20:30:57.519622 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message -2024/03/24 20:30:57.519701 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/03/24 20:30:57.519712 irc.go:294: INFO IRC routine asked to terminate -2024/03/24 20:30:57.519740 irc.go:269: INFO IRC client connected, quitting -2024/03/24 20:30:57.519776 irc.go:272: INFO Wait for IRC disconnect to complete -2024/03/24 20:30:57.519910 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.519963 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.520061 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.520237 irc.go:150: INFO Disconnected from IRC -2024/03/24 20:30:57.520287 irc.go:280: INFO IRC shutdown complete -2024/03/24 20:30:57.520358 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.711872 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38001 +2024/03/25 22:35:43.711995 irc.go:300: INFO Connecting to IRC 127.0.0.1:38001 +2024/03/25 22:35:43.712037 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.712078 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38001. +2024/03/25 22:35:43.712363 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:39550 +2024/03/25 22:35:43.712443 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.712512 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.712553 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.712583 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.712625 irc_test.go:292: INFO =Server= Wait before completing session +2024/03/25 22:35:43.712656 irc_test.go:294: INFO =Server= Completing session +2024/03/25 22:35:43.712839 irc.go:144: INFO Session established +2024/03/25 22:35:43.712919 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.712944 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.712968 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.713101 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.713154 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.713184 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.713385 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.713500 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.713576 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/03/25 22:35:43.713708 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message +2024/03/25 22:35:43.713786 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/03/25 22:35:43.713798 irc.go:294: INFO IRC routine asked to terminate +2024/03/25 22:35:43.713830 irc.go:269: INFO IRC client connected, quitting +2024/03/25 22:35:43.713864 irc.go:272: INFO Wait for IRC disconnect to complete +2024/03/25 22:35:43.714005 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.714058 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.714151 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.714318 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.714387 irc.go:280: INFO IRC shutdown complete +2024/03/25 22:35:43.714458 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertDisconnected (0.00s) === RUN TestReconnect -2024/03/24 20:30:57.520575 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36027 -2024/03/24 20:30:57.520670 irc.go:300: INFO Connecting to IRC 127.0.0.1:36027 -2024/03/24 20:30:57.520695 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.520718 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36027. -2024/03/24 20:30:57.520991 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34460 -2024/03/24 20:30:57.521089 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/03/24 20:30:57.521199 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.521249 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.521266 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.521428 irc.go:144: INFO Session established -2024/03/24 20:30:57.521501 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.521529 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.521554 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.521652 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.521685 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.521738 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.521905 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.521943 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.521918 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.522004 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:34460: read tcp 127.0.0.1:36027->127.0.0.1:34460: use of closed network connection -2024/03/24 20:30:57.522034 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/03/24 20:30:57.522105 irc.go:150: INFO Disconnected from IRC -2024/03/24 20:30:57.522182 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/03/24 20:30:57.522224 irc.go:300: INFO Connecting to IRC 127.0.0.1:36027 -2024/03/24 20:30:57.522241 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.522289 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36027. -2024/03/24 20:30:57.522586 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:34468 -2024/03/24 20:30:57.522682 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/03/24 20:30:57.522758 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.522814 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.522845 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.523003 irc.go:144: INFO Session established -2024/03/24 20:30:57.523073 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.523098 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.523132 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.523225 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.523279 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.523334 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.523421 irc.go:294: INFO IRC routine asked to terminate -2024/03/24 20:30:57.523452 irc.go:269: INFO IRC client connected, quitting -2024/03/24 20:30:57.523421 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/03/24 20:30:57.523482 irc.go:272: INFO Wait for IRC disconnect to complete -2024/03/24 20:30:57.523493 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.523528 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.523540 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.523603 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.523716 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.523884 irc.go:150: INFO Disconnected from IRC -2024/03/24 20:30:57.523939 irc.go:280: INFO IRC shutdown complete -2024/03/24 20:30:57.523993 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.714695 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:46127 +2024/03/25 22:35:43.714786 irc.go:300: INFO Connecting to IRC 127.0.0.1:46127 +2024/03/25 22:35:43.714826 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.714864 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46127. +2024/03/25 22:35:43.715131 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:45536 +2024/03/25 22:35:43.715250 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.715386 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.715440 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.715467 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.715627 irc.go:144: INFO Session established +2024/03/25 22:35:43.715696 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.715721 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.715756 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.715886 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.715931 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.715947 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.716092 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.716119 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:45536: read tcp 127.0.0.1:46127->127.0.0.1:45536: use of closed network connection +2024/03/25 22:35:43.716214 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.716256 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.716319 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.716332 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/03/25 22:35:43.716404 irc.go:300: INFO Connecting to IRC 127.0.0.1:46127 +2024/03/25 22:35:43.716431 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.716465 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:46127. +2024/03/25 22:35:43.716771 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:45538 +2024/03/25 22:35:43.716802 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.716929 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.716987 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.717023 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.717181 irc.go:144: INFO Session established +2024/03/25 22:35:43.717271 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.717308 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.717333 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.717516 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.717574 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.717601 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.717685 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/03/25 22:35:43.717723 irc.go:294: INFO IRC routine asked to terminate +2024/03/25 22:35:43.717750 irc.go:269: INFO IRC client connected, quitting +2024/03/25 22:35:43.717770 irc.go:272: INFO Wait for IRC disconnect to complete +2024/03/25 22:35:43.717868 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.717916 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.718045 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.718173 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.718209 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.718255 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.718294 irc.go:280: INFO IRC shutdown complete +2024/03/25 22:35:43.718356 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestReconnect (0.00s) === RUN TestConnectErrorRetry -2024/03/24 20:30:57.524217 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39349 -2024/03/24 20:30:57.524319 irc.go:300: INFO Connecting to IRC 127.0.0.1:39349 -2024/03/24 20:30:57.524347 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.524363 fake_delayer.go:45: INFO Waiting StopDelay signal -2024/03/24 20:30:57.524394 fake_delayer.go:47: INFO Received StopDelay signal -2024/03/24 20:30:57.524416 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39349. -2024/03/24 20:30:57.524661 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:43928 -2024/03/24 20:30:57.524701 irc_server_for_test.go:157: INFO =Server= Closing connection early -2024/03/24 20:30:57.524703 connection.go:399: INFO irc.Connect(): Performing SSL handshake. -2024/03/24 20:30:57.526367 irc.go:305: ERROR Could not connect to IRC: EOF -2024/03/24 20:30:57.526445 irc.go:300: INFO Connecting to IRC 127.0.0.1:39349 -2024/03/24 20:30:57.526469 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.526486 fake_delayer.go:45: INFO Waiting StopDelay signal -2024/03/24 20:30:57.526521 fake_delayer.go:47: INFO Received StopDelay signal -2024/03/24 20:30:57.526572 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39349. -2024/03/24 20:30:57.526835 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:43940 -2024/03/24 20:30:57.526899 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/03/24 20:30:57.526982 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.527055 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.527095 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.527279 irc.go:144: INFO Session established -2024/03/24 20:30:57.527358 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.527390 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.527415 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.527556 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.527603 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.527622 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.527715 irc.go:294: INFO IRC routine asked to terminate -2024/03/24 20:30:57.527756 irc.go:269: INFO IRC client connected, quitting -2024/03/24 20:30:57.527777 irc.go:272: INFO Wait for IRC disconnect to complete -2024/03/24 20:30:57.527794 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.527823 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.527725 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/03/24 20:30:57.527856 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.527898 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.528022 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.528194 irc.go:150: INFO Disconnected from IRC -2024/03/24 20:30:57.528246 irc.go:280: INFO IRC shutdown complete -2024/03/24 20:30:57.528312 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.718562 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:44265 +2024/03/25 22:35:43.718645 irc.go:300: INFO Connecting to IRC 127.0.0.1:44265 +2024/03/25 22:35:43.718671 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.718687 fake_delayer.go:45: INFO Waiting StopDelay signal +2024/03/25 22:35:43.718711 fake_delayer.go:47: INFO Received StopDelay signal +2024/03/25 22:35:43.718734 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:44265. +2024/03/25 22:35:43.718975 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:59144 +2024/03/25 22:35:43.719016 irc_server_for_test.go:157: INFO =Server= Closing connection early +2024/03/25 22:35:43.719214 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.719384 connection.go:444: ERROR irc.send(): write tcp 127.0.0.1:59144->127.0.0.1:44265: write: broken pipe +2024/03/25 22:35:43.719421 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.719488 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:59144->127.0.0.1:44265: use of closed network connection +2024/03/25 22:35:43.719567 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.719608 irc.go:319: WARN Receiving a session down before the session is up, this is odd +2024/03/25 22:35:43.719637 irc.go:300: INFO Connecting to IRC 127.0.0.1:44265 +2024/03/25 22:35:43.719652 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.719673 fake_delayer.go:45: INFO Waiting StopDelay signal +2024/03/25 22:35:43.719690 fake_delayer.go:47: INFO Received StopDelay signal +2024/03/25 22:35:43.719717 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:44265. +2024/03/25 22:35:43.720011 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:59160 +2024/03/25 22:35:43.720083 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.720121 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.720013 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.720150 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.720308 irc.go:144: INFO Session established +2024/03/25 22:35:43.720395 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.720424 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.720450 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.720603 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.720653 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.720671 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.720762 irc.go:294: INFO IRC routine asked to terminate +2024/03/25 22:35:43.720794 irc.go:269: INFO IRC client connected, quitting +2024/03/25 22:35:43.720823 irc.go:272: INFO Wait for IRC disconnect to complete +2024/03/25 22:35:43.720761 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/03/25 22:35:43.720892 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.720913 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.720929 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.720944 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.721038 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.721196 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.721248 irc.go:280: INFO IRC shutdown complete +2024/03/25 22:35:43.721304 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestConnectErrorRetry (0.00s) === RUN TestIdentify -2024/03/24 20:30:57.528569 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38131 -2024/03/24 20:30:57.528686 irc.go:300: INFO Connecting to IRC 127.0.0.1:38131 -2024/03/24 20:30:57.528721 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.528763 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38131. -2024/03/24 20:30:57.529058 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:49378 -2024/03/24 20:30:57.529160 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/03/24 20:30:57.529278 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.529386 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.529445 irc.go:165: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. -2024/03/24 20:30:57.529504 irc.go:189: INFO Handling NickServ request to IDENTIFY -2024/03/24 20:30:57.529600 irc.go:144: INFO Session established -2024/03/24 20:30:57.529638 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request -2024/03/24 20:30:57.529664 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword -2024/03/24 20:30:57.529685 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.529703 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.529704 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.529743 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.529891 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.529948 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.529984 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.530092 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/03/24 20:30:57.530113 irc.go:294: INFO IRC routine asked to terminate -2024/03/24 20:30:57.530155 irc.go:269: INFO IRC client connected, quitting -2024/03/24 20:30:57.530168 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.530177 irc.go:272: INFO Wait for IRC disconnect to complete -2024/03/24 20:30:57.530186 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.530271 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.530321 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.530488 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.530655 irc.go:150: INFO Disconnected from IRC -2024/03/24 20:30:57.530697 irc.go:280: INFO IRC shutdown complete -2024/03/24 20:30:57.530779 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.721552 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38151 +2024/03/25 22:35:43.721638 irc.go:300: INFO Connecting to IRC 127.0.0.1:38151 +2024/03/25 22:35:43.721663 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.721687 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38151. +2024/03/25 22:35:43.721959 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:43672 +2024/03/25 22:35:43.721995 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.722115 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.722222 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.722268 irc.go:165: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. +2024/03/25 22:35:43.722317 irc.go:189: INFO Handling NickServ request to IDENTIFY +2024/03/25 22:35:43.722407 irc.go:144: INFO Session established +2024/03/25 22:35:43.722441 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request +2024/03/25 22:35:43.722485 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword +2024/03/25 22:35:43.722515 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.722541 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.722580 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.722517 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.722723 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.722770 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.722795 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.722873 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/03/25 22:35:43.722906 irc.go:294: INFO IRC routine asked to terminate +2024/03/25 22:35:43.722925 irc.go:269: INFO IRC client connected, quitting +2024/03/25 22:35:43.722944 irc.go:272: INFO Wait for IRC disconnect to complete +2024/03/25 22:35:43.723088 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.723128 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.723168 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.723224 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.723345 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.723477 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.723522 irc.go:280: INFO IRC shutdown complete +2024/03/25 22:35:43.723576 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestIdentify (0.00s) === RUN TestGhost -2024/03/24 20:30:57.531014 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:44315 -2024/03/24 20:30:57.531111 irc.go:300: INFO Connecting to IRC 127.0.0.1:44315 -2024/03/24 20:30:57.531140 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.531164 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:44315. -2024/03/24 20:30:57.531443 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:39162 -2024/03/24 20:30:57.531509 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/03/24 20:30:57.531581 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.531639 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.531816 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' -2024/03/24 20:30:57.531930 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ -2024/03/24 20:30:57.532082 irc.go:144: INFO Session established -2024/03/24 20:30:57.532149 irc.go:204: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' -2024/03/24 20:30:57.532197 irc.go:210: INFO Changing nick to 'foo' -2024/03/24 20:30:57.532223 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request -2024/03/24 20:30:57.532258 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.532281 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.532303 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.532386 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword -2024/03/24 20:30:57.532424 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.532448 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.532479 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.532504 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.532526 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.532604 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/03/24 20:30:57.532613 irc.go:294: INFO IRC routine asked to terminate -2024/03/24 20:30:57.532652 irc.go:269: INFO IRC client connected, quitting -2024/03/24 20:30:57.532693 irc.go:272: INFO Wait for IRC disconnect to complete -2024/03/24 20:30:57.532846 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.532895 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.533018 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.533191 irc.go:150: INFO Disconnected from IRC -2024/03/24 20:30:57.533234 irc.go:280: INFO IRC shutdown complete -2024/03/24 20:30:57.533308 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.723775 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39091 +2024/03/25 22:35:43.723870 irc.go:300: INFO Connecting to IRC 127.0.0.1:39091 +2024/03/25 22:35:43.723897 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.723919 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39091. +2024/03/25 22:35:43.724154 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:45938 +2024/03/25 22:35:43.724296 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.724453 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.724503 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.724626 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' +2024/03/25 22:35:43.724709 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ +2024/03/25 22:35:43.724810 irc.go:144: INFO Session established +2024/03/25 22:35:43.724860 irc.go:204: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' +2024/03/25 22:35:43.724892 irc.go:210: INFO Changing nick to 'foo' +2024/03/25 22:35:43.724920 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request +2024/03/25 22:35:43.724964 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.724989 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.725012 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.725159 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword +2024/03/25 22:35:43.725205 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.725233 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.725253 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.725277 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.725292 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.725363 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/03/25 22:35:43.725396 irc.go:294: INFO IRC routine asked to terminate +2024/03/25 22:35:43.725417 irc.go:269: INFO IRC client connected, quitting +2024/03/25 22:35:43.725564 irc.go:272: INFO Wait for IRC disconnect to complete +2024/03/25 22:35:43.725682 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.725734 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.725842 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.725987 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.726036 irc.go:280: INFO IRC shutdown complete +2024/03/25 22:35:43.726098 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestGhost (0.00s) === RUN TestStopRunningWhenHalfConnected -2024/03/24 20:30:57.533532 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:37823 -2024/03/24 20:30:57.533634 irc.go:300: INFO Connecting to IRC 127.0.0.1:37823 -2024/03/24 20:30:57.533661 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.533683 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:37823. -2024/03/24 20:30:57.533934 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:54662 -2024/03/24 20:30:57.534017 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/03/24 20:30:57.534094 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.534133 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.534155 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.534190 irc_test.go:589: INFO =Server= NOT completing session -2024/03/24 20:30:57.534243 irc.go:321: INFO IRC routine asked to terminate -2024/03/24 20:30:57.534268 irc.go:280: INFO IRC shutdown complete -2024/03/24 20:30:57.534272 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.534385 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:54662 disconnected -2024/03/24 20:30:57.534402 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:54662->127.0.0.1:37823: use of closed network connection -2024/03/24 20:30:57.534478 irc.go:150: INFO Disconnected from IRC -2024/03/24 20:30:57.534520 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.726312 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:44329 +2024/03/25 22:35:43.726398 irc.go:300: INFO Connecting to IRC 127.0.0.1:44329 +2024/03/25 22:35:43.726425 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.726448 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:44329. +2024/03/25 22:35:43.726689 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:35722 +2024/03/25 22:35:43.726835 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/03/25 22:35:43.726983 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.727031 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.727058 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.727079 irc_test.go:589: INFO =Server= NOT completing session +2024/03/25 22:35:43.727154 irc.go:321: INFO IRC routine asked to terminate +2024/03/25 22:35:43.727205 irc.go:280: INFO IRC shutdown complete +2024/03/25 22:35:43.727272 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.727363 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:35722->127.0.0.1:44329: use of closed network connection +2024/03/25 22:35:43.727418 irc.go:150: INFO Disconnected from IRC +2024/03/25 22:35:43.727469 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:35722 disconnected +2024/03/25 22:35:43.727569 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestStopRunningWhenHalfConnected (0.00s) === RUN TestPreJoinChannels -2024/03/24 20:30:57.534778 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:44849 -2024/03/24 20:30:57.534886 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:44849. -2024/03/24 20:30:57.535135 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:48414 -2024/03/24 20:30:57.535306 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.535351 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.535375 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.535575 reconciler.go:103: INFO Channel #baz monitor: waiting to join -2024/03/24 20:30:57.535611 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.535625 reconciler.go:103: INFO Channel #bar monitor: waiting to join -2024/03/24 20:30:57.535650 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.535675 reconciler.go:112: INFO Channel #bar monitor: join request sent -2024/03/24 20:30:57.535619 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.535717 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.535743 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.535634 reconciler.go:112: INFO Channel #baz monitor: join request sent -2024/03/24 20:30:57.535814 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz -2024/03/24 20:30:57.535857 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.535890 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz -2024/03/24 20:30:57.535974 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar -2024/03/24 20:30:57.536015 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.536026 reconciler.go:201: INFO Received JOIN confirmation for channel #baz -2024/03/24 20:30:57.536047 reconciler.go:77: INFO Setting JOIN state on channel #baz -2024/03/24 20:30:57.536045 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar -2024/03/24 20:30:57.536085 reconciler.go:116: INFO Channel #baz monitor: join succeeded -2024/03/24 20:30:57.536128 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.536165 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.536189 reconciler.go:201: INFO Received JOIN confirmation for channel #bar -2024/03/24 20:30:57.536194 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.536208 reconciler.go:77: INFO Setting JOIN state on channel #bar -2024/03/24 20:30:57.536235 reconciler.go:116: INFO Channel #bar monitor: join succeeded -2024/03/24 20:30:57.536346 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.536376 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.536396 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.536404 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.536465 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/03/24 20:30:57.536506 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.536735 reconciler.go:129: INFO Channel #baz monitor: context canceled while monitoring -2024/03/24 20:30:57.536777 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/03/24 20:30:57.536811 reconciler.go:129: INFO Channel #bar monitor: context canceled while monitoring -2024/03/24 20:30:57.536909 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.727785 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39985 +2024/03/25 22:35:43.727858 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39985. +2024/03/25 22:35:43.728074 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:37768 +2024/03/25 22:35:43.728332 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.728383 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.728407 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.728567 reconciler.go:103: INFO Channel #baz monitor: waiting to join +2024/03/25 22:35:43.728604 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.728630 reconciler.go:112: INFO Channel #baz monitor: join request sent +2024/03/25 22:35:43.728715 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.728743 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.728785 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.728859 reconciler.go:103: INFO Channel #bar monitor: waiting to join +2024/03/25 22:35:43.728885 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.728908 reconciler.go:112: INFO Channel #bar monitor: join request sent +2024/03/25 22:35:43.729008 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz +2024/03/25 22:35:43.729051 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.729070 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz +2024/03/25 22:35:43.729126 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.729158 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.729174 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.729222 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar +2024/03/25 22:35:43.729249 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.729265 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar +2024/03/25 22:35:43.729393 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.729499 reconciler.go:201: INFO Received JOIN confirmation for channel #baz +2024/03/25 22:35:43.729505 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.729541 reconciler.go:77: INFO Setting JOIN state on channel #baz +2024/03/25 22:35:43.729573 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.729595 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.729625 reconciler.go:201: INFO Received JOIN confirmation for channel #bar +2024/03/25 22:35:43.729630 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.729673 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/03/25 22:35:43.729648 reconciler.go:77: INFO Setting JOIN state on channel #bar +2024/03/25 22:35:43.729658 reconciler.go:116: INFO Channel #baz monitor: join succeeded +2024/03/25 22:35:43.729765 reconciler.go:116: INFO Channel #bar monitor: join succeeded +2024/03/25 22:35:43.729805 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/03/25 22:35:43.729811 reconciler.go:129: INFO Channel #baz monitor: context canceled while monitoring +2024/03/25 22:35:43.729934 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestPreJoinChannels (0.00s) === RUN TestKeepJoining -2024/03/24 20:30:57.537160 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36759 -2024/03/24 20:30:57.537239 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36759. -2024/03/24 20:30:57.537471 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:35936 -2024/03/24 20:30:57.537634 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.537685 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.537709 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.537863 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.537902 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.537941 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.538099 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.538144 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.538161 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.538209 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2024/03/24 20:30:57.538234 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.538248 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.538285 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.538468 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.538517 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.538536 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.538581 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2024/03/24 20:30:57.538607 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.538621 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.538656 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.538795 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.538846 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.538864 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.539009 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.539059 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.539065 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.539094 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.539129 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/03/24 20:30:57.539171 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.539388 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/03/24 20:30:57.539468 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.730217 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:40915 +2024/03/25 22:35:43.730322 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:40915. +2024/03/25 22:35:43.730606 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:33732 +2024/03/25 22:35:43.730788 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.730840 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.730868 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.731018 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.731052 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.731077 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.731208 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.731258 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.731277 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.731342 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2024/03/25 22:35:43.731370 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.731385 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.731425 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.731527 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.731574 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.731643 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.731699 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2024/03/25 22:35:43.731729 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.731757 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.731793 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.731953 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.732012 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.732043 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.732256 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.732328 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.732496 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.732558 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.732597 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.732629 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/03/25 22:35:43.732703 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestKeepJoining (0.00s) === RUN TestKickRejoin -2024/03/24 20:30:57.539673 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:32973 -2024/03/24 20:30:57.539752 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:32973. -2024/03/24 20:30:57.539991 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:41794 -2024/03/24 20:30:57.540168 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/03/24 20:30:57.540218 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/03/24 20:30:57.540242 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/03/24 20:30:57.540423 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.540459 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.540499 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.540663 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.540708 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.540726 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.540789 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! -2024/03/24 20:30:57.540857 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.540887 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.540964 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/03/24 20:30:57.540971 reconciler.go:219: INFO Received KICK for channel #foo -2024/03/24 20:30:57.541003 reconciler.go:91: INFO Removing JOIN state on channel #foo -2024/03/24 20:30:57.541059 reconciler.go:127: INFO Channel #foo monitor: channel no longer joined -2024/03/24 20:30:57.541087 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/03/24 20:30:57.541102 fake_delayer.go:43: INFO Faking Backoff -2024/03/24 20:30:57.541143 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/03/24 20:30:57.541277 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/03/24 20:30:57.541325 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/03/24 20:30:57.541383 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/03/24 20:30:57.541531 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/03/24 20:30:57.541564 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/03/24 20:30:57.541581 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/03/24 20:30:57.541593 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/03/24 20:30:57.541626 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/03/24 20:30:57.541673 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/03/24 20:30:57.541867 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/03/24 20:30:57.541958 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/03/25 22:35:43.732923 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39343 +2024/03/25 22:35:43.733023 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39343. +2024/03/25 22:35:43.733258 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:52664 +2024/03/25 22:35:43.733379 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/03/25 22:35:43.733420 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/03/25 22:35:43.733504 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/03/25 22:35:43.733670 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.733708 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.733744 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.733869 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.733915 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.733959 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.734079 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! +2024/03/25 22:35:43.734129 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.734169 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.734197 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/03/25 22:35:43.734276 reconciler.go:219: INFO Received KICK for channel #foo +2024/03/25 22:35:43.734316 reconciler.go:91: INFO Removing JOIN state on channel #foo +2024/03/25 22:35:43.734355 reconciler.go:127: INFO Channel #foo monitor: channel no longer joined +2024/03/25 22:35:43.734380 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/03/25 22:35:43.734395 fake_delayer.go:43: INFO Faking Backoff +2024/03/25 22:35:43.734430 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/03/25 22:35:43.734528 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/03/25 22:35:43.734571 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/03/25 22:35:43.734624 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/03/25 22:35:43.734817 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/03/25 22:35:43.734886 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/03/25 22:35:43.735049 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/03/25 22:35:43.735124 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/03/25 22:35:43.735161 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/03/25 22:35:43.735237 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/03/25 22:35:43.735332 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.057s +ok github.com/google/alertmanager-irc-relay 0.068s create-stamp debian/debhelper-build-stamp fakeroot debian/rules binary dh binary --buildsystem=golang --with=golang @@ -1881,12 +1917,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/27731/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/27731/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/10757 and its subdirectories -I: Current time: Sun Mar 24 20:31:22 -12 2024 -I: pbuilder-time-stamp: 1711355482 +I: removing directory /srv/workspace/pbuilder/27731 and its subdirectories +I: Current time: Mon Mar 25 22:36:11 +14 2024 +I: pbuilder-time-stamp: 1711355771