mirror of
https://github.com/ansible-collections/community.general.git
synced 2026-05-07 05:42:50 +00:00
implements python logging for network connection plugin (#22817)
* enables logging for network_cli and paramiko * enables logging for ansible-connection * enabled logging for netconf connection
This commit is contained in:
@@ -39,6 +39,7 @@ import time
|
||||
import traceback
|
||||
import syslog
|
||||
import datetime
|
||||
import logging
|
||||
|
||||
from io import BytesIO
|
||||
|
||||
@@ -49,8 +50,8 @@ from ansible.playbook.play_context import PlayContext
|
||||
from ansible.plugins import connection_loader
|
||||
from ansible.utils.path import unfrackpath, makedirs_safe
|
||||
from ansible.errors import AnsibleConnectionFailure
|
||||
from ansible.utils.display import Display
|
||||
|
||||
logger = logging.getLogger('ansible-connection')
|
||||
|
||||
def do_fork():
|
||||
'''
|
||||
@@ -109,17 +110,24 @@ def recv_data(s):
|
||||
data += d
|
||||
return data
|
||||
|
||||
def log(msg, host, user=None):
|
||||
msg = 'h=%s u=%s %s' % (host, user, msg)
|
||||
logger.debug(msg)
|
||||
|
||||
|
||||
class Server():
|
||||
|
||||
def __init__(self, path, play_context):
|
||||
display.vvvv("starting new persistent socket with path %s" % path, play_context.remote_addr)
|
||||
|
||||
self.path = path
|
||||
self.play_context = play_context
|
||||
self.log = lambda x: log(x, play_context.remote_addr, play_context.remote_user)
|
||||
|
||||
self.log("starting new persistent socket with path %s" % path)
|
||||
|
||||
self._start_time = datetime.datetime.now()
|
||||
|
||||
display.vvv("using connection plugin %s" % self.play_context.connection, play_context.remote_addr)
|
||||
self.log("using connection plugin %s" % self.play_context.connection)
|
||||
|
||||
self.conn = connection_loader.get(play_context.connection, play_context, sys.stdin)
|
||||
self.conn._connect()
|
||||
@@ -127,7 +135,7 @@ class Server():
|
||||
raise AnsibleConnectionFailure('unable to connect to remote host')
|
||||
|
||||
connection_time = datetime.datetime.now() - self._start_time
|
||||
display.vvvv('connection established in %s' % connection_time, play_context.remote_addr)
|
||||
self.log('connection established in %s' % connection_time)
|
||||
|
||||
self.socket = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM)
|
||||
self.socket.bind(path)
|
||||
@@ -165,7 +173,7 @@ class Server():
|
||||
signal.alarm(C.PERSISTENT_CONNECT_TIMEOUT)
|
||||
try:
|
||||
(s, addr) = self.socket.accept()
|
||||
display.vvvv('incoming request accepted on persistent socket', self.play_context.remote_addr)
|
||||
self.log('incoming request accepted on persistent socket')
|
||||
# clear the alarm
|
||||
# FIXME: potential race condition here between the accept and
|
||||
# time to this call.
|
||||
@@ -177,14 +185,13 @@ class Server():
|
||||
data = recv_data(s)
|
||||
if not data:
|
||||
break
|
||||
display.vvvv("received data on socket with len %s" % len(data), self.play_context.remote_addr)
|
||||
|
||||
signal.alarm(C.DEFAULT_TIMEOUT)
|
||||
|
||||
rc = 255
|
||||
try:
|
||||
if data.startswith(b'EXEC: '):
|
||||
display.vvvv("socket operation is EXEC", self.play_context.remote_addr)
|
||||
self.log("socket operation is EXEC")
|
||||
cmd = data.split(b'EXEC: ')[1]
|
||||
(rc, stdout, stderr) = self.conn.exec_command(cmd)
|
||||
elif data.startswith(b'PUT: ') or data.startswith(b'FETCH: '):
|
||||
@@ -192,16 +199,16 @@ class Server():
|
||||
stdout = stderr = ''
|
||||
try:
|
||||
if op == 'FETCH:':
|
||||
display.vvvv("socket operation is FETCH", self.play_context.remote_addr)
|
||||
self.log("socket operation is FETCH")
|
||||
self.conn.fetch_file(src, dst)
|
||||
elif op == 'PUT:':
|
||||
display.vvvv("socket operation is PUT", self.play_context.remote_addr)
|
||||
self.log("socket operation is PUT")
|
||||
self.conn.put_file(src, dst)
|
||||
rc = 0
|
||||
except:
|
||||
pass
|
||||
elif data.startswith(b'CONTEXT: '):
|
||||
display.vvvv("socket operation is CONTEXT", self.play_context.remote_addr)
|
||||
self.log("socket operation is CONTEXT")
|
||||
pc_data = data.split(b'CONTEXT: ')[1]
|
||||
|
||||
src = StringIO(pc_data)
|
||||
@@ -214,7 +221,7 @@ class Server():
|
||||
self.dispatch(self.conn, 'update_play_context', pc)
|
||||
continue
|
||||
else:
|
||||
display.vvvv("socket operation is UNKNOWN", self.play_context.remote_addr)
|
||||
self.log("socket operation is UNKNOWN")
|
||||
stdout = ''
|
||||
stderr = 'Invalid action specified'
|
||||
except:
|
||||
@@ -223,20 +230,20 @@ class Server():
|
||||
|
||||
signal.alarm(0)
|
||||
|
||||
display.vvvv("socket operation completed with rc %s" % rc, self.play_context.remote_addr)
|
||||
self.log("socket operation completed with rc %s" % rc)
|
||||
|
||||
send_data(s, to_bytes(str(rc)))
|
||||
send_data(s, to_bytes(stdout))
|
||||
send_data(s, to_bytes(stderr))
|
||||
s.close()
|
||||
except Exception as e:
|
||||
display.vvvv(traceback.format_exc())
|
||||
self.log(traceback.foramt_exec())
|
||||
finally:
|
||||
# when done, close the connection properly and cleanup
|
||||
# the socket file so it can be recreated
|
||||
end_time = datetime.datetime.now()
|
||||
delta = end_time - self._start_time
|
||||
display.v('shutting down control socket, connection was active for %s secs' % delta, self.play_context.remote_addr)
|
||||
self.log('shutting down control socket, connection was active for %s secs' % delta)
|
||||
try:
|
||||
self.conn.close()
|
||||
self.socket.close()
|
||||
@@ -268,8 +275,6 @@ def main():
|
||||
sys.stderr.write(traceback.format_exc())
|
||||
sys.exit("FAIL: %s" % e)
|
||||
|
||||
display.verbosity = pc.verbosity
|
||||
|
||||
ssh = connection_loader.get('ssh', class_only=True)
|
||||
m = ssh._create_control_path(pc.remote_addr, pc.port, pc.remote_user)
|
||||
|
||||
@@ -290,16 +295,18 @@ def main():
|
||||
try:
|
||||
server = Server(sf_path, pc)
|
||||
except AnsibleConnectionFailure as exc:
|
||||
display.vvv(str(exc), pc.remote_addr)
|
||||
log(str(exc), pc.remote_addr, pc.remote_user)
|
||||
rc = 1
|
||||
except Exception as exc:
|
||||
display.vvv(traceback.format_exc(), pc.remote_addr)
|
||||
log(traceback.format_exc(), pc.remote_addr, pc.remote_user)
|
||||
rc = 1
|
||||
fcntl.lockf(lock_fd, fcntl.LOCK_UN)
|
||||
os.close(lock_fd)
|
||||
if rc == 0:
|
||||
server.run()
|
||||
sys.exit(rc)
|
||||
else:
|
||||
log('re-using existing socket connection', pc.remote_addr, pc.remote_user)
|
||||
fcntl.lockf(lock_fd, fcntl.LOCK_UN)
|
||||
os.close(lock_fd)
|
||||
|
||||
@@ -324,8 +331,8 @@ def main():
|
||||
time.sleep(C.PERSISTENT_CONNECT_INTERVAL)
|
||||
attempts += 1
|
||||
if attempts > C.PERSISTENT_CONNECT_RETRIES:
|
||||
display.vvvv('number of connection attempts exceeded, unable to connect to control socket')
|
||||
display.vvvv('persistent_connect_interval=%s, persistent_connect_retries=%s' % (C.PERSISTENT_CONNECT_INTERVAL, C.PERSISTENT_CONNECT_RETRIES))
|
||||
log('number of connection attempts exceeded, unable to connect to control socket', pc.remote_addr, pc.remote_user)
|
||||
log('persistent_connect_interval=%s, persistent_connect_retries=%s' % (C.PERSISTENT_CONNECT_INTERVAL, C.PERSISTENT_CONNECT_RETRIES), pc.remote_addr, pc.remote_user)
|
||||
sys.stderr.write('failed to connect to control socket')
|
||||
sys.exit(255)
|
||||
|
||||
@@ -350,5 +357,4 @@ def main():
|
||||
sys.exit(rc)
|
||||
|
||||
if __name__ == '__main__':
|
||||
display = Display()
|
||||
main()
|
||||
|
||||
Reference in New Issue
Block a user