しかし自分のマシンからこのブログへアクセスすると、これらAmazon広告の一部が正しく表示されない、という現象が度々発生していました。具体的には、広告の一部が表示されなかったり、広告領域全てが表示されなかったり、といった具合です。
毎回起こるわけではありませんが、連続してリロードした場合などには、大変高い頻度で発生します。アクセスに使用するマシンはiMac、MacBook Airどちらでも生じます。また、Chrome、Safari、Firefox、何れのブラウザを用いても発生します(頻度は異なります)。Amazonの広告タイプやサイズを色々と変更してみたりもしたのですが、変化はありません。
Amazon側の問題だろう、と気楽に考えていたのですが、ふとWindows PCからアクセスしてみたところ、何度リロードを行っても広告が欠けないことに気が付きました。問題は私のMacOS X環境だったようです。
Amazonの広告はiframe内に表示されており、広告コンテンツはsrcアトリビュートで指定されたURLから取得されています。例えば「Amazonライブリンク」という広告用ウィジェットを用いた場合、srcへは次のようなURLが指定されています。
http://rcm-jp.amazon.co.jp/e/cm?t=foo&o=9&p=14&l=bn1&mode=books-jp&browse=202188011&fc1=000000<1=_blank&lc1=856953&bg1=FFFFFF&f=ifr;
表示が不正になった状態でiframeのソースを確認したところ、HTMLが途中で切れてしまっていることに気が付きました。
<!DOCTYPE html PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN"> <html> <head> <meta http-equiv="Content-Type" content="text/html; charset=shift-jis" /> <style type="text/css"> /* Standard CSS */ body, div, p { margin:0px; padding:0px; } img { border:none; } a { color:#856953; } div#amazoncontent { font-family:'Arial', sans-serif; font-size:10px; color:#000000; background-color:#FFFFFF; position:relative; border:1px solid #000000; overflow:hidden; text-align:left; } div#logo { text-align:center; background-color:#000000; } div#privacy { position:absolute; bottom:0px; width:100%; text-align:center; padding:3px 0px; color:#a1a1a1; background-color:#FFFFFF; z-index:1; clear:both; } div#privacy a { color:#a1a1a1; } /* Custom CSS */ div#amazoncontent { width:158px; height:598px; } div.product { position:relative; padding:3px; height:76px; margin-left:65px; background-color:#FFFFFF; } img.productImage { position:absolute; left:-65px; top:3px; } div.prices { color:#990000; margin:1px 0px; } p.author {
この為、ブラウザがうまく広告を表示出来ないようです。
ブラウザ以外のアプリケーションでによる事象を確認するため、MacOS Xへ同梱されているcurl(1)を使い、iframeへ指定されていたURLへアクセスしてみました。
% curl -o foo 'http://rcm-jp.amazon.co.jp/e/cm?t=foo&o=9&p=14&l=bn1&mode=books-jp&browse=202188011&fc1=000000<1=_blank&lc1=856953&bg1=FFFFFF&f=ifr;'
するとcurlを何度も連続で実行させた場合に、同じくHTMLが途中で切れてしまう事象が確認できました。この事象は、アプリケーション特有のバグではなく、より深いレイヤで発生しているようです。
次にネットワーク上の伝送が正しいかどうかを検証するため、tcpdumpにより、ネットワークパケットを調べてみました。curl実行時、HTTPデータを圧縮することなく平文で伝送させるように指定し、全てのデータを一旦記録させ、その後、記録したデータを-Aで眺めてみることにします。
なお、iframeのsrcで指定されているホスト「rcm-jp.amazon.co.jp」はDNSラウンドロビンが設定されている為、tcpdumpでのhost指定はIPアドレスで指定すると良いでしょう。
% sudo tcpdump -w dump -s 0
% curl -o foo 'http://...'
% tcpdump -r dump -A -n host 207.171.187.112
記録したパケットを眺めてみたところ、curlではファイルが切れている状況でも、ネットワーク上は全てのデータが適切に到達していることが分かりました(但し以前の記事で指摘したように、Content-Lengthの値は不正です)。どうやら、デバイスドライバからアプリケーションへ至る間で、パケットが消失してしまっているようです。
問題発生箇所を調べるために、curlコマンドを、今度はdtrussコマンドと共に実行させてみます。dtrussは、コマンドのシステムコール呼び出し状況を表示してくれるコマンドで、Leopard以前に含まれていたtrussをDTraceを用いて実装したものです。
% sudo dtruss curl -s 'http://...'
すると次のような行が目につきました。
select(0x4, 0x7FFF5FBFEBE0, 0x7FFF5FBFEB60, 0x7FFF5FBFEAE0, 0x7FFF5FBFEC80) = 1 0
recvfrom(0x3, 0x10082DA00, 0x4000) = 1460 0
<省略>
select(0x4, 0x7FFF5FBFEBE0, 0x7FFF5FBFEB60, 0x7FFF5FBFEAE0, 0x7FFF5FBFEC80) = 1 0
recvfrom(0x3, 0x10082DA00, 0x1004) = 0 0
この流れを見る限り、単一プロセスで作られた一般的なネットワーククライアントプログラム同様、curlでは、select(2)でネットワークからのデータ到達を待ち受け、ディスクリプタの準備ができた事を確認した後、recvfrom(2)で実データを読み込んでいると考えられます。
しかし1回目のrecvfromで1460バイトのデータを読み込んだ後、2回目の準備完了を受けて読み込んだデータサイズは0バイト、即ちデータの終端となっています。このHTMLファイルは概ね5000バイト強になる筈ですから、これはおかしな事象です。
curlのソースコードを確認してみましたが、実装上不審な点は見当たりません。またtcpdumpが記録したTCPシーケンスも確認しましたが、RSTで切断されているといった問題もなさそうです。
ここまでで「select上はディスクリプタからの読み出し準備が整った状況でありながらも、実際にはデータを読み出すことが出来ない状況にあるのでは」と推測しました。この仮説が正しければ、ブラウザがHTMLを途中までしか読めていない現象も理解できます。
この仮説を検証するため、簡単な再現プログラムを作ってみました。このプログラムは、以下のURLから入手可能です(本プログラムの利用は自由です。著作権等は主張しません。無保証です。エラーチェックなども行っていません)。
機能は単純で、指定ホストの指定ポートに対して指定されたコマンドをHTTP/1.1で送信し、応答を受信します。但しselectで読み込み完了になった後、データ読み込みに先立ち、指定されたマイクロ秒だけ待たせることが出来ます。また、何回取得を繰り返すかも指定できます。
まずは待ち時間を0秒、50回繰り返しでコマンドを実行させ、recvfromが読み込んだバイト数を確認してみました。並行してtcpdumpも実行させます。
% ./c rcm-jp.amazon.co.jp 80 0 'GET /e/cm...' 50
結果selectが読み出し可能状態にあり、またネットワーク上も残存データが存在しているにも関わらず、recvfromが0を返す状況を再現させることができました。
ここで、selectが読み出し可能状態になってから後、100ms経過後にrecvfromを実行するようにしてみました。
% ./c rcm-jp.amazon.co.jp 80 100 'GET /e/cm...' 50
先ほど発生していた「残存データがあるにも関わらずrecvfromがデータを読めない」という状況は全く発生しません。
ここまで来てようやく問題の原因に気が付きました。この事象を引き起こしていたのはAntiVirusプログラムでした。
私はMacOS X上では、AntiVirusプログラムとしてVirus Barrier X6を使っています。このプログラムにはWeb Threatsという名の機能が備わっており、マニュアルによれば次のとおりです。
VirusBarrier X6 offers protection from web threats, such as cross-site scripting attacks, drive-by downloads, clickjacking, as well as web pages with malicious JavaScript or malicious Java applets.
この機能を有効にすると、Amazonの広告HTMLへ含まれているJavaScriptが検査されることになり、その検査時間分、読み可能状態になるまで遅延が発生するのだと思われます。
本来はVirusBarrierによる安全性の検査が終了してから後、selectに対して準備完了を返すようにすべきだと思うのですが、残念ながらそのような実装にはなっていないのでしょう。結果、VirusBarrierの検査終了前にrecvfromが実行されてしまうと、未だ読み込み可能データが無いことから0バイトが返されてしまい、データ終端だと認識してしまうということなのだと思います。
結局、このWeb Threat機能をオフにして試してみたところ、ブログ上のAmazon広告が正しく表示されるようになりました。
その後、幾つかのJavaScriptファイルを使っているサイトで検証を行ってみましたが、Amazonの広告以外では、この現象が確認できるサイトを見つけることは出来ませんでした。Amazonのファイルは、解析に必要なスクリプトの複雑さなどが絶妙なのかも知れません。
もし、Virus Barrierをお使いの環境で、Webサイトの一部が欠ける、などの事象が生じた場合には、Virus BarrierのWeb Threat機能が原因ではないかを確認してみると良いでしょう。
