Diff of the two buildlogs: -- --- b1/build.log 2024-05-22 20:39:26.937140015 +0000 +++ b2/build.log 2024-05-22 20:56:05.914605621 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Wed May 22 08:25:08 -12 2024 -I: pbuilder-time-stamp: 1716409508 +I: Current time: Thu May 23 10:39:44 +14 2024 +I: pbuilder-time-stamp: 1716410384 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/unstable-reproducible-base.tgz] I: copying local configuration @@ -30,52 +30,84 @@ dpkg-source: info: applying 0003-Fix-racing-connection-tests.patch I: Not using root during the build. I: Installing the build-deps -I: user script /srv/workspace/pbuilder/23234/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/917/tmp/hooks/D01_modify_environment starting +debug: Running on ff64a. +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 May 22 20:40 /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/917/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/917/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=6 ' + 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='2a172a92e3944f8e996567994f9a766b' - 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='23234' - PS1='# ' - PS2='> ' + INVOCATION_ID=bce7bad36ab84b209acbc447bcb5a671 + 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=917 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.ya8NPWLy/pbuilderrc_HtRw --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.ya8NPWLy/b1 --logfile b1/build.log mender-connect_2.1.0+ds1-4.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.ya8NPWLy/pbuilderrc_uPQ8 --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.ya8NPWLy/b2 --logfile b2/build.log mender-connect_2.1.0+ds1-4.dsc' + SUDO_GID=114 + SUDO_UID=109 + 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 cbxi4a 6.1.0-21-armmp #1 SMP Debian 6.1.90-1 (2024-05-03) armv7l GNU/Linux + Linux i-capture-the-hostname 6.1.0-21-arm64 #1 SMP Debian 6.1.90-1 (2024-05-03) aarch64 GNU/Linux I: ls -l /bin - lrwxrwxrwx 1 root root 7 May 19 07:46 /bin -> usr/bin -I: user script /srv/workspace/pbuilder/23234/tmp/hooks/D02_print_environment finished + lrwxrwxrwx 1 root root 7 May 22 07:45 /bin -> usr/bin +I: user script /srv/workspace/pbuilder/917/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -291,7 +323,7 @@ Get: 148 http://deb.debian.org/debian unstable/main armhf zlib1g-dev armhf 1:1.3.dfsg+really1.3.1-1 [904 kB] Get: 149 http://deb.debian.org/debian unstable/main armhf libglib2.0-dev armhf 2.80.2-1 [1617 kB] Get: 150 http://deb.debian.org/debian unstable/main armhf pkg-config armhf 1.8.1-1+b2 [14.0 kB] -Fetched 86.9 MB in 12s (7508 kB/s) +Fetched 86.9 MB in 4s (20.1 MB/s) debconf: delaying package configuration, since apt-utils is not installed Selecting previously unselected package libdbus-1-3:armhf. (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 ... 19463 files and directories currently installed.) @@ -791,8 +823,8 @@ Setting up tzdata (2024a-4) ... Current default time zone: 'Etc/UTC' -Local time is now: Wed May 22 20:28:26 UTC 2024. -Universal Time is now: Wed May 22 20:28:26 UTC 2024. +Local time is now: Wed May 22 20:43:54 UTC 2024. +Universal Time is now: Wed May 22 20:43:54 UTC 2024. Run 'dpkg-reconfigure tzdata' if you wish to change it. Setting up libsysprof-capture-4-dev:armhf (46.0-1) ... @@ -921,7 +953,11 @@ Building tag database... -> Finished parsing the build-deps I: Building the package -I: Running cd /build/reproducible-path/mender-connect-2.1.0+ds1/ && 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 > ../mender-connect_2.1.0+ds1-4_source.changes +I: user script /srv/workspace/pbuilder/917/tmp/hooks/A99_set_merged_usr starting +Not re-configuring usrmerge for unstable +I: user script /srv/workspace/pbuilder/917/tmp/hooks/A99_set_merged_usr finished +hostname: Name or service not known +I: Running cd /build/reproducible-path/mender-connect-2.1.0+ds1/ && 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 > ../mender-connect_2.1.0+ds1-4_source.changes dpkg-buildpackage: info: source package mender-connect dpkg-buildpackage: info: source version 2.1.0+ds1-4 dpkg-buildpackage: info: source distribution unstable @@ -942,34 +978,33 @@ make[1]: Entering directory '/build/reproducible-path/mender-connect-2.1.0+ds1' dh_auto_build -O--buildsystem=golang -- \ -ldflags "-X github.com/mendersoftware/mender-connect/config.Version=" - cd _build && go install -trimpath -v -p 3 -ldflags "-X github.com/mendersoftware/mender-connect/config.Version=" github.com/mendersoftware/mender-connect github.com/mendersoftware/mender-connect/app github.com/mendersoftware/mender-connect/cli github.com/mendersoftware/mender-connect/client/dbus github.com/mendersoftware/mender-connect/client/dbus/mocks github.com/mendersoftware/mender-connect/client/dbus/test github.com/mendersoftware/mender-connect/client/mender github.com/mendersoftware/mender-connect/client/mender/mocks github.com/mendersoftware/mender-connect/config github.com/mendersoftware/mender-connect/connection github.com/mendersoftware/mender-connect/connectionmanager github.com/mendersoftware/mender-connect/limits/filetransfer github.com/mendersoftware/mender-connect/procps github.com/mendersoftware/mender-connect/session github.com/mendersoftware/mender-connect/session/mocks github.com/mendersoftware/mender-connect/session/model github.com/mendersoftware/mender-connect/shell github.com/mendersoftware/mender-connect/utils + cd _build && go install -trimpath -v -p 6 -ldflags "-X github.com/mendersoftware/mender-connect/config.Version=" github.com/mendersoftware/mender-connect github.com/mendersoftware/mender-connect/app github.com/mendersoftware/mender-connect/cli github.com/mendersoftware/mender-connect/client/dbus github.com/mendersoftware/mender-connect/client/dbus/mocks github.com/mendersoftware/mender-connect/client/dbus/test github.com/mendersoftware/mender-connect/client/mender github.com/mendersoftware/mender-connect/client/mender/mocks github.com/mendersoftware/mender-connect/config github.com/mendersoftware/mender-connect/connection github.com/mendersoftware/mender-connect/connectionmanager github.com/mendersoftware/mender-connect/limits/filetransfer github.com/mendersoftware/mender-connect/procps github.com/mendersoftware/mender-connect/session github.com/mendersoftware/mender-connect/session/mocks github.com/mendersoftware/mender-connect/session/model github.com/mendersoftware/mender-connect/shell github.com/mendersoftware/mender-connect/utils internal/unsafeheader -internal/goarch internal/cpu internal/coverage/rtcov -internal/abi -internal/chacha8rand -internal/bytealg +internal/goarch +internal/goexperiment internal/godebugs internal/goos -internal/goexperiment -runtime/internal/atomic +runtime/internal/syscall +internal/abi +internal/chacha8rand runtime/internal/math runtime/internal/sys -runtime/internal/syscall internal/race sync/atomic internal/itoa math/bits +internal/bytealg +runtime/internal/atomic unicode/utf8 -math unicode -runtime +math cmp slices encoding -github.com/mendersoftware/go-lib-micro/ws/shell github.com/mendersoftware/go-lib-micro/ws +github.com/mendersoftware/go-lib-micro/ws/shell unicode/utf16 log/internal crypto/internal/alias @@ -982,143 +1017,144 @@ github.com/vmihailenco/tagparser/v2/internal github.com/mendersoftware/go-lib-micro/ws/menderclient github.com/mendersoftware/go-lib-micro/ws/portforward +runtime crypto/subtle internal/reflectlite sync internal/testlog -runtime/cgo internal/bisect +internal/singleflight +runtime/cgo errors -internal/oserror sort -syscall +internal/godebug +internal/oserror +io strconv +syscall +internal/safefilepath +path +math/rand +crypto/internal/nistec/fiat +strings +bytes reflect +html +bufio +regexp/syntax +text/tabwriter +hash +crypto +crypto/internal/randutil +crypto/rc4 +vendor/golang.org/x/net/dns/dnsmessage time -io internal/syscall/unix -internal/safefilepath internal/syscall/execenv -path -strings +regexp +internal/intern +net/netip +hash/crc32 +vendor/golang.org/x/text/transform +crypto/internal/nistec +net/http/internal/ascii +github.com/vmihailenco/tagparser/v2/internal/parser +net/http/internal/testcert +github.com/vmihailenco/tagparser/v2 +github.com/mendersoftware/mender-connect/client/dbus/test context internal/poll io/fs -bytes -os internal/fmtsort encoding/binary -bufio -html +github.com/mendersoftware/go-lib-micro/ws/filetransfer +os encoding/base64 +crypto/internal/edwards25519/field +crypto/cipher golang.org/x/sys/unix -regexp/syntax +crypto/md5 +crypto/internal/edwards25519 +crypto/internal/boring +crypto/des +crypto/sha1 +crypto/aes +crypto/ecdh +crypto/sha512 +crypto/hmac +crypto/sha256 +encoding/pem +vendor/golang.org/x/crypto/chacha20 fmt -regexp +io/ioutil +path/filepath +net +vendor/golang.org/x/crypto/internal/poly1305 +vendor/golang.org/x/crypto/chacha20poly1305 +vendor/golang.org/x/crypto/hkdf +os/exec +os/signal +github.com/mendersoftware/mender-connect/procps +github.com/creack/pty github.com/pkg/errors -github.com/mendersoftware/mender-connect/client/dbus -encoding/json log +encoding/json +github.com/mendersoftware/mender-connect/client/dbus flag -github.com/sirupsen/logrus github.com/russross/blackfriday/v2 -io/ioutil -path/filepath -text/tabwriter net/url -github.com/cpuguy83/go-md2man/v2/md2man text/template/parse os/user +github.com/sirupsen/logrus +github.com/cpuguy83/go-md2man/v2/md2man text/template -github.com/urfave/cli/v2 compress/flate -hash -crypto -crypto/cipher -crypto/internal/boring -crypto/internal/randutil -internal/godebug -math/rand -github.com/mendersoftware/mender-connect/config -crypto/sha1 math/big -crypto/aes -crypto/des -crypto/internal/edwards25519/field -crypto/internal/nistec/fiat +encoding/hex +compress/gzip +vendor/golang.org/x/text/unicode/bidi +github.com/urfave/cli/v2 +vendor/golang.org/x/text/unicode/norm +vendor/golang.org/x/text/secure/bidirule +vendor/golang.org/x/net/http2/hpack crypto/rand +crypto/elliptic crypto/internal/bigmod +github.com/mendersoftware/mender-connect/config crypto/internal/boring/bbig -crypto/sha512 encoding/asn1 -vendor/golang.org/x/crypto/cryptobyte -crypto/internal/nistec -crypto/internal/edwards25519 -crypto/ecdh -crypto/elliptic crypto/ed25519 -crypto/hmac -crypto/md5 -crypto/ecdsa -crypto/rc4 crypto/rsa -crypto/sha256 crypto/dsa -encoding/hex -encoding/pem -crypto/x509/pkix -vendor/golang.org/x/net/dns/dnsmessage -internal/singleflight -internal/intern -net/netip -vendor/golang.org/x/crypto/chacha20 -net -vendor/golang.org/x/crypto/internal/poly1305 -vendor/golang.org/x/crypto/chacha20poly1305 -vendor/golang.org/x/crypto/hkdf -hash/crc32 -compress/gzip -vendor/golang.org/x/text/transform -vendor/golang.org/x/text/unicode/bidi -vendor/golang.org/x/text/secure/bidirule -vendor/golang.org/x/text/unicode/norm -vendor/golang.org/x/net/idna -vendor/golang.org/x/net/http2/hpack -github.com/mendersoftware/mender-connect/client/mender mime +vendor/golang.org/x/net/idna mime/quotedprintable net/http/internal -net/http/internal/ascii -github.com/vmihailenco/tagparser/v2/internal/parser -database/sql/driver -github.com/vmihailenco/tagparser/v2 +vendor/golang.org/x/crypto/cryptobyte +crypto/x509/pkix github.com/vmihailenco/msgpack/v5 +database/sql/driver +github.com/gorilla/websocket/vendor/golang.org/x/net/internal/socks +net/textproto +github.com/gorilla/websocket/vendor/golang.org/x/net/proxy +crypto/ecdsa +vendor/golang.org/x/net/http/httpproxy github.com/go-ozzo/ozzo-validation/v4 -github.com/mendersoftware/go-lib-micro/ws/filetransfer -github.com/mendersoftware/mender-connect/session/model github.com/mendersoftware/mender-connect/utils -github.com/mendersoftware/mender-connect/limits/filetransfer -os/exec -os/signal -github.com/mendersoftware/mender-connect/procps -github.com/creack/pty +vendor/golang.org/x/net/http/httpguts +mime/multipart github.com/davecgh/go-spew/spew +crypto/x509 github.com/pmezard/go-difflib/difflib +github.com/mendersoftware/mender-connect/session/model github.com/stretchr/objx -crypto/x509 -github.com/gorilla/websocket/vendor/golang.org/x/net/internal/socks -github.com/gorilla/websocket/vendor/golang.org/x/net/proxy -net/textproto -vendor/golang.org/x/net/http/httpguts -vendor/golang.org/x/net/http/httpproxy -mime/multipart gopkg.in/yaml.v3 -net/http/internal/testcert +github.com/mendersoftware/mender-connect/limits/filetransfer runtime/debug -github.com/mendersoftware/mender-connect/client/dbus/test crypto/tls net/http/httptrace net/http +github.com/mendersoftware/mender-connect/client/mender net/http/httptest github.com/gorilla/websocket github.com/stretchr/testify/assert @@ -1126,13 +1162,13 @@ github.com/mendersoftware/mender-connect/connectionmanager github.com/mendersoftware/mender-connect/shell github.com/mendersoftware/mender-connect/session -github.com/mendersoftware/mender-connect/app github.com/stretchr/testify/mock -github.com/mendersoftware/mender-connect/cli -github.com/mendersoftware/mender-connect +github.com/mendersoftware/mender-connect/app github.com/mendersoftware/mender-connect/client/mender/mocks github.com/mendersoftware/mender-connect/client/dbus/mocks github.com/mendersoftware/mender-connect/session/mocks +github.com/mendersoftware/mender-connect/cli +github.com/mendersoftware/mender-connect make[1]: Leaving directory '/build/reproducible-path/mender-connect-2.1.0+ds1' debian/rules override_dh_auto_test make[1]: Entering directory '/build/reproducible-path/mender-connect-2.1.0+ds1' @@ -1140,20 +1176,20 @@ --bus-type=system \ --max-wait=600 \ -t dh_auto_test -DBus daemon: unix:path=/tmp/dbus-cyxODEvjRF,guid=d955caa440eb814c718559b5664e565a -task-0: Started with PID: 28247 -task-0: cd _build && go test -vet=off -v -p 3 github.com/mendersoftware/mender-connect github.com/mendersoftware/mender-connect/app github.com/mendersoftware/mender-connect/cli github.com/mendersoftware/mender-connect/client/dbus github.com/mendersoftware/mender-connect/client/dbus/mocks github.com/mendersoftware/mender-connect/client/dbus/test github.com/mendersoftware/mender-connect/client/mender github.com/mendersoftware/mender-connect/client/mender/mocks github.com/mendersoftware/mender-connect/config github.com/mendersoftware/mender-connect/connection github.com/mendersoftware/mender-connect/connectionmanager github.com/mendersoftware/mender-connect/limits/filetransfer github.com/mendersoftware/mender-connect/procps github.com/mendersoftware/mender-connect/session github.com/mendersoftware/mender-connect/session/mocks github.com/mendersoftware/mender-connect/session/model github.com/mendersoftware/mender-connect/shell github.com/mendersoftware/mender-connect/utils +DBus daemon: unix:path=/tmp/dbus-zbEh0QPsfx,guid=da168fbac8c4fdfd47f92e55664e59f0 +task-0: Started with PID: 16248 +task-0: cd _build && go test -vet=off -v -p 6 github.com/mendersoftware/mender-connect github.com/mendersoftware/mender-connect/app github.com/mendersoftware/mender-connect/cli github.com/mendersoftware/mender-connect/client/dbus github.com/mendersoftware/mender-connect/client/dbus/mocks github.com/mendersoftware/mender-connect/client/dbus/test github.com/mendersoftware/mender-connect/client/mender github.com/mendersoftware/mender-connect/client/mender/mocks github.com/mendersoftware/mender-connect/config github.com/mendersoftware/mender-connect/connection github.com/mendersoftware/mender-connect/connectionmanager github.com/mendersoftware/mender-connect/limits/filetransfer github.com/mendersoftware/mender-connect/procps github.com/mendersoftware/mender-connect/session github.com/mendersoftware/mender-connect/session/mocks github.com/mendersoftware/mender-connect/session/model github.com/mendersoftware/mender-connect/shell github.com/mendersoftware/mender-connect/utils task-0: === RUN TestMainExitCodes task-0: mender-connect version unknown runtime: go1.22.3 -task-0: --- PASS: TestMainExitCodes (0.00s) +task-0: --- PASS: TestMainExitCodes (0.01s) task-0: === RUN TestMainRequiresConfig -task-0: time="2024-05-22T08:35:51-12:00" level=info msg="No configuration files present. Using defaults" -task-0: time="2024-05-22T08:35:51-12:00" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" -task-0: time="2024-05-22T08:35:51-12:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-05-22T08:35:51-12:00" level=error msg="please provide a user to run the shell as" +task-0: time="2024-05-23T10:51:41+14:00" level=info msg="No configuration files present. Using defaults" +task-0: time="2024-05-23T10:51:41+14:00" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" +task-0: time="2024-05-23T10:51:41+14:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2024-05-23T10:51:41+14:00" level=error msg="please provide a user to run the shell as" task-0: --- PASS: TestMainRequiresConfig (0.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect 0.078s +task-0: ok github.com/mendersoftware/mender-connect 0.164s task-0: ? github.com/mendersoftware/mender-connect/cli [no test files] task-0: ? github.com/mendersoftware/mender-connect/client/dbus/mocks [no test files] task-0: ? github.com/mendersoftware/mender-connect/client/dbus/test [no test files] @@ -1164,59 +1200,62 @@ task-0: daemon_test.go:143: starting mock httpd with websockets task-0: newShellTransaction sendMessage(SpwanShell)= task-0: daemon_test.go:167: read message: type, session_id, data new, c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: time="2024-05-22T08:35:56-12:00" level=info msg="mender-connect starting shell command passing process, pid: 30814" +task-0: time="2024-05-23T10:51:43+14:00" level=info msg="mender-connect starting shell command passing process, pid: 26808" task-0: newShellTransaction (0) sendMessage=&{Header:{Proto:1 MsgType:new SessionID:c4993deb-26b4-4c58-aaee-fd0c9e694328 Properties:map[status:1]} Body:[83 104 101 108 108 32 115 116 97 114 116 101 100]}, task-0: newShellTransaction (1) sendMessage= task-0: newShellTransaction (2) sendMessage= task-0: newShellTransaction (3) sendMessage= task-0: newShellTransaction (4) sendMessage= -task-0: daemon_test.go:176: read message: type, session_id, data shell, c4993deb-26b4-4c58-aaee-fd0c9e694328, echo newShellTransaction.2093703 > /tmp/TestMenderShellExec814327089 -task-0: daemon_test.go:183: read message: type, session_id, data shell, undefined-session-id, rm -f /tmp/TestMenderShellExec814327089 -task-0: time="2024-05-22T08:35:56-12:00" level=error msg="session not found" +task-0: daemon_test.go:176: read message: type, session_id, data shell, c4993deb-26b4-4c58-aaee-fd0c9e694328, echo newShellTransaction.4524097 > /tmp/TestMenderShellExec4077101529 +task-0: daemon_test.go:183: read message: type, session_id, data shell, undefined-session-id, rm -f /tmp/TestMenderShellExec4077101529 +task-0: time="2024-05-23T10:51:43+14:00" level=error msg="session not found" task-0: daemon_test.go:186: route message error: session not found task-0: daemon_test.go:190: read message: type, session_id, data shell, c4993deb-26b4-4c58-aaee-fd0c9e694328, thiscommand probably does not exist task-0: daemon_test.go:197: read message: type, session_id, data stop, undefined-session-id, -task-0: time="2024-05-22T08:35:56-12:00" level=error msg="routeMessage: StopShellMessage: session not found for id undefined-session-id" +task-0: time="2024-05-23T10:51:43+14:00" level=error msg="routeMessage: StopShellMessage: session not found for id undefined-session-id" task-0: daemon_test.go:200: route message error: routeMessage: StopShellMessage: session not found for id undefined-session-id task-0: daemon_test.go:204: read message: type, session_id, data stop, c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: time="2024-05-22T08:36:00-12:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: time="2024-05-23T10:51:47+14:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" task-0: daemon_test.go:210: checking command execution results -task-0: daemon_test.go:213: checking if /tmp/TestMenderShellExec814327089 contains newShellTransaction.2093703 -task-0: daemon_test.go:216: got: 'newShellTransaction.2093703' -task-0: --- PASS: TestMenderShellSessionStart (8.03s) +task-0: daemon_test.go:213: checking if /tmp/TestMenderShellExec4077101529 contains newShellTransaction.4524097 +task-0: daemon_test.go:216: got: 'newShellTransaction.4524097' +task-0: --- PASS: TestMenderShellSessionStart (8.07s) task-0: === RUN TestMenderShellStopByUserId task-0: daemon_test.go:254: starting mock httpd with websockets task-0: newShellStopByUserId starting task-0: (0) newShellStopByUserId sendMessage: task-0: daemon_test.go:280: read message: type, session_id, data new, c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: time="2024-05-22T08:36:06-12:00" level=info msg="mender-connect starting shell command passing process, pid: 30822" +task-0: time="2024-05-23T10:51:53+14:00" level=info msg="mender-connect starting shell command passing process, pid: 27004" task-0: (1) newShellStopByUserId sendMessage: task-0: (2) newShellStopByUserId sendMessage: task-0: (3) newShellStopByUserId sendMessage: task-0: daemon_test.go:294: read message: type, session_id, data stop, c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: time="2024-05-22T08:36:06-12:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: time="2024-05-23T10:51:53+14:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: time="2024-05-23T10:51:53+14:00" level=error msg="error reading stdout: read /dev/ptmx: input/output error" +task-0: time="2024-05-23T10:51:57+14:00" level=error msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328, shell pid 27004, termination error: error waiting for the process: signal: interrupt" +task-0: time="2024-05-23T10:51:57+14:00" level=error msg="process error on exit: error waiting for the process: signal: interrupt" task-0: daemon_test.go:301: read message: type, session_id, data stop, c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: time="2024-05-22T08:36:10-12:00" level=error msg="routeMessage: StopShellMessage: session not found for id c4993deb-26b4-4c58-aaee-fd0c9e694328" +task-0: time="2024-05-23T10:51:57+14:00" level=error msg="routeMessage: StopShellMessage: session not found for id c4993deb-26b4-4c58-aaee-fd0c9e694328" task-0: daemon_test.go:304: route message error: routeMessage: StopShellMessage: session not found for id c4993deb-26b4-4c58-aaee-fd0c9e694328 -task-0: --- PASS: TestMenderShellStopByUserId (7.02s) +task-0: --- PASS: TestMenderShellStopByUserId (7.04s) task-0: === RUN TestMenderShellUnknownMessage task-0: daemon_test.go:334: starting mock httpd with websockets task-0: newShellUnknownMessage starting task-0: (0) newShellStopByUserId sendMessage: task-0: daemon_test.go:360: read message: proto, type, session_id, data 1, does-not-exist, c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: --- PASS: TestMenderShellUnknownMessage (2.01s) +task-0: --- PASS: TestMenderShellUnknownMessage (2.00s) task-0: === RUN TestMenderShellSessionLimitPerUser task-0: daemon_test.go:394: starting mock httpd with websockets task-0: newShellMulti: starting task-0: -task-0: daemon_test.go:428: read message: type, session_id, data new, 8ef1b09c-a216-499e-a81a-811f377328ca, -task-0: time="2024-05-22T08:36:13-12:00" level=info msg="mender-connect starting shell command passing process, pid: 30840" -task-0: daemon_test.go:428: read message: type, session_id, data new, 63f6ec9e-bfa6-47e3-8310-8015edced905, -task-0: time="2024-05-22T08:36:13-12:00" level=info msg="mender-connect starting shell command passing process, pid: 30841" -task-0: daemon_test.go:437: read message: type, session_id, data new, 942a32b1-8bcd-4fee-9337-9667d45d33b6, -task-0: time="2024-05-22T08:36:13-12:00" level=error msg="user has too many open sessions" +task-0: daemon_test.go:428: read message: type, session_id, data new, d84ded6e-eb1c-4619-ba95-59658278cf97, +task-0: time="2024-05-23T10:52:00+14:00" level=info msg="mender-connect starting shell command passing process, pid: 27252" +task-0: daemon_test.go:428: read message: type, session_id, data new, a58fcf6f-3f07-420f-940c-ff2902e768cf, +task-0: time="2024-05-23T10:52:01+14:00" level=info msg="mender-connect starting shell command passing process, pid: 27253" +task-0: daemon_test.go:437: read message: type, session_id, data new, 6967cff6-dca7-4f19-afe9-478d437d3c2c, +task-0: time="2024-05-23T10:52:01+14:00" level=error msg="user has too many open sessions" task-0: daemon_test.go:440: route message error: user has too many open sessions -task-0: --- PASS: TestMenderShellSessionLimitPerUser (0.02s) +task-0: --- PASS: TestMenderShellSessionLimitPerUser (0.08s) task-0: === RUN TestMenderShellStopDaemon task-0: --- PASS: TestMenderShellStopDaemon (0.00s) task-0: === RUN TestMenderShellReadMessage @@ -1228,14 +1267,14 @@ task-0: task-0: newShellMulti: starting task-0: -task-0: daemon_test.go:584: read message: type, session_id, data new, 26903321-078a-4d2f-9e69-a8443a9e8048, -task-0: time="2024-05-22T08:36:24-12:00" level=info msg="mender-connect starting shell command passing process, pid: 30863" -task-0: daemon_test.go:584: read message: type, session_id, data new, 776cb5bf-ea81-4c26-a6a2-a12b15d4c14f, -task-0: time="2024-05-22T08:36:25-12:00" level=info msg="mender-connect starting shell command passing process, pid: 30866" -task-0: daemon_test.go:593: read message: type, session_id, data new, c19e4a45-caef-4e2b-b60d-3133204d0ee7, -task-0: time="2024-05-22T08:36:25-12:00" level=error msg="too many shells spawned" +task-0: daemon_test.go:584: read message: type, session_id, data new, c8c71393-37a4-4731-a18d-fcd595b4219e, +task-0: time="2024-05-23T10:52:12+14:00" level=info msg="mender-connect starting shell command passing process, pid: 27497" +task-0: daemon_test.go:584: read message: type, session_id, data new, 722b9ca2-a223-41dd-bd9d-ff78a30089f1, +task-0: time="2024-05-23T10:52:13+14:00" level=info msg="mender-connect starting shell command passing process, pid: 27500" +task-0: daemon_test.go:593: read message: type, session_id, data new, aab627e7-3fa3-4051-9187-75bed7e37fb4, +task-0: time="2024-05-23T10:52:13+14:00" level=error msg="too many shells spawned" task-0: daemon_test.go:596: route message error: too many shells spawned -task-0: --- PASS: TestMenderShellMaxShellsLimit (2.02s) +task-0: --- PASS: TestMenderShellMaxShellsLimit (2.06s) task-0: === RUN TestMenderShellNeedsReconnect task-0: --- PASS: TestMenderShellNeedsReconnect (1.00s) task-0: === RUN TestMenderShellPostEvent @@ -1243,26 +1282,26 @@ task-0: === RUN TestMenderShellReadEvent task-0: --- PASS: TestMenderShellReadEvent (0.00s) task-0: === RUN TestOutputStatus -task-0: time="2024-05-22T08:36:26-12:00" level=info msg="mender-connect daemon vunknown" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" status: " -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" shells: 0/2" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" sessions: 4" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" id:8ef1b09c-a216-499e-a81a-811f377328ca status:0 started:Wed May 22 20:36:13 +0000 UTC 2024" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" expires:Wed May 22 20:38:21 +0000 UTC 2024 active:Wed May 22 20:36:13 +0000 UTC 2024" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" shell:/bin/sh" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" id:63f6ec9e-bfa6-47e3-8310-8015edced905 status:0 started:Wed May 22 20:36:13 +0000 UTC 2024" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" expires:Wed May 22 20:38:21 +0000 UTC 2024 active:Wed May 22 20:36:13 +0000 UTC 2024" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" shell:/bin/sh" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" id:26903321-078a-4d2f-9e69-a8443a9e8048 status:0 started:Wed May 22 20:36:24 +0000 UTC 2024" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" expires:Wed May 22 20:53:28 +0000 UTC 2024 active:Wed May 22 20:36:24 +0000 UTC 2024" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" shell:/bin/sh" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" id:776cb5bf-ea81-4c26-a6a2-a12b15d4c14f status:0 started:Wed May 22 20:36:25 +0000 UTC 2024" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" expires:Wed May 22 20:53:29 +0000 UTC 2024 active:Wed May 22 20:36:25 +0000 UTC 2024" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" shell:/bin/sh" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" file-transfer:" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" total: tx/rx 0/0" -task-0: time="2024-05-22T08:36:26-12:00" level=info msg=" 1m: tx rx 0.00 0.00 (w)" -task-0: --- PASS: TestOutputStatus (0.00s) +task-0: time="2024-05-23T10:52:14+14:00" level=info msg="mender-connect daemon vunknown" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" status: " +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" shells: 0/2" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" sessions: 4" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" id:d84ded6e-eb1c-4619-ba95-59658278cf97 status:0 started:Wed May 22 20:52:00 +0000 UTC 2024" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" expires:Wed May 22 20:54:08 +0000 UTC 2024 active:Wed May 22 20:52:00 +0000 UTC 2024" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" shell:/bin/sh" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" id:a58fcf6f-3f07-420f-940c-ff2902e768cf status:0 started:Wed May 22 20:52:00 +0000 UTC 2024" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" expires:Wed May 22 20:54:08 +0000 UTC 2024 active:Wed May 22 20:52:01 +0000 UTC 2024" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" shell:/bin/sh" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" id:c8c71393-37a4-4731-a18d-fcd595b4219e status:0 started:Wed May 22 20:52:12 +0000 UTC 2024" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" expires:Wed May 22 21:09:16 +0000 UTC 2024 active:Wed May 22 20:52:12 +0000 UTC 2024" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" shell:/bin/sh" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" id:722b9ca2-a223-41dd-bd9d-ff78a30089f1 status:0 started:Wed May 22 20:52:13 +0000 UTC 2024" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" expires:Wed May 22 21:09:17 +0000 UTC 2024 active:Wed May 22 20:52:13 +0000 UTC 2024" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" shell:/bin/sh" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" file-transfer:" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" total: tx/rx 0/0" +task-0: time="2024-05-23T10:52:14+14:00" level=info msg=" 1m: tx rx 0.00 0.00 (w)" +task-0: --- PASS: TestOutputStatus (0.01s) task-0: === RUN TestTimeToSweepSessions task-0: --- PASS: TestTimeToSweepSessions (4.00s) task-0: === RUN TestDBusEventLoop @@ -1270,14 +1309,14 @@ task-0: === RUN TestDBusEventLoop/token_not_returned_wait_forever task-0: === NAME TestDBusEventLoop task-0: daemon_test.go:803: ok: expected to run forever -task-0: --- PASS: TestDBusEventLoop (16.00s) -task-0: --- PASS: TestDBusEventLoop/stopped-gracefully (1.00s) +task-0: --- PASS: TestDBusEventLoop (16.01s) +task-0: --- PASS: TestDBusEventLoop/stopped-gracefully (1.01s) task-0: === RUN TestEventLoop task-0: === RUN TestEventLoop/stopped-gracefully task-0: === RUN TestEventLoop/run_forever task-0: === NAME TestEventLoop task-0: daemon_test.go:885: ok: expected to run forever -task-0: --- PASS: TestEventLoop (16.01s) +task-0: --- PASS: TestEventLoop (16.00s) task-0: --- PASS: TestEventLoop/stopped-gracefully (1.00s) task-0: === RUN TestMessageMainLoop task-0: daemon_test.go:931: starting mock httpd with websockets @@ -1286,10 +1325,10 @@ task-0: === NAME TestMessageMainLoop task-0: daemon_test.go:1001: ok: expected to run forever task-0: === RUN TestMessageMainLoop/ws-nil-error -task-0: time="2024-05-22T08:37:18-12:00" level=error msg="session 8ef1b09c-a216-499e-a81a-811f377328ca, health check failed, connection with the client lost" -task-0: time="2024-05-22T08:37:18-12:00" level=error msg="session 63f6ec9e-bfa6-47e3-8310-8015edced905, health check failed, connection with the client lost" -task-0: time="2024-05-22T08:37:29-12:00" level=error msg="session 26903321-078a-4d2f-9e69-a8443a9e8048, health check failed, connection with the client lost" -task-0: time="2024-05-22T08:37:30-12:00" level=error msg="session 776cb5bf-ea81-4c26-a6a2-a12b15d4c14f, health check failed, connection with the client lost" +task-0: time="2024-05-23T10:53:05+14:00" level=error msg="session d84ded6e-eb1c-4619-ba95-59658278cf97, health check failed, connection with the client lost" +task-0: time="2024-05-23T10:53:06+14:00" level=error msg="session a58fcf6f-3f07-420f-940c-ff2902e768cf, health check failed, connection with the client lost" +task-0: time="2024-05-23T10:53:17+14:00" level=error msg="session c8c71393-37a4-4731-a18d-fcd595b4219e, health check failed, connection with the client lost" +task-0: time="2024-05-23T10:53:18+14:00" level=error msg="session 722b9ca2-a223-41dd-bd9d-ff78a30089f1, health check failed, connection with the client lost" task-0: === NAME TestMessageMainLoop task-0: daemon_test.go:1001: ok: expected to run forever task-0: --- PASS: TestMessageMainLoop (30.01s) @@ -1322,14 +1361,10 @@ task-0: === RUN TestDecreaseSpawnedShellsCount/decrease_by_0_with_0 task-0: === PAUSE TestDecreaseSpawnedShellsCount/decrease_by_0_with_0 task-0: === CONT TestDecreaseSpawnedShellsCount/decrease_by_1_with_1 -task-0: === CONT TestRouteMessage/error,_session_router -task-0: --- PASS: TestRouteMessage (0.00s) -task-0: --- PASS: TestRouteMessage/ok,_session_router (0.00s) -task-0: --- PASS: TestRouteMessage/error,_session_router (0.00s) task-0: === CONT TestDecreaseSpawnedShellsCount/decrease_by_0_with_0 -task-0: time="2024-05-22T08:37:32-12:00" level=warning msg="can't decrement shellsSpawned count: it is 0." +task-0: time="2024-05-23T10:53:20+14:00" level=warning msg="can't decrement shellsSpawned count: it is 0." task-0: === CONT TestDecreaseSpawnedShellsCount/decrease_by_many_with_0 -task-0: time="2024-05-22T08:37:32-12:00" level=warning msg="can't decrement shellsSpawned count: it is 0." +task-0: time="2024-05-23T10:53:20+14:00" level=warning msg="can't decrement shellsSpawned count: it is 0." task-0: === CONT TestDecreaseSpawnedShellsCount/decrease_by_some_with_many task-0: === CONT TestDecreaseSpawnedShellsCount/decrease_by_many_with_some task-0: === CONT TestDecreaseSpawnedShellsCount/decrease_by_many_with_many @@ -1342,28 +1377,32 @@ task-0: --- PASS: TestDecreaseSpawnedShellsCount/decrease_by_many_with_some (0.00s) task-0: --- PASS: TestDecreaseSpawnedShellsCount/decrease_by_many_with_many (0.00s) task-0: --- PASS: TestDecreaseSpawnedShellsCount/decrease_by_1_with_many (0.00s) +task-0: === CONT TestRouteMessage/error,_session_router +task-0: --- PASS: TestRouteMessage (0.00s) +task-0: --- PASS: TestRouteMessage/ok,_session_router (0.01s) +task-0: --- PASS: TestRouteMessage/error,_session_router (0.01s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/app 96.189s +task-0: ok github.com/mendersoftware/mender-connect/app 96.423s task-0: === RUN TestBusGet -task-0: --- PASS: TestBusGet (0.03s) +task-0: --- PASS: TestBusGet (0.06s) task-0: === RUN TestBusProxyNew task-0: === RUN TestBusProxyNew/ok task-0: === RUN TestBusProxyNew/ko,_wrong_path task-0: -task-0: (process:31166): GLib-GIO-CRITICAL **: 08:36:40.006: g_dbus_proxy_new_sync: assertion 'g_variant_is_object_path (object_path)' failed -task-0: --- PASS: TestBusProxyNew (0.03s) -task-0: --- PASS: TestBusProxyNew/ok (0.02s) +task-0: (process:27928): GLib-GIO-CRITICAL **: 10:52:49.292: g_dbus_proxy_new_sync: assertion 'g_variant_is_object_path (object_path)' failed +task-0: --- PASS: TestBusProxyNew (0.01s) +task-0: --- PASS: TestBusProxyNew/ok (0.01s) task-0: --- PASS: TestBusProxyNew/ko,_wrong_path (0.00s) task-0: === RUN TestBusProxyCall -task-0: === RUN TestBusProxyCall/ko,_already_handled_Hello_message task-0: === RUN TestBusProxyCall/ok -task-0: --- PASS: TestBusProxyCall (0.03s) -task-0: --- PASS: TestBusProxyCall/ko,_already_handled_Hello_message (0.01s) +task-0: === RUN TestBusProxyCall/ko,_already_handled_Hello_message +task-0: --- PASS: TestBusProxyCall (0.04s) task-0: --- PASS: TestBusProxyCall/ok (0.02s) +task-0: --- PASS: TestBusProxyCall/ko,_already_handled_Hello_message (0.01s) task-0: === RUN TestMainLoop task-0: --- PASS: TestMainLoop (0.10s) task-0: === RUN TestWaitForSignal -task-0: --- PASS: TestWaitForSignal (0.11s) +task-0: --- PASS: TestWaitForSignal (0.10s) task-0: === RUN TestMenderclient task-0: dbus_libgio_test.go:160: skip TestMenderclient because it requires a running Mender client task-0: --- SKIP: TestMenderclient (0.00s) @@ -1372,7 +1411,7 @@ task-0: === RUN TestError task-0: --- PASS: TestError (0.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/client/dbus 0.384s +task-0: ok github.com/mendersoftware/mender-connect/client/dbus 0.395s task-0: === RUN TestNewAuthClientDefaultDBusAPI task-0: --- PASS: TestNewAuthClientDefaultDBusAPI (0.00s) task-0: === RUN TestNewAuthClient @@ -1381,78 +1420,78 @@ task-0: === RUN TestAuthClientConnect/ok task-0: === RUN TestAuthClientConnect/error_BusGet task-0: === RUN TestAuthClientConnect/error_ProxyNew -task-0: --- PASS: TestAuthClientConnect (0.00s) -task-0: --- PASS: TestAuthClientConnect/ok (0.00s) +task-0: --- PASS: TestAuthClientConnect (0.03s) +task-0: --- PASS: TestAuthClientConnect/ok (0.03s) task-0: --- PASS: TestAuthClientConnect/error_BusGet (0.00s) task-0: --- PASS: TestAuthClientConnect/error_ProxyNew (0.00s) task-0: === RUN TestAuthClientGetJWTToken task-0: === RUN TestAuthClientGetJWTToken/ok task-0: === RUN TestAuthClientGetJWTToken/error -task-0: --- PASS: TestAuthClientGetJWTToken (0.00s) -task-0: --- PASS: TestAuthClientGetJWTToken/ok (0.00s) +task-0: --- PASS: TestAuthClientGetJWTToken (0.01s) +task-0: --- PASS: TestAuthClientGetJWTToken/ok (0.01s) task-0: --- PASS: TestAuthClientGetJWTToken/error (0.00s) task-0: === RUN TestAuthClientFetchJWTToken task-0: === RUN TestAuthClientFetchJWTToken/ok task-0: === RUN TestAuthClientFetchJWTToken/error -task-0: --- PASS: TestAuthClientFetchJWTToken (0.01s) +task-0: --- PASS: TestAuthClientFetchJWTToken (0.02s) task-0: --- PASS: TestAuthClientFetchJWTToken/ok (0.00s) -task-0: --- PASS: TestAuthClientFetchJWTToken/error (0.00s) +task-0: --- PASS: TestAuthClientFetchJWTToken/error (0.02s) task-0: === RUN TestAuthClientWaitForJwtTokenStateChange -task-0: === RUN TestAuthClientWaitForJwtTokenStateChange/error task-0: === RUN TestAuthClientWaitForJwtTokenStateChange/ok-no-params task-0: === RUN TestAuthClientWaitForJwtTokenStateChange/ok-with-params +task-0: === RUN TestAuthClientWaitForJwtTokenStateChange/error task-0: --- PASS: TestAuthClientWaitForJwtTokenStateChange (0.00s) -task-0: --- PASS: TestAuthClientWaitForJwtTokenStateChange/error (0.00s) task-0: --- PASS: TestAuthClientWaitForJwtTokenStateChange/ok-no-params (0.00s) task-0: --- PASS: TestAuthClientWaitForJwtTokenStateChange/ok-with-params (0.00s) +task-0: --- PASS: TestAuthClientWaitForJwtTokenStateChange/error (0.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/client/mender 0.073s +task-0: ok github.com/mendersoftware/mender-connect/client/mender 0.186s task-0: === RUN Test_readConfigFile_noFile_returnsError -task-0: --- PASS: Test_readConfigFile_noFile_returnsError (0.00s) +task-0: --- PASS: Test_readConfigFile_noFile_returnsError (0.01s) task-0: === RUN Test_readConfigFile_brokenContent_returnsError -task-0: time="2024-05-22T08:36:49-12:00" level=error msg="Error loading configuration from file: /tmp/mendertest1204093145/mender-connect.conf (Error parsing mender configuration file: invalid character '\"' after object key:value pair)" -task-0: time="2024-05-22T08:36:49-12:00" level=error msg="Error loading configuration from file: /tmp/mendertest1204093145/mender-connect.conf (Error parsing mender configuration file: invalid character '\"' after object key:value pair)" +task-0: time="2024-05-23T10:52:49+14:00" level=error msg="Error loading configuration from file: /tmp/mendertest3049658807/mender-connect.conf (Error parsing mender configuration file: invalid character '\"' after object key:value pair)" +task-0: time="2024-05-23T10:52:49+14:00" level=error msg="Error loading configuration from file: /tmp/mendertest3049658807/mender-connect.conf (Error parsing mender configuration file: invalid character '\"' after object key:value pair)" task-0: --- PASS: Test_readConfigFile_brokenContent_returnsError (0.00s) task-0: === RUN Test_LoadConfig_correctConfFile_returnsConfiguration -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: /tmp/mendertest93915987/mender-connect.conf" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="both ExpireAfter and ExpireAfterIdle specified." -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: /tmp/mendertest93915987/mender-connect.conf" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="both ExpireAfter and ExpireAfterIdle specified." -task-0: --- PASS: Test_LoadConfig_correctConfFile_returnsConfiguration (0.01s) +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: /tmp/mendertest1861263929/mender-connect.conf" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="both ExpireAfter and ExpireAfterIdle specified." +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: /tmp/mendertest1861263929/mender-connect.conf" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="both ExpireAfter and ExpireAfterIdle specified." +task-0: --- PASS: Test_LoadConfig_correctConfFile_returnsConfiguration (0.02s) task-0: === RUN TestConfigurationMergeSettings -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: fallback.config" -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: main.config" +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: fallback.config" +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: main.config" task-0: --- PASS: TestConfigurationMergeSettings (0.00s) task-0: === RUN Test_LoadConfig_various_errors -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: /tmp/mendertest22590465/mender-connect.conf" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: /tmp/mendertest22590465/mender-connect.conf" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: /tmp/mendertest22590465/mender-connect.conf" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: /tmp/mendertest22590465/mender-connect.conf" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: /tmp/mendertest22590465/mender-connect.conf" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-05-22T08:36:49-12:00" level=error msg="ShellCommand /bin/ls is not present in /etc/shells" -task-0: time="2024-05-22T08:36:49-12:00" level=error msg="Error loading configuration from file: /tmp/mendertest22590465/mender-connect.conf (Error parsing mender configuration file: invalid character '\"' after object key:value pair)" -task-0: time="2024-05-22T08:36:49-12:00" level=error msg="Error loading configuration from file: /tmp/mendertest22590465/mender-connect.conf (Error parsing config file: json: cannot unmarshal number into Go struct field MenderShellConfigFromFile.ShellCommand of type string)" -task-0: --- PASS: Test_LoadConfig_various_errors (0.02s) +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: /tmp/mendertest3712490197/mender-connect.conf" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: /tmp/mendertest3712490197/mender-connect.conf" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: /tmp/mendertest3712490197/mender-connect.conf" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: /tmp/mendertest3712490197/mender-connect.conf" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: /tmp/mendertest3712490197/mender-connect.conf" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2024-05-23T10:52:49+14:00" level=error msg="ShellCommand /bin/ls is not present in /etc/shells" +task-0: time="2024-05-23T10:52:49+14:00" level=error msg="Error loading configuration from file: /tmp/mendertest3712490197/mender-connect.conf (Error parsing mender configuration file: invalid character '\"' after object key:value pair)" +task-0: time="2024-05-23T10:52:49+14:00" level=error msg="Error loading configuration from file: /tmp/mendertest3712490197/mender-connect.conf (Error parsing config file: json: cannot unmarshal number into Go struct field MenderShellConfigFromFile.ShellCommand of type string)" +task-0: --- PASS: Test_LoadConfig_various_errors (0.03s) task-0: === RUN TestConfigurationNeitherFileExistsIsNotError -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="No configuration files present. Using defaults" +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="No configuration files present. Using defaults" task-0: --- PASS: TestConfigurationNeitherFileExistsIsNotError (0.00s) task-0: === RUN TestShellArgumentsEmptyDefaults -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: main.config" -task-0: time="2024-05-22T08:36:49-12:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: main.config" -task-0: time="2024-05-22T08:36:49-12:00" level=info msg="Loaded configuration file: main.config" +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: main.config" +task-0: time="2024-05-23T10:52:49+14:00" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: main.config" +task-0: time="2024-05-23T10:52:49+14:00" level=info msg="Loaded configuration file: main.config" task-0: --- PASS: TestShellArgumentsEmptyDefaults (0.01s) task-0: === RUN TestServerArgumentsDeprecated -task-0: --- PASS: TestServerArgumentsDeprecated (0.05s) +task-0: --- PASS: TestServerArgumentsDeprecated (0.04s) task-0: === RUN TestGetStateDirPath task-0: --- PASS: TestGetStateDirPath (0.00s) task-0: === RUN TestGetConfDirPath @@ -1467,7 +1506,7 @@ task-0: === RUN TestMenderShowVersion task-0: --- PASS: TestMenderShowVersion (0.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/config 0.139s +task-0: ok github.com/mendersoftware/mender-connect/config 0.207s task-0: === RUN TestNewConnection task-0: connection_test.go:97: starting mock httpd with websockets task-0: --- PASS: TestNewConnection (0.01s) @@ -1477,12 +1516,12 @@ task-0: --- PASS: TestConnection_ReadMessage (1.01s) task-0: === RUN TestConnection_WriteMessage task-0: connection_test.go:149: starting mock httpd with websockets -task-0: --- PASS: TestConnection_WriteMessage (1.00s) +task-0: --- PASS: TestConnection_WriteMessage (1.01s) task-0: === RUN TestConnection_Close task-0: connection_test.go:174: starting mock httpd with websockets task-0: --- PASS: TestConnection_Close (1.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/connection 3.076s +task-0: ok github.com/mendersoftware/mender-connect/connection 3.107s task-0: === RUN TestSetReconnectIntervalSeconds task-0: --- PASS: TestSetReconnectIntervalSeconds (0.00s) task-0: === RUN TestGetWriteTimeout @@ -1490,65 +1529,65 @@ task-0: === RUN TestGetWsScheme task-0: --- PASS: TestGetWsScheme (0.00s) task-0: === RUN TestConnect -task-0: 2024/05/22 08:36:55 [130 163 104 100 114 129 165 112 114 111 116 111 205 0 1 164 98 111 100 121 196 5 100 117 109 109 121] task-0: --- PASS: TestConnect (2.02s) task-0: === RUN TestReconnect -task-0: 2024/05/22 08:36:55 http: panic serving 127.0.0.1:53434: websocket: close 1006 (abnormal closure): unexpected EOF -task-0: goroutine 25 [running]: +task-0: 2024/05/23 10:52:51 [130 163 104 100 114 129 165 112 114 111 116 111 205 0 1 164 98 111 100 121 196 5 100 117 109 109 121] +task-0: 2024/05/23 10:52:51 http: panic serving 127.0.0.1:44848: websocket: close 1006 (abnormal closure): unexpected EOF +task-0: goroutine 20 [running]: task-0: net/http.(*conn).serve.func1() task-0: /usr/lib/go-1.22/src/net/http/server.go:1898 +0xe4 task-0: panic({0x34a098, 0x5d1470}) task-0: /usr/lib/go-1.22/src/runtime/panic.go:770 +0xfc -task-0: github.com/mendersoftware/mender-connect/connectionmanager.newWebsocketServer.func2({0x402424, 0x26881e8}, 0x2524648) +task-0: github.com/mendersoftware/mender-connect/connectionmanager.newWebsocketServer.func2({0x402424, 0x18c4508}, 0x18c41e8) task-0: /build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/connectionmanager/connectionmanager_test.go:61 +0x1f0 -task-0: net/http.HandlerFunc.ServeHTTP(0x2514470, {0x402424, 0x26881e8}, 0x2524648) +task-0: net/http.HandlerFunc.ServeHTTP(0x182e490, {0x402424, 0x18c4508}, 0x18c41e8) task-0: /usr/lib/go-1.22/src/net/http/server.go:2166 +0x34 -task-0: net/http.(*ServeMux).ServeHTTP(0x2532180, {0x402424, 0x26881e8}, 0x2524648) +task-0: net/http.(*ServeMux).ServeHTTP(0x1914180, {0x402424, 0x18c4508}, 0x18c41e8) task-0: /usr/lib/go-1.22/src/net/http/server.go:2683 +0x208 -task-0: net/http.serverHandler.ServeHTTP({0x25245a8}, {0x402424, 0x26881e8}, 0x2524648) +task-0: net/http.serverHandler.ServeHTTP({0x190c468}, {0x402424, 0x18c4508}, 0x18c41e8) task-0: /usr/lib/go-1.22/src/net/http/server.go:3137 +0xe0 -task-0: net/http.(*conn).serve(0x254a8a0, {0x402648, 0x247a1f8}) +task-0: net/http.(*conn).serve(0x18c6060, {0x402648, 0x18920a8}) task-0: /usr/lib/go-1.22/src/net/http/server.go:2039 +0x61c -task-0: created by net/http.(*Server).Serve in goroutine 23 +task-0: created by net/http.(*Server).Serve in goroutine 10 task-0: /usr/lib/go-1.22/src/net/http/server.go:3285 +0x468 -task-0: --- PASS: TestReconnect (2.01s) +task-0: --- PASS: TestReconnect (2.02s) task-0: === RUN TestConnectFailed -task-0: 2024/05/22 08:36:57 http: panic serving 127.0.0.1:53444: read tcp 127.0.0.1:8999->127.0.0.1:53444: read: connection reset by peer -task-0: goroutine 7 [running]: +task-0: --- PASS: TestConnectFailed (0.00s) +task-0: === RUN TestConnectRetries +task-0: 2024/05/23 10:52:53 http: panic serving 127.0.0.1:43806: websocket: close 1006 (abnormal closure): unexpected EOF +task-0: goroutine 34 [running]: task-0: net/http.(*conn).serve.func1() task-0: /usr/lib/go-1.22/src/net/http/server.go:1898 +0xe4 -task-0: panic({0x35e238, 0x240e1d0}) +task-0: panic({0x34a098, 0x5d1470}) task-0: /usr/lib/go-1.22/src/runtime/panic.go:770 +0xfc -task-0: github.com/mendersoftware/mender-connect/connectionmanager.newWebsocketServer.func2({0x402424, 0x247c468}, 0x247c3c8) +task-0: github.com/mendersoftware/mender-connect/connectionmanager.newWebsocketServer.func2({0x402424, 0x19b60a8}, 0x19b6008) task-0: /build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/connectionmanager/connectionmanager_test.go:61 +0x1f0 -task-0: net/http.HandlerFunc.ServeHTTP(0x2514598, {0x402424, 0x247c468}, 0x247c3c8) +task-0: net/http.HandlerFunc.ServeHTTP(0x1898460, {0x402424, 0x19b60a8}, 0x19b6008) task-0: /usr/lib/go-1.22/src/net/http/server.go:2166 +0x34 -task-0: net/http.(*ServeMux).ServeHTTP(0x2532200, {0x402424, 0x247c468}, 0x247c3c8) +task-0: net/http.(*ServeMux).ServeHTTP(0x18e6000, {0x402424, 0x19b60a8}, 0x19b6008) task-0: /usr/lib/go-1.22/src/net/http/server.go:2683 +0x208 -task-0: net/http.serverHandler.ServeHTTP({0x25246e8}, {0x402424, 0x247c468}, 0x247c3c8) +task-0: net/http.serverHandler.ServeHTTP({0x18c4828}, {0x402424, 0x19b60a8}, 0x19b6008) task-0: /usr/lib/go-1.22/src/net/http/server.go:3137 +0xe0 -task-0: net/http.(*conn).serve(0x24780c0, {0x402648, 0x253a4e0}) +task-0: net/http.(*conn).serve(0x1998000, {0x402648, 0x1892330}) task-0: /usr/lib/go-1.22/src/net/http/server.go:2039 +0x61c -task-0: created by net/http.(*Server).Serve in goroutine 29 +task-0: created by net/http.(*Server).Serve in goroutine 25 task-0: /usr/lib/go-1.22/src/net/http/server.go:3285 +0x468 -task-0: --- PASS: TestConnectFailed (0.00s) -task-0: === RUN TestConnectRetries -task-0: time="2024-05-22T08:36:57-12:00" level=error msg="connection manager failed to connect to ws://localhost:8999/ws: dial tcp 127.0.0.1:8999: connect: connection refused; reconnecting in 1s (try 1/3); len(token)=5" -task-0: time="2024-05-22T08:36:58-12:00" level=error msg="connection manager failed to connect to ws://localhost:8999/ws: dial tcp 127.0.0.1:8999: connect: connection refused; reconnecting in 1s (try 2/3); len(token)=5" -task-0: --- PASS: TestConnectRetries (2.00s) +task-0: time="2024-05-23T10:52:53+14:00" level=error msg="connection manager failed to connect to ws://localhost:8999/ws: dial tcp 127.0.0.1:8999: connect: connection refused; reconnecting in 1s (try 1/3); len(token)=5" +task-0: time="2024-05-23T10:52:54+14:00" level=error msg="connection manager failed to connect to ws://localhost:8999/ws: dial tcp 127.0.0.1:8999: connect: connection refused; reconnecting in 1s (try 2/3); len(token)=5" +task-0: --- PASS: TestConnectRetries (2.02s) task-0: === RUN TestCloseFailed task-0: --- PASS: TestCloseFailed (0.00s) task-0: === RUN TestWriteFailed task-0: --- PASS: TestWriteFailed (0.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/connectionmanager 6.079s +task-0: ok github.com/mendersoftware/mender-connect/connectionmanager 6.126s task-0: === RUN TestGetCounters -task-0: --- PASS: TestGetCounters (8.01s) +task-0: --- PASS: TestGetCounters (8.04s) task-0: === RUN TestUpdateCounters -task-0: limits_test.go:160: after 18s; +{24576 24576 1663.3268261488847 1663.3268261488847 {13946438290936778578 8018489160 0x382e48} {13946438290936780578 8018491160 0x382e48}} 1663.00 vs 1663.33=0.33 1663.00 vs 1663.33=0.33 +task-0: limits_test.go:160: after 18s; +{24576 24576 1663.3268261488847 1663.3268261488847 {13946439320140368436 8055888328 0x382e48} {13946439320140369311 8055889203 0x382e48}} 1663.00 vs 1663.33=0.33 1663.00 vs 1663.33=0.33 task-0: --- PASS: TestUpdateCounters (20.02s) task-0: === RUN TestPermit_PreserveOwnerGroup -task-0: --- PASS: TestPermit_PreserveOwnerGroup (0.00s) +task-0: --- PASS: TestPermit_PreserveOwnerGroup (0.01s) task-0: === RUN TestPermit_PreserveModes task-0: === RUN TestPermit_PreserveModes/owner-group-other_mode task-0: === RUN TestPermit_PreserveModes/owner-group-other_mode_+s @@ -1561,7 +1600,7 @@ task-0: === RUN TestPermit_BelowMaxAllowedFileSize/below_the_limit task-0: === RUN TestPermit_BelowMaxAllowedFileSize/over_the_limit task-0: === RUN TestPermit_BelowMaxAllowedFileSize/at_the_limit -task-0: --- PASS: TestPermit_BelowMaxAllowedFileSize (0.00s) +task-0: --- PASS: TestPermit_BelowMaxAllowedFileSize (0.01s) task-0: --- PASS: TestPermit_BelowMaxAllowedFileSize/below_the_limit (0.00s) task-0: --- PASS: TestPermit_BelowMaxAllowedFileSize/over_the_limit (0.00s) task-0: --- PASS: TestPermit_BelowMaxAllowedFileSize/at_the_limit (0.00s) @@ -1574,7 +1613,7 @@ task-0: === RUN TestPermit_DownloadFile/file_group_match task-0: === RUN TestPermit_DownloadFile/over_the_max_file_size_limit_in_bytes task-0: === RUN TestPermit_DownloadFile/below_the_max_file_size_limit_in_bytes -task-0: --- PASS: TestPermit_DownloadFile (0.00s) +task-0: --- PASS: TestPermit_DownloadFile (0.01s) task-0: --- PASS: TestPermit_DownloadFile/not_a_regular_file (0.00s) task-0: --- PASS: TestPermit_DownloadFile/not_in_a_chroot (0.00s) task-0: --- PASS: TestPermit_DownloadFile/file_owner_mismatch (0.00s) @@ -1595,24 +1634,24 @@ task-0: === RUN TestPermit_UploadFile/file_exists_allowed_to_overwrite_group_match task-0: === RUN TestPermit_UploadFile/suid_bit_not_allowed_in_modes task-0: === RUN TestPermit_UploadFile/suid_bit_allowed_in_modes -task-0: --- PASS: TestPermit_UploadFile (0.01s) +task-0: --- PASS: TestPermit_UploadFile (0.03s) task-0: --- PASS: TestPermit_UploadFile/over_the_max_file_size_limit_in_bytes (0.00s) task-0: --- PASS: TestPermit_UploadFile/not_in_a_chroot (0.00s) -task-0: --- PASS: TestPermit_UploadFile/forbidden_to_follow_links (0.00s) +task-0: --- PASS: TestPermit_UploadFile/forbidden_to_follow_links (0.01s) task-0: --- PASS: TestPermit_UploadFile/file_exists_forbidden_to_overwrite (0.00s) task-0: --- PASS: TestPermit_UploadFile/file_exists_allowed_to_overwrite (0.00s) -task-0: --- PASS: TestPermit_UploadFile/file_exists_allowed_to_overwrite_owner_mismatch (0.00s) +task-0: --- PASS: TestPermit_UploadFile/file_exists_allowed_to_overwrite_owner_mismatch (0.01s) task-0: --- PASS: TestPermit_UploadFile/file_exists_allowed_to_overwrite_owner_match (0.00s) task-0: --- PASS: TestPermit_UploadFile/file_exists_allowed_to_overwrite_group_mismatch (0.00s) task-0: --- PASS: TestPermit_UploadFile/file_exists_allowed_to_overwrite_group_match (0.00s) task-0: --- PASS: TestPermit_UploadFile/suid_bit_not_allowed_in_modes (0.00s) task-0: --- PASS: TestPermit_UploadFile/suid_bit_allowed_in_modes (0.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/limits/filetransfer 28.071s +task-0: ok github.com/mendersoftware/mender-connect/limits/filetransfer 28.175s task-0: === RUN TestMenderShellProcPs -task-0: --- PASS: TestMenderShellProcPs (4.02s) +task-0: --- PASS: TestMenderShellProcPs (4.03s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/procps 4.044s +task-0: ok github.com/mendersoftware/mender-connect/procps 4.063s task-0: === RUN TestFileTransferUpload task-0: === PAUSE TestFileTransferUpload task-0: === RUN TestFileTransferDownload @@ -1624,21 +1663,21 @@ task-0: === RUN TestMenderClientHandler task-0: --- PASS: TestMenderClientHandler (0.00s) task-0: === RUN TestRunCommand -task-0: --- PASS: TestRunCommand (0.00s) +task-0: --- PASS: TestRunCommand (0.03s) task-0: === RUN TestPortForwardHandler -task-0: time="2024-05-22T08:37:13-12:00" level=error msg="portForwardHandler(unknown message type\ngithub.com/mendersoftware/mender-connect/session.init\n\t:1\nruntime.doInit1\n\t/usr/lib/go-1.22/src/runtime/proc.go:7176\nruntime.doInit\n\t/usr/lib/go-1.22/src/runtime/proc.go:7143\nruntime.main\n\t/usr/lib/go-1.22/src/runtime/proc.go:253\nruntime.goexit\n\t/usr/lib/go-1.22/src/runtime/asm_arm.s:859)" -task-0: time="2024-05-22T08:37:13-12:00" level=info msg="port-forward: new session/c1: tcp/localhost:43525" -task-0: time="2024-05-22T08:37:13-12:00" level=error msg="portForwardHandler(dial tcp 127.0.0.1:43525: connect: connection refused)" -task-0: time="2024-05-22T08:37:13-12:00" level=info msg="port-forward: new session/c1: dummy/localhost:36779" -task-0: time="2024-05-22T08:37:13-12:00" level=error msg="portForwardHandler(unknown protocol: dummy\ngithub.com/mendersoftware/mender-connect/session.(*MenderPortForwarder).Connect\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:74\ngithub.com/mendersoftware/mender-connect/session.(*PortForwardHandler).portForwardHandlerNew\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:276\ngithub.com/mendersoftware/mender-connect/session.(*PortForwardHandler).ServeProtoMsg\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:205\ngithub.com/mendersoftware/mender-connect/session.TestPortForwardHandler\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward_test.go:120\ntesting.tRunner\n\t/usr/lib/go-1.22/src/testing/testing.go:1689\nruntime.goexit\n\t/usr/lib/go-1.22/src/runtime/asm_arm.s:859)" -task-0: time="2024-05-22T08:37:13-12:00" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t:1\nruntime.doInit1\n\t/usr/lib/go-1.22/src/runtime/proc.go:7176\nruntime.doInit\n\t/usr/lib/go-1.22/src/runtime/proc.go:7143\nruntime.main\n\t/usr/lib/go-1.22/src/runtime/proc.go:253\nruntime.goexit\n\t/usr/lib/go-1.22/src/runtime/asm_arm.s:859)" -task-0: time="2024-05-22T08:37:13-12:00" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t:1\nruntime.doInit1\n\t/usr/lib/go-1.22/src/runtime/proc.go:7176\nruntime.doInit\n\t/usr/lib/go-1.22/src/runtime/proc.go:7143\nruntime.main\n\t/usr/lib/go-1.22/src/runtime/proc.go:253\nruntime.goexit\n\t/usr/lib/go-1.22/src/runtime/asm_arm.s:859)" +task-0: time="2024-05-23T10:53:06+14:00" level=error msg="portForwardHandler(unknown message type\ngithub.com/mendersoftware/mender-connect/session.init\n\t:1\nruntime.doInit1\n\t/usr/lib/go-1.22/src/runtime/proc.go:7176\nruntime.doInit\n\t/usr/lib/go-1.22/src/runtime/proc.go:7143\nruntime.main\n\t/usr/lib/go-1.22/src/runtime/proc.go:253\nruntime.goexit\n\t/usr/lib/go-1.22/src/runtime/asm_arm.s:859)" +task-0: time="2024-05-23T10:53:06+14:00" level=info msg="port-forward: new session/c1: tcp/localhost:45753" +task-0: time="2024-05-23T10:53:06+14:00" level=error msg="portForwardHandler(dial tcp 127.0.0.1:45753: connect: connection refused)" +task-0: time="2024-05-23T10:53:06+14:00" level=info msg="port-forward: new session/c1: dummy/localhost:39657" +task-0: time="2024-05-23T10:53:06+14:00" level=error msg="portForwardHandler(unknown protocol: dummy\ngithub.com/mendersoftware/mender-connect/session.(*MenderPortForwarder).Connect\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:74\ngithub.com/mendersoftware/mender-connect/session.(*PortForwardHandler).portForwardHandlerNew\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:276\ngithub.com/mendersoftware/mender-connect/session.(*PortForwardHandler).ServeProtoMsg\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:205\ngithub.com/mendersoftware/mender-connect/session.TestPortForwardHandler\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward_test.go:120\ntesting.tRunner\n\t/usr/lib/go-1.22/src/testing/testing.go:1689\nruntime.goexit\n\t/usr/lib/go-1.22/src/runtime/asm_arm.s:859)" +task-0: time="2024-05-23T10:53:06+14:00" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t:1\nruntime.doInit1\n\t/usr/lib/go-1.22/src/runtime/proc.go:7176\nruntime.doInit\n\t/usr/lib/go-1.22/src/runtime/proc.go:7143\nruntime.main\n\t/usr/lib/go-1.22/src/runtime/proc.go:253\nruntime.goexit\n\t/usr/lib/go-1.22/src/runtime/asm_arm.s:859)" +task-0: time="2024-05-23T10:53:06+14:00" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t:1\nruntime.doInit1\n\t/usr/lib/go-1.22/src/runtime/proc.go:7176\nruntime.doInit\n\t/usr/lib/go-1.22/src/runtime/proc.go:7143\nruntime.main\n\t/usr/lib/go-1.22/src/runtime/proc.go:253\nruntime.goexit\n\t/usr/lib/go-1.22/src/runtime/asm_arm.s:859)" task-0: --- PASS: TestPortForwardHandler (0.01s) task-0: === RUN TestPortForwardHandlerSuccessfulConnection -task-0: time="2024-05-22T08:37:15-12:00" level=info msg="port-forward: new session/c1: tcp/localhost:37989" -task-0: time="2024-05-22T08:37:17-12:00" level=info msg="port-forward: new session/c2: tcp/localhost:37989" -task-0: time="2024-05-22T08:37:17-12:00" level=info msg="port-forward: stop session/c1" -task-0: time="2024-05-22T08:37:18-12:00" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t:1\nruntime.doInit1\n\t/usr/lib/go-1.22/src/runtime/proc.go:7176\nruntime.doInit\n\t/usr/lib/go-1.22/src/runtime/proc.go:7143\nruntime.main\n\t/usr/lib/go-1.22/src/runtime/proc.go:253\nruntime.goexit\n\t/usr/lib/go-1.22/src/runtime/asm_arm.s:859)" +task-0: time="2024-05-23T10:53:08+14:00" level=info msg="port-forward: new session/c1: tcp/localhost:45007" +task-0: time="2024-05-23T10:53:10+14:00" level=info msg="port-forward: new session/c2: tcp/localhost:45007" +task-0: time="2024-05-23T10:53:10+14:00" level=info msg="port-forward: stop session/c1" +task-0: time="2024-05-23T10:53:11+14:00" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t:1\nruntime.doInit1\n\t/usr/lib/go-1.22/src/runtime/proc.go:7176\nruntime.doInit\n\t/usr/lib/go-1.22/src/runtime/proc.go:7143\nruntime.main\n\t/usr/lib/go-1.22/src/runtime/proc.go:253\nruntime.goexit\n\t/usr/lib/go-1.22/src/runtime/asm_arm.s:859)" task-0: --- PASS: TestPortForwardHandlerSuccessfulConnection (5.03s) task-0: === RUN TestRouter task-0: === PAUSE TestRouter @@ -1648,78 +1687,76 @@ task-0: === PAUSE TestSessionListen task-0: === RUN TestMenderShellStartStopShell task-0: session_test.go:587: starting mock httpd with websockets -task-0: time="2024-05-22T08:37:18-12:00" level=info msg="mender-connect starting shell command passing process, pid: 31444" +task-0: time="2024-05-23T10:53:11+14:00" level=info msg="mender-connect starting shell command passing process, pid: 28341" task-0: session_test.go:631: created session: task-0: id:c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: createdAt:Wed May 22 20:37:18 +0000 UTC 2024, -task-0: expiresAt:Wed May 22 20:54:22 +0000 UTC 2024 -task-0: now:Wed May 22 08:37:18 -1200 -12 2024 -task-0: time="2024-05-22T08:37:18-12:00" level=info msg="mender-connect starting shell command passing process, pid: 31445" -task-0: time="2024-05-22T08:37:18-12:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" -task-0: time="2024-05-22T08:37:22-12:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:4 stopping shell" -task-0: time="2024-05-22T08:37:22-12:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" -task-0: --- PASS: TestMenderShellStartStopShell (8.03s) +task-0: createdAt:Wed May 22 20:53:11 +0000 UTC 2024, +task-0: expiresAt:Wed May 22 21:10:15 +0000 UTC 2024 +task-0: now:Thu May 23 10:53:11 +1400 +14 2024 +task-0: time="2024-05-23T10:53:11+14:00" level=info msg="mender-connect starting shell command passing process, pid: 28342" +task-0: time="2024-05-23T10:53:11+14:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: time="2024-05-23T10:53:15+14:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:4 stopping shell" +task-0: time="2024-05-23T10:53:15+14:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: --- PASS: TestMenderShellStartStopShell (8.05s) task-0: === RUN TestMenderShellCommand task-0: session_test.go:680: starting mock httpd with websockets -task-0: time="2024-05-22T08:37:26-12:00" level=info msg="mender-connect starting shell command passing process, pid: 31461" +task-0: time="2024-05-23T10:53:19+14:00" level=info msg="mender-connect starting shell command passing process, pid: 28710" task-0: --- PASS: TestMenderShellCommand (0.01s) task-0: === RUN TestMenderShellShellAlreadyStartedFailedToStart +task-0: time="2024-05-23T10:53:19+14:00" level=error msg="error reading stdout: read /dev/ptmx: file already closed" task-0: session_test.go:757: starting mock httpd with websockets -task-0: time="2024-05-22T08:37:26-12:00" level=error msg="error reading stdout: read /dev/ptmx: file already closed" -task-0: time="2024-05-22T08:37:26-12:00" level=info msg="mender-connect starting shell command passing process, pid: 31462" -task-0: time="2024-05-22T08:37:26-12:00" level=error msg="failed to start shell: shell is already running" -task-0: time="2024-05-22T08:37:26-12:00" level=error msg="failed to start shell: fork/exec thatissomethingelse/bin/sh: no such file or directory" -task-0: --- PASS: TestMenderShellShellAlreadyStartedFailedToStart (0.02s) +task-0: time="2024-05-23T10:53:19+14:00" level=info msg="mender-connect starting shell command passing process, pid: 28712" +task-0: time="2024-05-23T10:53:19+14:00" level=error msg="failed to start shell: shell is already running" +task-0: time="2024-05-23T10:53:19+14:00" level=error msg="failed to start shell: fork/exec thatissomethingelse/bin/sh: no such file or directory" +task-0: --- PASS: TestMenderShellShellAlreadyStartedFailedToStart (0.01s) task-0: === RUN TestMenderShellSessionExpire -task-0: time="2024-05-22T08:37:26-12:00" level=info msg="mender-connect starting shell command passing process, pid: 31464" +task-0: time="2024-05-23T10:53:19+14:00" level=info msg="mender-connect starting shell command passing process, pid: 28714" task-0: --- PASS: TestMenderShellSessionExpire (4.01s) task-0: === RUN TestMenderShellSessionUpdateWS -task-0: time="2024-05-22T08:37:30-12:00" level=info msg="mender-connect starting shell command passing process, pid: 31473" -task-0: --- PASS: TestMenderShellSessionUpdateWS (0.00s) +task-0: time="2024-05-23T10:53:23+14:00" level=info msg="mender-connect starting shell command passing process, pid: 29182" +task-0: --- PASS: TestMenderShellSessionUpdateWS (0.02s) task-0: === RUN TestMenderShellSessionGetByUserId task-0: --- PASS: TestMenderShellSessionGetByUserId (0.00s) task-0: === RUN TestMenderShellSessionGetById task-0: --- PASS: TestMenderShellSessionGetById (0.00s) task-0: === RUN TestMenderShellDeleteById -task-0: --- PASS: TestMenderShellDeleteById (0.00s) +task-0: --- PASS: TestMenderShellDeleteById (0.01s) task-0: === RUN TestMenderShellNewMenderShellSession -task-0: --- PASS: TestMenderShellNewMenderShellSession (0.03s) +task-0: --- PASS: TestMenderShellNewMenderShellSession (0.01s) task-0: === RUN TestMenderSessionTerminateExpired task-0: session_test.go:1142: created session: task-0: id:c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: createdAt:Wed May 22 20:37:30 +0000 UTC 2024, -task-0: expiresAt:Wed May 22 20:37:38 +0000 UTC 2024 -task-0: now:Wed May 22 08:37:30 -1200 -12 2024 -task-0: time="2024-05-22T08:37:30-12:00" level=info msg="mender-connect starting shell command passing process, pid: 31476" -task-0: time="2024-05-22T08:37:46-12:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" -task-0: --- PASS: TestMenderSessionTerminateExpired (20.01s) +task-0: createdAt:Wed May 22 20:53:23 +0000 UTC 2024, +task-0: expiresAt:Wed May 22 20:53:31 +0000 UTC 2024 +task-0: now:Thu May 23 10:53:23 +1400 +14 2024 +task-0: time="2024-05-23T10:53:23+14:00" level=info msg="mender-connect starting shell command passing process, pid: 29185" +task-0: time="2024-05-23T10:53:39+14:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: --- PASS: TestMenderSessionTerminateExpired (20.03s) task-0: === RUN TestMenderSessionTerminateAll task-0: session_test.go:1194: created session: -task-0: id:0bc3989b-1822-45c9-bf59-1a2d7e1a4937, -task-0: createdAt:Wed May 22 20:37:50 +0000 UTC 2024, -task-0: expiresAt:Wed May 22 20:37:58 +0000 UTC 2024 -task-0: now:Wed May 22 08:37:50 -1200 -12 2024 -task-0: time="2024-05-22T08:37:50-12:00" level=info msg="mender-connect starting shell command passing process, pid: 31504" +task-0: id:d3711b2f-e1c2-426c-8fb4-cc6f9909b98e, +task-0: createdAt:Wed May 22 20:53:43 +0000 UTC 2024, +task-0: expiresAt:Wed May 22 20:53:51 +0000 UTC 2024 +task-0: now:Thu May 23 10:53:43 +1400 +14 2024 +task-0: time="2024-05-23T10:53:43+14:00" level=info msg="mender-connect starting shell command passing process, pid: 30049" task-0: session_test.go:1210: created session: -task-0: id:5fa8f3fe-a8bf-4196-bfe1-3e5c353412dc, -task-0: createdAt:Wed May 22 20:37:50 +0000 UTC 2024, -task-0: expiresAt:Wed May 22 20:37:58 +0000 UTC 2024 -task-0: now:Wed May 22 08:37:50 -1200 -12 2024 -task-0: time="2024-05-22T08:37:50-12:00" level=info msg="mender-connect starting shell command passing process, pid: 31505" -task-0: time="2024-05-22T08:37:50-12:00" level=info msg="session 0bc3989b-1822-45c9-bf59-1a2d7e1a4937 status:0 stopping shell" -task-0: time="2024-05-22T08:37:50-12:00" level=error msg="error reading stdout: read /dev/ptmx: input/output error" -task-0: time="2024-05-22T08:37:54-12:00" level=error msg="session 0bc3989b-1822-45c9-bf59-1a2d7e1a4937, shell pid 31504, termination error: error waiting for the process: signal: interrupt" -task-0: time="2024-05-22T08:37:54-12:00" level=info msg="session 5fa8f3fe-a8bf-4196-bfe1-3e5c353412dc status:0 stopping shell" -task-0: --- PASS: TestMenderSessionTerminateAll (8.01s) +task-0: id:23bffef0-dd95-452a-a9bc-bf20744a7c96, +task-0: createdAt:Wed May 22 20:53:43 +0000 UTC 2024, +task-0: expiresAt:Wed May 22 20:53:51 +0000 UTC 2024 +task-0: now:Thu May 23 10:53:43 +1400 +14 2024 +task-0: time="2024-05-23T10:53:43+14:00" level=info msg="mender-connect starting shell command passing process, pid: 30050" +task-0: time="2024-05-23T10:53:43+14:00" level=info msg="session d3711b2f-e1c2-426c-8fb4-cc6f9909b98e status:0 stopping shell" +task-0: time="2024-05-23T10:53:47+14:00" level=info msg="session 23bffef0-dd95-452a-a9bc-bf20744a7c96 status:0 stopping shell" +task-0: --- PASS: TestMenderSessionTerminateAll (8.06s) task-0: === RUN TestMenderSessionTerminateIdle task-0: session_test.go:1251: created session: task-0: id:c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: createdAt:Wed May 22 20:37:58 +0000 UTC 2024, -task-0: expiresAt:Wed May 22 20:42:13 +0000 UTC 2024 -task-0: now:Wed May 22 08:37:58 -1200 -12 2024 -task-0: time="2024-05-22T08:37:58-12:00" level=info msg="mender-connect starting shell command passing process, pid: 31506" -task-0: time="2024-05-22T08:38:06-12:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" -task-0: --- PASS: TestMenderSessionTerminateIdle (12.02s) +task-0: createdAt:Wed May 22 20:53:51 +0000 UTC 2024, +task-0: expiresAt:Wed May 22 20:58:06 +0000 UTC 2024 +task-0: now:Thu May 23 10:53:51 +1400 +14 2024 +task-0: time="2024-05-23T10:53:51+14:00" level=info msg="mender-connect starting shell command passing process, pid: 30138" +task-0: time="2024-05-23T10:53:59+14:00" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: --- PASS: TestMenderSessionTerminateIdle (12.01s) task-0: === RUN TestMenderSessionTimeNow task-0: --- PASS: TestMenderSessionTimeNow (0.00s) task-0: === CONT TestFileTransferUpload @@ -1744,14 +1781,10 @@ task-0: === RUN TestFileTransferUpload/error,_parent_directory_does_not_exist task-0: === PAUSE TestFileTransferUpload/error,_parent_directory_does_not_exist task-0: === CONT TestFileTransferUpload/ok -task-0: === CONT TestSessionListen task-0: === CONT TestFileTransferUpload/error,_broken_response_writer -task-0: === CONT TestFileTransferUpload/error,_fake_error_from_client -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="failed to respond to client: io: read/write on closed pipe" -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="Received error during upload: something unexpected happened" -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="handler aborted" -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="handler aborted" -task-0: === CONT TestFileTransferUpload/error,_offset_jumps_beyond_EOF +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="failed to respond to client: io: read/write on closed pipe" +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="handler aborted" +task-0: === CONT TestSessionListen task-0: === RUN TestSessionListen/ok task-0: === PAUSE TestSessionListen/ok task-0: === RUN TestSessionListen/ok,_ping/pong_->_close @@ -1764,11 +1797,9 @@ task-0: === PAUSE TestSessionListen/error,_bad_handshake_schema task-0: === RUN TestSessionListen/ok,_accepted task-0: === PAUSE TestSessionListen/ok,_accepted -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="received unexpected chunk offset" task-0: === RUN TestSessionListen/error,_malformed_handshake_response task-0: === PAUSE TestSessionListen/error,_malformed_handshake_response task-0: === RUN TestSessionListen/error,_invalid_handshake_version -task-0: === CONT TestFileTransferUpload/error,_chunk_missing_offset task-0: === PAUSE TestSessionListen/error,_invalid_handshake_version task-0: === RUN TestSessionListen/error,_control_message_not_understood task-0: === PAUSE TestSessionListen/error,_control_message_not_understood @@ -1780,41 +1811,52 @@ task-0: === PAUSE TestSessionListen/error,_ping_write_error task-0: === RUN TestSessionListen/error,_write_error task-0: === PAUSE TestSessionListen/error,_write_error +task-0: === CONT TestSessionListen/ok +task-0: === CONT TestRouterRace +task-0: === CONT TestRouter +task-0: === RUN TestRouter/ok +task-0: === PAUSE TestRouter/ok +task-0: === CONT TestRouter/ok +task-0: === CONT TestFileTransferUpload/error,_fake_error_from_client +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="Received error during upload: something unexpected happened" +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="handler aborted" +task-0: === CONT TestFileTransferUpload/error,_offset_jumps_beyond_EOF +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="received unexpected chunk offset" +task-0: === CONT TestFileTransferUpload/error,_chunk_missing_offset +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="invalid file chunk message: missing offset property" task-0: === CONT TestFileTransferUpload/error,_unexpected_ACK_message_from_client -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="invalid file chunk message: missing offset property" +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="received unexpected message type 'ack' during file upload" +task-0: === CONT TestSessionListen/error,_bad_protocol_->_close_error +task-0: === CONT TestFileTransferUpload/error,_file_too_big_upload_denied +task-0: --- PASS: TestRouter (0.00s) +task-0: --- PASS: TestRouter/ok (0.01s) +task-0: === CONT TestSessionListen/error,_control_message_not_understood +task-0: === CONT TestSessionListen/error,_invalid_handshake_version +task-0: === CONT TestSessionListen/error,_malformed_handshake_response +task-0: === CONT TestSessionListen/ok,_accepted +task-0: === CONT TestSessionListen/error,_bad_handshake_schema +task-0: === CONT TestSessionListen/error,_protocol_version_not_supported +task-0: === CONT TestFileTransferUpload/error,_path_is_a_directory +task-0: === CONT TestSessionListen/ok,_handshake +task-0: === CONT TestFileTransferUpload/ok,_relative_path +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="session: received error from client: dunno what to do next..." +task-0: === CONT TestSessionListen/ok,_ping/pong_->_close +task-0: time="2024-05-23T10:54:03+14:00" level=info msg="session: closed 1234" +task-0: === CONT TestFileTransferUpload/error,_parent_directory_does_not_exist +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="failed to create file: open /tmp/filetransfer-testing2099839212/parent/dir/does/not/exist/for/this/file.0000000800: no such file or directory" task-0: === CONT TestFileTransferServeErrors -task-0: === CONT TestRouterRace -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="received unexpected message type 'ack' during file upload" +task-0: === CONT TestFileTransferStat task-0: === CONT TestFileTransferDownload -task-0: === RUN TestFileTransferServeErrors/malformed_upload_request -task-0: === PAUSE TestFileTransferServeErrors/malformed_upload_request -task-0: === RUN TestFileTransferServeErrors/invalid_upload_request_parameters -task-0: === PAUSE TestFileTransferServeErrors/invalid_upload_request_parameters -task-0: === RUN TestFileTransferServeErrors/upload_already_in_progress -task-0: === PAUSE TestFileTransferServeErrors/upload_already_in_progress -task-0: === RUN TestFileTransferServeErrors/malformed_download_request -task-0: === PAUSE TestFileTransferServeErrors/malformed_download_request -task-0: === RUN TestFileTransferServeErrors/invalid_download_request_parameters task-0: === RUN TestFileTransferDownload/ok -task-0: === PAUSE TestFileTransferServeErrors/invalid_download_request_parameters task-0: === PAUSE TestFileTransferDownload/ok -task-0: === CONT TestRouter -task-0: === RUN TestFileTransferServeErrors/download_already_in_progress task-0: === RUN TestFileTransferDownload/ok,_file_larger_than_window task-0: === PAUSE TestFileTransferDownload/ok,_file_larger_than_window -task-0: === PAUSE TestFileTransferServeErrors/download_already_in_progress task-0: === RUN TestFileTransferDownload/error,_bad_ack_data_type -task-0: === RUN TestFileTransferServeErrors/got_chunk_but_no_file_transfer_in_progress task-0: === PAUSE TestFileTransferDownload/error,_bad_ack_data_type -task-0: === PAUSE TestFileTransferServeErrors/got_chunk_but_no_file_transfer_in_progress task-0: === RUN TestFileTransferDownload/error,_no_offset_in_ack -task-0: === RUN TestFileTransferServeErrors/generic_error_from_client task-0: === PAUSE TestFileTransferDownload/error,_no_offset_in_ack -task-0: === RUN TestRouter/ok task-0: === RUN TestFileTransferDownload/error,_unexpected_ack_message -task-0: === PAUSE TestRouter/ok task-0: === PAUSE TestFileTransferDownload/error,_unexpected_ack_message -task-0: === CONT TestFileTransferStat task-0: === RUN TestFileTransferDownload/error,_client_malformed_error_message task-0: === PAUSE TestFileTransferDownload/error,_client_malformed_error_message task-0: === RUN TestFileTransferDownload/error,_client_error_message @@ -1823,152 +1865,147 @@ task-0: === PAUSE TestFileTransferDownload/error,_file_does_not_exist task-0: === RUN TestFileTransferDownload/error,_forbidden_to_follow_links task-0: === PAUSE TestFileTransferDownload/error,_forbidden_to_follow_links -task-0: === PAUSE TestFileTransferServeErrors/generic_error_from_client -task-0: === RUN TestFileTransferStat/ok -task-0: === RUN TestFileTransferServeErrors/malformed_error_from_client -task-0: === PAUSE TestFileTransferStat/ok -task-0: === PAUSE TestFileTransferServeErrors/malformed_error_from_client -task-0: === RUN TestFileTransferStat/error,_malformed_schema -task-0: === RUN TestFileTransferServeErrors/message_type_not_implemented -task-0: === PAUSE TestFileTransferStat/error,_malformed_schema -task-0: === RUN TestFileTransferStat/error,_invalid_parameters -task-0: === PAUSE TestFileTransferStat/error,_invalid_parameters -task-0: === RUN TestFileTransferStat/error,_invalid_parameters#01 -task-0: === PAUSE TestFileTransferStat/error,_invalid_parameters#01 -task-0: === CONT TestFileTransferUpload/error,_path_is_a_directory -task-0: === PAUSE TestFileTransferServeErrors/message_type_not_implemented -task-0: === CONT TestFileTransferUpload/error,_file_too_big_upload_denied -task-0: === CONT TestFileTransferUpload/ok,_relative_path -task-0: === CONT TestFileTransferUpload/error,_parent_directory_does_not_exist -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="failed to create file: open /tmp/filetransfer-testing2743017960/parent/dir/does/not/exist/for/this/file.0000000800: no such file or directory" -task-0: === CONT TestSessionListen/ok -task-0: === CONT TestSessionListen/error,_invalid_handshake_version -task-0: === CONT TestSessionListen/error,_write_error -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="failed to write response to client: this is bad!" task-0: === CONT TestSessionListen/error,_ping_write_error -task-0: === CONT TestSessionListen/error,_session_timeout task-0: --- PASS: TestFileTransferUpload (0.00s) task-0: --- PASS: TestFileTransferUpload/error,_broken_response_writer (0.00s) +task-0: --- PASS: TestFileTransferUpload/error,_fake_error_from_client (0.00s) task-0: --- PASS: TestFileTransferUpload/error,_offset_jumps_beyond_EOF (0.00s) task-0: --- PASS: TestFileTransferUpload/error,_chunk_missing_offset (0.00s) -task-0: --- PASS: TestFileTransferUpload/ok (0.01s) -task-0: --- PASS: TestFileTransferUpload/error,_fake_error_from_client (0.01s) task-0: --- PASS: TestFileTransferUpload/error,_unexpected_ACK_message_from_client (0.00s) +task-0: --- PASS: TestFileTransferUpload/error,_file_too_big_upload_denied (0.01s) task-0: --- PASS: TestFileTransferUpload/error,_path_is_a_directory (0.00s) task-0: --- PASS: TestFileTransferUpload/ok,_relative_path (0.00s) task-0: --- PASS: TestFileTransferUpload/error,_parent_directory_does_not_exist (0.00s) -task-0: --- PASS: TestFileTransferUpload/error,_file_too_big_upload_denied (0.01s) -task-0: === CONT TestSessionListen/error,_bad_protocol_->_close_error -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="session: received error from client: dunno what to do next..." -task-0: === CONT TestSessionListen/error,_control_message_not_understood -task-0: === CONT TestSessionListen/error,_bad_handshake_schema -task-0: === CONT TestSessionListen/error,_malformed_handshake_response -task-0: === CONT TestSessionListen/ok,_accepted -task-0: === CONT TestSessionListen/ok,_handshake -task-0: time="2024-05-22T08:38:10-12:00" level=info msg="session: accepting new session with ID: 1234" -task-0: === CONT TestSessionListen/error,_protocol_version_not_supported -task-0: === CONT TestSessionListen/ok,_ping/pong_->_close -task-0: time="2024-05-22T08:38:10-12:00" level=info msg="session: closed 1234" -task-0: === CONT TestRouter/ok -task-0: --- PASS: TestRouter (0.00s) -task-0: --- PASS: TestRouter/ok (0.00s) +task-0: --- PASS: TestFileTransferUpload/ok (0.02s) +task-0: === CONT TestSessionListen/error,_write_error +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="failed to write response to client: this is bad!" +task-0: === CONT TestSessionListen/error,_session_timeout +task-0: time="2024-05-23T10:54:03+14:00" level=info msg="session: accepting new session with ID: 1234" +task-0: === RUN TestFileTransferServeErrors/malformed_upload_request +task-0: === PAUSE TestFileTransferServeErrors/malformed_upload_request +task-0: === RUN TestFileTransferServeErrors/invalid_upload_request_parameters +task-0: === PAUSE TestFileTransferServeErrors/invalid_upload_request_parameters +task-0: === RUN TestFileTransferServeErrors/upload_already_in_progress +task-0: === PAUSE TestFileTransferServeErrors/upload_already_in_progress +task-0: === RUN TestFileTransferServeErrors/malformed_download_request +task-0: === PAUSE TestFileTransferServeErrors/malformed_download_request +task-0: === RUN TestFileTransferServeErrors/invalid_download_request_parameters +task-0: === PAUSE TestFileTransferServeErrors/invalid_download_request_parameters +task-0: === RUN TestFileTransferServeErrors/download_already_in_progress +task-0: === PAUSE TestFileTransferServeErrors/download_already_in_progress +task-0: === RUN TestFileTransferServeErrors/got_chunk_but_no_file_transfer_in_progress +task-0: === PAUSE TestFileTransferServeErrors/got_chunk_but_no_file_transfer_in_progress +task-0: === RUN TestFileTransferServeErrors/generic_error_from_client +task-0: === PAUSE TestFileTransferServeErrors/generic_error_from_client +task-0: === RUN TestFileTransferServeErrors/malformed_error_from_client +task-0: === PAUSE TestFileTransferServeErrors/malformed_error_from_client +task-0: === RUN TestFileTransferServeErrors/message_type_not_implemented +task-0: === PAUSE TestFileTransferServeErrors/message_type_not_implemented task-0: === CONT TestFileTransferDownload/ok -task-0: === CONT TestFileTransferStat/ok -task-0: === CONT TestFileTransferServeErrors/malformed_upload_request -task-0: === CONT TestFileTransferStat/error,_invalid_parameters#01 -task-0: === CONT TestFileTransferStat/error,_invalid_parameters -task-0: === CONT TestFileTransferStat/error,_malformed_schema -task-0: --- PASS: TestFileTransferStat (0.00s) -task-0: --- PASS: TestFileTransferStat/ok (0.00s) -task-0: --- PASS: TestFileTransferStat/error,_invalid_parameters#01 (0.00s) -task-0: --- PASS: TestFileTransferStat/error,_invalid_parameters (0.00s) -task-0: --- PASS: TestFileTransferStat/error,_malformed_schema (0.00s) -task-0: === CONT TestFileTransferServeErrors/download_already_in_progress -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="another file transfer is in progress" -task-0: === CONT TestFileTransferServeErrors/message_type_not_implemented -task-0: === CONT TestFileTransferServeErrors/malformed_error_from_client -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="Error decoding error message from client: msgpack: unexpected code=73 decoding map length" -task-0: === CONT TestFileTransferServeErrors/generic_error_from_client -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="Received error from client: generic error" -task-0: === CONT TestFileTransferServeErrors/got_chunk_but_no_file_transfer_in_progress -task-0: === CONT TestFileTransferDownload/error,_client_malformed_error_message -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="received malformed error message from client: aborting" task-0: === CONT TestFileTransferDownload/error,_forbidden_to_follow_links -task-0: time="2024-05-22T08:38:10-12:00" level=warning msg="file download access denied: forbidden to follow the link" -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="access denied: forbidden to follow the link" +task-0: === RUN TestFileTransferStat/ok +task-0: === PAUSE TestFileTransferStat/ok +task-0: === RUN TestFileTransferStat/error,_malformed_schema +task-0: === PAUSE TestFileTransferStat/error,_malformed_schema +task-0: === RUN TestFileTransferStat/error,_invalid_parameters +task-0: === PAUSE TestFileTransferStat/error,_invalid_parameters +task-0: === RUN TestFileTransferStat/error,_invalid_parameters#01 +task-0: === PAUSE TestFileTransferStat/error,_invalid_parameters#01 task-0: === CONT TestFileTransferDownload/error,_file_does_not_exist -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="failed to open file for reading: open lets say it does not exist: no such file or directory" +task-0: time="2024-05-23T10:54:03+14:00" level=warning msg="file download access denied: forbidden to follow the link" +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="access denied: forbidden to follow the link" task-0: === CONT TestFileTransferDownload/error,_client_error_message -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="received error message from client: ENOSPC" -task-0: === CONT TestFileTransferDownload/error,_no_offset_in_ack -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="ack message: offset property cannot be blank" +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="received error message from client: ENOSPC" +task-0: === CONT TestFileTransferDownload/error,_client_malformed_error_message task-0: === CONT TestFileTransferDownload/error,_unexpected_ack_message -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="received unexpected message type 'file_chunk'; expected 'ack'" -task-0: === CONT TestFileTransferServeErrors/malformed_download_request -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="malformed request parameters: msgpack: unexpected code=2f decoding map length" -task-0: === CONT TestFileTransferServeErrors/invalid_download_request_parameters -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="invalid request parameters: path: cannot be blank." +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="received malformed error message from client: aborting" task-0: === CONT TestFileTransferDownload/error,_bad_ack_data_type -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="invalid offset data type: require int64" +task-0: === CONT TestFileTransferDownload/error,_no_offset_in_ack +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="ack message: offset property cannot be blank" +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="failed to open file for reading: open lets say it does not exist: no such file or directory" task-0: === CONT TestFileTransferDownload/ok,_file_larger_than_window +task-0: === CONT TestFileTransferServeErrors/malformed_upload_request +task-0: === CONT TestFileTransferServeErrors/got_chunk_but_no_file_transfer_in_progress +task-0: === CONT TestFileTransferServeErrors/download_already_in_progress +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="another file transfer is in progress" +task-0: === CONT TestFileTransferServeErrors/invalid_download_request_parameters +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="invalid request parameters: path: cannot be blank." +task-0: === CONT TestFileTransferServeErrors/malformed_download_request +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="malformed request parameters: msgpack: unexpected code=2f decoding map length" task-0: === CONT TestFileTransferServeErrors/upload_already_in_progress task-0: === CONT TestFileTransferServeErrors/invalid_upload_request_parameters -task-0: --- PASS: TestFileTransferServeErrors (0.01s) +task-0: === CONT TestFileTransferServeErrors/message_type_not_implemented +task-0: === CONT TestFileTransferServeErrors/malformed_error_from_client +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="Error decoding error message from client: msgpack: unexpected code=73 decoding map length" +task-0: === CONT TestFileTransferServeErrors/generic_error_from_client +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="Received error from client: generic error" +task-0: --- PASS: TestFileTransferServeErrors (0.02s) task-0: --- PASS: TestFileTransferServeErrors/malformed_upload_request (0.00s) -task-0: --- PASS: TestFileTransferServeErrors/download_already_in_progress (0.00s) -task-0: --- PASS: TestFileTransferServeErrors/message_type_not_implemented (0.00s) -task-0: --- PASS: TestFileTransferServeErrors/malformed_error_from_client (0.00s) -task-0: --- PASS: TestFileTransferServeErrors/generic_error_from_client (0.00s) task-0: --- PASS: TestFileTransferServeErrors/got_chunk_but_no_file_transfer_in_progress (0.00s) -task-0: --- PASS: TestFileTransferServeErrors/malformed_download_request (0.00s) +task-0: --- PASS: TestFileTransferServeErrors/download_already_in_progress (0.00s) task-0: --- PASS: TestFileTransferServeErrors/invalid_download_request_parameters (0.00s) +task-0: --- PASS: TestFileTransferServeErrors/malformed_download_request (0.00s) task-0: --- PASS: TestFileTransferServeErrors/upload_already_in_progress (0.00s) task-0: --- PASS: TestFileTransferServeErrors/invalid_upload_request_parameters (0.00s) -task-0: --- PASS: TestFileTransferDownload (0.01s) -task-0: --- PASS: TestFileTransferDownload/ok (0.00s) -task-0: --- PASS: TestFileTransferDownload/error,_client_malformed_error_message (0.00s) +task-0: --- PASS: TestFileTransferServeErrors/message_type_not_implemented (0.00s) +task-0: --- PASS: TestFileTransferServeErrors/malformed_error_from_client (0.00s) +task-0: --- PASS: TestFileTransferServeErrors/generic_error_from_client (0.00s) +task-0: === CONT TestFileTransferStat/ok +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="received unexpected message type 'file_chunk'; expected 'ack'" +task-0: === CONT TestFileTransferStat/error,_invalid_parameters +task-0: === CONT TestFileTransferStat/error,_invalid_parameters#01 +task-0: === CONT TestFileTransferStat/error,_malformed_schema +task-0: --- PASS: TestFileTransferStat (0.02s) +task-0: --- PASS: TestFileTransferStat/ok (0.00s) +task-0: --- PASS: TestFileTransferStat/error,_invalid_parameters (0.00s) +task-0: --- PASS: TestFileTransferStat/error,_invalid_parameters#01 (0.00s) +task-0: --- PASS: TestFileTransferStat/error,_malformed_schema (0.00s) +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="invalid offset data type: require int64" +task-0: --- PASS: TestFileTransferDownload (0.00s) task-0: --- PASS: TestFileTransferDownload/error,_forbidden_to_follow_links (0.00s) -task-0: --- PASS: TestFileTransferDownload/error,_file_does_not_exist (0.00s) -task-0: --- PASS: TestFileTransferDownload/error,_client_error_message (0.00s) -task-0: --- PASS: TestFileTransferDownload/error,_no_offset_in_ack (0.00s) +task-0: --- PASS: TestFileTransferDownload/ok (0.01s) +task-0: --- PASS: TestFileTransferDownload/error,_client_error_message (0.01s) task-0: --- PASS: TestFileTransferDownload/error,_unexpected_ack_message (0.00s) -task-0: --- PASS: TestFileTransferDownload/error,_bad_ack_data_type (0.00s) +task-0: --- PASS: TestFileTransferDownload/error,_client_malformed_error_message (0.00s) +task-0: --- PASS: TestFileTransferDownload/error,_file_does_not_exist (0.01s) +task-0: --- PASS: TestFileTransferDownload/error,_no_offset_in_ack (0.00s) task-0: --- PASS: TestFileTransferDownload/ok,_file_larger_than_window (0.01s) -task-0: time="2024-05-22T08:38:10-12:00" level=error msg="failed to ping client: this is bad!" -task-0: --- PASS: TestSessionListen (0.01s) +task-0: --- PASS: TestFileTransferDownload/error,_bad_ack_data_type (0.01s) +task-0: time="2024-05-23T10:54:03+14:00" level=error msg="failed to ping client: this is bad!" +task-0: --- PASS: TestSessionListen (0.00s) task-0: --- PASS: TestSessionListen/ok (0.00s) -task-0: --- PASS: TestSessionListen/error,_invalid_handshake_version (0.00s) -task-0: --- PASS: TestSessionListen/error,_write_error (0.00s) -task-0: --- PASS: TestSessionListen/error,_bad_protocol_->_close_error (0.00s) task-0: --- PASS: TestSessionListen/error,_control_message_not_understood (0.00s) -task-0: --- PASS: TestSessionListen/error,_bad_handshake_schema (0.00s) +task-0: --- PASS: TestSessionListen/error,_invalid_handshake_version (0.00s) task-0: --- PASS: TestSessionListen/error,_malformed_handshake_response (0.00s) task-0: --- PASS: TestSessionListen/ok,_accepted (0.00s) -task-0: --- PASS: TestSessionListen/ok,_handshake (0.00s) -task-0: --- PASS: TestSessionListen/error,_protocol_version_not_supported (0.00s) +task-0: --- PASS: TestSessionListen/error,_bad_handshake_schema (0.00s) +task-0: --- PASS: TestSessionListen/error,_bad_protocol_->_close_error (0.01s) task-0: --- PASS: TestSessionListen/ok,_ping/pong_->_close (0.00s) +task-0: --- PASS: TestSessionListen/error,_protocol_version_not_supported (0.02s) +task-0: --- PASS: TestSessionListen/error,_write_error (0.00s) +task-0: --- PASS: TestSessionListen/ok,_handshake (0.02s) task-0: --- PASS: TestSessionListen/error,_ping_write_error (0.20s) -task-0: --- PASS: TestSessionListen/error,_session_timeout (0.25s) -task-0: time="2024-05-22T08:38:11-12:00" level=error msg="[panic] panicHandler" trace="\n:1.(*panicHandler).ServeProtoMsg\n/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/session.go:368.(*Session).ListenAndServe\n/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/router.go:56.(*router).startSession\n/usr/lib/go-1.22/src/runtime/asm_arm.s:860.goexit" +task-0: --- PASS: TestSessionListen/error,_session_timeout (0.26s) +task-0: time="2024-05-23T10:54:04+14:00" level=error msg="[panic] panicHandler" trace="\n:1.(*panicHandler).ServeProtoMsg\n/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/session.go:368.(*Session).ListenAndServe\n/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/router.go:56.(*router).startSession\n/usr/lib/go-1.22/src/runtime/asm_arm.s:860.goexit" task-0: --- PASS: TestRouterRace (1.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/session 58.248s +task-0: ok github.com/mendersoftware/mender-connect/session 58.352s task-0: === RUN TestNewMenderShell task-0: --- PASS: TestNewMenderShell (0.00s) task-0: === RUN TestNewMenderShellReadStdIn -task-0: --- PASS: TestNewMenderShellReadStdIn (8.01s) +task-0: --- PASS: TestNewMenderShellReadStdIn (8.02s) task-0: === RUN TestPipeStdout task-0: exec_test.go:156: starting mock httpd with websockets -task-0: time="2024-05-22T08:37:35-12:00" level=error msg="error reading stdout: EOF" -task-0: --- PASS: TestPipeStdout (8.00s) +task-0: time="2024-05-23T10:53:13+14:00" level=error msg="error reading stdout: EOF" +task-0: --- PASS: TestPipeStdout (8.01s) task-0: === RUN TestMenderShellExecShell -task-0: shell_test.go:82: started shell, pid: 31503 -task-0: shell_test.go:85: FindProcess p: &{31503 0 {{} 0} {{0 0} 0 0 {{} 0} {{} 0}}} err: -task-0: --- PASS: TestMenderShellExecShell (4.01s) +task-0: shell_test.go:82: started shell, pid: 29114 +task-0: shell_test.go:85: FindProcess p: &{29114 0 {{} 0} {{0 0} 0 0 {{} 0} {{} 0}}} err: +task-0: --- PASS: TestMenderShellExecShell (4.06s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/shell 20.057s +task-0: ok github.com/mendersoftware/mender-connect/shell 20.144s task-0: === RUN TestFileSize -task-0: --- PASS: TestFileSize (0.00s) +task-0: --- PASS: TestFileSize (0.01s) task-0: === RUN TestFileExists task-0: --- PASS: TestFileExists (0.00s) task-0: === RUN TestFileGetUidGid @@ -1984,29 +2021,29 @@ task-0: === RUN TestNum64 task-0: === RUN TestNum64/uint32 task-0: === RUN TestNum64/uint64 -task-0: === RUN TestNum64/int +task-0: === RUN TestNum64/int16 task-0: === RUN TestNum64/int32 -task-0: === RUN TestNum64/int64 task-0: === RUN TestNum64/uint task-0: === RUN TestNum64/uint8 task-0: === RUN TestNum64/uint16 -task-0: === RUN TestNum64/uintptr +task-0: === RUN TestNum64/int task-0: === RUN TestNum64/int8 -task-0: === RUN TestNum64/int16 +task-0: === RUN TestNum64/int64 +task-0: === RUN TestNum64/uintptr task-0: --- PASS: TestNum64 (0.00s) task-0: --- PASS: TestNum64/uint32 (0.00s) task-0: --- PASS: TestNum64/uint64 (0.00s) -task-0: --- PASS: TestNum64/int (0.00s) +task-0: --- PASS: TestNum64/int16 (0.00s) task-0: --- PASS: TestNum64/int32 (0.00s) -task-0: --- PASS: TestNum64/int64 (0.00s) task-0: --- PASS: TestNum64/uint (0.00s) task-0: --- PASS: TestNum64/uint8 (0.00s) task-0: --- PASS: TestNum64/uint16 (0.00s) -task-0: --- PASS: TestNum64/uintptr (0.00s) +task-0: --- PASS: TestNum64/int (0.00s) task-0: --- PASS: TestNum64/int8 (0.00s) -task-0: --- PASS: TestNum64/int16 (0.00s) +task-0: --- PASS: TestNum64/int64 (0.00s) +task-0: --- PASS: TestNum64/uintptr (0.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/utils 0.036s +task-0: ok github.com/mendersoftware/mender-connect/utils 0.048s task-0: Shutting down DBus daemon: Shutdown make[1]: Leaving directory '/build/reproducible-path/mender-connect-2.1.0+ds1' @@ -2044,8 +2081,8 @@ dpkg-gencontrol: warning: package mender-connect: substitution variable ${misc:Static-Built-Using} unused, but is defined dh_md5sums -O--builddirectory=_build -O--buildsystem=golang dh_builddeb -O--builddirectory=_build -O--buildsystem=golang -dpkg-deb: building package 'mender-connect' in '../mender-connect_2.1.0+ds1-4_armhf.deb'. dpkg-deb: building package 'mender-connect-dbgsym' in '../mender-connect-dbgsym_2.1.0+ds1-4_armhf.deb'. +dpkg-deb: building package 'mender-connect' in '../mender-connect_2.1.0+ds1-4_armhf.deb'. dpkg-genbuildinfo --build=binary -O../mender-connect_2.1.0+ds1-4_armhf.buildinfo dpkg-genchanges --build=binary -O../mender-connect_2.1.0+ds1-4_armhf.changes dpkg-genchanges: info: binary-only upload (no source code included) @@ -2053,12 +2090,14 @@ dpkg-buildpackage: info: binary-only upload (no source included) dpkg-genchanges: info: not including original source code in upload I: copying local configuration +I: user script /srv/workspace/pbuilder/917/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/917/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/23234 and its subdirectories -I: Current time: Wed May 22 08:39:22 -12 2024 -I: pbuilder-time-stamp: 1716410362 +I: removing directory /srv/workspace/pbuilder/917 and its subdirectories +I: Current time: Thu May 23 10:56:01 +14 2024 +I: pbuilder-time-stamp: 1716411361