Diff of the two buildlogs: -- --- b1/build.log 2024-10-06 09:04:23.175969733 +0000 +++ b2/build.log 2024-10-06 09:04:54.258646793 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Sat Oct 5 21:03:47 -12 2024 -I: pbuilder-time-stamp: 1728205427 +I: Current time: Sun Nov 9 05:27:25 +14 2025 +I: pbuilder-time-stamp: 1762615645 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/trixie-reproducible-base.tgz] I: copying local configuration @@ -25,52 +25,84 @@ dpkg-source: info: unpacking libmojolicious-plugin-oauth2-perl_2.02-1.debian.tar.xz I: Not using root during the build. I: Installing the build-deps -I: user script /srv/workspace/pbuilder/440539/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/3807520/tmp/hooks/D01_modify_environment starting +debug: Running on codethink03-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 Nov 8 15:27 /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/3807520/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/3807520/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]="32" [3]="1" [4]="release" [5]="aarch64-unknown-linux-gnu") + BASH_VERSION='5.2.32(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='trixie' - HOME='/root' - HOST_ARCH='arm64' + DIRSTACK=() + DISTRIBUTION=trixie + EUID=0 + FUNCNAME=([0]="Echo" [1]="main") + GROUPS=() + HOME=/root + HOSTNAME=i-capture-the-hostname + HOSTTYPE=aarch64 + HOST_ARCH=arm64 IFS=' ' - INVOCATION_ID='3ff76a1991a44ebab28f3e2710814158' - 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='440539' - PS1='# ' - PS2='> ' + INVOCATION_ID=59b0d46afd93416791d69e3de466aadb + 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=3807520 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.60Fc8Ae8/pbuilderrc_ULaw --distribution trixie --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/trixie-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.60Fc8Ae8/b1 --logfile b1/build.log libmojolicious-plugin-oauth2-perl_2.02-1.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.4: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.60Fc8Ae8/pbuilderrc_oUGI --distribution trixie --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/trixie-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.60Fc8Ae8/b2 --logfile b2/build.log libmojolicious-plugin-oauth2-perl_2.02-1.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.4:3128 I: uname -a - Linux codethink02-arm64 6.1.0-26-cloud-arm64 #1 SMP Debian 6.1.112-1 (2024-09-30) aarch64 GNU/Linux + Linux i-capture-the-hostname 6.1.0-26-cloud-arm64 #1 SMP Debian 6.1.112-1 (2024-09-30) aarch64 GNU/Linux I: ls -l /bin - lrwxrwxrwx 1 root root 7 Aug 4 21:30 /bin -> usr/bin -I: user script /srv/workspace/pbuilder/440539/tmp/hooks/D02_print_environment finished + lrwxrwxrwx 1 root root 7 Aug 4 2024 /bin -> usr/bin +I: user script /srv/workspace/pbuilder/3807520/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -158,7 +190,7 @@ Get: 40 http://deb.debian.org/debian trixie/main arm64 libjs-highlight.js all 9.18.5+dfsg1-2 [397 kB] Get: 41 http://deb.debian.org/debian trixie/main arm64 libmojolicious-perl all 9.38+dfsg-1 [843 kB] Get: 42 http://deb.debian.org/debian trixie/main arm64 libmojo-jwt-perl all 0.09-1 [12.4 kB] -Fetched 21.6 MB in 0s (59.2 MB/s) +Fetched 21.6 MB in 0s (119 MB/s) debconf: delaying package configuration, since apt-utils is not installed Selecting previously unselected package netbase. (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 ... 19899 files and directories currently installed.) @@ -341,7 +373,11 @@ Building tag database... -> Finished parsing the build-deps I: Building the package -I: Running cd /build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02/ && 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 > ../libmojolicious-plugin-oauth2-perl_2.02-1_source.changes +I: user script /srv/workspace/pbuilder/3807520/tmp/hooks/A99_set_merged_usr starting +Not re-configuring usrmerge for trixie +I: user script /srv/workspace/pbuilder/3807520/tmp/hooks/A99_set_merged_usr finished +hostname: Name or service not known +I: Running cd /build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02/ && 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 > ../libmojolicious-plugin-oauth2-perl_2.02-1_source.changes dpkg-buildpackage: info: source package libmojolicious-plugin-oauth2-perl dpkg-buildpackage: info: source version 2.02-1 dpkg-buildpackage: info: source distribution unstable @@ -365,8 +401,8 @@ dh_auto_build make -j12 make[1]: Entering directory '/build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02' -cp lib/Mojolicious/Plugin/OAuth2.pm blib/lib/Mojolicious/Plugin/OAuth2.pm cp lib/Mojolicious/Plugin/OAuth2/Mock.pm blib/lib/Mojolicious/Plugin/OAuth2/Mock.pm +cp lib/Mojolicious/Plugin/OAuth2.pm blib/lib/Mojolicious/Plugin/OAuth2.pm Manifying 2 pod documents make[1]: Leaving directory '/build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02' dh_auto_test @@ -377,21 +413,21 @@ 1..10 ok 1 - use Mojolicious::Plugin::OAuth2 ok 2 # skip pod_file_ok(blib/lib/Mojolicious/Plugin/OAuth2.pm) (Test::Pod is required) -ok 3 # skip pod_coverage_ok(Mojolicious::Plugin::OAuth2 HASH(0xaaaaff4d2b78)) (Test::Pod::Coverage is required) +ok 3 # skip pod_coverage_ok(Mojolicious::Plugin::OAuth2 HASH(0xaaaad6791b20)) (Test::Pod::Coverage is required) ok 4 - use Mojolicious::Plugin::OAuth2::Mock ok 5 # skip pod_file_ok(blib/lib/Mojolicious/Plugin/OAuth2/Mock.pm) (Test::Pod is required) -ok 6 # skip pod_coverage_ok(Mojolicious::Plugin::OAuth2::Mock HASH(0xaaaaff5a4e08)) (Test::Pod::Coverage is required) +ok 6 # skip pod_coverage_ok(Mojolicious::Plugin::OAuth2::Mock HASH(0xaaaad6297110)) (Test::Pod::Coverage is required) ok 7 # skip changes_ok() (Test::CPAN::Changes is required) ok 8 # skip changes_ok() (Test::CPAN::Changes is required) ok 9 # skip changes_ok() (Test::CPAN::Changes is required) ok 10 # skip changes_ok() (Test::CPAN::Changes is required) ok -[2024-10-06 09:04:14.52597] [444869] [trace] [QjOa-1HRa8L5] GET "/test123" -[2024-10-06 09:04:14.52637] [444869] [trace] [QjOa-1HRa8L5] Routing to a callback -[2024-10-06 09:04:14.52730] [444869] [trace] [QjOa-1HRa8L5] 200 OK (0.001318s, 758.725/s) -[2024-10-06 09:04:14.53210] [444869] [trace] [8i1x61nC2Mqs] GET "/test123" -[2024-10-06 09:04:14.53229] [444869] [trace] [8i1x61nC2Mqs] Routing to a callback -[2024-10-06 09:04:14.53266] [444869] [trace] [8i1x61nC2Mqs] 200 OK (0.000549s, 1821.494/s) +[2025-11-08 15:27:46.15754] [3813769] [trace] [xCo2TrFXN2U6] GET "/test123" +[2025-11-08 15:27:46.15802] [3813769] [trace] [xCo2TrFXN2U6] Routing to a callback +[2025-11-08 15:27:46.15902] [3813769] [trace] [xCo2TrFXN2U6] 200 OK (0.001464s, 683.060/s) +[2025-11-08 15:27:46.16335] [3813769] [trace] [XnGN0ancPAwq] GET "/test123" +[2025-11-08 15:27:46.16356] [3813769] [trace] [XnGN0ancPAwq] Routing to a callback +[2025-11-08 15:27:46.16397] [3813769] [trace] [XnGN0ancPAwq] 200 OK (0.000602s, 1661.130/s) t/auth_url.t ........ ok 1 - provider_id is required ok 2 - GET /test123 @@ -409,51 +445,51 @@ ok 14 - state 1..14 ok -[2024-10-06 09:04:14.89719] [444916] [trace] [NWOz-r1q1t5_] GET "/oauth-delayed" -[2024-10-06 09:04:14.89762] [444916] [trace] [NWOz-r1q1t5_] Routing to a callback -[2024-10-06 09:04:14.89842] [444916] [trace] [NWOz-r1q1t5_] 302 Found (0.001213s, 824.402/s) -[2024-10-06 09:04:14.90314] [444916] [trace] [15rvbz4ImoNZ] GET "/oauth/authorize" -[2024-10-06 09:04:14.90459] [444916] [trace] [15rvbz4ImoNZ] Routing to a callback -[2024-10-06 09:04:14.90497] [444916] [trace] [15rvbz4ImoNZ] 302 Found (0.001825s, 547.945/s) -[2024-10-06 09:04:14.90849] [444916] [trace] [2CzXVhbhL7ff] GET "/oauth-delayed" -[2024-10-06 09:04:14.90868] [444916] [trace] [2CzXVhbhL7ff] Routing to a callback -[2024-10-06 09:04:14.91055] [444916] [trace] [2CzXVhbhL7ff] Template "oauthdelayed.html.ep" not found -[2024-10-06 09:04:14.91063] [444916] [trace] [2CzXVhbhL7ff] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-10-06 09:04:14.91337] [444916] [trace] [Et0nf_8CZjvl] POST "/oauth/token" -[2024-10-06 09:04:14.91368] [444916] [trace] [Et0nf_8CZjvl] Routing to a callback -[2024-10-06 09:04:14.91405] [444916] [trace] [Et0nf_8CZjvl] 200 OK (0.00067s, 1492.537/s) -[2024-10-06 09:04:14.91599] [444916] [trace] [2CzXVhbhL7ff] 200 OK (0.007475s, 133.779/s) +[2025-11-08 15:27:46.52303] [3813809] [trace] [oMbeKJ7IoYwC] GET "/oauth-delayed" +[2025-11-08 15:27:46.52352] [3813809] [trace] [oMbeKJ7IoYwC] Routing to a callback +[2025-11-08 15:27:46.52439] [3813809] [trace] [oMbeKJ7IoYwC] 302 Found (0.001353s, 739.098/s) +[2025-11-08 15:27:46.52938] [3813809] [trace] [kpW5JTB7nIDY] GET "/oauth/authorize" +[2025-11-08 15:27:46.52973] [3813809] [trace] [kpW5JTB7nIDY] Routing to a callback +[2025-11-08 15:27:46.53006] [3813809] [trace] [kpW5JTB7nIDY] 302 Found (0.00067s, 1492.537/s) +[2025-11-08 15:27:46.53381] [3813809] [trace] [vP33wG3SXJ_3] GET "/oauth-delayed" +[2025-11-08 15:27:46.53402] [3813809] [trace] [vP33wG3SXJ_3] Routing to a callback +[2025-11-08 15:27:46.53601] [3813809] [trace] [vP33wG3SXJ_3] Template "oauthdelayed.html.ep" not found +[2025-11-08 15:27:46.53611] [3813809] [trace] [vP33wG3SXJ_3] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2025-11-08 15:27:46.53818] [3813809] [trace] [dUmiQ0mIEfnB] POST "/oauth/token" +[2025-11-08 15:27:46.53850] [3813809] [trace] [dUmiQ0mIEfnB] Routing to a callback +[2025-11-08 15:27:46.53890] [3813809] [trace] [dUmiQ0mIEfnB] 200 OK (0.000706s, 1416.431/s) +[2025-11-08 15:27:46.54025] [3813809] [trace] [vP33wG3SXJ_3] 200 OK (0.006428s, 155.569/s) t/delayed.t ......... ok 1 - GET /oauth-delayed ok 2 - 302 Found ok 3 - got client_id -# /oauth/authorize?client_id=fake_key&redirect_uri=http%3A%2F%2F127.0.0.1%3A37877%2Foauth-delayed&scope=a%2Cb%2Cc -ok 4 - GET http://127.0.0.1:37877/oauth/authorize?client_id=fake_key&redirect_uri=http%3A%2F%2F127.0.0.1%3A37877%2Foauth-delayed&scope=a%2Cb%2Cc +# /oauth/authorize?client_id=fake_key&redirect_uri=http%3A%2F%2F127.0.0.1%3A42257%2Foauth-delayed&scope=a%2Cb%2Cc +ok 4 - GET http://127.0.0.1:42257/oauth/authorize?client_id=fake_key&redirect_uri=http%3A%2F%2F127.0.0.1%3A42257%2Foauth-delayed&scope=a%2Cb%2Cc ok 5 - 302 Found ok 6 - Returns to the right place ok 7 - Includes fake code -# http://127.0.0.1:37877/oauth-delayed?code=fake_code -ok 8 - GET http://127.0.0.1:37877/oauth-delayed?code=fake_code +# http://127.0.0.1:42257/oauth-delayed?code=fake_code +ok 8 - GET http://127.0.0.1:42257/oauth-delayed?code=fake_code ok 9 - 200 OK ok 10 - exact match for content 1..10 ok -[2024-10-06 09:04:15.37905] [444967] [trace] [VBp6cRVDOqg2] GET "/oauth-error" -[2024-10-06 09:04:15.38371] [444967] [trace] [VBp6cRVDOqg2] Routing to a callback -[2024-10-06 09:04:15.38468] [444967] [trace] [VBp6cRVDOqg2] 302 Found (0.005612s, 178.190/s) -[2024-10-06 09:04:15.39293] [444967] [trace] [IrIEg4tVLuqY] GET "/oauth-error" -[2024-10-06 09:04:15.39315] [444967] [trace] [IrIEg4tVLuqY] Routing to a callback -[2024-10-06 09:04:15.39506] [444967] [trace] [IrIEg4tVLuqY] Template "oautherror.html.ep" not found -[2024-10-06 09:04:15.39515] [444967] [trace] [IrIEg4tVLuqY] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-10-06 09:04:15.40145] [444967] [trace] [pQ3yaUFSAsfC] POST "/oauth/token" -[2024-10-06 09:04:15.40177] [444967] [trace] [pQ3yaUFSAsfC] Routing to a callback -[2024-10-06 09:04:15.40221] [444967] [trace] [pQ3yaUFSAsfC] 200 OK (0.000747s, 1338.688/s) -[2024-10-06 09:04:15.40774] [444967] [trace] [IrIEg4tVLuqY] 200 OK (0.01478s, 67.659/s) -[2024-10-06 09:04:15.41084] [444967] [trace] [GCCXXbXH3TdF] GET "/oauth-error" -[2024-10-06 09:04:15.41104] [444967] [trace] [GCCXXbXH3TdF] Routing to a callback -[2024-10-06 09:04:15.41207] [444967] [trace] [GCCXXbXH3TdF] Template "oautherror.html.ep" not found -[2024-10-06 09:04:15.41216] [444967] [trace] [GCCXXbXH3TdF] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-10-06 09:04:15.41247] [444967] [trace] [GCCXXbXH3TdF] 500 Internal Server Error (0.001627s, 614.628/s) +[2025-11-08 15:27:46.90254] [3813849] [trace] [gKdW2-u1GlE0] GET "/oauth-error" +[2025-11-08 15:27:46.90304] [3813849] [trace] [gKdW2-u1GlE0] Routing to a callback +[2025-11-08 15:27:46.90396] [3813849] [trace] [gKdW2-u1GlE0] 302 Found (0.001412s, 708.215/s) +[2025-11-08 15:27:46.90838] [3813849] [trace] [mugBQjF59qzv] GET "/oauth-error" +[2025-11-08 15:27:46.90863] [3813849] [trace] [mugBQjF59qzv] Routing to a callback +[2025-11-08 15:27:46.91073] [3813849] [trace] [mugBQjF59qzv] Template "oautherror.html.ep" not found +[2025-11-08 15:27:46.91085] [3813849] [trace] [mugBQjF59qzv] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2025-11-08 15:27:46.91308] [3813849] [trace] [j2n-qhYD9bqO] POST "/oauth/token" +[2025-11-08 15:27:46.91342] [3813849] [trace] [j2n-qhYD9bqO] Routing to a callback +[2025-11-08 15:27:46.91391] [3813849] [trace] [j2n-qhYD9bqO] 200 OK (0.000812s, 1231.527/s) +[2025-11-08 15:27:46.91538] [3813849] [trace] [mugBQjF59qzv] 200 OK (0.006987s, 143.123/s) +[2025-11-08 15:27:46.91856] [3813849] [trace] [5eZ6V3pfnsOu] GET "/oauth-error" +[2025-11-08 15:27:46.91879] [3813849] [trace] [5eZ6V3pfnsOu] Routing to a callback +[2025-11-08 15:27:46.91931] [3813849] [trace] [5eZ6V3pfnsOu] Template "oautherror.html.ep" not found +[2025-11-08 15:27:46.91939] [3813849] [trace] [5eZ6V3pfnsOu] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2025-11-08 15:27:46.91968] [3813849] [trace] [5eZ6V3pfnsOu] 500 Internal Server Error (0.001114s, 897.666/s) t/error.t ........... ok 1 - GET /oauth-error ok 2 - 302 Found @@ -464,40 +500,40 @@ 1..6 ok t/live.t ............ skipped: OAUTH_FB_KEY and OAUTH_FB_SECRET must be set for oauth tests -[2024-10-06 09:04:16.50468] [445000] [trace] [x8U4lcdl4if1] GET "/profile" -[2024-10-06 09:04:16.50523] [445000] [trace] [x8U4lcdl4if1] Routing to a callback -[2024-10-06 09:04:16.50608] [445000] [trace] [x8U4lcdl4if1] 302 Found (0.001392s, 718.391/s) -[2024-10-06 09:04:16.51465] [445000] [trace] [8XU0Y3bMhoqf] GET "/mocked/oauth/authorize" -[2024-10-06 09:04:16.51497] [445000] [trace] [8XU0Y3bMhoqf] Routing to a callback -[2024-10-06 09:04:16.51973] [445000] [trace] [8XU0Y3bMhoqf] 200 OK (0.005046s, 198.177/s) -[2024-10-06 09:04:16.52474] [445000] [trace] [50WtHvGLx7K9] GET "/profile" -[2024-10-06 09:04:16.52494] [445000] [trace] [50WtHvGLx7K9] Routing to a callback -[2024-10-06 09:04:16.53214] [445000] [trace] [50WtHvGLx7K9] Template "profile.html.ep" not found -[2024-10-06 09:04:16.53225] [445000] [trace] [50WtHvGLx7K9] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-10-06 09:04:16.53434] [445000] [trace] [fPrqX4vhyzNt] POST "/mocked/oauth/token" -[2024-10-06 09:04:16.53465] [445000] [trace] [fPrqX4vhyzNt] Routing to a callback -[2024-10-06 09:04:16.53506] [445000] [trace] [fPrqX4vhyzNt] 200 OK (0.000712s, 1404.494/s) -[2024-10-06 09:04:16.54076] [445000] [trace] [50WtHvGLx7K9] 200 OK (0.016001s, 62.496/s) -[2024-10-06 09:04:16.54850] [445000] [trace] [ycnCFq9nQBSE] GET "/profile" -[2024-10-06 09:04:16.54872] [445000] [trace] [ycnCFq9nQBSE] Routing to a callback -[2024-10-06 09:04:16.54922] [445000] [trace] [ycnCFq9nQBSE] Template "profile.html.ep" not found -[2024-10-06 09:04:16.54928] [445000] [trace] [ycnCFq9nQBSE] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-10-06 09:04:16.54956] [445000] [trace] [ycnCFq9nQBSE] 500 Internal Server Error (0.001057s, 946.074/s) -[2024-10-06 09:04:16.55703] [445000] [trace] [fHqoQGOGczH1] GET "/no-redirect" -[2024-10-06 09:04:16.55738] [445000] [trace] [fHqoQGOGczH1] Routing to a callback -[2024-10-06 09:04:16.55789] [445000] [trace] [fHqoQGOGczH1] Template "noredirect.html.ep" not found -[2024-10-06 09:04:16.55795] [445000] [trace] [fHqoQGOGczH1] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-10-06 09:04:16.55820] [445000] [trace] [fHqoQGOGczH1] 200 OK (0.001159s, 862.813/s) +[2025-11-08 15:27:47.63672] [3813996] [trace] [9CiG1BkDi4Xn] GET "/profile" +[2025-11-08 15:27:47.63735] [3813996] [trace] [9CiG1BkDi4Xn] Routing to a callback +[2025-11-08 15:27:47.63827] [3813996] [trace] [9CiG1BkDi4Xn] 302 Found (0.001529s, 654.022/s) +[2025-11-08 15:27:47.64282] [3813996] [trace] [bIemm_zHarQP] GET "/mocked/oauth/authorize" +[2025-11-08 15:27:47.64318] [3813996] [trace] [bIemm_zHarQP] Routing to a callback +[2025-11-08 15:27:47.64383] [3813996] [trace] [bIemm_zHarQP] 200 OK (0.000991s, 1009.082/s) +[2025-11-08 15:27:47.64854] [3813996] [trace] [cgutlDxFMhj0] GET "/profile" +[2025-11-08 15:27:47.64878] [3813996] [trace] [cgutlDxFMhj0] Routing to a callback +[2025-11-08 15:27:47.65217] [3813996] [trace] [cgutlDxFMhj0] Template "profile.html.ep" not found +[2025-11-08 15:27:47.65229] [3813996] [trace] [cgutlDxFMhj0] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2025-11-08 15:27:47.65452] [3813996] [trace] [DVFDMtqEDhZJ] POST "/mocked/oauth/token" +[2025-11-08 15:27:47.65487] [3813996] [trace] [DVFDMtqEDhZJ] Routing to a callback +[2025-11-08 15:27:47.65532] [3813996] [trace] [DVFDMtqEDhZJ] 200 OK (0.000787s, 1270.648/s) +[2025-11-08 15:27:47.65681] [3813996] [trace] [cgutlDxFMhj0] 200 OK (0.00825s, 121.212/s) +[2025-11-08 15:27:47.66067] [3813996] [trace] [7AJN1MOrbUW1] GET "/profile" +[2025-11-08 15:27:47.66095] [3813996] [trace] [7AJN1MOrbUW1] Routing to a callback +[2025-11-08 15:27:47.66151] [3813996] [trace] [7AJN1MOrbUW1] Template "profile.html.ep" not found +[2025-11-08 15:27:47.66159] [3813996] [trace] [7AJN1MOrbUW1] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2025-11-08 15:27:47.66190] [3813996] [trace] [7AJN1MOrbUW1] 500 Internal Server Error (0.001215s, 823.045/s) +[2025-11-08 15:27:47.66536] [3813996] [trace] [_3ptg90-l8jl] GET "/no-redirect" +[2025-11-08 15:27:47.66570] [3813996] [trace] [_3ptg90-l8jl] Routing to a callback +[2025-11-08 15:27:47.66624] [3813996] [trace] [_3ptg90-l8jl] Template "noredirect.html.ep" not found +[2025-11-08 15:27:47.66631] [3813996] [trace] [_3ptg90-l8jl] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2025-11-08 15:27:47.66656] [3813996] [trace] [_3ptg90-l8jl] 200 OK (0.001193s, 838.223/s) t/mocked.t .......... ok 1 - GET /profile ok 2 - 302 Found ok 3 - got client_id -ok 4 - GET http://127.0.0.1:40745/mocked/oauth/authorize?client_id=42&redirect_uri=http%3A%2F%2F127.0.0.1%3A40745%2Fprofile +ok 4 - GET http://127.0.0.1:35693/mocked/oauth/authorize?client_id=42&redirect_uri=http%3A%2F%2F127.0.0.1%3A35693%2Fprofile ok 5 - 200 OK ok 6 - element for selector "a" exists ok 7 - Returns to the right place ok 8 - Includes fake code -ok 9 - GET http://127.0.0.1:40745/profile?code=fake_code +ok 9 - GET http://127.0.0.1:35693/profile?code=fake_code ok 10 - 200 OK ok 11 - exact match for content ok 12 - GET /profile?error=access_denied @@ -508,93 +544,93 @@ ok 17 - content is similar 1..17 ok -[2024-10-06 09:04:17.10690] [445009] [debug] Fetching OpenID configuration from /mocked/oauth2/.well-known/configuration -[2024-10-06 09:04:17.12109] [445009] [trace] [CGMr0RPfSr0j] GET "/mocked/oauth2/.well-known/configuration" -[2024-10-06 09:04:17.12152] [445009] [trace] [CGMr0RPfSr0j] Routing to a callback -[2024-10-06 09:04:17.12286] [445009] [trace] [CGMr0RPfSr0j] Rendering template "oauth2/mock/configuration.json.ep" from DATA section -[2024-10-06 09:04:17.12528] [445009] [trace] [CGMr0RPfSr0j] 200 OK (0.004166s, 240.038/s) -[2024-10-06 09:04:17.13477] [445009] [trace] [iw25ckLA426B] GET "/mocked/oauth2/keys" -[2024-10-06 09:04:17.13511] [445009] [trace] [iw25ckLA426B] Routing to a callback -[2024-10-06 09:04:17.68532] [445009] [trace] [iw25ckLA426B] Rendering template "oauth2/mock/keys.json.ep" from DATA section -[2024-10-06 09:04:17.68731] [445009] [trace] [iw25ckLA426B] 200 OK (0.552511s, 1.810/s) -[2024-10-06 09:04:17.70380] [445009] [trace] [HpioJVWCeL1F] GET "/connect" -[2024-10-06 09:04:17.70430] [445009] [trace] [HpioJVWCeL1F] Routing to a callback -[2024-10-06 09:04:17.70482] [445009] [trace] [HpioJVWCeL1F] 302 Found (0.001005s, 995.025/s) -[2024-10-06 09:04:17.71452] [445009] [trace] [fAFY73A1Cmoj] GET "/mocked/oauth2/authorize" -[2024-10-06 09:04:17.71491] [445009] [trace] [fAFY73A1Cmoj] Routing to a callback -[2024-10-06 09:04:17.71531] [445009] [trace] [fAFY73A1Cmoj] Rendering template "oauth2/mock/form_post.html.ep" from DATA section -[2024-10-06 09:04:17.72041] [445009] [trace] [fAFY73A1Cmoj] 200 OK (0.005864s, 170.532/s) -[2024-10-06 09:04:17.72528] [445009] [trace] [Twd6G8oLPSUa] POST "/connect" -[2024-10-06 09:04:17.72563] [445009] [trace] [Twd6G8oLPSUa] Routing to a callback -[2024-10-06 09:04:17.73170] [445009] [trace] [hwI_Lz7mvfyD] POST "/mocked/oauth2/token" -[2024-10-06 09:04:17.73204] [445009] [trace] [hwI_Lz7mvfyD] Routing to a callback -[2024-10-06 09:04:17.74158] [445009] [trace] [hwI_Lz7mvfyD] Rendering template "oauth2/mock/token.json.ep" from DATA section -[2024-10-06 09:04:17.74327] [445009] [trace] [hwI_Lz7mvfyD] 200 OK (0.011541s, 86.648/s) -[2024-10-06 09:04:17.74926] [445009] [trace] Your secret passphrase needs to be changed (see FAQ for more) -[2024-10-06 09:04:17.75043] [445009] [trace] [Twd6G8oLPSUa] 200 OK (0.025142s, 39.774/s) -[2024-10-06 09:04:17.76201] [445009] [trace] [DW72vQi4a617] GET "/refresh" -[2024-10-06 09:04:17.76244] [445009] [trace] [DW72vQi4a617] Routing to a callback -[2024-10-06 09:04:17.76882] [445009] [trace] [QrUhntL1ABKf] POST "/mocked/oauth2/token" -[2024-10-06 09:04:17.76903] [445009] [trace] [QrUhntL1ABKf] Routing to a callback -[2024-10-06 09:04:17.77780] [445009] [trace] [QrUhntL1ABKf] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2024-10-06 09:04:17.77884] [445009] [trace] [QrUhntL1ABKf] 200 OK (0.009997s, 100.030/s) -[2024-10-06 09:04:17.78571] [445009] [trace] [DW72vQi4a617] 200 OK (0.023673s, 42.242/s) -[2024-10-06 09:04:17.79053] [445009] [trace] [idaBX5LooPZq] GET "/refresh" -[2024-10-06 09:04:17.79071] [445009] [trace] [idaBX5LooPZq] Routing to a callback -[2024-10-06 09:04:17.80105] [445009] [trace] [_0RgbsGo9nWD] POST "/mocked/oauth2/token" -[2024-10-06 09:04:17.80128] [445009] [trace] [_0RgbsGo9nWD] Routing to a callback -[2024-10-06 09:04:17.80602] [445009] [trace] [_0RgbsGo9nWD] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2024-10-06 09:04:17.80700] [445009] [trace] [_0RgbsGo9nWD] 200 OK (0.005935s, 168.492/s) -[2024-10-06 09:04:17.81380] [445009] [trace] [idaBX5LooPZq] 200 OK (0.02324s, 43.029/s) -[2024-10-06 09:04:17.82329] [445009] [trace] [mYkmLE1ieDjO] GET "/refresh" -[2024-10-06 09:04:17.82380] [445009] [trace] [mYkmLE1ieDjO] Routing to a callback -[2024-10-06 09:04:17.82470] [445009] [trace] [mYkmLE1ieDjO] 500 Internal Server Error (0.0014s, 714.286/s) -[2024-10-06 09:04:17.83837] [445009] [trace] [9Xngt9LP5gMY] GET "/connect" -[2024-10-06 09:04:17.83856] [445009] [trace] [9Xngt9LP5gMY] Routing to a callback -[2024-10-06 09:04:17.83896] [445009] [trace] [9Xngt9LP5gMY] 302 Found (0.000576s, 1736.111/s) -[2024-10-06 09:04:17.84820] [445009] [trace] [MDsq8uookb7X] GET "/mocked/oauth2/authorize" -[2024-10-06 09:04:17.84847] [445009] [trace] [MDsq8uookb7X] Routing to a callback -[2024-10-06 09:04:17.84882] [445009] [trace] [MDsq8uookb7X] 302 Found (0.000611s, 1636.661/s) -[2024-10-06 09:04:17.85743] [445009] [trace] [sRkudonYpj4H] GET "/connect" -[2024-10-06 09:04:17.85765] [445009] [trace] [sRkudonYpj4H] Routing to a callback -[2024-10-06 09:04:17.86375] [445009] [trace] [0emr5zFRtQH4] POST "/mocked/oauth2/token" -[2024-10-06 09:04:17.86398] [445009] [trace] [0emr5zFRtQH4] Routing to a callback -[2024-10-06 09:04:17.86880] [445009] [trace] [0emr5zFRtQH4] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2024-10-06 09:04:17.86974] [445009] [trace] [0emr5zFRtQH4] 200 OK (0.005971s, 167.476/s) -[2024-10-06 09:04:17.87657] [445009] [trace] [sRkudonYpj4H] 200 OK (0.019117s, 52.309/s) -[2024-10-06 09:04:17.89276] [445009] [trace] [wG77OCImrEDA] GET "/end_session" -[2024-10-06 09:04:17.89312] [445009] [trace] [wG77OCImrEDA] Routing to a callback -[2024-10-06 09:04:17.89362] [445009] [trace] [wG77OCImrEDA] 302 Found (0.000851s, 1175.088/s) -[2024-10-06 09:04:17.90276] [445009] [trace] [YkyTlal3RE1e] GET "/mocked/oauth2/logout" -[2024-10-06 09:04:17.90311] [445009] [trace] [YkyTlal3RE1e] Routing to a callback -[2024-10-06 09:04:17.90760] [445009] [trace] [YkyTlal3RE1e] 302 Found (0.00481s, 207.900/s) -[2024-10-06 09:04:17.91251] [445009] [trace] [wip6M5-BtjgD] GET "/end_session" -[2024-10-06 09:04:17.91272] [445009] [trace] [wip6M5-BtjgD] Routing to a callback -[2024-10-06 09:04:17.91345] [445009] [trace] [wip6M5-BtjgD] 302 Found (0.000923s, 1083.424/s) -[2024-10-06 09:04:17.92227] [445009] [trace] [zkNPwJbE2Tex] GET "/end_session" -[2024-10-06 09:04:17.92245] [445009] [trace] [zkNPwJbE2Tex] Routing to a callback -[2024-10-06 09:04:17.92267] [445009] [trace] [zkNPwJbE2Tex] 302 Found (0.000395s, 2531.646/s) -[2024-10-06 09:04:17.93601] [445009] [trace] [20o272uY1vob] GET "/protect/next" -[2024-10-06 09:04:17.93651] [445009] [trace] [20o272uY1vob] Routing to a callback -[2024-10-06 09:04:17.93672] [445009] [trace] [20o272uY1vob] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-10-06 09:04:18.03999] [445009] [trace] [20o272uY1vob] 302 Found (0.103954s, 9.620/s) -[2024-10-06 09:04:18.04253] [445009] [trace] [udB6uzLLBzED] GET "/connect" -[2024-10-06 09:04:18.04274] [445009] [trace] [udB6uzLLBzED] Routing to a callback -[2024-10-06 09:04:18.04314] [445009] [trace] [udB6uzLLBzED] 302 Found (0.000604s, 1655.629/s) -[2024-10-06 09:04:18.05015] [445009] [trace] [dNjW3QawJKOb] GET "/mocked/oauth2/authorize" -[2024-10-06 09:04:18.05040] [445009] [trace] [dNjW3QawJKOb] Routing to a callback -[2024-10-06 09:04:18.05075] [445009] [trace] [dNjW3QawJKOb] 302 Found (0.000596s, 1677.852/s) -[2024-10-06 09:04:18.05310] [445009] [trace] [tzK-UyGQOAfG] GET "/connect" -[2024-10-06 09:04:18.05332] [445009] [trace] [tzK-UyGQOAfG] Routing to a callback -[2024-10-06 09:04:18.05510] [445009] [trace] [eCG_KhPukIB5] POST "/mocked/oauth2/token" -[2024-10-06 09:04:18.05531] [445009] [trace] [eCG_KhPukIB5] Routing to a callback -[2024-10-06 09:04:18.06833] [445009] [trace] [eCG_KhPukIB5] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2024-10-06 09:04:18.06932] [445009] [trace] [eCG_KhPukIB5] 200 OK (0.014195s, 70.447/s) -[2024-10-06 09:04:18.07605] [445009] [trace] [tzK-UyGQOAfG] 302 Found (0.022921s, 43.628/s) -[2024-10-06 09:04:18.08369] [445009] [trace] [qhWio38TXaa4] GET "/protect/next" -[2024-10-06 09:04:18.08394] [445009] [trace] [qhWio38TXaa4] Routing to a callback -[2024-10-06 09:04:18.08429] [445009] [trace] [qhWio38TXaa4] Routing to a callback -[2024-10-06 09:04:18.08449] [445009] [trace] [qhWio38TXaa4] 200 OK (0.000796s, 1256.281/s) +[2025-11-08 15:27:48.02550] [3814048] [debug] Fetching OpenID configuration from /mocked/oauth2/.well-known/configuration +[2025-11-08 15:27:48.03170] [3814048] [trace] [PtAMx1DJ30Oq] GET "/mocked/oauth2/.well-known/configuration" +[2025-11-08 15:27:48.03222] [3814048] [trace] [PtAMx1DJ30Oq] Routing to a callback +[2025-11-08 15:27:48.03372] [3814048] [trace] [PtAMx1DJ30Oq] Rendering template "oauth2/mock/configuration.json.ep" from DATA section +[2025-11-08 15:27:48.03624] [3814048] [trace] [PtAMx1DJ30Oq] 200 OK (0.004514s, 221.533/s) +[2025-11-08 15:27:48.03989] [3814048] [trace] [ZbuWLPN3TiZc] GET "/mocked/oauth2/keys" +[2025-11-08 15:27:48.04023] [3814048] [trace] [ZbuWLPN3TiZc] Routing to a callback +[2025-11-08 15:27:48.38595] [3814048] [trace] [ZbuWLPN3TiZc] Rendering template "oauth2/mock/keys.json.ep" from DATA section +[2025-11-08 15:27:48.38798] [3814048] [trace] [ZbuWLPN3TiZc] 200 OK (0.348059s, 2.873/s) +[2025-11-08 15:27:48.39639] [3814048] [trace] [ssBdRBPQWPGi] GET "/connect" +[2025-11-08 15:27:48.39691] [3814048] [trace] [ssBdRBPQWPGi] Routing to a callback +[2025-11-08 15:27:48.39743] [3814048] [trace] [ssBdRBPQWPGi] 302 Found (0.001018s, 982.318/s) +[2025-11-08 15:27:48.40300] [3814048] [trace] [cGpGgzV_JFIE] GET "/mocked/oauth2/authorize" +[2025-11-08 15:27:48.40340] [3814048] [trace] [cGpGgzV_JFIE] Routing to a callback +[2025-11-08 15:27:48.40381] [3814048] [trace] [cGpGgzV_JFIE] Rendering template "oauth2/mock/form_post.html.ep" from DATA section +[2025-11-08 15:27:48.40482] [3814048] [trace] [cGpGgzV_JFIE] 200 OK (0.001803s, 554.631/s) +[2025-11-08 15:27:48.40952] [3814048] [trace] [eoQZ_hmORJCm] POST "/connect" +[2025-11-08 15:27:48.40990] [3814048] [trace] [eoQZ_hmORJCm] Routing to a callback +[2025-11-08 15:27:48.41194] [3814048] [trace] [2szTH3C23-7-] POST "/mocked/oauth2/token" +[2025-11-08 15:27:48.41227] [3814048] [trace] [2szTH3C23-7-] Routing to a callback +[2025-11-08 15:27:48.41776] [3814048] [trace] [2szTH3C23-7-] Rendering template "oauth2/mock/token.json.ep" from DATA section +[2025-11-08 15:27:48.41949] [3814048] [trace] [2szTH3C23-7-] 200 OK (0.007528s, 132.837/s) +[2025-11-08 15:27:48.42145] [3814048] [trace] Your secret passphrase needs to be changed (see FAQ for more) +[2025-11-08 15:27:48.42267] [3814048] [trace] [eoQZ_hmORJCm] 200 OK (0.013119s, 76.225/s) +[2025-11-08 15:27:48.43002] [3814048] [trace] [wSpqBpP9dMA8] GET "/refresh" +[2025-11-08 15:27:48.43047] [3814048] [trace] [wSpqBpP9dMA8] Routing to a callback +[2025-11-08 15:27:48.43266] [3814048] [trace] [QztD1yIoAAIf] POST "/mocked/oauth2/token" +[2025-11-08 15:27:48.43291] [3814048] [trace] [QztD1yIoAAIf] Routing to a callback +[2025-11-08 15:27:48.43763] [3814048] [trace] [QztD1yIoAAIf] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2025-11-08 15:27:48.43871] [3814048] [trace] [QztD1yIoAAIf] 200 OK (0.006032s, 165.782/s) +[2025-11-08 15:27:48.44157] [3814048] [trace] [wSpqBpP9dMA8] 200 OK (0.011524s, 86.775/s) +[2025-11-08 15:27:48.44669] [3814048] [trace] [WWzzzBrDF3gw] GET "/refresh" +[2025-11-08 15:27:48.44691] [3814048] [trace] [WWzzzBrDF3gw] Routing to a callback +[2025-11-08 15:27:48.44906] [3814048] [trace] [0AYWqaNHKw0a] POST "/mocked/oauth2/token" +[2025-11-08 15:27:48.44928] [3814048] [trace] [0AYWqaNHKw0a] Routing to a callback +[2025-11-08 15:27:48.45398] [3814048] [trace] [0AYWqaNHKw0a] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2025-11-08 15:27:48.45502] [3814048] [trace] [0AYWqaNHKw0a] 200 OK (0.005933s, 168.549/s) +[2025-11-08 15:27:48.45775] [3814048] [trace] [WWzzzBrDF3gw] 200 OK (0.011033s, 90.637/s) +[2025-11-08 15:27:48.46321] [3814048] [trace] [BODpSugbzJlD] GET "/refresh" +[2025-11-08 15:27:48.46346] [3814048] [trace] [BODpSugbzJlD] Routing to a callback +[2025-11-08 15:27:48.46436] [3814048] [trace] [BODpSugbzJlD] 500 Internal Server Error (0.001141s, 876.424/s) +[2025-11-08 15:27:48.47046] [3814048] [trace] [6J417bWznIWr] GET "/connect" +[2025-11-08 15:27:48.47066] [3814048] [trace] [6J417bWznIWr] Routing to a callback +[2025-11-08 15:27:48.47107] [3814048] [trace] [6J417bWznIWr] 302 Found (0.0006s, 1666.667/s) +[2025-11-08 15:27:48.47587] [3814048] [trace] [Ewo_1aQpomE1] GET "/mocked/oauth2/authorize" +[2025-11-08 15:27:48.47613] [3814048] [trace] [Ewo_1aQpomE1] Routing to a callback +[2025-11-08 15:27:48.47648] [3814048] [trace] [Ewo_1aQpomE1] 302 Found (0.000603s, 1658.375/s) +[2025-11-08 15:27:48.48089] [3814048] [trace] [Zt-9USuVelAv] GET "/connect" +[2025-11-08 15:27:48.48111] [3814048] [trace] [Zt-9USuVelAv] Routing to a callback +[2025-11-08 15:27:48.48308] [3814048] [trace] [q9GO5pFhtrmt] POST "/mocked/oauth2/token" +[2025-11-08 15:27:48.48330] [3814048] [trace] [q9GO5pFhtrmt] Routing to a callback +[2025-11-08 15:27:48.48796] [3814048] [trace] [q9GO5pFhtrmt] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2025-11-08 15:27:48.48902] [3814048] [trace] [q9GO5pFhtrmt] 200 OK (0.005905s, 169.348/s) +[2025-11-08 15:27:48.49179] [3814048] [trace] [Zt-9USuVelAv] 200 OK (0.010882s, 91.895/s) +[2025-11-08 15:27:48.49982] [3814048] [trace] [QJkTS-WqHabS] GET "/end_session" +[2025-11-08 15:27:48.50021] [3814048] [trace] [QJkTS-WqHabS] Routing to a callback +[2025-11-08 15:27:48.50078] [3814048] [trace] [QJkTS-WqHabS] 302 Found (0.00094s, 1063.830/s) +[2025-11-08 15:27:48.50595] [3814048] [trace] [dk-x7-4RcXfE] GET "/mocked/oauth2/logout" +[2025-11-08 15:27:48.50634] [3814048] [trace] [dk-x7-4RcXfE] Routing to a callback +[2025-11-08 15:27:48.50670] [3814048] [trace] [dk-x7-4RcXfE] 302 Found (0.00074s, 1351.351/s) +[2025-11-08 15:27:48.51133] [3814048] [trace] [bl8eFmUq6p6f] GET "/end_session" +[2025-11-08 15:27:48.51157] [3814048] [trace] [bl8eFmUq6p6f] Routing to a callback +[2025-11-08 15:27:48.51235] [3814048] [trace] [bl8eFmUq6p6f] 302 Found (0.001001s, 999.001/s) +[2025-11-08 15:27:48.51713] [3814048] [trace] [CkHzTff-PCpR] GET "/end_session" +[2025-11-08 15:27:48.51734] [3814048] [trace] [CkHzTff-PCpR] Routing to a callback +[2025-11-08 15:27:48.51757] [3814048] [trace] [CkHzTff-PCpR] 302 Found (0.000439s, 2277.904/s) +[2025-11-08 15:27:48.52244] [3814048] [trace] [U_S2Q_QA0lMm] GET "/protect/next" +[2025-11-08 15:27:48.52291] [3814048] [trace] [U_S2Q_QA0lMm] Routing to a callback +[2025-11-08 15:27:48.52310] [3814048] [trace] [U_S2Q_QA0lMm] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2025-11-08 15:27:48.62467] [3814048] [trace] [U_S2Q_QA0lMm] 302 Found (0.102174s, 9.787/s) +[2025-11-08 15:27:48.62920] [3814048] [trace] [FgeQcok672dC] GET "/connect" +[2025-11-08 15:27:48.62962] [3814048] [trace] [FgeQcok672dC] Routing to a callback +[2025-11-08 15:27:48.63041] [3814048] [trace] [FgeQcok672dC] 302 Found (0.001193s, 838.223/s) +[2025-11-08 15:27:48.63531] [3814048] [trace] [X690oK_fxi00] GET "/mocked/oauth2/authorize" +[2025-11-08 15:27:48.63580] [3814048] [trace] [X690oK_fxi00] Routing to a callback +[2025-11-08 15:27:48.63656] [3814048] [trace] [X690oK_fxi00] 302 Found (0.001203s, 831.255/s) +[2025-11-08 15:27:48.64068] [3814048] [trace] [NclB1qRdIQtl] GET "/connect" +[2025-11-08 15:27:48.64114] [3814048] [trace] [NclB1qRdIQtl] Routing to a callback +[2025-11-08 15:27:48.64462] [3814048] [trace] [BcWmh7gbT1kM] POST "/mocked/oauth2/token" +[2025-11-08 15:27:48.64502] [3814048] [trace] [BcWmh7gbT1kM] Routing to a callback +[2025-11-08 15:27:48.65717] [3814048] [trace] [BcWmh7gbT1kM] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2025-11-08 15:27:48.65866] [3814048] [trace] [BcWmh7gbT1kM] 200 OK (0.014009s, 71.383/s) +[2025-11-08 15:27:48.66322] [3814048] [trace] [NclB1qRdIQtl] 302 Found (0.022508s, 44.429/s) +[2025-11-08 15:27:48.66937] [3814048] [trace] [IV52Uy8Z1l9I] GET "/protect/next" +[2025-11-08 15:27:48.66967] [3814048] [trace] [IV52Uy8Z1l9I] Routing to a callback +[2025-11-08 15:27:48.67016] [3814048] [trace] [IV52Uy8Z1l9I] Routing to a callback +[2025-11-08 15:27:48.67046] [3814048] [trace] [IV52Uy8Z1l9I] 200 OK (0.001079s, 926.784/s) t/openid-connect.t .. # Subtest: warmup of provider data ok 1 - scope @@ -611,10 +647,10 @@ ok 2 - 302 Found ok 3 - scope set ok 4 - response mode set - ok 5 - GET http://127.0.0.1:38627/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A39281%2Fconnect&scope=openid&response_mode=form_post&response_type=code&state=test + ok 5 - GET http://127.0.0.1:42927/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A46171%2Fconnect&scope=openid&response_mode=form_post&response_type=code&state=test ok 6 - 200 OK ok 7 - absolute url - ok 8 - POST http://127.0.0.1:39281/connect + ok 8 - POST http://127.0.0.1:46171/connect ok 9 - 200 OK ok 10 - exact match for JSON Pointer "/aud" ok 11 - exact match for JSON Pointer "/email" @@ -644,12 +680,12 @@ ok 3 - scope set ok 4 - response mode set ok 5 - state propagates - ok 6 - GET http://127.0.0.1:38627/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A39281%2Fconnect&scope=openid+email+profile&response_mode=query&response_type=code&state=test + ok 6 - GET http://127.0.0.1:42927/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A46171%2Fconnect&scope=openid+email+profile&response_mode=query&response_type=code&state=test ok 7 - 302 Found ok 8 - redirect_uri ok 9 - code set ok 10 - state returned - ok 11 - GET http://127.0.0.1:39281/connect?code=authorize-code&state=test + ok 11 - GET http://127.0.0.1:46171/connect?code=authorize-code&state=test ok 12 - 200 OK ok 13 - exact match for JSON Pointer "/aud" ok 14 - exact match for JSON Pointer "/email" @@ -663,22 +699,22 @@ ok 4 - Authorize and obtain token - query response_mode # Subtest: Logout ok 1 - Have a current id token - ok 2 - GET http://127.0.0.1:39281/end_session + ok 2 - GET http://127.0.0.1:46171/end_session ok 3 - 302 Found ok 4 - correct ok 5 - correct id token ok 6 - post_logout_redirect_uri set ok 7 - state set - ok 8 - GET http://127.0.0.1:38627/mocked/oauth2/logout?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTcyODIwOTA1NywiaWF0IjoxNzI4MjA1NDU3LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6Mzg2MjdcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.WbXB7J1vbz-xlyjA_ZFvFxqO3JdVAuqRHdwiASqtMbFnFD_TkY9YYx3pCKOGvWXGpcTvclT6zpmJ-S6d5fgDFoXN4oYtWXTtJuNL_3nsU1Ad9Ju_wXH1wY7q1E5AspbtQt4jRhB7hBVfxHGBxtxjrB7CKS8XT2C4iaQEMjewHIc5V0vO8Gl4nIZl1kW4mfdKO0ZeG2q4wLUQsTp4a59Z4wsHgwb-GbuD6anf2Tvir88trjLIIpfzy07bU8aYL_kfnjbLqagEe3WVQyEXeh44wv0ORQQvQjMi0hzbT-g4vcH8oLCykAQtdqHWO6q5VZ_jNOxAH_uLYypb7b0PffnTUQ&post_logout_redirect_uri=http%3A%2F%2F127.0.0.1%3A39281%2Fend_session&state=1728205457 + ok 8 - GET http://127.0.0.1:42927/mocked/oauth2/logout?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTc2MjYxOTI2OCwiaWF0IjoxNzYyNjE1NjY4LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6NDI5MjdcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.emZTQfaEkF12RIE22AMGMe6ZgrD6tnDOzCuOf1z8YcF4qGk2xMuQRMc6goUS9bzsDjb82sZTVRo7x4rMw01Hptd88nAOzSUwafU4vj0odC8YmOdzW_drum7O-_VmFSdnx6ldDaMZvV_Bq9GAXSuV5G5vH_Oc6fTivk161pfNUZNFLstulpbDnokr5anDoY382wALBpxDl4yu1kKz9vbadi5RVWq_8nG1TqSyBaqcHn7oMdItbbCDznGiDLMK_vILKbghe1-7gNceJlHGwudtnNY87ERKDyjNFh2iMwWNs_9saJ0eIpRRs32PzipHlKkdRdRH_HYfT3ob96aCSZO4Cw&post_logout_redirect_uri=http%3A%2F%2F127.0.0.1%3A46171%2Fend_session&state=1762615668 ok 9 - 302 Found ok 10 - correct ok 11 - correct id token ok 12 - state set - ok 13 - GET http://127.0.0.1:39281/end_session?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTcyODIwOTA1NywiaWF0IjoxNzI4MjA1NDU3LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6Mzg2MjdcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.WbXB7J1vbz-xlyjA_ZFvFxqO3JdVAuqRHdwiASqtMbFnFD_TkY9YYx3pCKOGvWXGpcTvclT6zpmJ-S6d5fgDFoXN4oYtWXTtJuNL_3nsU1Ad9Ju_wXH1wY7q1E5AspbtQt4jRhB7hBVfxHGBxtxjrB7CKS8XT2C4iaQEMjewHIc5V0vO8Gl4nIZl1kW4mfdKO0ZeG2q4wLUQsTp4a59Z4wsHgwb-GbuD6anf2Tvir88trjLIIpfzy07bU8aYL_kfnjbLqagEe3WVQyEXeh44wv0ORQQvQjMi0hzbT-g4vcH8oLCykAQtdqHWO6q5VZ_jNOxAH_uLYypb7b0PffnTUQ&state=1728205457 + ok 13 - GET http://127.0.0.1:46171/end_session?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTc2MjYxOTI2OCwiaWF0IjoxNzYyNjE1NjY4LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6NDI5MjdcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.emZTQfaEkF12RIE22AMGMe6ZgrD6tnDOzCuOf1z8YcF4qGk2xMuQRMc6goUS9bzsDjb82sZTVRo7x4rMw01Hptd88nAOzSUwafU4vj0odC8YmOdzW_drum7O-_VmFSdnx6ldDaMZvV_Bq9GAXSuV5G5vH_Oc6fTivk161pfNUZNFLstulpbDnokr5anDoY382wALBpxDl4yu1kKz9vbadi5RVWq_8nG1TqSyBaqcHn7oMdItbbCDznGiDLMK_vILKbghe1-7gNceJlHGwudtnNY87ERKDyjNFh2iMwWNs_9saJ0eIpRRs32PzipHlKkdRdRH_HYfT3ob96aCSZO4Cw&state=1762615668 ok 14 - 302 Found ok 15 - home ok 16 - removed - ok 17 - GET http://127.0.0.1:39281/end_session + ok 17 - GET http://127.0.0.1:46171/end_session ok 18 - 302 Found ok 19 - home 1..19 @@ -694,7 +730,7 @@ 1..6 ok All tests successful. -Files=7, Tests=63, 5 wallclock secs ( 0.04 usr 0.01 sys + 2.31 cusr 0.28 csys = 2.64 CPU) +Files=7, Tests=63, 3 wallclock secs ( 0.05 usr 0.03 sys + 2.66 cusr 0.40 csys = 3.14 CPU) Result: PASS make[1]: Leaving directory '/build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02' create-stamp debian/debhelper-build-stamp @@ -729,12 +765,14 @@ dpkg-buildpackage: info: binary-only upload (no source included) dpkg-genchanges: info: including full source code in upload I: copying local configuration +I: user script /srv/workspace/pbuilder/3807520/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/3807520/tmp/hooks/B01_cleanup finished I: unmounting dev/ptmx filesystem I: unmounting dev/pts filesystem I: unmounting dev/shm filesystem I: unmounting proc filesystem I: unmounting sys filesystem I: cleaning the build env -I: removing directory /srv/workspace/pbuilder/440539 and its subdirectories -I: Current time: Sat Oct 5 21:04:21 -12 2024 -I: pbuilder-time-stamp: 1728205461 +I: removing directory /srv/workspace/pbuilder/3807520 and its subdirectories +I: Current time: Sun Nov 9 05:27:51 +14 2025 +I: pbuilder-time-stamp: 1762615671