[
https://issues.apache.org/jira/browse/KNOX-1091?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16364296#comment-16364296
]
Kevin Risden commented on KNOX-1091:
------------------------------------
Knox 1.0.0 following the exact same steps as above reproduces the duplicate
correlation ids.
Here is some example output from the Knox 1.0.0 run:
*1 concurrent request*
{noformat}
[knox-1.0.0]$ >logs/gateway-audit.log
[knox-1.0.0]$ ab -n 1000 -c 1
http://localhost:8443/gateway/health/api/v1/version
This is ApacheBench, Version 2.3 <$Revision: 1430300 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/
Benchmarking localhost (be patient)
Completed 100 requests
Completed 200 requests
Completed 300 requests
Completed 400 requests
Completed 500 requests
Completed 600 requests
Completed 700 requests
Completed 800 requests
Completed 900 requests
Completed 1000 requests
Finished 1000 requests
Server Software: Jetty(9.2.15.v20160210)
Server Hostname: localhost
Server Port: 8443
Document Path: /gateway/health/api/v1/version
Document Length: 157 bytes
Concurrency Level: 1
Time taken for tests: 2.225 seconds
Complete requests: 1000
Failed requests: 0
Write errors: 0
Total transferred: 298000 bytes
HTML transferred: 157000 bytes
Requests per second: 449.37 [#/sec] (mean)
Time per request: 2.225 [ms] (mean)
Time per request: 2.225 [ms] (mean, across all concurrent requests)
Transfer rate: 130.77 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.0 0 0
Processing: 1 2 1.2 2 34
Waiting: 1 2 1.2 2 34
Total: 1 2 1.2 2 34
Percentage of the requests served within a certain time (ms)
50% 2
66% 2
75% 3
80% 3
90% 3
95% 3
98% 4
99% 4
100% 34 (longest request)
[knox-1.0.0]$ grep -F access logs/gateway-audit.log | cut -d'|' -f3 | sort |
uniq -c | sort -n | wc -l
1000
[knox-1.0.0]$
[knox-1.0.0]$ grep -F access logs/gateway-audit.log | cut -d'|' -f3 | sort |
uniq -c | sort -n | tail -n5
2 fe31ec1a-46a7-4e16-ab8f-77851ad8bb26
2 fed3c318-a93b-4ffc-b34c-ed6a6e08b307
2 ffc9feb8-b828-4094-9075-81e6386ac7db
2 fff51220-080e-4cba-8155-38c6aa473d78
2 fffe9e58-4b2d-4be2-b612-dad93eec7a2e
{noformat}
*100 concurrent requests*
{noformat}
[knox-1.0.0]$ >logs/gateway-audit.log
[knox-1.0.0]$ ab -n 1000 -c 100
http://localhost:8443/gateway/health/api/v1/version
This is ApacheBench, Version 2.3 <$Revision: 1430300 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/
Benchmarking localhost (be patient)
Completed 100 requests
Completed 200 requests
Completed 300 requests
Completed 400 requests
Completed 500 requests
Completed 600 requests
Completed 700 requests
Completed 800 requests
Completed 900 requests
Completed 1000 requests
Finished 1000 requests
Server Software: Jetty(9.2.15.v20160210)
Server Hostname: localhost
Server Port: 8443
Document Path: /gateway/health/api/v1/version
Document Length: 157 bytes
Concurrency Level: 100
Time taken for tests: 0.440 seconds
Complete requests: 1000
Failed requests: 0
Write errors: 0
Total transferred: 298000 bytes
HTML transferred: 157000 bytes
Requests per second: 2271.74 [#/sec] (mean)
Time per request: 44.019 [ms] (mean)
Time per request: 0.440 [ms] (mean, across all concurrent requests)
Transfer rate: 661.11 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.6 0 3
Processing: 3 41 25.9 32 201
Waiting: 2 41 25.9 31 201
Total: 5 41 25.8 32 201
Percentage of the requests served within a certain time (ms)
50% 32
66% 45
75% 51
80% 57
90% 81
95% 102
98% 112
99% 116
100% 201 (longest request)
[knox-1.0.0]$ grep -F access logs/gateway-audit.log | cut -d'|' -f3 | sort |
uniq -c | sort -n | wc -l
789
[knox-1.0.0]$ grep -F access logs/gateway-audit.log | cut -d'|' -f3 | sort |
uniq -c | sort -n | tail -n5
8 a781630c-93b8-48c2-a6fd-aaa428a6bf14
8 f0ab4c10-0dc7-41ef-a27a-9aebe9c8ce58
9 985df820-a82c-4704-b773-016769413cc2
43 b46b3f23-5514-401c-bfee-440790e54b31
95 73e77c01-054b-4063-8fd2-c1a3cabdfe4c{noformat}
> Knox Audit Logging - duplicate correlation ids
> ----------------------------------------------
>
> Key: KNOX-1091
> URL: https://issues.apache.org/jira/browse/KNOX-1091
> Project: Apache Knox
> Issue Type: Bug
> Components: Server
> Reporter: Kevin Risden
> Priority: Major
>
> From the Knox User list thread: "Multiple topology audit logging", it came to
> my attention that Knox seems to be logging duplicate correlation ids.
> Separating out the topic specifically here to dig a bit deeper.
> While looking at our Knox audit logs (Knox 0.9 on HDP 2.5) the "correlation
> id" doesn't seem to be unique across requests. Is this to be expected? Here
> is a snippet (anonymized):
> grep 7557c91b-2a48-4e09-aefc-44e9892372da /var/knox/gateway-audit.log
> {code}
> 17/10/10 12:50:09
> ||7557c91b-2a48-4e09-aefc-44e9892372da|audit|WEBHBASE||||access|uri|/gateway/HADOOPTEST/hbase/hbase/NAMESPACE1:TABLE1/ID1//|unavailable|Request
> method: GET
> 17/10/10 12:50:09
> ||7557c91b-2a48-4e09-aefc-44e9892372da|audit|WEBHBASE|USER1|||authentication|uri|/gateway/HADOOPPROD/hbase/NAMESPACE2:TABLE2/multiget?row=ID2%2fd%3araw&|success|
> 17/10/10 12:50:09
> ||7557c91b-2a48-4e09-aefc-44e9892372da|audit|WEBHBASE|USER1|||authentication|uri|/gateway/HADOOPPROD/hbase/NAMESPACE2:TABLE2/multiget?row=ID2%2fd%3araw&|success|Groups:
> []
> 17/10/10 12:50:09
> ||7557c91b-2a48-4e09-aefc-44e9892372da|audit|WEBHBASE|USER1|||dispatch|uri|http://WEBHBASE.example.com:8084/NAMESPACE2:TABLE2/multiget?doAs=USER1&row=ID2%2Fd%3Araw|unavailable|Request
> method: GET
> 17/10/10 12:50:09
> ||7557c91b-2a48-4e09-aefc-44e9892372da|audit|WEBHBASE|USER1|||dispatch|uri|http://WEBHBASE.example.com:8084/NAMESPACE2:TABLE2/multiget?doAs=USER1&row=ID2%2Fd%3Araw|success|Response
> status: 200
> 17/10/10 12:50:09
> ||7557c91b-2a48-4e09-aefc-44e9892372da|audit|WEBHBASE|USER1|||access|uri|/gateway/HADOOPPROD/hbase/NAMESPACE2:TABLE2/multiget?row=ID2%2fd%3araw&|success|Response
> status: 200
> 17/10/10 12:50:09
> ||7557c91b-2a48-4e09-aefc-44e9892372da|audit|WEBHBASE||||authentication|principal|USER2|failure|LDAP
> authentication failed.
> 17/10/10 12:50:09
> ||7557c91b-2a48-4e09-aefc-44e9892372da|audit|WEBHBASE||||access|uri|/gateway/HADOOPTEST/hbase/hbase/NAMESPACE1:TABLE2/ID1//|success|Response
> status: 401
> {code}
> The things to highlight here for the same correlation id:
> * different topologies are being used
> * different uris are being used
> * different users are being used
> Some of the things that we have configured that could impact results:
> * authentication caching
> * multiple Knox servers
> * load balancer in front of Knox
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
