dhcpcd-discuss

After turning on debug with the -d option, these are the debug
messages I'm seeing in the syslog.  Notice that carrier is acquired
only for eth0 as expected.

3275:Dec 13 01:49:46 TS-2RVDE0 dhcpcd[3969]: received SIGTERM, stopping
3276:Dec 13 01:49:46 TS-2RVDE0 dhcpcd[3969]: eth0: removing interface
3277:Dec 13 01:49:46 TS-2RVDE0 dhcpcd[4124]: received SIGTERM, stopping
3278:Dec 13 01:49:46 TS-2RVDE0 dhcpcd[4124]: eth3: removing interface
3279:Dec 13 01:49:46 TS-2RVDE0 dhcpcd[4103]: received SIGTERM, stopping
3280:Dec 13 01:49:46 TS-2RVDE0 dhcpcd[4103]: eth2: removing interface
3281:Dec 13 01:49:46 TS-2RVDE0 dhcpcd[4067]: received SIGTERM, stopping
3282:Dec 13 01:49:46 TS-2RVDE0 dhcpcd[4067]: eth1: removing interface
3321:Dec 13 01:49:47 TS-2RVDE0 networking.sh: dhcp requesting...
3322:Dec 13 01:49:47 TS-2RVDE0 dhcpcd[9587]: version 5.2.12 starting
3323:Dec 13 01:49:48 TS-2RVDE0 dhcpcd[9587]: forked to background,
child pid 9588
3324:Dec 13 01:49:48 TS-2RVDE0 networking.sh: dhcp requesting...
3325:Dec 13 01:49:48 TS-2RVDE0 dhcpcd[9600]: version 5.2.12 starting
3326:Dec 13 01:49:48 TS-2RVDE0 dhcpcd[9588]: eth0: waiting for carrier
3327:Dec 13 01:49:48 TS-2RVDE0 dhcpcd[9600]: forked to background,
child pid 9618
3328:Dec 13 01:49:48 TS-2RVDE0 networking.sh: dhcp requesting...
3329:Dec 13 01:49:48 TS-2RVDE0 dhcpcd[9629]: version 5.2.12 starting
3330:Dec 13 01:49:48 TS-2RVDE0 dhcpcd[9618]: eth1: waiting for carrier
3331:Dec 13 01:49:48 TS-2RVDE0 dhcpcd[9629]: forked to background,
child pid 9639
3332:Dec 13 01:49:48 TS-2RVDE0 networking.sh: dhcp requesting...
3333:Dec 13 01:49:48 TS-2RVDE0 dhcpcd[9656]: version 5.2.12 starting
3334:Dec 13 01:49:48 TS-2RVDE0 dhcpcd[9639]: eth2: waiting for carrier
3335:Dec 13 01:49:48 TS-2RVDE0 dhcpcd[9656]: forked to background,
child pid 9661
3336:Dec 13 01:49:48 TS-2RVDE0 dhcpcd[9661]: eth3: waiting for carrier
3337:Dec 13 01:49:50 TS-2RVDE0 dhcpcd[9588]: eth0: carrier acquired
3342:Dec 13 01:49:50 TS-2RVDE0 dhcpcd[9588]: eth0: rebinding lease of
192.168.1.140
3343:Dec 13 01:49:54 TS-2RVDE0 dhcpcd[9588]: eth0: acknowledged
192.168.1.140 from 192.168.1.2
3344:Dec 13 01:49:54 TS-2RVDE0 dhcpcd[9588]: eth0: checking for 192.168.1.140
3383:Dec 13 01:50:00 TS-2RVDE0 dhcpcd[9588]: eth0: leased
192.168.1.140 for 691200 seconds

So if, eth0 is the only one that has detected carrier, why are the
other interfaces ultimately configured with a 169 address?

On Mon, Dec 12, 2011 at 10:42 AM, Dallas Clement
<dallas.a.clement@xxxxxxxxx> wrote:
> I tried the latest development version and got the same results, i.e.
> all of my uncabled interfaces are getting assigned a 169 address.
>
> Here are the printk's that are going to my syslog from the driver:
>
> 55821:Dec 13 00:55:14 kernel: [234971.511479] e1000e: eth0 NIC Link is Down
> 55868:Dec 13 00:55:31 kernel: [234988.523742] e1000e: eth0 NIC Link is
> Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
> 56047:Dec 13 00:56:18 kernel: [235034.601983] e1000e: eth0 NIC Link is
> Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
> 57042:Dec 13 01:02:24 kernel: [235400.276320] e1000e: eth0 NIC Link is
> Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
> 59235:Dec 13 01:10:35 kernel: [   39.630158] e1000e: Intel(R) PRO/1000
> Network Driver - 1.6.3-NAPI
> 59236:Dec 13 01:10:35 kernel: [   39.636270] e1000e: Copyright(c) 1999
> - 2011 Intel Corporation.
> 59237:Dec 13 01:10:35 kernel: [   39.642219] e1000e 0000:04:00.0:
> Disabling ASPM L0s
> 59238:Dec 13 01:10:35 kernel: [   39.647215] e1000e 0000:04:00.0: PCI
> INT A -> GSI 16 (level, low) -> IRQ 16
> 59239:Dec 13 01:10:35 kernel: [   39.868480] e1000e 0000:04:00.0:
> eth0: (PCI Express:2.5GT/s:Width x1) cc:52:af:ea:7e:d8
> 59240:Dec 13 01:10:35 kernel: [   39.876956] e1000e 0000:04:00.0:
> eth0: Intel(R) PRO/1000 Network Connection
> 59241:Dec 13 01:10:35 kernel: [   39.884010] e1000e 0000:04:00.0:
> eth0: MAC: 4, PHY: 8, PBA No: FFFFFF-0FF
> 59242:Dec 13 01:10:35 kernel: [   39.890815] e1000e 0000:05:00.0:
> Disabling ASPM L0s
> 59243:Dec 13 01:10:35 kernel: [   39.895804] e1000e 0000:05:00.0: PCI
> INT A -> GSI 17 (level, low) -> IRQ 17
> 59244:Dec 13 01:10:35 kernel: [   40.079673] e1000e 0000:05:00.0:
> eth1: (PCI Express:2.5GT/s:Width x1) cc:52:af:ea:7e:d9
> 59245:Dec 13 01:10:35 kernel: [   40.087697] e1000e 0000:05:00.0:
> eth1: Intel(R) PRO/1000 Network Connection
> 59246:Dec 13 01:10:35 kernel: [   40.094753] e1000e 0000:05:00.0:
> eth1: MAC: 4, PHY: 8, PBA No: FFFFFF-0FF
> 59247:Dec 13 01:10:35 kernel: [   40.101552] e1000e 0000:06:00.0:
> Disabling ASPM L0s
> 59248:Dec 13 01:10:35 kernel: [   40.106546] e1000e 0000:06:00.0: PCI
> INT A -> GSI 18 (level, low) -> IRQ 18
> 59249:Dec 13 01:10:35 kernel: [   40.279106] e1000e 0000:06:00.0:
> eth2: (PCI Express:2.5GT/s:Width x1) cc:52:af:ea:7e:da
> 59250:Dec 13 01:10:35 kernel: [   40.287128] e1000e 0000:06:00.0:
> eth2: Intel(R) PRO/1000 Network Connection
> 59251:Dec 13 01:10:35 kernel: [   40.294182] e1000e 0000:06:00.0:
> eth2: MAC: 4, PHY: 8, PBA No: FFFFFF-0FF
> 59252:Dec 13 01:10:35 kernel: [   40.300980] e1000e 0000:07:00.0:
> Disabling ASPM L0s
> 59253:Dec 13 01:10:35 kernel: [   40.305975] e1000e 0000:07:00.0: PCI
> INT A -> GSI 19 (level, low) -> IRQ 19
> 59254:Dec 13 01:10:35 kernel: [   40.478535] e1000e 0000:07:00.0:
> eth3: (PCI Express:2.5GT/s:Width x1) cc:52:af:ea:7e:db
> 59255:Dec 13 01:10:35 kernel: [   40.486555] e1000e 0000:07:00.0:
> eth3: Intel(R) PRO/1000 Network Connection
> 59256:Dec 13 01:10:35 kernel: [   40.493610] e1000e 0000:07:00.0:
> eth3: MAC: 4, PHY: 8, PBA No: FFFFFF-0FF
> 59361:Dec 13 01:10:35 kernel: [  121.472787] e1000e: eth0 NIC Link is
> Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
>
> As you can see, eth0 is the only one that reports a link up transition.
>
> Here is what ifconfig is reporting:
>
> root@bubba:# ifconfig
> eth0      Link encap:Ethernet  HWaddr CC:52:AF:EA:7E:D8
>          inet addr:192.168.1.142  Bcast:192.168.1.255  Mask:255.255.254.0
>          UP BROADCAST NOTRAILERS RUNNING MULTICAST  MTU:1500  Metric:1
>          RX packets:253104 errors:0 dropped:25 overruns:0 frame:0
>          TX packets:7686 errors:0 dropped:0 overruns:0 carrier:0
>          collisions:0 txqueuelen:1000
>          RX bytes:48025107 (45.7 MiB)  TX bytes:1303902 (1.2 MiB)
>          Interrupt:16 Memory:fbb00000-fbb20000
>
> eth1      Link encap:Ethernet  HWaddr CC:52:AF:EA:7E:D9
>          inet addr:169.254.49.74  Bcast:169.254.255.255  Mask:255.255.0.0
>          UP BROADCAST NOTRAILERS MULTICAST  MTU:1500  Metric:1
>          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
>          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
>          collisions:0 txqueuelen:1000
>          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)
>          Interrupt:17 Memory:fba00000-fba20000
>
> eth2      Link encap:Ethernet  HWaddr CC:52:AF:EA:7E:DA
>          inet addr:169.254.15.63  Bcast:169.254.255.255  Mask:255.255.0.0
>          UP BROADCAST NOTRAILERS MULTICAST  MTU:1500  Metric:1
>          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
>          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
>          collisions:0 txqueuelen:1000
>          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)
>          Interrupt:18 Memory:fb900000-fb920000
>
> eth3      Link encap:Ethernet  HWaddr CC:52:AF:EA:7E:DB
>          inet addr:169.254.103.123  Bcast:169.254.255.255  Mask:255.255.0.0
>          UP BROADCAST NOTRAILERS MULTICAST  MTU:1500  Metric:1
>          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
>          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
>          collisions:0 txqueuelen:1000
>          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)
>          Interrupt:19 Memory:fb800000-fb820000
>
> And here's what sysfs thinks:
>
> root@bubba:/var/log# cat /sys/class/net/eth0/operstate
> up
> root@bubba:/var/log# cat /sys/class/net/eth1/operstate
> down
> root@bubba:/var/log# cat /sys/class/net/eth2/operstate
> down
> root@bubba:/var/log# cat /sys/class/net/eth3/operstate
> down
>
> Does dhcpcd have any debugging that can help us observe why it is
> giving a 169 address to a down interface?
>
> On Sat, Dec 10, 2011 at 5:43 AM, Roy Marples <roy@xxxxxxxxxxxx> wrote:
>> On Fri, 2011-12-09 at 21:47 -0600, Dallas Clement wrote:
>>> Roy,  Thank you for the speedy and most helpful response.  I am indeed
>>>  seeing at least one extra spurious link down / up from the driver,
>>>  although it's only for the cabled interface.  Ifconfig  shows the
>>>  other 3 interfaces as down, as does /sys/class/net/ethX/overstate.  I
>>>  am using the very latest e1000e driver.  How is dhcpcd determining
>>>  carrier presence?
>>
>> dhcpcd determines a working carrier from the IFF_RUNNING flag against
>> the interface and listens to RTM_NEWLINK and RTM_DELLINK kernel
>> messages.
>>
>> Although this has changed slightly in my latest development version. Why
>> not try a trunk copy? You can get the latest code doing this with git:
>>
>> git clone git://roy.marples.name/dhcpcd.git
>>
>> Thanks
>>
>> Roy
>>