I use the TJvLogFile component to log information and errors for the current run session of my program. The component is created in the initialization section of my logging unit and set the filename, then set Active and AutoSave true.
Most of the time (always for me) it works perfectly, but a few users have submitted error reports which say that there’s been a CreateError. This occurs anywhere from 200ms to 20 minutes after program startup.
Cannot create file "xxxx.log".
The process cannot access the file because it is being used by another process.
Leading up to that error is:
LogNewSession (my function which calls TJvLogFile.Add)
So it looks like TJvLogFile is calling TFileStream.Create twice, hence the error ?
The two Add calls together at the start of that sequence seems wrong too.
I have not used TJvLogFile but is the TJvLogFile instance global to the program? That is is there only one instance of the class?
What is the actual name of the log file being created?
Could there be two instances of your application running at the same time?
There’s only one instance of the log component in my application.
The log file name is basically the time stamp of when the application was started, so multiple instances would create different files.
Is it possible to create two instances of the component in the same invocation of the application, each using the same file name?
Only if multiple instances were started within the same second.
That wouldn’t explain the times it happens many minutes apart.
It could be done in the one app as follows:
Save the App start datetime (or even the fileName)
some time has elapsed
Create an instance using the saved filename or date
some more time has elapsed
Create the second instance of the component (object) using the same saved filename.
You may even be using the same TJvLogFile variable, which would mean that the first instance may not be freed
Does a reboot fix the problem?
The issue happens very rarely. There are a lot of users and only the odd report. I don’t know if those users are seeing the error more than once per Windows session.
Here’s how the log file starts up:
SessionLogFileName := LogFilePath + FormatDateTime('yyyymmdd-hhmmss',Now) +'.log';
SessionLogFile := TJvLogFile.Create(Application.MainForm);
SessionLogFile.DefaultSeverity := lesInformation;
SessionLogFile.FileName := SessionLogFileName;
SessionLogFile.Active := True;
SessionLogFile.AutoSave := True;
This is done in the initialization section of my logging unit.
No, that’s just because TFileStream.Create/2 calls TFileStream.Create/3 internally.
To start with TJvLogFile whilst convenient for very simple purposes is not a great for any significant file logging (with AutoSave on) due to the following reasons:
- Performs a full rewrite of the logfile each time it logs a line.
- Keeps all the log entries in memory
- Needs to iterate through all the entries and get the string output of each log line each time you add line.
- Has some AnsiString stuff on writing the log, so you lose data if you’re working in a UNICODE environment.
That said assuming all the other points that people have raised above are true:
- Single instance of component
- Single instance of application
- Single instance of form created
Then I would check for things like an antivirus that’s scanning the file, because it’s doing a full rewrite of the file and closing the file handle each time a log entry is written it’s the perfect scenario for an AV to scan the file after the log file is written and before it opens. Adding a new log line too soon after the previous line is written and you may end up interacting with a badly with the AV. Typically I use ProcessMonitor (MS SysInternals) to track down these errors, add a filter for the expected log file path, drop filtered events and see what processes are touching the file. If you’ve got the monitoring running when it fails to write the file, you should be able to see what other process was busy with the file at the same time.
Tracking it down is made harder due to me never seeing the issue first hand, only via the occasional MadExcept report emailed to me.
Maybe it’s time to move to a better logging method / component. Anything cheap / free out there?
TMS have a logging pack, but at AUD $175 or so it’s more than I really want to spend on a freeware project.
At work (XE10.1 Berlin), we use Log4D which can be extended if what is there doesn’t suit your purpose.
I haven’t used it but it looks pretty extensive.
@David_Duffy are you sure your application is 100% single threaded?
Firstly, your trace log is fine because TFileStream.create passes onto a second overloaded function.
However, the code in TJvLogFile makes no sense to me. If auto save is on it saves out the entire log every single time you add an entry, and uses TFileStream.create(filename,fmCreate) every time. That doesn’t work if the file already exists as far as I know so not sure how it actually functions if you log 2 entries.
Its also not thread safe.
Turns out I’m wrong about TFileStream.create(fileName,fmCreate) - I thought it didn’t work if the file already exists but it seems it does.
However, in a multi-threaded test the code does fail with the error you are getting i.e.
JvLogFile1.FileName := ‘C:\Temp\Log.txt’;
JvLogFile1.AutoSave := true;
for i := 0 to 1000 do
for i := 0 to 1000 do
In my experience, Windows has been producing such spurious file errors since Windows 7 at least, hence my reluctance to use any 3rd-party solutions, which you can never know what they do, unless you are prepared to walk through every line of their code thrice. My own logging implementation caches messages and retries file operations as needed to insulate the caller from this.
@hsvandrew that’s a good point. My code does use threads for a few tasks, so I should check to see if I’m using any logging in those. I’m not convinced that the errors I’m seeing are due to that though, especially on the ones where the exception is 200ms after program startup.
What’s the solution for threaded applications? Are the other libraries discussed suitable for that?
I should point out that this is currently an XE project and some of the suggestions are XE2 and up only.
It will move to D11 at some point though.
I have a bit of code like the following, unfortunately I don’t know if the queue method is available in xe.
(Spring4d also has some logging functionality, it seems to support xe)
procedure TlogMulti.LLog(Level: TLogLevel; s: string);
// Send the message to all loggers.
IF TThread.CurrentThread.threadID <> MainThreadID then
ThreadID := TThread.CurrentThread.threadID.ToString;
LLog(Level, 'T' + ThreadID + ' ' + s);
XE does support TThread.Queue so I’ll look into that.
Your LLog procedure is in a class, but mine is not. Does it need to be?
I assume that the actual logging code is after the exit in your example?