Diff of the two buildlogs: -- --- b1/build.log 2024-04-26 11:55:44.346646101 +0000 +++ b2/build.log 2024-04-26 11:56:33.388556861 +0000 @@ -1,6 +1,6 @@ I: pbuilder: network access will be disabled during build -I: Current time: Thu May 29 06:18:14 -12 2025 -I: pbuilder-time-stamp: 1748542694 +I: Current time: Sat Apr 27 01:55:46 +14 2024 +I: pbuilder-time-stamp: 1714132546 I: Building the build Environment I: extracting base tarball [/var/cache/pbuilder/trixie-reproducible-base.tgz] I: copying local configuration @@ -26,54 +26,86 @@ 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/63788/tmp/hooks/D02_print_environment starting +I: user script /srv/workspace/pbuilder/8106/tmp/hooks/D01_modify_environment starting +debug: Running on ionos12-i386. +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 26 11:56 /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/8106/tmp/hooks/D01_modify_environment finished +I: user script /srv/workspace/pbuilder/8106/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='i386' - DEBIAN_FRONTEND='noninteractive' - DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=22 ' - DISTRIBUTION='trixie' - HOME='/root' - HOST_ARCH='i386' + 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]="i686-pc-linux-gnu") + 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=i386 + DEBIAN_FRONTEND=noninteractive + DEB_BUILD_OPTIONS='buildinfo=+all reproducible=+all parallel=10 ' + DIRSTACK=() + DISTRIBUTION=trixie + EUID=0 + FUNCNAME=([0]="Echo" [1]="main") + GROUPS=() + HOME=/root + HOSTNAME=i-capture-the-hostname + HOSTTYPE=i686 + HOST_ARCH=i386 IFS=' ' - INVOCATION_ID='a3e8ba86fb004f159699b72f2e2bf994' - LANG='C' - LANGUAGE='en_US:en' - LC_ALL='C' - LD_LIBRARY_PATH='/usr/lib/libeatmydata' - LD_PRELOAD='libeatmydata.so' - 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='63788' - PS1='# ' - PS2='> ' + INVOCATION_ID=9aa68e9e09ad417185e80608c3617a16 + LANG=C + LANGUAGE=de_CH:de + LC_ALL=C + LD_LIBRARY_PATH=/usr/lib/libeatmydata + LD_PRELOAD=libeatmydata.so + MACHTYPE=i686-pc-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=8106 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.LqKvObH8/pbuilderrc_lUHM --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.LqKvObH8/b1 --logfile b1/build.log libmojolicious-plugin-oauth2-perl_2.02-1.dsc' - SUDO_GID='112' - SUDO_UID='107' - SUDO_USER='jenkins' - TERM='unknown' - TZ='/usr/share/zoneinfo/Etc/GMT+12' - USER='root' - _='/usr/bin/systemd-run' - http_proxy='http://213.165.73.152: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.LqKvObH8/pbuilderrc_FfXd --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.LqKvObH8/b2 --logfile b2/build.log libmojolicious-plugin-oauth2-perl_2.02-1.dsc' + SUDO_GID=112 + SUDO_UID=107 + SUDO_USER=jenkins + TERM=unknown + TZ=/usr/share/zoneinfo/Etc/GMT-14 + UID=0 + USER=root + _='I: set' + http_proxy=http://46.16.76.132:3128 I: uname -a - Linux ionos16-i386 6.1.0-20-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.85-1 (2024-04-11) x86_64 GNU/Linux + Linux i-capture-the-hostname 6.1.0-20-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.85-1 (2024-04-11) x86_64 GNU/Linux I: ls -l /bin - lrwxrwxrwx 1 root root 7 May 27 17:46 /bin -> usr/bin -I: user script /srv/workspace/pbuilder/63788/tmp/hooks/D02_print_environment finished + lrwxrwxrwx 1 root root 7 Apr 21 07:12 /bin -> usr/bin +I: user script /srv/workspace/pbuilder/8106/tmp/hooks/D02_print_environment finished -> Attempting to satisfy build-dependencies -> Creating pbuilder-satisfydepends-dummy package Package: pbuilder-satisfydepends-dummy @@ -86,7 +118,7 @@ Depends: debhelper-compat (= 13), libcrypt-openssl-bignum-perl, libcrypt-openssl-rsa-perl, libio-socket-ssl-perl, libmojo-jwt-perl (>= 0.09), libmojolicious-perl (>= 8.25), perl dpkg-deb: building package 'pbuilder-satisfydepends-dummy' in '/tmp/satisfydepends-aptitude/pbuilder-satisfydepends-dummy.deb'. Selecting previously unselected package pbuilder-satisfydepends-dummy. -(Reading database ... 19706 files and directories currently installed.) +(Reading database ... 19882 files and directories currently installed.) Preparing to unpack .../pbuilder-satisfydepends-dummy.deb ... Unpacking pbuilder-satisfydepends-dummy (0.invalid.0) ... dpkg: pbuilder-satisfydepends-dummy: dependency problems, but configuring anyway as you requested: @@ -194,20 +226,21 @@ Get: 42 http://deb.debian.org/debian trixie/main i386 libjs-highlight.js all 9.18.5+dfsg1-2 [397 kB] Get: 43 http://deb.debian.org/debian trixie/main i386 libmojolicious-perl all 9.36+dfsg-1 [842 kB] Get: 44 http://deb.debian.org/debian trixie/main i386 libmojo-jwt-perl all 0.09-1 [12.4 kB] -Fetched 24.0 MB in 0s (77.9 MB/s) +Fetched 24.0 MB in 0s (48.7 MB/s) debconf: delaying package configuration, since apt-utils is not installed dpkg: libssl3:i386: dependency problems, but removing anyway as you requested: + libkrb5-3:i386 depends on libssl3 (>= 3.0.0). coreutils depends on libssl3 (>= 3.0.0). -(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 ... 19706 files and directories currently installed.) +(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 ... 19882 files and directories currently installed.) Removing libssl3:i386 (3.1.5-1) ... Selecting previously unselected package libssl3t64:i386. -(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 ... 19693 files and directories currently installed.) +(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 ... 19869 files and directories currently installed.) Preparing to unpack .../libssl3t64_3.2.1-3_i386.deb ... Unpacking libssl3t64:i386 (3.2.1-3) ... Setting up libssl3t64:i386 (3.2.1-3) ... 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 ... 19708 files and directories currently installed.) +(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 ... 19884 files and directories currently installed.) Preparing to unpack .../00-netbase_6.4_all.deb ... Unpacking netbase (6.4) ... Selecting previously unselected package sensible-utils. @@ -391,7 +424,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/8106/tmp/hooks/A99_set_merged_usr starting +Not re-configuring usrmerge for trixie +I: user script /srv/workspace/pbuilder/8106/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 @@ -413,35 +450,35 @@ Writing Makefile for Mojolicious::Plugin::OAuth2 Writing MYMETA.yml and MYMETA.json dh_auto_build - make -j22 + make -j10 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 Manifying 2 pod documents make[1]: Leaving directory '/build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02' dh_auto_test - make -j22 test TEST_VERBOSE=1 + make -j10 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(0x59a9cde8)) (Test::Pod::Coverage is required) +ok 3 # skip pod_coverage_ok(Mojolicious::Plugin::OAuth2 HASH(0x57ad9dc8)) (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(0x597aa440)) (Test::Pod::Coverage is required) +ok 6 # skip pod_coverage_ok(Mojolicious::Plugin::OAuth2::Mock HASH(0x57d96930)) (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 -[2025-05-29 18:18:37.14628] [86583] [trace] [BodPo2ONywS9] GET "/test123" -[2025-05-29 18:18:37.14661] [86583] [trace] [BodPo2ONywS9] Routing to a callback -[2025-05-29 18:18:37.14757] [86583] [trace] [BodPo2ONywS9] 200 OK (0.001285s, 778.210/s) -[2025-05-29 18:18:37.15116] [86583] [trace] [Xoe6WQ8jUSO9] GET "/test123" -[2025-05-29 18:18:37.15135] [86583] [trace] [Xoe6WQ8jUSO9] Routing to a callback -[2025-05-29 18:18:37.15172] [86583] [trace] [Xoe6WQ8jUSO9] 200 OK (0.000544s, 1838.235/s) +[2024-04-26 11:56:23.66905] [17720] [trace] [KjD27Cm12Mr5] GET "/test123" +[2024-04-26 11:56:23.66949] [17720] [trace] [KjD27Cm12Mr5] Routing to a callback +[2024-04-26 11:56:23.67069] [17720] [trace] [KjD27Cm12Mr5] 200 OK (0.001631s, 613.121/s) +[2024-04-26 11:56:23.67495] [17720] [trace] [zX5n1s1zWSHO] GET "/test123" +[2024-04-26 11:56:23.67512] [17720] [trace] [zX5n1s1zWSHO] Routing to a callback +[2024-04-26 11:56:23.67555] [17720] [trace] [zX5n1s1zWSHO] 200 OK (0.000593s, 1686.341/s) t/auth_url.t ........ ok 1 - provider_id is required ok 2 - GET /test123 @@ -459,51 +496,51 @@ ok 14 - state 1..14 ok -[2025-05-29 18:18:37.53743] [87757] [trace] [vXFz4dVNWRUP] GET "/oauth-delayed" -[2025-05-29 18:18:37.53788] [87757] [trace] [vXFz4dVNWRUP] Routing to a callback -[2025-05-29 18:18:37.53870] [87757] [trace] [vXFz4dVNWRUP] 302 Found (0.001271s, 786.782/s) -[2025-05-29 18:18:37.54260] [87757] [trace] [sAqzp2Fapg_i] GET "/oauth/authorize" -[2025-05-29 18:18:37.54293] [87757] [trace] [sAqzp2Fapg_i] Routing to a callback -[2025-05-29 18:18:37.54329] [87757] [trace] [sAqzp2Fapg_i] 302 Found (0.000672s, 1488.095/s) -[2025-05-29 18:18:37.54639] [87757] [trace] [8Qfa6x5E3cB9] GET "/oauth-delayed" -[2025-05-29 18:18:37.54660] [87757] [trace] [8Qfa6x5E3cB9] Routing to a callback -[2025-05-29 18:18:37.54844] [87757] [trace] [8Qfa6x5E3cB9] Template "oauthdelayed.html.ep" not found -[2025-05-29 18:18:37.54853] [87757] [trace] [8Qfa6x5E3cB9] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2025-05-29 18:18:37.55003] [87757] [trace] [mauV2PWqHGS0] POST "/oauth/token" -[2025-05-29 18:18:37.55031] [87757] [trace] [mauV2PWqHGS0] Routing to a callback -[2025-05-29 18:18:37.55073] [87757] [trace] [mauV2PWqHGS0] 200 OK (0.000681s, 1468.429/s) -[2025-05-29 18:18:37.55173] [87757] [trace] [8Qfa6x5E3cB9] 200 OK (0.005327s, 187.723/s) +[2024-04-26 11:56:24.36681] [17893] [trace] [AQQQX8HVXXvu] GET "/oauth-delayed" +[2024-04-26 11:56:24.36746] [17893] [trace] [AQQQX8HVXXvu] Routing to a callback +[2024-04-26 11:56:24.36872] [17893] [trace] [AQQQX8HVXXvu] 302 Found (0.001906s, 524.659/s) +[2024-04-26 11:56:24.37495] [17893] [trace] [4qncmGWhuGVX] GET "/oauth/authorize" +[2024-04-26 11:56:24.37544] [17893] [trace] [4qncmGWhuGVX] Routing to a callback +[2024-04-26 11:56:24.37600] [17893] [trace] [4qncmGWhuGVX] 302 Found (0.001032s, 968.992/s) +[2024-04-26 11:56:24.38025] [17893] [trace] [cmjhMWp48mc0] GET "/oauth-delayed" +[2024-04-26 11:56:24.38050] [17893] [trace] [cmjhMWp48mc0] Routing to a callback +[2024-04-26 11:56:24.38379] [17893] [trace] [cmjhMWp48mc0] Template "oauthdelayed.html.ep" not found +[2024-04-26 11:56:24.38392] [17893] [trace] [cmjhMWp48mc0] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-26 11:56:24.38615] [17893] [trace] [hyBtB4Skte5y] POST "/oauth/token" +[2024-04-26 11:56:24.38654] [17893] [trace] [hyBtB4Skte5y] Routing to a callback +[2024-04-26 11:56:24.38710] [17893] [trace] [hyBtB4Skte5y] 200 OK (0.000925s, 1081.081/s) +[2024-04-26 11:56:24.38856] [17893] [trace] [cmjhMWp48mc0] 200 OK (0.008308s, 120.366/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%3A42451%2Foauth-delayed&scope=a%2Cb%2Cc -ok 4 - GET http://127.0.0.1:42451/oauth/authorize?client_id=fake_key&redirect_uri=http%3A%2F%2F127.0.0.1%3A42451%2Foauth-delayed&scope=a%2Cb%2Cc +# /oauth/authorize?client_id=fake_key&redirect_uri=http%3A%2F%2F127.0.0.1%3A35307%2Foauth-delayed&scope=a%2Cb%2Cc +ok 4 - GET http://127.0.0.1:35307/oauth/authorize?client_id=fake_key&redirect_uri=http%3A%2F%2F127.0.0.1%3A35307%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:42451/oauth-delayed?code=fake_code -ok 8 - GET http://127.0.0.1:42451/oauth-delayed?code=fake_code +# http://127.0.0.1:35307/oauth-delayed?code=fake_code +ok 8 - GET http://127.0.0.1:35307/oauth-delayed?code=fake_code ok 9 - 200 OK ok 10 - exact match for content 1..10 ok -[2025-05-29 18:18:37.91845] [88488] [trace] [Vtl63yI2Fcyu] GET "/oauth-error" -[2025-05-29 18:18:37.91888] [88488] [trace] [Vtl63yI2Fcyu] Routing to a callback -[2025-05-29 18:18:37.91964] [88488] [trace] [Vtl63yI2Fcyu] 302 Found (0.001192s, 838.926/s) -[2025-05-29 18:18:37.92274] [88488] [trace] [t5FZI5CkoY33] GET "/oauth-error" -[2025-05-29 18:18:37.92294] [88488] [trace] [t5FZI5CkoY33] Routing to a callback -[2025-05-29 18:18:37.92461] [88488] [trace] [t5FZI5CkoY33] Template "oautherror.html.ep" not found -[2025-05-29 18:18:37.92470] [88488] [trace] [t5FZI5CkoY33] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2025-05-29 18:18:37.92611] [88488] [trace] [5FP_ZyQ0Y_-6] POST "/oauth/token" -[2025-05-29 18:18:37.92637] [88488] [trace] [5FP_ZyQ0Y_-6] Routing to a callback -[2025-05-29 18:18:37.92682] [88488] [trace] [5FP_ZyQ0Y_-6] 200 OK (0.000695s, 1438.849/s) -[2025-05-29 18:18:37.92778] [88488] [trace] [t5FZI5CkoY33] 200 OK (0.005038s, 198.491/s) -[2025-05-29 18:18:37.92997] [88488] [trace] [g4CagzvQN1is] GET "/oauth-error" -[2025-05-29 18:18:37.93018] [88488] [trace] [g4CagzvQN1is] Routing to a callback -[2025-05-29 18:18:37.93059] [88488] [trace] [g4CagzvQN1is] Template "oautherror.html.ep" not found -[2025-05-29 18:18:37.93068] [88488] [trace] [g4CagzvQN1is] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2025-05-29 18:18:37.93099] [88488] [trace] [g4CagzvQN1is] 500 Internal Server Error (0.001006s, 994.036/s) +[2024-04-26 11:56:25.01452] [18158] [trace] [9U9mDTEWuoe0] GET "/oauth-error" +[2024-04-26 11:56:25.01512] [18158] [trace] [9U9mDTEWuoe0] Routing to a callback +[2024-04-26 11:56:25.01606] [18158] [trace] [9U9mDTEWuoe0] 302 Found (0.001537s, 650.618/s) +[2024-04-26 11:56:25.02017] [18158] [trace] [U0otOaZkGR6G] GET "/oauth-error" +[2024-04-26 11:56:25.02038] [18158] [trace] [U0otOaZkGR6G] Routing to a callback +[2024-04-26 11:56:25.02305] [18158] [trace] [U0otOaZkGR6G] Template "oautherror.html.ep" not found +[2024-04-26 11:56:25.02317] [18158] [trace] [U0otOaZkGR6G] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-26 11:56:25.02499] [18158] [trace] [b_iEtUEgHxDA] POST "/oauth/token" +[2024-04-26 11:56:25.02530] [18158] [trace] [b_iEtUEgHxDA] Routing to a callback +[2024-04-26 11:56:25.02585] [18158] [trace] [b_iEtUEgHxDA] 200 OK (0.000847s, 1180.638/s) +[2024-04-26 11:56:25.02722] [18158] [trace] [U0otOaZkGR6G] 200 OK (0.007162s, 139.626/s) +[2024-04-26 11:56:25.03026] [18158] [trace] [3DcaSy3HLlXL] GET "/oauth-error" +[2024-04-26 11:56:25.03048] [18158] [trace] [3DcaSy3HLlXL] Routing to a callback +[2024-04-26 11:56:25.03090] [18158] [trace] [3DcaSy3HLlXL] Template "oautherror.html.ep" not found +[2024-04-26 11:56:25.03107] [18158] [trace] [3DcaSy3HLlXL] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-26 11:56:25.03127] [18158] [trace] [3DcaSy3HLlXL] 500 Internal Server Error (0.001015s, 985.222/s) t/error.t ........... ok 1 - GET /oauth-error ok 2 - 302 Found @@ -514,40 +551,40 @@ 1..6 ok t/live.t ............ skipped: OAUTH_FB_KEY and OAUTH_FB_SECRET must be set for oauth tests -[2025-05-29 18:18:38.69139] [90041] [trace] [1nU4XiVNmn9T] GET "/profile" -[2025-05-29 18:18:38.69185] [90041] [trace] [1nU4XiVNmn9T] Routing to a callback -[2025-05-29 18:18:38.69253] [90041] [trace] [1nU4XiVNmn9T] 302 Found (0.001134s, 881.834/s) -[2025-05-29 18:18:38.69554] [90041] [trace] [JSTp0xSLm-73] GET "/mocked/oauth/authorize" -[2025-05-29 18:18:38.69576] [90041] [trace] [JSTp0xSLm-73] Routing to a callback -[2025-05-29 18:18:38.69623] [90041] [trace] [JSTp0xSLm-73] 200 OK (0.000672s, 1488.095/s) -[2025-05-29 18:18:38.69950] [90041] [trace] [dJkRtjRA0moW] GET "/profile" -[2025-05-29 18:18:38.69965] [90041] [trace] [dJkRtjRA0moW] Routing to a callback -[2025-05-29 18:18:38.70223] [90041] [trace] [dJkRtjRA0moW] Template "profile.html.ep" not found -[2025-05-29 18:18:38.70231] [90041] [trace] [dJkRtjRA0moW] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2025-05-29 18:18:38.70359] [90041] [trace] [JLzILYjhJkul] POST "/mocked/oauth/token" -[2025-05-29 18:18:38.70379] [90041] [trace] [JLzILYjhJkul] Routing to a callback -[2025-05-29 18:18:38.70412] [90041] [trace] [JLzILYjhJkul] 200 OK (0.000519s, 1926.782/s) -[2025-05-29 18:18:38.70506] [90041] [trace] [dJkRtjRA0moW] 200 OK (0.005551s, 180.148/s) -[2025-05-29 18:18:38.70739] [90041] [trace] [IPFABmwJ70dy] GET "/profile" -[2025-05-29 18:18:38.70753] [90041] [trace] [IPFABmwJ70dy] Routing to a callback -[2025-05-29 18:18:38.70785] [90041] [trace] [IPFABmwJ70dy] Template "profile.html.ep" not found -[2025-05-29 18:18:38.70792] [90041] [trace] [IPFABmwJ70dy] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2025-05-29 18:18:38.70811] [90041] [trace] [IPFABmwJ70dy] 500 Internal Server Error (0.000719s, 1390.821/s) -[2025-05-29 18:18:38.71028] [90041] [trace] [qQSQpa1QeOPP] GET "/no-redirect" -[2025-05-29 18:18:38.71049] [90041] [trace] [qQSQpa1QeOPP] Routing to a callback -[2025-05-29 18:18:38.71081] [90041] [trace] [qQSQpa1QeOPP] Template "noredirect.html.ep" not found -[2025-05-29 18:18:38.71088] [90041] [trace] [qQSQpa1QeOPP] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2025-05-29 18:18:38.71105] [90041] [trace] [qQSQpa1QeOPP] 200 OK (0.00076s, 1315.789/s) +[2024-04-26 11:56:26.28014] [18643] [trace] [Btqx1TPkD1On] GET "/profile" +[2024-04-26 11:56:26.28087] [18643] [trace] [Btqx1TPkD1On] Routing to a callback +[2024-04-26 11:56:26.28181] [18643] [trace] [Btqx1TPkD1On] 302 Found (0.001638s, 610.501/s) +[2024-04-26 11:56:26.28638] [18643] [trace] [bhmVkhB1CB4X] GET "/mocked/oauth/authorize" +[2024-04-26 11:56:26.28666] [18643] [trace] [bhmVkhB1CB4X] Routing to a callback +[2024-04-26 11:56:26.28731] [18643] [trace] [bhmVkhB1CB4X] 200 OK (0.000988s, 1012.146/s) +[2024-04-26 11:56:26.29204] [18643] [trace] [ETfLxgihMYZM] GET "/profile" +[2024-04-26 11:56:26.29225] [18643] [trace] [ETfLxgihMYZM] Routing to a callback +[2024-04-26 11:56:26.29644] [18643] [trace] [ETfLxgihMYZM] Template "profile.html.ep" not found +[2024-04-26 11:56:26.29655] [18643] [trace] [ETfLxgihMYZM] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-26 11:56:26.29850] [18643] [trace] [hx1or3LrzdoZ] POST "/mocked/oauth/token" +[2024-04-26 11:56:26.29886] [18643] [trace] [hx1or3LrzdoZ] Routing to a callback +[2024-04-26 11:56:26.29945] [18643] [trace] [hx1or3LrzdoZ] 200 OK (0.000934s, 1070.664/s) +[2024-04-26 11:56:26.30090] [18643] [trace] [ETfLxgihMYZM] 200 OK (0.0089s, 112.360/s) +[2024-04-26 11:56:26.30466] [18643] [trace] [ZtdBdjxY7VcD] GET "/profile" +[2024-04-26 11:56:26.30501] [18643] [trace] [ZtdBdjxY7VcD] Routing to a callback +[2024-04-26 11:56:26.30546] [18643] [trace] [ZtdBdjxY7VcD] Template "profile.html.ep" not found +[2024-04-26 11:56:26.30565] [18643] [trace] [ZtdBdjxY7VcD] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-26 11:56:26.30590] [18643] [trace] [ZtdBdjxY7VcD] 500 Internal Server Error (0.001237s, 808.407/s) +[2024-04-26 11:56:26.30903] [18643] [trace] [CC7P5t2GqS0d] GET "/no-redirect" +[2024-04-26 11:56:26.30947] [18643] [trace] [CC7P5t2GqS0d] Routing to a callback +[2024-04-26 11:56:26.30994] [18643] [trace] [CC7P5t2GqS0d] Template "noredirect.html.ep" not found +[2024-04-26 11:56:26.31012] [18643] [trace] [CC7P5t2GqS0d] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-26 11:56:26.31038] [18643] [trace] [CC7P5t2GqS0d] 200 OK (0.001372s, 728.863/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:33565/mocked/oauth/authorize?client_id=42&redirect_uri=http%3A%2F%2F127.0.0.1%3A33565%2Fprofile +ok 4 - GET http://127.0.0.1:40431/mocked/oauth/authorize?client_id=42&redirect_uri=http%3A%2F%2F127.0.0.1%3A40431%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:33565/profile?code=fake_code +ok 9 - GET http://127.0.0.1:40431/profile?code=fake_code ok 10 - 200 OK ok 11 - exact match for content ok 12 - GET /profile?error=access_denied @@ -558,93 +595,93 @@ ok 17 - content is similar 1..17 ok -[2025-05-29 18:18:39.09329] [90745] [debug] Fetching OpenID configuration from /mocked/oauth2/.well-known/configuration -[2025-05-29 18:18:39.09852] [90745] [trace] [D5zSoyP_JJXt] GET "/mocked/oauth2/.well-known/configuration" -[2025-05-29 18:18:39.09890] [90745] [trace] [D5zSoyP_JJXt] Routing to a callback -[2025-05-29 18:18:39.10025] [90745] [trace] [D5zSoyP_JJXt] Rendering template "oauth2/mock/configuration.json.ep" from DATA section -[2025-05-29 18:18:39.10268] [90745] [trace] [D5zSoyP_JJXt] 200 OK (0.004146s, 241.196/s) -[2025-05-29 18:18:39.10494] [90745] [trace] [yVpGtSCnwA48] GET "/mocked/oauth2/keys" -[2025-05-29 18:18:39.10514] [90745] [trace] [yVpGtSCnwA48] Routing to a callback -[2025-05-29 18:18:39.51092] [90745] [trace] [yVpGtSCnwA48] Rendering template "oauth2/mock/keys.json.ep" from DATA section -[2025-05-29 18:18:39.51301] [90745] [trace] [yVpGtSCnwA48] 200 OK (0.408048s, 2.451/s) -[2025-05-29 18:18:39.52092] [90745] [trace] [niUiV2Q6gCAa] GET "/connect" -[2025-05-29 18:18:39.52134] [90745] [trace] [niUiV2Q6gCAa] Routing to a callback -[2025-05-29 18:18:39.52181] [90745] [trace] [niUiV2Q6gCAa] 302 Found (0.000875s, 1142.857/s) -[2025-05-29 18:18:39.52591] [90745] [trace] [0CGhm-JMzc7f] GET "/mocked/oauth2/authorize" -[2025-05-29 18:18:39.52628] [90745] [trace] [0CGhm-JMzc7f] Routing to a callback -[2025-05-29 18:18:39.52670] [90745] [trace] [0CGhm-JMzc7f] Rendering template "oauth2/mock/form_post.html.ep" from DATA section -[2025-05-29 18:18:39.52773] [90745] [trace] [0CGhm-JMzc7f] 200 OK (0.001812s, 551.876/s) -[2025-05-29 18:18:39.53147] [90745] [trace] [5vFwFpLemyjV] POST "/connect" -[2025-05-29 18:18:39.53179] [90745] [trace] [5vFwFpLemyjV] Routing to a callback -[2025-05-29 18:18:39.53322] [90745] [trace] [URBqdI46ZwgQ] POST "/mocked/oauth2/token" -[2025-05-29 18:18:39.53351] [90745] [trace] [URBqdI46ZwgQ] Routing to a callback -[2025-05-29 18:18:39.54212] [90745] [trace] [URBqdI46ZwgQ] Rendering template "oauth2/mock/token.json.ep" from DATA section -[2025-05-29 18:18:39.54369] [90745] [trace] [URBqdI46ZwgQ] 200 OK (0.010455s, 95.648/s) -[2025-05-29 18:18:39.54512] [90745] [trace] Your secret passphrase needs to be changed (see FAQ for more) -[2025-05-29 18:18:39.54624] [90745] [trace] [5vFwFpLemyjV] 200 OK (0.014753s, 67.783/s) -[2025-05-29 18:18:39.55343] [90745] [trace] [kc6GOFfivfni] GET "/refresh" -[2025-05-29 18:18:39.55383] [90745] [trace] [kc6GOFfivfni] Routing to a callback -[2025-05-29 18:18:39.55524] [90745] [trace] [Cia4GmRl-9Xg] POST "/mocked/oauth2/token" -[2025-05-29 18:18:39.55543] [90745] [trace] [Cia4GmRl-9Xg] Routing to a callback -[2025-05-29 18:18:39.56327] [90745] [trace] [Cia4GmRl-9Xg] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2025-05-29 18:18:39.56417] [90745] [trace] [Cia4GmRl-9Xg] 200 OK (0.008913s, 112.196/s) -[2025-05-29 18:18:39.56604] [90745] [trace] [kc6GOFfivfni] 200 OK (0.012601s, 79.359/s) -[2025-05-29 18:18:39.56996] [90745] [trace] [NFqUBUca6mDd] GET "/refresh" -[2025-05-29 18:18:39.57016] [90745] [trace] [NFqUBUca6mDd] Routing to a callback -[2025-05-29 18:18:39.57158] [90745] [trace] [cnCQkOpyIkm3] POST "/mocked/oauth2/token" -[2025-05-29 18:18:39.57177] [90745] [trace] [cnCQkOpyIkm3] Routing to a callback -[2025-05-29 18:18:39.57964] [90745] [trace] [cnCQkOpyIkm3] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2025-05-29 18:18:39.58039] [90745] [trace] [cnCQkOpyIkm3] 200 OK (0.008795s, 113.701/s) -[2025-05-29 18:18:39.58219] [90745] [trace] [NFqUBUca6mDd] 200 OK (0.012218s, 81.846/s) -[2025-05-29 18:18:39.58628] [90745] [trace] [0buXp-HR344V] GET "/refresh" -[2025-05-29 18:18:39.58650] [90745] [trace] [0buXp-HR344V] Routing to a callback -[2025-05-29 18:18:39.58721] [90745] [trace] [0buXp-HR344V] 500 Internal Server Error (0.000924s, 1082.251/s) -[2025-05-29 18:18:39.59168] [90745] [trace] [wNQknwvcHLSO] GET "/connect" -[2025-05-29 18:18:39.59186] [90745] [trace] [wNQknwvcHLSO] Routing to a callback -[2025-05-29 18:18:39.59227] [90745] [trace] [wNQknwvcHLSO] 302 Found (0.000584s, 1712.329/s) -[2025-05-29 18:18:39.59626] [90745] [trace] [ZAubtoo0cx6S] GET "/mocked/oauth2/authorize" -[2025-05-29 18:18:39.59655] [90745] [trace] [ZAubtoo0cx6S] Routing to a callback -[2025-05-29 18:18:39.59696] [90745] [trace] [ZAubtoo0cx6S] 302 Found (0.000688s, 1453.488/s) -[2025-05-29 18:18:39.60066] [90745] [trace] [HU67IiDU7jG0] GET "/connect" -[2025-05-29 18:18:39.60090] [90745] [trace] [HU67IiDU7jG0] Routing to a callback -[2025-05-29 18:18:39.60230] [90745] [trace] [Z_DDH4JU7w-L] POST "/mocked/oauth2/token" -[2025-05-29 18:18:39.60248] [90745] [trace] [Z_DDH4JU7w-L] Routing to a callback -[2025-05-29 18:18:39.61041] [90745] [trace] [Z_DDH4JU7w-L] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2025-05-29 18:18:39.61123] [90745] [trace] [Z_DDH4JU7w-L] 200 OK (0.008916s, 112.158/s) -[2025-05-29 18:18:39.61341] [90745] [trace] [HU67IiDU7jG0] 200 OK (0.012744s, 78.468/s) -[2025-05-29 18:18:39.62126] [90745] [trace] [UKYad4zfvxCA] GET "/end_session" -[2025-05-29 18:18:39.62165] [90745] [trace] [UKYad4zfvxCA] Routing to a callback -[2025-05-29 18:18:39.62216] [90745] [trace] [UKYad4zfvxCA] 302 Found (0.000886s, 1128.668/s) -[2025-05-29 18:18:39.62662] [90745] [trace] [SjHQ_9qFED3X] GET "/mocked/oauth2/logout" -[2025-05-29 18:18:39.62696] [90745] [trace] [SjHQ_9qFED3X] Routing to a callback -[2025-05-29 18:18:39.62734] [90745] [trace] [SjHQ_9qFED3X] 302 Found (0.000702s, 1424.501/s) -[2025-05-29 18:18:39.63139] [90745] [trace] [j_i3HfvwHJ7P] GET "/end_session" -[2025-05-29 18:18:39.63163] [90745] [trace] [j_i3HfvwHJ7P] Routing to a callback -[2025-05-29 18:18:39.63239] [90745] [trace] [j_i3HfvwHJ7P] 302 Found (0.000985s, 1015.228/s) -[2025-05-29 18:18:39.63626] [90745] [trace] [RKDcDfQa9qEK] GET "/end_session" -[2025-05-29 18:18:39.63645] [90745] [trace] [RKDcDfQa9qEK] Routing to a callback -[2025-05-29 18:18:39.63673] [90745] [trace] [RKDcDfQa9qEK] 302 Found (0.000443s, 2257.336/s) -[2025-05-29 18:18:39.64069] [90745] [trace] [jgxYglyJcxmv] GET "/protect/next" -[2025-05-29 18:18:39.64116] [90745] [trace] [jgxYglyJcxmv] Routing to a callback -[2025-05-29 18:18:39.64135] [90745] [trace] [jgxYglyJcxmv] Nothing has been rendered, expecting delayed response (see FAQ for more) -[2025-05-29 18:18:39.74256] [90745] [trace] [jgxYglyJcxmv] 302 Found (0.101833s, 9.820/s) -[2025-05-29 18:18:39.74476] [90745] [trace] [KOU4mjCmew5w] GET "/connect" -[2025-05-29 18:18:39.74502] [90745] [trace] [KOU4mjCmew5w] Routing to a callback -[2025-05-29 18:18:39.74548] [90745] [trace] [KOU4mjCmew5w] 302 Found (0.000717s, 1394.700/s) -[2025-05-29 18:18:39.74742] [90745] [trace] [tezVbIxBALaG] GET "/mocked/oauth2/authorize" -[2025-05-29 18:18:39.74771] [90745] [trace] [tezVbIxBALaG] Routing to a callback -[2025-05-29 18:18:39.74813] [90745] [trace] [tezVbIxBALaG] 302 Found (0.000702s, 1424.501/s) -[2025-05-29 18:18:39.74975] [90745] [trace] [5AFw6fsmoL3U] GET "/connect" -[2025-05-29 18:18:39.75000] [90745] [trace] [5AFw6fsmoL3U] Routing to a callback -[2025-05-29 18:18:39.75145] [90745] [trace] [sk66uUYW9Dqh] POST "/mocked/oauth2/token" -[2025-05-29 18:18:39.75163] [90745] [trace] [sk66uUYW9Dqh] Routing to a callback -[2025-05-29 18:18:39.75964] [90745] [trace] [sk66uUYW9Dqh] Rendering cached template "oauth2/mock/token.json.ep" from DATA section -[2025-05-29 18:18:39.76052] [90745] [trace] [sk66uUYW9Dqh] 200 OK (0.009063s, 110.339/s) -[2025-05-29 18:18:39.76254] [90745] [trace] [5AFw6fsmoL3U] 302 Found (0.012776s, 78.272/s) -[2025-05-29 18:18:39.76520] [90745] [trace] [Lq12W5ZrPbwV] GET "/protect/next" -[2025-05-29 18:18:39.76539] [90745] [trace] [Lq12W5ZrPbwV] Routing to a callback -[2025-05-29 18:18:39.76575] [90745] [trace] [Lq12W5ZrPbwV] Routing to a callback -[2025-05-29 18:18:39.76597] [90745] [trace] [Lq12W5ZrPbwV] 200 OK (0.000753s, 1328.021/s) +[2024-04-26 11:56:26.96775] [18908] [debug] Fetching OpenID configuration from /mocked/oauth2/.well-known/configuration +[2024-04-26 11:56:26.97574] [18908] [trace] [s4CAwGh20bD5] GET "/mocked/oauth2/.well-known/configuration" +[2024-04-26 11:56:26.97637] [18908] [trace] [s4CAwGh20bD5] Routing to a callback +[2024-04-26 11:56:26.97872] [18908] [trace] [s4CAwGh20bD5] Rendering template "oauth2/mock/configuration.json.ep" from DATA section +[2024-04-26 11:56:26.98238] [18908] [trace] [s4CAwGh20bD5] 200 OK (0.006625s, 150.943/s) +[2024-04-26 11:56:26.98599] [18908] [trace] [FGg8W07_tYOb] GET "/mocked/oauth2/keys" +[2024-04-26 11:56:26.98631] [18908] [trace] [FGg8W07_tYOb] Routing to a callback +[2024-04-26 11:56:27.28769] [18908] [trace] [FGg8W07_tYOb] Rendering template "oauth2/mock/keys.json.ep" from DATA section +[2024-04-26 11:56:27.29037] [18908] [trace] [FGg8W07_tYOb] 200 OK (0.304363s, 3.286/s) +[2024-04-26 11:56:27.30068] [18908] [trace] [3cN5uXlXYY2o] GET "/connect" +[2024-04-26 11:56:27.30122] [18908] [trace] [3cN5uXlXYY2o] Routing to a callback +[2024-04-26 11:56:27.30178] [18908] [trace] [3cN5uXlXYY2o] 302 Found (0.001085s, 921.659/s) +[2024-04-26 11:56:27.30849] [18908] [trace] [Y3L4TM_cPXd0] GET "/mocked/oauth2/authorize" +[2024-04-26 11:56:27.30897] [18908] [trace] [Y3L4TM_cPXd0] Routing to a callback +[2024-04-26 11:56:27.30945] [18908] [trace] [Y3L4TM_cPXd0] Rendering template "oauth2/mock/form_post.html.ep" from DATA section +[2024-04-26 11:56:27.31100] [18908] [trace] [Y3L4TM_cPXd0] 200 OK (0.0025s, 400.000/s) +[2024-04-26 11:56:27.31766] [18908] [trace] [NEUEqvkeWr-Y] POST "/connect" +[2024-04-26 11:56:27.31808] [18908] [trace] [NEUEqvkeWr-Y] Routing to a callback +[2024-04-26 11:56:27.32042] [18908] [trace] [MhC6L39ue7Yo] POST "/mocked/oauth2/token" +[2024-04-26 11:56:27.32073] [18908] [trace] [MhC6L39ue7Yo] Routing to a callback +[2024-04-26 11:56:27.33428] [18908] [trace] [MhC6L39ue7Yo] Rendering template "oauth2/mock/token.json.ep" from DATA section +[2024-04-26 11:56:27.33651] [18908] [trace] [MhC6L39ue7Yo] 200 OK (0.016075s, 62.208/s) +[2024-04-26 11:56:27.33869] [18908] [trace] Your secret passphrase needs to be changed (see FAQ for more) +[2024-04-26 11:56:27.34039] [18908] [trace] [NEUEqvkeWr-Y] 200 OK (0.022703s, 44.047/s) +[2024-04-26 11:56:27.34993] [18908] [trace] [UgcIO2wtXqaX] GET "/refresh" +[2024-04-26 11:56:27.35056] [18908] [trace] [UgcIO2wtXqaX] Routing to a callback +[2024-04-26 11:56:27.35259] [18908] [trace] [hvjZG0bDA-GV] POST "/mocked/oauth2/token" +[2024-04-26 11:56:27.35277] [18908] [trace] [hvjZG0bDA-GV] Routing to a callback +[2024-04-26 11:56:27.36493] [18908] [trace] [hvjZG0bDA-GV] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2024-04-26 11:56:27.36613] [18908] [trace] [hvjZG0bDA-GV] 200 OK (0.013519s, 73.970/s) +[2024-04-26 11:56:27.36888] [18908] [trace] [UgcIO2wtXqaX] 200 OK (0.018938s, 52.804/s) +[2024-04-26 11:56:27.37502] [18908] [trace] [ryrRNlkkb5wY] GET "/refresh" +[2024-04-26 11:56:27.37524] [18908] [trace] [ryrRNlkkb5wY] Routing to a callback +[2024-04-26 11:56:27.37732] [18908] [trace] [EL7jQmc1FPYj] POST "/mocked/oauth2/token" +[2024-04-26 11:56:27.37750] [18908] [trace] [EL7jQmc1FPYj] Routing to a callback +[2024-04-26 11:56:27.38971] [18908] [trace] [EL7jQmc1FPYj] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2024-04-26 11:56:27.39083] [18908] [trace] [EL7jQmc1FPYj] 200 OK (0.013491s, 74.123/s) +[2024-04-26 11:56:27.39350] [18908] [trace] [ryrRNlkkb5wY] 200 OK (0.018468s, 54.148/s) +[2024-04-26 11:56:27.39961] [18908] [trace] [F2sYlfmdH4ci] GET "/refresh" +[2024-04-26 11:56:27.39985] [18908] [trace] [F2sYlfmdH4ci] Routing to a callback +[2024-04-26 11:56:27.40082] [18908] [trace] [F2sYlfmdH4ci] 500 Internal Server Error (0.001197s, 835.422/s) +[2024-04-26 11:56:27.40692] [18908] [trace] [QiLmbCpyj9nY] GET "/connect" +[2024-04-26 11:56:27.40712] [18908] [trace] [QiLmbCpyj9nY] Routing to a callback +[2024-04-26 11:56:27.40760] [18908] [trace] [QiLmbCpyj9nY] 302 Found (0.000664s, 1506.024/s) +[2024-04-26 11:56:27.41372] [18908] [trace] [cdv2HuZlxBXV] GET "/mocked/oauth2/authorize" +[2024-04-26 11:56:27.41405] [18908] [trace] [cdv2HuZlxBXV] Routing to a callback +[2024-04-26 11:56:27.41458] [18908] [trace] [cdv2HuZlxBXV] 302 Found (0.000842s, 1187.648/s) +[2024-04-26 11:56:27.42004] [18908] [trace] [lgtgky3oya3J] GET "/connect" +[2024-04-26 11:56:27.42029] [18908] [trace] [lgtgky3oya3J] Routing to a callback +[2024-04-26 11:56:27.42241] [18908] [trace] [pDrt3ZbZa_Vz] POST "/mocked/oauth2/token" +[2024-04-26 11:56:27.42260] [18908] [trace] [pDrt3ZbZa_Vz] Routing to a callback +[2024-04-26 11:56:27.43464] [18908] [trace] [pDrt3ZbZa_Vz] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2024-04-26 11:56:27.43593] [18908] [trace] [pDrt3ZbZa_Vz] 200 OK (0.013491s, 74.123/s) +[2024-04-26 11:56:27.43935] [18908] [trace] [lgtgky3oya3J] 200 OK (0.019295s, 51.827/s) +[2024-04-26 11:56:27.44923] [18908] [trace] [8p7faDmWjuFH] GET "/end_session" +[2024-04-26 11:56:27.44968] [18908] [trace] [8p7faDmWjuFH] Routing to a callback +[2024-04-26 11:56:27.45028] [18908] [trace] [8p7faDmWjuFH] 302 Found (0.000992s, 1008.065/s) +[2024-04-26 11:56:27.45608] [18908] [trace] [23Nz7c1smZev] GET "/mocked/oauth2/logout" +[2024-04-26 11:56:27.45644] [18908] [trace] [23Nz7c1smZev] Routing to a callback +[2024-04-26 11:56:27.45690] [18908] [trace] [23Nz7c1smZev] 302 Found (0.000796s, 1256.281/s) +[2024-04-26 11:56:27.46221] [18908] [trace] [aln0JRXz5FyX] GET "/end_session" +[2024-04-26 11:56:27.46250] [18908] [trace] [aln0JRXz5FyX] Routing to a callback +[2024-04-26 11:56:27.46342] [18908] [trace] [aln0JRXz5FyX] 302 Found (0.001206s, 829.187/s) +[2024-04-26 11:56:27.46863] [18908] [trace] [BOPIBMXtSxsm] GET "/end_session" +[2024-04-26 11:56:27.46882] [18908] [trace] [BOPIBMXtSxsm] Routing to a callback +[2024-04-26 11:56:27.46904] [18908] [trace] [BOPIBMXtSxsm] 302 Found (0.00041s, 2439.024/s) +[2024-04-26 11:56:27.47409] [18908] [trace] [bv45AlTIeKOh] GET "/protect/next" +[2024-04-26 11:56:27.47468] [18908] [trace] [bv45AlTIeKOh] Routing to a callback +[2024-04-26 11:56:27.47487] [18908] [trace] [bv45AlTIeKOh] Nothing has been rendered, expecting delayed response (see FAQ for more) +[2024-04-26 11:56:27.57623] [18908] [trace] [bv45AlTIeKOh] 302 Found (0.102108s, 9.794/s) +[2024-04-26 11:56:27.57907] [18908] [trace] [LXYgHMEkae3H] GET "/connect" +[2024-04-26 11:56:27.57931] [18908] [trace] [LXYgHMEkae3H] Routing to a callback +[2024-04-26 11:56:27.57985] [18908] [trace] [LXYgHMEkae3H] 302 Found (0.000773s, 1293.661/s) +[2024-04-26 11:56:27.58264] [18908] [trace] [RlKO4nXgwLZ9] GET "/mocked/oauth2/authorize" +[2024-04-26 11:56:27.58296] [18908] [trace] [RlKO4nXgwLZ9] Routing to a callback +[2024-04-26 11:56:27.58350] [18908] [trace] [RlKO4nXgwLZ9] 302 Found (0.000848s, 1179.245/s) +[2024-04-26 11:56:27.58564] [18908] [trace] [FwUe0iIwj9iS] GET "/connect" +[2024-04-26 11:56:27.58593] [18908] [trace] [FwUe0iIwj9iS] Routing to a callback +[2024-04-26 11:56:27.58801] [18908] [trace] [TXdzlg75e_YS] POST "/mocked/oauth2/token" +[2024-04-26 11:56:27.58820] [18908] [trace] [TXdzlg75e_YS] Routing to a callback +[2024-04-26 11:56:27.59997] [18908] [trace] [TXdzlg75e_YS] Rendering cached template "oauth2/mock/token.json.ep" from DATA section +[2024-04-26 11:56:27.60105] [18908] [trace] [TXdzlg75e_YS] 200 OK (0.013021s, 76.799/s) +[2024-04-26 11:56:27.60406] [18908] [trace] [FwUe0iIwj9iS] 302 Found (0.018405s, 54.333/s) +[2024-04-26 11:56:27.60806] [18908] [trace] [m3gZRf8GOKJY] GET "/protect/next" +[2024-04-26 11:56:27.60827] [18908] [trace] [m3gZRf8GOKJY] Routing to a callback +[2024-04-26 11:56:27.60866] [18908] [trace] [m3gZRf8GOKJY] Routing to a callback +[2024-04-26 11:56:27.60890] [18908] [trace] [m3gZRf8GOKJY] 200 OK (0.000823s, 1215.067/s) t/openid-connect.t .. # Subtest: warmup of provider data ok 1 - scope @@ -661,10 +698,10 @@ ok 2 - 302 Found ok 3 - scope set ok 4 - response mode set - ok 5 - GET http://127.0.0.1:33469/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A34085%2Fconnect&scope=openid&response_mode=form_post&response_type=code&state=test + ok 5 - GET http://127.0.0.1:40303/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A42071%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:34085/connect + ok 8 - POST http://127.0.0.1:42071/connect ok 9 - 200 OK ok 10 - exact match for JSON Pointer "/aud" ok 11 - exact match for JSON Pointer "/email" @@ -694,12 +731,12 @@ ok 3 - scope set ok 4 - response mode set ok 5 - state propagates - ok 6 - GET http://127.0.0.1:33469/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A34085%2Fconnect&scope=openid+email+profile&response_mode=query&response_type=code&state=test + ok 6 - GET http://127.0.0.1:40303/mocked/oauth2/authorize?client_id=c0e71b99-2c66-42e7-8589-6502153a7e3&redirect_uri=http%3A%2F%2F127.0.0.1%3A42071%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:34085/connect?code=authorize-code&state=test + ok 11 - GET http://127.0.0.1:42071/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" @@ -713,22 +750,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:34085/end_session + ok 2 - GET http://127.0.0.1:42071/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:33469/mocked/oauth2/logout?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTc0ODU0NjMxOSwiaWF0IjoxNzQ4NTQyNzE5LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6MzM0NjlcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.WMjf9_VrQcoHimg3dW7Qgyy6gc1OxKGRELjYIvpEF9We5bTKTeJO3YNNto30AhwBUcNJZIbL_HBMJ_j5o9oehAoRCkis0OsypU2XVnLkazyTdG7n7WhPOBogTiMh_Jf9Dxppq74VguUH4ZQ77qEbJB8R_XLpDCQKktJ3WflrIkLOdAwgoy7xyo5fu4UAgZxkpHbDe_ZbgHKR8k5bXvtdPvPCr606Ko7PKzCuW9Dslkoq-bGc4-nwlakWZl3rESK1RtxwUlcSRaK2-oCQm7bc-3YenKOzbeBNAU1Ba7ygFzLmgSUlSwsFTx0GL0LXg-nmNHFNJ13B-xTtffy2-m-_PQ&post_logout_redirect_uri=http%3A%2F%2F127.0.0.1%3A34085%2Fend_session&state=1748542719 + ok 8 - GET http://127.0.0.1:40303/mocked/oauth2/logout?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTcxNDEzNjE4NywiaWF0IjoxNzE0MTMyNTg3LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6NDAzMDNcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.GfS7APSKj1pyRJLIJDF4AYjbONERepyJXpVBH-hrW0EIU4LfwPB5dKLt4lS_iwzC1Gw5zx7eXYienQRcfvdRH9bg6--DKCl3GgjE2hK2Bl-7fq7s3yu7z7EKbSvWa2oqnuY0f53ubgwgoOH0l5ZIQpErVZTCEdQU0QOMZoNF_7nPEfzgVXurx8iffK9194AnyqZtJIUrrM5_NVGdNhK704SoqyMKbsi-NcmDCv8Ag56PM1_Q1Lk_8wvdmkF97cQ7sK1iBkVynmP7UHmOov5wvduIlXuLcbRgsf1uo-PIOplpk5LGnmbDeRyQOTJAPlI_m6r5ziaJZWycTJSm-NNrmA&post_logout_redirect_uri=http%3A%2F%2F127.0.0.1%3A42071%2Fend_session&state=1714132587 ok 9 - 302 Found ok 10 - correct ok 11 - correct id token ok 12 - state set - ok 13 - GET http://127.0.0.1:34085/end_session?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTc0ODU0NjMxOSwiaWF0IjoxNzQ4NTQyNzE5LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6MzM0NjlcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.WMjf9_VrQcoHimg3dW7Qgyy6gc1OxKGRELjYIvpEF9We5bTKTeJO3YNNto30AhwBUcNJZIbL_HBMJ_j5o9oehAoRCkis0OsypU2XVnLkazyTdG7n7WhPOBogTiMh_Jf9Dxppq74VguUH4ZQ77qEbJB8R_XLpDCQKktJ3WflrIkLOdAwgoy7xyo5fu4UAgZxkpHbDe_ZbgHKR8k5bXvtdPvPCr606Ko7PKzCuW9Dslkoq-bGc4-nwlakWZl3rESK1RtxwUlcSRaK2-oCQm7bc-3YenKOzbeBNAU1Ba7ygFzLmgSUlSwsFTx0GL0LXg-nmNHFNJ13B-xTtffy2-m-_PQ&state=1748542719 + ok 13 - GET http://127.0.0.1:42071/end_session?id_token_hint=eyJhbGciOiJSUzI1NiIsImtpZCI6IlRFU1RfU0lHTklOR19LRVkiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOiJjMGU3MWI5OS0yYzY2LTQyZTctODU4OS02NTAyMTUzYTdlMyIsImVtYWlsIjoiZm9vLmJhckBleGFtcGxlLmNvbSIsImV4cCI6MTcxNDEzNjE4NywiaWF0IjoxNzE0MTMyNTg3LCJpc3MiOiJodHRwOlwvXC8xMjcuMC4wLjE6NDAzMDNcL21vY2tlZFwvb2F1dGgyXC92Mi4wIiwibmFtZSI6ImZvbyBiYXIiLCJwcmVmZXJyZWRfdXNlcm5hbWUiOiJmb28uYmFyQGV4YW1wbGUuY29tIiwic3ViIjoiZm9vLmJhciJ9.GfS7APSKj1pyRJLIJDF4AYjbONERepyJXpVBH-hrW0EIU4LfwPB5dKLt4lS_iwzC1Gw5zx7eXYienQRcfvdRH9bg6--DKCl3GgjE2hK2Bl-7fq7s3yu7z7EKbSvWa2oqnuY0f53ubgwgoOH0l5ZIQpErVZTCEdQU0QOMZoNF_7nPEfzgVXurx8iffK9194AnyqZtJIUrrM5_NVGdNhK704SoqyMKbsi-NcmDCv8Ag56PM1_Q1Lk_8wvdmkF97cQ7sK1iBkVynmP7UHmOov5wvduIlXuLcbRgsf1uo-PIOplpk5LGnmbDeRyQOTJAPlI_m6r5ziaJZWycTJSm-NNrmA&state=1714132587 ok 14 - 302 Found ok 15 - home ok 16 - removed - ok 17 - GET http://127.0.0.1:34085/end_session + ok 17 - GET http://127.0.0.1:42071/end_session ok 18 - 302 Found ok 19 - home 1..19 @@ -744,19 +781,19 @@ 1..6 ok All tests successful. -Files=7, Tests=63, 3 wallclock secs ( 0.06 usr 0.00 sys + 2.98 cusr 0.22 csys = 3.26 CPU) +Files=7, Tests=63, 5 wallclock secs ( 0.06 usr 0.02 sys + 4.62 cusr 0.34 csys = 5.04 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 -j22 install DESTDIR=/build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02/debian/libmojolicious-plugin-oauth2-perl AM_UPDATE_INFO_DIR=no PREFIX=/usr + make -j10 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 Installing /build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02/debian/libmojolicious-plugin-oauth2-perl/usr/share/perl5/Mojolicious/Plugin/OAuth2/Mock.pm -Installing /build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02/debian/libmojolicious-plugin-oauth2-perl/usr/share/man/man3/Mojolicious::Plugin::OAuth2.3pm Installing /build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02/debian/libmojolicious-plugin-oauth2-perl/usr/share/man/man3/Mojolicious::Plugin::OAuth2::Mock.3pm +Installing /build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02/debian/libmojolicious-plugin-oauth2-perl/usr/share/man/man3/Mojolicious::Plugin::OAuth2.3pm make[1]: Leaving directory '/build/reproducible-path/libmojolicious-plugin-oauth2-perl-2.02' dh_installdocs dh_installchangelogs @@ -779,12 +816,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/8106/tmp/hooks/B01_cleanup starting +I: user script /srv/workspace/pbuilder/8106/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/63788 and its subdirectories -I: Current time: Thu May 29 06:18:43 -12 2025 -I: pbuilder-time-stamp: 1748542723 +I: removing directory /srv/workspace/pbuilder/8106 and its subdirectories +I: Current time: Sat Apr 27 01:56:32 +14 2024 +I: pbuilder-time-stamp: 1714132592