Error Flooding of data/debug.txt Bug with the WebStatistics

We recently recognized that the cronjob which runs our statistics job in the shell makes some horrible mess in our data/debug.txt logfile.

It seems that these lines and similar lines are buggy in the logfile (data/log200705.txt):

| 07 May 2007 - 16:13 | WebStatistics: Bad logfile line | 28 Sep 2006 - 16:51 | Main.DanielSteiger | view | TRCourseAIAReadMe |  | 212.249.206.43 |

With many other examples in the attachment.

The error says Bad logfile line, but makes the statistics correctly, I can see the correct statistics in the Topic %WEB%/WebStatistics

This problem seems to appear since the 400 release of TWiki, and we never brought this problem away (now 412 installed), I also talked through the IRC to get this problem away, but even the twiki.org servers seem to receive these debug messages

A little patch to the lib/TWiki/UI/Statistics.pm will help to resolve the flooding problem, but I'm not sure if this is really your intention:

• line 302 (simply uncomment)...

} else {
           # $session->writeDebug('WebStatistics: Bad logfile line '.$line);
}

I don't know if this is really necessary, the Debug Writing...

-- TWiki:Main/ArminSchenkel - 07 May 2007

The message is an indicator of something being wrong somewhere else; in this case, it's a view report that can't be parsed by the statistics script, because the viewed topic is reported just as a topic name, and not as a full web.topic name. Thus the statistics script can't determine which web the request applied to.

So, you need to fix the cause i.e. the place the view is added to the log, and not the symptom - the message. Otherwise your statistics will still be cocked up.

Inspecting the core TWiki code, we can see that the only place that view is being logged at line 158 of lib/TWiki/UI/View.pm, thus:

    if( $TWiki::cfg{Log}{view} ) {
        $session->writeLog( 'view', $webName.'.'.$topicName, $logEntry );
    }

Since this line clearly includes the Web. portion of the log line, it is impossible for it to have generated the log line you reported above. That line of code has been there since March 2005, so it has to be in the code you are running.

So the only possible conclusion, based on the log line you show above (and those in your attachment), is that you have either hacked code, or you have installed a plugin that is generating incorrect lines in the log.

I would recommend that you check all your installed plugins (and the installed TWiki code) to see what is generating that view log line.

CC

I checked the TWiki Code and the Code seems to be right just like your example (exactly the same).

What also could be is that the lib/TWiki/Plugins folder has some writeLog entries which are crappy. A little grep shows the answer:

cd lib/TWiki/Plugins; grep -ri 'writeLog' *

TagMePlugin.pm: _writeLog( "New tag '$tag'" );
TagMePlugin.pm:                        _writeLog( "Added tag vote on '$tag'" );
TagMePlugin.pm:                _writeLog( "Added tag '$addTag'" );
TagMePlugin.pm:                        _writeLog( "Removed tag vote on '$tag'" );
TagMePlugin.pm:                        _writeLog( "Removed tag '$tag'" );
TagMePlugin.pm:sub _writeLog
TagMePlugin.pm:          ? $TWiki::Plugins::SESSION->writeLog( "tagme", "$web.$topic", $theText )
TagMePlugin.pm:          : TWiki::Store::writeLog( "tagme", "$web.$topic", $theText );

This is the only output I get from the Plugins.

Other output from the lib/TWiki:
Contrib/EditContrib.pm:        $session->writeLog( 'edit', $webName.'.'.$topic, $extra );
Plugins/TagMePlugin.pm:        _writeLog( "New tag '$tag'" );
Plugins/TagMePlugin.pm:                        _writeLog( "Added tag vote on '$tag'" );
Plugins/TagMePlugin.pm:                _writeLog( "Added tag '$addTag'" );
Plugins/TagMePlugin.pm:                        _writeLog( "Removed tag vote on '$tag'" );
Plugins/TagMePlugin.pm:                        _writeLog( "Removed tag '$tag'" );
Plugins/TagMePlugin.pm:sub _writeLog
Plugins/TagMePlugin.pm:          ? $TWiki::Plugins::SESSION->writeLog( "tagme", "$web.$topic", $theText )
Plugins/TagMePlugin.pm:          : TWiki::Store::writeLog( "tagme", "$web.$topic", $theText );
Search.pm:        $session->writeLog( 'search', $t, $searchString );
Store.pm:        $this->{session}->writeLog(
Store.pm:        $this->{session}->writeLog( 'rename', $old, "moved to $new", $user );
Store.pm:        $this->{session}->writeLog( 'renameweb', $oldWeb, 'moved to '.$newWeb, $user );
Store.pm:        $this->{session}->writeLog( $action, $web.'.'.$topic, $attachment, $user );
Store.pm:            $this->{session}->writeLog( 'save', $web.'.'.$topic,
Store.pm:        $this->{session}->writeLog( $options->{operation} || 'save',
Store.pm:    $this->{session}->writeLog( 'cmd', $web.'.'.$topic, 'delRev by '.
UI/Upload.pm:        $session->writeLog( 'attach', $webName.'.'.$topic, $fileName );
UI/Edit.pm:        $session->writeLog( 'edit', $webName.'.'.$topic, $extra );
UI/Changes.pm:        $session->writeLog( 'changes', $webName, '' );
UI/Register.pm:    $session->writeLog('bulkregister', $row->{webName}.'.'.$row->{WikiName},
UI/Register.pm:    $session->writeLog(
UI/Register.pm:            $session->writeLog('changepasswd', $user->wikiName());
UI/Register.pm:    #    $this->{session}->writeLog('verifyuser', $loginName, $userName);
UI/Register.pm:        $session->writeLog(
UI/RDiff.pm:        $session->writeLog( 'rdiff', $webName.'.'.$topic, "$rev1 $rev2" );
UI/View.pm:        $session->writeLog( 'view', $webName.'.'.$topicName, $logEntry );

It seems that the $webName doesn't get resolved somewhere, I'll look at this further and post my results again.

-- TWiki:Main.ArminSchenkel - 08 May 2007

Finally I found the results: We have logfiles since log200510.txt ... Every time the bin/webstatistics runs, it collects all data from the log files (and not only the current month) and makes the new statistics overall....

We have so many Bad Logfile Entries that are getting displayed in the debug.txt, so I thought It's on time to archive the logfiles till 2007. Don't ask me why these failure log entries came through, but new bad logfile entries aren't created since october 2006.

Maybe I'll write a perl script to resolve this issue and remove all Bad Logfile Entries with regexp on our system.

Sorry for the false bug report, I'll close it immediately

-- TWiki:Main.ArminSchenkel - 08 May 2007