Hatena::ブログ(Diary)

torutkの日記 RSSフィード

2017-03-12

[]インターネット接続のトラブル

先日、自宅ネットワークのインターネット接続が断続的に切断・再接続を繰り返す問題があり、無線LANルーターの設定をいろいろ試行錯誤してました。その辺りの経緯は次に書いています。

無線LANルーターAtermのリンクダウン頻発 - torutkの日記

自宅ネットワークは、CATV回線でインターネット接続しており、CATVケーブルモデムを使用しています。

この切断が、無線LANルーターの問題か、ケーブルモデムの問題かを切り分けるため、ケーブルモデムにPCを直結し、インターネット上のサーバー*1へpingを定期的に飛ばして様子をみてみました。

また、DHCPクライアントのイベントログを有効にして、切断が発生するときのログを見れるようにしました。

本日昼過ぎに、ケーブルモデムにPCを直結し、ケーブルモデムの電源を抜き挿ししてリセット、PC側も再起動して、pingをインターネットに飛ばして8時間ほど様子をみました。

結果

ping結果

8時間ほど実行しました。

インターネットとの接続が断絶するときのping結果は次のようになっていました。

2017/03/12 12:54:35 xxx.xxx.xxx.xxxからの応答: バイト数 =32 時間 =26ms TTL=54
2017/03/12 12:54:36 xxx.xxx.xxx.xxxからの応答: バイト数 =32 時間 =26ms TTL=54
  :
2017/03/12 15:58:07 xxx.xxx.xxx.xxxからの応答: バイト数 =32 時間 =27ms TTL=54
2017/03/12 15:58:12 要求がタイムアウトしました。
2017/03/12 15:58:13 一般エラー。
2017/03/12 15:58:14 一般エラー。
  :
2017/03/12 15:58:20 一般エラー。
2017/03/12 15:58:25 要求がタイムアウトしました。
2017/03/12 15:58:30 要求がタイムアウトしました。
2017/03/12 15:58:35 要求がタイムアウトしました。
2017/03/12 15:58:38 一般エラー。
2017/03/12 15:58:39 ping: 転送に失敗しました。一般エラーです。
2017/03/12 15:58:40 ping: 転送に失敗しました。一般エラーです。
  :
2017/03/12 15:59:35 ping: 転送に失敗しました。一般エラーです。
2017/03/12 15:59:36 xxx.xxx.xxx.xxxからの応答: バイト数 =32 時間 =35ms TTL=54
2017/03/12 15:59:41 要求がタイムアウトしました。
2017/03/12 15:59:42 xxx.xxx.xxx.xxxからの応答: バイト数 =32 時間 =40ms TTL=54
2017/03/12 15:59:43 xxx.xxx.xxx.xxxからの応答: バイト数 =32 時間 =27ms TTL=54
  :

このときのDHCP Clientのイベントログ(Microsoft-Windows-DHCP Client Events/Admin)には、

  • 2017/03/12 15:58:37 エラー イベント1002

「ネットワークアドレスが 0x... のネットワークカードに対するIPアドレス xxx.xxx.xxx.xxx のリースが、DHCPサーバー192.168.100.1 から拒否されました。DHCPサーバーは DHCPNACKメッセージを送信しました。」

  • 2017/03/12 15:59:29 警告 イベント1003

「ネットワークアドレスが 0x... のネットワークカードに対して、ネットワーク(DHCPサーバー)から割り当てられたアドレスを更新することができませんでした。次のエラーが発生しました:0x79。ネットワークアドレス(DHCP)サーバーから引き続き、アドレスの取得を試みます。」

このときのDHCP Clientのイベントログ(Microsoft-Windows-DHCP Client Events/Operational)には、

  • 2017/03/12 15:58:09 情報 イベント50002

「メディア切断の通知をインターフェイス ID 14 で受信しました」

  • 2017/03/12 15:58:31 情報 イベント50001

「メディア接続の通知をインターフェイス ID 14 で受信しました」

  • 2017/03/12 15:58:31 情報 イベント50004

「インターフェイス ID が 14 のアダプターでDHCPが有効化されました」

  :

  • 2017/03/12 15:58:39 情報 イベント50010

「アダプター 14 で OFFER メッセージが受け入れられました。提供アドレス: 192.168.100.20、サーバーアドレス: 192.168.100.1」

  :

  • 2017/03/12 15:59:29 エラー イベント50039

「アダプター 14 でソケットを開こうとしてエラーが発生しました。エラーコード:0x2741」

  • 2017/03/12 15:59:29 エラー イベント50053

「メッセージを送信するときに、ネットワークでエラーが発生しました。エラーコード:0x2741」

  • 2017/03/12 15:59:29 情報 イベント50029

「アダプター 14 へのアドレス 192.168.100.20 の組み込みが解除されました。ステータスコード:0x57」

  • 2017/03/12 15:59:29 エラー イベント50030

「アダプター 14 で組み込みエラーが発生しました。ステータスコード: 0x57」

  • 2017/03/12 15:59:35 情報 イベント50007

「インターフェイス ID が14 のアダプターで、DISCOVER-OFFER-REQUEST-ACK メッセージが開始されました」

  • 2017/03/12 15:59:35 情報 イベント50009

「アダプター 14 から DISCOVER メッセージが送信されました。ステータスコード:0x0」

  • 2017/03/12 15:59:35 情報 イベント50010

「アダプター 14 で OFFER メッセージが受け入れられました。提供アドレス: xxx.xxx.xxx.xxx、サーバーアドレス: xxx.xxx.xxx.xxx」

インターネット接続の断絶発生時刻

2017/03/12 12:54〜20:55までの間、次の時刻で断絶が発生していました。

15:58

16:11

16:17

16:30

16:34

17:18

18:37

20:23

サポートへの電話問い合わせ

内容を伝えましたが、障害もなく、類似問題の情報も上がっていませんとのこと。後日調査に来るということで予定日を調整して終わりました。

ケーブルモデムのLED

20:23の断絶発生時、ちょうどWeb検索中でエラーが発生したのでケーブルモデムのLEDを確認したところ、

  • POWER 点灯
  • DS 消灯
  • US 消灯
  • Online 消灯
  • Link 消灯

となっていました。数秒すると、DSが点滅→点灯となり、続いてUSが点滅→点灯、Onlineが点滅→点灯、Linkが点滅 となりました。

調査方法のメモ

Windowsでpingの結果を時刻付きでファイルに保存する

PowerShellを使う方法がありました。

> ping www.torutk.com -t | ?{$_ -ne ""} | %{(Get-Date).ToString() + " $_"} | Out-File ping_result.txt

カレントディレクトリ上にping_result.txtという名前でping結果を保存します。

WindowsでDHCP Clientのイベントログを有効にする

DHCP Clientの動作ログ取得について

イベントビューアで、[アプリケーションとサービスログ] > [Microsoft] > [Windows] > [Dhcp-Client] の下に次の2つの項目があります。

  • Microsoft-Windows-DHCP Client Events/Admin
  • Microsoft-Windows-DHCP Client Events/Operational

これらを有効にして(右クリック > [ログの有効化])、イベントを記録します。

Arris製ケーブルモデム

「arris 192.168.100」でググってみると、いろいろ情報がでてきました。なんと、192.168.100.1でケーブルモデムの管理Webページにアクセスでき、このモデムは、アップリンクが途絶えたとき、DHCPサーバーとして振る舞うようです。

(後日追記)

ケーブルモデムの交換となりました。

交換後、様子見中です。

*1:ping先は、さくらVPSで借りている自前のサーバーです。