突然ですが、皆さんは、馬に乗ったことはありますか？・・・このお話にご興味のある方は本文の最後の【閑話休題】までどうぞ。
さて、今回は、 Event Tracing for Windows (ETW) についてお話ししようと思います。ドライバ開発者の方にとって、なぜ、 ETW が必要なのでしょうか？読者の皆様にもご経験があるかもしれませんが、エンドユーザ様の運用環境の現象を、開発側で再現できない場合や、開発側でカーネルデバッガを接続し、Checked Build 版ドライバでデバッグプリントを出力すると、タイミングが変わって現象が再現しない場合があります。このような時、ドライバに ETW を実装しておくと、エンドユーザ様の運用環境で現象を再現することさえできれば、追加で何かをインストールする必要なく、かつ、パフォーマンスに影響を与えることもほとんどなく、デバッグプリント並みの詳細なログが取ることができるのです。追加で何かのインストールが必要ない、というのは、 OS にすでに入っているツール (logman.exe) を使ってログを採取することができる、ということです。ただ、一方で、「」の記事にも書いた通り、常時採取するには向いていません。短時間でもデータ量が非常に多くなってディスクスペースを圧迫する可能性がありますし、データ量を抑えようとしてサイクリックに上書きすると、肝心のエラー時の情報が上書きで消されてしまう可能性があるからです。そのため、イベントログで、トラブルが発生した時点を特定し、そのログの内容からトラブルシューティングを始め、現象発生の手順が確立した段階で、現象発生の前後のみ、 ETW のログを採取することが良いかと思います。
また、さらに言えば、 ETW はドライバ開発者以外の方にとっても重要な場合があります。ドライバ開発者にとって ETW が必要な理由を申し上げましたが、同じことは OS のコンポーネントにも言えます。つまり、 OS のコンポーネントの詳細なログ採取も行えます。以前の記事「」や「」、「」などは、 ETW を使用しています。
なお、ここで一点ご注意いただきたいのは、 ETW で採取できるログはバイナリ形式であることです。そのため、上記のブログ記事で紹介しているツールなどは、ログを人間が読みやすい形式に変換していますし、本ブログでも、バイナリ形式からテキスト形式に変換する方法をご紹介します。
今回のブログでは、 ETW について、以下の内容をご説明します。
1. ETW の仕組み
2. ログの採取と表示
3. ドライバへの ETW の実装
1. ETW の仕組み
ETW は、以下の図の通り、「プロバイダ」「コントローラ」「コンシューマー」の 3 つのコンポーネントで構成されています。
まず、図の左下にある「プロバイダ」は、読者の方のドライバやアプリケーション、 OS のコンポーネントのことです。何を provide するかというと、ログ出力されるトレースメッセージです。
OS のコンポーネントについては、例えば、以下のコマンドを実行することで OS のプロバイダを見ることができます。
| > logman query providers | more |
左側の名前に対し、右側に対応する GUID が表示されていますが、この GUID が何を表すのかは、後でご説明します。
続いて、図の上にある「コントローラ」とは、プロバイダからのトレースメッセージの出力を、有効にするか、無効にするかをコントロールするものです。例えば、先ほど少し出てきた logman.exe は、どのプロバイダにログを出させるかを GUID で指定して、ログ出力を開始したり、停止したりします。
また、コントローラは、セッションのコントロールもします。「セッション」（図の中央）とは、厳密に言えば、1つ以上のプロバイダが生成するログを、1つのログファイルに書く期間、のことですが、このブログではあまり気にする必要はないと思います。図の中央は、プロバイダから出力されたログがセッション内のバッファに書かれ、それが図の右側のトレースファイルに書きこまれています。が、コントローラについては、要は、ログ出力を開始したり停止したりするんだな、ということだけご理解いただければ十分です。
最後に、図の右下の「コンシューマー」とは、図の右側のトレースファイル（ログファイル）上のログを表示するものです。また、セッションにあるログをリアルタイムに表示することもできます。
2. ログの採取と表示
それでは、実際に ETW でログを採取し、採取したログの内容を表示する手順をご説明します。
今回、例として WDK のサンプル tracedrv を使用します。tracedrv サンプルは、
\WinDDK\{ バージョン}\src\general\tracing\tracedrv
のフォルダにあります。 ( WDK 6001.18002 以前の場合は generalの直下にtracedrvフォルダがあります。 )
tracedrv フォルダには、 tracectl と tracedrv という2つのサブフォルダがあります。tracectl フォルダをビルドすると、 tracectl.exe ができます。 tracedrv フォルダをビルドすると、 tracedrv.sys ができます。これらは、以下の図のように、 tracectl.exe を実行することで、 tracedrv.sys をロードします。 tracectl.exe は、 tracedrv.sys に I/O Control を発行することで、 tracedrv.sys のログを出力します。tracectl.exe を終了すると、 tracedrv.sys もアンロードされます。
これらを使って、ログを採取し、表示するまでの流れは、以下の図のようになります。
この図で示した手順は以下の通りです。
(1) tracedrv フォルダをビルド
運用環境でもログが採取できることをご理解いただくために、ここでは Free Build を行います。
(2) tracectl フォルダをビルド
ここで生成された tracectl.exe を (1) の tracedrv.sys と同じフォルダにコピーします。
これは、 tracectl.exe が同じフォルダの tracedrv.sys を制御する作りになっているからです。
(3) tracepdb.exe を使って、tracedrv.pdb ファイルから TMF ファイルを抽出
tracepdb.exe とは、ドライバやアプリケーションのシンボルファイル (.pdb) からトレースメッセージ情報を抽出し、 Trace Message Format (.tmf) ファイルを生成するツールです。なぜシンボルファイルからトレースメッセージ情報を抽出するかというと、後でドライバから採取したログファイルをバイナリ形式からテキスト形式に変換するために使うからです。
tracepdb.exe は、 WDK の以下のフォルダにあります。
\WinDDK\{ バージョン}\tools\tracing\
tracepdb.exe の詳細は、以下のドキュメントをご参照ください。
Tracepdb
手順 (1) で tracedrv ドライバをビルドした時に、 tracedrv.pdb というシンボルファイルができます。このシンボルファイルからトレースメッセージ情報を抽出するために、 tracepdb.exe をコマンドプロンプトから以下のように実行します。
| > tracepdb -f <path>\tracedrv.pdb |
(4) トレースのターゲットの GUID を Control GUID ファイル (.ctl) に保存
「1. ETW の仕組み」で少しお話ししたように、 ETW のコントローラは、ログ出力するプロバイダ(ここでは tracedrv.sys ドライバ) を GUID で指定します。 tracedrv.sys の GUID は、 tracedrv.h の 36行目から、以下のように定義しています。
| 36 #define WPP_CONTROL_GUIDS \ 37 WPP_DEFINE_CONTROL_GUID(CtlGuid,(d58c126f, b309, 11d1, 969e, 0000f875a5bc), \ 38 WPP_DEFINE_BIT(FLAG_ONE) \ 39 WPP_DEFINE_BIT(FLAG_TWO) ) |
今回、ログを出力するのは、 tracedrv.sys 1つだけなので、今回のような場合は、 ETW のコントローラで GUID を指定する際に、直接 GUID を記述すればいいので、必ずしもこの手順は必要ありません。ただ、運用環境では、発生した問題に関連すると思われる、複数のプロバイダのログを、同時に取りたい場合があります。そのような時、複数の GUID を Control GUID ファイル (.ctl) にまとめておけば、 ETW のコントローラは、書かれたすべての GUID のプロバイダのログを、1つのログファイルに集約してくれます。このことにより、必要なコンポーネントのログが時系列にすべて並ぶことになり、コンポーネント相互の関連性がわかりやすくなります。
本サンプルの tracedrv サブフォルダには、実はすでに上記 GUID を記載した tracedrv.ctl というファイルがあります。内容は、以下のようなコマンドを実行したのと同じです。
| > echo d58c126f-b309-11d1-969e-0000f875a5bc CtlGuid > tracedrv.ctl |
このファイルがなくなってしまっても、テキストファイルに「d58c126f-b309-11d1-969e-0000f875a5bc CtlGuid」という内容を保存し、 tracedrv.ctl というファイル名にリネームすれば OK です。
Control GUID ファイルについては、以下のドキュメントをご参照ください。
Control GUID File
(5) tracelog.exe を使って、ログの採取を開始
tracelog.exe とは、ログの採取を開始・停止するツールです。「1. ETW の仕組み」で少しお話しした ETW のコントローラです。これは、tracepdb.exe と同様に WDK の \WinDDK\{バージョン}\tools\tracing\ フォルダに含まれています。 OS に同梱されているものではありません。 OS に同梱されている ETW のコントローラは logman.exe ですが、これの利用例については、後程ご紹介します。
tracelog.exe の詳細は、以下のドキュメントをご参照ください。
Tracelog
tracelog.exe を使って、ログの採取を開始するためには、以下のようなコマンドを実行します。
| > tracelog -start TestTracedrv -guid tracedrv.ctl -f tracedrv.etl -flag 1 |
-start というオプションでログの採取の開始を表します。 TestTracedrv というのは開始したログ採取のトレースセッションの名前です。この名前は任意のものをつけることができます。この名前は、後述の手順 (7) でログの採取を終了する時に使います。-f オプションで tracedrv.etl というログファイル（トレースファイル）を指定します。-flag は、ログを採取する際の詳細さのレベルを表すフラグです。 (4) で tracedrv.sys の GUID を以下のように定義していますが、この FLAG_ONE や FLAG_TWO というのがフラグです。
| 36 #define WPP_CONTROL_GUIDS \ 37 WPP_DEFINE_CONTROL_GUID(CtlGuid,(d58c126f, b309, 11d1, 969e, 0000f875a5bc), \ 38 WPP_DEFINE_BIT(FLAG_ONE) \ 39 WPP_DEFINE_BIT(FLAG_TWO) ) |
FLAG_ONE は 1、 FLAG_TWO は 2 で、その後にもし WPP_DEFINE_BIT() が定義されていれば、その値は 4, 8, 16, ... と続いていきます。これらのフラグを指定することで、そのフラグが指定されたメッセージをログに出力することができます。言い換えれば、 -flag でフラグを指定しないと、 tracedrv.sys はトレースメッセージを出力しない、ということです。
(6) tracectl.exeを使って、トレースメッセージを生成
コマンドプロンプト上で tracectl.exe をオプションなしで実行します。すると、tracedrv.sys がロードされます。コマンドプロンプト上で Q または q 以外の文字を入力するたびに、 tracectl.exe は I/O Control を tracedrv.sys に送り、 tracedrv.sys はトレースメッセージを生成します。今回はa, b, cと入力し、最後に、 tracectl.exe を停止するために、Q または q を入力します。入力すると、 tracedrv.sys もアンロードされます。
なお、実際に読者の方のドライバでこの手順を実施する時は、対象ドライバのアンロードは必要ありません。ドライバがロードされ、実行されている任意のタイミングから、ログの採取を開始・終了できます。
(7) tracelog.exe を使い、ログの採取を停止
ログ出力をさせたい対象のドライバ tracedrv.sys によるログ出力が終わりましたので、 tracelog.exe を使って、ログの採取を停止するためには、以下のようなコマンドを実行します。
| > tracelog -stop TestTracedrv |
TestTracedrv というのは、 (5) で指定したトレースセッションの名前です。
ログの採取を停止すると、 (5) で指定したログファイル tracedrv.etl に、未だ出力できていなかった残りのログが全て出力されます。
(8) tracefmt.exe を使い、 tracedrv.etl のトレースメッセージを表示
tracefmt.exe とは TMF ファイルのトレースメッセージ情報を使って、バイナリのトレースログファイル (.etl) をテキスト形式に変換するツールです。これも、 tracepdb.exe などと同様に WDK の \WinDDK\{バージョン}\tools\tracing\ フォルダに含まれています。
tracefmt.exe についての詳細は、以下のドキュメントをご参照ください。
Tracefmt
これを実行するには、コマンドプロンプトで以下のコマンドを実行します。
| > tracefmt tracedrv.etl -p <Path to TMF file> -o Tracedrv.out |
<Path to TMF file>は TMF ファイルのある親フォルダまでを指定します。 Tracedrv.outファイルは tracedrv.sys のトレースメッセージをテキスト形式に変換したファイルです。
Tracedrv.out ファイルの内容は以下のように表示されます。
| [0]10E4.15DC::12/08/2011-19:12:05.852 [tracedrv]IOCTL = 1 [0]10E4.15DC::12/08/2011-19:12:05.852 [tracedrv]Hello, 1 Hi [0]10E4.15DC::12/08/2011-19:12:05.852 [tracedrv]Hello, 2 Hi [0]10E4.15DC::12/08/2011-19:12:05.852 [tracedrv]Hello, 3 Hi [0]10E4.15DC::12/08/2011-19:12:05.852 [tracedrv]Function Return=0x8000000f(STATUS_DEVICE_POWERED_OFF) [0]10E4.15DC::12/08/2011-19:12:06.126 [tracedrv]IOCTL = 2 [0]10E4.15DC::12/08/2011-19:12:06.126 [tracedrv]Hello, 1 Hi [0]10E4.15DC::12/08/2011-19:12:06.126 [tracedrv]Hello, 2 Hi [0]10E4.15DC::12/08/2011-19:12:06.126 [tracedrv]Hello, 3 Hi [0]10E4.15DC::12/08/2011-19:12:06.126 [tracedrv]Function Return=0x8000000f(STATUS_DEVICE_POWERED_OFF) [0]10E4.15DC::12/08/2011-19:12:06.580 [tracedrv]IOCTL = 3 [0]10E4.15DC::12/08/2011-19:12:06.580 [tracedrv]Hello, 1 Hi [0]10E4.15DC::12/08/2011-19:12:06.580 [tracedrv]Hello, 2 Hi [0]10E4.15DC::12/08/2011-19:12:06.580 [tracedrv]Hello, 3 Hi [0]10E4.15DC::12/08/2011-19:12:06.580 [tracedrv]Function Return=0x8000000f(STATUS_DEVICE_POWERED_OFF) |
以上の通り、 tracedrv.sys が出力するログを採取し、テキスト形式で表示することができました。しかし、読者の方のエンドユーザ様の運用環境によっては、手順(5)や(7)のように tracelog.exe を入れさせてもらうことは許容できない場合があります。そんな場合は、以下の手順のように、 OS に予め含まれている logman.exe を代わりに使用することができます。なお、 logman.exe については、以下のドキュメントをご参照ください。
Logman
■ logman.exe によるログの採取方法
(l-1) tracedrv.sys のログ採取に必要な GUID、flag を .ctl ファイルに保存
コマンドプロンプトで、以下を実行し、 tracedrv.sys のログ採取に必要な GUID と flag を持つ TestTrace.ctl というファイルを作ります。
| > echo {d58c126f-b309-11d1-969e-0000f875a5bc} 0x1 > TestTrace.ctl |
.ctl という拡張子や GUID を保存するのは、先ほどの手順 (4) に似ていますが、 CtlGuid のようなフレンドリーネームはなく、代わりに、 0x1 というフラグを指定している点にご注意ください。 tracelog.exe と logman.exe は、同じ機能を持ちますが、全く異なる Syntax を持っているツールだとお考えください。
(l-2) logmam.exe を使って、ログの採取を開始
管理者権限でコマンドプロンプトを起動して、.ctl が保存されているディレクトリに移動して、以下のコマンドを実行します。
| > logman -ets start TestTrace -pf TestTrace.ctl |
-ets というオプションは、event trace session のことを表します。要は、 -ets start でログ採取を開始する、とお考えください。 TestTrace は、手順 (5) の TestTracedrv と同様に、トレースセッション名であり、 (l-4) でログ採取を終了するのに使う名前です。 -pf オプションの後に、(l-1)の TestTrace.ctl を指定することで、ログ採取対象の GUID と フラグを指定できます。
(l-3) トレース対象のモジュールのテスト
上記手順 (6) と同じです。
(l-4) logmam.exe を使って、ログの採取を停止
テストが終了したら、以下のコマンドを実行します。
| > logman -ets stop TestTrace |
-ets stop でログ採取を停止する、ということです。 TestTrace はどのログ採取を停止するかを名前で指定すると同時に、これにより、 TestTrace.etl ファイルが生成されます。この etl ファイルは、手順 (7) と同じバイナリファイルで、手順 (8) のようにテキスト形式に変換する必要があります。
■ GUI ツール traceview.exe について
さて、ここまではコマンドプロンプトでのログ採取方法をご案内しましたが、実は WDK には GUI のツールもあります。それが traceview.exe です。これは、 tracelog + tracepdb + tracefmt の役割を持ちます。言い換えれば、ログの採取の開始、停止、シンボルファイルからのトレースメッセージの抽出、ログファイルをテキスト形式で表示、ということができます。これも、 tracepdb.exe などと同様に WDK の \WinDDK\{バージョン}\tools\tracing\ フォルダに含まれています。ご興味のある方は、以下のドキュメントをご参照いただき、使ってみてください。
TraceView
3. ドライバへの ETW の実装
さて、ここからは、自分のドライバにどのように ETW の機能を実装すればよいのかについてお話しします。これからご説明するのは、 Windows プリプロセッサ (WPP) ソフトウェア トレース というものです。具体的なコードを確認していただく場合は、先ほどの tracedrv サンプルをベースにお話しします。
(a) guidgen.exe を使用してコンポーネント用のGUIDを新しく取得
guidgen.exe は、 SDK の以下のフォルダにあります。
\Microsoft SDKs\Windows\{ バージョン}\Bin\
起動すると以下のようなGUIツールが起動します。
tracedrv サンプルの場合は、取得済みの GUID が既出の通り、 tracedrv.h の 36 行目から使用されています。
(b) 任意のヘッダファイルでデバッグフラグとGUIDを定義
tracedrv.h において、その取得済みの GUID は、以下のように定義されています。
| 36 #define WPP_CONTROL_GUIDS \ 37 WPP_DEFINE_CONTROL_GUID(CtlGuid,(d58c126f, b309, 11d1, 969e, 0000f875a5bc), \ 38 WPP_DEFINE_BIT(FLAG_ONE) \ 39 WPP_DEFINE_BIT(FLAG_TWO) ) |
先ほど触れましたが、 CtlGuid というフレンドリーネームをつけています。また、 WPP_DEFINE_BIT() でどのメッセージを出力するかを選ぶためのフラグを定義しています。WPP_DEFINE_BIT() を並べた順に、 1,2,4,8,... という値が割り当てられます。
WPP_CONTROL_GUIDS マクロについては、以下のドキュメントをご参照ください。
WPP_CONTROL_GUIDS
(c) ログを出力する .c ファイルごとに、 (b) のヘッダファイルと、.cファイルと同じ名前の .tmh ファイルをインクルード
tracedrv.c の 23,24 行目をご参照ください。
| 23 #include "tracedrv.h" 24 #include "tracedrv.tmh" // this is the file that will be auto generated |
23 行目の tracedrv.h は (b) のように WPP_CONTROL_GUIDS マクロを使ったヘッダファイルです。24 行目の tracedrv.tmh ファイルは、コメントにある通り、ビルド時に自動生成されるファイルです。tracedrv.c に記述する場合は、 tracedrv.tmh ファイルが自動生成されるので、 24 行目の通りに書きます。.tmh ファイルとは、 Trace Message Header ファイルで、ソースファイル上のソフトウェアトレース用のコードのビルドに必要な宣言や定義が入ったヘッダファイルです。手順 (3) に出てきた TMF ファイルを作るのに必要な情報をシンボルファイル (.pdb)に入れる役割があります。
(d) DriverEntry ルーチンに WPP_INIT_TRACING 呼び出しを追加
WPP_INIT_TRACING マクロを呼ぶことによって、そのドライバがソフトウェアトレーシングの初期化をすることになります。具体的なコードは、tracedrv.c の 166 行目 (DriverEntry() 内 ) をご参照ください。
| 158 // 159 // This macro is required to initialize software tracing. 160 // 161 // Win2K use the deviceobject as the first argument. 162 // 163 // XP and beyond does not require device object. First argument 164 // is ignored. 165 // 166 WPP_INIT_TRACING(pTracedrvDeviceObject,RegistryPath); |
この第一引数は、コメントにある通り、無視されるので、気にする必要はありません。第二引数は、ドライバへのレジストリパスとなっており、以下のような値が入ってきます。
_UNICODE_STRING "\Registry\Machine\System\CurrentControlSet\Services\<driver name>"
WPP_INIT_TRACING マクロの詳細については、以下をご参照ください。
WPP_INIT_TRACING
(e) DriverUnload ルーチンに WPP_CLEANUP 呼び出しを追加
WPP_CLEANUP マクロを呼ぶことによって、ソフトウェアトレーシングのクリーンアップを行います。具体的なコードは、tracedrv.c の 359 行目 (TracedrvDriverUnload() 内 ) をご参照ください。
| 355 // 356 // Cleanup using DeviceObject on Win2K. Make sure 357 // this is same deviceobject that used for initializing. 358 // On XP the Parameter is ignored 359 WPP_CLEANUP(pDevObj); |
この引数は、コメントの通り、無視されるので、気にする必要はありません。
WPP_CLEANUP マクロの詳細については、以下をご参照ください。
WPP_CLEANUP
(f) SOURCES ファイルに RUN_WPP を追加
SOURCES ファイルの 9 行目にあるように RUN_WPP ディレクティブの記述を追加します。
| 9 RUN_WPP= $(SOURCES) -km -func:DoTraceLevelMessage(LEVEL,FLAGS,MSG,...) -scan:tracedrv.h |
ここでポイントとなるのは、「RUN_WPP= $(SOURCES) -km」の部分です。RUN_WPP とは、WPP(Windows software trace PreProcessor)を実行するための記述です。WPP とは、手順 (d) や (e) で書かれている WPP マクロの処理を行ったり、ソースファイルごとの Trace Message Header (.tmh) ファイルの生成を行ったりします。 WPP はビルド時に実行されます。 -km オプションは、カーネルドライバを表すオプションです。その他のオプションの意味や、WPP プリプロセッサ自体については、以下のドキュメントをご参照ください。
WPP Preprocessor
(g) .c ファイルにトレースメッセージを追加
ログとして出力したいメッセージは、 DoTraceMessage() を使います。具体的なコードは、tracedrv.cの 259 行目 (TracedrvDispatchDeviceControl() 内 ) をご参照ください。
| 259 DoTraceMessage(FLAG_ONE, "IOCTL = %d", ioctlCount); |
上記のように、書式は、DoTraceMessage(フラグ, "メッセージ", 変数...) となっています。第一引数のフラグには、上記では FLAG_ONE が入っていますが、これは、(b) の#define WPP_CONTROL_GUID で定義したフラグです。「2. ログの採取と表示」の手順 (5) で -flag 1 としたように、フラグを有効にすることで、このメッセージが出力されます。DoTraceMessage() については以下のドキュメントをご参照ください。
DoTraceMessage
以上の手順で、ドライバに ETW のログ出力機能を実装することが可能です。読者の方のドライバ開発と運用でお役に立てば幸いです。
■参考文献
イベント トレース : ETW によりデバッグおよびパフォーマンス調整を改善する
イベント トレースについて
――――――――――――――――
【閑話休題】突然ですが、皆さんは、馬に乗ったことはありますか？
・・・いいえ、落馬した話ではありません。私は、引き馬と乗馬の両方体験したことがあります。引き馬は5年くらい前に、乗馬は数か月前に、それぞれ行ってきました。引き馬は、文字通り、インストラクターの方が馬を引いてくれる、乗馬の雰囲気を味わう感じのものです。通常は、馬を飼っている敷地の中をぐるぐる回るだけというイメージがあります。が、その時は、旅行ガイドの「砂浜で引き馬が体験できる！」という言葉と、海岸沿いのきれいな景色を馬が歩いている写真にひかれ、関東某所の海岸沿いの引き馬を体験しに行ったのでした。しかし、なんとタイミングの良いことでしょう。ちょうどその年は海岸の護岸工事中で、まったく砂浜の砂を踏むことなく、雑木林をぐるぐる回って終了したのでした・・・。
ちょうど引き馬をやった頃、乗馬にも興味があり、乗馬体験ができる場所をチェックしていたのですが、当時は行きませんでした。ですが、今年の初めごろに、友人の結婚式の引き出物として、カタログギフトをもらい、そこにちょうど乗馬体験のチケットがあったので、数か月前に行ってきました。馬に乗る前に、乗馬の基本のビデオを見てイメージをつかんだあと、その日に乗る馬のいるところまで移動しました。インストラクターの方は気さくな方で、私も話しやすく、「5年前くらいにも来ようと思っていたが、ようやく機会ができて来させてもらった」、という話をしました。体験自体は、全部で1時間ほどでしたが、乗馬の基本を教えてもらい、小さな円周上ではありますが、少し走れる程度にはなり、すごくうれしかったです。その後、インストラクターの方から乗馬教室の案内を受けました。乗馬には資格があるそうで、級が上がると、自分一人で雑木林を乗馬できるようになったり、某旅行会社の企画でモンゴルの大草原を馬で走れるようになったりする、という話を聞き、すごく魅力を感じました。ただ、今回は体験だけのつもりだったので、入会するつもりがないことを伝えました。すると、それまで友好的だったインストラクターさんの態度が一変しました。それまでは、楽しかったので、次は友人を誘って、また来たいと思っていたのですが、「そんな調子だと、次来るのも5年後になっちゃいますよね」と責められたり、「3回体験セットで＊万円だから、これだけでも」と執拗に食い下がられたりして、すごく悲しくなってしまいました。そして、その時やっと、なぜ5年前に来なかったのか、思い出しました。体験メニューのスケジュールに、乗馬体験の後、乗馬教室の案内の時間があると書かれており、当時、友人たちと相談した結果、この時間帯に非常に強く勧誘されそうだったので、やめていたのです。帰る支度をして、近くのバス停まで歩く間、乗馬体験で楽しかった気分はすっかり消え、ものすごく凹んだ気持ちになっている自分に気づきました。皆さんも、馬に乗る時は、凹んで帰らないようご注意ください。