Python logging hangs when calling a python script from another python script
<p>I have observed this weird problem in python logging class, I have two scripts, one is called from other one. First script waits for other script to end while other script logs a huge log using <code>logging.info</code></p>

<p>Here is the code snippet </p>

<pre><code>#!/usr/bin/env python

import subprocess
import time
import sys

chars = ["/","-","\\","|"]
i = 0
command = 'sudo python /home/tejto/test/writeIssue.py'
process = subprocess.Popen(command, stdout=subprocess.PIPE, stderr=subprocess.PIPE, shell=True)
while process.poll() is None:
    print chars[i],
    sys.stdout.flush()
    time.sleep(.3)
    print "\b\b\b",
    sys.stdout.flush()
    i = (i + 1)%4
output = process.communicate()
</code></pre>

<p>and the other script is</p>

<pre><code>#!/usr/bin/env python

import os
import logging as log_status

class upgradestatus():
    def __init__(self):
        if (os.path.exists("/tmp/updatestatus.txt")):
                os.remove("/tmp/updatestatus.txt")

        logFormatter = log_status.Formatter("%(asctime)s [%(levelname)-5.5s]  %(message)s")
        logger = log_status.getLogger()
        logger.setLevel(log_status.DEBUG)

        fileHandler = log_status.FileHandler('/tmp/updatestatus.txt', "a")
        fileHandler.setLevel(log_status.DEBUG)
        fileHandler.setFormatter(logFormatter)
        logger.addHandler(fileHandler)

        consoleHandler = log_status.StreamHandler()
        consoleHandler.setLevel(log_status.DEBUG)
        consoleHandler.setFormatter(logFormatter)
        logger.addHandler(consoleHandler)

    def status_change(self, status):
            log_status.info(str(status))

class upgradeThread ():
    def __init__(self, link):
        self.upgradethreadstatus = upgradestatus()
    self.upgradethreadstatus.status_change("Entered upgrade routine")
    procoutput = 'very huge logs, mine were 145091 characters'
    self.upgradethreadstatus.status_change(procoutput)
    self.upgradethreadstatus.status_change("Exiting upgrade routine")

if __name__ == '__main__':
    upgradeclass = upgradeThread(sys.argv[1:]
</code></pre>

<p>If I run first script, both scripts hangs,The problem seems to be with the code <code>while process.poll() is None</code> , If I comment this code every thing works fine. (<em>Not able to relate this with my problem!!</em>)</p>

<p>PS I tried to debug python logging classes too in which i found that the process gets stuck with <strong>emit</strong> function of <code>StreamHandler</code>class, in which it stucks at <code>stream.write</code> function call and doesn't come out after writing the huge logs, however my exit logs are not coming.</p>

<p>So what can be the problem in these scripts by which a deadlock situation is arising ?</p>

<blockquote>
  <p>Edit 1 (code with threading)</p>
</blockquote>

<h2>script.py</h2>

<pre><code>#!/usr/bin/env python 

import subprocess
import time
import sys
import threading

def launch():
    command = ['python', 'script2.py']
    process = subprocess.Popen(command,stdout=subprocess.PIPE, stderr=subprocess.PIPE, shell=True)
    output = process.communicate()

t = threading.Thread(target=launch)
t.start()

chars = ["/","-","\\","|"]
i = 0

while t.is_alive:
    print chars[i],
    sys.stdout.flush()
    time.sleep(.3)
    print "\b\b\b",
    sys.stdout.flush()
    i = (i + 1)%4
t.join()
</code></pre>

<h2>script2.py</h2>

<pre><code>#!/usr/bin/env python  
import os
import sys
import logging as log_status
import time

class upgradestatus():
    def __init__(self):
        if (os.path.exists("/tmp/updatestatus.txt")):
                        os.remove("/tmp/updatestatus.txt")

        logFormatter = log_status.Formatter("%(asctime)s [%(levelname)-5.5s]  %(message)s")
        logger = log_status.getLogger()
        logger.setLevel(log_status.DEBUG)

        fileHandler = log_status.FileHandler('/tmp/updatestatus.txt', "a")
        fileHandler.setLevel(log_status.DEBUG)
        fileHandler.setFormatter(logFormatter)
        logger.addHandler(fileHandler)

        consoleHandler = log_status.StreamHandler()
        consoleHandler.setLevel(log_status.DEBUG)
        consoleHandler.setFormatter(logFormatter)
        logger.addHandler(consoleHandler)

    def status_change(self, status):
        log_status.info(str(status))

class upgradeThread ():
    def __init__(self, link):
        self.upgradethreadstatus = upgradestatus()
        self.upgradethreadstatus.status_change("Entered upgrade routine")
        procoutput = "Please put logs of 145091 characters over here otherwise the situtation wouldn't remain same or run any command whose output is larger then 145091 characters"
    self.upgradethreadstatus.status_change(procoutput)
        time.sleep(1)
        self.upgradethreadstatus.status_change("Exiting upgrade routine")

if __name__ == '__main__':
    upgradeclass = upgradeThread(sys.argv[1:])
</code></pre>

<p>In this case t.is_alive function is not returning false (No idea, but launch function has already returned so ideally it should return false!!:()</p>