Opened 15 years ago

Last modified 15 years ago

#2 new defect

dhclientが頻繁にDHCPREQUESTを送信する問題

Reported by: mitty Owned by: mitty
Priority: major Component: network
Keywords: Cc:

Description (last modified by mitty)

例

  1. under Windows' ICS 
    Jun 29 06:51:58 iqus dhclient: DHCPREQUEST of <null address> on eth0 to 192.168.0.1 port 67
Jun 29 06:51:58 iqus dhclient: DHCPACK of 192.168.0.83 from 192.168.0.1
Jun 29 06:51:58 iqus dhclient: bound to 192.168.0.83 -- renewal in 267 seconds.
Jun 29 06:56:25 iqus dhclient: DHCPREQUEST of <null address> on eth0 to 192.168.0.1 port 67
Jun 29 06:56:25 iqus dhclient: DHCPACK of 192.168.0.83 from 192.168.0.1
Jun 29 06:56:25 iqus dhclient: bound to 192.168.0.83 -- renewal in 246 seconds.
Jun 29 07:00:31 iqus dhclient: DHCPREQUEST of <null address> on eth0 to 192.168.0.1 port 67
Jun 29 07:00:31 iqus dhclient: DHCPACK of 192.168.0.83 from 192.168.0.1
Jun 29 07:00:31 iqus dhclient: bound to 192.168.0.83 -- renewal in 296 seconds.
Jun 29 07:05:27 iqus dhclient: DHCPREQUEST of <null address> on eth0 to 192.168.0.1 port 67
Jun 29 07:05:27 iqus dhclient: DHCPACK of 192.168.0.83 from 192.168.0.1
Jun 29 07:05:27 iqus dhclient: bound to 192.168.0.83 -- renewal in 271 seconds.
Jun 29 07:09:58 iqus dhclient: DHCPREQUEST of <null address> on eth0 to 192.168.0.1 port 67
Jun 29 07:09:58 iqus dhclient: DHCPACK of 192.168.0.83 from 192.168.0.1
Jun 29 07:09:58 iqus dhclient: bound to 192.168.0.83 -- renewal in 254 seconds.
Jun 29 07:14:12 iqus dhclient: DHCPREQUEST of <null address> on eth0 to 192.168.0.1 port 67
Jun 29 07:14:12 iqus dhclient: DHCPACK of 192.168.0.83 from 192.168.0.1
Jun 29 07:14:12 iqus dhclient: bound to 192.168.0.83 -- renewal in 241 seconds.
    • renewalのたびに同じIPが振られるので使用上の問題はない
  2. under WAN with DHCPd (2 devices) 
    Jun 30 23:25:51 ubuntu-lan1 dhclient: DHCPREQUEST of <null address> on eth0 to 255.255.255.255 port 67
Jun 30 23:25:51 ubuntu-lan1 dhclient: DHCPREQUEST of <null address> on eth1 to 130.xyz.254.6 port 67
Jun 30 23:25:51 ubuntu-lan1 dhclient: DHCPACK of 133.xx.81.26 from 130.xyz.254.5
Jun 30 23:25:51 ubuntu-lan1 dhclient: bound to 133.xx.81.26 -- renewal in 250 seconds.
Jun 30 23:26:03 ubuntu-lan1 dhclient: DHCPREQUEST of <null address> on eth1 to 130.xyz.254.6 port 67
Jun 30 23:26:15 ubuntu-lan1 dhclient: DHCPREQUEST of <null address> on eth1 to 255.255.255.255 port 67
Jun 30 23:26:15 ubuntu-lan1 dhclient: DHCPACK of 133.xx.80.60 from 130.xyz.254.5
Jun 30 23:26:15 ubuntu-lan1 dhclient: bound to 133.xx.80.60 -- renewal in 250 seconds.
Jun 30 23:30:01 ubuntu-lan1 dhclient: DHCPREQUEST of <null address> on eth0 to 130.xyz.254.6 port 67
Jun 30 23:30:19 ubuntu-lan1 last message repeated 3 times
Jun 30 23:30:25 ubuntu-lan1 dhclient: DHCPREQUEST of <null address> on eth1 to 130.xyz.254.6 port 67
    • renewalのたびに同じIPが振られるので使用上の問題はない
    • dhcp-server-identifierで示されるDHCPdのIPとは違うIPからDHCPACKが帰ってきている
      • dhcpd側の設定ミス？
  3. under WAN with DHCPd (2 devices) 
    Jul  2 00:24:16 VM-centos5 dhclient: DHCPREQUEST on eth0 to 130.xyz.254.6 port 67
Jul  2 00:24:22 VM-centos5 dhclient: DHCPREQUEST on eth1 to 130.xyz.254.6 port 67
Jul  2 00:24:25 VM-centos5 dhclient: DHCPREQUEST on eth0 to 255.255.255.255 port 67
Jul  2 00:24:25 VM-centos5 dhclient: DHCPACK from 130.xyz.254.5
Jul  2 00:24:25 VM-centos5 dhclient: bound to 133.xx.80.164 -- renewal in 267 seconds.
Jul  2 00:24:31 VM-centos5 dhclient: DHCPREQUEST on eth1 to 255.255.255.255 port 67
Jul  2 00:24:31 VM-centos5 dhclient: DHCPACK from 130.xyz.254.5
Jul  2 00:24:31 VM-centos5 dhclient: bound to 133.xx.81.135 -- renewal in 273 seconds.
Jul  2 00:28:52 VM-centos5 dhclient: DHCPREQUEST on eth0 to 130.xyz.254.6 port 67
Jul  2 00:29:00 VM-centos5 dhclient: DHCPREQUEST on eth0 to 130.xyz.254.6 port 67
Jul  2 00:29:04 VM-centos5 dhclient: DHCPREQUEST on eth1 to 130.xyz.254.6 port 67
Jul  2 00:29:15 VM-centos5 last message repeated 2 times
Jul  2 00:29:18 VM-centos5 dhclient: DHCPREQUEST on eth0 to 130.xyz.254.6 port 67
    • 同上
  4. under Windows' ICS (2 devices) 
    Jul  1 23:46:33 ubuntu-napt dhclient: DHCPREQUEST of <null address> on eth1 to 192.168.0.1 port 67
Jul  1 23:46:33 ubuntu-napt dhclient: DHCPNAK from 192.168.0.1
Jul  1 23:46:34 ubuntu-napt dhclient: DHCPDISCOVER on eth1 to 255.255.255.255 port 67 interval 7
Jul  1 23:46:34 ubuntu-napt dhclient: DHCPOFFER of 192.168.0.173 from 192.168.0.1
Jul  1 23:46:34 ubuntu-napt dhclient: DHCPREQUEST of 192.168.0.173 on eth1 to 255.255.255.255 port 67
Jul  1 23:46:35 ubuntu-napt dhclient: DHCPACK of 192.168.0.173 from 192.168.0.1
Jul  1 23:46:36 ubuntu-napt dhclient: bound to 192.168.0.173 -- renewal in 237 seconds.
Jul  1 23:50:31 ubuntu-napt dhclient: DHCPREQUEST of <null address> on eth2 to 192.168.0.1 port 67
Jul  1 23:50:31 ubuntu-napt dhclient: DHCPACK of 192.168.0.234 from 192.168.0.1
Jul  1 23:50:31 ubuntu-napt dhclient: bound to 192.168.0.234 -- renewal in 225 seconds.
Jul  1 23:50:33 ubuntu-napt dhclient: DHCPREQUEST of <null address> on eth1 to 192.168.0.1 port 67
Jul  1 23:50:33 ubuntu-napt dhclient: DHCPNAK from 192.168.0.1
Jul  1 23:50:34 ubuntu-napt dhclient: DHCPDISCOVER on eth1 to 255.255.255.255 port 67 interval 6
Jul  1 23:50:34 ubuntu-napt dhclient: DHCPOFFER of 192.168.0.52 from 192.168.0.1
Jul  1 23:50:34 ubuntu-napt dhclient: DHCPREQUEST of 192.168.0.52 on eth1 to 255.255.255.255 port 67
Jul  1 23:50:35 ubuntu-napt dhclient: DHCPACK of 192.168.0.52 from 192.168.0.1
Jul  1 23:50:36 ubuntu-napt dhclient: bound to 192.168.0.52 -- renewal in 270 seconds.
Jul  1 23:54:16 ubuntu-napt dhclient: DHCPREQUEST of <null address> on eth2 to 192.168.0.1 port 67
Jul  1 23:54:16 ubuntu-napt dhclient: DHCPACK of 192.168.0.234 from 192.168.0.1
Jul  1 23:54:16 ubuntu-napt dhclient: bound to 192.168.0.234 -- renewal in 272 seconds.
Jul  1 23:55:06 ubuntu-napt dhclient: DHCPREQUEST of <null address> on eth1 to 192.168.0.1 port 67
Jul  1 23:55:06 ubuntu-napt dhclient: DHCPNAK from 192.168.0.1
Jul  1 23:55:07 ubuntu-napt dhclient: DHCPDISCOVER on eth1 to 255.255.255.255 port 67 interval 6
Jul  1 23:55:07 ubuntu-napt dhclient: DHCPOFFER of 192.168.0.60 from 192.168.0.1
Jul  1 23:55:07 ubuntu-napt dhclient: DHCPREQUEST of 192.168.0.60 on eth1 to 255.255.255.255 port 67
Jul  1 23:55:08 ubuntu-napt dhclient: DHCPACK of 192.168.0.60 from 192.168.0.1
Jul  1 23:55:09 ubuntu-napt dhclient: bound to 192.168.0.60 -- renewal in 240 seconds.
    • eth1に関しては、renewalのたびに違うIPになっている
      • 192.168.0.173 -> 192.168.0.52 -> 192.168.0.60
    • eth2は同じIPのまま
      • 192.168.0.234

問題点

  1. ログファイル (CentOS=>/var/log/messages, Ubuntu=>/var/log/syslog) が非常に肥大化する
  2. WindowsのICS下のNICが二つあるクライアントでは、二つのうち一つのNICのIPがrenewal毎(数分おき)に更新されてしまい安定しない
    • もう一方のNICのIPはずっと同じままだが、どこに差違があるか不明

Change History (5)

comment:1 Changed 15 years ago by mitty

  • DHCPdからのrenewal通知
    • /var/lib/dhcp3/dhclient.eth1.leases (Ubuntu) under Windows' ICS 
      lease {
  interface "eth1";
  fixed-address 192.168.0.174;
  option subnet-mask 255.255.255.0;
  option dhcp-lease-time 604800;
  option routers 192.168.0.1;
  option dhcp-message-type 5;
  option domain-name-servers 192.168.0.1;
  option dhcp-server-identifier 192.168.0.1;
  option dhcp-renewal-time 300;
  option dhcp-rebinding-time 453600;
  option domain-name "mshome.net";
  option netbios-node-type 4;
  renew 3 2009/7/1 14:36:46;
  rebind 1 2009/7/6 20:32:34;
  expire 3 2009/7/8 14:32:34;
}
      • option dhcp-renewal-time 300; なので、これが理由で4分強でrenewalされている？
    • WANのケースのDHCPdはdhcp-renewal-timeを通知してない模様 (/var/lib/dhclient/dhclient-eth0.leases (CentOS)) 
      lease {
  interface "eth0";
  fixed-address 133.xx.80.164;
  option subnet-mask 255.255.248.0;
  option dhcp-lease-time 600;
  option routers 133.xx.87.254;
  option dhcp-message-type 5;
  option domain-name-servers 130.xyz.68.xy,130.xyz.68.yz;
  option dhcp-server-identifier 130.xyz.254.6;
  option domain-name "xx.yyyyyyy.zz.jp";
  renew 3 2009/7/1 14:52:51;
  rebind 3 2009/7/1 14:57:37;
  expire 3 2009/7/1 14:58:52;
}

comment:2 Changed 15 years ago by mitty

ここに記述されているオプションのうちのいくつかは、DHCP サーバもしくはクライアントによって自動的に生成されるもので、ユーザには設定できません。そのようなオプションの値は、受信側の DHCP プロトコルエージェント (サーバもしくはクライアント) の設定ファイル中の、例えば条件式などで使われます。しかしこのオプションの値は、送信側のエージェントの設定ファイル中では使われることはありません。というのも、その値は、設定ファイルが処理された後に決定されるからです。以降の記述において、そのようなオプションには「ユーザが設定することはできません」と記されます。

option dhcp-renewal-time uint32;
本オプションは、クライアントがアドレスを取得してから REBINDING 状態に移行するまでの時間を秒数で指定します。 本オプションは、ユーザが設定することはできません。

とのことなので対処不能？

comment:3 Changed 15 years ago by mitty

  • 「dhcp-server-identifierで示されるDHCPdのIPとは違うIPからDHCPACKが帰ってきている」件について
option dhcp-server-identifier ip-address;
本オプションは、DHCPOFFER と DHCPREQUEST メッセージ中で使用され、また DHCPACK と DHCPNAK メッセージ中にも含まれることがあります。 DHCP サーバは、クライアントが (訳注: 複数サーバからの) リースの提示を区別できるよう、DHCPOFFER に本オプションを含めます。 DHCP クライアントは、DHCP サーバへユニキャストするすべての DHCP メッセージの宛先アドレスとして 'server identifier' フィールドの内容を使用します。また DHCP クライアントは、DHCPREQUEST メッセージ中に本オプションを含め、複数のリースの提示のどれを受け入れたかを示します。 本オプションの値は、サーバの IP アドレスです。 本オプションは、ユーザが直接設定することはできません。 dhcpd.conf(5) の server-identifier サーバオプションを参照してください。
server-identifier hostname;
server-identifier 文は、それが置かれたスコープ内において、 DHCP サーバ識別子オプションで送られる値を定義するために用います。指定する値は DHCP サーバの IP アドレスでなければならず、そのスコープにおいてサービスを受けるすべてのクライアントから到達可能でなければなりません。
  • dhcpd.confをクライアント側で変更することは不可能なので、ダメ元でdhclient.confでdhcp-server-identifierを指定してみたところ、DHCPでIPが取得できなくなってしまった
    • /etc/dhcp3/dhclient.conf 
      supersede dhcp-server-identifier 130.xyz.254.5;
      • /etc/init.d/networking restart 
        Listening on LPF/eth0/00:0c:29:xx:yy:zz
Sending on   LPF/eth0/00:0c:29:xx:yy:zz
Sending on   Socket/fallback
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3
DHCPOFFER of 133.xx.81.26 from 130.xyz.254.5
DHCPREQUEST of 133.xx.81.26 on eth0 to 255.255.255.255 port 67
DHCPREQUEST of 133.xx.81.26 on eth0 to 255.255.255.255 port 67
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 8
DHCPOFFER of 133.xx.81.26 from 130.xyz.254.5
DHCPREQUEST of 133.xx.81.26 on eth0 to 255.255.255.255 port 67
    • 130.xyz.254.5ではなく、DHCPdから指定されている130.xyz.254.6に設定するとIPが取得できるので、設定自体は効いている模様 
      supersede dhcp-server-identifier 130.xyz.254.6;
      • /etc/init.d/networking restart 
        Listening on LPF/eth0/00:0c:29:xx:yy:zz
Sending on   LPF/eth0/00:0c:29:xx:yy:zz
Sending on   Socket/fallback
DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 5
DHCPOFFER of 133.xx.81.26 from 130.158.254.5
DHCPREQUEST of 133.xx.81.26 on eth0 to 255.255.255.255 port 67
DHCPACK of 133.xx.81.26 from 130.xyz.254.5
bound to 133.xx.81.26 -- renewal in 281 seconds.
  • 結論としては、この件に限っても対策不能？

comment:4 Changed 15 years ago by mitty

  • Description modified (diff)

comment:5 Changed 15 years ago by mitty

  • 次善策として、ログの切り分け(/var/log/dhclient.logに保存など)を考えたが、こちらも不能？
    • Ubuntuにおいては、/var/log/syslogのみならず/var/log/daemon.logにも併せて記録されるので、ログファイルの増大がかなり急激

'dhclient's syslog facility is hard-wired in the source code to "LOG_DAEMON".

Also, while I can alter /etc/syslog.conf to send these messages to a new /var/log/dhclient file ...

とあるので、何らかの方法はあるのかもしれず。

  • dhclientのソースを書き換えるという手もあるが…。パッケージ管理できなくなってしまう点が難。
  • 蛇足
    • dhcpdはdhcpd.confで「log-facility local7;」のような設定が可能
Note: See TracTickets for help on using tickets.