Skip to content

Instantly share code, notes, and snippets.

@aristotelesneto
Last active August 29, 2015 14:06
Show Gist options
  • Save aristotelesneto/098c470187008e93f915 to your computer and use it in GitHub Desktop.
Save aristotelesneto/098c470187008e93f915 to your computer and use it in GitHub Desktop.
401-unauthorized
I, [2014-09-22T21:05:39.504253 #1626] INFO -- : Started PUT "/v2/service_instances/67a1702e-131a-434f-8aea-64e686ca4113" for 172.31.201.102 at 2014-09-22 21:05:39 +0000
I, [2014-09-22T21:05:39.528650 #1626] INFO -- : Processing by V2::ServiceInstancesController#update as JSON
I, [2014-09-22T21:05:39.529751 #1626] INFO -- : Parameters: {"service_id"=>"47e6ded8-9580-4024-bc70-2edb38cc3f10", "plan_id"=>"f80685a0-0c58-4640-9c2f-39b7f7759552", "organization_guid"=>"9f47ceac-4d1f-41c7-926f-1c6244967f48", "space_guid"=>"c02bd137-e3d1-4efe-9342-e90c2d8ca9b6", "id"=>"67a1702e-131a-434f-8aea-64e686ca4113"}
I, [2014-09-22T21:05:39.532694 #1626] INFO -- : Request: {"headers":{"REMOTE_ADDR":"172.31.201.102","REQUEST_METHOD":"PUT","REQUEST_PATH":"/v2/service_instances/67a1702e-131a-434f-8aea-64e686ca4113","PATH_INFO":"/v2/service_instances/67a1702e-131a-434f-8aea-64e686ca4113","REQUEST_URI":"/v2/service_instances/67a1702e-131a-434f-8aea-64e686ca4113","SERVER_PROTOCOL":"HTTP/1.1","HTTP_VERSION":"HTTP/1.1","HTTP_ACCEPT":"application/json","HTTP_USER_AGENT":"Ruby","HTTP_AUTHORIZATION":"[PRIVATE DATA HIDDEN]","HTTP_X_VCAP_REQUEST_ID":"560fcd9b-4106-48c4-412e-8c3e0abaa21d::ce2ff612-dd5f-471d-aa29-cf8bef579658","HTTP_X_BROKER_API_VERSION":"2.3","CONTENT_TYPE":"application/json","HTTP_HOST":"mariadb-broker.10.0.0.1.xip.io","CONTENT_LENGTH":"213","SERVER_NAME":"mariadb-broker.10.0.0.1.xip.io","SERVER_PORT":"80","QUERY_STRING":"","SCRIPT_NAME":"","SERVER_SOFTWARE":"Unicorn 4.6.3"},"body":""}
D, [2014-09-22T21:05:39.542881 #1626] DEBUG -- : (1.4ms) SELECT COUNT(*) FROM `service_instances`
D, [2014-09-22T21:05:39.546201 #1626] DEBUG -- : (1.9ms) SELECT COUNT(DISTINCT USER) FROM mysql.user
D, [2014-09-22T21:05:39.554153 #1626] DEBUG -- : (1.0ms) SELECT SUM(`service_instances`.`max_storage_mb`) AS sum_id FROM `service_instances`
D, [2014-09-22T21:05:39.570320 #1626] DEBUG -- : (14.6ms) CREATE DATABASE IF NOT EXISTS `cf_67a1702e_131a_434f_8aea_64e686ca4113`
D, [2014-09-22T21:05:39.574188 #1626] DEBUG -- : (0.7ms) BEGIN
D, [2014-09-22T21:05:39.581323 #1626] DEBUG -- : SQL (1.3ms) INSERT INTO `service_instances` (`db_name`, `guid`, `max_storage_mb`, `plan_guid`) VALUES ('cf_67a1702e_131a_434f_8aea_64e686ca4113', '67a1702e-131a-434f-8aea-64e686ca4113', 500, 'f80685a0-0c58-4640-9c2f-39b7f7759552')
D, [2014-09-22T21:05:39.585445 #1626] DEBUG -- : (2.1ms) COMMIT
I, [2014-09-22T21:05:39.587426 #1626] INFO -- : Response: {"headers":{"X-Frame-Options":"SAMEORIGIN","X-XSS-Protection":"1; mode=block","X-Content-Type-Options":"nosniff","X-UA-Compatible":"chrome=1"},"body":"{\"dashboard_url\":\"https://mariadb.10.0.0.1.xip.io/manage/instances/67a1702e-131a-434f-8aea-64e686ca4113\"}"}
I, [2014-09-22T21:05:39.588295 #1626] INFO -- : Completed 201 Created in 58ms (Views: 0.3ms | ActiveRecord: 23.0ms)
172.31.201.102 - - [22/Sep/2014 21:05:39] "PUT /v2/service_instances/67a1702e-131a-434f-8aea-64e686ca4113 HTTP/1.1" 201 - 0.0941
I, [2014-09-22T21:06:00.489404 #1623] INFO -- : Started GET "/manage/instances/67a1702e-131a-434f-8aea-64e686ca4113" for 172.31.201.11 at 2014-09-22 21:06:00 +0000
I, [2014-09-22T21:06:00.507860 #1623] INFO -- : Processing by Manage::InstancesController#show as HTML
I, [2014-09-22T21:06:00.508882 #1623] INFO -- : Parameters: {"id"=>"67a1702e-131a-434f-8aea-64e686ca4113"}
I, [2014-09-22T21:06:00.511274 #1623] INFO -- : Redirected to https://mariadb.10.0.0.1.xip.io/manage/auth/cloudfoundry
I, [2014-09-22T21:06:00.512118 #1623] INFO -- : Filter chain halted as :require_login rendered or redirected
I, [2014-09-22T21:06:00.513206 #1623] INFO -- : Completed 302 Found in 3ms (ActiveRecord: 0.0ms)
172.31.128.6, 172.31.255.102 - - [22/Sep/2014 21:06:00] "GET /manage/instances/67a1702e-131a-434f-8aea-64e686ca4113 HTTP/1.1" 302 - 0.0385
I, [2014-09-22T21:06:00.560540 #1617] INFO -- : Started GET "/manage/auth/cloudfoundry" for 172.31.201.11 at 2014-09-22 21:06:00 +0000
I, [2014-09-22T21:06:00.572913 #1617] INFO -- omniauth: (cloudfoundry) Request phase initiated.
I, [2014-09-22T21:06:00.575444 #1617] INFO -- omniauth: (cloudfoundry) Client: dashboard-sso-wd-mariadb auth_server: https://login.10.0.0.1.xip.io token_server: https://uaa.10.0.0.1.xip.io
I, [2014-09-22T21:06:00.579406 #1617] INFO -- omniauth: (cloudfoundry) Redirect URI https://login.10.0.0.1.xip.io/oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code+id_token&redirect_uri=https%3A%2F%2Fmariadb.10.0.0.1.xip.io%2Fmanage%2Fauth%2Fcloudfoundry%2Fcallback&state=e8b03e7a313c191bf11c3e77f72a4bd6&scope=cloud_controller_service_permissions.read+openid&nonce=e8b03e7a313c191bf11c3e77f72a4bd6
172.31.128.6, 172.31.255.102 - - [22/Sep/2014 21:06:00] "GET /manage/auth/cloudfoundry HTTP/1.1" 302 366 0.0338
I, [2014-09-22T21:06:03.965409 #1620] INFO -- : Started GET "/manage/auth/cloudfoundry/callback?code=aPoJbr&state=e8b03e7a313c191bf11c3e77f72a4bd6" for 172.31.201.11 at 2014-09-22 21:06:03 +0000
I, [2014-09-22T21:06:03.977212 #1620] INFO -- omniauth: (cloudfoundry) Callback phase initiated.
I, [2014-09-22T21:06:03.979728 #1620] INFO -- omniauth: (cloudfoundry) In callback phase code=aPoJbr&state=e8b03e7a313c191bf11c3e77f72a4bd6
I, [2014-09-22T21:06:03.980509 #1620] INFO -- omniauth: (cloudfoundry) Fetching access token
I, [2014-09-22T21:06:03.981393 #1620] INFO -- omniauth: (cloudfoundry) Client: dashboard-sso-wd-mariadb auth_server: https://login.10.0.0.1.xip.io token_server: https://uaa.10.0.0.1.xip.io
D, [2014-09-22T21:06:03.983994 #1620] DEBUG -- omniauth: --->
request: post https://uaa.10.0.0.1.xip.io/oauth/token
headers: {"content-type"=>"application/x-www-form-urlencoded;charset=utf-8", "accept"=>"application/json;charset=utf-8", "authorization"=>"Basic ZGFzaGJvYXJkLXNzby13ZC1tYXJpYWRiOlIyV05UeTNvQlZqSmh6MHFMQ1VJ"}
body: grant_type=authorization_code&code=aPoJbr&redir...
D, [2014-09-22T21:06:04.144070 #1620] DEBUG -- omniauth: <---
response: 200
headers: {"cache-control"=>"no-store", "content-type"=>"application/json;charset=utf-8", "pragma"=>"no-cache", "x-cf-requestid"=>"941cc9b6-4d99-46fd-7c1d-8cfc77abba50", "x-proxy-router"=>"router0", "content-length"=>"2152", "accept-ranges"=>"bytes", "date"=>"Mon, 22 Sep 2014 21:06:04 GMT", "x-varnish"=>"1785568035", "age"=>"0", "via"=>"1.1 varnish", "connection"=>"close", "x-cache"=>"MISS", "x-proxy-cache"=>"lb-cache1", "x-proxy-lb-ssl"=>"lb-cache1"}
body: {"access_token":"eyJhbGciOiJSUzI1NiJ9.eyJqdGkiO...
Class#decode is deprecated with these parameters. Please use options hash.
I, [2014-09-22T21:06:04.147760 #1620] INFO -- omniauth: (cloudfoundry) Got access token #<OmniAuth::Strategies::CFAccessToken:0x007faf58a263e0 @info={"access_token"=>"eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiI5OGU4YWZjNy02ZDE4LTRmMWMtODAyNi03MzM5OTIyYTYxYWUiLCJzdWIiOiIxM2NmZTVhMi02NWRmLTQ2ZmItYjY0ZC1hZWU2MzZlYWQ2MmUiLCJzY29wZSI6WyJjbG91ZF9jb250cm9sbGVyX3NlcnZpY2VfcGVybWlzc2lvbnMucmVhZCIsIm9wZW5pZCJdLCJjbGllbnRfaWQiOiJkYXNoYm9hcmQtc3NvLXdkLW1hcmlhZGIiLCJjaWQiOiJkYXNoYm9hcmQtc3NvLXdkLW1hcmlhZGIiLCJncmFudF90eXBlIjoiYXV0aG9yaXphdGlvbl9jb2RlIiwidXNlcl9pZCI6IjEzY2ZlNWEyLTY1ZGYtNDZmYi1iNjRkLWFlZTYzNmVhZDYyZSIsInVzZXJfbmFtZSI6ImFkbWluIiwiZW1haWwiOiJhZG1pbiIsImlhdCI6MTQxMTQxOTk2NCwiZXhwIjoxNDExNDYzMTY0LCJpc3MiOiJodHRwczovL3VhYS5wYWFzLmxhYi53ZWJob3N0LmNvLm56L29hdXRoL3Rva2VuIiwiYXVkIjpbImNsb3VkX2NvbnRyb2xsZXJfc2VydmljZV9wZXJtaXNzaW9ucyIsIm9wZW5pZCJdfQ.LrTGtBwz9VwMikbSEbMG3pO_80xMta9fR3woAf3hTl5GlnT-BZng97aGGcXfiWx0RHXSaw_Lg_tpGTXWVoJD5jlaKNjM36K1Tg4v5W2S293KvEjEuhQvRYp-lHJuBwVqEslKKY2jSVXihle9ajpe06Cm2N0kJcde6J0SgCHbWwDryKVLmRwLx8O81YIR1m5NCFEl7l_w0e2PNsogFZhaHUHkUPNCmtgfYaoGN9oORDLQN9FO4QiFFvcarIdfE0HgCiMOqGRTwlntsDmg6KGu8mG8eWwun8Gs7B4Vm2gTYQJcOmTO38-CMBlDV0REBXbjYFHCoLZdl_5dcRcHI7xsNg", "token_type"=>"bearer", "refresh_token"=>"eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiJjZWM2NjhmYi0xYmFlLTRhMmYtOGQ0Yi03NGYwMGU1ZTAwOTEiLCJzdWIiOiIxM2NmZTVhMi02NWRmLTQ2ZmItYjY0ZC1hZWU2MzZlYWQ2MmUiLCJzY29wZSI6WyJjbG91ZF9jb250cm9sbGVyX3NlcnZpY2VfcGVybWlzc2lvbnMucmVhZCIsIm9wZW5pZCJdLCJpYXQiOjE0MTE0MTk5NjQsImV4cCI6MTQxNDAxMTk2NCwiY2lkIjoiZGFzaGJvYXJkLXNzby13ZC1tYXJpYWRiIiwiaXNzIjoiaHR0cHM6Ly91YWEucGFhcy5sYWIud2ViaG9zdC5jby5uei9vYXV0aC90b2tlbiIsImdyYW50X3R5cGUiOiJhdXRob3JpemF0aW9uX2NvZGUiLCJ1c2VyX25hbWUiOiJhZG1pbiIsInVzZXJfaWQiOiIxM2NmZTVhMi02NWRmLTQ2ZmItYjY0ZC1hZWU2MzZlYWQ2MmUiLCJhdWQiOlsiY2xvdWRfY29udHJvbGxlcl9zZXJ2aWNlX3Blcm1pc3Npb25zLnJlYWQiLCJvcGVuaWQiXX0.UynsP9W57RhcnqfwvtK-2-lyHmNUABr2gsgENwun-NTB-Zla64bu9IW5xAYfCMTdd-OdN8sYcUGUDqI2OKDxE_NvtxQQejvA2H4aqEilbTXWvXl64-a3xPf2NIdOBi45DGSJcLVStU6tgA4QL5jKzJ-9F_jbvo0sWmwK9v9GNMkR-udJ1zxtklBHWVJLrXjgttiVzfDa2wy97fp2SZt8oKUSyouNHta0nlIei98FI-Z0p85egtp_AHBgWVPI5OodQ_2seISAFmc9pcA0_Bdf5rnBAou_kT9DDn3N5q1-oC_JznEpZUC6mZl65IkJKOPtBV-Cu0iT_HxZKHDbk5B5og", "expires_in"=>43199, "scope"=>"cloud_controller_service_permissions.read openid", "jti"=>"98e8afc7-6d18-4f1c-8026-7339922a61ae"}, @auth_header="bearer eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiI5OGU4YWZjNy02ZDE4LTRmMWMtODAyNi03MzM5OTIyYTYxYWUiLCJzdWIiOiIxM2NmZTVhMi02NWRmLTQ2ZmItYjY0ZC1hZWU2MzZlYWQ2MmUiLCJzY29wZSI6WyJjbG91ZF9jb250cm9sbGVyX3NlcnZpY2VfcGVybWlzc2lvbnMucmVhZCIsIm9wZW5pZCJdLCJjbGllbnRfaWQiOiJkYXNoYm9hcmQtc3NvLXdkLW1hcmlhZGIiLCJjaWQiOiJkYXNoYm9hcmQtc3NvLXdkLW1hcmlhZGIiLCJncmFudF90eXBlIjoiYXV0aG9yaXphdGlvbl9jb2RlIiwidXNlcl9pZCI6IjEzY2ZlNWEyLTY1ZGYtNDZmYi1iNjRkLWFlZTYzNmVhZDYyZSIsInVzZXJfbmFtZSI6ImFkbWluIiwiZW1haWwiOiJhZG1pbiIsImlhdCI6MTQxMTQxOTk2NCwiZXhwIjoxNDExNDYzMTY0LCJpc3MiOiJodHRwczovL3VhYS5wYWFzLmxhYi53ZWJob3N0LmNvLm56L29hdXRoL3Rva2VuIiwiYXVkIjpbImNsb3VkX2NvbnRyb2xsZXJfc2VydmljZV9wZXJtaXNzaW9ucyIsIm9wZW5pZCJdfQ.LrTGtBwz9VwMikbSEbMG3pO_80xMta9fR3woAf3hTl5GlnT-BZng97aGGcXfiWx0RHXSaw_Lg_tpGTXWVoJD5jlaKNjM36K1Tg4v5W2S293KvEjEuhQvRYp-lHJuBwVqEslKKY2jSVXihle9ajpe06Cm2N0kJcde6J0SgCHbWwDryKVLmRwLx8O81YIR1m5NCFEl7l_w0e2PNsogFZhaHUHkUPNCmtgfYaoGN9oORDLQN9FO4QiFFvcarIdfE0HgCiMOqGRTwlntsDmg6KGu8mG8eWwun8Gs7B4Vm2gTYQJcOmTO38-CMBlDV0REBXbjYFHCoLZdl_5dcRcHI7xsNg">
I, [2014-09-22T21:06:04.186620 #1620] INFO -- : Processing by Manage::AuthController#create as HTML
I, [2014-09-22T21:06:04.187600 #1620] INFO -- : Parameters: {"code"=>"aPoJbr", "state"=>"e8b03e7a313c191bf11c3e77f72a4bd6"}
I, [2014-09-22T21:06:04.190548 #1620] INFO -- : Redirected to https://mariadb.10.0.0.1.xip.io/manage/instances/67a1702e-131a-434f-8aea-64e686ca4113
I, [2014-09-22T21:06:04.191843 #1620] INFO -- : Completed 302 Found in 3ms (ActiveRecord: 0.0ms)
172.31.128.6, 172.31.255.102 - - [22/Sep/2014 21:06:04] "GET /manage/auth/cloudfoundry/callback?code=aPoJbr&state=e8b03e7a313c191bf11c3e77f72a4bd6 HTTP/1.1" 302 - 0.2378
I, [2014-09-22T21:06:04.234998 #1617] INFO -- : Started GET "/manage/instances/67a1702e-131a-434f-8aea-64e686ca4113" for 172.31.201.11 at 2014-09-22 21:06:04 +0000
I, [2014-09-22T21:06:04.243375 #1617] INFO -- : Processing by Manage::InstancesController#show as HTML
I, [2014-09-22T21:06:04.244349 #1617] INFO -- : Parameters: {"id"=>"67a1702e-131a-434f-8aea-64e686ca4113"}
I, [2014-09-22T21:06:04.284632 #1617] INFO -- : Rendered errors/not_authorized.html.erb within layouts/application (0.2ms)
I, [2014-09-22T21:06:04.287568 #1617] INFO -- : Filter chain halted as :ensure_can_manage_instance rendered or redirected
I, [2014-09-22T21:06:04.288722 #1617] INFO -- : Completed 200 OK in 43ms (Views: 5.2ms | ActiveRecord: 0.0ms)
172.31.128.6, 172.31.255.102 - - [22/Sep/2014 21:06:04] "GET /manage/instances/67a1702e-131a-434f-8aea-64e686ca4113 HTTP/1.1" 200 - 0.0588
172.31.128.6, 172.31.255.102 - - [22/Sep/2014 21:06:04] "GET %2Fassets%2Fapplication-260f9c46544a78d15942d0b038b08c8f.css HTTP/1.1" 200 151711 0.0112
172.31.128.6, 172.31.255.101 - - [22/Sep/2014 21:06:04] "GET %2Fassets%2Ficon-PivotalMySQLDev-f38400693e804d727e5dad2126db40a8.png HTTP/1.1" 200 2038 0.0034
172.31.128.6, 172.31.255.101 - - [22/Sep/2014 21:06:04] "GET %2Fassets%2Ffavicon-57ed4bb8f9b97e59250c2190036ea3f9.ico HTTP/1.1" 304 - 0.0017
I, [2014-09-15T07:28:16.391445 #1617] INFO -- : Started GET "/manage/instances/35616012-87d4-4faa-b6f7-2ae387740de6" for 172.31.201.11 at 2014-09-15 07:28:16 +0000
I, [2014-09-15T07:28:16.395434 #1617] INFO -- : Processing by Manage::InstancesController#show as HTML
I, [2014-09-15T07:28:16.396385 #1617] INFO -- : Parameters: {"id"=>"35616012-87d4-4faa-b6f7-2ae387740de6"}
I, [2014-09-15T07:28:16.397713 #1617] INFO -- : Redirected to https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry
I, [2014-09-15T07:28:16.398465 #1617] INFO -- : Filter chain halted as :require_login rendered or redirected
I, [2014-09-15T07:28:16.399240 #1617] INFO -- : Completed 302 Found in 2ms (ActiveRecord: 0.0ms)
172.31.128.6, 172.31.255.101 - - [15/Sep/2014 07:28:16] "GET /manage/instances/35616012-87d4-4faa-b6f7-2ae387740de6 HTTP/1.1" 302 - 0.0124
I, [2014-09-15T07:28:16.479763 #1626] INFO -- : Started GET "/manage/auth/cloudfoundry" for 172.31.201.11 at 2014-09-15 07:28:16 +0000
I, [2014-09-15T07:28:16.485525 #1626] INFO -- omniauth: (cloudfoundry) Request phase initiated.
I, [2014-09-15T07:28:16.488000 #1626] INFO -- omniauth: (cloudfoundry) Client: dashboard-sso-wd-mariadb auth_server: https://login.paas.10.0.0.1.xip.io token_server: https://uaa.paas.10.0.0.1.xip.io
I, [2014-09-15T07:28:16.491717 #1626] INFO -- omniauth: (cloudfoundry) Redirect URI https://login.paas.10.0.0.1.xip.io/oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code+id_token&redirect_uri=https%3A%2F%2Fmariadb.paas.10.0.0.1.xip.io%2Fmanage%2Fauth%2Fcloudfoundry%2Fcallback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read+openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7
172.31.128.6, 172.31.255.101 - - [15/Sep/2014 07:28:16] "GET /manage/auth/cloudfoundry HTTP/1.1" 302 366 0.0218
I, [2014-09-15T07:28:36.671760 #1623] INFO -- : Started GET "/manage/auth/cloudfoundry/callback?code=FZ7iOV&state=d9592512cf650b8ebbad45d8e6ffb9b7" for 172.31.201.11 at 2014-09-15 07:28:36 +0000
I, [2014-09-15T07:28:36.675117 #1623] INFO -- omniauth: (cloudfoundry) Callback phase initiated.
I, [2014-09-15T07:28:36.676969 #1623] INFO -- omniauth: (cloudfoundry) In callback phase code=FZ7iOV&state=d9592512cf650b8ebbad45d8e6ffb9b7
I, [2014-09-15T07:28:36.677787 #1623] INFO -- omniauth: (cloudfoundry) Fetching access token
I, [2014-09-15T07:28:36.678495 #1623] INFO -- omniauth: (cloudfoundry) Client: dashboard-sso-wd-mariadb auth_server: https://login.paas.10.0.0.1.xip.io token_server: https://uaa.paas.10.0.0.1.xip.io
D, [2014-09-15T07:28:36.680894 #1623] DEBUG -- omniauth: --->
request: post https://uaa.paas.10.0.0.1.xip.io/oauth/token
headers: {"content-type"=>"application/x-www-form-urlencoded;charset=utf-8", "accept"=>"application/json;charset=utf-8", "authorization"=>"Basic ZGFzaGJvYXJkLXNzby13ZC1tYXJpYWRiOlIyV05UeTNvQlZqSmh6MHFMQ1VJ"}
body: grant_type=authorization_code&code=FZ7iOV&redir...
D, [2014-09-15T07:28:36.993225 #1623] DEBUG -- omniauth: <---
response: 200
headers: {"cache-control"=>"no-store", "content-type"=>"application/json;charset=utf-8", "pragma"=>"no-cache", "x-cf-requestid"=>"12da3633-09d9-4a2e-413b-fece46a92947", "x-proxy-router"=>"router0", "content-length"=>"2152", "accept-ranges"=>"bytes", "date"=>"Mon, 15 Sep 2014 07:28:36 GMT", "x-varnish"=>"1078317665", "age"=>"0", "via"=>"1.1 varnish", "connection"=>"close", "x-cache"=>"MISS", "x-proxy-cache"=>"lb-cache0", "x-proxy-lb-ssl"=>"lb-cache0"}
body: {"access_token":"eyJhbGciOiJSUzI1NiJ9.eyJqdGkiO...
Class#decode is deprecated with these parameters. Please use options hash.
I, [2014-09-15T07:28:36.997474 #1623] INFO -- omniauth: (cloudfoundry) Got access token #<OmniAuth::Strategies::CFAccessToken:0x007faf58dcd368 @info={"access_token"=>"eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiI2MDA0OWI3ZS1iZjM2LTQzN2MtOWRkMS1lNGNhNDM4MjRmMDIiLCJzdWIiOiIxM2NmZTVhMi02NWRmLTQ2ZmItYjY0ZC1hZWU2MzZlYWQ2MmUiLCJzY29wZSI6WyJjbG91ZF9jb250cm9sbGVyX3NlcnZpY2VfcGVybWlzc2lvbnMucmVhZCIsIm9wZW5pZCJdLCJjbGllbnRfaWQiOiJkYXNoYm9hcmQtc3NvLXdkLW1hcmlhZGIiLCJjaWQiOiJkYXNoYm9hcmQtc3NvLXdkLW1hcmlhZGIiLCJncmFudF90eXBlIjoiYXV0aG9yaXphdGlvbl9jb2RlIiwidXNlcl9pZCI6IjEzY2ZlNWEyLTY1ZGYtNDZmYi1iNjRkLWFlZTYzNmVhZDYyZSIsInVzZXJfbmFtZSI6ImFkbWluIiwiZW1haWwiOiJhZG1pbiIsImlhdCI6MTQxMDc2NjExNiwiZXhwIjoxNDEwODA5MzE2LCJpc3MiOiJodHRwczovL3VhYS5wYWFzLmxhYi53ZWJob3N0LmNvLm56L29hdXRoL3Rva2VuIiwiYXVkIjpbImNsb3VkX2NvbnRyb2xsZXJfc2VydmljZV9wZXJtaXNzaW9ucyIsIm9wZW5pZCJdfQ.SJyoU_dS0hFoS1VKisdZHj99P-eV0Q3cvP3-TZh1D8zY_ThdfF3xPpzytFQ0TZku0t3ta8LZnQKjNWh4XCKCT0E4xwz_tCzpBhYBjvb9_RlkZ6okqeX8X0Ub_RPSseVVxofIruksKC2yB6u6ti8R__JGhk7xgTjfqRCnxN-_n_fRe6GlnsPTj64RhDSdA3C753sRKS1zWyHEcMlxgRlKO1_eIfCrzYuX00eH-aKu9LbRzkPvs4phzqCMWsefx_2BckLuEmFV0KPZn2EwPYdJdbrONbVSaadToOK6otNvr1kWCdD1OrMQ-1kCDqgEZrr8pTlALVuvQBA3db3JW31Xzg", "token_type"=>"bearer", "refresh_token"=>"eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiIyZGEwY2VmMy0yZDg3LTQwYzctOTJjMS0wZmEzYjdhYzIyNjMiLCJzdWIiOiIxM2NmZTVhMi02NWRmLTQ2ZmItYjY0ZC1hZWU2MzZlYWQ2MmUiLCJzY29wZSI6WyJjbG91ZF9jb250cm9sbGVyX3NlcnZpY2VfcGVybWlzc2lvbnMucmVhZCIsIm9wZW5pZCJdLCJpYXQiOjE0MTA3NjYxMTYsImV4cCI6MTQxMzM1ODExNiwiY2lkIjoiZGFzaGJvYXJkLXNzby13ZC1tYXJpYWRiIiwiaXNzIjoiaHR0cHM6Ly91YWEucGFhcy5sYWIud2ViaG9zdC5jby5uei9vYXV0aC90b2tlbiIsImdyYW50X3R5cGUiOiJhdXRob3JpemF0aW9uX2NvZGUiLCJ1c2VyX25hbWUiOiJhZG1pbiIsInVzZXJfaWQiOiIxM2NmZTVhMi02NWRmLTQ2ZmItYjY0ZC1hZWU2MzZlYWQ2MmUiLCJhdWQiOlsiY2xvdWRfY29udHJvbGxlcl9zZXJ2aWNlX3Blcm1pc3Npb25zLnJlYWQiLCJvcGVuaWQiXX0.iiiTUnEIvER1BW8CGHJGcaT90tio-pkSMjlgnFT7YyGQ-w_Lbi_At6opGXK59iCVU0qjofKdnYDBikkPRZUjUrX4vPEAmoK_UfMAmi-xHm8JX4BRgNfhkSRcIVbxSozwaXr_RIm-lA3YheCo0DnybXLWwtlJ4-RCwI_OSG2Z_gwSWGFemVi633Z0BnQOLSUwjByMZasjttF1L3vtsjY4WWt3fB8tNrqunF_HJQGIu_uTLOFZn-rhtHItKoJZbGtg4qmSxHCsG-0Z7yb8LNBYYPBPc3d72MxoaZlWSprAFAd3KZ75yijoCAJ13jgc7-f4GGb7sEvKy_FJx5FTkahl-w", "expires_in"=>43199, "scope"=>"cloud_controller_service_permissions.read openid", "jti"=>"60049b7e-bf36-437c-9dd1-e4ca43824f02"}, @auth_header="bearer eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiI2MDA0OWI3ZS1iZjM2LTQzN2MtOWRkMS1lNGNhNDM4MjRmMDIiLCJzdWIiOiIxM2NmZTVhMi02NWRmLTQ2ZmItYjY0ZC1hZWU2MzZlYWQ2MmUiLCJzY29wZSI6WyJjbG91ZF9jb250cm9sbGVyX3NlcnZpY2VfcGVybWlzc2lvbnMucmVhZCIsIm9wZW5pZCJdLCJjbGllbnRfaWQiOiJkYXNoYm9hcmQtc3NvLXdkLW1hcmlhZGIiLCJjaWQiOiJkYXNoYm9hcmQtc3NvLXdkLW1hcmlhZGIiLCJncmFudF90eXBlIjoiYXV0aG9yaXphdGlvbl9jb2RlIiwidXNlcl9pZCI6IjEzY2ZlNWEyLTY1ZGYtNDZmYi1iNjRkLWFlZTYzNmVhZDYyZSIsInVzZXJfbmFtZSI6ImFkbWluIiwiZW1haWwiOiJhZG1pbiIsImlhdCI6MTQxMDc2NjExNiwiZXhwIjoxNDEwODA5MzE2LCJpc3MiOiJodHRwczovL3VhYS5wYWFzLmxhYi53ZWJob3N0LmNvLm56L29hdXRoL3Rva2VuIiwiYXVkIjpbImNsb3VkX2NvbnRyb2xsZXJfc2VydmljZV9wZXJtaXNzaW9ucyIsIm9wZW5pZCJdfQ.SJyoU_dS0hFoS1VKisdZHj99P-eV0Q3cvP3-TZh1D8zY_ThdfF3xPpzytFQ0TZku0t3ta8LZnQKjNWh4XCKCT0E4xwz_tCzpBhYBjvb9_RlkZ6okqeX8X0Ub_RPSseVVxofIruksKC2yB6u6ti8R__JGhk7xgTjfqRCnxN-_n_fRe6GlnsPTj64RhDSdA3C753sRKS1zWyHEcMlxgRlKO1_eIfCrzYuX00eH-aKu9LbRzkPvs4phzqCMWsefx_2BckLuEmFV0KPZn2EwPYdJdbrONbVSaadToOK6otNvr1kWCdD1OrMQ-1kCDqgEZrr8pTlALVuvQBA3db3JW31Xzg">
I, [2014-09-15T07:28:37.055688 #1623] INFO -- : Processing by Manage::AuthController#create as HTML
I, [2014-09-15T07:28:37.056784 #1623] INFO -- : Parameters: {"code"=>"FZ7iOV", "state"=>"d9592512cf650b8ebbad45d8e6ffb9b7"}
I, [2014-09-15T07:28:37.061479 #1623] INFO -- : Redirected to https://mariadb.paas.10.0.0.1.xip.io/manage/instances/35616012-87d4-4faa-b6f7-2ae387740de6
I, [2014-09-15T07:28:37.063174 #1623] INFO -- : Completed 302 Found in 6ms (ActiveRecord: 0.0ms)
172.31.128.6, 172.31.255.101 - - [15/Sep/2014 07:28:37] "GET /manage/authority/cloudfoundry/callback?code=FZ7iOV&state=d9592512cf650b8ebbad45d8e6ffb9b7 HTTP/1.1" 302 - 0.4780
I, [2014-09-15T07:28:37.193409 #1620] INFO -- : Started GET "/manage/instances/35616012-87d4-4faa-b6f7-2ae387740de6" for 172.31.201.11 at 2014-09-15 07:28:37 +0000
I, [2014-09-15T07:28:37.197451 #1620] INFO -- : Processing by Manage::InstancesController#show as HTML
I, [2014-09-15T07:28:37.198303 #1620] INFO -- : Parameters: {"id"=>"35616012-87d4-4faa-b6f7-2ae387740de6"}
I, [2014-09-15T07:28:37.232504 #1620] INFO -- : Rendered errors/not_authorized.html.erb within layouts/application (0.1ms)
I, [2014-09-15T07:28:37.234696 #1620] INFO -- : Filter chain halted as :ensure_can_manage_instance rendered or redirected
I, [2014-09-15T07:28:37.235590 #1620] INFO -- : Completed 200 OK in 36ms (Views: 3.5ms | ActiveRecord: 0.0ms)
172.31.128.6, 172.31.255.101 - - [15/Sep/2014 07:28:37] "GET /manage/instances/35616012-87d4-4faa-b6f7-2ae387740de6 HTTP/1.1" 200 - 0.0471
^C
[2014-09-15 07:28:36.490] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/saml/web/**'
[2014-09-15 07:28:36.490] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/resources/**'
[2014-09-15 07:28:36.490] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/vendor/**'
[2014-09-15 07:28:36.490] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/healthz/**'
[2014-09-15 07:28:36.490] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- UaaRequestMatcher: [oauthTokenAuthcodeFlow] Checking match of request : '/oauth/authorize'; '/oauth/token' with parameters={grant_type=authorization_code} and headers {}
[2014-09-15 07:28:36.490] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- UaaRequestMatcher: [oauthTokenRefresh] Checking match of request : '/oauth/authorize'; '/oauth/token' with parameters={grant_type=refresh_token} and headers {}
[2014-09-15 07:28:36.490] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/login'
[2014-09-15 07:28:36.490] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/info'
[2014-09-15 07:28:36.490] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/error'
[2014-09-15 07:28:36.490] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/forgot_password*'
[2014-09-15 07:28:36.491] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/reset_password'
[2014-09-15 07:28:36.491] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/email_sent'
[2014-09-15 07:28:36.491] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/accounts/new'
[2014-09-15 07:28:36.491] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/accounts/email_sent'
[2014-09-15 07:28:36.491] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/autologin'
[2014-09-15 07:28:36.491] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- UaaRequestMatcher: [autologinAuthorizeRequestMatcher] Checking match of request : '/oauth/authorize'; '/oauth/authorize' with parameters={response_type=code, code=} and headers {}
[2014-09-15 07:28:36.491] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- UaaRequestMatcher: [oauthAuthorizeRequestMatcher] Checking match of request : '/oauth/authorize'; '/oauth/authorize' with parameters={response_type=token, source=credentials} and headers {accept=[application/json, application/x-www-form-urlencoded]}
[2014-09-15 07:28:36.491] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/log*.do'
[2014-09-15 07:28:36.491] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/reset_password.do'
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/accounts'
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- UaaRequestMatcher: [passcodeTokenMatcher] Checking match of request : '/oauth/authorize'; '/oauth/token' with parameters={grant_type=password, passcode=} and headers {accept=[application/json, application/x-www-form-urlencoded]}
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- UaaRequestMatcher: [uaaPasswordTokenMatcher] Checking match of request : '/oauth/authorize'; '/oauth/token' with parameters={grant_type=password, password=} and headers {}
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 1 of 13 in additional filter chain; firing Filter: 'NoOpFilter'
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 2 of 13 in additional filter chain; firing Filter: 'HttpsHeaderFilter'
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 3 of 13 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- HttpSessionSecurityContextRepository: Obtained a valid SecurityContext from SPRING_SECURITY_CONTEXT: 'org.springframework.security.core.context.SecurityContextImpl@a57093d0: Authentication: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@a57093d0: Principal: org.cloudfoundry.identity.uaa.authentication.UaaPrincipal@13e0e618; Credentials: [PROTECTED]; Authenticated: true; Details: null; Granted Authorities: uaa.user'
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 4 of 13 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 5 of 13 in additional filter chain; firing Filter: 'LogoutFilter'
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 6 of 13 in additional filter chain; firing Filter: 'OpenIDAuthenticationFilter'
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 7 of 13 in additional filter chain; firing Filter: 'NoOpFilter'
[2014-09-15 07:28:36.492] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 8 of 13 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 9 of 13 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 10 of 13 in additional filter chain; firing Filter: 'SessionManagementFilter'
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 11 of 13 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 12 of 13 in additional filter chain; firing Filter: 'OAuth2ClientContextFilter'
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FixHttpsSchemeRequest: Request X-Forwarded-Proto https
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 13 of 13 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterSecurityInterceptor: Secure object: FilterInvocation: URL: /oauth/authorize; Attributes: [IS_AUTHENTICATED_FULLY]
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterSecurityInterceptor: Previously Authenticated: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@a57093d0: Principal: org.cloudfoundry.identity.uaa.authentication.UaaPrincipal@13e0e618; Credentials: [PROTECTED]; Authenticated: true; Details: null; Granted Authorities: uaa.user
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AffirmativeBased: Voter: org.springframework.security.access.vote.RoleVoter@376d24be, returned: 0
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- AffirmativeBased: Voter: org.springframework.security.access.vote.AuthenticatedVoter@5e87525f, returned: 1
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterSecurityInterceptor: Authorization successful
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterSecurityInterceptor: RunAsManager did not change Authentication object
[2014-09-15 07:28:36.493] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- FilterChainProxy: /oauth/authorize reached end of additional filter chain; proceeding with original chain
[2014-09-15 07:28:36.494] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- DispatcherServlet: DispatcherServlet with name 'spring' processing POST request for [/oauth/authorize]
[2014-09-15 07:28:36.494] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- RequestMappingHandlerMapping: Looking up handler method for path /oauth/authorize
[2014-09-15 07:28:36.494] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- RequestMappingHandlerMapping: Returning handler method [public org.springframework.http.ResponseEntity<[B> org.cloudfoundry.identity.uaa.login.RemoteUaaController.approveOrDeny(javax.servlet.http.HttpServletRequest,org.springframework.http.HttpEntity<[B>,java.util.Map<java.lang.String, java.lang.Object>,org.springframework.web.bind.support.SessionStatus) throws java.lang.Exception]
[2014-09-15 07:28:36.496] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- HttpEntityMethodProcessor: Reading [[B] as "application/x-www-form-urlencoded" using [org.springframework.http.converter.ByteArrayHttpMessageConverter@5c4d0f8c]
[2014-09-15 07:28:36.497] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- RemoteUaaController: Path: oauth/authorize
[2014-09-15 07:28:36.497] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- RemoteUaaController: Outgoing headers: {user-agent=[Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36], content-length=[101], accept=[text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8], accept-encoding=[gzip,deflate], accept-language=[en-US,en;q=0.8], cache-control=[max-age=0], content-type=[application/x-www-form-urlencoded], cookie=[__VCAP_ID__=b461c71c-5814-4b16-a728-86a574b0c468; JSESSIONID=E907B64BAB3004E9CE15E18684297CD5], dnt=[1], origin=[https://login.paas.10.0.0.1.xip.io], referer=[https://login.paas.10.0.0.1.xip.io/oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code+id_token&redirect_uri=https%3A%2F%2Fmariadb.paas.10.0.0.1.xip.io%2Fmanage%2Fauth%2Fcloudfoundry%2Fcallback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read+openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7], x-cf-applicationid=[], x-cf-instanceid=[b461c71c-5814-4b16-a728-86a574b0c468], x-cf-requestid=[af477d8c-a076-4165-470e-003d93564f69], x-vcap-request-id=[700e0ada-c288-4b8c-5b9b-4efabffb9576], x-forwarded-port=[443], x-forwarded-proto=[https], x-request-start=[1410766116482], x-varnish=[1078317662], Host=[uaa.paas.10.0.0.1.xip.io]}
[2014-09-15 07:28:36.497] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- RemoteUaaController: Found back end cookies: __VCAP_ID__=d0519a97-42e7-4cb8-9271-33fa4285c574;JSESSIONID=15611ED766FF21BFBE5743FD1A5DE0FE
[2014-09-15 07:28:36.498] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- RestTemplate: Created POST request for "https://uaa.paas.10.0.0.1.xip.io/oauth/authorize"
[2014-09-15 07:28:36.499] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- RestTemplate: Setting request Accept header to [application/octet-stream, application/json, application/*+json, */*]
[2014-09-15 07:28:36.499] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- RestTemplate: Writing [[B@455b730e] as "application/x-www-form-urlencoded" using [org.springframework.http.converter.ByteArrayHttpMessageConverter@253d7814]
[2014-09-15 07:28:36.499] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- PoolingHttpClientConnectionManager: Connection request: [route: {s}->https://uaa.paas.10.0.0.1.xip.io:443][total kept alive: 0; route allocated: 0 of 5; total allocated: 0 of 10]
[2014-09-15 07:28:36.500] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- PoolingHttpClientConnectionManager: Connection leased: [id: 12][route: {s}->https://uaa.paas.10.0.0.1.xip.io:443][total kept alive: 0; route allocated: 1 of 5; total allocated: 1 of 10]
[2014-09-15 07:28:36.500] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- HttpClientConnectionOperator: Connecting to uaa.paas.10.0.0.1.xip.io/172.31.255.101:443
[2014-09-15 07:28:36.506] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- HttpClientConnectionOperator: Connection established 172.31.201.21:52746<->172.31.255.101:443
[2014-09-15 07:28:36.596] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- RestTemplate: POST request for "https://uaa.paas.10.0.0.1.xip.io/oauth/authorize" resulted in 302 (Found)
[2014-09-15 07:28:36.596] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- PoolingHttpClientConnectionManager: Connection [id: 12][route: {s}->https://uaa.paas.10.0.0.1.xip.io:443] can be kept alive indefinitely
[2014-09-15 07:28:36.596] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- PoolingHttpClientConnectionManager: Connection released: [id: 12][route: {s}->https://uaa.paas.10.0.0.1.xip.io:443][total kept alive: 1; route allocated: 1 of 5; total allocated: 1 of 10]
[2014-09-15 07:28:36.598] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- DispatcherServlet: Null ModelAndView returned to DispatcherServlet with name 'spring': assuming HandlerAdapter completed request handling
[2014-09-15 07:28:36.598] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- DispatcherServlet: Successfully completed request
[2014-09-15 07:28:36.598] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- ExceptionTranslationFilter: Chain processed normally
[2014-09-15 07:28:36.598] login - 21476 [http-bio-9090-exec-1] .... DEBUG --- SecurityContextPersistenceFilter: SecurityContextHolder now cleared, as request processing completed
[2014-09-15 07:28:16.559] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/resources/**'
[2014-09-15 07:28:16.560] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/favicon.ico'
[2014-09-15 07:28:16.560] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/info'
[2014-09-15 07:28:16.560] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/password/**'
[2014-09-15 07:28:16.561] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/healthz/**'
[2014-09-15 07:28:16.561] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- UaaRequestMatcher: [loginAuthenticateRequestMatcher] Checking match of request : '/oauth/authorize'; '/authenticate' with parameters={} and headers {Authorization=[Bearer ], accept=[application/json]}
[2014-09-15 07:28:16.561] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/authenticate/**'
[2014-09-15 07:28:16.562] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- UaaRequestMatcher: [loginAuthorizeRequestMatcher] Checking match of request : '/oauth/authorize'; '/oauth/authorize' with parameters={source=login} and headers {accept=[application/json]}
[2014-09-15 07:28:16.563] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- UaaRequestMatcher: [loginAuthorizeRequestMatcher]Matched request /oauth/authorize'; '/oauth/authorize' with parameters={source=login} and headers {accept=[application/json]}
[2014-09-15 07:28:16.563] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 at position 1 of 11 in additional filter chain; firing Filter: 'UaaLoggingFilter'
[2014-09-15 07:28:16.563] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- SecurityFilterChainPostProcessor$UaaLoggingFilter: Filter chain 'org.springframework.security.web.DefaultSecurityFilterChain#7' processing request POST /oauth/authorize
[2014-09-15 07:28:16.563] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 at position 2 of 11 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
[2014-09-15 07:28:16.564] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- HttpSessionSecurityContextRepository: No HttpSession currently exists
[2014-09-15 07:28:16.564] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- HttpSessionSecurityContextRepository: No SecurityContext was available from the HttpSession: null. A new one will be created.
[2014-09-15 07:28:16.564] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 at position 3 of 11 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
[2014-09-15 07:28:16.565] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 at position 4 of 11 in additional filter chain; firing Filter: 'OAuth2AuthenticationProcessingFilter'
[2014-09-15 07:28:16.567] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:16.567] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:16.572] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:16.572] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:16.575] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- OAuth2AuthenticationProcessingFilter: Authentication success: org.springframework.security.oauth2.provider.OAuth2Authentication@97cb716b: Principal: login; Credentials: [PROTECTED]; Authenticated: true; Details: remoteAddress=172.31.201.21, , tokenValue=<TOKEN>; Granted Authorities: oauth.login
[2014-09-15 07:28:16.575] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 at position 5 of 11 in additional filter chain; firing Filter: 'ScopeAuthenticationFilter'
[2014-09-15 07:28:16.575] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 at position 6 of 11 in additional filter chain; firing Filter: 'AuthzAuthenticationFilter'
[2014-09-15 07:28:16.576] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- AuthzAuthenticationFilter: Located credentials in request, with keys: [username, origin, user_id]
[2014-09-15 07:28:16.576] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- LoginAuthenticationManager: Processing authentication request for admin
[2014-09-15 07:28:16.576] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:16.577] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select id,username,password,email,givenName,familyName,created,lastModified,authorities,origin,external_id from users where id = ? and active=?]
[2014-09-15 07:28:16.578] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:16.578] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select g.displayName from groups g, group_membership m where g.id = m.group_id and m.member_id = ?
]
[2014-09-15 07:28:16.580] uaa - 21358 [http-bio-8080-exec-4] .... INFO --- Audit: UserAuthenticationSuccess ('admin'): principal=13cfe5a2-65df-46fb-b64d-aee636ead62e, origin=[remoteAddress=172.31.201.21, clientId=dashboard-sso-wd-mariadb]
[2014-09-15 07:28:16.580] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL update
[2014-09-15 07:28:16.581] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [delete from sec_audit where principal_id=?]
[2014-09-15 07:28:16.582] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: SQL update affected 0 rows
[2014-09-15 07:28:16.582] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 at position 7 of 11 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
[2014-09-15 07:28:16.582] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 at position 8 of 11 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
[2014-09-15 07:28:16.583] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 at position 9 of 11 in additional filter chain; firing Filter: 'SessionManagementFilter'
[2014-09-15 07:28:16.583] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- CompositeSessionAuthenticationStrategy: Delegating to org.springframework.security.web.authentication.session.SessionFixationProtectionStrategy@73e00a5b
[2014-09-15 07:28:16.583] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- HttpSessionSecurityContextRepository: The HttpSession is currently null, and the HttpSessionSecurityContextRepository is prohibited from creating an HttpSession (because the allowSessionCreation property is false) - SecurityContext thus not stored for next request
[2014-09-15 07:28:16.584] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 at position 10 of 11 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
[2014-09-15 07:28:16.584] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 at position 11 of 11 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
[2014-09-15 07:28:16.584] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterSecurityInterceptor: Secure object: FilterInvocation: URL: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7; Attributes: [IS_AUTHENTICATED_FULLY]
[2014-09-15 07:28:16.584] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterSecurityInterceptor: Previously Authenticated: org.cloudfoundry.identity.uaa.authentication.UaaAuthentication@30cfc783
[2014-09-15 07:28:16.585] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- AffirmativeBased: Voter: org.springframework.security.access.vote.RoleVoter@3f924ee3, returned: 0
[2014-09-15 07:28:16.585] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- AffirmativeBased: Voter: org.springframework.security.access.vote.AuthenticatedVoter@1e7939b0, returned: 1
[2014-09-15 07:28:16.585] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterSecurityInterceptor: Authorization successful
[2014-09-15 07:28:16.585] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterSecurityInterceptor: RunAsManager did not change Authentication object
[2014-09-15 07:28:16.586] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- FilterChainProxy: /oauth/authorize?client_id=dashboard-sso-wd-mariadb&response_type=code%20id_token&redirect_uri=https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback&state=d9592512cf650b8ebbad45d8e6ffb9b7&scope=cloud_controller_service_permissions.read%20openid&nonce=d9592512cf650b8ebbad45d8e6ffb9b7 reached end of additional filter chain; proceeding with original chain
[2014-09-15 07:28:16.586] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- DispatcherServlet: DispatcherServlet with name 'spring' processing POST request for [/oauth/authorize]
[2014-09-15 07:28:16.588] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:16.588] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:16.592] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:16.593] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:16.595] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- UserManagedAuthzApprovalHandler: Looking up user approved authorizations for client_id=dashboard-sso-wd-mariadb and username=admin
[2014-09-15 07:28:16.596] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:16.596] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:16.599] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcApprovalStore: Filtering approvals with filter: [sql: (LOWER(user_id) = LOWER(:__lu40kg_0) AND LOWER(client_id) = LOWER(:__lu40kg_1)), params: {__lu40kg_1=dashboard-sso-wd-mariadb, __lu40kg_0=13cfe5a2-65df-46fb-b64d-aee636ead62e}]
[2014-09-15 07:28:16.600] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:16.600] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select count(*) from authz_approvals where (lower(user_id) = lower(?) and lower(client_id) = lower(?))]
[2014-09-15 07:28:16.601] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- UserManagedAuthzApprovalHandler: Valid user approved/denied scopes are []
[2014-09-15 07:28:16.602] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:16.602] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:16.605] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- AuthorizationEndpoint: Loading user approval page: forward:/oauth/confirm_access
[2014-09-15 07:28:16.607] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- ContentNegotiatingViewResolver: Requested media types are [application/json] based on Accept header types and producible media types [*/*])
[2014-09-15 07:28:16.608] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- ContentNegotiatingViewResolver: Returning [org.springframework.web.servlet.view.InternalResourceView: unnamed; URL [/oauth/confirm_access]] based on requested media type 'application/json'
[2014-09-15 07:28:16.608] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- DispatcherServlet: Rendering view [org.springframework.web.servlet.view.InternalResourceView: unnamed; URL [/oauth/confirm_access]] in DispatcherServlet with name 'spring'
[2014-09-15 07:28:16.608] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'authorizationRequest' of type [org.springframework.security.oauth2.provider.DefaultAuthorizationRequest] to request in view with name 'null'
[2014-09-15 07:28:16.609] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'nonce' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.609] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'scope' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.609] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'state' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.609] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'username' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.610] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'origin' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.610] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'client_id' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.610] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'source' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.610] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'response_type' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.611] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'original_scope' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.611] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'redirect_uri' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.611] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'external_scopes' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.611] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'add_new' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.612] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'user_id' of type [java.lang.String] to request in view with name 'null'
[2014-09-15 07:28:16.612] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Added model object 'org.springframework.validation.BindingResult.authorizationRequest' of type [org.springframework.validation.BeanPropertyBindingResult] to request in view with name 'null'
[2014-09-15 07:28:16.612] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- InternalResourceView: Forwarding to resource [/oauth/confirm_access] in InternalResourceView 'null'
[2014-09-15 07:28:16.613] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- DispatcherServlet: DispatcherServlet with name 'spring' processing POST request for [/oauth/confirm_access]
[2014-09-15 07:28:16.614] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:16.614] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:16.618] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcApprovalStore: Filtering approvals with filter: [sql: (LOWER(user_id) = LOWER(:__pambho_0) AND LOWER(client_id) = LOWER(:__pambho_1)), params: {__pambho_1=dashboard-sso-wd-mariadb, __pambho_0=13cfe5a2-65df-46fb-b64d-aee636ead62e}]
[2014-09-15 07:28:16.619] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:16.619] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select count(*) from authz_approvals where (lower(user_id) = lower(?) and lower(client_id) = lower(?))]
[2014-09-15 07:28:16.621] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- ContentNegotiatingViewResolver: Requested media types are [application/json] based on Accept header types and producible media types [*/*])
[2014-09-15 07:28:16.621] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- ContentNegotiatingViewResolver: Returning [org.springframework.web.servlet.view.json.MappingJacksonJsonView: name 'org.springframework.web.servlet.view.json.MappingJacksonJsonView#570aa4d0'] based on requested media type 'application/json'
[2014-09-15 07:28:16.621] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- DispatcherServlet: Rendering view [org.springframework.web.servlet.view.json.MappingJacksonJsonView: name 'org.springframework.web.servlet.view.json.MappingJacksonJsonView#570aa4d0'] in DispatcherServlet with name 'spring'
[2014-09-15 07:28:16.623] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- HttpSessionSecurityContextRepository: SecurityContext stored to HttpSession: 'org.springframework.security.core.context.SecurityContextImpl@30cfc783: Authentication: org.cloudfoundry.identity.uaa.authentication.UaaAuthentication@30cfc783'
[2014-09-15 07:28:16.624] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- DispatcherServlet: Successfully completed request
[2014-09-15 07:28:16.624] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- DispatcherServlet: Successfully completed request
[2014-09-15 07:28:16.624] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- ExceptionTranslationFilter: Chain processed normally
[2014-09-15 07:28:16.625] uaa - 21358 [http-bio-8080-exec-4] .... DEBUG --- SecurityContextPersistenceFilter: SecurityContextHolder now cleared, as request processing completed
[2014-09-15 07:28:36.512] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/resources/**'
[2014-09-15 07:28:36.513] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/favicon.ico'
[2014-09-15 07:28:36.513] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/info'
[2014-09-15 07:28:36.513] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/password/**'
[2014-09-15 07:28:36.513] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/healthz/**'
[2014-09-15 07:28:36.513] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- UaaRequestMatcher: [loginAuthenticateRequestMatcher] Checking match of request : '/oauth/authorize'; '/authenticate' with parameters={} and headers {Authorization=[Bearer ], accept=[application/json]}
[2014-09-15 07:28:36.513] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/authenticate/**'
[2014-09-15 07:28:36.513] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- UaaRequestMatcher: [loginAuthorizeRequestMatcher] Checking match of request : '/oauth/authorize'; '/oauth/authorize' with parameters={source=login} and headers {accept=[application/json]}
[2014-09-15 07:28:36.513] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- UaaRequestMatcher: [loginTokenRequestMatcher] Checking match of request : '/oauth/authorize'; '/oauth/token' with parameters={source=login, grant_type=password, add_new=} and headers {Authorization=[Bearer ], accept=[application/json]}
[2014-09-15 07:28:36.513] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- UaaRequestMatcher: [loginAuthorizeRequestMatcherOld] Checking match of request : '/oauth/authorize'; '/oauth/authorize' with parameters={login={} and headers {accept=[application/json]}
[2014-09-15 07:28:36.514] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/codes/**'
[2014-09-15 07:28:36.514] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/password_*'
[2014-09-15 07:28:36.514] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/create_account'
[2014-09-15 07:28:36.514] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/oauth/token/**'
[2014-09-15 07:28:36.514] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- UaaRequestMatcher: [oauthAuthorizeRequestMatcher] Checking match of request : '/oauth/authorize'; '/oauth/authorize' with parameters={response_type=token, source=credentials} and headers {accept=[application/json, application/x-www-form-urlencoded]}
[2014-09-15 07:28:36.514] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- UaaRequestMatcher: [oauthAuthorizeRequestMatcherOld] Checking match of request : '/oauth/authorize'; '/oauth/authorize' with parameters={response_type=token, credentials={} and headers {accept=[application/json, application/x-www-form-urlencoded]}
[2014-09-15 07:28:36.514] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- UaaRequestMatcher: [groupsUpdateRequestMatcher] Checking match of request : '/oauth/authorize'; '/Groups' with parameters={} and headers {}
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- UaaRequestMatcher: [groupsReadRequestMatcher] Checking match of request : '/oauth/authorize'; '/Groups' with parameters={} and headers {}
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/groups/**'
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/user*/*/password'
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/users/**'
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/ids/users*'
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/approvals/**'
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/oauth/clients/*/secret'
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/oauth/clients/tx/**'
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/oauth/clients/**'
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/check_token'
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/token_key'
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/clientinfo'
[2014-09-15 07:28:36.515] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/userinfo'
[2014-09-15 07:28:36.516] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/'
[2014-09-15 07:28:36.516] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/spring_security_login'
[2014-09-15 07:28:36.516] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/oauth/**'
[2014-09-15 07:28:36.516] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 1 of 11 in additional filter chain; firing Filter: 'UaaLoggingFilter'
[2014-09-15 07:28:36.516] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- SecurityFilterChainPostProcessor$UaaLoggingFilter: Filter chain 'uiSecurity' processing request POST /oauth/authorize
[2014-09-15 07:28:36.516] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 2 of 11 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
[2014-09-15 07:28:36.516] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- HttpSessionSecurityContextRepository: Obtained a valid SecurityContext from SPRING_SECURITY_CONTEXT: 'org.springframework.security.core.context.SecurityContextImpl@30cfc783: Authentication: org.cloudfoundry.identity.uaa.authentication.UaaAuthentication@30cfc783'
[2014-09-15 07:28:36.516] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 3 of 11 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
[2014-09-15 07:28:36.516] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 4 of 11 in additional filter chain; firing Filter: 'LogoutFilter'
[2014-09-15 07:28:36.517] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 5 of 11 in additional filter chain; firing Filter: 'UsernamePasswordAuthenticationFilter'
[2014-09-15 07:28:36.517] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 6 of 11 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
[2014-09-15 07:28:36.517] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 7 of 11 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
[2014-09-15 07:28:36.517] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 8 of 11 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
[2014-09-15 07:28:36.517] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AnonymousAuthenticationFilter: SecurityContextHolder not populated with anonymous token, as it already contained: 'org.cloudfoundry.identity.uaa.authentication.UaaAuthentication@30cfc783'
[2014-09-15 07:28:36.517] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 9 of 11 in additional filter chain; firing Filter: 'SessionManagementFilter'
[2014-09-15 07:28:36.517] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 10 of 11 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
[2014-09-15 07:28:36.517] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize at position 11 of 11 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
[2014-09-15 07:28:36.517] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/authorize'; against '/login**'
[2014-09-15 07:28:36.518] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterSecurityInterceptor: Secure object: FilterInvocation: URL: /oauth/authorize; Attributes: [IS_AUTHENTICATED_FULLY]
[2014-09-15 07:28:36.518] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterSecurityInterceptor: Previously Authenticated: org.cloudfoundry.identity.uaa.authentication.UaaAuthentication@30cfc783
[2014-09-15 07:28:36.518] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AffirmativeBased: Voter: org.springframework.security.access.vote.RoleVoter@76cc0e6f, returned: 0
[2014-09-15 07:28:36.518] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- AffirmativeBased: Voter: org.springframework.security.access.vote.AuthenticatedVoter@4ec7d657, returned: 1
[2014-09-15 07:28:36.518] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterSecurityInterceptor: Authorization successful
[2014-09-15 07:28:36.518] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterSecurityInterceptor: RunAsManager did not change Authentication object
[2014-09-15 07:28:36.518] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- FilterChainProxy: /oauth/authorize reached end of additional filter chain; proceeding with original chain
[2014-09-15 07:28:36.518] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- DispatcherServlet: DispatcherServlet with name 'spring' processing POST request for [/oauth/authorize]
[2014-09-15 07:28:36.520] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.520] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:36.525] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- UserManagedAuthzApprovalHandler: Looking up user approved authorizations for client_id=dashboard-sso-wd-mariadb and username=admin
[2014-09-15 07:28:36.525] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.525] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:36.528] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcApprovalStore: adding approval: [[13cfe5a2-65df-46fb-b64d-aee636ead62e, cloud_controller_service_permissions.read, dashboard-sso-wd-mariadb, Wed Oct 15 07:28:36 UTC 2014, APPROVED, Mon Sep 15 07:28:36 UTC 2014]]
[2014-09-15 07:28:36.528] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcApprovalStore: refreshing approval: [[13cfe5a2-65df-46fb-b64d-aee636ead62e, cloud_controller_service_permissions.read, dashboard-sso-wd-mariadb, Wed Oct 15 07:28:36 UTC 2014, APPROVED, Mon Sep 15 07:28:36 UTC 2014]]
[2014-09-15 07:28:36.528] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL update
[2014-09-15 07:28:36.528] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [update authz_approvals set lastModifiedAt=?, expiresAt=?, status=? where user_id=? and client_Id=? and scope=?]
[2014-09-15 07:28:36.529] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: SQL update affected 0 rows
[2014-09-15 07:28:36.530] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL update
[2014-09-15 07:28:36.530] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [insert into authz_approvals ( user_id,client_id,scope,expiresAt,status,lastModifiedAt ) values (?,?,?,?,?,?)]
[2014-09-15 07:28:36.577] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: SQL update affected 1 rows
[2014-09-15 07:28:36.578] uaa - 21358 [http-bio-8080-exec-5] .... INFO --- Audit: ApprovalModifiedEvent ('{"scope":"cloud_controller_service_permissions.read","status":"APPROVED"}'): principal=13cfe5a2-65df-46fb-b64d-aee636ead62e, origin=[caller=admin, , details=(type=UaaAuthenticationDetails)]
[2014-09-15 07:28:36.580] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcApprovalStore: adding approval: [[13cfe5a2-65df-46fb-b64d-aee636ead62e, openid, dashboard-sso-wd-mariadb, Wed Oct 15 07:28:36 UTC 2014, APPROVED, Mon Sep 15 07:28:36 UTC 2014]]
[2014-09-15 07:28:36.580] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcApprovalStore: refreshing approval: [[13cfe5a2-65df-46fb-b64d-aee636ead62e, openid, dashboard-sso-wd-mariadb, Wed Oct 15 07:28:36 UTC 2014, APPROVED, Mon Sep 15 07:28:36 UTC 2014]]
[2014-09-15 07:28:36.580] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL update
[2014-09-15 07:28:36.580] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [update authz_approvals set lastModifiedAt=?, expiresAt=?, status=? where user_id=? and client_Id=? and scope=?]
[2014-09-15 07:28:36.581] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: SQL update affected 0 rows
[2014-09-15 07:28:36.581] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL update
[2014-09-15 07:28:36.582] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [insert into authz_approvals ( user_id,client_id,scope,expiresAt,status,lastModifiedAt ) values (?,?,?,?,?,?)]
[2014-09-15 07:28:36.583] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: SQL update affected 1 rows
[2014-09-15 07:28:36.584] uaa - 21358 [http-bio-8080-exec-5] .... INFO --- Audit: ApprovalModifiedEvent ('{"scope":"openid","status":"APPROVED"}'): principal=13cfe5a2-65df-46fb-b64d-aee636ead62e, origin=[caller=admin, , details=(type=UaaAuthenticationDetails)]
[2014-09-15 07:28:36.588] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL update
[2014-09-15 07:28:36.588] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [insert into oauth_code (code, authentication) values (?, ?)]
[2014-09-15 07:28:36.589] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- DefaultLobHandler: Set bytes for BLOB with length 3723
[2014-09-15 07:28:36.590] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- JdbcTemplate: SQL update affected 1 rows
[2014-09-15 07:28:36.591] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- DispatcherServlet: Rendering view [org.springframework.web.servlet.view.RedirectView: unnamed; URL [https://mariadb.paas.10.0.0.1.xip.io/manage/auth/cloudfoundry/callback?code=FZ7iOV&state=d9592512cf650b8ebbad45d8e6ffb9b7]] in DispatcherServlet with name 'spring'
[2014-09-15 07:28:36.591] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- DispatcherServlet: Successfully completed request
[2014-09-15 07:28:36.591] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- ExceptionTranslationFilter: Chain processed normally
[2014-09-15 07:28:36.591] uaa - 21358 [http-bio-8080-exec-5] .... DEBUG --- SecurityContextPersistenceFilter: SecurityContextHolder now cleared, as request processing completed
[2014-09-15 07:28:36.703] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/token'; against '/resources/**'
[2014-09-15 07:28:36.703] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/token'; against '/favicon.ico'
[2014-09-15 07:28:36.703] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/token'; against '/info'
[2014-09-15 07:28:36.703] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/token'; against '/password/**'
[2014-09-15 07:28:36.703] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/token'; against '/healthz/**'
[2014-09-15 07:28:36.703] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- UaaRequestMatcher: [loginAuthenticateRequestMatcher] Checking match of request : '/oauth/token'; '/authenticate' with parameters={} and headers {Authorization=[Bearer ], accept=[application/json]}
[2014-09-15 07:28:36.703] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/token'; against '/authenticate/**'
[2014-09-15 07:28:36.703] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- UaaRequestMatcher: [loginAuthorizeRequestMatcher] Checking match of request : '/oauth/token'; '/oauth/authorize' with parameters={source=login} and headers {accept=[application/json]}
[2014-09-15 07:28:36.703] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- UaaRequestMatcher: [loginTokenRequestMatcher] Checking match of request : '/oauth/token'; '/oauth/token' with parameters={source=login, grant_type=password, add_new=} and headers {Authorization=[Bearer ], accept=[application/json]}
[2014-09-15 07:28:36.703] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- UaaRequestMatcher: [loginAuthorizeRequestMatcherOld] Checking match of request : '/oauth/token'; '/oauth/authorize' with parameters={login={} and headers {accept=[application/json]}
[2014-09-15 07:28:36.703] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/token'; against '/codes/**'
[2014-09-15 07:28:36.704] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/token'; against '/password_*'
[2014-09-15 07:28:36.704] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/token'; against '/create_account'
[2014-09-15 07:28:36.704] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/oauth/token'; against '/oauth/token/**'
[2014-09-15 07:28:36.704] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterChainProxy: /oauth/token at position 1 of 8 in additional filter chain; firing Filter: 'UaaLoggingFilter'
[2014-09-15 07:28:36.704] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- SecurityFilterChainPostProcessor$UaaLoggingFilter: Filter chain 'tokenEndpointSecurity' processing request POST /oauth/token
[2014-09-15 07:28:36.704] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterChainProxy: /oauth/token at position 2 of 8 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
[2014-09-15 07:28:36.704] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterChainProxy: /oauth/token at position 3 of 8 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
[2014-09-15 07:28:36.704] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterChainProxy: /oauth/token at position 4 of 8 in additional filter chain; firing Filter: 'BasicAuthenticationFilter'
[2014-09-15 07:28:36.705] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- BasicAuthenticationFilter: Basic Authentication Authorization header found for user 'dashboard-sso-wd-mariadb'
[2014-09-15 07:28:36.705] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- ProviderManager: Authentication attempt using org.springframework.security.authentication.dao.DaoAuthenticationProvider
[2014-09-15 07:28:36.705] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.705] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:36.865] uaa - 21358 [http-bio-8080-exec-7] .... INFO --- Audit: ClientAuthenticationSuccess ('Client authentication success'): principal=null, origin=[remoteAddress=172.31.202.1]
[2014-09-15 07:28:36.866] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- BasicAuthenticationFilter: Authentication success: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@12c6cd88: Principal: org.springframework.security.core.userdetails.User@4d1a35cb: Username: dashboard-sso-wd-mariadb; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: uaa.none; Credentials: [PROTECTED]; Authenticated: true; Details: remoteAddress=172.31.202.1; Granted Authorities: uaa.none
[2014-09-15 07:28:36.866] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterChainProxy: /oauth/token at position 5 of 8 in additional filter chain; firing Filter: 'TokenEndpointAuthenticationFilter'
[2014-09-15 07:28:36.866] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterChainProxy: /oauth/token at position 6 of 8 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
[2014-09-15 07:28:36.867] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterChainProxy: /oauth/token at position 7 of 8 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
[2014-09-15 07:28:36.867] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterChainProxy: /oauth/token at position 8 of 8 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
[2014-09-15 07:28:36.867] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterSecurityInterceptor: Secure object: FilterInvocation: URL: /oauth/token; Attributes: [IS_AUTHENTICATED_FULLY]
[2014-09-15 07:28:36.868] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterSecurityInterceptor: Previously Authenticated: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@12c6cd88: Principal: org.springframework.security.core.userdetails.User@4d1a35cb: Username: dashboard-sso-wd-mariadb; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: uaa.none; Credentials: [PROTECTED]; Authenticated: true; Details: remoteAddress=172.31.202.1; Granted Authorities: uaa.none
[2014-09-15 07:28:36.868] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AffirmativeBased: Voter: org.springframework.security.access.vote.RoleVoter@4154ca4, returned: 0
[2014-09-15 07:28:36.868] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AffirmativeBased: Voter: org.springframework.security.access.vote.AuthenticatedVoter@125aa514, returned: 1
[2014-09-15 07:28:36.868] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterSecurityInterceptor: Authorization successful
[2014-09-15 07:28:36.869] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterSecurityInterceptor: RunAsManager did not change Authentication object
[2014-09-15 07:28:36.869] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- FilterChainProxy: /oauth/token reached end of additional filter chain; proceeding with original chain
[2014-09-15 07:28:36.869] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- DispatcherServlet: DispatcherServlet with name 'spring' processing POST request for [/oauth/token]
[2014-09-15 07:28:36.871] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.871] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:36.874] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.875] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:36.877] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- TokenEndpoint: Clearing scope of incoming auth code request
[2014-09-15 07:28:36.878] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.878] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:36.881] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- AuthorizationCodeTokenGranter: Getting access token for: dashboard-sso-wd-mariadb
[2014-09-15 07:28:36.881] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.882] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select code, authentication from oauth_code where code = ?]
[2014-09-15 07:28:36.887] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL update
[2014-09-15 07:28:36.888] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [delete from oauth_code where code = ?]
[2014-09-15 07:28:36.928] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: SQL update affected 1 rows
[2014-09-15 07:28:36.928] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.928] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:36.937] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.937] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select id,username,password,email,givenName,familyName,created,lastModified,authorities,origin,external_id from users where id = ? and active=?]
[2014-09-15 07:28:36.938] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.938] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select g.displayName from groups g, group_membership m where g.id = m.group_id and m.member_id = ?
]
[2014-09-15 07:28:36.958] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.958] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select id,username,password,email,givenName,familyName,created,lastModified,authorities,origin,external_id from users where id = ? and active=?]
[2014-09-15 07:28:36.960] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.960] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select g.displayName from groups g, group_membership m where g.id = m.group_id and m.member_id = ?
]
[2014-09-15 07:28:36.961] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:36.961] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:36.987] uaa - 21358 [http-bio-8080-exec-7] .... INFO --- Audit: TokenIssuedEvent ('["cloud_controller_service_permissions.read","openid"]'): principal=13cfe5a2-65df-46fb-b64d-aee636ead62e, origin=[caller=dashboard-sso-wd-mariadb, , details=(type=UaaAuthenticationDetails)]
[2014-09-15 07:28:36.989] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- HttpEntityMethodProcessor: Written [eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiI2MDA0OWI3ZS1iZjM2LTQzN2MtOWRkMS1lNGNhNDM4MjRmMDIiLCJzdWIiOiIxM2NmZTVhMi02NWRmLTQ2ZmItYjY0ZC1hZWU2MzZlYWQ2MmUiLCJzY29wZSI6WyJjbG91ZF9jb250cm9sbGVyX3NlcnZpY2VfcGVybWlzc2lvbnMucmVhZCIsIm9wZW5pZCJdLCJjbGllbnRfaWQiOiJkYXNoYm9hcmQtc3NvLXdkLW1hcmlhZGIiLCJjaWQiOiJkYXNoYm9hcmQtc3NvLXdkLW1hcmlhZGIiLCJncmFudF90eXBlIjoiYXV0aG9yaXphdGlvbl9jb2RlIiwidXNlcl9pZCI6IjEzY2ZlNWEyLTY1ZGYtNDZmYi1iNjRkLWFlZTYzNmVhZDYyZSIsInVzZXJfbmFtZSI6ImFkbWluIiwiZW1haWwiOiJhZG1pbiIsImlhdCI6MTQxMDc2NjExNiwiZXhwIjoxNDEwODA5MzE2LCJpc3MiOiJodHRwczovL3VhYS5wYWFzLmxhYi53ZWJob3N0LmNvLm56L29hdXRoL3Rva2VuIiwiYXVkIjpbImNsb3VkX2NvbnRyb2xsZXJfc2VydmljZV9wZXJtaXNzaW9ucyIsIm9wZW5pZCJdfQ.SJyoU_dS0hFoS1VKisdZHj99P-eV0Q3cvP3-TZh1D8zY_ThdfF3xPpzytFQ0TZku0t3ta8LZnQKjNWh4XCKCT0E4xwz_tCzpBhYBjvb9_RlkZ6okqeX8X0Ub_RPSseVVxofIruksKC2yB6u6ti8R__JGhk7xgTjfqRCnxN-_n_fRe6GlnsPTj64RhDSdA3C753sRKS1zWyHEcMlxgRlKO1_eIfCrzYuX00eH-aKu9LbRzkPvs4phzqCMWsefx_2BckLuEmFV0KPZn2EwPYdJdbrONbVSaadToOK6otNvr1kWCdD1OrMQ-1kCDqgEZrr8pTlALVuvQBA3db3JW31Xzg] as "application/json;charset=utf-8" using [org.springframework.http.converter.json.MappingJacksonHttpMessageConverter@4c206964]
[2014-09-15 07:28:36.989] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- DispatcherServlet: Null ModelAndView returned to DispatcherServlet with name 'spring': assuming HandlerAdapter completed request handling
[2014-09-15 07:28:36.990] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- DispatcherServlet: Successfully completed request
[2014-09-15 07:28:36.990] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- ExceptionTranslationFilter: Chain processed normally
[2014-09-15 07:28:36.990] uaa - 21358 [http-bio-8080-exec-7] .... DEBUG --- SecurityContextPersistenceFilter: SecurityContextHolder now cleared, as request processing completed
[2014-09-15 07:28:37.016] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/resources/**'
[2014-09-15 07:28:37.017] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/favicon.ico'
[2014-09-15 07:28:37.017] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/info'
[2014-09-15 07:28:37.018] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/password/**'
[2014-09-15 07:28:37.018] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/healthz/**'
[2014-09-15 07:28:37.018] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- UaaRequestMatcher: [loginAuthenticateRequestMatcher] Checking match of request : '/userinfo'; '/authenticate' with parameters={} and headers {Authorization=[Bearer ], accept=[application/json]}
[2014-09-15 07:28:37.019] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/authenticate/**'
[2014-09-15 07:28:37.019] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- UaaRequestMatcher: [loginAuthorizeRequestMatcher] Checking match of request : '/userinfo'; '/oauth/authorize' with parameters={source=login} and headers {accept=[application/json]}
[2014-09-15 07:28:37.019] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- UaaRequestMatcher: [loginTokenRequestMatcher] Checking match of request : '/userinfo'; '/oauth/token' with parameters={source=login, grant_type=password, add_new=} and headers {Authorization=[Bearer ], accept=[application/json]}
[2014-09-15 07:28:37.020] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- UaaRequestMatcher: [loginAuthorizeRequestMatcherOld] Checking match of request : '/userinfo'; '/oauth/authorize' with parameters={login={} and headers {accept=[application/json]}
[2014-09-15 07:28:37.020] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/codes/**'
[2014-09-15 07:28:37.020] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/password_*'
[2014-09-15 07:28:37.021] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/create_account'
[2014-09-15 07:28:37.021] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/oauth/token/**'
[2014-09-15 07:28:37.021] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- UaaRequestMatcher: [oauthAuthorizeRequestMatcher] Checking match of request : '/userinfo'; '/oauth/authorize' with parameters={response_type=token, source=credentials} and headers {accept=[application/json, application/x-www-form-urlencoded]}
[2014-09-15 07:28:37.021] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- UaaRequestMatcher: [oauthAuthorizeRequestMatcherOld] Checking match of request : '/userinfo'; '/oauth/authorize' with parameters={response_type=token, credentials={} and headers {accept=[application/json, application/x-www-form-urlencoded]}
[2014-09-15 07:28:37.022] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- UaaRequestMatcher: [groupsUpdateRequestMatcher] Checking match of request : '/userinfo'; '/Groups' with parameters={} and headers {}
[2014-09-15 07:28:37.022] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- UaaRequestMatcher: [groupsReadRequestMatcher] Checking match of request : '/userinfo'; '/Groups' with parameters={} and headers {}
[2014-09-15 07:28:37.022] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/groups/**'
[2014-09-15 07:28:37.023] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/user*/*/password'
[2014-09-15 07:28:37.023] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/users/**'
[2014-09-15 07:28:37.023] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/ids/users*'
[2014-09-15 07:28:37.024] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/approvals/**'
[2014-09-15 07:28:37.024] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/oauth/clients/*/secret'
[2014-09-15 07:28:37.024] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/oauth/clients/tx/**'
[2014-09-15 07:28:37.024] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/oauth/clients/**'
[2014-09-15 07:28:37.025] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/check_token'
[2014-09-15 07:28:37.025] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/token_key'
[2014-09-15 07:28:37.025] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/clientinfo'
[2014-09-15 07:28:37.026] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AntPathRequestMatcher: Checking match of request : '/userinfo'; against '/userinfo'
[2014-09-15 07:28:37.026] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterChainProxy: /userinfo?schema=openid at position 1 of 8 in additional filter chain; firing Filter: 'UaaLoggingFilter'
[2014-09-15 07:28:37.026] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- SecurityFilterChainPostProcessor$UaaLoggingFilter: Filter chain 'userInfoSecurity' processing request GET /userinfo
[2014-09-15 07:28:37.027] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterChainProxy: /userinfo?schema=openid at position 2 of 8 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
[2014-09-15 07:28:37.027] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterChainProxy: /userinfo?schema=openid at position 3 of 8 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
[2014-09-15 07:28:37.027] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterChainProxy: /userinfo?schema=openid at position 4 of 8 in additional filter chain; firing Filter: 'OAuth2AuthenticationProcessingFilter'
[2014-09-15 07:28:37.029] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:37.029] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:37.033] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:37.033] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select client_id, client_secret, resource_ids, scope, authorized_grant_types, web_server_redirect_uri, authorities, access_token_validity, refresh_token_validity, additional_information from oauth_client_details where client_id = ?]
[2014-09-15 07:28:37.036] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- OAuth2AuthenticationProcessingFilter: Authentication success: org.springframework.security.oauth2.provider.OAuth2Authentication@50a1c2df: Principal: org.cloudfoundry.identity.uaa.authentication.UaaPrincipal@13e0e618; Credentials: [PROTECTED]; Authenticated: true; Details: remoteAddress=172.31.202.1, , tokenValue=<TOKEN>; Granted Authorities: uaa.user
[2014-09-15 07:28:37.036] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterChainProxy: /userinfo?schema=openid at position 5 of 8 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
[2014-09-15 07:28:37.036] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterChainProxy: /userinfo?schema=openid at position 6 of 8 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
[2014-09-15 07:28:37.037] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- AnonymousAuthenticationFilter: SecurityContextHolder not populated with anonymous token, as it already contained: 'org.springframework.security.oauth2.provider.OAuth2Authentication@50a1c2df: Principal: org.cloudfoundry.identity.uaa.authentication.UaaPrincipal@13e0e618; Credentials: [PROTECTED]; Authenticated: true; Details: remoteAddress=172.31.202.1, , tokenValue=<TOKEN>; Granted Authorities: uaa.user'
[2014-09-15 07:28:37.037] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterChainProxy: /userinfo?schema=openid at position 7 of 8 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
[2014-09-15 07:28:37.037] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterChainProxy: /userinfo?schema=openid at position 8 of 8 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
[2014-09-15 07:28:37.038] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterSecurityInterceptor: Secure object: FilterInvocation: URL: /userinfo?schema=openid; Attributes: [scope=openid]
[2014-09-15 07:28:37.038] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterSecurityInterceptor: Previously Authenticated: org.springframework.security.oauth2.provider.OAuth2Authentication@50a1c2df: Principal: org.cloudfoundry.identity.uaa.authentication.UaaPrincipal@13e0e618; Credentials: [PROTECTED]; Authenticated: true; Details: remoteAddress=172.31.202.1, , tokenValue=<TOKEN>; Granted Authorities: uaa.user
[2014-09-15 07:28:37.038] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- UnanimousBased: Voter: org.springframework.security.oauth2.provider.vote.ScopeVoter@18567af2, returned: 1
[2014-09-15 07:28:37.039] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- UnanimousBased: Voter: org.springframework.security.access.vote.RoleVoter@55a1b259, returned: 0
[2014-09-15 07:28:37.039] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- UnanimousBased: Voter: org.springframework.security.access.vote.AuthenticatedVoter@6ac41cfa, returned: 0
[2014-09-15 07:28:37.039] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterSecurityInterceptor: Authorization successful
[2014-09-15 07:28:37.039] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterSecurityInterceptor: RunAsManager did not change Authentication object
[2014-09-15 07:28:37.040] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- FilterChainProxy: /userinfo?schema=openid reached end of additional filter chain; proceeding with original chain
[2014-09-15 07:28:37.040] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- DispatcherServlet: DispatcherServlet with name 'spring' processing GET request for [/userinfo]
[2014-09-15 07:28:37.042] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- DispatcherServlet: Last-Modified value for [/userinfo] is: -1
[2014-09-15 07:28:37.043] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:37.043] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select id,username,password,email,givenName,familyName,created,lastModified,authorities,origin,external_id from users where id = ? and active=?]
[2014-09-15 07:28:37.044] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- JdbcTemplate: Executing prepared SQL query
[2014-09-15 07:28:37.045] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select g.displayName from groups g, group_membership m where g.id = m.group_id and m.member_id = ?
]
[2014-09-15 07:28:37.047] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- RequestResponseBodyMethodProcessor: Written [{user_id=13cfe5a2-65df-46fb-b64d-aee636ead62e, user_name=admin, email=admin}] as "application/json;charset=utf-8" using [org.springframework.http.converter.json.MappingJacksonHttpMessageConverter@4c206964]
[2014-09-15 07:28:37.047] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- DispatcherServlet: Null ModelAndView returned to DispatcherServlet with name 'spring': assuming HandlerAdapter completed request handling
[2014-09-15 07:28:37.047] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- DispatcherServlet: Successfully completed request
[2014-09-15 07:28:37.048] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- ExceptionTranslationFilter: Chain processed normally
[2014-09-15 07:28:37.049] uaa - 21358 [http-bio-8080-exec-9] .... DEBUG --- SecurityContextPersistenceFilter: SecurityContextHolder now cleared, as request processing completed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment