| カウントアップスクリプトの検証 「直接サーバアクセスによる連続処理」の章でも説明したとおり、上西のウォッチ数のカウントアップにはサーバへの直接アクセス行為が疑われる。知らない人にとっては直接サーバアクセスという行為が、何かハッキングのような犯罪行為とのように受け止められる人がいるが、それ行為自体を違法行為だと判断することは非常に難しい。サーバ側からはそうしたアクセスがあったということだけでは、本来想定された方法でアクセスされたのか、それ以外の方法でアクセスがあったのかは簡単には見極められない。多くの場合、そうした行為が不正だと判断されるのは、短時間で大量のアクセスが集中することによりサーバ側の応答が出来なくなり、多くの人がそのサイトを利用できない状況が発生することによって、不正なアクセスが短時間に集中していたということが判明する。それ以外では大量のアクセスログデータを解析して、どこからどのくらいの時間、どの程度の量のアクセスが集中していたのかを時間をかけて検証するしかない。 |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| カウントアップ処理の流れ カウントアップ処理は一般的には右記の図1にあるようなデータの動きになる。端末からのGETコマンド送信によるリクエストに反応して、サーバー内のカウントデータに対してカウントアップ処理が行われ、その結果をレスポンスとして端末側に返信する。この一連の流れが処理されるとカウントデータが1カウントアップされることになるわけである。連続してカウントアップされる場合はこの処理が連続して正常に完了すると短時間で大幅なカウントアップ処理がされることになる。 ところが端末側からのGETコマンドによるHTTPリクエストが連続して送信されると、図2のようにサーバ内でカウントアップ処理が間に合わず、端末からのリクエストの多くが処理されず終了してしまうことが発生する。実際にはこの場合、正常に処理できなかった分のリクエストに関しては、更新エラーのメッセージが端末側に返されることになる。 755端末側アプリではこうしたことを避けるため、サーバからのレスポンスが帰ってこない限り、次のGETコマンドによるHTTPリクエストの送信を行わないような仕様になっている（詳細に関しては後記）。リトークタップしているときに、次の画面がなかなか開かない状況があったことを記憶している人も多いかと思うが、こうした時間はサーバーからの応答を待っている時間だと考えると理解しやすいだろう。そのため1タップしてから再度同じ画面が開くのに1～2秒程度かかっていたわけである。 こうしたサーバからのレスポンスを無視して、さらに大量のGETコマンドによるHTTPリクエストが送信されると、サーバー側で受付処理自体が出来なくなり、サーバー自体が反応を止めてしまう。いわゆるDos攻撃に相当する行為になる。こうなると完全に不正アクセスによる迷惑行為となり、時には「偽計業務妨害」による犯罪行為として警察沙汰になる可能性もある。 一般的にはこうした大量のHTTPリクエスト送信に際しては、サーバ側もそれなりに大量のアクセスが集中した場合を想定した準備がされているので、極短時間でよほど大量のコマンド送信によるリクエストを行わない限りDos攻撃に相当するような結果になることはない。後から説明するが、このサイトでも30ミリ秒（0.03秒）程度の間隔でリクエストを送ってもきちんとカウントアップする。上西の755でのカウントアップでは最大で約780,000/5分もの増加があったわけだから、2,600カウント/秒程度（約0.4ミリ秒間隔）でのカウントアップ処理は出来ていたことになる。残念ながらこのサイトで用意しているカウントアップシステムは単純なファイル更新型のものなので、それほどの短い間隔で更新できる仕組みにはなっていないが、サンプルスクリプトを実行するには十分だと思う。 ただ、気をつけなければいけないのは、Dos攻撃による迷惑行為は必ずしもこうした短時間で大量の送信行為をもって必ずしも事件化される理由になるわけではないという点である。有名なところでは「岡崎市立中央図書館事件」というのがある。これは利用者個人が中央図書館の蔵書を検索するために、公開されている中央図書館のサイトに対して自身の作成した簡単な検索プログラム（クローラ）を用いて検索を実行したため、図書館側が用意していた蔵書検索システムを他の人が利用できなくなり、実行者が「偽計業務妨害容疑」で逮捕されたという事件である。実際のところは図書館側のシステムに普通では考えられない問題があり、1時間に400アクセス以上のリクエストが送られると他のリクエストの処理が出来なくなるという仕様だったため、1秒間に1アクセス程度のクローラ程度の処理要求でもシステム停止を招く原因となってしまったというものだった。そういうレベルの問題が管理者側にあったとしても、管理者から被害届が出されると犯罪行為として検挙される事例としてかなり有名な事件である。 こうした点から考えても他のシステムが稼働しているサーバに対して、決められたアクセス方法ではなく安易に指定以外の方法でアクセス行為を行うと、犯罪行為に相当する事になりかねないという認識を持つことが必要となる。 |
図1 |
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
図2 |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
図3 |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| 上の表は最終日（5/3）の23:00～24:00の間のデータの動きである。この時点で非常に気になるのは23:10から23:30の動きと23:40から24:00の間でのデータの動きである。古畑のウォッチ活動に於いてはこちらのまとめサイトの記事でも23:15近辺でサーバへのアクセスが出来なくなったという書き込み多々あった。データの動きを見ると、古畑の変動は一旦23:10に上昇するがすぐに減少し、23:25、23:30の値が増えている。それに対して上西の方は23:10以降値は増え続け、23:15～23:20の間に直前値より40,000/5分もの値が増えていることがわかる。つまりこの時点で図2のような状況に陥っていたことが推測される。そのためサーバからの応答がない限り、755端末アプリのHTTPリクエストの送信は制限されるが、755端末アプリを使っていないスクリプトではHTTPリクエストを連続して送り続けることができるので、上西側だけカウントアップが進んでいたのではと推測される。スクリプトによるカウントアップリクエストが大量に送られていれば、同じように上西サイドで755端末アプリでの無反応状況が発生しても、結果として変動がプラスになっていたのではと考えられる（8,000の減少があっても、10,000の増加があれば合計では2,000の増加になる）。 23:40以降も同様の状況が発生したのであろう。他のメンバーのウォッチバトル終了間際の動向から見ても、終了直前の最終20～30分間程度は増分値は上昇し続けるのが普通なのだが、755端末アプリによるアクセスができなくなったことにより、古畑の増分値はどんどん減っている。それに対して上西は23:40以降も継続して増え続け、終了前5分に上西のウォッチ数は約68,000/5分もの上昇が見られるが、古畑の方は23:50に一旦増加（直前の10分間で減少した分の回復程度）した後は減少する一方になっている。そして23:55～24:00の5分間は双方とも大幅にウォッチ数が減少している。つまりこうした増分値の推移から考えると、この時点では図3のような状況が起こっていたのではと推測される。 |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| 短時間での大量アクセスに対する対処法 755のような大規模なSNSツールを管理するサーバー側のシステムとしては、一般的に上記の図3のようなことが起こらないように負荷分散装置を設置し、複数台（数十台から数百台程度）のアプリケーションサーバ（APサーバ）を配置する。そうすることによって外部からは１台のサーバにアクセスしているように見えても、実際のシステム的には複数台のAPサーバに分散させて処理を行っているのが普通である。この場合、APサーバは複数あってもデータを保存するDBサーバは１台に集約されているのが一般的なシステム形態になる（バックアップ用に同等機能のDBサーバを用意されていることはあるが）。このDBサーバには高性能なDBMS（データベースマネージメントシステム）が搭載されており、複数台のAPサーバから短時間で大量のアクセスがあっても処理できるDBエンジンが搭載されているのが一般的なシステム形態である。 負荷分散装置は最初に端末からアクセスがあった時点で、設定された分散ロジックに従い１台のAPサーバに負荷が集中しないようにその処理を分散させるわけだが、基本的に同じ端末からのアクセスがあれば、以前にその端末からの処理を行った同じAPサーバに接続させるロジックになっていることが多い。したがって右記のような状況でAPサーバにアクセスが発生した場合、タブレットとPC-Bは同じAPサーバに対して更新要求をしているわけだが、もしタブレットが755端末アプリを利用していて、PC-Bがスクリプトで大量の更新要求を送っていた場合、この状態で上記の図3のようなことが起きると、スマホやPC-Aでは特に支障なく更新処理が出来てもタブレットでの反応は停止してしまい、APサーバ4に接続している多くの端末で755端末アプリからの更新が出来ない状況が発生するわけである。 |
図4 |
||
| しかしながら負荷分散装置を設置したところでその処理能力以上のHTTPリクエストが端末側から送られてくると、処理できない大量のトラフィックが原因となりネットワーク全体でのスループットを低下させるなど、システム全体に大きな影響を及ぼすこともある。「直接サーバアクセスによる連続処理」の章にあるように5/3 23：55時点では、他誌のウォッチバトルに参加していたメンバーのウォッチ数を確認することが出来なかった。負荷分散装置はその性能によりいろいろな機種はあるが、最近の機種に於いても端末側からのアクセスに対して、そのデータ処理能力は数千/秒から数万/秒程度のものが多い。たとえば10,000/秒程度の分散処理が出来るものであったとしても、10,000/秒＝600,000/分＝3,000,000/5分程度の処理能力になる。5/3 23：55時点のアクセス数は古畑と上西の二人分のみを合計しても、1,150,000/5分以上のデータが送られていたことがわかる。当然その時点での755サーバシステム全体においては二人以外のページへのアクセスも発生していたわけだから、二人分のみで1,000,000/5分を超えるようなアクセスがあった時点で、全体のアクセス数は負荷分散装置の処理能力を超えていた可能性がある。そうした状況が、他のメンバーをチェックしていたシステムでのウォッチ数の確認エラーを発生させたり、その直後に古畑や上西のウォッチ数が急激に減少する原因となったのではないかと推測される。 | |||
| 755端末アプリにおける更新要求の実際 755端末アプリでリトークタップしたときに実際にどの様なデータの動きになっているかを検証してみた。検証方法としてはフリーソフトのLANアナライザーを利用して、BlueStacksによる755端末アプリをエミュレートした環境でのパケット情報をトレースし、755関係のサーバに対するTCP及びHTTPに関するパケット情報を確認した。 755端末アプリでリトーク部分をタップすると基本的には4つの処理が実行されることがわかった。その4つを大きく分けると①：認証サーバへの確認要求、②～④：APサーバへのデータ要求に分けられる。①に関する処理と②～④に関する処理ではアクセスする接続先サーバのIPアドレスが違うので、明らかに別サーバから情報を得ていることがわかる。基本的には①の認証確認を行った後、一定の時間内で②～④の処理を行わないとデータを取得できない仕掛けになっていることがわかった。何らかの理由により①の実行後、時間が経過すると再度①を実行してから②～④の処理が行われていることも確認できた。 ②～④の処理に関しては次のようになっていた。
|
図5 |
||
| ②、③に関しては情報の取得と同時にメンバーや、やじうまトークを書き込んだ参加者のアイコンなど画像データの取得も同時に行っていたが、それらの画像データは755サーバシステムでの反応速度の低下を招かないように、外部DBサーバを利用してそちらに保存された画像データを読み込む形になっていた。APサーバの内容について①で認証を得てから一定の時間内にアクセスしないと情報取得は出来ないが、外部DBサーバの画像データは認証なしに取得できることもわかった（ちなみにこちらが上西のトークルームの画像データになります。リンク先が開かないときはアドレスバーの情報をコピーして再度貼り付けてから再読み込みすると開きます）。 ④に関してはリトークタップしたときに、そのトークを含み同時に1画面に表示されるトークを全て読み込む形になっていた。つまり上西の当時のトーク：4020にリトークがあるが、それとタップ（クリック）すると、4019～4025までを1画面に開くというHTTPリクエストが送られる形になっていた。 基本的にウォッチ数に関する情報を含んでいたのは②と④であったが、②は更新前のカウント数で、④には更新後のカウント数が記載されていた。したがってスクリプトを実行させる際には①の認証サーバへのアクセスに続いて④のカウントアップさせるためのHTTPリクエストを送信すればいいことがわかる。カウントアップに必要でない③のやじうまトークの内容など取得する必要はない（実際には755端末アプリではこのデータの取得に時間がかかっていた）。不正アクセスによる迷惑行為を助長することになるので、これ以上の具体的な方法論はここでは記載しないが、データのパケット情報をトレースすることでこの程度のことは簡単に確認できた。 また、パケットのトレースによってAPサーバへのアクセス直前に認証サーバでの確認要求を行っていることはわかったが、それに関する応答は負荷分散装置が認証サーバの情報を随時状態監視をすることで代行して応答している可能性が高い。そのため、①の応答が返ってくる時間は14～15ミリ秒という非常に短い時間になっている。②などのHTTPリクエストに関する情報はDBサーバのデータが随時更新されているので、その都度必ずAPサーバにアクセスした後応答していることは明白であり、その応答は40ミリ秒程度の時間がかかっている。こうした点から考えても負荷分散装置が要求発生の都度、認証サーバに問い合わせをしているとは考えにくい。負荷分散装置は常に管理下にあるサーバの状態監視をしており、直接サーバとやりとりしなくていい処理に関しては、サーバに変わって代行処理する機能を持っているものも多い。755端末アプリでの処理フローで①の応答が帰ってくるまでは②以降の処理を実行しないしようになっていた点から推測すると、負荷分散装置は①の問い合わせが発生したタイミングで、応答時間を早くするためID確認をするのと同時に、次に端末側からHTTPリクエストが要求されたときの接続先に関して、複数のAPサーバの混雑状況から最適な接続先を決定していたものと考えられる。 755端末アプリでは1タップする間にこれだけの処理が実際に行われており、その応答を返ってこないと次の処理が実行されない形になっている。ある意味端末アプリで送信データをコントロールし、755サーバアプリに必要以上の負荷がかからないような仕組みにしていたとも言える。こうした状況にもかかわらず、5/3 23時台には多くの利用者で幾度となくサーバへの接続が出来ない状況がかなり長い時間発生していた。このような端末アプリのデータ送信状況から考えると、全員が端末アプリを利用している限りに於いては、サーバ側で端末からのアクセスが不能になるような想定外の負荷が発生することはなかなか考えにくい。 |
|||
| サンプルスクリプトによるカウントアップ体験 スクリプトによるカウントアップが実際にどの程度の短時間で処理できるのかを理解してもらうために、サンプルスクリプトを作成したので、その反応速度を実感していただきたい。 右の図6に示したものは実際にサンプルスクリプトの実行画面を切り取ったものだが、作成したスクリプトは次の3種類になる。
|
図6 |
||
| スクリプトの実行にはIE9.0以上のブラウザが必要です。 他のブラウザでは正常に稼働しません。 |
|||
| NO1で100回カウントアップすると大抵のパソコンでは上のカウンターは100カウント増加しない結果になると思われる。なぜなら100回カウントアップするためのHTTPリクエストの送信にかかる処理時間はせいぜい1000～2000ミリ秒（1～2秒）ぐらいで、送信間隔が短すぎて実際にカウンターを更新が完了する前に次のHTTPリクエストが発行されてしまい、そのような状況のまま送信間隔をコントロールせずにリクエストを送信すると、結果としてエラーとなるリクエストが多発するのである（上の図2の状況）。 NO2では自分で回数を指定して実行すると、その回数分だけカウントアップすることが確認できるはずである。このときには1回ずつ確認メッセージが出るので、毎回そのメッセージを消さない限り次のHTTPリクエストは発行されない。したがってどんなに早くメッセージを消したところで、人手による作業では処理速度に限界があり、一定の送信間隔以下にはならないので確実にカウントアップされるはずである。 NO3ではHTTPリクエストの送信間隔を自身で設定し、指定した回数分カウントアップを繰り返す。このサイトでの1回のカウントアップには30ミリ秒ぐらいかかるはずなので、HTTPリクエストの送信タイミングをそれ以下に設定すると、直前のリクエストが正しく処理できないうちに次のリクエストを送信することになり、指定した回数のカウントアップがされないことが確認できる。この処理に関しては時間間隔をパソコンの処理能力以上に速くしても、合計処理時間は一定以下にはならないので、その間隔を処理限界時間より短くしたばあい、トータルの処理時間は指定した更新間隔に比例するものではない。しかしながらその送信間隔を遅くすることはコントロール出来るので、上西の増分値が定量的に増加していた時間帯には、こうした送信間隔や実行するスクリプトの数をコントロールして、急激なウォッチ数上昇になってその不自然さが目立たないよう（実際にはそうした一定量の等分での増加となる方が不自然なのだが、）に徐々に増加させていたことが疑われる。 |
|||
| こうしたスクリプトでのカウントアップを体験すれば1,000カウント程度は十数秒で、10,000カウントでも数分で処理できることがわかるだろう。今回ここで実行しているカウントアッププログラムは単純なファイル更新型のものを利用しているため、1カウント処理するのに30ミリ秒程度の時間がかかるが、実際の上西のデータでは5分間で780,000ものカウントアップが出来ており、速度的には780,000/5分=156,000/分=2,600/秒という速度でカウントアップ処理が出来ていたわけである。つまり755サーバアプリケーションでは1カウントのあたりの処理が約0.4ミリ秒程度で出来るような能力をもっていることになる。 今回、このサイトでのカウントアップ処理には1回で30ミリ秒程度の時間がかかるので、100回リピートさせるスクリプトでも1回の処理に少し時間をかけるようにしている（そうしないと性能のよいPCではほとんどカウントアップされなくなってしまう）。しかし1,000ミリ秒（1秒）ほどで100回程度のカウントアップが出来ることは十分確認できたと思う。100カウントアップに1,000ミリ秒（1秒）かかるということは、1スクリプトの実行で6,000カウント/1分、30,000カウント/5分のカウントアップが可能だということになる。このスクリプト自体はそれほど負荷のかかるものではないので、1台のパソコンで複数のスクリプトを同時に実行することも可能である。最近のパソコンは市販されているものでも4コアや8コアのものも多いので、4つ程度のスクリプトを同時に実行したところで過大と言えるほどの負荷にはならない。つまり30,000カウント/5分×4＝120,000カウント/5分程度のカウントアップリクエストを1台のPCで送信することもさほど難しいことではないということがわかる。「5月3日 23:00～24:00のデータ解析」の章でも書いたように、スクリプトによるカウントアップの最大値は560,000/5分程度を想定している。したがってこのようなスクリプトを準備すれば、4～5台程度のパソコンを稼働させることで十分その程度のカウントアップを行うことが可能だということがわかる。 しかしながら、このような状態でパソコンでのスクリプトを長時間実行したら、時間の経過と共にパソコンに対する負荷も相当なものになることは十分想定される。当然、本当にそんなことを実行していたら某巨大掲示板サイトに下記のような書き込みをする輩がいたとしても何ら不思議はない。 |
|||
|
|||
| 最後に 実はこのページを作成するきっかけになったのは、このサイトを開設後に嫌がらせなのか、こちらのトップページに短時間で大量のGETコマンドを送信する迷惑行為を行う輩がいたからである。気がついたのはトップページをチェックしていたときに、短時間では通常発生しえないカウンターの上昇をたまたま見つけた事による。その時のログデータを確認したところ、人手では起こりえないような速度で1秒間に数回のアクセスが発生していたことが記録されていた。そうした行為が実行されていたのは数分間程度ではあったが当然こうした行為は一般的には迷惑行為に相当する。サイトが閲覧できなくなるような頻度ではないので、偽計業務妨害などの犯罪行為として警察に通報するようなレベルではなかったが、こうした行為を行えば当然のことながら迷惑行為と判断して発信元になっているプロバイダーに通報し対処を依頼した。 プロバイダーからは具体的な処置は回答してもらえなかったが、発信元回線の契約者に対してそれ相当の対応したとの連絡があったので、直接利用者に警告がされたと思われるが、そうした迷惑行為を行うと利用プロバイダからの契約を打ち切られる可能性もある。ちなみに迷惑行為を行った輩が大阪府下からアクセスしていたことは確認している。 |
|||
 トップへ戻る |
