PUT to a secret fails after plugins update

Running cafe test test_putting_w_valid_binary_data_no_utf8 fails with http 500:

Traceback (most recent call last):
  File "/Users/step6927/CloudCafe/cloudroast/cloudroast/cloudkeep/barbican/functional/secrets.py", line 517, in test_putting_w_valid_binary_data_no_utf8
    'Returned unexpected response code')
AssertionError: 500 != 204 : Returned unexpected response code

Server shows:

2014-07-08 21:58:41.416 47555 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-07-08 21:58:41.417 47555 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-07-08 21:58:42.019 47555 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-07-08 21:58:42.021 47555 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 151a2022365643179d6b5c9cbb148925 with project_id : 788c9ea4a057403ba3f334f4de0f9a9f and roles: _member_,admin _build_user_headers /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-07-08 21:58:42.023 47555 DEBUG barbican.api.middleware.context [-] ==== Inserted barbican auth request context: {'user_id': u'151a2022365643179d6b5c9cbb148925', 'user': u'151a2022365643179d6b5c9cbb148925', 'roles': [u'_member_', u'admin'], 'request_id': 'ae40cb08-3076-4548-8947-5c226b3dad34', 'tenant_id': u'788c9ea4a057403ba3f334f4de0f9a9f', 'auth_token': 'MIIFPAYJKoZIhvcNAQcCoIIFLTCCBSkCAQExCTAHBgUrDgMCGjCCBBUGCSqGSIb3DQEHAaCCBAYEggQCeyJhY2Nlc3MiOiB7InRva2VuIjogeyJpc3N1ZWRfYXQiOiAiMjAxNC0wNy0wOVQwMzowNjoxNy41NTI5NzQiLCAiZXhwaXJlcyI6ICIyMDE0LTA3LTEwVDAzOjA2OjE2WiIsICJpZCI6ICJwbGFjZWhvbGRlciIsICJ0ZW5hbnQiOiB7ImRlc2NyaXB0aW9uIjogIkRlZmF1bHQgVGVuYW50IiwgImVuYWJsZWQiOiB0cnVlLCAiaWQiOiAiNzg4YzllYTRhMDU3NDAzYmEzZjMzNGY0ZGUwZjlhOWYiLCAibmFtZSI6ICJkZW1vIn19LCAic2VydmljZUNhdGFsb2ciOiBbeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vbG9jYWxob3N0OjgwMDEiLCAicmVnaW9uIjogInJlZ2lvbk9uZSIsICJwdWJsaWNVUkwiOiAiaHR0cDovL2xvY2FsaG9zdDo4MDAwIiwgImlkIjogImY5ZTg3N2E4MDQ5MzQ0YzViODc1OWVlMWQ1OWM2MDBhIn1dLCAiZW5kcG9pbnRzX2xpbmtzIjogW10sICJ0eXBlIjogInZvbHVtZSIsICJuYW1lIjogInN3aWZ0X3Byb3h5In0sIHsiZW5kcG9pbnRzIjogW3siYWRtaW5VUkwiOiAiaHR0cDovL2lhZC1pbnQtYXBpLmNsb3Vka2VlcC5pbzo5MzEyL3YxIiwgInJlZ2lvbiI6ICJyZWdpb25PbmUiLCAicHVibGljVVJMIjogImh0dHA6Ly9pYWQtaW50LWFwaS5jbG91ZGtlZXAuaW86OTMxMS92MSIsICJpZCI6ICJmZjU5OGQ5NTk5NGU0MTA4YTc0ZWZiNjg3NTY3MmZiNCJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJrZXlzdG9yZSIsICJuYW1lIjogImJhcmJpY2FuIn1dLCAidXNlciI6IHsidXNlcm5hbWUiOiAiYWRtaW5fdXNlciIsICJyb2xlc19saW5rcyI6IFtdLCAiaWQiOiAiMTUxYTIwMjIzNjU2NDMxNzlkNmI1YzljYmIxNDg5MjUiLCAicm9sZXMiOiBbeyJuYW1lIjogIl9tZW1iZXJfIn0sIHsibmFtZSI6ICJhZG1pbiJ9XSwgIm5hbWUiOiAiYWRtaW5fdXNlciJ9LCAibWV0YWRhdGEiOiB7ImlzX2FkbWluIjogMCwgInJvbGVzIjogWyI5ZmUyZmY5ZWU0Mzg0YjE4OTRhOTA4NzhkM2U5MmJhYiIsICJkZjFkODMzNjdjZDk0OGE1YjVkOTM1NjdmMjQ3M2IzMCJdfX19MYH-MIH8AgEBMFwwVzELMAkGA1UEBhMCVVMxDjAMBgNVBAgTBVVuc2V0MQ4wDAYDVQQHEwVVbnNldDEOMAwGA1UEChMFVW5zZXQxGDAWBgNVBAMTD3d3dy5leGFtcGxlLmNvbQIBATAHBgUrDgMCGjANBgkqhkiG9w0BAQEFAASBgNFV-YoPxYKadiRrdyaSgxEmBKNOqRtmPFlgmhQQdt-KDE327pbZ1yl-v5c3mF9RnfOf7aTJtFmUoWa4EQzKLtcohjH56A5Hz3qorwQRszmQoOZGNmTpHbYUh-EQihupUYK7JqU1nx+AYaJHPs-sC01wfohi5IbEZ-3zBHSoD+5J', 'project_id': u'788c9ea4a057403ba3f334f4de0f9a9f', 'service_catalog': [{u'endpoints': [{u'adminURL': u'http://localhost:8001', u'region': u'regionOne', u'id': u'f9e877a8049344c5b8759ee1d59c600a', u'publicURL': u'http://localhost:8000'}], u'endpoints_links': [], u'type': u'volume', u'name': u'swift_proxy'}, {u'endpoints': [{u'adminURL': u'http://iad-int-api.cloudkeep.io:9312/v1', u'region': u'regionOne', u'id': u'ff598d95994e4108a74efb6875672fb4', u'publicURL': u'http://iad-int-api.cloudkeep.io:9311/v1'}], u'endpoints_links': [], u'type': u'keystore', u'name': u'barbican'}], 'tenant': u'788c9ea4a057403ba3f334f4de0f9a9f'} ==== process_request /Users/step6927/barbican/barbican/api/middleware/context.py:87
2014-07-08 21:58:42.026 47555 DEBUG barbican.openstack.common.policy [-] Rule secrets:post will be now enforced enforce /Users/step6927/barbican/barbican/openstack/common/policy.py:288
2014-07-08 21:58:42.027 47555 DEBUG barbican.api.controllers.secrets [-] Start on_post for tenant-ID 788c9ea4a057403ba3f334f4de0f9a9f:... on_post /Users/step6927/barbican/barbican/api/controllers/secrets.py:231
2014-07-08 21:58:42.049 47555 DEBUG barbican.model.repositories [-] Getting session... get_session /Users/step6927/barbican/barbican/model/repositories.py:286
2014-07-08 21:58:42.055 47555 INFO sqlalchemy.engine.base.Engine [-] SELECT tenants.id AS tenants_id, tenants.created_at AS tenants_created_at, tenants.updated_at AS tenants_updated_at, tenants.deleted_at AS tenants_deleted_at, tenants.deleted AS tenants_deleted, tenants.status AS tenants_status, tenants.keystone_id AS tenants_keystone_id
FROM tenants
WHERE tenants.keystone_id = ?
2014-07-08 21:58:42.056 47555 INFO sqlalchemy.engine.base.Engine [-] ('788c9ea4a057403ba3f334f4de0f9a9f',)
2014-07-08 21:58:42.058 47555 DEBUG sqlalchemy.engine.base.Engine [-] Col ('tenants_id', 'tenants_created_at', 'tenants_updated_at', 'tenants_deleted_at', 'tenants_deleted', 'tenants_status', 'tenants_keystone_id') __init__ /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/sqlalchemy/engine/base.py:2788
2014-07-08 21:58:42.058 47555 DEBUG sqlalchemy.engine.base.Engine [-] Row (u'ab33cd29-32eb-43ea-978e-35c268edac79', u'2014-07-07 16:41:48.545908', u'2014-07-07 16:41:48.545917', None, 0, u'ACTIVE', u'788c9ea4a057403ba3f334f4de0f9a9f') process_rows /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/sqlalchemy/engine/base.py:3193
2014-07-08 21:58:42.061 47555 DEBUG barbican.model.repositories [-] Begin create from... create_from /Users/step6927/barbican/barbican/model/repositories.py:326
2014-07-08 21:58:42.062 47555 DEBUG barbican.model.repositories [-] Saving entity... create_from /Users/step6927/barbican/barbican/model/repositories.py:338
2014-07-08 21:58:42.066 47555 INFO sqlalchemy.engine.base.Engine [-] BEGIN (implicit)
2014-07-08 21:58:42.068 47555 INFO sqlalchemy.engine.base.Engine [-] INSERT INTO secrets (id, created_at, updated_at, deleted_at, deleted, status, name, expiration, algorithm, bit_length, mode) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2014-07-08 21:58:42.069 47555 INFO sqlalchemy.engine.base.Engine [-] ('ad98af9e-2f9d-4f46-b682-5026c5da20f8', '2014-07-09 02:58:42.068333', '2014-07-09 02:58:42.068374', None, 0, 'ACTIVE', None, None, None, None, None)
2014-07-08 21:58:42.071 47555 INFO sqlalchemy.engine.base.Engine [-] COMMIT
2014-07-08 21:58:42.073 47555 DEBUG barbican.model.repositories [-] Elapsed repo create secret:0.0124230384827 create_from /Users/step6927/barbican/barbican/model/repositories.py:345
2014-07-08 21:58:42.074 47555 DEBUG barbican.model.repositories [-] Begin create from... create_from /Users/step6927/barbican/barbican/model/repositories.py:326
2014-07-08 21:58:42.075 47555 DEBUG barbican.model.repositories [-] Saving entity... create_from /Users/step6927/barbican/barbican/model/repositories.py:338
2014-07-08 21:58:42.078 47555 INFO sqlalchemy.engine.base.Engine [-] BEGIN (implicit)
2014-07-08 21:58:42.079 47555 INFO sqlalchemy.engine.base.Engine [-] INSERT INTO tenant_secret (id, created_at, updated_at, deleted_at, deleted, status, tenant_id, secret_id, role) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)
2014-07-08 21:58:42.080 47555 INFO sqlalchemy.engine.base.Engine [-] ('43604ba7-f054-4868-a7b7-ae49d759667c', '2014-07-09 02:58:42.079612', '2014-07-09 02:58:42.079651', None, 0, 'ACTIVE', u'ab33cd29-32eb-43ea-978e-35c268edac79', 'ad98af9e-2f9d-4f46-b682-5026c5da20f8', 'admin')
2014-07-08 21:58:42.082 47555 INFO sqlalchemy.engine.base.Engine [-] COMMIT
2014-07-08 21:58:42.085 47555 DEBUG barbican.model.repositories [-] Elapsed repo create secret:0.0108799934387 create_from /Users/step6927/barbican/barbican/model/repositories.py:345
2014-07-08 21:58:42.086 47555 DEBUG barbican.api.controllers.secrets [-] URI to secret is http://localhost:9311/v1/788c9ea4a057403ba3f334f4de0f9a9f/secrets/ad98af9e-2f9d-4f46-b682-5026c5da20f8 on_post /Users/step6927/barbican/barbican/api/controllers/secrets.py:248
2014-07-08 21:58:42.088 47555 WARNING barbican.api.middleware.context [-] Unable to retrieve request id from context
{address space usage: 2642104320 bytes/2519MB} {rss usage: 71655424 bytes/68MB} [pid: 47555|app: 0|req: 4/4] 127.0.0.1 () {32 vars in 2278 bytes} [Tue Jul 8 21:58:41 2014] POST /v1/788c9ea4a057403ba3f334f4de0f9a9f/secrets => generated 120 bytes in 672 msecs (HTTP/1.1 201) 3 headers in 203 bytes (2 switches on core 0)
2014-07-08 21:58:42.093 47555 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-07-08 21:58:42.094 47555 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-07-08 21:58:42.096 47555 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1124
2014-07-08 21:58:42.097 47555 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-07-08 21:58:42.098 47555 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 151a2022365643179d6b5c9cbb148925 with project_id : 788c9ea4a057403ba3f334f4de0f9a9f and roles: _member_,admin _build_user_headers /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-07-08 21:58:42.100 47555 DEBUG barbican.api.middleware.context [-] ==== Inserted barbican auth request context: {'user_id': u'151a2022365643179d6b5c9cbb148925', 'user': u'151a2022365643179d6b5c9cbb148925', 'roles': [u'_member_', u'admin'], 'request_id': '3bd8db63-362f-4a3d-8030-90005fa486f5', 'tenant_id': u'788c9ea4a057403ba3f334f4de0f9a9f', 'auth_token': 'MIIFPAYJKoZIhvcNAQcCoIIFLTCCBSkCAQExCTAHBgUrDgMCGjCCBBUGCSqGSIb3DQEHAaCCBAYEggQCeyJhY2Nlc3MiOiB7InRva2VuIjogeyJpc3N1ZWRfYXQiOiAiMjAxNC0wNy0wOVQwMzowNjoxNy41NTI5NzQiLCAiZXhwaXJlcyI6ICIyMDE0LTA3LTEwVDAzOjA2OjE2WiIsICJpZCI6ICJwbGFjZWhvbGRlciIsICJ0ZW5hbnQiOiB7ImRlc2NyaXB0aW9uIjogIkRlZmF1bHQgVGVuYW50IiwgImVuYWJsZWQiOiB0cnVlLCAiaWQiOiAiNzg4YzllYTRhMDU3NDAzYmEzZjMzNGY0ZGUwZjlhOWYiLCAibmFtZSI6ICJkZW1vIn19LCAic2VydmljZUNhdGFsb2ciOiBbeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vbG9jYWxob3N0OjgwMDEiLCAicmVnaW9uIjogInJlZ2lvbk9uZSIsICJwdWJsaWNVUkwiOiAiaHR0cDovL2xvY2FsaG9zdDo4MDAwIiwgImlkIjogImY5ZTg3N2E4MDQ5MzQ0YzViODc1OWVlMWQ1OWM2MDBhIn1dLCAiZW5kcG9pbnRzX2xpbmtzIjogW10sICJ0eXBlIjogInZvbHVtZSIsICJuYW1lIjogInN3aWZ0X3Byb3h5In0sIHsiZW5kcG9pbnRzIjogW3siYWRtaW5VUkwiOiAiaHR0cDovL2lhZC1pbnQtYXBpLmNsb3Vka2VlcC5pbzo5MzEyL3YxIiwgInJlZ2lvbiI6ICJyZWdpb25PbmUiLCAicHVibGljVVJMIjogImh0dHA6Ly9pYWQtaW50LWFwaS5jbG91ZGtlZXAuaW86OTMxMS92MSIsICJpZCI6ICJmZjU5OGQ5NTk5NGU0MTA4YTc0ZWZiNjg3NTY3MmZiNCJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJrZXlzdG9yZSIsICJuYW1lIjogImJhcmJpY2FuIn1dLCAidXNlciI6IHsidXNlcm5hbWUiOiAiYWRtaW5fdXNlciIsICJyb2xlc19saW5rcyI6IFtdLCAiaWQiOiAiMTUxYTIwMjIzNjU2NDMxNzlkNmI1YzljYmIxNDg5MjUiLCAicm9sZXMiOiBbeyJuYW1lIjogIl9tZW1iZXJfIn0sIHsibmFtZSI6ICJhZG1pbiJ9XSwgIm5hbWUiOiAiYWRtaW5fdXNlciJ9LCAibWV0YWRhdGEiOiB7ImlzX2FkbWluIjogMCwgInJvbGVzIjogWyI5ZmUyZmY5ZWU0Mzg0YjE4OTRhOTA4NzhkM2U5MmJhYiIsICJkZjFkODMzNjdjZDk0OGE1YjVkOTM1NjdmMjQ3M2IzMCJdfX19MYH-MIH8AgEBMFwwVzELMAkGA1UEBhMCVVMxDjAMBgNVBAgTBVVuc2V0MQ4wDAYDVQQHEwVVbnNldDEOMAwGA1UEChMFVW5zZXQxGDAWBgNVBAMTD3d3dy5leGFtcGxlLmNvbQIBATAHBgUrDgMCGjANBgkqhkiG9w0BAQEFAASBgNFV-YoPxYKadiRrdyaSgxEmBKNOqRtmPFlgmhQQdt-KDE327pbZ1yl-v5c3mF9RnfOf7aTJtFmUoWa4EQzKLtcohjH56A5Hz3qorwQRszmQoOZGNmTpHbYUh-EQihupUYK7JqU1nx+AYaJHPs-sC01wfohi5IbEZ-3zBHSoD+5J', 'project_id': u'788c9ea4a057403ba3f334f4de0f9a9f', 'service_catalog': [{u'endpoints_links': [], u'endpoints': [{u'adminURL': u'http://localhost:8001', u'region': u'regionOne', u'id': u'f9e877a8049344c5b8759ee1d59c600a', u'publicURL': u'http://localhost:8000'}], u'type': u'volume', u'name': u'swift_proxy'}, {u'endpoints_links': [], u'endpoints': [{u'adminURL': u'http://iad-int-api.cloudkeep.io:9312/v1', u'region': u'regionOne', u'id': u'ff598d95994e4108a74efb6875672fb4', u'publicURL': u'http://iad-int-api.cloudkeep.io:9311/v1'}], u'type': u'keystore', u'name': u'barbican'}], 'tenant': u'788c9ea4a057403ba3f334f4de0f9a9f'} ==== process_request /Users/step6927/barbican/barbican/api/middleware/context.py:87
2014-07-08 21:58:42.105 47555 DEBUG barbican.api.controllers.secrets [-] === Creating SecretController === __init__ /Users/step6927/barbican/barbican/api/controllers/secrets.py:59
2014-07-08 21:58:42.107 47555 DEBUG barbican.openstack.common.policy [-] Rule secret:put will be now enforced enforce /Users/step6927/barbican/barbican/openstack/common/policy.py:288
2014-07-08 21:58:42.108 47555 DEBUG barbican.model.repositories [-] Getting session... get_session /Users/step6927/barbican/barbican/model/repositories.py:286
2014-07-08 21:58:42.137 47555 INFO sqlalchemy.engine.base.Engine [-] SELECT secrets.id AS secrets_id, secrets.created_at AS secrets_created_at, secrets.updated_at AS secrets_updated_at, secrets.deleted_at AS secrets_deleted_at, secrets.deleted AS secrets_deleted, secrets.status AS secrets_status, secrets.name AS secrets_name, secrets.expiration AS secrets_expiration, secrets.algorithm AS secrets_algorithm, secrets.bit_length AS secrets_bit_length, secrets.mode AS secrets_mode, encrypted_data_1.id AS encrypted_data_1_id, encrypted_data_1.created_at AS encrypted_data_1_created_at, encrypted_data_1.updated_at AS encrypted_data_1_updated_at, encrypted_data_1.deleted_at AS encrypted_data_1_deleted_at, encrypted_data_1.deleted AS encrypted_data_1_deleted, encrypted_data_1.status AS encrypted_data_1_status, encrypted_data_1.secret_id AS encrypted_data_1_secret_id, encrypted_data_1.kek_id AS encrypted_data_1_kek_id, encrypted_data_1.content_type AS encrypted_data_1_content_type, encrypted_data_1.cypher_text AS encrypted_data_1_cypher_text, encrypted_data_1.kek_meta_extended AS encrypted_data_1_kek_meta_extended
FROM secrets JOIN tenant_secret ON secrets.id = tenant_secret.secret_id JOIN tenants ON tenants.id = tenant_secret.tenant_id LEFT OUTER JOIN encrypted_data AS encrypted_data_1 ON secrets.id = encrypted_data_1.secret_id
WHERE secrets.id = ? AND secrets.deleted = ? AND (secrets.expiration IS NULL OR secrets.expiration > ?) AND tenants.keystone_id = ? AND tenants.deleted = ?
2014-07-08 21:58:42.138 47555 INFO sqlalchemy.engine.base.Engine [-] ('ad98af9e-2f9d-4f46-b682-5026c5da20f8', 0, '2014-07-09 02:58:42.109418', '788c9ea4a057403ba3f334f4de0f9a9f', 0)
2014-07-08 21:58:42.145 47555 DEBUG sqlalchemy.engine.base.Engine [-] Col ('secrets_id', 'secrets_created_at', 'secrets_updated_at', 'secrets_deleted_at', 'secrets_deleted', 'secrets_status', 'secrets_name', 'secrets_expiration', 'secrets_algorithm', 'secrets_bit_length', 'secrets_mode', 'encrypted_data_1_id', 'encrypted_data_1_created_at', 'encrypted_data_1_updated_at', 'encrypted_data_1_deleted_at', 'encrypted_data_1_deleted', 'encrypted_data_1_status', 'encrypted_data_1_secret_id', 'encrypted_data_1_kek_id', 'encrypted_data_1_content_type', 'encrypted_data_1_cypher_text', 'encrypted_data_1_kek_meta_extended') __init__ /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/sqlalchemy/engine/base.py:2788
2014-07-08 21:58:42.147 47555 DEBUG sqlalchemy.engine.base.Engine [-] Row (u'ad98af9e-2f9d-4f46-b682-5026c5da20f8', u'2014-07-09 02:58:42.068333', u'2014-07-09 02:58:42.068374', None, 0, u'ACTIVE', None, None, None, None, None, None, None, None, None, None, None, None, None, None, None, None) process_rows /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/sqlalchemy/engine/base.py:3193
2014-07-08 21:58:42.150 47555 DEBUG barbican.model.repositories [-] Getting session... get_session /Users/step6927/barbican/barbican/model/repositories.py:286
2014-07-08 21:58:42.155 47555 INFO sqlalchemy.engine.base.Engine [-] SELECT tenants.id AS tenants_id, tenants.created_at AS tenants_created_at, tenants.updated_at AS tenants_updated_at, tenants.deleted_at AS tenants_deleted_at, tenants.deleted AS tenants_deleted, tenants.status AS tenants_status, tenants.keystone_id AS tenants_keystone_id
FROM tenants
WHERE tenants.keystone_id = ?
2014-07-08 21:58:42.155 47555 INFO sqlalchemy.engine.base.Engine [-] ('788c9ea4a057403ba3f334f4de0f9a9f',)
2014-07-08 21:58:42.157 47555 DEBUG sqlalchemy.engine.base.Engine [-] Col ('tenants_id', 'tenants_created_at', 'tenants_updated_at', 'tenants_deleted_at', 'tenants_deleted', 'tenants_status', 'tenants_keystone_id') __init__ /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/sqlalchemy/engine/base.py:2788
2014-07-08 21:58:42.158 47555 DEBUG sqlalchemy.engine.base.Engine [-] Row (u'ab33cd29-32eb-43ea-978e-35c268edac79', u'2014-07-07 16:41:48.545908', u'2014-07-07 16:41:48.545917', None, 0, u'ACTIVE', u'788c9ea4a057403ba3f334f4de0f9a9f') process_rows /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/sqlalchemy/engine/base.py:3193
2014-07-08 21:58:42.163 47555 INFO sqlalchemy.engine.base.Engine [-] SELECT secret_store_metadata.id AS secret_store_metadata_id, secret_store_metadata.created_at AS secret_store_metadata_created_at, secret_store_metadata.updated_at AS secret_store_metadata_updated_at, secret_store_metadata.deleted_at AS secret_store_metadata_deleted_at, secret_store_metadata.deleted AS secret_store_metadata_deleted, secret_store_metadata.status AS secret_store_metadata_status, secret_store_metadata.secret_id AS secret_store_metadata_secret_id, secret_store_metadata."key" AS secret_store_metadata_key, secret_store_metadata.value AS secret_store_metadata_value
FROM secret_store_metadata
WHERE ? = secret_store_metadata.secret_id
2014-07-08 21:58:42.164 47555 INFO sqlalchemy.engine.base.Engine [-] (u'ad98af9e-2f9d-4f46-b682-5026c5da20f8',)
2014-07-08 21:58:42.167 47555 DEBUG sqlalchemy.engine.base.Engine [-] Col ('secret_store_metadata_id', 'secret_store_metadata_created_at', 'secret_store_metadata_updated_at', 'secret_store_metadata_deleted_at', 'secret_store_metadata_deleted', 'secret_store_metadata_status', 'secret_store_metadata_secret_id', 'secret_store_metadata_key', 'secret_store_metadata_value') __init__ /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/sqlalchemy/engine/base.py:2788
2014-07-08 21:58:42.168 47555 DEBUG stevedore.extension [-] found extension EntryPoint.parse('store_crypto = barbican.plugin.store_crypto:StoreCryptoAdapterPlugin') _load_plugins /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/stevedore/extension.py:156
2014-07-08 21:58:42.169 47555 DEBUG stevedore.extension [-] found extension EntryPoint.parse('dogtag_crypto = barbican.plugin.dogtag:DogtagPlugin') _load_plugins /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/stevedore/extension.py:156
2014-07-08 21:58:42.170 47555 ERROR barbican.api.controllers [-] Secret update failure seen - please contact site administrator.
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers Traceback (most recent call last):
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers File "/Users/step6927/barbican/barbican/api/controllers/__init__.py", line 85, in handler
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers return fn(inst, *args, **kwargs)
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers File "/Users/step6927/barbican/barbican/api/controllers/__init__.py", line 71, in enforcer
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers return fn(inst, *args, **kwargs)
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers File "/Users/step6927/barbican/barbican/api/controllers/__init__.py", line 117, in content_types_enforcer
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers return fn(inst, *args, **kwargs)
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers File "/Users/step6927/barbican/barbican/api/controllers/secrets.py", line 135, in on_put
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers secret_model, tenant_model, self.repos)
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers File "/Users/step6927/barbican/barbican/plugin/resources.py", line 57, in store_secret
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers key_spec = secret_store.KeySpec(alg=spec.get('algorithm'),
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers AttributeError: 'function' object has no attribute 'get'
2014-07-08 21:58:42.170 47555 TRACE barbican.api.controllers
2014-07-08 21:58:42.174 47555 WARNING barbican.api.middleware.context [-] Unable to retrieve request id from context
{address space usage: 2642104320 bytes/2519MB} {rss usage: 71741440 bytes/68MB} [pid: 47555|app: 0|req: 5/5] 127.0.0.1 () {34 vars in 2390 bytes} [Tue Jul 8 21:58:42 2014] PUT /v1/788c9ea4a057403ba3f334f4de0f9a9f/secrets/ad98af9e-2f9d-4f46-b682-5026c5da20f8 => generated 129 bytes in 81 msecs (HTTP/1.1 500) 2 headers in 106 bytes (2 switches on core 0)
2014-07-08 21:58:42.179 47555 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-07-08 21:58:42.180 47555 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-07-08 21:58:42.182 47555 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1124
2014-07-08 21:58:42.185 47555 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-07-08 21:58:42.187 47555 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 151a2022365643179d6b5c9cbb148925 with project_id : 788c9ea4a057403ba3f334f4de0f9a9f and roles: _member_,admin _build_user_headers /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-07-08 21:58:42.190 47555 DEBUG barbican.api.middleware.context [-] ==== Inserted barbican auth request context: {'user_id': u'151a2022365643179d6b5c9cbb148925', 'user': u'151a2022365643179d6b5c9cbb148925', 'roles': [u'_member_', u'admin'], 'request_id': 'a94a3442-6a78-40ac-9fea-728a9bd960f1', 'tenant_id': u'788c9ea4a057403ba3f334f4de0f9a9f', 'auth_token': 'MIIFPAYJKoZIhvcNAQcCoIIFLTCCBSkCAQExCTAHBgUrDgMCGjCCBBUGCSqGSIb3DQEHAaCCBAYEggQCeyJhY2Nlc3MiOiB7InRva2VuIjogeyJpc3N1ZWRfYXQiOiAiMjAxNC0wNy0wOVQwMzowNjoxNy41NTI5NzQiLCAiZXhwaXJlcyI6ICIyMDE0LTA3LTEwVDAzOjA2OjE2WiIsICJpZCI6ICJwbGFjZWhvbGRlciIsICJ0ZW5hbnQiOiB7ImRlc2NyaXB0aW9uIjogIkRlZmF1bHQgVGVuYW50IiwgImVuYWJsZWQiOiB0cnVlLCAiaWQiOiAiNzg4YzllYTRhMDU3NDAzYmEzZjMzNGY0ZGUwZjlhOWYiLCAibmFtZSI6ICJkZW1vIn19LCAic2VydmljZUNhdGFsb2ciOiBbeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vbG9jYWxob3N0OjgwMDEiLCAicmVnaW9uIjogInJlZ2lvbk9uZSIsICJwdWJsaWNVUkwiOiAiaHR0cDovL2xvY2FsaG9zdDo4MDAwIiwgImlkIjogImY5ZTg3N2E4MDQ5MzQ0YzViODc1OWVlMWQ1OWM2MDBhIn1dLCAiZW5kcG9pbnRzX2xpbmtzIjogW10sICJ0eXBlIjogInZvbHVtZSIsICJuYW1lIjogInN3aWZ0X3Byb3h5In0sIHsiZW5kcG9pbnRzIjogW3siYWRtaW5VUkwiOiAiaHR0cDovL2lhZC1pbnQtYXBpLmNsb3Vka2VlcC5pbzo5MzEyL3YxIiwgInJlZ2lvbiI6ICJyZWdpb25PbmUiLCAicHVibGljVVJMIjogImh0dHA6Ly9pYWQtaW50LWFwaS5jbG91ZGtlZXAuaW86OTMxMS92MSIsICJpZCI6ICJmZjU5OGQ5NTk5NGU0MTA4YTc0ZWZiNjg3NTY3MmZiNCJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJrZXlzdG9yZSIsICJuYW1lIjogImJhcmJpY2FuIn1dLCAidXNlciI6IHsidXNlcm5hbWUiOiAiYWRtaW5fdXNlciIsICJyb2xlc19saW5rcyI6IFtdLCAiaWQiOiAiMTUxYTIwMjIzNjU2NDMxNzlkNmI1YzljYmIxNDg5MjUiLCAicm9sZXMiOiBbeyJuYW1lIjogIl9tZW1iZXJfIn0sIHsibmFtZSI6ICJhZG1pbiJ9XSwgIm5hbWUiOiAiYWRtaW5fdXNlciJ9LCAibWV0YWRhdGEiOiB7ImlzX2FkbWluIjogMCwgInJvbGVzIjogWyI5ZmUyZmY5ZWU0Mzg0YjE4OTRhOTA4NzhkM2U5MmJhYiIsICJkZjFkODMzNjdjZDk0OGE1YjVkOTM1NjdmMjQ3M2IzMCJdfX19MYH-MIH8AgEBMFwwVzELMAkGA1UEBhMCVVMxDjAMBgNVBAgTBVVuc2V0MQ4wDAYDVQQHEwVVbnNldDEOMAwGA1UEChMFVW5zZXQxGDAWBgNVBAMTD3d3dy5leGFtcGxlLmNvbQIBATAHBgUrDgMCGjANBgkqhkiG9w0BAQEFAASBgNFV-YoPxYKadiRrdyaSgxEmBKNOqRtmPFlgmhQQdt-KDE327pbZ1yl-v5c3mF9RnfOf7aTJtFmUoWa4EQzKLtcohjH56A5Hz3qorwQRszmQoOZGNmTpHbYUh-EQihupUYK7JqU1nx+AYaJHPs-sC01wfohi5IbEZ-3zBHSoD+5J', 'project_id': u'788c9ea4a057403ba3f334f4de0f9a9f', 'service_catalog': [{u'endpoints': [{u'adminURL': u'http://localhost:8001', u'region': u'regionOne', u'id': u'f9e877a8049344c5b8759ee1d59c600a', u'publicURL': u'http://localhost:8000'}], u'endpoints_links': [], u'type': u'volume', u'name': u'swift_proxy'}, {u'endpoints': [{u'adminURL': u'http://iad-int-api.cloudkeep.io:9312/v1', u'region': u'regionOne', u'id': u'ff598d95994e4108a74efb6875672fb4', u'publicURL': u'http://iad-int-api.cloudkeep.io:9311/v1'}], u'endpoints_links': [], u'type': u'keystore', u'name': u'barbican'}], 'tenant': u'788c9ea4a057403ba3f334f4de0f9a9f'} ==== process_request /Users/step6927/barbican/barbican/api/middleware/context.py:87
2014-07-08 21:58:42.193 47555 DEBUG barbican.api.controllers.secrets [-] === Creating SecretController === __init__ /Users/step6927/barbican/barbican/api/controllers/secrets.py:59
2014-07-08 21:58:42.194 47555 DEBUG barbican.openstack.common.policy [-] Rule secret:delete will be now enforced enforce /Users/step6927/barbican/barbican/openstack/common/policy.py:288
2014-07-08 21:58:42.195 47555 DEBUG barbican.model.repositories [-] Getting session... get_session /Users/step6927/barbican/barbican/model/repositories.py:286
2014-07-08 21:58:42.220 47555 INFO sqlalchemy.engine.base.Engine [-] SELECT secrets.id AS secrets_id, secrets.created_at AS secrets_created_at, secrets.updated_at AS secrets_updated_at, secrets.deleted_at AS secrets_deleted_at, secrets.deleted AS secrets_deleted, secrets.status AS secrets_status, secrets.name AS secrets_name, secrets.expiration AS secrets_expiration, secrets.algorithm AS secrets_algorithm, secrets.bit_length AS secrets_bit_length, secrets.mode AS secrets_mode, encrypted_data_1.id AS encrypted_data_1_id, encrypted_data_1.created_at AS encrypted_data_1_created_at, encrypted_data_1.updated_at AS encrypted_data_1_updated_at, encrypted_data_1.deleted_at AS encrypted_data_1_deleted_at, encrypted_data_1.deleted AS encrypted_data_1_deleted, encrypted_data_1.status AS encrypted_data_1_status, encrypted_data_1.secret_id AS encrypted_data_1_secret_id, encrypted_data_1.kek_id AS encrypted_data_1_kek_id, encrypted_data_1.content_type AS encrypted_data_1_content_type, encrypted_data_1.cypher_text AS encrypted_data_1_cypher_text, encrypted_data_1.kek_meta_extended AS encrypted_data_1_kek_meta_extended
FROM secrets JOIN tenant_secret ON secrets.id = tenant_secret.secret_id JOIN tenants ON tenants.id = tenant_secret.tenant_id LEFT OUTER JOIN encrypted_data AS encrypted_data_1 ON secrets.id = encrypted_data_1.secret_id
WHERE secrets.id = ? AND secrets.deleted = ? AND (secrets.expiration IS NULL OR secrets.expiration > ?) AND tenants.keystone_id = ? AND tenants.deleted = ?
2014-07-08 21:58:42.220 47555 INFO sqlalchemy.engine.base.Engine [-] ('ad98af9e-2f9d-4f46-b682-5026c5da20f8', 0, '2014-07-09 02:58:42.196149', '788c9ea4a057403ba3f334f4de0f9a9f', 0)
2014-07-08 21:58:42.227 47555 DEBUG sqlalchemy.engine.base.Engine [-] Col ('secrets_id', 'secrets_created_at', 'secrets_updated_at', 'secrets_deleted_at', 'secrets_deleted', 'secrets_status', 'secrets_name', 'secrets_expiration', 'secrets_algorithm', 'secrets_bit_length', 'secrets_mode', 'encrypted_data_1_id', 'encrypted_data_1_created_at', 'encrypted_data_1_updated_at', 'encrypted_data_1_deleted_at', 'encrypted_data_1_deleted', 'encrypted_data_1_status', 'encrypted_data_1_secret_id', 'encrypted_data_1_kek_id', 'encrypted_data_1_content_type', 'encrypted_data_1_cypher_text', 'encrypted_data_1_kek_meta_extended') __init__ /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/sqlalchemy/engine/base.py:2788
2014-07-08 21:58:42.228 47555 DEBUG sqlalchemy.engine.base.Engine [-] Row (u'ad98af9e-2f9d-4f46-b682-5026c5da20f8', u'2014-07-09 02:58:42.068333', u'2014-07-09 02:58:42.068374', None, 0, u'ACTIVE', None, None, None, None, None, None, None, None, None, None, None, None, None, None, None, None) process_rows /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/sqlalchemy/engine/base.py:3193
2014-07-08 21:58:42.235 47555 INFO sqlalchemy.engine.base.Engine [-] SELECT secret_store_metadata.id AS secret_store_metadata_id, secret_store_metadata.created_at AS secret_store_metadata_created_at, secret_store_metadata.updated_at AS secret_store_metadata_updated_at, secret_store_metadata.deleted_at AS secret_store_metadata_deleted_at, secret_store_metadata.deleted AS secret_store_metadata_deleted, secret_store_metadata.status AS secret_store_metadata_status, secret_store_metadata.secret_id AS secret_store_metadata_secret_id, secret_store_metadata."key" AS secret_store_metadata_key, secret_store_metadata.value AS secret_store_metadata_value
FROM secret_store_metadata
WHERE ? = secret_store_metadata.secret_id
2014-07-08 21:58:42.236 47555 INFO sqlalchemy.engine.base.Engine [-] (u'ad98af9e-2f9d-4f46-b682-5026c5da20f8',)
2014-07-08 21:58:42.238 47555 DEBUG sqlalchemy.engine.base.Engine [-] Col ('secret_store_metadata_id', 'secret_store_metadata_created_at', 'secret_store_metadata_updated_at', 'secret_store_metadata_deleted_at', 'secret_store_metadata_deleted', 'secret_store_metadata_status', 'secret_store_metadata_secret_id', 'secret_store_metadata_key', 'secret_store_metadata_value') __init__ /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/sqlalchemy/engine/base.py:2788
2014-07-08 21:58:42.240 47555 DEBUG stevedore.extension [-] found extension EntryPoint.parse('store_crypto = barbican.plugin.store_crypto:StoreCryptoAdapterPlugin') _load_plugins /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/stevedore/extension.py:156
2014-07-08 21:58:42.240 47555 DEBUG stevedore.extension [-] found extension EntryPoint.parse('dogtag_crypto = barbican.plugin.dogtag:DogtagPlugin') _load_plugins /Users/step6927/.pyenv/versions/newbarbican27/lib/python2.7/site-packages/stevedore/extension.py:156
2014-07-08 21:58:42.241 47555 ERROR barbican.api.controllers [-] Secret deletion failure seen - please contact site administrator.
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers Traceback (most recent call last):
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers File "/Users/step6927/barbican/barbican/api/controllers/__init__.py", line 85, in handler
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers return fn(inst, *args, **kwargs)
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers File "/Users/step6927/barbican/barbican/api/controllers/__init__.py", line 71, in enforcer
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers return fn(inst, *args, **kwargs)
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers File "/Users/step6927/barbican/barbican/api/controllers/secrets.py", line 148, in on_delete
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers plugin.delete_secret(secret_model, keystone_id, self.repos)
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers File "/Users/step6927/barbican/barbican/plugin/resources.py", line 141, in delete_secret
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers .get_plugin_retrieve_delete(secret_metadata.get('plugin_name'))
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers File "/Users/step6927/barbican/barbican/plugin/interface/secret_store.py", line 381, in get_plugin_retrieve_delete
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers raise SecretStoreSupportedPluginNotFound()
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers SecretStoreSupportedPluginNotFound: Secret store plugin not found for requested operation.
2014-07-08 21:58:42.241 47555 TRACE barbican.api.controllers