key=value logs with nginx

(by )

In Six Ways to Make Your Production Logs More Useful @roidrage talked about how to make your logs much more useful. One of the proposed solutions was to use a format that is more structured and thus easier to read: key=value logging. This way it’s easy to parse for a human eye, but a machine will have no problems either. And of course your standard shell tools (with the combination of some basic regular expressions) will still work to find what you want in your logs.

This blog and all of my other sites run on nginx and with nginx it is very easy to use a custom log format. Just define a new log_format, give it a meaningful name and the layout you want. For example I use the following now:

log_format  keyvalue  'time=$time_iso8601 ip=$remote_addr user=$remote_user req="$request" '
                  'status=$status bytes_sent=$body_bytes_sent req_time=$request_time ref="$http_referer" '
                  'ua="$http_user_agent" forwarded="$http_x_forwarded_for"';

Put this in your http {} block and wherever you define a new access log file append keyvalue (or the name you have chosen) like this:

access_log  /var/log/nginx/access.log  keyvalue;

And voilà:

$ tail -1 /var/log/nginx/access.log
time=2014-04-15T18:20:54+02:00 ip=127.0.0.1 user=- req="GET / HTTP/1.1" status=301 bytes_sent=184 req_time=0.000 ref="-" ua="curl/7.36.0" forwarded="-"

If you want to know which variables are available, read the nginx docs.

Update: @rhoml pointed me to a full overview of available variables.

OpenTechSchool - Learn new things

(by )

Last weekend (29./30.03.) I coached beginners some HTML & CSS. This is about my experience.

A while back a friend of mine asked me if I wanted to help at OpenTechSchool Dortmund, coaching programming or to hold a talk. At that time I was a little busy with University stuff like writing exams, but I said I would be very happy to help.

Workshop schedule

Then about a week ago he reached out to me. One of their coaches had canceled and they needed a new one. I immediately said yes. Last friday then we had a short and fun coach meeting where I met the organizers. They worked hard to translate the complete material into German to make it easily understandable. The full material can be found online. It’s not quite perfect but it is a good starting point.

Saturday began quite early and by 11 o’clock the room at ständige vertretung was filled with about 20 beginners ready to start learning HTML & CSS. The OpenTechSchool encourages people to learn at their own pace, so my task was not to teach them but only assist when questions came up. This was a lot of fun for all, it was very interesting and great to see people getting so much fun by learning a new thing, implementing their own ideas and setting their creativity free. Oh, and I also learned a few things (typography can be an interesting topic).

After two full days of HTML & CSS and a very very funny evening in a local bar, the workshop came to an end and results started to show up. All attendees had something done, at least one website was successfully uploaded to the internet, some even worked on their sites after that.

If you want to know more about the OpenTechSchool and what they do go over and read about it. The next beginner’s workshop will be on 24th and 25th of May. Register at Meetup. Maybe I can find the time to be there as a coach as well (if the organizers want me as a coach of course ;)) There are also monthly “Learners Meetups” with talks, discussions and a lot of great people, next one just next week on 9th April.

A big thanks to the organizers Ola, Dennis, Leif, Tobias, Carsten and Hendrik. Another big thanks to the other coaches Lars and Dennis. And of course to all attendees, who had so much fun.

Fixing zfs pool error in zones/dump

(by )

At work we’re using SmartOS, an Open Solaris clone featuring all kinds of cool stuff. One of the best things is the underlying file system: ZFS.

With ZFS it is easy to create, mirror, extend storage pools, it’s also very easy to snapshot pools and backup them using zfs send and zfs receive. In the process of a manual backup of one of the pools today I wanted to see the status of the whole system by using zpool status. This is what it showed:

$ zpool status -v
  pool: zones
 state: DEGRADED
status: One or more devices has experienced an error resulting in data
        corruption.  Applications may be affected.
action: Restore the file in question if possible.  Otherwise restore the
        entire pool from backup.
   see: http://illumos.org/msg/ZFS-8000-8A
config:

        NAME        STATE     READ WRITE CKSUM
        zones       DEGRADED    16     0     0
          mirror-0  DEGRADED    32     0     0
            c0t4d0  DEGRADED    32     0     0  too many errors
            c0t6d0  DEGRADED    32     0     0  too many errors
        logs
          c0t9d0    ONLINE       0     0     0
        cache
          c0t8d0    ONLINE       0     0     0

errors: Permanent errors have been detected in the following files:

        zones/dump:<0x1>

At first this looks a litte bit weird. What is this zones/dump even for? Why is it broken? The answer: Solaris dumps the memory onto the disk on a system crash. I tried googling this error, why it would get corrupt, if the disks are really broken or if it is just a software error.

Turns out this bug is known. We recently upgraded our SmartOS, which brings up this issue. The disk and the pool are not really broken, but simply the data is misinterpreted. To correct it you must replace the dump and later scrub the whole pool again. I executed the following commands to do this (found them in a forum post):

zfs create -o refreservation=0 -V 4G zones/dump2
dumpadm -d /dev/zvol/dsk/zones/dump2
zfs destroy zones/dump
zfs create -o refreservation=0 -V 4G zones/dump
dumpadm -d /dev/zvol/dsk/zones/dump
zfs destroy zones/dump2

This will first create a new file system, swap it in as the dump file system, delete the old one and once again create a new one with the old name and putting it back in place.

In case the dumpadm -d part fails, complaining about the file system being to small, just resize it:

zfs set volsize=20G zones/dump2

See Swap and Dump Volume Sizes for ZFS File Systems.

The scrubbing took 21 hours with our large data set, but it was not noticable in running machines on this host due to its low priority. The final status:

  pool: zones
 state: DEGRADED
…

errors: Permanent errors have been detected in the following files:

        <0x17f>:<0x1>

Well, now the zones/dump:<0x1> is gone. But it still shows an error for the same file system, just that it is not named anymore. We’re scheduling a maintenance soon to reboot the machine. Let’s hope this will clear the error. Otherwise we will replace the HDD.

Redis Cluster with pre-existing data

(by )

With Beta 2 of Redis Cluster arriving soon released just now, I finally found some time to play around with it.

A few days back in the #redis IRC channel someone asked how to migrate data from one existing normal Redis instance into a Cluster of several machines. Back then I did not know how to do it, so today, after a short conversation with antirez and a small bug fix, I got going. This is how it works.


tl;dr: Create cluster with empty nodes, reshard all (empty) slots to just one instance, restart that instance with the dump in place and reshard again.


Short info upfront: I’m using the latest git checkout as of right now, cc11d103c09eb5a34f9097adf014b5193a8c9df3. I shortened the output of some of the commands, all necessary information is still present.

First you need a cluster. To start, create the config for 3 instances on port 7001-7003. This is even simpler than the Cluster tutorial.

mkdir cluster-test && cd cluster-test

for port in 7001 7002 7003; do
  mkdir ${port}
  cat > ${port}/redis.conf <<EOF
port $port
cluster-enabled yes
cluster-config-file nodes.conf
cluster-node-timeout 5000
dir ./
save 900 1
save 300 10
save 60 10000
EOF
done

This creates the config for 3 instances. Now start them (use one terminal per server or add daemonize yes to the config):

cd 7001; redis-server ./redis.conf

Once done, let the nodes meet each other:

$ ./redis-trib.rb create 127.0.0.1:7001 127.0.0.1:7002 127.0.0.1:7003
>>> Creating cluster
Connecting to node 127.0.0.1:7001: OK
Connecting to node 127.0.0.1:7002: OK
Connecting to node 127.0.0.1:7003: OK
...
[OK] All nodes agree about slots configuration.
>>> Check for open slots...
>>> Check slots coverage...
[OK] All 16384 slots covered.

At this point the instances should be empty and each one should have an ID and some assigned slots:

$ ./redis-trib.rb call 127.0.0.1:7001 info memory | grep 'used_memory_human:'  
used_memory_human:919.44K
used_memory_human:919.44K
used_memory_human:919.44K
$ ./redis-trib.rb check 127.0.0.1:7001
...
>>> Performing Cluster Check (using node 127.0.0.1:7001)
M: 6b916c5189438ee2a8b2248cdab264b16492abe9 127.0.0.1:7001
   slots:0-5460 (5461 slots) master
   0 additional replica(s)
...

Before we can re-use an existing dump, let’s reshard all slots to one instance. We specify the number of slots we move (all, so 16384), the id we move to (here Node 1 on port 7001) and where we take these slots from (all other nodes).

$ ./redis-trib.rb reshard 127.0.0.1:7001
Connecting to node 127.0.0.1:7001: OK
Connecting to node 127.0.0.1:7002: OK
Connecting to node 127.0.0.1:7003: OK
>>> Performing Cluster Check (using node 127.0.0.1:7001)
M: 635607ddd921c61e2b6afa425a60b2ad206d1645 127.0.0.1:7001
   slots:0-5460 (5461 slots) master
   0 additional replica(s)
M: e3a0fde219b53dafa0e7904b47251b38e3c35513 127.0.0.1:7002
   slots:5461-10921 (5461 slots) master
   0 additional replica(s)
M: 7bd6d759fb11983e63925055ad27eaab45ee0b24 127.0.0.1:7003
   slots:10922-16383 (5462 slots) master
   0 additional replica(s)
[OK] All nodes agree about slots configuration.
>>> Check for open slots...
>>> Check slots coverage...
[OK] All 16384 slots covered.
How many slots do you want to move (from 1 to 16384)? 16384
What is the receiving node ID? 635607ddd921c61e2b6afa425a60b2ad206d1645
Please enter all the source node IDs.
  Type 'all' to use all the nodes as source nodes for the hash slots.
  Type 'done' once you entered all the source nodes IDs.
Source node #1: all
...
Do you want to proceed with the proposed reshard plan (yes/no)? yes
...

A quick check should show that everything is fine:

$ ./redis-trib.rb check 127.0.0.1:7001
...
M: 635607ddd921c61e2b6afa425a60b2ad206d1645 127.0.0.1:7001
   slots:0-16383 (16384 slots) master
   0 additional replica(s)
...
[OK] All 16384 slots covered.

We now have a Cluster consisting of 3 master nodes, with all 16384 slots only assigned to the first instance. Setting a key on this instance works fine. Every other node will report a MOVED error:

$ redis-cli -p 7001 set foo bar
OK
$ redis-cli -p 7002 set foo bar
(error) MOVED 12182 127.0.0.1:7001

Next step: Importing our existing data. Grab the dump.rdb from your existing instance (make sure you’ve got a recent version, by either sending SAVE or BGSAVE on that instance first), put it into the right directory and restart the node:

$ cp /tmp/dump.rdb 7001/
$ du -h 7001/dump.rdb
22M  7001/dump.rdb
$ redis-cli -p 7001 shutdown nosave
$ redis-server ./redis.conf
...
[23191] 11 Mar 16:11:58.978 * DB loaded from disk: 3.253 seconds
[23191] 11 Mar 16:11:59.035 * The server is now ready to accept connections on port 7001

The Cluster instance saved information about nodes it was connected to in the nodes.conf file, so on restart it can join the cluster again. Let’s see if the data is really there and our Cluster is in a stable state:

$ ./redis-trib.rb check 127.0.0.1:7001
...
[OK] All 16384 slots covered.
$ ./redis-trib.rb call 127.0.0.1:7001 info memory | grep 'used_memory_human:'
used_memory_human:212.29M
used_memory_human:918.44K
used_memory_human:918.44K

Yes, looks like it is. Now onto resharding to make use of all instances. We want to distribute it evenly across all 3 nodes, so about 5461 slots per instance. The reshard command will again list the existing nodes, their IDs and the assigned slots.

$ ./redis-trib.rb reshard 127.0.0.1:7001
...
[OK] All 16384 slots covered.
How many slots do you want to move (from 1 to 16384)? 5461
What is the receiving node ID? e3a0fde219b53dafa0e7904b47251b38e3c35513
Please enter all the source node IDs.
  Type 'all' to use all the nodes as source nodes for the hash slots.
  Type 'done' once you entered all the source nodes IDs.
Source node #1:635607ddd921c61e2b6afa425a60b2ad206d1645
Source node #2:done
...
Do you want to proceed with the proposed reshard plan (yes/no)? yes
...

When it finished some data should be moved to the second instance:

$ ./redis-trib.rb call 127.0.0.1:7001 info memory | grep 'used_memory_human:'
used_memory_human:144.49M
used_memory_human:72.70M
used_memory_human:918.44K

Now repeat the reshard step to migrate another 5461 slots to the third instance. Final check after the second reshard:

$ ./redis-trib.rb call 127.0.0.1:7001 info memory | grep 'used_memory_human:'
used_memory_human:76.71M
used_memory_human:72.70M
used_memory_human:72.70M
$ ./redis-trib.rb check 127.0.0.1:7001                                  
...
[OK] All 16384 slots covered.

That looks good. We have all our data distributed onto 3 nodes, just as we wanted. The whole process might seem a bit complicated right now, but maybe with more time we can improve it and write a few simple scripts to do this instead of manually resharding.

Oh, and putting new data into Redis works as well:

$ redis-cli -p 7001 set foo bar    
OK
$ redis-cli -p 7001 set baz bar
(error) MOVED 4813 127.0.0.1:7002
$ redis-cli -p 7002 set baz bar
OK

If you have a smart client already, it can automatically follow the redirection.

It was my first time playing with Redis Cluster and there is a lot more to it. If you’re interested, see the Cluster tutorial, the Cluster specification or read the source code. If you had the time to play with Redis Cluster, are already using it or planning to use it, I’m interested to here about your use case. Just drop me a message via Twitter, mail (janerik at fnordig dot de) or directly to the Redis mailing list.

Don't set an empty root password on Chrome OS

(by )

So I got this Chromebook in Developer Mode and wanted to set a root password to atleast protect it a little.

Easy:

sudo chromeos-setdevpasswd

Oh, wait. You pressed enter twice here? Backup your data and reset the device.

This is what chromeos-setdevpasswd does:

#!/bin/sh

mkdir -p /mnt/stateful_partition/etc
echo "chronos:$(openssl passwd -1)" > /mnt/stateful_partition/etc/devmode.passwd

openssl does not care that you just used an empty password, atleast if you also verify it. But so do su and sudo, which means you won’t be able to get root rights again.

But it’s Chrome OS after all, so most things are stored in your Google profile anyway, resetting and restoring the thing is done easily.