Log File Rotation.

[GoogleCodeExporter]

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]

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]

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]

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]

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]

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]

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
#465 (comment)

[Fishwaldo]

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]

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

Thanks!

[bibi21000]

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
#465 (comment)

[michapr]

@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]

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
#465 (comment)

[michapr]

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]

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

Thanks!

[kylejohnson]

Any news on this?

[electrofloat]

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? #1946

[electrofloat]

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]

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

[petergebruers]

@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".