CODEWITHSUNDEEP
pythonpython-3.xloggingmultiprocessing
Mahesha999
Mahesha999

Reputation: 24801

Why logging to the same file from different processes works while the docs says it shouldn't?

I was learning how can I log to the same file from different processes from these official examples: 1,2.

Then I tried a simple example of logging from different processes but without following the things suggested in above examples, that is by following usual way without considering multi process scenario for logging:

Code

import time
import multiprocessing as mup
import sys
import os
import logging

def worker(name):

    logging.basicConfig(
     filename='temp.log',
     level=logging.INFO, 
     filemode = 'a',
     format= '[%(asctime)s][%(levelname)s]: %(message)s')

    logger = logging.getLogger()

    a = 0

    while(a < 5):
        print(name,":",a)
        logger.info("{}: {}".format(name,a))
        a = a+1
        time.sleep(0.2)
        pass 

    print("Exiting worker: ", name, "(", os.getpid(), ")")

def start_server():
    b = 0

    while(b<3):
        new_worker = mup.Process(target=worker,args=('worker-'+str(b),))
        new_worker.daemon = True
        new_worker.start()
        b = b + 1

    time.sleep(3600)

start_server()

Console

worker-0 : 0
worker-0 : 1
worker-1 : 0
worker-0 : 2
worker-1 : 1
worker-2 : 0
worker-0 : 3
worker-1 : 2
worker-2 : 1
worker-0 : 4
worker-1 : 3
worker-2 : 2
Exiting worker:  worker-0 ( 13300 )
worker-1 : 4
worker-2 : 3
Exiting worker:  worker-1 ( 13228 )
worker-2 : 4
Exiting worker:  worker-2 ( 11000 )

temp.log

[2018-09-12 17:28:21,442][INFO]: worker-0: 0
[2018-09-12 17:28:21,643][INFO]: worker-0: 1
[2018-09-12 17:28:21,655][INFO]: worker-1: 0
[2018-09-12 17:28:21,843][INFO]: worker-0: 2
[2018-09-12 17:28:21,855][INFO]: worker-1: 1
[2018-09-12 17:28:21,871][INFO]: worker-2: 0
[2018-09-12 17:28:22,044][INFO]: worker-0: 3
[2018-09-12 17:28:22,056][INFO]: worker-1: 2
[2018-09-12 17:28:22,071][INFO]: worker-2: 1
[2018-09-12 17:28:22,244][INFO]: worker-0: 4
[2018-09-12 17:28:22,256][INFO]: worker-1: 3
[2018-09-12 17:28:22,272][INFO]: worker-2: 2
[2018-09-12 17:28:22,456][INFO]: worker-1: 4
[2018-09-12 17:28:22,472][INFO]: worker-2: 3
[2018-09-12 17:28:22,672][INFO]: worker-2: 4

Surprisingly it was working. I thought I should face some file access conflicts while logging to the same file from different processes. But that didnt happenned. The multiprocessing package says following:

Although logging is thread-safe, and logging to a single file from multiple threads in a single process is supported, logging to a single file from multiple processes is not supported, because there is no standard way to serialize access to a single file across multiple processes in Python.

So is it working because doing 

 new_worker.daemon = True

does not really create a new process, but just a new thread?

I am on Windows 7 64 bit running Python 3.6.4 on cygwin

Upvotes: 1

Views: 73

Answers (1)

Tyler Gannon
Tyler Gannon

Reputation: 1012

Not supported doesn't mean that the expected behavior is to fail with errors. It just means they don't promise performance and behavior under those circumstances.

Not supported likely also means that due to the technical complications named, it's not desirable to try and work out the ramifications of logging from multiple processes in all types of contexts.

Which basically means YMMV, and don't email the Python team when you start getting IO errors or garbled logs, if you choose to continue logging in this way. It looks like it's working fine for you, but if you're going to scale your application up or move it to a different OS which might handle file IO in a different way, then just be warned ... this behavior is not supported.

Upvotes: 3

Related Questions