Diff of the two buildlogs: -- --- b1/build.log 2024-04-19 09:37:03.138850001 +0000 +++ b2/build.log 2024-04-19 09:38:31.687086892 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Thu Apr 18 21:36:10 -12 2024 -I: pbuilder-time-stamp: 1713519370 +I: Current time: Fri Apr 19 23:37:12 +14 2024 +I: pbuilder-time-stamp: 1713519432 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/unstable-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/4053/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/28051/tmp/hooks/D01_modify_environment starting +debug: Running on ff4a. +I: Changing host+domainname to test build reproducibility +I: Adding a custom variable just for the fun of it... +I: Changing /bin/sh to bash +'/bin/sh' -> '/bin/bash' +lrwxrwxrwx 1 root root 9 Apr 19 09:37 /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/28051/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/28051/tmp/hooks/D02_print_environment starting I: set - BUILDDIR='/build/reproducible-path' - BUILDUSERGECOS='first user,first room,first work-phone,first home-phone,first other' - BUILDUSERNAME='pbuilder1' - BUILD_ARCH='armhf' - DEBIAN_FRONTEND='noninteractive' - DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=3 ' - DISTRIBUTION='unstable' - HOME='/root' - HOST_ARCH='armhf' + BASH=/bin/sh + BASHOPTS=checkwinsize:cmdhist:complete_fullquote:extquote:force_fignore:globasciiranges:globskipdots:hostcomplete:interactive_comments:patsub_replacement:progcomp:promptvars:sourcepath + BASH_ALIASES=() + BASH_ARGC=() + BASH_ARGV=() + BASH_CMDS=() + BASH_LINENO=([0]="12" [1]="0") + BASH_LOADABLES_PATH=/usr/local/lib/bash:/usr/lib/bash:/opt/local/lib/bash:/usr/pkg/lib/bash:/opt/pkg/lib/bash:. + BASH_SOURCE=([0]="/tmp/hooks/D02_print_environment" [1]="/tmp/hooks/D02_print_environment") + BASH_VERSINFO=([0]="5" [1]="2" [2]="21" [3]="1" [4]="release" [5]="arm-unknown-linux-gnueabihf") + BASH_VERSION='5.2.21(1)-release' + BUILDDIR=/build/reproducible-path + BUILDUSERGECOS='second user,second room,second work-phone,second home-phone,second other' + BUILDUSERNAME=pbuilder2 + BUILD_ARCH=armhf + DEBIAN_FRONTEND=noninteractive + DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=4 ' + DIRSTACK=() + DISTRIBUTION=unstable + EUID=0 + FUNCNAME=([0]="Echo" [1]="main") + GROUPS=() + HOME=/root + HOSTNAME=i-capture-the-hostname + HOSTTYPE=arm + HOST_ARCH=armhf IFS=' ' - INVOCATION_ID='bedbcb01e8a4427c8d553e1b59165a43' - 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='4053' - PS1='# ' - PS2='> ' + INVOCATION_ID=02b1c639de0e4f1194f30b78116bf39f + LANG=C + LANGUAGE=it_CH:it + LC_ALL=C + MACHTYPE=arm-unknown-linux-gnueabihf + MAIL=/var/mail/root + OPTERR=1 + OPTIND=1 + OSTYPE=linux-gnueabihf + PATH=/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/i/capture/the/path + PBCURRENTCOMMANDLINEOPERATION=build + PBUILDER_OPERATION=build + PBUILDER_PKGDATADIR=/usr/share/pbuilder + PBUILDER_PKGLIBDIR=/usr/lib/pbuilder + PBUILDER_SYSCONFDIR=/etc + PIPESTATUS=([0]="0") + POSIXLY_CORRECT=y + PPID=28051 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.JszMvDmE/pbuilderrc_zvc1 --distribution unstable --hookdir /etc/pbuilder/first-build-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/unstable-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.JszMvDmE/b1 --logfile b1/build.log libmojolicious-plugin-oauth2-perl_2.02-1.dsc' - SUDO_GID='110' - SUDO_UID='103' - SUDO_USER='jenkins' - TERM='unknown' - TZ='/usr/share/zoneinfo/Etc/GMT+12' - USER='root' - _='/usr/bin/systemd-run' - http_proxy='http://10.0.0.15:3142/' + PWD=/ + SHELL=/bin/bash + SHELLOPTS=braceexpand:errexit:hashall:interactive-comments:posix + SHLVL=3 + SUDO_COMMAND='/usr/bin/timeout -k 24.1h 24h /usr/bin/ionice -c 3 /usr/bin/nice -n 11 /usr/bin/unshare --uts -- /usr/sbin/pbuilder --build --configfile /srv/reproducible-results/rbuild-debian/r-b-build.JszMvDmE/pbuilderrc_ZRFp --distribution unstable --hookdir /etc/pbuilder/rebuild-hooks --debbuildopts -b --basetgz /var/cache/pbuilder/unstable-reproducible-base.tgz --buildresult /srv/reproducible-results/rbuild-debian/r-b-build.JszMvDmE/b2 --logfile b2/build.log libmojolicious-plugin-oauth2-perl_2.02-1.dsc' + SUDO_GID=113 + SUDO_UID=107 + SUDO_USER=jenkins + TERM=unknown + TZ=/usr/share/zoneinfo/Etc/GMT-14 + UID=0 + USER=root + _='I: set' + http_proxy=http://10.0.0.15:3142/ I: uname -a - Linux virt64z 6.1.0-20-arm64 #1 SMP Debian 6.1.85-1 (2024-04-11) aarch64 GNU/Linux + Linux i-capture-the-hostname 6.1.0-20-armmp-lpae #1 SMP Debian 6.1.85-1 (2024-04-11) armv7l GNU/Linux I: ls -l /bin - lrwxrwxrwx 1 root root 7 Apr 17 07:44 /bin -> usr/bin -I: user script /srv/workspace/pbuilder/4053/tmp/hooks/D02_print_environment finished + lrwxrwxrwx 1 root root 7 Apr 18 07:43 /bin -> usr/bin +I: user script /srv/workspace/pbuilder/28051/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -159,7 +191,7 @@ Get: 41 http://deb.debian.org/debian unstable/main armhf libjs-highlight.js all 9.18.5+dfsg1-2 [397 kB] Get: 42 http://deb.debian.org/debian unstable/main armhf libmojolicious-perl all 9.36+dfsg-1 [842 kB] Get: 43 http://deb.debian.org/debian unstable/main armhf libmojo-jwt-perl all 0.09-1 [12.4 kB] -Fetched 20.8 MB in 0s (56.5 MB/s) +Fetched 20.8 MB in 1s (14.4 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 ... 19442 files and directories currently installed.) @@ -346,7 +378,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/28051/tmp/hooks/A99_set_merged_usr starting +Not re-configuring usrmerge for unstable +I: user script /srv/workspace/pbuilder/28051/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 @@ -368,35 +404,35 @@ Writing Makefile for Mojolicious::Plugin::OAuth2 Writing MYMETA.yml and MYMETA.json dh_auto_build - make -j3 + make -j4 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 - make -j3 test TEST_VERBOSE=1 + make -j4 test TEST_VERBOSE=1 make[1]: Entering directory '/build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02' PERL_DL_NONLAZY=1 "/usr/bin/perl" "-MExtUtils::Command::MM" "-MTest::Harness" "-e" "undef *Test::Harness::Switches; test_harness(1, 'blib/lib', 'blib/arch')" t/*.t t/00-basic.t ........ 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(0x2cd8a28)) (Test::Pod::Coverage is required) +ok 3 # skip pod_coverage_ok(Mojolicious::Plugin::OAuth2 HASH(0x2ffba00)) (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(0x2a219d8)) (Test::Pod::Coverage is required) +ok 6 # skip pod_coverage_ok(Mojolicious::Plugin::OAuth2::Mock HASH(0x2ffbda8)) (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-04-19 09:36:49.64420] [5229] [trace] [9Tm5Cy4Y3jJA] GET "/test123" -[2024-04-19 09:36:49.64496] [5229] [trace] [9Tm5Cy4Y3jJA] Routing to a callback -[2024-04-19 09:36:49.64659] [5229] [trace] [9Tm5Cy4Y3jJA] 200 OK (0.002374s, 421.230/s) -[2024-04-19 09:36:49.65287] [5229] [trace] [_qwF_vsHhmBE] GET "/test123" -[2024-04-19 09:36:49.65317] [5229] [trace] [_qwF_vsHhmBE] Routing to a callback -[2024-04-19 09:36:49.65377] [5229] [trace] [_qwF_vsHhmBE] 200 OK (0.000883s, 1132.503/s) +[2024-04-19 09:38:12.87774] [29147] [trace] [XjKGWkUfbqx8] GET "/test123" +[2024-04-19 09:38:12.87870] [29147] [trace] [XjKGWkUfbqx8] Routing to a callback +[2024-04-19 09:38:12.88108] [29147] [trace] [XjKGWkUfbqx8] 200 OK (0.003325s, 300.752/s) +[2024-04-19 09:38:12.89026] [29147] [trace] [HiH1lJh3XuCa] GET "/test123" +[2024-04-19 09:38:12.89072] [29147] [trace] [HiH1lJh3XuCa] Routing to a callback +[2024-04-19 09:38:12.89172] [29147] [trace] [HiH1lJh3XuCa] 200 OK (0.001436s, 696.379/s) t/auth_url.t ........ ok 1 - provider_id is required ok 2 - GET /test123 @@ -414,51 +450,51 @@ ok 14 - state 1..14 ok -[2024-04-19 09:36:50.44882] [5231] [trace] [Pp5L3Du6DJP_] GET "/oauth-delayed" -[2024-04-19 09:36:50.44965] [5231] [trace] [Pp5L3Du6DJP_] Routing to a callback -[2024-04-19 09:36:50.45119] [5231] [trace] [Pp5L3Du6DJP_] 302 Found (0.002358s, 424.088/s) -[2024-04-19 09:36:50.45881] [5231] [trace] [X0GC1djNIPKt] GET "/oauth/authorize" -[2024-04-19 09:36:50.45936] [5231] [trace] [X0GC1djNIPKt] Routing to a callback -[2024-04-19 09:36:50.45991] [5231] [trace] [X0GC1djNIPKt] 302 Found (0.001091s, 916.590/s) -[2024-04-19 09:36:50.46572] [5231] [trace] [Cwlngou4LRXm] GET "/oauth-delayed" -[2024-04-19 09:36:50.46607] [5231] [trace] [Cwlngou4LRXm] Routing to a callback -[2024-04-19 09:36:50.46992] [5231] [trace] [Cwlngou4LRXm] Template "oauthdelayed.html.ep" not found -[2024-04-19 09:36:50.47013] [5231] [trace] [Cwlngou4LRXm] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-04-19 09:36:50.47344] [5231] [trace] [1_RTrjFAV1vo] POST "/oauth/token" -[2024-04-19 09:36:50.47396] [5231] [trace] [1_RTrjFAV1vo] Routing to a callback -[2024-04-19 09:36:50.47466] [5231] [trace] [1_RTrjFAV1vo] 200 OK (0.001206s, 829.187/s) -[2024-04-19 09:36:50.47684] [5231] [trace] [Cwlngou4LRXm] 200 OK (0.011097s, 90.114/s) +[2024-04-19 09:38:14.01868] [29148] [trace] [EgBWpJLPjKjS] GET "/oauth-delayed" +[2024-04-19 09:38:14.01977] [29148] [trace] [EgBWpJLPjKjS] Routing to a callback +[2024-04-19 09:38:14.02189] [29148] [trace] [EgBWpJLPjKjS] 302 Found (0.003198s, 312.695/s) +[2024-04-19 09:38:14.03245] [29148] [trace] [T9zJ03apE2Jd] GET "/oauth/authorize" +[2024-04-19 09:38:14.03323] [29148] [trace] [T9zJ03apE2Jd] Routing to a callback +[2024-04-19 09:38:14.03413] [29148] [trace] [T9zJ03apE2Jd] 302 Found (0.001645s, 607.903/s) +[2024-04-19 09:38:14.04264] [29148] [trace] [Fdg9o3hRca9p] GET "/oauth-delayed" +[2024-04-19 09:38:14.04315] [29148] [trace] [Fdg9o3hRca9p] Routing to a callback +[2024-04-19 09:38:14.04835] [29148] [trace] [Fdg9o3hRca9p] Template "oauthdelayed.html.ep" not found +[2024-04-19 09:38:14.04857] [29148] [trace] [Fdg9o3hRca9p] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-19 09:38:14.05282] [29148] [trace] [r5lLdKe4dHoT] POST "/oauth/token" +[2024-04-19 09:38:14.05350] [29148] [trace] [r5lLdKe4dHoT] Routing to a callback +[2024-04-19 09:38:14.05456] [29148] [trace] [r5lLdKe4dHoT] 200 OK (0.00171s, 584.795/s) +[2024-04-19 09:38:14.05761] [29148] [trace] [Fdg9o3hRca9p] 200 OK (0.014932s, 66.970/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%3A40105%2Foauth-delayed&scope=a%2Cb%2Cc -ok 4 - GET http://127.0.0.1:40105/oauth/authorize?client_id=fake_key&redirect_uri=http%3A%2F%2F127.0.0.1%3A40105%2Foauth-delayed&scope=a%2Cb%2Cc +# /oauth/authorize?client_id=fake_key&redirect_uri=http%3A%2F%2F127.0.0.1%3A43779%2Foauth-delayed&scope=a%2Cb%2Cc +ok 4 - GET http://127.0.0.1:43779/oauth/authorize?client_id=fake_key&redirect_uri=http%3A%2F%2F127.0.0.1%3A43779%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:40105/oauth-delayed?code=fake_code -ok 8 - GET http://127.0.0.1:40105/oauth-delayed?code=fake_code +# http://127.0.0.1:43779/oauth-delayed?code=fake_code +ok 8 - GET http://127.0.0.1:43779/oauth-delayed?code=fake_code ok 9 - 200 OK ok 10 - exact match for content 1..10 ok -[2024-04-19 09:36:51.25015] [5239] [trace] [AVEl0B63CWrM] GET "/oauth-error" -[2024-04-19 09:36:51.25091] [5239] [trace] [AVEl0B63CWrM] Routing to a callback -[2024-04-19 09:36:51.25222] [5239] [trace] [AVEl0B63CWrM] 302 Found (0.002054s, 486.855/s) -[2024-04-19 09:36:51.25827] [5239] [trace] [BtzLPRv_Dl4B] GET "/oauth-error" -[2024-04-19 09:36:51.25861] [5239] [trace] [BtzLPRv_Dl4B] Routing to a callback -[2024-04-19 09:36:51.26218] [5239] [trace] [BtzLPRv_Dl4B] Template "oautherror.html.ep" not found -[2024-04-19 09:36:51.26235] [5239] [trace] [BtzLPRv_Dl4B] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-04-19 09:36:51.26532] [5239] [trace] [f4x_v68gfQYb] POST "/oauth/token" -[2024-04-19 09:36:51.26579] [5239] [trace] [f4x_v68gfQYb] Routing to a callback -[2024-04-19 09:36:51.26653] [5239] [trace] [f4x_v68gfQYb] 200 OK (0.001185s, 843.882/s) -[2024-04-19 09:36:51.26852] [5239] [trace] [BtzLPRv_Dl4B] 200 OK (0.010227s, 97.780/s) -[2024-04-19 09:36:51.27268] [5239] [trace] [ola2WE40iktp] GET "/oauth-error" -[2024-04-19 09:36:51.27299] [5239] [trace] [ola2WE40iktp] Routing to a callback -[2024-04-19 09:36:51.27368] [5239] [trace] [ola2WE40iktp] Template "oautherror.html.ep" not found -[2024-04-19 09:36:51.27382] [5239] [trace] [ola2WE40iktp] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-04-19 09:36:51.27423] [5239] [trace] [ola2WE40iktp] 500 Internal Server Error (0.001534s, 651.890/s) +[2024-04-19 09:38:15.18000] [29149] [trace] [eJlaDKwSw5js] GET "/oauth-error" +[2024-04-19 09:38:15.18104] [29149] [trace] [eJlaDKwSw5js] Routing to a callback +[2024-04-19 09:38:15.18309] [29149] [trace] [eJlaDKwSw5js] 302 Found (0.003075s, 325.203/s) +[2024-04-19 09:38:15.19182] [29149] [trace] [jJJbN-MEeyG_] GET "/oauth-error" +[2024-04-19 09:38:15.19233] [29149] [trace] [jJJbN-MEeyG_] Routing to a callback +[2024-04-19 09:38:15.19751] [29149] [trace] [jJJbN-MEeyG_] Template "oautherror.html.ep" not found +[2024-04-19 09:38:15.19772] [29149] [trace] [jJJbN-MEeyG_] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-19 09:38:15.20191] [29149] [trace] [YuPFjXbVQ0ui] POST "/oauth/token" +[2024-04-19 09:38:15.20261] [29149] [trace] [YuPFjXbVQ0ui] Routing to a callback +[2024-04-19 09:38:15.20376] [29149] [trace] [YuPFjXbVQ0ui] 200 OK (0.001835s, 544.959/s) +[2024-04-19 09:38:15.20681] [29149] [trace] [jJJbN-MEeyG_] 200 OK (0.014961s, 66.840/s) +[2024-04-19 09:38:15.21327] [29149] [trace] [Q8LHbFDXYE14] GET "/oauth-error" +[2024-04-19 09:38:15.21377] [29149] [trace] [Q8LHbFDXYE14] Routing to a callback +[2024-04-19 09:38:15.21493] [29149] [trace] [Q8LHbFDXYE14] Template "oautherror.html.ep" not found +[2024-04-19 09:38:15.21511] [29149] [trace] [Q8LHbFDXYE14] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-19 09:38:15.21581] [29149] [trace] [Q8LHbFDXYE14] 500 Internal Server Error (0.002508s, 398.724/s) t/error.t ........... ok 1 - GET /oauth-error ok 2 - 302 Found @@ -469,40 +505,40 @@ 1..6 ok t/live.t ............ skipped: OAUTH_FB_KEY and OAUTH_FB_SECRET must be set for oauth tests -[2024-04-19 09:36:52.76746] [5252] [trace] [e5ryWd30baVG] GET "/profile" -[2024-04-19 09:36:52.76864] [5252] [trace] [e5ryWd30baVG] Routing to a callback -[2024-04-19 09:36:52.77013] [5252] [trace] [e5ryWd30baVG] 302 Found (0.002651s, 377.216/s) -[2024-04-19 09:36:52.77770] [5252] [trace] [aJeHIIWYqv35] GET "/mocked/oauth/authorize" -[2024-04-19 09:36:52.77824] [5252] [trace] [aJeHIIWYqv35] Routing to a callback -[2024-04-19 09:36:52.77923] [5252] [trace] [aJeHIIWYqv35] 200 OK (0.001509s, 662.691/s) -[2024-04-19 09:36:52.78609] [5252] [trace] [sKYzMX21HfWY] GET "/profile" -[2024-04-19 09:36:52.78643] [5252] [trace] [sKYzMX21HfWY] Routing to a callback -[2024-04-19 09:36:52.79202] [5252] [trace] [sKYzMX21HfWY] Template "profile.html.ep" not found -[2024-04-19 09:36:52.79220] [5252] [trace] [sKYzMX21HfWY] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-04-19 09:36:52.79509] [5252] [trace] [8Z758m9SuxdG] POST "/mocked/oauth/token" -[2024-04-19 09:36:52.79560] [5252] [trace] [8Z758m9SuxdG] Routing to a callback -[2024-04-19 09:36:52.79643] [5252] [trace] [8Z758m9SuxdG] 200 OK (0.001314s, 761.035/s) -[2024-04-19 09:36:52.79845] [5252] [trace] [sKYzMX21HfWY] 200 OK (0.012335s, 81.070/s) -[2024-04-19 09:36:52.80369] [5252] [trace] [05CtbT7K8ObM] GET "/profile" -[2024-04-19 09:36:52.80404] [5252] [trace] [05CtbT7K8ObM] Routing to a callback -[2024-04-19 09:36:52.80493] [5252] [trace] [05CtbT7K8ObM] Template "profile.html.ep" not found -[2024-04-19 09:36:52.80509] [5252] [trace] [05CtbT7K8ObM] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-04-19 09:36:52.80554] [5252] [trace] [05CtbT7K8ObM] 500 Internal Server Error (0.001827s, 547.345/s) -[2024-04-19 09:36:52.81038] [5252] [trace] [Do6LPk0bY4iu] GET "/no-redirect" -[2024-04-19 09:36:52.81092] [5252] [trace] [Do6LPk0bY4iu] Routing to a callback -[2024-04-19 09:36:52.81170] [5252] [trace] [Do6LPk0bY4iu] Template "noredirect.html.ep" not found -[2024-04-19 09:36:52.81185] [5252] [trace] [Do6LPk0bY4iu] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-04-19 09:36:52.81222] [5252] [trace] [Do6LPk0bY4iu] 200 OK (0.001826s, 547.645/s) +[2024-04-19 09:38:17.42206] [29151] [trace] [aHYec3DNml0X] GET "/profile" +[2024-04-19 09:38:17.42350] [29151] [trace] [aHYec3DNml0X] Routing to a callback +[2024-04-19 09:38:17.42547] [29151] [trace] [aHYec3DNml0X] 302 Found (0.003394s, 294.638/s) +[2024-04-19 09:38:17.43473] [29151] [trace] [nHsk3PDqITH9] GET "/mocked/oauth/authorize" +[2024-04-19 09:38:17.43555] [29151] [trace] [nHsk3PDqITH9] Routing to a callback +[2024-04-19 09:38:17.43701] [29151] [trace] [nHsk3PDqITH9] 200 OK (0.002241s, 446.229/s) +[2024-04-19 09:38:17.44710] [29151] [trace] [oRN26KQfYRig] GET "/profile" +[2024-04-19 09:38:17.44759] [29151] [trace] [oRN26KQfYRig] Routing to a callback +[2024-04-19 09:38:17.45548] [29151] [trace] [oRN26KQfYRig] Template "profile.html.ep" not found +[2024-04-19 09:38:17.45570] [29151] [trace] [oRN26KQfYRig] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-19 09:38:17.45994] [29151] [trace] [fZYb0zEou3Ra] POST "/mocked/oauth/token" +[2024-04-19 09:38:17.46064] [29151] [trace] [fZYb0zEou3Ra] Routing to a callback +[2024-04-19 09:38:17.46179] [29151] [trace] [fZYb0zEou3Ra] 200 OK (0.00182s, 549.451/s) +[2024-04-19 09:38:17.46492] [29151] [trace] [oRN26KQfYRig] 200 OK (0.017799s, 56.183/s) +[2024-04-19 09:38:17.47267] [29151] [trace] [QhQjriSGviDj] GET "/profile" +[2024-04-19 09:38:17.47317] [29151] [trace] [QhQjriSGviDj] Routing to a callback +[2024-04-19 09:38:17.47428] [29151] [trace] [QhQjriSGviDj] Template "profile.html.ep" not found +[2024-04-19 09:38:17.47450] [29151] [trace] [QhQjriSGviDj] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-19 09:38:17.47520] [29151] [trace] [QhQjriSGviDj] 500 Internal Server Error (0.00251s, 398.406/s) +[2024-04-19 09:38:17.48231] [29151] [trace] [EjViaONEc_-c] GET "/no-redirect" +[2024-04-19 09:38:17.48310] [29151] [trace] [EjViaONEc_-c] Routing to a callback +[2024-04-19 09:38:17.48423] [29151] [trace] [EjViaONEc_-c] Template "noredirect.html.ep" not found +[2024-04-19 09:38:17.48442] [29151] [trace] [EjViaONEc_-c] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-19 09:38:17.48501] [29151] [trace] [EjViaONEc_-c] 200 OK (0.00267s, 374.532/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:37525/mocked/oauth/authorize?client_id=42&redirect_uri=http%3A%2F%2F127.0.0.1%3A37525%2Fprofile +ok 4 - GET http://127.0.0.1:37171/mocked/oauth/authorize?client_id=42&redirect_uri=http%3A%2F%2F127.0.0.1%3A37171%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:37525/profile?code=fake_code +ok 9 - GET http://127.0.0.1:37171/profile?code=fake_code ok 10 - 200 OK ok 11 - exact match for content ok 12 - GET /profile?error=access_denied @@ -513,93 +549,93 @@ ok 17 - content is similar 1..17 ok -[2024-04-19 09:36:53.59571] [5253] [debug] Fetching OpenID configuration from /mocked/oauth2/.well-known/configuration -[2024-04-19 09:36:53.60792] [5253] [trace] [-LG5Zz41y4qU] GET "/mocked/oauth2/.well-known/configuration" -[2024-04-19 09:36:53.60863] [5253] [trace] [-LG5Zz41y4qU] Routing to a callback -[2024-04-19 09:36:53.61151] [5253] [trace] [-LG5Zz41y4qU] Rendering template "oauth2/mock/configuration.json.ep" from DATA section -[2024-04-19 09:36:53.61635] [5253] [trace] [-LG5Zz41y4qU] 200 OK (0.008324s, 120.135/s) -[2024-04-19 09:36:53.62142] [5253] [trace] [Iku-fmpOoyz3] GET "/mocked/oauth2/keys" -[2024-04-19 09:36:53.62215] [5253] [trace] [Iku-fmpOoyz3] Routing to a callback -[2024-04-19 09:36:53.92586] [5253] [trace] [Iku-fmpOoyz3] Rendering template "oauth2/mock/keys.json.ep" from DATA section -[2024-04-19 09:36:53.92957] [5253] [trace] [Iku-fmpOoyz3] 200 OK (0.308109s, 3.246/s) -[2024-04-19 09:36:53.94477] [5253] [trace] [bZxCZ4JNHvWH] GET "/connect" -[2024-04-19 09:36:53.94547] [5253] [trace] [bZxCZ4JNHvWH] Routing to a callback -[2024-04-19 09:36:53.94624] [5253] [trace] [bZxCZ4JNHvWH] 302 Found (0.001459s, 685.401/s) -[2024-04-19 09:36:53.95445] [5253] [trace] [gJgoE140kjv-] GET "/mocked/oauth2/authorize" -[2024-04-19 09:36:53.95513] [5253] [trace] [gJgoE140kjv-] Routing to a callback -[2024-04-19 09:36:53.95579] [5253] [trace] [gJgoE140kjv-] Rendering template "oauth2/mock/form_post.html.ep" from DATA section -[2024-04-19 09:36:53.95786] [5253] [trace] [gJgoE140kjv-] 200 OK (0.003385s, 295.421/s) -[2024-04-19 09:36:53.96564] [5253] [trace] [iW8IKCsAEXs7] POST "/connect" -[2024-04-19 09:36:53.96624] [5253] [trace] [iW8IKCsAEXs7] Routing to a callback -[2024-04-19 09:36:53.96913] [5253] [trace] [tH8-aedPv8f4] POST "/mocked/oauth2/token" -[2024-04-19 09:36:53.96955] [5253] [trace] [tH8-aedPv8f4] Routing to a callback -[2024-04-19 09:36:53.97958] [5253] [trace] [tH8-aedPv8f4] Rendering template "oauth2/mock/token.json.ep" from DATA section -[2024-04-19 09:36:53.98248] [5253] [trace] [tH8-aedPv8f4] 200 OK (0.013315s, 75.103/s) -[2024-04-19 09:36:53.98547] [5253] [trace] Your secret passphrase needs to be changed (see FAQ for more) -[2024-04-19 09:36:53.98757] [5253] [trace] [iW8IKCsAEXs7] 200 OK (0.021899s, 45.664/s) -[2024-04-19 09:36:54.00125] [5253] [trace] [WmGGxZnIuWuT] GET "/refresh" -[2024-04-19 09:36:54.00200] [5253] [trace] [WmGGxZnIuWuT] Routing to a callback -[2024-04-19 09:36:54.00509] [5253] [trace] [bPMAwTS5YYqh] POST "/mocked/oauth2/token" -[2024-04-19 09:36:54.00540] [5253] [trace] [bPMAwTS5YYqh] Routing to a callback -[2024-04-19 09:36:54.01397] [5253] [trace] [bPMAwTS5YYqh] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2024-04-19 09:36:54.01557] [5253] [trace] [bPMAwTS5YYqh] 200 OK (0.01045s, 95.694/s) -[2024-04-19 09:36:54.01933] [5253] [trace] [WmGGxZnIuWuT] 200 OK (0.018062s, 55.365/s) -[2024-04-19 09:36:54.02712] [5253] [trace] [VWipfQdqbXfN] GET "/refresh" -[2024-04-19 09:36:54.02749] [5253] [trace] [VWipfQdqbXfN] Routing to a callback -[2024-04-19 09:36:54.03064] [5253] [trace] [22CnBiJ1xpgU] POST "/mocked/oauth2/token" -[2024-04-19 09:36:54.03097] [5253] [trace] [22CnBiJ1xpgU] Routing to a callback -[2024-04-19 09:36:54.03991] [5253] [trace] [22CnBiJ1xpgU] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2024-04-19 09:36:54.04147] [5253] [trace] [22CnBiJ1xpgU] 200 OK (0.010803s, 92.567/s) -[2024-04-19 09:36:54.04521] [5253] [trace] [VWipfQdqbXfN] 200 OK (0.018064s, 55.359/s) -[2024-04-19 09:36:54.05340] [5253] [trace] [XDYVWmfGggJw] GET "/refresh" -[2024-04-19 09:36:54.05377] [5253] [trace] [XDYVWmfGggJw] Routing to a callback -[2024-04-19 09:36:54.05506] [5253] [trace] [XDYVWmfGggJw] 500 Internal Server Error (0.001645s, 607.903/s) -[2024-04-19 09:36:54.06402] [5253] [trace] [RCbRFNDm-c45] GET "/connect" -[2024-04-19 09:36:54.06448] [5253] [trace] [RCbRFNDm-c45] Routing to a callback -[2024-04-19 09:36:54.06518] [5253] [trace] [RCbRFNDm-c45] 302 Found (0.001144s, 874.126/s) -[2024-04-19 09:36:54.07367] [5253] [trace] [n-kbtRloj6pr] GET "/mocked/oauth2/authorize" -[2024-04-19 09:36:54.07413] [5253] [trace] [n-kbtRloj6pr] Routing to a callback -[2024-04-19 09:36:54.07475] [5253] [trace] [n-kbtRloj6pr] 302 Found (0.001056s, 946.970/s) -[2024-04-19 09:36:54.08189] [5253] [trace] [ZbdJXHC_ZiLe] GET "/connect" -[2024-04-19 09:36:54.08224] [5253] [trace] [ZbdJXHC_ZiLe] Routing to a callback -[2024-04-19 09:36:54.08509] [5253] [trace] [k4x4XFfjLIdo] POST "/mocked/oauth2/token" -[2024-04-19 09:36:54.08539] [5253] [trace] [k4x4XFfjLIdo] Routing to a callback -[2024-04-19 09:36:54.09412] [5253] [trace] [k4x4XFfjLIdo] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2024-04-19 09:36:54.09555] [5253] [trace] [k4x4XFfjLIdo] 200 OK (0.010434s, 95.841/s) -[2024-04-19 09:36:54.09977] [5253] [trace] [ZbdJXHC_ZiLe] 200 OK (0.017853s, 56.013/s) -[2024-04-19 09:36:54.11386] [5253] [trace] [K1kMEQ2tdyC-] GET "/end_session" -[2024-04-19 09:36:54.11448] [5253] [trace] [K1kMEQ2tdyC-] Routing to a callback -[2024-04-19 09:36:54.11527] [5253] [trace] [K1kMEQ2tdyC-] 302 Found (0.001397s, 715.820/s) -[2024-04-19 09:36:54.12391] [5253] [trace] [935JL05Woi_u] GET "/mocked/oauth2/logout" -[2024-04-19 09:36:54.12457] [5253] [trace] [935JL05Woi_u] Routing to a callback -[2024-04-19 09:36:54.12522] [5253] [trace] [935JL05Woi_u] 302 Found (0.001279s, 781.861/s) -[2024-04-19 09:36:54.13331] [5253] [trace] [sMD0HUkfeUFK] GET "/end_session" -[2024-04-19 09:36:54.13370] [5253] [trace] [sMD0HUkfeUFK] Routing to a callback -[2024-04-19 09:36:54.13497] [5253] [trace] [sMD0HUkfeUFK] 302 Found (0.001642s, 609.013/s) -[2024-04-19 09:36:54.14271] [5253] [trace] [iXWKcGqal0Zf] GET "/end_session" -[2024-04-19 09:36:54.14303] [5253] [trace] [iXWKcGqal0Zf] Routing to a callback -[2024-04-19 09:36:54.14335] [5253] [trace] [iXWKcGqal0Zf] 302 Found (0.000633s, 1579.779/s) -[2024-04-19 09:36:54.15074] [5253] [trace] [bqxn843mTqkV] GET "/protect/next" -[2024-04-19 09:36:54.15149] [5253] [trace] [bqxn843mTqkV] Routing to a callback -[2024-04-19 09:36:54.15178] [5253] [trace] [bqxn843mTqkV] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2024-04-19 09:36:54.25336] [5253] [trace] [bqxn843mTqkV] 302 Found (0.102576s, 9.749/s) -[2024-04-19 09:36:54.25730] [5253] [trace] [42u4DdANceor] GET "/connect" -[2024-04-19 09:36:54.25766] [5253] [trace] [42u4DdANceor] Routing to a callback -[2024-04-19 09:36:54.25851] [5253] [trace] [42u4DdANceor] 302 Found (0.001188s, 841.751/s) -[2024-04-19 09:36:54.26267] [5253] [trace] [i5b9b3qvxjcO] GET "/mocked/oauth2/authorize" -[2024-04-19 09:36:54.26313] [5253] [trace] [i5b9b3qvxjcO] Routing to a callback -[2024-04-19 09:36:54.26379] [5253] [trace] [i5b9b3qvxjcO] 302 Found (0.001107s, 903.342/s) -[2024-04-19 09:36:54.26704] [5253] [trace] [ruSC33FP-uE5] GET "/connect" -[2024-04-19 09:36:54.26743] [5253] [trace] [ruSC33FP-uE5] Routing to a callback -[2024-04-19 09:36:54.27031] [5253] [trace] [UuPqBYviVIX-] POST "/mocked/oauth2/token" -[2024-04-19 09:36:54.27061] [5253] [trace] [UuPqBYviVIX-] Routing to a callback -[2024-04-19 09:36:54.27934] [5253] [trace] [UuPqBYviVIX-] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2024-04-19 09:36:54.28090] [5253] [trace] [UuPqBYviVIX-] 200 OK (0.010559s, 94.706/s) -[2024-04-19 09:36:54.28468] [5253] [trace] [ruSC33FP-uE5] 302 Found (0.017613s, 56.776/s) -[2024-04-19 09:36:54.29046] [5253] [trace] [f3ZECgJgJy2m] GET "/protect/next" -[2024-04-19 09:36:54.29078] [5253] [trace] [f3ZECgJgJy2m] Routing to a callback -[2024-04-19 09:36:54.29131] [5253] [trace] [f3ZECgJgJy2m] Routing to a callback -[2024-04-19 09:36:54.29163] [5253] [trace] [f3ZECgJgJy2m] 200 OK (0.001153s, 867.303/s) +[2024-04-19 09:38:18.60374] [29152] [debug] Fetching OpenID configuration from /mocked/oauth2/.well-known/configuration +[2024-04-19 09:38:18.61872] [29152] [trace] [7kuVYT7U8dAC] GET "/mocked/oauth2/.well-known/configuration" +[2024-04-19 09:38:18.62005] [29152] [trace] [7kuVYT7U8dAC] Routing to a callback +[2024-04-19 09:38:18.62422] [29152] [trace] [7kuVYT7U8dAC] Rendering template "oauth2/mock/configuration.json.ep" from DATA section +[2024-04-19 09:38:18.63119] [29152] [trace] [7kuVYT7U8dAC] 200 OK (0.012431s, 80.444/s) +[2024-04-19 09:38:18.63853] [29152] [trace] [4WWSrW0TfIFE] GET "/mocked/oauth2/keys" +[2024-04-19 09:38:18.63925] [29152] [trace] [4WWSrW0TfIFE] Routing to a callback +[2024-04-19 09:38:19.10665] [29152] [trace] [4WWSrW0TfIFE] Rendering template "oauth2/mock/keys.json.ep" from DATA section +[2024-04-19 09:38:19.11148] [29152] [trace] [4WWSrW0TfIFE] 200 OK (0.472917s, 2.115/s) +[2024-04-19 09:38:19.13062] [29152] [trace] [_ZIeayyquPL2] GET "/connect" +[2024-04-19 09:38:19.13160] [29152] [trace] [_ZIeayyquPL2] Routing to a callback +[2024-04-19 09:38:19.13274] [29152] [trace] [_ZIeayyquPL2] 302 Found (0.002083s, 480.077/s) +[2024-04-19 09:38:19.14462] [29152] [trace] [73c3B8IPpEnb] GET "/mocked/oauth2/authorize" +[2024-04-19 09:38:19.14550] [29152] [trace] [73c3B8IPpEnb] Routing to a callback +[2024-04-19 09:38:19.14652] [29152] [trace] [73c3B8IPpEnb] Rendering template "oauth2/mock/form_post.html.ep" from DATA section +[2024-04-19 09:38:19.14938] [29152] [trace] [73c3B8IPpEnb] 200 OK (0.00472s, 211.864/s) +[2024-04-19 09:38:19.16087] [29152] [trace] [K6O_npFQb4q1] POST "/connect" +[2024-04-19 09:38:19.16172] [29152] [trace] [K6O_npFQb4q1] Routing to a callback +[2024-04-19 09:38:19.16624] [29152] [trace] [dYGjHCPtAGKk] POST "/mocked/oauth2/token" +[2024-04-19 09:38:19.16695] [29152] [trace] [dYGjHCPtAGKk] Routing to a callback +[2024-04-19 09:38:19.18071] [29152] [trace] [dYGjHCPtAGKk] Rendering template "oauth2/mock/token.json.ep" from DATA section +[2024-04-19 09:38:19.18457] [29152] [trace] [dYGjHCPtAGKk] 200 OK (0.018289s, 54.678/s) +[2024-04-19 09:38:19.18859] [29152] [trace] Your secret passphrase needs to be changed (see FAQ for more) +[2024-04-19 09:38:19.19129] [29152] [trace] [K6O_npFQb4q1] 200 OK (0.030389s, 32.907/s) +[2024-04-19 09:38:19.21006] [29152] [trace] [loCq6Bp7W6rY] GET "/refresh" +[2024-04-19 09:38:19.21111] [29152] [trace] [loCq6Bp7W6rY] Routing to a callback +[2024-04-19 09:38:19.21557] [29152] [trace] [PCGnUkwOdAe5] POST "/mocked/oauth2/token" +[2024-04-19 09:38:19.21602] [29152] [trace] [PCGnUkwOdAe5] Routing to a callback +[2024-04-19 09:38:19.22798] [29152] [trace] [PCGnUkwOdAe5] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2024-04-19 09:38:19.23005] [29152] [trace] [PCGnUkwOdAe5] 200 OK (0.014441s, 69.247/s) +[2024-04-19 09:38:19.23562] [29152] [trace] [loCq6Bp7W6rY] 200 OK (0.025522s, 39.182/s) +[2024-04-19 09:38:19.24731] [29152] [trace] [JB_kIZOSDx-E] GET "/refresh" +[2024-04-19 09:38:19.24776] [29152] [trace] [JB_kIZOSDx-E] Routing to a callback +[2024-04-19 09:38:19.25219] [29152] [trace] [_ebcK79dNPhk] POST "/mocked/oauth2/token" +[2024-04-19 09:38:19.25264] [29152] [trace] [_ebcK79dNPhk] Routing to a callback +[2024-04-19 09:38:19.26466] [29152] [trace] [_ebcK79dNPhk] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2024-04-19 09:38:19.26660] [29152] [trace] [_ebcK79dNPhk] 200 OK (0.01437s, 69.589/s) +[2024-04-19 09:38:19.27215] [29152] [trace] [JB_kIZOSDx-E] 200 OK (0.024798s, 40.326/s) +[2024-04-19 09:38:19.28432] [29152] [trace] [KjP6F-YBQFcI] GET "/refresh" +[2024-04-19 09:38:19.28485] [29152] [trace] [KjP6F-YBQFcI] Routing to a callback +[2024-04-19 09:38:19.28686] [29152] [trace] [KjP6F-YBQFcI] 500 Internal Server Error (0.002506s, 399.042/s) +[2024-04-19 09:38:19.29996] [29152] [trace] [-QOBYCCT9NLa] GET "/connect" +[2024-04-19 09:38:19.30042] [29152] [trace] [-QOBYCCT9NLa] Routing to a callback +[2024-04-19 09:38:19.30147] [29152] [trace] [-QOBYCCT9NLa] 302 Found (0.001476s, 677.507/s) +[2024-04-19 09:38:19.31341] [29152] [trace] [gvnga_1IEAhP] GET "/mocked/oauth2/authorize" +[2024-04-19 09:38:19.31410] [29152] [trace] [gvnga_1IEAhP] Routing to a callback +[2024-04-19 09:38:19.31512] [29152] [trace] [gvnga_1IEAhP] 302 Found (0.001683s, 594.177/s) +[2024-04-19 09:38:19.32602] [29152] [trace] [7FrSV2_vAmj3] GET "/connect" +[2024-04-19 09:38:19.32657] [29152] [trace] [7FrSV2_vAmj3] Routing to a callback +[2024-04-19 09:38:19.33107] [29152] [trace] [cIePG2m6k1Tm] POST "/mocked/oauth2/token" +[2024-04-19 09:38:19.33153] [29152] [trace] [cIePG2m6k1Tm] Routing to a callback +[2024-04-19 09:38:19.34362] [29152] [trace] [cIePG2m6k1Tm] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2024-04-19 09:38:19.34555] [29152] [trace] [cIePG2m6k1Tm] 200 OK (0.014444s, 69.233/s) +[2024-04-19 09:38:19.35161] [29152] [trace] [7FrSV2_vAmj3] 200 OK (0.025558s, 39.127/s) +[2024-04-19 09:38:19.37169] [29152] [trace] [nmzswEue_cE6] GET "/end_session" +[2024-04-19 09:38:19.37259] [29152] [trace] [nmzswEue_cE6] Routing to a callback +[2024-04-19 09:38:19.37383] [29152] [trace] [nmzswEue_cE6] 302 Found (0.002109s, 474.158/s) +[2024-04-19 09:38:19.38640] [29152] [trace] [lyHow1dige9_] GET "/mocked/oauth2/logout" +[2024-04-19 09:38:19.38732] [29152] [trace] [lyHow1dige9_] Routing to a callback +[2024-04-19 09:38:19.38824] [29152] [trace] [lyHow1dige9_] 302 Found (0.001815s, 550.964/s) +[2024-04-19 09:38:19.39981] [29152] [trace] [rmGyfRC_kCFZ] GET "/end_session" +[2024-04-19 09:38:19.40037] [29152] [trace] [rmGyfRC_kCFZ] Routing to a callback +[2024-04-19 09:38:19.40228] [29152] [trace] [rmGyfRC_kCFZ] 302 Found (0.002445s, 408.998/s) +[2024-04-19 09:38:19.41379] [29152] [trace] [rk3rg6i-cUeB] GET "/end_session" +[2024-04-19 09:38:19.41425] [29152] [trace] [rk3rg6i-cUeB] Routing to a callback +[2024-04-19 09:38:19.41483] [29152] [trace] [rk3rg6i-cUeB] 302 Found (0.001003s, 997.009/s) +[2024-04-19 09:38:19.42589] [29152] [trace] [-YsPjHRW7Q2-] GET "/protect/next" +[2024-04-19 09:38:19.42703] [29152] [trace] [-YsPjHRW7Q2-] Routing to a callback +[2024-04-19 09:38:19.42746] [29152] [trace] [-YsPjHRW7Q2-] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-19 09:38:19.52940] [29152] [trace] [-YsPjHRW7Q2-] 302 Found (0.103472s, 9.664/s) +[2024-04-19 09:38:19.53461] [29152] [trace] [joppAjwQ1NxY] GET "/connect" +[2024-04-19 09:38:19.53513] [29152] [trace] [joppAjwQ1NxY] Routing to a callback +[2024-04-19 09:38:19.53624] [29152] [trace] [joppAjwQ1NxY] 302 Found (0.0016s, 625.000/s) +[2024-04-19 09:38:19.54241] [29152] [trace] [RI4791FVkd-X] GET "/mocked/oauth2/authorize" +[2024-04-19 09:38:19.54315] [29152] [trace] [RI4791FVkd-X] Routing to a callback +[2024-04-19 09:38:19.54424] [29152] [trace] [RI4791FVkd-X] 302 Found (0.001799s, 555.864/s) +[2024-04-19 09:38:19.54931] [29152] [trace] [cu3Ybs8ToOk7] GET "/connect" +[2024-04-19 09:38:19.54990] [29152] [trace] [cu3Ybs8ToOk7] Routing to a callback +[2024-04-19 09:38:19.55451] [29152] [trace] [FdoPiG88mAKI] POST "/mocked/oauth2/token" +[2024-04-19 09:38:19.55496] [29152] [trace] [FdoPiG88mAKI] Routing to a callback +[2024-04-19 09:38:19.56712] [29152] [trace] [FdoPiG88mAKI] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2024-04-19 09:38:19.56912] [29152] [trace] [FdoPiG88mAKI] 200 OK (0.014573s, 68.620/s) +[2024-04-19 09:38:19.57480] [29152] [trace] [cu3Ybs8ToOk7] 302 Found (0.025456s, 39.283/s) +[2024-04-19 09:38:19.58372] [29152] [trace] [9zAVhDwmvvJc] GET "/protect/next" +[2024-04-19 09:38:19.58418] [29152] [trace] [9zAVhDwmvvJc] Routing to a callback +[2024-04-19 09:38:19.58500] [29152] [trace] [9zAVhDwmvvJc] Routing to a callback +[2024-04-19 09:38:19.58550] [29152] [trace] [9zAVhDwmvvJc] 200 OK (0.001744s, 573.394/s) t/openid-connect.t .. # Subtest: warmup of provider data ok 1 - scope @@ -616,10 +652,10 @@ ok 2 - 302 Found ok 3 - scope set ok 4 - response mode set - ok 5 - GET http://127.0.0.1:35407/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A44493%2Fconnect&scope=openid&response_mode=form_post&response_type=code&state=test + ok 5 - GET http://127.0.0.1:35443/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A44149%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:44493/connect + ok 8 - POST http://127.0.0.1:44149/connect ok 9 - 200 OK ok 10 - exact match for JSON Pointer "/aud" ok 11 - exact match for JSON Pointer "/email" @@ -649,12 +685,12 @@ ok 3 - scope set ok 4 - response mode set ok 5 - state propagates - ok 6 - GET http://127.0.0.1:35407/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A44493%2Fconnect&scope=openid+email+profile&response_mode=query&response_type=code&state=test + ok 6 - GET http://127.0.0.1:35443/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A44149%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:44493/connect?code=authorize-code&state=test + ok 11 - GET http://127.0.0.1:44149/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" @@ -668,22 +704,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:44493/end_session + ok 2 - GET http://127.0.0.1:44149/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:35407/mocked/oauth2/logout?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTcxMzUyMzAxNCwiaWF0IjoxNzEzNTE5NDE0LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6MzU0MDdcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.J1GicAIBoQfTvT9qtrs_CZ6_CIAp8NGTD3M6QBVEdwQmWdTUSrsPQOHgMgBGSaLqAJCW87Rjbr06SUKQR8cKKvXr35sQVAQYMPU2tYpzpxlPedOqx9xjkpbmUZx7yU1mxsh3pQhSItcxsQKjDNZ_sXksGrNP7AXDFxaHMGWgX57F8Aw5orAI--3kW4COe3tKJ4kn0CItHE2LapEP-AaN5wcva2rjv0LCri3Yo9Wd6AZJINHhulEPpxfWEp3jsQC01nQ_wehHYpz9x9wvlcU4tPHrLXAKtj4YeNA_rXNNTaHLuRcn9qLf82m-Fcr_8FV8I0QeaNG9VNuOG0yU0Ar_qg&post_logout_redirect_uri=http%3A%2F%2F127.0.0.1%3A44493%2Fend_session&state=1713519414 + ok 8 - GET http://127.0.0.1:35443/mocked/oauth2/logout?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTcxMzUyMzA5OSwiaWF0IjoxNzEzNTE5NDk5LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6MzU0NDNcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.TMpV9WqMZgeL62DI3Kr2OITbpnqbLplPoH8avbWY7Fwtg4dahWSKXGzlMZ8bsrog6_arnrpu9O8vs4b5r_mJ3PPbggmJ48eWjipY_b2XsqvkA1Lz3lO4bJwt6Upr5h11IKZdzJHtmL3Y9z1jqdlUrJRbPr7U3IlkdWU_PEXqAW9fhH-3C3T-Vyz_ZMm6_xLOIsKXJTLogn5cTwUtZ_k4Fn9so6A76J3oFcpD11gfH9Oyt3VfikuDeNUn5mihGkOvJDHxKoSiHI10OGUpwz07bPVDkIaSbrXeHJDndJalXIjZb4hMYLvDC1Vn_qdCTWm_7lZG5tElKdz-TzDL88bC8g&post_logout_redirect_uri=http%3A%2F%2F127.0.0.1%3A44149%2Fend_session&state=1713519499 ok 9 - 302 Found ok 10 - correct ok 11 - correct id token ok 12 - state set - ok 13 - GET http://127.0.0.1:44493/end_session?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTcxMzUyMzAxNCwiaWF0IjoxNzEzNTE5NDE0LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6MzU0MDdcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.J1GicAIBoQfTvT9qtrs_CZ6_CIAp8NGTD3M6QBVEdwQmWdTUSrsPQOHgMgBGSaLqAJCW87Rjbr06SUKQR8cKKvXr35sQVAQYMPU2tYpzpxlPedOqx9xjkpbmUZx7yU1mxsh3pQhSItcxsQKjDNZ_sXksGrNP7AXDFxaHMGWgX57F8Aw5orAI--3kW4COe3tKJ4kn0CItHE2LapEP-AaN5wcva2rjv0LCri3Yo9Wd6AZJINHhulEPpxfWEp3jsQC01nQ_wehHYpz9x9wvlcU4tPHrLXAKtj4YeNA_rXNNTaHLuRcn9qLf82m-Fcr_8FV8I0QeaNG9VNuOG0yU0Ar_qg&state=1713519414 + ok 13 - GET http://127.0.0.1:44149/end_session?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTcxMzUyMzA5OSwiaWF0IjoxNzEzNTE5NDk5LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6MzU0NDNcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.TMpV9WqMZgeL62DI3Kr2OITbpnqbLplPoH8avbWY7Fwtg4dahWSKXGzlMZ8bsrog6_arnrpu9O8vs4b5r_mJ3PPbggmJ48eWjipY_b2XsqvkA1Lz3lO4bJwt6Upr5h11IKZdzJHtmL3Y9z1jqdlUrJRbPr7U3IlkdWU_PEXqAW9fhH-3C3T-Vyz_ZMm6_xLOIsKXJTLogn5cTwUtZ_k4Fn9so6A76J3oFcpD11gfH9Oyt3VfikuDeNUn5mihGkOvJDHxKoSiHI10OGUpwz07bPVDkIaSbrXeHJDndJalXIjZb4hMYLvDC1Vn_qdCTWm_7lZG5tElKdz-TzDL88bC8g&state=1713519499 ok 14 - 302 Found ok 15 - home ok 16 - removed - ok 17 - GET http://127.0.0.1:44493/end_session + ok 17 - GET http://127.0.0.1:44149/end_session ok 18 - 302 Found ok 19 - home 1..19 @@ -699,13 +735,13 @@ 1..6 ok All tests successful. -Files=7, Tests=63, 6 wallclock secs ( 0.06 usr 0.04 sys + 5.56 cusr 0.42 csys = 6.08 CPU) +Files=7, Tests=63, 9 wallclock secs ( 0.12 usr 0.07 sys + 8.04 cusr 0.62 csys = 8.85 CPU) Result: PASS make[1]: Leaving directory '/build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02' create-stamp debian/debhelper-build-stamp dh_prep dh_auto_install --destdir=debian/libmojolicious-plugin-oauth2-perl/ - make -j3 install DESTDIR=/build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02/debian/libmojolicious-plugin-oauth2-perl AM_UPDATE_INFO_DIR=no PREFIX=/usr + make -j4 install DESTDIR=/build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02/debian/libmojolicious-plugin-oauth2-perl AM_UPDATE_INFO_DIR=no PREFIX=/usr make[1]: Entering directory '/build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02' Manifying 2 pod documents Installing /build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02/debian/libmojolicious-plugin-oauth2-perl/usr/share/perl5/Mojolicious/Plugin/OAuth2.pm @@ -734,12 +770,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/28051/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/28051/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/4053 and its subdirectories -I: Current time: Thu Apr 18 21:36:59 -12 2024 -I: pbuilder-time-stamp: 1713519419 +I: removing directory /srv/workspace/pbuilder/28051 and its subdirectories +I: Current time: Fri Apr 19 23:38:27 +14 2024 +I: pbuilder-time-stamp: 1713519507