Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,527 655550 [qtp1589228348-31] INFO org.openrepose.powerfilter.PowerFilter.trace-id-logging - Tracing header: {"requestId":"f863f80f-914d-4c01-a579-648673206a96","origin":null}
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,533 655556 [qtp1589228348-31] DEBUG org.apache.http.impl.conn.PoolingClientConnectionManager - Connection request: [route: {}->http://localhost:8000][total kept alive: 0; route allocated: 0 of 200; total allocated: 0 of 400]
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,534 655557 [qtp1589228348-31] DEBUG org.apache.http.impl.conn.PoolingClientConnectionManager - Connection leased: [id: 2][route: {}->http://localhost:8000][total kept alive: 0; route allocated: 1 of 200; total allocated: 1 of 400]
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,534 655557 [qtp1589228348-31] DEBUG org.apache.http.impl.conn.DefaultClientConnectionOperator - Connecting to localhost:8000
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,535 655558 [qtp1589228348-31] DEBUG org.apache.http.client.protocol.RequestAddCookies - CookieSpec selected: ignoreCookies
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,535 655558 [qtp1589228348-31] DEBUG org.apache.http.client.protocol.RequestAuthCache - Auth cache not set in the context
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,535 655558 [qtp1589228348-31] DEBUG org.apache.http.client.protocol.RequestTargetAuthentication - Target auth state: UNCHALLENGED
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,536 655559 [qtp1589228348-31] DEBUG org.apache.http.client.protocol.RequestProxyAuthentication - Proxy auth state: UNCHALLENGED
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,536 655559 [qtp1589228348-31] DEBUG org.apache.http.impl.client.DefaultHttpClient - Attempt 1 to execute request
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,536 655559 [qtp1589228348-31] DEBUG org.apache.http.impl.conn.DefaultClientConnection - Sending request: POST /post HTTP/1.1
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,536 655559 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "POST /post HTTP/1.1[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,537 655560 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "via: 1.1 localhost:8080 (Repose/7.2.2.0)[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,537 655560 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "x-forwarded-for: 0:0:0:0:0:0:0:1[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,537 655560 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "Host: localhost:8000[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,537 655560 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "x-pp-user: repose_user[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,538 655561 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "x-trans-id: eyJyZXF1ZXN0SWQiOiJmODYzZjgwZi05MTRkLTRjMDEtYTU3OS02NDg2NzMyMDZhOTYiLCJvcmlnaW4iOm51bGx9[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,538 655561 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "Accept-Encoding: gzip[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,538 655561 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "Accept-Encoding: deflate[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,538 655561 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "User-Agent: HTTPie/0.9.2[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,538 655561 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "Accept: application/json[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,539 655562 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "Content-Type: application/json[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,539 655562 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "Content-Length: 17[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,539 655562 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "Connection: Keep-Alive[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,539 655562 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,540 655563 [qtp1589228348-31] DEBUG org.apache.http.headers - >> POST /post HTTP/1.1
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,540 655563 [qtp1589228348-31] DEBUG org.apache.http.headers - >> via: 1.1 localhost:8080 (Repose/7.2.2.0)
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,540 655563 [qtp1589228348-31] DEBUG org.apache.http.headers - >> x-forwarded-for: 0:0:0:0:0:0:0:1
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,540 655563 [qtp1589228348-31] DEBUG org.apache.http.headers - >> Host: localhost:8000
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,540 655563 [qtp1589228348-31] DEBUG org.apache.http.headers - >> x-pp-user: repose_user
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,540 655563 [qtp1589228348-31] DEBUG org.apache.http.headers - >> x-trans-id: eyJyZXF1ZXN0SWQiOiJmODYzZjgwZi05MTRkLTRjMDEtYTU3OS02NDg2NzMyMDZhOTYiLCJvcmlnaW4iOm51bGx9
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,540 655563 [qtp1589228348-31] DEBUG org.apache.http.headers - >> Accept-Encoding: gzip
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,541 655564 [qtp1589228348-31] DEBUG org.apache.http.headers - >> Accept-Encoding: deflate
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,541 655564 [qtp1589228348-31] DEBUG org.apache.http.headers - >> User-Agent: HTTPie/0.9.2
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,541 655564 [qtp1589228348-31] DEBUG org.apache.http.headers - >> Accept: application/json
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,541 655564 [qtp1589228348-31] DEBUG org.apache.http.headers - >> Content-Type: application/json
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,541 655564 [qtp1589228348-31] DEBUG org.apache.http.headers - >> Content-Length: 17
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,541 655564 [qtp1589228348-31] DEBUG org.apache.http.headers - >> Connection: Keep-Alive
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,542 655565 [qtp1589228348-31] DEBUG org.apache.http.wire - >> "{"server": "bob"}"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,543 655566 [qtp1589228348-31] DEBUG org.apache.http.wire - << "HTTP/1.1 200 OK[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,544 655567 [qtp1589228348-31] DEBUG org.apache.http.wire - << "Server: gunicorn/19.4.1[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,544 655567 [qtp1589228348-31] DEBUG org.apache.http.wire - << "Date: Fri, 04 Dec 2015 17:10:57 GMT[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,544 655567 [qtp1589228348-31] DEBUG org.apache.http.wire - << "Connection: close[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,544 655567 [qtp1589228348-31] DEBUG org.apache.http.wire - << "Content-Type: application/json[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,544 655567 [qtp1589228348-31] DEBUG org.apache.http.wire - << "Content-Length: 652[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,545 655568 [qtp1589228348-31] DEBUG org.apache.http.wire - << "Access-Control-Allow-Origin: *[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,545 655568 [qtp1589228348-31] DEBUG org.apache.http.wire - << "Access-Control-Allow-Credentials: true[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,545 655568 [qtp1589228348-31] DEBUG org.apache.http.wire - << "[\r][\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,545 655568 [qtp1589228348-31] DEBUG org.apache.http.impl.conn.DefaultClientConnection - Receiving response: HTTP/1.1 200 OK
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,545 655568 [qtp1589228348-31] DEBUG org.apache.http.headers - << HTTP/1.1 200 OK
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,545 655568 [qtp1589228348-31] DEBUG org.apache.http.headers - << Server: gunicorn/19.4.1
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,546 655569 [qtp1589228348-31] DEBUG org.apache.http.headers - << Date: Fri, 04 Dec 2015 17:10:57 GMT
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,546 655569 [qtp1589228348-31] DEBUG org.apache.http.headers - << Connection: close
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,546 655569 [qtp1589228348-31] DEBUG org.apache.http.headers - << Content-Type: application/json
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,546 655569 [qtp1589228348-31] DEBUG org.apache.http.headers - << Content-Length: 652
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,546 655569 [qtp1589228348-31] DEBUG org.apache.http.headers - << Access-Control-Allow-Origin: *
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,546 655569 [qtp1589228348-31] DEBUG org.apache.http.headers - << Access-Control-Allow-Credentials: true
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,547 655570 [qtp1589228348-31] DEBUG org.apache.http.wire - << "{[\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,547 655570 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "args": {}, [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,548 655571 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "data": "{\"server\": \"bob\"}", [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,548 655571 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "files": {}, [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,548 655571 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "form": {}, [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,548 655571 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "headers": {[\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,548 655571 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "Accept": "application/json", [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,548 655571 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "Accept-Encoding": "gzip,deflate", [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,549 655572 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "Connection": "Keep-Alive", [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,549 655572 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "Content-Length": "17", [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,549 655572 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "Content-Type": "application/json", [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,549 655572 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "Host": "localhost:8000", [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,549 655572 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "User-Agent": "HTTPie/0.9.2", [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,549 655572 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "Via": "1.1 localhost:8080 (Repose/7.2.2.0)", [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,550 655573 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "X-Pp-User": "repose_user", [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,550 655573 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "X-Trans-Id": "eyJyZXF1ZXN0SWQiOiJmODYzZjgwZi05MTRkLTRjMDEtYTU3OS02NDg2NzMyMDZhOTYiLCJvcmlnaW4iOm51bGx9"[\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,550 655573 [qtp1589228348-31] DEBUG org.apache.http.wire - << " }, [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,550 655573 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "json": {[\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,551 655574 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "server": "bob"[\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,551 655574 [qtp1589228348-31] DEBUG org.apache.http.wire - << " }, [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,551 655574 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "origin": "0:0:0:0:0:0:0:1", [\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,551 655574 [qtp1589228348-31] DEBUG org.apache.http.wire - << " "url": "http://localhost:8000/post"[\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,551 655574 [qtp1589228348-31] DEBUG org.apache.http.wire - << "}[\n]"
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,552 655575 [qtp1589228348-31] DEBUG org.apache.http.impl.conn.DefaultClientConnection - Connection 0.0.0.0:60510<->127.0.0.1:8000 closed
Trans-Id:f863f80f-914d-4c01-a579-648673206a96 - 2015-12-04 11:10:57,552 655575 [qtp1589228348-31] DEBUG org.apache.http.impl.conn.PoolingClientConnectionManager - Connection released: [id: 2][route: {}->http://localhost:8000][total kept alive: 0; route allocated: 0 of 200; total allocated: 0 of 400]