Diff of the two buildlogs: -- --- b1/build.log 2024-04-20 09:19:34.200131628 +0000 +++ b2/build.log 2024-04-20 09:28:48.764471570 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Fri Apr 19 21:05:42 -12 2024 -I: pbuilder-time-stamp: 1713603942 +I: Current time: Sat Apr 20 23:19:43 +14 2024 +I: pbuilder-time-stamp: 1713604783 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/unstable-reproducible-base.tgz] I: copying local configuration @@ -26,52 +26,84 @@ dpkg-source: info: unpacking alertmanager-irc-relay_0.4.2-1.debian.tar.xz I: using fakeroot in build. I: Installing the build-deps -I: user script /srv/workspace/pbuilder/15496/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/22883/tmp/hooks/D01_modify_environment starting +debug: Running on virt64c. +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 Apr 20 09:20 /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/22883/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/22883/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='unstable' - 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=unstable + EUID=0 + FUNCNAME=([0]="Echo" [1]="main") + GROUPS=() + HOME=/root + HOSTNAME=i-capture-the-hostname + HOSTTYPE=arm + HOST_ARCH=armhf IFS=' ' - INVOCATION_ID='55d9703aa9e24c76b284501bff15214b' - 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='15496' - PS1='# ' - PS2='> ' + INVOCATION_ID=183525d6106a41ff90223ddcc82cfc77 + 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=22883 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.2FcVuZWr/pbuilderrc_pyNE --distribution unstable --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/unstable-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.2FcVuZWr/b1 --logfile b1/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+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.2FcVuZWr/pbuilderrc_3fGx --distribution unstable --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/unstable-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.2FcVuZWr/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 virt32a 6.1.0-20-armmp-lpae #1 SMP Debian 6.1.85-1 (2024-04-11) armv7l GNU/Linux + Linux i-capture-the-hostname 6.1.0-20-arm64 #1 SMP Debian 6.1.85-1 (2024-04-11) aarch64 GNU/Linux I: ls -l /bin - lrwxrwxrwx 1 root root 7 Apr 20 07:44 /bin -> usr/bin -I: user script /srv/workspace/pbuilder/15496/tmp/hooks/D02_print_environment finished + lrwxrwxrwx 1 root root 7 Apr 17 07:43 /bin -> usr/bin +I: user script /srv/workspace/pbuilder/22883/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 unstable/main armhf golang-gopkg-telebot.v3-dev all 3.2.1-1 [95.0 kB] Get: 188 http://deb.debian.org/debian unstable/main armhf golang-protobuf-extensions-dev all 1.0.4-2 [29.7 kB] Get: 189 http://deb.debian.org/debian unstable/main armhf golang-github-prometheus-alertmanager-dev all 0.27.0+ds-2 [1116 kB] -Fetched 133 MB in 10s (13.8 MB/s) +Fetched 133 MB in 10s (13.0 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 ... 19442 files and directories currently installed.) @@ -930,8 +962,8 @@ Setting up tzdata (2024a-3) ... Current default time zone: 'Etc/UTC' -Local time is now: Sat Apr 20 09:11:18 UTC 2024. -Universal Time is now: Sat Apr 20 09:11:18 UTC 2024. +Local time is now: Sat Apr 20 09:23:06 UTC 2024. +Universal Time is now: Sat Apr 20 09:23:06 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/22883/tmp/hooks/A99_set_merged_usr starting +Not re-configuring usrmerge for unstable +I: user script /srv/workspace/pbuilder/22883/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,33 +1146,32 @@ 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/unsafeheader internal/goarch -internal/cpu internal/coverage/rtcov -internal/abi -internal/chacha8rand -internal/bytealg +internal/cpu internal/godebugs internal/goexperiment +internal/abi +internal/chacha8rand internal/goos -runtime/internal/atomic runtime/internal/math runtime/internal/sys +internal/bytealg +runtime/internal/atomic runtime/internal/syscall internal/race sync/atomic unicode unicode/utf8 -runtime internal/itoa container/list math/bits crypto/internal/alias -math crypto/internal/boring/sig cmp +math slices unicode/utf16 vendor/golang.org/x/crypto/cryptobyte/asn1 @@ -1144,100 +1179,101 @@ vendor/golang.org/x/crypto/internal/alias encoding github.com/fluffle/goirc/logging +runtime log/internal google.golang.org/protobuf/internal/flags google.golang.org/protobuf/internal/set -internal/reflectlite -crypto/subtle sync +crypto/subtle runtime/metrics +internal/reflectlite internal/testlog internal/bisect internal/singleflight +google.golang.org/protobuf/internal/pragma runtime/cgo -internal/godebug errors +sort +internal/godebug io -internal/oserror bytes -syscall hash +internal/oserror +syscall strconv +crypto/internal/nistec/fiat crypto reflect time -encoding/binary -context -crypto/cipher -crypto/internal/edwards25519/field -crypto/internal/boring -crypto/des -crypto/aes -crypto/internal/nistec/fiat crypto/internal/randutil -sort -internal/fmtsort +context internal/syscall/unix internal/poll internal/safefilepath +crypto/internal/nistec internal/syscall/execenv path -crypto/internal/nistec io/fs -os -crypto/ecdh math/rand -fmt +os +encoding/binary +internal/fmtsort strings +crypto/rc4 +vendor/golang.org/x/net/dns/dnsmessage +crypto/cipher +crypto/internal/edwards25519/field +fmt +crypto/internal/boring +crypto/aes +crypto/des +crypto/ecdh crypto/sha512 crypto/internal/edwards25519 -math/big crypto/hmac crypto/md5 -crypto/rc4 crypto/sha1 -crypto/elliptic -crypto/internal/bigmod -crypto/internal/boring/bbig -encoding/asn1 -crypto/rand -crypto/ed25519 -vendor/golang.org/x/crypto/cryptobyte -crypto/rsa crypto/sha256 -crypto/ecdsa -crypto/dsa -encoding/hex -crypto/x509/pkix encoding/base64 -vendor/golang.org/x/net/dns/dnsmessage -encoding/pem internal/intern -net/netip -net/url path/filepath +net/netip +encoding/pem vendor/golang.org/x/crypto/chacha20 +math/big +encoding/hex +net/url vendor/golang.org/x/crypto/internal/poly1305 -vendor/golang.org/x/crypto/hkdf -encoding/json vendor/golang.org/x/crypto/chacha20poly1305 net +vendor/golang.org/x/crypto/hkdf +encoding/json flag bufio github.com/golang/mock/gomock -github.com/fluffle/goirc/state log -compress/flate +crypto/elliptic +crypto/internal/bigmod +crypto/internal/boring/bbig +encoding/asn1 +crypto/rand +crypto/ed25519 +crypto/rsa +crypto/dsa +github.com/fluffle/goirc/state +vendor/golang.org/x/crypto/cryptobyte +crypto/x509/pkix github.com/google/alertmanager-irc-relay/logging +compress/flate hash/crc32 vendor/golang.org/x/text/transform +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 @@ -1247,96 +1283,96 @@ google.golang.org/protobuf/internal/detrand google.golang.org/protobuf/internal/errors google.golang.org/protobuf/encoding/protowire -regexp -google.golang.org/protobuf/internal/pragma +vendor/golang.org/x/net/idna google.golang.org/protobuf/reflect/protoreflect -github.com/go-kit/log -github.com/go-kit/log/level +regexp google.golang.org/protobuf/internal/descfmt -github.com/prometheus/alertmanager/featurecontrol google.golang.org/protobuf/internal/descopts +github.com/go-kit/log embed -go/token google.golang.org/protobuf/internal/editiondefaults -google.golang.org/protobuf/internal/strs +go/token +github.com/go-kit/log/level google.golang.org/protobuf/internal/encoding/messageset -google.golang.org/protobuf/internal/genid +google.golang.org/protobuf/internal/strs +github.com/prometheus/alertmanager/featurecontrol +google.golang.org/protobuf/internal/encoding/text google.golang.org/protobuf/internal/order +google.golang.org/protobuf/internal/genid google.golang.org/protobuf/reflect/protoregistry -google.golang.org/protobuf/internal/encoding/text google.golang.org/protobuf/runtime/protoiface -google.golang.org/protobuf/internal/encoding/defval io/ioutil -google.golang.org/protobuf/proto 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 +google.golang.org/protobuf/encoding/prototext crypto/x509 golang.org/x/net/internal/socks golang.org/x/net/proxy -crypto/tls net/textproto vendor/golang.org/x/net/http/httpproxy vendor/golang.org/x/net/http/httpguts mime/multipart -google.golang.org/protobuf/internal/filedesc -google.golang.org/protobuf/encoding/prototext -github.com/fluffle/goirc/client -net/http/httptrace -net/http -github.com/beorn7/perks/quantile google.golang.org/protobuf/internal/encoding/tag -github.com/cespare/xxhash -github.com/prometheus/common/internal/bitbucket.org/ww/goautoneg -google.golang.org/protobuf/encoding/protodelim google.golang.org/protobuf/internal/impl -github.com/prometheus/procfs/internal/fs -github.com/prometheus/procfs/internal/util -golang.org/x/sys/unix +google.golang.org/protobuf/encoding/protodelim +golang.org/x/text/internal/language/compact +golang.org/x/text/language +crypto/tls github.com/prometheus/procfs -github.com/gorilla/mux +golang.org/x/text/internal +golang.org/x/text/transform +golang.org/x/text/unicode/norm +golang.org/x/text/cases +html +text/template/parse +gopkg.in/yaml.v2 +github.com/fluffle/goirc/client +net/http/httptrace google.golang.org/protobuf/internal/filetype +net/http google.golang.org/protobuf/runtime/protoimpl -expvar google.golang.org/protobuf/types/known/timestamppb -golang.org/x/text/internal/tag github.com/prometheus/client_model/go -golang.org/x/text/internal/language +text/template github.com/prometheus/common/model -golang.org/x/text/internal/language/compact -golang.org/x/text/language +os/signal github.com/prometheus/alertmanager/pkg/labels -github.com/prometheus/alertmanager/matchers/parse github.com/prometheus/client_golang/prometheus/internal +html/template +github.com/prometheus/alertmanager/matchers/parse github.com/prometheus/alertmanager/matchers/compat +expvar github.com/prometheus/common/expfmt -golang.org/x/text/internal -golang.org/x/text/transform -html -golang.org/x/text/unicode/norm -text/template/parse +github.com/gorilla/mux github.com/prometheus/client_golang/prometheus -text/template -golang.org/x/text/cases -gopkg.in/yaml.v2 -html/template github.com/prometheus/alertmanager/types github.com/prometheus/client_golang/prometheus/promauto github.com/prometheus/client_golang/prometheus/promhttp github.com/prometheus/alertmanager/template -os/signal 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/04/19 21:18:32.376168 backoff.go:111: INFO Backoff for 0s starts -2024/04/19 21:18:32.376440 backoff.go:114: INFO Backoff for 0s ends -2024/04/19 21:18:32.376479 backoff.go:111: INFO Backoff for 2ms starts -2024/04/19 21:18:32.376503 backoff.go:116: INFO Backoff for 2ms canceled by context +2024/04/20 23:27:33.658303 backoff.go:111: INFO Backoff for 0s starts +2024/04/20 23:27:33.658535 backoff.go:114: INFO Backoff for 0s ends +2024/04/20 23:27:33.658568 backoff.go:111: INFO Backoff for 2ms starts +2024/04/20 23:27:33.658591 backoff.go:116: INFO Backoff for 2ms canceled by context --- PASS: TestBackoffDelayContext (0.00s) === RUN TestNoConfig --- PASS: TestNoConfig (0.00s) @@ -1353,12 +1389,12 @@ === RUN TestMsgDefaultTemplate --- PASS: TestMsgDefaultTemplate (0.00s) === RUN TestGivenTemplateNotOverwritten ---- PASS: TestGivenTemplateNotOverwritten (0.00s) +--- PASS: TestGivenTemplateNotOverwritten (0.01s) === RUN TestTemplateErrorsCreateRawAlertMsg -2024/04/19 21:18:32.388536 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/04/19 21:18:32.388592 format.go:61: WARN Sending raw alert -2024/04/19 21:18:32.390099 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/04/19 21:18:32.390148 format.go:61: WARN Sending raw alert +2024/04/20 23:27:33.673261 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/04/20 23:27:33.673303 format.go:61: WARN Sending raw alert +2024/04/20 23:27:33.673425 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/04/20 23:27:33.673455 format.go:61: WARN Sending raw alert --- PASS: TestTemplateErrorsCreateRawAlertMsg (0.00s) === RUN TestAlertsDispatchedOnce --- PASS: TestAlertsDispatchedOnce (0.00s) @@ -1367,483 +1403,482 @@ === RUN TestUrlFunctions --- PASS: TestUrlFunctions (0.00s) === RUN TestAlertsDispatched -2024/04/19 21:18:32.392228 http.go:132: INFO Starting HTTP server +2024/04/20 23:27:33.675203 http.go:132: INFO Starting HTTP server --- PASS: TestAlertsDispatched (0.00s) === RUN TestRootReturnsError -2024/04/19 21:18:32.393513 http.go:132: INFO Starting HTTP server +2024/04/20 23:27:33.676177 http.go:132: INFO Starting HTTP server --- PASS: TestRootReturnsError (0.00s) === RUN TestInvalidDataReturnsError -2024/04/19 21:18:32.394071 http.go:132: INFO Starting HTTP server -2024/04/19 21:18:32.394182 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/04/20 23:27:33.681150 http.go:132: INFO Starting HTTP server +2024/04/20 23:27:33.681274 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/04/19 21:18:32.400436 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33729 -2024/04/19 21:18:32.400640 irc.go:300: INFO Connecting to IRC 127.0.0.1:33729 -2024/04/19 21:18:32.400673 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.400704 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33729. -2024/04/19 21:18:32.401262 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:55194 -2024/04/19 21:18:32.401632 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.401899 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret -2024/04/19 21:18:32.401950 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping -2024/04/19 21:18:32.401970 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.401990 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.402007 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.402156 irc.go:144: INFO Session established -2024/04/19 21:18:32.402231 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.402255 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.402284 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.402414 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.402456 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.402473 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.402518 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/04/19 21:18:32.402547 irc.go:294: INFO IRC routine asked to terminate -2024/04/19 21:18:32.402567 irc.go:269: INFO IRC client connected, quitting -2024/04/19 21:18:32.402588 irc.go:272: INFO Wait for IRC disconnect to complete -2024/04/19 21:18:32.402679 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.402741 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.402885 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.403121 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.403190 irc.go:280: INFO IRC shutdown complete -2024/04/19 21:18:32.403262 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections ---- PASS: TestServerPassword (0.01s) +2024/04/20 23:27:33.681971 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:45153 +2024/04/20 23:27:33.682097 irc.go:300: INFO Connecting to IRC 127.0.0.1:45153 +2024/04/20 23:27:33.682126 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.682155 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:45153. +2024/04/20 23:27:33.682630 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:42436 +2024/04/20 23:27:33.684596 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.684885 irc_server_for_test.go:119: INFO =Server= Received PASS hostsecret +2024/04/20 23:27:33.684932 irc_server_for_test.go:96: INFO =Server= No handler for command 'PASS', skipping +2024/04/20 23:27:33.684952 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.684976 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.684992 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.685159 irc.go:144: INFO Session established +2024/04/20 23:27:33.685231 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.685252 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.685279 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.685448 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.685487 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.685514 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.685559 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/04/20 23:27:33.685586 irc.go:294: INFO IRC routine asked to terminate +2024/04/20 23:27:33.685605 irc.go:269: INFO IRC client connected, quitting +2024/04/20 23:27:33.685626 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/20 23:27:33.685715 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.685757 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.685905 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.686075 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.686114 irc.go:280: INFO IRC shutdown complete +2024/04/20 23:27:33.686174 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +--- PASS: TestServerPassword (0.00s) === RUN TestSendAlertOnPreJoinedChannel -2024/04/19 21:18:32.403591 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:32997 -2024/04/19 21:18:32.403692 irc.go:300: INFO Connecting to IRC 127.0.0.1:32997 -2024/04/19 21:18:32.403716 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.403744 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:32997. -2024/04/19 21:18:32.404041 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:59156 -2024/04/19 21:18:32.404215 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.404393 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.404467 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.404488 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.404636 irc.go:144: INFO Session established -2024/04/19 21:18:32.404709 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.404731 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.404759 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.404885 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.404930 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.404949 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.405088 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.405122 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.405257 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/04/19 21:18:32.405308 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message -2024/04/19 21:18:32.405360 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/04/19 21:18:32.405386 irc.go:294: INFO IRC routine asked to terminate -2024/04/19 21:18:32.405406 irc.go:269: INFO IRC client connected, quitting -2024/04/19 21:18:32.405478 irc.go:272: INFO Wait for IRC disconnect to complete -2024/04/19 21:18:32.405592 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.405642 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.405777 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.405948 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.407375 irc.go:280: INFO IRC shutdown complete -2024/04/19 21:18:32.407466 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections ---- PASS: TestSendAlertOnPreJoinedChannel (0.00s) +2024/04/20 23:27:33.686409 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41621 +2024/04/20 23:27:33.686509 irc.go:300: INFO Connecting to IRC 127.0.0.1:41621 +2024/04/20 23:27:33.686531 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.686552 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41621. +2024/04/20 23:27:33.686872 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:60726 +2024/04/20 23:27:33.687050 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.687219 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.687259 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.687277 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.687408 irc.go:144: INFO Session established +2024/04/20 23:27:33.687470 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.687490 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.687517 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.687656 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.687694 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.687710 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.687834 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.687862 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.687972 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/20 23:27:33.688041 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :test message +2024/04/20 23:27:33.688092 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/20 23:27:33.688121 irc.go:294: INFO IRC routine asked to terminate +2024/04/20 23:27:33.688139 irc.go:269: INFO IRC client connected, quitting +2024/04/20 23:27:33.688159 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/20 23:27:33.688351 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.688404 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.688557 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.696601 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.696692 irc.go:280: INFO IRC shutdown complete +2024/04/20 23:27:33.696775 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +--- PASS: TestSendAlertOnPreJoinedChannel (0.01s) === RUN TestUsePrivmsgToSendAlertOnPreJoinedChannel -2024/04/19 21:18:32.407762 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:35893 -2024/04/19 21:18:32.407855 irc.go:300: INFO Connecting to IRC 127.0.0.1:35893 -2024/04/19 21:18:32.407878 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.407906 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:35893. -2024/04/19 21:18:32.408266 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:39918 -2024/04/19 21:18:32.408578 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.408783 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.408827 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.408847 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.408991 irc.go:144: INFO Session established -2024/04/19 21:18:32.409059 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.409082 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.409108 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.409238 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.409279 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.409298 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.409429 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.409461 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.409567 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/04/19 21:18:32.409618 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message -2024/04/19 21:18:32.409672 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/04/19 21:18:32.409697 irc.go:294: INFO IRC routine asked to terminate -2024/04/19 21:18:32.409716 irc.go:269: INFO IRC client connected, quitting -2024/04/19 21:18:32.409737 irc.go:272: INFO Wait for IRC disconnect to complete -2024/04/19 21:18:32.409840 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.409887 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.410017 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.410164 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.410204 irc.go:280: INFO IRC shutdown complete -2024/04/19 21:18:32.410261 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections ---- PASS: TestUsePrivmsgToSendAlertOnPreJoinedChannel (0.00s) +2024/04/20 23:27:33.697083 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39475 +2024/04/20 23:27:33.697175 irc.go:300: INFO Connecting to IRC 127.0.0.1:39475 +2024/04/20 23:27:33.697209 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.697238 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39475. +2024/04/20 23:27:33.697633 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:43904 +2024/04/20 23:27:33.700615 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.700883 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.700929 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.700948 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.701103 irc.go:144: INFO Session established +2024/04/20 23:27:33.701176 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.701201 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.701232 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.701409 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.701451 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.701470 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.701609 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.701640 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.701746 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/20 23:27:33.701797 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG #foo :test message +2024/04/20 23:27:33.701851 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/20 23:27:33.701879 irc.go:294: INFO IRC routine asked to terminate +2024/04/20 23:27:33.701898 irc.go:269: INFO IRC client connected, quitting +2024/04/20 23:27:33.701919 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/20 23:27:33.702031 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.702077 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.702222 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.702390 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.702432 irc.go:280: INFO IRC shutdown complete +2024/04/20 23:27:33.702498 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +--- PASS: TestUsePrivmsgToSendAlertOnPreJoinedChannel (0.01s) === RUN TestSendAlertAndJoinChannel -2024/04/19 21:18:32.410513 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38065 -2024/04/19 21:18:32.410653 irc.go:300: INFO Connecting to IRC 127.0.0.1:38065 -2024/04/19 21:18:32.410677 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.410704 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38065. -2024/04/19 21:18:32.411002 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:60964 -2024/04/19 21:18:32.411336 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.411640 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.411714 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.411734 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.411939 irc.go:144: INFO Session established -2024/04/19 21:18:32.412008 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.412028 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.412057 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.412186 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.412229 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.412248 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.412334 reconciler.go:245: INFO Request to JOIN new channel #foobar -2024/04/19 21:18:32.412377 reconciler.go:103: INFO Channel #foobar monitor: waiting to join -2024/04/19 21:18:32.412397 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.412455 reconciler.go:112: INFO Channel #foobar monitor: join request sent -2024/04/19 21:18:32.412607 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar -2024/04/19 21:18:32.412650 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.412669 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar -2024/04/19 21:18:32.412787 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.412818 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.412857 reconciler.go:201: INFO Received JOIN confirmation for channel #foobar -2024/04/19 21:18:32.412876 reconciler.go:77: INFO Setting JOIN state on channel #foobar -2024/04/19 21:18:32.412907 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/04/19 21:18:32.412936 reconciler.go:116: INFO Channel #foobar monitor: join succeeded -2024/04/19 21:18:32.413080 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message -2024/04/19 21:18:32.413142 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/04/19 21:18:32.413167 irc.go:294: INFO IRC routine asked to terminate -2024/04/19 21:18:32.413185 irc.go:269: INFO IRC client connected, quitting -2024/04/19 21:18:32.413207 irc.go:272: INFO Wait for IRC disconnect to complete -2024/04/19 21:18:32.413280 reconciler.go:129: INFO Channel #foobar monitor: context canceled while monitoring -2024/04/19 21:18:32.413348 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.413388 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.413526 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.413680 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.413721 irc.go:280: INFO IRC shutdown complete -2024/04/19 21:18:32.413782 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections ---- PASS: TestSendAlertAndJoinChannel (0.00s) +2024/04/20 23:27:33.702825 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33841 +2024/04/20 23:27:33.702931 irc.go:300: INFO Connecting to IRC 127.0.0.1:33841 +2024/04/20 23:27:33.702956 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.702982 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33841. +2024/04/20 23:27:33.703284 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:58536 +2024/04/20 23:27:33.703481 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.703654 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.703694 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.703713 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.703854 irc.go:144: INFO Session established +2024/04/20 23:27:33.703920 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.703942 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.703969 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.704107 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.704147 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.704166 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.704367 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.704400 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.704461 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/20 23:27:33.704500 reconciler.go:245: INFO Request to JOIN new channel #foobar +2024/04/20 23:27:33.704536 reconciler.go:103: INFO Channel #foobar monitor: waiting to join +2024/04/20 23:27:33.704554 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.704579 reconciler.go:112: INFO Channel #foobar monitor: join request sent +2024/04/20 23:27:33.707840 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foobar +2024/04/20 23:27:33.707904 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.707926 irc_server_for_test.go:119: INFO =Server= Received JOIN #foobar +2024/04/20 23:27:33.708158 reconciler.go:201: INFO Received JOIN confirmation for channel #foobar +2024/04/20 23:27:33.708199 reconciler.go:77: INFO Setting JOIN state on channel #foobar +2024/04/20 23:27:33.708286 reconciler.go:116: INFO Channel #foobar monitor: join succeeded +2024/04/20 23:27:33.708368 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foobar :test message +2024/04/20 23:27:33.708433 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/20 23:27:33.708447 irc.go:294: INFO IRC routine asked to terminate +2024/04/20 23:27:33.708467 reconciler.go:129: INFO Channel #foobar monitor: context canceled while monitoring +2024/04/20 23:27:33.708468 irc.go:269: INFO IRC client connected, quitting +2024/04/20 23:27:33.708498 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/20 23:27:33.712348 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.712425 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.712585 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.712759 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.712803 irc.go:280: INFO IRC shutdown complete +2024/04/20 23:27:33.712863 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +--- PASS: TestSendAlertAndJoinChannel (0.01s) === RUN TestSendAlertDisconnected -2024/04/19 21:18:32.414039 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39707 -2024/04/19 21:18:32.414126 irc.go:300: INFO Connecting to IRC 127.0.0.1:39707 -2024/04/19 21:18:32.414148 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.414173 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39707. -2024/04/19 21:18:32.414468 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:56786 -2024/04/19 21:18:32.414627 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.414795 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.414839 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.414865 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.414888 irc_test.go:292: INFO =Server= Wait before completing session -2024/04/19 21:18:32.414905 irc_test.go:294: INFO =Server= Completing session -2024/04/19 21:18:32.415230 irc.go:144: INFO Session established -2024/04/19 21:18:32.415341 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.415366 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.415394 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.415541 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.415592 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.415612 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.415846 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.415904 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.416028 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/04/19 21:18:32.416131 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message -2024/04/19 21:18:32.416238 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/04/19 21:18:32.416277 irc.go:294: INFO IRC routine asked to terminate -2024/04/19 21:18:32.416298 irc.go:269: INFO IRC client connected, quitting -2024/04/19 21:18:32.416320 irc.go:272: INFO Wait for IRC disconnect to complete -2024/04/19 21:18:32.416468 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.416517 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.416654 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.416819 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.416865 irc.go:280: INFO IRC shutdown complete -2024/04/19 21:18:32.416927 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/20 23:27:33.713120 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36451 +2024/04/20 23:27:33.713208 irc.go:300: INFO Connecting to IRC 127.0.0.1:36451 +2024/04/20 23:27:33.713230 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.713256 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36451. +2024/04/20 23:27:33.713602 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:33696 +2024/04/20 23:27:33.713775 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.713971 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.714011 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.714029 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.714050 irc_test.go:292: INFO =Server= Wait before completing session +2024/04/20 23:27:33.714067 irc_test.go:294: INFO =Server= Completing session +2024/04/20 23:27:33.714222 irc.go:144: INFO Session established +2024/04/20 23:27:33.714287 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.714307 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.714333 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.714461 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.714500 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.714518 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.714651 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.714679 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.714780 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/20 23:27:33.714830 irc_server_for_test.go:119: INFO =Server= Received NOTICE #foo :connected test message +2024/04/20 23:27:33.714877 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/20 23:27:33.714929 irc.go:294: INFO IRC routine asked to terminate +2024/04/20 23:27:33.714950 irc.go:269: INFO IRC client connected, quitting +2024/04/20 23:27:33.714971 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/20 23:27:33.715078 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.715121 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.715243 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.715392 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.715438 irc.go:280: INFO IRC shutdown complete +2024/04/20 23:27:33.715502 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestSendAlertDisconnected (0.00s) === RUN TestReconnect -2024/04/19 21:18:32.417218 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33847 -2024/04/19 21:18:32.417317 irc.go:300: INFO Connecting to IRC 127.0.0.1:33847 -2024/04/19 21:18:32.417342 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.417370 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33847. -2024/04/19 21:18:32.417707 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:46844 -2024/04/19 21:18:32.417883 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.418062 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.418108 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.418127 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.418266 irc.go:144: INFO Session established -2024/04/19 21:18:32.418341 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.418366 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.418397 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.418524 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.418567 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.418601 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.418795 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:46844: read tcp 127.0.0.1:33847->127.0.0.1:46844: use of closed network connection -2024/04/19 21:18:32.418913 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.419622 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.419685 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.419728 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/04/19 21:18:32.419874 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.419931 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/04/19 21:18:32.419964 irc.go:300: INFO Connecting to IRC 127.0.0.1:33847 -2024/04/19 21:18:32.419983 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.420010 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33847. -2024/04/19 21:18:32.420460 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.420692 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:46856 -2024/04/19 21:18:32.420759 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.420795 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.420816 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.420962 irc.go:144: INFO Session established -2024/04/19 21:18:32.421034 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.421055 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.421083 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.421213 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.421256 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.421277 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.421372 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/04/19 21:18:32.421409 irc.go:294: INFO IRC routine asked to terminate -2024/04/19 21:18:32.421429 irc.go:269: INFO IRC client connected, quitting -2024/04/19 21:18:32.421450 irc.go:272: INFO Wait for IRC disconnect to complete -2024/04/19 21:18:32.421551 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.421601 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.421763 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.421925 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.421957 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.422001 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.422040 irc.go:280: INFO IRC shutdown complete -2024/04/19 21:18:32.422107 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/20 23:27:33.715708 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:43813 +2024/04/20 23:27:33.715783 irc.go:300: INFO Connecting to IRC 127.0.0.1:43813 +2024/04/20 23:27:33.715802 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.715823 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43813. +2024/04/20 23:27:33.716088 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:46190 +2024/04/20 23:27:33.720350 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.720665 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.720713 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.720732 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.720914 irc.go:144: INFO Session established +2024/04/20 23:27:33.720986 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.721006 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.721033 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.721155 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.721190 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.721209 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.721426 irc_server_for_test.go:115: INFO =Server= Could not read from 127.0.0.1:46190: read tcp 127.0.0.1:43813->127.0.0.1:46190: use of closed network connection +2024/04/20 23:27:33.721544 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.721701 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.721734 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.721776 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.721807 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/20 23:27:33.721845 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/20 23:27:33.721870 irc.go:300: INFO Connecting to IRC 127.0.0.1:43813 +2024/04/20 23:27:33.721885 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.721946 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:43813. +2024/04/20 23:27:33.722300 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.722511 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:46202 +2024/04/20 23:27:33.722584 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.722617 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.722636 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.722772 irc.go:144: INFO Session established +2024/04/20 23:27:33.722835 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.722852 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.722874 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.722992 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.723027 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.723060 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.723139 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/04/20 23:27:33.723164 irc.go:294: INFO IRC routine asked to terminate +2024/04/20 23:27:33.723181 irc.go:269: INFO IRC client connected, quitting +2024/04/20 23:27:33.723221 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/20 23:27:33.723354 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.723397 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.723531 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.723802 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.723838 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.723884 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.723921 irc.go:280: INFO IRC shutdown complete +2024/04/20 23:27:33.724013 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestReconnect (0.01s) === RUN TestConnectErrorRetry -2024/04/19 21:18:32.422394 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42483 -2024/04/19 21:18:32.422491 irc.go:300: INFO Connecting to IRC 127.0.0.1:42483 -2024/04/19 21:18:32.422514 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.422531 fake_delayer.go:45: INFO Waiting StopDelay signal -2024/04/19 21:18:32.422549 fake_delayer.go:47: INFO Received StopDelay signal -2024/04/19 21:18:32.422573 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42483. -2024/04/19 21:18:32.422895 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:54264 -2024/04/19 21:18:32.422927 irc_server_for_test.go:157: INFO =Server= Closing connection early -2024/04/19 21:18:32.423312 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.423544 connection.go:444: ERROR irc.send(): write tcp 127.0.0.1:54264->127.0.0.1:42483: write: broken pipe -2024/04/19 21:18:32.423576 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.423648 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:54264->127.0.0.1:42483: use of closed network connection -2024/04/19 21:18:32.423722 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.423762 irc.go:319: WARN Receiving a session down before the session is up, this is odd -2024/04/19 21:18:32.423786 irc.go:300: INFO Connecting to IRC 127.0.0.1:42483 -2024/04/19 21:18:32.423803 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.423819 fake_delayer.go:45: INFO Waiting StopDelay signal -2024/04/19 21:18:32.423836 fake_delayer.go:47: INFO Received StopDelay signal -2024/04/19 21:18:32.423861 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42483. -2024/04/19 21:18:32.424297 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.424553 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:54278 -2024/04/19 21:18:32.424614 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.424649 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.424669 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.427362 irc.go:144: INFO Session established -2024/04/19 21:18:32.427489 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.427519 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.427555 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.427757 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.427803 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.427823 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.427919 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/04/19 21:18:32.427949 irc.go:294: INFO IRC routine asked to terminate -2024/04/19 21:18:32.427969 irc.go:269: INFO IRC client connected, quitting -2024/04/19 21:18:32.427989 irc.go:272: INFO Wait for IRC disconnect to complete -2024/04/19 21:18:32.428102 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.428150 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.428335 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.428541 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.428576 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.428619 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.428656 irc.go:280: INFO IRC shutdown complete -2024/04/19 21:18:32.428723 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/20 23:27:33.724395 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41877 +2024/04/20 23:27:33.724515 irc.go:300: INFO Connecting to IRC 127.0.0.1:41877 +2024/04/20 23:27:33.724540 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.724556 fake_delayer.go:45: INFO Waiting StopDelay signal +2024/04/20 23:27:33.724573 fake_delayer.go:47: INFO Received StopDelay signal +2024/04/20 23:27:33.724609 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41877. +2024/04/20 23:27:33.724927 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:46834 +2024/04/20 23:27:33.724958 irc_server_for_test.go:157: INFO =Server= Closing connection early +2024/04/20 23:27:33.728499 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.728722 connection.go:444: ERROR irc.send(): write tcp 127.0.0.1:46834->127.0.0.1:41877: write: broken pipe +2024/04/20 23:27:33.728753 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.728837 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:46834->127.0.0.1:41877: use of closed network connection +2024/04/20 23:27:33.728900 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.728938 irc.go:319: WARN Receiving a session down before the session is up, this is odd +2024/04/20 23:27:33.728961 irc.go:300: INFO Connecting to IRC 127.0.0.1:41877 +2024/04/20 23:27:33.728977 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.728994 fake_delayer.go:45: INFO Waiting StopDelay signal +2024/04/20 23:27:33.729013 fake_delayer.go:47: INFO Received StopDelay signal +2024/04/20 23:27:33.729039 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41877. +2024/04/20 23:27:33.729424 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.729642 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:46842 +2024/04/20 23:27:33.729723 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.729759 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.729779 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.729957 irc.go:144: INFO Session established +2024/04/20 23:27:33.730025 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.730043 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.730073 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.730217 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.730259 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.730277 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.730367 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/04/20 23:27:33.730399 irc.go:294: INFO IRC routine asked to terminate +2024/04/20 23:27:33.730418 irc.go:269: INFO IRC client connected, quitting +2024/04/20 23:27:33.730439 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/20 23:27:33.730551 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.730596 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.730748 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.730896 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.730926 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.730965 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.730996 irc.go:280: INFO IRC shutdown complete +2024/04/20 23:27:33.731060 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestConnectErrorRetry (0.01s) === RUN TestIdentify -2024/04/19 21:18:32.429022 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41891 -2024/04/19 21:18:32.429138 irc.go:300: INFO Connecting to IRC 127.0.0.1:41891 -2024/04/19 21:18:32.429158 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.429185 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41891. -2024/04/19 21:18:32.429601 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.429579 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:47938 -2024/04/19 21:18:32.429811 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.429935 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.430115 irc.go:165: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. -2024/04/19 21:18:32.430196 irc.go:189: INFO Handling NickServ request to IDENTIFY -2024/04/19 21:18:32.430297 irc.go:144: INFO Session established -2024/04/19 21:18:32.430424 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request -2024/04/19 21:18:32.430482 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.430502 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.430531 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.435272 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword -2024/04/19 21:18:32.435386 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.435419 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.435444 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.435462 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.435612 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/04/19 21:18:32.435657 irc.go:294: INFO IRC routine asked to terminate -2024/04/19 21:18:32.435677 irc.go:269: INFO IRC client connected, quitting -2024/04/19 21:18:32.435698 irc.go:272: INFO Wait for IRC disconnect to complete -2024/04/19 21:18:32.435824 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.435876 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.436043 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.436226 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.436257 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.436307 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.436345 irc.go:280: INFO IRC shutdown complete -2024/04/19 21:18:32.436435 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/20 23:27:33.731325 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:34629 +2024/04/20 23:27:33.731411 irc.go:300: INFO Connecting to IRC 127.0.0.1:34629 +2024/04/20 23:27:33.731434 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.731459 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:34629. +2024/04/20 23:27:33.731742 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:32804 +2024/04/20 23:27:33.731919 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.732088 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.732370 irc.go:165: INFO Received NOTICE from NickServ: This nickname is registered. Please choose a different nickname, or identify yourself ktnxbye. +2024/04/20 23:27:33.732466 irc.go:189: INFO Handling NickServ request to IDENTIFY +2024/04/20 23:27:33.732643 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.732741 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :IDENTIFY nickpassword +2024/04/20 23:27:33.732773 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.736424 irc.go:144: INFO Session established +2024/04/20 23:27:33.736509 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request +2024/04/20 23:27:33.736561 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.736583 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.736612 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.736786 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.736829 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.736847 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.736936 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/04/20 23:27:33.736968 irc.go:294: INFO IRC routine asked to terminate +2024/04/20 23:27:33.736987 irc.go:269: INFO IRC client connected, quitting +2024/04/20 23:27:33.737006 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/20 23:27:33.737115 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.737158 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.737328 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.737518 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.737549 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.737589 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.737621 irc.go:280: INFO IRC shutdown complete +2024/04/20 23:27:33.737683 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestIdentify (0.01s) === RUN TestGhost -2024/04/19 21:18:32.436751 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:39041 -2024/04/19 21:18:32.436853 irc.go:300: INFO Connecting to IRC 127.0.0.1:39041 -2024/04/19 21:18:32.436892 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.436925 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:39041. -2024/04/19 21:18:32.437421 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.437659 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:51140 -2024/04/19 21:18:32.437747 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.437783 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.437941 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' -2024/04/19 21:18:32.438047 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ -2024/04/19 21:18:32.438174 irc.go:144: INFO Session established -2024/04/19 21:18:32.438224 irc.go:204: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' -2024/04/19 21:18:32.438252 irc.go:210: INFO Changing nick to 'foo' -2024/04/19 21:18:32.438273 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request -2024/04/19 21:18:32.438342 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.438369 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.438395 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.438581 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword -2024/04/19 21:18:32.438624 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.438643 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.438667 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.438687 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.438705 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.438797 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join -2024/04/19 21:18:32.438831 irc.go:294: INFO IRC routine asked to terminate -2024/04/19 21:18:32.438850 irc.go:269: INFO IRC client connected, quitting -2024/04/19 21:18:32.438870 irc.go:272: INFO Wait for IRC disconnect to complete -2024/04/19 21:18:32.438981 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.439029 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.439217 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.439396 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.439443 irc.go:280: INFO IRC shutdown complete -2024/04/19 21:18:32.439506 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/20 23:27:33.737936 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:42955 +2024/04/20 23:27:33.738017 irc.go:300: INFO Connecting to IRC 127.0.0.1:42955 +2024/04/20 23:27:33.738039 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.738064 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:42955. +2024/04/20 23:27:33.738356 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:52978 +2024/04/20 23:27:33.738561 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.738734 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.738774 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.738924 irc.go:57: INFO Received: ':example.com 433 * foo :nick in use' +2024/04/20 23:27:33.739019 irc_server_for_test.go:119: INFO =Server= Received NICK foo^ +2024/04/20 23:27:33.739131 irc.go:144: INFO Session established +2024/04/20 23:27:33.739178 irc.go:204: INFO My nick is 'foo^', sending GHOST to NickServ to get 'foo' +2024/04/20 23:27:33.739206 irc.go:210: INFO Changing nick to 'foo' +2024/04/20 23:27:33.739226 irc.go:224: INFO Waiting for NickServ to notice us and issue an identify request +2024/04/20 23:27:33.739262 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.739282 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.739306 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.739480 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG NickServ :GHOST foo nickpassword +2024/04/20 23:27:33.739519 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.739536 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.739556 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.739576 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.739593 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.739677 reconciler.go:120: INFO Channel #foo monitor: context canceled while waiting for join +2024/04/20 23:27:33.739709 irc.go:294: INFO IRC routine asked to terminate +2024/04/20 23:27:33.739731 irc.go:269: INFO IRC client connected, quitting +2024/04/20 23:27:33.739752 irc.go:272: INFO Wait for IRC disconnect to complete +2024/04/20 23:27:33.739887 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.739928 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.740016 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.740187 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.740285 irc.go:280: INFO IRC shutdown complete +2024/04/20 23:27:33.740352 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestGhost (0.00s) === RUN TestStopRunningWhenHalfConnected -2024/04/19 21:18:32.439777 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36441 -2024/04/19 21:18:32.439879 irc.go:300: INFO Connecting to IRC 127.0.0.1:36441 -2024/04/19 21:18:32.439902 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.439931 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36441. -2024/04/19 21:18:32.440264 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:57164 -2024/04/19 21:18:32.440982 irc.go:308: INFO Connected to IRC server, waiting to establish session -2024/04/19 21:18:32.441195 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.441240 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.441260 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.441285 irc_test.go:589: INFO =Server= NOT completing session -2024/04/19 21:18:32.441335 irc.go:321: INFO IRC routine asked to terminate -2024/04/19 21:18:32.441361 irc.go:280: INFO IRC shutdown complete -2024/04/19 21:18:32.441435 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.441536 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:57164->127.0.0.1:36441: use of closed network connection -2024/04/19 21:18:32.441589 irc.go:150: INFO Disconnected from IRC -2024/04/19 21:18:32.441646 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:57164 disconnected -2024/04/19 21:18:32.441765 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/20 23:27:33.740623 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:36639 +2024/04/20 23:27:33.740707 irc.go:300: INFO Connecting to IRC 127.0.0.1:36639 +2024/04/20 23:27:33.740727 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.740752 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:36639. +2024/04/20 23:27:33.741059 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:33070 +2024/04/20 23:27:33.744469 irc.go:308: INFO Connected to IRC server, waiting to establish session +2024/04/20 23:27:33.744717 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.744759 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.744778 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.744797 irc_test.go:589: INFO =Server= NOT completing session +2024/04/20 23:27:33.744844 irc.go:321: INFO IRC routine asked to terminate +2024/04/20 23:27:33.744871 irc.go:280: INFO IRC shutdown complete +2024/04/20 23:27:33.744948 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.745064 connection.go:466: ERROR irc.recv(): read tcp 127.0.0.1:33070->127.0.0.1:36639: use of closed network connection +2024/04/20 23:27:33.745117 irc.go:150: INFO Disconnected from IRC +2024/04/20 23:27:33.745164 irc_server_for_test.go:113: INFO =Server= Client 127.0.0.1:33070 disconnected +2024/04/20 23:27:33.745282 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestStopRunningWhenHalfConnected (0.00s) === RUN TestPreJoinChannels -2024/04/19 21:18:32.442027 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:35033 -2024/04/19 21:18:32.442118 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:35033. -2024/04/19 21:18:32.442388 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:38840 -2024/04/19 21:18:32.442676 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.442719 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.442738 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.442910 reconciler.go:103: INFO Channel #baz monitor: waiting to join -2024/04/19 21:18:32.442939 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.442967 reconciler.go:112: INFO Channel #baz monitor: join request sent -2024/04/19 21:18:32.443170 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz -2024/04/19 21:18:32.443217 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.443226 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.443238 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.443246 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz -2024/04/19 21:18:32.443260 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.443286 reconciler.go:103: INFO Channel #bar monitor: waiting to join -2024/04/19 21:18:32.443302 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.443324 reconciler.go:112: INFO Channel #bar monitor: join request sent -2024/04/19 21:18:32.443405 reconciler.go:201: INFO Received JOIN confirmation for channel #baz -2024/04/19 21:18:32.443437 reconciler.go:77: INFO Setting JOIN state on channel #baz -2024/04/19 21:18:32.443466 reconciler.go:116: INFO Channel #baz monitor: join succeeded -2024/04/19 21:18:32.444913 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.444986 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.445011 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.445088 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar -2024/04/19 21:18:32.445119 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.445138 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar -2024/04/19 21:18:32.445314 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.445358 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.445536 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.445709 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.445743 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.445803 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/04/19 21:18:32.445846 reconciler.go:120: INFO Channel #bar monitor: context canceled while waiting for join -2024/04/19 21:18:32.445874 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/04/19 21:18:32.445899 reconciler.go:129: INFO Channel #baz monitor: context canceled while monitoring -2024/04/19 21:18:32.445959 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/20 23:27:33.745559 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:41293 +2024/04/20 23:27:33.745637 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:41293. +2024/04/20 23:27:33.745892 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:60034 +2024/04/20 23:27:33.746187 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.746226 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.746245 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.746428 reconciler.go:103: INFO Channel #baz monitor: waiting to join +2024/04/20 23:27:33.746455 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.746483 reconciler.go:112: INFO Channel #baz monitor: join request sent +2024/04/20 23:27:33.746578 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.746603 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.746627 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.746717 reconciler.go:103: INFO Channel #bar monitor: waiting to join +2024/04/20 23:27:33.746743 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.746768 reconciler.go:112: INFO Channel #bar monitor: join request sent +2024/04/20 23:27:33.746897 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #baz +2024/04/20 23:27:33.746938 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.746957 irc_server_for_test.go:119: INFO =Server= Received JOIN #baz +2024/04/20 23:27:33.747024 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.747057 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.747076 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.747134 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #bar +2024/04/20 23:27:33.747160 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.747179 irc_server_for_test.go:119: INFO =Server= Received JOIN #bar +2024/04/20 23:27:33.747347 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.747392 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.747428 reconciler.go:201: INFO Received JOIN confirmation for channel #baz +2024/04/20 23:27:33.747458 reconciler.go:77: INFO Setting JOIN state on channel #baz +2024/04/20 23:27:33.747502 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.747515 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.747524 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.747565 reconciler.go:201: INFO Received JOIN confirmation for channel #bar +2024/04/20 23:27:33.747587 reconciler.go:77: INFO Setting JOIN state on channel #bar +2024/04/20 23:27:33.747622 reconciler.go:116: INFO Channel #baz monitor: join succeeded +2024/04/20 23:27:33.747647 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/20 23:27:33.747649 reconciler.go:116: INFO Channel #bar monitor: join succeeded +2024/04/20 23:27:33.747705 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestPreJoinChannels (0.00s) === RUN TestKeepJoining -2024/04/19 21:18:32.446248 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:33207 -2024/04/19 21:18:32.446334 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:33207. -2024/04/19 21:18:32.446635 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:37950 -2024/04/19 21:18:32.446941 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.446984 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.447003 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.447225 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.447258 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.447291 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.447425 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.447468 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.447502 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.447545 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2024/04/19 21:18:32.447569 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.447595 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.447625 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.447758 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.447817 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.447839 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.447886 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry -2024/04/19 21:18:32.447909 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.447926 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.447950 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.448085 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.448132 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.448192 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.448351 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.448397 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.449155 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.449327 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.449361 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.449448 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/04/19 21:18:32.449492 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/04/19 21:18:32.449557 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections ---- PASS: TestKeepJoining (0.00s) +2024/04/20 23:27:33.747952 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:38875 +2024/04/20 23:27:33.748017 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:38875. +2024/04/20 23:27:33.756410 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:47102 +2024/04/20 23:27:33.764337 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.764413 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.764436 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.764682 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.764712 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.764743 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.764880 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.764920 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.764938 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.764982 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2024/04/20 23:27:33.765004 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.765020 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.765045 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.765175 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.765215 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.765235 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.765272 reconciler.go:118: WARN Channel #foo monitor: could not join after 10 seconds, will retry +2024/04/20 23:27:33.765293 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.765308 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.765343 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.765505 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.765544 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.765562 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.765715 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.765756 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.765928 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.766092 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.766123 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.766176 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/20 23:27:33.766215 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/20 23:27:33.766281 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +--- PASS: TestKeepJoining (0.02s) === RUN TestKickRejoin -2024/04/19 21:18:32.449846 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:44291 -2024/04/19 21:18:32.449927 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:44291. -2024/04/19 21:18:32.450243 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:40158 -2024/04/19 21:18:32.450558 irc_server_for_test.go:119: INFO =Server= Received NICK foo -2024/04/19 21:18:32.450603 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping -2024/04/19 21:18:32.450620 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : -2024/04/19 21:18:32.450770 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.450795 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.450823 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.450947 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.450987 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.451006 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.451244 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.451285 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.451324 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/04/19 21:18:32.451379 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! -2024/04/19 21:18:32.454436 reconciler.go:219: INFO Received KICK for channel #foo -2024/04/19 21:18:32.454511 reconciler.go:91: INFO Removing JOIN state on channel #foo -2024/04/19 21:18:32.454581 reconciler.go:127: INFO Channel #foo monitor: channel no longer joined -2024/04/19 21:18:32.454609 reconciler.go:103: INFO Channel #foo monitor: waiting to join -2024/04/19 21:18:32.454628 fake_delayer.go:43: INFO Faking Backoff -2024/04/19 21:18:32.454656 reconciler.go:112: INFO Channel #foo monitor: join request sent -2024/04/19 21:18:32.454800 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo -2024/04/19 21:18:32.454844 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping -2024/04/19 21:18:32.454865 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo -2024/04/19 21:18:32.456279 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya -2024/04/19 21:18:32.456355 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate -2024/04/19 21:18:32.456568 connection.go:577: INFO irc.Close(): Disconnected from server. -2024/04/19 21:18:32.456825 reconciler.go:201: INFO Received JOIN confirmation for channel #foo -2024/04/19 21:18:32.456859 reconciler.go:77: INFO Setting JOIN state on channel #foo -2024/04/19 21:18:32.456917 reconciler.go:116: INFO Channel #foo monitor: join succeeded -2024/04/19 21:18:32.456956 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring -2024/04/19 21:18:32.457021 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections +2024/04/20 23:27:33.766544 irc_server_for_test.go:201: INFO =Server= Test server listening on 127.0.0.1:35605 +2024/04/20 23:27:33.766643 connection.go:390: INFO irc.Connect(): Connecting to 127.0.0.1:35605. +2024/04/20 23:27:33.767006 irc_server_for_test.go:171: INFO =Server= New client connected from 127.0.0.1:58962 +2024/04/20 23:27:33.767326 irc_server_for_test.go:119: INFO =Server= Received NICK foo +2024/04/20 23:27:33.767368 irc_server_for_test.go:96: INFO =Server= No handler for command 'NICK', skipping +2024/04/20 23:27:33.767386 irc_server_for_test.go:119: INFO =Server= Received USER foo 12 * : +2024/04/20 23:27:33.767561 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.767589 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.767615 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.767741 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.767813 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.767836 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.767926 irc_server_for_test.go:139: INFO =Server= sending to client: :test!~test@example.com KICK #foo foo :Bye! +2024/04/20 23:27:33.768063 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.768091 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.768126 reconciler.go:219: INFO Received KICK for channel #foo +2024/04/20 23:27:33.768147 reconciler.go:91: INFO Removing JOIN state on channel #foo +2024/04/20 23:27:33.768176 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/20 23:27:33.768195 reconciler.go:103: INFO Channel #foo monitor: waiting to join +2024/04/20 23:27:33.772296 fake_delayer.go:43: INFO Faking Backoff +2024/04/20 23:27:33.772392 reconciler.go:112: INFO Channel #foo monitor: join request sent +2024/04/20 23:27:33.772648 irc_server_for_test.go:119: INFO =Server= Received PRIVMSG ChanServ :UNBAN #foo +2024/04/20 23:27:33.772695 irc_server_for_test.go:96: INFO =Server= No handler for command 'PRIVMSG', skipping +2024/04/20 23:27:33.772715 irc_server_for_test.go:119: INFO =Server= Received JOIN #foo +2024/04/20 23:27:33.772895 irc_server_for_test.go:119: INFO =Server= Received QUIT :see ya +2024/04/20 23:27:33.772936 irc_server_for_test.go:127: INFO =Server= Closing connection: client asked to terminate +2024/04/20 23:27:33.773097 connection.go:577: INFO irc.Close(): Disconnected from server. +2024/04/20 23:27:33.773258 reconciler.go:201: INFO Received JOIN confirmation for channel #foo +2024/04/20 23:27:33.773289 reconciler.go:77: INFO Setting JOIN state on channel #foo +2024/04/20 23:27:33.773343 reconciler.go:116: INFO Channel #foo monitor: join succeeded +2024/04/20 23:27:33.773453 reconciler.go:129: INFO Channel #foo monitor: context canceled while monitoring +2024/04/20 23:27:33.773538 irc_server_for_test.go:168: INFO =Server= Stopped accepting new connections --- PASS: TestKickRejoin (0.01s) PASS -ok github.com/google/alertmanager-irc-relay 0.153s +ok github.com/google/alertmanager-irc-relay 0.172s create-stamp debian/debhelper-build-stamp fakeroot debian/rules binary dh binary --buildsystem=golang --with=golang @@ -1884,12 +1919,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/22883/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/22883/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/15496 and its subdirectories -I: Current time: Fri Apr 19 21:19:18 -12 2024 -I: pbuilder-time-stamp: 1713604758 +I: removing directory /srv/workspace/pbuilder/22883 and its subdirectories +I: Current time: Sat Apr 20 23:28:40 +14 2024 +I: pbuilder-time-stamp: 1713605320