You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ignite.apache.org by "Ksenia Rybakova (JIRA)" <ji...@apache.org> on 2017/06/21 15:02:00 UTC
[jira] [Updated] (IGNITE-5573) Yardstick: Incorrect actual warmup
and duration when test with pds and many caches
[ https://issues.apache.org/jira/browse/IGNITE-5573?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Ksenia Rybakova updated IGNITE-5573:
------------------------------------
Description:
Load config:
- CacheRandomOperation benchmak
- 5 driver nodes
- 12 server nodes (1 per host)
- 14 phisical caches + 50 groups with 500 logical caches (10 per group)
- preloading amount 10K, key range 20K
- warmup time 300s
- duration 1800s
But according to driver logs actual warmup time and duration are incorrect (or it's just logging problem)
{noformat}
<16:15:35><main><yardstick> Preload logger was started.
...
<16:27:19><main><yardstick> Preload logger was stopped.
<16:27:19><main><yardstick> Probe writer is not configured (using default CSV writer)
<16:27:19><main><yardstick> ThroughputLatencyProbe is started.
<16:27:19><main><yardstick> DStatProbe is started. Command: 'dstat -m --all --noheaders --noupdate 1'
<16:27:19><main><yardstick> PercentileProbe is started.
<16:27:19><main><yardstick> Starting warmup.
...
<17:02:09><benchmark-worker-49><yardstick> Starting main test (warmup finished).
<17:02:09><benchmark-worker-22><yardstick> Starting iteration: 18
<17:02:09><benchmark-worker-59><yardstick> Starting iteration: 10
<17:02:09><benchmark-worker-54><yardstick> Starting iteration: 9
<17:02:09><benchmark-worker-11><yardstick> Starting iteration: 25
<17:02:09><benchmark-worker-33><yardstick> Starting iteration: 27
<17:02:09><benchmark-worker-4><yardstick> Starting iteration: 23
<17:02:09><benchmark-worker-42><yardstick> Starting iteration: 34
<17:02:09><benchmark-worker-35><yardstick> Starting iteration: 36
<17:02:09><benchmark-worker-45><yardstick> Starting iteration: 41
<17:02:09><benchmark-worker-58><yardstick> Starting iteration: 1
<17:02:09><benchmark-worker-12><yardstick> Starting iteration: 44
<17:02:09><benchmark-worker-19><yardstick> Starting iteration: 46
<17:02:09><benchmark-worker-32><yardstick> Starting iteration: 47
<17:02:09><benchmark-worker-9><yardstick> Starting iteration: 48
<17:02:09><benchmark-worker-6><yardstick> Starting iteration: 39
<17:02:09><benchmark-worker-36><yardstick> Starting iteration: 52
<17:02:09><benchmark-worker-47><yardstick> Starting iteration: 54
<17:02:09><benchmark-worker-62><yardstick> Starting iteration: 56
<17:02:09><benchmark-worker-50><yardstick> Starting iteration: 57
<17:02:09><benchmark-worker-56><yardstick> Starting iteration: 58
<17:02:09><benchmark-worker-10><yardstick> Starting iteration: 20
<17:02:09><benchmark-worker-63><yardstick> Starting iteration: 24
<17:02:09><benchmark-worker-3><yardstick> Starting iteration: 59
<17:02:09><benchmark-worker-43><yardstick> Starting iteration: 60
<17:02:09><benchmark-worker-44><yardstick> Starting iteration: 61
<17:02:09><benchmark-worker-28><yardstick> Starting iteration: 62
<17:02:09><benchmark-worker-24><yardstick> Starting iteration: 63
<17:02:09><benchmark-worker-51><yardstick> Starting iteration: 21
<17:02:09><benchmark-worker-38><yardstick> Starting iteration: 22
<17:02:09><benchmark-worker-0><yardstick> Starting iteration: 7
<17:02:09><benchmark-worker-49><yardstick> Starting iteration: 8
<17:02:09><benchmark-worker-27><yardstick> Starting iteration: 5
<17:02:09><benchmark-worker-29><yardstick> Starting iteration: 3
<17:02:09><benchmark-worker-53><yardstick> Starting iteration: 15
<17:02:09><benchmark-worker-31><yardstick> Starting iteration: 2
<17:02:09><benchmark-worker-46><yardstick> Starting iteration: 11
<17:02:09><benchmark-worker-23><yardstick> Starting iteration: 12
<17:02:09><benchmark-worker-52><yardstick> Starting iteration: 4
<17:02:09><benchmark-worker-16><yardstick> Starting iteration: 16
<17:02:09><benchmark-worker-30><yardstick> Starting iteration: 19
<17:02:09><benchmark-worker-57><yardstick> Starting iteration: 6
<17:02:09><benchmark-worker-8><yardstick> Starting iteration: 17
<17:02:09><benchmark-worker-41><yardstick> Starting iteration: 13
<17:02:09><benchmark-worker-7><yardstick> Starting iteration: 14
<17:02:09><benchmark-worker-18><yardstick> Starting iteration: 64
<17:02:09><benchmark-worker-21><yardstick> Starting iteration: 37
<17:02:09><benchmark-worker-15><yardstick> Starting iteration: 55
<17:02:09><benchmark-worker-48><yardstick> Starting iteration: 53
<17:02:09><benchmark-worker-5><yardstick> Starting iteration: 51
<17:02:09><benchmark-worker-39><yardstick> Starting iteration: 50
<17:02:09><benchmark-worker-13><yardstick> Starting iteration: 49
<17:02:09><benchmark-worker-14><yardstick> Starting iteration: 45
<17:02:09><benchmark-worker-40><yardstick> Starting iteration: 38
<17:02:09><benchmark-worker-55><yardstick> Starting iteration: 42
<17:02:09><benchmark-worker-34><yardstick> Starting iteration: 43
<17:02:09><benchmark-worker-2><yardstick> Starting iteration: 40
<17:02:09><benchmark-worker-26><yardstick> Starting iteration: 35
<17:02:09><benchmark-worker-1><yardstick> Starting iteration: 31
<17:02:09><benchmark-worker-61><yardstick> Starting iteration: 32
<17:02:09><benchmark-worker-17><yardstick> Starting iteration: 33
<17:02:09><benchmark-worker-25><yardstick> Starting iteration: 29
<17:02:09><benchmark-worker-37><yardstick> Starting iteration: 30
<17:02:09><benchmark-worker-60><yardstick> Starting iteration: 28
<17:02:09><benchmark-worker-20><yardstick> Starting iteration: 26
<17:02:10><probe-dump-thread><yardstick> ThroughputLatencyProbe results will be saved to: results-20170621-161454/0-172.25.1.31
<17:02:10><probe-dump-thread><yardstick> DStatProbe results will be saved to: results-20170621-161454/0-172.25.1.31
...
Finishing main test [ts=1498054591988, date=Wed Jun 21 17:16:31 MSK 2017]
{noformat}
Also iterations in log are out of order.
was:
Load config:
- CacheRandomOperation benchmak
- 5 driver nodes
- 12 server nodes (1 per host)
- 14 phisical caches + 50 groups with 500 logical caches (10 per group)
- preloading amount 10K, key range 20K
- warmup time 300s
- duration 1800s
But according to driver logs actual warmup time and duration are incorrect (or it's just logging problem)
{noformat}
<16:15:35><main><yardstick> Preload logger was started.
...
<16:27:19><main><yardstick> Preload logger was stopped.
<16:27:19><main><yardstick> Probe writer is not configured (using default CSV writer)
<16:27:19><main><yardstick> ThroughputLatencyProbe is started.
<16:27:19><main><yardstick> DStatProbe is started. Command: 'dstat -m --all --noheaders --noupdate 1'
<16:27:19><main><yardstick> PercentileProbe is started.
<16:27:19><main><yardstick> Starting warmup.
...
<17:02:09><benchmark-worker-49><yardstick> Starting main test (warmup finished).
<17:02:09><benchmark-worker-22><yardstick> Starting iteration: 18
<17:02:09><benchmark-worker-59><yardstick> Starting iteration: 10
<17:02:09><benchmark-worker-54><yardstick> Starting iteration: 9
<17:02:09><benchmark-worker-11><yardstick> Starting iteration: 25
<17:02:09><benchmark-worker-33><yardstick> Starting iteration: 27
<17:02:09><benchmark-worker-4><yardstick> Starting iteration: 23
<17:02:09><benchmark-worker-42><yardstick> Starting iteration: 34
<17:02:09><benchmark-worker-35><yardstick> Starting iteration: 36
<17:02:09><benchmark-worker-45><yardstick> Starting iteration: 41
<17:02:09><benchmark-worker-58><yardstick> Starting iteration: 1
<17:02:09><benchmark-worker-12><yardstick> Starting iteration: 44
<17:02:09><benchmark-worker-19><yardstick> Starting iteration: 46
<17:02:09><benchmark-worker-32><yardstick> Starting iteration: 47
<17:02:09><benchmark-worker-9><yardstick> Starting iteration: 48
<17:02:09><benchmark-worker-6><yardstick> Starting iteration: 39
<17:02:09><benchmark-worker-36><yardstick> Starting iteration: 52
<17:02:09><benchmark-worker-47><yardstick> Starting iteration: 54
<17:02:09><benchmark-worker-62><yardstick> Starting iteration: 56
<17:02:09><benchmark-worker-50><yardstick> Starting iteration: 57
<17:02:09><benchmark-worker-56><yardstick> Starting iteration: 58
<17:02:09><benchmark-worker-10><yardstick> Starting iteration: 20
<17:02:09><benchmark-worker-63><yardstick> Starting iteration: 24
<17:02:09><benchmark-worker-3><yardstick> Starting iteration: 59
<17:02:09><benchmark-worker-43><yardstick> Starting iteration: 60
<17:02:09><benchmark-worker-44><yardstick> Starting iteration: 61
<17:02:09><benchmark-worker-28><yardstick> Starting iteration: 62
<17:02:09><benchmark-worker-24><yardstick> Starting iteration: 63
<17:02:09><benchmark-worker-51><yardstick> Starting iteration: 21
<17:02:09><benchmark-worker-38><yardstick> Starting iteration: 22
<17:02:09><benchmark-worker-0><yardstick> Starting iteration: 7
<17:02:09><benchmark-worker-49><yardstick> Starting iteration: 8
<17:02:09><benchmark-worker-27><yardstick> Starting iteration: 5
<17:02:09><benchmark-worker-29><yardstick> Starting iteration: 3
<17:02:09><benchmark-worker-53><yardstick> Starting iteration: 15
<17:02:09><benchmark-worker-31><yardstick> Starting iteration: 2
<17:02:09><benchmark-worker-46><yardstick> Starting iteration: 11
<17:02:09><benchmark-worker-23><yardstick> Starting iteration: 12
<17:02:09><benchmark-worker-52><yardstick> Starting iteration: 4
<17:02:09><benchmark-worker-16><yardstick> Starting iteration: 16
<17:02:09><benchmark-worker-30><yardstick> Starting iteration: 19
<17:02:09><benchmark-worker-57><yardstick> Starting iteration: 6
<17:02:09><benchmark-worker-8><yardstick> Starting iteration: 17
<17:02:09><benchmark-worker-41><yardstick> Starting iteration: 13
<17:02:09><benchmark-worker-7><yardstick> Starting iteration: 14
<17:02:09><benchmark-worker-18><yardstick> Starting iteration: 64
<17:02:09><benchmark-worker-21><yardstick> Starting iteration: 37
<17:02:09><benchmark-worker-15><yardstick> Starting iteration: 55
<17:02:09><benchmark-worker-48><yardstick> Starting iteration: 53
<17:02:09><benchmark-worker-5><yardstick> Starting iteration: 51
<17:02:09><benchmark-worker-39><yardstick> Starting iteration: 50
<17:02:09><benchmark-worker-13><yardstick> Starting iteration: 49
<17:02:09><benchmark-worker-14><yardstick> Starting iteration: 45
<17:02:09><benchmark-worker-40><yardstick> Starting iteration: 38
<17:02:09><benchmark-worker-55><yardstick> Starting iteration: 42
<17:02:09><benchmark-worker-34><yardstick> Starting iteration: 43
<17:02:09><benchmark-worker-2><yardstick> Starting iteration: 40
<17:02:09><benchmark-worker-26><yardstick> Starting iteration: 35
<17:02:09><benchmark-worker-1><yardstick> Starting iteration: 31
<17:02:09><benchmark-worker-61><yardstick> Starting iteration: 32
<17:02:09><benchmark-worker-17><yardstick> Starting iteration: 33
<17:02:09><benchmark-worker-25><yardstick> Starting iteration: 29
<17:02:09><benchmark-worker-37><yardstick> Starting iteration: 30
<17:02:09><benchmark-worker-60><yardstick> Starting iteration: 28
<17:02:09><benchmark-worker-20><yardstick> Starting iteration: 26
<17:02:10><probe-dump-thread><yardstick> ThroughputLatencyProbe results will be saved to: results-20170621-161454/0-172.25.1.31
<17:02:10><probe-dump-thread><yardstick> DStatProbe results will be saved to: results-20170621-161454/0-172.25.1.31
...
Finishing main test [ts=1498054591988, date=Wed Jun 21 17:16:31 MSK 2017]
{noformat}
> Yardstick: Incorrect actual warmup and duration when test with pds and many caches
> ----------------------------------------------------------------------------------
>
> Key: IGNITE-5573
> URL: https://issues.apache.org/jira/browse/IGNITE-5573
> Project: Ignite
> Issue Type: Bug
> Components: yardstick
> Affects Versions: 2.1
> Reporter: Ksenia Rybakova
>
> Load config:
> - CacheRandomOperation benchmak
> - 5 driver nodes
> - 12 server nodes (1 per host)
> - 14 phisical caches + 50 groups with 500 logical caches (10 per group)
> - preloading amount 10K, key range 20K
> - warmup time 300s
> - duration 1800s
> But according to driver logs actual warmup time and duration are incorrect (or it's just logging problem)
> {noformat}
> <16:15:35><main><yardstick> Preload logger was started.
> ...
> <16:27:19><main><yardstick> Preload logger was stopped.
> <16:27:19><main><yardstick> Probe writer is not configured (using default CSV writer)
> <16:27:19><main><yardstick> ThroughputLatencyProbe is started.
> <16:27:19><main><yardstick> DStatProbe is started. Command: 'dstat -m --all --noheaders --noupdate 1'
> <16:27:19><main><yardstick> PercentileProbe is started.
> <16:27:19><main><yardstick> Starting warmup.
> ...
> <17:02:09><benchmark-worker-49><yardstick> Starting main test (warmup finished).
> <17:02:09><benchmark-worker-22><yardstick> Starting iteration: 18
> <17:02:09><benchmark-worker-59><yardstick> Starting iteration: 10
> <17:02:09><benchmark-worker-54><yardstick> Starting iteration: 9
> <17:02:09><benchmark-worker-11><yardstick> Starting iteration: 25
> <17:02:09><benchmark-worker-33><yardstick> Starting iteration: 27
> <17:02:09><benchmark-worker-4><yardstick> Starting iteration: 23
> <17:02:09><benchmark-worker-42><yardstick> Starting iteration: 34
> <17:02:09><benchmark-worker-35><yardstick> Starting iteration: 36
> <17:02:09><benchmark-worker-45><yardstick> Starting iteration: 41
> <17:02:09><benchmark-worker-58><yardstick> Starting iteration: 1
> <17:02:09><benchmark-worker-12><yardstick> Starting iteration: 44
> <17:02:09><benchmark-worker-19><yardstick> Starting iteration: 46
> <17:02:09><benchmark-worker-32><yardstick> Starting iteration: 47
> <17:02:09><benchmark-worker-9><yardstick> Starting iteration: 48
> <17:02:09><benchmark-worker-6><yardstick> Starting iteration: 39
> <17:02:09><benchmark-worker-36><yardstick> Starting iteration: 52
> <17:02:09><benchmark-worker-47><yardstick> Starting iteration: 54
> <17:02:09><benchmark-worker-62><yardstick> Starting iteration: 56
> <17:02:09><benchmark-worker-50><yardstick> Starting iteration: 57
> <17:02:09><benchmark-worker-56><yardstick> Starting iteration: 58
> <17:02:09><benchmark-worker-10><yardstick> Starting iteration: 20
> <17:02:09><benchmark-worker-63><yardstick> Starting iteration: 24
> <17:02:09><benchmark-worker-3><yardstick> Starting iteration: 59
> <17:02:09><benchmark-worker-43><yardstick> Starting iteration: 60
> <17:02:09><benchmark-worker-44><yardstick> Starting iteration: 61
> <17:02:09><benchmark-worker-28><yardstick> Starting iteration: 62
> <17:02:09><benchmark-worker-24><yardstick> Starting iteration: 63
> <17:02:09><benchmark-worker-51><yardstick> Starting iteration: 21
> <17:02:09><benchmark-worker-38><yardstick> Starting iteration: 22
> <17:02:09><benchmark-worker-0><yardstick> Starting iteration: 7
> <17:02:09><benchmark-worker-49><yardstick> Starting iteration: 8
> <17:02:09><benchmark-worker-27><yardstick> Starting iteration: 5
> <17:02:09><benchmark-worker-29><yardstick> Starting iteration: 3
> <17:02:09><benchmark-worker-53><yardstick> Starting iteration: 15
> <17:02:09><benchmark-worker-31><yardstick> Starting iteration: 2
> <17:02:09><benchmark-worker-46><yardstick> Starting iteration: 11
> <17:02:09><benchmark-worker-23><yardstick> Starting iteration: 12
> <17:02:09><benchmark-worker-52><yardstick> Starting iteration: 4
> <17:02:09><benchmark-worker-16><yardstick> Starting iteration: 16
> <17:02:09><benchmark-worker-30><yardstick> Starting iteration: 19
> <17:02:09><benchmark-worker-57><yardstick> Starting iteration: 6
> <17:02:09><benchmark-worker-8><yardstick> Starting iteration: 17
> <17:02:09><benchmark-worker-41><yardstick> Starting iteration: 13
> <17:02:09><benchmark-worker-7><yardstick> Starting iteration: 14
> <17:02:09><benchmark-worker-18><yardstick> Starting iteration: 64
> <17:02:09><benchmark-worker-21><yardstick> Starting iteration: 37
> <17:02:09><benchmark-worker-15><yardstick> Starting iteration: 55
> <17:02:09><benchmark-worker-48><yardstick> Starting iteration: 53
> <17:02:09><benchmark-worker-5><yardstick> Starting iteration: 51
> <17:02:09><benchmark-worker-39><yardstick> Starting iteration: 50
> <17:02:09><benchmark-worker-13><yardstick> Starting iteration: 49
> <17:02:09><benchmark-worker-14><yardstick> Starting iteration: 45
> <17:02:09><benchmark-worker-40><yardstick> Starting iteration: 38
> <17:02:09><benchmark-worker-55><yardstick> Starting iteration: 42
> <17:02:09><benchmark-worker-34><yardstick> Starting iteration: 43
> <17:02:09><benchmark-worker-2><yardstick> Starting iteration: 40
> <17:02:09><benchmark-worker-26><yardstick> Starting iteration: 35
> <17:02:09><benchmark-worker-1><yardstick> Starting iteration: 31
> <17:02:09><benchmark-worker-61><yardstick> Starting iteration: 32
> <17:02:09><benchmark-worker-17><yardstick> Starting iteration: 33
> <17:02:09><benchmark-worker-25><yardstick> Starting iteration: 29
> <17:02:09><benchmark-worker-37><yardstick> Starting iteration: 30
> <17:02:09><benchmark-worker-60><yardstick> Starting iteration: 28
> <17:02:09><benchmark-worker-20><yardstick> Starting iteration: 26
> <17:02:10><probe-dump-thread><yardstick> ThroughputLatencyProbe results will be saved to: results-20170621-161454/0-172.25.1.31
> <17:02:10><probe-dump-thread><yardstick> DStatProbe results will be saved to: results-20170621-161454/0-172.25.1.31
> ...
> Finishing main test [ts=1498054591988, date=Wed Jun 21 17:16:31 MSK 2017]
> {noformat}
> Also iterations in log are out of order.
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)