adds more logging output to network_cli and ansible-connection (#21716)

This commit is contained in:
Peter Sprygada 2017-02-21 09:21:41 -05:00 committed by GitHub
parent 77596951b8
commit 6e9244a9e1
2 changed files with 23 additions and 8 deletions

View file

@ -112,12 +112,14 @@ def recv_data(s):
class Server(): class Server():
def __init__(self, path, play_context): def __init__(self, path, play_context):
display.vvvv("starting new persistent socket with path %s" % path, play_context.remote_addr)
self.path = path self.path = path
self.play_context = play_context self.play_context = play_context
self._start_time = datetime.datetime.now() self._start_time = datetime.datetime.now()
display.vvv("using connection %s" % self.play_context.connection, play_context.remote_addr) display.vvv("using connection plugin %s" % self.play_context.connection, play_context.remote_addr)
self.conn = connection_loader.get(play_context.connection, play_context, sys.stdin) self.conn = connection_loader.get(play_context.connection, play_context, sys.stdin)
self.conn._connect() self.conn._connect()
@ -160,6 +162,7 @@ class Server():
signal.alarm(C.PERSISTENT_CONNECT_TIMEOUT) signal.alarm(C.PERSISTENT_CONNECT_TIMEOUT)
try: try:
(s, addr) = self.socket.accept() (s, addr) = self.socket.accept()
display.vvvv('incoming request accepted on persistent socket', self.play_context.remote_addr)
# clear the alarm # clear the alarm
# FIXME: potential race condition here between the accept and # FIXME: potential race condition here between the accept and
# time to this call. # time to this call.
@ -171,12 +174,14 @@ class Server():
data = recv_data(s) data = recv_data(s)
if not data: if not data:
break break
display.vvvv("received data on socket with len %s" % len(data), self.play_context.remote_addr)
signal.alarm(C.DEFAULT_TIMEOUT) signal.alarm(C.DEFAULT_TIMEOUT)
rc = 255 rc = 255
try: try:
if data.startswith(b'EXEC: '): if data.startswith(b'EXEC: '):
display.vvvv("socket operation is EXEC", self.play_context.remote_addr)
cmd = data.split(b'EXEC: ')[1] cmd = data.split(b'EXEC: ')[1]
(rc, stdout, stderr) = self.conn.exec_command(cmd) (rc, stdout, stderr) = self.conn.exec_command(cmd)
elif data.startswith(b'PUT: ') or data.startswith(b'FETCH: '): elif data.startswith(b'PUT: ') or data.startswith(b'FETCH: '):
@ -184,13 +189,16 @@ class Server():
stdout = stderr = '' stdout = stderr = ''
try: try:
if op == 'FETCH:': if op == 'FETCH:':
display.vvvv("socket operation is FETCH", self.play_context.remote_addr)
self.conn.fetch_file(src, dst) self.conn.fetch_file(src, dst)
elif op == 'PUT:': elif op == 'PUT:':
display.vvvv("socket operation is PUT", self.play_context.remote_addr)
self.conn.put_file(src, dst) self.conn.put_file(src, dst)
rc = 0 rc = 0
except: except:
pass pass
elif data.startswith(b'CONTEXT: '): elif data.startswith(b'CONTEXT: '):
display.vvvv("socket operation is CONTEXT", self.play_context.remote_addr)
pc_data = data.split(b'CONTEXT: ')[1] pc_data = data.split(b'CONTEXT: ')[1]
src = StringIO(pc_data) src = StringIO(pc_data)
@ -203,6 +211,7 @@ class Server():
self.dispatch(self.conn, 'update_play_context', pc) self.dispatch(self.conn, 'update_play_context', pc)
continue continue
else: else:
display.vvvv("socket operation is UNKNOWN", self.play_context.remote_addr)
stdout = '' stdout = ''
stderr = 'Invalid action specified' stderr = 'Invalid action specified'
except: except:
@ -211,12 +220,14 @@ class Server():
signal.alarm(0) signal.alarm(0)
display.vvvv("socket operation completed with rc %s" % rc, self.play_context.remote_addr)
send_data(s, to_bytes(str(rc))) send_data(s, to_bytes(str(rc)))
send_data(s, to_bytes(stdout)) send_data(s, to_bytes(stdout))
send_data(s, to_bytes(stderr)) send_data(s, to_bytes(stderr))
s.close() s.close()
except Exception as e: except Exception as e:
display.debug(traceback.format_exc()) display.vvvv(traceback.format_exc())
finally: finally:
# when done, close the connection properly and cleanup # when done, close the connection properly and cleanup
# the socket file so it can be recreated # the socket file so it can be recreated

View file

@ -56,6 +56,8 @@ class Connection(_Connection):
def update_play_context(self, play_context): def update_play_context(self, play_context):
"""Updates the play context information for the connection""" """Updates the play context information for the connection"""
display.vvvv('updating play_context for connection', self._play_context.remote_addr)
if self._play_context.become is False and play_context.become is True: if self._play_context.become is False and play_context.become is True:
auth_pass = play_context.become_pass auth_pass = play_context.become_pass
self._terminal.on_authorize(passwd=auth_pass) self._terminal.on_authorize(passwd=auth_pass)
@ -69,8 +71,7 @@ class Connection(_Connection):
"""Connections to the device and sets the terminal type""" """Connections to the device and sets the terminal type"""
super(Connection, self)._connect() super(Connection, self)._connect()
display.debug('starting network_cli._connect()') display.vvvv('ssh connection done, setting terminal', self._play_context.remote_addr)
display.vvvv('starting network_cli._connect()')
network_os = self._play_context.network_os network_os = self._play_context.network_os
if not network_os: if not network_os:
@ -84,9 +85,11 @@ class Connection(_Connection):
raise AnsibleConnectionFailure('network os %s is not supported' % network_os) raise AnsibleConnectionFailure('network os %s is not supported' % network_os)
self._connected = True self._connected = True
display.vvvv('ssh connection has completed successfully', self._play_context.remote_addr)
@ensure_connect @ensure_connect
def open_shell(self): def open_shell(self):
display.vvvv('attempting to open shell to device', self._play_context.remote_addr)
self._shell = self.ssh.invoke_shell() self._shell = self.ssh.invoke_shell()
self._shell.settimeout(self._play_context.timeout) self._shell.settimeout(self._play_context.timeout)
@ -99,16 +102,18 @@ class Connection(_Connection):
auth_pass = self._play_context.become_pass auth_pass = self._play_context.become_pass
self._terminal.on_authorize(passwd=auth_pass) self._terminal.on_authorize(passwd=auth_pass)
display.vvvv('shell successfully opened', self._play_context.remote_addr)
return (0, 'ok', '') return (0, 'ok', '')
def close(self): def close(self):
display.vvv('closing connection', host=self._play_context.remote_addr) display.vvvv('closing connection', self._play_context.remote_addr)
self.close_shell() self.close_shell()
super(Connection, self).close() super(Connection, self).close()
self._connected = False self._connected = False
def close_shell(self): def close_shell(self):
"""Closes the vty shell if the device supports multiplexing""" """Closes the vty shell if the device supports multiplexing"""
display.vvvv('closing shell on device', self._play_context.remote_addr)
if self._shell: if self._shell:
self._terminal.on_close_shell() self._terminal.on_close_shell()
@ -204,7 +209,7 @@ class Connection(_Connection):
def alarm_handler(self, signum, frame): def alarm_handler(self, signum, frame):
"""Alarm handler raised in case of command timeout """ """Alarm handler raised in case of command timeout """
display.debug('alarm_handler fired!') display.vvvv('closing shell due to sigalarm', self._play_context.remote_addr)
self.close_shell() self.close_shell()
def exec_command(self, cmd): def exec_command(self, cmd):
@ -217,7 +222,7 @@ class Connection(_Connection):
Keywords supported for cmd: Keywords supported for cmd:
* command - the command string to execute * command - the command string to execute
* prompt - the expected prompt generated by executing command * prompt - the expected prompt generated by executing command
* response - the string to respond to the prompt with * answer - the string to respond to the prompt with
* sendonly - bool to disable waiting for response * sendonly - bool to disable waiting for response
:arg cmd: the string that represents the command to be executed :arg cmd: the string that represents the command to be executed
@ -225,7 +230,6 @@ class Connection(_Connection):
:returns: a tuple of (return code, stdout, stderr). The return :returns: a tuple of (return code, stdout, stderr). The return
code is an integer and stdout and stderr are strings code is an integer and stdout and stderr are strings
""" """
display.vvv('cmd: %s' % cmd)
try: try:
obj = json.loads(cmd) obj = json.loads(cmd)
except (ValueError, TypeError): except (ValueError, TypeError):