Ceph » rbd

This popped up on pacific_16.2.11_RC6.6 but the code is mostly the same in main:

2023-01-17T17:58:55.709 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule status
2023-01-17T17:58:55.709 INFO:tasks.workunit.client.0.smithi027.stderr:+ grep rbd2/ns1/test1
2023-01-17T17:58:55.755 INFO:tasks.workunit.client.0.smithi027.stdout:2023-01-17 17:59:00  rbd2/ns1/test1
2023-01-17T17:58:55.756 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule add 1h 00:15
2023-01-17T17:58:55.810 INFO:tasks.workunit.client.0.smithi027.stderr:++ rbd mirror snapshot schedule ls
2023-01-17T17:58:55.851 INFO:tasks.workunit.client.0.smithi027.stderr:+ test 'every 1h starting at 00:15:00' = 'every 1h starting at 00:15:00'
2023-01-17T17:58:55.852 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule ls -R
2023-01-17T17:58:55.852 INFO:tasks.workunit.client.0.smithi027.stderr:+ grep 'every 1h starting at 00:15:00'
2023-01-17T17:58:55.898 INFO:tasks.workunit.client.0.smithi027.stdout:-     -          -      every 1h starting at 00:15:00
2023-01-17T17:58:55.899 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule ls -R
2023-01-17T17:58:55.899 INFO:tasks.workunit.client.0.smithi027.stderr:+ grep 'rbd2 *ns1 *test1 *every 1m'
2023-01-17T17:58:55.943 INFO:tasks.workunit.client.0.smithi027.stdout:rbd2  ns1        test1  every 1m
2023-01-17T17:58:55.944 INFO:tasks.workunit.client.0.smithi027.stderr:+ expect_fail rbd mirror snapshot schedule ls -p rbd2
2023-01-17T17:58:55.944 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule ls -p rbd2
2023-01-17T17:58:55.988 INFO:tasks.workunit.client.0.smithi027.stderr:+ return 0
2023-01-17T17:58:55.989 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule ls -p rbd2 -R
2023-01-17T17:58:55.989 INFO:tasks.workunit.client.0.smithi027.stderr:+ grep 'every 1h starting at 00:15:00'
2023-01-17T17:58:56.034 INFO:tasks.workunit.client.0.smithi027.stdout:-     -          -      every 1h starting at 00:15:00
2023-01-17T17:58:56.035 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule ls -p rbd2 -R
2023-01-17T17:58:56.035 INFO:tasks.workunit.client.0.smithi027.stderr:+ grep 'rbd2 *ns1 *test1 *every 1m'
2023-01-17T17:58:56.081 INFO:tasks.workunit.client.0.smithi027.stdout:rbd2  ns1        test1  every 1m
2023-01-17T17:58:56.082 INFO:tasks.workunit.client.0.smithi027.stderr:+ expect_fail rbd mirror snapshot schedule ls -p rbd2/ns1
2023-01-17T17:58:56.082 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule ls -p rbd2/ns1
2023-01-17T17:58:56.129 INFO:tasks.workunit.client.0.smithi027.stderr:+ return 0
2023-01-17T17:58:56.130 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule ls -p rbd2/ns1 -R
2023-01-17T17:58:56.130 INFO:tasks.workunit.client.0.smithi027.stderr:+ grep 'every 1h starting at 00:15:00'
2023-01-17T17:58:56.177 INFO:tasks.workunit.client.0.smithi027.stdout:-     -          -      every 1h starting at 00:15:00
2023-01-17T17:58:56.178 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule ls -p rbd2/ns1 -R
2023-01-17T17:58:56.178 INFO:tasks.workunit.client.0.smithi027.stderr:+ grep 'rbd2 *ns1 *test1 *every 1m'
2023-01-17T17:58:56.226 INFO:tasks.workunit.client.0.smithi027.stdout:rbd2  ns1        test1  every 1m
2023-01-17T17:58:56.227 INFO:tasks.workunit.client.0.smithi027.stderr:++ rbd mirror snapshot schedule ls -p rbd2/ns1 --image test1
2023-01-17T17:58:56.294 INFO:tasks.workunit.client.0.smithi027.stderr:+ test 'every 1m' = 'every 1m'
2023-01-17T17:58:56.295 INFO:tasks.workunit.client.0.smithi027.stderr:+ expect_fail rbd mirror snapshot schedule add dummy
2023-01-17T17:58:56.295 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule add dummy
2023-01-17T17:58:56.335 INFO:tasks.ceph.mgr.x.smithi027.stderr:2023-01-17T17:58:56.333+0000 7f198953f700 -1 mgr.server reply reply (22) Invalid argument Invalid interval (dummy)
2023-01-17T17:58:56.335 INFO:tasks.workunit.client.0.smithi027.stderr:rbd: rbd mirror snapshot schedule add failed: (22) Invalid argument: Invalid interval (dummy)
2023-01-17T17:58:56.340 INFO:tasks.workunit.client.0.smithi027.stderr:+ return 0
2023-01-17T17:58:56.340 INFO:tasks.workunit.client.0.smithi027.stderr:+ expect_fail rbd mirror snapshot schedule add -p rbd2/ns1 --image test1 dummy
2023-01-17T17:58:56.340 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule add -p rbd2/ns1 --image test1 dummy
2023-01-17T17:58:56.404 INFO:tasks.ceph.mgr.x.smithi027.stderr:2023-01-17T17:58:56.401+0000 7f198953f700 -1 mgr.server reply reply (22) Invalid argument Invalid interval (dummy)
2023-01-17T17:58:56.405 INFO:tasks.workunit.client.0.smithi027.stderr:rbd: rbd mirror snapshot schedule add failed: (22) Invalid argument: Invalid interval (dummy)
2023-01-17T17:58:56.409 INFO:tasks.workunit.client.0.smithi027.stderr:+ return 0
2023-01-17T17:58:56.410 INFO:tasks.workunit.client.0.smithi027.stderr:+ expect_fail rbd mirror snapshot schedule remove dummy
2023-01-17T17:58:56.410 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule remove dummy
2023-01-17T17:58:56.450 INFO:tasks.ceph.mgr.x.smithi027.stderr:2023-01-17T17:58:56.449+0000 7f198953f700 -1 mgr.server reply reply (22) Invalid argument Invalid interval (dummy)
2023-01-17T17:58:56.450 INFO:tasks.workunit.client.0.smithi027.stderr:rbd: rbd mirror snapshot schedule remove failed: (22) Invalid argument: Invalid interval (dummy)
2023-01-17T17:58:56.454 INFO:tasks.workunit.client.0.smithi027.stderr:+ return 0
2023-01-17T17:58:56.455 INFO:tasks.workunit.client.0.smithi027.stderr:+ expect_fail rbd mirror snapshot schedule remove -p rbd2/ns1 --image test1 dummy
2023-01-17T17:58:56.455 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule remove -p rbd2/ns1 --image test1 dummy
2023-01-17T17:58:56.524 INFO:tasks.ceph.mgr.x.smithi027.stderr:2023-01-17T17:58:56.521+0000 7f198953f700 -1 mgr.server reply reply (22) Invalid argument Invalid interval (dummy)
2023-01-17T17:58:56.524 INFO:tasks.workunit.client.0.smithi027.stderr:rbd: rbd mirror snapshot schedule remove failed: (22) Invalid argument: Invalid interval (dummy)
2023-01-17T17:58:56.527 INFO:tasks.workunit.client.0.smithi027.stderr:+ return 0
2023-01-17T17:58:56.528 INFO:tasks.workunit.client.0.smithi027.stderr:++ rbd mirror snapshot schedule ls
2023-01-17T17:58:56.574 INFO:tasks.workunit.client.0.smithi027.stderr:+ test 'every 1h starting at 00:15:00' = 'every 1h starting at 00:15:00'
2023-01-17T17:58:56.574 INFO:tasks.workunit.client.0.smithi027.stderr:++ rbd mirror snapshot schedule ls -p rbd2/ns1 --image test1
2023-01-17T17:58:56.646 INFO:tasks.workunit.client.0.smithi027.stderr:+ test 'every 1m' = 'every 1m'
2023-01-17T17:58:56.646 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd rm rbd2/ns1/test1
2023-01-17T17:58:58.879 INFO:tasks.workunit.client.0.smithi027.stderr:2023-01-17T17:58:58.877+0000 7f5940d3e700  0 -- 172.21.15.27:0/4279233003 >> [v2:172.21.15.27:6800/26330,v1:172.21.15.27:6801/26330] conn(0x5646a3585480 msgr2=0x5646a35974c0 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_until injecting socket failure
2023-01-17T17:58:59.897 INFO:tasks.workunit.client.0.smithi027.stderr:2023-01-17T17:58:59.893+0000 7f5940d3e700  0 -- 172.21.15.27:0/4279233003 >> [v2:172.21.15.27:6800/26330,v1:172.21.15.27:6801/26330] conn(0x7f59200347a0 msgr2=0x7f5920036b90 crc :-1 s=STATE_CONNECTION_ESTABLISHED l=1).read_until injecting socket failure
2023-01-17T17:58:59.957 INFO:tasks.workunit.client.0.smithi027.stderr:^MRemoving image: 100% complete...done.
2023-01-17T17:58:59.963 INFO:tasks.workunit.client.0.smithi027.stderr:++ seq 12
2023-01-17T17:58:59.964 INFO:tasks.workunit.client.0.smithi027.stderr:+ for i in `seq 12`
2023-01-17T17:58:59.964 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule status
2023-01-17T17:58:59.965 INFO:tasks.workunit.client.0.smithi027.stderr:+ grep rbd2/ns1/test1
2023-01-17T17:59:00.009 INFO:tasks.workunit.client.0.smithi027.stderr:+ break
2023-01-17T17:59:00.009 INFO:tasks.workunit.client.0.smithi027.stderr:+ rbd mirror snapshot schedule status
2023-01-17T17:59:00.010 INFO:tasks.workunit.client.0.smithi027.stderr:+ expect_fail grep rbd2/ns1/test1
2023-01-17T17:59:00.010 INFO:tasks.workunit.client.0.smithi027.stderr:+ grep rbd2/ns1/test1
2023-01-17T17:59:00.052 INFO:tasks.workunit.client.0.smithi027.stdout:2023-01-17 18:00:00  rbd2/ns1/test1
2023-01-17T17:59:00.053 INFO:tasks.workunit.client.0.smithi027.stderr:+ return 1
2023-01-17T17:59:00.054 DEBUG:teuthology.orchestra.run:got remote process result: 1
2023-01-17T17:59:00.054 INFO:tasks.workunit:Stopping ['rbd/cli_generic.sh'] on client.0...
2023-01-17T17:59:00.055 DEBUG:teuthology.orchestra.run.smithi027:> sudo rm -rf -- /home/ubuntu/cephtest/workunits.list.client.0 /home/ubuntu/cephtest/clone.client.0
2023-01-17T17:59:00.304 ERROR:teuthology.run_tasks:Saw exception from tasks.
Traceback (most recent call last):
  File "/home/teuthworker/src/git.ceph.com_teuthology_19d18db866afdc31fd6586f558fc29b95a87ccfb/teuthology/run_tasks.py", line 103, in run_tasks
    manager = run_one_task(taskname, ctx=ctx, config=config)
  File "/home/teuthworker/src/git.ceph.com_teuthology_19d18db866afdc31fd6586f558fc29b95a87ccfb/teuthology/run_tasks.py", line 82, in run_one_task
    return task(**kwargs)
  File "/home/teuthworker/src/github.com_idryomov_ceph_d158d6409994693da5611f9b5747b4ca30fcbcf6/qa/tasks/workunit.py", line 129, in task
    p.spawn(_run_tests, ctx, refspec, role, tests,
  File "/home/teuthworker/src/git.ceph.com_teuthology_19d18db866afdc31fd6586f558fc29b95a87ccfb/teuthology/parallel.py", line 84, in __exit__
    for result in self:
  File "/home/teuthworker/src/git.ceph.com_teuthology_19d18db866afdc31fd6586f558fc29b95a87ccfb/teuthology/parallel.py", line 98, in __next__
    resurrect_traceback(result)
  File "/home/teuthworker/src/git.ceph.com_teuthology_19d18db866afdc31fd6586f558fc29b95a87ccfb/teuthology/parallel.py", line 30, in resurrect_traceback
    raise exc.exc_info[1]
  File "/home/teuthworker/src/git.ceph.com_teuthology_19d18db866afdc31fd6586f558fc29b95a87ccfb/teuthology/parallel.py", line 23, in capture_traceback
    return func(*args, **kwargs)
  File "/home/teuthworker/src/github.com_idryomov_ceph_d158d6409994693da5611f9b5747b4ca30fcbcf6/qa/tasks/workunit.py", line 423, in _run_tests
    remote.run(
  File "/home/teuthworker/src/git.ceph.com_teuthology_19d18db866afdc31fd6586f558fc29b95a87ccfb/teuthology/orchestra/remote.py", line 525, in run
    r = self._runner(client=self.ssh, name=self.shortname, **kwargs)
  File "/home/teuthworker/src/git.ceph.com_teuthology_19d18db866afdc31fd6586f558fc29b95a87ccfb/teuthology/orchestra/run.py", line 455, in run
    r.wait()
  File "/home/teuthworker/src/git.ceph.com_teuthology_19d18db866afdc31fd6586f558fc29b95a87ccfb/teuthology/orchestra/run.py", line 161, in wait
    self._raise_for_status()
  File "/home/teuthworker/src/git.ceph.com_teuthology_19d18db866afdc31fd6586f558fc29b95a87ccfb/teuthology/orchestra/run.py", line 181, in _raise_for_status
    raise CommandFailedError(
teuthology.exceptions.CommandFailedError: Command failed (workunit test rbd/cli_generic.sh) on smithi027 with status 1: 'mkdir -p -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && cd -- /home/ubuntu/cephtest/mnt.0/client.0/tmp && CEPH_CLI_TEST_DUP_COMMAND=1 CEPH_REF=d158d6409994693da5611f9b5747b4ca30fcbcf6 TESTDIR="/home/ubuntu/cephtest" CEPH_ARGS="--cluster ceph" CEPH_ID="0" PATH=$PATH:/usr/sbin CEPH_BASE=/home/ubuntu/cephtest/clone.client.0 CEPH_ROOT=/home/ubuntu/cephtest/clone.client.0 CEPH_MNT=/home/ubuntu/cephtest/mnt.0 adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 3h /home/ubuntu/cephtest/clone.client.0/qa/workunits/rbd/cli_generic.sh'

    rbd rm rbd2/ns1/test1
    for i in `seq 12`; do
        rbd mirror snapshot schedule status | grep 'rbd2/ns1/test1' || break
        sleep 10
    done
    rbd mirror snapshot schedule status | expect_fail grep 'rbd2/ns1/test1'

One the first iteration "rbd mirror snapshot schedule status" unexpectedly produced no output, letting the control to break out of the loop too early.

https://pulpito.ceph.com/dis-2023-01-17_16:09:39-rbd-pacific_16.2.11_RC6.6-distro-default-smithi/7143931