Diff of the two buildlogs: -- --- b1/build.log 2024-01-06 22:56:56.469893215 +0000 +++ b2/build.log 2024-01-06 23:00:16.777368360 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Sat Jan 6 10:53:52 -12 2024 -I: pbuilder-time-stamp: 1704581632 +I: Current time: Sat Feb 8 19:20:00 +14 2025 +I: pbuilder-time-stamp: 1738992000 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/bookworm-reproducible-base.tgz] I: copying local configuration @@ -30,49 +30,81 @@ 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/2757009/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/3140971/tmp/hooks/D01_modify_environment starting +debug: Running on codethink01-arm64. +I: Changing host+domainname to test build reproducibility +I: Adding a custom variable just for the fun of it... +I: Changing /bin/sh to bash +'/bin/sh' -> '/bin/bash' +lrwxrwxrwx 1 root root 9 Feb 8 05:20 /bin/sh -> /bin/bash +I: Setting pbuilder2's login shell to /bin/bash +I: Setting pbuilder2's GECOS to second user,second room,second work-phone,second home-phone,second other +I: user script /srv/workspace/pbuilder/3140971/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/3140971/tmp/hooks/D02_print_environment starting I: set - BUILDDIR='/build/reproducible-path' - BUILDUSERGECOS='first user,first room,first work-phone,first home-phone,first other' - BUILDUSERNAME='pbuilder1' - BUILD_ARCH='arm64' - DEBIAN_FRONTEND='noninteractive' + BASH=/bin/sh + BASHOPTS=checkwinsize:cmdhist:complete_fullquote:extquote:force_fignore:globasciiranges:globskipdots:hostcomplete:interactive_comments:patsub_replacement:progcomp:promptvars:sourcepath + BASH_ALIASES=() + BASH_ARGC=() + BASH_ARGV=() + BASH_CMDS=() + BASH_LINENO=([0]="12" [1]="0") + BASH_LOADABLES_PATH=/usr/local/lib/bash:/usr/lib/bash:/opt/local/lib/bash:/usr/pkg/lib/bash:/opt/pkg/lib/bash:. + BASH_SOURCE=([0]="/tmp/hooks/D02_print_environment" [1]="/tmp/hooks/D02_print_environment") + BASH_VERSINFO=([0]="5" [1]="2" [2]="15" [3]="1" [4]="release" [5]="aarch64-unknown-linux-gnu") + BASH_VERSION='5.2.15(1)-release' + BUILDDIR=/build/reproducible-path + BUILDUSERGECOS='second user,second room,second work-phone,second home-phone,second other' + BUILDUSERNAME=pbuilder2 + BUILD_ARCH=arm64 + DEBIAN_FRONTEND=noninteractive DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=12 ' - DISTRIBUTION='bookworm' - HOME='/root' - HOST_ARCH='arm64' + DIRSTACK=() + DISTRIBUTION=bookworm + EUID=0 + FUNCNAME=([0]="Echo" [1]="main") + GROUPS=() + HOME=/root + HOSTNAME=i-capture-the-hostname + HOSTTYPE=aarch64 + HOST_ARCH=arm64 IFS=' ' - INVOCATION_ID='8c221022b3cd4a6ea4107c890b2c315c' - 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='2757009' - PS1='# ' - PS2='> ' + INVOCATION_ID=0cbb9e9ee3e84170a8bc55fd41a44448 + LANG=C + LANGUAGE=nl_BE:nl + LC_ALL=C + MACHTYPE=aarch64-unknown-linux-gnu + MAIL=/var/mail/root + OPTERR=1 + OPTIND=1 + OSTYPE=linux-gnu + PATH=/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/i/capture/the/path + PBCURRENTCOMMANDLINEOPERATION=build + PBUILDER_OPERATION=build + PBUILDER_PKGDATADIR=/usr/share/pbuilder + PBUILDER_PKGLIBDIR=/usr/lib/pbuilder + PBUILDER_SYSCONFDIR=/etc + PIPESTATUS=([0]="0") + POSIXLY_CORRECT=y + PPID=3140971 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.2oMmV61a/pbuilderrc_0btp --distribution bookworm --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/bookworm-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.2oMmV61a/b1 --logfile b1/build.log mender-connect_2.1.0+ds1-4.dsc' - SUDO_GID='109' - SUDO_UID='104' - SUDO_USER='jenkins' - TERM='unknown' - TZ='/usr/share/zoneinfo/Etc/GMT+12' - USER='root' - _='/usr/bin/systemd-run' - http_proxy='http://192.168.101.104:3128' + PWD=/ + SHELL=/bin/bash + SHELLOPTS=braceexpand:errexit:hashall:interactive-comments:posix + SHLVL=3 + SUDO_COMMAND='/usr/bin/timeout -k 24.1h 24h /usr/bin/ionice -c 3 /usr/bin/nice -n 11 /usr/bin/unshare --uts -- /usr/sbin/pbuilder --build --configfile /srv/reproducible-results/rbuild-debian/r-b-build.2oMmV61a/pbuilderrc_SlRs --distribution bookworm --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/bookworm-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.2oMmV61a/b2 --logfile b2/build.log mender-connect_2.1.0+ds1-4.dsc' + SUDO_GID=109 + SUDO_UID=104 + SUDO_USER=jenkins + TERM=unknown + TZ=/usr/share/zoneinfo/Etc/GMT-14 + UID=0 + USER=root + _='I: set' + http_proxy=http://192.168.101.104:3128 I: uname -a - Linux codethink02-arm64 6.1.0-17-cloud-arm64 #1 SMP Debian 6.1.69-1 (2023-12-30) aarch64 GNU/Linux + Linux i-capture-the-hostname 6.1.0-17-cloud-arm64 #1 SMP Debian 6.1.69-1 (2023-12-30) aarch64 GNU/Linux I: ls -l /bin total 7104 -rwxr-xr-x 1 root root 1346480 Apr 23 2023 bash @@ -130,15 +162,15 @@ -rwxr-xr-x 1 root root 68456 Sep 20 2022 readlink -rwxr-xr-x 1 root root 68592 Sep 20 2022 rm -rwxr-xr-x 1 root root 68480 Sep 20 2022 rmdir - -rwxr-xr-x 1 root root 68392 Jul 28 23:46 run-parts + -rwxr-xr-x 1 root root 68392 Jul 28 2023 run-parts -rwxr-xr-x 1 root root 134536 Jan 5 2023 sed - lrwxrwxrwx 1 root root 4 Jan 5 2023 sh -> dash + lrwxrwxrwx 1 root root 9 Feb 8 05:20 sh -> /bin/bash -rwxr-xr-x 1 root root 68432 Sep 20 2022 sleep -rwxr-xr-x 1 root root 134088 Sep 20 2022 stty -rwsr-xr-x 1 root root 133312 Mar 23 2023 su -rwxr-xr-x 1 root root 68448 Sep 20 2022 sync -rwxr-xr-x 1 root root 539896 Apr 6 2023 tar - -rwxr-xr-x 1 root root 67904 Jul 28 23:46 tempfile + -rwxr-xr-x 1 root root 67904 Jul 28 2023 tempfile -rwxr-xr-x 1 root root 134160 Sep 20 2022 touch -rwxr-xr-x 1 root root 68384 Sep 20 2022 true -rwxr-xr-x 1 root root 67664 Mar 23 2023 ulockmgr_server @@ -158,7 +190,7 @@ -rwxr-xr-x 1 root root 2206 Apr 10 2022 zless -rwxr-xr-x 1 root root 1842 Apr 10 2022 zmore -rwxr-xr-x 1 root root 4577 Apr 10 2022 znew -I: user script /srv/workspace/pbuilder/2757009/tmp/hooks/D02_print_environment finished +I: user script /srv/workspace/pbuilder/3140971/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -363,7 +395,7 @@ Get: 137 http://deb.debian.org/debian bookworm/main arm64 pkg-config arm64 1.8.1-1 [13.7 kB] Get: 138 http://deb.debian.org/debian bookworm/main arm64 zlib1g-dev arm64 1:1.2.13.dfsg-1 [913 kB] Get: 139 http://deb.debian.org/debian bookworm/main arm64 libglib2.0-dev arm64 2.74.6-2 [1613 kB] -Fetched 119 MB in 1s (142 MB/s) +Fetched 119 MB in 1s (185 MB/s) debconf: delaying package configuration, since apt-utils is not installed Selecting previously unselected package libdbus-1-3:arm64. (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 ... 18171 files and directories currently installed.) @@ -939,7 +971,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/3140971/tmp/hooks/A99_set_merged_usr starting +Not re-configuring usrmerge for bookworm +I: user script /srv/workspace/pbuilder/3140971/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 @@ -961,28 +997,28 @@ dh_auto_build -O--buildsystem=golang -- \ -ldflags "-X github.com/mendersoftware/mender-connect/config.Version=" cd _build && go install -trimpath -v -p 12 -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/goarch internal/unsafeheader +internal/goarch +internal/goos +internal/cpu internal/race -internal/goexperiment -math/bits internal/itoa -unicode/utf8 sync/atomic +math/bits +unicode/utf8 unicode +encoding +internal/goexperiment internal/abi -runtime/internal/math -internal/goos -internal/cpu runtime/internal/syscall -encoding +runtime/internal/math +runtime/internal/sys +github.com/mendersoftware/go-lib-micro/ws github.com/mendersoftware/go-lib-micro/ws/shell unicode/utf16 +math crypto/internal/subtle crypto/subtle -runtime/internal/sys -math -github.com/mendersoftware/go-lib-micro/ws crypto/internal/boring/sig container/list vendor/golang.org/x/crypto/cryptobyte/asn1 @@ -1003,11 +1039,11 @@ runtime/cgo errors internal/oserror +strconv +sort io -path internal/safefilepath -sort -strconv +path crypto/internal/nistec/fiat vendor/golang.org/x/net/dns/dnsmessage syscall @@ -1016,107 +1052,107 @@ text/tabwriter hash crypto/internal/randutil -hash/crc32 reflect -crypto crypto/rc4 +crypto +hash/crc32 html -regexp/syntax -net/http/internal/ascii net/http/internal/testcert +net/http/internal/ascii +regexp/syntax bufio vendor/golang.org/x/text/transform github.com/vmihailenco/tagparser/v2/internal/parser github.com/vmihailenco/tagparser/v2 time -internal/syscall/execenv internal/syscall/unix +internal/syscall/execenv regexp context internal/poll -io/fs github.com/mendersoftware/go-lib-micro/ws/filetransfer +io/fs embed +github.com/mendersoftware/mender-connect/client/dbus/test +os internal/fmtsort encoding/binary -os encoding/base64 +crypto/md5 golang.org/x/sys/unix -crypto/cipher crypto/internal/nistec +crypto/cipher +vendor/golang.org/x/crypto/curve25519/internal/field crypto/internal/edwards25519/field -crypto/md5 vendor/golang.org/x/crypto/internal/poly1305 -vendor/golang.org/x/crypto/curve25519/internal/field -encoding/pem -github.com/mendersoftware/mender-connect/client/dbus/test -crypto/internal/boring fmt io/ioutil -crypto/des -internal/godebug -vendor/golang.org/x/crypto/chacha20 path/filepath +encoding/pem +internal/godebug os/signal +internal/intern crypto/internal/edwards25519 +net/netip +crypto/internal/boring +crypto/des +vendor/golang.org/x/crypto/chacha20 +os/exec crypto/sha1 crypto/aes crypto/sha512 crypto/hmac crypto/sha256 -internal/intern vendor/golang.org/x/crypto/hkdf -os/exec -net/netip vendor/golang.org/x/crypto/chacha20poly1305 +github.com/mendersoftware/mender-connect/procps +github.com/creack/pty +net github.com/pkg/errors encoding/json log flag +net/url text/template/parse github.com/russross/blackfriday/v2 os/user compress/flate -net/url -math/big github.com/mendersoftware/mender-connect/client/dbus +math/big encoding/hex -net vendor/golang.org/x/crypto/curve25519 vendor/golang.org/x/text/unicode/bidi -vendor/golang.org/x/text/unicode/norm compress/gzip +vendor/golang.org/x/text/unicode/norm vendor/golang.org/x/net/http2/hpack -text/template mime -mime/quotedprintable -vendor/golang.org/x/text/secure/bidirule github.com/sirupsen/logrus +text/template github.com/cpuguy83/go-md2man/v2/md2man +mime/quotedprintable +vendor/golang.org/x/text/secure/bidirule net/http/internal github.com/vmihailenco/msgpack/v5 database/sql/driver -github.com/mendersoftware/mender-connect/procps -github.com/creack/pty github.com/davecgh/go-spew/spew github.com/pmezard/go-difflib/difflib -crypto/elliptic crypto/rand -github.com/urfave/cli/v2 +crypto/elliptic crypto/internal/boring/bbig encoding/asn1 +crypto/dsa crypto/ed25519 crypto/rsa -crypto/dsa -vendor/golang.org/x/net/idna -github.com/go-ozzo/ozzo-validation/v4 github.com/stretchr/objx +vendor/golang.org/x/net/idna gopkg.in/yaml.v3 +github.com/urfave/cli/v2 +github.com/go-ozzo/ozzo-validation/v4 runtime/debug vendor/golang.org/x/crypto/cryptobyte crypto/x509/pkix -crypto/ecdsa github.com/mendersoftware/mender-connect/session/model +crypto/ecdsa github.com/mendersoftware/mender-connect/config github.com/mendersoftware/mender-connect/utils github.com/mendersoftware/mender-connect/limits/filetransfer @@ -1128,10 +1164,10 @@ crypto/tls net/http/httptrace net/http -github.com/mendersoftware/mender-connect/client/mender github.com/gorilla/websocket net/http/httptest github.com/stretchr/testify/assert +github.com/mendersoftware/mender-connect/client/mender github.com/mendersoftware/mender-connect/connection github.com/mendersoftware/mender-connect/connectionmanager github.com/mendersoftware/mender-connect/shell @@ -1150,77 +1186,77 @@ --bus-type=system \ --max-wait=600 \ -t dh_auto_test -DBus daemon: unix:path=/tmp/dbus-NKqCWoHCbI,guid=680d74653f9b1b3e8ec9fa316599da3a -task-0: Started with PID: 2787897 +DBus daemon: unix:path=/tmp/dbus-nO4gc72RxH,guid=a1dd7cbb92ee5f2a16f0f19e67a6e9cf +task-0: Started with PID: 3165920 task-0: cd _build && go test -vet=off -v -p 12 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.19.8 task-0: --- PASS: TestMainExitCodes (0.00s) task-0: === RUN TestMainRequiresConfig -task-0: time="2024-01-06T22:55:10Z" level=info msg="No configuration files present. Using defaults" -task-0: time="2024-01-06T22:55:10Z" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" -task-0: time="2024-01-06T22:55:10Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-01-06T22:55:10Z" level=error msg="please provide a user to run the shell as" +task-0: time="2025-02-08T05:21:38Z" level=info msg="No configuration files present. Using defaults" +task-0: time="2025-02-08T05:21:38Z" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" +task-0: time="2025-02-08T05:21:38Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2025-02-08T05:21:38Z" 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.061s +task-0: ok github.com/mendersoftware/mender-connect 0.066s task-0: === RUN TestMenderShellSessionStart 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-01-06T22:55:10Z" level=info msg="mender-connect starting shell command passing process, pid: 2795194" +task-0: time="2025-02-08T05:21:38Z" level=info msg="mender-connect starting shell command passing process, pid: 3171441" 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.4238895 > /tmp/TestMenderShellExec3908615197 -task-0: daemon_test.go:183: read message: type, session_id, data shell, undefined-session-id, rm -f /tmp/TestMenderShellExec3908615197 -task-0: time="2024-01-06T22:55:10Z" 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.531766 > /tmp/TestMenderShellExec3866732904 +task-0: daemon_test.go:183: read message: type, session_id, data shell, undefined-session-id, rm -f /tmp/TestMenderShellExec3866732904 +task-0: time="2025-02-08T05:21:38Z" 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-01-06T22:55:10Z" level=error msg="routeMessage: StopShellMessage: session not found for id undefined-session-id" +task-0: time="2025-02-08T05:21:38Z" 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-01-06T22:55:14Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: time="2025-02-08T05:21:42Z" 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/TestMenderShellExec3908615197 contains newShellTransaction.4238895 -task-0: daemon_test.go:216: got: 'newShellTransaction.4238895' +task-0: daemon_test.go:213: checking if /tmp/TestMenderShellExec3866732904 contains newShellTransaction.531766 +task-0: daemon_test.go:216: got: 'newShellTransaction.531766' task-0: --- PASS: TestMenderShellSessionStart (8.05s) 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-01-06T22:55:20Z" level=info msg="mender-connect starting shell command passing process, pid: 2797138" +task-0: time="2025-02-08T05:21:48Z" level=info msg="mender-connect starting shell command passing process, pid: 3174652" 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-01-06T22:55:20Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: time="2025-02-08T05:21:48Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" task-0: daemon_test.go:301: read message: type, session_id, data stop, c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: time="2024-01-06T22:55:24Z" level=error msg="routeMessage: StopShellMessage: session not found for id c4993deb-26b4-4c58-aaee-fd0c9e694328" +task-0: time="2025-02-08T05:21:52Z" 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.04s) +task-0: --- PASS: TestMenderShellStopByUserId (7.03s) 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.00s) +task-0: --- PASS: TestMenderShellUnknownMessage (2.01s) 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, fe482c3a-9c13-4852-b1fa-5be170bb5704, -task-0: time="2024-01-06T22:55:27Z" level=info msg="mender-connect starting shell command passing process, pid: 2797852" -task-0: daemon_test.go:428: read message: type, session_id, data new, 54583911-ab05-4944-ad38-365ff2040d61, -task-0: time="2024-01-06T22:55:27Z" level=info msg="mender-connect starting shell command passing process, pid: 2797855" -task-0: daemon_test.go:437: read message: type, session_id, data new, 27bf554d-43ed-4fd4-8373-2ce37e28ed18, -task-0: time="2024-01-06T22:55:27Z" level=error msg="user has too many open sessions" +task-0: daemon_test.go:428: read message: type, session_id, data new, edf27f13-2a33-4fb7-b181-5a3e2bb3ec9c, +task-0: time="2025-02-08T05:21:55Z" level=info msg="mender-connect starting shell command passing process, pid: 3176354" +task-0: daemon_test.go:428: read message: type, session_id, data new, 130479b3-7a14-4bee-bfcf-a44fceeeedab, +task-0: time="2025-02-08T05:21:55Z" level=info msg="mender-connect starting shell command passing process, pid: 3176359" +task-0: daemon_test.go:437: read message: type, session_id, data new, cd7f25d8-3cce-40cf-9b75-4d921ebc39e0, +task-0: time="2025-02-08T05:21:55Z" 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.03s) +task-0: --- PASS: TestMenderShellSessionLimitPerUser (0.02s) task-0: === RUN TestMenderShellStopDaemon task-0: --- PASS: TestMenderShellStopDaemon (0.00s) task-0: === RUN TestMenderShellReadMessage @@ -1232,40 +1268,40 @@ task-0: task-0: newShellMulti: starting task-0: -task-0: daemon_test.go:584: read message: type, session_id, data new, 4b46ac07-41cd-4155-9402-3749dab94f77, -task-0: time="2024-01-06T22:55:38Z" level=info msg="mender-connect starting shell command passing process, pid: 2801543" -task-0: daemon_test.go:584: read message: type, session_id, data new, af91f6ad-b0f2-4c44-ad52-6672392a1f6d, -task-0: time="2024-01-06T22:55:39Z" level=info msg="mender-connect starting shell command passing process, pid: 2801806" -task-0: daemon_test.go:593: read message: type, session_id, data new, 2eaddf65-aa37-4e7a-b653-9ade23883e8d, -task-0: time="2024-01-06T22:55:39Z" level=error msg="too many shells spawned" +task-0: daemon_test.go:584: read message: type, session_id, data new, 542fbe6d-bc33-4232-b0ab-a10af7326463, +task-0: time="2025-02-08T05:22:06Z" level=info msg="mender-connect starting shell command passing process, pid: 3179824" +task-0: daemon_test.go:584: read message: type, session_id, data new, c1015412-f981-4a16-a0e5-6fd361f21cf6, +task-0: time="2025-02-08T05:22:07Z" level=info msg="mender-connect starting shell command passing process, pid: 3180219" +task-0: daemon_test.go:593: read message: type, session_id, data new, 96c4ebcd-42c1-44ef-b821-3b8dfff3ed2c, +task-0: time="2025-02-08T05:22:07Z" 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.01s) +task-0: --- PASS: TestMenderShellMaxShellsLimit (2.02s) task-0: === RUN TestMenderShellNeedsReconnect -task-0: --- PASS: TestMenderShellNeedsReconnect (1.00s) +task-0: --- PASS: TestMenderShellNeedsReconnect (1.01s) task-0: === RUN TestMenderShellPostEvent task-0: --- PASS: TestMenderShellPostEvent (0.00s) task-0: === RUN TestMenderShellReadEvent task-0: --- PASS: TestMenderShellReadEvent (0.00s) task-0: === RUN TestOutputStatus -task-0: time="2024-01-06T22:55:40Z" level=info msg="mender-connect daemon vunknown" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" status: " -task-0: time="2024-01-06T22:55:40Z" level=info msg=" shells: 0/2" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" sessions: 4" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" id:fe482c3a-9c13-4852-b1fa-5be170bb5704 status:0 started:Sat Jan 6 22:55:27 +0000 UTC 2024" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" expires:Sat Jan 6 22:57:35 +0000 UTC 2024 active:Sat Jan 6 22:55:27 +0000 UTC 2024" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" shell:/bin/sh" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" id:54583911-ab05-4944-ad38-365ff2040d61 status:0 started:Sat Jan 6 22:55:27 +0000 UTC 2024" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" expires:Sat Jan 6 22:57:35 +0000 UTC 2024 active:Sat Jan 6 22:55:27 +0000 UTC 2024" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" shell:/bin/sh" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" id:4b46ac07-41cd-4155-9402-3749dab94f77 status:0 started:Sat Jan 6 22:55:38 +0000 UTC 2024" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" expires:Sat Jan 6 23:12:42 +0000 UTC 2024 active:Sat Jan 6 22:55:38 +0000 UTC 2024" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" shell:/bin/sh" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" id:af91f6ad-b0f2-4c44-ad52-6672392a1f6d status:0 started:Sat Jan 6 22:55:39 +0000 UTC 2024" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" expires:Sat Jan 6 23:12:43 +0000 UTC 2024 active:Sat Jan 6 22:55:39 +0000 UTC 2024" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" shell:/bin/sh" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" file-transfer:" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" total: tx/rx 0/0" -task-0: time="2024-01-06T22:55:40Z" level=info msg=" 1m: tx rx 0.00 0.00 (w)" +task-0: time="2025-02-08T05:22:08Z" level=info msg="mender-connect daemon vunknown" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" status: " +task-0: time="2025-02-08T05:22:08Z" level=info msg=" shells: 0/2" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" sessions: 4" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" id:542fbe6d-bc33-4232-b0ab-a10af7326463 status:0 started:Sat Feb 8 05:22:06 +0000 UTC 2025" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" expires:Sat Feb 8 05:39:10 +0000 UTC 2025 active:Sat Feb 8 05:22:06 +0000 UTC 2025" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" shell:/bin/sh" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" id:c1015412-f981-4a16-a0e5-6fd361f21cf6 status:0 started:Sat Feb 8 05:22:07 +0000 UTC 2025" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" expires:Sat Feb 8 05:39:11 +0000 UTC 2025 active:Sat Feb 8 05:22:07 +0000 UTC 2025" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" shell:/bin/sh" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" id:edf27f13-2a33-4fb7-b181-5a3e2bb3ec9c status:0 started:Sat Feb 8 05:21:55 +0000 UTC 2025" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" expires:Sat Feb 8 05:24:03 +0000 UTC 2025 active:Sat Feb 8 05:21:55 +0000 UTC 2025" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" shell:/bin/sh" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" id:130479b3-7a14-4bee-bfcf-a44fceeeedab status:0 started:Sat Feb 8 05:21:55 +0000 UTC 2025" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" expires:Sat Feb 8 05:24:03 +0000 UTC 2025 active:Sat Feb 8 05:21:55 +0000 UTC 2025" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" shell:/bin/sh" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" file-transfer:" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" total: tx/rx 0/0" +task-0: time="2025-02-08T05:22:08Z" level=info msg=" 1m: tx rx 0.00 0.00 (w)" task-0: --- PASS: TestOutputStatus (0.00s) task-0: === RUN TestTimeToSweepSessions task-0: --- PASS: TestTimeToSweepSessions (4.00s) @@ -1274,14 +1310,14 @@ task-0: === RUN TestDBusEventLoop/token_not_returned_wait_forever task-0: === CONT TestDBusEventLoop task-0: daemon_test.go:803: ok: expected to run forever -task-0: --- PASS: TestDBusEventLoop (16.00s) +task-0: --- PASS: TestDBusEventLoop (16.01s) task-0: --- PASS: TestDBusEventLoop/stopped-gracefully (1.00s) task-0: === RUN TestEventLoop task-0: === RUN TestEventLoop/stopped-gracefully task-0: === RUN TestEventLoop/run_forever task-0: === CONT 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 @@ -1290,10 +1326,10 @@ task-0: === CONT TestMessageMainLoop task-0: daemon_test.go:1001: ok: expected to run forever task-0: === RUN TestMessageMainLoop/ws-nil-error -task-0: time="2024-01-06T22:56:32Z" level=error msg="session fe482c3a-9c13-4852-b1fa-5be170bb5704, health check failed, connection with the client lost" -task-0: time="2024-01-06T22:56:32Z" level=error msg="session 54583911-ab05-4944-ad38-365ff2040d61, health check failed, connection with the client lost" -task-0: time="2024-01-06T22:56:43Z" level=error msg="session 4b46ac07-41cd-4155-9402-3749dab94f77, health check failed, connection with the client lost" -task-0: time="2024-01-06T22:56:44Z" level=error msg="session af91f6ad-b0f2-4c44-ad52-6672392a1f6d, health check failed, connection with the client lost" +task-0: time="2025-02-08T05:23:00Z" level=error msg="session 130479b3-7a14-4bee-bfcf-a44fceeeedab, health check failed, connection with the client lost" +task-0: time="2025-02-08T05:23:00Z" level=error msg="session edf27f13-2a33-4fb7-b181-5a3e2bb3ec9c, health check failed, connection with the client lost" +task-0: time="2025-02-08T05:23:11Z" level=error msg="session 542fbe6d-bc33-4232-b0ab-a10af7326463, health check failed, connection with the client lost" +task-0: time="2025-02-08T05:23:12Z" level=error msg="session c1015412-f981-4a16-a0e5-6fd361f21cf6, health check failed, connection with the client lost" task-0: === CONT TestMessageMainLoop task-0: daemon_test.go:1001: ok: expected to run forever task-0: --- PASS: TestMessageMainLoop (30.00s) @@ -1333,9 +1369,9 @@ 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-01-06T22:56:46Z" level=warning msg="can't decrement shellsSpawned count: it is 0." +task-0: time="2025-02-08T05:23:14Z" level=warning msg="can't decrement shellsSpawned count: it is 0." task-0: === CONT TestDecreaseSpawnedShellsCount/decrease_by_many_with_0 -task-0: time="2024-01-06T22:56:46Z" level=warning msg="can't decrement shellsSpawned count: it is 0." +task-0: time="2025-02-08T05:23:14Z" 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 @@ -1349,28 +1385,37 @@ task-0: --- PASS: TestDecreaseSpawnedShellsCount/decrease_by_many_with_many (0.00s) task-0: --- PASS: TestDecreaseSpawnedShellsCount/decrease_by_1_with_many (0.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/app 96.220s +task-0: ok github.com/mendersoftware/mender-connect/app 96.224s task-0: ? github.com/mendersoftware/mender-connect/cli [no test files] task-0: === RUN TestBusGet -task-0: --- PASS: TestBusGet (0.02s) +task-0: --- PASS: TestBusGet (0.04s) task-0: === RUN TestBusProxyNew +task-0: === RUN TestBusProxyNew/ok task-0: === RUN TestBusProxyNew/ko,_wrong_path task-0: -task-0: (process:2796951): GLib-GIO-CRITICAL **: 22:55:18.190: g_dbus_proxy_new_sync: assertion 'g_variant_is_object_path (object_path)' failed -task-0: === RUN TestBusProxyNew/ok -task-0: --- PASS: TestBusProxyNew (0.01s) +task-0: (process:3173277): GLib-GIO-CRITICAL **: 05:21:44.577: 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.03s) task-0: --- PASS: TestBusProxyNew/ko,_wrong_path (0.00s) -task-0: --- PASS: TestBusProxyNew/ok (0.01s) task-0: === RUN TestBusProxyCall task-0: === RUN TestBusProxyCall/ok +task-0: dbus_libgio_test.go:122: +task-0: Error Trace: /build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/client/dbus/dbus_libgio_test.go:122 +task-0: Error: Received unexpected error: +task-0: Timeout was reached +task-0: Test: TestBusProxyCall/ok +task-0: dbus_libgio_test.go:123: +task-0: Error Trace: /build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/client/dbus/dbus_libgio_test.go:123 +task-0: Error: Expected value not to be nil. +task-0: Test: TestBusProxyCall/ok task-0: === RUN TestBusProxyCall/ko,_already_handled_Hello_message -task-0: --- PASS: TestBusProxyCall (0.00s) -task-0: --- PASS: TestBusProxyCall/ok (0.00s) -task-0: --- PASS: TestBusProxyCall/ko,_already_handled_Hello_message (0.00s) +task-0: --- FAIL: TestBusProxyCall (0.09s) +task-0: --- FAIL: TestBusProxyCall/ok (0.04s) +task-0: --- PASS: TestBusProxyCall/ko,_already_handled_Hello_message (0.04s) 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) @@ -1378,8 +1423,8 @@ task-0: --- PASS: TestGetDBusAPI (0.00s) task-0: === RUN TestError task-0: --- PASS: TestError (0.00s) -task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/client/dbus 0.285s +task-0: FAIL +task-0: FAIL github.com/mendersoftware/mender-connect/client/dbus 0.399s 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] task-0: === RUN TestNewAuthClientDefaultDBusAPI @@ -1400,14 +1445,14 @@ task-0: --- PASS: TestAuthClientConnect/error_BusGet (0.00s) task-0: --- PASS: TestAuthClientConnect/error_ProxyNew (0.00s) task-0: === RUN TestAuthClientGetJWTToken -task-0: === RUN TestAuthClientGetJWTToken/error -task-0: auth_test.go:144: PASS: BusProxyCall(dbus.Handle,string,,int) task-0: === RUN TestAuthClientGetJWTToken/ok task-0: auth_test.go:144: PASS: BusProxyCall(dbus.Handle,string,,int) task-0: auth_test.go:144: PASS: GetTwoStrings() +task-0: === RUN TestAuthClientGetJWTToken/error +task-0: auth_test.go:144: PASS: BusProxyCall(dbus.Handle,string,,int) task-0: --- PASS: TestAuthClientGetJWTToken (0.00s) -task-0: --- PASS: TestAuthClientGetJWTToken/error (0.00s) task-0: --- PASS: TestAuthClientGetJWTToken/ok (0.00s) +task-0: --- PASS: TestAuthClientGetJWTToken/error (0.00s) task-0: === RUN TestAuthClientFetchJWTToken task-0: === RUN TestAuthClientFetchJWTToken/ok task-0: auth_test.go:193: PASS: BusProxyCall(dbus.Handle,string,,int) @@ -1429,51 +1474,51 @@ 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.052s +task-0: ok github.com/mendersoftware/mender-connect/client/mender 0.035s task-0: ? github.com/mendersoftware/mender-connect/client/mender/mocks [no test files] task-0: === RUN Test_readConfigFile_noFile_returnsError task-0: --- PASS: Test_readConfigFile_noFile_returnsError (0.00s) task-0: === RUN Test_readConfigFile_brokenContent_returnsError -task-0: time="2024-01-06T22:55:09Z" level=error msg="Error loading configuration from file: /tmp/mendertest3108517274/mender-connect.conf (Error parsing mender configuration file: invalid character '\"' after object key:value pair)" -task-0: time="2024-01-06T22:55:09Z" level=error msg="Error loading configuration from file: /tmp/mendertest3108517274/mender-connect.conf (Error parsing mender configuration file: invalid character '\"' after object key:value pair)" +task-0: time="2025-02-08T05:21:37Z" level=error msg="Error loading configuration from file: /tmp/mendertest3533524485/mender-connect.conf (Error parsing mender configuration file: invalid character '\"' after object key:value pair)" +task-0: time="2025-02-08T05:21:37Z" level=error msg="Error loading configuration from file: /tmp/mendertest3533524485/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-01-06T22:55:09Z" level=info msg="Loaded configuration file: /tmp/mendertest2051317952/mender-connect.conf" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="both ExpireAfter and ExpireAfterIdle specified." -task-0: time="2024-01-06T22:55:09Z" level=info msg="Loaded configuration file: /tmp/mendertest2051317952/mender-connect.conf" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="both ExpireAfter and ExpireAfterIdle specified." +task-0: time="2025-02-08T05:21:37Z" level=info msg="Loaded configuration file: /tmp/mendertest2146688481/mender-connect.conf" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="both ExpireAfter and ExpireAfterIdle specified." +task-0: time="2025-02-08T05:21:37Z" level=info msg="Loaded configuration file: /tmp/mendertest2146688481/mender-connect.conf" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="ShellCommand is empty, defaulting to /bin/sh" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="both ExpireAfter and ExpireAfterIdle specified." task-0: --- PASS: Test_LoadConfig_correctConfFile_returnsConfiguration (0.00s) task-0: === RUN TestConfigurationMergeSettings -task-0: time="2024-01-06T22:55:09Z" level=info msg="Loaded configuration file: fallback.config" -task-0: time="2024-01-06T22:55:09Z" level=info msg="Loaded configuration file: main.config" +task-0: time="2025-02-08T05:21:37Z" level=info msg="Loaded configuration file: fallback.config" +task-0: time="2025-02-08T05:21:37Z" 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-01-06T22:55:09Z" level=info msg="Loaded configuration file: /tmp/mendertest4100483393/mender-connect.conf" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-01-06T22:55:09Z" level=info msg="Loaded configuration file: /tmp/mendertest4100483393/mender-connect.conf" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-01-06T22:55:09Z" level=info msg="Loaded configuration file: /tmp/mendertest4100483393/mender-connect.conf" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-01-06T22:55:09Z" level=info msg="Loaded configuration file: /tmp/mendertest4100483393/mender-connect.conf" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-01-06T22:55:09Z" level=info msg="Loaded configuration file: /tmp/mendertest4100483393/mender-connect.conf" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-01-06T22:55:09Z" level=error msg="ShellCommand /bin/ls is not present in /etc/shells" -task-0: time="2024-01-06T22:55:09Z" level=error msg="Error loading configuration from file: /tmp/mendertest4100483393/mender-connect.conf (Error parsing mender configuration file: invalid character '\"' after object key:value pair)" -task-0: time="2024-01-06T22:55:09Z" level=error msg="Error loading configuration from file: /tmp/mendertest4100483393/mender-connect.conf (Error parsing config file: json: cannot unmarshal number into Go struct field MenderShellConfigFromFile.ShellCommand of type string)" +task-0: time="2025-02-08T05:21:37Z" level=info msg="Loaded configuration file: /tmp/mendertest95460714/mender-connect.conf" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2025-02-08T05:21:37Z" level=info msg="Loaded configuration file: /tmp/mendertest95460714/mender-connect.conf" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2025-02-08T05:21:37Z" level=info msg="Loaded configuration file: /tmp/mendertest95460714/mender-connect.conf" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2025-02-08T05:21:37Z" level=info msg="Loaded configuration file: /tmp/mendertest95460714/mender-connect.conf" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2025-02-08T05:21:37Z" level=info msg="Loaded configuration file: /tmp/mendertest95460714/mender-connect.conf" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2025-02-08T05:21:37Z" level=error msg="ShellCommand /bin/ls is not present in /etc/shells" +task-0: time="2025-02-08T05:21:37Z" level=error msg="Error loading configuration from file: /tmp/mendertest95460714/mender-connect.conf (Error parsing mender configuration file: invalid character '\"' after object key:value pair)" +task-0: time="2025-02-08T05:21:37Z" level=error msg="Error loading configuration from file: /tmp/mendertest95460714/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.00s) task-0: === RUN TestConfigurationNeitherFileExistsIsNotError -task-0: time="2024-01-06T22:55:09Z" level=info msg="No configuration files present. Using defaults" +task-0: time="2025-02-08T05:21:37Z" level=info msg="No configuration files present. Using defaults" task-0: --- PASS: TestConfigurationNeitherFileExistsIsNotError (0.00s) task-0: === RUN TestShellArgumentsEmptyDefaults -task-0: time="2024-01-06T22:55:09Z" level=info msg="Loaded configuration file: main.config" -task-0: time="2024-01-06T22:55:09Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" -task-0: time="2024-01-06T22:55:09Z" level=info msg="Loaded configuration file: main.config" -task-0: time="2024-01-06T22:55:09Z" level=info msg="Loaded configuration file: main.config" +task-0: time="2025-02-08T05:21:37Z" level=info msg="Loaded configuration file: main.config" +task-0: time="2025-02-08T05:21:37Z" level=warning msg="ShellArguments is empty, defaulting to [--login]" +task-0: time="2025-02-08T05:21:37Z" level=info msg="Loaded configuration file: main.config" +task-0: time="2025-02-08T05:21:37Z" level=info msg="Loaded configuration file: main.config" task-0: --- PASS: TestShellArgumentsEmptyDefaults (0.00s) task-0: === RUN TestServerArgumentsDeprecated task-0: --- PASS: TestServerArgumentsDeprecated (0.00s) @@ -1491,7 +1536,7 @@ task-0: === RUN TestMenderShowVersion task-0: --- PASS: TestMenderShowVersion (0.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/config 0.036s +task-0: ok github.com/mendersoftware/mender-connect/config 0.056s task-0: === RUN TestNewConnection task-0: connection_test.go:97: starting mock httpd with websockets task-0: --- PASS: TestNewConnection (0.00s) @@ -1501,12 +1546,12 @@ task-0: --- PASS: TestConnection_ReadMessage (1.00s) task-0: === RUN TestConnection_WriteMessage task-0: connection_test.go:149: starting mock httpd with websockets -task-0: --- PASS: TestConnection_WriteMessage (1.01s) +task-0: --- PASS: TestConnection_WriteMessage (1.00s) 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.078s +task-0: ok github.com/mendersoftware/mender-connect/connection 3.047s task-0: === RUN TestSetReconnectIntervalSeconds task-0: --- PASS: TestSetReconnectIntervalSeconds (0.00s) task-0: === RUN TestGetWriteTimeout @@ -1516,22 +1561,22 @@ task-0: === RUN TestConnect task-0: --- PASS: TestConnect (2.01s) task-0: === RUN TestReconnect -task-0: 2024/01/06 22:55:11 [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/01/06 22:55:11 http: panic serving 127.0.0.1:45218: websocket: close 1006 (abnormal closure): unexpected EOF -task-0: goroutine 20 [running]: +task-0: 2025/02/08 05:21:39 [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: 2025/02/08 05:21:39 http: panic serving 127.0.0.1:49756: websocket: close 1006 (abnormal closure): unexpected EOF +task-0: goroutine 36 [running]: task-0: net/http.(*conn).serve.func1() task-0: /usr/lib/go-1.19/src/net/http/server.go:1850 +0xb8 task-0: panic({0x694260, 0x911b10}) task-0: /usr/lib/go-1.19/src/runtime/panic.go:890 +0x260 -task-0: github.com/mendersoftware/mender-connect/connectionmanager.newWebsocketServer.func2({0x774260?, 0x4000174000?}, 0xffff6e42af3b?) +task-0: github.com/mendersoftware/mender-connect/connectionmanager.newWebsocketServer.func2({0x774260?, 0x40001cc000?}, 0xffff7c0e983b?) task-0: /build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/connectionmanager/connectionmanager_test.go:61 +0x158 -task-0: net/http.HandlerFunc.ServeHTTP(0x4000097ad8?, {0x774260?, 0x4000174000?}, 0x0?) +task-0: net/http.HandlerFunc.ServeHTTP(0x40000b5ad8?, {0x774260?, 0x40001cc000?}, 0x0?) task-0: /usr/lib/go-1.19/src/net/http/server.go:2109 +0x38 -task-0: net/http.(*ServeMux).ServeHTTP(0x0?, {0x774260, 0x4000174000}, 0x4000146200) +task-0: net/http.(*ServeMux).ServeHTTP(0x0?, {0x774260, 0x40001cc000}, 0x400019e200) task-0: /usr/lib/go-1.19/src/net/http/server.go:2487 +0x140 -task-0: net/http.serverHandler.ServeHTTP({0x4000144240?}, {0x774260, 0x4000174000}, 0x4000146200) +task-0: net/http.serverHandler.ServeHTTP({0x400019c240?}, {0x774260, 0x40001cc000}, 0x400019e200) task-0: /usr/lib/go-1.19/src/net/http/server.go:2947 +0x2cc -task-0: net/http.(*conn).serve(0x400015e0a0, {0x774740, 0x400007dbf0}) +task-0: net/http.(*conn).serve(0x40001b60a0, {0x774740, 0x40000a5bf0}) task-0: /usr/lib/go-1.19/src/net/http/server.go:1991 +0x544 task-0: created by net/http.(*Server).Serve task-0: /usr/lib/go-1.19/src/net/http/server.go:3102 +0x43c @@ -1539,38 +1584,38 @@ task-0: === RUN TestConnectFailed task-0: --- PASS: TestConnectFailed (0.00s) task-0: === RUN TestConnectRetries -task-0: time="2024-01-06T22:55:13Z" 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: 2024/01/06 22:55:13 http: panic serving 127.0.0.1:45232: websocket: close 1006 (abnormal closure): unexpected EOF -task-0: goroutine 14 [running]: +task-0: time="2025-02-08T05:21:41Z" 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: 2025/02/08 05:21:41 http: panic serving 127.0.0.1:51780: websocket: close 1006 (abnormal closure): unexpected EOF +task-0: goroutine 7 [running]: task-0: net/http.(*conn).serve.func1() task-0: /usr/lib/go-1.19/src/net/http/server.go:1850 +0xb8 task-0: panic({0x694260, 0x911b10}) task-0: /usr/lib/go-1.19/src/runtime/panic.go:890 +0x260 -task-0: github.com/mendersoftware/mender-connect/connectionmanager.newWebsocketServer.func2({0x774260?, 0x40000e21c0?}, 0xffff6e42af3b?) +task-0: github.com/mendersoftware/mender-connect/connectionmanager.newWebsocketServer.func2({0x774260?, 0x400021e000?}, 0xffff7c0e993b?) task-0: /build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/connectionmanager/connectionmanager_test.go:61 +0x158 -task-0: net/http.HandlerFunc.ServeHTTP(0x4000064ad8?, {0x774260?, 0x40000e21c0?}, 0x0?) +task-0: net/http.HandlerFunc.ServeHTTP(0x4000063ad8?, {0x774260?, 0x400021e000?}, 0x0?) task-0: /usr/lib/go-1.19/src/net/http/server.go:2109 +0x38 -task-0: net/http.(*ServeMux).ServeHTTP(0x0?, {0x774260, 0x40000e21c0}, 0x40000fe200) +task-0: net/http.(*ServeMux).ServeHTTP(0x0?, {0x774260, 0x400021e000}, 0x400020a200) task-0: /usr/lib/go-1.19/src/net/http/server.go:2487 +0x140 -task-0: net/http.serverHandler.ServeHTTP({0x400007de60?}, {0x774260, 0x40000e21c0}, 0x40000fe200) +task-0: net/http.serverHandler.ServeHTTP({0x4000208240?}, {0x774260, 0x400021e000}, 0x400020a200) task-0: /usr/lib/go-1.19/src/net/http/server.go:2947 +0x2cc -task-0: net/http.(*conn).serve(0x40000a92c0, {0x774740, 0x40001448d0}) +task-0: net/http.(*conn).serve(0x40002180a0, {0x774740, 0x400019c8d0}) task-0: /usr/lib/go-1.19/src/net/http/server.go:1991 +0x544 task-0: created by net/http.(*Server).Serve task-0: /usr/lib/go-1.19/src/net/http/server.go:3102 +0x43c -task-0: time="2024-01-06T22:55:14Z" 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: time="2025-02-08T05:21:42Z" 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.01s) 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.051s +task-0: ok github.com/mendersoftware/mender-connect/connectionmanager 6.072s task-0: === RUN TestGetCounters task-0: --- PASS: TestGetCounters (8.04s) task-0: === RUN TestUpdateCounters -task-0: limits_test.go:160: after 18s; +{24576 24576 1663.3268261488847 1663.3268261488847 {13933737529235405467 8043435982 0x97e040} {13933737529235405547 8043436062 0x97e040}} 1663.00 vs 1663.33=0.33 1663.00 vs 1663.33=0.33 -task-0: --- PASS: TestUpdateCounters (20.01s) +task-0: limits_test.go:160: after 18s; +{24576 24576 1663.3268261488847 1663.3268261488847 {13970685401745471274 8047619081 0x97e040} {13970685401745471314 8047619121 0x97e040}} 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: === RUN TestPermit_PreserveModes @@ -1632,11 +1677,11 @@ 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.083s +task-0: ok github.com/mendersoftware/mender-connect/limits/filetransfer 28.104s task-0: === RUN TestMenderShellProcPs task-0: --- PASS: TestMenderShellProcPs (4.04s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/procps 4.070s +task-0: ok github.com/mendersoftware/mender-connect/procps 4.093s task-0: === RUN TestFileTransferUpload task-0: === PAUSE TestFileTransferUpload task-0: === RUN TestFileTransferDownload @@ -1648,21 +1693,21 @@ task-0: === RUN TestMenderClientHandler task-0: --- PASS: TestMenderClientHandler (0.00s) task-0: === RUN TestRunCommand -task-0: --- PASS: TestRunCommand (0.01s) +task-0: --- PASS: TestRunCommand (0.02s) task-0: === RUN TestPortForwardHandler -task-0: time="2024-01-06T22:55:10Z" level=error msg="portForwardHandler(unknown message type\ngithub.com/mendersoftware/mender-connect/session.init\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:41\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6329\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6306\nruntime.main\n\t/usr/lib/go-1.19/src/runtime/proc.go:233\nruntime.goexit\n\t/usr/lib/go-1.19/src/runtime/asm_arm64.s:1172)" -task-0: time="2024-01-06T22:55:10Z" level=info msg="port-forward: new session/c1: tcp/localhost:44031" -task-0: time="2024-01-06T22:55:10Z" level=error msg="portForwardHandler(dial tcp 127.0.0.1:44031: connect: connection refused)" -task-0: time="2024-01-06T22:55:10Z" level=info msg="port-forward: new session/c1: dummy/localhost:34997" -task-0: time="2024-01-06T22:55:10Z" 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.19/src/testing/testing.go:1446\nruntime.goexit\n\t/usr/lib/go-1.19/src/runtime/asm_arm64.s:1172)" -task-0: time="2024-01-06T22:55:10Z" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:42\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6329\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6306\nruntime.main\n\t/usr/lib/go-1.19/src/runtime/proc.go:233\nruntime.goexit\n\t/usr/lib/go-1.19/src/runtime/asm_arm64.s:1172)" -task-0: time="2024-01-06T22:55:10Z" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:42\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6329\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6306\nruntime.main\n\t/usr/lib/go-1.19/src/runtime/proc.go:233\nruntime.goexit\n\t/usr/lib/go-1.19/src/runtime/asm_arm64.s:1172)" +task-0: time="2025-02-08T05:21:38Z" level=error msg="portForwardHandler(unknown message type\ngithub.com/mendersoftware/mender-connect/session.init\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:41\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6329\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6306\nruntime.main\n\t/usr/lib/go-1.19/src/runtime/proc.go:233\nruntime.goexit\n\t/usr/lib/go-1.19/src/runtime/asm_arm64.s:1172)" +task-0: time="2025-02-08T05:21:38Z" level=info msg="port-forward: new session/c1: tcp/localhost:33555" +task-0: time="2025-02-08T05:21:38Z" level=error msg="portForwardHandler(dial tcp 127.0.0.1:33555: connect: connection refused)" +task-0: time="2025-02-08T05:21:38Z" level=info msg="port-forward: new session/c1: dummy/localhost:40901" +task-0: time="2025-02-08T05:21:38Z" 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.19/src/testing/testing.go:1446\nruntime.goexit\n\t/usr/lib/go-1.19/src/runtime/asm_arm64.s:1172)" +task-0: time="2025-02-08T05:21:38Z" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:42\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6329\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6306\nruntime.main\n\t/usr/lib/go-1.19/src/runtime/proc.go:233\nruntime.goexit\n\t/usr/lib/go-1.19/src/runtime/asm_arm64.s:1172)" +task-0: time="2025-02-08T05:21:38Z" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:42\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6329\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6306\nruntime.main\n\t/usr/lib/go-1.19/src/runtime/proc.go:233\nruntime.goexit\n\t/usr/lib/go-1.19/src/runtime/asm_arm64.s:1172)" task-0: --- PASS: TestPortForwardHandler (0.00s) task-0: === RUN TestPortForwardHandlerSuccessfulConnection -task-0: time="2024-01-06T22:55:12Z" level=info msg="port-forward: new session/c1: tcp/localhost:41195" -task-0: time="2024-01-06T22:55:14Z" level=info msg="port-forward: new session/c2: tcp/localhost:41195" -task-0: time="2024-01-06T22:55:15Z" level=info msg="port-forward: stop session/c1" -task-0: time="2024-01-06T22:55:15Z" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:42\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6329\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6306\nruntime.main\n\t/usr/lib/go-1.19/src/runtime/proc.go:233\nruntime.goexit\n\t/usr/lib/go-1.19/src/runtime/asm_arm64.s:1172)" +task-0: time="2025-02-08T05:21:40Z" level=info msg="port-forward: new session/c1: tcp/localhost:43399" +task-0: time="2025-02-08T05:21:42Z" level=info msg="port-forward: new session/c2: tcp/localhost:43399" +task-0: time="2025-02-08T05:21:43Z" level=info msg="port-forward: stop session/c1" +task-0: time="2025-02-08T05:21:43Z" level=error msg="portForwardHandler(unknown connection\ngithub.com/mendersoftware/mender-connect/session.init\n\t/build/reproducible-path/mender-connect-2.1.0+ds1/_build/src/github.com/mendersoftware/mender-connect/session/portforward.go:42\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6329\nruntime.doInit\n\t/usr/lib/go-1.19/src/runtime/proc.go:6306\nruntime.main\n\t/usr/lib/go-1.19/src/runtime/proc.go:233\nruntime.goexit\n\t/usr/lib/go-1.19/src/runtime/asm_arm64.s:1172)" task-0: --- PASS: TestPortForwardHandlerSuccessfulConnection (5.03s) task-0: === RUN TestRouter task-0: === PAUSE TestRouter @@ -1672,36 +1717,36 @@ task-0: === PAUSE TestSessionListen task-0: === RUN TestMenderShellStartStopShell task-0: session_test.go:587: starting mock httpd with websockets -task-0: time="2024-01-06T22:55:15Z" level=info msg="mender-connect starting shell command passing process, pid: 2796671" +task-0: time="2025-02-08T05:21:43Z" level=info msg="mender-connect starting shell command passing process, pid: 3172929" task-0: session_test.go:631: created session: task-0: id:c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: createdAt:Sat Jan 6 22:55:15 +0000 UTC 2024, -task-0: expiresAt:Sat Jan 6 23:12:19 +0000 UTC 2024 -task-0: now:Sat Jan 6 22:55:15 +0000 UTC 2024 -task-0: time="2024-01-06T22:55:15Z" level=info msg="mender-connect starting shell command passing process, pid: 2796672" -task-0: time="2024-01-06T22:55:15Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" -task-0: time="2024-01-06T22:55:19Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:4 stopping shell" -task-0: time="2024-01-06T22:55:19Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" -task-0: --- PASS: TestMenderShellStartStopShell (8.06s) +task-0: createdAt:Sat Feb 8 05:21:43 +0000 UTC 2025, +task-0: expiresAt:Sat Feb 8 05:38:47 +0000 UTC 2025 +task-0: now:Sat Feb 8 05:21:43 +0000 UTC 2025 +task-0: time="2025-02-08T05:21:43Z" level=info msg="mender-connect starting shell command passing process, pid: 3172935" +task-0: time="2025-02-08T05:21:43Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: time="2025-02-08T05:21:47Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:4 stopping shell" +task-0: time="2025-02-08T05:21:47Z" 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-01-06T22:55:23Z" level=info msg="mender-connect starting shell command passing process, pid: 2797566" -task-0: time="2024-01-06T22:55:23Z" level=error msg="error reading stdout: read /dev/ptmx: file already closed" -task-0: --- PASS: TestMenderShellCommand (0.03s) +task-0: time="2025-02-08T05:21:51Z" level=info msg="mender-connect starting shell command passing process, pid: 3175607" +task-0: --- PASS: TestMenderShellCommand (0.01s) task-0: === RUN TestMenderShellShellAlreadyStartedFailedToStart task-0: session_test.go:757: starting mock httpd with websockets -task-0: time="2024-01-06T22:55:23Z" level=info msg="mender-connect starting shell command passing process, pid: 2797572" -task-0: time="2024-01-06T22:55:23Z" level=error msg="failed to start shell: shell is already running" -task-0: time="2024-01-06T22:55:23Z" level=error msg="failed to start shell: fork/exec thatissomethingelse/bin/sh: no such file or directory" -task-0: --- PASS: TestMenderShellShellAlreadyStartedFailedToStart (0.04s) +task-0: time="2025-02-08T05:21:51Z" level=error msg="error reading stdout: read /dev/ptmx: file already closed" +task-0: time="2025-02-08T05:21:51Z" level=info msg="mender-connect starting shell command passing process, pid: 3175611" +task-0: time="2025-02-08T05:21:51Z" level=error msg="failed to start shell: shell is already running" +task-0: time="2025-02-08T05:21:51Z" level=error msg="failed to start shell: fork/exec thatissomethingelse/bin/sh: no such file or directory" +task-0: --- PASS: TestMenderShellShellAlreadyStartedFailedToStart (0.03s) task-0: === RUN TestMenderShellSessionExpire -task-0: time="2024-01-06T22:55:23Z" level=info msg="mender-connect starting shell command passing process, pid: 2797577" -task-0: --- PASS: TestMenderShellSessionExpire (4.03s) +task-0: time="2025-02-08T05:21:51Z" level=info msg="mender-connect starting shell command passing process, pid: 3175618" +task-0: --- PASS: TestMenderShellSessionExpire (4.00s) task-0: === RUN TestMenderShellSessionUpdateWS -task-0: time="2024-01-06T22:55:27Z" level=info msg="mender-connect starting shell command passing process, pid: 2797840" -task-0: --- PASS: TestMenderShellSessionUpdateWS (0.02s) +task-0: time="2025-02-08T05:21:55Z" level=info msg="mender-connect starting shell command passing process, pid: 3176404" +task-0: --- PASS: TestMenderShellSessionUpdateWS (0.00s) task-0: === RUN TestMenderShellSessionGetByUserId -task-0: --- PASS: TestMenderShellSessionGetByUserId (0.01s) +task-0: --- PASS: TestMenderShellSessionGetByUserId (0.00s) task-0: === RUN TestMenderShellSessionGetById task-0: --- PASS: TestMenderShellSessionGetById (0.00s) task-0: === RUN TestMenderShellDeleteById @@ -1711,37 +1756,37 @@ task-0: === RUN TestMenderSessionTerminateExpired task-0: session_test.go:1142: created session: task-0: id:c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: createdAt:Sat Jan 6 22:55:27 +0000 UTC 2024, -task-0: expiresAt:Sat Jan 6 22:55:35 +0000 UTC 2024 -task-0: now:Sat Jan 6 22:55:27 +0000 UTC 2024 -task-0: time="2024-01-06T22:55:27Z" level=info msg="mender-connect starting shell command passing process, pid: 2797844" -task-0: time="2024-01-06T22:55:43Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" -task-0: --- PASS: TestMenderSessionTerminateExpired (20.02s) +task-0: createdAt:Sat Feb 8 05:21:55 +0000 UTC 2025, +task-0: expiresAt:Sat Feb 8 05:22:03 +0000 UTC 2025 +task-0: now:Sat Feb 8 05:21:55 +0000 UTC 2025 +task-0: time="2025-02-08T05:21:55Z" level=info msg="mender-connect starting shell command passing process, pid: 3176406" +task-0: time="2025-02-08T05:22:11Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: --- PASS: TestMenderSessionTerminateExpired (20.01s) task-0: === RUN TestMenderSessionTerminateAll task-0: session_test.go:1194: created session: -task-0: id:74955c51-231b-4111-80a1-4a0f73f01e28, -task-0: createdAt:Sat Jan 6 22:55:47 +0000 UTC 2024, -task-0: expiresAt:Sat Jan 6 22:55:55 +0000 UTC 2024 -task-0: now:Sat Jan 6 22:55:47 +0000 UTC 2024 -task-0: time="2024-01-06T22:55:47Z" level=info msg="mender-connect starting shell command passing process, pid: 2805145" +task-0: id:fc59dec5-2eba-4b15-ae65-4b07e56ae331, +task-0: createdAt:Sat Feb 8 05:22:15 +0000 UTC 2025, +task-0: expiresAt:Sat Feb 8 05:22:23 +0000 UTC 2025 +task-0: now:Sat Feb 8 05:22:15 +0000 UTC 2025 +task-0: time="2025-02-08T05:22:15Z" level=info msg="mender-connect starting shell command passing process, pid: 3182597" task-0: session_test.go:1210: created session: -task-0: id:a643730f-da81-4486-874c-d744d5690cdc, -task-0: createdAt:Sat Jan 6 22:55:47 +0000 UTC 2024, -task-0: expiresAt:Sat Jan 6 22:55:55 +0000 UTC 2024 -task-0: now:Sat Jan 6 22:55:47 +0000 UTC 2024 -task-0: time="2024-01-06T22:55:47Z" level=info msg="mender-connect starting shell command passing process, pid: 2805146" -task-0: time="2024-01-06T22:55:47Z" level=info msg="session 74955c51-231b-4111-80a1-4a0f73f01e28 status:0 stopping shell" -task-0: time="2024-01-06T22:55:51Z" level=info msg="session a643730f-da81-4486-874c-d744d5690cdc status:0 stopping shell" -task-0: --- PASS: TestMenderSessionTerminateAll (8.01s) +task-0: id:f0a02400-4b70-42ff-9820-3b9237a5517c, +task-0: createdAt:Sat Feb 8 05:22:15 +0000 UTC 2025, +task-0: expiresAt:Sat Feb 8 05:22:23 +0000 UTC 2025 +task-0: now:Sat Feb 8 05:22:15 +0000 UTC 2025 +task-0: time="2025-02-08T05:22:15Z" level=info msg="mender-connect starting shell command passing process, pid: 3182599" +task-0: time="2025-02-08T05:22:15Z" level=info msg="session fc59dec5-2eba-4b15-ae65-4b07e56ae331 status:0 stopping shell" +task-0: time="2025-02-08T05:22:19Z" level=info msg="session f0a02400-4b70-42ff-9820-3b9237a5517c status:0 stopping shell" +task-0: --- PASS: TestMenderSessionTerminateAll (8.05s) task-0: === RUN TestMenderSessionTerminateIdle task-0: session_test.go:1251: created session: task-0: id:c4993deb-26b4-4c58-aaee-fd0c9e694328, -task-0: createdAt:Sat Jan 6 22:55:55 +0000 UTC 2024, -task-0: expiresAt:Sat Jan 6 23:00:10 +0000 UTC 2024 -task-0: now:Sat Jan 6 22:55:55 +0000 UTC 2024 -task-0: time="2024-01-06T22:55:55Z" level=info msg="mender-connect starting shell command passing process, pid: 2805460" -task-0: time="2024-01-06T22:56:03Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" -task-0: --- PASS: TestMenderSessionTerminateIdle (12.01s) +task-0: createdAt:Sat Feb 8 05:22:23 +0000 UTC 2025, +task-0: expiresAt:Sat Feb 8 05:26:38 +0000 UTC 2025 +task-0: now:Sat Feb 8 05:22:23 +0000 UTC 2025 +task-0: time="2025-02-08T05:22:23Z" level=info msg="mender-connect starting shell command passing process, pid: 3185043" +task-0: time="2025-02-08T05:22:31Z" level=info msg="session c4993deb-26b4-4c58-aaee-fd0c9e694328 status:0 stopping shell" +task-0: --- PASS: TestMenderSessionTerminateIdle (12.03s) task-0: === RUN TestMenderSessionTimeNow task-0: --- PASS: TestMenderSessionTimeNow (0.00s) task-0: === CONT TestFileTransferUpload @@ -1854,28 +1899,28 @@ task-0: === PAUSE TestFileTransferDownload/error,_forbidden_to_follow_links task-0: === CONT TestFileTransferDownload/ok task-0: === CONT TestFileTransferUpload/error,_parent_directory_does_not_exist -task-0: time="2024-01-06T22:56:07Z" level=error msg="failed to create file: open /tmp/filetransfer-testing1063319799/parent/dir/does/not/exist/for/this/file.0000000200: no such file or directory" +task-0: time="2025-02-08T05:22:35Z" level=error msg="failed to create file: open /tmp/filetransfer-testing377158092/parent/dir/does/not/exist/for/this/file.0000000200: no such file or directory" task-0: === CONT TestFileTransferUpload/error,_broken_response_writer -task-0: time="2024-01-06T22:56:07Z" level=error msg="failed to respond to client: io: read/write on closed pipe" -task-0: time="2024-01-06T22:56:07Z" level=error msg="handler aborted" +task-0: time="2025-02-08T05:22:35Z" level=error msg="failed to respond to client: io: read/write on closed pipe" +task-0: time="2025-02-08T05:22:35Z" level=error msg="handler aborted" task-0: === CONT TestFileTransferUpload/error,_offset_jumps_beyond_EOF -task-0: time="2024-01-06T22:56:07Z" level=error msg="received unexpected chunk offset" +task-0: time="2025-02-08T05:22:35Z" level=error msg="received unexpected chunk offset" task-0: === CONT TestFileTransferUpload/error,_chunk_missing_offset -task-0: time="2024-01-06T22:56:07Z" level=error msg="invalid file chunk message: missing offset property" +task-0: time="2025-02-08T05:22:35Z" level=error msg="invalid file chunk message: missing offset property" task-0: === CONT TestFileTransferUpload/error,_unexpected_ACK_message_from_client -task-0: time="2024-01-06T22:56:07Z" level=error msg="received unexpected message type 'ack' during file upload" +task-0: time="2025-02-08T05:22:35Z" level=error msg="received unexpected message type 'ack' during file upload" task-0: === CONT TestFileTransferUpload/error,_fake_error_from_client -task-0: time="2024-01-06T22:56:07Z" level=error msg="Received error during upload: something unexpected happened" -task-0: time="2024-01-06T22:56:07Z" level=error msg="handler aborted" +task-0: time="2025-02-08T05:22:35Z" level=error msg="Received error during upload: something unexpected happened" +task-0: time="2025-02-08T05:22:35Z" level=error msg="handler aborted" task-0: === CONT TestFileTransferUpload/error,_path_is_a_directory task-0: === CONT TestFileTransferUpload/error,_file_too_big_upload_denied task-0: === CONT TestFileTransferUpload/ok,_relative_path task-0: === CONT TestSessionListen/error,_write_error -task-0: time="2024-01-06T22:56:07Z" level=error msg="failed to write response to client: this is bad!" +task-0: time="2025-02-08T05:22:35Z" 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: === CONT TestSessionListen/error,_bad_protocol_->_close_error -task-0: time="2024-01-06T22:56:07Z" level=error msg="session: received error from client: dunno what to do next..." +task-0: time="2025-02-08T05:22:35Z" 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,_invalid_handshake_version task-0: === CONT TestSessionListen/error,_malformed_handshake_response @@ -1883,61 +1928,43 @@ task-0: === CONT TestSessionListen/error,_bad_handshake_schema task-0: === CONT TestSessionListen/error,_protocol_version_not_supported task-0: === CONT TestSessionListen/ok,_handshake -task-0: time="2024-01-06T22:56:07Z" level=info msg="session: accepting new session with ID: 1234" +task-0: time="2025-02-08T05:22:35Z" level=info msg="session: accepting new session with ID: 1234" task-0: === CONT TestSessionListen/ok,_ping/pong_->_close -task-0: time="2024-01-06T22:56:07Z" level=info msg="session: closed 1234" +task-0: time="2025-02-08T05:22:35Z" level=info msg="session: closed 1234" task-0: === CONT TestFileTransferServeErrors/message_type_not_implemented task-0: === CONT TestFileTransferServeErrors/malformed_error_from_client -task-0: time="2024-01-06T22:56:07Z" level=error msg="Error decoding error message from client: msgpack: unexpected code=73 decoding map length" +task-0: time="2025-02-08T05:22:35Z" 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-01-06T22:56:07Z" level=error msg="Received error from client: generic error" +task-0: time="2025-02-08T05:22:35Z" level=error msg="Received error from client: generic error" task-0: === CONT TestFileTransferServeErrors/got_chunk_but_no_file_transfer_in_progress task-0: === CONT TestFileTransferServeErrors/download_already_in_progress -task-0: time="2024-01-06T22:56:07Z" level=error msg="another file transfer is in progress" task-0: === CONT TestFileTransferServeErrors/invalid_download_request_parameters -task-0: time="2024-01-06T22:56:07Z" level=error msg="invalid request parameters: path: cannot be blank." task-0: === CONT TestFileTransferServeErrors/malformed_download_request -task-0: time="2024-01-06T22:56:07Z" 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.00s) -task-0: --- PASS: TestFileTransferServeErrors/malformed_upload_request (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/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: === CONT TestFileTransferStat/error,_invalid_parameters#01 task-0: === CONT TestFileTransferStat/error,_invalid_parameters +task-0: time="2025-02-08T05:22:35Z" level=error msg="another file transfer is in progress" 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 TestFileTransferDownload/error,_forbidden_to_follow_links -task-0: time="2024-01-06T22:56:07Z" level=warning msg="file download access denied: forbidden to follow the link" -task-0: time="2024-01-06T22:56:07Z" level=error msg="access denied: forbidden to follow the link" +task-0: time="2025-02-08T05:22:35Z" level=error msg="invalid request parameters: path: cannot be blank." task-0: === CONT TestFileTransferDownload/error,_file_does_not_exist -task-0: time="2024-01-06T22:56:07Z" level=error msg="failed to open file for reading: open lets say it does not exist: no such file or directory" +task-0: time="2025-02-08T05:22:35Z" 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/error,_client_error_message -task-0: time="2024-01-06T22:56:07Z" level=error msg="received error message from client: ENOSPC" +task-0: time="2025-02-08T05:22:35Z" level=error msg="received error message from client: ENOSPC" task-0: === CONT TestFileTransferDownload/error,_client_malformed_error_message -task-0: time="2024-01-06T22:56:07Z" level=error msg="received malformed error message from client: aborting" +task-0: time="2025-02-08T05:22:35Z" level=error msg="received malformed error message from client: aborting" task-0: === CONT TestFileTransferDownload/error,_unexpected_ack_message -task-0: time="2024-01-06T22:56:07Z" level=error msg="received unexpected message type 'file_chunk'; expected 'ack'" +task-0: time="2025-02-08T05:22:35Z" level=error msg="received unexpected message type 'file_chunk'; expected 'ack'" task-0: === CONT TestFileTransferDownload/error,_no_offset_in_ack -task-0: time="2024-01-06T22:56:07Z" level=error msg="ack message: offset property cannot be blank" +task-0: time="2025-02-08T05:22:35Z" level=error msg="ack message: offset property cannot be blank" task-0: === CONT TestFileTransferDownload/error,_bad_ack_data_type -task-0: time="2024-01-06T22:56:07Z" level=error msg="invalid offset data type: require int64" +task-0: time="2025-02-08T05:22:35Z" level=error msg="invalid offset data type: require int64" task-0: === CONT TestFileTransferDownload/ok,_file_larger_than_window +task-0: === CONT TestFileTransferDownload/error,_forbidden_to_follow_links +task-0: time="2025-02-08T05:22:35Z" level=warning msg="file download access denied: forbidden to follow the link" +task-0: time="2025-02-08T05:22:35Z" level=error msg="access denied: forbidden to follow the link" task-0: --- PASS: TestFileTransferDownload (0.00s) task-0: --- PASS: TestFileTransferDownload/ok (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,_client_malformed_error_message (0.00s) @@ -1945,6 +1972,24 @@ task-0: --- PASS: TestFileTransferDownload/error,_no_offset_in_ack (0.00s) task-0: --- PASS: TestFileTransferDownload/error,_bad_ack_data_type (0.00s) task-0: --- PASS: TestFileTransferDownload/ok,_file_larger_than_window (0.00s) +task-0: --- PASS: TestFileTransferDownload/error,_forbidden_to_follow_links (0.00s) +task-0: time="2025-02-08T05:22:35Z" level=error msg="malformed request parameters: msgpack: unexpected code=2f decoding map length" +task-0: --- PASS: TestFileTransferServeErrors (0.00s) +task-0: --- PASS: TestFileTransferServeErrors/malformed_upload_request (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/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: TestFileTransferStat (0.00s) +task-0: --- PASS: TestFileTransferStat/ok (0.00s) +task-0: --- PASS: TestFileTransferStat/error,_malformed_schema (0.00s) +task-0: --- PASS: TestFileTransferStat/error,_invalid_parameters#01 (0.00s) +task-0: --- PASS: TestFileTransferStat/error,_invalid_parameters (0.00s) task-0: --- PASS: TestFileTransferUpload (0.00s) task-0: --- PASS: TestFileTransferUpload/error,_parent_directory_does_not_exist (0.00s) task-0: --- PASS: TestFileTransferUpload/error,_broken_response_writer (0.00s) @@ -1956,7 +2001,7 @@ task-0: --- PASS: TestFileTransferUpload/error,_file_too_big_upload_denied (0.00s) task-0: --- PASS: TestFileTransferUpload/ok,_relative_path (0.00s) task-0: --- PASS: TestFileTransferUpload/ok (0.00s) -task-0: time="2024-01-06T22:56:08Z" level=error msg="failed to ping client: this is bad!" +task-0: time="2025-02-08T05:22:35Z" 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,_write_error (0.00s) @@ -1971,28 +2016,28 @@ task-0: --- PASS: TestSessionListen/ok,_ping/pong_->_close (0.00s) task-0: --- PASS: TestSessionListen/error,_ping_write_error (0.20s) task-0: --- PASS: TestSessionListen/error,_session_timeout (0.25s) -task-0: time="2024-01-06T22:56:08Z" 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.19/src/runtime/asm_arm64.s:1173.goexit" +task-0: time="2025-02-08T05:22:36Z" 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.19/src/runtime/asm_arm64.s:1173.goexit" task-0: --- PASS: TestRouterRace (1.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/session 58.375s +task-0: ok github.com/mendersoftware/mender-connect/session 58.308s task-0: ? github.com/mendersoftware/mender-connect/session/mocks [no test files] task-0: ? github.com/mendersoftware/mender-connect/session/model [no test files] task-0: === RUN TestNewMenderShell task-0: --- PASS: TestNewMenderShell (0.00s) task-0: === RUN TestNewMenderShellReadStdIn -task-0: --- PASS: TestNewMenderShellReadStdIn (8.02s) +task-0: --- PASS: TestNewMenderShellReadStdIn (8.03s) task-0: === RUN TestPipeStdout task-0: exec_test.go:156: starting mock httpd with websockets -task-0: time="2024-01-06T22:55:18Z" level=error msg="error reading stdout: EOF" -task-0: --- PASS: TestPipeStdout (8.01s) +task-0: time="2025-02-08T05:21:45Z" level=error msg="error reading stdout: EOF" +task-0: --- PASS: TestPipeStdout (8.00s) task-0: === RUN TestMenderShellExecShell -task-0: shell_test.go:82: started shell, pid: 2797711 -task-0: shell_test.go:85: FindProcess p: &{2797711 0 0 {{0 0} 0 0 0 0}} err: -task-0: --- PASS: TestMenderShellExecShell (4.04s) +task-0: shell_test.go:82: started shell, pid: 3176078 +task-0: shell_test.go:85: FindProcess p: &{3176078 0 0 {{0 0} 0 0 0 0}} err: +task-0: --- PASS: TestMenderShellExecShell (4.03s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/shell 20.108s +task-0: ok github.com/mendersoftware/mender-connect/shell 20.117s 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 @@ -2006,83 +2051,52 @@ task-0: === RUN TestIsInChroot task-0: --- PASS: TestIsInChroot (0.00s) task-0: === RUN TestNum64 +task-0: === RUN TestNum64/uint8 +task-0: === RUN TestNum64/uint16 task-0: === RUN TestNum64/int -task-0: === RUN TestNum64/int64 task-0: === RUN TestNum64/uint +task-0: === RUN TestNum64/int32 +task-0: === RUN TestNum64/int64 task-0: === RUN TestNum64/uint32 +task-0: === RUN TestNum64/uint64 task-0: === RUN TestNum64/uintptr task-0: === RUN TestNum64/int8 task-0: === RUN TestNum64/int16 -task-0: === RUN TestNum64/int32 -task-0: === RUN TestNum64/uint8 -task-0: === RUN TestNum64/uint16 -task-0: === RUN TestNum64/uint64 task-0: --- PASS: TestNum64 (0.00s) +task-0: --- PASS: TestNum64/uint8 (0.00s) +task-0: --- PASS: TestNum64/uint16 (0.00s) task-0: --- PASS: TestNum64/int (0.00s) -task-0: --- PASS: TestNum64/int64 (0.00s) task-0: --- PASS: TestNum64/uint (0.00s) +task-0: --- PASS: TestNum64/int32 (0.00s) +task-0: --- PASS: TestNum64/int64 (0.00s) task-0: --- PASS: TestNum64/uint32 (0.00s) +task-0: --- PASS: TestNum64/uint64 (0.00s) task-0: --- PASS: TestNum64/uintptr (0.00s) task-0: --- PASS: TestNum64/int8 (0.00s) task-0: --- PASS: TestNum64/int16 (0.00s) -task-0: --- PASS: TestNum64/int32 (0.00s) -task-0: --- PASS: TestNum64/uint8 (0.00s) -task-0: --- PASS: TestNum64/uint16 (0.00s) -task-0: --- PASS: TestNum64/uint64 (0.00s) task-0: PASS -task-0: ok github.com/mendersoftware/mender-connect/utils 0.047s +task-0: ok github.com/mendersoftware/mender-connect/utils 0.069s +task-0: FAIL +dh_auto_test: error: cd _build && go test -vet=off -v -p 12 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 returned exit code 1 +task-0: Exited with status 6400 task-0: Shutting down DBus daemon: Shutdown +make[1]: *** [debian/rules:18: override_dh_auto_test] Error 255 make[1]: Leaving directory '/build/reproducible-path/mender-connect-2.1.0+ds1' - create-stamp debian/debhelper-build-stamp - dh_testroot -O--builddirectory=_build -O--buildsystem=golang - dh_prep -O--builddirectory=_build -O--buildsystem=golang - debian/rules override_dh_auto_install -make[1]: Entering directory '/build/reproducible-path/mender-connect-2.1.0+ds1' -dh_auto_install -- --no-source - cd _build && mkdir -p /build/reproducible-path/mender-connect-2.1.0\+ds1/debian/mender-connect/usr - cd _build && cp -r bin /build/reproducible-path/mender-connect-2.1.0\+ds1/debian/mender-connect/usr -# Install example config provided by upstream -/usr/bin/make DESTDIR=debian/mender-connect install-conf -make[2]: Entering directory '/build/reproducible-path/mender-connect-2.1.0+ds1' -make[2]: Leaving directory '/build/reproducible-path/mender-connect-2.1.0+ds1' -make[1]: Leaving directory '/build/reproducible-path/mender-connect-2.1.0+ds1' - dh_installdocs -O--builddirectory=_build -O--buildsystem=golang - dh_installchangelogs -O--builddirectory=_build -O--buildsystem=golang - dh_installinit -O--builddirectory=_build -O--buildsystem=golang - dh_installsystemd -O--builddirectory=_build -O--buildsystem=golang - dh_installsystemduser -O--builddirectory=_build -O--buildsystem=golang - dh_perl -O--builddirectory=_build -O--buildsystem=golang - dh_link -O--builddirectory=_build -O--buildsystem=golang - dh_strip_nondeterminism -O--builddirectory=_build -O--buildsystem=golang - dh_compress -O--builddirectory=_build -O--buildsystem=golang - dh_fixperms -O--builddirectory=_build -O--buildsystem=golang - dh_missing -O--builddirectory=_build -O--buildsystem=golang - dh_strip -a -O--builddirectory=_build -O--buildsystem=golang - dh_makeshlibs -a -O--builddirectory=_build -O--buildsystem=golang - dh_shlibdeps -a -O--builddirectory=_build -O--buildsystem=golang - dh_installdeb -O--builddirectory=_build -O--buildsystem=golang - dh_golang -O--builddirectory=_build -O--buildsystem=golang - dh_gencontrol -O--builddirectory=_build -O--buildsystem=golang -dpkg-gencontrol: warning: package mender-connect: substitution variable ${misc:Static-Built-Using} unused, but is defined -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-dbgsym' in '../mender-connect-dbgsym_2.1.0+ds1-4_arm64.deb'. -dpkg-deb: building package 'mender-connect' in '../mender-connect_2.1.0+ds1-4_arm64.deb'. - dpkg-genbuildinfo --build=binary -O../mender-connect_2.1.0+ds1-4_arm64.buildinfo - dpkg-genchanges --build=binary -O../mender-connect_2.1.0+ds1-4_arm64.changes -dpkg-genchanges: info: binary-only upload (no source code included) - dpkg-source --after-build . -dpkg-buildpackage: info: binary-only upload (no source included) -dpkg-genchanges: info: not including original source code in upload +make: *** [debian/rules:6: binary] Error 2 +dpkg-buildpackage: error: debian/rules binary subprocess returned exit status 2 I: copying local configuration +E: Failed autobuilding of package +I: user script /srv/workspace/pbuilder/3140971/tmp/hooks/C01_cleanup starting +debug output: disk usage on i-capture-the-hostname at Sat Feb 8 05:23:14 UTC 2025 +Filesystem Size Used Avail Use% Mounted on +tmpfs 16G 0 16G 0% /dev/shm + +I: user script /srv/workspace/pbuilder/3140971/tmp/hooks/C01_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/2757009 and its subdirectories -I: Current time: Sat Jan 6 10:56:55 -12 2024 -I: pbuilder-time-stamp: 1704581815 +I: removing directory /srv/workspace/pbuilder/3140971 and its subdirectories