Dreams of Bizar (by sarah)

Ok so last nights dream... this guy called Matt I know who is a fantastic musician was setting up a performing arts space which needed loads of work, the building was shambolic and dark with wires hanging out of the ceiling. I was the manager and it really was a big rambling old building. Creatures from the nth dimension had broken through these sort of crab-dogs which I was shooting whilst trying to prevent tenticles rising from the basement in a Cthulu type manor. Mean while Alaric had gotten himself trapped on the elysian fields which were accessible through the attic windows (these are the Greek/Roman version of Heaven). He was in the van and was trying to avoid the giant that was smashing it up whilst not driving off the edge. Matt was wondering around doing DIY serenely whilst smashing mosters with a bit of two by four whilst asking me if I thought that we should put a climbing wall up in the hall way. Then one of my uni friends James (another fantastic musician) knocks on the door to ask if he can borrow the recording studio - I tell him to talk to Matt and it is all agreed but then he is followed by the backing choir, which was a 60 + strong hippy choir run by Jesus. They all wore technicolour coats made of patch work or knitted. I was starting to get a bit frazzeled at this point so had to shrink Jean and Mary and pop them in a travel coat with two magical mice for protection. Mum and Dad then turned up looking grim with a credit card given to them by James Bond for me - I used it to hire a paranormal assassin to kill the giant and retrieve Alaric and whilst doing all of this I was making drinks and food for everybody and fretting over the fact I couldn't find any disinfectant to clean the crab-dog gunk up :/ Oh also it was tipping it down and grey outside in the dream and only the fields in the attic were sunny. There was flooding occuring and refugees began to turn up expecting food but Jesus told me he was out of miracles and that it was up to me. When I told Al the dream he said, 'Ah so the fret about organising the big family meal has started - I thought you'd been rather calm.'

Logging, Profiling, Debugging, and Reporting Progress (by alaric)

I have a hypothesis. The hypothesis is that, in software, the goals of logging stuff for audit purposes, reporting progress to a user on the course of a long-winded process, profiling a system to see where it is spending its time in the long run, and debugging certain kinds of problems (in particular, hangs of multithreaded systems come to mind, although many other kinds of problems too), can all fundamentally be met by a single piece of software infrastructure. I say this because, largely, I write very similar code to do all four of them, and end up building unnervingly similar-looking ad-hoc solutions, despite the fact that a single well-developed tool could do all of them *really well*. Basically, all of them boil down to a bit of code stating what it's about to do and what it's just done at interesting points. Let's look at each in turn. Software often writes, either to a log file for unattended bits of software such as daemons, or direct to the user if there is one, lines of text describing the current state of affairs. Generally, it logs when steps in the process are started (to document what it's about to do), when steps end (to document the results), and sometimes during iterations over something or other (although that's really just a special case of the previous cases, as each iteration is itself a step). This is often done for auditing reasons - to find out what operations led up to some state of the system, for a plethora of reasons - and sometimes to offer a kind of primitive progress reporting; you can look at the log to see how far something has gotten. But we have more sophisticated progress reporting, sometimes. Rather than using a dumb logging facility to say "I'm about to process 1000 objects", then "I have processed N objects so far" periodically and letting the user read the text and do the maths to work out how far through we are, we can use a more evolved progress reporting infrastructure (usually called a "progress bar"), telling it when the process starts (displaying the bar) and ends (removing the bar from the display) and periodically updating it on progress by telling it how many steps we have to do and how many are currently done. Given that higher-level information, it can produce a more intuitive display, and even estimate the time to completion and report a rate of progress. Although the display is rather different, there is a great commonality in the interface - we are stating the fact that a process has started (and how many steps it will take), and periodically stating how far we have done, and then confirming when we are finished. A high-level progress reporting interface could just as easily generate lines in a log file as display a progress bar on a graphical screen, from the same software interface. I've also used logging for debugging, quite extensively. Rather than logging user-level messages that relate to the user's model of the state of the system, I can also log messages about the internal state of things "under the covers", and use that to guide my own investigations of problems caused by the internal state going awry. Sometimes I will do that by just printing those messages to a console I can observe, and removing or commenting out the code that does so when I'm not debugging; but more featureful logging infrastructures allow for "debug logging" that is hidden away unless specially requested, meaning I can leave the logging statements present in "production code" and turn them on at run-time, which can be a great boon. Meanwhile, in profiling and debugging server applications with multiple threads handling requests in parallel, I have often used a particular technique. I've given each thread a thread-local "current status string", and then peppered my code at interesting points with a call to set the current thread's status string with a summary of what it's about to do. I can then easily ask the system to display a dump of all running threads and what they're currently doing. Java makes this easy with threads having a name string and the ability to introspect the tree of threads and thread groups; in a system written in C using different processes rather than threads, I've written my own infrastructure to do it using a shared memory segment with each process getting a fixed-sized slot therein and some lock-free atomic update mechanisms to avoid races between the processes and the sampling tool. This lets me do two things. Firstly, when the system is grindingly slow, I can quickly see what every thread is up to. Is everyone all blocked in the same operation, all queuing for the same limited resource? Secondly, when something hangs, I can look at the state of the unresponsive threads to see what they're doing. Generally, this shows me what lock they're stalled on, and who has the lock (or, more tellingly, if nobody seems to have the lock). And finally, I can profile the system during heavy load by periodically sampling the status of each thread and then building a histogram of statuses, to see which statuses take up most of the time. However, I had to be careful with this - it worked well if the status string merely recorded what step was in progress, but not if the status string included details of the data being worked upon, because that made the strings different even if the system was at the same step, so they didn't count for the same histogram bucket. The solution was to mark such parameter data in some way (such as by always quoting it with square brackets) so that profiling tools can make themselves blind to them. Sometimes I've run into trouble with the fact that the same procedure might be called in many different places; so the thread status shows me that I'm using that procedure (and where I am in it) but doesn't tell me why. If I was attaching a debugger I could view the entire stacktrace, but that pauses execution (which may interfere with the delicate race condition I'm hunting down) and it's fiddly to do that for every thread or process in a system to get a good snapshot of the overall state, which is why I prefer the explicit-status approach in the first place. The solution is simple: rather than replacing the entire status string, each procedure should just append their status to the existing string, and remove it when it's done. In Java I did this by capturing the current thread name and then assigning "originalName + processStep" each time, then restoring "originalName" at the end of the process; in C, I did it by recording a pointer to the end of the current string and just writing our new string there, and then setting it to "\0" at the end (being careful not to overrun the buffer!). This turned the status string into a kind of mini-backtrace, but rather than logging each and every procedure call, it only logs things considered important enough to log. When looking at a snapshot of a system with a hundred concurrent requests in progress, this is a great time-saver. But, clearly, all of the above really just comes down to "reporting the current status of a thread of execution". All that changes is what the infrastructure does with that information. There's no reason why the same notification from the software cannot generate a line in a log file, an on-screen log message to a waiting user, the creation, updating, or removal of a progress bar, the updating of a global scoreboard on what all the threads in the system are up to, and the updating of a profiling histogram of where the system is spending its resources. So here's my proposal for an API. `(task-start! name [args...])` => task handle : Starts a task, which is some unit of work. Tasks may be dynamically nested within a thread, opening tasks within other tasks. Returns a task handle. The name is a string describing the task, which should itself be static, but may refer to the additional arguments positionally with `%` syntax. `(task-status! handle status [args...])` => void : Notifies the system that the given task's current status is the given status string, which again may refer to the arguments positionally with `%` syntax. `(counted-task-start! steps unit-s unit-p name [args...])` => task handle : Starts a task with the given number of counted steps. The singular name of a step is `unit-s` and the plural name is `unit-p`, eg `"byte"` and `"bytes"`. Otherwise, as per `task-start!` `(counted-task-status! handle steps-completed [status [args...]])` => void : Notifies the system that the given counted task's current status is the given status string, which again may refer to the arguments positionally with `%` syntax, and that the given number of steps have been completed so far. The status and arguments can be omitted if there's really nothing more to say then the number of steps completed. `(task-end! handle)` => void : Ends a task (counted or not), given its handle. `(task-fault! handle message [args...])` => void : Logs a fatal fault (internal failure within the task) of a task. The message should be a static string, referring positionally to the arguments with the usual syntax. `(task-error! handle message [args...])` => void : Logs an fatal error (invalid inputs, or invalid behaviour from a subcomponent, but not a problem with the task itself) encountered by a task. The message is as above. `(task-warning! handle message [args...])` => void : Logs a non-fatal problem encountered by a task. The message is as above. `(task-debug! handle message [args...])` => void : Logs a debug-level event encountered by a task. The message is as above. Now, this looks like a very ordinary logging framework, with the exception of an explicit hierarchy of nested tasks and the explicit mention of "counted" tasks with a known number of steps. Yet those two additions allow for the same interface to cover all of the above goals. Seeing how they might generate a log file for auditing is trivial. The explicit knowledge of task nesting lets us give context to common subtasks used in lots of different places, be it by something as simple as indenting each log message according to the subtask nesting depth or creating a an aggregrate "task pathname" by combining all the names of parent tasks into one long string to log. Generating a profile is also trivial; using the task names and status strings without interpolating the arguments, we can obtain a measure of what bit of the code we're in - either in isolation, or including the entire context of parent tasks, as desired. And we can also generate histograms of the arguments for each different status if we want; if a given subtask takes widely varying amounts of time depending on how it's called, we can find out what arguments make it run slowly to narrow down the problem. Debugging is helped by turning on the display of debug-level messages in the log, and by making a snapshot of the current status (status and name of the current task and all parent tasks) of each thread/process in the system available for introspecting the current state of the system. That's a useful thing to include in a crash log, too. But reporting progress to the user is where having a common infrastructure really shines. Rather than needing the explicit construction of "progress dialogs" in interactive applications, the infrastucture could notice when a thread has spent more than a few seconds inside a counted task and produce on automatically. It would display the progress of the highest-level parent counted task of the current task hierarchy, as the overall progress measure of the operation in progress; but if a subtask takes more than a few seconds, then it becomes worthwhile automatically expanding the dialog to list the entire hierarchy of nested counted tasks with progress bars (the very tip of the hierarchy, that has not gained several seconds of age, should be elided to avoid spamming the user with endless wizzing progress bars for short-lived subtasks; only display subtasks that have shown themselves to take user-interesting amounts of time). And the display of non-counted subtasks and their textual statuses within the hierarchy can be turned on as an option for users who want to see "more verbose" information, perhaps along with each task then growing a scrollable log showing that task's history of statuses, warnings, starting subtasks, and so on. How best to handle multithreaded tasks is an open question, depending really on the threading model of the language you're using. Perhaps tasks should require an explicit parent-task handle to be passed in, to make it clear what the task hierarchy is in the presence of threads; or perhaps newly created threads should inherit their parent's current task. Either way, with threading, it's possible for a task to be parent to more than one active subtask, and a progress reporting user interface will need to handle that, perhaps by dividing the space underneath the parent task into multiple vertical columns for each concurrent subtask, when that level of detail is required. Also left unspecified is more detail on the "log level" concept; I've just suggested a few (fault, error, warning, status update (called "notice" or "info" in most existing logging systems) and debug, but the system really needs to make some intelligent decision as to who to notify. A server-based interactive application given a fault condition really needs to apologise to the user in vague terms, while sending a detailled crash log and raising an alarm to the system's administrators, for instance. And more complex systems composed of multiple components may have fairly complex rules about who should be notified about what level of event in what context, which I've not even begun to worry about here... But, to conclude, I think it's a shame that there's so many very different bits of infrastructure that have very similar interfaces and are used in similar ways by software, but with very different goals. I think it'd be great to create a single progress-reporting interface for applications to use, and make different goals into pluggable components beneath that interface!

Boxing Day 2012 (by sarah)

Boxing Day in our house hold is the second day of stockings and the opening of all those presents that there just was not time to open on Christmas Day! This particular Boxing Day it was discovered by Jean that everybody's stocking was full to bulging except... Mummy's :/ So I wouldn't be sad she sneaked in some chocs but didn't want to lie to me so told me. She reckons Santa must have forgotten as there was no coal which is what you get if you're naughty apparently. This made me cry because it was so sweet and I am hoping that Santa will perhaps drop off some late stuff say on my birthday! Alaric cheered me up by presenting me with purple candles which I set out on the table as a centre piece - we put out our favourite table cloth to go with the candles :) Jean got even more books which she was exstatic about along with reindeer earmuffs which she insisted on wearing out shopping today :) Mary finally managed to open her presents - she had been so excited Christmas Day that she'd managed two! One of them was a bouncy reindeer toy which she loves very much and which resulted in a beached Mummy - for some reason I thought that it would be a good idea to try and sit on the thing, Alaric had to come and rescue me and my pelvis has been a bit mobile since but it was halarious at the same time :) And of course Mummy's glittery red shoes were kid napped! First by Mary then by Jean Mary then disappeared with them - when we tracked her down she had gifted the cat who was not entirely happy with it though just lay there like the fat lump he is accepting snugs from her :/ Mary seemed most put out with the idea that the cat wouldn't like the shoes! We gave the neighbours some home made chocs and then settled down to a dinner of left overs :) Jean declared it was the best dinner she could have - brussel sprouts, peas and one of her new books to read - Alaric is now wondering if she is actually a human child! The book is The Worst Witch All At Sea which Jeany is emotionally engaged with as there is a catnapping and the cat and owner are sad! Her first statement on reading the book was, 'This is like old style Harry Potter only with just girls.' Alaric played games with Jean on the computer and I wrote story ideas in my new lego note books! We are all alas a bit virally and the baby ended up calpoled and in bed with a mild temperature. But it was a good Boxing Day even if I ended up having to nap!

Christmas Day 2012 (by sarah)

Christmas Morning and the stockings were bulging at the seams, two dresses lay draped across the fire guard. Jean was almost bursting with excitement and Mary had picked up on this - they had woken us up at like 4:30 am - we sent them back to bed and then I couldn't sleep for excitement and so went and woke them up at first light! Jean was ecstatic to find the things she had asked for in the stocking and Mary got a little confused and kept trying to put her things back into the stocking! Jean then entertained us with jokes from her Angry Bird book. Whilst Mary played plinky music on her little plinky guitar :) I was impressed that Santa realised I needed a pencil sharpener and rubbers and pencils and a calligraphy set! Mary finally got the idea with the stockings... just in time to help Daddy. The girls were sleepy but perked up once breakfast and more present opening was mentioned! There was a lot of presents! Most of them were from our friends and we could not believe their generocity, there were lots and lots of lovely things for the girls but also things for me and Al. My presents ranged from a lovely pocket dragon broach which I wore at dinner, to butterfly necklaces - one of which Jean had chosen specially for me. Then there was a Clangers craft book and so many other things - all I could say was 'Oh wow!' and then it came time to open the package that had turned up on the door step Christmas Eve. The tag read 'The Snell-Pym Family From Santa' it was a complete mystery and it contained an X-Box Connect! Jean did little happy jumps and Daddy stood there frozen and then started trying to work out if he had a cable to connect it to one of the monitors we have kicking about the place etc... and I cried. I'd tried to make a video Christmas Eve to thank everybody for being so lovely but I had gotten too choked up. Father Christmas had delivered what was wanted but not what had actually been asked for as Jean was worried it was too big a present and I had said on Facebook that such a present would have to be a whole family present. Jean loves Angry Birds and so the umbrella had to instantly be tried out! As did the Ju Jistu mitts that she had asked Santa about specially. Butterflies! I received lots of butterflies as necklaces and wall hangings - Alaric says he is neither for nor against butterflies in the house but that they make me so happy that he wants to just cover the house in them now :) Jean was over the moon at the stack of books she received and we knew that there was just as many to come on Boxing Day too! She chose a Worst Witch book to start with and was just finishing chapter two when it came to bed time :) Jean loves books So does Mary :) Mary also loved her little Hedgehog that Jeany had gotten her. The girls both wanted to put on their new cloths - Jean chose the blue dress which had been mine at the same age - though it had been made longer for me when I was about 10 so is long enough for Jean! The hat is one of Nanny's which she then put on Mary, a process I don't think Mary appreciated! But then Mary was really happy with the hat and wondered around with it on for ages! Mary loves the little Minni Mouse outfit so much that there was a cross tantrum when it had to be removed due to a nappy breach - but this was solved by the fact she saw her new pj's (sent by the same person! Helen her god mother!). We left the kids watching their new film whilst we went to cook the dinner. Well when I say 'we' I mean Al the elf! I was busy decorating the Christmas cake :) The Snowflake Cake! It didn't quiet come out the way I invisioned - the two techniques didn't work well together - most of the slump in the wonky cake stand rather than the cake itself though! I was very happy with how the glittery snowflakes came out though! More on this will appear on our [cooking bog](http://cooking.salaric.co.uk/) at some point! It was then Dinner time and Jean rushed to the table - anyone would think she was hungry! We went with a standard fruity starter :) Melon and strawberries :) then onto the leopard pie which I had made little vent tubes for, these represent polyp tubes in colonial organisms :) It worked really well this year and I really enjoyed dinner :) Jean of course was very hungry and couldn't even wait for the crackers to be pulled - she got shouted at! (ok so this is a posed shot taken after the event!). Yummy yummy for my tummy! I then made pud as Alaric was exhausted! See very tired - one Alaric! Mary never quiet got the hang of the crackers! We then all went off to read our books whilst Mary napped - apparently I was snoring away on the sofa! :/ Then me and Jean played an epic game of Scrabble where I found the new challenge was to to try and make the board as open as possible and to only use words I could explain the meaning of to her - I am hopeful that in about three years I will have a proper opponent for the game!

Merry Christmas On And All (by sarah)

Merry Christmas on this dreary Christmas Eve! Here at the Snell-Pym Household we are recovering from mulled wine and minced pies with friends and are about to under take some lovely craft activities followed by christmas food prep! Until then here is the outline of the Cathedral I have drawn for [Percival's Christmas Wish](http://www.snell-pym.org.uk/archives/2012/12/12/because-we-have-our-home/). I have only so far managed two complete drawings both in outline but will attempt some more later on! I have a confession - I'm not very good at drawing buildings - I've never really done it to be honest and it took a lot longer than expected and I'm not entirely happy with it but it will none the less be going up on [Wiggly Pets](http://www.wigglypets.co.uk/) with the story a little later today!