Project

General

Profile

Actions

Bug #52503

open

cli_generic.sh: slow ops when trying rand write on cache pools

Added by Deepika Upadhyay over 2 years ago. Updated over 2 years ago.

Status:
New
Priority:
Normal
Assignee:
Category:
-
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
quincy,pacific, octopus
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(RADOS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

failing: leads to slow ops: http://qa-proxy.ceph.com/teuthology/yuriw-2021-09-01_19:04:25-rbd-wip-yuri-testing-2021-09-01-0844-pacific-distro-basic-smithi/6371432/teuthology.log

2021-09-02T01:46:35.007 INFO:tasks.workunit.client.0.smithi107.stderr:+ rbd bench --io-type write --io-pattern rand --io-total 32M --io-size 4K rbd/image2
2021-09-02T01:46:35.075 INFO:tasks.workunit.client.0.smithi107.stdout:bench  type write io_size 4096 io_threads 16 bytes 33554432 pattern random
2021-09-02T01:46:35.505 INFO:tasks.workunit.client.0.smithi107.stdout:  SEC       OPS   OPS/SEC   BYTES/SEC
2021-09-02T01:46:35.506 INFO:tasks.workunit.client.0.smithi107.stderr:2021-09-02T01:46:35.504+0000 7ff778b0f700  0 -- 172.21.15.107:0/3363340619 >> [v2:172.21.15.107:6800/32737,v1:172.21.15.107:6801/32737] conn(0x7ff754008780 msgr2=0x7ff75400abd0 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_until injecting socket failure
2021-09-02T01:46:35.579 INFO:tasks.workunit.client.0.smithi107.stderr:2021-09-02T01:46:35.578+0000 7ff779310700  0 -- 172.21.15.107:0/3363340619 >> [v2:172.21.15.107:6808/32738,v1:172.21.15.107:6810/32738] conn(0x5609d2ea8040 msgr2=0x5609d2f90d50 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1)._try_send injecting socket failure
2021-09-02T01:46:35.586 INFO:tasks.workunit.client.0.smithi107.stderr:2021-09-02T01:46:35.585+0000 7ff779310700  0 -- 172.21.15.107:0/3363340619 >> [v2:172.21.15.107:6808/32738,v1:172.21.15.107:6810/32738] conn(0x7ff754008780 msgr2=0x7ff75c073cc0 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1)._try_send injecting socket failure
2021-09-02T01:46:36.512 INFO:tasks.workunit.client.0.smithi107.stderr:2021-09-02T01:46:36.510+0000 7ff779310700  0 -- 172.21.15.107:0/3363340619 >> [v2:172.21.15.107:6808/32738,v1:172.21.15.107:6810/32738] conn(0x7ff754008780 msgr2=0x7ff75c073ca0 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_until injecting socket failure
2021-09-02T01:46:36.804 INFO:tasks.workunit.client.0.smithi107.stdout:    1      3216    1870.4   7.3 MiB/s
2021-09-02T01:46:36.990 INFO:tasks.workunit.client.0.smithi107.stderr:2021-09-02T01:46:36.988+0000 7ff779310700  0 -- 172.21.15.107:0/3363340619 >> [v2:172.21.15.107:6808/32738,v1:172.21.15.107:6810/32738] conn(0x7ff75c035a40 msgr2=0x7ff75c037e70 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_until injecting socket failure
2021-09-02T01:46:36.995 INFO:tasks.workunit.client.0.smithi107.stderr:2021-09-02T01:46:36.993+0000 7ff779310700  0 -- 172.21.15.107:0/3363340619 >> [v2:172.21.15.107:6808/32738,v1:172.21.15.107:6810/32738] conn(0x5609d2ea8040 msgr2=0x7ff75c0741d0 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1)._try_send injecting socket failure
2021-09-02T01:46:37.225 INFO:tasks.workunit.client.0.smithi107.stdout:    2      3248   1518.87   5.9 MiB/s
2021-09-02T01:46:38.048 INFO:tasks.workunit.client.0.smithi107.stderr:2021-09-02T01:46:38.044+0000 7ff779310700  0 -- 172.21.15.107:0/3363340619 >> [v2:172.21.15.107:6808/32738,v1:172.21.15.107:6810/32738] conn(0x5609d2ea8040 msgr2=0x7ff75c037e30 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_until injecting socket failure
2021-09-02T01:46:38.160 INFO:tasks.workunit.client.0.smithi107.stdout:    3      4944   1608.33   6.3 MiB/s
2021-09-02T01:46:38.505 INFO:tasks.workunit.client.0.smithi107.stderr:2021-09-02T01:46:38.504+0000 7ff778b0f700  0 -- 172.21.15.107:0/3363340619 >> [v2:172.21.15.107:6800/32737,v1:172.21.15.107:6801/32737] conn(0x5609d2ea8040 msgr2=0x7ff75c037e30 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1)._try_send injecting socket failure
2021-09-02T01:46:39.257 INFO:tasks.workunit.client.0.smithi107.stderr:2021-09-02T01:46:39.256+0000 7ff779310700  0 -- 172.21.15.107:0/3363340619 >> [v2:172.21.15.107:6808/32738,v1:172.21.15.107:6810/32738] conn(0x7ff75c035a40 msgr2=0x7ff75c074190 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_until injecting socket failure
2021-09-02T01:46:39.403 INFO:tasks.workunit.client.0.smithi107.stderr:2021-09-02T01:46:39.395+0000 7ff779310700  0 -- 172.21.15.107:0/3363340619 >> [v2:172.21.15.107:6808/32738,v1:172.21.15.107:6810/32738] conn(0x5609d2ea8040 msgr2=0x7ff75c037e30 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_until injecting socket failure
2021-09-02T01:46:39.624 INFO:tasks.workunit.client.0.smithi107.stderr:2021-09-02T01:46:39.622+0000 7ff778b0f700  0 -- 172.21.15.107:0/3363340619 >> [v2:172.21.15.107:6800/32737,v1:172.21.15.107:6801/32737] conn(0x7ff754008780 msgr2=0x7ff75c073ca0 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1)._try_send injecting socket failure
2021-09-02T01:46:40.103 INFO:tasks.workunit.client.0.smithi107.stdout:    5      6816   1358.81   5.3 MiB/s
2021-09-02T01:47:10.451 INFO:tasks.ceph.osd.1.smithi107.stderr:2021-09-02T01:47:10.450+0000 7fee233dc700 -1 osd.1 153 get_health_metrics reporting 16 slow ops, oldest is osd_op(client.10600.0:5250 3.2 3:6612ec91:::rbd_data.2965a7ef300.0000000000000051:head [write 2244608~4096 [fadvise_random] in=4096b] snapc 0=[] RETRY=6 ondisk+retry+write+known_if_redirected e152)

passing: http://qa-proxy.ceph.com/teuthology/teuthology-2021-08-30_06:07:02-rbd-pacific-distro-basic-smithi/6366493/teuthology.log

2021-08-30T09:20:23.438 INFO:tasks.workunit.client.0.smithi164.stdout:bench  type write io_size 4096 io_threads 16 bytes 33554432 pattern random
2021-08-30T09:20:24.631 INFO:tasks.workunit.client.0.smithi164.stdout:  SEC       OPS   OPS/SEC   BYTES/SEC
2021-08-30T09:20:24.631 INFO:tasks.workunit.client.0.smithi164.stdout:    1      3632   3063.03    12 MiB/s
2021-08-30T09:20:24.804 INFO:tasks.workunit.client.0.smithi164.stderr:2021-08-30T09:20:24.802+0000 7f880d2bc700  0 -- 172.21.15.164:0/1034694029 >> [v2:172.21.15.164:6805/31302,v1:172.21.15.164:6808/31302] conn(0x55be70eb70e0 msgr2=0x7f87f00d1c90 crc :-1 

    msgr-failures/few objectstore/bluestore-stupid pool/small-cache-pool supported-random-distro$/{rhel_8}
    workloads/rbd_cli_generic}

object grep: /home/ideepika/rbd_cli.log teuthology server

Actions

Also available in: Atom PDF