From 38e25070ab5e5b74917797f9049dd226afeb9728 Mon Sep 17 00:00:00 2001 From: Marco Capitani Date: Thu, 16 Nov 2017 16:59:04 +0100 Subject: storyboard: add logging and log retrieval --- examples/example.py | 55 ++++++++++++++++++++++++++++++---------- examples/rinaperf_sb-usage.py | 58 ------------------------------------------- rumba/model.py | 16 +++++++++--- rumba/ssh_support.py | 57 ++++++++++++++++++++++++++++++++++++++++-- rumba/storyboard.py | 57 ++++++++++++++++++++++++++++++++++-------- 5 files changed, 156 insertions(+), 87 deletions(-) delete mode 100644 examples/rinaperf_sb-usage.py diff --git a/examples/example.py b/examples/example.py index 8d17ff2..a26ab3b 100755 --- a/examples/example.py +++ b/examples/example.py @@ -30,26 +30,55 @@ n1.add_policy("security-manager", "passwd") e1 = ShimEthDIF("e1") a = Node("a", - difs = [n1, e1], - dif_registrations = {n1 : [e1]}) + difs=[n1, e1], + dif_registrations={n1: [e1]}) b = Node("b", - difs = [e1, n1], - dif_registrations = {n1 : [e1]}) + difs=[e1, n1], + dif_registrations={n1: [e1]}) -tb = jfed.Testbed(exp_name = "example1", - username = "user1", - cert_file = "/home/user1/cert.pem") +tb = jfed.Testbed(exp_name="example1", + username="user1", + cert_file="/home/user1/cert.pem") + +exp = rl.Experiment(tb, nodes=[a, b]) + +print(exp) + +# General setup (can be reused in other scripts as-is) +storyboard = StoryBoard(duration=30) + +# Clients can be applications that just keep running, and will be +# stopped by a SIGINT... +client1 = Client("rinaperf", + options="-t perf -s 1000 -c 0") + +# ... or a custom shutdown method can be provided. +client2 = Client("rinaperf", + options="-t perf -s 1000 -D ", + shutdown="") + +server = Server("rinaperf", options="-l", arrival_rate=0.5, + mean_duration=5, clients=[client1, client2]) + + +# Experiment-specific configuration: +# (This can be done anytime before storyboard.start()) + +storyboard.set_experiment(exp) +storyboard.add_server((server, a)) +client1.add_node(b) +client2.add_node(b) -exp = rl.Experiment(tb, nodes = [a, b]) print(exp) with ExperimentManager(exp): exp.swap_in() + exp.install_prototype() exp.bootstrap_prototype() - c1 = Client("rinaperf", options ="-t perf -s 1000 -c 0", nodes=[b]) - s1 = Server("rinaperf", arrival_rate=2, mean_duration=5, - options = "-l", nodes = [a], clients = [c1]) - sb = StoryBoard(duration=3600, experiment=exp, servers=[s1]) - sb.start() + storyboard.start() + + # Fetch the client/server logs from the nodes + # and put them in the cwd. + storyboard.fetch_logs() diff --git a/examples/rinaperf_sb-usage.py b/examples/rinaperf_sb-usage.py deleted file mode 100644 index 0e7ca72..0000000 --- a/examples/rinaperf_sb-usage.py +++ /dev/null @@ -1,58 +0,0 @@ -#!/usr/bin/env python - -from rumba.model import * -from rumba.storyboard import * -import rumba.testbeds.qemu as qemu -import rumba.prototypes.irati as irati -import rumba.log as log -from rumba.utils import ExperimentManager - -log.set_logging_level('DEBUG') - - -n1 = NormalDIF("n1") - -n1.add_policy("rmt.pff", "lfa") -n1.add_policy("security-manager", "passwd") - -e1 = ShimEthDIF("e1") - -a = Node("a", - difs=[n1, e1], - dif_registrations={n1: [e1]}) - -b = Node("b", - difs=[e1, n1], - dif_registrations={n1: [e1]}) - -tb = qemu.Testbed(exp_name="example1", - username="root", - password="root") - -exp = irati.Experiment(tb, nodes=[a, b]) - - -# General setup (can be reused in other scripts as-is) -storyboard = StoryBoard(duration=30) -client = Client("rinaperf", - options="-t perf -s 1000 -D ", - shutdown="") -server = Server("rinaperf", options="-l", arrival_rate=0.5, - mean_duration=5, clients=[client]) - - -# Experiment-specific configuration: -# (This can be done anytime before storyboard.start()) - -storyboard.set_experiment(exp) -storyboard.add_server((server, a)) -client.add_node(b) - - -print(exp) - -with ExperimentManager(exp): - exp.swap_in() - exp.bootstrap_prototype() - storyboard.start() - input('ENTER') diff --git a/rumba/model.py b/rumba/model.py index 7a68459..7573df2 100644 --- a/rumba/model.py +++ b/rumba/model.py @@ -370,12 +370,20 @@ class Node: destination ) - def setup_vlan(self, vlan_id, int_name): - ssh_support.setup_vlan( + def fetch_files(self, paths, destination): + ssh_support.copy_files_from_testbed( self.ssh_config, self.ssh_config, - vlan_id, - int_name + paths, + destination + ) + + def fetch_file(self, path, destination): + ssh_support.copy_file_from_testbed( + self.ssh_config, + self.ssh_config, + path, + destination ) diff --git a/rumba/ssh_support.py b/rumba/ssh_support.py index fbe68c8..1a065c6 100644 --- a/rumba/ssh_support.py +++ b/rumba/ssh_support.py @@ -26,6 +26,7 @@ import os import paramiko +import re import time import rumba.log as log @@ -53,12 +54,15 @@ def get_ssh_client(): def _print_stream(stream): o = str(stream.read()).strip('b') o = o.strip('\'\"') - o = o.replace('\\n', '') + o = o.rstrip() + o = re.sub(r'(\\n)*$', '', o) if o != "": o_array = o.split('\\n') for oi in o_array: logger.debug(oi) - return o.rstrip() + else: + o_array = [] + return '\n'.join(o_array) def ssh_connect(hostname, port, username, password, time_out, proxy_server): logger.debug('Trying to open a connection towards node %s.' % hostname) @@ -300,6 +304,55 @@ def copy_file_to_testbed(testbed, ssh_config, path, destination): copy_files_to_testbed(testbed, ssh_config, [path], destination) +def copy_files_from_testbed(testbed, ssh_config, paths, destination): + """ + Copies local files to a remote node. + + @param testbed: testbed info + @param ssh_config: ssh config of the node + @param paths: source paths (remote) as an iterable + @param destination: destination folder name (local) + """ + if destination is not '' and not destination.endswith('/'): + destination = destination + '/' + + if ssh_config.client is None: + client, proxy_client = ssh_connect(ssh_config.hostname, ssh_config.port, + testbed.username, testbed.password, + None, ssh_config.proxy_server) + ssh_config.client = client + ssh_config.proxy_client = proxy_client + + try: + sftp_client = ssh_config.client.open_sftp() + + for path in paths: + file_name = os.path.basename(path) + dest_file = destination + file_name + logger.debug("Copying %s to %s@%s:%s path %s" % ( + path, + testbed.username, + ssh_config.hostname, + ssh_config.port, + dest_file)) + sftp_client.get(path, dest_file) + + except Exception as e: + raise SSHException('Failed to copy files from testbed', e) + + +def copy_file_from_testbed(testbed, ssh_config, path, destination): + """ + Copies a local file to a remote node. + + @param testbed: testbed info + @param ssh_config: ssh config of the node + @param path: source path (remote) + @param destination: destination folder name (local) + """ + copy_files_from_testbed(testbed, ssh_config, [path], destination) + + def setup_vlans(testbed, node, vlans): """ Gets the interface (ethx) to link mapping diff --git a/rumba/storyboard.py b/rumba/storyboard.py index 52bd875..4a09ac8 100644 --- a/rumba/storyboard.py +++ b/rumba/storyboard.py @@ -5,6 +5,7 @@ # Copyright (C) 2017 imec # # Sander Vrijders +# Dimitri Staessens # Vincenzo Maffione # Marco Capitani # @@ -23,11 +24,12 @@ # Foundation, Inc., http://www.fsf.org/about/contact/. # -# Base class for client programs +# Base class for client apps # # @ap: Application Process binary # @options: Options to pass to the binary # +import os import random import time @@ -50,6 +52,14 @@ except ImportError: logger.debug("Falling back to simple implementations.") # PROBLEM! These logs will almost never be printed... But we might not care +current_id = -1 + + +def get_id(): + global current_id + current_id += 1 + return current_id + class Client(object): def __init__(self, ap, nodes=None, options=None, shutdown="kill "): @@ -69,7 +79,7 @@ class Client(object): def process(self, duration): node = random.choice(self.nodes) if len(self.nodes) > 0 else None - return ClientProcess(self.ap, self.startup, duration, node, self.shutdown) + return ClientProcess(get_id(), self.ap, self.startup, duration, node, self.shutdown) # Base class for client processes @@ -80,8 +90,9 @@ class Client(object): # @options: Options to pass to the binary # class ClientProcess(object): - def __init__(self, ap, startup, duration, + def __init__(self, client_id, ap, startup, duration, node=None, shutdown=""): + self.id = client_id self.ap = ap self.startup = startup self.duration = duration @@ -103,7 +114,9 @@ class ClientProcess(object): self.ap, self.node.name, self.duration ) - start_cmd = "./startup.sh %s" % ( + start_cmd = "./startup.sh %s_%s %s" % ( + self.ap, + self.id, self.startup.replace("", str(self.duration)), ) self.running = True @@ -209,11 +222,11 @@ class Server: def run(self): for node in self.nodes: logfile = "%s_server.log" % self.ap - script = r'nohup "$@" > %s & echo "$!"' % (logfile,) + script = r'nohup "$@" > %s 2>&1 & echo "$!"' % (logfile,) run_cmd = self.ap + ( (" " + self.options) if self.options is not None else "" ) - cmd_1 = "echo '%s' > startup.sh && chmod a+x startup.sh && cat startup.sh" \ + cmd_1 = "echo '%s' > startup.sh && chmod a+x startup.sh" \ % (script,) cmd_2 = "./startup.sh %s" % (run_cmd,) logger.debug( @@ -223,7 +236,6 @@ class Server: try: node.execute_command(cmd_1) self.pids[node] = (node.execute_command(cmd_2)) - node.execute_command("cat startup.sh") except ssh_support.SSHException: logger.warn('Could not start server %s on node %s.', self.ap, node.name) @@ -269,7 +281,8 @@ class StoryBoard: "setting the experiment.") if hasattr(s, '__len__') and len(s) == 2: server, node = s - if not isinstance(server, Server) or not isinstance(node, model.Node): + if not isinstance(server, Server) \ + or not isinstance(node, model.Node): raise TypeError('First element must be of "Server" type, ' 'second must be of "Node" type.') server.add_node(node) @@ -297,13 +310,15 @@ class StoryBoard: def start(self): self.start_time = time.time() - script = r'nohup "$@" > /tmp/$1 & echo "$!"' + script = r'logname="$1"; shift; nohup "${@}" ' \ + r'> /tmp/${logname}.rumba.log 2>&1 & echo "$!"' logger.debug("Writing utility startup script on client nodes.") for server in self.servers: for client in server.clients: for node in client.nodes: node.execute_command( - "echo '%s' > startup.sh && chmod a+x startup.sh" % (script,) + "echo '%s' > startup.sh && chmod a+x startup.sh" + % (script,) ) try: for server in self.servers: @@ -325,3 +340,25 @@ class StoryBoard: client.stop() for server in self.servers: server.stop() + + def fetch_logs(self, local_dir='.'): + if not os.path.isdir(local_dir): + raise Exception('"%s" is not a directory. Cannot fetch logs.' + % local_dir) + server_nodes = set() + client_nodes = set() + for server in self.servers: + for node in server.nodes: + server_nodes.add(node) + for client in server.clients: + for node in client.nodes: + client_nodes.add(node) + for node in server_nodes: + logs_list = node.execute_command('ls *_server.log') + logger.info('Log list is:\n%s', logs_list) + node.fetch_files(logs_list.split('\n'), local_dir) + for node in client_nodes: + logs_list = node.execute_command('ls /tmp/*.rumba.log ' + '|| echo ""') + logger.info('Log list is:\n%s', logs_list) + node.fetch_files(logs_list.split('\n'), local_dir) -- cgit v1.2.3