KLab若手エンジニアの これなぁに?

KLab株式会社の若手エンジニアによる技術ブログです。phpやRubyなどの汎用LLやJavaScript/actionScript等のクライアントサイドの内容、MySQL等のデータベース、その他フレームワークまで幅広く面白い情報を発信します。

Symfonyのトランザクション処理時のログ出力内容を調査

Symfony(phpのフレームワーク)にて気になる部分があったので若手ホープのhonda-hに調査してもらった。 ※データベースはMySQL5、InnoDBを利用。 気になった部分 以下のコードサンプルのように 明示的にトランザクション処理を行ったとする。 Symfonyのログを見ると何故か4回づつbeginやcommitが行われたように sfCreoleのログが出力されている。 これでは、以下のコードサンプルの更新2の部分で エラーとなった場合に更新1も含めてロールバックしてほしいのに 更新1はコミットされたように見える。 しかし、SQLログを見るとサンプルコードで期待する結果となっている。 (begin ⇒ 更新1⇒ 更新2 ⇒ commit) コードサンプル:
    // 実際はもう少し処理をしているがコアな部分以外は割愛する
...
    $bookmark = new Bookmark();
    $bookmark->setTitle($this->getRequestParameter('title'));
    $bookmark->setUrl($this->getRequestParameter('url'));

    if ($this->getRequestParameter('category_id'))
    {
        $bookmark->setCategoryId($this->getRequestParameter('category_id'));
        $category = CategoryPeer::retrieveByPk($this->getRequestParameter('category_id'));
        $category->incrementSize();
    }

    $con = Propel::getConnection();  // DBコネクションオブジェクト取得

    try
    {
        $con->begin();  // トランザクション開始
        if ($this->getRequestParameter('category_id'))
        {
            $this->logMessage('{sfAction} save category.', 'info');
            $category->save($con);  // 更新1
        }
    
        $this->logMessage('{sfAction} save bookmark.', 'info');
        $bookmark->save($con);  // 更新2
    
        $this->logMessage('{sfAction} commit transaction.', 'info');
        $con->commit();  // コミット
    }
    catch (Exception $e)
    {
        $con->rollback();  // ロールバック
...
Symfonyログサンプル
Oct 28 11:29:51 symfony [info] {sfCreole} prepareStatement(): SELECT category.ID, category.TITLE, category.SIZE FROM category WHERE category.ID=?
Oct 28 11:29:51 symfony [info] {sfCreole} executeQuery(): [0.47 ms] SELECT category.ID, category.TITLE, category.SIZE FROM category WHERE category.ID=5
Oct 28 11:29:51 symfony [info] {sfCreole} connect(): DSN: array (   'compat_assoc_lower' => NULL,   'compat_rtrim_string' => NULL,   'database' => 'criteria_test',   'encoding' => 'cp932',   'hostspec' => 'localhost',   'password' => 'criteria_test',   'persistent' => NULL,   'phptype' => 'mysql',   'port' => NULL,   'protocol' => NULL,   'socket' => NULL,   'username' => 'criteria_test', ), FLAGS: 0
Oct 28 11:29:51 symfony [info] {sfCreole} beginning transaction.
Oct 28 11:29:51 symfony [info] {sfAction} save category.
Oct 28 11:29:51 symfony [info] {sfCreole} beginning transaction.
Oct 28 11:29:51 symfony [info] {sfCreole} prepareStatement(): UPDATE category SET SIZE = ? WHERE category.ID=?
Oct 28 11:29:51 symfony [info] {sfCreole} executeUpdate(): UPDATE category SET SIZE = 5 WHERE category.ID=5
Oct 28 11:29:51 symfony [info] {sfCreole} committing transaction.
Oct 28 11:29:51 symfony [info] {sfAction} save bookmark.
Oct 28 11:29:51 symfony [info] {sfCreole} beginning transaction.
Oct 28 11:29:51 symfony [info] {sfCreole} beginning transaction.
Oct 28 11:29:51 symfony [info] {sfCreole} prepareStatement(): INSERT INTO bookmark (CATEGORY_ID,TITLE,URL,CREATED_AT,UPDATED_AT) VALUES (?,?,?,?,?)
Oct 28 11:29:51 symfony [info] {sfCreole} executeUpdate(): INSERT INTO bookmark (CATEGORY_ID,TITLE,URL,CREATED_AT,UPDATED_AT) VALUES (5,'koreha hidoi','http://korea.hidoi/','2008-10-28 11:29:51','2008-10-28 11:29:51')
Oct 28 11:29:51 symfony [info] {sfCreole} committing transaction.
Oct 28 11:29:51 symfony [info] {sfCreole} committing transaction.
Oct 28 11:29:51 symfony [info] {sfAction} commit transaction.
Oct 28 11:29:51 symfony [info] {sfCreole} committing transaction.
SQLログサンプル:
# at 3946
#081028 11:29:51 server id 1  end_log_pos 4023 	Query	thread_id=47	exec_time=0	error_code=0
SET TIMESTAMP=1225160991/*!*/;
BEGIN
/*!*/;
# at 4023
#081028 11:29:51 server id 1  end_log_pos 4143 	Query	thread_id=47	exec_time=0	error_code=0
SET TIMESTAMP=1225160991/*!*/;
UPDATE category SET SIZE = 5 WHERE category.ID=5
/*!*/;
# at 4143
#081028 11:29:51 server id 1  end_log_pos 4171 	Intvar
SET INSERT_ID=40/*!*/;
# at 4171
#081028 11:29:51 server id 1  end_log_pos 4401 	Query	thread_id=47	exec_time=0	error_code=0
SET TIMESTAMP=1225160991/*!*/;
INSERT INTO bookmark (CATEGORY_ID,TITLE,URL,CREATED_AT,UPDATED_AT) VALUES (5,'koreha hidoi','http://koreha.hidoi/','2008-10-28 11:29:51','2008-10-28 11:29:51')
/*!*/;
# at 4401
#081028 11:29:51 server id 1  end_log_pos 4428 	Xid = 334
COMMIT/*!*/;
DELIMITER ;
ということで、honda-hの調査結果を次に書きます。 ではhonnda-h、あとはよろしく~ 調査結果

SMTPコマンドを打ってみよう

takada-atです。こんにちは。 amo-k先輩に「自分SMTPコマンドなんて打ったことないッス」と言うと、「おまえも打てよ、な?」と、まるで後輩に煙草を薦める不良の先輩のような調子で、SMTPコマンドを打つようにすごまれました。 というわけで今日は、telnetとSMTPコマンドを使い、メーラーになった気持ちでメールを送信してみます。 SMTPといっても何だかわからないという方もおられるでしょうが、SMTPは「Simple Mail Transfer Protocol(単純なメール転送プロトコロル)」の略であり、メール送信のために定められた手続きのことです。要するに「この決まりを守っていればメールを送受信できるよー」というきまりのことです。 どんなメーラーもメールサーバーも基本的には、SMTPに従った動作を実装しています。 Wikipediaの記事にリンクをはっておきます。 -Simple Mail Transfer Protocol - Wikipedia 最新のSMTPプロトコルは、RFC 5321で標準化されています。 わたしも全部読んだことはないのですが、以下にリンクを載せておきます。RFC5321の日本語訳は見つけられませんでしたが、旧版のRFC 821には複数の日本語訳があるようです。 -RFC 5321 - Simple Mail Transfer Protocol -RFC日本語版リスト SMTPでメールを送信するには、メールサーバーにtelnetでアクセスし、SMTPコマンドを送っていけばよいようです。 実際にやってみましょう。 同期の honda-h に「ランチに行きませんか」というメールを出してみます。 ↓honda-h


以下入力したコマンドを、C:からはじまる行に、サーバーからの返答をH:からはじまる行に書きます。 まずtelnetコマンドを使いmail.example.comの25番ポートにログインします。 (アドレスはすべて架空のものです)。
# telnet mail.example.com 25
> 220 mail.example.com ESMTP
HELOコマンドを入力し、こちらのサーバー名を伝えます。
C:HELO localhost
H:250 mail.example.com
MAILコマンドを利用し、差し出しアドレスを伝えます。
C:MAIL FROM:takada-at@example.com
H:250 ok
RCPTコマンドを利用し、送り先アドレスを伝えます。
C:RCPT TO:honda-h@example.com
H:250 ok
メールの本文はDATAコマンドを使って送ります。「.」だけで終る行がメッセージの終了を意味します。 今回はマルチバイト文字を使わず、ローマ字で送ってみることにします。
C:DATA
H:354 Please start mail input.
C:
Subject: lunch
From: takada-at@example.com

honda-h san. gohan tabe ni ikimasyou.
.

H:250 Mail queued for delivery.
最後にQUITコマンドを利用し、コネクションを切断します。メールサーバーはちゃんと挨拶ができる子のようです。
C:QUIT
H:221 Closing connection. Good bye.
もう少し実験してみましょう。 HELO の際に、nothing.example.com と答え、noone@example.com という存在しないアドレスにメールを送ります。 DATA コマンド中の From: の値も、noone@example.com にしておきます。
220 mail.example.com ESMTP
HELO nothing.example.com
250 mail.example.com
MAIL FROM: takada-at@example.com
250 ok
RCPT TO: noone@example.com
250 ok
DATA:
354 Please start mail input.
Subject: aaa
From: noone@example.com
cccc

.
250 Mail queued for delivery.
QUIT
221 Closing connection. Good bye.
こういう入力の仕方でも、メーラーデーモンからのリプライが takada-at@example.com に届きました。 デーモンからの返信先は必ず MAIL FROMで指定したアドレスとなるようです。 以上です。簡単ながら、自分で打ってみると、ブラックボックスに見えていたメール送信の仕組みが、心で理解できた気がします。やったことのない方はぜひ一度試してみるとよいのではないでしょうか。

SMTPコマンドを使って手動でメールを送ってみよう

amo-kです。 さて、SMTPクライント絡みでSMTPの話題です。 聞くところによるとtakada-at以外はSMTPコマンドを打ったことがあるそうです。 ということで今回はtakada-atにSMTPコマンドを使って手動でメールを送ってもらうことにします。 では、takada-at、よろしくお願いします~
 KLab若手エンジニアブログのフッター