Project

General

Profile

Bug #18005

Updated by Ward Vandewege about 3 years ago

I am seeing an "undefined method `each_line` for nil:NilClass error on ce8i5 when trying to add a new property to a collection without any properties (I used wb2): 

 <pre> 
 Aug 10 15:49:36 api.ce8i5.arvadosapi.com arvados-controller[22796]: {"PID":22796,"RequestID":"req-1lpuf064itirjfaslvcm","level":"info","msg":"request","remoteAddr":"127.0.0.1:40238","reqBytes":86,"reqForwardedFor":"207.180.129.25","reqHost":"ce8i5.arvadosapi.com","reqMethod":"PUT","reqPath":"arvados/v1/collections/ce8i5-4zz18-k74yj38bjtguqg4","reqQuery":"","time":"2021-08-10T15:49:36.212264450Z"} 
 Aug 10 15:49:36 api.ce8i5.arvadosapi.com arvados-controller[22796]: {"PID":22796,"RequestID":"req-1lpuf064itirjfaslvcm","level":"info","msg":"response","remoteAddr":"127.0.0.1:40238","reqBytes":86,"reqForwardedFor":"207.180.129.25","reqHost":"ce8i5.arvadosapi.com","reqMethod":"PUT","reqPath":"arvados/v1/collections/ce8i5-4zz18-k74yj38bjtguqg4","reqQuery":"","respBody":"{\"errors\":[\"//railsapi.internal/arvados/v1/collections/ce8i5-4zz18-k74yj38bjtguqg4: 422 Unprocessable Entity: #\\u003cNoMethodError: undefined method `each_line' for nil:NilClass\\u003e (req-1lpuf064itirjfaslvcm)\"]}\n","respBytes":214,"respStatus":"Unprocessable Entity","respStatusCode":422,"time":"2021-08-10T15:49:36.242228716Z","timeToStatus":0.029935,"timeTotal":0.029955,"timeWriteBody":0.000020} 
 </pre> 

 The corresponding backtrace in the rails log: 

 <pre> 
 { 
   "method": "PATCH", 
   "path": "/arvados/v1/collections/ce8i5-4zz18-k74yj38bjtguqg4", 
   "format": "html", 
   "controller": "Arvados::V1::CollectionsController", 
   "action": "update", 
   "status": 422, 
   "duration": 20.94, 
   "view": 0.31, 
   "db": 6.58, 
   "request_id": null, 
   "client_ipaddr": "127.0.0.1", 
   "client_auth": "ce8i5-gj3su-cihrx35dbfrjoiy", 
   "exception": "#<NoMethodError: undefined method `each_line' for nil:NilClass>", 
   "exception_backtrace": "/var/www/arvados-api/current/app/models/collection.rb:462:in `each_manifest_locator' 
 /var/www/arvados-api/current/app/models/collection.rb:154:in `strip_signatures_and_update_replication_confirmed' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:426:in `block in make_lambda' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:198:in `block (2 levels) in halting' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:606:in `block (2 levels) in default_terminator' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:605:in `catch' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:605:in `block in default_terminator' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:199:in `block in halting' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:513:in `block in invoke_before' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:513:in `each' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:513:in `invoke_before' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:131:in `run_callbacks' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:816:in `_run_validation_callbacks' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activemodel-5.2.6/lib/active_model/validations/callbacks.rb:118:in `run_validations!' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activemodel-5.2.6/lib/active_model/validations.rb:339:in `valid?' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/validations.rb:67:in `valid?' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/validations.rb:84:in `perform_validations' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/validations.rb:46:in `save' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:310:in `block (2 levels) in save' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:387:in `block in with_transaction_returning_status' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/connection_adapters/abstract/database_statements.rb:265:in `transaction' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:212:in `transaction' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:385:in `with_transaction_returning_status' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:310:in `block in save' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:325:in `rollback_active_record_state!' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:309:in `save' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/suppressor.rb:44:in `save' 
 /var/www/arvados-api/current/app/models/collection.rb:301:in `block (4 levels) in manage_versioning' 
 /var/www/arvados-api/current/lib/current_api_client.rb:138:in `block in act_as_system_user' 
 /var/www/arvados-api/current/lib/current_api_client.rb:149:in `act_as_user' 
 /var/www/arvados-api/current/lib/current_api_client.rb:137:in `act_as_system_user' 
 /var/www/arvados-api/current/app/models/collection.rb:300:in `block (3 levels) in manage_versioning' 
 /var/www/arvados-api/current/lib/arvados_model_updates.rb:32:in `leave_modified_at_alone' 
 /var/www/arvados-api/current/app/models/collection.rb:299:in `block (2 levels) in manage_versioning' 
 /var/www/arvados-api/current/lib/arvados_model_updates.rb:16:in `leave_modified_by_user_alone' 
 /var/www/arvados-api/current/app/models/collection.rb:298:in `block in manage_versioning' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/locking/pessimistic.rb:84:in `block in with_lock' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/connection_adapters/abstract/database_statements.rb:265:in `transaction' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:212:in `transaction' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:301:in `transaction' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/locking/pessimistic.rb:82:in `with_lock' 
 /var/www/arvados-api/current/app/models/collection.rb:268:in `manage_versioning' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:118:in `block in run_callbacks' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:136:in `run_callbacks' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:816:in `_run_update_callbacks' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/callbacks.rb:350:in `_update_record' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/timestamp.rb:114:in `_update_record' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/persistence.rb:705:in `create_or_update' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/callbacks.rb:342:in `block in create_or_update' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:132:in `run_callbacks' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:816:in `_run_save_callbacks' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/callbacks.rb:342:in `create_or_update' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/persistence.rb:308:in `save!' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/validations.rb:52:in `save!' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:315:in `block in save!' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:387:in `block in with_transaction_returning_status' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/connection_adapters/abstract/database_statements.rb:265:in `transaction' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:212:in `transaction' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:385:in `with_transaction_returning_status' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:315:in `save!' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/suppressor.rb:48:in `save!' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/persistence.rb:441:in `block in update!' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:387:in `block in with_transaction_returning_status' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/connection_adapters/abstract/database_statements.rb:267:in `block in transaction' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/connection_adapters/abstract/transaction.rb:239:in `block in within_new_transaction' 
 /usr/lib/ruby/2.5.0/monitor.rb:226:in `mon_synchronize' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/connection_adapters/abstract/transaction.rb:236:in `within_new_transaction' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/connection_adapters/abstract/database_statements.rb:267:in `transaction' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:212:in `transaction' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/transactions.rb:385:in `with_transaction_returning_status' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/persistence.rb:439:in `update!' 
 /var/www/arvados-api/current/app/controllers/application_controller.rb:121:in `update' 
 /var/www/arvados-api/current/app/controllers/arvados/v1/collections_controller.rb:51:in `update' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/abstract_controller/base.rb:194:in `process_action' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_controller/metal/rendering.rb:30:in `process_action' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/abstract_controller/callbacks.rb:42:in `block in process_action' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:109:in `block in run_callbacks' 
 /var/www/arvados-api/current/app/controllers/application_controller.rb:423:in `block in set_current_request_id' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/tagged_logging.rb:71:in `block in tagged' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/tagged_logging.rb:28:in `tagged' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/tagged_logging.rb:71:in `tagged' 
 /var/www/arvados-api/current/app/controllers/application_controller.rb:422:in `set_current_request_id' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:118:in `block in run_callbacks' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:136:in `run_callbacks' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/abstract_controller/callbacks.rb:41:in `process_action' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_controller/metal/rescue.rb:22:in `process_action' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/notifications.rb:168:in `block in instrument' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/notifications/instrumenter.rb:23:in `instrument' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/notifications.rb:168:in `instrument' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_controller/metal/instrumentation.rb:32:in `process_action' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_controller/metal/params_wrapper.rb:256:in `process_action' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activerecord-5.2.6/lib/active_record/railties/controller_runtime.rb:24:in `process_action' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/abstract_controller/base.rb:134:in `process' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionview-5.2.6/lib/action_view/rendering.rb:32:in `process' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_controller/metal.rb:191:in `dispatch' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_controller/metal.rb:252:in `dispatch' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/routing/route_set.rb:52:in `dispatch' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/routing/route_set.rb:34:in `serve' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/journey/router.rb:52:in `block in serve' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/journey/router.rb:35:in `each' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/journey/router.rb:35:in `serve' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/routing/route_set.rb:840:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/rack-2.2.3/lib/rack/tempfile_reaper.rb:15:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/rack-2.2.3/lib/rack/etag.rb:27:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/rack-2.2.3/lib/rack/conditional_get.rb:40:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/rack-2.2.3/lib/rack/head.rb:12:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/http/content_security_policy.rb:18:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:266:in `context' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:260:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/cookies.rb:670:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/callbacks.rb:98:in `run_callbacks' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/callbacks.rb:26:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/lograge-0.10.0/lib/lograge/rails_ext/rack/logger.rb:15:in `call_app' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/railties-5.2.6/lib/rails/rack/logger.rb:26:in `block in call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/tagged_logging.rb:71:in `block in tagged' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/tagged_logging.rb:28:in `tagged' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/tagged_logging.rb:71:in `tagged' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/railties-5.2.6/lib/rails/rack/logger.rb:26:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/request_store-1.4.1/lib/request_store/middleware.rb:19:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/request_id.rb:27:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/rack-2.2.3/lib/rack/method_override.rb:24:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/rack-2.2.3/lib/rack/runtime.rb:22:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/activesupport-5.2.6/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/executor.rb:14:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/rack-2.2.3/lib/rack/sendfile.rb:110:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/actionpack-5.2.6/lib/action_dispatch/middleware/ssl.rb:80:in `call' 
 /var/www/arvados-api/current/app/middlewares/arvados_api_token.rb:67:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/railties-5.2.6/lib/rails/engine.rb:524:in `call' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/railties-5.2.6/lib/rails/railtie.rb:190:in `public_send' 
 /var/www/arvados-api/shared/vendor_bundle/ruby/2.5.0/gems/railties-5.2.6/lib/rails/railtie.rb:190:in `method_missing' 
 /usr/lib/ruby/vendor_ruby/phusion_passenger/rack/thread_handler_extension.rb:107:in `process_request' 
 /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:157:in `accept_and_process_next_request' 
 /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:110:in `main_loop' 
 /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler.rb:416:in `block (3 levels) in start_threads' 
 /usr/lib/ruby/vendor_ruby/phusion_passenger/utils.rb:113:in `block in create_thread_and_abort_on_exception' 
 ", 
   "params": { 
     "collection": "{\"preserve_version\":true,\"properties\":{\"IDTAGANIMALS\":\"IDVALANIMALS3\"}}" 
   }, 
   "@timestamp": "2021-08-10T15:49:36.240979904Z", 
   "@version": "1", 
   "message": "[422] PATCH /arvados/v1/collections/ce8i5-4zz18-k74yj38bjtguqg4 (Arvados::V1::CollectionsController#update)" 
 } 

 </pre> 

 Note that the request id from the controller log (req-1lpuf064itirjfaslvcm) is nowhere to be found in the rails api log. Why? 


 On tordo, versioning is disabled, and I can't reproduce the problem. But when I set enable @Collections/CollectionVersioning@ on tordo, I see the same problem. This seems to be a bug/regression in our collection versioning code. 

 More data: testing against 2.2.1 (latest release), with collection versioning enabled, the bug does not exist.

Back