travis_fold:start:worker_info
Worker information
hostname: 2325c382-132b-4010-bb9e-ca557948c95f@1.worker-n2-com-779d777f7b-rxlft.gce-production-1
version: 6.2.22 https://github.com/travis-ci/worker/tree/858cb91994a513269f2fe9782c15fc113e966231
instance: travis-job-099fce6d-7d7d-4b0f-8be4-826afbee8938 travis-ci-ubuntu-1804-1706776257-3d36ff62 (via amqp)
startup: 6.319607369s
travis_fold:end:worker_info
travis_time:start:0f818b90
travis_time:end:0f818b90:start=1709113623698149901,finish=1709113623884969842,duration=186819941,event=no_world_writable_dirs
travis_time:start:0286258e
travis_time:end:0286258e:start=1709113623887756231,finish=1709113623894318460,duration=6562229,event=agent
travis_time:start:07d4e44e
travis_time:end:07d4e44e:start=1709113623896856273,finish=1709113623898665314,duration=1809041,event=check_unsupported
travis_time:start:09610fc0
travis_fold:start:system_info
Build system information
Build language: ruby
Build dist: bionic
Build id: 269164226
Job id: 618440283
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:09610fc0:start=1709113623901111844,finish=1709113623913089543,duration=11977699,event=show_system_info
travis_time:start:0f35bbd8
travis_time:end:0f35bbd8:start=1709113623915650612,finish=1709113623934088631,duration=18438019,event=rm_riak_source
travis_time:start:19070d6e
travis_time:end:19070d6e:start=1709113623936893377,finish=1709113623947012165,duration=10118788,event=fix_rwky_redis
travis_time:start:0dc2ce49
travis_time:end:0dc2ce49:start=1709113623950321637,finish=1709113624712093339,duration=761771702,event=wait_for_network
travis_time:start:0064a78a
travis_time:end:0064a78a:start=1709113624715360557,finish=1709113625032947950,duration=317587393,event=update_apt_keys
travis_time:start:26f92b90
travis_time:end:26f92b90:start=1709113625035769309,finish=1709113625085821085,duration=50051776,event=fix_hhvm_source
travis_time:start:01136b44
travis_time:end:01136b44:start=1709113625088620797,finish=1709113625090862729,duration=2241932,event=update_mongo_arch
travis_time:start:090ebfec
travis_time:end:090ebfec:start=1709113625093461163,finish=1709113625131786630,duration=38325467,event=fix_sudo_enabled_trusty
travis_time:start:05f37714
travis_time:end:05f37714:start=1709113625134578759,finish=1709113625136544269,duration=1965510,event=update_glibc
travis_time:start:1d6f6144
travis_time:end:1d6f6144:start=1709113625139007253,finish=1709113625145985225,duration=6977972,event=clean_up_path
travis_time:start:01a9fe92
travis_time:end:01a9fe92:start=1709113625148446656,finish=1709113625156222576,duration=7775920,event=fix_resolv_conf
travis_time:start:14e7d0aa
travis_time:end:14e7d0aa:start=1709113625158681823,finish=1709113625173385111,duration=14703288,event=fix_etc_hosts
travis_time:start:0692b2cf
travis_time:end:0692b2cf:start=1709113625175894246,finish=1709113625182976552,duration=7082306,event=fix_mvn_settings_xml
travis_time:start:02f38a95
travis_time:end:02f38a95:start=1709113625185753661,finish=1709113625194937114,duration=9183453,event=no_ipv6_localhost
travis_time:start:10763ac3
travis_time:end:10763ac3:start=1709113625197643520,finish=1709113625199689850,duration=2046330,event=fix_etc_mavenrc
travis_time:start:01005ea0
OK
travis_time:end:01005ea0:start=1709113625202492297,finish=1709113625572774907,duration=370282610,event=fix_perforce_key
travis_time:start:0334549e
travis_time:end:0334549e:start=1709113625575577134,finish=1709113625578078307,duration=2501173,event=fix_wwdr_certificate
travis_time:start:0586dacd
travis_time:end:0586dacd:start=1709113625580720552,finish=1709113625631274959,duration=50554407,event=put_localhost_first
travis_time:start:0ac41946
travis_time:end:0ac41946:start=1709113625633550494,finish=1709113625636172204,duration=2621710,event=home_paths
travis_time:start:168782a0
travis_time:end:168782a0:start=1709113625638776744,finish=1709113625649231297,duration=10454553,event=disable_initramfs
travis_time:start:28ae87b0
travis_time:end:28ae87b0:start=1709113625651618391,finish=1709113625783626702,duration=132008311,event=disable_ssh_roaming
travis_time:start:095d0044
travis_time:end:095d0044:start=1709113625786332173,finish=1709113625788154654,duration=1822481,event=debug_tools
travis_time:start:2bdeee68
travis_time:end:2bdeee68:start=1709113625790413228,finish=1709113625792769253,duration=2356025,event=uninstall_oclint
travis_time:start:0e4d9880
travis_time:end:0e4d9880:start=1709113625795158122,finish=1709113625797408465,duration=2250343,event=rvm_use
travis_time:start:1a1aaa1c
travis_time:end:1a1aaa1c:start=1709113625799691635,finish=1709113625806095901,duration=6404266,event=rm_etc_boto_cfg
travis_time:start:1d5221e4
travis_time:end:1d5221e4:start=1709113625808392205,finish=1709113625810558570,duration=2166365,event=rm_oraclejdk8_symlink
travis_time:start:015dde17
travis_time:end:015dde17:start=1709113625812941373,finish=1709113625897140227,duration=84198854,event=enable_i386
travis_time:start:291ce23a
travis_time:end:291ce23a:start=1709113625899694188,finish=1709113625903275644,duration=3581456,event=update_rubygems
travis_time:start:1101b57d
travis_time:end:1101b57d:start=1709113625905842079,finish=1709113626676597294,duration=770755215,event=ensure_path_components
travis_time:start:2c3177e5
travis_time:end:2c3177e5:start=1709113626679295958,finish=1709113626681091296,duration=1795338,event=redefine_curl
travis_time:start:0299a1fe
travis_time:end:0299a1fe:start=1709113626683447397,finish=1709113626685106890,duration=1659493,event=nonblock_pipe
travis_time:start:0dab31b2
travis_time:end:0dab31b2:start=1709113626687429138,finish=1709113632715007566,duration=6027578428,event=apt_get_update
travis_time:start:385468d6
travis_time:end:385468d6:start=1709113632718229425,finish=1709113632720364326,duration=2134901,event=deprecate_xcode_64
travis_time:start:1bf7986d
travis_time:end:1bf7986d:start=1709113632723038751,finish=1709113636559844405,duration=3836805654,event=update_heroku
travis_time:start:0178ff98
travis_time:end:0178ff98:start=1709113636562700891,finish=1709113636564603951,duration=1903060,event=shell_session_update
travis_time:start:02045462
travis_fold:start:docker_mtu_and_registry_mirrors
travis_fold:end:docker_mtu_and_registry_mirrors
travis_time:end:02045462:start=1709113636567108534,finish=1709113638825318932,duration=2258210398,event=set_docker_mtu_and_registry_mirrors
travis_time:start:063661c8
travis_fold:start:resolvconf
travis_fold:end:resolvconf
travis_time:end:063661c8:start=1709113638828241228,finish=1709113638904953111,duration=76711883,event=resolvconf
travis_time:start:140e06eb
travis_time:end:140e06eb:start=1709113638908497433,finish=1709113639030643528,duration=122146095,event=maven_central_mirror
travis_time:start:13131a59
travis_time:end:13131a59:start=1709113639033674872,finish=1709113639116818546,duration=83143674,event=maven_https
travis_fold:start:apt
travis_time:start:0bf1a870
$ travis_apt_get_update
travis_time:end:0bf1a870:start=1709113639120628625,finish=1709113651099612329,duration=11978983704,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:01008906
$ 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:01008906:start=1709113651146115644,finish=1709113651834477408,duration=688361764,event=prepare
travis_fold:end:apt
travis_time:start:057ea954
travis_fold:start:services
travis_fold:end:services
travis_time:end:057ea954:start=1709113651837811524,finish=1709113654843448016,duration=3005636492,event=services
travis_time:start:028ab700
travis_time:end:028ab700:start=1709113654847016585,finish=1709113654849276957,duration=2260372,event=fix_ps4
travis_fold:start:postgresql
travis_time:start:02f05980
$ travis_setup_postgresql 11
Starting PostgreSQL v11
sudo systemctl start postgresql@11-main
travis_time:end:02f05980:start=1709113654852358945,finish=1709113658027945604,duration=3175586659,event=prepare
travis_fold:end:postgresql
travis_time:start:08f69814

travis_fold:start:git.checkout
travis_time:start:09dae318
travis_time:end:09dae318:start=1709113658034241849,finish=1709113658038759385,duration=4517536,event=checkout
travis_time:start:051efdf1
$ 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: 500, done.
remote: Counting objects:   0% (1/500)
remote: Counting objects:   1% (5/500)
remote: Counting objects:   2% (10/500)
remote: Counting objects:   3% (15/500)
remote: Counting objects:   4% (20/500)
remote: Counting objects:   5% (25/500)
remote: Counting objects:   6% (30/500)
remote: Counting objects:   7% (35/500)
remote: Counting objects:   8% (40/500)
remote: Counting objects:   9% (45/500)
remote: Counting objects:  10% (50/500)
remote: Counting objects:  11% (55/500)
remote: Counting objects:  12% (60/500)
remote: Counting objects:  13% (65/500)
remote: Counting objects:  14% (70/500)
remote: Counting objects:  15% (75/500)
remote: Counting objects:  16% (80/500)
remote: Counting objects:  17% (85/500)
remote: Counting objects:  18% (90/500)
remote: Counting objects:  19% (95/500)
remote: Counting objects:  20% (100/500)
remote: Counting objects:  21% (105/500)
remote: Counting objects:  22% (110/500)
remote: Counting objects:  23% (115/500)
remote: Counting objects:  24% (120/500)
remote: Counting objects:  25% (125/500)
remote: Counting objects:  26% (130/500)
remote: Counting objects:  27% (135/500)
remote: Counting objects:  28% (140/500)
remote: Counting objects:  29% (145/500)
remote: Counting objects:  30% (150/500)
remote: Counting objects:  31% (155/500)
remote: Counting objects:  32% (160/500)
remote: Counting objects:  33% (165/500)
remote: Counting objects:  34% (170/500)
remote: Counting objects:  35% (175/500)
remote: Counting objects:  36% (180/500)
remote: Counting objects:  37% (185/500)
remote: Counting objects:  38% (190/500)
remote: Counting objects:  39% (195/500)
remote: Counting objects:  40% (200/500)
remote: Counting objects:  41% (205/500)
remote: Counting objects:  42% (210/500)
remote: Counting objects:  43% (215/500)
remote: Counting objects:  44% (220/500)
remote: Counting objects:  45% (225/500)
remote: Counting objects:  46% (230/500)
remote: Counting objects:  47% (235/500)
remote: Counting objects:  48% (240/500)
remote: Counting objects:  49% (245/500)
remote: Counting objects:  50% (250/500)
remote: Counting objects:  51% (255/500)
remote: Counting objects:  52% (260/500)
remote: Counting objects:  53% (265/500)
remote: Counting objects:  54% (270/500)
remote: Counting objects:  55% (275/500)
remote: Counting objects:  56% (280/500)
remote: Counting objects:  57% (285/500)
remote: Counting objects:  58% (290/500)
remote: Counting objects:  59% (295/500)
remote: Counting objects:  60% (300/500)
remote: Counting objects:  61% (305/500)
remote: Counting objects:  62% (310/500)
remote: Counting objects:  63% (315/500)
remote: Counting objects:  64% (320/500)
remote: Counting objects:  65% (325/500)
remote: Counting objects:  66% (330/500)
remote: Counting objects:  67% (335/500)
remote: Counting objects:  68% (340/500)
remote: Counting objects:  69% (345/500)
remote: Counting objects:  70% (350/500)
remote: Counting objects:  71% (355/500)
remote: Counting objects:  72% (360/500)
remote: Counting objects:  73% (365/500)
remote: Counting objects:  74% (370/500)
remote: Counting objects:  75% (375/500)
remote: Counting objects:  76% (380/500)
remote: Counting objects:  77% (385/500)
remote: Counting objects:  78% (390/500)
remote: Counting objects:  79% (395/500)
remote: Counting objects:  80% (400/500)
remote: Counting objects:  81% (405/500)
remote: Counting objects:  82% (410/500)
remote: Counting objects:  83% (415/500)
remote: Counting objects:  84% (420/500)
remote: Counting objects:  85% (425/500)
remote: Counting objects:  86% (430/500)
remote: Counting objects:  87% (435/500)
remote: Counting objects:  88% (440/500)
remote: Counting objects:  89% (445/500)
remote: Counting objects:  90% (450/500)
remote: Counting objects:  91% (455/500)
remote: Counting objects:  92% (460/500)
remote: Counting objects:  93% (465/500)
remote: Counting objects:  94% (470/500)
remote: Counting objects:  95% (475/500)
remote: Counting objects:  96% (480/500)
remote: Counting objects:  97% (485/500)
remote: Counting objects:  98% (490/500)
remote: Counting objects:  99% (495/500)
remote: Counting objects: 100% (500/500)
remote: Counting objects: 100% (500/500), done.
remote: Compressing objects:   0% (1/258)
remote: Compressing objects:   1% (3/258)
remote: Compressing objects:   2% (6/258)
remote: Compressing objects:   3% (8/258)
remote: Compressing objects:   4% (11/258)
remote: Compressing objects:   5% (13/258)
remote: Compressing objects:   6% (16/258)
remote: Compressing objects:   7% (19/258)
remote: Compressing objects:   8% (21/258)
remote: Compressing objects:   9% (24/258)
remote: Compressing objects:  10% (26/258)
remote: Compressing objects:  11% (29/258)
remote: Compressing objects:  12% (31/258)
remote: Compressing objects:  13% (34/258)
remote: Compressing objects:  14% (37/258)
remote: Compressing objects:  15% (39/258)
remote: Compressing objects:  16% (42/258)
remote: Compressing objects:  17% (44/258)
remote: Compressing objects:  18% (47/258)
remote: Compressing objects:  19% (50/258)
remote: Compressing objects:  20% (52/258)
remote: Compressing objects:  21% (55/258)
remote: Compressing objects:  22% (57/258)
remote: Compressing objects:  23% (60/258)
remote: Compressing objects:  24% (62/258)
remote: Compressing objects:  25% (65/258)
remote: Compressing objects:  26% (68/258)
remote: Compressing objects:  27% (70/258)
remote: Compressing objects:  28% (73/258)
remote: Compressing objects:  29% (75/258)
remote: Compressing objects:  30% (78/258)
remote: Compressing objects:  31% (80/258)
remote: Compressing objects:  32% (83/258)
remote: Compressing objects:  33% (86/258)
remote: Compressing objects:  34% (88/258)
remote: Compressing objects:  35% (91/258)
remote: Compressing objects:  36% (93/258)
remote: Compressing objects:  37% (96/258)
remote: Compressing objects:  38% (99/258)
remote: Compressing objects:  39% (101/258)
remote: Compressing objects:  40% (104/258)
remote: Compressing objects:  41% (106/258)
remote: Compressing objects:  42% (109/258)
remote: Compressing objects:  43% (111/258)
remote: Compressing objects:  44% (114/258)
remote: Compressing objects:  45% (117/258)
remote: Compressing objects:  46% (119/258)
remote: Compressing objects:  47% (122/258)
remote: Compressing objects:  48% (124/258)
remote: Compressing objects:  49% (127/258)
remote: Compressing objects:  50% (129/258)
remote: Compressing objects:  51% (132/258)
remote: Compressing objects:  52% (135/258)
remote: Compressing objects:  53% (137/258)
remote: Compressing objects:  54% (140/258)
remote: Compressing objects:  55% (142/258)
remote: Compressing objects:  56% (145/258)
remote: Compressing objects:  57% (148/258)
remote: Compressing objects:  58% (150/258)
remote: Compressing objects:  59% (153/258)
remote: Compressing objects:  60% (155/258)
remote: Compressing objects:  61% (158/258)
remote: Compressing objects:  62% (160/258)
remote: Compressing objects:  63% (163/258)
remote: Compressing objects:  64% (166/258)
remote: Compressing objects:  65% (168/258)
remote: Compressing objects:  66% (171/258)
remote: Compressing objects:  67% (173/258)
remote: Compressing objects:  68% (176/258)
remote: Compressing objects:  69% (179/258)
remote: Compressing objects:  70% (181/258)
remote: Compressing objects:  71% (184/258)
remote: Compressing objects:  72% (186/258)
remote: Compressing objects:  73% (189/258)
remote: Compressing objects:  74% (191/258)
remote: Compressing objects:  75% (194/258)
remote: Compressing objects:  76% (197/258)
remote: Compressing objects:  77% (199/258)
remote: Compressing objects:  78% (202/258)
remote: Compressing objects:  79% (204/258)
remote: Compressing objects:  80% (207/258)
remote: Compressing objects:  81% (209/258)
remote: Compressing objects:  82% (212/258)
remote: Compressing objects:  83% (215/258)
remote: Compressing objects:  84% (217/258)
remote: Compressing objects:  85% (220/258)
remote: Compressing objects:  86% (222/258)
remote: Compressing objects:  87% (225/258)
remote: Compressing objects:  88% (228/258)
remote: Compressing objects:  89% (230/258)
remote: Compressing objects:  90% (233/258)
remote: Compressing objects:  91% (235/258)
remote: Compressing objects:  92% (238/258)
remote: Compressing objects:  93% (240/258)
remote: Compressing objects:  94% (243/258)
remote: Compressing objects:  95% (246/258)
remote: Compressing objects:  96% (248/258)
remote: Compressing objects:  97% (251/258)
remote: Compressing objects:  98% (253/258)
remote: Compressing objects:  99% (256/258)
remote: Compressing objects: 100% (258/258)
remote: Compressing objects: 100% (258/258), done.
Receiving objects:   0% (1/500)
Receiving objects:   1% (5/500)
Receiving objects:   2% (10/500)
Receiving objects:   3% (15/500)
Receiving objects:   4% (20/500)
Receiving objects:   5% (25/500)
Receiving objects:   6% (30/500)
Receiving objects:   7% (35/500)
Receiving objects:   8% (40/500)
Receiving objects:   9% (45/500)
Receiving objects:  10% (50/500)
Receiving objects:  11% (55/500)
Receiving objects:  12% (60/500)
Receiving objects:  13% (65/500)
Receiving objects:  14% (70/500)
Receiving objects:  15% (75/500)
Receiving objects:  16% (80/500)
Receiving objects:  17% (85/500)
Receiving objects:  18% (90/500)
Receiving objects:  19% (95/500)
Receiving objects:  20% (100/500)
Receiving objects:  21% (105/500)
Receiving objects:  22% (110/500)
Receiving objects:  23% (115/500)
Receiving objects:  24% (120/500)
Receiving objects:  25% (125/500)
Receiving objects:  26% (130/500)
Receiving objects:  27% (135/500)
Receiving objects:  28% (140/500)
Receiving objects:  29% (145/500)
Receiving objects:  30% (150/500)
Receiving objects:  31% (155/500)
Receiving objects:  32% (160/500)
Receiving objects:  33% (165/500)
Receiving objects:  34% (170/500)
Receiving objects:  35% (175/500)
Receiving objects:  36% (180/500)
Receiving objects:  37% (185/500)
Receiving objects:  38% (190/500)
Receiving objects:  39% (195/500)
remote: Total 500 (delta 249), reused 457 (delta 214), pack-reused 0
Receiving objects:  40% (200/500)
Receiving objects:  41% (205/500)
Receiving objects:  42% (210/500)
Receiving objects:  43% (215/500)
Receiving objects:  44% (220/500)
Receiving objects:  45% (225/500)
Receiving objects:  46% (230/500)
Receiving objects:  47% (235/500)
Receiving objects:  48% (240/500)
Receiving objects:  49% (245/500)
Receiving objects:  50% (250/500)
Receiving objects:  51% (255/500)
Receiving objects:  52% (260/500)
Receiving objects:  53% (265/500)
Receiving objects:  54% (270/500)
Receiving objects:  55% (275/500)
Receiving objects:  56% (280/500)
Receiving objects:  57% (285/500)
Receiving objects:  58% (290/500)
Receiving objects:  59% (295/500)
Receiving objects:  60% (300/500)
Receiving objects:  61% (305/500)
Receiving objects:  62% (310/500)
Receiving objects:  63% (315/500)
Receiving objects:  64% (320/500)
Receiving objects:  65% (325/500)
Receiving objects:  66% (330/500)
Receiving objects:  67% (335/500)
Receiving objects:  68% (340/500)
Receiving objects:  69% (345/500)
Receiving objects:  70% (350/500)
Receiving objects:  71% (355/500)
Receiving objects:  72% (360/500)
Receiving objects:  73% (365/500)
Receiving objects:  74% (370/500)
Receiving objects:  75% (375/500)
Receiving objects:  76% (380/500)
Receiving objects:  77% (385/500)
Receiving objects:  78% (390/500)
Receiving objects:  79% (395/500)
Receiving objects:  80% (400/500)
Receiving objects:  81% (405/500)
Receiving objects:  82% (410/500)
Receiving objects:  83% (415/500)
Receiving objects:  84% (420/500)
Receiving objects:  85% (425/500)
Receiving objects:  86% (430/500)
Receiving objects:  87% (435/500)
Receiving objects:  88% (440/500)
Receiving objects:  89% (445/500)
Receiving objects:  90% (450/500)
Receiving objects:  91% (455/500)
Receiving objects:  92% (460/500)
Receiving objects:  93% (465/500)
Receiving objects:  94% (470/500)
Receiving objects:  95% (475/500)
Receiving objects:  96% (480/500)
Receiving objects:  97% (485/500)
Receiving objects:  98% (490/500)
Receiving objects:  99% (495/500)
Receiving objects: 100% (500/500)
Receiving objects: 100% (500/500), 69.28 KiB | 1.78 MiB/s, done.
Resolving deltas:   0% (0/249)
Resolving deltas:   1% (3/249)
Resolving deltas:   2% (5/249)
Resolving deltas:   3% (8/249)
Resolving deltas:   4% (10/249)
Resolving deltas:   5% (13/249)
Resolving deltas:   6% (15/249)
Resolving deltas:   7% (18/249)
Resolving deltas:   8% (20/249)
Resolving deltas:   9% (23/249)
Resolving deltas:  10% (25/249)
Resolving deltas:  11% (28/249)
Resolving deltas:  12% (30/249)
Resolving deltas:  13% (33/249)
Resolving deltas:  14% (35/249)
Resolving deltas:  15% (38/249)
Resolving deltas:  16% (40/249)
Resolving deltas:  17% (43/249)
Resolving deltas:  18% (45/249)
Resolving deltas:  19% (48/249)
Resolving deltas:  20% (50/249)
Resolving deltas:  21% (53/249)
Resolving deltas:  22% (55/249)
Resolving deltas:  23% (58/249)
Resolving deltas:  24% (60/249)
Resolving deltas:  25% (63/249)
Resolving deltas:  26% (65/249)
Resolving deltas:  27% (68/249)
Resolving deltas:  28% (70/249)
Resolving deltas:  29% (73/249)
Resolving deltas:  30% (75/249)
Resolving deltas:  31% (78/249)
Resolving deltas:  32% (80/249)
Resolving deltas:  33% (83/249)
Resolving deltas:  34% (85/249)
Resolving deltas:  35% (88/249)
Resolving deltas:  36% (90/249)
Resolving deltas:  37% (93/249)
Resolving deltas:  38% (95/249)
Resolving deltas:  39% (98/249)
Resolving deltas:  40% (100/249)
Resolving deltas:  41% (103/249)
Resolving deltas:  42% (105/249)
Resolving deltas:  43% (108/249)
Resolving deltas:  44% (110/249)
Resolving deltas:  45% (113/249)
Resolving deltas:  46% (115/249)
Resolving deltas:  47% (118/249)
Resolving deltas:  48% (120/249)
Resolving deltas:  49% (123/249)
Resolving deltas:  50% (125/249)
Resolving deltas:  51% (128/249)
Resolving deltas:  52% (130/249)
Resolving deltas:  53% (132/249)
Resolving deltas:  54% (135/249)
Resolving deltas:  55% (137/249)
Resolving deltas:  56% (140/249)
Resolving deltas:  57% (142/249)
Resolving deltas:  58% (145/249)
Resolving deltas:  59% (147/249)
Resolving deltas:  60% (150/249)
Resolving deltas:  61% (152/249)
Resolving deltas:  62% (155/249)
Resolving deltas:  63% (157/249)
Resolving deltas:  64% (160/249)
Resolving deltas:  65% (162/249)
Resolving deltas:  66% (165/249)
Resolving deltas:  67% (167/249)
Resolving deltas:  68% (170/249)
Resolving deltas:  69% (172/249)
Resolving deltas:  70% (175/249)
Resolving deltas:  71% (177/249)
Resolving deltas:  72% (180/249)
Resolving deltas:  73% (182/249)
Resolving deltas:  74% (185/249)
Resolving deltas:  75% (187/249)
Resolving deltas:  76% (190/249)
Resolving deltas:  77% (192/249)
Resolving deltas:  78% (195/249)
Resolving deltas:  79% (197/249)
Resolving deltas:  80% (200/249)
Resolving deltas:  81% (202/249)
Resolving deltas:  82% (205/249)
Resolving deltas:  83% (207/249)
Resolving deltas:  84% (210/249)
Resolving deltas:  85% (212/249)
Resolving deltas:  86% (215/249)
Resolving deltas:  87% (217/249)
Resolving deltas:  88% (221/249)
Resolving deltas:  89% (223/249)
Resolving deltas:  90% (225/249)
Resolving deltas:  91% (227/249)
Resolving deltas:  92% (230/249)
Resolving deltas:  93% (232/249)
Resolving deltas:  94% (235/249)
Resolving deltas:  95% (237/249)
Resolving deltas:  96% (240/249)
Resolving deltas:  97% (242/249)
Resolving deltas:  98% (245/249)
Resolving deltas:  99% (247/249)
Resolving deltas: 100% (249/249)
Resolving deltas: 100% (249/249), done.
travis_time:end:051efdf1:start=1709113658041760058,finish=1709113658489389231,duration=447629173,event=checkout
$ cd travis-ci/marginalia
$ git checkout -qf 584927e7921c9d0d5111ee79f7b577725c940e5d
travis_fold:end:git.checkout

travis_time:end:051efdf1:start=1709113658041760058,finish=1709113658495374960,duration=453614902,event=checkout
travis_time:start:1bea9896

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:1bea9896:start=1709113658498298113,finish=1709113658504933199,duration=6635086,event=env
travis_fold:start:rvm
travis_time:start:008207f1
$ 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:008207f1:start=1709113658513478292,finish=1709113661267654262,duration=2754175970,event=
travis_time:start:1109bd0d
$ rvm use 3.2.2 --install --binary --fuzzy
curl: (22) The requested URL returned error: 404 
Required ruby-3.2.2 is not installed - installing.
curl: (22) The requested URL returned error: 404 
Searching for binary rubies, this might take some time.
Found remote file https://rubies.travis-ci.org/ubuntu/18.04/x86_64/ruby-3.2.2.tar.bz2
Checking requirements for ubuntu.
Requirements installation successful.
ruby-3.2.2 - #configure
ruby-3.2.2 - #download
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:01 --:--:--     0
  0     0    0     0    0     0      0      0 --:--:--  0:00:01 --:--:--     0

 19 29.2M   19 5942k    0     0  3758k      0  0:00:07  0:00:01  0:00:06 3758k
100 29.2M  100 29.2M    0     0  15.4M      0  0:00:01  0:00:01 --:--:-- 77.0M
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:1109bd0d:start=1709113661271693596,finish=1709113683244388855,duration=21972695259,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:0f05eef8
$ bash -c "yes | gem uninstall -i /home/travis/.rvm/gems/ruby-3.2.0@global rake"
Gem 'rake' is not installed
travis_time:end:0f05eef8:start=1709113683656441183,finish=1709113683814345673,duration=157904490,event=before_install
travis_fold:end:before_install
travis_fold:start:install.bundler
travis_time:start:0fa11974
$ 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
Installing bigdecimal 3.1.6 with native extensions
Fetching connection_pool 2.4.1
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:0fa11974:start=1709113683819392661,finish=1709113699732995761,duration=15913603100,event=install
travis_fold:end:install.bundler

travis_fold:start:before_script
travis_time:start:138e13fd
$ sudo chmod 0644 $MARGINALIA_LOG_FILE
travis_time:end:138e13fd:start=1709113699737963513,finish=1709113699746672323,duration=8708810,event=before_script
travis_fold:end:before_script
travis_time:start:268f2018
$ 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 51782

# Running:

......

Finished in 0.005211s, 1151.5188 runs/s, 1535.3583 assertions/s.

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

# Running:

..

Finished in 0.001227s, 1630.5792 runs/s, 2445.8688 assertions/s.

2 runs, 3 assertions, 0 failures, 0 errors, 0 skips
-- create_table("posts", {:force=>true})
   -> 0.0064s
Run options: --seed 62441

# Running:

.

Finished in 0.018161s, 55.0636 runs/s, 165.1908 assertions/s.

1 runs, 3 assertions, 0 failures, 0 errors, 0 skips
Run options: --seed 48417

# Running:

..

Finished in 0.005297s, 377.5920 runs/s, 755.1839 assertions/s.

2 runs, 4 assertions, 0 failures, 0 errors, 0 skips
travis_time:end:268f2018:start=1709113699750916253,finish=1709113702046768961,duration=2295852708,event=script
The command "bundle exec rake db:reset test:postgresql" exited with 0.
travis_time:start:08271c0a
$ cat $MARGINALIA_LOG_FILE
2024-02-28 09:47:35.537 UTC [4905] LOG:  listening on IPv4 address "127.0.0.1", port 5432
2024-02-28 09:47:35.537 UTC [4905] LOG:  listening on IPv4 address "127.0.1.1", port 5432
2024-02-28 09:47:35.537 UTC [4905] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-02-28 09:47:35.558 UTC [4914] LOG:  database system was shut down at 2024-02-01 08:57:39 UTC
2024-02-28 09:47:35.563 UTC [4905] LOG:  database system is ready to accept connections
2024-02-28 09:47:36.103 UTC [4922] [unknown]@[unknown] LOG:  incomplete startup packet
2024-02-28 09:47:37.702 UTC [4935] postgres@postgres ERROR:  role "travis" already exists
2024-02-28 09:47:37.702 UTC [4935] postgres@postgres STATEMENT:  CREATE ROLE travis SUPERUSER CREATEDB CREATEROLE INHERIT LOGIN;
2024-02-28 09:48:20.628 UTC [9412] travis@marginalia_test LOG:  statement: DROP TABLE IF EXISTS posts;
	 /**/
2024-02-28 09:48:20.630 UTC [9412] travis@marginalia_test LOG:  statement: CREATE TABLE posts (
	  id INTEGER,
	  title VARCHAR
	);
	 /**/
2024-02-28 09:48:20.638 UTC [9412] travis@marginalia_test LOG:  statement: INSERT INTO POSTS VALUES (1, 'My Title') /*adapter:pg,app:crud.insert*/
2024-02-28 09:48:20.638 UTC [9412] travis@marginalia_test LOG:  statement: UPDATE posts
	SET id = 2
	where id = 1
	 /*adapter:pg,app:crud.update*/
2024-02-28 09:48:20.639 UTC [9412] travis@marginalia_test LOG:  statement: DELETE FROM POSTS where id = 2 /*adapter:pg,app:crud.delete*/
2024-02-28 09:48:20.639 UTC [9412] travis@marginalia_test LOG:  statement: select * from posts; /*adapter:pg,app:async_query*/
2024-02-28 09:48:20.640 UTC [9412] travis@marginalia_test LOG:  statement: select * from posts; /*adapter:pg,app:foobar*/
2024-02-28 09:48:20.640 UTC [9412] travis@marginalia_test LOG:  statement: select * from posts; /*adapter:pg,app:async_exec*/
2024-02-28 09:48:20.641 UTC [9412] travis@marginalia_test LOG:  statement: select * from posts; /*adapter:pg,app:query*/
2024-02-28 09:48:20.641 UTC [9412] travis@marginalia_test LOG:  execute statement1: INSERT INTO posts (id, title) VALUES ($1, $2) /*adapter:pg,app:prepare*/
2024-02-28 09:48:20.641 UTC [9412] travis@marginalia_test DETAIL:  parameters: $1 = '100', $2 = 'Welcome Tessa!'
2024-02-28 09:48:21.620 UTC [9430] travis@marginalia_test LOG:  statement: DROP TABLE IF EXISTS posts;
	 /**/
2024-02-28 09:48:21.624 UTC [9430] travis@marginalia_test LOG:  statement: SHOW max_identifier_length /**/
2024-02-28 09:48:21.625 UTC [9430] travis@marginalia_test LOG:  statement: DROP TABLE IF EXISTS "posts" /**/
2024-02-28 09:48:21.625 UTC [9430] travis@marginalia_test LOG:  statement: CREATE TABLE "posts" ("id" bigserial primary key, "title" character varying) /**/
2024-02-28 09:48:21.628 UTC [9430] 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:48:21.629 UTC [9430] travis@marginalia_test LOG:  statement: CREATE TABLE "schema_migrations" ("version" character varying NOT NULL PRIMARY KEY) /**/
2024-02-28 09:48:21.631 UTC [9430] 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:48:21.631 UTC [9430] 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:48:21.633 UTC [9430] 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:48:21.633 UTC [9430] travis@marginalia_test DETAIL:  parameters: $1 = 'environment'
2024-02-28 09:48:21.635 UTC [9430] travis@marginalia_test LOG:  execute <unnamed>: INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES ('environment', 'test', '2024-02-28 09:48:21.635383', '2024-02-28 09:48:21.635388') RETURNING "key"
2024-02-28 09:48:21.642 UTC [9430] 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:48:21.644 UTC [9430] 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:48:21.644 UTC [9430] 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:48:21.650 UTC [9430] travis@marginalia_test LOG:  statement: BEGIN /*adapter:active_record,app:crud.insert*/
2024-02-28 09:48:21.650 UTC [9430] travis@marginalia_test LOG:  execute <unnamed>: INSERT INTO "posts" ("title") VALUES ($1) RETURNING "id"
2024-02-28 09:48:21.650 UTC [9430] travis@marginalia_test DETAIL:  parameters: $1 = 'foo'
2024-02-28 09:48:21.651 UTC [9430] travis@marginalia_test LOG:  statement: COMMIT /*adapter:active_record,app:crud.insert*/
2024-02-28 09:48:21.655 UTC [9430] travis@marginalia_test LOG:  statement: SHOW search_path /*adapter:active_record,app:crud.update*/
2024-02-28 09:48:21.655 UTC [9430] 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:48:21.655 UTC [9430] travis@marginalia_test DETAIL:  parameters: $1 = '1', $2 = '1'
2024-02-28 09:48:21.656 UTC [9430] travis@marginalia_test LOG:  statement: BEGIN /*adapter:active_record,app:crud.update*/
2024-02-28 09:48:21.657 UTC [9430] travis@marginalia_test LOG:  execute <unnamed>: UPDATE "posts" SET "title" = $1 WHERE "posts"."id" = $2
2024-02-28 09:48:21.657 UTC [9430] travis@marginalia_test DETAIL:  parameters: $1 = 'bar', $2 = '1'
2024-02-28 09:48:21.657 UTC [9430] travis@marginalia_test LOG:  statement: COMMIT /*adapter:active_record,app:crud.update*/
2024-02-28 09:48:21.657 UTC [9430] 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:48:21.657 UTC [9430] travis@marginalia_test DETAIL:  parameters: $1 = '1', $2 = '1'
2024-02-28 09:48:21.658 UTC [9430] travis@marginalia_test LOG:  statement: BEGIN /*adapter:active_record,app:crud.delete*/
2024-02-28 09:48:21.658 UTC [9430] travis@marginalia_test LOG:  execute <unnamed>: DELETE FROM "posts" WHERE "posts"."id" = $1
2024-02-28 09:48:21.658 UTC [9430] travis@marginalia_test DETAIL:  parameters: $1 = '1'
2024-02-28 09:48:21.658 UTC [9430] travis@marginalia_test LOG:  statement: COMMIT /*adapter:active_record,app:crud.delete*/
2024-02-28 09:48:22.024 UTC [9439] travis@marginalia_test LOG:  statement: DROP TABLE IF EXISTS posts
2024-02-28 09:48:22.025 UTC [9439] travis@marginalia_test LOG:  statement: CREATE TABLE posts (id INTEGER, title VARCHAR(255));
2024-02-28 09:48:22.033 UTC [9439] travis@marginalia_test LOG:  statement: SELECT CAST(current_setting('server_version_num') AS integer) AS v /*adapter:sequel,app:foobar*/
2024-02-28 09:48:22.033 UTC [9439] travis@marginalia_test LOG:  statement: SELECT * FROM "posts" /*adapter:sequel,app:foobar*/
2024-02-28 09:48:22.034 UTC [9439] travis@marginalia_test LOG:  statement: SELECT "pg_attribute"."attname" AS "pk" FROM "pg_class", "pg_attribute", "pg_index", "pg_namespace" WHERE (("pg_class"."oid" = "pg_attribute"."attrelid") AND ("pg_class"."relnamespace" = "pg_namespace"."oid") AND ("pg_class"."oid" = "pg_index"."indrelid") AND ("pg_index"."indkey"[0] = "pg_attribute"."attnum") AND ("pg_index"."indisprimary" = 't') AND ("pg_class"."oid" = CAST(CAST('"posts"' AS regclass) AS oid))) LIMIT 1 /*adapter:sequel,app:crud.insert*/
2024-02-28 09:48:22.035 UTC [9439] travis@marginalia_test LOG:  statement: INSERT INTO "posts" ("id", "title") VALUES (1, 'Insert') RETURNING NULL /*adapter:sequel,app:crud.insert*/
2024-02-28 09:48:22.036 UTC [9439] travis@marginalia_test LOG:  statement: UPDATE "posts" SET "title" = 'Update' WHERE ("id" = 1) /*adapter:sequel,app:crud.update*/
2024-02-28 09:48:22.036 UTC [9439] travis@marginalia_test LOG:  statement: DELETE FROM "posts" WHERE ("id" = 1) /*adapter:sequel,app:crud.delete*/
travis_time:end:08271c0a:start=1709113702051651122,finish=1709113702056179128,duration=4528006,event=script
The command "cat $MARGINALIA_LOG_FILE" exited with 0.


Done. Your build exited with 0.