Project

General

Profile

Bug #45512

Jobs are running on the same machine at the same time

Added by David Galloway over 2 years ago. Updated 6 months ago.

Status:
Fix Under Review
Priority:
Immediate
Assignee:
Category:
-
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Crash signature (v1):
Crash signature (v2):

History

#1 Updated by David Galloway over 2 years ago

Related?

2020-05-11 20:14:57,859.859 DEBUG:teuthology.lock.ops:lock_many request: {'locked_by': 'scheduled_varsha@teuthology', 'count': 1, 'machine_type': 'smithi', 'description': '/home/teuthworker/archive/varsha-2020-05-11_15:54:35-rados-wip-varsha-testing-distro-basic-smithi/5046616'}
2020-05-11 20:14:57,879.879 DEBUG:teuthology.lock.ops:locked ubuntu@smithi078.front.sepia.ceph.com
2020-05-11 20:14:57,903.903 DEBUG:teuthology.exit:Installing handler: Handler(exiter=<teuthology.exit.Exiter object at 0x7fb9a894c668>, func=<function ConsoleLog.start_logging.<locals>.kill_console_loggers at 0x7fb9a8b07950>, signals=[15])
2020-05-11 20:14:57,911.911 INFO:teuthology.task.internal.lock_machines:Locking machines...
2020-05-11 20:14:57,911.911 DEBUG:teuthology.report:Pushing job info to http://paddles.front.sepia.ceph.com/
Traceback (most recent call last):
  File "<string>", line 1, in <module>
NameError: name 'file' is not defined
2020-05-11 20:14:57,961.961 DEBUG:teuthology.lock.ops:lock_many request: {'locked_by': 'scheduled_varsha@teuthology', 'count': 1, 'machine_type': 'smithi', 'description': '/home/teuthworker/archive/varsha-2020-05-11_15:58:25-rados-wip-varsha-testing-distro-basic-smithi/5046639'}
2020-05-11 20:14:57,981.981 DEBUG:teuthology.lock.ops:locked ubuntu@smithi012.front.sepia.ceph.com
2020-05-11 20:14:58,006.006 DEBUG:teuthology.exit:Installing handler: Handler(exiter=<teuthology.exit.Exiter object at 0x7f1bd11316d8>, func=<function ConsoleLog.start_logging.<locals>.kill_console_loggers at 0x7f1bd129e950>, signals=[15])
Traceback (most recent call last):
  File "<string>", line 1, in <module>
NameError: name 'file' is not defined

#2 Updated by Zack Cerza over 2 years ago

I don't have the answer yet, but here's some information from the paddles server:


ubuntu@pulpito:~$ grep -a smithi104 paddles.out.log
...
2020-05-11 14:17:08,997 INFO [paddles.controllers.nodes] Locked <Node smithi104.front.sepia.ceph.com> for scheduled_teuthology@teuthology with description /home/teuthworker/archive/teuthology-2020-05-11_02:01:02-rbd-master-distro-basic-smithi/5043278
2020-05-11 14:18:02,202 DEBUG [paddles.controllers.nodes] Unlocking <Node smithi104.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2020-05-11 14:18:02,204 INFO [paddles.controllers.nodes] Unlocked <Node smithi104.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2020-05-11 14:19:22,832 INFO [paddles.controllers.nodes] Locked <Node smithi104.front.sepia.ceph.com> <Node smithi068.front.sepia.ceph.com> <Node smithi065.front.sepia.ceph.com> for scheduled_teuthology@teuthology with description /home/teuthworker/archive/teuthology-2020-05-11_02:01:02-rbd-master-distro-basic-smithi/5043260
2020-05-11 14:20:15,937 DEBUG [paddles.controllers.nodes] Unlocking <Node smithi104.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2020-05-11 14:20:15,939 INFO [paddles.controllers.nodes] Unlocked <Node smithi104.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2020-05-11 14:20:34,843 INFO [paddles.controllers.nodes] Locked <Node smithi104.front.sepia.ceph.com> for scheduled_teuthology@teuthology with description /home/teuthworker/archive/teuthology-2020-05-11_02:01:02-rbd-master-distro-basic-smithi/5043279
2020-05-11 14:22:29,870 DEBUG [paddles.controllers.nodes] Unlocking <Node smithi104.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2020-05-11 14:22:29,871 INFO [paddles.controllers.nodes] Unlocked <Node smithi104.front.sepia.ceph.com> for scheduled_teuthology@teuthology
...

smithi104 was unlocked very shortly after 5043278 locked it, and the request came from teuthology.front, though it looks like it didn't come from the job's process. This all happened before 5043279 had even started, let alone attempted any locks.

#3 Updated by David Galloway over 2 years ago

Another instance: smithi146

http://qa-proxy.ceph.com/teuthology/teuthology-2020-05-12_02:30:02-upgrade:mimic-x-nautilus-distro-basic-smithi/5048079/teuthology.log

2020-05-12T11:57:04.811 INFO:teuthology.task.ansible.out:fatal: [smithi146.front.sepia.ceph.com]: FAILED! => {"changed": true, "cmd": ["rpm", "--rebuilddb"], "delta": "0:00:00.034381", "end": "2020-05-12 11:57:04.779147", "msg": "non-zero return code", "rc": 255, "start": "2020-05-12 11:57:04.744766", "stderr": "error: can't create transaction lock on /var/lib/rpm/.rpm.lock (Resource temporarily unavailable)", "stderr_lines": ["error: can't create transaction lock on /var/lib/rpm/.rpm.lock (Resource temporarily unavailable)"], "stdout": "", "stdout_lines": []}

http://qa-proxy.ceph.com/teuthology/teuthology-2020-05-12_05:00:02-smoke-master-testing-basic-smithi/5048546/teuthology.log

2020-05-12T11:56:34.186 INFO:teuthology.task.kernel:Installing kernel 2df39dc136ccbbccbbb0d080cebc99614118a329 on mon.b...
2020-05-12T11:56:34.186 INFO:teuthology.orchestra.run.smithi146:> sudo rpm -ivh --oldpackage --replacefiles --replacepkgs /tmp/kernel.x86_64.rpm
2020-05-12T11:56:35.953 INFO:teuthology.orchestra.run.smithi146.stdout:Verifying...                          ########################################
2020-05-12T11:56:36.255 INFO:teuthology.orchestra.run.smithi146.stdout:Preparing...                          ########################################
2020-05-12T11:56:36.290 INFO:teuthology.orchestra.run.smithi146.stdout:Updating / installing...
2020-05-12T11:57:11.180 INFO:teuthology.orchestra.run.smithi146.stdout:kernel-5.7.0_rc5_ceph_g2df39dc136cc-1 ########################################
2020-05-12T11:57:31.587 DEBUG:teuthology.task.kernel:install_kernel(remote=ubuntu@smithi146.front.sepia.ceph.com, path=/tmp/kernel.x86_64.rpm, version=None)
2020-05-12T11:57:31.588 INFO:teuthology.orchestra.run.smithi146:> rpm -qlp /tmp/kernel.x86_64.rpm

This is very bad.

2020-05-12 11:47:09,086 INFO  [paddles.controllers.nodes] Locked <Node smithi164.front.sepia.ceph.com> <Node smithi189.front.sepia.ceph.com> <Node smithi043.front.sepia.ceph.com> <Node smithi146.front.sepia.ceph.com> <Node smithi060.front.sepia.ceph.com> for scheduled_teuthology@teuthology with description /home/teuthworker/archive/teuthology-2020-05-12_02:30:02-upgrade:mimic-x-nautilus-distro-basic-smithi/5048079
2020-05-12 11:49:17,688 DEBUG [paddles.controllers.nodes] Unlocking <Node smithi146.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2020-05-12 11:49:17,689 INFO  [paddles.controllers.nodes] Unlocked <Node smithi146.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2020-05-12 11:49:20,932 INFO  [paddles.controllers.nodes] Locked <Node smithi043.front.sepia.ceph.com> <Node smithi146.front.sepia.ceph.com> <Node smithi060.front.sepia.ceph.com> for scheduled_teuthology@teuthology with description /home/teuthworker/archive/teuthology-2020-05-12_05:00:02-smoke-master-testing-basic-smithi/5048546
2020-05-12 11:53:51,613 INFO  [paddles.controllers.nodes] Updating <Node smithi146.front.sepia.ceph.com>: {u'ssh_pub_key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC0HT4TiSwtVS+c5nPdyrnm6k8MKCC+3NMPcrvOkLEImO/jRJ97HY0b0PSw0KKglQEu98LjHeRqAZ6FoDAR9un59KxI9OBjwMlaaGFvAlY5EW5C5bUCsBFX0qnJ/BKRlkuQ7NH2GpaeCDJmfw2bO4W0HKtLjASivoWdsw+6PTRcRSZJwRvgTbL+/TQEbh7IYbvIjMo2u7Zj8mmwTCAys6leCTIEI2OgKlhlZAkWZh2c8E99QzEPdqURZCYQj6IeGMhN2wOq9eLcHGaItCsDaWR4Kpanj95mn1H0tS0dFBgdA0OP5UIhECV7fHyM9Bluc1H6xidFAWJXWUVEKzRgZjjB1nKO3SBhuGGpY/8XJAVj904AsIsAEmig4+6oQWbAS5BwqHlXzmGhyenjeKpQVGiSCtrPZLq7ucY/gAm0ixI/Sj8Ax4xQwKwug9Q44PfCiz99ra3dOEjrYqOCgOyTO2LCqUaeEW/vrDfDnxvcsnTZuU4uu1Fe/WFkC6hTf3JarUU='}
2020-05-12 11:53:52,465 INFO  [paddles.controllers.nodes] Updating <Node smithi146.front.sepia.ceph.com>: {u'name': u'smithi146.front.sepia.ceph.com', u'up': True, u'os_version': u'8.1', u'user': u'ubuntu', u'os_type': u'rhel', u'arch': u'x86_64', u'ssh_pub_key': u'ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBGhz/E0m6Y9T1S6IqTAoM7P0vMFhIp1dFVD6lWtcKOArRiRZly3wztdD4MHbOpypD7y4R5Bvh8KlF6FEdQTS01M='}
2020-05-12 11:53:54,311 INFO  [paddles.controllers.nodes] Updating <Node smithi146.front.sepia.ceph.com>: {u'name': u'smithi146.front.sepia.ceph.com', u'up': True, u'os_version': u'8.1', u'user': u'ubuntu', u'os_type': u'rhel', u'arch': u'x86_64', u'ssh_pub_key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC0HT4TiSwtVS+c5nPdyrnm6k8MKCC+3NMPcrvOkLEImO/jRJ97HY0b0PSw0KKglQEu98LjHeRqAZ6FoDAR9un59KxI9OBjwMlaaGFvAlY5EW5C5bUCsBFX0qnJ/BKRlkuQ7NH2GpaeCDJmfw2bO4W0HKtLjASivoWdsw+6PTRcRSZJwRvgTbL+/TQEbh7IYbvIjMo2u7Zj8mmwTCAys6leCTIEI2OgKlhlZAkWZh2c8E99QzEPdqURZCYQj6IeGMhN2wOq9eLcHGaItCsDaWR4Kpanj95mn1H0tS0dFBgdA0OP5UIhECV7fHyM9Bluc1H6xidFAWJXWUVEKzRgZjjB1nKO3SBhuGGpY/8XJAVj904AsIsAEmig4+6oQWbAS5BwqHlXzmGhyenjeKpQVGiSCtrPZLq7ucY/gAm0ixI/Sj8Ax4xQwKwug9Q44PfCiz99ra3dOEjrYqOCgOyTO2LCqUaeEW/vrDfDnxvcsnTZuU4uu1Fe/WFkC6hTf3JarUU='}
2020-05-12 11:54:20,966 INFO  [paddles.controllers.nodes] Updating <Node smithi146.front.sepia.ceph.com>: {u'name': u'smithi146.front.sepia.ceph.com', u'up': True, u'os_version': u'8.1', u'user': u'ubuntu', u'os_type': u'rhel', u'arch': u'x86_64', u'ssh_pub_key': u'ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBGhz/E0m6Y9T1S6IqTAoM7P0vMFhIp1dFVD6lWtcKOArRiRZly3wztdD4MHbOpypD7y4R5Bvh8KlF6FEdQTS01M='}
2020-05-12 11:54:22,944 INFO  [paddles.controllers.nodes] Updating <Node smithi146.front.sepia.ceph.com>: {u'name': u'smithi146.front.sepia.ceph.com', u'up': True, u'os_version': u'8.1', u'user': u'ubuntu', u'os_type': u'rhel', u'arch': u'x86_64', u'ssh_pub_key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC0HT4TiSwtVS+c5nPdyrnm6k8MKCC+3NMPcrvOkLEImO/jRJ97HY0b0PSw0KKglQEu98LjHeRqAZ6FoDAR9un59KxI9OBjwMlaaGFvAlY5EW5C5bUCsBFX0qnJ/BKRlkuQ7NH2GpaeCDJmfw2bO4W0HKtLjASivoWdsw+6PTRcRSZJwRvgTbL+/TQEbh7IYbvIjMo2u7Zj8mmwTCAys6leCTIEI2OgKlhlZAkWZh2c8E99QzEPdqURZCYQj6IeGMhN2wOq9eLcHGaItCsDaWR4Kpanj95mn1H0tS0dFBgdA0OP5UIhECV7fHyM9Bluc1H6xidFAWJXWUVEKzRgZjjB1nKO3SBhuGGpY/8XJAVj904AsIsAEmig4+6oQWbAS5BwqHlXzmGhyenjeKpQVGiSCtrPZLq7ucY/gAm0ixI/Sj8Ax4xQwKwug9Q44PfCiz99ra3dOEjrYqOCgOyTO2LCqUaeEW/vrDfDnxvcsnTZuU4uu1Fe/WFkC6hTf3JarUU='}
2020-05-12 12:09:52,403 DEBUG [paddles.controllers.nodes] Unlocking <Node smithi146.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2020-05-12 12:09:52,405 INFO  [paddles.controllers.nodes] Unlocked <Node smithi146.front.sepia.ceph.com> for scheduled_teuthology@teuthology

#4 Updated by Kefu Chai over 2 years ago

  • Assignee set to Kefu Chai

#5 Updated by Kefu Chai over 2 years ago

  • Status changed from New to Resolved

#6 Updated by David Galloway over 2 years ago

  • Status changed from Resolved to In Progress

This is still happening :(

http://pulpito.ceph.com/nodes/smithi040.front.sepia.ceph.com/

5058215 started at 2020-05-15 15:17:50 but 5058307 started at 2020-05-15 14:31:32 and is still going as of 2020-05-15 20:31:40.

Also 5058318 started at 2020-05-15 15:00:53 and somehow managed to pass while 5058307 was going?!

#7 Updated by Kefu Chai over 2 years ago

  • Status changed from In Progress to New
  • Assignee deleted (Kefu Chai)

#8 Updated by David Galloway over 2 years ago

Another example

#9 Updated by David Galloway over 1 year ago

This is still happening.

http://qa-proxy.ceph.com/teuthology/yuriw-2021-05-11_00:22:55-rados-wip-yuri2-testing-2021-05-10-1557-nautilus-distro-basic-smithi/6107945/teuthology.log

Notice:

2021-05-11T00:33:39.741 INFO:teuthology.task.ansible.out:failed: [smithi154.front.sepia.ceph.com] (item={'name': 'tserlin', 'key': 'ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA2ok6CBUpOVGv2RFws44GtEP5SVxOi4Vie0WSZYLpD55rTfmOtsItN1d1EciVNTUyWuyzMeQGWC4JAd3/2l3gR/5ZwSvd7b/7TCNYxjAMEubRand0GxEoiKhpkJMMmJqcT0KefP8pr31MASWPuERj1+0/IbjJExsvrJaUjqeIfZ+DWR8dC2VYdcH3hsp6AE3mqKX/9693sxe8ROt6qY4WkpZcO4M90unOVa2CnJsYqKaaIC4z3fmKuHZpJZjiJMrg8rtuN4r7bnKWPEVGcahj+i74JWwKR5+2gntLpxw2chIBmf4qFu6HDplddig4V3I/2NLB8soBpgc+m8O7YyYl0w== thomas@easystreet', 'ovpn': 'tserlin@annarbor DlKe+OWBPcFAQtWMUAHnwg 6b268bd737ffa5dd38865575ccd444b92cb912c70f5b82dac41f9c50505df4a5'}) => {"ansible_loop_var": "item", "item": {"key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA2ok6CBUpOVGv2RFws44GtEP5SVxOi4Vie0WSZYLpD55rTfmOtsItN1d1EciVNTUyWuyzMeQGWC4JAd3/2l3gR/5ZwSvd7b/7TCNYxjAMEubRand0GxEoiKhpkJMMmJqcT0KefP8pr31MASWPuERj1+0/IbjJExsvrJaUjqeIfZ+DWR8dC2VYdcH3hsp6AE3mqKX/9693sxe8ROt6qY4WkpZcO4M90unOVa2CnJsYqKaaIC4z3fmKuHZpJZjiJMrg8rtuN4r7bnKWPEVGcahj+i74JWwKR5+2gntLpxw2chIBmf4qFu6HDplddig4V3I/2NLB8soBpgc+m8O7YyYl0w== thomas@easystreet", "name": "tserlin", "ovpn": "tserlin@annarbor DlKe+OWBPcFAQtWMUAHnwg 6b268bd737ffa5dd38865575ccd444b92cb912c70f5b82dac41f9c50505df4a5"}, "msg": "Data could not be sent to remote host \"smithi154.front.sepia.ceph.com\". Make sure this host can be reached over ssh: ssh: connect to host smithi154.front.sepia.ceph.com port 22: No route to host\r\n", "unreachable": true}

That's the first failure. If you look at the console log, you can see another job reimaged the host. This is poisoning run results.

http://qa-proxy.ceph.com/teuthology/yuriw-2021-05-11_00:22:55-rados-wip-yuri2-testing-2021-05-10-1557-nautilus-distro-basic-smithi/6107945/console_logs/smithi154.log

 TheTimeIs
2021-05-11T00:37:52.440

That is /etc/rc.local running after a FOG reimage while the first job is still running.

#11 Updated by Deepika Upadhyay over 1 year ago

noticed one recently:

{'smithi083.front.sepia.ceph.com': {'changed': False, 'msg': 'Data could not be sent to remote host "smithi083.front.sepia.ceph.com". Make sure this host can be reached over ssh: ssh: connect to host smithi083.front.sepia.ceph.com port 22: No route to host\r\n', 'unreachable': True}, 'smithi167.front.sepia.ceph.com': {'changed': False, 'msg': 'Data could not be sent to remote host "smithi167.front.sepia.ceph.com". Make sure this host can be reached over ssh: ssh: connect to host smithi167.front.sepia.ceph.com port 22: No route to host\r\n', 'unreachable': True}}

http://qa-proxy.ceph.com/teuthology/yuriw-2021-06-14_20:08:33-rados-wip-yuri-testing-2021-06-14-0729-nautilus-distro-basic-smithi/6172542/teuthology.log

#13 Updated by David Galloway over 1 year ago

I wonder if nuke has anything to do with it. I killed a run today.

2021-06-24 20:58:30,643.643 INFO:teuthology.kill:Nuking machines: ['gibba001', 'gibba002', 'gibba004', 'gibba008', 'gibba010', 'gibba012', 'gibba013', 'gibba014', 'gibba016', 'gibba017', 'gibba018', 'gibba019', 'gibba020', 'gibba022', 'gibba023', 'gibba025', 'gibba026', 'gibba027', 'gibba028', 'gibba029', 'gibba030', 'gibba031', 'gibba035', 'gibba036', 'gibba038', 'gibba040', 'gibba041', 'gibba042', 'gibba043', 'gibba044', 'gibba045']
2021-06-24 20:58:31,639.639 INFO:teuthology.kill:2021-06-24 20:58:31,638.638 INFO:teuthology.nuke:targets:
2021-06-24 20:58:31,639.639 INFO:teuthology.kill:  gibba001.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC63w09w+i4yiSHpQ4WKoCCZXx8DfXfohTTRf5r5EnORXUTJtx6bCoJGoXL+yjjwRhaAWIEY69W5iVFgSx1AgbQ3CsQk7jcY/AFwz5yH7Tf9/kWbCQMnIGtWo1XZJceQEKs3pwP0YZqRVJ2UmB3xS0HlRKhv7GjcrkMl1qO+XonCP81noSd/Lu9KQV4ntUvgQBMXP9c51s7J6T67QZFZIHXFfPjOU1bO/fAzAhm2bbG44MQOPVQH+u19xY0UfVC8NCVS3sPzvopdI9UJDuyt2w0zBK94ui+tj5HQ5+EW1CT4/3jO8AvXb86cvPfX489uNjfSDROSnEpoyfC52bL2D+P
2021-06-24 20:58:31,639.639 INFO:teuthology.kill:  gibba002.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCxHERnVwQKcoP3EbU/MvRVTQk8/8M/4qv79NDjk99Nfpjr6xQS/XyGTShk9aAjDjPY4NXfLJizsK/smwcA05yWlaFgbWLuO5SZRuV6rnwLwEj/HFLTEEqIlIXvvsJ/Wajf87OEbwQfCWAet6H+csV+cR3mk+s0HEd7qI+IvQ3avUdwhPAyk0jbKo/9pgCgSpMfUq5Lgi+6mhJMtolwtUzGvHvSwSbYAM2R97KXN7dKTg2EFKtxa6yOcZfjJvrWHjQqGixpePBxH0+mEAXRryIF4Z6y8G7a8enuMxd+hnow+6EaQAM9Zjil572rRUh8CxpLcJ/RlzjJcgmPO747DgaN
2021-06-24 20:58:31,639.639 INFO:teuthology.kill:  gibba004.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCsCA20dsS6By49U0e4jsjdnjQADI4UtPf29XANuuG134HwpDzbScQQVcDEyfLGyltonczdcPXAwv/qIFguJTxtUlwvOYXUuXYIzFjev+nqfRHWDrhGEoGml5oCsuMpQRHAxa6nIOrIaaSzN/+OATzDl5hS68MYukKUQduI0OPHOwwujFoSx2Ah8TpdZ0dh6GpuTYsidGy271RONrPtB+S2G3Nis59DttsbFoCuUus4m2qSPC4RBZW42g0lzLmNqOCqlh5ugN2H3yri0L2zNDvhNZnYqQmKuwrWKG9fIpWM9Ux0D523TbDozNJGYXdBh5ShxHD8B+UFPXXBp7fe0ZZWCWkKaG8hM+BpLkg3CeNYbr/KTCRJhCspXYq0NmrufYW53tzI+rIWvFyA6iMyEBbaMJTbd6M8awfBbLV4F3CEO08PKrWKNCdfX2VOPQtr+AEQMcGvgrBnIH69V195+iBffixlZKC2DHgMHcGU5zdRS6v7ajUx1W3tNOno1Ix4mXc=
2021-06-24 20:58:31,639.639 INFO:teuthology.kill:  gibba008.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDd0VNpA9GwOmwnKp0AXX0/IrpN+sm3mcB7AHIOWD7PVa8LBCZmHwZdKnlxbU616mEdYiC03NAnq2qsc5USo1hH9hnk5NmipqdZtAdbGJczOfA7dhiM4fQtwfjOdB0V+INt+w7imPKPBdALkX7p/oWCZpikGIMiiZYVZUJ3Aw2LjHB7hda2sm8pGSUcw620W1Z6jlDd4MbQQ5ZctEe+zn4a7jHOOOdlGJgzeH2a7EgYThjCKs2bol4pgw4mgGDRRMFNOQLDhca0TjVWQoc6GtOLp8rMdeDV8+eNFFxZa6gOVDISCNV3bSbgx7QflxHDX1xt4HWzjz5V0EKHK/ddKeTRR1v6chnSspGOmZho1ARHzZHOCQmcMPVno4JhPC0mHIGTddhxP5nlZ1c9qeKAJgVT+NwtGTUfxXE1ZxNDYpaQ2mSrnvGp/6w0ndmp1aMQZp7Dq16tNz43UAhpn6zf0gU0C6bLQFuLSDT72UiXA1asyvsDhAMO6lfrpL9b4roFsSU=
2021-06-24 20:58:31,639.639 INFO:teuthology.kill:  gibba010.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCzA6m8QcqD4dP1keZ6HzzJ//GtwC9Op/OKszaB8qsZkc1i/Zf1j8RIN621d9qWktYpyLTouxaoHQ3tisMsC0X/39zJ7AVJqVFRyhBWdVD7oqrOf6DMkwDT5XDZh13pUbTn07Z13IPlcbXWyebwqrMxhS+lIy7B4hEN8qgdcezjN+8B/A/oUuBVBFIamn5ZAEK+xWdGiiobuc7KtHoqAJtdnqa9oztdKrNQ56dj+E6v6pc0tqMBEfknqXjKgE56PBMTEwGZODNcnEUOKGtbveMmKM1Mf+i6T9zjL1fy+FwKKAuJhrXmYpjWGTxDzTLwdGm0kjxgnxp1Htf9CfuhScUFO7nO4Ri4t7x+IjPCCe2z8w8BMNw3Pvz2wlY1dip5wOnU/DX5OJiOOHVNYZ9F9zjIez+MIqBGtgjl0AysbBHDQDiiVInsoXx8LXETnUrGHvSochs2gpZZ83rK3IRyIEi52RsHaVSrLx7u3oiXatuzsG96bKMvjeKbTRnk4SVRkCE=
2021-06-24 20:58:31,639.639 INFO:teuthology.kill:  gibba012.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC05tRGrnUhb7budVyVcuvNmoFRjF77uset/JctPsMWC4SMURFccTgBYb/65q2i1v3MvmAgYg7yHPzWw/41hXZB1Z/JEBXmUP54t2hCZQ7932msctLR5srABvchM6gNcBRhThUUEroe6HWinpnVEOAI97Jv3N4Z4QdnU8vOOpKyUDBYc3ZyIEENixXqMe0B8axcglvDRKhOIUx/Wn+z+HKFXUR4sjfxxBpzqkrPEx3BEs/2qd83sJ+lMINfcV0ooGMiPQkFnIsKmAsrBwe7Lr9z8a5W86ENYme94F2NlYYUZpK1t3LvlYB0jTawOYI9rvWHwzqW4N04AMeAd0Wrczbl
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba013.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCgnsLyr2AbD4f8Qi3sHoebnHIn9Z8X8qAYi4qtv7WtseDP/JKmhcwHMm6PK5GGMVjmRB8x8JMdYjklN653p2Ed0hltzbkfpTYCcDyKuPeYJaP1udEoQN0lqcFNB0vUxm8bGIX2j+D4rtZzT3x6m0bB96sknoqW5lzqq1zoCaZyiW/alTRYWOsFFyQxEHQUFynYdf67287HLfDVxQO7/WJCHeoKjpDAZzdUVQK40Ni4p5RO99E/ubYOPQQWx/SrXScpI3wZO+L44M4SEApCfLZ3V7WBhbdMq5YIqTwr+0sroTR3qlrwzXnjFHO63NW+9GUwgNnLEL4gSvKdMN3+VXE0iAu44Whv/lptokrEhMjg6d+Y/O9zyszf1avHKxXwlO3bhIOVABjrz90RzLN3TyzQAxd4WTljlx5c4MFDinMTHXAEcc+41ccBMOwDdsDd4AjVmUTJOH6sX00ELaiAUb5Ehcd53GrrZ2e2UraVWXPbkXNT2ohfp3gHIIgRHzIWctU=
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba014.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDQbaSNxxrX7SlYaIuJjcCHDZf0mEn29S9K7vW7MvqHrRaP3NFYJ278+7HqiP7jBS21TbfCBqhLanaIqYqCmVWxdiQgPK4F85FPVpZKveS8hwhsdA54mWk857C+Pa6nSQAre3F7TQ2peyWj5W6H6Q203HV4UQC5ZER/TGW66KYheDuQYNxDUt83xY62EVUvNkpSVIT2Va9gd3P+IZGsH6hmi0RaefRgBe167qXpQ/dhqruhuAj6SXlSmBxzMbx9fhpljfh/MB7/PrO8d7WVTnt+N4tAWuaLLvxpNysKxsE8865PZtkR4rxgi4IjXC7UvrBbMmZ14atvdTIU6ulbWBOJDwSPRPWoNlCP6Agwn5yAc7UtZYrPCKwdnoInvRgVFExdkCxRRA/9hWHTZSDRL4RwCS5gNrOC0kjZpjxXsIn/HRQX88Ccu+CiguQaz+Hkqrrz9TgyGst5XzAYpE27nJt8sKxSmfutTcGNznrcVpubz2JBvDsBWpcu7kqiYYPSBss=
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba016.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDJvfDittrxdf8JRxfbRCMYNgFz45xWZJFbFUzMuhdi9fwXnAgwIBjp9cy5vn3Hqm5zIwC5YHLOi94yJTL6qxXX1gP+voETx+3oRGsw1cohCjp27vtF+ZEp8mtcISRAhFEH7ZUWqESj0bTjYRhM6PW44swHtDofxBoJbaTktdogjnEzwwnfHDVbZwQ/u7790Z8jTFeVVau/b0iaL9KEM4nBPw9nKtEb9pKbeh824tdp+WTBbr0PYWahabkj798uHAZVMQpMU3PX67pX+Vj97ACP+uM5cBsNE2ub3MttUCEUTuxhF3+ZHZ9GJSgeZN8uowYJBdtro838H++ED3/9IPKsvK0uz7divoYlUMCLNGC4N3BkDQWbC7Pjc6X3zReVtMNYRyyoqYE4iElZJHF8X0VJ5Us2vr23Q/5b3ZhlF+N8fEiCAXXPE2a2t4Qia7Beenk3m38zO8A2NA/a4+iiC3XZjjfSlpDBkhykchrdrKEUza+wigIwTcs+JMoj5tPAsg0=
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba017.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDIHT9ZF7r5PZOgCt+YlLybf/sU5d8JksuZrj4In5oQ5m2BqJ8bhzDt53L9CxSe7CR2Q2F77JhGbxARvwxQZf3F2HiJsIATJtK6pwzTCLfIzUEXMguPpJfz3GF02H0/nJa0bvIhlK6SUS8unovlH+OstK8bfqb2zqI68IClck3QnsGpVrsShXeS7jEjBEPW2WsXz8LHIpRc5McC3h8MvlptaZj1yTpOQTX2WaRBL1+vT14ENuMYNnFfzcOmg4w0mMd2vHLLjwFKl5xXMCOJ1bxxadUFjQVw0ArQebibSoMJ0xTthqHLx4rxNR3oZ1RI4o0cnZRJMi7shQ9jWOp+ZFbX
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba018.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC9gb1+gxttUusCTd61O5E91jTJOJwe6mVJYsY7Y4Lvl2aUXKw5+EK4/SKxU+KuoLgg7mKOSmXGL7WIV9Ma2QGImbYv1oNULJNRQ3kOGc17aHmeKqTyg3cCLdYewA9wJryk+WCM7U1jvO3Qzd+UAr1EnHugVWx6VU2KSC/o45Z4Ot9ljLFs+qq+WHDZsXfrC8wP5qLD5h6CcZa6Mg8LByYFvY1wbfNNGckHFmMEntI+h6qxJyUgjk2Em3WZhPFDO+nCH9114O2PHW5GvxCNqjcSXn38xpVGEA7N8Yq1wRAVCIGKRlTHLVlazEnv1u8SbqlVyUm/xLwL2EUxoxTMjboNtgh8p9yjIHzIecEr2Q/kKAu3/X5yw7V223xRbaLGSm/o79glgdeWB42TY0XMYH57fuZovobJMtjqzLfayKMjRCVlK4FifQWJrJJYjtOvlBqHttNyuS5hR6r3NAUkcfYZblwqKuAzQ2WAfy2Hq8TSJ7KyIoNzp3KvOJA9TGen4xs=
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba019.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDJ8X5a1B8j03QEXuu+6HMxuzNL1xDndmxwoui0/KGM3No9syFQ/OqqP9j3jYXbBVtYVOkv+QLdBEBNRaiUIM1QeDwWeDHn1pM0rH7EOzPqf0TiIsH8CSKTdsvruDtpFzTa08AYTVxjxM1j3A+BAdv98WIeSOeiU2uOixufzpkKhU69nFjo/xuPTfi6HRs5x2/1mWvJhxBz4B0iEZxVeyPU9VIWM11m9HjjMTMRGKer5nD6N54GTAxRZKxP3yUsoXupP4+PXMr6go3H9EHVLynrcftmBPqhpNh9TF2Oz3zK/mXUc4h0FrZQ1a7bxOEZN3kI0AQECuk77/yGo503ttGN
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba020.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCjDZLjymjqQV+WLD2gSqjYAMFhbyGKNjhMoZyVDaTRpsiF9nRIqP5cUrmjKHXC3WdrwwzzpkYRVsx2mbx9OaKNrOpW7bI3JRgWQSt2tYHo8RYbOVvTqAQb98Uz3tiwHOim5l1xrXi2LP6C6UL2F1HhkoRkr3NzwbGM+wXuyCkUW1e3+KR0GSM/f4QqXthFGcMPJ0Jx9qpyvuAuoNUJAiYl8buN6OZOJ3N3FHOd+d+31lD0PIFIeJVkgs5efWL8NP5koPkVbDtkqEsQhfTEFMeeJDEszAozOQVojOZ43oortWhU/j+Gc6UIIKndVPEyph4qsFVCFubAl5EIowPAl/iOeTnNgi37h65GFvYEIc2/H2gb9bUYsh4IqC0Z2fd7ysCdLbP1mNnFR3o/qOMDKwxrXUVfRvx2tuDzBsfX7gz5lm/nQ1Rjpjrzzm4zw8yJXH9648UofdA+YDDqeNc++0dilTEU7e0S9WGWznkO2EXEotDKcPK2/ujqdYXTFyEemnM=
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba022.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC2wgHVO4P60mIQvyp0LQ+69oGqn0rOrTsdg7lUEhrKJOTzlYbaszgIuL2YEgSCcjkKBZXnJrr2TgDfeSrZ0rgm1XMOlPb0YbB6Fgm8nd/5yFgbuSxAb8+ZDp2yQXdqB625/DJAl/30L7ZT788nKa5r5TQdyImqTf3nfHskWsmP+sZ1Sfyds9AQz+DsrR59NrjiAn1GTXmQKRQKHoKt0GKYCS0eSZW6psLX1R+KGnsr0b6bZQIuwzSWK6KI7UzEQwUhWZvdMrLx85i/G/UE1JxBd3wBz5QV1xRlJHMDRg+Ox2UYM6qP+SiG5IPSSWxGyPYcaQO8PKBv0dZlKQIFZq6Ny3F69v8uHjb4u7i5uQa39Qc0gkwnx9mHUmZ+/W1m3c2hTNhcKC9iSp25lH6+pxYu5mD6Ikei2YV3WnkXedbcNaDUcgcTWl/pnhP34vgHe8Xd3bWwhX79tatRorXzXIUbguM0Bz8Ad4mJ0trRsDgrmGF16142S5fjWrt14duAngE=
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba023.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDBFsziErGYsgcm1FMe5IBVXtXhjquo3lt7SLyfIIxVQDEF71uDfRVrSR5M7AksJHsW54kLLPHqTY/VY4L1phFVBOdcufjyKgtnJMf4g535kLuBv7TNydLtJrm8Wlo3xuxJ2AiqaJBEFLu8/Lz2S2o+pJGxwpkFmZtQv0YcLIAIZYxxA6Lv93QNIGR2izBNMRB6iLJJeJb7s15PLReC0nnfAFVAJFzR0H+Ia/xc3Qh/EU9/UoVVb01RGzyxY9NE1LN+oSxJNUOxHjnG8lOT1zr21p2No8tsp4C4BlQRyh5LKceDVvdCoAldMafGbZm+USR+HIa/4UjR7w/C7XNCR4QWHpQHCvjXvFsgG9IIIhlWITvhcX72UW+61j4z1nl5/YJneS0/9MPBs02KCR5FnVpGHsKPe8Gccytcob9m5/juxlvqQUuRk5q5dN/Jp+W4ALNuA1/U/pd/5It5mQTK0cQbPBb9VTx22H4JFSRxR3lCbygwWuYMsVWspROAEyQPksU=
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba025.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDY7KHBxoQC/V7For5vkc3OpCbHvJjzkabFdOslsgb6s+2iir2ioUXRs6+CRFErAXIHIAySci2oL4Wy7nvOLs8ObtSwiqAW3x/3QlDNwR1eBTj4dEHE0BgqkkF/3oYCizMLXAHKnTUAXIo3tLPV+GDLpQhxTvj+z/UFu1Ym2Buv/1BCgQXw6Ckae5sOKnnJyyls37R0AU+pRRbPox9Q8nXBMRX8zgzagBa8H4Ek5tfh6qDsLlCKSsf/BtkDWmQp6ocgMnlqUO8EY96ma32tIEMNxmeMDI60TNs5w08TEQLQRcxPyiVAS2cKh48EeEz5WZTmLvja8tSKv/PODPQVWImKq4v/M45/d8fkOcfN5uX4e9FU4TzFblQRd6gCDwnrSurYEWkH3isSijaDApstdUyS/TTYuZdIyDKeB9se0xzwKNGyVC/ekF/g2vfA7bMMz1wikyuqu1teeDZ0FMkFQS3o+/GMkdsSQiSqH79knzBZC95lbKclH08Y2RUvzdBLMTU=
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba026.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC6tTtCFtRHgrrnE5azGBzWkR+AsC6JS4BCNwoui5zTVHOshxmErcfO+o197QEufexQqBxgmYvH1JtgFo67Mx3fXaUHXqN99esCezMUIg9AD487ooVTepGO5+6VZd9VuGRI0rZeaAftQGxTk+eUCvdH4NZFHOdOV6305wLBEq/wu7dIlZijNp9GPlK5UZN5ZgmZYnV7rQq5RGlk/NmAJSuHI0x0poAeGd0snfv/KEs+hW/PwLlriLvYTgwpi/PhZdqREzqTji1W9fCaPD/XHBARNCd9HjjHDCaXwq+xYjNqq3FmQZdHAooTkcBMwaZs67v5NT20wYXT/SbRFi7qawEz
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba027.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDlIkiKVt3QztKJklTE/2kqaiFIZCmvXwaQj40dt5FBCPtgW2Iv3Vpfz50cqvqp/JJtDWQhBt/DEkp7iVWWmXs0W/f3wWb2XS7uWo5sJdo7UNZfS+O6GIREkQjJsyxj9+8R2Z6YbkT8ZTSPeUR8qak6huiDmdmKhiLfXd12Ji77Hc9Je7vio1chWPrypFTlOc945m5evLbiJbZsLK4YgD1my1I60unnthBRst5x7QbYLB1r91WNOyV39F99C/S1qV/Ql9grFyZeEgTUDQkjey8MlV/4eVgAvvvqxWg0ipuVwKdK5BuTU7nG0phHBJcpP5HOmBjPt5ifxz8SASskCmRf
2021-06-24 20:58:31,640.640 INFO:teuthology.kill:  gibba028.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC+ywPjo8f2b0Xk07wQ+wImARSgo8a9XSSPJNaotVZPBwtA37ikXMdtJ57a4tVJli95YijliwwRqEhxQ6m+dvZr52rBWGU+GrWiQPLZlAVuMBS8CCJQ09b4SwnvS0BZo4ePLGU8mHYVZIVoLHxsw3SVqBa8v57GSaLMUvNCHv6JeyAGi875usmNbdU3Ij6SPyXqnlGffBk/OUBUlwiV4Sp65GkAYskiAK0QluIh0TxO6c5Q5MgRVN/wDMevLNto3j2ALdDdf9zEWHGbplqf0zTRsUuhi6hjrVc8kF8e7uiCXgSGy4B8+EmFtlrSp5exCFOEheMEk7DkolDXJSz6vIuL
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba029.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDZjk1dzIaELpY/XDrDAqBzebcKM9lPbcyZ9LUQpcCgBvD0yXV5yR2vhbuLSt5dyQ81qBApUqjP900kNQBJChNyAO9Rwc6Haw0z6Ff+1LbsaLFi13gw6f8TQ0xJS9fWJ/4QroSkOidwX1nAQAZFEmlhMBpbLJhHWFlRLYe9eX4ykF9umWjyDJr7Ccneg08dlsNPsu79DNCBNuVaZ7DMDf8G9JW7qj+JB3Tj3oCV64Hih8GS7HtcCCkpP4sNXfMDXDc0oEm9En8pfkbClHf8lIhAvlveNB/+OmcoTke0UOqYnMluQhD7x5cSznDxoacyvXtH0MHzvv2QzqbVE1cQlIrn
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba030.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC1Shi7KNhaJ6WY3dkOZtXxBnOvQVyxApNeJRYap0avjm8g2/gx+Jyfg+BT0NzkPNY3wMvCUdfBNqvtuAbwqOvYeEwn7ILmyxy6V+dQFVTyUA6AaJhGUcp0FaHd8F8QqHssEi4x4qpOKUJo8j/FxyhHqyO4MYUt2nnAs3MgunpkJSxzoywXyMO0v9D6b6ymNE+bcVHFqSmNd7iG8Mf6pCzoueHATZFXjqnUx+XBoF1mGm/jQr5fo7tQBVteDmtbhJy91nfaHXhLB1meb/eoBnzx8lmqVCiVnNmRQ1t5CvM9sit8cBb3cGie0UBmbzLIWUQXKlndRDsGIQ7rdb0lS62y8/6m+x80ZTP87+YwJsBDQEsV4ZxXea7P4AKt/knHwXD5j5Kut7CGt0kt/s3p+pv3/P4Ty07pX6tJqLWobJpNRrOoLT11qSqBjlWeRM8Xcjx353EUKdzOmR2df/USluy09kxJMwHU3E/xeOSigBCp10H43Nt2bbS4cyVTC4tHmTM=
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba031.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDPuxHPi0R+gxEmObY145HSHM/wJElcF6U9VWgmzu0VCzCpm6MWLX9uoxDCixrmA0hKnmzGu8KQTcIhTgiZkBjpGRjeWWoseGzTDwTGKFdURm6YPCo8aEErZ7B+zsYqDWC2mhSEEFG9v6T/5DhMaRvv3kPfH3jD3TermgL+AZzI6dFCSu5drtuBSKOM1C9FB9KjXXm20GiIrTDrsmvNrntk5ayVqG1U4+NKGFCkQ6EB2TqxFVnWMM4ji3q8s3DlPwHTPQkaDQnZQSHqqJRpPKhudfBT+GChSxQk+y0Td7vAOCaJphkZ5E08h9kZ/XfLDPXWGzVMZ6s9qSQQ6h+TkwW5w/7c2RtCjaJPhwfSPDO5eZ4AZjvgLqLfH34vFSXzk91CR9FNskQu8a7f2yYn4xk0GbfDIjim5tiWcqy+I4H/A5TH644nlPqRCZoVJGdG5UNbIpzrWp4W1/WckQ6d6uUXNtH3PXHSwvVjKKzH0BIOzK0zSuTYn2POY3V/OEpjiAE=
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba035.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDgHQwuLaS6vtTE215XIoqUzUCGVcTVokS6zAZHCFQU1cQKxWiODcD5PurH0LLWg5Z8UoP7J8xLAMCWmuqXx4koWmxewJkvSMVuJlrrJ8V0wiNlOMODGqlnP3ZFXCW4Whe7OWY8JHQSHk8ZX9xqslJYy0iPfwWFlxB0kML8z10GNEDa7BA5PGfaa0KPWQvAzBhg6AS5mitAjLLebYebT0c4vPaqdPQufQ5vn5QZAli7tI9PvgdNRJSzkvaKFeZkS1cJraA9Hu05NNpxWc+yB5G4T9tfhg6hfqeHgc+kDszUREOPBTlhy47qrUal/E36epXexx/c0LPq+26KTJJH+hdNkKZozu2h46RyENMz0/93kn3JsiLuhKkelapld8PRUIQYw/4C3B9q0fa2a9lUymyJy8Spr8Fu1NulGjhvJJgywgnzyFaDk7LtmBVPlv49Gj8rC1RQS+HGkM730zj8Ki66g2musO7k5Ja25PD+Haf3AZqU5FwGXsdS8YpRtkZGK2s=
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba036.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC/PH2qXwcM+qkIaMNvpZbT2POuuvVC40J2wF6wWqHy50+dgcqzzLKplu8EVp4zenUsxrABEl3iFjtqnAu/ZMery0S7mQcjrNuXOoARetq36M+naV5QkKaiiA+juquXBg7qFaP+7jg5Nq8TxJVRQBhUTIGQ9TAwa3nJ4g66nZg1FwAFOshdGUe2ASrV3DkdAMO/eUt+qa9RQe86Zolgp4beXOJIHT/X2TEZp0CA65z2IK4x1h6rKrvSQm+HhZWLrpZGjoz5oKswFU4Qc6/WshNl4TajwkXPm2ylQeKkPfWKy2koH3UVXSOd0kmWZrFwxbGCNHjwMPtxpuvqhbDBFpItfmXzeABhY//R2dpwoO2vlyzAwIno1Q1bFA1uNOTz8o5Wtok7UlpU3x1H0q+amiOaxKb7kt824Fu5OXeyoiL4QRVkiQ/BUetq+99Ogze4NJ7GlVvZgge2If7cmbcIz/3hUF47hete+dZKV9i1fETWYHsalmvkGr7e5h8z4eH35rM=
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba038.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDYHZHxdqQN6uj6O29QHBPGGVWBchTLQjA7zpTw07kyk4QyLeepcESxsDLO2cMQ3GQer7z9rhKKQ0ot/6AqeOHS0QdkdfzrfP7NGXsGwcByQogq3Gq/vQaj8GQ8p+mgYJ5xNNPL4bzEZJsX5luvoLKcxURtjhlgrCU+U9iyqWlqGsvI9xvqVnHI63GD28JmNPj0piGeIeQGzEOV6gIuYiqKOJ52GMNkQE7sp/dnKAfopkjFhE/dXZ/ay8y3ZTbnn3B7g3c2CizvpqjhJ8F+82sJtheY40YzUctxQZtSw7cXkXQ8w2MOmpQkeqsqRW34/HwPZDYGKIY8gP3Rs251rkntKS5kHYIT3sTAO8KHRYvfI6uU4mtDQ067Oqc123e1m7RuNUuMv/aF1Frx5jz6eV/ImHphOmgQlLQXxfJjen0aQxCOm2KyQFTIYQ/AkOvxipaKnYtowqnS5ViK3sqCwj4kBFELfEEdxYVUTnQKWvqzRUfuPsT2vD19fKaON0FIRxs=
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba040.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDAy6A3xUwBjYVGjRoRo58dxsgydihrA/zIgLbFRhmr7PyyIuPAxOQv+iRypjdGQ8RtiQeoANDFxaqzjbsgpaAziQHKZCvyUflsIHUGhfEzsz15lk984fG/Zhp/xPAkdz4i76+LaaS5QisFGjuD2WkZT4BE9ksGeeVHzbRdvShIlLjuJb+yRILMkKPsUpkpjToo9W26fQqIqTjGRFH5pWdT6AGowXs6QZ4nP6t8v42SRN3I9OI4giIkj4eVFcFwfj2SJC8XWtNkhUP96h3uPqOXf7nVLPfBoQJGcnrM9dafcxZBhkAldYaRhOepQHEO0b5h1rbTwC8jFjAUKWxxA9aj
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba041.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDTT4JYu6yRFlSBVOaOPkN/mo3xXyPzJAB46P1k0bE455ilpOZFmeprieyzxgC2hRfPbmQs56D8lRVBy6U6rxxoxoQaXYEwYwK7BTp4sfgpm27qArRRhUlzysF/UFlBvmDWANiHmwaPhiagNgYhnJWF1cLAmKvvdvJNkhctO574NTQE0C3vSq3Vdabs3dzDSus4Meui1zadzdzZZc1eU6a934vaT0DphTIlOxE3MPNpRtPuHETsT+Mur8igA6w+UXfnZR7MX18EF3wVsem9XN0sHsjTsYiRHwHER143wdPBnCp6/cr6z8+RemI0QxSnhj4SUsbUNNn3UxDd10iIeKVj
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba042.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDti40VtRrUyNl5sG5UUd2bEYAfXKh+BCcksKcOT5xt7dexDUBv22bq9CNTiwyg2xpsiorgXZgRI5GxEdXnSuoATmNIsprdRTu5/sy7fw2QONmHke+Hu0Ic4wL+ASX0My7i3OEnFXtadiG74DVd19auXKq4RF1XisPvmWseHBArsUGS9aJuvnlaCwMgXk8ItAkvmBu2M2E+qPbnOx0I9/6TBE+Fhc9CQsSPNfexXQ2VG2lnB4T21cad0+A8ho9ufpVLSvs8J/74g6BzJ9Y7BnFQ7ViU0KuVWkgLWDrjSUA5apgQY+o5AmZ/XV8lU0q8V6DR3nKyBZBUP2RVIoqidy0eUs+NvBsKIwsSn+NBC1qgaFvyF1k6m3p1vneSI0Ys6mn1VrWzBCudN/IzC8QZETh1XUHijNzQH5iHu8jOST/vUaLRDx/sIJIYRQheoaP61PugqFWg6krsG9Hc9Xqn2Bu2+v0U/Wm5byyD6sMhC1tr0lnlnDwZwKp7orWEbw89Wls=
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba043.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDE7wEzcDML6Yay5gIxe20mIgHS2jr2jzL0NfPWJ2283Vtl2Fhflc8QBIZv5ZNRxqbbC2zhOyc4cPnh1KPH1ROopSzclQ3QEvNkqJjeXyejXUINZ4Jhz75IDoReTYptUQ0/fenbl6zit2hgzlpYJEzJdZEKHal/Vw8/bFwN0Pbq4wtG/0MimVU8XCnIcAwYiH0wVFIwMK0eYR183ZpRBfihmPZDE21KIOvCvHlrtuKS0HubOZ+ZJ+91UhN9IYUazp2rhuwZ3WCidtgZartWFmD919/Q3rZB8HD9oujj9LHCKaU/BLbEwzlxP/TNlPRB7iGrvJwNYSg4qzvk6TChMf7j
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba044.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDGVStz8YLnViw+ESmpGxoW2PEcMc4MZvIkj8Km/L6M1AjZxIWQWA/fWk1haeP+VUxVfVS0fluCrkaX/BWfqJNtxGbsmQWvR5MYsA8uunYdl1dqud+aA06M0JqhnGMWtCm8huaSQM8X7RYV2+XfLDKzTYmPglxlnyeO9ZkCwKHI8X+P3+9jw9MWV8qeGtspDhXD5hx+ZduUiJzyo+0shQnQlKH0qLIYfzCPm/C6j/qQdF4ONPe24BG8ARp+E5LHvS1sUCY70dEW4Hn41H1kK0mUdkY4ejSFnV1zbZ3DXa9Vpc+SNA0jiCgLR8a0Ibb/rokyZ7PcTT0rKIBMEHL2gFqR
2021-06-24 20:58:31,641.641 INFO:teuthology.kill:  gibba045.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC/HFOWl3CAx/68LjFt5eZ7SgrNaam8w2+l3MYy1RUMsudTfm3zVSoAudnpdJ65GzEtrtC47N8O8HlVDKttrB++CNFTY4NgEuwfs/eM98hZI8dxDlGVm3m0gF34d2HtoZhe+RgLUlIsYwaAi83MkRJc3epmYGbTFspG1sXs2T1p0E3MJqeC/s3bjc9/VsCr0aePAJRHbyxEy1CWQ3NSyERsS8HHU+MSe9uEuOx798bmr0Tgg8qs0s6Ha2aUUOmUBemFua8B7CF/NIsFVM/arSsgX1JJ0Q/LKf+GaBhNOf6UYHz9mzZqYQ4aglIWtftwS+PDXMvFgglETiAweZz/+Yd/FvTwshzXZk1O/S7RyuCo/OBbgDDkG0M3ck6KIbqkderkohORiXoKE+XQW7xwYa8mL+Mn371jd24bYHZMvO9rSsON7ZpvmRJ6NEJD9TCFm4z546lO8Ls1RA7ACK4G6qGxolpFn1DdPE5/NPJIR7Tj48QEXYMZC7tsefoWMtScaks=
2021-06-24 20:58:31,706.706 INFO:teuthology.kill:2021-06-24 20:58:31,706.706 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,713.713 INFO:teuthology.kill:2021-06-24 20:58:31,712.712 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,714.714 INFO:teuthology.kill:2021-06-24 20:58:31,714.714 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,715.715 INFO:teuthology.kill:2021-06-24 20:58:31,715.715 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,716.716 INFO:teuthology.kill:2021-06-24 20:58:31,716.716 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,722.722 INFO:teuthology.kill:2021-06-24 20:58:31,722.722 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,726.726 INFO:teuthology.kill:2021-06-24 20:58:31,726.726 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,728.728 INFO:teuthology.kill:2021-06-24 20:58:31,727.727 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,734.734 INFO:teuthology.kill:2021-06-24 20:58:31,734.734 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,735.735 INFO:teuthology.kill:2021-06-24 20:58:31,735.735 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,736.736 INFO:teuthology.kill:2021-06-24 20:58:31,736.736 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,737.737 INFO:teuthology.kill:2021-06-24 20:58:31,737.737 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,747.747 INFO:teuthology.kill:2021-06-24 20:58:31,746.746 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,748.748 INFO:teuthology.kill:2021-06-24 20:58:31,748.748 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,749.749 INFO:teuthology.kill:2021-06-24 20:58:31,749.749 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,750.750 INFO:teuthology.kill:2021-06-24 20:58:31,750.750 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,751.751 INFO:teuthology.kill:2021-06-24 20:58:31,751.751 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,769.769 INFO:teuthology.kill:2021-06-24 20:58:31,768.768 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,770.770 INFO:teuthology.kill:2021-06-24 20:58:31,770.770 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,771.771 INFO:teuthology.kill:2021-06-24 20:58:31,771.771 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,773.773 INFO:teuthology.kill:2021-06-24 20:58:31,772.772 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,774.774 INFO:teuthology.kill:2021-06-24 20:58:31,773.773 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,790.790 INFO:teuthology.kill:2021-06-24 20:58:31,790.790 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,792.792 INFO:teuthology.kill:2021-06-24 20:58:31,791.791 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,793.793 INFO:teuthology.kill:2021-06-24 20:58:31,793.793 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,794.794 INFO:teuthology.kill:2021-06-24 20:58:31,794.794 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,795.795 INFO:teuthology.kill:2021-06-24 20:58:31,795.795 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,797.797 INFO:teuthology.kill:2021-06-24 20:58:31,797.797 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,814.814 INFO:teuthology.kill:2021-06-24 20:58:31,814.814 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,815.815 INFO:teuthology.kill:2021-06-24 20:58:31,815.815 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:31,817.817 INFO:teuthology.kill:2021-06-24 20:58:31,817.817 INFO:teuthology.task.internal.check_lock:Checking locks...
2021-06-24 20:58:32,002.002 INFO:teuthology.kill:2021-06-24 20:58:32,002.002 INFO:teuthology.orchestra.console:Power off gibba012
2021-06-24 20:58:32,019.019 INFO:teuthology.kill:2021-06-24 20:58:32,019.019 INFO:teuthology.orchestra.console:Power off gibba040
2021-06-24 20:58:32,058.058 INFO:teuthology.kill:2021-06-24 20:58:32,058.058 INFO:teuthology.orchestra.console:Power off gibba008
2021-06-24 20:58:32,072.072 INFO:teuthology.kill:2021-06-24 20:58:32,072.072 INFO:teuthology.orchestra.console:Power off gibba044
2021-06-24 20:58:32,092.092 INFO:teuthology.kill:2021-06-24 20:58:32,091.091 INFO:teuthology.orchestra.console:Power off gibba035
2021-06-24 20:58:32,114.114 INFO:teuthology.kill:2021-06-24 20:58:32,114.114 INFO:teuthology.orchestra.console:Power off gibba028
2021-06-24 20:58:32,129.129 INFO:teuthology.kill:2021-06-24 20:58:32,128.128 INFO:teuthology.orchestra.console:Power off gibba014
2021-06-24 20:58:32,141.141 INFO:teuthology.kill:2021-06-24 20:58:32,140.140 INFO:teuthology.orchestra.console:Power off gibba029
2021-06-24 20:58:32,153.153 INFO:teuthology.kill:2021-06-24 20:58:32,152.152 INFO:teuthology.orchestra.console:Power off gibba004
2021-06-24 20:58:32,166.166 INFO:teuthology.kill:2021-06-24 20:58:32,166.166 INFO:teuthology.orchestra.console:Power off gibba001
2021-06-24 20:58:32,178.178 INFO:teuthology.kill:2021-06-24 20:58:32,178.178 INFO:teuthology.orchestra.console:Power off gibba041
2021-06-24 20:58:32,193.193 INFO:teuthology.kill:2021-06-24 20:58:32,193.193 INFO:teuthology.orchestra.console:Power off gibba026
2021-06-24 20:58:32,207.207 INFO:teuthology.kill:2021-06-24 20:58:32,206.206 INFO:teuthology.orchestra.console:Power off gibba010
2021-06-24 20:58:32,221.221 INFO:teuthology.kill:2021-06-24 20:58:32,221.221 INFO:teuthology.orchestra.console:Power off gibba043
2021-06-24 20:58:32,253.253 INFO:teuthology.kill:2021-06-24 20:58:32,252.252 INFO:teuthology.orchestra.console:Power off gibba030
2021-06-24 20:58:32,264.264 INFO:teuthology.kill:2021-06-24 20:58:32,264.264 INFO:teuthology.orchestra.console:Power off gibba027
2021-06-24 20:58:32,275.275 INFO:teuthology.kill:2021-06-24 20:58:32,274.274 INFO:teuthology.orchestra.console:Power off gibba019
2021-06-24 20:58:32,286.286 INFO:teuthology.kill:2021-06-24 20:58:32,286.286 INFO:teuthology.orchestra.console:Power off gibba020
2021-06-24 20:58:32,299.299 INFO:teuthology.kill:2021-06-24 20:58:32,299.299 INFO:teuthology.orchestra.console:Power off gibba023
2021-06-24 20:58:32,313.313 INFO:teuthology.kill:2021-06-24 20:58:32,313.313 INFO:teuthology.orchestra.console:Power off gibba025
2021-06-24 20:58:32,324.324 INFO:teuthology.kill:2021-06-24 20:58:32,324.324 INFO:teuthology.orchestra.console:Power off gibba013
2021-06-24 20:58:32,338.338 INFO:teuthology.kill:2021-06-24 20:58:32,338.338 INFO:teuthology.orchestra.console:Power off gibba031
2021-06-24 20:58:32,373.373 INFO:teuthology.kill:2021-06-24 20:58:32,373.373 INFO:teuthology.orchestra.console:Power off for gibba040 completed
2021-06-24 20:58:32,380.380 INFO:teuthology.kill:2021-06-24 20:58:32,380.380 INFO:teuthology.orchestra.console:Power off gibba022
2021-06-24 20:58:32,392.392 INFO:teuthology.kill:2021-06-24 20:58:32,392.392 INFO:teuthology.orchestra.console:Power off gibba038
2021-06-24 20:58:32,405.405 INFO:teuthology.kill:2021-06-24 20:58:32,405.405 INFO:teuthology.orchestra.console:Power off gibba016
2021-06-24 20:58:32,418.418 INFO:teuthology.kill:2021-06-24 20:58:32,418.418 INFO:teuthology.orchestra.console:Power off gibba042
2021-06-24 20:58:32,430.430 INFO:teuthology.kill:2021-06-24 20:58:32,430.430 INFO:teuthology.orchestra.console:Power off gibba036
2021-06-24 20:58:32,441.441 INFO:teuthology.kill:2021-06-24 20:58:32,441.441 INFO:teuthology.orchestra.console:Power off gibba002
2021-06-24 20:58:32,567.567 INFO:teuthology.kill:2021-06-24 20:58:32,566.566 INFO:teuthology.orchestra.console:Power off gibba018
2021-06-24 20:58:32,577.577 INFO:teuthology.kill:2021-06-24 20:58:32,577.577 INFO:teuthology.orchestra.console:Power off gibba017
2021-06-24 20:58:32,588.588 INFO:teuthology.kill:2021-06-24 20:58:32,588.588 INFO:teuthology.orchestra.console:Power off gibba045
2021-06-24 20:58:32,618.618 INFO:teuthology.kill:2021-06-24 20:58:32,618.618 INFO:teuthology.orchestra.console:Power off for gibba012 completed
2021-06-24 20:58:32,626.626 INFO:teuthology.kill:2021-06-24 20:58:32,625.625 INFO:teuthology.orchestra.console:Power off for gibba026 completed
2021-06-24 20:58:32,628.628 INFO:teuthology.kill:2021-06-24 20:58:32,628.628 INFO:teuthology.orchestra.console:Power off for gibba001 completed
2021-06-24 20:58:32,639.639 INFO:teuthology.kill:2021-06-24 20:58:32,639.639 INFO:teuthology.orchestra.console:Power off for gibba002 completed
2021-06-24 20:58:32,642.642 INFO:teuthology.kill:2021-06-24 20:58:32,642.642 INFO:teuthology.orchestra.console:Power off for gibba028 completed
2021-06-24 20:58:32,643.643 INFO:teuthology.kill:2021-06-24 20:58:32,643.643 INFO:teuthology.orchestra.console:Power off for gibba036 completed
2021-06-24 20:58:32,644.644 INFO:teuthology.kill:2021-06-24 20:58:32,644.644 INFO:teuthology.orchestra.console:Power off for gibba029 completed
2021-06-24 20:58:32,645.645 INFO:teuthology.kill:2021-06-24 20:58:32,645.645 INFO:teuthology.orchestra.console:Power off for gibba018 completed
2021-06-24 20:58:32,666.666 INFO:teuthology.kill:2021-06-24 20:58:32,666.666 INFO:teuthology.orchestra.console:Power off for gibba030 completed
2021-06-24 20:58:32,666.666 INFO:teuthology.kill:2021-06-24 20:58:32,666.666 INFO:teuthology.orchestra.console:Power off for gibba019 completed
2021-06-24 20:58:32,666.666 INFO:teuthology.kill:2021-06-24 20:58:32,666.666 INFO:teuthology.orchestra.console:Power off for gibba043 completed
2021-06-24 20:58:32,667.667 INFO:teuthology.kill:2021-06-24 20:58:32,666.666 INFO:teuthology.orchestra.console:Power off for gibba017 completed
2021-06-24 20:58:32,696.696 INFO:teuthology.kill:2021-06-24 20:58:32,695.695 ERROR:teuthology.lock.ops:failed to unlock gibba026.front.sepia.ceph.com. reason: 500
2021-06-24 20:58:32,701.701 INFO:teuthology.kill:2021-06-24 20:58:32,700.700 INFO:teuthology.lock.ops:unlocked gibba040.front.sepia.ceph.com
2021-06-24 20:58:32,703.703 INFO:teuthology.kill:2021-06-24 20:58:32,703.703 ERROR:teuthology.lock.ops:failed to unlock gibba036.front.sepia.ceph.com. reason: 500
2021-06-24 20:58:32,706.706 INFO:teuthology.kill:2021-06-24 20:58:32,706.706 INFO:teuthology.lock.ops:unlocked gibba001.front.sepia.ceph.com
2021-06-24 20:58:32,707.707 INFO:teuthology.kill:2021-06-24 20:58:32,707.707 ERROR:teuthology.lock.ops:failed to unlock gibba002.front.sepia.ceph.com. reason: 500
2021-06-24 20:58:32,708.708 INFO:teuthology.kill:2021-06-24 20:58:32,708.708 ERROR:teuthology.lock.ops:failed to unlock gibba018.front.sepia.ceph.com. reason: 500
2021-06-24 20:58:32,719.719 INFO:teuthology.kill:2021-06-24 20:58:32,719.719 INFO:teuthology.orchestra.console:Power off for gibba016 completed
2021-06-24 20:58:32,726.726 INFO:teuthology.kill:2021-06-24 20:58:32,726.726 INFO:teuthology.orchestra.console:Power off for gibba025 completed
2021-06-24 20:58:32,726.726 INFO:teuthology.kill:2021-06-24 20:58:32,726.726 INFO:teuthology.orchestra.console:Power off for gibba031 completed
2021-06-24 20:58:32,726.726 INFO:teuthology.kill:2021-06-24 20:58:32,726.726 INFO:teuthology.orchestra.console:Power off for gibba038 completed
2021-06-24 20:58:32,727.727 INFO:teuthology.kill:2021-06-24 20:58:32,726.726 INFO:teuthology.orchestra.console:Power off for gibba044 completed
2021-06-24 20:58:32,727.727 INFO:teuthology.kill:2021-06-24 20:58:32,727.727 INFO:teuthology.orchestra.console:Power off for gibba022 completed
2021-06-24 20:58:32,728.728 INFO:teuthology.kill:2021-06-24 20:58:32,728.728 INFO:teuthology.lock.ops:unlocked gibba017.front.sepia.ceph.com
2021-06-24 20:58:32,757.757 INFO:teuthology.kill:2021-06-24 20:58:32,757.757 INFO:teuthology.lock.ops:unlocked gibba012.front.sepia.ceph.com
2021-06-24 20:58:32,782.782 INFO:teuthology.kill:2021-06-24 20:58:32,781.781 INFO:teuthology.lock.ops:unlocked gibba028.front.sepia.ceph.com
2021-06-24 20:58:32,810.810 INFO:teuthology.kill:2021-06-24 20:58:32,810.810 INFO:teuthology.lock.ops:unlocked gibba030.front.sepia.ceph.com
2021-06-24 20:58:32,814.814 INFO:teuthology.kill:2021-06-24 20:58:32,813.813 ERROR:teuthology.lock.ops:failed to unlock gibba019.front.sepia.ceph.com. reason: 500
2021-06-24 20:58:32,866.866 INFO:teuthology.kill:2021-06-24 20:58:32,865.865 ERROR:teuthology.lock.ops:failed to unlock gibba044.front.sepia.ceph.com. reason: 500
2021-06-24 20:58:32,867.867 INFO:teuthology.kill:2021-06-24 20:58:32,867.867 ERROR:teuthology.lock.ops:failed to unlock gibba025.front.sepia.ceph.com. reason: 500
2021-06-24 20:58:32,875.875 INFO:teuthology.kill:2021-06-24 20:58:32,874.874 ERROR:teuthology.lock.ops:failed to unlock gibba038.front.sepia.ceph.com. reason: 500
2021-06-24 20:58:32,876.876 INFO:teuthology.kill:2021-06-24 20:58:32,875.875 INFO:teuthology.lock.ops:unlocked gibba031.front.sepia.ceph.com
2021-06-24 20:58:33,786.786 INFO:teuthology.kill:2021-06-24 20:58:33,786.786 INFO:teuthology.lock.ops:unlocked gibba029.front.sepia.ceph.com
2021-06-24 20:58:33,812.812 INFO:teuthology.kill:2021-06-24 20:58:33,812.812 INFO:teuthology.lock.ops:unlocked gibba043.front.sepia.ceph.com
2021-06-24 20:58:33,863.863 INFO:teuthology.kill:2021-06-24 20:58:33,862.862 INFO:teuthology.lock.ops:unlocked gibba016.front.sepia.ceph.com
2021-06-24 20:58:34,079.079 INFO:teuthology.kill:2021-06-24 20:58:34,078.078 INFO:teuthology.lock.ops:unlocked gibba022.front.sepia.ceph.com
2021-06-24 20:58:36,594.594 INFO:teuthology.kill:2021-06-24 20:58:36,594.594 INFO:teuthology.orchestra.console:Power off for gibba008 completed
2021-06-24 20:58:36,734.734 INFO:teuthology.kill:2021-06-24 20:58:36,734.734 INFO:teuthology.lock.ops:unlocked gibba008.front.sepia.ceph.com
2021-06-24 20:58:36,779.779 INFO:teuthology.kill:2021-06-24 20:58:36,778.778 INFO:teuthology.orchestra.console:Power off for gibba041 completed
2021-06-24 20:58:36,858.858 INFO:teuthology.kill:2021-06-24 20:58:36,858.858 INFO:teuthology.orchestra.console:Power off for gibba027 completed
2021-06-24 20:58:36,915.915 INFO:teuthology.kill:2021-06-24 20:58:36,915.915 INFO:teuthology.lock.ops:unlocked gibba041.front.sepia.ceph.com
2021-06-24 20:58:36,994.994 INFO:teuthology.kill:2021-06-24 20:58:36,994.994 INFO:teuthology.lock.ops:unlocked gibba027.front.sepia.ceph.com
2021-06-24 20:58:40,703.703 INFO:teuthology.kill:2021-06-24 20:58:40,703.703 INFO:teuthology.orchestra.console:Power off for gibba035 completed
2021-06-24 20:58:40,841.841 INFO:teuthology.kill:2021-06-24 20:58:40,841.841 INFO:teuthology.lock.ops:unlocked gibba035.front.sepia.ceph.com
2021-06-24 20:58:40,881.881 INFO:teuthology.kill:2021-06-24 20:58:40,881.881 INFO:teuthology.orchestra.console:Power off for gibba004 completed
2021-06-24 20:58:40,900.900 INFO:teuthology.kill:2021-06-24 20:58:40,900.900 INFO:teuthology.orchestra.console:Power off for gibba023 completed
2021-06-24 20:58:40,905.905 INFO:teuthology.kill:2021-06-24 20:58:40,905.905 INFO:teuthology.orchestra.console:Power off for gibba014 completed
2021-06-24 20:58:40,950.950 INFO:teuthology.kill:2021-06-24 20:58:40,950.950 INFO:teuthology.orchestra.console:Power off for gibba013 completed
2021-06-24 20:58:40,963.963 INFO:teuthology.kill:2021-06-24 20:58:40,963.963 INFO:teuthology.orchestra.console:Power off for gibba010 completed
2021-06-24 20:58:40,972.972 INFO:teuthology.kill:2021-06-24 20:58:40,972.972 INFO:teuthology.orchestra.console:Power off for gibba042 completed
2021-06-24 20:58:41,001.001 INFO:teuthology.kill:2021-06-24 20:58:41,001.001 INFO:teuthology.orchestra.console:Power off for gibba045 completed
2021-06-24 20:58:41,010.010 INFO:teuthology.kill:2021-06-24 20:58:41,010.010 ERROR:teuthology.lock.ops:failed to unlock gibba004.front.sepia.ceph.com. reason: Cannot unlock an already-unlocked node
2021-06-24 20:58:41,038.038 INFO:teuthology.kill:2021-06-24 20:58:41,038.038 INFO:teuthology.lock.ops:unlocked gibba023.front.sepia.ceph.com
2021-06-24 20:58:41,045.045 INFO:teuthology.kill:2021-06-24 20:58:41,045.045 INFO:teuthology.lock.ops:unlocked gibba014.front.sepia.ceph.com
2021-06-24 20:58:41,086.086 INFO:teuthology.kill:2021-06-24 20:58:41,086.086 INFO:teuthology.lock.ops:unlocked gibba013.front.sepia.ceph.com
2021-06-24 20:58:41,105.105 INFO:teuthology.kill:2021-06-24 20:58:41,105.105 INFO:teuthology.lock.ops:unlocked gibba010.front.sepia.ceph.com
2021-06-24 20:58:41,108.108 INFO:teuthology.kill:2021-06-24 20:58:41,108.108 INFO:teuthology.lock.ops:unlocked gibba042.front.sepia.ceph.com
2021-06-24 20:58:41,139.139 INFO:teuthology.kill:2021-06-24 20:58:41,138.138 INFO:teuthology.lock.ops:unlocked gibba045.front.sepia.ceph.com
2021-06-24 20:58:45,067.067 INFO:teuthology.kill:2021-06-24 20:58:45,066.066 INFO:teuthology.orchestra.console:Power off for gibba020 completed
2021-06-24 20:58:45,198.198 INFO:teuthology.kill:2021-06-24 20:58:45,197.197 ERROR:teuthology.lock.ops:failed to unlock gibba020.front.sepia.ceph.com. reason: Cannot unlock an already-unlocked node

Notice the last line.

Then in the paddles log

ubuntu@pulpito:~$ grep gibba020 paddles.out.log | tail -n 20
2021-06-24 19:45:45,058 INFO  [paddles.controllers.nodes] Updating <Node gibba020.front.sepia.ceph.com>: {u'os_version': u'', u'os_type': u'', u'name': u'gibba020.front.sepia.ceph.com'}
2021-06-24 19:50:21,813 INFO  [paddles.controllers.nodes] Updating <Node gibba020.front.sepia.ceph.com>: {u'ssh_pub_key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDJgrjPiAHY9xDwTezM+7DXJZK4OK7n+voePEwPD01GGqcAUpdvtYS7TaigvgEIjvrW+cdsFEGLrQOi6Lg7JMc7LAOl/Bq/nUxzl+gXc3Ea2qUgfQQsvLznJLx/IOemA/opNYbnb5dpzqgghUYZcgHUDFn+hDNGanFfcYInHpnVpYAfuxfbZxHFVqO0xX2ZYQiNZQ2e62pAyUOgDcJNhaCM7+yY+3OHiQZoirIzO/ajkeBTjW7y6OMaVRrOZ0KTS3JBdZAIsODqotzCK5xfu0RkENxWlRnlOIghGunP8GCyaQ91811Q6Ci++bHX/yp13s0CXQD7rbI1BclA+j6wCPhCV/I0o2ou0skkJmrmxZbFuuqceP+2gQIilvnmc4VUh6iKc/zSQm/NhN4VGbQsF/+eRU/dE6ZM3dMZPHbvQ75MV/A2+rbrCl8MggiYuW9cbhV1PHGvpWjwTmgwEDJUEF1KouFZIQ0Rf2djbr/IZDKYgwu3EYk031dTfNWxLs3nlfs='}
2021-06-24 19:50:22,136 INFO  [paddles.controllers.nodes] Updating <Node gibba020.front.sepia.ceph.com>: {u'name': u'gibba020.front.sepia.ceph.com', u'up': True, u'os_version': u'8.2', u'user': u'ubuntu', u'os_type': u'rhel', u'arch': u'x86_64', u'ssh_pub_key': u'ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBE6G4y0SqM4Y5alyQ9OnH6wJ9pUEZyz6WZiaJJfMVwgUdN3jTZc7MJPCO9sJ5G7RXHiB6mkCX8uhPQT5ObyQS7s='}
2021-06-24 19:50:24,258 INFO  [paddles.controllers.nodes] Updating <Node gibba020.front.sepia.ceph.com>: {u'name': u'gibba020.front.sepia.ceph.com', u'up': True, u'os_version': u'8.2', u'user': u'ubuntu', u'os_type': u'rhel', u'arch': u'x86_64', u'ssh_pub_key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDJgrjPiAHY9xDwTezM+7DXJZK4OK7n+voePEwPD01GGqcAUpdvtYS7TaigvgEIjvrW+cdsFEGLrQOi6Lg7JMc7LAOl/Bq/nUxzl+gXc3Ea2qUgfQQsvLznJLx/IOemA/opNYbnb5dpzqgghUYZcgHUDFn+hDNGanFfcYInHpnVpYAfuxfbZxHFVqO0xX2ZYQiNZQ2e62pAyUOgDcJNhaCM7+yY+3OHiQZoirIzO/ajkeBTjW7y6OMaVRrOZ0KTS3JBdZAIsODqotzCK5xfu0RkENxWlRnlOIghGunP8GCyaQ91811Q6Ci++bHX/yp13s0CXQD7rbI1BclA+j6wCPhCV/I0o2ou0skkJmrmxZbFuuqceP+2gQIilvnmc4VUh6iKc/zSQm/NhN4VGbQsF/+eRU/dE6ZM3dMZPHbvQ75MV/A2+rbrCl8MggiYuW9cbhV1PHGvpWjwTmgwEDJUEF1KouFZIQ0Rf2djbr/IZDKYgwu3EYk031dTfNWxLs3nlfs='}
2021-06-24 19:56:23,160 DEBUG [paddles.controllers.nodes] Unlocking <Node gibba020.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2021-06-24 19:56:23,161 INFO  [paddles.controllers.nodes] Unlocked <Node gibba020.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2021-06-24 19:56:28,379 INFO  [paddles.controllers.nodes] Locked <Node gibba020.front.sepia.ceph.com> <Node gibba041.front.sepia.ceph.com> <Node gibba004.front.sepia.ceph.com> <Node gibba034.front.sepia.ceph.com> for scheduled_teuthology@teuthology with description /home/teuthworker/archive/teuthology-2021-06-09_03:30:03-rados-octopus-distro-basic-gibba/6161538
2021-06-24 19:56:29,805 INFO  [paddles.controllers.nodes] Updating <Node gibba020.front.sepia.ceph.com>: {u'os_version': u'', u'os_type': u'', u'name': u'gibba020.front.sepia.ceph.com'}
2021-06-24 19:57:33,584 DEBUG [paddles.controllers.nodes] Unlocking <Node gibba020.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2021-06-24 19:57:33,586 INFO  [paddles.controllers.nodes] Unlocked <Node gibba020.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2021-06-24 19:57:38,803 INFO  [paddles.controllers.nodes] Locked <Node gibba020.front.sepia.ceph.com> <Node gibba004.front.sepia.ceph.com> for scheduled_teuthology@teuthology with description /home/teuthworker/archive/teuthology-2021-06-09_03:30:03-rados-octopus-distro-basic-gibba/6161539
2021-06-24 19:57:40,008 INFO  [paddles.controllers.nodes] Updating <Node gibba020.front.sepia.ceph.com>: {u'os_version': u'', u'os_type': u'', u'name': u'gibba020.front.sepia.ceph.com'}
2021-06-24 20:02:34,314 INFO  [paddles.controllers.nodes] Updating <Node gibba020.front.sepia.ceph.com>: {u'ssh_pub_key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCjDZLjymjqQV+WLD2gSqjYAMFhbyGKNjhMoZyVDaTRpsiF9nRIqP5cUrmjKHXC3WdrwwzzpkYRVsx2mbx9OaKNrOpW7bI3JRgWQSt2tYHo8RYbOVvTqAQb98Uz3tiwHOim5l1xrXi2LP6C6UL2F1HhkoRkr3NzwbGM+wXuyCkUW1e3+KR0GSM/f4QqXthFGcMPJ0Jx9qpyvuAuoNUJAiYl8buN6OZOJ3N3FHOd+d+31lD0PIFIeJVkgs5efWL8NP5koPkVbDtkqEsQhfTEFMeeJDEszAozOQVojOZ43oortWhU/j+Gc6UIIKndVPEyph4qsFVCFubAl5EIowPAl/iOeTnNgi37h65GFvYEIc2/H2gb9bUYsh4IqC0Z2fd7ysCdLbP1mNnFR3o/qOMDKwxrXUVfRvx2tuDzBsfX7gz5lm/nQ1Rjpjrzzm4zw8yJXH9648UofdA+YDDqeNc++0dilTEU7e0S9WGWznkO2EXEotDKcPK2/ujqdYXTFyEemnM='}
2021-06-24 20:02:34,712 INFO  [paddles.controllers.nodes] Updating <Node gibba020.front.sepia.ceph.com>: {u'name': u'gibba020.front.sepia.ceph.com', u'up': True, u'os_version': u'20.04', u'user': u'ubuntu', u'os_type': u'ubuntu', u'arch': u'x86_64', u'ssh_pub_key': u'ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIIH7ETizQ5y2jw8PQJDkXxvB8FZtwbzrHBZ61xco8j3T'}
2021-06-24 20:02:36,635 INFO  [paddles.controllers.nodes] Updating <Node gibba020.front.sepia.ceph.com>: {u'name': u'gibba020.front.sepia.ceph.com', u'up': True, u'os_version': u'20.04', u'user': u'ubuntu', u'os_type': u'ubuntu', u'arch': u'x86_64', u'ssh_pub_key': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCjDZLjymjqQV+WLD2gSqjYAMFhbyGKNjhMoZyVDaTRpsiF9nRIqP5cUrmjKHXC3WdrwwzzpkYRVsx2mbx9OaKNrOpW7bI3JRgWQSt2tYHo8RYbOVvTqAQb98Uz3tiwHOim5l1xrXi2LP6C6UL2F1HhkoRkr3NzwbGM+wXuyCkUW1e3+KR0GSM/f4QqXthFGcMPJ0Jx9qpyvuAuoNUJAiYl8buN6OZOJ3N3FHOd+d+31lD0PIFIeJVkgs5efWL8NP5koPkVbDtkqEsQhfTEFMeeJDEszAozOQVojOZ43oortWhU/j+Gc6UIIKndVPEyph4qsFVCFubAl5EIowPAl/iOeTnNgi37h65GFvYEIc2/H2gb9bUYsh4IqC0Z2fd7ysCdLbP1mNnFR3o/qOMDKwxrXUVfRvx2tuDzBsfX7gz5lm/nQ1Rjpjrzzm4zw8yJXH9648UofdA+YDDqeNc++0dilTEU7e0S9WGWznkO2EXEotDKcPK2/ujqdYXTFyEemnM='}

SPECIFICALLY BELOW

2021-06-24 20:58:44,090 DEBUG [paddles.controllers.nodes] Unlocking <Node gibba020.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2021-06-24 20:58:44,091 INFO  [paddles.controllers.nodes] Unlocked <Node gibba020.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2021-06-24 20:58:45,193 DEBUG [paddles.controllers.nodes] Unlocking <Node gibba020.front.sepia.ceph.com> for scheduled_teuthology@teuthology
2021-06-24 20:58:49,508 INFO  [paddles.controllers.nodes] Locked <Node gibba020.front.sepia.ceph.com> <Node gibba014.front.sepia.ceph.com> <Node gibba023.front.sepia.ceph.com> for scheduled_teuthology@teuthology with description /home/teuthworker/archive/teuthology-2021-06-09_05:15:03-ceph-ansible-octopus-distro-basic-gibba/6161936
2021-06-24 20:58:50,804 INFO  [paddles.controllers.nodes] Updating <Node gibba020.front.sepia.ceph.com>: {u'os_version': u'', u'os_type': u'', u'name': u'gibba020.front.sepia.ceph.com'}

What.

#14 Updated by Aishwarya Mathuria about 1 year ago

  • Assignee set to Aishwarya Mathuria

#15 Updated by Zack Cerza about 1 year ago

I don't know if there is more than one root cause for this, but I spent a few hours tracking an instance of this today.
I started by constructing a timeline: https://pad.ceph.com/p/21-10-20_node_double-dipping
Pasted here:

lines w/o 'T' between date and time are from paddles

2021-10-20 15:21:09,152 unlocked by 6452278 supervisor
2021-10-20T15:21:11.216 locked by worker for 6452338
2021-10-20T15:46:05.517 unlocked by 6452338 supervisor
2021-10-20T15:46:09.430 locked by worker for 6452392
2021-10-20 15:46:12,318 unlocked 

2021-10-20T15:50:47.269 6452392 dies because node was NOT LOCKED: http://qa-proxy.ceph.com/teuthology/sage-2021-10-20_13:52:58-rados-wip-sage-testing-2021-10-19-1841-distro-basic-smithi/6452392/teuthology.log
2021-10-20T15:51:12.404 locked by worker for 6452399
2021-10-20T15:52:54.826 unlocked by 6452392 supervisor
2021-10-20 15:53:34,284 locked by worker for 6452403
2021-10-20T16:02:05.743 unlocked by 6452399 supervisor
2021-10-20 16:02:12,414 locked by worker for 6452423
2021-10-20T16:08:28.592 unlocked by 6452403 supervisor

2021-10-20T16:35:32.316 locked by worker for 6452501
2021-10-20 16:45:08,894 locked by worker for 6452517
2021-10-20T16:49:08.121 unlocked by 6452501 supervisor
2021-10-20 16:49:43,473 locked by worker for 6452526
2021-10-20T16:57:12.648 rebooted by 6452526
2021-10-20 17:00:19,823 unlocked by 6452517 supervisor
2021-10-20T17:00:24.602 scheduled for provision by 6452545
2021-10-20T17:01:56.280 6452526 begins to die bc it lost the node
2021-10-20T17:03:59.257 unlocked by 6452526 supervisor
2021-10-20T17:04:08.329 scheduled for provision by 6452555
2021-10-20T17:11:09.522 rebooted by 6452545
2021-10-20T17:17:29.772 6452545 fails

I never tracked down the cause for the 15:46 unlock, but it did occur to me that this cycle could be broken:
https://github.com/ceph/teuthology/pull/1688

I do suspect nuke, and we will see this again. But it will be far less damaging next time, and easier to analyze I hope.

#16 Updated by Yuri Weinstein about 1 year ago

  • Priority changed from Immediate to Normal

#17 Updated by Yuri Weinstein about 1 year ago

  • Priority changed from Normal to Immediate

#18 Updated by Aishwarya Mathuria 12 months ago

  • Assignee changed from Aishwarya Mathuria to Zack Cerza

#19 Updated by Zack Cerza 6 months ago

Saw a pretty great example today of this bug not being fixed:

zack@pulpito:~$ sudo journalctl -S '2022-06-06 17:54:00' | grep smithi101
Jun 06 17:54:43 pulpito paddles[10782]: 2022-06-06 17:54:43,285 INFO  [paddles.controllers.nodes] Locked <Node smithi101.front.sepia.ceph.com> <Node smithi133.front.sepia.ceph.com> <Node smithi042.front.sepia.ceph.com> for scheduled_jlayton@teuthology with description /home/teuthworker/archive/jlayton-2022-06-06_16:00:20-fs-wip-vshankar-testing1-20220603-134300-distro-default-smithi/6864093
Jun 06 17:54:43 pulpito paddles[10782]: 2022-06-06 17:54:43,733 INFO  [paddles.controllers.nodes] Locked <Node smithi101.front.sepia.ceph.com> <Node smithi170.front.sepia.ceph.com> for scheduled_jlayton@teuthology with description /home/teuthworker/archive/jlayton-2022-06-06_16:00:20-fs-wip-vshankar-testing1-20220603-134300-distro-default-smithi/6864094

#20 Updated by David Galloway 6 months ago

This is happening pretty often :(

root@pulpito:~# journalctl -S '2022-06-07 16:0' | grep 6865934
Jun 07 16:00:32 pulpito paddles[10782]: 2022-06-07 16:00:32,106 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865934 status changed from queued to running
Jun 07 16:00:32 pulpito paddles[10782]: 2022-06-07 16:00:32,178 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865934 status changed from running to waiting
Jun 07 16:01:42 pulpito paddles[10782]: 2022-06-07 16:01:42,389 INFO  [paddles.controllers.nodes] Locked <Node smithi125.front.sepia.ceph.com> <Node smithi072.front.sepia.ceph.com> for scheduled_adking@teuthology with description /home/teuthworker/archive/adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865934
Jun 07 16:01:42 pulpito paddles[10782]: 2022-06-07 16:01:42,538 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865934 status changed from waiting to running
Jun 07 16:01:44 pulpito paddles[10782]: 2022-06-07 16:01:44,017 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865934 status changed from running to waiting
Jun 07 16:07:27 pulpito paddles[10782]: 2022-06-07 16:07:27,907 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865934 status changed from waiting to running
Jun 07 16:08:41 pulpito paddles[10782]: 2022-06-07 16:08:41,256 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865934 status changed from running to fail
root@pulpito:~# journalctl -S '2022-06-07 16:0' | grep 6865933
Jun 07 16:00:01 pulpito paddles[10782]: 2022-06-07 16:00:01,647 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933 status changed from queued to running
Jun 07 16:00:01 pulpito paddles[10782]: 2022-06-07 16:00:01,721 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933 status changed from running to waiting
Jun 07 16:00:31 pulpito paddles[10782]: 2022-06-07 16:00:31,843 INFO  [paddles.controllers.nodes] Locked <Node smithi125.front.sepia.ceph.com> <Node smithi106.front.sepia.ceph.com> for scheduled_adking@teuthology with description /home/teuthworker/archive/adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933
Jun 07 16:00:31 pulpito paddles[10782]: 2022-06-07 16:00:31,990 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933 status changed from waiting to running
Jun 07 16:00:33 pulpito paddles[10782]: 2022-06-07 16:00:33,284 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933 status changed from running to waiting
Jun 07 16:06:31 pulpito paddles[10782]: 2022-06-07 16:06:31,066 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933 status changed from waiting to running
Jun 07 16:16:53 pulpito paddles[10782]: 2022-06-07 16:16:53,208 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933 status changed from running to fail
Jun  7 16:00:31 pulpito paddles[10782]: 2022-06-07 16:00:31,843 INFO  [paddles.controllers.nodes] Locked <Node smithi125.front.sepia.ceph.com> <Node smithi106.front.sepia.ceph.com> for scheduled_adking@teuthology with description /home/teuthworker/archive/adking-2022-06-0
7_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933

Jun  7 16:00:31 pulpito paddles[10782]: 2022-06-07 16:00:31,990 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933 status changed from waiting to running

# Unlocks while running!!!
Jun  7 16:01:36 pulpito paddles[10782]: 2022-06-07 16:01:36,270 DEBUG [paddles.controllers.nodes] Unlocking <Node smithi125.front.sepia.ceph.com> for scheduled_adking@teuthology

Jun  7 16:16:53 pulpito paddles[10782]: 2022-06-07 16:16:53,208 INFO  [paddles.controllers.jobs] Job adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933 status changed from running to fail
2022-06-07T16:00:01.554 INFO:teuthology.dispatcher:Reserved job 6865933
2022-06-07T16:00:01.651 INFO:teuthology.lock.ops:Locking machines...
2022-06-07T16:00:01.740 INFO:teuthology.lock.ops:waiting for more smithi machines to be free (need 0 + 2, have 0)...
2022-06-07T16:00:11.766 INFO:teuthology.lock.ops:waiting for more smithi machines to be free (need 0 + 2, have 0)...
2022-06-07T16:00:21.789 INFO:teuthology.lock.ops:waiting for more smithi machines to be free (need 0 + 2, have 0)...
2022-06-07T16:00:31.847 INFO:teuthology.lock.ops:2 smithi machines locked this try, 2/2 locked so far
2022-06-07T16:00:31.908 INFO:teuthology.lock.ops:Locked targets:
  smithi106.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC9eVpn7n0YZwv2eyZPCYaeyJfXM0ApnQc5YXuJ1CU2Cd/B+m58IfWaLJWHcTCvuILopVxdSDyWvdQvOAwaZ7ykUREw9V0Rm5rvYnbyL2CmWGTUT4dJq3LRVdN4I9TVNK2BJmMmQjBgkU34vrcJEaf2K+Z33TuD7tK8D2p/gYPE+ZmXeiNlw3Ry2yTzhzqvfPWruMvqi7NoKOPx8KArmBxMIgAMLOwZfCswQ0gwi0G4DpRahjvoqhSChEh/XnBp1ddX1JxPz734YsNgjn2+FiAoXwMhcjQsEhVD96FvrGr3sZmf+DF03x03ftKQBI0C8u6qREDomY3OyLuv8XaLSg3Yp/Io80EsLgGyYr8zRy0VL8gcISZ+rtqRJrnjyMQEiZbZATHxFqho6BSZCNq8ZId2tG1OwOOJ3coO6XkO5LQ9mtAT1wfeSnOS5g2uNSxUxMOMyYIaeRvyqzOsY22y7VX+m4WLHj9Hx+763s0SQDUbOh6+ADLsJHQ+6Bz658qlOUM=
  smithi125.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDQYaBjusW609YC0PmHBK+iD270GtGB1TKYrJOTquKD3OGz7tcYwLm2IRd/KBc/A/VPe8sZvJBPJEsj4/EuFky7HesQBRAv91bjMGwTUBmWjZmsis7FvlKql2uEoMAJmITbkab2vAwdk7b9S1DjTC5Fm379N3bleGpGit5QPi2zFFtb+S8OApWcljAG9BJ/UJBbiCohkeRaGjDo1LQK5vk4lSw1GTfMrKGmB10LpEoTRDsGYO/iShDRPzZJkBZuqy3qWqYEWEGkBuUTgDwkw5OAU94MFKrzABwEU3OrdXNYc/chuMGbkMdwWNlIZnHjdEsRuJKAbV819gB3PxZWpuJ9IxOQVwcsQqxWySNnhbOkZZ31Rrg5nqrjERBna4qjNsRNmEbBqTZ9UoT47R8YkdpyrXZ/0lSbigRn0LItnJA6nT3S6Mfl/tXzjigLkHULyJw0F2BUUKMBin3GPUIWlsLhAu6As5WCQf6rG5Vst/WWX7OyE99i+/MKSe5kSHRTI70=
2022-06-07T16:00:31.994 INFO:teuthology.dispatcher:Creating job's archive dir /home/teuthworker/archive/adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933
2022-06-07T16:00:32.007 INFO:teuthology.dispatcher:Job supervisor PID: 16333
2022-06-07T16:00:32.021 INFO:teuthology.dispatcher:Reserved job 6865934
2022-06-07T16:00:32.110 INFO:teuthology.lock.ops:Locking machines...
2022-06-07T16:00:32.195 INFO:teuthology.lock.ops:waiting for more smithi machines to be free (need 0 + 2, have 0)...
2022-06-07T16:00:42.215 INFO:teuthology.lock.ops:waiting for more smithi machines to be free (need 0 + 2, have 0)...
2022-06-07T16:00:52.237 INFO:teuthology.lock.ops:waiting for more smithi machines to be free (need 0 + 2, have 0)...
2022-06-07T16:01:02.259 INFO:teuthology.lock.ops:waiting for more smithi machines to be free (need 0 + 2, have 0)...
2022-06-07T16:01:12.284 INFO:teuthology.lock.ops:waiting for more smithi machines to be free (need 0 + 2, have 0)...
2022-06-07T16:01:22.313 INFO:teuthology.lock.ops:waiting for more smithi machines to be free (need 0 + 2, have 0)...
2022-06-07T16:01:32.336 INFO:teuthology.lock.ops:waiting for more smithi machines to be free (need 0 + 2, have 0)...
2022-06-07T16:01:42.394 INFO:teuthology.lock.ops:2 smithi machines locked this try, 2/2 locked so far
2022-06-07T16:01:42.457 INFO:teuthology.lock.ops:Locked targets:
  smithi072.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDM3A67zHyL+jU2WaLh6aitBLtqJ164MY5wZQFPa00+2DQMejS9TCVget2tC4pXgHth/4Lgmf4w57IRblenvPp1ZJgw86+B99RyYvERgi92UbfAdat5AVuB49JnZfqHY5Q0iZQpVMW5ODbEl3wX5hxKxTF2l1tcIcjr1FREn5vzF+7nDrtw2oW7gV+nekOQXDpqvCeaWeJIQHAyK22TC4tBWbQY0bwQWo3YgzEMZ+BDm27THwjx7yhVov+oYf9O2mTA/5GZh/GWFFshoE9YzAaBGOuxXdknWSl93svhjLV6OjxyQmykH7oVH7fAY0x5BYGydC/q4aIEhZWW1nuPDDN7
  smithi125.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDQYaBjusW609YC0PmHBK+iD270GtGB1TKYrJOTquKD3OGz7tcYwLm2IRd/KBc/A/VPe8sZvJBPJEsj4/EuFky7HesQBRAv91bjMGwTUBmWjZmsis7FvlKql2uEoMAJmITbkab2vAwdk7b9S1DjTC5Fm379N3bleGpGit5QPi2zFFtb+S8OApWcljAG9BJ/UJBbiCohkeRaGjDo1LQK5vk4lSw1GTfMrKGmB10LpEoTRDsGYO/iShDRPzZJkBZuqy3qWqYEWEGkBuUTgDwkw5OAU94MFKrzABwEU3OrdXNYc/chuMGbkMdwWNlIZnHjdEsRuJKAbV819gB3PxZWpuJ9IxOQVwcsQqxWySNnhbOkZZ31Rrg5nqrjERBna4qjNsRNmEbBqTZ9UoT47R8YkdpyrXZ/0lSbigRn0LItnJA6nT3S6Mfl/tXzjigLkHULyJw0F2BUUKMBin3GPUIWlsLhAu6As5WCQf6rG5Vst/WWX7OyE99i+/MKSe5kSHRTI70=
2022-06-07T16:01:42.542 INFO:teuthology.dispatcher:Creating job's archive dir /home/teuthworker/archive/adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865934

#21 Updated by Zack Cerza 6 months ago

  • Status changed from New to Fix Under Review

If we step back a bit in time:

# journalctl -S '2022-06-07 15:53:00' -U '2022-06-07 16:02' | grep 'smithi125' | grep -v Updating
Jun 07 15:53:09 pulpito paddles[10782]: 2022-06-07 15:53:09,882 INFO  [paddles.controllers.nodes] Locked <Node smithi125.front.sepia.ceph.com> <Node smithi106.front.sepia.ceph.com> for scheduled_adking@teuthology with description /home/teuthworker/archive/adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865905
Jun 07 15:53:10 pulpito paddles[10782]: 2022-06-07 15:53:10,296 INFO  [paddles.controllers.nodes] Locked <Node smithi125.front.sepia.ceph.com> <Node smithi072.front.sepia.ceph.com> for scheduled_adking@teuthology with description /home/teuthworker/archive/adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865906
Jun 07 16:00:25 pulpito paddles[10782]: 2022-06-07 16:00:25,436 DEBUG [paddles.controllers.nodes] Unlocking <Node smithi125.front.sepia.ceph.com> for scheduled_adking@teuthology
Jun 07 16:00:25 pulpito paddles[10782]: 2022-06-07 16:00:25,483 INFO  [paddles.controllers.nodes] Unlocked <Node smithi125.front.sepia.ceph.com> for scheduled_adking@teuthology
Jun 07 16:00:31 pulpito paddles[10782]: 2022-06-07 16:00:31,843 INFO  [paddles.controllers.nodes] Locked <Node smithi125.front.sepia.ceph.com> <Node smithi106.front.sepia.ceph.com> for scheduled_adking@teuthology with description /home/teuthworker/archive/adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865933
Jun 07 16:01:36 pulpito paddles[10782]: 2022-06-07 16:01:36,270 DEBUG [paddles.controllers.nodes] Unlocking <Node smithi125.front.sepia.ceph.com> for scheduled_adking@teuthology
Jun 07 16:01:36 pulpito paddles[10782]: 2022-06-07 16:01:36,281 INFO  [paddles.controllers.nodes] Unlocked <Node smithi125.front.sepia.ceph.com> for scheduled_adking@teuthology
Jun 07 16:01:42 pulpito paddles[10782]: 2022-06-07 16:01:42,389 INFO  [paddles.controllers.nodes] Locked <Node smithi125.front.sepia.ceph.com> <Node smithi072.front.sepia.ceph.com> for scheduled_adking@teuthology with description /home/teuthworker/archive/adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865934

This node was double-locked after all, and here's the source of the unlock-while-running:

zack@teuthology:/a/adking-2022-06-07_15:52:19-orch:cephadm-wip-adk-testing-2022-06-07-0930-distro-default-smithi/6865906$ grep -A21 ERROR supervisor.6865906.log
2022-06-07T16:01:27.347 ERROR:teuthology.dispatcher.supervisor:Reimaging error. Nuking machines...
Traceback (most recent call last):
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_93d2b653facc0e5a7a532b39d9ff91a044f2c4a9/teuthology/dispatcher/supervisor.py", line 209, in reimage
    reimaged = reimage_machines(ctx, targets, job_config['machine_type'])
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_93d2b653facc0e5a7a532b39d9ff91a044f2c4a9/teuthology/lock/ops.py", line 325, in reimage_machines
    reimaged = do_update_keys(list(reimaged.keys()))[1]
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_93d2b653facc0e5a7a532b39d9ff91a044f2c4a9/teuthology/lock/ops.py", line 288, in do_update_keys
    keys_dict = misc.ssh_keyscan(machines, _raise=_raise)
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_93d2b653facc0e5a7a532b39d9ff91a044f2c4a9/teuthology/misc.py", line 1103, in ssh_keyscan
    while proceed():
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_93d2b653facc0e5a7a532b39d9ff91a044f2c4a9/teuthology/contextutil.py", line 133, in __call__
    raise MaxWhileTries(error_msg)
teuthology.exceptions.MaxWhileTries: 'ssh_keyscan smithi125.front.sepia.ceph.com' reached maximum tries (5) after waiting for 5 seconds
2022-06-07T16:01:27.438 INFO:teuthology.nuke:Checking targets against current locks
2022-06-07T16:01:27.609 INFO:teuthology.task.internal.check_lock:Checking locks...
2022-06-07T16:01:27.612 INFO:teuthology.task.internal.check_lock:Checking locks...
2022-06-07T16:01:27.726 INFO:teuthology.orchestra.console:Power off smithi072
2022-06-07T16:01:27.745 INFO:teuthology.orchestra.console:Power off smithi125
2022-06-07T16:01:36.111 INFO:teuthology.orchestra.console:Power off for smithi072 completed
2022-06-07T16:01:36.118 INFO:teuthology.orchestra.console:Power off for smithi125 completed
2022-06-07T16:01:36.272 INFO:teuthology.lock.ops:unlocked: smithi072.front.sepia.ceph.com
2022-06-07T16:01:36.284 INFO:teuthology.lock.ops:unlocked: smithi125.front.sepia.ceph.com

I may have a fix for this: https://github.com/ceph/teuthology/pull/1765

Also available in: Atom PDF