☰

発掘+追跡を完了するのに数秒かかるのはなぜですか？

tag-icon • tag-icon dns dig
発掘+追跡を完了するのに数秒かかるのはなぜですか？

次のdigコマンドのDNSクエリの合計は完了するのに200ミリ秒未満かかりますが、コマンド全体は4秒以上かかります。発掘+追跡がDNSクエリを組み合わせたよりもはるかに長い時間がかかるのはなぜですか?

time dig @1.1.1.1 google.com +trace

; <<>> DiG 9.16.1-Ubuntu <<>> @1.1.1.1 google.com +trace
; (1 server found)
;; global options: +cmd
.           518226  IN  NS  a.root-servers.net.
.           518226  IN  NS  b.root-servers.net.
.           518226  IN  NS  c.root-servers.net.
.           518226  IN  NS  d.root-servers.net.
.           518226  IN  NS  e.root-servers.net.
.           518226  IN  NS  f.root-servers.net.
.           518226  IN  NS  g.root-servers.net.
.           518226  IN  NS  h.root-servers.net.
.           518226  IN  NS  i.root-servers.net.
.           518226  IN  NS  j.root-servers.net.
.           518226  IN  NS  k.root-servers.net.
.           518226  IN  NS  l.root-servers.net.
.           518226  IN  NS  m.root-servers.net.
.           518226  IN  RRSIG   NS 8 0 518400 20200611050000 20200529040000 48903 . UPDRbakA0IKukt7UAHMmcGhNsg7QHWkEifKreuLASnSxAYH4N+i4EDLy RniJQJswKaBaZJS1Eput7i1RUKKaryv57q4ZxgjFbQOSiwvJJAgJqoUe n/XTH8SAUwbJHFVMkpi0XlctOeeX9uLv438khUJyPkxMyTUxTHBeqRev i5kboRwLWwXA7ui+q/lNTt9NCSnBKZSk9qULvOi3WuxVCOCYrQerLDgH UKVzhDxfoS7sIGNSKw7cIq2Cq7txU1sI9A5DZLzfGZzHNFNgZVWzYmS9 gFMyDepVljc4c0RJpnzFVACKUYjAMC/wqTtybgwIhL9h+TwBiT4+323k 0gpqog==
;; Received 525 bytes from 1.1.1.1#53(1.1.1.1) in 12 ms

com.            172800  IN  NS  k.gtld-servers.net.
com.            172800  IN  NS  g.gtld-servers.net.
com.            172800  IN  NS  d.gtld-servers.net.
com.            172800  IN  NS  e.gtld-servers.net.
com.            172800  IN  NS  j.gtld-servers.net.
com.            172800  IN  NS  l.gtld-servers.net.
com.            172800  IN  NS  i.gtld-servers.net.
com.            172800  IN  NS  b.gtld-servers.net.
com.            172800  IN  NS  m.gtld-servers.net.
com.            172800  IN  NS  c.gtld-servers.net.
com.            172800  IN  NS  f.gtld-servers.net.
com.            172800  IN  NS  h.gtld-servers.net.
com.            172800  IN  NS  a.gtld-servers.net.
com.            86400   IN  DS  30909 8 2 E2D3C916F6DEEAC73294E8268FB5885044A833FC5459588F4A9184CF C41A5766
com.            86400   IN  RRSIG   DS 8 1 86400 20200611050000 20200529040000 48903 . Vloranh+Ko0eMmq+QYgOK+yTHESioE5rM6rMNCH001IQqlQ2QkHGTqbI 7V4m2gLaPRgWBcnVe6MzaiVICjs0XupPqXMoZ4NvPCpEzM/QpfVSjjZ+ EKOxxZQ+A9jn9KH36OKEoS/XIJnke2Q/liFXJwRmcw8Wac501YORtUZP H4r/N4BEkWI+jIcYbzIqeZ+PcMaRB2Of+b1loNZ9MrOb+UdVUa0qT/0i 13sop9ynCs5Zfpds15L1lFnj6Lym244KjfYnPJQjjLlWtdk17DCW9TwY KFWM/BaPUJ/6m3qveENjAnsqVu+0GBqZTdPSwpkGjIGVzGOHd1ohdr0B wRE1hA==
;; Received 1198 bytes from 192.112.36.4#53(g.root-servers.net) in 68 ms

google.com.     172800  IN  NS  ns2.google.com.
google.com.     172800  IN  NS  ns1.google.com.
google.com.     172800  IN  NS  ns3.google.com.
google.com.     172800  IN  NS  ns4.google.com.
CK0POJMG874LJREF7EFN8430QVIT8BSM.com. 86400 IN NSEC3 1 1 0 - CK0Q1GIN43N1ARRC9OSM6QPQR81H5M9A NS SOA RRSIG DNSKEY NSEC3PARAM
CK0POJMG874LJREF7EFN8430QVIT8BSM.com. 86400 IN RRSIG NSEC3 8 2 86400 20200602045009 20200526034009 39844 com. B2EYsHhknBbnBb/ztws9dVndTXw1YepK2JNj7oyVOa+YSrPZXGMn9VTs X0+TGRlQolc5paKNQQF110lip0laiACz8TNQ/R4NX3rqvYeu240/9zBZ B48qzQO/Gz4lQX8XMhv4RuLKiaeKEj/G2lN7tWT4PEo+pDZ7FLwABENi CZTfy7xE7/7xmDnt2O2NEhG0+qlDXjldIQ4uuUAFEia2eQ==
S84BDVKNH5AGDSI7F5J0O3NPRHU0G7JQ.com. 86400 IN NSEC3 1 1 0 - S84CDVS9VPREADFD6KK7PDADH0M6IO8H NS DS RRSIG
S84BDVKNH5AGDSI7F5J0O3NPRHU0G7JQ.com. 86400 IN RRSIG NSEC3 8 2 86400 20200603044553 20200527033553 39844 com. HsP3w9+t2VkMhtbIPXbZIodkSYKGnhaGahxdKz1oF3tYiHF80j/rZKQJ pbdDpHdQJ4ucc4IzUs2+Hfs9vJLZjLwGzt7LvWyq0hEfpPElWnkf+St8 Mf/vqhr99ji17WQR9LHoPympEdod4+FUOC25eITgKfK+KXXYCzs1sWs4 KbguhA6wV2YCZp0oUeQb2h+kDb9OqucJzdgtJnlcuOUVxA==
;; Received 836 bytes from 192.41.162.30#53(l.gtld-servers.net) in 88 ms

google.com.     300 IN  A   172.217.17.110
;; Received 55 bytes from 216.239.38.10#53(ns4.google.com) in 16 ms

dig @1.1.1.1 google.com +trace  0,01s user 0,02s system 0% cpu 4,214 total

ベストアンサー1

bash 時間ユーティリティの 4 秒です。発掘バイナリの合計実行時間を報告します。

12ms、68ms...は採掘自体で報告された時間です。 digのドキュメントは少しまれですが（おそらくこれがあなたがここにいる理由です）、これはリクエストの純粋なランタイムである可能性が高いです。この周辺では、digはいくつかの異なるタスクを実行し、合計実行時間が4秒になります。

詳細と確認のためにソースコードを確認してください。存在するhttps://gitlab.isc.org/isc-projects/bind9/-/blob/master/bin/dig/dig.c#L387、単一の要求の印刷時間が2つのタイムスタンプ（query->time_recvとquery->time_sent）の違いであることがわかります。どこにありますか？これは少し複雑です。存在するhttps://gitlab.isc.org/isc-projects/bind9/-/blob/master/bin/dig/dighost.c#L2949、query->time_sentが設定されます。 recv_done() には query->time_recv が設定されています。ただし、recv_done（）はイベントによってコールバックとして呼び出されます。行2941では、recv_done（）はisc_socket_recv（）のコールバックとして渡されます。これはライン2954でトリガされます。

このセクションの前後に発生するすべての作業は4秒にカウントされますが、個々のクエリ時間には含まれません。これは、スレッドの開始など、非常に長い時間がかかる一般的な作業です。 dig.cのおおよその確認とhttps://gitlab.isc.org/isc-projects/bind9/-/blob/master/lib/isc/app.c#L194digがかなり多くのインフラストラクチャ、つまりフレームワークにツールをバインドするための標準アプリケーションインフラストラクチャを設定したことを示すようです。これには、イベント処理、操作（同時実行可能）が含まれます。これも時間がかかります。

次のステップは、デバッグバージョンのdigを取得して分析することです。しかし、まず、なぜ知っておくべきですか？この違いは常に存在しますか、それとも特定のホスト/特定のシステムにのみ存在しますか？ （私のコンピュータでも違いを見ましたが、20倍ほどではなく、約2〜3倍程度でした。）

おすすめ記事