classification
Title: 2 scripts running from crontab simultaneously reference the same instance of a variable
Type: behavior Stage:
Components: Interpreter Core Versions: Python 3.1
process
Status: closed Resolution: not a bug
Dependencies: Superseder:
Assigned To: Nosy List: exarkun, yuri
Priority: normal Keywords:

Created on 2010-09-26 13:52 by yuri, last changed 2010-09-26 13:55 by exarkun. This issue is now closed.

Messages (2)
msg117416 - (view) Author: yuri (yuri) Date: 2010-09-26 13:52
Originally the problem was that one script used a logger instance initialized in another script, and, as a result, log entries were "signed" by the later one.

Setup: python 3.1.1, Suse Linux enterprise server 9

2 scripts are scheduled in crontab as follows:
*/1 * * * * /my_path/python/test1.py > /dev/null 2>&1
*/1 * * * * /my_path/python/test2.py > /dev/null 2>&1

Each script does:
1) gets a logger instance and adds FileHandler, 
2) prints to its log the current time and PID, 
3) prints ID of the logger instance, 
4) prints ID and value of some variable
5) sleeps for 3 sec, 
6) prints the current time again.

Result: each script prints the same IDs of the variables

test1.py
______________________________
#!/usr/local/bin/python3
import logging
from logging import FileHandler
from datetime import datetime
import time
import os
import sys
log = logging.getLogger('MyLog1')
log.setLevel(logging.INFO)
logFilePath = os.path.join(os.path.realpath(os.path.dirname(sys.argv[0])), 'log')
dh = FileHandler(os.path.join(logFilePath, 'log1'))
log.addHandler(dh)
someVariable = 9
log.info(str(datetime.now()) + ' PID=' + str(os.getpid()))
log.info('logger ID=' + str(id(log)))
log.info('someVariable ID=' + str(id(someVariable)) + 'value=' + str(someVariable))
time.sleep(3)
log.info(str(datetime.now()) + ' PID=' + str(os.getpid()))

test2.py:
_________________________________
#!/usr/local/bin/python3
import logging
from logging import FileHandler
from datetime import datetime
import time
import os
import sys
log = logging.getLogger('MyLog2')
log.setLevel(logging.INFO)
logFilePath = os.path.join(os.path.realpath(os.path.dirname(sys.argv[0])), 'log')
dh = FileHandler(os.path.join(logFilePath, 'log2'))
log.addHandler(dh)
someVariable = 10
log.info(str(datetime.now()) + ' PID=' + str(os.getpid()))
log.info('logger ID=' + str(id(log)))
log.info('someVariable ID=' + str(id(someVariable)) + 'value=' + str(someVariable))
time.sleep(3)
log.info(str(datetime.now()) + ' PID=' + str(os.getpid()))

Result:

log1:
2010-09-26 15:45:01.531460 PID=5704
logger ID=182908380624
someVariable ID=7167488value=9
2010-09-26 15:45:04.535591 PID=5704

log2:
2010-09-26 15:45:01.528691 PID=5705
logger ID=182908380624
someVariable ID=7167520value=10
2010-09-26 15:45:04.534598 PID=5705

If I change value of someVariable to 9 in the both scripts, I have:

log1:
2010-09-26 15:48:01.488008 PID=6036
logger ID=182908380624
someVariable ID=7167488value=9
2010-09-26 15:48:04.491977 PID=6036

log2:
2010-09-26 15:48:01.490214 PID=6035
logger ID=182908380624
someVariable ID=7167488value=9
2010-09-26 15:48:04.494991 PID=6035
msg117417 - (view) Author: Jean-Paul Calderone (exarkun) * (Python committer) Date: 2010-09-26 13:55
You can't rely on id() to return distinct values across different processes.  It guarantees uniqueness *within a single process* (at any particular moment).

In other words, you're misusing id() here.  This is not a Python bug.
History
Date User Action Args
2010-09-26 13:55:26exarkunsetstatus: open -> closed

nosy: + exarkun
messages: + msg117417

resolution: not a bug
2010-09-26 13:52:51yuricreate