travis_fold:start:worker_info Worker information hostname: af29ad15-eaaf-417a-9efc-343dfb197fa9@1.worker-n2-com-779d777f7b-rxlft.gce-production-1 version: 6.2.22 https://github.com/travis-ci/worker/tree/858cb91994a513269f2fe9782c15fc113e966231 instance: travis-job-7b6fe8e8-4f41-4671-abdf-7b1a3216d147 travis-ci-ubuntu-1804-1706776257-3d36ff62 (via amqp) startup: 7.105320112s travis_fold:end:worker_info travis_time:start:01a0c2b8 travis_time:end:01a0c2b8:start=1709112761213258509,finish=1709112761407927805,duration=194669296,event=no_world_writable_dirs travis_time:start:09ba6be0 travis_time:end:09ba6be0:start=1709112761410767830,finish=1709112761418121378,duration=7353548,event=agent travis_time:start:01fea310 travis_time:end:01fea310:start=1709112761420965344,finish=1709112761422873570,duration=1908226,event=check_unsupported travis_time:start:0bd70bcc travis_fold:start:system_info Build system information Build language: ruby Build dist: bionic Build id: 269163833 Job id: 618439210 Runtime kernel version: 5.4.0-1106-gcp travis-build version: f3de9fb7 Build image provisioning date and time Thu Feb 1 09:04:40 UTC 2024 Operating System Details Distributor ID: Ubuntu Description: Ubuntu 18.04.6 LTS Release: 18.04 Codename: bionic Systemd Version systemd 237 Cookbooks Version 4a0cff6 https://github.com/travis-ci/travis-cookbooks/tree/4a0cff6 git version git version 2.43.0 bash version GNU bash, version 4.4.20(1)-release (x86_64-pc-linux-gnu) gcc version gcc (Ubuntu 7.5.0-3ubuntu1~18.04) 7.5.0 docker version Client: Version: 20.10.21 API version: 1.41 Go version: go1.18.1 Git commit: 20.10.21-0ubuntu1~18.04.3 Built: Thu Apr 27 05:50:21 2023 OS/Arch: linux/amd64 Context: default Experimental: true Server: Engine: Version: 20.10.21 API version: 1.41 (minimum version 1.12) Go version: go1.18.1 Git commit: 20.10.21-0ubuntu1~18.04.3 Built: Thu Apr 27 05:36:22 2023 OS/Arch: linux/amd64 Experimental: false containerd: Version: 1.6.12-0ubuntu1~18.04.1 GitCommit: runc: Version: 1.1.4-0ubuntu1~18.04.2 GitCommit: docker-init: Version: 0.19.0 GitCommit: clang version clang version 16.0.0 jq version jq-1.7 bats version Bats 0.4.0 shellcheck version 0.9.0 shfmt version v3.7.0 ccache version 3.4.1 cmake version cmake version 3.26.3 heroku version heroku/8.7.1 linux-x64 node-v16.19.0 imagemagick version Version: ImageMagick 6.9.7-4 Q16 x86_64 20170114 http://www.imagemagick.org md5deep version 4.4 mercurial version version 5.3 mysql version mysql Ver 14.14 Distrib 5.7.42, for Linux (x86_64) using EditLine wrapper openssl version OpenSSL 1.1.1 11 Sep 2018 packer version 1.9.4 postgresql client version psql (PostgreSQL) 11.20 (Ubuntu 11.20-1.pgdg18.04+1) ragel version Ragel State Machine Compiler version 6.10 March 2017 sudo version 1.8.21p2 gzip version gzip 1.6 zip version Zip 3.0 vim version VIM - Vi IMproved 8.0 (2016 Sep 12, compiled Apr 18 2023 09:20:34) iptables version iptables v1.6.1 curl version curl 7.58.0 (x86_64-pc-linux-gnu) libcurl/7.58.0 OpenSSL/1.1.1 zlib/1.2.11 libidn2/2.0.4 libpsl/0.19.1 (+libidn2/2.0.4) nghttp2/1.30.0 librtmp/2.3 wget version GNU Wget 1.19.4 built on linux-gnu. rsync version rsync version 3.1.2 protocol version 31 gimme version v1.5.4 nvm version 0.39.7 perlbrew version /home/travis/perl5/perlbrew/bin/perlbrew - App::perlbrew/0.95 phpenv version rbenv 1.2.0 rvm version rvm 1.29.12 (latest) by Michal Papis, Piotr Kuczynski, Wayne E. Seguin [https://rvm.io] default ruby version ruby 2.7.6p219 (2022-04-12 revision c9c2245c0a) [x86_64-linux] default python version Python 3.7.17 ElasticSearch version 7.16.3 Installed Firefox version firefox 63.0.1 MongoDB version MongoDB 4.4.28 PhantomJS version 2.1.1 Pre-installed PostgreSQL versions 9.3.25 9.4.26 9.5.25 9.6.24 Redis version redis-server 7.2.4 Pre-installed Go versions 1.11.1 mvn version Apache Maven 3.9.4 (dfbb324ad4a7c8fb0bf182e6d91b0ae20e3d2dd9) gradle version Gradle 8.3! lein version Leiningen 2.11.1 on Java 11.0.21 OpenJDK 64-Bit Server VM Pre-installed Node.js versions v10.24.1 v12.22.12 v14.21.3 v16.15 v16.15.1 v16.20.2 v18.19.0 v20.11.0 v4.9.1 v6.17.1 v8.17.0 phpenv versions system 7.1 7.1.33 7.2 * 7.2.27 (set by /home/travis/.phpenv/version) 7.3 7.3.14 7.4 7.4.2 hhvm-stable hhvm composer --version Composer version 1.9.2 2020-01-14 16:30:31 Pre-installed Ruby versions ruby-2.5.9 ruby-2.7.6 ruby-3.1.2 travis_fold:end:system_info  travis_time:end:0bd70bcc:start=1709112761425938241,finish=1709112761436869476,duration=10931235,event=show_system_info travis_time:start:0015bad4 travis_time:end:0015bad4:start=1709112761439690060,finish=1709112761459432852,duration=19742792,event=rm_riak_source travis_time:start:11b04f94 travis_time:end:11b04f94:start=1709112761462252261,finish=1709112761467521408,duration=5269147,event=fix_rwky_redis travis_time:start:0d810a6c travis_time:end:0d810a6c:start=1709112761470416772,finish=1709112762192056957,duration=721640185,event=wait_for_network travis_time:start:0ef8da19 travis_time:end:0ef8da19:start=1709112762194841150,finish=1709112762525746314,duration=330905164,event=update_apt_keys travis_time:start:036a0fec travis_time:end:036a0fec:start=1709112762528837349,finish=1709112762580330708,duration=51493359,event=fix_hhvm_source travis_time:start:05db648c travis_time:end:05db648c:start=1709112762583179953,finish=1709112762585551975,duration=2372022,event=update_mongo_arch travis_time:start:1186004f travis_time:end:1186004f:start=1709112762588183703,finish=1709112762626745116,duration=38561413,event=fix_sudo_enabled_trusty travis_time:start:02b952e8 travis_time:end:02b952e8:start=1709112762629635198,finish=1709112762631543343,duration=1908145,event=update_glibc travis_time:start:02cc20a8 travis_time:end:02cc20a8:start=1709112762634123513,finish=1709112762641110281,duration=6986768,event=clean_up_path travis_time:start:091e4e6c travis_time:end:091e4e6c:start=1709112762643754185,finish=1709112762651898955,duration=8144770,event=fix_resolv_conf travis_time:start:0635a804 travis_time:end:0635a804:start=1709112762654533993,finish=1709112762679430357,duration=24896364,event=fix_etc_hosts travis_time:start:02889a92 travis_time:end:02889a92:start=1709112762682161746,finish=1709112762690027871,duration=7866125,event=fix_mvn_settings_xml travis_time:start:0ede72a2 travis_time:end:0ede72a2:start=1709112762692757747,finish=1709112762701276663,duration=8518916,event=no_ipv6_localhost travis_time:start:22acaef4 travis_time:end:22acaef4:start=1709112762703934711,finish=1709112762705854395,duration=1919684,event=fix_etc_mavenrc travis_time:start:001d1cf3 OK travis_time:end:001d1cf3:start=1709112762708489093,finish=1709112763081143693,duration=372654600,event=fix_perforce_key travis_time:start:04ce1788 travis_time:end:04ce1788:start=1709112763084165376,finish=1709112763086820503,duration=2655127,event=fix_wwdr_certificate travis_time:start:139f5778 travis_time:end:139f5778:start=1709112763089672505,finish=1709112763163004381,duration=73331876,event=put_localhost_first travis_time:start:006b035e travis_time:end:006b035e:start=1709112763165720615,finish=1709112763168661816,duration=2941201,event=home_paths travis_time:start:1935143e travis_time:end:1935143e:start=1709112763171306449,finish=1709112763183302889,duration=11996440,event=disable_initramfs travis_time:start:01b6180b travis_time:end:01b6180b:start=1709112763186113472,finish=1709112763331590029,duration=145476557,event=disable_ssh_roaming travis_time:start:18eea54f travis_time:end:18eea54f:start=1709112763334328306,finish=1709112763336321743,duration=1993437,event=debug_tools travis_time:start:039b6b50 travis_time:end:039b6b50:start=1709112763338980143,finish=1709112763341722811,duration=2742668,event=uninstall_oclint travis_time:start:044423a8 travis_time:end:044423a8:start=1709112763344299443,finish=1709112763346776507,duration=2477064,event=rvm_use travis_time:start:0f10f850 travis_time:end:0f10f850:start=1709112763349441742,finish=1709112763356801725,duration=7359983,event=rm_etc_boto_cfg travis_time:start:02e2eff2 travis_time:end:02e2eff2:start=1709112763359356216,finish=1709112763361860525,duration=2504309,event=rm_oraclejdk8_symlink travis_time:start:2c94ecac travis_time:end:2c94ecac:start=1709112763364530276,finish=1709112763460101799,duration=95571523,event=enable_i386 travis_time:start:1fc5a91c travis_time:end:1fc5a91c:start=1709112763463012725,finish=1709112763466621971,duration=3609246,event=update_rubygems travis_time:start:21d3a983 travis_time:end:21d3a983:start=1709112763469029211,finish=1709112764285981614,duration=816952403,event=ensure_path_components travis_time:start:0a9f4caf travis_time:end:0a9f4caf:start=1709112764288869355,finish=1709112764290717077,duration=1847722,event=redefine_curl travis_time:start:052c9d67 travis_time:end:052c9d67:start=1709112764293190470,finish=1709112764294942444,duration=1751974,event=nonblock_pipe travis_time:start:18c624d5 travis_time:end:18c624d5:start=1709112764297321779,finish=1709112770330170065,duration=6032848286,event=apt_get_update travis_time:start:0c257fa3 travis_time:end:0c257fa3:start=1709112770333028496,finish=1709112770335026461,duration=1997965,event=deprecate_xcode_64 travis_time:start:0b979015 travis_time:end:0b979015:start=1709112770337582992,finish=1709112774268039177,duration=3930456185,event=update_heroku travis_time:start:07300a55 travis_time:end:07300a55:start=1709112774270937675,finish=1709112774273083769,duration=2146094,event=shell_session_update travis_time:start:0023ec86 travis_fold:start:docker_mtu_and_registry_mirrors travis_fold:end:docker_mtu_and_registry_mirrors travis_time:end:0023ec86:start=1709112774275839123,finish=1709112776586897151,duration=2311058028,event=set_docker_mtu_and_registry_mirrors travis_time:start:0e471b86 travis_fold:start:resolvconf travis_fold:end:resolvconf travis_time:end:0e471b86:start=1709112776590348056,finish=1709112776657673221,duration=67325165,event=resolvconf travis_time:start:03d7bd0a travis_time:end:03d7bd0a:start=1709112776662271021,finish=1709112776806760842,duration=144489821,event=maven_central_mirror travis_time:start:020ead6a travis_time:end:020ead6a:start=1709112776809612863,finish=1709112776895334505,duration=85721642,event=maven_https travis_fold:start:apt travis_time:start:0659a1d7 $ travis_apt_get_update travis_time:end:0659a1d7:start=1709112776898884917,finish=1709112789081987515,duration=12183102598,event=prepare Installing APT Packages PostgreSQL package is detected. Stopping postgresql service. See https://github.com/travis-ci/travis-ci/issues/5737 for more information. $ sudo systemctl stop postgresql travis_time:start:17e56d46 $ sudo -E apt-get -yq --no-install-suggests --no-install-recommends $(travis_apt_get_options) install postgresql-11 postgresql-client-11 Reading package lists... Building dependency tree... Reading state information... postgresql-11 is already the newest version (11.20-1.pgdg18.04+1). postgresql-client-11 is already the newest version (11.20-1.pgdg18.04+1). postgresql-client-11 set to manually installed. The following package was automatically installed and is no longer required: libgeos-3.6.2 Use 'sudo apt autoremove' to remove it. 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. travis_time:end:17e56d46:start=1709112789121533091,finish=1709112789859681152,duration=738148061,event=prepare travis_fold:end:apt travis_time:start:1b3faaee travis_fold:start:services travis_fold:end:services travis_time:end:1b3faaee:start=1709112789862935939,finish=1709112792868871019,duration=3005935080,event=services travis_time:start:005d3dc2 travis_time:end:005d3dc2:start=1709112792872083575,finish=1709112792874202492,duration=2118917,event=fix_ps4 travis_fold:start:postgresql travis_time:start:0e2d1660 $ travis_setup_postgresql 11 Starting PostgreSQL v11 sudo systemctl start postgresql@11-main travis_time:end:0e2d1660:start=1709112792877105798,finish=1709112796045716091,duration=3168610293,event=prepare travis_fold:end:postgresql travis_time:start:00c15f30  travis_fold:start:git.checkout travis_time:start:12c33f00 travis_time:end:12c33f00:start=1709112796052020169,finish=1709112796056809115,duration=4788946,event=checkout travis_time:start:05fa417c $ git clone --depth=50 --branch=ga-test280224 https://github.com/travis-ci/marginalia.git travis-ci/marginalia Cloning into 'travis-ci/marginalia'... remote: Enumerating objects: 525, done. remote: Counting objects: 0% (1/525) remote: Counting objects: 1% (6/525) remote: Counting objects: 2% (11/525) remote: Counting objects: 3% (16/525) remote: Counting objects: 4% (21/525) remote: Counting objects: 5% (27/525) remote: Counting objects: 6% (32/525) remote: Counting objects: 7% (37/525) remote: Counting objects: 8% (42/525) remote: Counting objects: 9% (48/525) remote: Counting objects: 10% (53/525) remote: Counting objects: 11% (58/525) remote: Counting objects: 12% (63/525) remote: Counting objects: 13% (69/525) remote: Counting objects: 14% (74/525) remote: Counting objects: 15% (79/525) remote: Counting objects: 16% (84/525) remote: Counting objects: 17% (90/525) remote: Counting objects: 18% (95/525) remote: Counting objects: 19% (100/525) remote: Counting objects: 20% (105/525) remote: Counting objects: 21% (111/525) remote: Counting objects: 22% (116/525) remote: Counting objects: 23% (121/525) remote: Counting objects: 24% (126/525) remote: Counting objects: 25% (132/525) remote: Counting objects: 26% (137/525) remote: Counting objects: 27% (142/525) remote: Counting objects: 28% (147/525) remote: Counting objects: 29% (153/525) remote: Counting objects: 30% (158/525) remote: Counting objects: 31% (163/525) remote: Counting objects: 32% (168/525) remote: Counting objects: 33% (174/525) remote: Counting objects: 34% (179/525) remote: Counting objects: 35% (184/525) remote: Counting objects: 36% (189/525) remote: Counting objects: 37% (195/525) remote: Counting objects: 38% (200/525) remote: Counting objects: 39% (205/525) remote: Counting objects: 40% (210/525) remote: Counting objects: 41% (216/525) remote: Counting objects: 42% (221/525) remote: Counting objects: 43% (226/525) remote: Counting objects: 44% (231/525) remote: Counting objects: 45% (237/525) remote: Counting objects: 46% (242/525) remote: Counting objects: 47% (247/525) remote: Counting objects: 48% (252/525) remote: Counting objects: 49% (258/525) remote: Counting objects: 50% (263/525) remote: Counting objects: 51% (268/525) remote: Counting objects: 52% (273/525) remote: Counting objects: 53% (279/525) remote: Counting objects: 54% (284/525) remote: Counting objects: 55% (289/525) remote: Counting objects: 56% (294/525) remote: Counting objects: 57% (300/525) remote: Counting objects: 58% (305/525) remote: Counting objects: 59% (310/525) remote: Counting objects: 60% (315/525) remote: Counting objects: 61% (321/525) remote: Counting objects: 62% (326/525) remote: Counting objects: 63% (331/525) remote: Counting objects: 64% (336/525) remote: Counting objects: 65% (342/525) remote: Counting objects: 66% (347/525) remote: Counting objects: 67% (352/525) remote: Counting objects: 68% (357/525) remote: Counting objects: 69% (363/525) remote: Counting objects: 70% (368/525) remote: Counting objects: 71% (373/525) remote: Counting objects: 72% (378/525) remote: Counting objects: 73% (384/525) remote: Counting objects: 74% (389/525) remote: Counting objects: 75% (394/525) remote: Counting objects: 76% (399/525) remote: Counting objects: 77% (405/525) remote: Counting objects: 78% (410/525) remote: Counting objects: 79% (415/525) remote: Counting objects: 80% (420/525) remote: Counting objects: 81% (426/525) remote: Counting objects: 82% (431/525) remote: Counting objects: 83% (436/525) remote: Counting objects: 84% (441/525) remote: Counting objects: 85% (447/525) remote: Counting objects: 86% (452/525) remote: Counting objects: 87% (457/525) remote: Counting objects: 88% (462/525) remote: Counting objects: 89% (468/525) remote: Counting objects: 90% (473/525) remote: Counting objects: 91% (478/525) remote: Counting objects: 92% (483/525) remote: Counting objects: 93% (489/525) remote: Counting objects: 94% (494/525) remote: Counting objects: 95% (499/525) remote: Counting objects: 96% (504/525) remote: Counting objects: 97% (510/525) remote: Counting objects: 98% (515/525) remote: Counting objects: 99% (520/525) remote: Counting objects: 100% (525/525) remote: Counting objects: 100% (525/525), done. remote: Compressing objects: 0% (1/274) remote: Compressing objects: 1% (3/274) remote: Compressing objects: 2% (6/274) remote: Compressing objects: 3% (9/274) remote: Compressing objects: 4% (11/274) remote: Compressing objects: 5% (14/274) remote: Compressing objects: 6% (17/274) remote: Compressing objects: 7% (20/274) remote: Compressing objects: 8% (22/274) remote: Compressing objects: 9% (25/274) remote: Compressing objects: 10% (28/274) remote: Compressing objects: 11% (31/274) remote: Compressing objects: 12% (33/274) remote: Compressing objects: 13% (36/274) remote: Compressing objects: 14% (39/274) remote: Compressing objects: 15% (42/274) remote: Compressing objects: 16% (44/274) remote: Compressing objects: 17% (47/274) remote: Compressing objects: 18% (50/274) remote: Compressing objects: 19% (53/274) remote: Compressing objects: 20% (55/274) remote: Compressing objects: 21% (58/274) remote: Compressing objects: 22% (61/274) remote: Compressing objects: 23% (64/274) remote: Compressing objects: 24% (66/274) remote: Compressing objects: 25% (69/274) remote: Compressing objects: 26% (72/274) remote: Compressing objects: 27% (74/274) remote: Compressing objects: 28% (77/274) remote: Compressing objects: 29% (80/274) remote: Compressing objects: 30% (83/274) remote: Compressing objects: 31% (85/274) remote: Compressing objects: 32% (88/274) remote: Compressing objects: 33% (91/274) remote: Compressing objects: 34% (94/274) remote: Compressing objects: 35% (96/274) remote: Compressing objects: 36% (99/274) remote: Compressing objects: 37% (102/274) remote: Compressing objects: 38% (105/274) remote: Compressing objects: 39% (107/274) remote: Compressing objects: 40% (110/274) remote: Compressing objects: 41% (113/274) remote: Compressing objects: 42% (116/274) remote: Compressing objects: 43% (118/274) remote: Compressing objects: 44% (121/274) remote: Compressing objects: 45% (124/274) remote: Compressing objects: 46% (127/274) remote: Compressing objects: 47% (129/274) remote: Compressing objects: 48% (132/274) remote: Compressing objects: 49% (135/274) remote: Compressing objects: 50% (137/274) remote: Compressing objects: 51% (140/274) remote: Compressing objects: 52% (143/274) remote: Compressing objects: 53% (146/274) remote: Compressing objects: 54% (148/274) remote: Compressing objects: 55% (151/274) remote: Compressing objects: 56% (154/274) remote: Compressing objects: 57% (157/274) remote: Compressing objects: 58% (159/274) remote: Compressing objects: 59% (162/274) remote: Compressing objects: 60% (165/274) remote: Compressing objects: 61% (168/274) remote: Compressing objects: 62% (170/274) remote: Compressing objects: 63% (173/274) remote: Compressing objects: 64% (176/274) remote: Compressing objects: 65% (179/274) remote: Compressing objects: 66% (181/274) remote: Compressing objects: 67% (184/274) remote: Compressing objects: 68% (187/274) remote: Compressing objects: 69% (190/274) remote: Compressing objects: 70% (192/274) remote: Compressing objects: 71% (195/274) remote: Compressing objects: 72% (198/274) remote: Compressing objects: 73% (201/274) remote: Compressing objects: 74% (203/274) remote: Compressing objects: 75% (206/274) remote: Compressing objects: 76% (209/274) remote: Compressing objects: 77% (211/274) remote: Compressing objects: 78% (214/274) remote: Compressing objects: 79% (217/274) remote: Compressing objects: 80% (220/274) remote: Compressing objects: 81% (222/274) remote: Compressing objects: 82% (225/274) remote: Compressing objects: 83% (228/274) remote: Compressing objects: 84% (231/274) remote: Compressing objects: 85% (233/274) remote: Compressing objects: 86% (236/274) remote: Compressing objects: 87% (239/274) remote: Compressing objects: 88% (242/274) remote: Compressing objects: 89% (244/274) remote: Compressing objects: 90% (247/274) remote: Compressing objects: 91% (250/274) remote: Compressing objects: 92% (253/274) remote: Compressing objects: 93% (255/274) remote: Compressing objects: 94% (258/274) remote: Compressing objects: 95% (261/274) remote: Compressing objects: 96% (264/274) remote: Compressing objects: 97% (266/274) remote: Compressing objects: 98% (269/274) remote: Compressing objects: 99% (272/274) remote: Compressing objects: 100% (274/274) remote: Compressing objects: 100% (274/274), done. Receiving objects: 0% (1/525) Receiving objects: 1% (6/525) Receiving objects: 2% (11/525) Receiving objects: 3% (16/525) Receiving objects: 4% (21/525) Receiving objects: 5% (27/525) Receiving objects: 6% (32/525) Receiving objects: 7% (37/525) Receiving objects: 8% (42/525) Receiving objects: 9% (48/525) Receiving objects: 10% (53/525) Receiving objects: 11% (58/525) Receiving objects: 12% (63/525) Receiving objects: 13% (69/525) Receiving objects: 14% (74/525) Receiving objects: 15% (79/525) Receiving objects: 16% (84/525) Receiving objects: 17% (90/525) Receiving objects: 18% (95/525) Receiving objects: 19% (100/525) Receiving objects: 20% (105/525) Receiving objects: 21% (111/525) Receiving objects: 22% (116/525) Receiving objects: 23% (121/525) Receiving objects: 24% (126/525) Receiving objects: 25% (132/525) Receiving objects: 26% (137/525) Receiving objects: 27% (142/525) Receiving objects: 28% (147/525) Receiving objects: 29% (153/525) Receiving objects: 30% (158/525) Receiving objects: 31% (163/525) Receiving objects: 32% (168/525) Receiving objects: 33% (174/525) Receiving objects: 34% (179/525) Receiving objects: 35% (184/525) Receiving objects: 36% (189/525) Receiving objects: 37% (195/525) Receiving objects: 38% (200/525) Receiving objects: 39% (205/525) Receiving objects: 40% (210/525) Receiving objects: 41% (216/525) Receiving objects: 42% (221/525) Receiving objects: 43% (226/525) Receiving objects: 44% (231/525) Receiving objects: 45% (237/525) Receiving objects: 46% (242/525) Receiving objects: 47% (247/525) Receiving objects: 48% (252/525) Receiving objects: 49% (258/525) Receiving objects: 50% (263/525) Receiving objects: 51% (268/525) Receiving objects: 52% (273/525) Receiving objects: 53% (279/525) Receiving objects: 54% (284/525) Receiving objects: 55% (289/525) Receiving objects: 56% (294/525) Receiving objects: 57% (300/525) Receiving objects: 58% (305/525) Receiving objects: 59% (310/525) Receiving objects: 60% (315/525) Receiving objects: 61% (321/525) Receiving objects: 62% (326/525) remote: Total 525 (delta 260), reused 478 (delta 222), pack-reused 0 Receiving objects: 63% (331/525) Receiving objects: 64% (336/525) Receiving objects: 65% (342/525) Receiving objects: 66% (347/525) Receiving objects: 67% (352/525) Receiving objects: 68% (357/525) Receiving objects: 69% (363/525) Receiving objects: 70% (368/525) Receiving objects: 71% (373/525) Receiving objects: 72% (378/525) Receiving objects: 73% (384/525) Receiving objects: 74% (389/525) Receiving objects: 75% (394/525) Receiving objects: 76% (399/525) Receiving objects: 77% (405/525) Receiving objects: 78% (410/525) Receiving objects: 79% (415/525) Receiving objects: 80% (420/525) Receiving objects: 81% (426/525) Receiving objects: 82% (431/525) Receiving objects: 83% (436/525) Receiving objects: 84% (441/525) Receiving objects: 85% (447/525) Receiving objects: 86% (452/525) Receiving objects: 87% (457/525) Receiving objects: 88% (462/525) Receiving objects: 89% (468/525) Receiving objects: 90% (473/525) Receiving objects: 91% (478/525) Receiving objects: 92% (483/525) Receiving objects: 93% (489/525) Receiving objects: 94% (494/525) Receiving objects: 95% (499/525) Receiving objects: 96% (504/525) Receiving objects: 97% (510/525) Receiving objects: 98% (515/525) Receiving objects: 99% (520/525) Receiving objects: 100% (525/525) Receiving objects: 100% (525/525), 73.44 KiB | 2.45 MiB/s, done. Resolving deltas: 0% (0/260) Resolving deltas: 1% (3/260) Resolving deltas: 2% (6/260) Resolving deltas: 3% (8/260) Resolving deltas: 4% (11/260) Resolving deltas: 5% (13/260) Resolving deltas: 6% (16/260) Resolving deltas: 7% (19/260) Resolving deltas: 8% (21/260) Resolving deltas: 9% (24/260) Resolving deltas: 10% (26/260) Resolving deltas: 11% (29/260) Resolving deltas: 12% (32/260) Resolving deltas: 13% (34/260) Resolving deltas: 14% (37/260) Resolving deltas: 15% (39/260) Resolving deltas: 16% (42/260) Resolving deltas: 17% (45/260) Resolving deltas: 18% (47/260) Resolving deltas: 19% (50/260) Resolving deltas: 20% (52/260) Resolving deltas: 21% (55/260) Resolving deltas: 22% (58/260) Resolving deltas: 23% (60/260) Resolving deltas: 24% (63/260) Resolving deltas: 25% (65/260) Resolving deltas: 26% (68/260) Resolving deltas: 27% (71/260) Resolving deltas: 28% (73/260) Resolving deltas: 29% (76/260) Resolving deltas: 30% (78/260) Resolving deltas: 31% (81/260) Resolving deltas: 32% (84/260) Resolving deltas: 33% (86/260) Resolving deltas: 34% (89/260) Resolving deltas: 35% (91/260) Resolving deltas: 36% (94/260) Resolving deltas: 37% (97/260) Resolving deltas: 38% (99/260) Resolving deltas: 39% (102/260) Resolving deltas: 40% (104/260) Resolving deltas: 41% (107/260) Resolving deltas: 42% (110/260) Resolving deltas: 43% (112/260) Resolving deltas: 44% (115/260) Resolving deltas: 45% (117/260) Resolving deltas: 46% (120/260) Resolving deltas: 47% (123/260) Resolving deltas: 48% (125/260) Resolving deltas: 49% (128/260) Resolving deltas: 50% (130/260) Resolving deltas: 51% (133/260) Resolving deltas: 52% (136/260) Resolving deltas: 53% (138/260) Resolving deltas: 54% (141/260) Resolving deltas: 55% (143/260) Resolving deltas: 56% (146/260) Resolving deltas: 57% (149/260) Resolving deltas: 58% (151/260) Resolving deltas: 59% (154/260) Resolving deltas: 60% (156/260) Resolving deltas: 61% (159/260) Resolving deltas: 62% (162/260) Resolving deltas: 63% (164/260) Resolving deltas: 64% (167/260) Resolving deltas: 65% (169/260) Resolving deltas: 66% (172/260) Resolving deltas: 67% (175/260) Resolving deltas: 68% (177/260) Resolving deltas: 69% (180/260) Resolving deltas: 70% (182/260) Resolving deltas: 71% (185/260) Resolving deltas: 72% (188/260) Resolving deltas: 73% (190/260) Resolving deltas: 74% (193/260) Resolving deltas: 75% (195/260) Resolving deltas: 76% (198/260) Resolving deltas: 77% (201/260) Resolving deltas: 78% (203/260) Resolving deltas: 79% (206/260) Resolving deltas: 80% (208/260) Resolving deltas: 81% (211/260) Resolving deltas: 82% (214/260) Resolving deltas: 83% (216/260) Resolving deltas: 84% (219/260) Resolving deltas: 85% (221/260) Resolving deltas: 86% (224/260) Resolving deltas: 87% (227/260) Resolving deltas: 88% (229/260) Resolving deltas: 89% (232/260) Resolving deltas: 90% (234/260) Resolving deltas: 91% (237/260) Resolving deltas: 92% (240/260) Resolving deltas: 93% (242/260) Resolving deltas: 94% (245/260) Resolving deltas: 95% (247/260) Resolving deltas: 96% (250/260) Resolving deltas: 97% (253/260) Resolving deltas: 98% (255/260) Resolving deltas: 99% (258/260) Resolving deltas: 100% (260/260) Resolving deltas: 100% (260/260), done. travis_time:end:05fa417c:start=1709112796059898690,finish=1709112796510310233,duration=450411543,event=checkout $ cd travis-ci/marginalia $ git checkout -qf b0ca5dbf9e0e535bd94725c0f40c4c553aed3343 travis_fold:end:git.checkout  travis_time:end:05fa417c:start=1709112796059898690,finish=1709112796515823786,duration=455925096,event=checkout travis_time:start:1026e4b4  Setting environment variables from .travis.yml $ export MARGINALIA_DB_PORT=5432 $ export MARGINALIA_LOG_FILE=/var/log/postgresql/postgresql-11-main.log travis_time:end:1026e4b4:start=1709112796518773700,finish=1709112796524557327,duration=5783627,event=env travis_fold:start:rvm travis_time:start:03c52080 $ rvm get head Downloading https://get.rvm.io Downloading https://raw.githubusercontent.com/rvm/rvm/master/binscripts/rvm-installer.asc Verifying /home/travis/.rvm/archives/rvm-installer.asc gpg: Signature made Tue 21 Feb 2023 11:35:16 PM UTC gpg: using RSA key 7D2BAF1CF37B13E2069D6956105BD0E739499BDB gpg: Good signature from "Piotr Kuczynski " [unknown] gpg: WARNING: This key is not certified with a trusted signature! gpg: There is no indication that the signature belongs to the owner. Primary key fingerprint: 7D2B AF1C F37B 13E2 069D 6956 105B D0E7 3949 9BDB GPG verified '/home/travis/.rvm/archives/rvm-installer' Downloading https://github.com/rvm/rvm/archive/master.tar.gz Upgrading the RVM installation in /home/travis/.rvm/  RVM PATH line found in /home/travis/.mkshrc /home/travis/.profile /home/travis/.zshrc.  RVM PATH line not found for Bash, rerun this command with '--auto-dotfiles' flag to fix it.  RVM sourcing line found in /home/travis/.profile /home/travis/.bashrc /home/travis/.zlogin. Upgrade of RVM in /home/travis/.rvm/ is complete.  Thanks for installing RVM 🙏 Please consider donating to our open collective to help us maintain RVM. 👉 Donate: https://opencollective.com/rvm/donate  RVM reloaded! travis_time:end:03c52080:start=1709112796532204531,finish=1709112799362799256,duration=2830594725,event= travis_time:start:014080da $ rvm use 3.2.2 --install --binary --fuzzy curl: (22) The requested URL returned error: 404 Required ruby-3.2.2 is not installed - installing. curl: (22) The requested URL returned error: 404 Searching for binary rubies, this might take some time. Found remote file https://rubies.travis-ci.org/ubuntu/18.04/x86_64/ruby-3.2.2.tar.bz2 Checking requirements for ubuntu. Requirements installation successful. ruby-3.2.2 - #configure ruby-3.2.2 - #download % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 0 0 0 0 0 0 0 0 --:--:-- 0:00:01 --:--:-- 0 0 0 0 0 0 0 0 0 --:--:-- 0:00:01 --:--:-- 0 82 29.2M 82 24.0M 0 0 12.3M 0 0:00:02 0:00:01 0:00:01 12.3M 100 29.2M 100 29.2M 0 0 14.3M 0 0:00:02 0:00:02 --:--:-- 59.2M No checksum for downloaded archive, recording checksum in user configuration. ruby-3.2.2 - #validate archive ruby-3.2.2 - #extract ruby-3.2.2 - #validate binary ruby-3.2.2 - #setup ruby-3.2.2 - #gemset created /home/travis/.rvm/gems/ruby-3.2.2@global ruby-3.2.2 - #importing gemset /home/travis/.rvm/gemsets/global.gems|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.. ruby-3.2.2 - #generating global wrappers|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/. ruby-3.2.2 - #uninstalling gem rubygems-bundler-1.4.5|/. ruby-3.2.2 - #gemset created /home/travis/.rvm/gems/ruby-3.2.2 ruby-3.2.2 - #importing gemset /home/travis/.rvm/gemsets/default.gems|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\. ruby-3.2.2 - #generating default wrappers|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-. Using /home/travis/.rvm/gems/ruby-3.2.2 travis_time:end:014080da:start=1709112799367040976,finish=1709112821282924315,duration=21915883339,event= travis_fold:end:rvm  $ export BUNDLE_GEMFILE=$PWD/Gemfile travis_fold:start:ruby.versions $ ruby --version ruby 3.2.2 (2023-03-30 revision e51014f9c0) [x86_64-linux] $ rvm --version rvm 1.29.12-next (master) by Michal Papis, Piotr Kuczynski, Wayne E. Seguin [https://rvm.io] $ bundle --version Bundler version 2.4.10 $ gem --version 3.4.10 travis_fold:end:ruby.versions  travis_fold:start:before_install travis_time:start:0e44393e $ bash -c "yes | gem uninstall -i /home/travis/.rvm/gems/ruby-3.2.0@global rake" Gem 'rake' is not installed travis_time:end:0e44393e:start=1709112821705256368,finish=1709112821869627788,duration=164371420,event=before_install travis_fold:end:before_install travis_fold:start:install.bundler travis_time:start:2db5b0bd $ bundle install --jobs=3 --retry=3 Fetching gem metadata from https://rubygems.org/....... Resolving dependencies... Fetching rake 13.1.0 Installing rake 13.1.0 Fetching base64 0.2.0 Fetching bigdecimal 3.1.6 Fetching concurrent-ruby 1.2.3 Installing base64 0.2.0 Fetching connection_pool 2.4.1 Installing bigdecimal 3.1.6 with native extensions Installing concurrent-ruby 1.2.3 Installing connection_pool 2.4.1 Using ruby2_keywords 0.0.5 Fetching minitest 5.18.1 Fetching mutex_m 0.2.0 Installing minitest 5.18.1 Fetching timeout 0.4.1 Installing mutex_m 0.2.0 Using bundler 2.4.10 Fetching pg 1.5.5 Installing timeout 0.4.1 Using power_assert 2.0.3 Fetching drb 2.2.0 Installing drb 2.2.0 Fetching mocha 2.1.0 Installing pg 1.5.5 with native extensions Installing mocha 2.1.0 Fetching i18n 1.14.1 Installing i18n 1.14.1 Fetching tzinfo 2.0.6 Installing tzinfo 2.0.6 Fetching test-unit 3.6.2 Installing test-unit 3.6.2 Fetching activesupport 7.1.3.2 Fetching sequel 5.77.0 Installing activesupport 7.1.3.2 Installing sequel 5.77.0 Fetching activemodel 7.1.3.2 Installing activemodel 7.1.3.2 Fetching activerecord 7.1.3.2 Installing activerecord 7.1.3.2 Using marginalia 1.5.0 from source at `.` Bundle complete! 7 Gemfile dependencies, 22 gems now installed. Use `bundle info [gemname]` to see where a bundled gem is installed. travis_time:end:2db5b0bd:start=1709112821874880655,finish=1709112837940481188,duration=16065600533,event=install travis_fold:end:install.bundler  travis_fold:start:before_script travis_time:start:0e80bf07 $ sudo chmod 0644 $MARGINALIA_LOG_FILE travis_time:end:0e80bf07:start=1709112837945416453,finish=1709112837954349498,duration=8933045,event=before_script travis_fold:end:before_script travis_time:start:00b01cf8 $ bundle exec rake db:reset test:postgresql set -e; for file in $(find test -type f -name '*_test.rb'); do MARGINALIA_LOG_FILE=/var/log/postgresql/postgresql-11-main.log MARGINALIA_DB_PORT=5432 ruby -Ilib -Itest $file; done EXEC "SET log_statement = 'all';\n" EXEC COMMENT: "/**/" EXEC "DROP TABLE IF EXISTS posts;\n" EXEC COMMENT: "/**/" EXEC "CREATE TABLE posts (\n id INTEGER,\n title VARCHAR\n);\n" EXEC COMMENT: "/**/" Run options: --seed 948 # Running: QUERY "select * from posts;" Q COMMENT: "/*adapter:pg,app:query*/" .EXEC "INSERT INTO POSTS VALUES (1, 'My Title')" EXEC COMMENT: "/*adapter:pg,app:crud.insert*/" EXEC "UPDATE posts\nSET id = 2\nwhere id = 1\n" EXEC COMMENT: "/*adapter:pg,app:crud.update*/" EXEC "DELETE FROM POSTS where id = 2" EXEC COMMENT: "/*adapter:pg,app:crud.delete*/" .PREP "INSERT INTO posts (id, title) VALUES ($1, $2)" PREP COMMENT: "/*adapter:pg,app:prepare*/" .EXEC "select * from posts;" EXEC COMMENT: "/*adapter:pg,app:foobar*/" .A.EXEC "select * from posts;" AE COMMENT: "/*adapter:pg,app:async_exec*/" .A.QUERY "select * from posts;" AQ COMMENT: "/*adapter:pg,app:async_query*/" . Finished in 0.005965s, 1005.8200 runs/s, 1341.0933 assertions/s. 6 runs, 8 assertions, 0 failures, 0 errors, 0 skips Run options: --seed 50938 # Running: .. Finished in 0.000972s, 2056.5806 runs/s, 3084.8710 assertions/s. 2 runs, 3 assertions, 0 failures, 0 errors, 0 skips A.EXEC "SET client_min_messages TO 'warning'" AE COMMENT: "/**/" A.EXEC "SET standard_conforming_strings = on" AE COMMENT: "/**/" A.EXEC "SET intervalstyle = iso_8601" AE COMMENT: "/**/" A.EXEC "SET SESSION timezone TO 'UTC'" AE COMMENT: "/**/" QUERY ";" Q COMMENT: "/**/" A.EXEC "SET log_statement = 'all';\n" AE COMMENT: "/**/" A.EXEC "DROP TABLE IF EXISTS posts;\n" AE COMMENT: "/**/" -- create_table("posts", {:force=>true}) A.EXEC "SHOW max_identifier_length" AE COMMENT: "/**/" A.EXEC "DROP TABLE IF EXISTS \"posts\"" AE COMMENT: "/**/" A.EXEC "CREATE TABLE \"posts\" (\"id\" bigserial primary key, \"title\" character varying)" AE COMMENT: "/**/" -> 0.0069s A.EXEC "SELECT c.relname FROM pg_class c LEFT JOIN pg_namespace n ON n.oid = c.relnamespace WHERE n.nspname = ANY (current_schemas(false)) AND c.relname = 'schema_migrations' AND c.relkind IN ('r','p')" AE COMMENT: "/**/" A.EXEC "CREATE TABLE \"schema_migrations\" (\"version\" character varying NOT NULL PRIMARY KEY)" AE COMMENT: "/**/" A.EXEC "SELECT c.relname FROM pg_class c LEFT JOIN pg_namespace n ON n.oid = c.relnamespace WHERE n.nspname = ANY (current_schemas(false)) AND c.relname = 'ar_internal_metadata' AND c.relkind IN ('r','p')" AE COMMENT: "/**/" A.EXEC "CREATE TABLE \"ar_internal_metadata\" (\"key\" character varying NOT NULL PRIMARY KEY, \"value\" character varying, \"created_at\" timestamp(6) NOT NULL, \"updated_at\" timestamp(6) NOT NULL)" AE COMMENT: "/**/" Run options: --seed 26920 # Running: EA.EXEC "SELECT a.attname, format_type(a.atttypid, a.atttypmod),\n pg_get_expr(d.adbin, d.adrelid), a.attnotnull, a.atttypid, a.atttypmod,\n c.collname, col_description(a.attrelid, a.attnum) AS comment,\n attidentity AS identity,\n '' as attgenerated\n FROM pg_attribute a\n LEFT JOIN pg_attrdef d ON a.attrelid = d.adrelid AND a.attnum = d.adnum\n LEFT JOIN pg_type t ON a.atttypid = t.oid\n LEFT JOIN pg_collation c ON a.attcollation = c.oid AND a.attcollation <> t.typcollation\n WHERE a.attrelid = '\"posts\"'::regclass\n AND a.attnum > 0 AND NOT a.attisdropped\n ORDER BY a.attnum\n" AE COMMENT: "/*adapter:active_record,app:crud.insert*/" A.EXEC "SELECT c.relname FROM pg_class c LEFT JOIN pg_namespace n ON n.oid = c.relnamespace WHERE n.nspname = ANY (current_schemas(false)) AND c.relkind IN ('r','v','m','p','f')" AE COMMENT: "/*adapter:active_record,app:crud.insert*/" A.EXEC "SELECT a.attname\n FROM (\n SELECT indrelid, indkey, generate_subscripts(indkey, 1) idx\n FROM pg_index\n WHERE indrelid = '\"posts\"'::regclass\n AND indisprimary\n ) i\n JOIN pg_attribute a\n ON a.attrelid = i.indrelid\n AND a.attnum = i.indkey[i.idx]\n ORDER BY i.idx\n" AE COMMENT: "/*adapter:active_record,app:crud.insert*/" A.EXEC "BEGIN" AE COMMENT: "/*adapter:active_record,app:crud.insert*/" A.EXEC "COMMIT" AE COMMENT: "/*adapter:active_record,app:crud.insert*/" A.EXEC "SHOW search_path" AE COMMENT: "/*adapter:active_record,app:crud.update*/" PREP "SELECT \"posts\".* FROM \"posts\" WHERE \"posts\".\"id\" = $1 LIMIT $2" PREP COMMENT: "/*adapter:active_record,app:crud.update*/" A.EXEC "BEGIN" AE COMMENT: "/*adapter:active_record,app:crud.update*/" A.EXEC "COMMIT" AE COMMENT: "/*adapter:active_record,app:crud.update*/" A.EXEC "BEGIN" AE COMMENT: "/*adapter:active_record,app:crud.delete*/" A.EXEC "COMMIT" AE COMMENT: "/*adapter:active_record,app:crud.delete*/" . Finished in 0.023228s, 86.1019 runs/s, 129.1528 assertions/s. 1) Error: ActiveRecordMarginaliaTest#test_configuring_application: RuntimeError: Expected to find string /*adapter:active_record,app:customapp*/ in file /var/log/postgresql/postgresql-11-main.log /home/travis/build/travis-ci/marginalia/test/test_helpers.rb:10:in `file_contains_string' test/active_record/query_comments_test.rb:70:in `test_configuring_application' 2 runs, 3 assertions, 0 failures, 1 errors, 0 skips rake aborted! Command failed with status (1): [set -e; for file in $(find test -type f -name '*_test.rb'); do MARGINALIA_LOG_FILE=/var/log/postgresql/postgresql-11-main.log MARGINALIA_DB_PORT=5432 ruby -Ilib -Itest $file; done] /home/travis/build/travis-ci/marginalia/Rakefile:15:in `block (2 levels) in ' /home/travis/.rvm/gems/ruby-3.2.2/gems/rake-13.1.0/exe/rake:27:in `' /home/travis/.rvm/gems/ruby-3.2.2/bin/ruby_executable_hooks:22:in `eval' /home/travis/.rvm/gems/ruby-3.2.2/bin/ruby_executable_hooks:22:in `
' Tasks: TOP => test:postgresql (See full trace by running task with --trace) travis_time:end:00b01cf8:start=1709112837958946965,finish=1709112839925806750,duration=1966859785,event=script The command "bundle exec rake db:reset test:postgresql" exited with 1. travis_time:start:0f02f5da $ cat $MARGINALIA_LOG_FILE 2024-02-28 09:33:13.555 UTC [4951] LOG: listening on IPv4 address "127.0.0.1", port 5432 2024-02-28 09:33:13.555 UTC [4951] LOG: listening on IPv4 address "127.0.1.1", port 5432 2024-02-28 09:33:13.555 UTC [4951] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432" 2024-02-28 09:33:13.575 UTC [4960] LOG: database system was shut down at 2024-02-01 08:57:39 UTC 2024-02-28 09:33:13.579 UTC [4951] LOG: database system is ready to accept connections 2024-02-28 09:33:14.114 UTC [4968] [unknown]@[unknown] LOG: incomplete startup packet 2024-02-28 09:33:15.719 UTC [4981] postgres@postgres ERROR: role "travis" already exists 2024-02-28 09:33:15.719 UTC [4981] postgres@postgres STATEMENT: CREATE ROLE travis SUPERUSER CREATEDB CREATEROLE INHERIT LOGIN; 2024-02-28 09:33:58.849 UTC [9458] travis@marginalia_test LOG: statement: DROP TABLE IF EXISTS posts; /**/ 2024-02-28 09:33:58.851 UTC [9458] travis@marginalia_test LOG: statement: CREATE TABLE posts ( id INTEGER, title VARCHAR ); /**/ 2024-02-28 09:33:58.859 UTC [9458] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:query*/ 2024-02-28 09:33:58.860 UTC [9458] travis@marginalia_test LOG: statement: INSERT INTO POSTS VALUES (1, 'My Title') /*adapter:pg,app:crud.insert*/ 2024-02-28 09:33:58.860 UTC [9458] travis@marginalia_test LOG: statement: UPDATE posts SET id = 2 where id = 1 /*adapter:pg,app:crud.update*/ 2024-02-28 09:33:58.861 UTC [9458] travis@marginalia_test LOG: statement: DELETE FROM POSTS where id = 2 /*adapter:pg,app:crud.delete*/ 2024-02-28 09:33:58.862 UTC [9458] travis@marginalia_test LOG: execute statement1: INSERT INTO posts (id, title) VALUES ($1, $2) /*adapter:pg,app:prepare*/ 2024-02-28 09:33:58.862 UTC [9458] travis@marginalia_test DETAIL: parameters: $1 = '100', $2 = 'Welcome Tessa!' 2024-02-28 09:33:58.862 UTC [9458] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:foobar*/ 2024-02-28 09:33:58.863 UTC [9458] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:async_exec*/ 2024-02-28 09:33:58.863 UTC [9458] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:async_query*/ 2024-02-28 09:33:59.867 UTC [9476] travis@marginalia_test LOG: statement: DROP TABLE IF EXISTS posts; /**/ 2024-02-28 09:33:59.872 UTC [9476] travis@marginalia_test LOG: statement: SHOW max_identifier_length /**/ 2024-02-28 09:33:59.873 UTC [9476] travis@marginalia_test LOG: statement: DROP TABLE IF EXISTS "posts" /**/ 2024-02-28 09:33:59.873 UTC [9476] travis@marginalia_test LOG: statement: CREATE TABLE "posts" ("id" bigserial primary key, "title" character varying) /**/ 2024-02-28 09:33:59.877 UTC [9476] travis@marginalia_test LOG: statement: SELECT c.relname FROM pg_class c LEFT JOIN pg_namespace n ON n.oid = c.relnamespace WHERE n.nspname = ANY (current_schemas(false)) AND c.relname = 'schema_migrations' AND c.relkind IN ('r','p') /**/ 2024-02-28 09:33:59.878 UTC [9476] travis@marginalia_test LOG: statement: CREATE TABLE "schema_migrations" ("version" character varying NOT NULL PRIMARY KEY) /**/ 2024-02-28 09:33:59.880 UTC [9476] travis@marginalia_test LOG: statement: SELECT c.relname FROM pg_class c LEFT JOIN pg_namespace n ON n.oid = c.relnamespace WHERE n.nspname = ANY (current_schemas(false)) AND c.relname = 'ar_internal_metadata' AND c.relkind IN ('r','p') /**/ 2024-02-28 09:33:59.881 UTC [9476] travis@marginalia_test LOG: statement: CREATE TABLE "ar_internal_metadata" ("key" character varying NOT NULL PRIMARY KEY, "value" character varying, "created_at" timestamp(6) NOT NULL, "updated_at" timestamp(6) NOT NULL) /**/ 2024-02-28 09:33:59.883 UTC [9476] travis@marginalia_test LOG: execute : SELECT * FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 ORDER BY "ar_internal_metadata"."key" ASC LIMIT 1 2024-02-28 09:33:59.883 UTC [9476] travis@marginalia_test DETAIL: parameters: $1 = 'environment' 2024-02-28 09:33:59.885 UTC [9476] travis@marginalia_test LOG: execute : INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ('environment', 'test', '2024-02-28 09:33:59.884893', '2024-02-28 09:33:59.884899') RETURNING "key" 2024-02-28 09:33:59.895 UTC [9476] travis@marginalia_test LOG: execute : SELECT "posts".* FROM "posts" 2024-02-28 09:33:59.896 UTC [9476] travis@marginalia_test LOG: statement: SELECT a.attname, format_type(a.atttypid, a.atttypmod), pg_get_expr(d.adbin, d.adrelid), a.attnotnull, a.atttypid, a.atttypmod, c.collname, col_description(a.attrelid, a.attnum) AS comment, attidentity AS identity, '' as attgenerated FROM pg_attribute a LEFT JOIN pg_attrdef d ON a.attrelid = d.adrelid AND a.attnum = d.adnum LEFT JOIN pg_type t ON a.atttypid = t.oid LEFT JOIN pg_collation c ON a.attcollation = c.oid AND a.attcollation <> t.typcollation WHERE a.attrelid = '"posts"'::regclass AND a.attnum > 0 AND NOT a.attisdropped ORDER BY a.attnum /*adapter:active_record,app:crud.insert*/ 2024-02-28 09:33:59.899 UTC [9476] travis@marginalia_test LOG: statement: SELECT c.relname FROM pg_class c LEFT JOIN pg_namespace n ON n.oid = c.relnamespace WHERE n.nspname = ANY (current_schemas(false)) AND c.relkind IN ('r','v','m','p','f') /*adapter:active_record,app:crud.insert*/ 2024-02-28 09:33:59.900 UTC [9476] travis@marginalia_test LOG: statement: SELECT a.attname FROM ( SELECT indrelid, indkey, generate_subscripts(indkey, 1) idx FROM pg_index WHERE indrelid = '"posts"'::regclass AND indisprimary ) i JOIN pg_attribute a ON a.attrelid = i.indrelid AND a.attnum = i.indkey[i.idx] ORDER BY i.idx /*adapter:active_record,app:crud.insert*/ 2024-02-28 09:33:59.906 UTC [9476] travis@marginalia_test LOG: statement: BEGIN /*adapter:active_record,app:crud.insert*/ 2024-02-28 09:33:59.906 UTC [9476] travis@marginalia_test LOG: execute : INSERT INTO "posts" ("title") VALUES ($1) RETURNING "id" 2024-02-28 09:33:59.906 UTC [9476] travis@marginalia_test DETAIL: parameters: $1 = 'foo' 2024-02-28 09:33:59.907 UTC [9476] travis@marginalia_test LOG: statement: COMMIT /*adapter:active_record,app:crud.insert*/ 2024-02-28 09:33:59.909 UTC [9476] travis@marginalia_test LOG: statement: SHOW search_path /*adapter:active_record,app:crud.update*/ 2024-02-28 09:33:59.910 UTC [9476] travis@marginalia_test LOG: execute a1: SELECT "posts".* FROM "posts" WHERE "posts"."id" = $1 LIMIT $2 /*adapter:active_record,app:crud.update*/ 2024-02-28 09:33:59.910 UTC [9476] travis@marginalia_test DETAIL: parameters: $1 = '1', $2 = '1' 2024-02-28 09:33:59.911 UTC [9476] travis@marginalia_test LOG: statement: BEGIN /*adapter:active_record,app:crud.update*/ 2024-02-28 09:33:59.911 UTC [9476] travis@marginalia_test LOG: execute : UPDATE "posts" SET "title" = $1 WHERE "posts"."id" = $2 2024-02-28 09:33:59.911 UTC [9476] travis@marginalia_test DETAIL: parameters: $1 = 'bar', $2 = '1' 2024-02-28 09:33:59.911 UTC [9476] travis@marginalia_test LOG: statement: COMMIT /*adapter:active_record,app:crud.update*/ 2024-02-28 09:33:59.912 UTC [9476] travis@marginalia_test LOG: execute a1: SELECT "posts".* FROM "posts" WHERE "posts"."id" = $1 LIMIT $2 /*adapter:active_record,app:crud.update*/ 2024-02-28 09:33:59.912 UTC [9476] travis@marginalia_test DETAIL: parameters: $1 = '1', $2 = '1' 2024-02-28 09:33:59.912 UTC [9476] travis@marginalia_test LOG: statement: BEGIN /*adapter:active_record,app:crud.delete*/ 2024-02-28 09:33:59.913 UTC [9476] travis@marginalia_test LOG: execute : DELETE FROM "posts" WHERE "posts"."id" = $1 2024-02-28 09:33:59.913 UTC [9476] travis@marginalia_test DETAIL: parameters: $1 = '1' 2024-02-28 09:33:59.913 UTC [9476] travis@marginalia_test LOG: statement: COMMIT /*adapter:active_record,app:crud.delete*/ travis_time:end:0f02f5da:start=1709112839930515292,finish=1709112839935403572,duration=4888280,event=script The command "cat $MARGINALIA_LOG_FILE" exited with 0. Done. Your build exited with 1.