As sure as logs are logs

… or not.

As promised, I’ll write a bit about build logs today. You’ll see what our logs are, and, to begin with, I’ll take you on a tour through buildMessage to explain how the logs we have end up being what you see served off of tinderbox.

First off, buildbot is basically the same thing as any regular gecko app, one main thread and loads of callbacks. So when reading on, all your spontanous reactions are good.

The buildMessage code does:

  1. synchronous IO to load all logs of a build into memory, basically up to some 70M
  2. synchronous string handling to paste all that data together, with some extra padding
  3. synchronous compression of the resulting string
  4. synchronous base64 encoding of the compressed string

All on the main thread, all in one go, blocking. All of that to give you a single lengthy unformatted blob of text. Why?

Because our build logs are actually not a single lengthy unformatted blob of text, which is what tinderbox wants.

Let’s have a peek into what our build logs are, really. In my previous posts, I introduced you to the concept of build steps. They’re really the basic entity of work to be done for a build. Now, the logs are stored in buildbot pretty much in how the data comes, that is, each log is associated with a step, and the storage is happening as the chunks arrive. Commonly, that’d be stdout and stderr data coming from shell commands run on the slave. The information about which stream the data is on is persisted, too, as is the order, so any log looks like this, basically:

Step reference header length data
stdout length data
stdout length data
stdout length data
stderr length data
stdout length data

As most of you aren’t among the few priviledged ones to actually look at the real logs, I’ve set up a fake log page for you to take a look. It’s an l10n repack, mostly because they’re somewhat small in both step count and log size, and because I’m used to them. Here’s the actual make step highlighted. You can see the introduction being shown in blue, which is the common color for header chunks. Buildbot just uses that channel to show setup and shutdown information on the step. Then there’s the actual make output in black. If there was something on stderr, it’d be styled in red. Sorry, I didn’t quickly come up with something that has stderr.

The first take-away is that you can get to just the build output of the step you’re interested in.

If you’re nostalgic, you can check the checkbox for tinderbox, the css style sheet changes to show you what you’d get from tinderbox. Try to find the information again?

One further detail, there can be more than one log per step. Buildsteps that set build properties quite commonly have two logs, one that keeps track of the command that got run, and another that keeps track of the actually changed build properties. You can look at an example in the builddir step. The boring last line is the second log.

Log files are really not all that complicated, and much more useful than what we get back from tinderbox. Let’s look at some of the pros:

Log files come in as the build goes. This enables buildbot to publish build logs in almost realtime. There’s little-to-no cost for that, too, a simple node.js proxy can ensure that only one log is read at any time. Another benefit is, one can archive logs incrementally, removing the current stress on the masters to publish more data than they want to chew in one go.

Log files are per task. As the logs are associated with a step, which has a name and a builder, there’s pretty rich information available on what the data in question is actually about. Think about hg-specific error parsers for one step, ftp-specific ones for the next, and mochitest-specific ones for the one after that. All in one build. If we’d archive the raw data, we can easily improve our parsers and be compatible with old logs. Or add new steps to the build process without fear to break existing log parsers.

Tinderbox can still be fed. Even if we’re not sending out tinderbox log mails from the masters, we can still do the processing out of band in an external process or even external machine, offload the masters, and not enforce us to change all infrastructure in one go.

There is a hard piece, too, storage. Build logs are plenty, and they’re anywhere from a dozen bytes to 70M. Within the same build, even. There a hundreds of thousands small files, and thousands of really large ones. I hope that adding some information on what our build logs really are helps to spike a design discussion on this. If to compress, on which level. Retention, per step type, even? Store as single files, in one dir, or in a hierarchy, or as tar balls? Or all of the above as part of retention? Is hbase a fit?

Counting sourcestamps, changes, and faking data

As a follow up to my previous post on my digging through our build status, I want to look with a bit more detail, pretend it’d all be simple and what it could be, and, well, add the promised chocolate to coconut. Bounty.

Let’s look at the actual data for two and half landings. First, I’ll start with a rather simple landing by roc, revision 1b43… on mozilla-central. Let me summarize the builds real quick:

1 changeset in 1 push.

27 change rows in status db.

16 different branch names.

106 sourcestamps in status db.

245 builds.

That’s a lot, because, what we’re really interested in is

1 push, 245 builds.

Talk is cheap, but what’s really cheap is manipulating other peoples database, so while Vettel was running in circles in Brazil, I was running circles in the db and manually stitched things back together. The result is still coconut, but with chocolate, so here is the same url in bounty.

1 source, 1 change, 253 builds.

Wait, what, not 245? No, 253, because, well, there are more disconnects in the status, so the query in the database doesn’t catch them all. That’s what you need manual stitching for. Also, finding the right sourcestamp to keep isn’t trivial.

Which is why I only did it for a few builds. Sorry, you’ll not find a lot of builds that are stitched together, so enjoy the guided tour through the few shiny places.

During my needlework I came across another set of changes which are worthwhile to include into today’s tour. It’s two pushes, by khuey and vlad. Let’s give Count Count a rest and look at them with chocolate right away, the builds for khuey’s revision and vlad’s. What you’ll notice is that some of the builds for khuey aren’t there, but lumped together with vlad’s. Why’s that?

Our build infrastructure really doesn’t know about pushes. As I’ve detailed in my previous post, there are sourcestamps and changes, but no further grouping. At this point it’s really a design decision on whether the buildbot changes are hg pushes or hg changesets. This decision is currently in favor of hg changesets, which may just be right. At that point, the scheduling logic that puts changes into builds needs to put extra care into creating sourcestamps for what we intend to get builds for, and to keep those sourcestamps apart. The current implementation puts anything coming in within three minutes into the same sourcestamp, which is somewhat of a load limiter.

Anyway, back to chocolate. When you looked at the pages, did you realize that once you add it, you’re almost at a tinderboxpushlog page? Right, it could be that “easy”.

What’s between reality and chocolate? Well, sendchange. That’s a buildbot architecture component that allows shell commands to insert changes into buildmaster. It’s rather limited in the data it can transport, which is why we loose data on the way. There’s an alternative feature called trigger, which doesn’t. There is an open ticket to make that span different buildmasters, but given how much Mozilla invested into schedulerdb, let’s pray it’s easy to fix. Filed bug 611670.

Update: Changed links to l10n community server.

Looking at the internals of our builds

Chris Atlee has put up database dumps of both the scheduler and the status databases. These databases are the most detailed and (almost, status db is not) first class information on what our builds are really doing. The current code on top of that is all pylons-based, and I am, as many other mozillians, part of the django shop. So for one I figured “let’s see if I can make django read this”.

I can. It’s a bit rough, though, as some of the tables for many-to-many relationships don’t contain a primary key column. Django really doesn’t like that, and thus there are some things that you cannot do without those columns. Most of it works just fine, though. This holds at least for the status db, which I looked at in more detail, but the scheduler db ain’t much different. Filed bug 611014.

The code for this is up at django_moz_status on github.

Of course, me being able to talk to the db with a python shell won’t help you much, right? So I’ve spent a few more hours to actually create a really rough website on top of it, which I want to share with you.

Coconut. Hard to open, and once you get there, you may not like it. I have a thing with project names.

Coconut is a bunch of django views on top of django_moz_status, held together by site_demo. You can see it in action (for now) on the l10n community server. This view is exposing three concepts of buildbot, and how they play together:

Sourcestamps (first column): Every build in buildbot has a sourcestamp, and a sourcestamp can have multiple builds. The sourcestamp knows a branch, a revision, and a list of changes going into the builds associated with it.

Changes (second column): Changes are the external “real life” events that may or may not trigger builds. In this view, you see a few list of changes that look like a push to hg (and are just that), as well as a plethora of changes by Mr. sendchange, and Mr. sendchange-unittest. If you remove some query params on the above URL, you can also see a bunch of sourcestamps without changes. Those are nightlies.

Builds (last column): Each sourcestamp can have multiple builds, I’m just showing the builder name (a symbolic short name), the buildnumber, and the result as color. The third column is actually a guess on the platform of the build, based on the platform build property. If that’s not set, unknown is used.

Which brings me nicely to another two pieces of our build infrastructure that has been hard to look at so far. Build steps and build properties. Surf along? Let’s look at a build.

The first section of the build pages shows some general information, builder, buildnumber, status. The start and end time, how long the build took. Also it lists the buildbot master, and the category of the builder. Categories allow to filter for builds, sadly, a builder can only be in one category.

Next up is build steps. Each step in a build is an item of work, and an entity of failure. Different steps can handle failures differently, too. You can see that the build starts with a flock of steps that do administrative tasks on the slave. You can see which fragment of time of the build that step took by looking at the bar in the second column. You’ll see that the majority of that build went into the compile step. And that that passed. And after that compile, there’s a bunch of adminstrative stuff again.

There are two things that you do not see. One is, each of those steps has build logs attached to them. Commonly one, but possibly more. I’ll talk more about logs in a different post. The other thing is, steps can change the build properties. Which is to say, the build properties which are shown at the end of the build page are not static, but change during the build run.

Build properties? Right, within buildbot, several objects can have properties, among them, builds. You’ll find things like the buildnumber, the slavename, the branch, buildername (pretty). You’ll also find a host of things around the packaging of the build. Quite generally, our build try to put things that are needed for the build itself or for logic around into build properties.

The end of the page is reiterating which changes are associated with the sourcestamp for this build.

Let me stress your patience once more and invite you to visit a build with a failed step. In this build page you can see how the clobber step worked fine, and took quite some time, and the actual status of the build is due to the actual test step failing with a warning.

Now this post is already pretty lengthy, so I’ll take a break here and invite you to go in and click back and forth a bit, and to do some url hacking. If you think this is rough and you’re having a hard time figuring out what’s why, I’ll do a follow up post on how to add chocolate to coconut.

PS: the database this instance is working on is a snapshot that ends in August, details may be different today. I shrunk the database, too, only the last 10k builds still have the buildsteps.

Update: Changed the links to the l10n community server.

MultilingualWeb: Workshop in Madrid

So I’ve been at the W3 MultilingualWeb Workshop in Madrid last week, and I guess there are a few things worth reporting.

MultilingualWeb is a project bound to host 4 workshops to bring people from different fields together to see how standards and best practices (existing and not) can help the web. Being mozilla, we don’t really need to add that it’s beyond just one language, right? The effort is strongly supported by the European Union, so there’s a bias towards participants in these workshops being from Europe, though the folks by themselves certainly talk beyond that.

The crowd in Madrid was really diverse, standards people, government (EU and India), researchers, content, and, well, browsers. The browsers people were Charles McCathieNevile (Opera), Jan Nelson and Peter Constable (Microsoft), and me (Mozilla). There we no folks from webkit-based browsers.

Interesting bits and pieces:

I guess other people made that experience lately, too, but I welcome the way that MSFT is positioning themselves lately. Now they just need to compare beta builds to beta builds, and, (insider joke) while we hack on canvas, you learn JS:

- ctx = canvas1.getContext("2d");
+ ctx = document.getElementById('canvas1').getContext("2d");

Still need to actually look at the results in competing browsers, and not on my font-broken OSX, but we’re not doing too bad.

Gecko should really start using CLDR data for stuff like plurals, dates, calendars, lists. I should also really read up on ES’ i18n_api.

It was interesting to see common questions on what’s a language from Denis Gikunda, who’s working on l10n for google in sub-saharan Africa. Now that Anloc is coming in with their localizations, we’re getting more exposed to how the history of those languages is so different from European ones.

Facebook’s Ghassan Haddad reported on a few interesting things. Like Zuckerman coming into his interview with “you can’t slow our development down”. Interesting about this is that the resulting infrastructure is far from zero-impact on the development. There are quite some restrictions on what content you can put up, and you have to add syntactic sugar all over, too. Go check their docs for details. Also, they’re not slowing down the publishing of localizations.

We got a bit of detail in the discussion about vandalism in fb l10n. They initially relied on community there, but when they got hit, they took down the localized sites until they had tooling support. Ghassan didn’t come forward with details on what they do, though.

They are doing something conceptually similar to l20n to localize their social messages like “A is now friend with B, C”, to make those depend on all the genders. IIRC, they call it string or entity explosion. Didn’t get to ask any questions about this one, sadly.

Most of the science people talked about processes that all sound very good for the data we get from feedback in Firefox 4 betas. Natural language processing with trends detection, “translation” of SMS Spanish into Spanish, and much more. Sadly, there’s nothing shrink wrapped that we could just use, but there’s interest in creating a project to find out, maybe for Firefox Next?

One thing that felt slightly odd was the Semantic Web. I thought that was dead, but there’s still optimism around that. Maybe semantics that help machine translation make a case for it, I’m not sure. Also, there seems to be more structured data coming to the “public web”, and the algorithms that transform the “hidden web” into the “public web” could more easily add markup than human authors would. Still, there wasn’t much hope in the browser people. Luckily, the browser doesn’t really need to do anything but creating a DOM, and passing markup around for machine translation engines taking benefit from additional semantics.

Last but not least, I did finally get to spend some quality time with our Madrid community, thanks to the folks for taking me out twice. I had a great time, and sorry that my English speaking tempo aligned with your Spanish speaking tempo way too often :-).

Releasing compare-locales 0.9, aka, the value checker

I’ve just uploaded version 0.9 of compare-locales onto pypi. It’s finally the version that does all the fancy value checks that I’ve been talking about for a while, and that some of the localizers have seen flying by in their bugmail.

Here’s what it does:

For DTDs, I create fake xml docs, and try to parse them. This should find encoding errors, as well as unbalanced XML tags or stray ‘&’ ampersands. There’s one thing that’s tricky, and that is references to entities. I do get the list of entities from en-US, so I do have a good idea which should work (really, please). On the other hand, referencing other entities may not be an error. &rdquot; for example could be totally fine. If referenced in an XHTML document, that is. Not if it was included in a XUL document. Of course both breeds could include the same DTD file. I can’t really tell, so I’ve added a new category of reporting, called warnings.

For properties files, I check a bunch of printf tricks. Some of those are warnings, some of those are errors. Which is which basically depended on code-inspection. I also did some heuristics based on comments referencing the plural docs to check for our plurals-special variable handling.

Outstanding are the installer variable checks still, didn’t want to hold back this release for that. They’re somewhat tricky in the details and yet more tedious to get right than the other checks.

What does that mean for localizers? You wanna get the error count down to zero. The warnings count may or may not go down to zero, that’s your call.

The new version isn’t in public use anywhere yet, the deployment will go like this:

  • Get a round of public feedback on this release.
  • Use on the dashboard (likely gonna happen when I do the 2.0 branch dance, too).
  • Try to get the new version used on the build system.

Please give the new version a bit of pounding in your local l10n-merge builds, too. It should strip entities with errors from your localization, and merge in en-US strings for that.

Feel free to file bugs on issues you find.

Lazyweb, can I have compilers in js and python?

For our l20n project, we’ll want to compile l20n source files into javascript. We want to do that both at compile time, and at runtime.

For runtime, I’ll need the compiler written in js by all chances, and for compile time, I’d rather go with python so that I don’t have build a HOST_JS or something. Of course, I don’t want to maintain two completely independent compiler implementations.

Thus I’m looking for code that can generate compilers in js and python, preferably itself in python or some other language we can use at build time, or at least use for one-off compilations.

Any tips?

Porcupine, meet Churchill

I’ve been talking with Seth today on how we can answer questions about the status of l10n. My grumpy argument was that I wouldn’t know how to make graphs over time actually show progress, instead of just “failure”. I had two naive graphs, one is showing all missing strings summed up over all locales. That graph would be dominated by the long tail of several dozen locales with a few hundred strings each, and you wouldn’t see a dozen fighting over a few strings each.

The other is what I nick-name “porcupine graph”, show how many locales have no missing strings, vs those that have some missing strings. This is what’s actually implemented on the l10n dashboard as tree progress graphs. But how ever small a string change would be, it goes to all red. And it doesn’t help that one can’t mix green and red color gradients, so the graph usually shows spikes of red and a little black.

porcupine

Who’d want that as their progress stats, huh?

Now, during the chat with Seth I came up with the idea to just give a little bit of leeway, and accept some missing strings to be OK, at least for some time. I filed bug 582280 on that, and made a rough initial implementation of it. Nothing fancy, just a constant ignored bound of missing strings. Let’s see how the past two weeks of Firefox 4 look now, with just a total of 5 missing strings being OK, ?bound=5:

two weeks good and bad

Now Churchill won over the porcupine, but it’s still pretty red. Which is OK, we haven’t even branched yet, right? So I went ahead and figured I’d add an option hideBad:

two weeks good

Wow, progress. This graph actually looks like our community rocks as much as it does. Gets me grumpy, because this was really just about half an hour of work, plus a few years of thinking.

Now, how do we look on the long run, say, well over half a year? Bumping the bound up to 15, we’re doing like

half year progress

Pretty good, heh? You can play with it on the dashboard, too. The overall take aways would be:

We have about 20 locales that really track trunk.

We didn’t have that many landings with a high amount of added strings.

I like both :-).

Looking at a l10n bugzilla classification

We intend to move from components per locale in the “Mozilla Localizations” product to a matrix of products per locale, and components for each of Firefox, Thunderbird, et al. I’ve created an add-on to set up the products and components and laid out in the newsgroup thread. I wanted to share some screen shots on how things look locally now.

enter_bug.cgi?classification=Mozilla in Your Language looks like this:

enter_bug.cgi

Localizers can edit the descriptions on localize.m.o. I’m not totally convinced that the current formatting of the products are great. The double () braces disturb me, both here and on the actual bug form (see below). I might prefer “l10n:ab-CD Language (Region)”.

Enter bug

This is the actual bug entry form, and shows the localized component description. It also shows a rather confusing line wrapping of the product name.

Another aspect that we were concerned about was how it’d look if you changed the product of a bug. Locally, this looks like this now:

Re-productize bug

Got comments? Please leave them in the original newsgroup thread, or here.

l20n meetup in the european times

I heard there was interest to join the l20n discussions, so I’ll do an “even more public” invitation to tomorrow’s l20n call.

We’re going to have that call on conference bridge 206 at 11 am CET, standard mozilla conference call details. Blame Seth for being almost-european these days, even if it’s just timezone. (No, not calling London Europe, no way.)

The agenda for this call is to look at some l20n-compiled files for browser.xul to make an educated decision on how to encode both external vs internal properties, and multi-locale files.

Sorry for the late invite, if you’re not on my radar and can’t make the meeting at such European hours, please follow up here, or by mail, and leave a note of your timezone.

Localizing Lorentz

It’s been a while, but I’ll take a stab at what we did to localize Lorentz, i.e., how did we add strings to a stable branch?

The underlying principle was add-on compatibility, that is, language packs that are out there and compatible with 3.6.* needed to continue to work. The second principle was that while we didn’t want to break existing language packs, we did want to offer our localizers to work on the new strings to get the best possible user experience. So we’re adding strings without adding strings.

Given that we had a project branch for Lorentz, the work on the Lorentz branch itself was rather simple, just code like you’d always do. We didn’t do any special branch mechanics there, and built the Lorentz branch against the regular l10n repositories on 1.9.2. The only caveat here was to not remove strings, only additions were OK. As soon as that work got stable in terms of the strings used, we landed a patch that, for each new string, adds a hard-coded fallback to the code. That way, you pick up the localized string without failing if it doesn’t exist. So much for the work on the project branch.

On the stable branch, things are a bit more tricky. Of course we needed to be able to continue shipping security updates from the stable branch, that is, we didn’t want to turn builds red for strings that aren’t really missing. Yet we wanted to signal that the strings are there and to be localized. Up until then, we only had two stages of strings, missing or not. The latter is what we use for handlers in region.properties, for example. We needed a third stage, “report on this string, but don’t fail”. So I added a third stage to the logic around filter.py in compare-locales. This logic is now used in filter.py on the 1.9.2 branch, but not on central. Another necessary addition was to support filter.py for each module, so that we only had to hack around the toolkit strings once, and ont for all apps on 1.9.2. So there’s now a filter.py file for toolkit on 1.9.2, making sure we only report on the lorentz strings in toolkit.

Once that logic was in place, we added a “strings-only” patch to 1.9.2, which had the benefit of exposing the en-US strings in the regular repository that our l10n community is working on.

The outcome today is that out of the 74 languages we ship, only 25 still rely on the en-US fallback strings.

In bullet points, that’d be:

  • Do not remove strings, so that newer language packs are compatible with older releases.
  • Add strings with en-US fallbacks, so that they can be localized, but don’t error when missing.
  • Make filter.py for the module (browser/mail/toolkit) “report” on the new strings, so that localizers see the strings without hiding real errors from non-fatal ones.
  • Land strings early on the stable branch to get them exposed to l10n (with filter.py, see above).