Python: Different behavior in run vs debug mode in PyCharm

Question

Python code when being run from PyCharm without the debugger attached is behaving differently from when being run with pydev attached.

I am running a POX SDN controller in PyCharm and a Mininet simulation from console that connects the a listening socket opened by POX. When running in debug mode, the POX process finishes as soon as the Mininet simulation connects to it without producing any errors while it continues working as expected when in run mode. Here is the output:

Run:

/usr/bin/python2.7 /home/wirate/pyretic/pyretic.py pyretic.sdx.main
Initialize SDX
SDX: {'_policy': drop, 'notify': None, 'arp_policy': [DynamicPolicy]
packets
FwdBucket}
Creating SDX environment from the config files
Adding Physical ports for  A
Adding virtual ports for  A
Adding Physical ports for  C
Adding virtual ports for  C
Adding Physical ports for  B
Adding virtual ports for  B
{u'A': {u'A': [1], u'C': [3], u'B': [2]}, u'C': {u'C': [3, 4]}, u'B': {u'B': [2]}}
{u'A': {u'A': [1], u'C': [3], u'B': [2]}, u'C': {u'A': [1], u'C': [3, 4], u'B': [2]}, u'B': {u'B': [2]}}
{u'A': {u'A': [1], u'C': [3], u'B': [2]}, u'C': {u'A': [1], u'C': [3, 4], u'B': [2]}, u'B': {u'A': [1], u'C': [3], u'B': [2]}}
Parsing participant's policies
Starting VNH Assignment
After new assignment
Virtual Next Hop --> IP Prefix:  {'VNH1': set([u'110.0.0.0/24', u'100.0.0.0/24']), 'VNH2': set([u'140.0.0.0/24', u'150.0.0.0/24'])}
Virtual Next Hop --> Next Hop IP Address (Virtual):  {'VNH1': '172.0.1.1', 'VNH2': '172.0.1.2', 'VNH': [IPAddress('172.0.1.0'), IPAddress('172.0.1.1'), IPAddress('172.0.1.2'), IPAddress('172.0.1.3'), IPAddress('172.0.1.4'), IPAddress('172.0.1.5'), IPAddress('172.0.1.6'), IPAddress('172.0.1.7'), IPAddress('172.0.1.8'), IPAddress('172.0.1.9'), IPAddress('172.0.1.10'), IPAddress('172.0.1.11'), IPAddress('172.0.1.12'), IPAddress('172.0.1.13'), IPAddress('172.0.1.14'), IPAddress('172.0.1.15')]}
Virtual Next Hop --> Next Hop Mac Address (Virtual) {'VNH1': aa:00:00:00:00:01, 'VNH2': aa:00:00:00:00:02, 'VNH': 'aa:00:00:00:00:00'}
Completed VNH Assignment
POX 0.2.0 (carp) / Copyright 2011-2013 James McCauley, et al.
Connected to pyretic frontend.
DEBUG:core:POX 0.2.0 (carp) going up...
DEBUG:core:Running on CPython (2.7.8/Oct 20 2014 15:05:19)
DEBUG:core:Platform is Linux-3.16.0-24-generic-x86_64-with-Ubuntu-14.10-utopic
INFO:core:POX 0.2.0 (carp) is up.
DEBUG:openflow.of_01:Listening on 0.0.0.0:6633
INFO:openflow.of_01:[00-00-00-00-00-01 1] connected

Debug:

/usr/bin/python2.7 /home/wirate/pycharm-4.0/helpers/pydev/pydevd.py --multiproc --client 127.0.0.1 --port 49196 --file /home/wirate/pyretic/pyretic.py pyretic.sdx.main
pydev debugger: process 5555 is connecting

Connected to pydev debugger (build 139.574)
Initialize SDX
SDX: {'_policy': drop, 'notify': None, 'arp_policy': [DynamicPolicy]
packets
FwdBucket}
Creating SDX environment from the config files
Adding Physical ports for  A
Adding virtual ports for  A
Adding Physical ports for  C
Adding virtual ports for  C
Adding Physical ports for  B
Adding virtual ports for  B
{u'A': {u'A': [1], u'C': [3], u'B': [2]}, u'C': {u'C': [3, 4]}, u'B': {u'B': [2]}}
{u'A': {u'A': [1], u'C': [3], u'B': [2]}, u'C': {u'A': [1], u'C': [3, 4], u'B': [2]}, u'B': {u'B': [2]}}
{u'A': {u'A': [1], u'C': [3], u'B': [2]}, u'C': {u'A': [1], u'C': [3, 4], u'B': [2]}, u'B': {u'A': [1], u'C': [3], u'B': [2]}}
Parsing participant's policies
Starting VNH Assignment
After new assignment
Virtual Next Hop --> IP Prefix:  {'VNH1': set([u'110.0.0.0/24', u'100.0.0.0/24']), 'VNH2': set([u'140.0.0.0/24', u'150.0.0.0/24'])}
Virtual Next Hop --> Next Hop IP Address (Virtual):  {'VNH1': '172.0.1.1', 'VNH2': '172.0.1.2', 'VNH': [IPAddress('172.0.1.0'), IPAddress('172.0.1.1'), IPAddress('172.0.1.2'), IPAddress('172.0.1.3'), IPAddress('172.0.1.4'), IPAddress('172.0.1.5'), IPAddress('172.0.1.6'), IPAddress('172.0.1.7'), IPAddress('172.0.1.8'), IPAddress('172.0.1.9'), IPAddress('172.0.1.10'), IPAddress('172.0.1.11'), IPAddress('172.0.1.12'), IPAddress('172.0.1.13'), IPAddress('172.0.1.14'), IPAddress('172.0.1.15')]}
Virtual Next Hop --> Next Hop Mac Address (Virtual) {'VNH1': aa:00:00:00:00:01, 'VNH2': aa:00:00:00:00:02, 'VNH': 'aa:00:00:00:00:00'}
Completed VNH Assignment
pydev debugger: process 5595 is connecting

POX 0.2.0 (carp) / Copyright 2011-2013 James McCauley, et al.
POX 0.2.0 (carp) / Copyright 2011-2013 James McCauley, et al.
Connected to pyretic frontend.
DEBUG:core:POX 0.2.0 (carp) going up...
DEBUG:core:Running on CPython (2.7.8/Oct 20 2014 15:05:19)
DEBUG:core:Platform is Linux-3.16.0-24-generic-x86_64-with-Ubuntu-14.10-utopic
INFO:core:POX 0.2.0 (carp) is up.
DEBUG:openflow.of_01:Listening on 0.0.0.0:6633
INFO:openflow.of_01:[None 1] closed
INFO:openflow.of_01:[00-00-00-00-00-01 2] connected

Process finished with exit code 137

This is the code that starts the controller:

def main():
    global of_client
    (op, options, args, kwargs_to_pass) = parseArgs()
    if options.mode == 'i':
        options.mode = 'interpreted'
    elif options.mode == 'r0':
        options.mode = 'reactive0'
    elif options.mode == 'p0':
        options.mode = 'proactive0'
    elif options.mode == 'p1':
        options.mode = 'proactive1'
    try:
        module_name = args[0]
    except IndexError:
        print 'Module must be specified'
        print ''
        op.print_usage()
        sys.exit(1)
    try:
        module = import_module(module_name)
    except ImportError, e:
        print 'Must be a valid python module'
        print 'e.g, full module name,'
        print '     no .py suffix,'
        print '     located on the system PYTHONPATH'
        print ''
        print 'Exception message for ImportError was:'
        print e
        sys.exit(1)

    main = module.main
    kwargs = { k : v for [k,v] in [ i.lstrip('--').split('=') for i in kwargs_to_pass ]}

    sys.setrecursionlimit(1500) #INCREASE THIS IF "maximum recursion depth exceeded"

    # Set up multiprocess logging.
    verbosity_map = { 'low' : logging.WARNING,
                      'normal' : logging.INFO,
                      'high' : logging.DEBUG,
                      'please-make-it-stop' : logging.DEBUG }
    logging_queue = Queue()

    # Make a logging process.
    def log_writer(queue, log_level):
        formatter = logging.Formatter('%(levelname)s:%(name)s: %(message)s')
        handler = logging.StreamHandler()
        handler.setFormatter(formatter)
        handler.setLevel(log_level)
        logger = logging.getLogger()
        logger.addHandler(handler)
        logger.setLevel(log_level)
        while(True):
            try:
                to_log = queue.get()
            except KeyboardInterrupt, e:
                print "\nkilling log"
                import sys
                sys.exit(0)
            logger.handle(to_log)
    log_level = verbosity_map.get(options.verbosity, logging.DEBUG)
    log_process = Process(target=log_writer,args=(logging_queue, log_level,))
    log_process.daemon = True
    log_process.start()

    # Set default handler.
    logger = logging.getLogger()
    handler = util.QueueStreamHandler(logging_queue)
    logger.addHandler(handler)
    logger.setLevel(log_level)

    runtime = Runtime(Backend(),main,kwargs,options.mode,options.verbosity)
    if not options.frontend_only:
        try:
            output = subprocess.check_output('echo $PYTHONPATH',shell=True).strip()
        except:
            print 'Error: Unable to obtain PYTHONPATH'
            sys.exit(1)
        poxpath = None
        for p in output.split(':'):
             if re.match('.*pox/?$',p):
                 poxpath = os.path.abspath(p)
                 break
        if poxpath is None:
            print 'Error: pox not found in PYTHONPATH'
            sys.exit(1)
        pox_exec = os.path.join(poxpath,'pox.py')
        python=sys.executable
        # TODO(josh): pipe pox_client stdout to subprocess.PIPE or
        # other log file descriptor if necessary
        of_client = subprocess.Popen([python, 
                                      pox_exec,
                                      '--verbose',
                                      'of_client.pox_client' ],
                                     stdout=sys.stdout,
                                     stderr=subprocess.STDOUT)

    signal.signal(signal.SIGINT, signal_handler)
    signal.pause()

Maybe I should add that I am running PyCharm as root because starting the controller requires privileges.

Answer 1

Check expressions you watch! If you are evaluating some callable (function), it may affect the result of the execution during debug.

For example, you watch statement like

array.sort()

while this is not part of the code in your program. During the debug this watch will be called and your list will be sorted although you don't do any sorting in your main program. At the end you might get unexpected result and variation between execution in execution

Answer 2

My project was working in Debug and failing in Run. This happened to me several times during revisions. Attempted solutions included:

• restarting PyCharm
• updating
• updating to new PyCharm installation
• clearing cache
• starting a new project with just the python files
• etc.

One thing solved the problem for me.

1. I went to "Run" menu -> "Attach to Local Process.."
2. I chose the only option available, "pydevconsole.py" (also some process IDs followed the name).

The problem was solved; it worked in both run and debug.