Foswiki 1.1.5 released – rpms, debs and usbstick ready

Foswiki 1.1.5 released – rpms, debs and usbstick ready

George has been leading the charge to a major bug fixing release of foswiki – we’ve resolved over 120 issues, and worked hard to improve security – dealing with some interesting cross site scripting issues found by ‘SonyStyles’, and then pushing on to harden the registration process to deal with spammers.

foswiki’s password system can now migrate your user’s password store to more modern encryption methods – the default that we shipped with Twiki can thus move from crypt to md5-apache.

4 days after the release, the installation and maintenance options for 1.1.5 have improved too:

  1. my yum package repository (extensions too)
  2. my debian package repository (extensions too)
  3. my Foswiki on a USB stick for Windows
  4. Oliver’s VirtualMachine

More Apache conf magic, this time for foswiki

More Apache conf magic, this time for foswiki

Last month, I’ve needed to diagnose 2 issues with a foswiki installation.

The first is the constant issue of pinpointing performance problems, the second with session persistence not persisting.

Both of these needed some form of logging to track when and to whom they were happening, so I figured the easiest thing to do was to use Apache to log what I needed.

Performance monitoring

Apache can log ‘The time taken to serve the request, in microseconds.’, and it can log HTTP response header values. So I added a little code to the foswiki installation to output a HiRes timer of how long it took to render the request, and set up my log as:

#add a 'performance' log
LogFormat  "%h %l %{SCRIPT_URI}e%q %u %t %>s %Ts (%DuS) foswiki: %{X-Foswiki-Monitor-Rendertime}o " performance
CustomLog logs/performance_log performance

Using this log, we can compare configuration changes and loads vs both perl execution times and (it seems) some measure of communication times.

Session Cookie logging

In this foswiki’s case, there was a mix of http/https, ipv4/ipv6, Client SSL Certificates and hotfixed RewriteRules that I was suspicious of. So given that it worked for my connections more often than not, I wondered if there were conflicts of session cookies between ssl and non-ssl, or something more insidious.

So I started logging session cookies (guid’s)

#add a 'session cookies and strikeone' log
LogFormat  "%h %{HTTP_HOST}e %>s \"%r\" %{pid}P \"%{SSL_CLIENT_S_DN_CN}e\" %{FOSWIKISID}C %{SFOSWIKISID}C %{FOSWIKISTRIKEONE}C " session
CustomLog logs/session_log session

In both cases, these log files let me pinpoint what the problem was not – and then have that inspiration that fixed the worst of it.

 

X-Foswiki-Monitor-renderTime patch

I’ll either add this to foswiki 1.2.0, or make a plugin for it, but if you want to see how long things take to render, apply this patch:

NOTE: you will need to install the Time::HiRes CPAN library

diff --git a/core/lib/Foswiki.pm b/core/lib/Foswiki.pm
index 4771f71..d26bd80 100644
--- a/core/lib/Foswiki.pm
+++ b/core/lib/Foswiki.pm
@@ -838,6 +838,9 @@ BOGUS
         }
     }

+    $this->{response}->pushHeader( 'X-Foswiki-Monitor-renderTime',
+        $this->{request}->getTime() );
+        
     $this->generateHTTPHeaders( $pageType, $contentType, $text, $cachedPage );

     # SMELL: null operation. the http headers are written out
diff --git a/core/lib/Foswiki/Request.pm b/core/lib/Foswiki/Request.pm
index 2ce2e15..a06af69 100644
--- a/core/lib/Foswiki/Request.pm
+++ b/core/lib/Foswiki/Request.pm
@@ -36,6 +36,14 @@ use Assert;
 use Error    ();
 use IO::File ();
 use CGI::Util qw(rearrange);
+use Time::HiRes ();
+
+sub getTime {
+    my $this = shift;
+    my $endTime = [Time::HiRes::gettimeofday];
+    my $timeDiff = Time::HiRes::tv_interval( $this->{start_time}, $endTime );
+    return $timeDiff;
+}

 =begin TML

@@ -69,6 +77,7 @@ sub new {
         remote_user    => undef,
         secure         => 0,
         server_port    => undef,
+        start_time     => [Time::HiRes::gettimeofday],
         uploads        => {},
         uri            => '',
     };

 

 

 

Time::HiRes

Zero overhead Client-Side error logging with Apache

Thanks to a tweet by a Brisbane local (Bruce) I was continuing to mull the disconnect I have from external web traffic tracking tools. I prefer to reduce the number of requests needed to serve my users – and zero requests are always fastest.

I’ve been messing with Apache CustomLog formats to debug session and performance issues in foswiki, and so given a hammer, wondered why not apply it to more things.

Then comes Bruce’s link to Client-Side Error Logging With Google Analytics, a continuation of You Really Should Log Client-Side Errors – and I wondered…

What if I put the client error into the next user request made to the server?

the javascript:

function logError(details) {
    $.cookie('clientError', details);
}
window.onerror = function(message, file, line) {
  logError(file + ':' + line + '\n\n' + message);
};
$(document).ajaxError(function(e, xhr, settings) {
  logError(settings.url + ':' + xhr.status + '\n\n' + xhr.responseText);
});
$.cookie('clientError', null);

the apache CustomLog settings:

#add a Client Error log
 LogFormat  "%h %l \"%r\" %u %t %>s %{clientError}C" clientError
 CustomLog ${APACHE_LOG_DIR}/clientError_local_log clientError

and the result:

192.168.1.51 - "GET /~sven/core/pub/System/JQueryPlugin/plugins/foswiki/jquery.foswiki.js?version=2.01 HTTP/1.1" - [07/Apr/2012:16:18:26 +1000] 304 -
 192.168.1.51 - "GET /~sven/core/pub/System/TwistyPlugin/jquery.twisty.js?version=1.6.0 HTTP/1.1" - [07/Apr/2012:16:18:26 +1000] 304 -
 192.168.1.51 - "GET /~sven/core/bin/view/Sandbox/TestClientSideLogging HTTP/1.1" - [07/Apr/2012:16:18:31 +1000] 200 http%3A%2F%2F192.168.1.51%2F~sven%2Fcore%2Fbin%2Fview%2FSandbox%2FTestClientSideLogging%3A1%0A%0Acall_me%20is%20not%20defined
 192.168.1.51 - "GET /~sven/core/pub/System/TwistyPlugin/twisty.css?version=1.6.0 HTTP/1.1" - [07/Apr/2012:16:18:32 +1000] 304 -
 192.168.1.51 - "GET /~sven/core/pub/System/JQueryPlugin/plugins/livequery/jquery.livequery.js?version=1.1.1 HTTP/1.1" - [07/Apr/2012:16:18:32 +1000] 304 -

This way we get super fast, no extra traffic client error tracking.

 

(If someone has the apache-foo to get the right SetEnvIF or RewriteCond to only log when an error is defined, please help – I tried, but failed.)

down the https rabbit hole: foswiki irc support is awesome.

I’ve spent time trying to work out why a client foswiki setup was slow last month.

http requests to the view script were taking in the order of 1second to respond (not good, but bearable given the virtual machine setup) ~ whereas https requests were taking around 5 times as long.

The connect times for https where an eye opener – sometimes it took up to 500mS.

After poking all sorts of options, spending time profiling foswiki, and generally assuming we had something wrong, I got to discussing the issue with Paul on the #foswiki irc channel, and he asked some interesting questions – the most notable

Are the host names in the /etc/hosts file?

and the answer – nope (that’ll teach me for not reviewing the basic server setup 🙂 ).

So I added them, and suddenly, the performance of the https connections became alot more inline with the http times.

So if you have a problem that is vaguely related to your foswiki / twiki – come brainstorm with us on irc, in the foswiki support web, or on the mailing list – you just never know when someone will ask the right odd question 🙂