travis_fold:start:worker_info Worker information hostname: 12bf3c4b-5153-4b75-b70f-0925928152de@1.worker-n2-com-779d777f7b-rxlft.gce-production-1 version: 6.2.22 https://github.com/travis-ci/worker/tree/858cb91994a513269f2fe9782c15fc113e966231 instance: travis-job-9f68b29f-fd71-471e-8d22-9375d5a168cf travis-ci-ubuntu-1804-1706776257-3d36ff62 (via amqp) startup: 6.37519429s travis_fold:end:worker_info travis_time:start:17cf2a44 travis_time:end:17cf2a44:start=1709113151884853441,finish=1709113152099550033,duration=214696592,event=no_world_writable_dirs travis_time:start:22b6d1e1 travis_time:end:22b6d1e1:start=1709113152102888123,finish=1709113152112490002,duration=9601879,event=agent travis_time:start:04f370d0 travis_time:end:04f370d0:start=1709113152115279692,finish=1709113152117632904,duration=2353212,event=check_unsupported travis_time:start:13973160 travis_fold:start:system_info Build system information Build language: ruby Build dist: bionic Build id: 269163985 Job id: 618439733 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:13973160:start=1709113152120475373,finish=1709113152131969099,duration=11493726,event=show_system_info travis_time:start:1251e286 travis_time:end:1251e286:start=1709113152134819253,finish=1709113152154798043,duration=19978790,event=rm_riak_source travis_time:start:1e3fe378 travis_time:end:1e3fe378:start=1709113152158528742,finish=1709113152163644563,duration=5115821,event=fix_rwky_redis travis_time:start:0eab6934 travis_time:end:0eab6934:start=1709113152166814929,finish=1709113152789252591,duration=622437662,event=wait_for_network travis_time:start:25f440f0 travis_time:end:25f440f0:start=1709113152792276848,finish=1709113153135976193,duration=343699345,event=update_apt_keys travis_time:start:02265cdb travis_time:end:02265cdb:start=1709113153138768171,finish=1709113153192245751,duration=53477580,event=fix_hhvm_source travis_time:start:049c8dc6 travis_time:end:049c8dc6:start=1709113153195262056,finish=1709113153197756556,duration=2494500,event=update_mongo_arch travis_time:start:215c7eea travis_time:end:215c7eea:start=1709113153200499489,finish=1709113153241008874,duration=40509385,event=fix_sudo_enabled_trusty travis_time:start:28bdab74 travis_time:end:28bdab74:start=1709113153244190876,finish=1709113153246455453,duration=2264577,event=update_glibc travis_time:start:06f18230 travis_time:end:06f18230:start=1709113153249351338,finish=1709113153257615995,duration=8264657,event=clean_up_path travis_time:start:0657b05e travis_time:end:0657b05e:start=1709113153260675815,finish=1709113153269495498,duration=8819683,event=fix_resolv_conf travis_time:start:131cace1 travis_time:end:131cace1:start=1709113153272430801,finish=1709113153317441067,duration=45010266,event=fix_etc_hosts travis_time:start:2c09a693 travis_time:end:2c09a693:start=1709113153320408593,finish=1709113153329118754,duration=8710161,event=fix_mvn_settings_xml travis_time:start:1cb835ac travis_time:end:1cb835ac:start=1709113153332176663,finish=1709113153341980384,duration=9803721,event=no_ipv6_localhost travis_time:start:17f2cab0 travis_time:end:17f2cab0:start=1709113153344924567,finish=1709113153347170659,duration=2246092,event=fix_etc_mavenrc travis_time:start:001c0ac2 OK travis_time:end:001c0ac2:start=1709113153350065562,finish=1709113153723038022,duration=372972460,event=fix_perforce_key travis_time:start:04172187 travis_time:end:04172187:start=1709113153726030448,finish=1709113153728824067,duration=2793619,event=fix_wwdr_certificate travis_time:start:04491670 travis_time:end:04491670:start=1709113153731581955,finish=1709113153796704851,duration=65122896,event=put_localhost_first travis_time:start:0daeadfe travis_time:end:0daeadfe:start=1709113153799886374,finish=1709113153802879571,duration=2993197,event=home_paths travis_time:start:0d9b6a65 travis_time:end:0d9b6a65:start=1709113153805845556,finish=1709113153819336434,duration=13490878,event=disable_initramfs travis_time:start:09018780 travis_time:end:09018780:start=1709113153822347621,finish=1709113153989635369,duration=167287748,event=disable_ssh_roaming travis_time:start:0529824f travis_time:end:0529824f:start=1709113153992265734,finish=1709113153994172642,duration=1906908,event=debug_tools travis_time:start:1f7d6eac travis_time:end:1f7d6eac:start=1709113153996740360,finish=1709113153999339811,duration=2599451,event=uninstall_oclint travis_time:start:0634c2dc travis_time:end:0634c2dc:start=1709113154001981182,finish=1709113154004544804,duration=2563622,event=rvm_use travis_time:start:170e8d1a travis_time:end:170e8d1a:start=1709113154007114696,finish=1709113154014359129,duration=7244433,event=rm_etc_boto_cfg travis_time:start:15fa38f6 travis_time:end:15fa38f6:start=1709113154016945844,finish=1709113154019422186,duration=2476342,event=rm_oraclejdk8_symlink travis_time:start:13d4d65c travis_time:end:13d4d65c:start=1709113154022196153,finish=1709113154115595917,duration=93399764,event=enable_i386 travis_time:start:05878ff2 travis_time:end:05878ff2:start=1709113154118265193,finish=1709113154122155357,duration=3890164,event=update_rubygems travis_time:start:1465d715 travis_time:end:1465d715:start=1709113154124749997,finish=1709113154982770973,duration=858020976,event=ensure_path_components travis_time:start:02e0d6dc travis_time:end:02e0d6dc:start=1709113154985796121,finish=1709113154987859305,duration=2063184,event=redefine_curl travis_time:start:0c507fd8 travis_time:end:0c507fd8:start=1709113154990453325,finish=1709113154992378030,duration=1924705,event=nonblock_pipe travis_time:start:0b6c4ca2 travis_time:end:0b6c4ca2:start=1709113154994814958,finish=1709113161029365670,duration=6034550712,event=apt_get_update travis_time:start:1f366f6e travis_time:end:1f366f6e:start=1709113161032452331,finish=1709113161034525320,duration=2072989,event=deprecate_xcode_64 travis_time:start:068ef176 travis_time:end:068ef176:start=1709113161037238637,finish=1709113165043826752,duration=4006588115,event=update_heroku travis_time:start:00aa418c travis_time:end:00aa418c:start=1709113165046716079,finish=1709113165048715440,duration=1999361,event=shell_session_update travis_time:start:2bafc37a travis_fold:start:docker_mtu_and_registry_mirrors travis_fold:end:docker_mtu_and_registry_mirrors travis_time:end:2bafc37a:start=1709113165051290389,finish=1709113167443674429,duration=2392384040,event=set_docker_mtu_and_registry_mirrors travis_time:start:0c01e8a0 travis_fold:start:resolvconf travis_fold:end:resolvconf travis_time:end:0c01e8a0:start=1709113167446866839,finish=1709113167516159307,duration=69292468,event=resolvconf travis_time:start:04051ed1 travis_time:end:04051ed1:start=1709113167520727749,finish=1709113167668949067,duration=148221318,event=maven_central_mirror travis_time:start:076de131 travis_time:end:076de131:start=1709113167672216377,finish=1709113167763510947,duration=91294570,event=maven_https travis_fold:start:apt travis_time:start:04efc43b $ travis_apt_get_update travis_time:end:04efc43b:start=1709113167767962793,finish=1709113180353159500,duration=12585196707,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:260e292a $ 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:260e292a:start=1709113180399665387,finish=1709113181255177506,duration=855512119,event=prepare travis_fold:end:apt travis_time:start:03894eaa travis_fold:start:services travis_fold:end:services travis_time:end:03894eaa:start=1709113181259116530,finish=1709113184265534186,duration=3006417656,event=services travis_time:start:18839259 travis_time:end:18839259:start=1709113184268697938,finish=1709113184270834257,duration=2136319,event=fix_ps4 travis_fold:start:postgresql travis_time:start:28188e97 $ travis_setup_postgresql 11 Starting PostgreSQL v11 sudo systemctl start postgresql@11-main travis_time:end:28188e97:start=1709113184273888426,finish=1709113187512239734,duration=3238351308,event=prepare travis_fold:end:postgresql travis_time:start:0247bdb0  travis_fold:start:git.checkout travis_time:start:1650e8c1 travis_time:end:1650e8c1:start=1709113187518969898,finish=1709113187524271804,duration=5301906,event=checkout travis_time:start:0085b528 $ 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: 503, done. remote: Counting objects: 0% (1/503) remote: Counting objects: 1% (6/503) remote: Counting objects: 2% (11/503) remote: Counting objects: 3% (16/503) remote: Counting objects: 4% (21/503) remote: Counting objects: 5% (26/503) remote: Counting objects: 6% (31/503) remote: Counting objects: 7% (36/503) remote: Counting objects: 8% (41/503) remote: Counting objects: 9% (46/503) remote: Counting objects: 10% (51/503) remote: Counting objects: 11% (56/503) remote: Counting objects: 12% (61/503) remote: Counting objects: 13% (66/503) remote: Counting objects: 14% (71/503) remote: Counting objects: 15% (76/503) remote: Counting objects: 16% (81/503) remote: Counting objects: 17% (86/503) remote: Counting objects: 18% (91/503) remote: Counting objects: 19% (96/503) remote: Counting objects: 20% (101/503) remote: Counting objects: 21% (106/503) remote: Counting objects: 22% (111/503) remote: Counting objects: 23% (116/503) remote: Counting objects: 24% (121/503) remote: Counting objects: 25% (126/503) remote: Counting objects: 26% (131/503) remote: Counting objects: 27% (136/503) remote: Counting objects: 28% (141/503) remote: Counting objects: 29% (146/503) remote: Counting objects: 30% (151/503) remote: Counting objects: 31% (156/503) remote: Counting objects: 32% (161/503) remote: Counting objects: 33% (166/503) remote: Counting objects: 34% (172/503) remote: Counting objects: 35% (177/503) remote: Counting objects: 36% (182/503) remote: Counting objects: 37% (187/503) remote: Counting objects: 38% (192/503) remote: Counting objects: 39% (197/503) remote: Counting objects: 40% (202/503) remote: Counting objects: 41% (207/503) remote: Counting objects: 42% (212/503) remote: Counting objects: 43% (217/503) remote: Counting objects: 44% (222/503) remote: Counting objects: 45% (227/503) remote: Counting objects: 46% (232/503) remote: Counting objects: 47% (237/503) remote: Counting objects: 48% (242/503) remote: Counting objects: 49% (247/503) remote: Counting objects: 50% (252/503) remote: Counting objects: 51% (257/503) remote: Counting objects: 52% (262/503) remote: Counting objects: 53% (267/503) remote: Counting objects: 54% (272/503) remote: Counting objects: 55% (277/503) remote: Counting objects: 56% (282/503) remote: Counting objects: 57% (287/503) remote: Counting objects: 58% (292/503) remote: Counting objects: 59% (297/503) remote: Counting objects: 60% (302/503) remote: Counting objects: 61% (307/503) remote: Counting objects: 62% (312/503) remote: Counting objects: 63% (317/503) remote: Counting objects: 64% (322/503) remote: Counting objects: 65% (327/503) remote: Counting objects: 66% (332/503) remote: Counting objects: 67% (338/503) remote: Counting objects: 68% (343/503) remote: Counting objects: 69% (348/503) remote: Counting objects: 70% (353/503) remote: Counting objects: 71% (358/503) remote: Counting objects: 72% (363/503) remote: Counting objects: 73% (368/503) remote: Counting objects: 74% (373/503) remote: Counting objects: 75% (378/503) remote: Counting objects: 76% (383/503) remote: Counting objects: 77% (388/503) remote: Counting objects: 78% (393/503) remote: Counting objects: 79% (398/503) remote: Counting objects: 80% (403/503) remote: Counting objects: 81% (408/503) remote: Counting objects: 82% (413/503) remote: Counting objects: 83% (418/503) remote: Counting objects: 84% (423/503) remote: Counting objects: 85% (428/503) remote: Counting objects: 86% (433/503) remote: Counting objects: 87% (438/503) remote: Counting objects: 88% (443/503) remote: Counting objects: 89% (448/503) remote: Counting objects: 90% (453/503) remote: Counting objects: 91% (458/503) remote: Counting objects: 92% (463/503) remote: Counting objects: 93% (468/503) remote: Counting objects: 94% (473/503) remote: Counting objects: 95% (478/503) remote: Counting objects: 96% (483/503) remote: Counting objects: 97% (488/503) remote: Counting objects: 98% (493/503) remote: Counting objects: 99% (498/503) remote: Counting objects: 100% (503/503) remote: Counting objects: 100% (503/503), done. remote: Compressing objects: 0% (1/260) remote: Compressing objects: 1% (3/260) remote: Compressing objects: 2% (6/260) remote: Compressing objects: 3% (8/260) remote: Compressing objects: 4% (11/260) remote: Compressing objects: 5% (13/260) remote: Compressing objects: 6% (16/260) remote: Compressing objects: 7% (19/260) remote: Compressing objects: 8% (21/260) remote: Compressing objects: 9% (24/260) remote: Compressing objects: 10% (26/260) remote: Compressing objects: 11% (29/260) remote: Compressing objects: 12% (32/260) remote: Compressing objects: 13% (34/260) remote: Compressing objects: 14% (37/260) remote: Compressing objects: 15% (39/260) remote: Compressing objects: 16% (42/260) remote: Compressing objects: 17% (45/260) remote: Compressing objects: 18% (47/260) remote: Compressing objects: 19% (50/260) remote: Compressing objects: 20% (52/260) remote: Compressing objects: 21% (55/260) remote: Compressing objects: 22% (58/260) remote: Compressing objects: 23% (60/260) remote: Compressing objects: 24% (63/260) remote: Compressing objects: 25% (65/260) remote: Compressing objects: 26% (68/260) remote: Compressing objects: 27% (71/260) remote: Compressing objects: 28% (73/260) remote: Compressing objects: 29% (76/260) remote: Compressing objects: 30% (78/260) remote: Compressing objects: 31% (81/260) remote: Compressing objects: 32% (84/260) remote: Compressing objects: 33% (86/260) remote: Compressing objects: 34% (89/260) remote: Compressing objects: 35% (91/260) remote: Compressing objects: 36% (94/260) remote: Compressing objects: 37% (97/260) remote: Compressing objects: 38% (99/260) remote: Compressing objects: 39% (102/260) remote: Compressing objects: 40% (104/260) remote: Compressing objects: 41% (107/260) remote: Compressing objects: 42% (110/260) remote: Compressing objects: 43% (112/260) remote: Compressing objects: 44% (115/260) remote: Compressing objects: 45% (117/260) remote: Compressing objects: 46% (120/260) remote: Compressing objects: 47% (123/260) remote: Compressing objects: 48% (125/260) remote: Compressing objects: 49% (128/260) remote: Compressing objects: 50% (130/260) remote: Compressing objects: 51% (133/260) remote: Compressing objects: 52% (136/260) remote: Compressing objects: 53% (138/260) remote: Compressing objects: 54% (141/260) remote: Compressing objects: 55% (143/260) remote: Compressing objects: 56% (146/260) remote: Compressing objects: 57% (149/260) remote: Compressing objects: 58% (151/260) remote: Compressing objects: 59% (154/260) remote: Compressing objects: 60% (156/260) remote: Compressing objects: 61% (159/260) remote: Compressing objects: 62% (162/260) remote: Compressing objects: 63% (164/260) remote: Compressing objects: 64% (167/260) remote: Compressing objects: 65% (169/260) remote: Compressing objects: 66% (172/260) remote: Compressing objects: 67% (175/260) remote: Compressing objects: 68% (177/260) remote: Compressing objects: 69% (180/260) remote: Compressing objects: 70% (182/260) remote: Compressing objects: 71% (185/260) remote: Compressing objects: 72% (188/260) remote: Compressing objects: 73% (190/260) remote: Compressing objects: 74% (193/260) remote: Compressing objects: 75% (195/260) remote: Compressing objects: 76% (198/260) remote: Compressing objects: 77% (201/260) remote: Compressing objects: 78% (203/260) remote: Compressing objects: 79% (206/260) remote: Compressing objects: 80% (208/260) remote: Compressing objects: 81% (211/260) remote: Compressing objects: 82% (214/260) remote: Compressing objects: 83% (216/260) remote: Compressing objects: 84% (219/260) remote: Compressing objects: 85% (221/260) remote: Compressing objects: 86% (224/260) remote: Compressing objects: 87% (227/260) remote: Compressing objects: 88% (229/260) remote: Compressing objects: 89% (232/260) remote: Compressing objects: 90% (234/260) remote: Compressing objects: 91% (237/260) remote: Compressing objects: 92% (240/260) remote: Compressing objects: 93% (242/260) remote: Compressing objects: 94% (245/260) remote: Compressing objects: 95% (247/260) remote: Compressing objects: 96% (250/260) remote: Compressing objects: 97% (253/260) remote: Compressing objects: 98% (255/260) remote: Compressing objects: 99% (258/260) remote: Compressing objects: 100% (260/260) remote: Compressing objects: 100% (260/260), done. Receiving objects: 0% (1/503) Receiving objects: 1% (6/503) Receiving objects: 2% (11/503) Receiving objects: 3% (16/503) Receiving objects: 4% (21/503) Receiving objects: 5% (26/503) Receiving objects: 6% (31/503) Receiving objects: 7% (36/503) Receiving objects: 8% (41/503) Receiving objects: 9% (46/503) Receiving objects: 10% (51/503) Receiving objects: 11% (56/503) Receiving objects: 12% (61/503) Receiving objects: 13% (66/503) Receiving objects: 14% (71/503) Receiving objects: 15% (76/503) Receiving objects: 16% (81/503) Receiving objects: 17% (86/503) Receiving objects: 18% (91/503) Receiving objects: 19% (96/503) Receiving objects: 20% (101/503) Receiving objects: 21% (106/503) Receiving objects: 22% (111/503) Receiving objects: 23% (116/503) Receiving objects: 24% (121/503) Receiving objects: 25% (126/503) Receiving objects: 26% (131/503) Receiving objects: 27% (136/503) Receiving objects: 28% (141/503) Receiving objects: 29% (146/503) Receiving objects: 30% (151/503) Receiving objects: 31% (156/503) Receiving objects: 32% (161/503) Receiving objects: 33% (166/503) Receiving objects: 34% (172/503) Receiving objects: 35% (177/503) Receiving objects: 36% (182/503) Receiving objects: 37% (187/503) Receiving objects: 38% (192/503) Receiving objects: 39% (197/503) Receiving objects: 40% (202/503) Receiving objects: 41% (207/503) Receiving objects: 42% (212/503) Receiving objects: 43% (217/503) Receiving objects: 44% (222/503) Receiving objects: 45% (227/503) Receiving objects: 46% (232/503) Receiving objects: 47% (237/503) Receiving objects: 48% (242/503) Receiving objects: 49% (247/503) Receiving objects: 50% (252/503) Receiving objects: 51% (257/503) Receiving objects: 52% (262/503) Receiving objects: 53% (267/503) Receiving objects: 54% (272/503) Receiving objects: 55% (277/503) Receiving objects: 56% (282/503) Receiving objects: 57% (287/503) Receiving objects: 58% (292/503) Receiving objects: 59% (297/503) Receiving objects: 60% (302/503) Receiving objects: 61% (307/503) Receiving objects: 62% (312/503) Receiving objects: 63% (317/503) Receiving objects: 64% (322/503) Receiving objects: 65% (327/503) Receiving objects: 66% (332/503) remote: Total 503 (delta 250), reused 460 (delta 215), pack-reused 0 Receiving objects: 67% (338/503) Receiving objects: 68% (343/503) Receiving objects: 69% (348/503) Receiving objects: 70% (353/503) Receiving objects: 71% (358/503) Receiving objects: 72% (363/503) Receiving objects: 73% (368/503) Receiving objects: 74% (373/503) Receiving objects: 75% (378/503) Receiving objects: 76% (383/503) Receiving objects: 77% (388/503) Receiving objects: 78% (393/503) Receiving objects: 79% (398/503) Receiving objects: 80% (403/503) Receiving objects: 81% (408/503) Receiving objects: 82% (413/503) Receiving objects: 83% (418/503) Receiving objects: 84% (423/503) Receiving objects: 85% (428/503) Receiving objects: 86% (433/503) Receiving objects: 87% (438/503) Receiving objects: 88% (443/503) Receiving objects: 89% (448/503) Receiving objects: 90% (453/503) Receiving objects: 91% (458/503) Receiving objects: 92% (463/503) Receiving objects: 93% (468/503) Receiving objects: 94% (473/503) Receiving objects: 95% (478/503) Receiving objects: 96% (483/503) Receiving objects: 97% (488/503) Receiving objects: 98% (493/503) Receiving objects: 99% (498/503) Receiving objects: 100% (503/503) Receiving objects: 100% (503/503), 69.83 KiB | 2.00 MiB/s, done. Resolving deltas: 0% (0/250) Resolving deltas: 1% (3/250) Resolving deltas: 2% (5/250) Resolving deltas: 3% (8/250) Resolving deltas: 4% (10/250) Resolving deltas: 5% (13/250) Resolving deltas: 6% (15/250) Resolving deltas: 7% (18/250) Resolving deltas: 8% (20/250) Resolving deltas: 9% (23/250) Resolving deltas: 10% (25/250) Resolving deltas: 11% (28/250) Resolving deltas: 12% (30/250) Resolving deltas: 13% (33/250) Resolving deltas: 14% (35/250) Resolving deltas: 15% (38/250) Resolving deltas: 16% (40/250) Resolving deltas: 17% (43/250) Resolving deltas: 18% (45/250) Resolving deltas: 19% (48/250) Resolving deltas: 20% (50/250) Resolving deltas: 21% (53/250) Resolving deltas: 22% (55/250) Resolving deltas: 23% (58/250) Resolving deltas: 24% (60/250) Resolving deltas: 25% (63/250) Resolving deltas: 26% (65/250) Resolving deltas: 27% (68/250) Resolving deltas: 28% (70/250) Resolving deltas: 29% (73/250) Resolving deltas: 30% (75/250) Resolving deltas: 31% (78/250) Resolving deltas: 32% (80/250) Resolving deltas: 33% (83/250) Resolving deltas: 34% (85/250) Resolving deltas: 35% (88/250) Resolving deltas: 36% (90/250) Resolving deltas: 37% (93/250) Resolving deltas: 38% (95/250) Resolving deltas: 39% (98/250) Resolving deltas: 40% (100/250) Resolving deltas: 41% (103/250) Resolving deltas: 42% (105/250) Resolving deltas: 43% (108/250) Resolving deltas: 44% (110/250) Resolving deltas: 45% (113/250) Resolving deltas: 46% (115/250) Resolving deltas: 47% (118/250) Resolving deltas: 48% (120/250) Resolving deltas: 49% (123/250) Resolving deltas: 50% (125/250) Resolving deltas: 51% (128/250) Resolving deltas: 52% (130/250) Resolving deltas: 53% (133/250) Resolving deltas: 54% (135/250) Resolving deltas: 55% (138/250) Resolving deltas: 56% (140/250) Resolving deltas: 57% (143/250) Resolving deltas: 58% (145/250) Resolving deltas: 59% (148/250) Resolving deltas: 60% (150/250) Resolving deltas: 61% (153/250) Resolving deltas: 62% (155/250) Resolving deltas: 63% (158/250) Resolving deltas: 64% (160/250) Resolving deltas: 65% (163/250) Resolving deltas: 66% (165/250) Resolving deltas: 67% (168/250) Resolving deltas: 68% (170/250) Resolving deltas: 69% (173/250) Resolving deltas: 70% (175/250) Resolving deltas: 71% (178/250) Resolving deltas: 72% (180/250) Resolving deltas: 73% (183/250) Resolving deltas: 74% (186/250) Resolving deltas: 75% (188/250) Resolving deltas: 76% (190/250) Resolving deltas: 77% (193/250) Resolving deltas: 78% (195/250) Resolving deltas: 79% (198/250) Resolving deltas: 80% (200/250) Resolving deltas: 81% (203/250) Resolving deltas: 82% (205/250) Resolving deltas: 83% (208/250) Resolving deltas: 84% (210/250) Resolving deltas: 85% (213/250) Resolving deltas: 86% (215/250) Resolving deltas: 87% (218/250) Resolving deltas: 88% (220/250) Resolving deltas: 89% (223/250) Resolving deltas: 90% (225/250) Resolving deltas: 91% (228/250) Resolving deltas: 92% (230/250) Resolving deltas: 93% (233/250) Resolving deltas: 94% (235/250) Resolving deltas: 95% (238/250) Resolving deltas: 96% (240/250) Resolving deltas: 97% (243/250) Resolving deltas: 98% (245/250) Resolving deltas: 99% (248/250) Resolving deltas: 100% (250/250) Resolving deltas: 100% (250/250), done. travis_time:end:0085b528:start=1709113187527771881,finish=1709113187985673197,duration=457901316,event=checkout $ cd travis-ci/marginalia $ git checkout -qf 4ebafa6a386faa08d5e35e65ce3ac951b2aa4c2b travis_fold:end:git.checkout  travis_time:end:0085b528:start=1709113187527771881,finish=1709113187991594500,duration=463822619,event=checkout travis_time:start:21f6860a  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:21f6860a:start=1709113187994732368,finish=1709113188001571802,duration=6839434,event=env travis_fold:start:rvm travis_time:start:0983f4ca $ 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:0983f4ca:start=1709113188010455665,finish=1709113190750891186,duration=2740435521,event= travis_time:start:16ff82f3 $ 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 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 29.2M 100 29.2M 0 0 16.9M 0 0:00:01 0:00:01 --:--:-- 16.9M 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:16ff82f3:start=1709113190755379843,finish=1709113213677423878,duration=22922044035,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:1ad95a60 $ bash -c "yes | gem uninstall -i /home/travis/.rvm/gems/ruby-3.2.0@global rake" Gem 'rake' is not installed travis_time:end:1ad95a60:start=1709113214137297274,finish=1709113214309141757,duration=171844483,event=before_install travis_fold:end:before_install travis_fold:start:install.bundler travis_time:start:001c6137 $ 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 Installing mutex_m 0.2.0 Fetching timeout 0.4.1 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 pg 1.5.5 with native extensions Installing drb 2.2.0 Fetching mocha 2.1.0 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 Fetching activemodel 7.1.3.2 Installing sequel 5.77.0 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:001c6137:start=1709113214314816179,finish=1709113231131039013,duration=16816222834,event=install travis_fold:end:install.bundler  travis_fold:start:before_script travis_time:start:288ffc7e $ sudo chmod 0644 $MARGINALIA_LOG_FILE travis_time:end:288ffc7e:start=1709113231136347774,finish=1709113231145656313,duration=9308539,event=before_script travis_fold:end:before_script travis_time:start:18a2da98 $ 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 6870 # Running: A.EXEC "select * from posts;" AE COMMENT: "/*adapter:pg,app:async_exec*/" .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*/" .EXEC "select * from posts;" EXEC COMMENT: "/*adapter:pg,app:foobar*/" .A.QUERY "select * from posts;" AQ COMMENT: "/*adapter:pg,app:async_query*/" .PREP "INSERT INTO posts (id, title) VALUES ($1, $2)" PREP COMMENT: "/*adapter:pg,app:prepare*/" .QUERY "select * from posts;" Q COMMENT: "/*adapter:pg,app:query*/" . Finished in 0.005352s, 1121.1646 runs/s, 1494.8862 assertions/s. 6 runs, 8 assertions, 0 failures, 0 errors, 0 skips Run options: --seed 50607 # Running: .. Finished in 0.000923s, 2166.9576 runs/s, 3250.4364 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.0076s 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 26233 # Running: ALL1 ALL1-- 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.024603s, 81.2904 runs/s, 121.9356 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:72: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:18a2da98:start=1709113231150594497,finish=1709113233211939034,duration=2061344537,event=script The command "bundle exec rake db:reset test:postgresql" exited with 1. travis_time:start:12dc0956 $ cat $MARGINALIA_LOG_FILE 2024-02-28 09:39:45.000 UTC [5022] LOG: listening on IPv4 address "127.0.0.1", port 5432 2024-02-28 09:39:45.000 UTC [5022] LOG: listening on IPv4 address "127.0.1.1", port 5432 2024-02-28 09:39:45.000 UTC [5022] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432" 2024-02-28 09:39:45.021 UTC [5031] LOG: database system was shut down at 2024-02-01 08:57:39 UTC 2024-02-28 09:39:45.027 UTC [5022] LOG: database system is ready to accept connections 2024-02-28 09:39:45.559 UTC [5039] [unknown]@[unknown] LOG: incomplete startup packet 2024-02-28 09:39:47.169 UTC [5052] postgres@postgres ERROR: role "travis" already exists 2024-02-28 09:39:47.169 UTC [5052] postgres@postgres STATEMENT: CREATE ROLE travis SUPERUSER CREATEDB CREATEROLE INHERIT LOGIN; 2024-02-28 09:40:32.082 UTC [9542] travis@marginalia_test LOG: statement: DROP TABLE IF EXISTS posts; /**/ 2024-02-28 09:40:32.083 UTC [9542] travis@marginalia_test LOG: statement: CREATE TABLE posts ( id INTEGER, title VARCHAR ); /**/ 2024-02-28 09:40:32.091 UTC [9542] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:async_exec*/ 2024-02-28 09:40:32.092 UTC [9542] travis@marginalia_test LOG: statement: INSERT INTO POSTS VALUES (1, 'My Title') /*adapter:pg,app:crud.insert*/ 2024-02-28 09:40:32.093 UTC [9542] travis@marginalia_test LOG: statement: UPDATE posts SET id = 2 where id = 1 /*adapter:pg,app:crud.update*/ 2024-02-28 09:40:32.093 UTC [9542] travis@marginalia_test LOG: statement: DELETE FROM POSTS where id = 2 /*adapter:pg,app:crud.delete*/ 2024-02-28 09:40:32.094 UTC [9542] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:foobar*/ 2024-02-28 09:40:32.094 UTC [9542] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:async_query*/ 2024-02-28 09:40:32.095 UTC [9542] travis@marginalia_test LOG: execute statement1: INSERT INTO posts (id, title) VALUES ($1, $2) /*adapter:pg,app:prepare*/ 2024-02-28 09:40:32.095 UTC [9542] travis@marginalia_test DETAIL: parameters: $1 = '100', $2 = 'Welcome Tessa!' 2024-02-28 09:40:32.095 UTC [9542] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:query*/ 2024-02-28 09:40:33.150 UTC [9560] travis@marginalia_test LOG: statement: DROP TABLE IF EXISTS posts; /**/ 2024-02-28 09:40:33.155 UTC [9560] travis@marginalia_test LOG: statement: SHOW max_identifier_length /**/ 2024-02-28 09:40:33.156 UTC [9560] travis@marginalia_test LOG: statement: DROP TABLE IF EXISTS "posts" /**/ 2024-02-28 09:40:33.156 UTC [9560] travis@marginalia_test LOG: statement: CREATE TABLE "posts" ("id" bigserial primary key, "title" character varying) /**/ 2024-02-28 09:40:33.161 UTC [9560] 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:40:33.162 UTC [9560] travis@marginalia_test LOG: statement: CREATE TABLE "schema_migrations" ("version" character varying NOT NULL PRIMARY KEY) /**/ 2024-02-28 09:40:33.164 UTC [9560] 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:40:33.165 UTC [9560] 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:40:33.167 UTC [9560] 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:40:33.167 UTC [9560] travis@marginalia_test DETAIL: parameters: $1 = 'environment' 2024-02-28 09:40:33.170 UTC [9560] travis@marginalia_test LOG: execute : INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ('environment', 'test', '2024-02-28 09:40:33.169476', '2024-02-28 09:40:33.169481') RETURNING "key" 2024-02-28 09:40:33.180 UTC [9560] travis@marginalia_test LOG: execute : SELECT "posts".* FROM "posts" 2024-02-28 09:40:33.182 UTC [9560] 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:40:33.184 UTC [9560] 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:40:33.185 UTC [9560] 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:40:33.191 UTC [9560] travis@marginalia_test LOG: statement: BEGIN /*adapter:active_record,app:crud.insert*/ 2024-02-28 09:40:33.192 UTC [9560] travis@marginalia_test LOG: execute : INSERT INTO "posts" ("title") VALUES ($1) RETURNING "id" 2024-02-28 09:40:33.192 UTC [9560] travis@marginalia_test DETAIL: parameters: $1 = 'foo' 2024-02-28 09:40:33.192 UTC [9560] travis@marginalia_test LOG: statement: COMMIT /*adapter:active_record,app:crud.insert*/ 2024-02-28 09:40:33.194 UTC [9560] travis@marginalia_test LOG: statement: SHOW search_path /*adapter:active_record,app:crud.update*/ 2024-02-28 09:40:33.195 UTC [9560] 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:40:33.195 UTC [9560] travis@marginalia_test DETAIL: parameters: $1 = '1', $2 = '1' 2024-02-28 09:40:33.196 UTC [9560] travis@marginalia_test LOG: statement: BEGIN /*adapter:active_record,app:crud.update*/ 2024-02-28 09:40:33.197 UTC [9560] travis@marginalia_test LOG: execute : UPDATE "posts" SET "title" = $1 WHERE "posts"."id" = $2 2024-02-28 09:40:33.197 UTC [9560] travis@marginalia_test DETAIL: parameters: $1 = 'bar', $2 = '1' 2024-02-28 09:40:33.197 UTC [9560] travis@marginalia_test LOG: statement: COMMIT /*adapter:active_record,app:crud.update*/ 2024-02-28 09:40:33.198 UTC [9560] 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:40:33.198 UTC [9560] travis@marginalia_test DETAIL: parameters: $1 = '1', $2 = '1' 2024-02-28 09:40:33.199 UTC [9560] travis@marginalia_test LOG: statement: BEGIN /*adapter:active_record,app:crud.delete*/ 2024-02-28 09:40:33.199 UTC [9560] travis@marginalia_test LOG: execute : DELETE FROM "posts" WHERE "posts"."id" = $1 2024-02-28 09:40:33.199 UTC [9560] travis@marginalia_test DETAIL: parameters: $1 = '1' 2024-02-28 09:40:33.199 UTC [9560] travis@marginalia_test LOG: statement: COMMIT /*adapter:active_record,app:crud.delete*/ travis_time:end:12dc0956:start=1709113233217072773,finish=1709113233222016525,duration=4943752,event=script The command "cat $MARGINALIA_LOG_FILE" exited with 0. Done. Your build exited with 1.