electron-log icon indicating copy to clipboard operation
electron-log copied to clipboard

Share rolling file transport

Open xmedeko opened this issue 3 years ago • 10 comments

I would like to log just to one file in Electron, so I set in main.js:

const log = require("electron-log").create("main");
log.transports.file.fileName = "log.log";
log.transports.file.maxSize = 1024;

and preload.js

const log = require("electron-log").create("renderer");
log.transports.file.fileName = "log.log";
log.transports.file.maxSize = 1024;

The maxSize does not work, the file exceeds 1024 bytes if the logs are interleaved. And is it safe to share same file from main and renderer process? What if I have more windows - more renderer processes?

xmedeko avatar Apr 13 '21 18:04 xmedeko

  • It's fine, log file could be a bit larger if it uses across multiple process, since file size is calculated on initialization only. I've decided not to fix it because it could impact on performance.
  • Logging to the same file works fine for the most apps, it was the default behavior prior to v4. Only in a case of very intensive writing some log records could be overwritten, but most apps have no such an issue.

megahertz avatar Apr 14 '21 03:04 megahertz

  • I think the problem is not in the initialization, but in the fact, then the bytesWritten counters are independent. So, if I have N windows writing to the same file, it could grow somewhere between maxSize ... N*maxSize depending when the windows are opened and how intensively they log.
  • So, the electron-log is not safe but you assume probability of log overwriting is low and acceptable. I think this should be mentioned in the README.md.

I think proper solution for both problems is to manage files in the main process only and send logs from renderer to main by IPC.

Note: I am not much sure about fs.writeFile, but if you just append and use fs.createWriteStream or filehandle.appendFile then on some OSes the append to file should be atomic (on Linux, not on Windows, not sure about MacOS).

xmedeko avatar Apr 14 '21 06:04 xmedeko

Thank you for the suggestion, you've just described how did it work in early versions of the library :) It have had a lot of pitfalls. As for adding notes about maxSize, yes I agree with you.

megahertz avatar Apr 14 '21 13:04 megahertz

Which pitfalls has such implementation which sends all over IPC? Could a plain socket/TCP connection do better?

Note: the note was about log overwriting, but the maxSize should be added, too.

xmedeko avatar Apr 14 '21 13:04 xmedeko

It's pretty slow and may lead to app crash/hang when called intensively. I'm not going to play with sockets as an alternative transport.

megahertz avatar Apr 14 '21 15:04 megahertz

Hmm, digging through the VS Code code seems like they use net sockets by named pipe, see ipc.net, for most of IPC and the logging, too. (Even process.send transport is marked as deprecated.)

Have you experienced rare problems with calling fs functions from preload, see electron/electron#19554 - the bug is closed, but users report the problem still persist. (We have experienced similar rare problems in our CI build machine running playwright tests, but not in real use, though.)

xmedeko avatar Apr 14 '21 15:04 xmedeko

There are only a few people who uses async writing mode for file transport, so, I haven't seen that before.

megahertz avatar Apr 14 '21 16:04 megahertz

@megahertz I have done custom Electron IPC transport and logging to file with Electron 12 and seems to me IPC is not the bottleneck. I have tested 100000 logs in a for cycle resulting in approx. 5MB of log file (increased maxSize, so no rotation) from the renderer process. I've made 4 tests with console transport switched off in main and renderer, too:

  • electron-log from preload (renderer) sync - window completely stuck for one minute.
  • electron-log from preload (renderer) async - window sluggish for approx. 2 sec and then working. But the logging has asynchronously continues.
  • Send string by IPC to main and then do electron-log sync - window stuck for a second then sluggish. Very slow response to show Electron menu or to show dev tools, minimize and maximize the app until logging finishes (approx 1 minute).
  • Send string by IPC to main and then do electron-log async - window sloggish for approx 2. seconds and then second then working. But the logging has asynchronously continues.

I have also tried sync tests sync logging by setTimeout(() => doLog(...), 0):

  • electron-log from preload (renderer) sync - window working OK.
  • Send string by IPC to main and then do electron-log sync - window response faster, otherwise same as before: Very slow response to show Electron menu or to show dev tools, minimize and maximize the app until logging finishes (approx 1 minute).

So, it seems to me, that the IPC is not a problem (in Electron 12), the problem is synchronous logging (file or console).

Also, according to my experience with other logging frameworks (Java log4j, Python logging, C# NLog, ...) such async queues/buffers drop messages in the queue when they reaches some limit (e.g. 10000 logs, see NLog AsyncTargetWrapper.cs) to avoid memory or performance instabilities in case of massive logging. (Massive logging is a bug.) That's useful in case of desktop app especially, because you cannot control the users' HW and OS health.

xmedeko avatar Apr 15 '21 08:04 xmedeko

Thank you for the performance test. It seems that now IPC performed much more better compared to the previous electron version. I'm not going to change these things right now but I'll think about it for the next major release.

megahertz avatar Apr 15 '21 13:04 megahertz

And on the renderer side, ipcRenderer.send maybe used with window.requestIdleCallback() and a queue with a limit to keep renderer responsive even when under heavy log load.

xmedeko avatar Apr 15 '21 13:04 xmedeko

In v5 only the main process writes to a file. Thank you for your suggestions.

megahertz avatar Nov 24 '22 12:11 megahertz