Log File Rotation. - Githubissues

GoogleCodeExporter commented 9 years ago

What steps will reproduce the problem?
1. Run a program that uses OpenZwave with logging turned on
2. View log file
3. Logrotate the log file with copy truncate
4. Watch log file return to original size
5. View log file and notice null values at the head of the file
6. Log file grows endlessly until it fills up the partition

This issue is explained here:
http://serverfault.com/questions/221337/logrotate-successful-original-file-goes-
back-to-original-size

What is the expected output? What do you see instead?
The log file should start in size at zero and grow from there. Also, there 
should not be null values at the head of the file.

What version of the product are you using? On what operating system?
Domoticz v2.2248 using OpenZwave Version 1.3.1008 on Linux raspberrypi 3.12.36+ 

The fix is to not keep the offset when writing to the log file, but to append 
to the file when writing.

Original issue reported on code.google.com by martywes...@gmail.com on 24 Feb 2015 at 6:28

GoogleCodeExporter commented 9 years ago

I've dug into this a bit more and this issue appears to be caused by holding 
the log file open in the Unix version of LogImpl.cpp. The file is truncated 
underneath the process, but the process still keeps the writing pointer where 
it was so on the next write, it creates a sparse file up to the offset of the 
write.

I have found some information to suggest that calling fflush() will push all 
writes to the files and update the file position pointer, but I have not been 
able to test this myself.

In the meantime, the workaround is to have a post log rotate script that 
restarts the process, which is not ideal.

Original comment by martywes...@gmail.com on 24 Feb 2015 at 8:46

GoogleCodeExporter commented 9 years ago

fflush will not handle a truncated file (which is essentially what happens when 
you remove the file), hence it wont fix the solution. 

There needs to be a way for you to notify OZW to close/open the Log file, but 
its racy. Instead we should implement a function to perform log file rotation 
within OZW. Hence, adding this as a enhancement. 

In the mean time, if your concerned about space, once things are running 
smoothly, turn down the logging.

Original comment by jus...@dynam.ac on 2 Mar 2015 at 2:37

Changed title: _Log File Rotation. _
Changed state: Accepted
Added labels: Type-Enhancement, Milestone-1.6
Removed labels: Type-Defect

michapr commented 8 years ago

I think a daily log rotation by default would help everyone. Restarting OZW is really not a solution, for larger networks it maybe a problem, for battery devices the last status will be lost etc. I like to wotk with the OZW log for debugging issues, but do not want to restart every week my service...

Hope it will be implemented very soon ;)

apexo commented 8 years ago

The usual way to do this is to let logrotate rename the log file (no copying, no truncation) and then trigger the daemon (e.g. via a SIGHUP) to re-open its log files.

michapr commented 8 years ago

and then trigger the daemon (e.g. via a SIGHUP) to re-open its log files.

Yes,... but how to trigger without restarting all the OpenZwave process? There is missing any "graceful" (or like this)

bibi21000 commented 8 years ago

I think a daily log rotation by default would help everyone. No, I don't log in debug mode, so a weekly rotation is nice for me :) why not using the copytruncate option of logrotate ? http://linux.die.net/man/8/logrotate

2016-04-18 17:33 GMT+02:00 Michael P. notifications@github.com:

and then trigger the daemon (e.g. via a SIGHUP) to re-open its log files.

Yes,... but how to trigger without restarting all the OpenZwave process? There is missing any "graceful" (or like this)

— You are receiving this because you are subscribed to this thread. Reply to this email directly or view it on GitHub https://github.com/OpenZWave/open-zwave/issues/465#issuecomment-211433719

Fishwaldo commented 8 years ago

Signal Handlers in a Library are a bad idea.

What if the Application wants to do something different with SIGHUP?

When I do this, it will be a function call. Upto the application to decide when to call the function.

CopyTruncate option of LogRotate probably wont work (anymore) as one of the enhancements we made recently was to keep the LogFile Open while OZW is running... (we use to Open/Write/Close on every log message, but thats pretty inefficient)

michapr commented 8 years ago

Yes, right. I think a function call will be the best. Application can control the interval for rotating the log.

Thanks!

bibi21000 commented 8 years ago

From logrotate doc :

It can be used when some program cannot be told to close its logfile and thus might continue writing (appending) to the previous log file forever. Note that there is a very small time slice between copying the file and truncating it, so some logging data might be lost.

2016-04-19 15:05 GMT+02:00 Michael P. notifications@github.com:

Yes, right. I think a function call will be the best. Application can control the interval for rotating the log.

Thanks!

— You are receiving this because you commented. Reply to this email directly or view it on GitHub https://github.com/OpenZWave/open-zwave/issues/465#issuecomment-211916806

michapr commented 8 years ago

@bibi21000 : this will not work, file size will be after rotation the same as before - but empty file content. New log will be attached to the end of this file. I think it's because of the file handler.

That's why a OZW function is needed ;)

bibi21000 commented 8 years ago

So ... please add an helper in manager for wrappers : we should be abble to rotate filelog if logrotate can't. Thanks in advance

2016-04-19 15:51 GMT+02:00 Michael P. notifications@github.com:

@bibi21000 https://github.com/bibi21000 : this will not work, file size will be after rotation the same as before - but empty file content. New log will be attached to the end of this file. I think it's because of the file handler.

That's why a OZW function is needed ;)

— You are receiving this because you were mentioned. Reply to this email directly or view it on GitHub https://github.com/OpenZWave/open-zwave/issues/465#issuecomment-211930609

michapr commented 6 years ago

Hi, is here any progress in implementation? I already had sometimes hanging OZW because of very large log files (users did not know about this problem)

Thanks!

michapr commented 6 years ago

@Fishwaldo : can you please tell us - can it be implemented? Is it a hard job?

Thanks!

kylejohnson commented 6 years ago

Any news on this?

electrofloat commented 4 years ago

Signal Handlers in a Library are a bad idea.

What if the Application wants to do something different with SIGHUP?

When I do this, it will be a function call. Upto the application to decide when to call the function.

CopyTruncate option of LogRotate probably wont work (anymore) as one of the enhancements we made recently was to keep the LogFile Open while OZW is running... (we use to Open/Write/Close on every log message, but thats pretty inefficient)

@Fishwaldo Can you work with this? https://github.com/OpenZWave/open-zwave/pull/1946

electrofloat commented 4 years ago

As a workaround - haven't fully tested it yet - adding <Option name="AppendLogFile" value="true" /> to options.txt and using copytruncate option of logrotate should work. (I only tested this with manually truncating the OZW_Log.txt file and with AppendLogFile=true it did not add the garbage null bytes after truncate, so it should work with copytruncate too).

electrofloat commented 4 years ago

Update: Logrotate confirmed working (on linux) with the above mentioned settings.

petergebruers commented 4 years ago

@electrofloat thank you for reporting back. I never got round to testing "copytruncate" so you're feedback is much appreciated!

Somewhat related to this Log Rotation... On my "wish list for a next-gen OpenZWave 🙂 " I would like to have these changes:

A log of all the options set. Now (with default settings) the "Option" class logs but that gets overwritten when the Manager starts.
A separate log file of all add, remove and refresh node operations. These operations do things you'll never see in operation, ie they "interview" the device and make decisions once then write config and setup the device. The log lines pertaining to this are almost certainly lost (because people notice an issue and restart -> log cleared by default) so we often have to ask to trigger the interview (eg remove ozwcache* file) which is somewhat annoying. And Log Rotation should leave those logs alone...

It is one of those things that are "easier said than done".

OpenZWave / open-zwave

Log File Rotation. #465