I developed a logger module in Ignition 7.8.1 application which has been run in my client’s server for few months without problem. The following is the Jython script (Ignition uses Jython 2.5) I call every time I want to log an event from my Ignition application.
[code]def NewEventLog(eventLevel, logMsg):
rd = system.tag.read
wr = system.tag.write
tagProvider = "default"
logTagPath = "[" + tagProvider + "]" + "Debug/EvLog"
timeFormat = "%Y%m%d"
dt = datetime.datetime.now()
folderPath = rd(logTagPath + "/FolderPath").value
fullFolderPath = folderPath + "\\" + dt.strftime(timeFormat)
if not os.path.exists(fullFolderPath): #this is where it creates new folder
wr(logTagPath + "/FileNo", 0) #reset fileNo and fileRow in the tag whenever new folder is created
wr(logTagPath + "/FileRow", 0)
os.makedirs(fullFolderPath)
fileRow = rd(logTagPath + "/FileRow").value
maxRecord = rd(logTagPath + "/MaxRecord").value
fileNo = rd(logTagPath + "/FileNo").value
if fileRow >= maxRecord: #exceeds the allowed limit
fileRow = 0 #reset the fileRow
fileNo += 1 #increase fileNo
wr(logTagPath + "/FileNo", fileNo) #update fileNo in the tag
fileName = rd(logTagPath + "/FileName").value
#fullFileName = fileName + "_" + '{0:04d}'.format(fileNo) #only in Python 2.6 or above
fullFileName = fullFolderPath + "\\" + fileName + "_" + ('%04d' % fileNo) + ".txt"
f = open(fullFileName, "a")
logLine = dt.strftime("%H:%M:%S ") + str(eventLevel) + " " + logMsg + "\n"
f.write(logLine)
f.close()
fileRow += 1
wr(logTagPath + "/FileRow", fileRow)
[/code]
Basically the above function is to write a new line in a file whenever it is called. And there are two checks there (1) folder check, and (2) file row check:
[code] #(1) if the folder does not exist, create new one
if not os.path.exists(fullFolderPath): #this is where it creates new folder
wr(logTagPath + “/FileNo”, 0) #reset fileNo and fileRow in the tag whenever new folder is created
wr(logTagPath + “/FileRow”, 0)
os.makedirs(fullFolderPath)
#(2) if a file has less reach the maxRecord per file limit, creates new file
if fileRow >= maxRecord: #exceeds the allowed limit
fileRow = 0 #reset the fileRow
fileNo += 1 #increase fileNo
wr(logTagPath + "/FileNo", fileNo) #update fileNo in the tag
[/code]
Which create a new folder / file whenever necessary.
The following is the resulting log files when there is no problem:
[attachment=2]iglog1.png[/attachment]
But recently, I notice that there is a problem in the log files generated:
A. There are some log files generated with only one record:
[attachment=1]iglog2.png[/attachment]
B. There are log files which have more than maxRecord rows
[attachment=0]iglog3.png[/attachment]
I noticed the time where the log files which have more rows are last updated and they show that they are updated after the log file with the highest running number in the same folder.
These phenomena lead me to believe that it is caused by the racing condition in the (1) folder check (resulting in B) and (2) file check (resulting in A).
And so, I tried to test the hypotheses by coding this in PyCharm 5.0.4:
[code]import os
import threading
exitFlag = 0
class myThread (threading.Thread):
def init(self, threadID, name, counter):
threading.Thread.init(self)
self.threadID = threadID
self.name = name
self.counter = counter
def run(self):
try:
for i in range(1000000):
if not os.path.exists(“testfolder”):
print(“here!”) #expecting to come here when race condition occurs
except Exception as exc: #expecting an exception here
print(exc)
print ("Exiting " + self.name)
Create new threads
thread1 = myThread(1, “Thread-1”, 1)
thread2 = myThread(2, “Thread-2”, 2)
thread3 = myThread(3, “Thread-3”, 3)
thread4 = myThread(4, “Thread-4”, 4)
thread5 = myThread(5, “Thread-5”, 5)
thread6 = myThread(6, “Thread-6”, 6)
thread7 = myThread(7, “Thread-7”, 7)
thread8 = myThread(8, “Thread-8”, 8)
Start new Threads
thread1.start()
thread2.start()
print (“Exiting Main Thread”)
[/code]
As you can see, I expect the racing condition to occur and I should see either “here!” or Exception is printed. But…
I never got any of them.
So, my questions are:
- Is it true that I got race condition in my Jython script?
- If it is true, why can’t I reproduce it in the Python code in my PyCharm?
- How to fix this?
(note: for no 3, any idea is welcomed. Not necessarily to lock the resource since in Ignition, the Jython script is read after wrapping by its application (written in Java) and thus each piece of Jython script may not really have a “global” knowledge of the resources used)
(I asked the same question in SO)