読者です 読者をやめる 読者になる 読者になる

Yesod と HDBC-mysql と haskell-relational-record で “Commands out of sync”

Yesod と HDBC-mysqlhaskell-relational-record を一緒に使っているのだが、MySQL サーバーに「Commands out of sync; you can’t run this command now」って言われてぐぬぬってなって、最近デバッグをがんばっている。とりあえず途中経過をメモしておく。

そもそも MySQL プロトコルの呼び出し順とか知らないので苦戦していた。

この辺でエラーが出ている。結合をしなければエラーは出ない。

import Import hiding (on)
import Database.Relational.Query (on)
import qualified Model.Table.Account as Account
import qualified Model.Table.Tweet as Tweet
import qualified Model.Table.User as User

getTweetR :: AccountIdParam -> TweetIdParam -> Handler Html
getTweetR accountIdParam tweetIdParam = do
    user <- requireAuth
    p <- runRelational $ do
             accounts <- runQuery Account.selectAccount accountIdParam
             ts <- flip runQuery () $ relationalQuery $ relation $ do
                       t <- query Tweet.tweet
                       u <- query User.user
                       on $ t ! Tweet.userId' .=. u ! User.id'
                       wheres $ t ! Tweet.id' .=. value tweetIdParam
                       return $ (,) |$| t |*| u
             return (accounts, ts)
    case p of
        ([account@(Account _ _ _ _)], [(tweet@(Tweet _ _ _ _ _), tweetUser@(User _ _ _ _))]) -> do
            form <- generateFormPost commentForm
            defaultLayout $ do
                headerWidget $ Just user
                tweetWidget account user tweet form
        _ -> notFound

とりあえず HDBC-mysqlFFI で libmysqlclient を呼んでるので C のレベルでどの関数を呼んでいるのかログに出してみる。コードはこんな感じ。めっちゃ地道にログを挟んでいった。一部引用すると下記。

mysql_stmt_prepare :: Ptr MYSQL_STMT -> CString -> CInt -> IO CInt
mysql_stmt_prepare mysql a1 a2 = do
  s1 <- peekCString a1
  hPutStrLn stderr $ "mysql_stmt_prepare " ++ (show mysql) ++ " " ++ (show s1) ++ " " ++ (show a2)
  cr <- mysql_stmt_prepare_ mysql a1 a2
  hPutStrLn stderr $ "\t→ " ++ (show cr)
  return cr

そのログ出力が下記(別ページで開く)。同じ接続・同じステートメントに同じ色を塗った。

どうも mysql_stmt_execute した後に mysql_stmt_fetch せずに mysql_stmt_prepare するとダメっぽい。C で確認してみると下記のコードコメントアウトしてるところのありなしでエラーが出たり出なかったりするのでおそらく合ってる。

MYSQL_BIND result;
char display_name[100];
unsigned long display_name_length;
my_bool display_name_error;
memset(&result, 0, 1);
result.buffer = display_name;
result.buffer_length = sizeof(display_name) * sizeof(display_name[0]);
result.is_null = NULL;
result.length = &display_name_length;
result.error = &display_name_error;
{
    my_bool error = mysql_stmt_bind_result(stmt, &result);
    if (error) {
        fprintf(stderr, "mysql_stmt_bind_result\n");
        mysql_close(mysql);
        exit(1);
    }
}
// {
//     int fetch_result = mysql_stmt_fetch(stmt);
//     switch (fetch_result) {
//         case MYSQL_NO_DATA:
//             printf("mysql_stmt_fetch: MYSQL_NO_DATA\n");
//             break;
//         case MYSQL_DATA_TRUNCATED:
//             printf("mysql_stmt_fetch: MYSQL_DATA_TRUNCATED\n");
//             break;
//         default:
//             printf("mysql_stmt_fetch: %d\n", fetch_result);
//     }
//     printf("display_name: %s\n", display_name);
//     switch (result.buffer_type) {
//         case MYSQL_TYPE_BLOB:
//             printf("display_name type: MYSQL_TYPE_BLOB\n");
//         default:
//             printf("display_name type: %d\n", result.buffer_type);
//     }
//     printf("display_name_length: %ld\n", display_name_length);
//     printf("display_name_error: %d\n", display_name_error);
// }
{
    my_ulonglong rows = mysql_stmt_affected_rows(stmt);
    printf("mysql_stmt_affected_rows: %ld\n", (long)rows);
}
{
    MYSQL_STMT *stmt2 = mysql_stmt_init(mysql);
    if (stmt == NULL) {
        fprintf(stderr, "mysql_stmt_init: error\n");
        mysql_close(mysql);
        exit(1);
    }
    {
        const char * const stmt_str = "SELECT `email` FROM `user` WHERE `id` = ?";
        int error = mysql_stmt_prepare(stmt2, stmt_str, strlen(stmt_str));
        if (error) {
            fprintf(stderr, "mysql_stmt_prepare: error\n");
            fprintf(stderr, "error message: %s\n", mysql_stmt_error(stmt2));
            mysql_close(mysql);
            exit(1);
        }
    }
}

この FFI 呼び出しがどういう経緯で呼ばれてるかを探すのはこれから。

接続を使い回すようにしたのがダメなのかもしれない。

解決しました。(2017.03.17)

正格版の runQuery' があったのですね。