Arvados

#13752#note-15 says

Evidently file_names was already dropped from the (non-full-text) index.

...but it's still in the full-text index.

https://www.postgresql.org/docs/9.6/textsearch-limitations.html:

The length of a tsvector (lexemes + positions) must be less than 1 megabyte

It seems the error text "string is too long for tsvector" is misleading. This 27 MB string is not too long for tsvector:

select to_tsvector(repeat('abcdefghijklmnopqrstuvwxyz ',2000000));

Hopefully, limiting the input to 1M is an effective way to ensure the output doesn't exceed 1M.

14560-tsvector-too-long @ 2ab2ec271e09c54f6e7e1d4c3adbd1d76e56f1cd
https://ci.curoverse.com/view/Developer/job/developer-run-tests/993/

With an example that crashes:

Tom Clegg wrote:

14560-tsvector-too-long @ 2ab2ec271e09c54f6e7e1d4c3adbd1d76e56f1cd
https://ci.curoverse.com/view/Developer/job/developer-run-tests/993/

Seems like it should work. I don't see any reason to_tsvector(substr(...)) would be a problem for the index. I guess that's a "looks good enough to me", I haven't tested directly.

For the sake of argument, an alternate fix might be to go back to truncating the file_names column like we did before (either way, we will be missing some filenames from the search index for large collections).

I'm pretty sure length(to_tsvector(join(" ",filenames"))) isn't returning bytes, but I'm not sure exactly what it is counting (length of the text search vector obviously... maybe unique lexemes?)

Post 1.3 we'll need to revisit alternatives to full text search indexes for filenames, eg https://dev.arvados.org/issues/13752#note-7

Peter Amstutz wrote:

Tom Clegg wrote:

14560-tsvector-too-long @ 2ab2ec271e09c54f6e7e1d4c3adbd1d76e56f1cd
https://ci.curoverse.com/view/Developer/job/developer-run-tests/993/

Seems like it should work. I don't see any reason to_tsvector(substr(...)) would be a problem for the index. I guess that's a "looks good enough to me", I haven't tested directly.

I went ahead and merged this so we can have packages to test with.

Peter Amstutz wrote:

I'm pretty sure length(to_tsvector(join(" ",filenames"))) isn't returning bytes, but I'm not sure exactly what it is counting (length of the text search vector obviously... maybe unique lexemes?)

The rule is length of a tsvector (lexemes + positions) must be less than 1 megabyte and the error refers to a number of bytes, so I suspect "length" is the encoded/stored size.

Whatever it is, it seems like length(to_tsvector()) does return the length mentioned in the rule/error: in all cases I've tried, either it's less than 1048576, or to_tsvector() throws the "max 1048575 bytes" error.

This will be a slow migration. Let's make sure the new index still performs well before this gets into a release.

Trying with cc059aea76194417f5aaf37073b3ae530219b11e:

Error: Could not update: Execution of '/usr/bin/apt-get -q -y -o DPkg::Options::=--force-confold install arvados-api-server' returned 100: Reading package lists...
Building dependency tree...
Reading state information...
The following packages will be upgraded:
  arvados-api-server
1 upgraded, 0 newly installed, 0 to remove and 255 not upgraded.
Need to get 29.4 MB of archives.
After this operation, 46.1 kB of additional disk space will be used.
Get:1 http://apt.arvados.org xenial-dev/main amd64 arvados-api-server amd64 1.3.0-1 [29.4 MB]
Fetched 29.4 MB in 1s (15.1 MB/s)
(Reading database ... 111304 files and directories currently installed.)
Preparing to unpack .../arvados-api-server_1.3.0-1_amd64.deb ...
Unpacking arvados-api-server (1.3.0-1) over (1.2.1-1) ...
Setting up arvados-api-server (1.3.0-1) ...

Assumption: nginx is configured to serve Rails from
            /var/www/arvados-api/current
Assumption: nginx and passenger run as www-data

Creating symlinks to configuration in /etc/arvados/api ...... done.
Running bundle install... done.
Ensuring directory and file permissions ...... done.
Running db:migrate...Defaulting to memory cache, because /var/www/arvados-api/current/tmp/cache owner (uid=33) is not me (uid=0)
The PGconn, PGresult, and PGError constants are deprecated, and will be
removed as of version 1.0.

You should use PG::Connection, PG::Result, and PG::Error instead, respectively.

Called from /var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activesupport-4.2.10/lib/active_support/dependencies.rb:240:in `load_dependency'
== 20180917200000 ReplaceFullTextIndexes: migrating ===========================
-- execute("DROP INDEX IF EXISTS collections_full_text_search_idx")
   -> 0.8383s
-- execute("CREATE INDEX collections_full_text_search_idx ON collections USING gin(to_tsvector('english', substr(coalesce(owner_uuid,'') || ' ' || coalesce(modified_by_client_uuid,'') || ' ' || coalesce(modified_by_user_uuid,'') || ' ' || coalesce(portable_data_hash,'') || ' 
' || coalesce(uuid,'') || ' ' || coalesce(name,'') || ' ' || coalesce(description,'') || ' ' || coalesce(properties::text,'') || ' ' || coalesce(file_names,''), 0, 1000000)))")
   -> 46.5404s
-- execute("DROP INDEX IF EXISTS container_requests_full_text_search_idx")
   -> 0.0196s
-- execute("CREATE INDEX container_requests_full_text_search_idx ON container_requests USING gin(to_tsvector('english', substr(coalesce(uuid,'') || ' ' || coalesce(owner_uuid,'') || ' ' || coalesce(modified_by_client_uuid,'') || ' ' || coalesce(modified_by_user_uuid,'') || ' ' || coalesce(name,'') || ' ' || coalesce(description,'') || ' ' || coalesce(properties::text,'') || ' ' || coalesce(state,'') || ' ' || coalesce(requesting_container_uuid,'') || ' ' || coalesce(container_uuid,'') || ' ' || coalesce(runtime_constraints::text,'') || ' ' || coalesce(container_image,'') || ' ' || coalesce(environment::text,'') || ' ' || coalesce(cwd,'') || ' ' || coalesce(command::text,'') || ' ' || coalesce(output_path,'') || ' ' || coalesce(filters,'') || ' ' || coalesce(scheduling_parameters::text,'') || ' ' || coalesce(output_uuid,'') || ' ' || coalesce(log_uuid,'') || ' ' || coalesce(output_name,''), 0, 1000000)))")
   -> 4.3381s
-- execute("DROP INDEX IF EXISTS groups_full_text_search_idx")
   -> 0.0056s
-- execute("CREATE INDEX groups_full_text_search_idx ON groups USING gin(to_tsvector('english', substr(coalesce(uuid,'') || ' ' || coalesce(owner_uuid,'') || ' ' || coalesce(modified_by_client_uuid,'') || ' ' || coalesce(modified_by_user_uuid,'') || ' ' || coalesce(name,'') || ' ' || coalesce(description,'') || ' ' || coalesce(group_class,'') || ' ' || coalesce(properties::text,''), 0, 1000000)))")
   -> 0.1267s
-- execute("DROP INDEX IF EXISTS jobs_full_text_search_idx")
   -> 0.0183s
-- execute("CREATE INDEX jobs_full_text_search_idx ON jobs USING gin(to_tsvector('english', substr(coalesce(uuid,'') || ' ' || coalesce(owner_uuid,'') || ' ' || coalesce(modified_by_client_uuid,'') || ' ' || coalesce(modified_by_user_uuid,'') || ' ' || coalesce(submit_id,'') || ' ' || coalesce(script,'') || ' ' || coalesce(script_version,'') || ' ' || coalesce(script_parameters::text,'') || ' ' || coalesce(cancelled_by_client_uuid,'') || ' ' || coalesce(cancelled_by_user_uuid,'') || ' ' || coalesce(output,'') || ' ' || coalesce(is_locked_by_uuid,'') || ' ' || coalesce(log,'') || ' ' || coalesce(tasks_summary::text,'') || ' ' || coalesce(runtime_constraints::text,'') || ' ' || coalesce(repository,'') || ' ' || coalesce(supplied_script_version,'') || ' ' || coalesce(docker_image_locator,'') || ' ' || coalesce(description,'') || ' ' || coalesce(state,'') || ' ' || coalesce(arvados_sdk_version,'') || ' ' || coalesce(components::text,''), 0, 1000000)))")
   -> 27.6990s
-- execute("DROP INDEX IF EXISTS pipeline_instances_full_text_search_idx")
   -> 0.0008s
-- execute("CREATE INDEX pipeline_instances_full_text_search_idx ON pipeline_instances USING gin(to_tsvector('english', substr(coalesce(uuid,'') || ' ' || coalesce(owner_uuid,'') || ' ' || coalesce(modified_by_client_uuid,'') || ' ' || coalesce(modified_by_user_uuid,'') || ' ' || coalesce(pipeline_template_uuid,'') || ' ' || coalesce(name,'') || ' ' || coalesce(components::text,'') || ' ' || coalesce(properties::text,'') || ' ' || coalesce(state,'') || ' ' || coalesce(components_summary::text,'') || ' ' || coalesce(description,''), 0, 1000000)))")
   -> 73.1543s
-- execute("DROP INDEX IF EXISTS pipeline_templates_full_text_search_idx")
   -> 0.0090s
-- execute("CREATE INDEX pipeline_templates_full_text_search_idx ON pipeline_templates USING gin(to_tsvector('english', substr(coalesce(uuid,'') || ' ' || coalesce(owner_uuid,'') || ' ' || coalesce(modified_by_client_uuid,'') || ' ' || coalesce(modified_by_user_uuid,'') || ' ' || coalesce(name,'') || ' ' || coalesce(components::text,'') || ' ' || coalesce(description,''), 0, 1000000)))")
   -> 1.2197s
-- execute("DROP INDEX IF EXISTS workflows_full_text_search_idx")
   -> 0.0054s
-- execute("CREATE INDEX workflows_full_text_search_idx ON workflows USING gin(to_tsvector('english', substr(coalesce(uuid,'') || ' ' || coalesce(owner_uuid,'') || ' ' || coalesce(modified_by_client_uuid,'') || ' ' || coalesce(modified_by_user_uuid,'') || ' ' || coalesce(name,'') || ' ' || coalesce(description,''), 0, 1000000)))")
   -> 0.0231s
== 20180917200000 ReplaceFullTextIndexes: migrated (154.0194s) ================

== 20180917205609 RecomputeFileNamesIndex: migrating ==========================
WARNING:  there is already a transaction in progress
rake aborted!
StandardError: An error has occurred, this and all later migrations canceled:

PG::ProgramLimitExceeded: ERROR:  string is too long for tsvector (1099830 bytes, max 1048575 bytes)
: update collections set file_names=$1 where portable_data_hash=$2
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:602:in `exec_prepared'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:602:in `block in exec_cache'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract_adapter.rb:484:in `block in log'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activesupport-4.2.10/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract_adapter.rb:478:in `log'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:601:in `exec_cache'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:585:in `execute_and_clear'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql/database_statements.rb:160:in `exec_query'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:9:in `block in do_batch'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:8:in `do_batch'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:40:in `block in up'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:35:in `up'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:611:in `exec_migration'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:592:in `block (2 levels) in migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:591:in `block in migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/connection_pool.rb:292:in `with_connection'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:590:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:768:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1023:in `block in execute_migration_in_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1069:in `block in ddl_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/transactions.rb:220:in `transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1069:in `ddl_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1022:in `execute_migration_in_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:984:in `block in migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:980:in `each'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:980:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:823:in `up'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:801:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/tasks/database_tasks.rb:139:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/railties/databases.rake:44:in `block (2 levels) in <top (required)>'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/rake-12.3.1/exe/rake:27:in `<top (required)>'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli/exec.rb:75:in `load'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli/exec.rb:75:in `kernel_load'

/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli/exec.rb:28:in `run'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli.rb:424:in `exec'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor/invocation.rb:126:in `invoke_command'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor.rb:387:in `dispatch'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli.rb:27:in `dispatch'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor/base.rb:466:in `start'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli.rb:18:in `start'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/exe/bundle:30:in `block in <top (required)>'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/friendly_errors.rb:122:in `with_friendly_errors'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/exe/bundle:22:in `<top (required)>'
/usr/local/rvm/gems/ruby-2.3.5/bin/bundle:23:in `load'
/usr/local/rvm/gems/ruby-2.3.5/bin/bundle:23:in `<main>'
/usr/local/rvm/gems/ruby-2.3.5/bin/ruby_executable_hooks:15:in `eval'
/usr/local/rvm/gems/ruby-2.3.5/bin/ruby_executable_hooks:15:in `<main>'

Caused by:
ActiveRecord::StatementInvalid: PG::ProgramLimitExceeded: ERROR:  string is too long for tsvector (1099830 bytes, max 1048575 bytes)
: update collections set file_names=$1 where portable_data_hash=$2
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:602:in `exec_prepared'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:602:in `block in exec_cache'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract_adapter.rb:484:in `block in log'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activesupport-4.2.10/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract_adapter.rb:478:in `log'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:601:in `exec_cache'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:585:in `execute_and_clear'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql/database_statements.rb:160:in `exec_query'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:9:in `block in do_batch'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:8:in `do_batch'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:40:in `block in up'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:35:in `up'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:611:in `exec_migration'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:592:in `block (2 levels) in migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:591:in `block in migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/connection_pool.rb:292:in `with_connection'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:590:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:768:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1023:in `block in execute_migration_in_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1069:in `block in ddl_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/transactions.rb:220:in `transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1069:in `ddl_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1022:in `execute_migration_in
_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:984:in `block in migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:980:in `each'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:980:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:823:in `up'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:801:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/tasks/database_tasks.rb:139:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/railties/databases.rake:44:in `block (2 levels) in <top (required)>'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/rake-12.3.1/exe/rake:27:in `<top (required)>'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli/exec.rb:75:in `load'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli/exec.rb:75:in `kernel_load'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli/exec.rb:28:in `run'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli.rb:424:in `exec'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor/invocation.rb:126:in `invoke_command'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor.rb:387:in `dispatch'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli.rb:27:in `dispatch'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor/base.rb:466:in `start'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli.rb:18:in `start'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/exe/bundle:30:in `block in <top (required)>'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/friendly_errors.rb:122:in `with_friendly_errors'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/exe/bundle:22:in `<top (required)>'
/usr/local/rvm/gems/ruby-2.3.5/bin/bundle:23:in `load'
/usr/local/rvm/gems/ruby-2.3.5/bin/bundle:23:in `<main>'
/usr/local/rvm/gems/ruby-2.3.5/bin/ruby_executable_hooks:15:in `eval'
/usr/local/rvm/gems/ruby-2.3.5/bin/ruby_executable_hooks:15:in `<main>'

Caused by:
PG::ProgramLimitExceeded: ERROR:  string is too long for tsvector (1099830 bytes, max 1048575 bytes)
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:602:in `exec_prepared'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:602:in `block in exec_cache'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract_adapter.rb:484:in `block in log'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activesupport-4.2.10/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract_adapter.rb:478:in `log'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:601:in `exec_cache'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql_adapter.rb:585:in `execute_and_clear'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/postgresql/database_statements.rb:160:in `exec_query'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:9:in `block in do_batch'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:8:in `do_batch'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:40:in `block in up'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/relation/delegation.rb:46:in `each'
/var/www/arvados-api/current/db/migrate/20180917205609_recompute_file_names_index.rb:35:in `up'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:611:in `exec_migration'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:592:in `block (2 levels) in migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:591:in `block in migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/connection_pool.rb:292:in `with_connection'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:590:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:768:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1023:in `block in execute_migration_in_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1069:in `block in ddl_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/transactions.rb:220:in `transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1069:in `ddl_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:1022:in `execute_migration_in_transaction'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:984:in `block in migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:980:in `each'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:980:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:823:in `up'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/migration.rb:801:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/tasks/database_tasks.rb:139:in `migrate'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/activerecord-4.2.10/lib/active_record/railties/databases.rake:44:in `block (2 levels) in <top (required)>'
/var/www/arvados-api/shared/vendor_bundle/ruby/2.3.0/gems/rake-12.3.1/exe/rake:27:in `<top (required)>'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli/exec.rb:75:in `load'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli/exec.rb:75:in `kernel_load'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli/exec.rb:28:in `run'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli.rb:424:in `exec'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor/invocation.rb:126:in `invoke_command'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor.rb:387:in `dispatch'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli.rb:27:in `dispatch'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/vendor/thor/lib/thor/base.rb:466:in `start'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/cli.rb:18:in `start'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/exe/bundle:30:in `block in <top (required)>'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/lib/bundler/friendly_errors.rb:122:in `with_friendly_errors'
/usr/local/rvm/gems/ruby-2.3.5/gems/bundler-1.16.0/exe/bundle:22:in `<top (required)>'
/usr/local/rvm/gems/ruby-2.3.5/bin/bundle:23:in `load'
/usr/local/rvm/gems/ruby-2.3.5/bin/bundle:23:in `<main>'
/usr/local/rvm/gems/ruby-2.3.5/bin/ruby_executable_hooks:15:in `eval'
/usr/local/rvm/gems/ruby-2.3.5/bin/ruby_executable_hooks:15:in `<main>'
Tasks: TOP => db:migrate
(See full trace by running task with --trace)
 failed.
dpkg: error processing package arvados-api-server (--configure):
 subprocess installed post-installation script returned error exit status 1
Errors were encountered while processing:
 arvados-api-server
E: Sub-process /usr/bin/dpkg returned an error code (1)
Notice: /Stage[main]/Arvados-api-server/File[/var/www/qr1hi.arvadosapi.com]: Dependency Package[arvados-api-server] has failures: true
Warning: /Stage[main]/Arvados-api-server/File[/var/www/qr1hi.arvadosapi.com]: Skipping because of failed dependencies
Notice: /Stage[main]/Arvados-api-server/File[/var/www/qr1hi.arvadosapi.com/shared]: Dependency Package[arvados-api-server] has failures: true  
Warning: /Stage[main]/Arvados-api-server/File[/var/www/qr1hi.arvadosapi.com/shared]: Skipping because of failed dependencies
Notice: /Stage[main]/Arvados-dns-server/Exec[ensure_unbound_conf.d_ownership]/returns: executed successfully