Monday, February 21, 2011

memcachedのstats slabsを解析するRubyスクリプト

memcachedのstats slabsの項目名は直感的でない。

例えば、
free_chunksは、delete等されて再利用可能なチャンク数
free_chunks_endが最後にアロケートされたページで一度もsetされていないチャンク数
とかは、memcachedのソースを読んでやっと意味がわかった。

また、チューニングの際に必要な、アラインメントによる無駄領域の合計がぱっと見でわからなかったりする。

とういことで、
memcachedのstats slabs統計情報を解析するRubyスクリプトを張り付けておく。

# テキストプロトコルにしか対応してません。
# バイナリプロトコル専用のmemachedへは、rubyのmemcachedライブラリを使うように改造すりゃできる。


起動オプション
Usage:
./better_stats_slabs.rb -d /path_to_dir
or ./better_stats_slabs.rb -f /path_to_file
or ./better_stats_slabs.rb -h localhost:11211,localhost11222

Byte表示  オプションなし(デフォルト)
KiloByte表示 -k
MegaByte表示 -m
GigaByte表示 -g

出力結果

出力説明

STAT1..の行はスラブクラスごとの情報、下のtotalは全体の情報。
数字は全部サイズ。(byte, kB, MB GBの切り替えはオプションで可能)

空き領域が0のスラブクラスの先頭にはアスタリスクを表示している。
どのスラブでout of memoryが発生しているか、が分かる。

never_usedは、free_chunks_endのサイズ合計であり、最後に割り当てられたスラブ(ページ)の空き領域
reusableは、free_chunksのサイズ合計であり、delete済みのチャンク数合計
free_totalは、never_usedと、reusableの合計。つまり、そのスラブの空き領域合計サイズ。
free_totalが0だと、次にそのスラブクラスにsetした際にmallocされるってこと。(-Lオプションつけない場合)

item_sizeは、アラインメントを意識したアイテムの平均サイズの合計
wastedは、アラインメントを意識したアイテムの平均無駄サイズの合計
item_size + wastedが使用中チャンクサイズの合計です。
チューニング時にgrowth_factorを決める際に参考にできる。

total mallocは、スラブ用領域に割り当てられたサイズの合計、
total free sizeは空き領域合計
total ued sizeは使用中チャンクサイズ合計
items sizeの割合は、スラブ用メモリ領域全体のうちのアイテム本体のサイズが占める割合
wasted sizeの割合は、スラブ用メモリ領域全体のうちの無駄領域のサイズが占める割合


ソース
  1. #!/usr/bin/ruby  
  2. # encoding: UTF-8  
  3.   
  4. def comma(number)  
  5.   number.to_s.reverse.gsub(/(\d{3})(?=\d)/, '\1,').reverse  
  6. end  
  7.   
  8. def percent(numerator, denominator)  
  9.   (denominator == 0 ? "- " : (100 * numerator / denominator).to_s).rjust(3)  
  10. end  
  11.   
  12. alias :org_printf :printf  
  13. def printf(fmt, *args)  
  14.   org_printf(fmt, *args.map{|a| a.is_a?(Numeric) ? a / $options[:unit_scale] : a})  
  15. end  
  16.   
  17. def stats_slabs(host_port)  
  18.   host, port = host_port.split(":").first, host_port.split(":").last  
  19.   lines = []  
  20.   begin  
  21.     TCPSocket.open(host, port) do |s|  
  22.       s.puts "stats slabs"  
  23.       while "END" != (line = s.gets.chop)  
  24.         lines << line  
  25.       end  
  26.     end  
  27.   rescue => e  
  28.     puts "counld not connect to #{host_port}"  
  29.     puts e.message  
  30.   end  
  31.   lines  
  32. end  
  33.   
  34. def parse(lines)  
  35.   chunks_stats = []  
  36.   lines.each do |line|  
  37.     case line  
  38.       when /^STAT (\d+).*:chunk_size (\d+)/  
  39.         chunks_stats << {no: $1, size: $2.to_i,  
  40.           previous_size: chunks_stats.last ? chunks_stats.last[:size].to_i : 0 }  
  41.       when /^STAT.*:total_chunks (\d+)/  
  42.         chunks_stats.last[:total_chunks] = $1.to_i  
  43.       when /^STAT.*:used_chunks (\d+)/  
  44.         chunks_stats.last[:used_chunks] = $1.to_i  
  45.       when /^STAT.*:free_chunks_end (\d+)/  
  46.         chunks_stats.last[:free_chunks_end] = $1.to_i  
  47.       when /^STAT.*:free_chunks (\d+)/  
  48.         chunks_stats.last[:free_chunks] = $1.to_i  
  49.     end  
  50.   end  
  51.   chunks_stats  
  52. end  
  53.   
  54. def calc_and_print(chunks_stats)  
  55.   
  56.   total_malloced = 0 # total size of all chunks.  
  57.   
  58.   total_free_size = 0 # total size of free chunks.  
  59.   total_used_size = 0 # total size of used chunks.  
  60.   
  61.   total_items_size_about = 0 # total size of items.  
  62.   total_waste_size_about = 0 # total size of wasted spaces by align.  
  63.   
  64.   puts "(unit: #{$options[:unit]})"  
  65.   chunks_stats.each_with_index do |stat, i|  
  66.   
  67.     total_malloced += (stat[:size] * stat[:total_chunks])  
  68.   
  69.     # The number of free chunks in a subclass = free_chunks_end + free_chunks  
  70.     sum_unused_size = stat[:size] * (stat[:free_chunks_end])   # chunks has not used yet.  
  71.     sum_reusable_size = stat[:size] * (stat[:free_chunks])     # deleted chunks.  
  72.     sum_free_size = sum_unused_size + sum_reusable_size  
  73.     total_free_size += sum_free_size  
  74.   
  75.     used_size = stat[:size] * stat[:used_chunks]  
  76.     total_used_size += used_size  
  77.   
  78.     # The average of wasted size(unused space) of a chunk.  
  79.     agv_wasted_size_per_chunk = (stat[:size] - stat[:previous_size] ) / 2  
  80.   
  81.     sum_wasted_size = agv_wasted_size_per_chunk * stat[:used_chunks]  
  82.     total_waste_size_about += sum_wasted_size  
  83.   
  84.     sum_items_size = (stat[:size] - agv_wasted_size_per_chunk) * stat[:used_chunks]  
  85.     total_items_size_about += sum_items_size  
  86.   
  87.     printf(" #{sum_free_size == 0 ? "*" : " "} STAT %2d(#{stat[:size].to_s.rjust(4)}) | never_used: %10d reusable: %10d free_total: %10d | item_size : %10d (#{percent(sum_items_size, used_size)}%%) wasted: %10d (#{percent(sum_wasted_size, used_size)}%%)\n", stat[:no],  sum_unused_size, sum_reusable_size, sum_free_size, sum_items_size, sum_wasted_size)  
  88.   end  
  89.   
  90.   puts ""  
  91.   printf(" total malloced  : %11d #{$options[:unit]}\n", total_malloced)  
  92.   printf(" total free size : %11d #{$options[:unit]}(#{percent(total_free_size, total_malloced)}%%)\n", total_free_size)  
  93.   printf(" total used size : %11d #{$options[:unit]}(#{percent(total_used_size, total_malloced)}%%)\n", total_used_size)  
  94.   printf("     items size ≈ %12d #{$options[:unit]}(#{percent(total_items_size_about, total_malloced)}%%)\n", total_items_size_about)  
  95.   printf("    wasted size ≈ %12d #{$options[:unit]}(#{percent(total_waste_size_about, total_malloced)}%%)\n", total_waste_size_about)  
  96. end  
  97.   
  98. def parse_calc_print(header, lines)  
  99.   chunks_stats = parse(lines)  
  100.   puts "-" * 5 + header + "-" * 130  
  101.   return if chunks_stats.empty?  
  102.   calc_and_print chunks_stats  
  103. end  
  104.   
  105. Usage = "Usage:  
  106.                ./better_stats_slabs.rb -d /path_to_dir  
  107.             or ./better_stats_slabs.rb -f /path_to_file  
  108.             or ./better_stats_slabs.rb -h localhost:11211,localhost11222  
  109.   
  110.             Byte     ./better_stats_slabs.rb -d /path_to_dir  
  111.             KiloByte ./better_stats_slabs.rb -d /path_to_dir -k  
  112.             MegaByte ./better_stats_slabs.rb -d /path_to_dir -m  
  113.             GigaByte ./better_stats_slabs.rb -d /path_to_dir -g  
  114.         "  
  115. $options = {unit: "Byte", unit_scale: 1}  
  116. require 'optparse'  
  117. OptionParser.new{|opt|  
  118.   Version = "0.1"  
  119.   opt.banner = Usage  
  120.   opt.on("-k""kB""KilloByte"do  
  121.     $options[:unit] = "kB"  
  122.     $options[:unit_scale] = 1024  
  123.   end  
  124.   opt.on("-m""MB""MegaByte"do  
  125.     $options[:unit] = "MB"  
  126.     $options[:unit_scale] = 1024 ** 2  
  127.   end  
  128.   opt.on("-g""GB""GigaByte"do  
  129.     $options[:unit] = "GB"  
  130.     $options[:unit_scale] = 1024 ** 3  
  131.   end  
  132.   opt.on("-f filepath""a file which had saved 'stats slabs'."do |file|  
  133.     $options[:file] = file  
  134.   end  
  135.   opt.on("-d dir_path""a dir path wihch has 'stats slabs' files."do |dir|  
  136.     $options[:dir] = dir  
  137.   end  
  138.   opt.on("-h localhost:11211,localhost11222""Host:Port of memcached process. ex. localhost:11211,localhost:11212"do |hs|  
  139.     $options[:hosts_and_ports] = hs  
  140.   end  
  141.   opt.parse!(ARGV)  
  142. }  
  143.   
  144. if file = $options[:file]  
  145.     lines = File.readlines(File.expand_path file)  
  146.     parse_calc_print(file, lines)  
  147. elsif dir = $options[:dir]  
  148.     Dir.glob("#{dir}/*"do |path|  
  149.       lines= File.readlines(File.expand_path path)  
  150.       parse_calc_print(path, lines)  
  151.     end  
  152. elsif hs = $options[:hosts_and_ports]  
  153.     require 'socket'  
  154.     host_port_array = hs.split(",").map{|h| h.strip}  
  155.     host_port_array.each do |h|  
  156.       lines = stats_slabs(h)  
  157.       parse_calc_print(h, lines)  
  158.     end  
  159. else  
  160.   puts Usage  
  161. end  

Thursday, February 17, 2011

動作中のmemcachedのログ出力レベルをGDBで無理やり変更する方法

memcached起動オプションで、-vvvをつけると標準エラー出力にログが表示される。
(-vvvオプションの詳細は、こことか詳しい。)

デバッグ目的で、起動中memcachedプロセスのログレベルをコマンドで変更したかったのだけど、動的にログレベルを変更するコマンドが見当たらない。

コマンドで用意されてなけりゃ、GDBで。
ということで、GDBでmemcachedプロセスにアタッチしてログ出力モード用の変数を無理やり変更したらできました(笑)

以下、手順を書いときます。


memcachedを-vつけずに起動(デバッグログ非表示モード)
kanbe@kanbe-laptop% ./memcached -p 11211 -r -B auto -C -m 10 -M -f 1.25 -I 1000000 -t 24 -c 256 -R 20

この状態で、telnetから適当にsetする。
memcachedプロセスの標準エラー出力には何も表示されない。


GDBでアタッチ

デバッグレベル用変数は、settings.verbose

verbose levelを最強にしてみる。(memcached起動オプションの-vvvと同じ)

(gdb) whatis settings
type = struct settings
(gdb) ptype settings
type = struct settings {
  size_t maxbytes;
  int maxconns;
  int port;
  int udpport;
  char *inter;
  int verbose;
  rel_time_t oldest_live;
  int evict_to_free;
  char *socketpath;
  int access;
  double factor;
  int chunk_size;
  int num_threads;
  char prefix_delimiter;
  int detail_enabled;
  int reqs_per_event;
  _Bool use_cas;
  enum protocol binding_protocol;
  int backlog;
  int item_size_max;
  _Bool sasl;
}
(gdb) p settings.verbose
$3 = 0
(gdb) set write on
(gdb) set settings.verbose = 3
(gdb) p settings.verbose
$4 = 3
(gdb) c
Continuing.

この状態でもう一回telnetからsetする
set ddddddddddddddddd 0 0 1
a
STORED

memcachedの標準エラー出力に以下が表示される
159: going from conn_read to conn_parse_cmd
<159 set ddddddddddddddddd 0 0 1 159: going from conn_parse_cmd to conn_nread > NOT FOUND ddddddddddddddddd
>159 STORED
159: going from conn_nread to conn_write
159: going from conn_write to conn_new_cmd
159: going from conn_new_cmd to conn_waiting
159: going from conn_waiting to conn_read

動いてるmemcachedプロセスのログレベルを変更できた!


参考

プログラムへのパッチ適用

実行中のmemcachedプロセスをGDBでdebugする方法

アタッチするプロセス番号を取得
kanbe@kanbe-laptop% ps -aux |grep memcached
kanbe 26951 0.2 0.0 622312 1376 pts/1 Sl+ 11:34 0:00 ./memcached -vvv -p 11211 -r -B auto -C -m 10 -M -f 1.25 -I 1000000 -t 24 -c 256 -R 20 -L

process番号は26951

アタッチしてブレイクポイントをセット
cd /path/to/memcached_install_dir/bin
sudo gdb memcached
(gdb) attach 26951
(gdb) b slabs_alloc
(gdb) c
Continuing.
別端末からtelnetで適当にset
kanbe@kanbe-laptop% telnet localhost 11211
Trying 127.0.0.1...
Connected to localhost.localdomain.
Escape character is '^]'.
set key 1 0 0 1
gdb上で該当threadに切り替わり、セットしたブレイクポイントのとこで止まる
[Switching to Thread 0x7f9b5adbd700 (LWP 26952)]
Breakpoint 1, slabs_alloc (size=60, id=1) at slabs.c:421
421 void *slabs_alloc(size_t size, unsigned int id) {

あとは、煮るなり焼くなり。

デタッチ
(gdb) detach
Detaching from program: /home/kanbe/work/memcached/bin/memcached, process 26951
!!!!!!!!!! 注意点 !!!!!!!!

attachした状態でrun, quitすると、memcachedプロセスが止まってしまう!!
(一応ほんとにプロセス止めるの?っていう確認メッセージが出る)

gdbを終了するときはdetachしてからquitで。

以下、既に実行中のプロセスのデバッグより引用

detach
アタッチされたプロセスのデバッグが終了した場合には、 detachコマンドを使用してそのプロセスをGDBの管理から解放することができます。 プロセスからディタッチしても、 そのプロセスは実行を継続します。 detachコマンド実行後は、 ディタッチされたプロセスと GDBは互いに完全に依存関係がなくなり、 attachコマンドによる別のプロセスへのアタッチや、 runコマンドによる別のプロセスの起動が可能になります。 detachコマンドを実行後RETキーを押しても、 detachコマンドは再実行されません。

プロセスがアタッチされている状態で、 GDBを終了したりrunコマンドを使用したりすると、 アタッチされたプロセスを終了させてしまいます。 デフォルトの状態では、 このようなことを実行しようとすると、 GDBが確認を求めてきます。 この確認処理を行うか否かは、 set confirmコマンドで制御可能です (オプションの警告およびメッセージ参照)。

参考ページ

Debugging with GDB

Friday, February 11, 2011

python: Listから重複を無くす

>>> L = [1, 2, 1, 3, 2, 4, 5]
>>> set(L)
{1, 2, 3, 4, 5}
>>> L = list(set(L)) # Remove duplicates
>>> L
[1, 2, 3, 4, 5]

Lerning Python 4th P138

Wednesday, December 22, 2010

Rails3で動的にログレベルを変更する

Rails3で大量データをBulkInsertで、大量データをActiveRecord経由でInsertしまくったんだけどさ、log/devlelopment.logみたらなんだかこんなwarningが大量に吐かれてるんですよ。

WARNING: Can't mass-assign protected attributes: column_id

importした行数分。

こりゃいかんということでちょっと調べたけど、わがらながったのでさ、
めんどくせぇからImportの時だけ一時的にログレベルを変更するという外道的解決をした時のメモ。

Rails.logger.levelを変えたらできました。

Rails.logger.level = 0 ... debug
Rails.logger.level = 3 ... error
ほかは調べてないけど、ログファイル見ながらlevelをかえれば分かるはず。

Rails3で大量データをBulkInsert

import元のOracleからActiveRecord経由で大量データをimportするときに
Model.create とかModel.new -> Model.saveだとSQLがマシンガンのようにながれまくるので、いつまで待っても終わらない。

そりゃ、SQL一発でバルクインサートでしょうってことで、このへんをみながらやってみた。
activerecord-import
Bulk insertion of data with ActiveRecord

log/development.logを見ながら確認したんだけど、
SQLiteだとバルクインサート的に書いても、SQLが連発される。
MySQLにしたらInsert文が1発のみだった。

Saturday, November 13, 2010

S25

S-99: Ninety-Nine Scala Problemsを試してみる。
勉強のためにListのAPIはなるべく使わない方向。

  1. // P25 (*) Generate a random permutation of the elements of a list.  
  2. // Hint: Use the solution of problem P23.  
  3. // Example:  
  4. // scala> randomPermute(List('a, 'b, 'c, 'd, 'e, 'f))  
  5. // res0: List[Symbol] = List('b, 'a, 'd, 'c, 'e, 'f)  
  6.   
  7. // P20 (*) Remove the Kth element from a list.  
  8. def removeAt[T](i: Int, xs: List[T]) = {  
  9.   def r(i: Int, xs: List[T], acc: List[T]): (List[T], T) = (i, xs) match {  
  10.     case (0, h :: t) => (acc.reverse ::: t, h)  
  11.     case (i, h :: t) => r(i - 1, t, h :: acc)  
  12.   }  
  13.   if(i < 0 || xs.size <= i) throw new NoSuchElementException else r(i, xs, Nil)  
  14. }  
  15.   
  16. import scala.util.Random  
  17. def randomPermute[T](xs: List[T]) = {  
  18.   val rand = new Random  
  19.   def r(ys: List[T], acc: List[T]): List[T] = {  
  20.     if(ys.size == 1) ys.head :: acc  
  21.     else {  
  22.       val (rest, removed) = removeAt(rand.nextInt(ys.size), ys)  
  23.       r(rest, removed :: acc)  
  24.     }  
  25.   }  
  26.   if(xs.isEmpty) Nil else r(xs, Nil)  
  27. }  
解答例
またもや、してやられたぜ!