[FOLIO-1312] Intermittant ansible deployment errors during PRs Created: 26/Jun/18 Updated: 12/Nov/18 Resolved: 22/Aug/18 |
|
| Status: | Closed |
| Project: | FOLIO |
| Components: | None |
| Affects versions: | None |
| Fix versions: | None |
| Type: | Bug | Priority: | P3 |
| Reporter: | John Malconian | Assignee: | John Malconian |
| Resolution: | Done | Votes: | 0 |
| Labels: | ci, sprint41, sprint42, sprint43, sprint44, sprint45 | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original estimate: | Not Specified | ||
| Attachments: |
|
||||||||||||||||||||
| Issue links: |
|
||||||||||||||||||||
| Sprint: | |||||||||||||||||||||
| Description |
|
The following auth error occurs every so often while loading sample circulation data for a tenant during PR regression testing initialization: ASK [folio-ansible/roles/mod-circulation-data : Load loan policies] *********** to retry, use: --limit @/home/jenkins/workspace/folio-org/ui-users/PR-413/folio-infrastructure/CI/ansible/folioci-pr.retry |
| Comments |
| Comment by John Malconian [ 26/Jun/18 ] |
|
Example occurances: |
| Comment by John Malconian [ 26/Jun/18 ] |
|
Subsequent success - https://jenkins-aws.indexdata.com/job/folio-org/job/ui-users/view/change-requests/job/PR-413/9/ |
| Comment by John Malconian [ 26/Jun/18 ] |
|
It appears the permission is added to the tenant admin user here on PR-413 Build 8: changed: [localhost] => (item= {u'dummy': False, u'permissionName': u'circulation-storage.all', u'displayName': u'Circulation storage module - all permissions', u'description': u'Entire set of permissions needed to use the circulation storage module', u'tags': [], u'childOf': [], u'visible': False, u'subPermissions': [u'circulation-storage.loans.collection.get', u'circulation-storage.loans.item.get', u'circulation-storage.loans.item.post', u'circulation-storage.loans.item.put', u'circulation-storage.loans.item.delete', u'circulation-storage.loans.collection.delete', u'circulation-storage.loans-history.collection.get', u'circulation-storage.loan-rules.get', u'circulation-storage.loan-rules.put', u'circulation-storage.loan-policies.collection.get', u'circulation-storage.loan-policies.item.get', u'circulation-storage.loan-policies.item.post', u'circulation-storage.loan-policies.item.put', u'circulation-storage.loan-policies.item.delete', u'circulation-storage.loan-policies.collection.delete', u'circulation-storage.requests.collection.get', u'circulation-storage.requests.item.get', u'circulation-storage.requests.item.post', u'circulation-storage.requests.item.put', u'circulation-storage.requests.item.delete', u'circulation-storage.requests.collection.delete', u'circulation-storage.fixed-due-date-schedules.collection.delete', u'circulation-storage.fixed-due-date-schedules.item.delete', u'circulation-storage.fixed-due-date-schedules.item.put', u'circulation-storage.fixed-due-date-schedules.item.post', u'circulation-storage.fixed-due-date-schedules.item.get', u'circulation-storage.fixed-due-date-schedules.collection.get', u'circulation-storage.staff-slips.item.delete', u'circulation-storage.staff-slips.collection.delete', u'circulation-storage.staff-slips.collection.get', u'circulation-storage.staff-slips.item.post', u'circulation-storage.staff-slips.item.put', u'circulation-storage.staff-slips.item.get'], u'mutable': False, u'id': u'a9e33958-888c-40ff-bb81-793649b6965b', u'grantedTo': []}) And here on PR-413 Build 9: changed: [localhost] => (item= {u'dummy': False, u'permissionName': u'circulation-storage.all', u'displayName': u'Circulation storage module - all permissions', u'description': u'Entire set of permissions needed to use the circulation storage module', u'tags': [], u'childOf': [], u'visible': False, u'subPermissions': [u'circulation-storage.loans.collection.get', u'circulation-storage.loans.item.get', u'circulation-storage.loans.item.post', u'circulation-storage.loans.item.put', u'circulation-storage.loans.item.delete', u'circulation-storage.loans.collection.delete', u'circulation-storage.loans-history.collection.get', u'circulation-storage.loan-rules.get', u'circulation-storage.loan-rules.put', u'circulation-storage.loan-policies.collection.get', u'circulation-storage.loan-policies.item.get', u'circulation-storage.loan-policies.item.post', u'circulation-storage.loan-policies.item.put', u'circulation-storage.loan-policies.item.delete', u'circulation-storage.loan-policies.collection.delete', u'circulation-storage.requests.collection.get', u'circulation-storage.requests.item.get', u'circulation-storage.requests.item.post', u'circulation-storage.requests.item.put', u'circulation-storage.requests.item.delete', u'circulation-storage.requests.collection.delete', u'circulation-storage.fixed-due-date-schedules.collection.delete', u'circulation-storage.fixed-due-date-schedules.item.delete', u'circulation-storage.fixed-due-date-schedules.item.put', u'circulation-storage.fixed-due-date-schedules.item.post', u'circulation-storage.fixed-due-date-schedules.item.get', u'circulation-storage.fixed-due-date-schedules.collection.get', u'circulation-storage.staff-slips.item.delete', u'circulation-storage.staff-slips.collection.delete', u'circulation-storage.staff-slips.collection.get', u'circulation-storage.staff-slips.item.post', u'circulation-storage.staff-slips.item.put', u'circulation-storage.staff-slips.item.get'], u'mutable': False, u'id': u'2f2048b5-1438-43b5-85aa-6bdf56ab63fa', u'grantedTo': []}) |
| Comment by John Malconian [ 26/Jun/18 ] |
|
Permissions for pr_413_8_admin: [malc@ip-10-36-20-124 scripts]$ curl -s -D - -X POST -d ' { "username": "pr_413_8_admin", "password": "admin"}' -H 'X-Okapi-Tenant: pr_413_8' -H 'Accept: application/json, text/plain' -H 'Content-Type: application/json' http://folio-snapshot-stable.aws.indexdata.com:9130/bl-users/login { }, , Permissions for pr_413_9_admin: [malc@ip-10-36-20-124 scripts]$ curl -s -D - -XPOST -d ' { "username": "pr_413_9_admin", "password": "admin"}' -H 'X-Okapi-Tenant: pr_413_9' -H 'Accept: application/json, text/plain' -H 'Content-Type: application/json' http://folio-snapshot-stable.aws.indexdata.com:9130/bl-users/login { }, , |
| Comment by John Malconian [ 26/Jun/18 ] |
|
Both tenant admin users have 'circulation-storage.all' defined which I assume includes 'circulation-storage.loan-policies.item.post' |
| Comment by John Malconian [ 26/Jun/18 ] |
|
The task that loads the loan policies looks like this:
I wonder if the header 'Authtoken-Refresh-Cache: "true"' may have something to do with this. |
| Comment by John Malconian [ 26/Jun/18 ] |
|
the permission 'circulation-storage.all' is created and granted to the tenant admin user minutes prior to when this request is made and approximately a few seconds after the tenant admin user is granted the x_okapi_token that is used in the request. |
| Comment by John Malconian [ 10/Jul/18 ] |
|
I believe this might be resolved by
|
| Comment by John Malconian [ 18/Jul/18 ] |
|
Haven't seen problem since
|
| Comment by John Malconian [ 19/Jul/18 ] |
|
Re-opening this issue. New instance of failure detected. https://jenkins-aws.indexdata.com/job/folio-org/job/ui-checkout/job/PR-158/2/console |
| Comment by John Malconian [ 19/Jul/18 ] |
|
I thought maybe the admin user became 'inactive' maybe, but that does not appear to be the case: [malc@ip-10-36-20-124 scripts]$ curl -H "x-okapi-token: $OKAPI_TOKEN" -H "x-okapi-tenant: pr_158_2" -H "Content-Type: application/json" $ {OKAPI_URL}/users } ], |
| Comment by John Malconian [ 19/Jul/18 ] |
|
Log snippet: 2018-07-19 16:42:35,777 INFO DockerModuleHandle mod-permissions-5.2.5-SNAPSHOT.22 16:42:35 INFO PermsAPI Calling getExpandedPermissionsSequential with permissionList: inventory-storage.location-units.campuses.item.get, inventory-storage.location-units.campuses.item.post, inventory-storage.location-units.campuses.item.put, inventory-storage.location-units.campuses.item.delete, inventory-storage.location-units.libraries.collection.get, inventory-storage.location-units.libraries.item.get, inventory-storage.location-units.libraries.item.post, inventory-storage.location-units.libraries.item.put, inventory-storage.location-units.libraries.item.delete, inventory-storage.locations.collection.get, inventory-storage.locations.item.get, inventory-storage.locations.item.post, inventory-storage.locations.item.put, inventory-storage.locations.item.delete, inventory-storage.identifier-types.collection.get 2018-07-19 16:42:35,780 INFO ProxyContext 954162/classification-types REQ 10.36.20.139:36938 pr_158_2 POST /classification-types mod-authtoken-1.4.1-SNAPSHOT.21 mod-inventory-storage-12.1.0-SNAPSHOT.128 2018-07-19 16:42:35,781 WARN ProxyService relayToResponse XXX Returning direct response 403 2018-07-19 16:42:35,781 INFO ProxyContext 954162/classification-types RES 403 617us mod-authtoken-1.4.1-SNAPSHOT.21 http://10.36.1.64:9135/classification-types 2018-07-19 16:42:35,784 INFO DockerModuleHandle mod-authtoken-1.4.1-SNAPSHOT.21 getUserAndExpandedPermissions, userid=8965408e-13df-59b1-b927-f7324aa5771apermissions=[] 2018-07-19 16:42:35,784 INFO DockerModuleHandle mod-authtoken-1.4.1-SNAPSHOT.21 completing future with user permissions=[], expanded permissions=[] 2018-07-19 16:42:35,784 INFO DockerModuleHandle mod-authtoken-1.4.1-SNAPSHOT.21 Jul 19, 2018 4:42:35 PM mod-auth-authtoken-module 2018-07-19 16:42:35,784 INFO DockerModuleHandle mod-authtoken-1.4.1-SNAPSHOT.21 INFO: Retrieving permissions for userid 8965408e-13df-59b1-b927-f7324aa5771a and expanding permissions for [] 2018-07-19 16:42:35,784 INFO DockerModuleHandle mod-authtoken-1.4.1-SNAPSHOT.21 Jul 19, 2018 4:42:35 PM mod-auth-authtoken-module 2018-07-19 16:42:35,784 INFO DockerModuleHandle mod-authtoken-1.4.1-SNAPSHOT.21 INFO: Retrieving permissions for userid 8965408e-13df-59b1-b927-f7324aa5771a, and expanded permissions for [] 2018-07-19 16:42:35,784 INFO DockerModuleHandle mod-authtoken-1.4.1-SNAPSHOT.21 Jul 19, 2018 4:42:35 PM mod-auth-authtoken-module 2018-07-19 16:42:35,784 INFO DockerModuleHandle mod-authtoken-1.4.1-SNAPSHOT.21 SEVERE: [](user permissions) nor [](module permissions) do not contain inventory-storage.classification-types.item.post |
| Comment by John Malconian [ 19/Jul/18 ] |
|
Permissions for user pr_158_2_admin: ubuntu@ip-10-36-1-64:~$ curl -s -D - -X POST -d '{ "username": "pr_158_2_admin", "password": "admin"}' -H 'X-Okapi-Tenant: pr_158_2' -H 'Accept: application/json, text/plain' -H 'Content-Type: application/json' http://folio-snapshot-stable.aws.indexdata.com:9130/bl-users/login
HTTP/1.1 201 Created
X-Okapi-Trace: POST mod-authtoken-1.4.1-SNAPSHOT.21 http://10.36.1.64:9135/bl-users/login : 202 854us
Content-Type: application/json
x-okapi-token: eyJhbGciOiJIUzUxMiJ9.eyJzdWIiOiJwcl8xNThfMl9hZG1pbiIsInVzZXJfaWQiOiI4OTY1NDA4ZS0xM2RmLTU5YjEtYjkyNy1mNzMyNGFhNTc3MWEiLCJ0ZW5hbnQiOiJwcl8xNThfMiJ9.gKQ3UyFROWL5A8A4RaYD3f4Jm7l8Z2JJCGmuECTfVtqUoC-sRRl_Jg25KCO4O-xAY7ijZ2fuq8_KhWaCIkRULg
host: folio-snapshot-stable.aws.indexdata.com:9130
user-agent: curl/7.47.0
x-okapi-tenant: pr_158_2
accept: application/json, text/plain
x-okapi-request-id: 150912/bl-users
x-okapi-url: http://10.36.1.64:9130
x-okapi-permissions: []
X-Okapi-Trace: POST mod-users-bl-3.0.0-SNAPSHOT.17 http://10.36.1.64:9134/bl-users/login : 201 60350us
Transfer-Encoding: chunked
{
"user" : {
"username" : "pr_158_2_admin",
"id" : "8965408e-13df-59b1-b927-f7324aa5771a",
"active" : true,
"proxyFor" : [ ],
"personal" : {
"lastName" : "pr_158_2",
"firstName" : "Admin",
"email" : "admin@example.org",
"addresses" : [ ]
}
},
"permissions" : {
"id" : "de79044f-f0a5-524c-8e01-0c7eaf9e8018",
"userId" : "8965408e-13df-59b1-b927-f7324aa5771a",
"permissions" : [ "perms.all", "login.all", "users.all", "ui-checkin.all", "ui-checkout.all", "settings.checkout.enabled", "settings.loan-policies.all", "ui-circulation.settings.fixed-due-date-schedules", "module.developer.enabled", "ui-inventory.settings.contributor-types", "settings.loan-rules.all", "ui-inventory.settings.materialtypes", "ui-inventory.settings.loantypes", "ui-circulation.settings.cancellation-reasons", "ui-inventory.settings.instance-formats", "settings.developer.enabled", "ui-inventory.settings.instance-types", "module.organization.enabled", "ui-requests.all", "ui-inventory.all-permissions.TEMPORARY", "module.search.enabled", "circulation-storage.all", "ui-organization.settings.key-bindings", "ui-organization.settings.locale", "ui-organization.settings.plugins", "ui-organization.settings.sso", "okapi.proxy.pull.modules.post", "okapi.all", "inventory.all", "ui-organization.settings.location", "circulation.all", "configuration.all", "notify.all", "settings.enabled", "inventory-storage.all", "login-saml.all", "users-bl.all", "stripes-util-notes.all", "stripes-util-notes.edit", "module.notes.enabled", "stripes-util-notes.create", "stripes-util-notes.delete" ]
},
"proxiesFor" : [ ]
|
| Comment by John Malconian [ 19/Jul/18 ] |
|
Kurt Nordstrom suggested setting the header 'Authtoken-Refresh-Cache: true' in the data loading requests. Updated folio-ansible/roles/module-sample-data/tasks/load-data.yml. Will also attempt to see if I can set something up that runs in a loop in an attempt to duplicate the error. |
| Comment by John Malconian [ 20/Jul/18 ] |
|
Looks like adding Authtoken-Refresh-Cache: true has exacerbated the issue. There were at least a half dozen failures overnight. Here are a few examples: https://jenkins-aws.indexdata.com/job/folio-org/job/ui-users/job/PR-429/7/console |
| Comment by Kurt Nordstrom [ 20/Jul/18 ] |
|
Well, crap, that's not how it was supposed to work! Will investigate and let you know what I find. |
| Comment by John Malconian [ 24/Jul/18 ] |
|
I ran a loop that created tenants. enabled modules, assigned permissions, and loaded sample data exactly how jenkins is configured and am unable to reproduce a single failure. About 50 tenants created. I'm going to continue to see if I can generate an error, but have a feeling that I won't. That's making this issue all the more perplexing. Something environmental? Will look into other approaches. |
| Comment by John Malconian [ 24/Jul/18 ] |
|
Ran another loop of 40 tenants. No errors. |
| Comment by John Malconian [ 31/Jul/18 ] |
|
Most recent PR failure due to this issue: https://jenkins-aws.indexdata.com/job/folio-org/job/ui-users/job/PR-413/21/ TASK [folio-ansible/roles/module-sample-data : Load module data to /loan-policy-storage/loan-policies] *** failed: [localhost] (item=/tmp/ansible.K4GiNK/mod-circulation-storage/reference-data/loan-policy-storage/loan-policies/rolling.json) => {"changed": false, "connection": "close", "content": "Access requires permission: circulation-storage.loan-policies.item.post", "data_file": "/tmp/ansible.K4GiNK/mod-circulation-storage/reference-data/loan-policy-storage/loan-policies/rolling.json", "msg": "Status code was 403 and not [201, 500]: HTTP Error 403: Forbidden", "redirected": false, "status": 403, "transfer_encoding": "chunked", "url": "http://folio-snapshot-stable.aws.indexdata.com:9130/loan-policy-storage/loan-policies", "x_okapi_trace": "POST mod-authtoken-1.5.1-SNAPSHOT.24 http://10.36.1.143:9135/loan-policy-storage/loan-policies : 403 870us"}I've re-added 'Authtoken-Refresh-Cache: "true" header to Ansible module-sample-data role. Hoping for different result after Kurt's bugfix here: https://github.com/folio-org/mod-authtoken/commit/79eea50d23a7f441eac220b79fba089bcf4ea844 |
| Comment by John Malconian [ 01/Aug/18 ] |
|
Another error here this morning after enabling 'Authtoken-Refresh-Cache: "true": https://jenkins-aws.indexdata.com/job/folio-org/job/ui-organization/job/PR-72/18/console failed: [localhost] (item=/tmp/ansible.aojbH0/mod-inventory-storage/reference-data/contributor-types/Degreegrantinginstitution.json) => {"changed": false, "connection": "close", "content": "Access requires permission: inventory-storage.contributor-types.item.post", "data_file": "/tmp/ansible.aojbH0/mod-inventory-storage/reference-data/contributor-types/Degreegrantinginstitution.json", "msg": "Status code was 403 and not [201, 400]: HTTP Error 403: Forbidden", "redirected": false, "status": 403, "transfer_encoding": "chunked", "url": "http://folio-snapshot-stable.aws.indexdata.com:9130/contributor-types", "x_okapi_trace": "POST mod-authtoken-1.5.1-SNAPSHOT.24 http://10.36.1.143:9135/contributor-types : 403 16360us"} |
| Comment by John Malconian [ 01/Aug/18 ] |
|
I think the issue here is that there is a tenant admin user and tenant mismatch occurring. This build - https://jenkins-aws.indexdata.com/job/folio-org/job/ui-organization/view/change-requests/job/PR-72/18/ - which creates tenant 'pr_72_18' with a tenant admin user called 'pr_72_18_admin' and this build - Here are the attributes of the 'pr_72_18_admin' user: ubuntu@ip-10-36-1-143:~$ curl -s -D - -X POST -d '{ "username": "pr_72_18_admin", "password": "admin"}' -H 'X-Okapi-Tenant: pr_72_18' -H 'Accept: application/json, text/plain' -H 'Content-Type: application/json' http://folio-snapshot-stable.aws.indexdata.com:9130/bl-users/login
HTTP/1.1 201 Created
X-Okapi-Trace: POST mod-authtoken-1.5.1-SNAPSHOT.24 http://10.36.1.143:9135/bl-users/login : 202 612us
Content-Type: application/json
x-okapi-token: eyJhbGciOiJIUzUxMiJ9.eyJzdWIiOiJwcl83Ml8xOF9hZG1pbiIsInVzZXJfaWQiOiIyM2NmMTM3YS1mNzkxLTUwNjYtOWE0Ny0wYmEwYzk3OGJhYzQiLCJ0ZW5hbnQiOiJwcl83Ml8xOCIsImlhdCI6MTUzMzEzNzM1OH0.HRwAsqc8jSZt01Nqqe0V00pTWyNkczEcYTalvM0Zx3oAVJO3vwY0T3XUD-EDHZDmCNp_vMnK2d2gyO8BpEHJGw
host: folio-snapshot-stable.aws.indexdata.com:9130
user-agent: curl/7.47.0
x-okapi-tenant: pr_72_18
accept: application/json, text/plain
x-okapi-request-id: 354913/bl-users
x-okapi-url: http://10.36.1.143:9130
x-okapi-permissions: []
X-Okapi-Trace: POST mod-users-bl-3.0.0-SNAPSHOT.19 http://10.36.1.143:9134/bl-users/login : 201 63516us
Transfer-Encoding: chunked
{
"user" : {
"username" : "pr_72_18_admin",
"id" : "23cf137a-f791-5066-9a47-0ba0c978bac4",
"active" : true,
"proxyFor" : [ ],
"personal" : {
"lastName" : "pr_72_18",
"firstName" : "Admin",
"email" : "admin@example.org",
"addresses" : [ ]
}
},
"permissions" : {
"id" : "305e8b1c-659a-595a-9718-ebba56792100",
"userId" : "23cf137a-f791-5066-9a47-0ba0c978bac4",
"permissions" : [ "perms.all", "login.all", "users.all", "ui-checkin.all", "ui-checkout.all", "settings.checkout.enabled", "settings.loan-policies.all", "ui-circulation.settings.fixed-due-date-schedules", "ui-circulation.settings.cancellation-reasons", "module.organization.enabled", "module.search.enabled", "settings.loan-rules.all", "module.developer.enabled", "ui-inventory.settings.instance-types", "settings.developer.enabled", "ui-inventory.settings.instance-formats", "ui-organization.settings.location", "ui-inventory.all-permissions.TEMPORARY", "ui-inventory.settings.materialtypes", "ui-inventory.settings.loantypes", "ui-organization.settings.key-bindings", "ui-organization.settings.locale", "ui-organization.settings.plugins", "ui-organization.settings.sso", "ui-inventory.settings.contributor-types", "circulation.all", "ui-requests.all", "circulation-storage.all", "inventory.all", "configuration.all", "login-saml.all", "okapi.proxy.pull.modules.post", "okapi.all", "notify.all", "inventory-storage.all", "ui-users.create", "settings.comments.all", "settings.feefines.all", "module.notes.enabled", "tags.all", "settings.refunds.all", "users-bl.all", "stripes-util-notes.all", "module.tags.enabled", "settings.usergroups.all", "stripes-util-notes.edit", "stripes-util-notes.create", "stripes-util-notes.delete", "settings.tags.enabled", "settings.waives.all", "settings.accounts.all", "settings.transfers.all", "feesfines.all", "ui-users.editperms", "ui-users.editproxies", "settings.owners.all", "settings.feefineactions.all", "settings.transfertypes.all", "ui-users.editpermsets", "settings.payments.all", "settings.addresstypes.all" ]
},
"proxiesFor" : [ ]
}
Here are the attributes of the pr_99_6_admin user: ubuntu@ip-10-36-1-143:~$ curl -s -D - -X POST -d '{ "username": "pr_99_6_admin", "password": "admin"}' -H 'X-Okapi-Tenant: pr_99_6' -H 'Accept: application/json, text/plain' -H 'Content-Type: application/json' http://folio-snapshot-stable.aws.indexdata.com:9130/bl-users/login
HTTP/1.1 201 Created
X-Okapi-Trace: POST mod-authtoken-1.5.1-SNAPSHOT.24 http://10.36.1.143:9135/bl-users/login : 202 730us
Content-Type: application/json
x-okapi-token: eyJhbGciOiJIUzUxMiJ9.eyJzdWIiOiJwcl85OV82X2FkbWluIiwidXNlcl9pZCI6ImJlNDVkNDFkLTAwYmItNWEwMC1iMTg5LWYyMDliZTEyMzM0YSIsInRlbmFudCI6InByXzk5XzYiLCJpYXQiOjE1MzMxMzc3NDF9.j1WCtmbpmdC154AlUGl4dQVd4dIaLegN4EbIwCf0qDE4ygVceh936Ju92S6YplHC7HR-LCWzvY925P31Swe8Ig
host: folio-snapshot-stable.aws.indexdata.com:9130
user-agent: curl/7.47.0
x-okapi-tenant: pr_99_6
accept: application/json, text/plain
x-okapi-request-id: 850488/bl-users
x-okapi-url: http://10.36.1.143:9130
x-okapi-permissions: []
X-Okapi-Trace: POST mod-users-bl-3.0.0-SNAPSHOT.19 http://10.36.1.143:9134/bl-users/login : 201 70740us
Transfer-Encoding: chunked
{
"user" : {
"username" : "pr_99_6_admin",
"id" : "be45d41d-00bb-5a00-b189-f209be12334a",
"active" : true,
"proxyFor" : [ ],
"personal" : {
"lastName" : "pr_99_6",
"firstName" : "Admin",
"email" : "admin@example.org",
"addresses" : [ ]
}
},
"permissions" : {
"id" : "fa2fb195-de51-5b4e-935b-2b420de46db0",
"userId" : "be45d41d-00bb-5a00-b189-f209be12334a",
"permissions" : [ "perms.all", "login.all", "users.all", "ui-checkin.all", "ui-checkout.all", "settings.checkout.enabled", "settings.loan-policies.all", "ui-circulation.settings.cancellation-reasons", "module.developer.enabled", "ui-inventory.settings.loantypes", "settings.loan-rules.all", "settings.developer.enabled", "inventory.all", "ui-circulation.settings.fixed-due-date-schedules", "ui-inventory.all-permissions.TEMPORARY", "ui-inventory.settings.materialtypes", "ui-inventory.settings.instance-formats", "module.organization.enabled", "ui-inventory.settings.instance-types", "ui-inventory.settings.contributor-types", "ui-organization.settings.key-bindings", "ui-organization.settings.locale", "ui-organization.settings.plugins", "ui-organization.settings.sso", "ui-organization.settings.location", "ui-requests.all", "module.search.enabled", "circulation.all", "configuration.all", "circulation-storage.all", "okapi.all", "module.notes.enabled", "module.tags.enabled", "login-saml.all", "notify.all", "inventory-storage.all", "okapi.proxy.pull.modules.post", "feesfines.all", "settings.tags.enabled", "ui-users.create", "settings.feefines.all", "settings.payments.all", "users-bl.all", "stripes-util-notes.all", "stripes-util-notes.edit", "stripes-util-notes.create", "stripes-util-notes.delete", "tags.all", "settings.comments.all", "settings.feefineactions.all", "ui-users.editperms", "ui-users.editproxies", "settings.owners.all", "settings.refunds.all", "settings.waives.all", "settings.accounts.all", "settings.usergroups.all", "settings.transfers.all", "settings.transfertypes.all", "settings.addresstypes.all", "ui-users.editpermsets" ]
},
"proxiesFor" : [ ]
}
Here is the okapi log where the error occurred: 2018-08-01 11:26:41,331 INFO DockerModuleHandle mod-permissions-5.3.0-SNAPSHOT.25 11:26:41 INFO LogUtil org.folio.rest.RestVerticle start invoking getPermsUsersByIdPermissions 2018-08-01 11:26:41,331 INFO DockerModuleHandle mod-permissions-5.3.0-SNAPSHOT.25 11:26:41 INFO LogUtil 10.36.1.143:37756 GET /perms/users/305e8b1c-659a-595a-9718-ebba56792100/permissions expanded=true HTTP_1_1 404 56 1 tid=pr_99_6 Not Found 2018-08-01 11:26:41,331 WARN ProxyService relayToResponse XXX Returning direct response 403 2018-08-01 11:26:41,331 INFO ProxyContext 001166/contributor-types RES 403 16365us mod-authtoken-1.5.1-SNAPSHOT.24 http://10.36.1.143:9135/contributor-types 2018-08-01 11:26:41,331 INFO DockerModuleHandle mod-authtoken-1.5.1-SNAPSHOT.24 Aug 01, 2018 11:26:41 AM mod-auth-authtoken-module 2018-08-01 11:26:41,331 INFO DockerModuleHandle mod-authtoken-1.5.1-SNAPSHOT.24 SEVERE: [](user permissions) nor [](module permissions) do not contain inventory-storage.contributor-types.item.post 2018-08-01 11:26:41,331 INFO DockerModuleHandle mod-authtoken-1.5.1-SNAPSHOT.24 completing future with user permissions=[], expanded permissions=[] Note the following line in particular: 10.36.1.143:37756 GET /perms/users/305e8b1c-659a-595a-9718-ebba56792100/permissions expanded=true HTTP_1_1 404 56 1 tid=pr_99_6 Not Found In the above line, the tenant admin's permissions id is '305e8b1c-659a-595a-9718-ebba56792100'. This is the permissions id for the tenant admin user 'pr_72_18_admin'. However, also note that the 'tid' logged in pr_99_6. This tenant user and the tenant do not match. |
| Comment by John Malconian [ 01/Aug/18 ] |
|
I guess the question is what is causing this mismatch. Something environmental on the Jenkins side that is passing the wrong tenant in a header or is this a bug in okapi or one of the modules. |
| Comment by John Malconian [ 01/Aug/18 ] |
|
attached okapi log file that contains the error for tenant, pr_72_18. |
| Comment by John Malconian [ 02/Aug/18 ] |
|
I'm able to duplicate this problem rather easily outside of Jenkins by creating two tenants and bootstrapping tenant data almost simultaneously. So its not a CI issue. |
| Comment by Adam Dickmeiss [ 02/Aug/18 ] |
|
Excellent. Then we can try this locally.. Please supply the produce/script .. |
| Comment by John Malconian [ 02/Aug/18 ] |
|
Adam Dickmeiss I'll attempt to package something up you can run easily. The data loading is via ansible. |
| Comment by John Malconian [ 02/Aug/18 ] |
|
Adam Dickmeiss I've cobbled together some bash scripts so that you do not have to deal with setting up an Ansible environment. I was able to replicate the issue on the first try with these scripts. Steps to run:
|
| Comment by Jakub Skoczen [ 06/Aug/18 ] |
|
Heikki Levanto or Kurt Nordstrom would it make sense for one of you to look into it while Adam is away? |
| Comment by Heikki Levanto [ 07/Aug/18 ] |
|
I can take a look |
| Comment by Heikki Levanto [ 07/Aug/18 ] |
|
I tried to reproduce this locally. Run into small problems with the maze of small scripts, and assumptions about database setups, so never got to the point where it would load the reference data. Now I need to move on to other things. |
| Comment by Jakub Skoczen [ 08/Aug/18 ] |
|
Adam Dickmeiss can you look into this first thing after you get back? Thanks! |
| Comment by Adam Dickmeiss [ 09/Aug/18 ] |
|
From code inspection, I think the problem is in mod-authtoken. It has a class, ModulePermissionsSource, which is created once (for all tenants) and it has a member (tenant) which will be inconsistent whenever requests is made to handleAuthorize. I'll try to fix and make a PR. |
| Comment by Adam Dickmeiss [ 09/Aug/18 ] |
|
Made a pull request: See
|
| Comment by Adam Dickmeiss [ 10/Aug/18 ] |
|
John Malconian .. When convenient, please check if the issue goes away with mod-authtoken from master. |
| Comment by Jakub Skoczen [ 15/Aug/18 ] |
|
John Malconian what's the latest status here? |
| Comment by John Malconian [ 15/Aug/18 ] |
|
I still need to verify if this is fixed. |