Feature Proposal: Add seconds to the timestamp in debug/log/warn

Motivation

For debugging purposes, I find it useful to include seconds in the debug/log/warn logs (normally set as data/warn2026-02-11.txt, data/log2026-02-11.txt and data/warn2026-02-11.txt in the configuration)

Today, a line in the log file starts with:

 
... 
| YYYY-MM-DD - HH:MM | <user> | <action> .... 
... 

My proposal is to change is to:

 
... 
| YYYY-MM-DD - HH:MM:SS | <user> | <action> .... 
... 

In the WhatDoesItAffect list, I selected:

• Documentation, because I believe it helps the administrator of an TWiki instance to debug and investigate more efficiently.

Description and Documentation

To modify TWiki::_writeReport() to include seconds in the dateformat used typically by debug.txt, log2026-02-11.txt and warn2026-02-11.txt.

Examples

Example of a line in data/log201307.txt:

| 2013-07-01 - 14:27 | <user> | view | Main.WebHome | Mozilla | <IP> |

This feature proposes to add seconds to the timestamp:

| 2013-07-01 - 14:27:10 | <user> | view | Main.WebHome | Mozilla | <IP> |

Impact

• Log files will contain a few more bytes, as each "log line" will include the second in the timestamp.
• When you want to know the distribution of log lines for a given minutes, this will be made possible by this feature.

Implementation

This could be implemented in two ways:

In TWiki::_writeReport, the following change is done to specify a different dateFormat:

 
-   $time = TWiki::Time::formatTime( time(), undef, 'servertime' );
+   my $dateFormat = $TWiki::cfg{DefaultDateFormat} . ' - $hour:$min:$sec' 
+   $time = TWiki::Time::formatTime( time(), $dateFormat, 'servertime' );

An alternative to this is to only change the dateFormat for logs if the user gives a different setting for it:

In /lib/LocalSite.cfg:

$TWiki::cfg{LogDateFormat} = '$year-$mo-$day $hour:$min:$sec';

in TWiki::_writeReport:

-   $time = TWiki::Time::formatTime( time(), undef, 'servertime' ); 
+   $time = TWiki::Time::formatTime( time(), $TWiki::cfg{LogDateFormat}, 'servertime' );

The first option provides less clutter in my opinion, because it does not introduce another configuration flag. But if seconds it's "too much info" for the average admin, a configuration flag could be nice too.

-- Contributors: Terje Ness Andersen - 2013-07-15

Discussion

Proposal looks good. On configurable date format, I don't think we can use the existing {DefaultDateFormat} because that one is used for signatures. It would look odd to have signature dates shown up to seconds. So I think either hard code the log date to include seconds, or add a new configuration setting for log date format.

-- Peter Thoeny - 2013-07-16

How about modifying TWiki::Time::formatTime() so that the default time format has :$sec at the end? This results in every log entry getting :ss in its time stamp. This is not flexible, but we don't need flexibility here, I suppose. TWiki::UI::Statistics in the SVN trunk has a code depending on the fact that the time stamp of each log entry starts with "YYYY-MM-DD - hh:mm". That code is not affected by the change I'm proposing here. That dependency is necessary to deal with multiple log files generated by multiple servers.

-- Hideyo Imazu - 2013-07-16

Peter: It was a typo, in the last <verbatim /> section, it was meant to say $TWiki::cfg{LogDateFormat} as introducing a new configure flag instead of using the existing configure flag $TWiki::cfg{DefaultDateFormat}. Changing this would be a bad idea, I agree.

Modifying TWiki::Time::formatTime()'s default time format could be a solution yes, but I guess one then has to go over all calls to this subrputine and check that the extra seconds doesn't cause any trouble?

-- Terje Ness Andersen - 2013-07-16

For me I would go for a simple solution, however I am fine with or without configure a setting. Modifying TWiki::Time::formatTime() and checking for side-effects looks like a good approach to me.

-- Peter Thoeny - 2013-07-17

So, from reading Codev.TWikiFeatureProposals and Codev.SubversionReadme, am I correct on this timeline for implementing this:

1. Adding myself as CommittedDeveloper and setting DateOfCommitment (I read this as the date I plan to implement this?) will start the " Seven Day Feedback Period". I also set ProposedFor to JerusalemRelease.
2. If, after this period all requirements defined in SevenDayFeedbackPeriod are met, this request will get a CurrentState of AcceptedProposal with ReasonForDecision set to AcceptedBy7DayFeedbackPeriod.
3. I will then have to "Create New Report" in http://develop.twiki.org/~twiki4/cgi-bin/view/Bugs/ to get a Item for the commit to subversion that I'm about to do.
   • I wonder a bit about this, is the "Bug web" at develop.twiki.org/~twiki4/ the right place to create the Item for this change?
   • I guess it's a nice thing to fill the BugTracking field of this topic to create a logic link between this topic and the bug Item.
4. In http://svn.twiki.org/svn/twiki/trunk/core, I will make the necessary changes, and commit with my twiki.org TWikiName/Password, with a log like this: "<myItem>: Modified TWiki::Time::formatTime() in order to have seconds in log timestamps"

-- Terje Ness Andersen - 2013-07-17

Set the date of commitment at the time of creating the proposal if you are committed to implement it. You can back-date the start date of the 7 day period accordingly.

You can wait for the 7 days, it is auto-accepted if no concerns raised. With this one it looks like you are good to go after 7 days. You can also participate in the next JerusalemReleaseMeeting2013x07x18. At release meetings we discuss feature proposals. We can also accept a proposal ahead of the 7 day feedback period.

On bug item, create one for each feature proposal at TWikibug:WebHome - see Bugs pulldown menu. Use same/similar title for proposal and bug item. Link back and forth (see OpenAndClosePTags and TWikibug:Item7290 for an example).

On checkin, use the title, such as svn ci -m 'ItemXXXX: Add seconds to the timestamp in debug/log/warn'. You could also append some more details if you do several checkins.

-- Peter Thoeny - 2013-07-17

As discussed in JerusalemReleaseMeeting2013x07x18, this proposal has been approved under the condition of {LogDateHavingSecond} instead of {LogDateFormat}. If {LogDateHavingSecond} is true, the log date format is "$year-$mo-$day - $hour:$min:$sec". Otherwise "$year-$mo-$day - $hour:$min". This makes sure time stamp in log files is plainly sortable.

-- Hideyo Imazu - 2013-07-18

To clarify, log date can be either hard coded or configurable. If configurable, use the aforementioned configure setting. Read also the log at JerusalemReleaseMeeting2013x07x18.

-- Peter Thoeny - 2013-07-18

Thank you Peter and Hideyo. I read the logs of the meeting, sorry for not attending, and thank you for your input on this

Since TWiki::_writeReport only seems to be called from TWiki::writeLog, TWiki::writeWarning and TWiki::writeDebug, I guess the hard-coded way would be to make the following change in TWiki::_writeReport:

 
- $time = TWiki::Time::formatTime( time(), undef, 'servertime' ); 
+ $time = TWiki::Time::formatTime( time(), "$year-$mo-$day - $hour:$min:$sec", 'servertime' );

If it's not desired that this dateFormat is changed for everyone, we could add a check for the {LogDateHavingSecond} flag as well:

 
- $time = TWiki::Time::formatTime( time(), undef, 'servertime' ); 
+ my $dateFormat = ($TWiki::cfg{LogDateHavingSecond} ? "$year-$mo-$day - $hour:$min:$sec" : undef); 
+ $time = TWiki::Time::formatTime( time(), $dateFormat, 'servertime' );

I take it that you Hideyo have a vote on the second option, letting admins choose if they want seconds with {LogDateHavingSecond}. If no objections, I will implement this using this flag.

-- Terje Ness Andersen - 2013-07-19

Your call if to make it configurable or not. In any case I recommend to enforce a sortable date, e.g. use "$year-$mo-$day - $hour:$min" instead of undef. Looking forward seeing your checkin activities!

-- Peter Thoeny - 2013-07-19

Feature implemented with tag TWikibug:Item7307 I made it hard-coded for now.

-- Terje Ness Andersen - 2013-07-23