Code for Concinnity

Slow batch insert with MongoDB sharding and how I debugged it

Now this title sounds fairly technical and seems to belong in a bug ticket rather than a general blog post. But I want to write about it anyway because it took me a couple of hours to find out and it highlights how immature MongoDB in general is. In the end I give a solution that solves the issue so you can still get performance with sharding+batch insert.

So here we go:

A couple of weeks ago I was hanging out at the #mongodb IRC channel and troubleshooting performance issue with a guy. So he had a beefy 32 GB server with 8 cores but it was taking 20 seconds for him to insert 20000 documents as simple as this:

{ t: "2013-06-23", n: 7, a: 1, v: 0, j: "1234" }

So I wrote a quick script (included below) to try it on my MacBook Pro with SSD, and I was able to get results like this:

20000 documents inserted
Took 580ms
34482.75862068966 doc/s

So something must be wrong with his configuration / code, I thought, and I kept telling him to just run my code on his machine.

Turns out it’s due to MongoDB sharding failing with batch inserts

So it turns out performance dropped drastically also for me after I enabled sharding:

20000 documents inserted
Took 15701ms
1273.8042162919558 doc/s

The test set up

Here’s what I used to test:

3 config servers
8 shards, sharding on { _id: "hashed" }
All on localhost

Here is the setup script I used to create 8 shards on my localhost. (By the way, setting up sharding is painful)

The test script

The test script is as simple as possible — just a normal batch insert:

// Quite a lot of orchestration
var count0 = db.foos.find().count();
var t0 = Date.now();
 
var docs = [];
 
for(var i = 0; i < 20000; i++) {
  docs.push({ t: "2013-06-23", n: 7 * i, a: 1, v: 0, j: "1234" });
}
 
// And actually just these couple of lines are the real action
db.foos.insert(docs);
db.getLastError();
 
var t1 = Date.now();
var count1 = db.foos.find().count();
 
var took = t1 - t0;
var count = count1 - count0;
var throughput = count / took * 1000;
 
print(count + " documents inserted");
print("Took " + took + "ms");
print(throughput + " doc/s");

How I systematically discovered the problem

By passing the -v option to mongod and doing something like tail -f mongolab/**/*.log, I saw tons of logs like this:

==> mongolab/sh5/mongo.log <==
Sun Aug 18 10:12:23.136 [conn2] run command admin.$cmd { getLastError: 1 }
Sun Aug 18 10:12:23.136 [conn2] command admin.$cmd command: { getLastError: 1 } ntoreturn:1 keyUpdates:0  reslen:67 0ms

==> mongolab/sh6/mongo.log <==
Sun Aug 18 10:12:23.136 [conn2] run command admin.$cmd { getLastError: 1 }
Sun Aug 18 10:12:23.136 [conn2] command admin.$cmd command: { getLastError: 1 } ntoreturn:1 keyUpdates:0  reslen:67 0ms

==> mongolab/sh7/mongo.log <==
Sun Aug 18 10:12:23.137 [conn2] run command admin.$cmd { getLastError: 1 }
Sun Aug 18 10:12:23.137 [conn2] command admin.$cmd command: { getLastError: 1 } ntoreturn:1 keyUpdates:0  reslen:67 0ms

...

So mongos is splitting up the batch insert into individual inserts and donig it one by one, with a getLastError() accompanying each of them!

How to prove that it’s related to batch insert

I changed my test script to do sequential insert, and it worked out fine (note that this is still slower than non-sharded batch insert):

20000 documents inserted
Took 1746ms
11454.75372279496 doc/s

The moral of the lesson is that if you shard — you should benchmark very carefully if you do batch inserts.

So can I shard and still get good batch insert performance?

I figured out a way to still get good batch insert performance by using a numeric (instead of hashed) shard key:

sh.shardCollection("shard_test.foos", {rnd: 1})
Pre-chunk the collection on rnd
On each document, generate the rnd key db.foos.insert({ rnd: _rand(), t: ...
Before inserting the documents, sort the doucment array so that mongos will only send N batch inserts, if you have N shards

(The code to do all this is available in GitHub, to avoid flooding this post with code snippets)

So instead of letting mongos calculate and sort the hash keys before sending the inserts, I have to do this all by myself. This is fairly basic and I am totally shocked that it could have been solved just like that.

The last step (sorting) is also required. Apparently mongos is not smart enough to sort the batch insert to optimize its own operation.

Benchmark Summary

Time in ms (lower is better).
                       No-Shard     No-Shard (with rnd)     Shard { id: "hashed" }  Shard { rnd: 1 }
Batch insert           640      740                     21038                   1004
Normal               1404       1468                    1573                      1790
(sequential) insert

Note that even with the rnd insert is still slower than the non-sharded version. Granted I sharded all on a single machine but this about shows the general non-zero overhead of sharding.

Published by kizzx2, on August 18th, 2013 at 11:49 am. Filled under: Uncategorized • No Comments

Thunderbird hanging with 100% CPU usage — culprit discovered — the Google Contacts add-on

Several months ago I started using the Google Contacts add-on for Thunderbird and it’s been hanging periodically ever since. I just thought it’s Thunderbird and tried all those compacting folder, resetting the cache thing.

Today it hang again and I was frustrated, so I did dtruss (strace) on it and found that it seemed to be stuck in an infinite loop trying to access my Google contact feed.

I replaced it with the gContactSync add-on and it’s working smoothly now.

Published by kizzx2, on May 6th, 2013 at 9:35 pm. Filled under: Uncategorized • No Comments

Windows takes 10+ minutes to boot with black screen — Solved!

Just a quick note for anyone struggling with this. This is talking about the infamous case after the Windows logo, there is a black screen for 10 minutes until Windows shows the welcome screen. Caps Lock key is unresponsive during that time.

After struggling on and off for a couple of weeks, the culprit was discovered to be a freaking font file!

Failing with Windows EFS

It turned out that when I installed .otf files from my Desktop, which is EFS encrypted, the font files copied to C:\Windows\Fonts appeared to be encrypted as well. Because the Windows system doesn’t have the EFS key, it would stall in the black screen trying and failing to decrypt the file.

How I solved it

Just decrypt the files before installing them, duh!

Published by kizzx2, on May 6th, 2013 at 9:35 pm. Filled under: Uncategorized • No Comments

Install R <= 2.13 with Homebrew

Probably Homebrew has changed much since then, with Superenv and stuff. If you are stuck at an old R version and need to install it using Homebrew, you need to add depends_on :x11 to /usr/local/Library/Formula/r.rb, like so:

# /usr/local/Library/Formula/r.rb
class R < Formula
  url 'http://cran.r-project.org/src/base/R-2/R-2.13.1.tar.gz'
  homepage 'http://www.r-project.org/'
  md5 '28dd0d68ac3a0eab93fe7035565a1c30'
 
  depends_on 'valgrind' if valgrind?
  depends_on :x11 # Add this line
 
  def options
    [
      ['--with-valgrind', 'Compile an unoptimized build with support for the Valgrind debugger.']
    ]
  end
 
 
# ...

Published by kizzx2, on April 25th, 2013 at 11:29 am. Filled under: Uncategorized • No Comments

tmux-sync — Open a dozen of synchronized tmux panes easily

While managing server clusters I often want to open SSH session to a dozen of machines and have them run the same set of commands, interactively. So I wrote tmux-sync to do this:

tmux-sync my-session 'ssh host1' 'ssh host2' 'ssh host3' 'ssh host4'

The above command drops you into a tmux session like below. Your input will be sent to all the panes in tmux:

The source code:

#!/bin/sh # # The MIT License (MIT) # # Copyright (c) 2013 Chris Yuen # # Permission is hereby granted, free of charge, to any person obtaining a copy # of this software and associated documentation files (the "Software"), to deal # in the Software without restriction, including without limitation the rights # to use, copy, modify, merge, publish, distribute, sublicense, and/or sell # copies of the Software, and to permit persons to whom the Software is # furnished to do so, subject to the following conditions: # # The above copyright notice and this permission notice shall be included in # all copies or substantial portions of the Software. # # THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR # IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, # FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE # AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, # OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE # SOFTWARE. set -e if [ $# -lt 2 ] then echo "Usage: $0 [session_name] [command_1]..." exit 1 fi session=$1 shift tmux start-server tmux new -d -s $session on_error() { tmux kill-session -t $session } trap on_error ERR cmd1=$1 shift tmux send -t $session:0 "$cmd1" C-m for i in "$@" do tmux splitw -t $session -l 1 tmux send -t $session:0.1 "$i" C-m tmux selectp -t $session:0.0 tmux selectl -t $session tiled done tmux setw synchronize-panes on tmux a -t $session

Published by kizzx2, on February 8th, 2013 at 10:28 pm. Filled under: Uncategorized • No Comments

A Clean Approach to Partial Object Validation with Rails + Wicked Wizard

This is cleaner than the official method IMO, because it involves zero / minimal model object modification. The wizard logic clearly belongs to the controller only.

The basic ideas are:

Derive from the ActiveRecord
Override save to make Wicked behave. You can do arbitrarily complex thing there without wrangling with validation conditions.

Here’s the code:

class Post < ActiveRecord::Base attr_accessible :body, :price, :title validates_presence_of :title validates_length_of :title, minimum: 10 validates_presence_of :body validates_numericality_of :price, greater_than: 0 endclass PostWizardController < ApplicationController include Wicked::Wizard steps '1_title', '2_body', '3_price' # Define partial validation in a clear tabular format VALIDATIONS = { '1_title' => [:title], '2_body' => [:title, :body], '3_price' => [:title, :body, :price], }.freeze # Here PartialPost is a private property of this controller not shared in any # other part of the code so we make it a nested class. class PartialPost < Post attr_accessor :step # For message passing only attr_accessor :session def self.model_name Post.model_name end def save # In the last step, actually persist to database if self.step == VALIDATIONS.keys.last rv = super session.delete(:post_wizard) if rv self.session = nil return rv end # Clear out the session because we can't save session within session self.session = nil # Trigger ActiveRecord's validation self.valid? (self.errors.messages.keys - VALIDATIONS[self.step]).each do |k| self.errors.messages.delete(k) end # Insert complicated custom validation manipulation here self.errors.empty? end end def index session[:post_wizard] ||= {} session[:post_wizard][:post] = PartialPost.new redirect_to wizard_path(steps.first) end def show if session[:post_wizard].try(:[], :post).present? @post = session[:post_wizard][:post] end render_wizard end def update @post = session[:post_wizard][:post] @post.attributes = params[:post] @post.step = step @post.session = session render_wizard(@post) end end

Here is another version using a partial flag to persist the partial object in database:

class Post < ActiveRecord::Base attr_accessible :body, :price, :title validates_presence_of :title validates_length_of :title, minimum: 10 validates_presence_of :body validates_numericality_of :price, greater_than: 0 endclass PostWizardController < ApplicationController include Wicked::Wizard steps '1_title', '2_body', '3_price' VALIDATIONS = { '1_title' => [:title], '2_body' => [:title, :body], '3_price' => [:title, :body, :price], }.freeze # Here PartialPost is a private property of this controller not shared in any # other part of the code so we make it a nested class. class PartialPost < Post attr_accessor :step attr_accessor :session def self.model_name Post.model_name end def save # Trigger ActiveRecord's validation rv = super(validate: false) if rv && self.step == VALIDATIONS.keys.last self.partial = false rv = super session.delete(:post_wizard) if rv rv else self.valid? (self.errors.messages.keys - VALIDATIONS[self.step]).each do |k| self.errors.messages.delete(k) end # Insert complicated custom validation manipulation here self.errors.empty? end end end def index post = Post.new post.save(validate: false) session[:post_wizard] ||= {} session[:post_wizard][:post_id] = post.id redirect_to wizard_path(steps.first) end def show if session[:post_wizard].try(:[], :post_id).present? @post = PartialPost.find(session[:post_wizard][:post_id]) end render_wizard end def update @post = PartialPost.find(session[:post_wizard][:post_id]) @post.attributes = params[:post] @post.step = step @post.session = session render_wizard(@post) end end

Published by kizzx2, on February 6th, 2013 at 11:00 pm. Filled under: Uncategorized • No Comments

Performance benchmark for Windows EFS, and BoxCryptor

Didn’t have the time to do a very serious benchmark but in case this is useful:



Some SSD, unencrypted

$ dd if=/dev/zero of=zero bs=500M count=1
1+0 records in
1+0 records out
524288000 bytes (524 MB) copied, 4.42172 s, 119 MB/s

Some SSD, with EFS

$ dd if=/dev/zero of=zero bs=500M count=1
1+0 records in
1+0 records out
524288000 bytes (524 MB) copied, 13.4115 s, 39.1 MB/s

Some SATA HDD, unencrypted

$ dd if=/dev/zero of=zero bs=500M count=1
1+0 records in
1+0 records out
524288000 bytes (524 MB) copied, 8.64324 s, 60.7 MB/s

Some SATA HDD, BoxCryptor

$ dd if=/dev/zero of=zero bs=500M count=1
1+0 records in
1+0 records out
524288000 bytes (524 MB) copied, 17.8249 s, 29.4 MB/s

Another run using a Mac with some SSD hard disk. CoreStorage vs. TrueCrypt vs BoxCryptor:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23

Unencrypted, SSD

$ dd if=/dev/zero of=zero bs=500m count=1
1+0 records in
1+0 records out
524288000 bytes transferred in 1.431038 secs (366 MB/sec)

CoreStorage (AES-XTS, default), SSD

$ dd if=/dev/zero of=zero bs=500m count=1
1+0 records in
1+0 records out
524288000 bytes transferred in 3.975945 secs (131 MB/sec)

TrueCrypt (AES-XTS, default), SSD

$ dd if=/dev/zero of=zero bs=500m count=1
1+0 records in
1+0 records out
524288000 bytes transferred in 3.984627 secs (131 MB/sec)

BoxCryptor, SSD

$ dd if=/dev/zero of=zero bs=500m count=1
1+0 records in
1+0 records out
524288000 bytes transferred in 8.353867 secs (62 MB/sec)

Published by kizzx2, on February 5th, 2013 at 1:44 am. Filled under: Uncategorized • No Comments

“One-click” Rakefile to build .framework for iOS

This technique is based on Jeff Verkoeyen’s method. I find that modifying .xcodeproj files to be rather inconvenient so I whipped up a Rakefile that can be easily copied and pasted into new projects:

# This assumes you have placed your public header files in the `Headers` # directory in your output directory. You can satisfy that easily by creating a # "Copy Files" build phase. See # http://image.bayimg.com/9cf4804007f7a7b59505de345ad2bbc388499475.jpg # Usage: # # 1. Change `PROJECT_NAME` below. E.g. if you have `Calculator.xcodeproj`, change it to `"Calculator"` # 2. Put this beside your `.xcodeproj` file, then just run `rake` task :default => :build SDKS = %w(iphonesimulator iphoneos).freeze CONFIGS = %w(Debug Release).freeze BUILD_DIR = "build".freeze PROJECT_NAME = "MyCoolFramework".freeze def run(command) puts "> #{command}" system(command) fail "Command \`#{command}\` failed with exit status #{$?}" if !$?.success? end task :build do CONFIGS.each do |config| fat_lib = File.join(BUILD_DIR, config, "lib#{PROJECT_NAME}.a") FileUtils.mkdir_p(File.join(BUILD_DIR, config)) SDKS.each do |sdk| run "xcodebuild -sdk #{sdk} -configuration #{config}" end inputs = SDKS.map do |sdk| File.join(BUILD_DIR, "#{config}-#{sdk}", "lib#{PROJECT_NAME}.a") end run "lipo -create #{inputs.join(' ')} -output #{fat_lib}" end CONFIGS.product(SDKS).each do |config, sdk| fat_lib = File.join(BUILD_DIR, config, "lib#{PROJECT_NAME}.a") headers_dir = File.join(BUILD_DIR, "#{config}-#{sdk}", "Headers") framework_dir = File.join(BUILD_DIR, config, "#{PROJECT_NAME}.framework") version_a_dir = File.join(framework_dir, "Versions", "A") FileUtils.mkdir_p(version_a_dir) FileUtils.cp_r(headers_dir, version_a_dir, :preserve => true) FileUtils.cp(fat_lib, File.join(version_a_dir, PROJECT_NAME)) FileUtils.rm_f(File.join(framework_dir, "Versions", "Current")) FileUtils.ln_sf("A", File.join(framework_dir, "Versions", "Current")) FileUtils.rm_f(File.join(framework_dir, "Headers")) FileUtils.rm_f(File.join(framework_dir, PROJECT_NAME)) FileUtils.ln_sf(File.join("Versions", "Current", "Headers"), framework_dir) FileUtils.ln_sf(File.join("Versions", "Current", PROJECT_NAME), framework_dir) end end

Published by kizzx2, on December 17th, 2012 at 12:50 pm. Filled under: Uncategorized • No Comments

Ultimate Mac keyboard trick

After two years of using Mac, I just discovered the wonder of the Help menu item.

⌘ + /

If you are like me and regard yourself as a “pro” user you’d probably discard Help as something you’ll never need. But the fact is that you can access every menu item from the search field:

I have always thought that Windows does a better job at serving “pro” users due to menu access shortcuts (Alt + something). This thing from Mac is arguably more hacker friendly.

Published by kizzx2, on December 7th, 2012 at 9:14 pm. Filled under: Uncategorized • No Comments

Vim keybindings in Xcode

Finally @JugglerShu stepped up and wrote the wonderful XVim. I just have the spread the word and personally report that it worked right out of the box. Thanks JugglerShu!

Published by kizzx2, on November 26th, 2012 at 11:30 pm. Filled under: Uncategorized • No Comments

« Older Entries

Newer Entries »