Skip to content

N
neoppod
Commit 14110668 authored by Kirill Smelkov's avatar Kirill Smelkov
Browse files
Options

X time on z6001 (localhost) 

Seems to be similar to localhost on neo1.
parent 6ec740c1
Hide whitespace changes
Inline Side-by-side
Showing with 346 additions and 0 deletions
go/time-soct04-z6001.txt 0 → 100644
View file @ 14110668
>>> bench-local
# Wed, 04 Oct 2017 18:10:30 +0300
# neotest@z6001.ivan.nexedi.com (2401:5180:0:6f::1)
# Linux COMP-2784-z6001 4.10.0-35-generic #39~16.04.1-Ubuntu SMP Wed Sep 13 09:02:42 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
# cpu: Intel(R) Xeon(R) CPU X5650 @ 2.67GHz
# cpu[0-23]: freq: acpi-cpufreq/performance [1.59GHz - 2.66GHz]
# cpu[0-23]: idle: intel_idle/menu: POLL(0μs) C1-NHM(3μs) C1E-NHM(10μs) C3-NHM(20μs) C6-NHM(200μs)
# cpu: WARNING: frequency not fixed - benchmark timings won't be stable
# cpu: WARNING: C-state exit-latency is max 200μs - that can add to networked request-reply latency (?)
# sda: ADATA SU800 rev 8BS 119,2G
# enp1s0: Broadcom Corporation NetXtreme BCM5764M Gigabit Ethernet PCIe rev 10 (rxc: 20μs/5f/0μs-irq/5f-irq txc: 72μs/53f/0μs-irq/5f-irq)
# enp1s0: WARNING: RX coalesce latency is max 20μs - that will add to networked request-reply latency
# Python 2.7.12
# go version go1.9 linux/amd64
# sqlite 3.11.0 (py mod 2.6.0)
# mysqld Ver 10.1.25-MariaDB-1 for debian-linux-gnu on x86_64 (Ubuntu 17.10)
# neo : v1.8-1238-g6ec740c
# zodb : 5.3.0
# zeo : 5.1.0
# mysqlclient : 1.3.12
# wendelin.core : 0.11
*** random direct (no kernel cache) 4K-read disk latency
--- . (ext4 /dev/sda1) ioping statistics ---
21.6 k requests completed in 2.97 s, 84.4 MiB read, 7.28 k iops, 28.4 MiB/s
generated 21.6 k requests in 3.00 s, 84.4 MiB, 7.20 k iops, 28.1 MiB/s
min/avg/max/mdev = 125.8 us / 137.4 us / 215.3 us / 13.3 us
< 125.8 us 0 |
< 130.3 us 13665 | *******************************
< 134.8 us 121 |
< 139.2 us 46 |
< 143.7 us 9 |
< 148.2 us 174 |
< 152.7 us 716 | *
< 157.1 us 6220 | **************
< 161.6 us 490 | *
< 166.1 us 25 |
< 170.6 us 28 |
< 175.0 us 12 |
< 179.5 us 1 |
< 184.0 us 1 |
< 188.4 us 1 |
< 192.9 us 0 |
< 197.4 us 1 |
< 201.9 us 2 |
< 206.3 us 2 |
< 210.8 us 0 |
< 215.3 us 0 |
< +∞ 0 |
--- . (ext4 /dev/sda1) ioping statistics ---
23.7 k requests completed in 2.97 s, 92.4 MiB read, 7.96 k iops, 31.1 MiB/s
generated 23.7 k requests in 3.00 s, 92.4 MiB, 7.89 k iops, 30.8 MiB/s
min/avg/max/mdev = 122.8 us / 125.6 us / 237.1 us / 2.61 us
< 124.1 us 217 |
< 126.8 us 19824 | *****************************************
< 129.6 us 3387 | *******
< 132.4 us 11 |
< 135.2 us 48 |
< 137.9 us 14 |
< 140.7 us 2 |
< 143.5 us 3 |
< 146.3 us 2 |
< 149.0 us 0 |
< 151.8 us 1 |
< 154.6 us 1 |
< 157.4 us 2 |
< 160.1 us 1 |
< 162.9 us 3 |
< 165.7 us 9 |
< 168.5 us 15 |
< 171.2 us 1 |
< 174.0 us 2 |
< 176.8 us 3 |
< 179.6 us 9 |
< +∞ 7 |
--- . (ext4 /dev/sda1) ioping statistics ---
19.8 k requests completed in 2.96 s, 77.3 MiB read, 6.68 k iops, 26.1 MiB/s
generated 19.8 k requests in 3.00 s, 77.3 MiB, 6.60 k iops, 25.8 MiB/s
min/avg/max/mdev = 122.5 us / 149.8 us / 247.8 us / 9.76 us
< 122.6 us 4 |
< 124.6 us 1137 | **
< 126.5 us 733 | *
< 128.5 us 139 |
< 130.4 us 5 |
< 132.4 us 16 |
< 134.3 us 399 | *
< 136.3 us 260 |
< 138.3 us 19 |
< 140.2 us 2 |
< 142.2 us 4 |
< 144.1 us 77 |
< 146.1 us 27 |
< 148.0 us 136 |
< 150.0 us 164 |
< 152.0 us 2027 | *****
< 153.9 us 9891 | ************************
< 155.9 us 2404 | ******
< 157.8 us 1653 | ****
< 159.8 us 423 | *
< 161.7 us 40 |
< +∞ 131 |
--- . (ext4 /dev/sda1) ioping statistics ---
19.4 k requests completed in 2.96 s, 75.6 MiB read, 6.53 k iops, 25.5 MiB/s
generated 19.4 k requests in 3.00 s, 75.6 MiB, 6.45 k iops, 25.2 MiB/s
min/avg/max/mdev = 124.6 us / 153.1 us / 835.0 us / 8.90 us
< 124.6 us 0 |
< 129.9 us 53 |
< 135.2 us 63 |
< 140.5 us 32 |
< 145.8 us 562 | *
< 151.1 us 2180 | *****
< 156.4 us 13375 | **********************************
< 161.7 us 2728 | *******
< 167.0 us 81 |
< 172.3 us 39 |
< 177.7 us 9 |
< 183.0 us 12 |
< 188.3 us 21 |
< 193.6 us 8 |
< 198.9 us 26 |
< 204.2 us 40 |
< 209.5 us 10 |
< 214.8 us 1 |
< 220.1 us 0 |
< 225.4 us 0 |
< 230.7 us 6 |
< +∞ 13 |
*** random cached 4K-read disk latency
--- . (ext4 /dev/sda1) ioping statistics ---
2.58 M requests completed in 2.80 s, 9.83 GiB read, 920.8 k iops, 3.51 GiB/s
generated 2.58 M requests in 3.00 s, 9.83 GiB, 858.6 k iops, 3.28 GiB/s
min/avg/max/mdev = 406 ns / 1.09 us / 145.9 us / 371 ns
< 690 ns 18627 |
< 887 ns 317384 | ******
< 1.08 us 929536 | ******************
< 1.28 us 1047638 | ********************
< 1.48 us 246334 | ****
< 1.68 us 13387 |
< 1.88 us 1502 |
< 2.08 us 499 |
< 2.27 us 48 |
< 2.47 us 7 |
< 2.67 us 1 |
< 2.87 us 0 |
< 3.06 us 2 |
< 3.26 us 1 |
< 3.46 us 1 |
< 3.66 us 1 |
< 3.86 us 0 |
< 4.05 us 5 |
< 4.25 us 4 |
< 4.45 us 5 |
< 4.65 us 4 |
< +∞ 713 |
--- . (ext4 /dev/sda1) ioping statistics ---
2.57 M requests completed in 2.80 s, 9.81 GiB read, 919.6 k iops, 3.51 GiB/s
generated 2.57 M requests in 3.00 s, 9.81 GiB, 857.5 k iops, 3.27 GiB/s
min/avg/max/mdev = 399 ns / 1.09 us / 94.9 us / 363 ns
< 693 ns 18711 |
< 901 ns 356996 | ******
< 1.11 us 1045960 | ********************
< 1.32 us 975905 | ******************
< 1.53 us 164748 | ***
< 1.74 us 7744 |
< 1.95 us 1224 |
< 2.15 us 301 |
< 2.36 us 20 |
< 2.57 us 10 |
< 2.78 us 10 |
< 2.99 us 5 |
< 3.20 us 1 |
< 3.41 us 1 |
< 3.61 us 1 |
< 3.82 us 0 |
< 4.03 us 11 |
< 4.24 us 12 |
< 4.45 us 19 |
< 4.66 us 16 |
< 4.87 us 4 |
< +∞ 731 |
--- . (ext4 /dev/sda1) ioping statistics ---
2.56 M requests completed in 2.80 s, 9.76 GiB read, 914.7 k iops, 3.49 GiB/s
generated 2.56 M requests in 3.00 s, 9.76 GiB, 853.3 k iops, 3.25 GiB/s
min/avg/max/mdev = 397 ns / 1.09 us / 72.2 us / 349 ns
< 880 ns 285220 | *****
< 1.07 us 846529 | ****************
< 1.26 us 1058984 | ********************
< 1.45 us 340287 | ******
< 1.63 us 24423 |
< 1.82 us 1967 |
< 2.01 us 710 |
< 2.20 us 643 |
< 2.39 us 172 |
< 2.58 us 11 |
< 2.77 us 10 |
< 2.96 us 9 |
< 3.14 us 5 |
< 3.33 us 2 |
< 3.52 us 4 |
< 3.71 us 6 |
< 3.90 us 2 |
< 4.09 us 7 |
< 4.28 us 10 |
< 4.46 us 8 |
< 4.65 us 5 |
< +∞ 702 |
--- . (ext4 /dev/sda1) ioping statistics ---
2.57 M requests completed in 2.80 s, 9.81 GiB read, 918.9 k iops, 3.51 GiB/s
generated 2.57 M requests in 3.00 s, 9.81 GiB, 857.3 k iops, 3.27 GiB/s
min/avg/max/mdev = 399 ns / 1.09 us / 122.9 us / 358 ns
< 916 ns 424751 | ********
< 1.12 us 1066418 | ********************
< 1.33 us 930007 | ******************
< 1.54 us 142379 | **
< 1.75 us 6036 |
< 1.95 us 1081 |
< 2.16 us 256 |
< 2.37 us 23 |
< 2.58 us 2 |
< 2.78 us 1 |
< 2.99 us 1 |
< 3.20 us 2 |
< 3.40 us 4 |
< 3.61 us 0 |
< 3.82 us 1 |
< 4.03 us 1 |
< 4.23 us 2 |
< 4.44 us 1 |
< 4.65 us 1 |
< 4.86 us 0 |
< 5.06 us 0 |
< +∞ 697 |
*** generating fs1 data...
I: RAM: 7.77GB
I: WORK: 0.03GB
gen signal t=0...4.19e+06 float64 (= 0.03GB)
gen signal blk [0:4194304] (100.0%)
VIRT: 1117 MB RSS: 68MB
*** generating sqlite data...
I: RAM: 7.77GB
I: WORK: 0.03GB
gen signal t=0...4.19e+06 float64 (= 0.03GB)
gen signal blk [0:4194304] (100.0%)
VIRT: 1223 MB RSS: 92MB
2017-10-04 18:11:20.0465 ERROR NEO [ app: 91] primary master is down
Cluster state changed
*** generating sql data...
2017-10-04 18:11:20 140071505950976 [Note] /usr/sbin/mysqld (mysqld 10.1.25-MariaDB-1) starting as process 26117 ...
2017-10-04 18:11:23 140016386541824 [Note] /usr/sbin/mysqld (mysqld 10.1.25-MariaDB-1) starting as process 26150 ...
2017-10-04 18:11:26 140090151004416 [Note] /usr/sbin/mysqld (mysqld 10.1.25-MariaDB-1) starting as process 26179 ...
2017-10-04 18:11:29 139657664948480 [Note] mysqld (mysqld 10.1.25-MariaDB-1) starting as process 26211 ...
I: RAM: 7.77GB
I: WORK: 0.03GB
gen signal t=0...4.19e+06 float64 (= 0.03GB)
gen signal blk [0:4194304] (100.0%)
VIRT: 1236 MB RSS: 104MB
2017-10-04 18:11:40.8228 ERROR NEO [ app: 91] primary master is down
Cluster state changed
*** FileStorage
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=0.294s (34.6μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=0.330s (38.8μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=0.332s (39.1μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=0.329s (38.7μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=32.346154ms (3.805µs / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=32.186793ms (3.786µs / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=33.364371ms (3.925µs / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=32.24541ms (3.793µs / object) x=zhash.go
*** ZEO
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=5.323s (626.2μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=5.468s (643.3μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=5.343s (628.5μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=5.322s (626.2μs / object) x=zhash.py
(skipping zhash.go on ZEO -- Cgo does not support zeo:// protocol)
*** NEO/py sqlite
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=6.539s (769.3μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=5.475s (644.1μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=6.542s (769.7μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=6.712s (789.7μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=4.217965775s (496.231µs / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=4.265558246s (501.83µs / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=4.326820672s (509.037µs / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=4.235854236s (498.335µs / object) x=zhash.go
2017-10-04 18:12:53.4252 ERROR NEO [ app: 91] primary master is down
Cluster state changed
*** NEO/py sql
2017-10-04 18:12:53 140345656494336 [Note] mysqld (mysqld 10.1.25-MariaDB-1) starting as process 26656 ...
2017-10-04 18:12:54.8080 ERROR NEO [ app:233] Connection to None lost
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=12.549s (1476.4μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=12.049s (1417.6μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=12.425s (1461.7μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=12.405s (1459.4μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=8.089297003s (951.682µs / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=9.062227561s (1.066144ms / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=9.006447209s (1.059582ms / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=8.320841691s (978.922µs / object) x=zhash.go
2017-10-04 18:14:21.1097 ERROR NEO [ app: 91] primary master is down
Cluster state changed
*** NEO/go
2017-10-04 18:14:23.9592 ERROR NEO [ app:233] Connection to None lost
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=3.250s (382.3μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=4.438s (522.1μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=4.296s (505.4μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=4.867s (572.6μs / object) x=zhash.py
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=761.556647ms (89.594µs / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=760.632097ms (89.486µs / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=723.405593ms (85.106µs / object) x=zhash.go
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=758.319712ms (89.214µs / object) x=zhash.go
E1004 18:14:46.197261 27059 storage.go:120] storage([2401:5180:0:6f::1]:5554): accept: accept tcp [2401:5180:0:6f::1]:5554: use of closed network connection
2017/10/04 18:14:46 talk master([2401:5180:0:6f::1]:5552): context canceled
2017-10-04 18:14:46.1917 ERROR NEO [ app: 91] primary master is down
Cluster state changed
*** NEO/go (sha1 disabled)
# NEO/go/storage: skipping SHA1 computations
# NEO/go/client: skipping SHA1 checks
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=539.872594ms (63.514µs / object) x=zhash.go
# NEO/go/client: skipping SHA1 checks
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=518.352728ms (60.982µs / object) x=zhash.go
# NEO/go/client: skipping SHA1 checks
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=531.142508ms (62.487µs / object) x=zhash.go
# NEO/go/client: skipping SHA1 checks
crc32:83514ce0 ; oid=0..8499 nread=34159871 t=505.481197ms (59.468µs / object) x=zhash.go
2017-10-04 18:14:50.4846 ERROR NEO [ app: 91] primary master is down
2017/10/04 18:14:50 talk master([2401:5180:0:6f::1]:5552): context canceled
Cluster state changed
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment
GitLab Nexedi Edition | About GitLab | About Nexedi | 沪ICP备2021021310号-2 | 沪ICP备2021021310号-7