デバッグ

デバッグ #

WebRTCのデバッグは、非常に困難な作業です。たくさんの可動部品があり、それらがすべて独立して壊れる可能性があります。注意していないと、間違ったものを探すために何週間もの時間を費やすことになります。やっと壊れた部品を見つけても、その原因を理解するためには、少し勉強する必要があります。

本章では、WebRTC をデバッグするための心構えを身につけます。問題をどのように分解するかを説明します。問題を把握した後は、一般的なデバッグツールを簡単にご紹介します。

問題の切り分け #

デバッグの際には、問題がどこから発生しているのかを切り分ける必要があります。問題の始まりから始めてみましょう。

シグナリングの失敗 #

ネットワーキングの失敗 #

netcatを使ってSTUNサーバーをテストします。

  1. 20バイトのバインディングリクエストパケットを準備します。

    echo -ne "\x00\x01\x00\x00\x21\x12\xA4\x42TESTTESTTEST" | hexdump -C
    00000000  00 01 00 00 21 12 a4 42  54 45 53 54 54 45 53 54  |....!..BTESTTEST|
    00000010  54 45 53 54                                       |TEST|
    00000014
    

    の解釈を行います。

    • 0001 はメッセージタイプ

    • 00 00 はデータセクションの長さです。

    • 21 12 a4 42 はマジック・クッキーです。

    • 54 45 53 54 54 45 53 54 54 45 53 54 (ASCIIでは TESTTESTTEST とデコードされます)は12バイトのトランザクションIDです。

  2. リクエストを送信し、32バイトのレスポンスを待ちます。

    stunserver=stun1.l.google.com;stunport=19302;listenport=20000;echo -ne "\x00\x01\x00\x00\x21\x12\xA4\x42TESTTESTTEST" | nc -u -p $listenport $stunserver $stunport -w 1 | hexdump -C
    00000000  01 01 00 0c 21 12 a4 42  54 45 53 54 54 45 53 54  |....!..BTESTTEST|
    00000010  54 45 53 54 00 20 00 08  00 01 6f 32 7f 36 de 89  |TEST. ....o2.6..|
    00000020
    

    の解釈を行います:

    • 01 01 はメッセージタイプ

    • 00 0c はデータセクションの長さで、10進数では12にデコードされます。

    • 21 12 a4 42 は、マジッククッキーです。

    • そして、54 45 53 54 54 45 53 54 54 45 53 54(ASCIIではTESTTESTTESTとデコードされる)は、12バイトのトランザクションIDです。

    • 00 20 00 08 00 01 6f 32 7f 36 de 89 は 12 バイトのデータで解釈は次のようになります:

      • 00 20 はタイプ: xor-mapped-address です。

      • 00 08 は値の部分の長さで、10進数では8にデコードされます。

      • 00 01 6f 32 7f 36 de 89 はデータの値で、以下のように解釈します:

        • 00 01 はアドレスタイプ(IPv4)です

        • 6f 32 は XOR マップされたポートです

        • 7f 36 de 89 はXORマップされたIPアドレスです

XORマップされた部分を解読するのは面倒ですが、00 00 00 00に設定された(無効な)ダミーのマジッククッキーを与えることで、stunサーバを騙してダミーのXORマップを実行させることができます。

stunserver=stun1.l.google.com;stunport=19302;listenport=20000;echo -ne "\x00\x01\x00\x00\x00\x00\x00\x00TESTTESTTEST" | nc -u -p $listenport $stunserver $stunport -w 1 | hexdump -C
00000000  01 01 00 0c 00 00 00 00  54 45 53 54 54 45 53 54  |........TESTTEST|
00000010  54 45 53 54 00 01 00 08  00 01 4e 20 5e 24 7a cb  |TEST......N ^$z.|
00000020

ダミーのマジッククッキーとのXORは冪等であるため、ポートとアドレスはレスポンスに明確に表示されます(IPアドレスをごまかして通過するパケットを操作するルータもあるため、すべての状況でこれが機能するわけではありません)。

  • 00 01 4e 20 5e 24 7a cb がデータ値で、解釈は次のようになります:

    • 00 01 はアドレスタイプ(IPv4)です

    • 4e 20 はマップされたポートで,10進数で 20000 にデコードされます

    • 5e 24 7a cb は IP アドレスで,ドット 10 進表記では 94.36.122.203 となります

セキュリティの失敗 #

メディアの障害 #

データの障害 #

Tools of the trade #

netcat (nc) #

netcatは、TCP や UDP を使ったネットワーク接続を読み書きするためのコマンドラインネットワークユーティリティです。主に nc コマンドとして利用できます。

tcpdump #

tcpdump は、コマンドラインのデータネットワークパケットアナライザです。

一般的なコマンドです。

  • 19302 番ポートとの間の UDP パケットをキャプチャし、パケットの内容を 16 進数で表示します。

    sudo tcpdump 'udp port 19302' -xx

  • 同じくパケットをPCAP(packet capture)ファイルに保存して後で確認する。

    sudo tcpdump 'udp port 19302' -w stun.pcap

    PCAPファイルは、wiresharkのGUIで開くことができます。wireshark stun.pcap です。

wireshark #

webrtc-internals #

Chromeには、chrome://webrtc-internalsで利用できる WebRTC の統計ページが組み込まれています。

レイテンシー #

レイテンシーが高いことをどうやって知ることができますか?

映像が遅れていることに気づいているかもしれませんが、どれくらい遅れているか正確に知っていますか?遅延を減らすためには、まず遅延を測定することから始めなければなりません。

本当の意味での遅延は、エンドツーエンドで測定することになっています。

つまり、送信者と受信者の間のネットワークパスのレイテンシーだけでなく、カメラのキャプチャ、フレームのエンコード、送信、受信、デコード、表示などの複合的なレイテンシーや、これらのステップ間のキューイングの可能性も含めて測定します。

エンド・ツー・エンドのレイテンシーは、各コンポーネントのレイテンシーの単純な合計ではありません。

理論的には、ライブビデオ伝送パイプラインの各コンポーネントのレイテンシーを個別に測定し、それらを合計することができますが、実際には、少なくともいくつかのコンポーネントは計測のためにアクセスできないか、パイプラインの外で測定すると大きく異なる結果になります。パイプラインステージ間のキューデプスの変化、ネットワークトポロジー、カメラの露出変化などは、エンドツーエンドのレイテンシーに影響を与えるコンポーネントのほんの一例です。

ライブストリーミングシステムの各コンポーネントの固有のレイテンシーが変化し、下流のコンポーネントに影響を与える可能性があります。キャプチャーしたビデオの内容も、レイテンシーに影響を与えます。例えば、木の枝などの高周波数の特徴には、低周波数の澄んだ青空に比べて多くのビットが必要となります。また、自動露出をオンにしたカメラでは、キャプチャレートを毎秒30フレームに設定しても、1フレームをキャプチャするのに予想される33ミリ秒よりもはるかに長い時間がかかることがあります。また、ネットワーク(特に携帯電話)での通信は、需要の変化に応じて非常にダイナミックに変化します。ユーザーが増えれば増えるほど、放送中のおしゃべりも増えます。また、ユーザーの物理的な位置(悪名高い低信号ゾーン)やその他の要因により、パケットロスやレイテンシーが増加します。無線LANアダプターやLTEモデムなどのネットワークインターフェースにパケットを送信するとどうなるでしょうか。すぐに配送できない場合は、インターフェース上でキューに入れられます。キューが大きいほど、そのネットワークインターフェースがもたらす遅延も大きくなります。

手動によるエンド・ツー・エンドのレイテンシー測定 #

エンド・ツー・エンドのレイテンシーとは、ある事象が発生してから、それが観測されるまでの時間、つまりビデオのフレームが画面に表示されるまでの時間を意味します。

EndToEndLatency = T(observe) - T(happen)

素朴なアプローチとしては、イベント発生時の時間を記録し、それを観測時の時間から差し引くという方法があります。 しかし、精度がミリ秒単位になると、時間の同期が問題になります。 分散したシステム間で時計を同期させようとしても、ほとんどの場合は無駄であり、時間同期のわずかな誤差でさえ、信頼性の低い遅延測定になってしまいます。

クロック同期の問題を回避する簡単な方法は、同じクロックを使用することです。 送信者と受信者を同じ基準のフレームに入れます。

時を刻むミリ秒クロックやその他のイベントソースがあるとします。 カメラをリモートスクリーンに向けて、クロックをライブストリーミングするシステムのレイテンシーを測定したいとします。 ミリ秒のタイマーがカチカチと音を立ててから (Thappen)、時計のビデオフレームが画面に表示される (Tobserve) までの時間を計測するには、次のような方法があります。

  • ミリ秒の時計にカメラを向ける。
  • 物理的に同じ場所にある受信機にビデオフレームを送る。
  • ミリ秒のタイマーと受信した映像を画面上で撮影する(携帯電話を使用)。
  • 2回分を引く。 これが最も正確なエンド・ツー・エンドのレイテンシー測定法です。 これはすべてのコンポーネント(カメラ、エンコーダー、ネットワーク、デコーダー)のレイテンシーを考慮しており、クロック同期に依存していません。

DIY Latencyを参照してください。 DIY Latency Example

上の写真では、測定されたエンドツーエンドのレイテンシーは101ミリ秒です。現在発生しているイベントは10:16:02.862ですが、ライブストリーミングシステムのオブザーバーは10:16:02.761を見ています。

エンドツーエンドの遅延の自動測定 #

執筆時点(2021年5月)では、エンドツーエンドの遅延に関するWebRTC規格が活発に議論されています。 Firefoxは、標準的なWebRTC APIの上に、ユーザーが自動遅延測定を作成できるようにするための一連のAPIを実装しました。 しかし、この段落では、遅延を自動的に測定する最も互換性のある方法について説明します。

NTP Style Latency Measurement

ラウンドトリップタイムを簡単に説明すると 私はあなたに私の時間 tR1 を送り、私の tR1 を時間 tR2 で受け取ると、ラウンドトリップタイムは tR2 - tR1 であることがわかります。

送信者と受信者の間に通信チャネル(例:DataChannel)が与えられた場合、受信者は以下のプロトコルに従って送信者のモノトニッククロックをモデル化することができます。

  1. 時刻 tR1 に、受信者はそのローカル・モノトニック・クロックのタイムスタンプをメッセージとして送信します。
  2. 送信者のローカル時間 tS1 に受信すると、送信者は tR1 のコピーに加えて、送信者の tS1 と送信者のビデオトラック時間 tSV1 を返信します。 送信者のビデオトラックの時間 tSV1 を含む。
  3. 受信側の時刻tR2において,メッセージの送信時間と受信時間を差し引くことでラウンド・トリップ・タイムを計算する。RTT = tR2 - tR1 となります。
  4. ラウンド・トリップ・タイム RTT と送信者のローカル・タイムスタンプ tS1 を合わせれば、送信者のモノトニック・クロックの推定値が得られます。時刻 tR2 における送信者の現在の時刻は、tS1 にラウンド・トリップ・タイムの半分を加えたものになります。
  5. 送信者のローカルクロックのタイムスタンプ tS1 とビデオトラックのタイムスタンプ tSV1 のペア、およびラウンドトリップタイム RTT は、受信者のビデオトラックの時間を送信者のビデオトラックに同期させるのに十分です。

最後に確認した送信側ビデオフレームの時間 tSV1 からどれだけの時間が経過したかがわかったので、現在表示されているビデオフレームの時間と tSV1 からの経過時間を比較することで、遅延を概算することができます。

expected_video_time = tSV1 + time_since(tSV1)
latency = expected_video_time - actual_video_time

この方法の欠点は、カメラの固有のレイテンシーが含まれていないことです。 ほとんどのビデオシステムでは,フレームキャプチャのタイムスタンプを,カメラからのフレームがメインメモリに送られた時刻とみなしていますが,これは記録されるイベントが実際に起こってから数秒後になります。

レイテンシー推定の例 #

サンプルの実装では、受信機で latency データチャネルを開き、受信機の単調なタイマーのタイムスタンプを送信機に定期的に送信します。 送信者は、JSONメッセージで応答を返します。 受信機はこのメッセージに基づいてレイテンシーを計算します。

{
    "received_time": 64714, // 受信者が送信したタイムスタンプ、送信者はそのタイムスタンプを反映する 
    "delay_since_received": 46, // 送信者が最後に受信した `received_time` から経過した時間
    "local_clock": 1597366470336, // 送信者の現在の単調なクロック時間
    "track_times_msec": {
        "myvideo_track1": [
            13100, // ビデオフレームのrtpタイムスタンプ (ミリ秒のタイムスケール)
            1597366470289 // ビデオフレームのモノトニッククロックのタイムスタンプ
        ]
    }
}

受信機でデータチャンネルを開く

dataChannel = peerConnection.createDataChannel('latency');

受信機の時間 tR1 を定期的に送信する。この例では特に理由なく2秒を使用している。

setInterval(() => {
    let tR1 = Math.trunc(performance.now());
    dataChannel.send("" + tR1);
}, 2000);

受信者から送信者に届くメッセージを処理する

//イベントデータが以下のような文字列であると仮定します。"1234567"
tR1 = event.data
now = Math.trunc(performance.now());
tSV1 = 42000; //現在のフレームのrtpのタイムスタンプをミリ秒のタイムスケールに変換
tS1 = 1597366470289; //カレントフレームのモノトニッククロックのタイムスタンプ
msg = {
  "received_time": tR1,
  "delay_since_received": 0,
  "local_clock": now,
  "track_times_msec": {
    "myvideo_track1": [tSV1, tS1].
  }
}
dataChannel.send(JSON.stringify(msg));

送信者からの受信メッセージを処理し、推定レイテンシーを コンソール に表示する

let tR2 = performance.now();
let fromSender = JSON.parse(event.data);
let tR1 = fromSender['received_time'];
let delay = fromSender['delay_since_received']; // 送信者がレスポンスを受信してから送信するまでに経過した時間
let senderTimeFromResponse = fromSender['local_clock'];
let rtt = tR2 - delay - tR1;
let networkLatency = rtt / 2;
let senderTime = (senderTimeFromResponse + delay + networkLatency);
VIDEO.requestVideoFrameCallback((now, framemeta) => {
    // 送信者の現在時刻を推定
    let delaySinceVideoCallbackRequested = now - tR2;
    senderTime += delaySinceVideoCallbackRequested;
    let [tSV1, tS1] = Object.entries(fromSender['track_times_msec'])[0][1].
    let timeSinceLastKnownFrame = senderTime - tS1;
    let expectedVideoTimeMsec = tSV1 + timeSinceLastKnownFrame;
    let actualVideoTimeMsec = Math.trunc(framemeta.rtpTimestamp / 90); // rtpのタイムベース(90000)をミリ秒のタイムベースに変換する
    let latency = expectedVideoTimeMsec - actualVideoTimeMsec;
    console.log('latency', latency, 'msec');
});

ブラウザでの実際のビデオ時間 #

<video>.requestVideoFrameCallback()を使うと、ウェブ制作者は合成用のフレームが提示されたときに通知を受けることができます。

ごく最近(2020年5月)まで、ブラウザで現在表示されているビデオフレームのタイムスタンプを確実に取得することは不可能に近かった。video.currentTime に基づく回避方法は存在していましたが、特に正確ではありませんでした。

Chrome と Mozilla の両ブラウザ開発者は、新しい W3C 標準である HTMLVideoElement.requestVideoFrameCallback() の導入を サポート しており、現在のビデオフレーム時間にアクセスするための API コールバックが追加されています。 この追加は些細なことのようですが、オーディオとビデオの同期を必要とするウェブ上の複数の高度なメディアアプリケーションを可能にしました。 特にWebRTCの場合、コールバックには、現在のビデオフレームに関連するRTPタイムスタンプであるrtpTimestampフィールドが含まれます。 これは、WebRTCアプリケーションでは存在すべきですが、それ以外では存在しません。

レイテンシーのデバッグのヒント #

まず第一に、デバッグは測定されたレイテンシーに影響を与える可能性が高いため、一般的なルールとして、問題を再現できる最小のセットアップに簡略化することが挙げられます。 より多くのコンポーネントを取り除くことができれば、どのコンポーネントがレイテンシーの問題を引き起こしているのかを簡単に把握することができます。

カメラのレイテンシー #

カメラの設定により、カメラの待ち時間が異なる場合があります。 自動露出、自動フォーカス、自動ホワイトバランスの設定を確認してください。 Webカメラの「自動」機能はすべて、撮影した画像を分析してからWebRTCスタックで利用できるようにするまでに時間がかかります。

Linux をお使いの場合は、カメラの設定を制御するために v4l2-ctl コマンドラインツールを使用してください。

# オートフォーカスの無効化
v4l2-ctl -d /dev/video0 -c focus_auto=0
# フォーカスを無限大にする
v4l2-ctl -d /dev/video0 -c focus_absolute=0

また、カメラの設定を素早く確認したり調整したりするために、UIツールのguvcviewを使用しています。

エンコーダーのレイテンシー #

最近のエンコーダーは、エンコードされたフレームを出力する前に、いくつかのフレームをバッファリングします。 画質とビットレートのバランスを第一に考えています。 マルチパスエンコーディングは、エンコーダーが出力レイテンシーを無視した極端な例です。 エンコーダーは、最初のパスで映像全体を取り込み、その後、フレームの出力を開始します。

しかし、適切な調整を行えば、サブフレームのレイテンシーを達成した人もいます。 エンコーダが過剰な参照フレームを使用したり、B-フレームに依存していないことを確認してください。 コーデックごとにレイテンシーチューニングの設定は異なりますが、x264 の場合、フレーム出力のレイテンシーを最小にするために、tune=zerolatencyprofile=baseline を使用することをお勧めします。

ネットワークのレイテンシー #

ネットワークの遅延は、より良いネットワーク接続にアップグレードする以外には、ほとんど何もできないと言っても過言ではありません。 ネットワークの遅延は天気とよく似ています。雨を止めることはできませんが、天気予報をチェックして傘を持つことはできます。 WebRTCでは、ネットワークの状態をミリ秒単位で測定しています。

重要な測定基準は

  • ラウンド・トリップ・タイム
  • パケットロスとパケット再送

ラウンド・トリップ・タイム(Round-Trip Time)

WebRTC スタックには、ネットワークのラウンドトリップタイム(RTT)の測定メカニズムが組み込まれています。 遅延の適切な近似値はRTTの半分です。RTT は、パケットの送信と受信に同じ時間がかかることを前提としていますが、必ずしもそうではありません。 RTTはエンドツーエンドのレイテンシーの下限を設定します。 カメラからエンコーダーまでのパイプラインがどれだけ最適化されていても、ビデオフレームはRTT/2よりも早く受信機に到達することはできません。

組み込みのRTTメカニズムは、送信者/受信者レポートと呼ばれる特別なRTCPパケットに基づいています。 送信者は受信者にタイムリーディングを送信し、受信者は同じタイムスタンプを送信者に反映させます。 これにより、送信者は、パケットが受信者まで移動して戻ってくるまでにかかった時間を知ることができます。 RTT測定の詳細については、送受信レポートの章を参照してください。

パケットロスとパケット再送について

RTPとRTCPの両プロトコルはUDPをベースにしていますが、UDPには順序付け、配送の成功、重複しないことなどの保証はありません。 上記のようなことは、実際のWebRTCアプリケーションでも起こり得ますし、実際に起こっています。 素朴なデコーダの実装では、デコーダが画像を正常に再構成するために、フレームのすべてのパケットが配信されることを期待します。 P-フレームのパケットが失われた場合、パケットロスがあると、デコーディングアーチファクトが発生する可能性があります。 I-フレームのパケットが失われると、それに依存するすべてのフレームに重いアーティファクトが発生するか、まったくデコードされません。 これは、ビデオが「フリーズ」しているように見えます。

ビデオのフリーズやデコードの不具合を避けるために(少なくとも避けようとするために)、WebRTCはネガティブアクノレッジメントメッセージ(NACK)を使用しています。 受信者が期待したRTPパケットを取得できなかった場合、送信者に不足しているパケットを再度送信するようにNACKメッセージを返します。 受信者は、パケットの再送を_待つことになります。 このような再送は明らかにレイテンシーの増加を引き起こします。 送受信された NACK パケットの数は、WebRTC の組み込み統計フィールド outbound stream nackCount および inbound stream nackCount に記録されます。

webrtc internals pageでは、インバウンドとアウトバウンドの nackCount の美しいグラフを見ることができます。 nackCountが増加している場合は、ネットワークで高いパケットロスが発生していることを意味し、WebRTCスタックはそれにもかかわらず、スムーズなビデオ/オーディオ体験を実現するために最善を尽くしています。

パケットロスが非常に大きく、デコーダーが画像を生成できない場合、または完全に失われたIフレームの場合のように後続の依存画像を生成できない場合、以降のすべてのPフレームがデコードされません。 受信側は、特別なピクチャ・ロス・インジケーション・メッセージ(PLI)を送信することで、その影響を軽減しようとします。 送信者はPLIを受信すると、受信者のデコーダを助けるために新しいIフレームを生成します。 I-フレームは通常、P-フレームよりもサイズが大きくなります。これにより、送信しなければならないパケットの数が増えます。 NACKメッセージと同様に、受信者は新しいI-フレームを待つ必要があり、追加のレイテンシーが発生します。

webrtc internals pagepliCountを見て、もし増えていたら、パケット数が少なくなるようにエンコーダを調整するか、error resilient modeを有効にしてください。

受信側のレイテンシー #

パケットが順番通りに来ないと、レイテンシーに影響します。 イメージパケットの下半分が上半分より先に来た場合、デコードする前に上半分を待たなければなりません。 これについては、ジッターの解決の章で詳しく説明しています。

また、jitterBufferDelayというビルトインメトリックで、フレームがデコーダに解放されるまで受信バッファで全てのパケットを待っていた時間を確認することができます。