台風
明け方が最も風雨がひどかった気がする。そんな中を奥さんは出社。そして、奥さんが職場についた頃に香椎は晴れる。なんか面白い。
台風一過
夕方は夕焼けがきっと綺麗だっただろう＠香椎浜
flasgger
良い。
馬刺し
夕飯に馬刺しを食べる。美味しかった。ヒヒーン。
2016 年 10 月 04 日（火）
朝のジョギング
- 香椎浜 2 周
- やっぱり左太腿痛い
- 腕立て(30)、腹筋(20) x 3 セット
暑い
- 10 月なのに蒸し暑い...
- 汗だくで作業
Elasticsearch
- 繰り返しになるけど複数ノードでの運用が幸せの第一歩
Datadog の dogstatd
自作 API アプリケーションとかから Datadog にメトリクスを送りたい場合には API を叩くのも有りだけど Datadog Agent がインストールされていれば dogstatd を使った方が良さそう。以下のような簡単なコードでよしなに Datadog に値を投げてくれる。肝は statsd.gauge だと思う。
#!/opt/datadog-agent/embedded/bin/python # -*- coding: utf-8 -*- import sys, time, json import requests from datadog import statsd if __name__ == '__main__': while 1: time.sleep(3) r = requests.get('http://xxxxx/endpoint') print json.loads(r.text)['duration_time'] duration_time = json.loads(r.text)['duration_time'] statsd.gauge('oreno.app.duration_time', duration_time)
http://xxxxx/endpoint にアクセスすると JSON で duration_time: N というレスポンス（N はレスポンスによって異なる）が返ってくるので、この数値を Datadog に飛ばしたい場合の例。（Python バージョンは 2.7.12 で OS は CentOS 7 にて確認）
俺のカレー
俺のカレー、ファイナル。流石に三日目ともなると飽きた。
2016 年 10 月 03 日（月）
ジョギング
- 香椎浜 2 周
- 左太ももは相変わらず違和感、めっちゃキツかった
10 月なのに
- 日中はエアコンが必要なくらい暑かった
Elasticsearch
- 色々と弄る機会を頂いている
- シングルノードよりもマルチノード（奇数台が良い）で運用した方が色々と幸せになれることが解った
- 詳しくはまた今度
Python 配列の比較（差分が欲しい）
追記）ここでの配列を意図するものは Python では list 型であって、厳密な「配列」では無いと西尾先生に教えてもらった
a の配列と b の配列の差分が欲しい。下記の例だと baz が返ってくることを期待。
a = ['foo', 'bar', 'baz'] b = ['foo', 'bar'] c = list(set(a) - set(b)) print c
以下のように baz だけ配列で取り出せる。
['baz']
list 型を set 型に変えると + や - 等の演算子で集合演算出来るとのこと。参考：Python: set型の集合演算で2つのリスト要素を比較
そう言えば Ruby では配列オブジェクトをそのまま演算出来ていたのを思い出した。
[1] pry(main)> [2] pry(main)> a = ['foo', 'bar', 'baz'] => ["foo", "bar", "baz"] [3] pry(main)> b = ['foo', 'bar'] => ["foo", "bar"] [4] pry(main)> c = a - b => ["baz"]
俺のカレー
- 二日目
- 昨日の余りに新しいスープとカレールウを継ぎ足して食べた
- 美味しかった
2016 年 10 月 02 日（日）
久しぶりに
雨が降っていない朝。洗濯物が捗る。
奥さんは
中洲の美容院に朝早く出かけていった。中洲の美容院と聞くと夜の蝶達御用達の美容院もあったりするのかなと妄想...夜の若い蝶が集う待合室に飛んで火にいる香椎の蝶...妄想が膨らんで面白い。
久しぶりに（2）
香椎浜を走った。左足太ももが痛かったり、風邪をひいたりしていてサボっていたので体は重かったし、昨晩のおろしにんにくがヒットしたのかお腹が痛くてトイレにピットイン...結局、一周で止めた。
イオンモール香椎浜
- いつものタリーズが満員御礼、スタバに河岸を変えて MCP 70-533 の勉強等
- スタバでタゾチャイティラテをがぶ飲みしたら腹痛再来、トイレに駆け込む
- トイレ後はタリーズにて引続き資料を読んだり、調べ物をしたり...周囲の人の会話が耳に飛び込んできて、色々と考えさせられた
Azure Service Bus の Queue を触ってみた
Azure キューと Service Bus キュー
そもそも、Azure キューと Service Bus のキューが在って混乱しそう。
個人的に気になったのが FIFO で順番が保証されているところ。Amazon SQS には無い機能。
Python でちょこっと
- requirements.txt
azure-batch azure-servicebus==0.20.2 azure-mgmt-scheduler
azure-servicebus==0.20.2 しておかないと、'could not convert string to float: max-age=31536000' のエラーに見舞われる。
- Namespace 作成
PowerShell で実行。
New-AzureSBNamespace -Name 'oreno-namespace' -Location 'Japan West' -NamespaceType 'Messaging' -CreateACSNamespace $true
以下のように出力される。
Name : oreno-namespace Region : Japan West DefaultKey : xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx Status : Active CreatedAt : 2016/10/02 16:44:38 AcsManagementEndpoint : https://oreno-namespace-sb.accesscontrol.windows.net/ ServiceBusEndpoint : https://oreno-namespace.servicebus.windows.net/ ConnectionString : Endpoint=sb://oreno-namespace.servicebus.windows.net/;SharedSecretIssuer=owner;SharedSecretValue=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx NamespaceType : Messaging
- 送信側
from azure.servicebus import ServiceBusService, Message, Queue import time service_namespace = 'oreno-namespace' account_key = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx' issuer = 'owner' sbs = ServiceBusService(service_namespace, account_key=account_key, issuer=issuer) num = 0 while num < 100: time.sleep(1) print 'Test Message' + str(num) sbs.send_queue_message('taskqueue', Message(b'Test Message' + str(num))) num += 1 print 'finished.'
- 受信側
from azure.servicebus import ServiceBusService, Message, Queue import time service_namespace = 'oreno-namespace' account_key = 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx' issuer = 'owner' sbs = ServiceBusService(service_namespace, account_key=account_key, issuer=issuer) while 1: time.sleep(1) msg = sbs.receive_queue_message('taskqueue', peek_lock=False) print(msg.body)
- 実行してみると...
一応、順番が守られているっぽい。
時間があればもう少し突っ込んで触ってみたい。
俺のカレー
カレーを作る。
細かく刻んだトマト、玉ねぎと豚ひき肉、鶏肉をコンソメスープで適当に煮込んで市販のカレールウを 2 個位放り込んで適当に煮込んだもの。後はカレー粉でサッと炒めたじゃがいも、人参等の野菜を後乗せで食べる。（鷹の爪、ローリエも投入している）
カレーの保存を考慮する際にじゃがいもや人参を一緒に煮込んでいるとそれらの消費期限を気にしなければいけないが、野菜を後乗せすることで、野菜はお好みで選べるし、消費期限をあまり考慮する必要がなるメリットがあると考えている。
まあまあ美味しかった。
2016 年 10 月 01 日（土）
天下一品の日
今日は「天下一品の日」らしい。しばらく「天下一品ラーメン」に行っていない。
X-Frame-Options HTTP レスポンスヘッダ
iframe 内から Web ページ読み込みを制御する X-Frame-Options という HTTP レスポンスヘッダがあることを知った。
読み込まれる側で Web サーバー（Apache や Nginx）又はアプリケーション側で設定する。
Apache の場合には以下のように設定する。
| 設定 | 挙動 |
|---|---|
| Header always append X-Frame-Options DENY | フレームへの読み込みを拒否 |
| Header always append X-Frame-Options SAMEORIGIN | フレームに読み込むページを同一ドメインのページのみ許可 |
| Header always append X-Frame-Options ALLOW-FROM=http://example.com | http://example.com からの iframe 読み込みを許可 |
全然知らなかった。
日帰り湯
ラジオで紹介されていた美奈宜の湯に行ってみた。温度は少し高めだったが、源泉掛け流しで良かった。
キラキラネーム
スポーツニュースを見ていると若い年代（十代、二十代）の選手名にルビが振られるのを見かけるようになった。キラキラネーム自体の定義が曖昧だと思うので、全てがキラキラネームになるとは思わないが、一般的な漢字の知識では読めないような名前が増えてきているんだろう。おそらく、彼らの親は自分と同じ年代になるのかな...ちょっと複雑。
2020 年東京オリンピック
マスコミの偏った見解しか耳に入ってこないので、真実はどこにあるのかは定かではないけど、何か違うよなーって思った。エンブレム問題に始まって、全く報じられなくなった不正献金疑惑、招致当初の想定を超えた巨額予算問題。雑な性格な自分が見てもかなり杜撰な気がするので、開催自体も白紙に戻した方がいいんぢゃないかなと思う。
信頼って何だろう。誰の信頼なんだろう。開催国の国民の信頼はちゃんと得られていないような気がする。何の為の誰の為のオリンピック、パラリンピックなのか。
ニンテンドークラシックミニ ファミリーコンピュータ
こっそり発注したのが奥さんにバレて怒られて「返品してこい」と言われたけど、奥さんと一緒に「マリオブラザーズ」やりたい等と説得して許して貰えた。改めて到着が楽しみ。
Flask のエラーハンドラメモ
tl;dr
Flask で簡単なアプリケーションを書く機会を頂いたので試行錯誤しながら書いていますが、特にエラーハンドラが心地よかったのでメモしておきます。
参考
上記のサイトがとても参考になりました。感謝！
memo
エラーハンドラ
abort(xxx) でエラーを返す際に任意のエラーを返すことが出来るとのことで、例えば Web アプリケーション内のエラー処理で abort(xxx) と書いておけば、指定したエラー内容でクライアントに返却することが出来ます。
サンプル
以下のようなサンプルアプリケーションを書いてみました。
#!/usr/bin/env python # -*- coding: utf-8 -*- from flask import Flask from flask import abort, jsonify, request import json app = Flask(__name__) @app.route('/foo', methods=['POST']) def post_foo(): ''' Description - リクエストボディ {"id": "foo"} であれば ok を返す - リクエストボディ {"id": "foo"} であれば id is different を返す ''' if request.headers['Content-Type'] == 'application/json': id = request.json['id'] else: id = json.loads(request.form.to_dict().keys()[0])['id'] if id == 'foo': return jsonify({ 'message': 'ok'}) else: abort(404, { 'id': id }) @app.errorhandler(404) def error_handler(error): ''' Description - abort(404) した時にレスポンスをレンダリングするハンドラ ''' response = jsonify({ 'id': error.description['id'], 'message': 'id is different', 'result': error.code }) return response, error.code if __name__ == '__main__': app.run()
実行すると以下のような感じ。
$ curl -X POST -d '{"id": "foo"}' localhost:5000/foo 127.0.0.1 - - [01/Oct/2016 12:15:11] "POST /foo HTTP/1.1" 200 - { "message": "ok" } $ curl -X POST -d '{"id": "fo0"}' localhost:5000/foo 127.0.0.1 - - [01/Oct/2016 12:15:25] "POST /foo HTTP/1.1" 404 - { "id": "fo0", "message": "id is different", "result": 404 }
少し詳しく（1）
@app.errorhandler(404) def error_handler(error): ''' Description - abort(404) した時にレスポンスをレンダリングするハンドラ ''' response = jsonify({ 'id': error.description['id'], 'message': 'id is different', 'result': 404 }) return response, error.code
error_handler の引数 error にはどのようなメソッドが含まれているか確認してみます。
['__call__', '__class__', '__delattr__', '__dict__', '__doc__', '__format__', '__getattribute__', '__getitem__', '__getslice__', '__hash__', '__init__', '__module__', '__new__', '__reduce__', '__reduce_ex__', '__repr__', '__setattr__', '__setstate__', '__sizeof__', '__str__', '__subclasshook__', '__unicode__', '__weakref__', 'args', 'code', 'description', 'get_body', 'get_description', 'get_headers', 'get_response', 'message', 'name', 'response', 'wrap']
それぞれのメソッドを見てみます。
(snip) @app.errorhandler(404) def error_handler(error): ''' Description - abort(404) した時にレスポンスをレンダリングするハンドラ ''' print dir(error) print 'error.args = ' + str(error.args) print 'error.code = ' + str(error.code) print 'error.description = ' + str(error.description) print 'error.message = ' + str(error.message) print 'error.name = ' + str(error.name) print 'error.response = ' + str(error.response) print 'error.wrap = ' + str(error.wrap) response = jsonify({ 'id': error.description['id'], 'message': 'id is different', 'result': error.code }) return response, error.code (snip)
以下のような結果となりました。
['__call__', '__class__', '__delattr__', '__dict__', '__doc__', '__format__', '__getattribute__', '__getitem__', '__getslice__', '__hash__', '__init__', '__module__', '__new__', '__reduce__', '__reduce_ex__', '__repr__', '__setattr__', '__setstate__', '__sizeof__', '__str__', '__subclasshook__', '__unicode__', '__weakref__', 'args', 'code', 'description', 'get_body', 'get_description', 'get_headers', 'get_response', 'message', 'name', 'response', 'wrap'] error.args = () error.code = 404 error.description = {'id': u'fo0'} error.message = error.name = Not Found error.response = None error.wrap = <bound method type.wrap of <class 'werkzeug.exceptions.NotFound'>>
abort(xxx) を投げる時にエラーレスポンスに入れたい情報を引数として書いてあげれば error.description で取り出して、エラーに合わせたメッセージをレンダリングしてクライアント返却することができるので嬉しいです。
少し詳しく（2）
以下のように書けば、それぞれのエラーでも一つの関数でハンドリングすることが出来ます。
@app.errorhandler(400) @app.errorhandler(404) @app.errorhandler(500) def error_handler(error): ''' Description - abort(400) / abort(404) / abort(500) した時にレスポンスをレンダリングするハンドラ ''' response = jsonify({ 'message': error.name, 'result': error.code }) return response, error.code
これも嬉しいです。
以上
メモでした。
2016 年 09 月 30 日（金）
ずーっとサボっていたけど、日記的なものは極力書く努力をしたいと思った。
最後に書いたのが 7/10 だったので、約三ヶ月サボっていたことになる。ということで、ここ三ヶ月の軽い振り返り。
- 9 月に入るまではほぼ毎朝ジョギングしていたが、左足太ももを痛めてから走る頻度が落ちている
- AWS GAMEDAY JAPAN で優勝した
- 8/6 には Ruby Association Certified Ruby Programmer Silver version 2.1 を受験して合格した
- リオオリンピック、パラリンピックがだいぶん盛り上がった気がする（オリンピックとパラリンピックでメディアの取り扱い方が全然違う点には憤慨した）
- 8 月〜 9 月まではとにかく暑くてエアコンはフル稼働だった
- SMAP が今年いっぱいで解散とのこと
- ISUCON 2016 予選に参加するが何も出来ずに終わった
- ニンテンドークラシックミニ ファミリーコンピュータをこっそり発注、届くのが楽しみ
- 京都マラソン 2017 に走ることになった
他にもありそうだけど、初老なりに頑張った部分もあるけど、努力不足も否めないところあったり。
残り三ヶ月も頑張ろ。
来年の isucon で泣かずに予選を終える為のメモ（1）
tl;dr
isucon6 予選は何も出来ずに涙を飲んだので、来年は少しでも手を動かせるように過去問を触りながら isucon の雰囲気に慣れていきたい。
isucon6 予選の反省点
- どの言語でとか等のチーム方針が明確では無かった
- チーム方針が明確では無かったので当然役割分担も不明瞭だった
- 過去問に触れずに挑んだ為、何をすれば良いのか全く解らなかった
- 各種解析ツールの存在、使い方に慣れていなかった（そもそも使ったことが無かった）
- データベースに関する知識、経験がほぼ 0 だった為、データベースのチューニングには全く手を付けることが出来なかった
ということで、今回は過去問を起動するところから、解析ツールを仕込むところまでやってみる。
過去問や解析ツールのメモ
Apache / Nginx アクセスログの解析
MySQL スローログの解析
アプリケーションの解析
- Ruby（Rack アプリケーション）
- https://github.com/kainosnoema/rack-lineprof
- Python(WSGI アプリケーション)
- http://werkzeug.pocoo.org/docs/0.11/contrib/profiler/
過去問 matsuu さんに感謝
isucon2 から isucon5 まで用意されており、各過去問が vagrant 一発で起動させることが出来る。
isucon5 の予選で利用された問題を展開する例
$ git clone https://github.com/matsuu/vagrant-isucon.git
$ cd isucon5-qualifier-standalone
vagrant up
ブラウザでアクセスしたい場合には Vagrantfile を以下のように修正する。
$ diff -u Vagrantfile.original Vagrantfile --- Vagrantfile.original 2016-09-25 11:35:04.349082426 +0900 +++ Vagrantfile 2016-09-24 21:27:00.276552570 +0900 @@ -28,7 +28,7 @@ # Create a private network, which allows host-only access to the machine # using a specific IP. - # config.vm.network "private_network", ip: "192.168.33.10" + config.vm.network "private_network", ip: "192.168.33.10" # Create a public network, which generally matched to bridged network. # Bridged networks make the machine appear as another physical device on
ボクがログインしたらやれそうなこと...
これだったら出来そう
- Nginx ログの解析
- MySQL SlowLog 取得の設定
- アプリケーション解析の設定
Nginx ログの解析
- alp を使う場合に Nginx のアクセスログフォーマットを ltsv 形式に設定する
http { log_format ltsv "time:$time_local" "\thost:$remote_addr" "\tforwardedfor:$http_x_forwarded_for" "\treq:$request" "\tstatus:$status" "\tmethod:$request_method" "\turi:$request_uri" "\tsize:$body_bytes_sent" "\treferer:$http_referer" "\tua:$http_user_agent" "\treqtime:$request_time" "\tcache:$upstream_http_x_cache" "\truntime:$upstream_http_x_runtime" "\tapptime:$upstream_response_time" "\tvhost:$host"; access_log /var/log/nginx/access.log ltsv; upstream app { server 127.0.0.1:8080; } server { location / { proxy_set_header Host $host; proxy_pass http://app; } } }
- alp でログ解析
$ sudo cat /var/log/nginx/access.log | ./alp -r | less +-------+-------+-------+---------+-------+-------+-------+-------+--------+-----------+------------+-------------+-----------+--------+------------------------------------+ | COUNT | MIN | MAX | SUM | AVG | P1 | P50 | P99 | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY) | AVG(BODY) | METHOD | URI | +-------+-------+-------+---------+-------+-------+-------+-------+--------+-----------+------------+-------------+-----------+--------+------------------------------------+ | 207 | 0.001 | 2.669 | 225.738 | 1.091 | 0.001 | 1.012 | 2.548 | 0.612 | 16285.000 | 16791.000 | 2966944.000 | 14333.063 | GET | / | | 3 | 0.654 | 2.499 | 3.875 | 1.292 | 0.654 | 0.654 | 0.722 | 0.854 | 3476.000 | 3747.000 | 10970.000 | 3656.667 | GET | /diary/entry/489651 | | 9 | 0.013 | 2.292 | 3.258 | 0.362 | 0.013 | 0.025 | 0.588 | 0.704 | 53984.000 | 61469.000 | 530916.000 | 58990.667 | GET | /diary/entries/verlie_crooks151 (snip)
MySQL SlowLog 取得の設定
- my.cnf に設定を追加
[mysqld] (snip) slow_query_log = 1 slow_query_log_file = /var/log/mysql/mysqld-slow.log long_query_time = 0 log-queries-not-using-indexes =
- pt-query-digest で解析
$ sudo pt-query-digest /var/log/mysql/mysqld-slow.log # 1.3s user time, 0 system time, 28.45M rss, 85.27M vsz # Current date: Sun Sep 25 11:54:50 2016 # Hostname: vagrant # Files: /var/log/mysql/mysqld-slow.log # Overall: 7.45k total, 27 unique, 2.45 QPS, 0.00x concurrency ___________ # Time range: 2016-09-25 08:22:49 to 09:13:31 # Attribute total min max avg 95% stddev median # ============ ======= ======= ======= ======= ======= ======= ======= # Exec time 3s 3us 204ms 432us 247us 6ms 113us # Lock time 238ms 0 2ms 31us 44us 38us 27us # Rows sent 21.36k 0 1000 2.94 0.99 40.61 0.99 # Rows examine 5.71M 0 488.50k 804.05 0.99 19.01k 0 # Query size 817.88k 11 226 112.42 112.70 19.13 112.70 # Profile # Rank Query ID Response time Calls R/Call V/M Item # ==== ================== ============= ===== ====== ===== =============== # 1 0xDE6DD0309F9386F8 1.0643 33.1% 6 0.1774 0.00 SELECT relations # 2 0xD44150558D8295E1 0.9162 28.5% 6942 0.0001 0.00 SELECT relations # 3 0x492C7CAB538DE80D 0.8483 26.3% 6 0.1414 0.00 SELECT footprints # 4 0x064A5B2042FC8316 0.2127 6.6% 7 0.0304 0.01 SELECT entries # 5 0xCE3E456E0D0EFD1C 0.0584 1.8% 6 0.0097 0.01 SELECT comments entries # MISC 0xMISC 0.1200 3.7% 483 0.0002 0.0 <22 ITEMS> # Query 1: 0.00 QPS, 0.00x concurrency, ID 0xDE6DD0309F9386F8 at byte 317533 # Scores: V/M = 0.00 # Time range: 2016-09-25 08:23:03 to 09:13:31 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 0 6 # Exec time 33 1s 168ms 204ms 177ms 198ms 13ms 163ms # Lock time 0 176us 28us 32us 29us 31us 1us 28us # Rows sent 5 1.24k 212 212 212 212 0 212 # Rows examine 49 2.83M 483.53k 483.53k 483.53k 483.53k 0 483.53k # Query size 0 522 87 87 87 87 0 87 # String: # Databases isucon5q # Hosts localhost # Users root # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms ################################################################ # 1s # 10s+ # Tables # SHOW TABLE STATUS FROM `isucon5q` LIKE 'relations'\G # SHOW CREATE TABLE `isucon5q`.`relations`\G # EXPLAIN /*!50100 PARTITIONS*/ SELECT * FROM relations WHERE one = '3657' OR another = '3657' ORDER BY created_at DESC\G (snip)
アプリケーション解析の設定
- rack-lineprof を仕込む（事前に bundle install しておく）
$ diff -u app.rb.original app.rb --- app.rb.original 2016-09-25 11:59:24.195894782 +0900 +++ app.rb 2016-09-25 12:00:10.071619573 +0900 @@ -4,6 +4,7 @@ require 'tilt/erubis' require 'erubis' require 'rack-lineprof' +require 'profiler' module Isucon5 class AuthenticationError < StandardError; end @@ -18,6 +19,7 @@ end class Isucon5::WebApp < Sinatra::Base + use Rack::Lineprof use Rack::Session::Cookie set :erb, escape_html: true set :public_folder, File.expand_path('../../static', __FILE__)
- アプリケーションにアクセス
ブラウザで 192.168.33.10/?lineprof=app.rb にアクセスする。
$ sudo journalctl -f (snip) 9月 25 12:04:18 vagrant bundle[5117]: ....... 9月 25 12:04:18 vagrant bundle[5117]: | 189 entry[:title] = entry[:body].split(/\n/).first 9月 25 12:04:18 vagrant bundle[5117]: | 190 entries_of_friends << entry 9月 25 12:04:18 vagrant bundle[5117]: 2.9ms 3 | 191 break if entries_of_friends.size >= 10 9月 25 12:04:18 vagrant bundle[5117]: | 192 end 9月 25 12:04:18 vagrant bundle[5117]: | 193 9月 25 12:04:18 vagrant bundle[5117]: 151.4ms 1587 | 194 comments_of_friends = [] 9月 25 12:04:18 vagrant bundle[5117]: 114.7ms 528 | 195 db.query('SELECT * FROM comments ORDER BY created_at DESC LIMIT 1000').each do |comment| 9月 25 12:04:18 vagrant bundle[5117]: 0.4ms 20 | 196 next unless is_friend?(comment[:user_id]) 9月 25 12:04:18 vagrant bundle[5117]: | 197 entry = db.xquery('SELECT * FROM entries WHERE id = ?', comment[:entry_id]).first 9月 25 12:04:18 vagrant bundle[5117]: | 198 entry[:is_private] = (entry[:private] == 1) 9月 25 12:04:18 vagrant bundle[5117]: ....... 9月 25 12:04:18 vagrant bundle[5117]: | 200 comments_of_friends << comment 9月 25 12:04:18 vagrant bundle[5117]: | 201 break if comments_of_friends.size >= 10 9月 25 12:04:18 vagrant bundle[5117]: 151.8ms 1884 | 202 end 9月 25 12:04:18 vagrant bundle[5117]: 128.2ms 627 | 203 9月 25 12:04:18 vagrant bundle[5117]: 2.4ms 84 | 204 friends_query = 'SELECT * FROM relations WHERE one = ? OR another = ? ORDER BY created_at DESC' 9月 25 12:04:18 vagrant bundle[5117]: | 205 friends_map = {} 9月 25 12:04:18 vagrant bundle[5117]: 0.4ms 2 | 206 db.xquery(friends_query, current_user[:id], current_user[:id]).each do |rel| 9月 25 12:04:18 vagrant bundle[5117]: | 207 key = (rel[:one] == current_user[:id] ? :another : :one) 9月 25 12:04:18 vagrant bundle[5117]: | 208 friends_map[rel[key]] ||= rel[:created_at] 9月 25 12:04:18 vagrant bundle[5117]: ....... 9月 25 12:04:18 vagrant bundle[5117]: | 211 9月 25 12:04:18 vagrant bundle[5117]: | 212 query = <<SQL 9月 25 12:04:18 vagrant bundle[5117]: 170.6ms 641 | 213 SELECT user_id, owner_id, DATE(created_at) AS date, MAX(created_at) AS updated 9月 25 12:04:18 vagrant bundle[5117]: | 214 FROM footprints 9月 25 12:04:18 vagrant bundle[5117]: | 215 WHERE user_id = ? 9月 25 12:04:18 vagrant bundle[5117]: ....... (snip)
上記のように行ごとに処理に要した時間が出力される。
ひとまず
解析する為の仕込みは出来た。ただ、これらから何を読み取って、どこを改善していくか...ここからが本当の isucon なんだと思う。
Nginx の rewrite を使ったリダイレクトで URL に #（アンカーリンク）が付いていたらどうなるの？
追記
以下、同僚のぐっさんに教えて頂いたので追記。
#fooの事をフラグメント識別子（URL フラグメント / Fragment identifier）と呼ぶ（https://www.w3.org/DesignIssues/Fragment.html）- フラグメント識別子はサーバーへ送信されない
tl;dr
http://xxx.xxx.xx.xxx/index.html#foo のようなリンクを http://xxx.xxx.xx.xxx/maintenance.html にリダイレクトさせた場合に、#foo ってどうなのかなと思って調べてみた。
出来れば、リダイレクト先では #foo を削除出来たら嬉しい。
memo
試した環境
bash-3.2$ sw_vers ProductName: Mac OS X ProductVersion: 10.11.6 BuildVersion: 15G31 bash-3.2$ docker-machine -version docker-machine version 0.6.0, build e27fb87 bash-3.2$ docker exec -t -i nginx nginx -v nginx version: nginx/1.11.3
結論
- リダイレクト先にも
#はくっついてくる
雑な Nginx 設定
server { listen 80; server_name example.org; charset utf-8; location / { root html; index index.html index.htm; rewrite /index.html /maintenance.html permanent; } }
Dockerfile は以下のように用意。
FROM nginx:alpine RUN rm /etc/nginx/conf.d/default.conf RUN mkdir /etc/nginx/html ADD maintenance.html /etc/nginx/html/ ADD index.html /etc/nginx/html/ ADD demo.conf /etc/nginx/conf.d/
各コンテンツ。
bash-3.2$ cat index.html index.html bash-3.2$ cat maintenance.html maintenance.html
以下のようにコンテナを起動。
docker run --name=nginx -d -p 80:80 inokappa/nginx-demo
curl で試す
bash-3.2$ curl -vL 'http://xxx.xxx.xx.xxx/index.html#foo' * Trying xxx.xxx.xx.xxx... * Connected to xxx.xxx.xx.xxx (xxx.xxx.xx.xxx) port 80 (#0) > GET /index.html HTTP/1.1 > Host: xxx.xxx.xx.xxx > User-Agent: curl/7.43.0 > Accept: */* > < HTTP/1.1 301 Moved Permanently < Server: nginx/1.11.3 < Date: Tue, 20 Sep 2016 13:59:40 GMT < Content-Type: text/html < Content-Length: 185 < Location: http://xxx.xxx.xx.xxx/maintenance.html < Connection: keep-alive < * Ignoring the response-body * Connection #0 to host xxx.xxx.xx.xxx left intact * Issue another request to this URL: 'http://xxx.xxx.xx.xxx/maintenance.html' * Found bundle for host xxx.xxx.xx.xxx: 0x7fed63d10e70 * Re-using existing connection! (#0) with host xxx.xxx.xx.xxx * Connected to xxx.xxx.xx.xxx (xxx.xxx.xx.xxx) port 80 (#0) > GET /maintenance.html HTTP/1.1 > Host: xxx.xxx.xx.xxx > User-Agent: curl/7.43.0 > Accept: */* > < HTTP/1.1 200 OK < Server: nginx/1.11.3 < Date: Tue, 20 Sep 2016 13:59:40 GMT < Content-Type: text/html; charset=utf-8 < Content-Length: 17 < Last-Modified: Tue, 20 Sep 2016 07:12:24 GMT < Connection: keep-alive < ETag: "57e0e158-11" < Accept-Ranges: bytes < maintenance.html * Connection #0 to host xxx.xxx.xx.xxx left intact
よく見ると...
< Location: http://192.168.99.100/maintenance.html
Response ヘッダの Location は http://192.168.99.100/maintenance.html で返ってきているのでなんか期待できそうだ。
ブラウザで見る
それ、リダイレクト。
うおお、#foo が付いたままや。
アクセスログ見てみる
とりあえず、アクセスログを見てみる。
# curl でアクセスした場合 xxx.xxx.xx.x - - [20/Sep/2016:13:59:40 +0000] "GET /index.html HTTP/1.1" 301 185 "-" "curl/7.43.0" "-" xxx.xxx.xx.x - - [20/Sep/2016:13:59:40 +0000] "GET /maintenance.html HTTP/1.1" 200 17 "-" "curl/7.43.0" "-" # ブラウザでアクセスした場合 xxx.xxx.xx.x - - [20/Sep/2016:14:03:49 +0000] "GET /index.html HTTP/1.1" 301 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/53.0.2785.116 Safari/537.36" "-" xxx.xxx.xx.x - - [20/Sep/2016:14:03:49 +0000] "GET /maintenance.html HTTP/1.1" 200 17 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/53.0.2785.116 Safari/537.36" "-"
あら、ログには #foo はくっついてきてませんがな。イメージとしてクエリパラメータ（?foo=bar）と同じような内容を想定していたけど。ちなみに、クエリパラメータをくっつけた場合には以下のようなログが記録される。
# curl でアクセスした場合 xxx.xxx.xx.x - - [20/Sep/2016:14:11:34 +0000] "GET /index.html?foo=bar HTTP/1.1" 301 185 "-" "curl/7.43.0" "-" xxx.xxx.xx.x - - [20/Sep/2016:14:11:34 +0000] "GET /maintenance.html?foo=bar HTTP/1.1" 200 17 "-" "curl/7.43.0" "-" # ブラウザでアクセスした場合 xxx.xxx.xx.x - - [20/Sep/2016:14:12:10 +0000] "GET /index.html?foo=bar HTTP/1.1" 301 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/53.0.2785.116 Safari/537.36" "-" xxx.xxx.xx.x - - [20/Sep/2016:14:12:10 +0000] "GET /maintenance.html?foo=bar HTTP/1.1" 200 17 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/53.0.2785.116 Safari/537.36" "-"
ちゃんとクエリパラメータがログに記録されている。これであればサーバーサイドでパラメータを削除したり、書き換えたりすることができそう。ちなみに、クエリパラメータを削除したい場合には以下のような設定を書くことでクエリパラメータを削除した状態でリダイレクトされる。
server { listen 80; server_name example.org; charset utf-8; location / { root html; index index.html index.htm; rewrite /index.html /maintenance.html? permanent; } }
ということで
アンカーリンクは...
リダイレクト先にも引き継がれてしまう。
なんで？
アンカーリンクでサーバーサイドというよりもブラウザで解釈されるものだからかなと。
誤り等あればご指摘頂ければ幸いです。
Elasticsearch の Multi Search API メモ
tl;dr
- 定期的に Elasticsearch に問い合わせを行うバッチスクリプトで Elasticsearch への問い合わせ回数を減らしたい
memo
状況
- Amazon ES に保存されたログを検索するバッチスクリプトで特定の ID 毎に日付を範囲してログの件数を取得する
- 当初は ID が少なかったのであまり意識していなかったけど、テストで ID を増やしていったところ CPU 負荷も上がるし、たまに Amazon ES への接続エラーも発生している（認証辺りも絡んでいるかもしれない）
- ID 毎に Elasticsearch に問い合わせを行う実装にしていた（先に気づけよ的な話ではある）
戦略
Multi Search API で実装すれば良さそう。
Multi Search API を使う前
以下のような感じのスクリプトで ID 毎に Elaseticsearch に検索していた。
#!/bin/bash declare -A _hash _hash["foo"]="2016-09-19T10:00:00+09:00" _hash["bar"]="2016-09-19T10:00:00+09:00" _hash["baz"]="2016-09-19T10:00:00+09:00" while true; do for key in ${!_hash[@]}; do curl -s -XGET "https://${AMAZON_ES_ENDPOINT}/cwl-*/_search" -w "\n" -d " { \"size\": 0, \"query\" : {\"term\" : { \"param_id\" : \"${key}\" }}, \"aggregations\": { \"id_name\": { \"terms\": {\"field\": \"param_id\"}, \"aggregations\": { \"id_count\": { \"filter\":{ \"range\": { \"@timestamp\": { \"gte\": \"${_hash[${key}]}\", \"lte\": \"now\" }} } } } } } }" | jq -c '.aggregations.id_name.buckets[0]|{"id": .key, "count": .id_count.doc_count}' sleep 1 done sleep 3 done
実行すると以下のような出力が得られる。
{"count":867,"id":"foo"} {"count":863,"id":"bar"} {"count":865,"id":"baz"}
Multi Search API を使った場合
以下のような感じで検索する。コードの行数も減らせてイイ感じ。
#!/bin/bash declare -A _hash _hash["foo"]="2016-09-19T10:00:00+09:00" _hash["bar"]="2016-09-19T10:00:00+09:00" _hash["baz"]="2016-09-19T10:00:00+09:00" while true; do queries="" for key in ${!_hash[@]}; do queries+="{\"index\": \"cwl-*\"}\n" queries+="{\"size\": 0,\"query\" : {\"term\" : { \"param_id\" : \"${key}\" }},\"aggregations\": {\"id_name\": {\"terms\": {\"field\": \"param_id\"},\"aggregations\": {\"id_count\": {\"filter\":{\"range\": { \"@timestamp\": { \"gte\": \"${_hash[${key}]}\", \"lte\": \"now\" }}}}}}}}\n" done echo -e ${queries} | curl -s -XGET 'https://${AMAZON_ES_ENDPOINT}/_msearch' --data-binary @- | \ jq -c '.responses[].aggregations.id_name.buckets[0]|{"count":.id_count.doc_count,"id":.key}' sleep 3 done
実行すると以下のような出力が得られる。
{"count":1778,"id":"foo"} {"count":1744,"id":"bar"} {"count":1841,"id":"baz"}
Multi Search API を使う場合、クエリは以下のような内容となる。
{"index": ${インデックス名}} {"query" : ${実際のクエリ} {"index": ${インデックス名}} {"query" : ${実際のクエリ}
Elasticsearch へのリクエストは以下のような内容となる。
echo -e ${queries} | curl -s -XGET 'https://${AMAZON_ES_ENDPOINT}/_msearch' --data-binary @-
で、Multi Search API を使ったらどうなったか
以下のようにバッチを動かしているコンテナの CPU 使用率が少しだけ下がった。
以上
必要に応じて Multi Search API を使いましょう。
