selmertsxの素振り日記

ひたすら日々の素振り内容を書き続けるだけの日記

AWS Startup Tech で話してきた

10/19 にAWS Startup Tech で30分間話してきました。

内容は Kinesis Firehose, Athena, QuickSightで行動ログ分析できるようにしたというお話しです。Kinesis Firehoseは、スケーラビリティに着目されることが多いですが、簡便性やコストの安さ価値の一つだよ!ということをお話ししてきました。

Kinesis Firehose、Athena、QuickSightについてお金が掛かるポイントをまとめたので、よかったら見てやってください。 Kinesis Analyticsや Glueについては、今後検討していきたいっすな。

speakerdeck.com

browserify 及び gulpの知識整理

最初に

将来的に、browserify => webpackに移行するだろうけれども、 現在の構成を正しく把握するために、メモとして残しておく。

browserifyとは

browserifyは、JavaScriptにおいて依存関係の解決を行うツール。 ES6においては、modulesの仕様が策定されているが、 対応している環境は少ないのでそれをなんとかするために使う必要がある。

用いるコード

function foo(){
  return 'foo';
}
module.exports = foo;
function bar(){
  return 'bar';
}
module.exports = bar;
var foo = require('./foo');
var bar = require('./bar');
var el = document.getElementById('box');
el.textConent = foo() + ' ' + bar();

browserifyを使ったビルド方法

# mainとなるコードだけビルドすれば良い。
browserify js/main.js -o bundle.js

すると、下記のコードが生成される。

(function e(t,n,r){function s(o,u){if(!n[o]){if(!t[o]){var a=typeof require=="function"&&require;if(!u&&a)return a(o,!0);if(i)return i(o,!0);var f=new Error("Cannot find module '"+o+"'");throw f.code="MODULE_NOT_FOUND",f}var l=n[o]={exports:{}};t[o][0].call(l.exports,function(e){var n=t[o][1][e];return s(n?n:e)},l,l.exports,e,t,n,r)}return n[o].exports}var i=typeof require=="function"&&require;for(var o=0;o<r.length;o++)s(r[o]);return s})({1:[function(require,module,exports){
// bar.js
function bar() {
  return 'bar!';
}
 
module.exports = bar;
 
},{}],2:[function(require,module,exports){
// foo.js
function foo() {
  return 'foo!';
}
 
module.exports = foo;
 
},{}],3:[function(require,module,exports){
// main.js
var foo = require('./foo');
var bar = require('./bar');
var el = document.getElementById('box');
el.textContent = foo() + ' ' + bar();
 
},{"./bar":1,"./foo":2}]},{},[3]);

ということで、mainとなるコードだけbuildすればrequireしているファイルを全て探し、依存を解決してくれる超便利ツールがbrowserifyである。

参考資料

Gulpとは

開発ワークフローの中にある、時間の掛かる苦痛な作業を自動化してくれるツール。 npm moduleを利用して、2000以上のfile変換のためのpluginsが利用できる。 pluginを使えば CoffeeScriptをES5に置き換えたりすることも可能である。

gulpにおけるtaskの例

gulpはファイルをストリームとして扱いながら処理を行う。 例を下記のコードに示す。

// gulp.taskの第一引数はタスク名
gulp.task('sass', function(){
    var stream = gulp.src('sass/.scss')
        .pipe(sass()) // compile
        .pipe(autoprefixer()) // prefixの付与
        .pipe(minify()) // 圧縮
        .pipe(gulp.dest('css')) // 任意の場所に出力
    return stream;
})

このように .pipe() の中に、行いたい処理をまとめて実行することが可能である。

gulpとbrowserifyを使ったtransformの指定

gulpを利用したCoffeeScript => ES5変換方法は下記の用になる。

'use strict';

const gulp = require('gulp');
const browserify = require('browserify');
const babelify = require('babelify');
const fs = require('fs');

const dir = {
    srcJS: "./frontend/js/",
    distJS: "./app/assets/javascripts/",
};

const jsFiles = [
    'a.js',
    'b.js',
]

gulp.task('debug', ['debug_flag', 'build']);
var debuging = false;
gulp.task('debug_flag', function() { debuging = true } );
gulp.task('build', () => {
    jsFiles.forEach(function (file) {
        browserify(dir.srcJS + file, { debug: debuging } )
        .transform(babelify, { presets: ["es2015"] } )
        .bundle()
        .pipe(fs.createWriteStream(dir.distJS + file));
    })
});

isucon6の過去問を解く

やり方

とりあえず、現状自分たちが考えることができる理想的な方法で、過去問を解いてみる。

参考資料

https://speakerdeck.com/fujiwara3/isucon-summer-school-1 https://speakerdeck.com/fujiwara3/isucon-summer-school-2

環境を作る

https://github.com/matsuu/vagrant-isucon

# 1時間以上かかるので、暇な時にやっておくと良い
➜  isucon git clone git@github.com:matsuu/vagrant-isucon.git
➜  vagrant-isucon git:(master) cd ./vagrant-isucon/isucon6-qualifier-standalone
➜  isucon6-qualifier-standalone git:(master) vagrant up

ベンチマークを取ってみる

➜  isucon6-qualifier-standalone git:(master) vagrant ssh
ubuntu@ubuntu-xenial:~$ sudo -i -u isucon
isucon@ubuntu-xenial:~$ cd isucon6q
isucon@ubuntu-xenial:~/isucon6q$ ./isucon6q-bench -target http://127.0.0.1
2017/10/09 11:35:16 start pre-checking
2017/10/09 11:35:22 pre-check finished and start main benchmarking
2017/10/09 11:36:16 benchmarking finished

nginxのプロファイリング

# alpのinstall
root@ubuntu-xenial:~# wget https://github.com/tkuchiki/alp/releases/download/v0.3.1/alp_linux_amd64.zip
root@ubuntu-xenial:~# apt install unzip
root@ubuntu-xenial:~# unzip alp_linux_amd64.zip
root@ubuntu-xenial:~# install ./alp /usr/local/bin/
#ベンチマーク実行
isucon@ubuntu-xenial:~/isucon6q$ cd isucon6q/
isucon@ubuntu-xenial:~/isucon6q$ ./isucon6q-bench -target http://127.0.0.1
#alp実行
root@ubuntu-xenial:~# alp --sum -r -f /var/log/nginx/access_log --aggregates='/keywords/.*'
+-------+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+--------+--------------------------------------------------------+
| COUNT |  MIN  |  MAX  |   SUM   |  AVG  |  P1   |  P50  |  P99  | STDDEV | MIN(BODY)  | MAX(BODY)  |  SUM(BODY)   | AVG(BODY)  | METHOD |                          URI                           |
+-------+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+--------+--------------------------------------------------------+
|    68 | 1.147 | 7.731 | 323.394 | 4.756 | 1.147 | 4.726 | 7.696 |  1.423 |   7894.000 | 108819.000 |  4688744.000 |  68952.118 | GET    | /                                                      |
|   270 | 0.001 | 4.718 | 274.573 | 1.017 | 0.001 | 0.882 | 4.559 |  0.943 | 106015.000 | 106015.000 | 28624050.000 | 106015.000 | GET    | /css/bootstrap.min.css                                 |
|   135 | 0.001 | 4.710 | 137.316 | 1.017 | 0.001 | 0.856 | 4.154 |  0.942 |  28631.000 |  28631.000 |  3865185.000 |  28631.000 | GET    | /js/bootstrap.min.js                                   |
|   135 | 0.001 | 4.711 | 137.077 | 1.015 | 0.000 | 0.868 | 4.152 |  0.942 |  16849.000 |  16849.000 |  2274615.000 |  16849.000 | GET    | /css/bootstrap-responsive.min.css                      |
|   135 | 0.001 | 4.710 | 136.959 | 1.015 | 0.001 | 0.859 | 4.153 |  0.942 |  86351.000 |  86351.000 | 11657385.000 |  86351.000 | GET    | /js/jquery.min.js                                      |
|   135 | 0.001 | 4.709 | 136.811 | 1.013 | 0.000 | 0.872 | 4.150 |  0.943 |   1092.000 |   1092.000 |   147420.000 |   1092.000 | GET    | /favicon.ico                                           |
|   135 | 0.001 | 4.709 | 136.020 | 1.008 | 0.000 | 0.852 | 4.148 |  0.941 |     93.000 |     93.000 |    12555.000 |     93.000 | GET    | /img/star.gif                                          |
|    57 | 0.003 | 3.001 |  63.052 | 1.106 | 0.003 | 1.046 | 3.000 |  0.802 |     25.000 |    335.000 |     2615.000 |     45.877 | POST   | /stars                                                 |
|    67 | 0.001 | 3.006 |  59.732 | 0.892 | 0.001 | 0.714 | 3.001 |  0.779 |      5.000 |    335.000 |     3615.000 |     53.955 | POST   | /login                                                 |
|    41 | 0.032 | 3.002 |  49.207 | 1.200 | 0.032 | 0.969 | 3.001 |  0.886 |      5.000 |    331.000 |     6374.000 |    155.463 | POST   | /keyword

mysqlのプロファイリング

root@ubuntu-xenial:~# vim /etc/mysql/my.cnf
[mysqld]
slow_query_log  = 1
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 0
root@ubuntu-xenial:~# systemctl restart mysql
root@ubuntu-xenial:~# systemctl restart isuda.ruby
root@ubuntu-xenial:~# systemctl restart isutar.ruby
root@ubuntu-xenial:~# head -20 /var/log/mysql/slow.log
/usr/sbin/mysqld, Version: 5.7.19-0ubuntu0.16.04.1-log ((Ubuntu)). started with:
Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
Time                 Id Command    Argument
# Time: 2017-10-09T05:02:00.742015Z
# User@Host: isucon[isucon] @ localhost []  Id:     4
# Query_time: 0.000143  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
use isuda;
SET timestamp=1507525320;
SET SESSION sql_mode='TRADITIONAL,NO_AUTO_VALUE_ON_ZERO,ONLY_FULL_GROUP_BY';
# Time: 2017-10-09T05:02:00.746467Z
# User@Host: isucon[isucon] @ localhost []  Id:     4
# Query_time: 0.004247  Lock_time: 0.003866 Rows_sent: 2  Rows_examined: 4
SET timestamp=1507525320;
SELECT * FROM entry
        ORDER BY updated_at DESC
        LIMIT 10
        OFFSET 0;
# Time: 2017-10-09T05:02:00.747545Z
# User@Host: isucon[isucon] @ localhost []  Id:     4
# Query_time: 0.000388  Lock_time: 0.000143 Rows_sent: 2  Rows_examined: 4
root@ubuntu-xenial:~# wget https://www.percona.com/downloads/percona-toolkit/3.0.4/binary/debian/xenial/x86_64/percona-toolkit_3.0.4-1.xenial_amd64.deb
root@ubuntu-xenial:~# apt install libdbd-mysql-perl libdbi-perl libio-socket-ssl-perl libnet-ssleay-perl libterm-readkey-perl
# Profile
# Rank Query ID           Response time Calls R/Call V/M   Item
# ==== ================== ============= ===== ====== ===== ===============
#    1 0x6C987DBB94BEC091 43.9842 96.9%   414 0.1062  0.13 SELECT entry
#    2 0x51C26B78ABE63960  0.6851  1.5%    28 0.0245  0.00 INSERT SELECT UPDATE entry
#    3 0x0C85264D3C24C18B  0.3384  0.7%    44 0.0077  0.09 SELECT entry
#    4 0x782FEBA311BC59ED  0.1392  0.3%   414 0.0003  0.00 SELECT star
#    5 0xF32185B56AEF3A1D  0.0631  0.1%    44 0.0014  0.00 SELECT entry
#    6 0x7E7900C7AF4DD0A4  0.0440  0.1%    23 0.0019  0.00 INSERT star
#    7 0x6FF06CCB4B4E1FAC  0.0261  0.1%    17 0.0015  0.00 INSERT UPDATE entry
#    8 0x41883793B68D128E  0.0235  0.1%    82 0.0003  0.00 SELECT user
#    9 0x16F15936BC5B2382  0.0224  0.0%    70 0.0003  0.00 SELECT entry
#   10 0x87B0C6DEA95CEF2E  0.0201  0.0%    84 0.0002  0.00 SELECT user
# MISC 0xMISC              0.0312  0.1%    59 0.0005   0.0 <32 ITEMS>

上から順番に遅いやつ。

# Query 1: 0.70 QPS, 0.07x concurrency, ID 0x6C987DBB94BEC091 at byte 28601055
# Scores: V/M = 0.13
# Time range: 2017-10-09T05:24:22 to 2017-10-09T05:34:12
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         32     414
# Exec time     96     44s   129us      1s   106ms   266ms   117ms    75ms
# Lock time     39    64ms    40us     5ms   153us   224us   361us    93us
# Rows sent     99   2.70M       1   6.94k   6.67k   6.63k   1.28k   6.63k
# Rows examine  91   5.40M       2  13.89k  13.34k  13.78k   2.66k  13.78k
# Query size     0  23.85k      59      59      59      59       0      59
# String:
# Databases    isuda
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us  ###
#   1ms
#  10ms  ################################################################
# 100ms  ###########################
#    1s  #
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isuda` LIKE 'entry'\G
#    SHOW CREATE TABLE `isuda`.`entry`\G
# EXPLAIN /*!50100 PARTITIONS*/
select * from entry order by character_length(keyword) desc\G

改善作業に入る

step1 不要なカラムを読み込まないようにする

# before
keywords = db.xquery(%| select * from entry order by character_length(keyword) desc |)

# after
keywords = db.xquery(%| select keyword from entry order by character_length(keyword) desc |)
# Query 1: 17.68 QPS, 0.14x concurrency, ID 0x8AC9E716A43D8A44 at byte 610435
# Scores: V/M = 0.00
# Time range: 2017-10-09T05:57:41 to 2017-10-09T05:58:44
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         37    1114
# Exec time     89      9s     5ms   103ms     8ms    16ms     6ms     6ms
# Lock time     34   111ms    45us     4ms    99us   144us   138us    80us
# Rows sent     99   7.55M   6.93k   6.95k   6.94k   6.63k       0   6.63k
# Rows examine  92  15.11M  13.87k  13.90k  13.89k  13.78k       0  13.78k
# Query size    21  70.71k      65      65      65      65       0      65
# String:
# Databases    isuda
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms  ################################################################
#  10ms  ###############
# 100ms  #
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isuda` LIKE 'entry'\G
#    SHOW CREATE TABLE `isuda`.`entry`\G
# EXPLAIN /*!50100 PARTITIONS*/
select keyword from entry order by character_length(keyword) desc\G
isucon@ubuntu-xenial:~/isucon6q$ ./isucon6q-bench -target http://127.0.0.1
2017/10/09 14:57:41 start pre-checking
2017/10/09 14:57:45 pre-check finished and start main benchmarking
2017/10/09 14:58:41 benchmarking finished
{"pass":true,"score":4719,"success":1918,"fail":1,"messages":["リクエストがタイムアウトしました (POST /stars)"]}

step2 何度も実行されないようにする

#before
      entries.each do |entry|
        entry[:html] = htmlify(entry[:description])
        entry[:stars] = load_stars(entry[:keyword])
      end
#after
    keywords = 
    entries.each do |entry|
      entry[:html] = htmlify(keywords, entry[:description])
      entry[:stars] = load_stars(entry[:keyword])
    end
# Query 1: 4.67 QPS, 0.04x concurrency, ID 0x8AC9E716A43D8A44 at byte 687529
# Scores: V/M = 0.00
# Time range: 2017-10-09T06:04:42 to 2017-10-09T06:05:54
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         13     336
# Exec time     69      3s     5ms    54ms     9ms    17ms     5ms     6ms
# Lock time      9    28ms    32us   287us    83us   144us    33us    73us
# Rows sent     99   2.28M   6.93k   6.95k   6.94k   6.63k       0   6.63k
# Rows examine  73   4.56M  13.87k  13.90k  13.89k  13.78k    0.00  13.78k
# Query size     7  21.33k      65      65      65      65       0      65
# String:
# Databases    isuda
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms  ################################################################
#  10ms  ############################
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isuda` LIKE 'entry'\G
#    SHOW CREATE TABLE `isuda`.`entry`\G
# EXPLAIN /*!50100 PARTITIONS*/
select keyword from entry order by character_length(keyword) desc\G
isucon@ubuntu-xenial:~/isucon6q$ ./isucon6q-bench -target http://127.0.0.1
2017/10/09 15:04:42 start pre-checking
2017/10/09 15:04:47 pre-check finished and start main benchmarking
2017/10/09 15:05:42 benchmarking finished
{"pass":true,"score":5051,"success":2093,"fail":1,"messages":["リクエストがタイムアウトしました (POST /keyword)"]}

step3 assetsをnginxで返す

root@ubuntu-xenial:~# alp --sum -r -f /var/log/nginx/access.log --aggregates='/keywords/.*'
+-------+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+--------+---------------------------------------------+
| COUNT |  MIN  |  MAX  |   SUM   |  AVG  |  P1   |  P50  |  P99  | STDDEV | MIN(BODY)  | MAX(BODY)  |  SUM(BODY)   | AVG(BODY)  | METHOD |                     URI                     |
+-------+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+--------+---------------------------------------------+
|   114 | 0.645 | 6.417 | 314.101 | 2.755 | 0.645 | 2.723 | 4.654 |  0.862 |   7960.000 |  93210.000 |  4816125.000 |  42246.711 | GET    | /                                           |
|   456 | 0.001 | 3.043 | 278.135 | 0.610 | 0.002 | 0.503 | 2.131 |  0.497 | 106015.000 | 106015.000 | 48342840.000 | 106015.000 | GET    | /css/bootstrap.min.css                      |
|   228 | 0.001 | 3.038 | 140.322 | 0.615 | 0.001 | 0.511 | 2.059 |  0.496 |  28631.000 |  28631.000 |  6527868.000 |  28631.000 | GET    | /js/bootstrap.min.js                        |
|   228 | 0.001 | 3.039 | 140.048 | 0.614 | 0.002 | 0.513 | 2.060 |  0.496 |  86351.000 |  86351.000 | 19688028.000 |  86351.000 | GET    | /js/jquery.min.js                           |
|   228 | 0.002 | 3.044 | 139.345 | 0.611 | 0.002 | 0.505 | 2.062 |  0.497 |  16849.000 |  16849.000 |  3841572.000 |  16849.000 | GET    | /css/bootstrap-responsive.min.css           |
|   228 | 0.001 | 3.038 | 138.529 | 0.608 | 0.001 | 0.509 | 2.058 |  0.497 |   1092.000 |   1092.000 |   248976.000 |   1092.000 | GET    | /favicon.ico                                |
|   228 | 0.001 | 3.027 | 137.308 | 0.602 | 0.001 | 0.498 | 2.057 |  0.495 |     93.000 |     93.000 |    21204.000 |     93.000 | GET    | /img/star.gif

やっぱり / 重いけれども、まずはすぐにできそうな assetsまわりからやってみる。

        location ~ ^/(img|css|js|favicon.ico){
            root /home/isucon/webapp/public;
        }
isucon@ubuntu-xenial:~/isucon6q$ ./isucon6q-bench -target http://127.0.0.1
2017/10/09 15:15:16 start pre-checking
2017/10/09 15:15:20 pre-check finished and start main benchmarking
2017/10/09 15:16:16 benchmarking finished
{"pass":true,"score":5258,"success":2380,"fail":2,"messages":["リクエストがタイムアウトしました (POST /stars)"]}

200 score早くなった。

step4 失敗しているリクエストをなくす

isucon@ubuntu-xenial:~/isucon6q$ ./isucon6q-bench -target http://127.0.0.1
{"pass":true,"score":3779,"success":1851,"fail":4,"messages":["starがついていません (GET /)","リクエストがタイムアウトしました (POST /stars)","讃岐典侍日記 に 1109年 へのリンクがありません (GET /)"]}

これを見ると POST /stars でtimeoutしている。

    post '/stars' do
      keyword = params[:keyword]
      isuda_keyword_url = URI(settings.isuda_origin)
      isuda_keyword_url.path = '/keyword/%s' % [Rack::Utils.escape_path(keyword)]
      res = Net::HTTP.get_response(isuda_keyword_url)
      halt(404) unless Net::HTTPSuccess === res

POST /stars では GET /keyword/:keyword を実行している。 GET /keyword/:keyword の検索がなかなか遅いので、こいつをなんとかしなければならない。

root@ubuntu-xenial:~# alp --sum -r -f /var/log/nginx/access.log --aggregates='/keywords/.*'
|     8 | 1.287 | 3.497 |   19.388 | 2.423 | 1.287 | 2.553 | 2.927 |  0.671 |  11924.000 |  11928.000 |     95408.000 |  11926.000 | GET    | /keyword/巨大基数

なぜ遅いのか見てみる。

mysql> desc star;
+------------+---------------------+------+-----+---------+----------------+
| Field      | Type                | Null | Key | Default | Extra          |
+------------+---------------------+------+-----+---------+----------------+
| id         | bigint(20) unsigned | NO   | PRI | NULL    | auto_increment |
| keyword    | varchar(191)        | NO   |     | NULL    |                |
| user_name  | varchar(191)        | NO   |     | NULL    |                |
| created_at | datetime            | YES  |     | NULL    |                |
+------------+---------------------+------+-----+---------+----------------+

keywordにindexが貼られていない。keywordにindexを貼っておく。

isucon@ubuntu-xenial:~/isucon6q$ ./isucon6q-bench -target http://127.0.0.1
2017/10/09 16:01:56 start pre-checking
2017/10/09 16:01:59 pre-check finished and start main benchmarking
2017/10/09 16:02:56 benchmarking finished
{"pass":true,"score":5671,"success":2476,"fail":0,"messages":[]}

300 scoreあがった。

5step get /をなんとかする。

root@ubuntu-xenial:~# alp --sum -r -f /var/log/nginx/access.log --aggregates='/keywords/.*'
+-------+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+--------+-------------------------------------------------------+
| COUNT |  MIN  |  MAX  |   SUM   |  AVG  |  P1   |  P50  |  P99  | STDDEV | MIN(BODY)  | MAX(BODY)  |  SUM(BODY)   | AVG(BODY)  | METHOD |                          URI                          |
+-------+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+--------+-------------------------------------------------------+
|   101 | 0.709 | 7.417 | 345.768 | 3.423 | 0.709 | 3.317 | 6.436 |  1.414 |   7960.000 | 162448.000 |  5027564.000 |  49777.861 | GET    | /                                                     |
      keywords = db.xquery(%| select keyword from entry order by character_length(keyword) desc |)
      entries.each do |entry|
        entry[:html] = htmlify(keywords, entry[:description])
        entry[:stars] = load_stars(entry[:keyword])
      end

ここを、下記のようにできるのは無いか。

      keywords = db.xquery(%| select keyword from entry order by character_length(keyword) desc |)
      stars = load_stars(keywords)
      
      entries.each do |entry|
        entry[:html] = htmlify(keywords, entry[:description])
        entry[:stars] = stars[entry[:keyword]]
      end

今日は一旦ここまで

その他

再起動用script

#!/bin/sh

set -e

now=`date +%Y%m%d-%H%M%S`
mv /var/log/nginx/access.log /var/log/nginx/access.log.$now
systemctl restart nginx

mv /var/log/mysql/slow.log /var/log/mysql/slow.log.$now
mysqladmin -uisucon -pisucon flush-logs

systemctl restart isuda.ruby
systemctl restart isutar.ruby

過去問の作業ログ

当日の作業の流れ

環境確認

  • githubでコード管理
  • アプリケーションの動作確認: ブラウザでさわってみる、どんなプロセス動いてるとか
  • 運営側から提供されているベンチマークを実行
  • マシンスペックの確認(core数とか重要そう)

計測

ndenvでnodejsのバージョンを固定した話

モチベーション

僕がいたwebサービスにおいて、nodejsのバージョンを指定するものがなく、みんな異なるバージョンの nodejsを利用していた。なので、全員が開発で使う nodejsのバージョンと実際本番で利用しているnodejsのバージョンを合わせたかった。

※ nodejsはjsのbuildにしか使っていなかった。

ndenvを利用した理由

nodejs を管理するためのツールとして、ndenvを選択。 https://github.com/riywo/ndenv

理由としては、nvmと違って、.node-versionでプロジェクト毎にnodeのバージョンを指定することができるから。

Unlike nvm, ndenv automatically change node version using .node-version file locally.

導入作業

➜  ~ git clone https://github.com/riywo/ndenv ~/.ndenv
➜  ~ git clone https://github.com/riywo/node-build.git $(ndenv root)/plugins/node-build

.zshrcに下記設定を追加。

#=== ndenv ====#
export PATH="$HOME/.ndenv/bin:$PATH"
eval "$(ndenv init -)"
➜  ~ exec $SHELL -l
➜  ~ ndenv install -l | grep v6.11.
  v6.11.0
  v6.11.1
  v6.11.2
  v6.11.3
➜  ~ ndenv install v6.11.3
➜  app git:(master) ndenv local v6.11.3
➜  app git:(master) ✗ node -v
v6.11.3

最後に

コミットログを見たら、last updateが2年前だったので、導入取りやめ。 他の方法を模索する。

(#1)ふつうのLINUXプログラミング

1.2 プログラミング環境の準備

gccを5系の最新入れる必要があるらしい

➜  ~ gcc -dumpversion
4.2.1
➜  ~ brew install gcc5
==> Pouring gcc@5-5.4.0_1.el_capitan.bottle.tar.gz
🍺  /usr/local/Cellar/gcc@5/5.4.0_1: 1,391 files, 253.3MB
➜  ~ ln -s /usr/local/bin/gcc-5 /usr/local/bin/gcc
➜  ~ source ~/.zshrc
➜  ~ gcc -dumpversion
5.4.0

ということで、5.4.0のGCCを入れることができた。

1.3 gccを使ったbuild(1)

IDEを使わずに、コンパイルして実行してみる

# hello.cの作成
➜  c mkdir hello
➜  c cd hello
➜  hello vi hello.c
#include <stdio.h>

int main(int argc, char *argv[]){
  printf("Hello, World\n");
  return 0;
}
# build
➜  hello gcc hello.c
➜  hello ls
a.out   hello.c
➜  hello ./a.out
Hello, World

gccでbuildして ./xxx.out コマンドでコードを実行する。

1.4 gccを使ったbuild(2)

# -o optionを使って作るファイル名を指定する
➜  hello rm a.out
➜  hello gcc -o hello hello.c
➜  hello ls
hello   hello.c
➜  hello ./hello
Hello, World

1.5 コマンドライン引数

➜  hello touch args.c
#include <stdio.h>
#include <stdlib.h>

int main(int argc, char *argv[]){
  int i;
  printf("argc=%d\n", argc);
  for(i = 0; i<argc; i++){
    printf("argv[%d]=%s\n", i, argv[i]);
  }
  exit(0);
}
➜  hello gcc -o args args.c
➜  hello ./args
argc=1
argv[0]=./args
➜  hello ./args x y z #3つのコマンドライン引数 x, y, z
argc=4
argv[0]=./args
argv[1]=x
argv[2]=y
argv[3]=z
➜  hello ./args "x y z" # `"`で囲むと一つの文字列として扱える
argc=2
argv[0]=./args
argv[1]=x y z
➜  hello ./args *.c # globを使って引数を渡すこともできる。
argc=3
argv[0]=./args
argv[1]=args.c
argv[2]=hello.c

Revieee開発日記 [20170725]

今日の作業

  • RDSへの置き換えを行う

1pomo 9:50 - 10:15

cloudformationでRDSの設定をする.

RevieeeDB:
    Type: AWS::RDS::DB::Instance
    Properites:
      DBSecurityGroups:
        - Ref: #TODO: SET Security Group
        - Ref: #TODO: SET Security Group
      AllocatedStorage: '' #TODO:
      DBInstanceClass: db.m1.small #TODO: set correct instance type
      Engine: MySQL
      MasterUsername: #TODO: secure settings
      MasterUserPassword: #TODO: secure settings
    DeletionPolicy: Snapshot

ベースはこれ。このあと、下記の項目について対応する

  • 適切なDBInstanceClassの指定
  • SecurityGroupの設定
  • AllocatedStorageの設定
  • Username, Passwordの設定(暗号化必須?)

ほとんどデータも格納しないだろうし、一旦 t2.microにした。 vCPU 1, ECU 1, Memory 1GB.

次はSecurityGroupsの設定を行う。 アクセスする必要があるのは、nginxとLambdaであり、nginx RevieeeAppServerSecurityGroupに入っているので、一旦これだけ設定。 Lambdaについては、やりながら考える

AllocatedStorageについて調べる。

http://docs.aws.amazon.com/AWSCloudFormation/latest/UserGuide/aws-properties-rds-database-instance.html#cfn-rds-dbinstance-allocatedstorage

The allocated storage size, specified in gigabytes (GB). If any value is set in the Iops parameter, AllocatedStorage must be at least 100 GB, which corresponds to the minimum Iops value of 1,000.

よくIOPSを忘れるのでメモ :sweat_smile: 
IOPS => 1秒あたりに捌けるI/Oの数.
https://en.wikipedia.org/wiki/IOPS

2pomo 10:25 - 10:50

引き続きAllocatedStorageから。 Iopの設定すると、AllocatedStorageの値は最低100GBで、Iopsの値は1000になるよ! とのこと。AllocatedStorageの値って、最低何GBが適正なんだろ….

http://docs.aws.amazon.com/ja_jp/AmazonRDS/latest/UserGuide/CHAP_Storage.html

汎用 (SSD) – gp2 とも呼ばれる汎用 (SSD) ボリュームは、さまざまなワークロードに対応できるコスト効率の高いストレージとして使用できます。これらのボリュームでは、レイテンシーは 1 桁台のミリ秒であり、長時間 3,000 IOPS にバーストできます。最小 100 IOPS (33.33 GiB 以下) から最大 10,000 IOPS (3,334 GiB 以上) まで、ベースラインパフォーマンスは 3 IOPS/GiB (ボリュームサイズ) の割合で線形に拡大します。gp2 ボリュームのサイズ範囲は、1 GiB ~ 16 TiB です。

ふーむ。汎用SSDだと1GB ~ 16 TiBと…

Provisioned IOPS – Provisioned IOPS ストレージは、ランダムアクセス I/O スループットにおけるストレージのパフォーマンスと整合性が重視される大量の I/O を伴うワークロード (特にデータベースワークロード) の要件を満たすように設計されています。Provisioned IOPS ボリュームのサイズは、100 GB〜6 TB (MySQLMariaDBPostgreSQL、および Oracle DB エンジン用) です。

なるほど、IOPSの設定をすると、Provisioned IOPSになるのかな。 となると、100GBがミニマムスタートになる。

今回は汎用SSDで良さげだな。容量と金額の関係性が分からないが、1GBでも十分かな。 足りなくなったら、後で増やそう。

次は Username, Passwordの設定 に入る。 これは外部引数として渡す方法でやるかなぁ。

一旦 Parametersを使った。 次のポモドーロで Conditionsを使う方法を調査する。

3pomo 11:00 - 11:25

Conditionsの設定を見て、書いてみた。 https://github.com/speee/webapp-revieee/pull/75 ここから先は、実行しながら確認していく。

このあとは、今後の設計に関する議論になったので、今日の作業はここまで

revieee開発日記[20170713]

やりたいこと

現状整理

  • curlを実行すると http://127.0.0.1:80 が返ってきてる
  • 実際は、mysqlにはport3000が入っている
  • http://127.0.0.1:3000 が返ってきて欲しい
# curl
curl -H "Host: endpoint-1.reviewapps.speee.jp" http://127.0.01
http://127.0.0.1:80
# container log
nginx-proxy      | nginx.1    | endpoint-1.reviewapps.speee.jp 172.21.0.1 
- - [13/Jul/2017:01:11:01 +0000] "GET / HTTP/1.1" 200 20 "-" "curl/7.43.0"

問題ありそうな場所

  • nginx-proxyがリクエストを掴んじゃって、revieee_nginx_container にリクエストを返していない
  • ちゃんとcacheを消せていない

確認方法

  • revieee_nginx_containerのキャッシュが消せていない問題
    • キャッシュを物理的に削除してみる。

1pomo 10:40 - 11:05

ちゃんとcacheが消せていない可能性を潰す。

% docker exec -it revieee_nginx_container /bin/bash
root@06ec8eb57c9f:/# rm /var/tmp/localmemcache/*.lmc
mysql> select * from endpoints;
+------+-----------+------+---------+
| id   | ip        | port | task_id |
+------+-----------+------+---------+
|    1 | 127.0.0.1 | 3000 |       1 |
+------+-----------+------+---------+
1 row in set (0.01 sec)

これで、アクセスしたら、http://127.0.0.1:3000が返ってくるはず。

% curl -H "Host: endpoint-1.reviewapps.speee.jp" http://127.0.01
http://127.0.0.1:3000
http://127.0.0.1:3000

つまり、cacheがちゃんと消せてないということが分かった。 もう一度、revieee/clear時のエラーログを確認する。

nginx-proxy      | nginx.1    | 2017/07/13 01:49:04 [error] 
39#39: *7 upstream prematurely closed connection while reading 
response header from upstream, client: 172.21.0.1, 
server: *.reviewapps.speee.jp, request: "GET /revieee/clear HTTP/1.1", 
upstream: "http://172.21.0.4:80/revieee/clear", 
host: "endpoint-1.reviewapps.speee.jp"
nginx-proxy      | nginx.1    | 
endpoint-1.reviewapps.speee.jp 172.21.0.1 - - 
[13/Jul/2017:01:49:04 +0000] "GET /revieee/clear HTTP/1.1" 
502 173 "-" "curl/7.43.0"

今からは上のエラーの原因調査のみに集中する

upstream prematurely closed connection while reading response header from upstream

エラーログはこれ。upstreamのresponse headerを読み込んでいる最中に、upstreamが早まってconnectionをclosedにしたぞと。どういうことよ…

revieee_nginx側のlogが欲しい。なので、revieee_nginx側のlog設定を見直す。

 なので、下記の設定を nginxのcontainerに追記する。

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

nginx 再起動

docker exec revieee_nginx_container /usr/local/nginx/sbin/nginx -s reload
root@06ec8eb57c9f:/var/log# tail -f nginx/access.log
172.21.0.3 - - [13/Jul/2017:02:16:07 +0000] "GET / HTTP/1.1" 200 22 "-" "curl/7.43.0"
172.21.0.3 - - [13/Jul/2017:02:16:10 +0000] "GET /revieee/clear HTTP/1.1" 000 0 "-" "curl/7.43.0"

logが流れている….どうやら、このnginx containerまでは到達した模様. もうちょっとloggerの精度を高めたいなぁ。

2pomo 11:20 - 11:45

わざわざcontainer入らないと見れないのツライからもっと調査する。

https://docs.docker.com/engine/admin/logging/view_container_logs/

を熟読。access_logを↓のように設定する。

access_log /dev/stdout;

すると、accessしたときに、下記のようなlogが流れた。

revieee_nginx_container | 172.21.0.3 - - [13/Jul/2017:02:39:09 +0000] "GET /sample HTTP/1.1" 200 32 "-" "curl/7.43.0"
nginx-proxy      | nginx.1    | sample.reviewapps.speee.jp 172.21.0.1 - - [13/Jul/2017:02:39:09 +0000] "GET /sample HTTP/1.1" 200 32 "-" "curl/7.43.0"

大体目的どおり。