Actions
Bug #17053
closed
Integration test failing
Story points:
-
Description
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"request","remoteAddr":"127.0.0.1:40010","reqBytes":46,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/users/current","reqQuery":"","time":"2020-10-28T18:30:04.529360777Z"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","apiEndpoint":{"Method":"GET","Path":"arvados/v1/users/current","AttrsKey":""},"apiOpts":{"select":null,"include_trash":false},"apiOptsType":"*arvados.GetOptions","level":"debug","msg":"exec","remoteAddr":"127.0.0.1:40010","reqBytes":46,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/users/current","reqQuery":"","time":"2020-10-28T18:30:04.529490712Z"}
[railsapi] App 1696 output: (0.2ms) SET TIME ZONE 'UTC'
[railsapi] App 1696 output: ApiClientAuthorization Load (0.4ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token='3kg6k6lzmp9kj5cpkcoxie963cmvjahbt2fod9zru30k1jqdmi' and (expires_at is null or expires_at > CURRENT_TIMESTAMP)) ORDER BY "api_client_authorizations"."id" ASC LIMIT $1 [["LIMIT", 1]]
[railsapi] App 1696 output: User Load (0.3ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 186579971]]
[railsapi] App 1696 output: ApiClient Load (0.2ms) SELECT "api_clients".* FROM "api_clients" WHERE "api_clients"."id" = $1 [["id", 243589807]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User.group_permissions (0.6ms)
[railsapi] App 1696 output: SELECT target_uuid, perm_level
[railsapi] App 1696 output: FROM materialized_permissions
[railsapi] App 1696 output: WHERE user_uuid in (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ($1)
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= $2
[railsapi] App 1696 output: ) and perm_level >= $2
[railsapi] App 1696 output: [[nil, "zzzzz-tpzed-xurymjxw79nv3jz"], [nil, 3]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Link Load (0.3ms) SELECT "links".* FROM "links" WHERE "links"."head_uuid" = $1 AND "links"."link_class" = $2 [["head_uuid", "zzzzz-tpzed-xurymjxw79nv3jz"], ["link_class", "permission"]]
[railsapi] App 1696 output: {"method":"GET","path":"/arvados/v1/users/current","format":"html","controller":"Arvados::V1::UsersController","action":"current","status":200,"duration":3.94,"view":0.19,"db":0.88,"request_id":"req-4l5xfbvwnnlf2twzv0vd","client_ipaddr":"127.0.0.1","client_auth":"zzzzz-gj3su-077z32aux8dg2s1","params":{},"@timestamp":"2020-10-28T18:30:04.539778188Z","@version":"1","message":"[200] GET /arvados/v1/users/current (Arvados::V1::UsersController#current)"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"response","remoteAddr":"127.0.0.1:40010","reqBytes":46,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/users/current","reqQuery":"","respBytes":813,"respStatus":"OK","respStatusCode":200,"time":"2020-10-28T18:30:04.540513861Z","timeToStatus":0.011141,"timeTotal":0.011147,"timeWriteBody":0.000006}
[nginx_access] [28/Oct/2020:18:30:04 +0000] "req-4l5xfbvwnnlf2twzv0vd" controller 200 813 0.011 POST "https://0.0.0.0:40943/arvados/v1/users/current" 127.0.0.1:34188 "-" "HTTPClient/1.0 (2.8.3, ruby 2.5.7 (2019-10-01))"
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"request","remoteAddr":"127.0.0.1:40012","reqBytes":102,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/container_requests/zzzzz-xvhdp-cr4uncommitted3","reqQuery":"","time":"2020-10-28T18:30:04.543050474Z"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","apiEndpoint":{"Method":"GET","Path":"arvados/v1/container_requests/{uuid}","AttrsKey":""},"apiOpts":{"uuid":"zzzzz-xvhdp-cr4uncommitted3","select":null,"include_trash":false},"apiOptsType":"*arvados.GetOptions","level":"debug","msg":"exec","remoteAddr":"127.0.0.1:40012","reqBytes":102,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/container_requests/zzzzz-xvhdp-cr4uncommitted3","reqQuery":"","time":"2020-10-28T18:30:04.543162580Z"}
[railsapi] App 1696 output: (0.2ms) SET TIME ZONE 'UTC'
[railsapi] App 1696 output: ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token='3kg6k6lzmp9kj5cpkcoxie963cmvjahbt2fod9zru30k1jqdmi' and (expires_at is null or expires_at > CURRENT_TIMESTAMP)) ORDER BY "api_client_authorizations"."id" ASC LIMIT $1 [["LIMIT", 1]]
[railsapi] App 1696 output: User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 186579971]]
[railsapi] App 1696 output: ApiClient Load (0.1ms) SELECT "api_clients".* FROM "api_clients" WHERE "api_clients"."id" = $1 [["id", 243589807]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] ApiClientAuthorization Load (0.2ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token IN ('4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi') AND
[railsapi] App 1696 output: (expires_at IS NULL OR expires_at > CURRENT_TIMESTAMP))
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 36826545]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] ContainerRequest Load (1.1ms) SELECT "container_requests".* FROM "container_requests" WHERE ((container_requests.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) OR container_requests.owner_uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp()) AND traverse_owned) ) ) AND (container_requests.uuid='zzzzz-xvhdp-cr4uncommitted3') ORDER BY "container_requests"."id" ASC LIMIT $1 OFFSET $2 [["LIMIT", 1], ["OFFSET", 0]]
[railsapi] App 1696 output: {"method":"GET","path":"/arvados/v1/container_requests/zzzzz-xvhdp-cr4uncommitted3","format":"html","controller":"Arvados::V1::ContainerRequestsController","action":"show","status":200,"duration":8.44,"view":0.2,"db":1.51,"request_id":"req-4l5xfbvwnnlf2twzv0vd","client_ipaddr":"127.0.0.1","client_auth":"zzzzz-gj3su-077z32aux8dg2s1","params":{"reader_tokens":"[\"4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi\"]"},"@timestamp":"2020-10-28T18:30:04.557238835Z","@version":"1","message":"[200] GET /arvados/v1/container_requests/zzzzz-xvhdp-cr4uncommitted3 (Arvados::V1::ContainerRequestsController#show)"}
[nginx_access] [28/Oct/2020:18:30:04 +0000] "req-4l5xfbvwnnlf2twzv0vd" controller 200 2243 0.016 POST "https://0.0.0.0:40943/arvados/v1/container_requests/zzzzz-xvhdp-cr4uncommitted3" 127.0.0.1:34188 "-" "HTTPClient/1.0 (2.8.3, ruby 2.5.7 (2019-10-01))"
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"response","remoteAddr":"127.0.0.1:40012","reqBytes":102,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/container_requests/zzzzz-xvhdp-cr4uncommitted3","reqQuery":"","respBytes":2231,"respStatus":"OK","respStatusCode":200,"time":"2020-10-28T18:30:04.558108040Z","timeToStatus":0.015038,"timeTotal":0.015052,"timeWriteBody":0.000015}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"request","remoteAddr":"127.0.0.1:40014","reqBytes":46,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/users/current","reqQuery":"","time":"2020-10-28T18:30:04.565950706Z"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","apiEndpoint":{"Method":"GET","Path":"arvados/v1/users/current","AttrsKey":""},"apiOpts":{"select":null,"include_trash":false},"apiOptsType":"*arvados.GetOptions","level":"debug","msg":"exec","remoteAddr":"127.0.0.1:40014","reqBytes":46,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/users/current","reqQuery":"","time":"2020-10-28T18:30:04.566099004Z"}
[railsapi] App 1696 output: (0.2ms) SET TIME ZONE 'UTC'
[railsapi] App 1696 output: ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token='3kg6k6lzmp9kj5cpkcoxie963cmvjahbt2fod9zru30k1jqdmi' and (expires_at is null or expires_at > CURRENT_TIMESTAMP)) ORDER BY "api_client_authorizations"."id" ASC LIMIT $1 [["LIMIT", 1]]
[railsapi] App 1696 output: User Load (0.3ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 186579971]]
[railsapi] App 1696 output: ApiClient Load (0.2ms) SELECT "api_clients".* FROM "api_clients" WHERE "api_clients"."id" = $1 [["id", 243589807]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User.group_permissions (0.5ms)
[railsapi] App 1696 output: SELECT target_uuid, perm_level
[railsapi] App 1696 output: FROM materialized_permissions
[railsapi] App 1696 output: WHERE user_uuid in (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ($1)
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= $2
[railsapi] App 1696 output: ) and perm_level >= $2
[railsapi] App 1696 output: [[nil, "zzzzz-tpzed-xurymjxw79nv3jz"], [nil, 3]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Link Load (0.2ms) SELECT "links".* FROM "links" WHERE "links"."head_uuid" = $1 AND "links"."link_class" = $2 [["head_uuid", "zzzzz-tpzed-xurymjxw79nv3jz"], ["link_class", "permission"]]
[railsapi] App 1696 output: {"method":"GET","path":"/arvados/v1/users/current","format":"html","controller":"Arvados::V1::UsersController","action":"current","status":200,"duration":3.05,"view":0.17,"db":0.68,"request_id":"req-4l5xfbvwnnlf2twzv0vd","client_ipaddr":"127.0.0.1","client_auth":"zzzzz-gj3su-077z32aux8dg2s1","params":{},"@timestamp":"2020-10-28T18:30:04.575080905Z","@version":"1","message":"[200] GET /arvados/v1/users/current (Arvados::V1::UsersController#current)"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"response","remoteAddr":"127.0.0.1:40014","reqBytes":46,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/users/current","reqQuery":"","respBytes":813,"respStatus":"OK","respStatusCode":200,"time":"2020-10-28T18:30:04.575741382Z","timeToStatus":0.009781,"timeTotal":0.009786,"timeWriteBody":0.000005}
[nginx_access] [28/Oct/2020:18:30:04 +0000] "req-4l5xfbvwnnlf2twzv0vd" controller 200 813 0.010 POST "https://0.0.0.0:40943/arvados/v1/users/current" 127.0.0.1:34188 "-" "HTTPClient/1.0 (2.8.3, ruby 2.5.7 (2019-10-01))"
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"request","remoteAddr":"127.0.0.1:40016","reqBytes":414,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/links","reqQuery":"","time":"2020-10-28T18:30:04.577779051Z"}
[railsapi] App 1696 output: (0.1ms) SET TIME ZONE 'UTC'
[railsapi] App 1696 output: ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token='3kg6k6lzmp9kj5cpkcoxie963cmvjahbt2fod9zru30k1jqdmi' and (expires_at is null or expires_at > CURRENT_TIMESTAMP)) ORDER BY "api_client_authorizations"."id" ASC LIMIT $1 [["LIMIT", 1]]
[railsapi] App 1696 output: User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 186579971]]
[railsapi] App 1696 output: ApiClient Load (0.1ms) SELECT "api_clients".* FROM "api_clients" WHERE "api_clients"."id" = $1 [["id", 243589807]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] ApiClientAuthorization Load (0.2ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token IN ('4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi') AND
[railsapi] App 1696 output: (expires_at IS NULL OR expires_at > CURRENT_TIMESTAMP))
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 36826545]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Link Load (1.4ms) SELECT links."head_uuid" FROM "links" WHERE ((links.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) OR links.owner_uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp()) AND traverse_owned) OR (links.link_class IN ('permission','resources') AND (links.head_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) OR links.tail_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: )))) ) AND ((links.owner_uuid in ('zzzzz-j7d0g-publicfavorites','zzzzz-tpzed-xurymjxw79nv3jz')) AND (links.link_class = 'star') AND (substring(links.head_uuid, 7, 5) = 'j7d0g')) LIMIT $1 OFFSET $2 [["LIMIT", 1000], ["OFFSET", 0]]
[railsapi] App 1696 output: {"method":"GET","path":"/arvados/v1/links","format":"json","controller":"Arvados::V1::LinksController","action":"index","status":200,"duration":6.17,"view":0.2,"db":1.85,"request_id":"req-4l5xfbvwnnlf2twzv0vd","client_ipaddr":"127.0.0.1","client_auth":"zzzzz-gj3su-077z32aux8dg2s1","params":{"reader_tokens":"[\"4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi\"]","_method":"GET","count":"none","select":"[\"head_uuid\"]","filters":"[[\"owner_uuid\",\"in\",[\"zzzzz-j7d0g-publicfavorites\",\"zzzzz-tpzed-xurymjxw79nv3jz\"]],[\"link_class\",\"=\",\"star\"],[\"head_uuid\",\"is_a\",\"arvados#group\"]]","limit":"9223372036854775807","offset":"0","_profile":"true"},"@timestamp":"2020-10-28T18:30:04.589098066Z","@version":"1","message":"[200] GET /arvados/v1/links (Arvados::V1::LinksController#index)"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"response","remoteAddr":"127.0.0.1:40016","reqBytes":414,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/links","reqQuery":"","respBytes":152,"respStatus":"OK","respStatusCode":200,"time":"2020-10-28T18:30:04.589621188Z","timeToStatus":0.011763,"timeTotal":0.011830,"timeWriteBody":0.000067}
[nginx_access] [28/Oct/2020:18:30:04 +0000] "req-4l5xfbvwnnlf2twzv0vd" controller 200 152 0.012 POST "https://0.0.0.0:40943/arvados/v1/links" 127.0.0.1:34188 "-" "HTTPClient/1.0 (2.8.3, ruby 2.5.7 (2019-10-01))"
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"request","remoteAddr":"127.0.0.1:40018","reqBytes":414,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/links","reqQuery":"","time":"2020-10-28T18:30:04.591453224Z"}
[railsapi] App 1696 output: (0.1ms) SET TIME ZONE 'UTC'
[railsapi] App 1696 output: ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token='3kg6k6lzmp9kj5cpkcoxie963cmvjahbt2fod9zru30k1jqdmi' and (expires_at is null or expires_at > CURRENT_TIMESTAMP)) ORDER BY "api_client_authorizations"."id" ASC LIMIT $1 [["LIMIT", 1]]
[railsapi] App 1696 output: User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 186579971]]
[railsapi] App 1696 output: ApiClient Load (0.1ms) SELECT "api_clients".* FROM "api_clients" WHERE "api_clients"."id" = $1 [["id", 243589807]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] ApiClientAuthorization Load (0.4ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token IN ('4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi') AND
[railsapi] App 1696 output: (expires_at IS NULL OR expires_at > CURRENT_TIMESTAMP))
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User Load (0.4ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 36826545]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Link Load (1.2ms) SELECT links."head_uuid" FROM "links" WHERE ((links.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) OR links.owner_uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp()) AND traverse_owned) OR (links.link_class IN ('permission','resources') AND (links.head_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) OR links.tail_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: )))) ) AND ((links.owner_uuid in ('zzzzz-j7d0g-publicfavorites','zzzzz-tpzed-xurymjxw79nv3jz')) AND (links.link_class = 'star') AND (substring(links.head_uuid, 7, 5) = 'j7d0g')) LIMIT $1 OFFSET $2 [["LIMIT", 1000], ["OFFSET", 1]]
[railsapi] App 1696 output: {"method":"GET","path":"/arvados/v1/links","format":"json","controller":"Arvados::V1::LinksController","action":"index","status":200,"duration":7.0,"view":0.2,"db":2.05,"request_id":"req-4l5xfbvwnnlf2twzv0vd","client_ipaddr":"127.0.0.1","client_auth":"zzzzz-gj3su-077z32aux8dg2s1","params":{"reader_tokens":"[\"4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi\"]","_method":"GET","count":"none","select":"[\"head_uuid\"]","filters":"[[\"owner_uuid\",\"in\",[\"zzzzz-j7d0g-publicfavorites\",\"zzzzz-tpzed-xurymjxw79nv3jz\"]],[\"link_class\",\"=\",\"star\"],[\"head_uuid\",\"is_a\",\"arvados#group\"]]","limit":"9223372036854775807","offset":"1","_profile":"true"},"@timestamp":"2020-10-28T18:30:04.604447797Z","@version":"1","message":"[200] GET /arvados/v1/links (Arvados::V1::LinksController#index)"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"response","remoteAddr":"127.0.0.1:40018","reqBytes":414,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/links","reqQuery":"","respBytes":87,"respStatus":"OK","respStatusCode":200,"time":"2020-10-28T18:30:04.604976465Z","timeToStatus":0.013458,"timeTotal":0.013515,"timeWriteBody":0.000057}
[nginx_access] [28/Oct/2020:18:30:04 +0000] "req-4l5xfbvwnnlf2twzv0vd" controller 200 87 0.014 POST "https://0.0.0.0:40943/arvados/v1/links" 127.0.0.1:34188 "-" "HTTPClient/1.0 (2.8.3, ruby 2.5.7 (2019-10-01))"
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"request","remoteAddr":"127.0.0.1:40020","reqBytes":243,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups","reqQuery":"","time":"2020-10-28T18:30:04.606469411Z"}
[railsapi] App 1696 output: (0.1ms) SET TIME ZONE 'UTC'
[railsapi] App 1696 output: ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token='3kg6k6lzmp9kj5cpkcoxie963cmvjahbt2fod9zru30k1jqdmi' and (expires_at is null or expires_at > CURRENT_TIMESTAMP)) ORDER BY "api_client_authorizations"."id" ASC LIMIT $1 [["LIMIT", 1]]
[railsapi] App 1696 output: User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 186579971]]
[railsapi] App 1696 output: ApiClient Load (0.1ms) SELECT "api_clients".* FROM "api_clients" WHERE "api_clients"."id" = $1 [["id", 243589807]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] ApiClientAuthorization Load (0.2ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token IN ('4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi') AND
[railsapi] App 1696 output: (expires_at IS NULL OR expires_at > CURRENT_TIMESTAMP))
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 36826545]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Group Load (0.8ms) SELECT "groups".* FROM "groups" WHERE ((groups.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) ) AND (groups.trash_at is NULL or groups.trash_at > statement_timestamp())) AND ((groups.uuid in ('zzzzz-j7d0g-starredshared01'))) ORDER BY groups.name asc, groups.modified_at desc, groups.uuid LIMIT $1 OFFSET $2 [["LIMIT", 1000], ["OFFSET", 0]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Link Load (0.1ms) SELECT "links".* FROM "links" WHERE "links"."head_uuid" = $1 AND "links"."link_class" = $2 [["head_uuid", "zzzzz-j7d0g-starredshared01"], ["link_class", "permission"]]
[railsapi] App 1696 output: {"method":"GET","path":"/arvados/v1/groups","format":"json","controller":"Arvados::V1::GroupsController","action":"index","status":200,"duration":6.23,"view":0.18,"db":1.3,"request_id":"req-4l5xfbvwnnlf2twzv0vd","client_ipaddr":"127.0.0.1","client_auth":"zzzzz-gj3su-077z32aux8dg2s1","params":{"reader_tokens":"[\"4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi\"]","_method":"GET","count":"none","order":"name","filters":"[[\"uuid\",\"in\",[\"zzzzz-j7d0g-starredshared01\"]]]","limit":"9223372036854775807","offset":"0","_profile":"true"},"@timestamp":"2020-10-28T18:30:04.618127606Z","@version":"1","message":"[200] GET /arvados/v1/groups (Arvados::V1::GroupsController#index)"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"response","remoteAddr":"127.0.0.1:40020","reqBytes":243,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups","reqQuery":"","respBytes":746,"respStatus":"OK","respStatusCode":200,"time":"2020-10-28T18:30:04.618645111Z","timeToStatus":0.012093,"timeTotal":0.012167,"timeWriteBody":0.000074}
[nginx_access] [28/Oct/2020:18:30:04 +0000] "req-4l5xfbvwnnlf2twzv0vd" controller 200 746 0.012 POST "https://0.0.0.0:40943/arvados/v1/groups" 127.0.0.1:34188 "-" "HTTPClient/1.0 (2.8.3, ruby 2.5.7 (2019-10-01))"
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"request","remoteAddr":"127.0.0.1:40022","reqBytes":243,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups","reqQuery":"","time":"2020-10-28T18:30:04.620637419Z"}
[railsapi] App 1696 output: (0.1ms) SET TIME ZONE 'UTC'
[railsapi] App 1696 output: ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token='3kg6k6lzmp9kj5cpkcoxie963cmvjahbt2fod9zru30k1jqdmi' and (expires_at is null or expires_at > CURRENT_TIMESTAMP)) ORDER BY "api_client_authorizations"."id" ASC LIMIT $1 [["LIMIT", 1]]
[railsapi] App 1696 output: User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 186579971]]
[railsapi] App 1696 output: ApiClient Load (0.1ms) SELECT "api_clients".* FROM "api_clients" WHERE "api_clients"."id" = $1 [["id", 243589807]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token IN ('4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi') AND
[railsapi] App 1696 output: (expires_at IS NULL OR expires_at > CURRENT_TIMESTAMP))
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User Load (0.3ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 36826545]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Group Load (1.0ms) SELECT "groups".* FROM "groups" WHERE ((groups.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) ) AND (groups.trash_at is NULL or groups.trash_at > statement_timestamp())) AND ((groups.uuid in ('zzzzz-j7d0g-starredshared01'))) ORDER BY groups.name asc, groups.modified_at desc, groups.uuid LIMIT $1 OFFSET $2 [["LIMIT", 1000], ["OFFSET", 1]]
[railsapi] App 1696 output: {"method":"GET","path":"/arvados/v1/groups","format":"json","controller":"Arvados::V1::GroupsController","action":"index","status":200,"duration":5.58,"view":0.27,"db":1.47,"request_id":"req-4l5xfbvwnnlf2twzv0vd","client_ipaddr":"127.0.0.1","client_auth":"zzzzz-gj3su-077z32aux8dg2s1","params":{"reader_tokens":"[\"4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi\"]","_method":"GET","count":"none","order":"name","filters":"[[\"uuid\",\"in\",[\"zzzzz-j7d0g-starredshared01\"]]]","limit":"9223372036854775807","offset":"1","_profile":"true"},"@timestamp":"2020-10-28T18:30:04.631798386Z","@version":"1","message":"[200] GET /arvados/v1/groups (Arvados::V1::GroupsController#index)"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"response","remoteAddr":"127.0.0.1:40022","reqBytes":243,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups","reqQuery":"","respBytes":88,"respStatus":"OK","respStatusCode":200,"time":"2020-10-28T18:30:04.632790031Z","timeToStatus":0.011788,"timeTotal":0.012125,"timeWriteBody":0.000337}
[nginx_access] [28/Oct/2020:18:30:04 +0000] "req-4l5xfbvwnnlf2twzv0vd" controller 200 88 0.013 POST "https://0.0.0.0:40943/arvados/v1/groups" 127.0.0.1:34188 "-" "HTTPClient/1.0 (2.8.3, ruby 2.5.7 (2019-10-01))"
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"request","remoteAddr":"127.0.0.1:40024","reqBytes":276,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups","reqQuery":"","time":"2020-10-28T18:30:04.634551844Z"}
[railsapi] App 1696 output: (0.2ms) SET TIME ZONE 'UTC'
[railsapi] App 1696 output: ApiClientAuthorization Load (0.4ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token='3kg6k6lzmp9kj5cpkcoxie963cmvjahbt2fod9zru30k1jqdmi' and (expires_at is null or expires_at > CURRENT_TIMESTAMP)) ORDER BY "api_client_authorizations"."id" ASC LIMIT $1 [["LIMIT", 1]]
[railsapi] App 1696 output: User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 186579971]]
[railsapi] App 1696 output: ApiClient Load (0.2ms) SELECT "api_clients".* FROM "api_clients" WHERE "api_clients"."id" = $1 [["id", 243589807]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] ApiClientAuthorization Load (0.2ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token IN ('4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi') AND
[railsapi] App 1696 output: (expires_at IS NULL OR expires_at > CURRENT_TIMESTAMP))
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 36826545]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Group Load (0.9ms) SELECT "groups".* FROM "groups" WHERE ((groups.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) ) AND (groups.trash_at is NULL or groups.trash_at > statement_timestamp())) AND ((groups.group_class = 'project') AND (groups.owner_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz'))) ORDER BY groups.name asc, groups.modified_at desc, groups.uuid LIMIT $1 OFFSET $2 [["LIMIT", 200], ["OFFSET", 0]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Link Load (0.1ms) SELECT "links".* FROM "links" WHERE "links"."head_uuid" = $1 AND "links"."link_class" = $2 [["head_uuid", "zzzzz-j7d0g-9otoxmrksam74q6"], ["link_class", "permission"]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Link Load (0.1ms) SELECT "links".* FROM "links" WHERE "links"."head_uuid" = $1 AND "links"."link_class" = $2 [["head_uuid", "zzzzz-j7d0g-rew6elm53kancon"], ["link_class", "permission"]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Link Load (0.1ms) SELECT "links".* FROM "links" WHERE "links"."head_uuid" = $1 AND "links"."link_class" = $2 [["head_uuid", "zzzzz-j7d0g-starredshared01"], ["link_class", "permission"]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Link Load (0.1ms) SELECT "links".* FROM "links" WHERE "links"."head_uuid" = $1 AND "links"."link_class" = $2 [["head_uuid", "zzzzz-j7d0g-subprojsamenam1"], ["link_class", "permission"]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Link Load (0.1ms) SELECT "links".* FROM "links" WHERE "links"."head_uuid" = $1 AND "links"."link_class" = $2 [["head_uuid", "zzzzz-j7d0g-trashedproject1"], ["link_class", "permission"]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] (0.8ms) SELECT COUNT(DISTINCT "groups"."id") FROM "groups" WHERE ((groups.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) ) AND (groups.trash_at is NULL or groups.trash_at > statement_timestamp())) AND ((groups.group_class = 'project') AND (groups.owner_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz')))
[railsapi] App 1696 output: {"method":"GET","path":"/arvados/v1/groups","format":"json","controller":"Arvados::V1::GroupsController","action":"index","status":200,"duration":11.75,"view":0.21,"db":2.77,"request_id":"req-4l5xfbvwnnlf2twzv0vd","client_ipaddr":"127.0.0.1","client_auth":"zzzzz-gj3su-077z32aux8dg2s1","params":{"reader_tokens":"[\"4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi\"]","_method":"GET","order":"name","filters":"[[\"group_class\",\"=\",\"project\"],[\"owner_uuid\",\"in\",[\"zzzzz-tpzed-xurymjxw79nv3jz\"]]]","limit":"200","offset":"0","_profile":"true"},"@timestamp":"2020-10-28T18:30:04.655052544Z","@version":"1","message":"[200] GET /arvados/v1/groups (Arvados::V1::GroupsController#index)"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"response","remoteAddr":"127.0.0.1:40024","reqBytes":276,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups","reqQuery":"","respBytes":3220,"respStatus":"OK","respStatusCode":200,"time":"2020-10-28T18:30:04.655657649Z","timeToStatus":0.020997,"timeTotal":0.021098,"timeWriteBody":0.000102}
[nginx_access] [28/Oct/2020:18:30:04 +0000] "req-4l5xfbvwnnlf2twzv0vd" controller 200 3232 0.021 POST "https://0.0.0.0:40943/arvados/v1/groups" 127.0.0.1:34188 "-" "HTTPClient/1.0 (2.8.3, ruby 2.5.7 (2019-10-01))"
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"request","remoteAddr":"127.0.0.1:40026","reqBytes":420,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups","reqQuery":"","time":"2020-10-28T18:30:04.659630732Z"}
[railsapi] App 1696 output: (0.2ms) SET TIME ZONE 'UTC'
[railsapi] App 1696 output: ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token='3kg6k6lzmp9kj5cpkcoxie963cmvjahbt2fod9zru30k1jqdmi' and (expires_at is null or expires_at > CURRENT_TIMESTAMP)) ORDER BY "api_client_authorizations"."id" ASC LIMIT $1 [["LIMIT", 1]]
[railsapi] App 1696 output: User Load (0.4ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 186579971]]
[railsapi] App 1696 output: ApiClient Load (0.2ms) SELECT "api_clients".* FROM "api_clients" WHERE "api_clients"."id" = $1 [["id", 243589807]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token IN ('4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi') AND
[railsapi] App 1696 output: (expires_at IS NULL OR expires_at > CURRENT_TIMESTAMP))
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User Load (0.3ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 36826545]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Group Load (1.0ms) SELECT "groups".* FROM "groups" WHERE ((groups.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) ) AND (groups.trash_at is NULL or groups.trash_at > statement_timestamp())) AND ((groups.group_class = 'project') AND (groups.owner_uuid in ('zzzzz-j7d0g-9otoxmrksam74q6','zzzzz-j7d0g-rew6elm53kancon','zzzzz-j7d0g-starredshared01','zzzzz-j7d0g-subprojsamenam1','zzzzz-j7d0g-trashedproject1'))) ORDER BY groups.name asc, groups.modified_at desc, groups.uuid LIMIT $1 OFFSET $2 [["LIMIT", 200], ["OFFSET", 0]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User.group_permissions (0.5ms)
[railsapi] App 1696 output: SELECT target_uuid, perm_level
[railsapi] App 1696 output: FROM materialized_permissions
[railsapi] App 1696 output: WHERE user_uuid in (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ($1)
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= $2
[railsapi] App 1696 output: ) and perm_level >= $2
[railsapi] App 1696 output: [[nil, "zzzzz-tpzed-xurymjxw79nv3jz"], [nil, 3]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Link Load (0.2ms) SELECT "links".* FROM "links" WHERE "links"."head_uuid" = $1 AND "links"."link_class" = $2 [["head_uuid", "zzzzz-j7d0g-trashedproject2"], ["link_class", "permission"]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] (0.8ms) SELECT COUNT(DISTINCT "groups"."id") FROM "groups" WHERE ((groups.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) ) AND (groups.trash_at is NULL or groups.trash_at > statement_timestamp())) AND ((groups.group_class = 'project') AND (groups.owner_uuid in ('zzzzz-j7d0g-9otoxmrksam74q6','zzzzz-j7d0g-rew6elm53kancon','zzzzz-j7d0g-starredshared01','zzzzz-j7d0g-subprojsamenam1','zzzzz-j7d0g-trashedproject1')))
[railsapi] App 1696 output: {"method":"GET","path":"/arvados/v1/groups","format":"json","controller":"Arvados::V1::GroupsController","action":"index","status":200,"duration":8.04,"view":0.19,"db":2.95,"request_id":"req-4l5xfbvwnnlf2twzv0vd","client_ipaddr":"127.0.0.1","client_auth":"zzzzz-gj3su-077z32aux8dg2s1","params":{"reader_tokens":"[\"4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi\"]","_method":"GET","order":"name","filters":"[[\"group_class\",\"=\",\"project\"],[\"owner_uuid\",\"in\",[\"zzzzz-j7d0g-9otoxmrksam74q6\",\"zzzzz-j7d0g-rew6elm53kancon\",\"zzzzz-j7d0g-starredshared01\",\"zzzzz-j7d0g-subprojsamenam1\",\"zzzzz-j7d0g-trashedproject1\"]]]","limit":"200","offset":"0","_profile":"true"},"@timestamp":"2020-10-28T18:30:04.674614712Z","@version":"1","message":"[200] GET /arvados/v1/groups (Arvados::V1::GroupsController#index)"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"response","remoteAddr":"127.0.0.1:40026","reqBytes":420,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups","reqQuery":"","respBytes":659,"respStatus":"OK","respStatusCode":200,"time":"2020-10-28T18:30:04.675170125Z","timeToStatus":0.015460,"timeTotal":0.015532,"timeWriteBody":0.000073}
[nginx_access] [28/Oct/2020:18:30:04 +0000] "req-4l5xfbvwnnlf2twzv0vd" controller 200 659 0.016 POST "https://0.0.0.0:40943/arvados/v1/groups" 127.0.0.1:34188 "-" "HTTPClient/1.0 (2.8.3, ruby 2.5.7 (2019-10-01))"
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"request","remoteAddr":"127.0.0.1:40028","reqBytes":276,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups","reqQuery":"","time":"2020-10-28T18:30:04.677213431Z"}
[railsapi] App 1696 output: (0.1ms) SET TIME ZONE 'UTC'
[railsapi] App 1696 output: ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token='3kg6k6lzmp9kj5cpkcoxie963cmvjahbt2fod9zru30k1jqdmi' and (expires_at is null or expires_at > CURRENT_TIMESTAMP)) ORDER BY "api_client_authorizations"."id" ASC LIMIT $1 [["LIMIT", 1]]
[railsapi] App 1696 output: User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 186579971]]
[railsapi] App 1696 output: ApiClient Load (0.1ms) SELECT "api_clients".* FROM "api_clients" WHERE "api_clients"."id" = $1 [["id", 243589807]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] ApiClientAuthorization Load (0.2ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token IN ('4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi') AND
[railsapi] App 1696 output: (expires_at IS NULL OR expires_at > CURRENT_TIMESTAMP))
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 36826545]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Group Load (0.8ms) SELECT "groups".* FROM "groups" WHERE ((groups.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) ) AND (groups.trash_at is NULL or groups.trash_at > statement_timestamp())) AND ((groups.group_class = 'project') AND (groups.owner_uuid in ('zzzzz-j7d0g-trashedproject2'))) ORDER BY groups.name asc, groups.modified_at desc, groups.uuid LIMIT $1 OFFSET $2 [["LIMIT", 200], ["OFFSET", 0]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] (0.7ms) SELECT COUNT(DISTINCT "groups"."id") FROM "groups" WHERE ((groups.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) ) AND (groups.trash_at is NULL or groups.trash_at > statement_timestamp())) AND ((groups.group_class = 'project') AND (groups.owner_uuid in ('zzzzz-j7d0g-trashedproject2')))
[railsapi] App 1696 output: {"method":"GET","path":"/arvados/v1/groups","format":"json","controller":"Arvados::V1::GroupsController","action":"index","status":200,"duration":5.43,"view":0.16,"db":1.93,"request_id":"req-4l5xfbvwnnlf2twzv0vd","client_ipaddr":"127.0.0.1","client_auth":"zzzzz-gj3su-077z32aux8dg2s1","params":{"reader_tokens":"[\"4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi\"]","_method":"GET","order":"name","filters":"[[\"group_class\",\"=\",\"project\"],[\"owner_uuid\",\"in\",[\"zzzzz-j7d0g-trashedproject2\"]]]","limit":"200","offset":"0","_profile":"true"},"@timestamp":"2020-10-28T18:30:04.687961142Z","@version":"1","message":"[200] GET /arvados/v1/groups (Arvados::V1::GroupsController#index)"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"response","remoteAddr":"127.0.0.1:40028","reqBytes":276,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups","reqQuery":"","respBytes":107,"respStatus":"OK","respStatusCode":200,"time":"2020-10-28T18:30:04.688438483Z","timeToStatus":0.011152,"timeTotal":0.011216,"timeWriteBody":0.000064}
[nginx_access] [28/Oct/2020:18:30:04 +0000] "req-4l5xfbvwnnlf2twzv0vd" controller 200 107 0.011 POST "https://0.0.0.0:40943/arvados/v1/groups" 127.0.0.1:34188 "-" "HTTPClient/1.0 (2.8.3, ruby 2.5.7 (2019-10-01))"
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"request","remoteAddr":"127.0.0.1:40030","reqBytes":102,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups/zzzzz-tpzed-xurymjxw79nv3jz","reqQuery":"","time":"2020-10-28T18:30:04.695932758Z"}
[railsapi] App 1696 output: (0.2ms) SET TIME ZONE 'UTC'
[railsapi] App 1696 output: ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token='3kg6k6lzmp9kj5cpkcoxie963cmvjahbt2fod9zru30k1jqdmi' and (expires_at is null or expires_at > CURRENT_TIMESTAMP)) ORDER BY "api_client_authorizations"."id" ASC LIMIT $1 [["LIMIT", 1]]
[railsapi] App 1696 output: User Load (0.3ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 186579971]]
[railsapi] App 1696 output: ApiClient Load (0.1ms) SELECT "api_clients".* FROM "api_clients" WHERE "api_clients"."id" = $1 [["id", 243589807]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] ApiClientAuthorization Load (0.3ms) SELECT "api_client_authorizations".* FROM "api_client_authorizations" WHERE (api_token IN ('4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi') AND
[railsapi] App 1696 output: (expires_at IS NULL OR expires_at > CURRENT_TIMESTAMP))
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] User Load (0.2ms) SELECT "users".* FROM "users" WHERE (redirect_to_user_uuid is null) AND "users"."id" = $1 [["id", 36826545]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Group Load (0.7ms) SELECT "groups".* FROM "groups" WHERE ((groups.uuid IN (SELECT target_uuid FROM materialized_permissions WHERE user_uuid IN (
[railsapi] App 1696 output: select target_uuid from materialized_permissions where user_uuid in ('zzzzz-tpzed-xurymjxw79nv3jz','zzzzz-tpzed-anonymouspublic')
[railsapi] App 1696 output: and target_uuid like '_____-tpzed-_______________' and traverse_owned=true and perm_level >= 1
[railsapi] App 1696 output: ) AND perm_level >= 1 AND target_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp())) ) AND (groups.trash_at is NULL or groups.trash_at > statement_timestamp())) AND (groups.uuid='zzzzz-tpzed-xurymjxw79nv3jz') ORDER BY "groups"."id" ASC LIMIT $1 OFFSET $2 [["LIMIT", 1], ["OFFSET", 0]]
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] "Object not found"
[railsapi] App 1696 output: [req-4l5xfbvwnnlf2twzv0vd] Error 1603909804+2884ca33: 404
[railsapi] App 1696 output: {"method":"GET","path":"/arvados/v1/groups/zzzzz-tpzed-xurymjxw79nv3jz","format":"json","controller":"Arvados::V1::GroupsController","action":"show","status":404,"duration":4.4,"view":0.23,"db":1.14,"request_id":"req-4l5xfbvwnnlf2twzv0vd","client_ipaddr":"127.0.0.1","client_auth":"zzzzz-gj3su-077z32aux8dg2s1","params":{"reader_tokens":"[\"4kg6k6lzmp9kj4cpkcoxie964cmvjahbt4fod9zru44k4jqdmi\"]","_method":"GET","_profile":"true"},"@timestamp":"2020-10-28T18:30:04.706444781Z","@version":"1","message":"[404] GET /arvados/v1/groups/zzzzz-tpzed-xurymjxw79nv3jz (Arvados::V1::GroupsController#show)"}
[controller] {"PID":1765,"RequestID":"req-4l5xfbvwnnlf2twzv0vd","level":"info","msg":"response","remoteAddr":"127.0.0.1:40030","reqBytes":102,"reqForwardedFor":"127.0.0.1","reqHost":"0.0.0.0:40943","reqMethod":"POST","reqPath":"arvados/v1/groups/zzzzz-tpzed-xurymjxw79nv3jz","reqQuery":"","respBody":"{\"errors\":[\"Path not found (req-4l5xfbvwnnlf2twzv0vd)\"],\"error_token\":\"1603909804+2884ca33\"}","respBytes":92,"respStatus":"Not Found","respStatusCode":404,"time":"2020-10-28T18:30:04.706920078Z","timeToStatus":0.010918,"timeTotal":0.010981,"timeWriteBody":0.000063}
[nginx_access] [28/Oct/2020:18:30:04 +0000] "req-4l5xfbvwnnlf2twzv0vd" controller 404 92 0.012 POST "https://0.0.0.0:40943/arvados/v1/groups/zzzzz-tpzed-xurymjxw79nv3jz" 127.0.0.1:34188 "-" "HTTPClient/1.0 (2.8.3, ruby 2.5.7 (2019-10-01))"
[nginx_error] 2020/10/28 18:30:04 [info] 1758#1758: *2010 client closed connection while SSL handshaking, client: 127.0.0.1, server: 127.0.0.1:40943
Possible unhandled promise rejection: Error:
Saved ./tmp/workbench-fail-16.png
ContainerRequestsTest#test_Run_button_enabled_once_all_required_inputs_are_provided = 42.94 s = E
Files
Related issues
Updated by Nico César over 3 years ago
- Related to Feature #17014: Add Container Requests endpoint to controller added
Actions