Arvados

The object that being read here is ce8i5-tpzed-xo2k4i24bjzwedw, which is the UUID of my logged in user on Tordo. It's got a ce8i5 UUID because tordo is in a login federation with ce8i5 and the latter is the login cluster.

This seems to be the chain of events:

browser: https://workbench.tordo.arvadosapi.com/container_requests/tordo-xvhdp-fzp65jk7mjq2vw6
...
tordo workbench?controller?api?:

https://ce8i5.arvadosapi.com/arvados/v1/users/ce8i5-tpzed-xo2k4i24bjzwedw?reader_tokens=["v2/tordo-gj3su-anonymouspublic/383784b1c4068ee3dd621bf0c1175f873a84f40e"]

tordo workbench:

https://ce8i5.arvadosapi.com/arvados/v1/users?cluster_id=tordo&count=&include=&limit=9223372036854775807&offset=0&reader_tokens=["v2/tordo-gj3su-anonymouspublic/383784b1c4068ee3dd621bf0c1175f873a84f40e"]&where={"uuid":["ce8i5-tpzed-xo2k4i24bjzwedw"]}

ce8i5 controller:

https://tordo.arvadosapi.com/arvados/v1/users?cluster_id=tordo&count=&forwarded_for=ce8i5-&include=&limit=9223372036854775807&offset=0&reader_tokens=["v2/tordo-gj3su-anonymouspublic/383784b1c4068ee3dd621bf0c1175f873a84f40e"]&where={"uuid":["ce8i5-tpzed-xo2k4i24bjzwedw"]}

As a side note, I wonder what's up with the trailing dash in the "forwarded_for" field.

The workbench.tordo backtrace:

#<ActionView::Template::Error: request failed: https://ce8i5.arvadosapi.com/arvados/v1/users?cluster_id=tordo&count=&include=&limit=9223372036854775807&offset=0&reader_tokens=%5B%22v2%2Ftordo-gj3su-anonymouspublic%2F383784b1c4068ee3dd621bf0c1175f873a84f40e%22%5D&where=%7B%22uuid%22%3A%5B%22ce8i5-tpzed-xo2k4i24bjzwedw%22%5D%7D: 401 Unauthorized: request failed: https://tordo.arvadosapi.com/arvados/v1/users?cluster_id=tordo&count=&forwarded_for=ce8i5-&include=&limit=9223372036854775807&offset=0&reader_tokens=%5B%22v2%2Ftordo-gj3su-anonymouspublic%2F383784b1c4068ee3dd621bf0c1175f873a84f40e%22%5D&where=%7B%22uuid%22%3A%5B%22ce8i5-tpzed-xo2k4i24bjzwedw%22%5D%7D: 401 Unauthorized: cannot use a locally issued token to forward a request to our login cluster (ce8i5) [API: 401]>
/var/www/arvados-workbench/current/app/models/arvados_api_client.rb:180:in `api'
/var/www/arvados-workbench/current/app/models/arvados_resource_list.rb:241:in `each_page'
/var/www/arvados-workbench/current/app/models/arvados_resource_list.rb:151:in `each'
/var/www/arvados-workbench/current/app/controllers/application_controller.rb:1272:in `preload_objects_for_dataclass'
/var/www/arvados-workbench/current/app/controllers/application_controller.rb:1241:in `object_for_dataclass'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/abstract_controller/helpers.rb:67:in `object_for_dataclass'
/var/www/arvados-workbench/current/app/helpers/application_helper.rb:230:in `object_readable'
/var/www/arvados-workbench/current/app/helpers/application_helper.rb:200:in `link_to_arvados_object_if_readable'
/var/www/arvados-workbench/current/app/views/work_units/_component_detail.html.erb:64:in `block in _app_views_work_units__component_detail_html_erb__4409334712204176514_140340'
/var/www/arvados-workbench/current/app/views/work_units/_component_detail.html.erb:44:in `each'
/var/www/arvados-workbench/current/app/views/work_units/_component_detail.html.erb:44:in `_app_views_work_units__component_detail_html_erb__4409334712204176514_140340'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:159:in `block in render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:170:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:354:in `instrument_render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:157:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:344:in `block in render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:170:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:43:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:333:in `render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:312:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:49:in `render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:23:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/helpers/rendering_helper.rb:33:in `render'
/var/www/arvados-workbench/current/app/views/work_units/_show_component.html.erb:89:in `_app_views_work_units__show_component_html_erb___2196716879592559975_140300'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:159:in `block in render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:170:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:354:in `instrument_render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:157:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:344:in `block in render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:170:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:43:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:333:in `render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:312:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:49:in `render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:23:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/helpers/rendering_helper.rb:33:in `render'
/var/www/arvados-workbench/current/app/views/work_units/_show_status.html.erb:27:in `_app_views_work_units__show_status_html_erb__2304209190807095414_140280'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:159:in `block in render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:170:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:354:in `instrument_render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:157:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:344:in `block in render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:170:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:43:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:333:in `render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:312:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:49:in `render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:23:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/helpers/rendering_helper.rb:33:in `render'
/var/www/arvados-workbench/current/app/views/container_requests/_show_status.html.erb:5:in `_app_views_container_requests__show_status_html_erb__2182052373222432699_140260'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:159:in `block in render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:170:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:354:in `instrument_render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:157:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:344:in `block in render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:170:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:43:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:333:in `render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:312:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:49:in `render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:23:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/rendering.rb:103:in `_render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/streaming.rb:219:in `_render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/rendering.rb:84:in `render_to_body'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/rendering.rb:52:in `render_to_body'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/renderers.rb:142:in `render_to_body'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/abstract_controller/rendering.rb:46:in `render_to_string'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/rendering.rb:41:in `render_to_string'
/var/www/arvados-workbench/current/app/controllers/application_controller.rb:215:in `render_pane'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/abstract_controller/helpers.rb:67:in `render_pane'
/var/www/arvados-workbench/current/app/views/application/_content.html.erb:64:in `block (2 levels) in _app_views_application__content_html_erb___4322885377900803941_140240'
/var/www/arvados-workbench/current/app/views/application/_content.html.erb:50:in `each'
/var/www/arvados-workbench/current/app/views/application/_content.html.erb:50:in `each_with_index'
/var/www/arvados-workbench/current/app/views/application/_content.html.erb:50:in `block in _app_views_application__content_html_erb___4322885377900803941_140240'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/helpers/capture_helper.rb:41:in `block in capture'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/helpers/capture_helper.rb:205:in `with_output_buffer'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/helpers/capture_helper.rb:41:in `capture'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/helpers/capture_helper.rb:155:in `content_for'
/var/www/arvados-workbench/current/app/views/application/_content.html.erb:5:in `_app_views_application__content_html_erb___4322885377900803941_140240'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:159:in `block in render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:354:in `instrument_render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:157:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:344:in `block in render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:170:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:43:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:333:in `render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/partial_renderer.rb:312:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:49:in `render_partial'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:23:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/helpers/rendering_helper.rb:33:in `render'
/var/www/arvados-workbench/current/app/views/application/show.html.erb:6:in `_app_views_application_show_html_erb___3446077259343990559_140120'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:159:in `block in render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:170:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:354:in `instrument_render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/template.rb:157:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/template_renderer.rb:54:in `block (2 levels) in render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:44:in `block in instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:170:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/abstract_renderer.rb:43:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/template_renderer.rb:53:in `block in render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/template_renderer.rb:61:in `render_with_layout'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/template_renderer.rb:52:in `render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/template_renderer.rb:16:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:44:in `render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/renderer/renderer.rb:25:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/rendering.rb:103:in `_render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/streaming.rb:219:in `_render_template'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/rendering.rb:84:in `render_to_body'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/rendering.rb:52:in `render_to_body'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/renderers.rb:142:in `render_to_body'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/abstract_controller/rendering.rb:25:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/rendering.rb:36:in `render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/instrumentation.rb:46:in `block (2 levels) in render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/core_ext/benchmark.rb:14:in `block in ms'
/usr/local/rvm/rubies/ruby-2.7.5/lib/ruby/2.7.0/benchmark.rb:308:in `realtime'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/core_ext/benchmark.rb:14:in `ms'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/instrumentation.rb:46:in `block in render'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/instrumentation.rb:87:in `cleanup_view_runtime'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activerecord-5.2.6.3/lib/active_record/railties/controller_runtime.rb:36:in `cleanup_view_runtime'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/instrumentation.rb:45:in `render'
/var/www/arvados-workbench/current/app/controllers/application_controller.rb:303:in `block (2 levels) in show'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/mime_responds.rb:203:in `respond_to'
/var/www/arvados-workbench/current/app/controllers/application_controller.rb:291:in `show'
/var/www/arvados-workbench/current/app/controllers/container_requests_controller.rb:71:in `show'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/abstract_controller/base.rb:194:in `process_action'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/rendering.rb:30:in `process_action'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/callbacks.rb:109:in `block in run_callbacks'
/var/www/arvados-workbench/current/app/controllers/application_controller.rb:667:in `set_thread_api_token'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
/var/www/arvados-workbench/current/app/controllers/application_controller.rb:592:in `set_current_request_id'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
/var/www/arvados-workbench/current/app/controllers/application_controller.rb:584:in `thread_clear'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/callbacks.rb:136:in `run_callbacks'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/abstract_controller/callbacks.rb:41:in `process_action'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/rescue.rb:22:in `process_action'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:168:in `block in instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/notifications.rb:168:in `instrument'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal/params_wrapper.rb:256:in `process_action'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activerecord-5.2.6.3/lib/active_record/railties/controller_runtime.rb:24:in `process_action'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/abstract_controller/base.rb:134:in `process'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionview-5.2.6.3/lib/action_view/rendering.rb:32:in `process'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal.rb:191:in `dispatch'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_controller/metal.rb:252:in `dispatch'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/routing/route_set.rb:52:in `dispatch'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/routing/route_set.rb:34:in `serve'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/journey/router.rb:52:in `block in serve'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/journey/router.rb:35:in `each'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/journey/router.rb:35:in `serve'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/routing/route_set.rb:840:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/rack-2.2.3/lib/rack/tempfile_reaper.rb:15:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/rack-2.2.3/lib/rack/etag.rb:27:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/rack-2.2.3/lib/rack/conditional_get.rb:27:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/rack-2.2.3/lib/rack/head.rb:12:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:266:in `context'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:260:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/middleware/cookies.rb:670:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/callbacks.rb:98:in `run_callbacks'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/lograge-0.10.0/lib/lograge/rails_ext/rack/logger.rb:15:in `call_app'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/railties-5.2.6.3/lib/rails/rack/logger.rb:26:in `block in call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/tagged_logging.rb:71:in `block in tagged'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/tagged_logging.rb:28:in `tagged'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/tagged_logging.rb:71:in `tagged'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/railties-5.2.6.3/lib/rails/rack/logger.rb:26:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/request_store-1.4.1/lib/request_store/middleware.rb:19:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/middleware/request_id.rb:27:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/rack-2.2.3/lib/rack/method_override.rb:24:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/rack-2.2.3/lib/rack/runtime.rb:22:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/activesupport-5.2.6.3/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/middleware/executor.rb:14:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/rack-2.2.3/lib/rack/sendfile.rb:110:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/actionpack-5.2.6.3/lib/action_dispatch/middleware/ssl.rb:74:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/railties-5.2.6.3/lib/rails/engine.rb:524:in `call'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/railties-5.2.6.3/lib/rails/railtie.rb:190:in `public_send'
/var/www/arvados-workbench/shared/vendor_bundle/ruby/2.7.0/gems/railties-5.2.6.3/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:149: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:419: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'

The error message was introduced in 69a9857a37007723c17007b0c2f960b87e95bc02, as part of #18346. This commit is also part of the 2.3.1 release.

I've updated jutro to 2.3.3, and the bug is still not present there (cf. https://dev.arvados.org/issues/18887#note-8).

That suggests that perhaps it is caused by the way the API server handles the anonymous token, which was changed as part of #18676, which is not part of a stable release yet.

One difference here is that pirca is configured with a full v2 anon token, with a jutro (i.e. the federation login cluster) uuid.

Tordo has a just the anon token defined in the config (which we now want) and the uuid is automatically populated by the new code from #18676, and it is the anonymous user uuid for the local cluster, not the login cluster anonymous user uuid.

Yep, if I put the old anonymous token back on tordo, everything works again:

I suppose there are 2 possible fixes:

• make the code that generates the anonymous uuid for the new code path from #18676 use the login cluster uuid in a login federation setup.
• add an exception for the anonymous token to the "cannot use a locally issued token to forward a request to our login cluster" check in federation/conn.go 's func saltedTokenProvider.

That's assuming we want the minimal fix. I'm still wondering why this whole dance back and forth to the login cluster is necessary to begin with. That feels like a bug, too.

Questions:

• why is wb1 using the anonymous token in a request when the user is logged in already?

app/views/work_units/_component_detail.html.erb:64

                    <% elsif k.to_s.end_with? 'uuid' %>
                      <%= link_to_arvados_object_if_readable(val, val, friendly_name: true) %>

This leads to a call of object_readable in app/helpers/application_helper.rb, which leads to a call of preload_objects_for_dataclass in app/controllers/application_controller.rb, which leads to a call of arvados_api_client.api in app/models/arvados_api_client.rb. In that file, @reader_tokens is initialized as

@reader_tokens = Thread.current[:reader_tokens]

but if the value for reader_tokens passed to the @arvados_api_client.api is unset, this code is applied in app/models/arvados_api_client.rb:

      'reader_tokens' => ((tokens[:reader_tokens] ||
                           Thread.current[:reader_tokens] ||
                           []) +
                          anon_tokens).to_json,

which is presumably how we end up with the anonymous user token. Yeah, confirmed with some strategic debug lines, that's what is happening.

This request is also supposed to have the logged in user token, though, and that doesn't show up in the logs because it's sent as a header (cf. #18896).

• why is controller forwarding the request for a user object to the login cluster controller, which then forwards it back to controller, which then answers it without problem?

Presumably this is because the UUID is a login cluster UUID: ce8i5-tpzed-xo2k4i24bjzwedw. So maybe the question is then why is the login cluster sending that request back to the originating controller? Ah, that's because of the cluster_id parameter that is attached to the request. And how is the originating cluster able respond to the request at that point (is this the "break loops" code?).

It would have been helpful if controller logged the uuid of the user and the uuid of the token used for each request, I've added #18896 for that. And for the other go services, #18897

38492988c92cdf1d4c606f67b19e7cd7d13a3dba on branch 18887-wb1-fiddlesticks

developer-run-tests: #2974

I tried to implement the simple/naive change in check_anonymous_user_token in services/api/app/models/api_client_authorization.rb, i.e. use the uuid of the login cluster anonymous user api client authorization when the anonymous token is presented in a login federation context.

That fixes the bug observed here, but only if both clusters have the same anonymous user secret defined. We have test coverage in lib/controller/integration_test.go (func TestGetCollectionAsAnonymous) that pointed this out, yay.

So that's not a good enough workaround/fix.

It seems to me that we want the anonymous token of each cluster in a login federation to be treated as equivalent. There is a predictable uuid so that's not so hard - in fact we already do something like this in services/api/app/models/api_client_authorization.rb's def validate, where we rewrite the remote user uuid:

    if remote_user['uuid'][-22..-1] == '-tpzed-anonymouspublic'
      # Special case: map the remote anonymous user to local anonymous user
      remote_user['uuid'] = anonymous_user_uuid
    end

We discussed a bit after standup. A few notes:

• in a login federation, it is currently the case that we expect the anonymous user tokens are synchronized across clusters, and set to the login cluster anonymous user api authorization uuid. This is undocumented.

• in a peer federation, it is expected that the anonymous user tokens are different for each cluster and we have some code that maps incoming anonymous tokens from other clusters to the local anonymous user tokens. Todo: test if this works well?

• there is no particular reason for the anonymous user to need a random string. We could replace it with a hardcoded "anonymous..." string, say, and remove one more thing that currently needs to be configured.

• if we do that, it would be good to preserve a way to disable anonymous access altogether, like we currently can by setting the token to an empty string (but, how does that work - we don't have a cluster running in that config)

To summarize: the fiddlesticks was caused by a cluster that has a LoginCluster defined and a secret-only AnonymousUserToken in the config file, which is normal/likely since #18676.

Until #18676, the expectation for all clusters in a login federation to have the same, fully qualified v2 token with the uuid of the login cluster. After #18676 the expectation was that the AnonymousUserToken was a secret only. The API server automatically converts it to the v2 token with the uuid for the anonymous user token on the local cluster.

The bug:

• Workbench1 adds the anonymous token from the config file to the reader_tokens for each request. If only the secret is listed in the config file, the rails api converts that to a v2 token for the local anonymous user (as per #18676).
• Controller refused to forward the local anonymous token to a remote cluster since #18346, despite having code to map remote anonymous tokens to the local anonymous user. That results in a 401, which workbench chokes on leading to the fiddlesticks.

This patch makes 2 changes:

• make sure that Workbench 1 always sends a fully qualified v2 anonymous token in reader_tokens, even when the config file has just the secret it in (which is typical going forward).
• when controller checks against forwarding local v2 tokens to the login cluster, allow passing a local anonymous token. We already map any anonymous tokens to the local anonymous token in controller, so that will cause no issues on the receiving side.

442ddf0be3bdc9c28d839aaa4476a67f8feea19b on branch 18887-wb1-sends-v2-anonymous-token

developer-run-tests: #2988

developer-run-tests-apps-workbench-integration: #3189

With this, if just the anonymous user secret is listed in the config file (likely/normal since #18676)

• it gets translated automatically to "v2/#{clusterid}-gj3su-anonymouspublic/#{secret}" by wb1 when added to the reader_tokens (fixed here) and the rails api server (since #18676)
• controller forwards anonymous token from local cluster to login cluster (fixed here, tweak from #18346)
• controller maps any anonymous token it sees to the local anonymous token (was already in place)

That means that it is no longer needed to synchronize the anonymous token across a login federation.

The longer term fix is #18936.

I think I see how this works -- the local cluster forwards the salted "local-anonymous" token to the login cluster, which then calls back to the local cluster to validate it, and when that works, it automatically maps the user ID to its own anonymous user ("login-tpzed-anon...") instead of the remote anonymous user ("local-tpzed-anon...")... which effectively makes it just as good as the loging cluster's own anonymous token.

I think a test in lib/controller/integration_test.go would be good -- I don't see offhand why the existing anonymous-token test wasn't hit by this bug.

After talking with Tom, pushed e7b749c937b70f388111d008eca4631787768a30 to undo the warning when the config file contains a V2 anonymous token, which we handle fine (and is the common scenario for most clusters out there, most likely).

developer-run-tests: #2999
developer-run-tests-apps-workbench-functionals: #3053

Added an integration test that fails before this branch, and passes with it.

ready for another look at b8fbe615b87f04fe7cd1e1ad277a11b62aed0db0 on branch 18887-wb1-sends-v2-anonymous-token

developer-run-tests: #3007

I tried modifying the test to send a bogus AuthToken and the real anonymous token.

z3333 forwarded the request to z1111, which called back to z3333 to verify the anonymous token, which failed:

...

...

So I think the updated comment ("The anonymous token is OK to forward, because it gets mapped to the local anonymous token automatically on the login cluster") is incorrect -- the z3333 anonymous token is verified the usual way with a callback to z3333, and associates with the z3333 anonymous user, not the z1111 anonymous user.

• z1111 validates the real token, and therefore does not even try to validate the anonymous token, or
• z1111 cannot validate the real token, so it falls back to trying the anonymous token, which fails.

I suspect the reason why z3333 cannot verify its own anonymous token there is just that ApiClientAuthorization.check_anonymous_user_token() doesn't check for secret == OpenSSL::HMAC.hexdigest('sha1', secret, remote) so it doesn't accept a salted token.

As an aside, shouldn't "token" be "secret" here?

      return ApiClientAuthorization.new(user: User.find_by_uuid(anonymous_user_uuid),
                                        uuid: Rails.configuration.ClusterID+"-gj3su-anonymouspublic",
                                        api_token: token,
                                        api_client: anonymous_user_token_api_client,
                                        scopes: ['GET /'])

Tom Clegg wrote:

I tried modifying the test to send a bogus AuthToken and the real anonymous token.

z3333 forwarded the request to z1111, which called back to z3333 to verify the anonymous token, which failed:

.... ClusterID=z3333 ... reqPath=arvados/v1/users/current reqQuery="remote=z1111" respBody="{\"errors\":[\"//railsapi.internal/arvados/v1/users/current?remote=z1111: 401 Unauthorized: Not logged in (req-1od2ffbt9fnwk1lhptm7)\"]}\n"

...

[z1111] [services/api: passenger@api] App 10578 output: remote authentication with token "v2/z3333-gj3su-anonymouspublic/211ab3d6384d9b9ed52ad730bab12c57e5eccd89" failed: unexpected response: #<HTTP::Message::Headers:0x0000563886c34e38 @http_version="1.1", @body_size=0, @chunked=false, @request_method="GET", @request_uri=#<Addressable::URI:0xf6f4 URI:https://127.0.0.33:36629/arvados/v1/users/current>, @request_query={"remote"=>"z1111"}, @request_absolute_uri=nil, @status_code=401, @reason_phrase="Unauthorized", @body_type=nil, @body_charset=nil, @body_date=nil, @body_encoding=#<Encoding:ASCII-8BIT>, @is_request=false, @header_item=[["Server", "nginx/1.18.0"], ["Date", "Thu, 31 Mar 2022 20:25:56 GMT"], ["Content-Type", "application/json"], ["Content-Length", "133"], ["Connection", "keep-alive"], ["Access-Control-Allow-Headers", "Authorization, Content-Type, X-Http-Method-Override"], ["Access-Control-Allow-Methods", "GET, HEAD, PUT, POST, PATCH, DELETE"], ["Access-Control-Allow-Origin", "*"], ["Access-Control-Max-Age", "86486400"], ["X-Content-Type-Options", "nosniff"], ["X-Request-Id", "req-1od2ffbt9fnwk1lhptm7"]], @dumped=false>

...

"request failed: https://127.0.0.33:36629//arvados/v1/users?reader_tokens=%5B%22v2%2Fz3333-gj3su-anonymouspublic%2F78fca960b23cd7f003bf141b149bbf2f695eb62f34e74f6f8caf4dcdaf1f0840%22%5D&where=%7B%22uuid%22%3A%22z1111-tpzed-anonymouspublic%22%7D: 401 Unauthorized: request failed: https://127.0.0.11:40335/arvados/v1/users?cluster_id=&count=&include=&offset=0&reader_tokens=%5B%22v2%2Fz3333-gj3su-anonymouspublic%2F211ab3d6384d9b9ed52ad730bab12c57e5eccd89%22%5D&where=%7B%22uuid%22%3A%22z1111-tpzed-anonymouspublic%22%7D: 401 Unauthorized: //railsapi.internal/arvados/v1/users?cluster_id=&count=&forwarded_for=z1111-&include=&offset=0&reader_tokens=%5B%22v2%2Fz3333-gj3su-anonymouspublic%2F211ab3d6384d9b9ed52ad730bab12c57e5eccd89%22%5D&where=%7B%22uuid%22%3A%22z1111-tpzed-anonymouspublic%22%7D: 401 Unauthorized: Not logged in (req-xkv6rhf7zngjcbq6jaka)" >

So I think the updated comment ("The anonymous token is OK to forward, because it gets mapped to the local anonymous token automatically on the login cluster") is incorrect -- the z3333 anonymous token is verified the usual way with a callback to z3333, and associates with the z3333 anonymous user, not the z1111 anonymous user.

Hmm, I guess that's because controller does this. The code that is supposed to map it is in services/api/app/models/api_client_authorization.rb, line 347. But I guess it never gets there.

It looks to me like, when z3333 forwards a request to z1111 with both real (z1111) and anonymous (z3333) tokens, either:

• z1111 validates the real token, and therefore does not even try to validate the anonymous token, or

Yeah. The anonymous token is supplied as a reader_token, which controller just adds to the list of request tokens, at the end.

• z1111 cannot validate the real token, so it falls back to trying the anonymous token, which fails.

Yeah.

I suspect the reason why z3333 cannot verify its own anonymous token there is just that ApiClientAuthorization.check_anonymous_user_token() doesn't check for secret == OpenSSL::HMAC.hexdigest('sha1', secret, remote) so it doesn't accept a salted token.

Actually, that wasn't the problem in this test (the anonymous token appears to make it to rails unsalted -- is this expected behavior?); the issue was that self.check_anonymous_user_token was not able to handle a fully V2 token in the Rails.configuration.Users.AnonymousUserToken configuration. That's fixed now.

I added the comparison with the salted token.

As an aside, shouldn't "token" be "secret" here?

[...]

Yes - I thought I'd already fixed that but apparently not.

402be7db4c5795a40bbf974cec3d1e31b0c1708f on 18887-wb1-sends-v2-anonymous-token

developer-run-tests: #3008

Ward Vandewege wrote:

So I think the updated comment ("The anonymous token is OK to forward, because it gets mapped to the local anonymous token automatically on the login cluster") is incorrect -- the z3333 anonymous token is verified the usual way with a callback to z3333, and associates with the z3333 anonymous user, not the z1111 anonymous user.

Hmm, I guess that's because controller does this. The code that is supposed to map it is in services/api/app/models/api_client_authorization.rb, line 347. But I guess it never gets there.

Ah, I see what you mean. That maps the remote anonymous user to the local anonymous user, but only after verifying the remote token the usual way.

I think it would be accurate to say it's OK to forward the local anonymous token because (unlike other local tokens for real users) the validation callback will return the locally issued anonymous user ID instead of a login-cluster user ID.

I suspect the reason why z3333 cannot verify its own anonymous token there is just that ApiClientAuthorization.check_anonymous_user_token() doesn't check for secret == OpenSSL::HMAC.hexdigest('sha1', secret, remote) so it doesn't accept a salted token.

Actually, that wasn't the problem in this test (the anonymous token appears to make it to rails unsalted -- is this expected behavior?)

In the logs I pasted it is being salted. You can see in the epic error message that the client sends v2/z3333-gj3su-anonymouspublic/78fca96... to z3333, z3333 forwards with v2/z3333-gj3su-anonymouspublic/211ab3d... to z1111, and z1111 sends v2/z3333-gj3su-anonymouspublic/211ab3d back to z3333 for verification.

You might be seeing the unsalted token getting to z3333 Rails earlier in the process though, because when a client sends a bare secret, we do this:

                        case auth.ErrObsoleteToken:
                                ctx := auth.NewContext(ctx, &auth.Credentials{Tokens: []string{token}})
                                aca, err := local.APIClientAuthorizationCurrent(ctx, arvados.GetOptions{})

...and then salt the resulting V2 token.

We should probably short-circuit that in the case where token == cluster.Users.AnonymousToken.

(Do we need a more general version of the wb1 fix? Like exporting a v2 token in the exported config? Or can we just expect things to work with a bare token until we remove the whole anonymous token system?)

the issue was that self.check_anonymous_user_token was not able to handle a fully V2 token in the Rails.configuration.Users.AnonymousUserToken configuration. That's fixed now.

Wait, how is a full V2 token even getting into Rails.configuration.Users.AnonymousUserToken, given that the config loader already strips it down to the secret part? I don't think we should need to do this in Rails as well.

Tom Clegg wrote:

Ward Vandewege wrote:

So I think the updated comment ("The anonymous token is OK to forward, because it gets mapped to the local anonymous token automatically on the login cluster") is incorrect -- the z3333 anonymous token is verified the usual way with a callback to z3333, and associates with the z3333 anonymous user, not the z1111 anonymous user.

Hmm, I guess that's because controller does this. The code that is supposed to map it is in services/api/app/models/api_client_authorization.rb, line 347. But I guess it never gets there.

Ah, I see what you mean. That maps the remote anonymous user to the local anonymous user, but only after verifying the remote token the usual way.

I think it would be accurate to say it's OK to forward the local anonymous token because (unlike other local tokens for real users) the validation callback will return the locally issued anonymous user ID instead of a login-cluster user ID.

Right. I've updated the comment, thanks. This is so circuitous!

I suspect the reason why z3333 cannot verify its own anonymous token there is just that ApiClientAuthorization.check_anonymous_user_token() doesn't check for secret == OpenSSL::HMAC.hexdigest('sha1', secret, remote) so it doesn't accept a salted token.

Actually, that wasn't the problem in this test (the anonymous token appears to make it to rails unsalted -- is this expected behavior?)

In the logs I pasted it is being salted. You can see in the epic error message that the client sends v2/z3333-gj3su-anonymouspublic/78fca96... to z3333, z3333 forwards with v2/z3333-gj3su-anonymouspublic/211ab3d... to z1111, and z1111 sends v2/z3333-gj3su-anonymouspublic/211ab3d back to z3333 for verification.

You might be seeing the unsalted token getting to z3333 Rails earlier in the process though, because when a client sends a bare secret, we do this:

Ah, yes, that's what I saw.

(Do we need a more general version of the wb1 fix? Like exporting a v2 token in the exported config? Or can we just expect things to work with a bare token until we remove the whole anonymous token system?)

I think we can just wait until we remove the anonymous token system, and handle the anonymous token, salted or not.

the issue was that self.check_anonymous_user_token was not able to handle a fully V2 token in the Rails.configuration.Users.AnonymousUserToken configuration. That's fixed now.

Wait, how is a full V2 token even getting into Rails.configuration.Users.AnonymousUserToken, given that the config loader already strips it down to the secret part? I don't think we should need to do this in Rails as well.

Hmm, true, I see that code now, so this shouldn't be necessary. I've removed the rails code.

developer-run-tests: #3016

My "bogus primary token, real reader_token" thing still fails. I think we should add this to the test case -- that way we're checking that it actually works, not just checking that it doesn't prevent the real token from working.

        userac1.AuthToken = "v2/z1111-gj3su-asdfasdfasdfasd/this-token-does-not-validate-so-anonymous-token-will-be-used-instead" 
        err = userac1.RequestAndDecode(&userList, "GET", "/arvados/v1/users", nil,
                map[string]interface{}{
                        "reader_tokens": []string{anon3Auth.TokenV2()},
                        "where":         where,
                },
        )
        c.Check(err, check.IsNil)

Looks like it's failing because you salted the caller-provided secret instead of the real secret. If secret == salted_secret here then crypto is in serious trouble :)

    salted_secret = OpenSSL::HMAC.hexdigest('sha1', secret, remote)
    if ... secret == salted_secret ...

Tom Clegg wrote:

My "bogus primary token, real reader_token" thing still fails. I think we should add this to the test case -- that way we're checking that it actually works, not just checking that it doesn't prevent the real token from working.

[...]

Yeah, added.

Looks like it's failing because you salted the caller-provided secret instead of the real secret. If secret == salted_secret here then crypto is in serious trouble :)

[...]

Whoops, yeah, that's fixed now. The test passes at cb807029865aacbc54dc88b524ee55f3c5bfd327

developer-run-tests: #3021