travis_fold:start:worker_info [0K[33;1mWorker information[0m hostname: 46b0161d-cfc6-47a7-b268-0b90131795be@1.worker-n2-com-779d777f7b-rxlft.gce-production-1 version: 6.2.22 https://github.com/travis-ci/worker/tree/858cb91994a513269f2fe9782c15fc113e966231 instance: travis-job-67cd1237-6c49-4c25-b095-83e27ec025fc travis-ci-ubuntu-1804-1706776257-3d36ff62 (via amqp) startup: 6.301728762s travis_fold:end:worker_info [0Ktravis_time:start:27adc5b6 [0Ktravis_time:end:27adc5b6:start=1709111452526011670,finish=1709111452729688352,duration=203676682,event=no_world_writable_dirs [0Ktravis_time:start:1a335188 [0Ktravis_time:end:1a335188:start=1709111452732840921,finish=1709111452740592301,duration=7751380,event=agent [0Ktravis_time:start:0113da84 [0Ktravis_time:end:0113da84:start=1709111452743553022,finish=1709111452745674716,duration=2121694,event=check_unsupported [0Ktravis_time:start:05627f05 [0Ktravis_fold:start:system_info [0K[33;1mBuild system information[0m Build language: ruby Build dist: bionic Build id: 269163264 Job id: 618438017 Runtime kernel version: 5.4.0-1106-gcp travis-build version: f3de9fb7 [34m[1mBuild image provisioning date and time[0m Thu Feb 1 09:04:40 UTC 2024 [34m[1mOperating System Details[0m Distributor ID: Ubuntu Description: Ubuntu 18.04.6 LTS Release: 18.04 Codename: bionic [34m[1mSystemd Version[0m systemd 237 [34m[1mCookbooks Version[0m 4a0cff6 https://github.com/travis-ci/travis-cookbooks/tree/4a0cff6 [34m[1mgit version[0m git version 2.43.0 [34m[1mbash version[0m GNU bash, version 4.4.20(1)-release (x86_64-pc-linux-gnu) [34m[1mgcc version[0m gcc (Ubuntu 7.5.0-3ubuntu1~18.04) 7.5.0 [34m[1mdocker version[0m 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: [34m[1mclang version[0m clang version 16.0.0 [34m[1mjq version[0m jq-1.7 [34m[1mbats version[0m Bats 0.4.0 [34m[1mshellcheck version[0m 0.9.0 [34m[1mshfmt version[0m v3.7.0 [34m[1mccache version[0m 3.4.1 [34m[1mcmake version[0m cmake version 3.26.3 [34m[1mheroku version[0m heroku/8.7.1 linux-x64 node-v16.19.0 [34m[1mimagemagick version[0m Version: ImageMagick 6.9.7-4 Q16 x86_64 20170114 http://www.imagemagick.org [34m[1mmd5deep version[0m 4.4 [34m[1mmercurial version[0m version 5.3 [34m[1mmysql version[0m mysql Ver 14.14 Distrib 5.7.42, for Linux (x86_64) using EditLine wrapper [34m[1mopenssl version[0m OpenSSL 1.1.1 11 Sep 2018 [34m[1mpacker version[0m 1.9.4 [34m[1mpostgresql client version[0m psql (PostgreSQL) 11.20 (Ubuntu 11.20-1.pgdg18.04+1) [34m[1mragel version[0m Ragel State Machine Compiler version 6.10 March 2017 [34m[1msudo version[0m 1.8.21p2 [34m[1mgzip version[0m gzip 1.6 [34m[1mzip version[0m Zip 3.0 [34m[1mvim version[0m VIM - Vi IMproved 8.0 (2016 Sep 12, compiled Apr 18 2023 09:20:34) [34m[1miptables version[0m iptables v1.6.1 [34m[1mcurl version[0m 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 [34m[1mwget version[0m GNU Wget 1.19.4 built on linux-gnu. [34m[1mrsync version[0m rsync version 3.1.2 protocol version 31 [34m[1mgimme version[0m v1.5.4 [34m[1mnvm version[0m 0.39.7 [34m[1mperlbrew version[0m /home/travis/perl5/perlbrew/bin/perlbrew - App::perlbrew/0.95 [34m[1mphpenv version[0m rbenv 1.2.0 [34m[1mrvm version[0m rvm 1.29.12 (latest) by Michal Papis, Piotr Kuczynski, Wayne E. Seguin [https://rvm.io] [34m[1mdefault ruby version[0m ruby 2.7.6p219 (2022-04-12 revision c9c2245c0a) [x86_64-linux] [34m[1mdefault python version[0m Python 3.7.17 [34m[1mElasticSearch version[0m 7.16.3 [34m[1mInstalled Firefox version[0m firefox 63.0.1 [34m[1mMongoDB version[0m MongoDB 4.4.28 [34m[1mPhantomJS version[0m 2.1.1 [34m[1mPre-installed PostgreSQL versions[0m 9.3.25 9.4.26 9.5.25 9.6.24 [34m[1mRedis version[0m redis-server 7.2.4 [34m[1mPre-installed Go versions[0m 1.11.1 [34m[1mmvn version[0m Apache Maven 3.9.4 (dfbb324ad4a7c8fb0bf182e6d91b0ae20e3d2dd9) [34m[1mgradle version[0m Gradle 8.3! [34m[1mlein version[0m Leiningen 2.11.1 on Java 11.0.21 OpenJDK 64-Bit Server VM [34m[1mPre-installed Node.js versions[0m 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 [34m[1mphpenv versions[0m 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 [34m[1mcomposer --version[0m Composer version 1.9.2 2020-01-14 16:30:31 [34m[1mPre-installed Ruby versions[0m ruby-2.5.9 ruby-2.7.6 ruby-3.1.2 travis_fold:end:system_info [0K travis_time:end:05627f05:start=1709111452748514338,finish=1709111452761261527,duration=12747189,event=show_system_info [0Ktravis_time:start:00468bd6 [0Ktravis_time:end:00468bd6:start=1709111452765848861,finish=1709111452782392431,duration=16543570,event=rm_riak_source [0Ktravis_time:start:26a15f0c [0Ktravis_time:end:26a15f0c:start=1709111452785623184,finish=1709111452794470855,duration=8847671,event=fix_rwky_redis [0Ktravis_time:start:1554696f [0Ktravis_time:end:1554696f:start=1709111452797678013,finish=1709111453501452927,duration=703774914,event=wait_for_network [0Ktravis_time:start:00108e03 [0Ktravis_time:end:00108e03:start=1709111453504360629,finish=1709111453845922160,duration=341561531,event=update_apt_keys [0Ktravis_time:start:03367b5a [0Ktravis_time:end:03367b5a:start=1709111453848887660,finish=1709111453902859032,duration=53971372,event=fix_hhvm_source [0Ktravis_time:start:00d17e78 [0Ktravis_time:end:00d17e78:start=1709111453905840974,finish=1709111453908268343,duration=2427369,event=update_mongo_arch [0Ktravis_time:start:0c9977ba [0Ktravis_time:end:0c9977ba:start=1709111453910882071,finish=1709111453950694767,duration=39812696,event=fix_sudo_enabled_trusty [0Ktravis_time:start:12cc55b4 [0Ktravis_time:end:12cc55b4:start=1709111453953619614,finish=1709111453955667809,duration=2048195,event=update_glibc [0Ktravis_time:start:10f30299 [0Ktravis_time:end:10f30299:start=1709111453958342504,finish=1709111453965840961,duration=7498457,event=clean_up_path [0Ktravis_time:start:0bc64db0 [0Ktravis_time:end:0bc64db0:start=1709111453968542494,finish=1709111453976922955,duration=8380461,event=fix_resolv_conf [0Ktravis_time:start:023e1e80 [0Ktravis_time:end:023e1e80:start=1709111453979681967,finish=1709111454016497259,duration=36815292,event=fix_etc_hosts [0Ktravis_time:start:08434ad9 [0Ktravis_time:end:08434ad9:start=1709111454019362583,finish=1709111454026927267,duration=7564684,event=fix_mvn_settings_xml [0Ktravis_time:start:05978d4c [0Ktravis_time:end:05978d4c:start=1709111454029626656,finish=1709111454038629435,duration=9002779,event=no_ipv6_localhost [0Ktravis_time:start:01e7ca04 [0Ktravis_time:end:01e7ca04:start=1709111454041316573,finish=1709111454043287226,duration=1970653,event=fix_etc_mavenrc [0Ktravis_time:start:0a341942 [0KOK travis_time:end:0a341942:start=1709111454045923477,finish=1709111454423789267,duration=377865790,event=fix_perforce_key [0Ktravis_time:start:0c4c7c10 [0Ktravis_time:end:0c4c7c10:start=1709111454426741494,finish=1709111454429437670,duration=2696176,event=fix_wwdr_certificate [0Ktravis_time:start:0f0c7767 [0Ktravis_time:end:0f0c7767:start=1709111454432089272,finish=1709111454510705260,duration=78615988,event=put_localhost_first [0Ktravis_time:start:08350140 [0Ktravis_time:end:08350140:start=1709111454513737008,finish=1709111454516686228,duration=2949220,event=home_paths [0Ktravis_time:start:0389e138 [0Ktravis_time:end:0389e138:start=1709111454519527548,finish=1709111454531742874,duration=12215326,event=disable_initramfs [0Ktravis_time:start:125d9962 [0Ktravis_time:end:125d9962:start=1709111454534551605,finish=1709111454688403224,duration=153851619,event=disable_ssh_roaming [0Ktravis_time:start:19813d38 [0Ktravis_time:end:19813d38:start=1709111454691425793,finish=1709111454693605754,duration=2179961,event=debug_tools [0Ktravis_time:start:1a871a92 [0Ktravis_time:end:1a871a92:start=1709111454696480337,finish=1709111454699258148,duration=2777811,event=uninstall_oclint [0Ktravis_time:start:1cd11b7f [0Ktravis_time:end:1cd11b7f:start=1709111454702039448,finish=1709111454704726684,duration=2687236,event=rvm_use [0Ktravis_time:start:01efd940 [0Ktravis_time:end:01efd940:start=1709111454707481941,finish=1709111454715143500,duration=7661559,event=rm_etc_boto_cfg [0Ktravis_time:start:012a4668 [0Ktravis_time:end:012a4668:start=1709111454717932994,finish=1709111454720575036,duration=2642042,event=rm_oraclejdk8_symlink [0Ktravis_time:start:0a32fc2d [0Ktravis_time:end:0a32fc2d:start=1709111454723265564,finish=1709111454823853917,duration=100588353,event=enable_i386 [0Ktravis_time:start:094c3b80 [0Ktravis_time:end:094c3b80:start=1709111454826932607,finish=1709111454830822383,duration=3889776,event=update_rubygems [0Ktravis_time:start:0f82c9d8 [0Ktravis_time:end:0f82c9d8:start=1709111454833703603,finish=1709111455805457115,duration=971753512,event=ensure_path_components [0Ktravis_time:start:0639b0cd [0Ktravis_time:end:0639b0cd:start=1709111455808598682,finish=1709111455810745509,duration=2146827,event=redefine_curl [0Ktravis_time:start:0f8c559a [0Ktravis_time:end:0f8c559a:start=1709111455813553661,finish=1709111455815660869,duration=2107208,event=nonblock_pipe [0Ktravis_time:start:0a1c5daf [0Ktravis_time:end:0a1c5daf:start=1709111455818369036,finish=1709111461858869052,duration=6040500016,event=apt_get_update [0Ktravis_time:start:04586e26 [0Ktravis_time:end:04586e26:start=1709111461861797373,finish=1709111461863807166,duration=2009793,event=deprecate_xcode_64 [0Ktravis_time:start:04ba686f [0Ktravis_time:end:04ba686f:start=1709111461866328388,finish=1709111465767281822,duration=3900953434,event=update_heroku [0Ktravis_time:start:2803cc90 [0Ktravis_time:end:2803cc90:start=1709111465770179604,finish=1709111465772158564,duration=1978960,event=shell_session_update [0Ktravis_time:start:096ebf14 [0Ktravis_fold:start:docker_mtu_and_registry_mirrors [0Ktravis_fold:end:docker_mtu_and_registry_mirrors [0Ktravis_time:end:096ebf14:start=1709111465774730106,finish=1709111468069617836,duration=2294887730,event=set_docker_mtu_and_registry_mirrors [0Ktravis_time:start:006921da [0Ktravis_fold:start:resolvconf [0Ktravis_fold:end:resolvconf [0Ktravis_time:end:006921da:start=1709111468072713837,finish=1709111468147517282,duration=74803445,event=resolvconf [0Ktravis_time:start:04912698 [0Ktravis_time:end:04912698:start=1709111468151319746,finish=1709111468297728218,duration=146408472,event=maven_central_mirror [0Ktravis_time:start:05c657dc [0Ktravis_time:end:05c657dc:start=1709111468300569254,finish=1709111468389802175,duration=89232921,event=maven_https [0Ktravis_fold:start:apt [0Ktravis_time:start:01e983b4 [0K$ travis_apt_get_update travis_time:end:01e983b4:start=1709111468393407844,finish=1709111480932524132,duration=12539116288,event=prepare [0K[33;1mInstalling APT Packages[0m [33;1mPostgreSQL package is detected. Stopping postgresql service. See https://github.com/travis-ci/travis-ci/issues/5737 for more information.[0m $ sudo systemctl stop postgresql travis_time:start:0256164b [0K$ 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:0256164b:start=1709111480975022203,finish=1709111481818787282,duration=843765079,event=prepare [0Ktravis_fold:end:apt [0Ktravis_time:start:0012fbf1 [0Ktravis_fold:start:services [0Ktravis_fold:end:services [0Ktravis_time:end:0012fbf1:start=1709111481822099999,finish=1709111484827574373,duration=3005474374,event=services [0Ktravis_time:start:0ce293f8 [0Ktravis_time:end:0ce293f8:start=1709111484830764109,finish=1709111484832977102,duration=2212993,event=fix_ps4 [0Ktravis_fold:start:postgresql [0Ktravis_time:start:01c86cae [0K$ travis_setup_postgresql 11 [33;1mStarting PostgreSQL v11[0K sudo systemctl start postgresql@11-main travis_time:end:01c86cae:start=1709111484836200550,finish=1709111488042215481,duration=3206014931,event=prepare [0Ktravis_fold:end:postgresql [0Ktravis_time:start:09638403 [0K travis_fold:start:git.checkout [0Ktravis_time:start:141df975 [0Ktravis_time:end:141df975:start=1709111488048822909,finish=1709111488053880486,duration=5057577,event=checkout [0Ktravis_time:start:09599784 [0K$ 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: 554, done.[K remote: Counting objects: 0% (1/554)[K remote: Counting objects: 1% (6/554)[K remote: Counting objects: 2% (12/554)[K remote: Counting objects: 3% (17/554)[K remote: Counting objects: 4% (23/554)[K remote: Counting objects: 5% (28/554)[K remote: Counting objects: 6% (34/554)[K remote: Counting objects: 7% (39/554)[K remote: Counting objects: 8% (45/554)[K remote: Counting objects: 9% (50/554)[K remote: Counting objects: 10% (56/554)[K remote: Counting objects: 11% (61/554)[K remote: Counting objects: 12% (67/554)[K remote: Counting objects: 13% (73/554)[K remote: Counting objects: 14% (78/554)[K remote: Counting objects: 15% (84/554)[K remote: Counting objects: 16% (89/554)[K remote: Counting objects: 17% (95/554)[K remote: Counting objects: 18% (100/554)[K remote: Counting objects: 19% (106/554)[K remote: Counting objects: 20% (111/554)[K remote: Counting objects: 21% (117/554)[K remote: Counting objects: 22% (122/554)[K remote: Counting objects: 23% (128/554)[K remote: Counting objects: 24% (133/554)[K remote: Counting objects: 25% (139/554)[K remote: Counting objects: 26% (145/554)[K remote: Counting objects: 27% (150/554)[K remote: Counting objects: 28% (156/554)[K remote: Counting objects: 29% (161/554)[K remote: Counting objects: 30% (167/554)[K remote: Counting objects: 31% (172/554)[K remote: Counting objects: 32% (178/554)[K remote: Counting objects: 33% (183/554)[K remote: Counting objects: 34% (189/554)[K remote: Counting objects: 35% (194/554)[K remote: Counting objects: 36% (200/554)[K remote: Counting objects: 37% (205/554)[K remote: Counting objects: 38% (211/554)[K remote: Counting objects: 39% (217/554)[K remote: Counting objects: 40% (222/554)[K remote: Counting objects: 41% (228/554)[K remote: Counting objects: 42% (233/554)[K remote: Counting objects: 43% (239/554)[K remote: Counting objects: 44% (244/554)[K remote: Counting objects: 45% (250/554)[K remote: Counting objects: 46% (255/554)[K remote: Counting objects: 47% (261/554)[K remote: Counting objects: 48% (266/554)[K remote: Counting objects: 49% (272/554)[K remote: Counting objects: 50% (277/554)[K remote: Counting objects: 51% (283/554)[K remote: Counting objects: 52% (289/554)[K remote: Counting objects: 53% (294/554)[K remote: Counting objects: 54% (300/554)[K remote: Counting objects: 55% (305/554)[K remote: Counting objects: 56% (311/554)[K remote: Counting objects: 57% (316/554)[K remote: Counting objects: 58% (322/554)[K remote: Counting objects: 59% (327/554)[K remote: Counting objects: 60% (333/554)[K remote: Counting objects: 61% (338/554)[K remote: Counting objects: 62% (344/554)[K remote: Counting objects: 63% (350/554)[K remote: Counting objects: 64% (355/554)[K remote: Counting objects: 65% (361/554)[K remote: Counting objects: 66% (366/554)[K remote: Counting objects: 67% (372/554)[K remote: Counting objects: 68% (377/554)[K remote: Counting objects: 69% (383/554)[K remote: Counting objects: 70% (388/554)[K remote: Counting objects: 71% (394/554)[K remote: Counting objects: 72% (399/554)[K remote: Counting objects: 73% (405/554)[K remote: Counting objects: 74% (410/554)[K remote: Counting objects: 75% (416/554)[K remote: Counting objects: 76% (422/554)[K remote: Counting objects: 77% (427/554)[K remote: Counting objects: 78% (433/554)[K remote: Counting objects: 79% (438/554)[K remote: Counting objects: 80% (444/554)[K remote: Counting objects: 81% (449/554)[K remote: Counting objects: 82% (455/554)[K remote: Counting objects: 83% (460/554)[K remote: Counting objects: 84% (466/554)[K remote: Counting objects: 85% (471/554)[K remote: Counting objects: 86% (477/554)[K remote: Counting objects: 87% (482/554)[K remote: Counting objects: 88% (488/554)[K remote: Counting objects: 89% (494/554)[K remote: Counting objects: 90% (499/554)[K remote: Counting objects: 91% (505/554)[K remote: Counting objects: 92% (510/554)[K remote: Counting objects: 93% (516/554)[K remote: Counting objects: 94% (521/554)[K remote: Counting objects: 95% (527/554)[K remote: Counting objects: 96% (532/554)[K remote: Counting objects: 97% (538/554)[K remote: Counting objects: 98% (543/554)[K remote: Counting objects: 99% (549/554)[K remote: Counting objects: 100% (554/554)[K remote: Counting objects: 100% (554/554), done.[K remote: Compressing objects: 0% (1/293)[K remote: Compressing objects: 1% (3/293)[K remote: Compressing objects: 2% (6/293)[K remote: Compressing objects: 3% (9/293)[K remote: Compressing objects: 4% (12/293)[K remote: Compressing objects: 5% (15/293)[K remote: Compressing objects: 6% (18/293)[K remote: Compressing objects: 7% (21/293)[K remote: Compressing objects: 8% (24/293)[K remote: Compressing objects: 9% (27/293)[K remote: Compressing objects: 10% (30/293)[K remote: Compressing objects: 11% (33/293)[K remote: Compressing objects: 12% (36/293)[K remote: Compressing objects: 13% (39/293)[K remote: Compressing objects: 14% (42/293)[K remote: Compressing objects: 15% (44/293)[K remote: Compressing objects: 16% (47/293)[K remote: Compressing objects: 17% (50/293)[K remote: Compressing objects: 18% (53/293)[K remote: Compressing objects: 19% (56/293)[K remote: Compressing objects: 20% (59/293)[K remote: Compressing objects: 21% (62/293)[K remote: Compressing objects: 22% (65/293)[K remote: Compressing objects: 23% (68/293)[K remote: Compressing objects: 24% (71/293)[K remote: Compressing objects: 25% (74/293)[K remote: Compressing objects: 26% (77/293)[K remote: Compressing objects: 27% (80/293)[K remote: Compressing objects: 28% (83/293)[K remote: Compressing objects: 29% (85/293)[K remote: Compressing objects: 30% (88/293)[K remote: Compressing objects: 31% (91/293)[K remote: Compressing objects: 32% (94/293)[K remote: Compressing objects: 33% (97/293)[K remote: Compressing objects: 34% (100/293)[K remote: Compressing objects: 35% (103/293)[K remote: Compressing objects: 36% (106/293)[K remote: Compressing objects: 37% (109/293)[K remote: Compressing objects: 38% (112/293)[K remote: Compressing objects: 39% (115/293)[K remote: Compressing objects: 40% (118/293)[K remote: Compressing objects: 41% (121/293)[K remote: Compressing objects: 42% (124/293)[K remote: Compressing objects: 43% (126/293)[K remote: Compressing objects: 44% (129/293)[K remote: Compressing objects: 45% (132/293)[K remote: Compressing objects: 46% (135/293)[K remote: Compressing objects: 47% (138/293)[K remote: Compressing objects: 48% (141/293)[K remote: Compressing objects: 49% (144/293)[K remote: Compressing objects: 50% (147/293)[K remote: Compressing objects: 51% (150/293)[K remote: Compressing objects: 52% (153/293)[K remote: Compressing objects: 53% (156/293)[K remote: Compressing objects: 54% (159/293)[K remote: Compressing objects: 55% (162/293)[K remote: Compressing objects: 56% (165/293)[K remote: Compressing objects: 57% (168/293)[K remote: Compressing objects: 58% (170/293)[K remote: Compressing objects: 59% (173/293)[K remote: Compressing objects: 60% (176/293)[K remote: Compressing objects: 61% (179/293)[K remote: Compressing objects: 62% (182/293)[K remote: Compressing objects: 63% (185/293)[K remote: Compressing objects: 64% (188/293)[K remote: Compressing objects: 65% (191/293)[K remote: Compressing objects: 66% (194/293)[K remote: Compressing objects: 67% (197/293)[K remote: Compressing objects: 68% (200/293)[K remote: Compressing objects: 69% (203/293)[K remote: Compressing objects: 70% (206/293)[K remote: Compressing objects: 71% (209/293)[K remote: Compressing objects: 72% (211/293)[K remote: Compressing objects: 73% (214/293)[K remote: Compressing objects: 74% (217/293)[K remote: Compressing objects: 75% (220/293)[K remote: Compressing objects: 76% (223/293)[K remote: Compressing objects: 77% (226/293)[K remote: Compressing objects: 78% (229/293)[K remote: Compressing objects: 79% (232/293)[K remote: Compressing objects: 80% (235/293)[K remote: Compressing objects: 81% (238/293)[K remote: Compressing objects: 82% (241/293)[K remote: Compressing objects: 83% (244/293)[K remote: Compressing objects: 84% (247/293)[K remote: Compressing objects: 85% (250/293)[K remote: Compressing objects: 86% (252/293)[K remote: Compressing objects: 87% (255/293)[K remote: Compressing objects: 88% (258/293)[K remote: Compressing objects: 89% (261/293)[K remote: Compressing objects: 90% (264/293)[K remote: Compressing objects: 91% (267/293)[K remote: Compressing objects: 92% (270/293)[K remote: Compressing objects: 93% (273/293)[K remote: Compressing objects: 94% (276/293)[K remote: Compressing objects: 95% (279/293)[K remote: Compressing objects: 96% (282/293)[K remote: Compressing objects: 97% (285/293)[K remote: Compressing objects: 98% (288/293)[K remote: Compressing objects: 99% (291/293)[K remote: Compressing objects: 100% (293/293)[K remote: Compressing objects: 100% (293/293), done.[K Receiving objects: 0% (1/554) Receiving objects: 1% (6/554) Receiving objects: 2% (12/554) Receiving objects: 3% (17/554) Receiving objects: 4% (23/554) Receiving objects: 5% (28/554) Receiving objects: 6% (34/554) Receiving objects: 7% (39/554) Receiving objects: 8% (45/554) Receiving objects: 9% (50/554) Receiving objects: 10% (56/554) Receiving objects: 11% (61/554) Receiving objects: 12% (67/554) Receiving objects: 13% (73/554) Receiving objects: 14% (78/554) Receiving objects: 15% (84/554) Receiving objects: 16% (89/554) Receiving objects: 17% (95/554) Receiving objects: 18% (100/554) Receiving objects: 19% (106/554) Receiving objects: 20% (111/554) Receiving objects: 21% (117/554) Receiving objects: 22% (122/554) Receiving objects: 23% (128/554) Receiving objects: 24% (133/554) Receiving objects: 25% (139/554) Receiving objects: 26% (145/554) Receiving objects: 27% (150/554) Receiving objects: 28% (156/554) Receiving objects: 29% (161/554) Receiving objects: 30% (167/554) Receiving objects: 31% (172/554) Receiving objects: 32% (178/554) Receiving objects: 33% (183/554) Receiving objects: 34% (189/554) Receiving objects: 35% (194/554) Receiving objects: 36% (200/554) Receiving objects: 37% (205/554) Receiving objects: 38% (211/554) Receiving objects: 39% (217/554) Receiving objects: 40% (222/554) Receiving objects: 41% (228/554) Receiving objects: 42% (233/554) Receiving objects: 43% (239/554) Receiving objects: 44% (244/554) Receiving objects: 45% (250/554) Receiving objects: 46% (255/554) Receiving objects: 47% (261/554) Receiving objects: 48% (266/554) Receiving objects: 49% (272/554) Receiving objects: 50% (277/554) Receiving objects: 51% (283/554) Receiving objects: 52% (289/554) Receiving objects: 53% (294/554) Receiving objects: 54% (300/554) Receiving objects: 55% (305/554) Receiving objects: 56% (311/554) Receiving objects: 57% (316/554) Receiving objects: 58% (322/554) Receiving objects: 59% (327/554) Receiving objects: 60% (333/554) Receiving objects: 61% (338/554) Receiving objects: 62% (344/554) Receiving objects: 63% (350/554) Receiving objects: 64% (355/554) Receiving objects: 65% (361/554) Receiving objects: 66% (366/554) Receiving objects: 67% (372/554) Receiving objects: 68% (377/554) Receiving objects: 69% (383/554) remote: Total 554 (delta 276), reused 503 (delta 233), pack-reused 0[K Receiving objects: 70% (388/554) Receiving objects: 71% (394/554) Receiving objects: 72% (399/554) Receiving objects: 73% (405/554) Receiving objects: 74% (410/554) Receiving objects: 75% (416/554) Receiving objects: 76% (422/554) Receiving objects: 77% (427/554) Receiving objects: 78% (433/554) Receiving objects: 79% (438/554) Receiving objects: 80% (444/554) Receiving objects: 81% (449/554) Receiving objects: 82% (455/554) Receiving objects: 83% (460/554) Receiving objects: 84% (466/554) Receiving objects: 85% (471/554) Receiving objects: 86% (477/554) Receiving objects: 87% (482/554) Receiving objects: 88% (488/554) Receiving objects: 89% (494/554) Receiving objects: 90% (499/554) Receiving objects: 91% (505/554) Receiving objects: 92% (510/554) Receiving objects: 93% (516/554) Receiving objects: 94% (521/554) Receiving objects: 95% (527/554) Receiving objects: 96% (532/554) Receiving objects: 97% (538/554) Receiving objects: 98% (543/554) Receiving objects: 99% (549/554) Receiving objects: 100% (554/554) Receiving objects: 100% (554/554), 78.43 KiB | 2.31 MiB/s, done. Resolving deltas: 0% (0/276) Resolving deltas: 1% (3/276) Resolving deltas: 2% (6/276) Resolving deltas: 3% (9/276) Resolving deltas: 4% (12/276) Resolving deltas: 5% (14/276) Resolving deltas: 6% (17/276) Resolving deltas: 7% (20/276) Resolving deltas: 8% (23/276) Resolving deltas: 9% (25/276) Resolving deltas: 10% (28/276) Resolving deltas: 11% (31/276) Resolving deltas: 12% (34/276) Resolving deltas: 13% (36/276) Resolving deltas: 14% (39/276) Resolving deltas: 15% (42/276) Resolving deltas: 16% (45/276) Resolving deltas: 17% (47/276) Resolving deltas: 18% (50/276) Resolving deltas: 19% (53/276) Resolving deltas: 20% (56/276) Resolving deltas: 21% (58/276) Resolving deltas: 22% (61/276) Resolving deltas: 23% (64/276) Resolving deltas: 24% (67/276) Resolving deltas: 25% (69/276) Resolving deltas: 26% (72/276) Resolving deltas: 27% (75/276) Resolving deltas: 28% (78/276) Resolving deltas: 29% (81/276) Resolving deltas: 30% (83/276) Resolving deltas: 31% (86/276) Resolving deltas: 32% (89/276) Resolving deltas: 33% (92/276) Resolving deltas: 34% (94/276) Resolving deltas: 35% (97/276) Resolving deltas: 36% (100/276) Resolving deltas: 37% (103/276) Resolving deltas: 38% (105/276) Resolving deltas: 39% (108/276) Resolving deltas: 40% (111/276) Resolving deltas: 41% (114/276) Resolving deltas: 42% (116/276) Resolving deltas: 43% (119/276) Resolving deltas: 44% (122/276) Resolving deltas: 45% (125/276) Resolving deltas: 46% (127/276) Resolving deltas: 47% (130/276) Resolving deltas: 48% (133/276) Resolving deltas: 49% (136/276) Resolving deltas: 50% (138/276) Resolving deltas: 51% (141/276) Resolving deltas: 52% (144/276) Resolving deltas: 53% (147/276) Resolving deltas: 54% (150/276) Resolving deltas: 55% (152/276) Resolving deltas: 56% (155/276) Resolving deltas: 57% (158/276) Resolving deltas: 58% (161/276) Resolving deltas: 59% (163/276) Resolving deltas: 60% (166/276) Resolving deltas: 61% (169/276) Resolving deltas: 62% (172/276) Resolving deltas: 63% (174/276) Resolving deltas: 64% (177/276) Resolving deltas: 65% (180/276) Resolving deltas: 66% (183/276) Resolving deltas: 67% (185/276) Resolving deltas: 68% (188/276) Resolving deltas: 69% (191/276) Resolving deltas: 70% (194/276) Resolving deltas: 71% (196/276) Resolving deltas: 72% (199/276) Resolving deltas: 73% (202/276) Resolving deltas: 74% (205/276) Resolving deltas: 75% (207/276) Resolving deltas: 76% (210/276) Resolving deltas: 77% (213/276) Resolving deltas: 78% (216/276) Resolving deltas: 79% (220/276) Resolving deltas: 80% (221/276) Resolving deltas: 81% (224/276) Resolving deltas: 82% (227/276) Resolving deltas: 83% (230/276) Resolving deltas: 84% (232/276) Resolving deltas: 85% (235/276) Resolving deltas: 86% (238/276) Resolving deltas: 87% (241/276) Resolving deltas: 88% (243/276) Resolving deltas: 89% (246/276) Resolving deltas: 90% (249/276) Resolving deltas: 91% (252/276) Resolving deltas: 92% (254/276) Resolving deltas: 93% (257/276) Resolving deltas: 94% (260/276) Resolving deltas: 95% (263/276) Resolving deltas: 96% (265/276) Resolving deltas: 97% (268/276) Resolving deltas: 98% (271/276) Resolving deltas: 99% (274/276) Resolving deltas: 100% (276/276) Resolving deltas: 100% (276/276), done. travis_time:end:09599784:start=1709111488057348925,finish=1709111488514533764,duration=457184839,event=checkout [0K$ cd travis-ci/marginalia $ git checkout -qf 634817a1b380ae1ade64bf4ec854ab811e3270e9 travis_fold:end:git.checkout [0K travis_time:end:09599784:start=1709111488057348925,finish=1709111488520732390,duration=463383465,event=checkout [0Ktravis_time:start:0b2eb1a2 [0K [33;1mSetting environment variables from .travis.yml[0m $ export MARGINALIA_DB_PORT=5432 $ export MARGINALIA_LOG_FILE=/var/log/postgresql/postgresql-11-main.log travis_time:end:0b2eb1a2:start=1709111488523967403,finish=1709111488530080801,duration=6113398,event=env [0Ktravis_fold:start:rvm [0Ktravis_time:start:09375866 [0K$ rvm get head Downloading https://get.rvm.io [32mDownloading https://raw.githubusercontent.com/rvm/rvm/master/binscripts/rvm-installer.asc[0m [0m[32mVerifying /home/travis/.rvm/archives/rvm-installer.asc[0m [0mgpg: Signature made Tue 21 Feb 2023 11:35:16 PM UTC gpg: using RSA key 7D2BAF1CF37B13E2069D6956105BD0E739499BDB gpg: Good signature from "Piotr Kuczynski <piotr.kuczynski@gmail.com>" [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 [32mGPG verified '/home/travis/.rvm/archives/rvm-installer'[0m [0mDownloading https://github.com/rvm/rvm/archive/master.tar.gz [32mUpgrading the RVM installation in /home/travis/.rvm/[0m [0m RVM PATH line found in /home/travis/.mkshrc /home/travis/.profile /home/travis/.zshrc. [33m RVM PATH line not found for Bash, rerun this command with '--auto-dotfiles' flag to fix it.[0m [0m RVM sourcing line found in /home/travis/.profile /home/travis/.bashrc /home/travis/.zlogin. [32mUpgrade of RVM in /home/travis/.rvm/ is complete.[0m [0m [32m[33mThanks for installing RVM ðŸ™[0m Please consider donating to our open collective to help us maintain RVM. 👉 Donate: [34mhttps://opencollective.com/rvm/donate[0m [0m [0m[32mRVM reloaded![0m [0mtravis_time:end:09375866:start=1709111488538469823,finish=1709111491406915208,duration=2868445385,event= [0Ktravis_time:start:21922f13 [0K$ rvm use 3.2.2 --install --binary --fuzzy curl: (22) The requested URL returned error: 404 [33mRequired ruby-3.2.2 is not installed - installing.[0m [0mcurl: (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 17.9M 0 0:00:01 0:00:01 --:--:-- 17.9M [33mNo checksum for downloaded archive, recording checksum in user configuration.[0m [0mruby-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 [32mruby-3.2.2 - #importing gemset /home/travis/.rvm/gemsets/global.gems[0m|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.. [32mruby-3.2.2 - #generating global wrappers[0m|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/. [32mruby-3.2.2 - #uninstalling gem rubygems-bundler-1.4.5[0m|/. ruby-3.2.2 - #gemset created /home/travis/.rvm/gems/ruby-3.2.2 [32mruby-3.2.2 - #importing gemset /home/travis/.rvm/gemsets/default.gems[0m|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\. [32mruby-3.2.2 - #generating default wrappers[0m|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-. Using /home/travis/.rvm/gems/ruby-3.2.2 travis_time:end:21922f13:start=1709111491411734046,finish=1709111513023584196,duration=21611850150,event= [0Ktravis_fold:end:rvm [0K $ export BUNDLE_GEMFILE=$PWD/Gemfile travis_fold:start:ruby.versions [0K$ 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 [0K travis_fold:start:before_install [0Ktravis_time:start:02c95658 [0K$ bash -c "yes | gem uninstall -i /home/travis/.rvm/gems/ruby-3.2.0@global rake" Gem 'rake' is not installed travis_time:end:02c95658:start=1709111513483883303,finish=1709111513656258288,duration=172374985,event=before_install [0Ktravis_fold:end:before_install [0Ktravis_fold:start:install.bundler [0Ktravis_time:start:069cf689 [0K$ bundle install --jobs=3 --retry=3 Fetching gem metadata from https://rubygems.org/....... Resolving dependencies... [32mFetching rake 13.1.0[0m [32mInstalling rake 13.1.0[0m [32mFetching concurrent-ruby 1.2.3[0m [32mFetching base64 0.2.0[0m [32mFetching bigdecimal 3.1.6[0m [32mInstalling base64 0.2.0[0m [32mFetching connection_pool 2.4.1[0m [32mInstalling bigdecimal 3.1.6 with native extensions[0m [32mInstalling connection_pool 2.4.1[0m [32mInstalling concurrent-ruby 1.2.3[0m Using ruby2_keywords 0.0.5 [32mFetching minitest 5.18.1[0m [32mFetching mutex_m 0.2.0[0m [32mInstalling minitest 5.18.1[0m [32mFetching timeout 0.4.1[0m [32mInstalling mutex_m 0.2.0[0m Using bundler 2.4.10 [32mFetching pg 1.5.5[0m [32mInstalling timeout 0.4.1[0m Using power_assert 2.0.3 [32mFetching drb 2.2.0[0m [32mInstalling pg 1.5.5 with native extensions[0m [32mInstalling drb 2.2.0[0m [32mFetching mocha 2.1.0[0m [32mInstalling mocha 2.1.0[0m [32mFetching i18n 1.14.1[0m [32mInstalling i18n 1.14.1[0m [32mFetching tzinfo 2.0.6[0m [32mInstalling tzinfo 2.0.6[0m [32mFetching test-unit 3.6.2[0m [32mInstalling test-unit 3.6.2[0m [32mFetching activesupport 7.1.3.2[0m [32mFetching sequel 5.77.0[0m [32mInstalling activesupport 7.1.3.2[0m [32mInstalling sequel 5.77.0[0m [32mFetching activemodel 7.1.3.2[0m [32mInstalling activemodel 7.1.3.2[0m [32mFetching activerecord 7.1.3.2[0m [32mInstalling activerecord 7.1.3.2[0m Using marginalia 1.5.0 from source at `.` [32mBundle complete! 7 Gemfile dependencies, 22 gems now installed.[0m [32mUse `bundle info [gemname]` to see where a bundled gem is installed.[0m travis_time:end:069cf689:start=1709111513661819435,finish=1709111530669445097,duration=17007625662,event=install [0Ktravis_fold:end:install.bundler [0K travis_fold:start:before_script [0Ktravis_time:start:08aeb6aa [0K$ sudo chmod 0644 $MARGINALIA_LOG_FILE travis_time:end:08aeb6aa:start=1709111530674932415,finish=1709111530684764730,duration=9832315,event=before_script [0Ktravis_fold:end:before_script [0Ktravis_time:start:020b818f [0K$ 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 Run options: --seed 64837 # Running: ...... Finished in 0.005296s, 1132.9761 runs/s, 1510.6348 assertions/s. 6 runs, 8 assertions, 0 failures, 0 errors, 0 skips Run options: --seed 11627 # Running: .. Finished in 0.001504s, 1330.1737 runs/s, 1995.2606 assertions/s. 2 runs, 3 assertions, 0 failures, 0 errors, 0 skips -- create_table("posts", {:force=>true}) -> 0.0069s Run options: --seed 53900 # Running: .E Finished in 0.022505s, 88.8701 runs/s, 133.3052 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 <top (required)>' /home/travis/.rvm/gems/ruby-3.2.2/gems/rake-13.1.0/exe/rake:27:in `<top (required)>' /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 `<main>' Tasks: TOP => test:postgresql (See full trace by running task with --trace) travis_time:end:020b818f:start=1709111530689870831,finish=1709111532818586616,duration=2128715785,event=script [0K[31;1mThe command "bundle exec rake db:reset test:postgresql" exited with 1.[0m travis_time:start:1456c88a [0K$ cat $MARGINALIA_LOG_FILE 2024-02-28 09:11:25.543 UTC [4860] LOG: listening on IPv4 address "127.0.0.1", port 5432 2024-02-28 09:11:25.544 UTC [4860] LOG: listening on IPv4 address "127.0.1.1", port 5432 2024-02-28 09:11:25.544 UTC [4860] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432" 2024-02-28 09:11:25.563 UTC [4869] LOG: database system was shut down at 2024-02-01 08:57:39 UTC 2024-02-28 09:11:25.567 UTC [4860] LOG: database system is ready to accept connections 2024-02-28 09:11:26.106 UTC [4877] [unknown]@[unknown] LOG: incomplete startup packet 2024-02-28 09:11:27.711 UTC [4890] postgres@postgres ERROR: role "travis" already exists 2024-02-28 09:11:27.711 UTC [4890] postgres@postgres STATEMENT: CREATE ROLE travis SUPERUSER CREATEDB CREATEROLE INHERIT LOGIN; 2024-02-28 09:12:11.665 UTC [9368] travis@marginalia_test LOG: statement: DROP TABLE IF EXISTS posts; /**/ 2024-02-28 09:12:11.666 UTC [9368] travis@marginalia_test LOG: statement: CREATE TABLE posts ( id INTEGER, title VARCHAR ); /**/ 2024-02-28 09:12:11.675 UTC [9368] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:async_query*/ 2024-02-28 09:12:11.675 UTC [9368] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:foobar*/ 2024-02-28 09:12:11.676 UTC [9368] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:query*/ 2024-02-28 09:12:11.676 UTC [9368] travis@marginalia_test LOG: statement: select * from posts; /*adapter:pg,app:async_exec*/ 2024-02-28 09:12:11.677 UTC [9368] travis@marginalia_test LOG: statement: INSERT INTO POSTS VALUES (1, 'My Title') /*adapter:pg,app:crud.insert*/ 2024-02-28 09:12:11.677 UTC [9368] travis@marginalia_test LOG: statement: UPDATE posts SET id = 2 where id = 1 /*adapter:pg,app:crud.update*/ 2024-02-28 09:12:11.678 UTC [9368] travis@marginalia_test LOG: statement: DELETE FROM POSTS where id = 2 /*adapter:pg,app:crud.delete*/ 2024-02-28 09:12:11.678 UTC [9368] travis@marginalia_test LOG: execute statement1: INSERT INTO posts (id, title) VALUES ($1, $2) /*adapter:pg,app:prepare*/ 2024-02-28 09:12:11.678 UTC [9368] travis@marginalia_test DETAIL: parameters: $1 = '100', $2 = 'Welcome Tessa!' 2024-02-28 09:12:12.761 UTC [9386] travis@marginalia_test LOG: statement: DROP TABLE IF EXISTS posts; /**/ 2024-02-28 09:12:12.765 UTC [9386] travis@marginalia_test LOG: statement: SHOW max_identifier_length /**/ 2024-02-28 09:12:12.766 UTC [9386] travis@marginalia_test LOG: statement: DROP TABLE IF EXISTS "posts" /**/ 2024-02-28 09:12:12.766 UTC [9386] travis@marginalia_test LOG: statement: CREATE TABLE "posts" ("id" bigserial primary key, "title" character varying) /**/ 2024-02-28 09:12:12.770 UTC [9386] 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:12:12.771 UTC [9386] travis@marginalia_test LOG: statement: CREATE TABLE "schema_migrations" ("version" character varying NOT NULL PRIMARY KEY) /**/ 2024-02-28 09:12:12.773 UTC [9386] 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:12:12.774 UTC [9386] 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:12:12.776 UTC [9386] travis@marginalia_test LOG: execute <unnamed>: SELECT * FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 ORDER BY "ar_internal_metadata"."key" ASC LIMIT 1 2024-02-28 09:12:12.776 UTC [9386] travis@marginalia_test DETAIL: parameters: $1 = 'environment' 2024-02-28 09:12:12.778 UTC [9386] travis@marginalia_test LOG: execute <unnamed>: INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ('environment', 'test', '2024-02-28 09:12:12.778212', '2024-02-28 09:12:12.778217') RETURNING "key" 2024-02-28 09:12:12.786 UTC [9386] 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:12:12.789 UTC [9386] 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:12:12.789 UTC [9386] 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:12:12.795 UTC [9386] travis@marginalia_test LOG: statement: BEGIN /*adapter:active_record,app:crud.insert*/ 2024-02-28 09:12:12.796 UTC [9386] travis@marginalia_test LOG: execute <unnamed>: INSERT INTO "posts" ("title") VALUES ($1) RETURNING "id" 2024-02-28 09:12:12.796 UTC [9386] travis@marginalia_test DETAIL: parameters: $1 = 'foo' 2024-02-28 09:12:12.796 UTC [9386] travis@marginalia_test LOG: statement: COMMIT /*adapter:active_record,app:crud.insert*/ 2024-02-28 09:12:12.801 UTC [9386] travis@marginalia_test LOG: statement: SHOW search_path /*adapter:active_record,app:crud.update*/ 2024-02-28 09:12:12.802 UTC [9386] 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:12:12.802 UTC [9386] travis@marginalia_test DETAIL: parameters: $1 = '1', $2 = '1' 2024-02-28 09:12:12.803 UTC [9386] travis@marginalia_test LOG: statement: BEGIN /*adapter:active_record,app:crud.update*/ 2024-02-28 09:12:12.803 UTC [9386] travis@marginalia_test LOG: execute <unnamed>: UPDATE "posts" SET "title" = $1 WHERE "posts"."id" = $2 2024-02-28 09:12:12.803 UTC [9386] travis@marginalia_test DETAIL: parameters: $1 = 'bar', $2 = '1' 2024-02-28 09:12:12.804 UTC [9386] travis@marginalia_test LOG: statement: COMMIT /*adapter:active_record,app:crud.update*/ 2024-02-28 09:12:12.804 UTC [9386] 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:12:12.804 UTC [9386] travis@marginalia_test DETAIL: parameters: $1 = '1', $2 = '1' 2024-02-28 09:12:12.805 UTC [9386] travis@marginalia_test LOG: statement: BEGIN /*adapter:active_record,app:crud.delete*/ 2024-02-28 09:12:12.805 UTC [9386] travis@marginalia_test LOG: execute <unnamed>: DELETE FROM "posts" WHERE "posts"."id" = $1 2024-02-28 09:12:12.805 UTC [9386] travis@marginalia_test DETAIL: parameters: $1 = '1' 2024-02-28 09:12:12.805 UTC [9386] travis@marginalia_test LOG: statement: COMMIT /*adapter:active_record,app:crud.delete*/ 2024-02-28 09:12:12.806 UTC [9386] travis@marginalia_test LOG: execute <unnamed>: SELECT "posts".* FROM "posts" travis_time:end:1456c88a:start=1709111532823587592,finish=1709111532828532384,duration=4944792,event=script [0K[32;1mThe command "cat $MARGINALIA_LOG_FILE" exited with 0.[0m Done. Your build exited with 1.