Foswiki logging to bin directory (was: WebStatistics are inaccurate)

Our statistics run daily using cron ( 45 5 * * 1-5 (cd /opt/local/wiki/Foswiki-1.1.2/bin; ./statistics >/dev/null 2>&1) ) and they seem to run fine, but here's the problem:

One user is not mentioned in the stats at all for the last two months, even though he has made numerous edits. Since we're in the wiki's upstart phase, this causes a motivation problem, not less because I can't explain it.

I know that the stats script is running via cron because it is up-to-date according to the cron trigger time.
I know that the user has in fact made edits because I have seen him do it. Also, his contributions still exist.
I know that the user is logged in because we enforce that through Foswiki access rights.
I know that the user doesn't quiet save because that button is hidden in our skin. Users don't know this feature.
I trust that the user is logged in as himself.
Stats for other users seem to be accurate, but that's a gut-feeling.
We are logging into our Foswiki with a six-character login name (e.g. wzbgdt) so I don't believe his to match any special meaning that causes his stats to be omitted.

What can cause one user's contributions to be missing from the statistics? How can I troubleshoot this?

Here are some ideas. We need to determine if the events are not being logged for some reason, or are logged, but attributed to the wrong user, or logged and flagged to not be processed.

Statistics are generated by parsing the event logs generated by Foswiki for each web event. You should be able to find that user's events in the event log. If necessary have the user make a change during a quiet time and tail the logfile to find the event. Note that the event log can be stored in multiple places depending on the Logger setting in your configuration. The parameters are stored under $Foswiki::cfg{Log} or if you migrated your configuration, there may also be some {Log....} parameters.

For example, check for working/logs/events.log. The log file format is:

    # Log file contains: $user, $action, $webTopic, $extra, $remoteAddr
    # $user - cUID of user - default current user or failing that the user agent
    # $action - what happened, e.g. view, save, rename
    # $webTopic - what it happened to
    # $extra - extra info, such as minor flag
    # $remoteAddr = e.g. 127.0.0.5

From there you can determine if the user's actions are actually being logged. The $extra field contains flags, such as "dontlog" - used internally to exclude certain actions from the statistics and notifications. "minor" set when the user uses the "Quiet Save" button. It also has the user's browser agent.

Are the user's events stored in the event log.
Are they showing up with the expected $user id.
Do they have the dontlog flag set for some reason. (They shouldn't.)
Are they minor events. (They should still be counted in statistics)

I'm not sure what else to check yet. Please report back with what you discover.

-- GeorgeClark - 03 Jan 2011

At first I couldn't find the event log; it's not in working/logs as would be expected. I checked /bin/configure and confirmed that {Log}{Dir} is set to $Foswiki::cfg{WorkingDir}/logs so it should be there, but there's only a configure.log. In fact, looking into my backups, the working directory didn't even have a logs directory until I upgraded to 1.1.2 on 18.Nov.2010.

I found the logs in the bin directory, but only going back until 18.Nov.2010 which coincides with the date I upgraded to Foswiki 1.1.2. I am certain that Foswiki put the log files there automatically; there is no manual or automated file-moving going on. This location puzzles me; does this indicate that my Foswiki is broken to some extent?

Before this upgrade, the log files were placed in the data directory. Looking in those older log files, I do see that the user has made numerous save actions in November, just as he claims -- but this is missing from the statistics.

Now that I've found the old and the new logs, two questions remain:

How can I re-create the statistics for those previous months to be accurate? I know I would manually merge the logs so that I have them all in one location as an unbroken chain of log files, but how can I trigger stats for months that have already passed?
How can I fix the odd location of the log files? They should be written either in working/logs (as per configure) or in data (which makes more sense to me).

-- TorbenGB - 04 Jan 2011

Answer, part 1: How to re-create the statistics
Googling for it gave me this result on TWiki.org: I can enter a custom URL in the browser to trigger new statistics for past months: /bin/statistics?logdate=201101;webs=ProjectX,ProjectY,ProjectZ Just add the hostname of the local wiki installation and specify the desired month & webs.

Answer, part 2: still open

-- TorbenGB - 04 Jan 2011

The broken log file location is reported in Tasks.Item10192 - but no information on why. Are you running on Windows with Strawberry perl? Thats what Sven reported in the bug report.

Was your LocalSite.cfg created new or upgraded from 1.0.x? There might be some issues with stale settings left after an upgrade.
Which logger are you using? PlainFile or Compatibility?
Could you paste all of your Log related settings from your LocalSite.cfg?

$Foswiki::cfg{Log}{Dir} 
$Foswiki::cfg{Log}{Implementation} 
$Foswiki::cfg{Log}{Action}

and any obsolete settings that might be left from 1.0.x

$Foswiki::cfg{Log}{search} 
$Foswiki::cfg{Log}{rdiff}
$Foswiki::cfg{Log}{edit} 
$Foswiki::cfg{Log}{save}
$Foswiki::cfg{Log}{attach} 
$Foswiki::cfg{Log}{register} 
$Foswiki::cfg{Log}{Implementation} 
$Foswiki::cfg{Log}{view} 
$Foswiki::cfg{Log}{changes} 
$Foswiki::cfg{Log}{upload} 
$Foswiki::cfg{Log}{rename} 
$Foswiki::cfg{DebugFileName} 
$Foswiki::cfg{WarningFileName} 
$Foswiki::cfg{LogFileName}

-- GeorgeClark - 04 Jan 2011

Our wiki is running on Red hat 3.4 and Apache 2. This is a clean new 1.1.2 install into which I imported the web directory, so all config files should be okay. I'll post the configs tomorrow from work. -- TorbenGB - 04 Jan 2011

Does configure report any errors or warnings? Are there any errors in the various Foswiki logs? Apache error log? Does the working/logs directory exist, and is is writable by your Apache user? Do you have any mandatory access controls like SElinux enabled?

-- GeorgeClark - 04 Jan 2011

Yes configure does in fact report errors and warnings:

Perl Modules: CGI:
- Error: 3.05 installed. Version 3.15 required for base Foswiki
- I don't have the option of upgrading this because the wiki is not the primary purpose of the server. Everything seems to work anyway though!
General path settings: under {ScriptDir} I see these warnings (there are further sets for each monthly log file):
- Warning: log201012.txt appears to have a suffix (.txt), no script suffix is configured - please check it.
- Warning: log201012.txt might not be an executable script - please check it (and its permissions) manually.
- I was wondering about these warnings but didn't grasp what was actually happening until halfway through this support question. This is something that needs to be addressed!
{Sessions}{ExpireAfter} is deliberately set to -1 for performance reasons:
- Warning: Foswiki will not clean up sessions automatically. Make sure you have a cron job running.
- Yes, we have a cron job that handles this. No worries here.
{MailProgram} has the value /usr/sbin/sendmail -t -oi -oeq and shows this:
- Warning: Net::SMTP is installed in this environment, but {SMTP}{MAILHOST} is not defined, therefore the program listed at {MailProgram} will be used.
- We aren't getting mails from our wiki yet, but that's a topic for another day. Please ignore for now.

working/logs exists with 0775 and has the same owner&group as the Apache user (not root).

I'm having trouble understanding the Apache error_log, but it does have some errors like this one.

This appears to be an issue triggered by WorkflowPlugin, and still exists in the current Foswiki release (1.1.4+). I've been able to recreate it by browsing to an unsupported web/topic name. (An existing web with a template subweb for ex. Sandbox/_default/WebHome)

data/debug.txt contains this line for every time the stats were updated, but no other errors:

| 2011-01-04T16:09:47Z debug | WebStatistics: Bad logfile line logout&vbar;&vbar;AUTHENTICATION LOGOUT - wzbgdt -  MSIE 7&vbar;10.0.120.154 |

This has been addressed in Tasks.Item11545 and will be fixed in 1.1.5

data/log201012.txt contains no errors.

The only access control that exists is Foswiki's internal ALLOWEDITTOPIC setting, so that users must log in to edit.

-- TorbenGB - 05 Jan 2011

See some additional comments, in-line above. As far as the logs being written to the bin directory, I've been unable to triger that particular failure. I'd really like to get it resolved for 1.1.5. Only a couple of installations have reported the error, and no combination of config tweaks that I've come up with have managed to recreate the issue.

Changing this to Answered. I'll also open a task against WorkflowPlugin for the issue you've reported above.

-- GeorgeClark - 21 Feb 2012