python2.7 using debug behave different then withou

Question

I have a bug in my program and want to check it out using debug. In my IDE (WingIDE) I have a debug functionality. But I can not use that call the program from shell. So I use the Python module pdb. My application is single threaded.

I have looked into Code is behaving differently in Release vs Debug Mode but that seems something different to me.

I limited it down this the following code.

What I did :

I created a short method it will only be called when using no IDE.

def set_pdb_trace():
    run_in_ide = not sys.stdin.isatty()
    if not run_in_ide:
        import pdb; pdb.set_trace() # use only in python interpreter    

This work fine, I used it in many situations.

I want to debug the following method :

import sys
import os    
import subprocess32           

def call_backported():
    command = 'lsb_release -r'
    timeout1 = 0.001 # make value too short, so time-out will enforced  
    try:      
        p = subprocess32.Popen(command, shell=True,
                                  stdout=subprocess32.PIPE,
                                  stderr=subprocess32.STDOUT)  
        set_pdb_trace()
        tuple1 = p.communicate(input=b'exit %errorlevel%\r\n', timeout=timeout1)     
        print('No time out')
        value = tuple1[0].decode('utf-8').strip()  
        print('Value : '+ value)
    except subprocess32.TimeoutExpired, e:                  
        print('TimeoutExpired')                            

Explanation. I want to call subprocess with a timeout. For Python 3.3+ it is build in, but my application has be able to run using Python2.7 also. So I used https://pypi.python.org/pypi/subprocess32/3.2.6 as a backport. To read the returned value I used How to retrieve useful result from subprocess?
Without timeout, setting timeout to f.e. 1 sec the method works as expected. The result value and 'No time out' is printed.

I want to enforce a timeout so I set the timeout very short time 0.001 . So now only 'TimeoutExpired' should be printed.

I want to execute this is shell. When if first comment out line #set_pdb_trace() 'TimeoutExpired' is printed, so expected behaviour.

Now I uncomment set_pdb_trace() and execute in shell.

The debugger displays, I press 'c' (continue) and 'No time out' with the result is printed. This result is different then without debug. The generate output is :

bernard@bernard-vbox2:~/clones/it-should-work/unit_test$ python test_subprocess32.py 
--Return--
> /home/bernard/clones/it-should-work/unit_test/test_subprocess32.py(22)set_pdb_trace()->None
-> import pdb; pdb.set_trace() # use only in python interpreter
(Pdb) c
No time out
Value : Release:    13.10
bernard@bernard-vbox2:~/clones/it-should-work/unit_test$ 

How is this possible? And how to solve?

Answer 1

You introduced a delay between opening the subprocess and writing to it.

When you create the Popen() object, the child process is started immediately. When you then call p.communicate() and try to write to it, the process is not quite ready yet to receive input, and that delay together with the time it takes to read the process output is longer than your 0.0.1 timeout.

When you insert the breakpoint, the process gets a chance to spin up; the lsb_release command doesn't wait for input and produces its output immediately. By the time p.communicate() is called there is no need to wait for the pipe anymore and the output is produced immediately.

If you put your breakpoint before the Popen() call, then hit c, you'll see the timeout trigger again.