travis_fold:start:worker_info
Worker information
hostname: 49f2eea2-a9f7-46d6-87fb-0773da93f1e1@1.worker-n2-com-779d777f7b-rxlft.gce-production-1
version: 6.2.22 https://github.com/travis-ci/worker/tree/858cb91994a513269f2fe9782c15fc113e966231
instance: travis-job-8bc90565-da43-43ee-ae0d-4451c66b26ee travis-ci-ubuntu-1804-1706776257-3d36ff62 (via amqp)
startup: 6.100545052s
travis_fold:end:worker_info
travis_time:start:191ad5cb
travis_time:end:191ad5cb:start=1709112317598980539,finish=1709112317819367644,duration=220387105,event=no_world_writable_dirs
travis_time:start:0d14f784
travis_time:end:0d14f784:start=1709112317822790884,finish=1709112317831918647,duration=9127763,event=agent
travis_time:start:0674e88a
travis_time:end:0674e88a:start=1709112317835166655,finish=1709112317837307132,duration=2140477,event=check_unsupported
travis_time:start:31c8fc40
travis_fold:start:system_info
Build system information
Build language: ruby
Build dist: bionic
Build id: 269163658
Job id: 618438891
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:31c8fc40:start=1709112317840546759,finish=1709112317850268682,duration=9721923,event=show_system_info
travis_time:start:014b74ab
travis_time:end:014b74ab:start=1709112317853192846,finish=1709112317869515577,duration=16322731,event=rm_riak_source
travis_time:start:22b93976
travis_time:end:22b93976:start=1709112317874885347,finish=1709112317880367004,duration=5481657,event=fix_rwky_redis
travis_time:start:00d5019e
travis_time:end:00d5019e:start=1709112317883606912,finish=1709112318601348758,duration=717741846,event=wait_for_network
travis_time:start:08a0ccc6
travis_time:end:08a0ccc6:start=1709112318604557545,finish=1709112318947888294,duration=343330749,event=update_apt_keys
travis_time:start:118e18ab
travis_time:end:118e18ab:start=1709112318950949725,finish=1709112319006758493,duration=55808768,event=fix_hhvm_source
travis_time:start:0426d744
travis_time:end:0426d744:start=1709112319009873793,finish=1709112319012501442,duration=2627649,event=update_mongo_arch
travis_time:start:01073c40
travis_time:end:01073c40:start=1709112319015375807,finish=1709112319057100909,duration=41725102,event=fix_sudo_enabled_trusty
travis_time:start:14a26ec4
travis_time:end:14a26ec4:start=1709112319060187954,finish=1709112319062448443,duration=2260489,event=update_glibc
travis_time:start:120236c4
travis_time:end:120236c4:start=1709112319065226303,finish=1709112319072839081,duration=7612778,event=clean_up_path
travis_time:start:21370c28
travis_time:end:21370c28:start=1709112319075775947,finish=1709112319084401669,duration=8625722,event=fix_resolv_conf
travis_time:start:00f669fc
travis_time:end:00f669fc:start=1709112319087329564,finish=1709112319132943733,duration=45614169,event=fix_etc_hosts
travis_time:start:1044d71f
travis_time:end:1044d71f:start=1709112319136004592,finish=1709112319143848496,duration=7843904,event=fix_mvn_settings_xml
travis_time:start:159ebcce
travis_time:end:159ebcce:start=1709112319146706752,finish=1709112319156397134,duration=9690382,event=no_ipv6_localhost
travis_time:start:0bdff35a
travis_time:end:0bdff35a:start=1709112319159457523,finish=1709112319161730175,duration=2272652,event=fix_etc_mavenrc
travis_time:start:13f76400
OK
travis_time:end:13f76400:start=1709112319164578890,finish=1709112319563208331,duration=398629441,event=fix_perforce_key
travis_time:start:0d2ac5a8
travis_time:end:0d2ac5a8:start=1709112319566272424,finish=1709112319569062126,duration=2789702,event=fix_wwdr_certificate
travis_time:start:11158424
travis_time:end:11158424:start=1709112319571980784,finish=1709112319624564313,duration=52583529,event=put_localhost_first
travis_time:start:02828ecc
travis_time:end:02828ecc:start=1709112319627313558,finish=1709112319629940256,duration=2626698,event=home_paths
travis_time:start:13d8a103
travis_time:end:13d8a103:start=1709112319632551761,finish=1709112319644472283,duration=11920522,event=disable_initramfs
travis_time:start:0ff22dd0
travis_time:end:0ff22dd0:start=1709112319647384037,finish=1709112319796263303,duration=148879266,event=disable_ssh_roaming
travis_time:start:156cbe62
travis_time:end:156cbe62:start=1709112319799101576,finish=1709112319801160487,duration=2058911,event=debug_tools
travis_time:start:1a033100
travis_time:end:1a033100:start=1709112319803833530,finish=1709112319806449731,duration=2616201,event=uninstall_oclint
travis_time:start:13ae25d9
travis_time:end:13ae25d9:start=1709112319809030732,finish=1709112319811644725,duration=2613993,event=rvm_use
travis_time:start:28ba6080
travis_time:end:28ba6080:start=1709112319814258131,finish=1709112319821746367,duration=7488236,event=rm_etc_boto_cfg
travis_time:start:016dc074
travis_time:end:016dc074:start=1709112319824404244,finish=1709112319827030107,duration=2625863,event=rm_oraclejdk8_symlink
travis_time:start:0019aba9
travis_time:end:0019aba9:start=1709112319829718279,finish=1709112319920398404,duration=90680125,event=enable_i386
travis_time:start:07e7319c
travis_time:end:07e7319c:start=1709112319923267579,finish=1709112319927116427,duration=3848848,event=update_rubygems
travis_time:start:3cf0e754
travis_time:end:3cf0e754:start=1709112319929913454,finish=1709112320823478391,duration=893564937,event=ensure_path_components
travis_time:start:0f30bb4c
travis_time:end:0f30bb4c:start=1709112320826675998,finish=1709112320828798979,duration=2122981,event=redefine_curl
travis_time:start:0bf83e80
travis_time:end:0bf83e80:start=1709112320831548275,finish=1709112320833587495,duration=2039220,event=nonblock_pipe
travis_time:start:03ec07a8
travis_time:end:03ec07a8:start=1709112320836299985,finish=1709112326873166601,duration=6036866616,event=apt_get_update
travis_time:start:24230262
travis_time:end:24230262:start=1709112326876487473,finish=1709112326878679438,duration=2191965,event=deprecate_xcode_64
travis_time:start:0e2d748f
travis_time:end:0e2d748f:start=1709112326881471233,finish=1709112330851838096,duration=3970366863,event=update_heroku
travis_time:start:1d536a70
travis_time:end:1d536a70:start=1709112330855446883,finish=1709112330857752219,duration=2305336,event=shell_session_update
travis_time:start:094a7552
travis_fold:start:docker_mtu_and_registry_mirrors
travis_fold:end:docker_mtu_and_registry_mirrors
travis_time:end:094a7552:start=1709112330860786732,finish=1709112333215271224,duration=2354484492,event=set_docker_mtu_and_registry_mirrors
travis_time:start:02440d36
travis_fold:start:resolvconf
travis_fold:end:resolvconf
travis_time:end:02440d36:start=1709112333218505725,finish=1709112333286891743,duration=68386018,event=resolvconf
travis_time:start:039b6e80
travis_time:end:039b6e80:start=1709112333290896658,finish=1709112333440087484,duration=149190826,event=maven_central_mirror
travis_time:start:0bd3b57f
travis_time:end:0bd3b57f:start=1709112333443126919,finish=1709112333533526763,duration=90399844,event=maven_https
travis_fold:start:apt
travis_time:start:2337512e
$ travis_apt_get_update
travis_time:end:2337512e:start=1709112333537235601,finish=1709112346487016805,duration=12949781204,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:2134b1f8
$ 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:2134b1f8:start=1709112346533749189,finish=1709112347483237872,duration=949488683,event=prepare
travis_fold:end:apt
travis_time:start:3167e9c0
travis_fold:start:services
travis_fold:end:services
travis_time:end:3167e9c0:start=1709112347486704284,finish=1709112350492290792,duration=3005586508,event=services
travis_time:start:042e3a00
travis_time:end:042e3a00:start=1709112350495633178,finish=1709112350497983332,duration=2350154,event=fix_ps4
travis_fold:start:postgresql
travis_time:start:16ad8820
$ travis_setup_postgresql 11
Starting PostgreSQL v11
sudo systemctl start postgresql@11-main
travis_time:end:16ad8820:start=1709112350501399511,finish=1709112353691279325,duration=3189879814,event=prepare
travis_fold:end:postgresql
travis_time:start:00ac5bd0

travis_fold:start:git.checkout
travis_time:start:0b2a77a7
travis_time:end:0b2a77a7:start=1709112353698658981,finish=1709112353704179880,duration=5520899,event=checkout
travis_time:start:18780f3c
$ 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: 547, done.
remote: Counting objects:   0% (1/547)
remote: Counting objects:   1% (6/547)
remote: Counting objects:   2% (11/547)
remote: Counting objects:   3% (17/547)
remote: Counting objects:   4% (22/547)
remote: Counting objects:   5% (28/547)
remote: Counting objects:   6% (33/547)
remote: Counting objects:   7% (39/547)
remote: Counting objects:   8% (44/547)
remote: Counting objects:   9% (50/547)
remote: Counting objects:  10% (55/547)
remote: Counting objects:  11% (61/547)
remote: Counting objects:  12% (66/547)
remote: Counting objects:  13% (72/547)
remote: Counting objects:  14% (77/547)
remote: Counting objects:  15% (83/547)
remote: Counting objects:  16% (88/547)
remote: Counting objects:  17% (93/547)
remote: Counting objects:  18% (99/547)
remote: Counting objects:  19% (104/547)
remote: Counting objects:  20% (110/547)
remote: Counting objects:  21% (115/547)
remote: Counting objects:  22% (121/547)
remote: Counting objects:  23% (126/547)
remote: Counting objects:  24% (132/547)
remote: Counting objects:  25% (137/547)
remote: Counting objects:  26% (143/547)
remote: Counting objects:  27% (148/547)
remote: Counting objects:  28% (154/547)
remote: Counting objects:  29% (159/547)
remote: Counting objects:  30% (165/547)
remote: Counting objects:  31% (170/547)
remote: Counting objects:  32% (176/547)
remote: Counting objects:  33% (181/547)
remote: Counting objects:  34% (186/547)
remote: Counting objects:  35% (192/547)
remote: Counting objects:  36% (197/547)
remote: Counting objects:  37% (203/547)
remote: Counting objects:  38% (208/547)
remote: Counting objects:  39% (214/547)
remote: Counting objects:  40% (219/547)
remote: Counting objects:  41% (225/547)
remote: Counting objects:  42% (230/547)
remote: Counting objects:  43% (236/547)
remote: Counting objects:  44% (241/547)
remote: Counting objects:  45% (247/547)
remote: Counting objects:  46% (252/547)
remote: Counting objects:  47% (258/547)
remote: Counting objects:  48% (263/547)
remote: Counting objects:  49% (269/547)
remote: Counting objects:  50% (274/547)
remote: Counting objects:  51% (279/547)
remote: Counting objects:  52% (285/547)
remote: Counting objects:  53% (290/547)
remote: Counting objects:  54% (296/547)
remote: Counting objects:  55% (301/547)
remote: Counting objects:  56% (307/547)
remote: Counting objects:  57% (312/547)
remote: Counting objects:  58% (318/547)
remote: Counting objects:  59% (323/547)
remote: Counting objects:  60% (329/547)
remote: Counting objects:  61% (334/547)
remote: Counting objects:  62% (340/547)
remote: Counting objects:  63% (345/547)
remote: Counting objects:  64% (351/547)
remote: Counting objects:  65% (356/547)
remote: Counting objects:  66% (362/547)
remote: Counting objects:  67% (367/547)
remote: Counting objects:  68% (372/547)
remote: Counting objects:  69% (378/547)
remote: Counting objects:  70% (383/547)
remote: Counting objects:  71% (389/547)
remote: Counting objects:  72% (394/547)
remote: Counting objects:  73% (400/547)
remote: Counting objects:  74% (405/547)
remote: Counting objects:  75% (411/547)
remote: Counting objects:  76% (416/547)
remote: Counting objects:  77% (422/547)
remote: Counting objects:  78% (427/547)
remote: Counting objects:  79% (433/547)
remote: Counting objects:  80% (438/547)
remote: Counting objects:  81% (444/547)
remote: Counting objects:  82% (449/547)
remote: Counting objects:  83% (455/547)
remote: Counting objects:  84% (460/547)
remote: Counting objects:  85% (465/547)
remote: Counting objects:  86% (471/547)
remote: Counting objects:  87% (476/547)
remote: Counting objects:  88% (482/547)
remote: Counting objects:  89% (487/547)
remote: Counting objects:  90% (493/547)
remote: Counting objects:  91% (498/547)
remote: Counting objects:  92% (504/547)
remote: Counting objects:  93% (509/547)
remote: Counting objects:  94% (515/547)
remote: Counting objects:  95% (520/547)
remote: Counting objects:  96% (526/547)
remote: Counting objects:  97% (531/547)
remote: Counting objects:  98% (537/547)
remote: Counting objects:  99% (542/547)
remote: Counting objects: 100% (547/547)
remote: Counting objects: 100% (547/547), done.
remote: Compressing objects:   0% (1/290)
remote: Compressing objects:   1% (3/290)
remote: Compressing objects:   2% (6/290)
remote: Compressing objects:   3% (9/290)
remote: Compressing objects:   4% (12/290)
remote: Compressing objects:   5% (15/290)
remote: Compressing objects:   6% (18/290)
remote: Compressing objects:   7% (21/290)
remote: Compressing objects:   8% (24/290)
remote: Compressing objects:   9% (27/290)
remote: Compressing objects:  10% (29/290)
remote: Compressing objects:  11% (32/290)
remote: Compressing objects:  12% (35/290)
remote: Compressing objects:  13% (38/290)
remote: Compressing objects:  14% (41/290)
remote: Compressing objects:  15% (44/290)
remote: Compressing objects:  16% (47/290)
remote: Compressing objects:  17% (50/290)
remote: Compressing objects:  18% (53/290)
remote: Compressing objects:  19% (56/290)
remote: Compressing objects:  20% (58/290)
remote: Compressing objects:  21% (61/290)
remote: Compressing objects:  22% (64/290)
remote: Compressing objects:  23% (67/290)
remote: Compressing objects:  24% (70/290)
remote: Compressing objects:  25% (73/290)
remote: Compressing objects:  26% (76/290)
remote: Compressing objects:  27% (79/290)
remote: Compressing objects:  28% (82/290)
remote: Compressing objects:  29% (85/290)
remote: Compressing objects:  30% (87/290)
remote: Compressing objects:  31% (90/290)
remote: Compressing objects:  32% (93/290)
remote: Compressing objects:  33% (96/290)
remote: Compressing objects:  34% (99/290)
remote: Compressing objects:  35% (102/290)
remote: Compressing objects:  36% (105/290)
remote: Compressing objects:  37% (108/290)
remote: Compressing objects:  38% (111/290)
remote: Compressing objects:  39% (114/290)
remote: Compressing objects:  40% (116/290)
remote: Compressing objects:  41% (119/290)
remote: Compressing objects:  42% (122/290)
remote: Compressing objects:  43% (125/290)
remote: Compressing objects:  44% (128/290)
remote: Compressing objects:  45% (131/290)
remote: Compressing objects:  46% (134/290)
remote: Compressing objects:  47% (137/290)
remote: Compressing objects:  48% (140/290)
remote: Compressing objects:  49% (143/290)
remote: Compressing objects:  50% (145/290)
remote: Compressing objects:  51% (148/290)
remote: Compressing objects:  52% (151/290)
remote: Compressing objects:  53% (154/290)
remote: Compressing objects:  54% (157/290)
remote: Compressing objects:  55% (160/290)
remote: Compressing objects:  56% (163/290)
remote: Compressing objects:  57% (166/290)
remote: Compressing objects:  58% (169/290)
remote: Compressing objects:  59% (172/290)
remote: Compressing objects:  60% (174/290)
remote: Compressing objects:  61% (177/290)
remote: Compressing objects:  62% (180/290)
remote: Compressing objects:  63% (183/290)
remote: Compressing objects:  64% (186/290)
remote: Compressing objects:  65% (189/290)
remote: Compressing objects:  66% (192/290)
remote: Compressing objects:  67% (195/290)
remote: Compressing objects:  68% (198/290)
remote: Compressing objects:  69% (201/290)
remote: Compressing objects:  70% (203/290)
remote: Compressing objects:  71% (206/290)
remote: Compressing objects:  72% (209/290)
remote: Compressing objects:  73% (212/290)
remote: Compressing objects:  74% (215/290)
remote: Compressing objects:  75% (218/290)
remote: Compressing objects:  76% (221/290)
remote: Compressing objects:  77% (224/290)
remote: Compressing objects:  78% (227/290)
remote: Compressing objects:  79% (230/290)
remote: Compressing objects:  80% (232/290)
remote: Compressing objects:  81% (235/290)
remote: Compressing objects:  82% (238/290)
remote: Compressing objects:  83% (241/290)
remote: Compressing objects:  84% (244/290)
remote: Compressing objects:  85% (247/290)
remote: Compressing objects:  86% (250/290)
remote: Compressing objects:  87% (253/290)
remote: Compressing objects:  88% (256/290)
remote: Compressing objects:  89% (259/290)
remote: Compressing objects:  90% (261/290)
remote: Compressing objects:  91% (264/290)
remote: Compressing objects:  92% (267/290)
remote: Compressing objects:  93% (270/290)
remote: Compressing objects:  94% (273/290)
remote: Compressing objects:  95% (276/290)
remote: Compressing objects:  96% (279/290)
remote: Compressing objects:  97% (282/290)
remote: Compressing objects:  98% (285/290)
remote: Compressing objects:  99% (288/290)
remote: Compressing objects: 100% (290/290)
remote: Compressing objects: 100% (290/290), done.
Receiving objects:   0% (1/547)
Receiving objects:   1% (6/547)
Receiving objects:   2% (11/547)
Receiving objects:   3% (17/547)
Receiving objects:   4% (22/547)
Receiving objects:   5% (28/547)
Receiving objects:   6% (33/547)
Receiving objects:   7% (39/547)
Receiving objects:   8% (44/547)
Receiving objects:   9% (50/547)
Receiving objects:  10% (55/547)
Receiving objects:  11% (61/547)
Receiving objects:  12% (66/547)
Receiving objects:  13% (72/547)
Receiving objects:  14% (77/547)
Receiving objects:  15% (83/547)
Receiving objects:  16% (88/547)
Receiving objects:  17% (93/547)
Receiving objects:  18% (99/547)
Receiving objects:  19% (104/547)
Receiving objects:  20% (110/547)
Receiving objects:  21% (115/547)
Receiving objects:  22% (121/547)
Receiving objects:  23% (126/547)
Receiving objects:  24% (132/547)
Receiving objects:  25% (137/547)
Receiving objects:  26% (143/547)
Receiving objects:  27% (148/547)
Receiving objects:  28% (154/547)
Receiving objects:  29% (159/547)
Receiving objects:  30% (165/547)
Receiving objects:  31% (170/547)
Receiving objects:  32% (176/547)
Receiving objects:  33% (181/547)
Receiving objects:  34% (186/547)
Receiving objects:  35% (192/547)
Receiving objects:  36% (197/547)
Receiving objects:  37% (203/547)
Receiving objects:  38% (208/547)
Receiving objects:  39% (214/547)
Receiving objects:  40% (219/547)
Receiving objects:  41% (225/547)
Receiving objects:  42% (230/547)
Receiving objects:  43% (236/547)
Receiving objects:  44% (241/547)
Receiving objects:  45% (247/547)
Receiving objects:  46% (252/547)
Receiving objects:  47% (258/547)
Receiving objects:  48% (263/547)
Receiving objects:  49% (269/547)
Receiving objects:  50% (274/547)
Receiving objects:  51% (279/547)
Receiving objects:  52% (285/547)
Receiving objects:  53% (290/547)
Receiving objects:  54% (296/547)
Receiving objects:  55% (301/547)
Receiving objects:  56% (307/547)
Receiving objects:  57% (312/547)
remote: Total 547 (delta 273), reused 495 (delta 229), pack-reused 0
Receiving objects:  58% (318/547)
Receiving objects:  59% (323/547)
Receiving objects:  60% (329/547)
Receiving objects:  61% (334/547)
Receiving objects:  62% (340/547)
Receiving objects:  63% (345/547)
Receiving objects:  64% (351/547)
Receiving objects:  65% (356/547)
Receiving objects:  66% (362/547)
Receiving objects:  67% (367/547)
Receiving objects:  68% (372/547)
Receiving objects:  69% (378/547)
Receiving objects:  70% (383/547)
Receiving objects:  71% (389/547)
Receiving objects:  72% (394/547)
Receiving objects:  73% (400/547)
Receiving objects:  74% (405/547)
Receiving objects:  75% (411/547)
Receiving objects:  76% (416/547)
Receiving objects:  77% (422/547)
Receiving objects:  78% (427/547)
Receiving objects:  79% (433/547)
Receiving objects:  80% (438/547)
Receiving objects:  81% (444/547)
Receiving objects:  82% (449/547)
Receiving objects:  83% (455/547)
Receiving objects:  84% (460/547)
Receiving objects:  85% (465/547)
Receiving objects:  86% (471/547)
Receiving objects:  87% (476/547)
Receiving objects:  88% (482/547)
Receiving objects:  89% (487/547)
Receiving objects:  90% (493/547)
Receiving objects:  91% (498/547)
Receiving objects:  92% (504/547)
Receiving objects:  93% (509/547)
Receiving objects:  94% (515/547)
Receiving objects:  95% (520/547)
Receiving objects:  96% (526/547)
Receiving objects:  97% (531/547)
Receiving objects:  98% (537/547)
Receiving objects:  99% (542/547)
Receiving objects: 100% (547/547)
Receiving objects: 100% (547/547), 76.51 KiB | 2.07 MiB/s, done.
Resolving deltas:   0% (0/273)
Resolving deltas:   1% (3/273)
Resolving deltas:   2% (6/273)
Resolving deltas:   3% (9/273)
Resolving deltas:   4% (11/273)
Resolving deltas:   5% (14/273)
Resolving deltas:   6% (17/273)
Resolving deltas:   7% (20/273)
Resolving deltas:   8% (22/273)
Resolving deltas:   9% (25/273)
Resolving deltas:  10% (28/273)
Resolving deltas:  11% (31/273)
Resolving deltas:  12% (33/273)
Resolving deltas:  13% (36/273)
Resolving deltas:  14% (39/273)
Resolving deltas:  15% (41/273)
Resolving deltas:  16% (44/273)
Resolving deltas:  17% (47/273)
Resolving deltas:  18% (50/273)
Resolving deltas:  19% (52/273)
Resolving deltas:  20% (55/273)
Resolving deltas:  21% (58/273)
Resolving deltas:  22% (61/273)
Resolving deltas:  23% (63/273)
Resolving deltas:  24% (66/273)
Resolving deltas:  25% (69/273)
Resolving deltas:  26% (71/273)
Resolving deltas:  27% (74/273)
Resolving deltas:  28% (77/273)
Resolving deltas:  29% (80/273)
Resolving deltas:  30% (82/273)
Resolving deltas:  31% (85/273)
Resolving deltas:  32% (88/273)
Resolving deltas:  33% (91/273)
Resolving deltas:  34% (93/273)
Resolving deltas:  35% (96/273)
Resolving deltas:  36% (99/273)
Resolving deltas:  37% (102/273)
Resolving deltas:  38% (104/273)
Resolving deltas:  39% (107/273)
Resolving deltas:  40% (110/273)
Resolving deltas:  41% (112/273)
Resolving deltas:  42% (115/273)
Resolving deltas:  43% (118/273)
Resolving deltas:  44% (121/273)
Resolving deltas:  45% (123/273)
Resolving deltas:  46% (126/273)
Resolving deltas:  47% (129/273)
Resolving deltas:  48% (132/273)
Resolving deltas:  49% (134/273)
Resolving deltas:  50% (137/273)
Resolving deltas:  51% (140/273)
Resolving deltas:  52% (142/273)
Resolving deltas:  53% (145/273)
Resolving deltas:  54% (148/273)
Resolving deltas:  55% (151/273)
Resolving deltas:  56% (153/273)
Resolving deltas:  57% (156/273)
Resolving deltas:  58% (159/273)
Resolving deltas:  59% (162/273)
Resolving deltas:  60% (164/273)
Resolving deltas:  61% (167/273)
Resolving deltas:  62% (170/273)
Resolving deltas:  63% (172/273)
Resolving deltas:  64% (175/273)
Resolving deltas:  65% (178/273)
Resolving deltas:  66% (181/273)
Resolving deltas:  67% (183/273)
Resolving deltas:  68% (186/273)
Resolving deltas:  69% (189/273)
Resolving deltas:  70% (192/273)
Resolving deltas:  71% (194/273)
Resolving deltas:  72% (197/273)
Resolving deltas:  73% (200/273)
Resolving deltas:  74% (203/273)
Resolving deltas:  75% (205/273)
Resolving deltas:  76% (208/273)
Resolving deltas:  77% (211/273)
Resolving deltas:  78% (213/273)
Resolving deltas:  79% (216/273)
Resolving deltas:  80% (219/273)
Resolving deltas:  81% (222/273)
Resolving deltas:  82% (224/273)
Resolving deltas:  83% (227/273)
Resolving deltas:  84% (230/273)
Resolving deltas:  85% (233/273)
Resolving deltas:  86% (235/273)
Resolving deltas:  87% (238/273)
Resolving deltas:  88% (241/273)
Resolving deltas:  89% (243/273)
Resolving deltas:  90% (246/273)
Resolving deltas:  91% (249/273)
Resolving deltas:  92% (252/273)
Resolving deltas:  93% (254/273)
Resolving deltas:  94% (257/273)
Resolving deltas:  95% (260/273)
Resolving deltas:  96% (263/273)
Resolving deltas:  97% (266/273)
Resolving deltas:  98% (268/273)
Resolving deltas:  99% (271/273)
Resolving deltas: 100% (273/273)
Resolving deltas: 100% (273/273), done.
travis_time:end:18780f3c:start=1709112353707872738,finish=1709112354152275508,duration=444402770,event=checkout
$ cd travis-ci/marginalia
$ git checkout -qf 347a3c5c916eb69a202ad07110ab38f52bf1c1fe
travis_fold:end:git.checkout

travis_time:end:18780f3c:start=1709112353707872738,finish=1709112354158298055,duration=450425317,event=checkout
travis_time:start:00fd0f98

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:00fd0f98:start=1709112354161453524,finish=1709112354168539319,duration=7085795,event=env
travis_fold:start:rvm
travis_time:start:008d4405
$ 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 <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
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:008d4405:start=1709112354177282064,finish=1709112357191392366,duration=3014110302,event=
travis_time:start:16ed85d0
$ 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:00:01 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:01 --:--:--     0

100 29.2M  100 29.2M    0     0  14.2M      0  0:00:02  0:00:02 --:--:-- 14.2M
No checksum for downloaded archive, recording checksum in user configuration.
ruby-3.2.2 - #validate archive
ruby-3.2.2 - #extract
ruby-3.2.2 - #validate binary
ruby-3.2.2 - #setup
ruby-3.2.2 - #gemset created /home/travis/.rvm/gems/ruby-3.2.2@global
ruby-3.2.2 - #importing gemset /home/travis/.rvm/gemsets/global.gems|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|..
ruby-3.2.2 - #generating global wrappers|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/.
ruby-3.2.2 - #uninstalling gem rubygems-bundler-1.4.5|/.
ruby-3.2.2 - #gemset created /home/travis/.rvm/gems/ruby-3.2.2
ruby-3.2.2 - #importing gemset /home/travis/.rvm/gemsets/default.gems|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\.
ruby-3.2.2 - #generating default wrappers|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-\|/-.|/-\|/-\|.-\|/-.
Using /home/travis/.rvm/gems/ruby-3.2.2
travis_time:end:16ed85d0:start=1709112357196344916,finish=1709112381801849076,duration=24605504160,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:09f48f38
$ bash -c "yes | gem uninstall -i /home/travis/.rvm/gems/ruby-3.2.0@global rake"
Gem 'rake' is not installed
travis_time:end:09f48f38:start=1709112382270946107,finish=1709112382449126131,duration=178180024,event=before_install
travis_fold:end:before_install
travis_fold:start:install.bundler
travis_time:start:0929a3c3
$ 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 concurrent-ruby 1.2.3
Fetching base64 0.2.0
Fetching bigdecimal 3.1.6
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
Installing sequel 5.77.0
Fetching activemodel 7.1.3.2
Installing activemodel 7.1.3.2
Fetching activerecord 7.1.3.2
Installing activerecord 7.1.3.2
Using marginalia 1.5.0 from source at `.`
Bundle complete! 7 Gemfile dependencies, 22 gems now installed.
Use `bundle info [gemname]` to see where a bundled gem is installed.
travis_time:end:0929a3c3:start=1709112382454879662,finish=1709112399531122138,duration=17076242476,event=install
travis_fold:end:install.bundler

travis_fold:start:before_script
travis_time:start:11e08c0e
$ sudo chmod 0644 $MARGINALIA_LOG_FILE
travis_time:end:11e08c0e:start=1709112399536398847,finish=1709112399545634578,duration=9235731,event=before_script
travis_fold:end:before_script
travis_time:start:10e56b18
$ 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 "DROP TABLE IF EXISTS posts;\n"
EXEC "CREATE TABLE posts (\n  id INTEGER,\n  title VARCHAR\n);\n"
Run options: --seed 63009

# Running:

QUERY "select * from posts;"
.A.EXEC "select * from posts;"
.EXEC "select * from posts;"
.A.QUERY "select * from posts;"
.PREP "INSERT INTO posts (id, title) VALUES ($1, $2)"
.EXEC "INSERT INTO POSTS VALUES (1, 'My Title')"
EXEC "UPDATE posts\nSET id = 2\nwhere id = 1\n"
EXEC "DELETE FROM POSTS where id = 2"
.

Finished in 0.006040s, 993.3816 runs/s, 1324.5088 assertions/s.

6 runs, 8 assertions, 0 failures, 0 errors, 0 skips
Run options: --seed 48183

# Running:

..

Finished in 0.001717s, 1165.0178 runs/s, 1747.5267 assertions/s.

2 runs, 3 assertions, 0 failures, 0 errors, 0 skips
A.EXEC "SET client_min_messages TO 'warning'"
A.EXEC "SET standard_conforming_strings = on"
A.EXEC "SET intervalstyle = iso_8601"
A.EXEC "SET SESSION timezone TO 'UTC'"
QUERY ";"
A.EXEC "SET log_statement = 'all';\n"
A.EXEC "DROP TABLE IF EXISTS posts;\n"
-- create_table("posts", {:force=>true})
A.EXEC "SHOW max_identifier_length"
A.EXEC "DROP TABLE IF EXISTS \"posts\""
A.EXEC "CREATE TABLE \"posts\" (\"id\" bigserial primary key, \"title\" character varying)"
   -> 0.0078s
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')"
A.EXEC "CREATE TABLE \"schema_migrations\" (\"version\" character varying NOT NULL PRIMARY KEY)"
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')"
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)"
Run options: --seed 25184

# Running:

EA.EXEC "SELECT a.attname, format_type(a.atttypid, a.atttypmod),\n       pg_get_expr(d.adbin, d.adrelid), a.attnotnull, a.atttypid, a.atttypmod,\n       c.collname, col_description(a.attrelid, a.attnum) AS comment,\n       attidentity AS identity,\n       '' as attgenerated\n  FROM pg_attribute a\n  LEFT JOIN pg_attrdef d ON a.attrelid = d.adrelid AND a.attnum = d.adnum\n  LEFT JOIN pg_type t ON a.atttypid = t.oid\n  LEFT JOIN pg_collation c ON a.attcollation = c.oid AND a.attcollation <> t.typcollation\n WHERE a.attrelid = '\"posts\"'::regclass\n   AND a.attnum > 0 AND NOT a.attisdropped\n ORDER BY a.attnum\n"
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')"
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"
A.EXEC "BEGIN"
A.EXEC "COMMIT"
A.EXEC "SHOW search_path"
PREP "SELECT \"posts\".* FROM \"posts\" WHERE \"posts\".\"id\" = $1 LIMIT $2"
A.EXEC "BEGIN"
A.EXEC "COMMIT"
A.EXEC "BEGIN"
A.EXEC "COMMIT"
.

Finished in 0.023658s, 84.5390 runs/s, 126.8084 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:10e56b18:start=1709112399550712295,finish=1709112401666800441,duration=2116088146,event=script
The command "bundle exec rake db:reset test:postgresql" exited with 1.
travis_time:start:060f285c
$ cat $MARGINALIA_LOG_FILE
2024-02-28 09:25:51.183 UTC [4823] LOG:  listening on IPv4 address "127.0.0.1", port 5432
2024-02-28 09:25:51.183 UTC [4823] LOG:  listening on IPv4 address "127.0.1.1", port 5432
2024-02-28 09:25:51.183 UTC [4823] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-02-28 09:25:51.205 UTC [4832] LOG:  database system was shut down at 2024-02-01 08:57:39 UTC
2024-02-28 09:25:51.210 UTC [4823] LOG:  database system is ready to accept connections
2024-02-28 09:25:51.747 UTC [4840] [unknown]@[unknown] LOG:  incomplete startup packet
2024-02-28 09:25:53.358 UTC [4853] postgres@postgres ERROR:  role "travis" already exists
2024-02-28 09:25:53.358 UTC [4853] postgres@postgres STATEMENT:  CREATE ROLE travis SUPERUSER CREATEDB CREATEROLE INHERIT LOGIN;
2024-02-28 09:26:40.502 UTC [9331] travis@marginalia_test LOG:  statement: DROP TABLE IF EXISTS posts;
	 /**/
2024-02-28 09:26:40.504 UTC [9331] travis@marginalia_test LOG:  statement: CREATE TABLE posts (
	  id INTEGER,
	  title VARCHAR
	);
	 /**/
2024-02-28 09:26:40.512 UTC [9331] travis@marginalia_test LOG:  statement: select * from posts; /*adapter:pg,app:query*/
2024-02-28 09:26:40.513 UTC [9331] travis@marginalia_test LOG:  statement: select * from posts; /*adapter:pg,app:async_exec*/
2024-02-28 09:26:40.513 UTC [9331] travis@marginalia_test LOG:  statement: select * from posts; /*adapter:pg,app:foobar*/
2024-02-28 09:26:40.514 UTC [9331] travis@marginalia_test LOG:  statement: select * from posts; /*adapter:pg,app:async_query*/
2024-02-28 09:26:40.514 UTC [9331] travis@marginalia_test LOG:  execute statement1: INSERT INTO posts (id, title) VALUES ($1, $2) /*adapter:pg,app:prepare*/
2024-02-28 09:26:40.514 UTC [9331] travis@marginalia_test DETAIL:  parameters: $1 = '100', $2 = 'Welcome Tessa!'
2024-02-28 09:26:40.515 UTC [9331] travis@marginalia_test LOG:  statement: INSERT INTO POSTS VALUES (1, 'My Title') /*adapter:pg,app:crud.insert*/
2024-02-28 09:26:40.515 UTC [9331] travis@marginalia_test LOG:  statement: UPDATE posts
	SET id = 2
	where id = 1
	 /*adapter:pg,app:crud.update*/
2024-02-28 09:26:40.516 UTC [9331] travis@marginalia_test LOG:  statement: DELETE FROM POSTS where id = 2 /*adapter:pg,app:crud.delete*/
2024-02-28 09:26:41.605 UTC [9349] travis@marginalia_test LOG:  statement: DROP TABLE IF EXISTS posts;
	 /**/
2024-02-28 09:26:41.610 UTC [9349] travis@marginalia_test LOG:  statement: SHOW max_identifier_length /**/
2024-02-28 09:26:41.611 UTC [9349] travis@marginalia_test LOG:  statement: DROP TABLE IF EXISTS "posts" /**/
2024-02-28 09:26:41.611 UTC [9349] travis@marginalia_test LOG:  statement: CREATE TABLE "posts" ("id" bigserial primary key, "title" character varying) /**/
2024-02-28 09:26:41.616 UTC [9349] 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:26:41.617 UTC [9349] travis@marginalia_test LOG:  statement: CREATE TABLE "schema_migrations" ("version" character varying NOT NULL PRIMARY KEY) /**/
2024-02-28 09:26:41.619 UTC [9349] 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:26:41.620 UTC [9349] 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:26:41.622 UTC [9349] 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:26:41.622 UTC [9349] travis@marginalia_test DETAIL:  parameters: $1 = 'environment'
2024-02-28 09:26:41.625 UTC [9349] travis@marginalia_test LOG:  execute <unnamed>: INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ('environment', 'test', '2024-02-28 09:26:41.624507', '2024-02-28 09:26:41.624512') RETURNING "key"
2024-02-28 09:26:41.636 UTC [9349] travis@marginalia_test LOG:  execute <unnamed>: SELECT "posts".* FROM "posts"
2024-02-28 09:26:41.637 UTC [9349] 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:26:41.640 UTC [9349] 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:26:41.640 UTC [9349] 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:26:41.647 UTC [9349] travis@marginalia_test LOG:  statement: BEGIN /*adapter:active_record,app:crud.insert*/
2024-02-28 09:26:41.647 UTC [9349] travis@marginalia_test LOG:  execute <unnamed>: INSERT INTO "posts" ("title") VALUES ($1) RETURNING "id"
2024-02-28 09:26:41.647 UTC [9349] travis@marginalia_test DETAIL:  parameters: $1 = 'foo'
2024-02-28 09:26:41.648 UTC [9349] travis@marginalia_test LOG:  statement: COMMIT /*adapter:active_record,app:crud.insert*/
2024-02-28 09:26:41.650 UTC [9349] travis@marginalia_test LOG:  statement: SHOW search_path /*adapter:active_record,app:crud.update*/
2024-02-28 09:26:41.650 UTC [9349] 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:26:41.650 UTC [9349] travis@marginalia_test DETAIL:  parameters: $1 = '1', $2 = '1'
2024-02-28 09:26:41.651 UTC [9349] travis@marginalia_test LOG:  statement: BEGIN /*adapter:active_record,app:crud.update*/
2024-02-28 09:26:41.652 UTC [9349] travis@marginalia_test LOG:  execute <unnamed>: UPDATE "posts" SET "title" = $1 WHERE "posts"."id" = $2
2024-02-28 09:26:41.652 UTC [9349] travis@marginalia_test DETAIL:  parameters: $1 = 'bar', $2 = '1'
2024-02-28 09:26:41.652 UTC [9349] travis@marginalia_test LOG:  statement: COMMIT /*adapter:active_record,app:crud.update*/
2024-02-28 09:26:41.653 UTC [9349] 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:26:41.653 UTC [9349] travis@marginalia_test DETAIL:  parameters: $1 = '1', $2 = '1'
2024-02-28 09:26:41.653 UTC [9349] travis@marginalia_test LOG:  statement: BEGIN /*adapter:active_record,app:crud.delete*/
2024-02-28 09:26:41.654 UTC [9349] travis@marginalia_test LOG:  execute <unnamed>: DELETE FROM "posts" WHERE "posts"."id" = $1
2024-02-28 09:26:41.654 UTC [9349] travis@marginalia_test DETAIL:  parameters: $1 = '1'
2024-02-28 09:26:41.654 UTC [9349] travis@marginalia_test LOG:  statement: COMMIT /*adapter:active_record,app:crud.delete*/
travis_time:end:060f285c:start=1709112401671920876,finish=1709112401676972816,duration=5051940,event=script
The command "cat $MARGINALIA_LOG_FILE" exited with 0.


Done. Your build exited with 1.