Writing to a log file

General
1

I need to write a lot of stuff to a log file. Every command we send to our motion control unit, and every response we get back, needs to be logged. This could be several entries per second in some cases, then nothing for a few minutes, then a barrage of entries in a short period of time.

I had thought that maybe I’d keep a running log in memory, and when it reaches a certain length, it would get written to the file on disk. But my concern is that I might lose critical information that leads up to a crash (where that log data in memory would be lost), making it hard to debug.

Writing every entry as it comes in seems terribly inefficient though, with a lot of folder items being opened and closed.

One thought was to use something like the system level ‘cat’ tool, to append a line of text to the end of the log file, though I wonder if that’s going to be just as inefficient as doing it within my app.

Is there a better way to do this?

2

Would it be possible to send information to a helper app, in a smart way, and let make the helper responsible for physical logging etc. In this way your main process should not have a big delay because of fileopenings etc.

1 Like
3

Yep, a Xojo worker. https://documentation.xojo.com/api/language/worker.html

4

I imagine it depends on your expected rate of messages. My log method opens, writes, closes a log file for each message. I also have a housekeeping thread that runs every hour and one of whose tasks is to check the length of the log file and rotate the log if the file is greater than 500kb. Seems to work for me and is fairly simple.

You may need to prototype a couple of approaches.

5

Hmmm. Xojo workers have a bit of delay due to the bi directional talk. Maybe it’s better to create a separate dumb console logger app, run, and connect to it via IPCSocket and sending blind data to be logged by it.

6

thanks. I’ll look into using a worker. I’ve built some apps before (a while back) that used multiple instances of helper console applications that mostly just deal with running command line apps. I was thinking of something similar just using cat to append some text to the end of the file. But I like the idea of doing it in a worker app since I’ve been meaning to learn more about those anyway.

Would the delays really be much of an issue? I mean, it’s more or less a one-way communication from my app to the worker.

As far as frequency: there will be instances where there could be up to 5-6 entries per second, but for the most part, there will be gaps of several seconds to minutes between entries.

7

Behind the scenes the system exchange data due to the nature of “firing events”. That’s why I suggested a more one way tailored version.

That simplifies things a lot. I was thinking in 60+ not 6. :smiley: A worker must be is enough.

8

Do both.

  1. Coalesced logging. When a log entry is added, check to see if a timer is running, if not, start it.
    When the timer fires (say after 10 seconds) it writes all the unsaved log entries to disk, in one go.

  2. Have an option in the preferences and a key combo on startup, that activates direct logging, so that every time a log entry is added, it is written to disk.
    This way, when the application is crashing for the user (and log data is not being saved), they can activate this mode and it will get written, but comes at the expense of performance and SSD writes.

2 Likes
9

What about leaving the log file open, then close and reopen every 10 seconds?

1 Like
10

With the log task in a worker, you just need to send the message to the logger worker and forget. THERE, in the worker, you must be queuing the received messages really fast and being prepared to receive another one, and you should have a lower priority thread unqueuing those messages and writing to disk.

1 Like
11

So my only concern about running a Worker for this is that it’s still part of the main application, isn’t it? What happens if the main app crashes? doesn’t the worker go down with it, potentially taking its last several lines of log entries?

I feel like a helper app is probably a little bit safer, in that it’s separate so it’s insulated from a crash of the main app, no?

12

Loosely bound. Main dies, worker continues. But… an error event will rise to say this condition. You should test it and see what error will be. Probably you would flag a “let’s flush whatever we have and quit” condition and just continue.

I would create a small PoC test.

13

Another direction to go is to use a shell (which you instantiate and keep) and then just use echo to append to the end of the log file. We’ve found this technique to be very fast on our projects.

1 Like
14

An one way comm provides the fastest “release and continue” time. I like the idea.

15

In my experience, the extra layer of a “logger app” is unnecessary and doesn’t actually make things any faster.

16

As I said, I liked your idea, as it follows a light concept of “fire and forget”, “one way” (at our level) comm.

17

But using echo, you need take care of special chars and escaping in different forms for Windows and Linux.

For Windows here it is: Batch files - Escape Characters

For Linux: A.11. echo Options and Escape Sequences - bash Cookbook [Book]

It adds one small layer of complexity before pushing the content out.

18

I use the .Flush method with BinaryStream and TextOutputStream. I open the log files when the app starts. A quick review of my code - looks like I don’t explicitly close the logs. Its been this way since 2009, no problems noted. But I guess I should add a formal close as the app exits.

19

That causes delays due to the blocking I/O operations. A “realtime” app could have bad hiccups. The idea here is to outsource this task to some other process and continue.