Saturday, May 24, 2008

cacheboy 1.0 released

Cacheboy 1.0 has been tagged, tarballed and port'ed. Its been in production at my beta testers site for a week or so now and hasn't missed a beat.

There's a lot more work to do to Cacheboy to shape it up like I believe Squid should've been; a stable 1.0 release is the first step along this path.

I'll let this settle for a couple weeks (ie, Adrian needs to sit his mid-year exams in two weeks!) before I begin some more larger-scale code refactoring and shuffling around.

Cacheboy-1.1 changes will include MemBuf, cbdata, most of the http request/reply/header manipulation code and potentially a little of the filedescriptor, disk, event and network communication code. This stuff forms the "core" of Squid/Cacheboy. I'll then look at some basic infrastructure changes to support IPv6 clients.

Like the Cacheboy-1.0 changes, these will not be terribly difficult or intrusive (the IPv6 client-only changes will be the most intrusive by far!) but a lot of refactoring, rewriting and shuffling about of the core needs to take place before I can begin work on the necessary stuff - HTTP/1.1, SMP, modularity, performance.

Saturday, May 17, 2008

FreeBSD port update

I've updated the port to CACHEBOY_0.PRE6; it also now defaults to the replacement shiny english errors (NewEnglish) rather than the default ones (English).

Friday, May 16, 2008

Revalidating objects in Polygraph

I have a locally hacked up polygraph config based on datacomm-1. Datacomm-1 is a very simple workload which doesn't pretend to be the real world at all; it thus makes it really easy for me to implement custom bits of polygraph to test specific things.

One thing I needed to test was object revalidation. I needed objects to be revalidated in a relatively short period of time so I could trigger a storage revalidation bug in Squid-2.HEAD.

Here's the changes.

include/content.pg; added:

ObjLifeCycle olcRevalid = {
  length = const(2min);   
  variance = 50%;
  with_lmt = 100%;
  expires = [
    lmt + const(2min) : 5%,
    now + const(5min) : 15%
  ];
};

content cntRevalid = {
  kind = "revalid";
  obj_life_cycle = olcRevalid;
  size = logn(32KB, 32KB);
  cachable = 80%;
  checksum = 1%;
};

I then edited my locally modified datacomm-1.pg to set the contents to cntRevalid.

Now, I get stale objects popping up during the test - and I need to figure out why -that- is happening - but note that my life cycles are very quick (couple minutes). squid _should_ be good down to object lifetime of 1 second so I'm a bit surprised.

In any case, it tripped the bug, which is all that matters..

Cacheboy PRE6 is out

I've just rolled PRE6. This includes the Squid-2.HEAD fix for the signed vs unsigned comparison bug I introduced earlier (which lead to a crash.)

This code -should- be stable enough for public consumption.

Wednesday, May 14, 2008

Error page update, phase 2


I've gone and modified all the English error pages in my little playpen project.

Here's an example of a live DNS failure. Same (confusing) text with Squid; slightly nicer layout.

Thursday, May 1, 2008

Errors shouldn't be ugly



Part of my "things i hate about Squid" list includes the god awful error pages which haven't really changed since .. well, since I got involved with the project in 2000.

Here's my take on the "simple" error page. The text is exactly the same as the old error page (note that I haven't included the "Generated by.." footer text here, as thats included by Squid/Cacheboy) but I've reformatted the error page to use CSS for layout and then crafted a very simple example CSS.

Sunday, April 27, 2008

Where is my CPU time going? (or how to divine useful information from oprofile)

OProfile is cool - it lets you dig into where your CPU is being spent. But aggregating statistics can be aggrevating. (Yes yes, it was bad, I know..)

Take this example from cacheboy:

CPU: Core 2, speed 2194.48 MHz (estimated)
Counted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit mask of 0x00 (Unhalted core cycles) count 100000
samples % image name symbol name
216049 6.5469 libc-2.7.so memcpy
115581 3.5024 libc-2.7.so _int_malloc
103345 3.1316 libc-2.7.so vfprintf
85197 2.5817 squid memPoolAlloc
64652 1.9591 libc-2.7.so memchr
60720 1.8400 libc-2.7.so strlen

...

Now, these tell you that CPU is being spent in the function (which is great) but its not the entire picture. The trouble is this: there's 527 functions in the top-level list, and 25 of them account for 1 or more percent of total runtime. Those top 25 account for ~ 45% of the total CPU time - so another 55% is being spent in the 501 functions remaining.

You may now ask yourself what the problem with that is - just optimise those top 25 functions and you'll be fine. Unfortunately, those top 25 functions aren't being called in one place - they're being called all over the shop.

Here's a example. Notice the strlen time:

496 13.7816 squid httpRequestFree
773 21.4782 squid httpHeaderPutStrf
9518 0.3432 libc-2.7.so vsnprintf
85433 55.6846 libc-2.7.so vfprintf
18212 11.8704 libc-2.7.so strchrnul
16037 10.4528 libc-2.7.so _IO_default_xsputn
13351 8.7021 libc-2.7.so _itoa_word
10872 7.0863 libc-2.7.so strlen
9518 6.2038 libc-2.7.so vsnprintf [self]

...

Note that the CPU times above "vsnprintf" are from the functions which call it, and CPU times below "vsnprintf" are the calls which it makes. Its not immediately obvious that I have to optimise "vsnprintf" calls from the top-level trace, as most of the *printf() calls end up being to "vsnprintf" (which shows up at 0.3% of CPU time) rather than "vfprintf" and friends.

Its obvious here that finding those places which call the *printf() functions in performance critical code - and then exorcising them - will probably help quite a bit.

What about the rest of the 500 odd functions? What I'd like to do is build aggregates of CPU time spent in different functions, including their called functions, and figure out which execution stacks are chewing the most CPU. Thats something to do after Cacheboy-1 is stable, and then only after my June exams.

The important thing here is that I have the data to figure out where Squid does things poorly and given enough time, I'm going to start fixing them in the next Cacheboy release.