Changed how SimulaQron does logging: we no longer use the logging from the NetQASM library (which results in logging to /dev/null and unclear how to adapt it) but simply write out own log files for the deamons to /tmp. This now allows us to properly debug the code and pinpoint where/when what happens

Author: StephanieWehner

examples/nativeMode/corrRNG/aliceTest.py

@@ -127,7 +127,7 @@ def main():
     # Check if we should run a server (if this node is listed in classicalNet)
     if myName in classicalNet.hostDict:
         # Create the local classical server
-        logging.debug("LOCAL %s: Creating classical server.", myName)
+        logging.debug("APP %s: Creating classical server.", myName)
         myNode = localNode(virtualNet.hostDict[myName], classicalNet)
     else:
         myNode = None
@@ -137,5 +137,9 @@ def main():
 
 
 ##################################################################################################
-logging.basicConfig(format="%(asctime)s:%(levelname)s:%(message)s", level=logging.DEBUG)
+logging.basicConfig(
+    format="%(asctime)s:%(levelname)s:%(name)s:%(filename)s:%(lineno)d:%(message)s",
+    level=logging.DEBUG,
+    force=True
+)
 main()

examples/nativeMode/corrRNG/bobTest.py

@@ -148,5 +148,9 @@ def main():
 
 
 ##################################################################################################
-logging.basicConfig(format="%(asctime)s:%(levelname)s:%(message)s", level=logging.DEBUG)
+logging.basicConfig(
+    format="%(asctime)s:%(levelname)s:%(name)s:%(filename)s:%(lineno)d:%(message)s",
+    level=logging.DEBUG,
+    force=True
+)
 main()

simulaqron/local/setup.py

@@ -27,10 +27,10 @@
 # (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
 # SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
 
+import logging
 import time
 from typing import Callable
 
-from netqasm.logging.glob import get_netqasm_logger
 from twisted.internet import error
 from twisted.internet.defer import DeferredList
 from twisted.internet.error import ReactorNotRunning
@@ -39,21 +39,21 @@
 from simulaqron.general.host_config import SocketsConfig
 from simulaqron.reactor import reactor
 
-_logger = get_netqasm_logger("setup-local")
+_logger = logging.getLogger("setup-local")
 
 
 #####################################################################################################
 #
 # setup_local
 #
-# Sets up the local classical comms server (if applicable), and connects to the local virtual node
-# and other classical communication servers.
+# Sets up the local classical application level comms server (if applicable), and connects to the local 
+# virtual node and other classical communication servers.
 
 
 def setup_local(myName: str, virtualNet: SocketsConfig, classicalNet: SocketsConfig,
                 lNode: pb.Root, func: Callable, *args, **kwargs):
     """
-    Sets up a local classical communication server (if desired according to the configuration file),
+    Sets up a local classical applicaiton level communication server (if desired according to the configuration file),
     a client connection to the local virtual node quantum backend and a client connections to all other
     classical communication servers
 
@@ -81,22 +81,22 @@ def setup_local(myName: str, virtualNet: SocketsConfig, classicalNet: SocketsCon
     if myName in classicalNet.hostDict:
         try:
             nb = classicalNet.hostDict[myName]
-            _logger.debug("LOCAL %s: Starting local classical communication server (%s: %s, %d).",
+            _logger.debug("SETUP_LOCAL %s: Starting local classical communication server (%s: %s, %d).",
                           myName, nb.name, nb.hostname, nb.port
                           )
             nb.root = lNode
             nb.factory = pb.PBServerFactory(nb.root)
             reactor.listenTCP(nb.port, nb.factory)
         except Exception as e:
-            _logger.error("LOCAL %s: Cannot start classical communication servers: %s", myName, e)
+            _logger.error("SETUP_LOCAL %s: Cannot start classical communication servers: %s", myName, e)
             return
 
     # Give the server some time to start up
     time.sleep(3)
 
     # Connect to the local virtual node simulating the "local" qubits
     node = virtualNet.hostDict[myName]
-    _logger.debug("LOCAL %s: Connecting to local virtual node (%s: %s, %d).", myName, node.name, node.hostname,
+    _logger.debug("SETUP_LOCAL %s: Connecting to local virtual node (%s: %s, %d).", myName, node.name, node.hostname,
                   node.port)
     factory = pb.PBClientFactory()
     reactor.connectTCP(node.hostname, node.port, factory)
@@ -107,7 +107,7 @@ def setup_local(myName: str, virtualNet: SocketsConfig, classicalNet: SocketsCon
     for node in classicalNet.hostDict:
         nb = classicalNet.hostDict[node]
         if nb.name != myName:
-            _logger.debug("LOCAL %s: Making classical connection to %s (%s: %s, %d).", myName, nb.name, nb.name,
+            _logger.debug("SETUP_LOCAL %s: Making classical connection to %s (%s: %s, %d).", myName, nb.name, nb.name,
                           nb.hostname, nb.port)
             nb.factory = pb.PBClientFactory()
             reactor.connectTCP(nb.hostname, nb.port, nb.factory)
@@ -133,7 +133,7 @@ def setup_local(myName: str, virtualNet: SocketsConfig, classicalNet: SocketsCon
 
 def init_register(resList: DeferredList, myName: str, virtualNet: SocketsConfig, classicalNet: SocketsConfig,
                   lNode: pb.Root, func: Callable, *args, **kwargs):
-    _logger.debug("LOCAL %s: All connections set up.", myName)
+    _logger.debug("SETUP_LOCAL %s: All connections set up.", myName)
 
     # Retrieve the connection to the local virtual node, if successful
     j = 0
@@ -142,7 +142,7 @@ def init_register(resList: DeferredList, myName: str, virtualNet: SocketsConfig,
         if lNode is not None:
             lNode.set_virtual_node(virtRoot)
     else:
-        _logger.error("LOCAL %s: Connection to virtual server failed!", myName)
+        _logger.error("SETUP_LOCAL %s: Connection to virtual server failed!", myName)
         reactor.stop()
 
     # Retrieve connections to the classical nodes
@@ -152,9 +152,9 @@ def init_register(resList: DeferredList, myName: str, virtualNet: SocketsConfig,
             j = j + 1
             if resList[j][0]:
                 nb.root = resList[j][1]
-                _logger.debug("LOCAL %s: Connected node %s with %s", myName, nb.name, nb.root)
+                _logger.debug("SETUP_LOCAL %s: Connected node %s with %s", myName, nb.name, nb.root)
             else:
-                _logger.error("LOCAL %s: Connection to %s failed!", myName, nb.name)
+                _logger.error("SETUP_LOCAL %s: Connection to %s failed!", myName, nb.name)
                 reactor.stop()
 
     # On the local virtual node, we still want to initialize a qubit register
@@ -164,7 +164,7 @@ def init_register(resList: DeferredList, myName: str, virtualNet: SocketsConfig,
 
 
 def fill_register(obj, myName, lNode, virtRoot, classicalNet, func, *args, **kwargs):
-    _logger.debug("LOCAL %s: Created quantum register at virtual node.", myName)
+    _logger.debug("SETUP_LOCAL %s: Created quantum register at virtual node.", myName)
     qReg = obj
 
     # If we run a server, record the handle to the local virtual register
@@ -179,7 +179,7 @@ def localError(reason):
     """
     Error handling for the connection.
     """
-    _logger.error("Critical error: %s", reason)
+    _logger.error("SETUP_LOCAL: Critical error: %s", reason)
     try:
         reactor.stop()
     except ReactorNotRunning:

simulaqron/netqasm_backend/factory.py

@@ -30,7 +30,7 @@
 
 from netqasm.backend.messages import MessageHeader, ErrorCode, deserialize_host_msg, Message, \
     InitNewAppMessage
-from netqasm.logging.glob import get_netqasm_logger
+import logging
 from twisted.internet.defer import DeferredLock, inlineCallbacks
 from twisted.internet.protocol import Factory, Protocol, connectionDone
 from twisted.internet.task import deferLater
@@ -81,7 +81,7 @@ def __init__(self, factory: "NetQASMFactory"):
         # Convenience
         self.name = self.factory.name
 
-        self._logger = get_netqasm_logger(f"{self.__class__.__name__}({self.name})")
+        self._logger = logging.getLogger(f"{self.__class__.__name__}({self.name})")
         self._logger.debug("Initialized Protocol")
 
     def connectionMade(self):
@@ -195,7 +195,7 @@ def __init__(
         # Lock governing access to the qubitList
         self._lock = DeferredLock()
 
-        self._logger = get_netqasm_logger(f"{self.__class__.__name__}({name})")
+        self._logger = logging.getLogger(f"{self.__class__.__name__}({name})")
 
         # Read in topology, if specified. topology=None means fully connected
         # topology

simulaqron/network.py

@@ -34,10 +34,11 @@
 
 import networkx as nx
 from multiprocess.context import ForkProcess as Process
-from netqasm.logging.glob import get_netqasm_logger, get_log_level
+import logging
 
 from simulaqron.settings import network_config
 from simulaqron.settings.network_config import NodeConfig
+from simulaqron.settings import simulaqron_settings
 from simulaqron.start import start_vnode, start_qnodeos
 # WARNING - this import *needs* to be after importing start_vnode and start_qnodeos
 # Otherwise the code that patches some netqasm internal definitions will not work correctly!
@@ -66,7 +67,7 @@ def __init__(self, nodes: List[str], network_name: str = "default"):
         self.name = network_name
 
         self.processes: List[Process] = []
-        self._logger = get_netqasm_logger(f"{self.__class__.__name__}({self.name})")
+        self._logger = logging.getLogger(f"{self.__class__.__name__}({self.name})")
 
         # Determine the nodes to start, using the in-memory network config
         self._nodes_to_start: List[NodeConfig] = []
@@ -110,10 +111,10 @@ def _setup_processes(self):
         """
         for node in self._nodes_to_start:
             process_virtual = Process(
-                target=start_vnode, args=(node.name, self.name, get_log_level()), name=f"VirtNode {node.name}"
+                target=start_vnode, args=(node.name, self.name, simulaqron_settings.log_level), name=f"VirtNode {node.name}"
             )
             process_qnodeos = Process(
-                target=start_qnodeos, args=(node.name, self.name, get_log_level()), name=f"QnodeOSNode {node.name}"
+                target=start_qnodeos, args=(node.name, self.name, simulaqron_settings.log_level), name=f"QnodeOSNode {node.name}"
             )
             self.processes += [process_virtual, process_qnodeos]
 

simulaqron/run/run.py

@@ -11,7 +11,7 @@
 from multiprocess.context import ForkContext as ProcessContext
 from multiprocess.pool import ApplyResult
 from multiprocess.sharedctypes import SynchronizedArray
-from netqasm.logging.glob import get_netqasm_logger
+import logging
 from netqasm.logging.output import (reset_struct_loggers,
                                     save_all_struct_loggers)
 from netqasm.runtime import env, process_logs
@@ -28,7 +28,7 @@
 from simulaqron.settings import simulaqron_settings, network_config
 from simulaqron.settings.simulaqron_config import SimBackend
 
-logger = get_netqasm_logger()
+logger = logging.getLogger()
 
 # TODO similar code to squidasm.run.run, make base-class and subclasses?
 

simulaqron/sdk/connection.py

@@ -11,7 +11,7 @@
                                       ErrorCode, Message, APP_ID)
 from netqasm.lang.ir import GenericInstr
 from netqasm.lang.operand import Address, Register
-from netqasm.logging.glob import get_netqasm_logger
+import logging
 from netqasm.sdk import EPRSocket
 from netqasm.sdk.config import LogConfig
 from netqasm.sdk.connection import BaseNetQASMConnection
@@ -24,7 +24,7 @@
                                             get_node_id_from_net_config)
 from simulaqron.settings import network_config
 
-logger = get_netqasm_logger("SimulaQronConnection")
+logger = logging.getLogger("SimulaQronConnection")
 
 
 class SimulaQronConnection(BaseNetQASMConnection):

simulaqron/sdk/socket.py

@@ -3,7 +3,7 @@
 from typing import Optional
 
 import dill
-from netqasm.logging.glob import get_netqasm_logger
+import logging
 from netqasm.sdk.classical_communication.message import StructuredMessage
 from netqasm.sdk.classical_communication.socket import Socket as _Socket
 
@@ -33,7 +33,7 @@ def __init__(
         self._use_callbacks = use_callbacks
         self._network_name = network_name
 
-        self._logger = get_netqasm_logger(f"{self.__class__.__name__}(L: {app_name} <-> R: {remote_app_name})")
+        self._logger = logging.getLogger(f"{self.__class__.__name__}(L: {app_name} <-> R: {remote_app_name})")
         self._timeout = timeout
         # We define _app_socket as None as a default value, so the __del__ method
         # does not fail when the socket could not be connected correctly.

simulaqron/sim_util.py

@@ -1,10 +1,10 @@
 import numpy as np
-from netqasm.logging.glob import get_netqasm_logger
+import logging
 from netqasm.sdk import Qubit
 
 from simulaqron.sdk import SimulaQronConnection
 
-logger = get_netqasm_logger("sim_util")
+logger = logging.getLogger("sim_util")
 
 
 def get_qubit_state(qubit: Qubit, reduced_dm: bool = True) -> np.ndarray:

simulaqron/simulaqron.py

@@ -1,6 +1,7 @@
 import importlib.metadata as metadata
 import logging
 import time
+import sys
 from pathlib import Path
 from typing import Optional, List
 
@@ -26,23 +27,31 @@
 class RunningSimulaQronDaemon(run.RunDaemon):
     """
     SimulaQronDaemon class used to represent SimulaQron daemons that are already running.
-    This class is useful to stop the already-running daemons without needed to read all
+    This class is useful to 5stop the already-running daemons without needed to read all
     the required configurations.
     """
 
     def __init__(self, pidfile: Path):
         assert pidfile is not None
-        super().__init__(pidfile=pidfile)
-
+        super().__init__(
+            pidfile=pidfile,
+        )
 
 class SimulaQronDaemon(run.RunDaemon):
     def __init__(self, pidfile: Path, name: str, nodes: List[str]):
-        super().__init__(pidfile=pidfile)
+        super().__init__(
+            pidfile=pidfile,
+        )
         self.name = name
         self.nodes = nodes
 
     def run(self):
         """Starts all nodes defined in netsim's config directory."""
+
+        # Let's make sure we can record the output where it's accessible
+        sys.stdout = open('/tmp/simulaqron.out', 'w', buffering=1)
+        sys.stderr = open('/tmp/simulaqron.err', 'w', buffering=1)
+
         network = Network(network_name=self.name, nodes=self.nodes)
         network.start()
 
@@ -141,6 +150,7 @@ def stop(name: str):
     """Stops a network."""
     assert name is not None
     pidfile = PID_FOLDER / f"simulaqron_network_{name}.pid"
+    logging.debug(f"Trying to open PIDfile")
     if not pidfile.exists():
         logging.warning("Network with name %s is not running", name)
         return
@@ -613,7 +623,8 @@ def get(network_name: str):
 
 if __name__ == "__main__":
     logging.basicConfig(
-        format="%(asctime)s:%(levelname)s:%(message)s",
+            logging.basicConfig(
+        format="%(asctime)s:%(levelname)s:%(filename)s:%(lineno)d:%(message)s",
         level=simulaqron_settings.log_level,
-    )
+    ))
     cli()