You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "Appy (JIRA)" <ji...@apache.org> on 2016/03/06 11:39:43 UTC

[jira] [Updated] (HBASE-15405) Fix PE logging and wrong defaults in help message

     [ https://issues.apache.org/jira/browse/HBASE-15405?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Appy updated HBASE-15405:
-------------------------
    Description: 
Corrects wrong default values for few options in the help message.

Final stats from multiple clients are intermingled making it hard to understand. Also the logged stats aren't very machine readable. It can be helpful in a daily perf testing rig which scraps logs for results.

Example of logs before the change.
{noformat}
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: 0/1048570/1048576, latency mean=953.98, min=359.00, max=324050.00, stdDev=851.82, 95th=1368.00, 99th=1625.00
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: 0/1048570/1048576, latency mean=953.92, min=356.00, max=323394.00, stdDev=817.55, 95th=1370.00, 99th=1618.00
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: 0/1048570/1048576, latency mean=953.98, min=367.00, max=322745.00, stdDev=840.43, 95th=1369.00, 99th=1622.00
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Min      = 375.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Min      = 363.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Avg      = 953.6624126434326
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Avg      = 953.4124526977539
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest StdDev   = 781.3929776087633
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest StdDev   = 742.8027916717297
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 50th     = 894.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 50th     = 894.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 75th     = 1070.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 75th     = 1071.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 95th     = 1369.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 95th     = 1369.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99th     = 1623.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99th     = 1624.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Min      = 372.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.9th   = 3013.9980000000214
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Avg      = 953.2451229095459
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.9th   = 3043.9980000000214
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest StdDev   = 725.4744472152282
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.99th  = 25282.380199996755
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 50th     = 895.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.99th  = 25812.763399994
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 75th     = 1071.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.999th = 89772.78990004538
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 95th     = 1369.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.999th = 122808.39587019826
{noformat}

After the change
{noformat}
16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Test : RandomWriteTest, Thread : TestClient-1
16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Latency (us) : , mean=6.23, min=2.00, max=101433.00, stdDev=246.62, 50th=2.00, 75th=2.00, 95th=3.00, 99th=13.00, 99.9th=558.00, 99.99th=9656.19, 99.999th=20213.63
16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Num measures (latency) : 1048576
16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: ValueSize (bytes) : , mean=0.00, min=0.00, max=0.00, stdDev=0.00, 50th=0.00, 75th=0.00, 95th=0.00, 99th=0.00, 99.9th=0.00, 99.99th=0.00, 99.999th=0.00
16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Num measures (ValueSize): 0
...
16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Test : RandomWriteTest, Thread : TestClient-0
16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Latency (us) : , mean=6.23, min=1.00, max=99321.00, stdDev=246.41, 50th=2.00, 75th=2.00, 95th=3.00, 99th=13.00, 99.9th=566.00, 99.99th=9694.60, 99.999th=23311.86
....
{noformat}

  was:
Corrects wrong default values for few options in the help message.

Final stats from multiple clients are intermingled making it hard to understand. Also the logged stats aren't very machine readable. It can be helpful in a daily perf testing rig which scraps logs for results.

Example of logs before the change.
{noformat}
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: 0/1048570/1048576, latency mean=953.98, min=359.00, max=324050.00, stdDev=851.82, 95th=1368.00, 99th=1625.00
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: 0/1048570/1048576, latency mean=953.92, min=356.00, max=323394.00, stdDev=817.55, 95th=1370.00, 99th=1618.00
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: 0/1048570/1048576, latency mean=953.98, min=367.00, max=322745.00, stdDev=840.43, 95th=1369.00, 99th=1622.00
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Min      = 375.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Min      = 363.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Avg      = 953.6624126434326
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Avg      = 953.4124526977539
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest StdDev   = 781.3929776087633
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest StdDev   = 742.8027916717297
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 50th     = 894.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 50th     = 894.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 75th     = 1070.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 75th     = 1071.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 95th     = 1369.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 95th     = 1369.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99th     = 1623.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99th     = 1624.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Min      = 372.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.9th   = 3013.9980000000214
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Avg      = 953.2451229095459
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.9th   = 3043.9980000000214
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest StdDev   = 725.4744472152282
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.99th  = 25282.380199996755
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 50th     = 895.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.99th  = 25812.763399994
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 75th     = 1071.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.999th = 89772.78990004538
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 95th     = 1369.0
16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.999th = 122808.39587019826
{noformat}


> Fix PE logging and wrong defaults in help message
> -------------------------------------------------
>
>                 Key: HBASE-15405
>                 URL: https://issues.apache.org/jira/browse/HBASE-15405
>             Project: HBase
>          Issue Type: Bug
>          Components: Performance
>            Reporter: Appy
>            Assignee: Appy
>            Priority: Minor
>
> Corrects wrong default values for few options in the help message.
> Final stats from multiple clients are intermingled making it hard to understand. Also the logged stats aren't very machine readable. It can be helpful in a daily perf testing rig which scraps logs for results.
> Example of logs before the change.
> {noformat}
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: 0/1048570/1048576, latency mean=953.98, min=359.00, max=324050.00, stdDev=851.82, 95th=1368.00, 99th=1625.00
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: 0/1048570/1048576, latency mean=953.92, min=356.00, max=323394.00, stdDev=817.55, 95th=1370.00, 99th=1618.00
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: 0/1048570/1048576, latency mean=953.98, min=367.00, max=322745.00, stdDev=840.43, 95th=1369.00, 99th=1622.00
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest latency log (microseconds), on 1048576 measures
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Min      = 375.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Min      = 363.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Avg      = 953.6624126434326
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Avg      = 953.4124526977539
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest StdDev   = 781.3929776087633
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest StdDev   = 742.8027916717297
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 50th     = 894.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 50th     = 894.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 75th     = 1070.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 75th     = 1071.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 95th     = 1369.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 95th     = 1369.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99th     = 1623.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99th     = 1624.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Min      = 372.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.9th   = 3013.9980000000214
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest Avg      = 953.2451229095459
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.9th   = 3043.9980000000214
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest StdDev   = 725.4744472152282
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.99th  = 25282.380199996755
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 50th     = 895.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.99th  = 25812.763399994
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 75th     = 1071.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.999th = 89772.78990004538
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 95th     = 1369.0
> 16/03/05 22:43:06 INFO hbase.PerformanceEvaluation: IncrementTest 99.999th = 122808.39587019826
> {noformat}
> After the change
> {noformat}
> 16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Test : RandomWriteTest, Thread : TestClient-1
> 16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Latency (us) : , mean=6.23, min=2.00, max=101433.00, stdDev=246.62, 50th=2.00, 75th=2.00, 95th=3.00, 99th=13.00, 99.9th=558.00, 99.99th=9656.19, 99.999th=20213.63
> 16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Num measures (latency) : 1048576
> 16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: ValueSize (bytes) : , mean=0.00, min=0.00, max=0.00, stdDev=0.00, 50th=0.00, 75th=0.00, 95th=0.00, 99th=0.00, 99.9th=0.00, 99.99th=0.00, 99.999th=0.00
> 16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Num measures (ValueSize): 0
> ...
> 16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Test : RandomWriteTest, Thread : TestClient-0
> 16/03/06 02:38:21 INFO hbase.PerformanceEvaluation: Latency (us) : , mean=6.23, min=1.00, max=99321.00, stdDev=246.41, 50th=2.00, 75th=2.00, 95th=3.00, 99th=13.00, 99.9th=566.00, 99.99th=9694.60, 99.999th=23311.86
> ....
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)