Project

General

Profile

Actions
Copy link

Bug #36685

closed

paramiko timeout not working for hung process

Added by Patrick Donnelly over 5 years ago. Updated over 2 years ago.

Status:
Can't reproduce
Priority:
High
Assignee:
-
Category:
-
% Done:

0%

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

Description

2018-11-02T03:47:17.293 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo fusermount -u /home/ubuntu/cephtest/mnt.0'
2018-11-02T03:47:17.383 DEBUG:teuthology.orchestra.run:got remote process result: 1
2018-11-02T03:47:17.413 INFO:teuthology.orchestra.run.smithi002.stderr:fusermount: failed to unmount /home/ubuntu/cephtest/mnt.0: Device or resource busy
2018-11-02T03:47:17.413 INFO:tasks.cephfs.fuse_mount:Failed to unmount ceph-fuse on ubuntu@smithi002.front.sepia.ceph.com, aborting...
2018-11-02T03:47:17.414 INFO:teuthology.orchestra.run:Running command with timeout 900
2018-11-02T03:47:17.414 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo PATH=/usr/sbin:$PATH lsof ; ps auxf'
2018-11-02T03:47:45.133 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:47:45.138 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:48:15.259 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:48:15.267 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:48:45.386 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:48:45.391 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:49:15.526 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:49:15.530 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:49:45.651 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:49:45.655 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:50:15.794 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:50:15.799 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:50:45.936 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:50:45.942 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:51:16.087 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:51:16.092 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:51:46.213 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:51:46.218 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:52:16.335 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:52:16.339 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:52:46.473 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:52:46.479 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:53:16.605 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:53:16.609 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:53:46.742 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:53:46.747 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:54:16.891 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:54:16.896 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:54:47.022 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:54:47.027 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:55:17.170 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:55:17.175 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:55:47.300 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:55:47.305 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:56:17.461 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:56:17.465 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:56:47.599 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:56:47.604 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:57:17.751 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:57:17.756 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:57:47.873 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:57:47.877 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:58:17.989 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:58:17.994 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:58:48.128 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:58:48.133 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:59:18.250 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:59:18.254 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:59:48.505 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:59:48.510 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T03:59:59.974 INFO:tasks.ceph.mon.a.smithi002.stderr:2018-11-02 03:59:59.999 7f43195d6700 -1 log_channel(cluster) log [ERR] : overall HEALTH_ERR 1 filesystem is degraded; 1 filesystem has a failed mds daemon; 1 filesystem is offline
2018-11-02T04:00:18.636 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T04:00:18.640 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T04:00:48.767 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T04:00:48.772 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T04:01:18.904 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T04:01:18.908 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T04:01:49.045 INFO:teuthology.orchestra.run.smithi002:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T04:01:49.050 INFO:teuthology.orchestra.run.smithi086:Running: 'sudo logrotate /etc/logrotate.d/ceph-test.conf'
2018-11-02T04:02:17.436 ERROR:teuthology:Uncaught exception (Hub)
Traceback (most recent call last):
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/virtualenv/local/lib/python2.7/site-packages/gevent/greenlet.py", line 536, in run
    result = self._run(*self.args, **self.kwargs)
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/teuthology/orchestra/run.py", line 300, in copy_file_to
    copy_to_log(src, logger)
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/teuthology/orchestra/run.py", line 267, in copy_to_log
    for line in f:
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/virtualenv/local/lib/python2.7/site-packages/paramiko/file.py", line 102, in next
    line = self.readline()
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/virtualenv/local/lib/python2.7/site-packages/paramiko/file.py", line 277, in readline
    new_data = self._read(n)
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/virtualenv/local/lib/python2.7/site-packages/paramiko/channel.py", line 1305, in _read
    return self.channel.recv_stderr(size)
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/virtualenv/local/lib/python2.7/site-packages/paramiko/channel.py", line 715, in recv_stderr
    raise socket.timeout()
timeout
2018-11-02T04:02:17.989 ERROR:teuthology:Uncaught exception (Hub)
Traceback (most recent call last):
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/virtualenv/local/lib/python2.7/site-packages/gevent/greenlet.py", line 536, in run
    result = self._run(*self.args, **self.kwargs)
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/teuthology/orchestra/run.py", line 300, in copy_file_to
    copy_to_log(src, logger)
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/teuthology/orchestra/run.py", line 267, in copy_to_log
    for line in f:
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/virtualenv/local/lib/python2.7/site-packages/paramiko/file.py", line 102, in next
    line = self.readline()
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/virtualenv/local/lib/python2.7/site-packages/paramiko/file.py", line 277, in readline
    new_data = self._read(n)
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/virtualenv/local/lib/python2.7/site-packages/paramiko/channel.py", line 1293, in _read
    return self.channel.recv(size)
  File "/home/teuthworker/src/git.ceph.com_git_teuthology_wip-pdonnell-testing/virtualenv/local/lib/python2.7/site-packages/paramiko/channel.py", line 667, in recv
    raise socket.timeout()
timeout
...

From: /ceph/teuthology-archive/pdonnell-2018-11-02_00:48:35-fs-wip-pdonnell-testing-20181101.222544-distro-basic-smithi/3212556/teuthology.log

The two stderr/stdout greenlets timed out as expected but the main process greenlet continues to hang. My intuition is that this is a Paramiko issue.

Actions
Copy link
 #2

Updated by Josh Durgin over 2 years ago

  • Status changed from New to Can't reproduce

no occurrence in the past year

Actions
Copy link

Also available in: Atom PDF