Adding ns3wrapper debug to dump ns-3 experiment execution to a runnable script
authorAlina Quereilhac <alina.quereilhac@inria.fr>
Wed, 25 Jun 2014 11:50:58 +0000 (13:50 +0200)
committerAlina Quereilhac <alina.quereilhac@inria.fr>
Wed, 25 Jun 2014 11:50:58 +0000 (13:50 +0200)
src/nepi/resources/linux/ns3/ns3client.py
src/nepi/resources/linux/ns3/ns3simulation.py
src/nepi/resources/ns3/ns3base.py
src/nepi/resources/ns3/ns3netdevice.py
src/nepi/resources/ns3/ns3server.py
src/nepi/resources/ns3/ns3wrapper.py
src/nepi/resources/ns3/ns3wrapper_debug.py [new file with mode: 0644]

index 43dd7d7..f81e449 100644 (file)
@@ -56,7 +56,6 @@ class LinuxNS3Client(NS3Client):
             sock.send("%s\n" % encoded)
             reply = sock.recv(1024)
             sock.close()
-
         else:
             command = ( "python -c 'import socket;"
                 "sock = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM);"
index f5a14ee..4f1cf0b 100644 (file)
@@ -76,6 +76,13 @@ class LinuxNS3Simulation(LinuxApplication, NS3Simulation):
             type = Types.Bool,
             flags = Flags.Design)
 
+        enable_dump = Attribute("enableDump",
+            "Enable dumping the remote executed ns-3 commands to a script "
+            "in order to later reproduce and debug the experiment",
+            type = Types.Bool,
+            default = False,
+            flags = Flags.Design)
+
         build_mode = Attribute("buildMode",
             "Mode used to build ns-3 with waf. One if: debug, release, oprimized ",
             default = "optimized", 
@@ -105,6 +112,7 @@ class LinuxNS3Simulation(LinuxApplication, NS3Simulation):
         cls._register_attribute(sched_type)
         cls._register_attribute(check_sum)
         cls._register_attribute(ns_log)
+        cls._register_attribute(enable_dump)
         cls._register_attribute(verbose)
         cls._register_attribute(build_mode)
         cls._register_attribute(ns3_version)
@@ -150,6 +158,14 @@ class LinuxNS3Simulation(LinuxApplication, NS3Simulation):
                 os.path.join(self.node.src_dir, "ns3wrapper", "ns3wrapper.py"),
                 overwrite = False)
 
+        # upload ns3 wrapper debug python script
+        ns3_wrapper_debug = os.path.join(os.path.dirname(__file__), "..", "..", "ns3", 
+                "ns3wrapper_debug.py")
+
+        self.node.upload(ns3_wrapper_debug,
+                os.path.join(self.node.src_dir, "ns3wrapper", "ns3wrapper_debug.py"),
+                overwrite = False)
+
         # upload ns3_server python script
         ns3_server = os.path.join(os.path.dirname(__file__), "..", "..", "ns3",
                 "ns3server.py")
@@ -342,6 +358,9 @@ class LinuxNS3Simulation(LinuxApplication, NS3Simulation):
         if ns_log:
             command.append("-L '%s'" % ns_log)
 
+        if self.get("enableDump"):
+            command.append("-D")
+
         if self.get("verbose"):
             command.append("-v")
 
index 00bdbfb..f86bea7 100644 (file)
@@ -104,9 +104,6 @@ class NS3Base(ResourceManager):
         return False
 
     def do_provision(self):
-        # TODO: create run dir for ns3 object !!!!
-        # self.simulation.node.mkdir(self.run_home)
-
         self._instantiate_object()
         self._connect_object()
         self._configure_object()
index d401e67..719f38f 100644 (file)
@@ -128,10 +128,6 @@ class NS3BaseNetDevice(NS3Base):
         node = self.node
         rms.add(node)
 
-        ipv4 = node.ipv4
-        if node.ipv4:
-            rms.add(ipv4)
-
         rms.add(self.channel)
         return rms
 
index 24b26b9..30d5baf 100644 (file)
@@ -43,78 +43,50 @@ class NS3WrapperMessage:
 def handle_message(ns3_wrapper, msg_type, args, kwargs):
     if msg_type == NS3WrapperMessage.SHUTDOWN:
         ns3_wrapper.shutdown()
-        
-        ns3_wrapper.logger.debug("SHUTDOWN")
-        
+
         return "BYEBYE"
     
     if msg_type == NS3WrapperMessage.STOP:
         time = kwargs.get("time")
 
-        ns3_wrapper.logger.debug("STOP time=%s" % str(time))
-
         ns3_wrapper.stop(time=time)
+
         return "STOPPED"
 
     if msg_type == NS3WrapperMessage.START:
-        ns3_wrapper.logger.debug("START") 
-
         ns3_wrapper.start()
+
         return "STARTED"
 
     if msg_type == NS3WrapperMessage.CREATE:
         clazzname = args.pop(0)
         
-        result = ns3_wrapper.create(clazzname, *args)
-
-        ns3_wrapper.logger.debug("%s CREATE %s %s" % (str(result), clazzname, 
-            str(args)))
+        return ns3_wrapper.create(clazzname, *args)
         
-        return result
-
     if msg_type == NS3WrapperMessage.FACTORY:
         type_name = args.pop(0)
 
-        result = ns3_wrapper.factory(type_name, **kwargs)
-        
-        ns3_wrapper.logger.debug("%s FACTORY %s %s" % (str(result), type_name, 
-            str(kwargs)))
-        
-        return result
-
+        return ns3_wrapper.factory(type_name, **kwargs)
+       
     if msg_type == NS3WrapperMessage.INVOKE:
         uuid = args.pop(0)
         operation = args.pop(0)
    
-        result = ns3_wrapper.invoke(uuid, operation, *args, **kwargs)
-
-        ns3_wrapper.logger.debug("%s INVOKE %s %s %s %s " % (str(result), uuid, 
-            operation, str(args), str(kwargs)))
-
-        return result
+        return ns3_wrapper.invoke(uuid, operation, *args, **kwargs)
 
     if msg_type == NS3WrapperMessage.GET:
         uuid = args.pop(0)
         name = args.pop(0)
 
-        result = ns3_wrapper.get(uuid, name)
+        return ns3_wrapper.get(uuid, name)
         
-        ns3_wrapper.logger.debug("%s GET %s %s" % (str(result), uuid, name))
-
-        return result
-
     if msg_type == NS3WrapperMessage.SET:
         uuid = args.pop(0)
         name = args.pop(0)
         value = args.pop(0)
 
-        result = ns3_wrapper.set(uuid, name, value)
-
-        ns3_wrapper.logger.debug("%s SET %s %s %s" % (str(result), uuid, name, 
-            str(value)))
+        return ns3_wrapper.set(uuid, name, value)
 
-        return result
     if msg_type == NS3WrapperMessage.FLUSH:
         # Forces flushing output and error streams.
         # NS-3 output will stay unflushed until the program exits or 
@@ -175,7 +147,7 @@ def send_reply(conn, reply):
     conn.send("%s\n" % encoded)
 
 def get_options():
-    usage = ("usage: %prog -S <socket-name> -L <NS_LOG> -v ")
+    usage = ("usage: %prog -S <socket-name> -L <ns-log>  -D <enable-dump> -v ")
     
     parser = OptionParser(usage = usage)
 
@@ -187,6 +159,12 @@ def get_options():
         help = "NS_LOG environmental variable to be set", 
         default = "", type="str")
 
+    parser.add_option("-D", "--enable-dump", dest="enable_dump",
+        help = "Enable dumping the remote executed ns-3 commands to a script "
+            "in order to later reproduce and debug the experiment",
+        action = "store_true",
+        default = False)
+
     parser.add_option("-v", "--verbose",
         help="Print debug output",
         action="store_true", 
@@ -194,9 +172,11 @@ def get_options():
 
     (options, args) = parser.parse_args()
     
-    return (options.socket_name, options.verbose, options.ns_log)
+    return (options.socket_name, options.verbose, options.ns_log,
+            options.enable_dump)
 
-def run_server(socket_name, level = logging.INFO, ns_log = None):
+def run_server(socket_name, level = logging.INFO, ns_log = None, 
+        enable_dump = False):
 
     # Sets NS_LOG environmental variable for NS debugging
     if ns_log:
@@ -204,7 +184,7 @@ def run_server(socket_name, level = logging.INFO, ns_log = None):
 
     ###### ns-3 wrapper instantiation
 
-    ns3_wrapper = NS3Wrapper(loglevel=level)
+    ns3_wrapper = NS3Wrapper(loglevel=level, enable_dump = enable_dump)
     
     ns3_wrapper.logger.info("STARTING...")
 
@@ -249,7 +229,7 @@ def run_server(socket_name, level = logging.INFO, ns_log = None):
 
 if __name__ == '__main__':
             
-    (socket_name, verbose, ns_log) = get_options()
+    (socket_name, verbose, ns_log, enable_dump) = get_options()
 
     ## configure logging
     FORMAT = "%(asctime)s %(name)s %(levelname)-4s %(message)s"
@@ -258,5 +238,5 @@ if __name__ == '__main__':
     logging.basicConfig(format = FORMAT, level = level)
 
     ## Run the server
-    run_server(socket_name, level, ns_log)
+    run_server(socket_name, level, ns_log, enable_dump)
 
index e5f4a89..0e95a2b 100644 (file)
@@ -101,7 +101,7 @@ def load_ns3_module():
     return ns3mod
 
 class NS3Wrapper(object):
-    def __init__(self, loglevel = logging.INFO):
+    def __init__(self, loglevel = logging.INFO, enable_dump = False):
         super(NS3Wrapper, self).__init__()
         # Thread used to run the simulation
         self._simulation_thread = None
@@ -130,6 +130,14 @@ class NS3Wrapper(object):
         # Collection of allowed ns3 classes
         self._allowed_types = None
 
+        # Object to dump instructions to reproduce and debug experiment
+        from ns3wrapper_debug import NS3WrapperDebuger
+        self._debuger = NS3WrapperDebuger(enabled = enable_dump)
+
+    @property
+    def debuger(self):
+        return self._debuger
+
     @property
     def ns3(self):
         if not self._ns3:
@@ -175,10 +183,21 @@ class NS3Wrapper(object):
         return self._objects.get(uuid)
 
     def factory(self, type_name, **kwargs):
+        """ This method should be used to construct ns-3 objects
+        that have a TypeId and related introspection information """
+
         if type_name not in self.allowed_types:
             msg = "Type %s not supported" % (type_name) 
             self.logger.error(msg)
+
+        uuid = self.make_uuid()
+        
+        ### DEBUG
+        self.logger.debug("FACTORY %s( %s )" % (type_name, str(kwargs)))
+        
+        self.debuger.dump_factory(uuid, type_name, kwargs)
+        ########
+
         factory = self.ns3.ObjectFactory()
         factory.SetTypeId(type_name)
 
@@ -188,16 +207,31 @@ class NS3Wrapper(object):
 
         obj = factory.Create()
 
-        uuid = self.make_uuid()
         self._objects[uuid] = obj
 
+        ### DEBUG
+        self.logger.debug("RET FACTORY ( uuid %s ) %s = %s( %s )" % (
+            str(uuid), str(obj), type_name, str(kwargs)))
+        ########
         return uuid
 
     def create(self, clazzname, *args):
+        """ This method should be used to construct ns-3 objects that
+        do not have a TypeId (e.g. Values) """
+
         if not hasattr(self.ns3, clazzname):
             msg = "Type %s not supported" % (clazzname) 
             self.logger.error(msg)
-     
+
+        uuid = self.make_uuid()
+        
+        ### DEBUG
+        self.logger.debug("CREATE %s( %s )" % (clazzname, str(args)))
+    
+        self.debuger.dump_create(uuid, clazzname, args)
+        ########
+
         clazz = getattr(self.ns3, clazzname)
  
         # arguments starting with 'uuid' identify ns-3 C++
@@ -206,47 +240,81 @@ class NS3Wrapper(object):
        
         obj = clazz(*realargs)
         
-        uuid = self.make_uuid()
         self._objects[uuid] = obj
 
+        ### DEBUG
+        self.logger.debug("RET CREATE ( uuid %s ) %s = %s( %s )" % (str(uuid), 
+            str(obj), clazzname, str(args)))
+        ########
+
         return uuid
 
     def invoke(self, uuid, operation, *args, **kwargs):
+        ### DEBUG
+        self.logger.debug("INVOKE %s -> %s( %s, %s ) " % (
+            uuid, operation, str(args), str(kwargs)))
+        ########
+
+        result = None
+        newuuid = None
+
         if operation == "isRunning":
-            return self.is_running
-        if operation == "isAppRunning":
-            return self._is_app_running(uuid)
-        if operation == "addStaticRoute":
-            return self._add_static_route(uuid, *args)
-
-        if uuid.startswith(SINGLETON):
-            obj = self._singleton(uuid)
+            result = self.is_running
+        elif operation == "isAppRunning":
+            result = self._is_app_running(uuid)
+        elif operation == "addStaticRoute":
+            ### DEBUG
+            self.debuger.dump_add_static_route(uuid, args)
+            ########
+
+            result = self._add_static_route(uuid, *args)
         else:
-            obj = self.get_object(uuid)
-        
-        method = getattr(obj, operation)
+            newuuid = self.make_uuid()
 
-        # arguments starting with 'uuid' identify ns-3 C++
-        # objects and must be replaced by the actual object
-        realargs = self.replace_args(args)
-        realkwargs = self.replace_kwargs(kwargs)
+            ### DEBUG
+            self.debuger.dump_invoke(newuuid, uuid, operation, args, kwargs)
+            ########
 
-        result = method(*realargs, **realkwargs)
+            if uuid.startswith(SINGLETON):
+                obj = self._singleton(uuid)
+            else:
+                obj = self.get_object(uuid)
+            
+            method = getattr(obj, operation)
 
-        # If the result is not an object, no need to 
-        # keep a reference. Directly return value.
-        if result is None or type(result) in [bool, float, long, str, int]:
-            return result
-      
-        newuuid = self.make_uuid()
-        self._objects[newuuid] = result
+            # arguments starting with 'uuid' identify ns-3 C++
+            # objects and must be replaced by the actual object
+            realargs = self.replace_args(args)
+            realkwargs = self.replace_kwargs(kwargs)
 
-        return newuuid
+            result = method(*realargs, **realkwargs)
+
+            # If the result is an object (not a base value),
+            # then keep track of the object a return the object
+            # reference (newuuid)
+            if not (result is None or type(result) in [
+                    bool, float, long, str, int]):
+                self._objects[newuuid] = result
+                result = newuuid
+
+        ### DEBUG
+        self.logger.debug("RET INVOKE %s%s = %s -> %s(%s, %s) " % (
+            "(uuid %s) " % str(newuuid) if newuuid else "", str(result), uuid, 
+            operation, str(args), str(kwargs)))
+        ########
+
+        return result
 
     def _set_attr(self, obj, name, ns3_value):
         obj.SetAttribute(name, ns3_value)
 
     def set(self, uuid, name, value):
+        ### DEBUG
+        self.logger.debug("SET %s %s %s" % (uuid, name, str(value)))
+    
+        self.debuger.dump_set(uuid, name, value)
+        ########
+
         obj = self.get_object(uuid)
         type_name = obj.GetInstanceTypeId().GetName()
         ns3_value = self._attr_from_string_to_ns3_value(type_name, name, value)
@@ -269,12 +337,23 @@ class NS3Wrapper(object):
         if not event_executed[0]:
             self._set_attr(obj, name, ns3_value)
 
+        ### DEBUG
+        self.logger.debug("RET SET %s = %s -> set(%s, %s)" % (str(value), uuid, name, 
+            str(value)))
+        ########
+
         return value
 
     def _get_attr(self, obj, name, ns3_value):
         obj.GetAttribute(name, ns3_value)
 
     def get(self, uuid, name):
+        ### DEBUG
+        self.logger.debug("GET %s %s" % (uuid, name))
+        
+        self.debuger.dump_get(uuid, name)
+        ########
+
         obj = self.get_object(uuid)
         type_name = obj.GetInstanceTypeId().GetName()
         ns3_value = self._create_attr_ns3_value(type_name, name)
@@ -289,9 +368,19 @@ class NS3Wrapper(object):
         if not event_executed[0]:
             self._get_attr(obj, name, ns3_value)
 
-        return self._attr_from_ns3_value_to_string(type_name, name, ns3_value)
+        result = self._attr_from_ns3_value_to_string(type_name, name, ns3_value)
+
+        ### DEBUG
+        self.logger.debug("RET GET %s = %s -> get(%s)" % (str(result), uuid, name))
+        ########
+
+        return result
 
     def start(self):
+        ### DEBUG
+        self.debuger.dump_start()
+        ########
+
         # Launch the simulator thread and Start the
         # simulator in that thread
         self._condition = threading.Condition()
@@ -302,13 +391,29 @@ class NS3Wrapper(object):
         self._simulator_thread.start()
         self._started = True
 
+        ### DEBUG
+        self.logger.debug("START")
+        ########
+
     def stop(self, time = None):
+        ### DEBUG
+        self.debuger.dump_stop(time=time)
+        ########
+        
         if time is None:
             self.ns3.Simulator.Stop()
         else:
             self.ns3.Simulator.Stop(self.ns3.Time(time))
 
+        ### DEBUG
+        self.logger.debug("STOP time=%s" % str(time))
+        ########
+
     def shutdown(self):
+        ### DEBUG
+        self.debuger.dump_shutdown()
+        ########
+
         while not self.ns3.Simulator.IsFinished():
             #self.logger.debug("Waiting for simulation to finish")
             time.sleep(0.5)
@@ -324,6 +429,10 @@ class NS3Wrapper(object):
         sys.stdout.flush()
         sys.stderr.flush()
 
+        ### DEBUG
+        self.logger.debug("SHUTDOWN")
+        ########
+
     def _simulator_run(self, condition):
         # Run simulation
         self.ns3.Simulator.Run()
diff --git a/src/nepi/resources/ns3/ns3wrapper_debug.py b/src/nepi/resources/ns3/ns3wrapper_debug.py
new file mode 100644 (file)
index 0000000..51eae83
--- /dev/null
@@ -0,0 +1,193 @@
+#
+#    NEPI, a framework to manage network experiments
+#    Copyright (C) 2013 INRIA
+#
+#    This program is free software: you can redistribute it and/or modify
+#    it under the terms of the GNU General Public License as published by
+#    the Free Software Foundation, either version 3 of the License, or
+#    (at your option) any later version.
+#
+#    This program is distributed in the hope that it will be useful,
+#    but WITHOUT ANY WARRANTY; without even the implied warranty of
+#    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+#    GNU General Public License for more details.
+#
+#    You should have received a copy of the GNU General Public License
+#    along with this program.  If not, see <http://www.gnu.org/licenses/>.
+#
+# Author: Alina Quereilhac <alina.quereilhac@inria.fr>
+
+
+############ METHODS DEBUG NS3WRAPPER EXECUTION
+##
+## The ns3wrapper works in an interactive mode, receiving instructions in
+## a distributed manner. This makes it very hard to debug scripting errors 
+## in the client side. To simplify error debugging, when set to debug mode,
+## the ns3wrapper dumps every executed line to a script that can be then
+## executed locally to reproduce and debug the experiment.
+##
+###########################################################################
+
+import logging
+
+SINGLETON = "singleton::"
+
+class NS3WrapperDebuger(object):
+    def __init__(self, enabled):
+        super(NS3WrapperDebuger, self).__init__()
+        self._enabled = enabled
+        self._script_path = "debug.py"
+
+        self.dump_header()
+
+    @property
+    def enabled(self):
+        return self._enabled
+
+    @property
+    def script_path(self):
+        return self._script_path
+
+    def dump_to_script(self, command):
+        f = open(self.script_path, "a")
+        f.write("%s" % command)
+        f.close()
+
+    def dump_header(self):
+        if not self.enabled:
+            return
+
+        header = """
+from ns3wrapper import NS3Wrapper
+
+wrapper = NS3Wrapper()
+
+"""
+        self.dump_to_script(header)
+
+    def dump_factory(self, uuid, type_name, kwargs):
+        if not self.enabled:
+            return
+
+        command = ("kwargs = %(kwargs)s\n"
+                "%(uuid)s = wrapper.factory(%(type_name)s, **kwargs)\n\n" 
+                ) % dict({
+                 "uuid": self.format_value(uuid),
+                 "type_name": self.format_value(type_name),
+                 "kwargs": self.format_kwargs(kwargs)
+                })
+
+        self.dump_to_script(command)
+
+    def dump_create(self, uuid, clazzname, args):
+        if not self.enabled:
+            return
+
+        command = ("args = %(args)s\n"
+                "%(uuid)s = wrapper.create(%(clazzname)s, *args)\n\n" 
+                ) % dict({
+                 "uuid": self.format_value(uuid),
+                 "clazzname": self.format_value(clazzname),
+                 "args": self.format_args(args),
+                })
+
+        self.dump_to_script(command)
+
+    def dump_invoke(self, newuuid, uuid, operation, args, kwargs):
+        if not self.enabled:
+            return
+
+        command = ("args = %(args)s\n"
+                   "kwargs = %(kwargs)s\n"
+                   "%(newuuid)s = wrapper.invoke(%(uuid)s, %(operation)s, *args, **kwargs)\n\n" 
+                ) % dict({
+                 "newuuid": self.format_value(newuuid) if newuuid else "nothing",
+                 "uuid": self.format_value(uuid),
+                 "operation": self.format_value(operation),
+                 "args": self.format_args(args),
+                 "kwargs": self.format_kwargs(kwargs),
+                })
+
+        self.dump_to_script(command)
+
+    def dump_set(self, uuid, name, value):
+        if not self.enabled:
+            return
+
+        command = ("wrapper.set(%(uuid)s, %(name)s, %(value)s)\n\n" 
+                ) % dict({
+                 "uuid": self.format_value(uuid),
+                 "name": self.format_value(name),
+                 "value": self.format_value(value),
+                })
+
+        self.dump_to_script(command)
+
+    def dump_get(self, uuid, name):
+        if not self.enabled:
+            return
+
+        command = ("wrapper.get(%(uuid)s, %(name)s)\n\n" 
+                ) % dict({
+                 "uuid": self.format_value(uuid),
+                 "name": self.format_value(name),
+                })
+        
+        self.dump_to_script(command)
+
+    def dump_start(self):
+        if not self.enabled:
+            return
+
+        command = "wrapper.start()\n\n"
+        self.dump_to_script(command)
+
+    def dump_stop(self, time = None):
+        if not self.enabled:
+            return
+
+        command = ("wrapper.stop(time=%(time)s)\n\n" 
+                ) % dict({
+                 "time": self.format_value(time) if time else "None",
+                })
+
+        self.dump_to_script(command)
+
+    def dump_shutdown(self):
+        if not self.enabled:
+            return
+
+        command = "wrapper.shutdown()\n\n"
+        self.dump_to_script(command)
+
+    def dump_add_static_route(self, uuid, args):
+        if not self.enabled:
+            return
+
+        command = ("args = %(args)s\n"
+                   "wrapper._add_static_route(%(uuid)s, *args)\n\n" 
+                ) % dict({
+                 "uuid": self.format_value(uuid),
+                 "args": self.format_args(args),
+                })
+
+        self.dump_to_script(command)
+
+    def format_value(self, value):
+        if isinstance(value, str) and value.startswith("uuid"):
+            return value.replace("-", "")
+
+        import pprint 
+        return pprint.pformat(value)
+
+    def format_args(self, args):
+        fargs = map(self.format_value, args)
+        return "[%s]" % ",".join(fargs)
+
+    def format_kwargs(self, kwargs):
+        fkwargs = map(lambda (k,w): 
+               "%s: %s" % (self.format_value(k), self.format_value(w)), 
+            kwargs.iteritems())
+        
+        return  "dict({%s})" % ",".join(fkwargs)
+