Bug #65022
openqa: test_max_items_per_obj open procs not fully cleaned up
100%
Description
2024-03-20T21:44:49.452 DEBUG:teuthology.orchestra.run.smithi103:> adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage rados --cluster ceph --pool cephfs_metadata stat mds0_openfiles.1 ... 2024-03-20T21:44:50.433 INFO:teuthology.nuke.actions:Clearing teuthology firewall rules... 2024-03-20T21:44:50.433 DEBUG:teuthology.orchestra.run.smithi103:> sudo sh -c 'iptables-save | grep -v teuthology | iptables-restore' 2024-03-20T21:44:50.512 DEBUG:teuthology.orchestra.run.smithi151:> sudo sh -c 'iptables-save | grep -v teuthology | iptables-restore' 2024-03-20T21:44:50.558 INFO:teuthology.nuke.actions:Cleared teuthology firewall rules. 2024-03-20T21:44:50.558 INFO:tasks.cephfs.mount:Terminating background process 2024-03-20T21:44:50.558 DEBUG:tasks.cephfs.mount:terminating RemoteProcess(client=<paramiko.client.SSHClient object at 0x7f1b1415f6a0>, args=['stdin-killer', '--', 'python3', '-c', '\nimport fcntl\nimport os\nimport sys\nimport time\n\nfcntl.fcntl(sys.stdin, fcntl.F_SETFL, fcntl.fcntl(sys.stdin, fcntl.F_GETFL) | os.O_NONBLOCK)\n\nwith open("/home/ubuntu/cephtest/mnt.0/open_file0", \'w\') as f:\n f.write("content")\n f.flush()\n while True:\n print("open_background: keeping file open", file=sys.stderr)\n try:\n if os.read(0, 4096) == b"":\n break\n except BlockingIOError:\n pass\n time.sleep(2)\n'], check_status=True, hostname='smithi103') 2024-03-20T21:44:50.559 INFO:teuthology.orchestra.run.smithi103.stderr:2024-03-20T21:44:50 stdin-killer INFO: expiration expected; waiting 5 seconds for command to complete 2024-03-20T21:44:50.688 INFO:teuthology.orchestra.run.smithi103.stderr:open_background: keeping file open 2024-03-20T21:44:50.919 INFO:teuthology.orchestra.run.smithi103.stderr:open_background: keeping file open 2024-03-20T21:44:51.164 INFO:teuthology.orchestra.run.smithi103.stderr:open_background: keeping file open 2024-03-20T21:44:51.434 INFO:teuthology.orchestra.run.smithi103.stderr:open_background: keeping file open 2024-03-20T21:44:51.673 INFO:teuthology.orchestra.run.smithi103.stderr:open_background: keeping file open 2024-03-20T21:44:51.677 INFO:teuthology.orchestra.run.smithi103.stderr:2024-03-20T21:44:51 stdin-killer INFO: command exited with status 0: exiting normally with same code! 2024-03-20T21:44:51.685 DEBUG:tasks.cephfs.mount:terminating RemoteProcess(client=<paramiko.client.SSHClient object at 0x7f1b1415f6a0>, args=['stdin-killer', '--', 'python3', '-c', '\nimport fcntl\nimport os\nimport sys\nimport time\n\nfcntl.fcntl(sys.stdin, fcntl.F_SETFL, fcntl.fcntl(sys.stdin, fcntl.F_GETFL) | os.O_NONBLOCK)\n\nwith open("/home/ubuntu/cephtest/mnt.0/open_file2", \'w\') as f:\n f.write("content")\n f.flush()\n while True:\n print("open_background: keeping file open", file=sys.stderr)\n try:\n if os.read(0, 4096) == b"":\n break\n except BlockingIOError:\n pass\n time.sleep(2)\n'], check_status=True, hostname='smithi103') 2024-03-20T21:44:51.727 INFO:teuthology.orchestra.run.smithi103.stderr:2024-03-20T21:44:51 stdin-killer INFO: expiration expected; waiting 5 seconds for command to complete 2024-03-20T21:44:51.917 INFO:teuthology.orchestra.run.smithi103.stderr:open_background: keeping file open 2024-03-20T21:44:52.181 INFO:teuthology.orchestra.run.smithi103.stderr:open_background: keeping file open 2024-03-20T21:44:52.184 INFO:teuthology.orchestra.run.smithi103.stderr:2024-03-20T21:44:52 stdin-killer INFO: command exited with status 0: exiting normally with same code! 2024-03-20T21:44:52.190 DEBUG:tasks.cephfs.mount:terminating RemoteProcess(client=<paramiko.client.SSHClient object at 0x7f1b1415f6a0>, args=['stdin-killer', '--', 'python3', '-c', '\nimport fcntl\nimport os\nimport sys\nimport time\n\nfcntl.fcntl(sys.stdin, fcntl.F_SETFL, fcntl.fcntl(sys.stdin, fcntl.F_GETFL) | os.O_NONBLOCK)\n\nwith open("/home/ubuntu/cephtest/mnt.0/open_file4", \'w\') as f:\n f.write("content")\n f.flush()\n while True:\n print("open_background: keeping file open", file=sys.stderr)\n try:\n if os.read(0, 4096) == b"":\n break\n except BlockingIOError:\n pass\n time.sleep(2)\n'], check_status=True, hostname='smithi103') 2024-03-20T21:44:52.232 INFO:teuthology.orchestra.run.smithi103.stderr:2024-03-20T21:44:52 stdin-killer INFO: expiration expected; waiting 5 seconds for command to complete 2024-03-20T21:44:52.688 INFO:teuthology.orchestra.run.smithi103.stderr:open_background: keeping file open 2024-03-20T21:44:52.692 INFO:teuthology.orchestra.run.smithi103.stderr:2024-03-20T21:44:52 stdin-killer INFO: command exited with status 0: exiting normally with same code! 2024-03-20T21:44:52.698 DEBUG:tasks.cephfs.mount:terminating RemoteProcess(client=<paramiko.client.SSHClient object at 0x7f1b1415f6a0>, args=['stdin-killer', '--', 'python3', '-c', '\nimport fcntl\nimport os\nimport sys\nimport time\n\nfcntl.fcntl(sys.stdin, fcntl.F_SETFL, fcntl.fcntl(sys.stdin, fcntl.F_GETFL) | os.O_NONBLOCK)\n\nwith open("/home/ubuntu/cephtest/mnt.0/open_file6", \'w\') as f:\n f.write("content")\n f.flush()\n while True:\n print("open_background: keeping file open", file=sys.stderr)\n try:\n if os.read(0, 4096) == b"":\n break\n except BlockingIOError:\n pass\n time.sleep(2)\n'], check_status=True, hostname='smithi103') 2024-03-20T21:44:52.739 INFO:teuthology.orchestra.run.smithi103.stderr:2024-03-20T21:44:52 stdin-killer INFO: expiration expected; waiting 5 seconds for command to complete 2024-03-20T21:44:52.920 INFO:teuthology.orchestra.run.smithi103.stderr:open_background: keeping file open 2024-03-20T21:44:53.166 INFO:teuthology.orchestra.run.smithi103.stderr:open_background: keeping file open 2024-03-20T21:44:53.171 INFO:teuthology.orchestra.run.smithi103.stderr:2024-03-20T21:44:53 stdin-killer INFO: command exited with status 0: exiting normally with same code! 2024-03-20T21:44:53.177 DEBUG:teuthology.orchestra.run.smithi103:> set -ex 2024-03-20T21:44:53.178 DEBUG:teuthology.orchestra.run.smithi103:> dd if=/proc/self/mounts of=/dev/stdout 2024-03-20T21:44:53.233 DEBUG:teuthology.orchestra.run.smithi103:> set -ex 2024-03-20T21:44:53.233 DEBUG:teuthology.orchestra.run.smithi103:> dd if=/proc/self/mounts of=/dev/stdout 2024-03-20T21:44:53.288 DEBUG:teuthology.orchestra.run.smithi103:> sudo adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 120 ceph --cluster ceph osd dump --format=json ... 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner:====================================================================== 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner:ERROR: test_max_items_per_obj (tasks.cephfs.test_openfiletable.OpenFileTable) 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner:The maximum number of openfiles omap objects keys are now equal to 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner:---------------------------------------------------------------------- 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner:Traceback (most recent call last): 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_ceph-c_360516069d9393362c4cc6eb9371680fe16d66ab/qa/tasks/cephfs/cephfs_test_case.py", line 205, in tearDown 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner: m.teardown() 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_ceph-c_360516069d9393362c4cc6eb9371680fe16d66ab/qa/tasks/cephfs/kernel_mount.py", line 210, in teardown 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner: self.umount() 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_ceph-c_360516069d9393362c4cc6eb9371680fe16d66ab/qa/tasks/cephfs/kernel_mount.py", line 170, in umount 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner: raise e 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_ceph-c_360516069d9393362c4cc6eb9371680fe16d66ab/qa/tasks/cephfs/kernel_mount.py", line 163, in umount 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner: self.client_remote.run(args=cmd, timeout=UMOUNT_TIMEOUT, omit_sudo=False) 2024-03-20T21:45:02.937 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_teuthology_e691533f9cbb33d85b2187bba20d7102f098636d/teuthology/orchestra/remote.py", line 523, in run 2024-03-20T21:45:02.938 INFO:tasks.cephfs_test_runner: r = self._runner(client=self.ssh, name=self.shortname, **kwargs) 2024-03-20T21:45:02.938 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_teuthology_e691533f9cbb33d85b2187bba20d7102f098636d/teuthology/orchestra/run.py", line 455, in run 2024-03-20T21:45:02.938 INFO:tasks.cephfs_test_runner: r.wait() 2024-03-20T21:45:02.938 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_teuthology_e691533f9cbb33d85b2187bba20d7102f098636d/teuthology/orchestra/run.py", line 161, in wait 2024-03-20T21:45:02.938 INFO:tasks.cephfs_test_runner: self._raise_for_status() 2024-03-20T21:45:02.938 INFO:tasks.cephfs_test_runner: File "/home/teuthworker/src/git.ceph.com_teuthology_e691533f9cbb33d85b2187bba20d7102f098636d/teuthology/orchestra/run.py", line 181, in _raise_for_status 2024-03-20T21:45:02.938 INFO:tasks.cephfs_test_runner: raise CommandFailedError( 2024-03-20T21:45:02.938 INFO:tasks.cephfs_test_runner:teuthology.exceptions.CommandFailedError: Command failed on smithi103 with status 32: 'sudo umount /home/ubuntu/cephtest/mnt.0'
/teuthology/pdonnell-2024-03-20_18:16:52-fs-wip-batrick-testing-20240320.145742-distro-default-smithi/7613030/teuthology.log
This one may be caused by the branch and the recent changes to teardown but I don't see how. Opening this for now as even if this is broke by the branch it's not troublesome enough to stop merging.
Updated by Venky Shankar about 1 month ago
Patrick Donnelly wrote:
[...]
/teuthology/pdonnell-2024-03-20_18:16:52-fs-wip-batrick-testing-20240320.145742-distro-default-smithi/7613030/teuthology.log
This one may be caused by the branch and the recent changes to teardown but I don't see how. Opening this for now as even if this is broke by the branch it's not troublesome enough to stop merging.
I haven't seen this in main branch runs, so its likely related to the commits under test.
Updated by Venky Shankar about 1 month ago
https://pulpito.ceph.com/teuthology-2024-03-31_21:24:02-fs-squid-distro-default-smithi/7633108
Patrick, do we have an RCA?
Updated by Patrick Donnelly about 1 month ago
- Status changed from New to In Progress
Updated by Patrick Donnelly about 1 month ago
- Status changed from In Progress to Fix Under Review
- Pull request ID set to 56638
Updated by Patrick Donnelly about 1 month ago
- Backport changed from squid,reef to squid
Updated by Patrick Donnelly 10 days ago
- Status changed from Fix Under Review to Pending Backport
Updated by Backport Bot 10 days ago
- Copied to Backport #65620: squid: qa: test_max_items_per_obj open procs not fully cleaned up added