Hi I am probably doing something wrong, but I can't figure out why I seem to be loosing attributes during the processing of a DHCP request. As I understand it, the snippet here shows that the attribute DHCP-Your-IP-Address is added by rlm_perl and later on that the attribute does not exist: Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Your-IP-Address = $RAD_REPLY{'DHCP-Your-IP-Address'} -> '10.200.0.50' ... Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP: Failed to find DHCP-Client-IP-Address or DHCP-Your-IP-Address for request; not responding What I can't understand is why the attribute cannot be found later on in the processing of the request. This server is running the latest 3.0. and it is successfully processing other DHCP packets. The only difference I can see with this packet is that is from a locally attached client wheras the other clients are behind relays. I would be grateful for any help. Here is the full debug: Received DHCP-Discover of Id 35a1700b from 0.0.0.0:68 to 255.255.255.255:67 0: 01 01 06 00 35 a1 70 0b 00 00 80 00 00 00 00 00 16: 00 00 00 00 00 00 00 00 00 00 00 00 00 0c 29 06 32: ca 30 00 00 00 00 00 00 00 00 00 00 00 00 00 00 48: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 64: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 96: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 112: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 128: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 144: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 160: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 176: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 192: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 208: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 224: 00 00 00 00 00 00 00 00 00 00 00 00 63 82 53 63 240: 35 01 01 74 01 01 3d 07 01 00 0c 29 06 ca 30 32 256: 04 a9 fe 85 6a 0c 0f 68 6f 6d 65 2d 63 63 37 61 272: 64 34 37 61 34 31 3c 08 4d 53 46 54 20 35 2e 30 288: 37 0b 01 0f 03 06 2c 2e 2f 1f 21 f9 2b 2b 02 dc 304: 00 ff DHCP-Opcode = Client-Message DHCP-Hardware-Type = Ethernet DHCP-Hardware-Address-Length = 6 DHCP-Hop-Count = 0 DHCP-Transaction-Id = 899772427 DHCP-Number-of-Seconds = 0 DHCP-Flags = Broadcast DHCP-Client-IP-Address = 0.0.0.0 DHCP-Your-IP-Address = 0.0.0.0 DHCP-Server-IP-Address = 0.0.0.0 DHCP-Gateway-IP-Address = 0.0.0.0 DHCP-Client-Hardware-Address = 00:0c:29:06:ca:30 DHCP-Message-Type = DHCP-Discover DHCP-Auto-Config = 1 DHCP-Client-Identifier = 0x01000c2906ca30 DHCP-Requested-IP-Address = 169.254.133.106 DHCP-Hostname = "home-cc7ad47a41" DHCP-Vendor-Class-Identifier = 0x4d53465420352e30 DHCP-Parameter-Request-List = DHCP-Subnet-Mask DHCP-Parameter-Request-List = DHCP-Domain-Name DHCP-Parameter-Request-List = DHCP-Router-Address DHCP-Parameter-Request-List = DHCP-Domain-Name-Server DHCP-Parameter-Request-List = DHCP-NETBIOS-Name-Servers DHCP-Parameter-Request-List = DHCP-NETBIOS-Node-Type DHCP-Parameter-Request-List = DHCP-NETBIOS DHCP-Parameter-Request-List = DHCP-Perform-Router-Discovery DHCP-Parameter-Request-List = DHCP-Static-Routes DHCP-Parameter-Request-List = DHCP-Site-specific-25 DHCP-Parameter-Request-List = DHCP-Vendor DHCP-Vendor = 0xdc00 Wed Sep 23 08:46:42 2015 : Debug: (5) Received code 1025 Id 899772427 from 0.0.0.0:68 to 255.255.255.255:67 length 306 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Opcode = Client-Message Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Hardware-Type = Ethernet Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Hardware-Address-Length = 6 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Hop-Count = 0 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Transaction-Id = 899772427 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Number-of-Seconds = 0 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Flags = Broadcast Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Client-IP-Address = 0.0.0.0 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Your-IP-Address = 0.0.0.0 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Server-IP-Address = 0.0.0.0 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Gateway-IP-Address = 0.0.0.0 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Client-Hardware-Address = 00:0c:29:06:ca:30 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Message-Type = DHCP-Discover Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Auto-Config = 1 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Client-Identifier = 0x01000c2906ca30 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Requested-IP-Address = 169.254.133.106 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Hostname = "home-cc7ad47a41" Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Vendor-Class-Identifier = 0x4d53465420352e30 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Parameter-Request-List = DHCP-Subnet-Mask Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Parameter-Request-List = DHCP-Domain-Name Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Parameter-Request-List = DHCP-Router-Address Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Parameter-Request-List = DHCP-Domain-Name-Server Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Parameter-Request-List = DHCP-NETBIOS-Name-Servers Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Parameter-Request-List = DHCP-NETBIOS-Node-Type Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Parameter-Request-List = DHCP-NETBIOS Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Parameter-Request-List = DHCP-Perform-Router-Discovery Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Parameter-Request-List = DHCP-Static-Routes Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Parameter-Request-List = DHCP-Site-specific-25 Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Parameter-Request-List = DHCP-Vendor Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP-Vendor = 0xdc00 Wed Sep 23 08:46:42 2015 : Debug: Trying sub-section dhcp DHCP-Discover {...} Wed Sep 23 08:46:42 2015 : Debug: (5) dhcp DHCP-Discover { Wed Sep 23 08:46:42 2015 : Debug: (5) modsingle[post-auth]: calling linelog-dhcp (rlm_linelog) for request 5 Wed Sep 23 08:46:42 2015 : Debug: %{%{reply:DHCP-Message-Type}:-%{request:DHCP-Message-Type}} Wed Sep 23 08:46:42 2015 : Debug: Parsed xlat tree: Wed Sep 23 08:46:42 2015 : Debug: if { Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Message-Type Wed Sep 23 08:46:42 2015 : Debug: } Wed Sep 23 08:46:42 2015 : Debug: else { Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Message-Type Wed Sep 23 08:46:42 2015 : Debug: } Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: EXPAND %{%{reply:DHCP-Message-Type}:-%{request:DHCP-Message-Type}} Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: --> DHCP-Discover Wed Sep 23 08:46:42 2015 : Debug: /usr/local/var/log/radius-dhcp/linelog-dhcp.log Wed Sep 23 08:46:42 2015 : Debug: Parsed xlat tree: Wed Sep 23 08:46:42 2015 : Debug: literal --> /usr/local/var/log/radius-dhcp/linelog-dhcp.log Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: EXPAND /usr/local/var/log/radius-dhcp/linelog-dhcp.log Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: --> /usr/local/var/log/radius-dhcp/linelog-dhcp.log Wed Sep 23 08:46:42 2015 : Debug: %S --> Transaction-ID: %{DHCP-Transaction-Id} DISCOVER: [%{DHCP-Client-Hardware-Address}] via (%{DHCP-Gateway-IP-Address}), hop count = %{DHCP-Hop-Count}, Relay = %{DHCP-Relay-Remote-Id}, Hostname = %{DHCP-Hostname} Wed Sep 23 08:46:42 2015 : Debug: Parsed xlat tree: Wed Sep 23 08:46:42 2015 : Debug: percent --> S Wed Sep 23 08:46:42 2015 : Debug: literal --> --> Transaction-ID: Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Transaction-Id Wed Sep 23 08:46:42 2015 : Debug: literal --> DISCOVER: [ Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Client-Hardware-Address Wed Sep 23 08:46:42 2015 : Debug: literal --> ] via ( Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Gateway-IP-Address Wed Sep 23 08:46:42 2015 : Debug: literal --> ), hop count = Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Hop-Count Wed Sep 23 08:46:42 2015 : Debug: literal --> , Relay = Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Relay-Remote-Id Wed Sep 23 08:46:42 2015 : Debug: literal --> , Hostname = Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Hostname Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: EXPAND %S --> Transaction-ID: %{DHCP-Transaction-Id} DISCOVER: [%{DHCP-Client-Hardware-Address}] via (%{DHCP-Gateway-IP-Address}), hop count = %{DHCP-Hop-Count}, Relay = %{DHCP-Relay-Remote-Id}, Hostname = %{DHCP-Hostname} Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: --> 2015-09-23 08:46:42 --> Transaction-ID: 899772427 DISCOVER: [00:0c:29:06:ca:30] via (0.0.0.0), hop count = 0, Relay = , Hostname = home-cc7ad47a41 Wed Sep 23 08:46:42 2015 : Debug: (5) modsingle[post-auth]: returned from linelog-dhcp (rlm_linelog) for request 5 Wed Sep 23 08:46:42 2015 : Debug: (5) [linelog-dhcp] = ok Wed Sep 23 08:46:42 2015 : Debug: (5) update reply { Wed Sep 23 08:46:42 2015 : Debug: (5) &DHCP-DHCP-Server-Identifier = 10.200.0.1 Wed Sep 23 08:46:42 2015 : Debug: (5) &DHCP-Flags = 0 Wed Sep 23 08:46:42 2015 : Debug: (5) } # update reply = noop Wed Sep 23 08:46:42 2015 : Debug: (5) modsingle[post-auth]: calling perl (rlm_perl) for request 5 Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Opcode'} = &request:DHCP-Opcode -> 'Client-Message' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Hardware-Type'} = &request:DHCP-Hardware-Type -> 'Ethernet' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Hardware-Address-Length'} = &request:DHCP-Hardware-Address-Length -> '6' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Hop-Count'} = &request:DHCP-Hop-Count -> '0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Transaction-Id'} = &request:DHCP-Transaction-Id -> '899772427' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Number-of-Seconds'} = &request:DHCP-Number-of-Seconds -> '0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Flags'} = &request:DHCP-Flags -> 'Broadcast' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Client-IP-Address'} = &request:DHCP-Client-IP-Address -> '0.0.0.0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Your-IP-Address'} = &request:DHCP-Your-IP-Address -> '0.0.0.0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Server-IP-Address'} = &request:DHCP-Server-IP-Address -> '0.0.0.0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Gateway-IP-Address'} = &request:DHCP-Gateway-IP-Address -> '0.0.0.0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Client-Hardware-Address'} = &request:DHCP-Client-Hardware-Address -> '00:0c:29:06:ca:30' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Hostname'} = &request:DHCP-Hostname -> 'home-cc7ad47a41' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Vendor'} = &request:DHCP-Vendor -> '0xdc00' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Requested-IP-Address'} = &request:DHCP-Requested-IP-Address -> '169.254.133.106' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Message-Type'} = &request:DHCP-Message-Type -> 'DHCP-Discover' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[0] = &request:DHCP-Parameter-Request-List -> 'DHCP-Subnet-Mask' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[1] = &request:DHCP-Parameter-Request-List -> 'DHCP-Domain-Name' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[2] = &request:DHCP-Parameter-Request-List -> 'DHCP-Router-Address' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[3] = &request:DHCP-Parameter-Request-List -> 'DHCP-Domain-Name-Server' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[4] = &request:DHCP-Parameter-Request-List -> 'DHCP-NETBIOS-Name-Servers' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[5] = &request:DHCP-Parameter-Request-List -> 'DHCP-NETBIOS-Node-Type' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[6] = &request:DHCP-Parameter-Request-List -> 'DHCP-NETBIOS' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[7] = &request:DHCP-Parameter-Request-List -> 'DHCP-Perform-Router-Discovery' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[8] = &request:DHCP-Parameter-Request-List -> 'DHCP-Static-Routes' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[9] = &request:DHCP-Parameter-Request-List -> 'DHCP-Site-specific-25' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[10] = &request:DHCP-Parameter-Request-List -> 'DHCP-Vendor' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Vendor-Class-Identifier'} = &request:DHCP-Vendor-Class-Identifier -> '0x4d53465420352e30' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Client-Identifier'} = &request:DHCP-Client-Identifier -> '0x01000c2906ca30' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REQUEST{'DHCP-Auto-Config'} = &request:DHCP-Auto-Config -> '1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REPLY{'DHCP-Flags'} = &reply:DHCP-Flags -> '0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: $RAD_REPLY{'DHCP-DHCP-Server-Identifier'} = &reply:DHCP-DHCP-Server-Identifier -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Your-IP-Address = $RAD_REQUEST{'DHCP-Your-IP-Address'} -> '0.0.0.0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Message-Type = $RAD_REQUEST{'DHCP-Message-Type'} -> 'DHCP-Discover' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Vendor-Class-Identifier = $RAD_REQUEST{'DHCP-Vendor-Class-Identifier'} -> '0x4d53465420352e30' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Hop-Count = $RAD_REQUEST{'DHCP-Hop-Count'} -> '0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Number-of-Seconds = $RAD_REQUEST{'DHCP-Number-of-Seconds'} -> '0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Client-IP-Address = $RAD_REQUEST{'DHCP-Client-IP-Address'} -> '0.0.0.0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Gateway-IP-Address = $RAD_REQUEST{'DHCP-Gateway-IP-Address'} -> '0.0.0.0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Hardware-Type = $RAD_REQUEST{'DHCP-Hardware-Type'} -> 'Ethernet' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Flags = $RAD_REQUEST{'DHCP-Flags'} -> 'Broadcast' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Hardware-Address-Length = $RAD_REQUEST{'DHCP-Hardware-Address-Length'} -> '6' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Hostname = $RAD_REQUEST{'DHCP-Hostname'} -> 'home-cc7ad47a41' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Opcode = $RAD_REQUEST{'DHCP-Opcode'} -> 'Client-Message' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Transaction-Id = $RAD_REQUEST{'DHCP-Transaction-Id'} -> '899772427' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Subnet-Mask' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Domain-Name' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Router-Address' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Domain-Name-Server' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-NETBIOS-Name-Servers' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-NETBIOS-Node-Type' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-NETBIOS' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Perform-Router-Discovery' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Static-Routes' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Site-specific-25' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Vendor' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Client-Hardware-Address = $RAD_REQUEST{'DHCP-Client-Hardware-Address'} -> '00:0c:29:06:ca:30' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Server-IP-Address = $RAD_REQUEST{'DHCP-Server-IP-Address'} -> '0.0.0.0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Requested-IP-Address = $RAD_REQUEST{'DHCP-Requested-IP-Address'} -> '169.254.133.106' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Auto-Config = $RAD_REQUEST{'DHCP-Auto-Config'} -> '1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Vendor = $RAD_REQUEST{'DHCP-Vendor'} -> '0xdc00' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &request:DHCP-Client-Identifier = $RAD_REQUEST{'DHCP-Client-Identifier'} -> '0x01000c2906ca30' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Your-IP-Address = $RAD_REPLY{'DHCP-Your-IP-Address'} -> '10.200.0.50' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Domain-Name-Server += $RAD_REPLY{'DHCP-Domain-Name-Server'} -> '10.1.1.253' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Domain-Name-Server += $RAD_REPLY{'DHCP-Domain-Name-Server'} -> '10.1.1.254' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-WWW-Server-Address = $RAD_REPLY{'DHCP-WWW-Server-Address'} -> 'www.censored' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Time-Offset = $RAD_REPLY{'DHCP-Time-Offset'} -> '2' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-SMTP-Server-Address = $RAD_REPLY{'DHCP-SMTP-Server-Address'} -> 'smtp.censored' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-POP3-Server-Address = $RAD_REPLY{'DHCP-POP3-Server-Address'} -> 'mail.censored' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Site-specific-25 = $RAD_REPLY{'DHCP-Site-specific-25'} -> '0x100a010ac80001100a020ac80001100a0a0ac800010cac100ac800010cac200ac8000108ef0ac80032' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Boot-Filename = $RAD_REPLY{'DHCP-Boot-Filename'} -> 'hydra.bin' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-IP-Address-Lease-Time = $RAD_REPLY{'DHCP-IP-Address-Lease-Time'} -> '300' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Time-Server = $RAD_REPLY{'DHCP-Time-Server'} -> 'time.censored' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-DHCP-Server-Identifier = $RAD_REPLY{'DHCP-DHCP-Server-Identifier'} -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Subnet-Mask = $RAD_REPLY{'DHCP-Subnet-Mask'} -> '255.255.255.0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-NNTP-Server-Address = $RAD_REPLY{'DHCP-NNTP-Server-Address'} -> 'ntp.censored' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Router-Address = $RAD_REPLY{'DHCP-Router-Address'} -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.1.1.5' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.1.2.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.2.2.7' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.2.2.8' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.2.2.9' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.2.2.11' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.1.1.250' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.1.1.252' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.1.1.254' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-IP-Forward-Enable = $RAD_REPLY{'DHCP-IP-Forward-Enable'} -> '0' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-Classless-Static-Route = $RAD_REPLY{'DHCP-Classless-Static-Route'} -> '0x100a010ac80001100a020ac80001100a0a0ac800010cac100ac800010cac200ac8000108ef0ac80032' Wed Sep 23 08:46:42 2015 : Debug: (5) perl: &reply:DHCP-NTP-Servers = $RAD_REPLY{'DHCP-NTP-Servers'} -> 'ntp.censored' Wed Sep 23 08:46:42 2015 : Debug: (5) modsingle[post-auth]: returned from perl (rlm_perl) for request 5 Wed Sep 23 08:46:42 2015 : Debug: (5) [perl] = ok Wed Sep 23 08:46:42 2015 : Debug: (5) if (ok) { Wed Sep 23 08:46:42 2015 : Debug: (5) if (ok) -> TRUE Wed Sep 23 08:46:42 2015 : Debug: (5) if (ok) { Wed Sep 23 08:46:42 2015 : Debug: (5) update reply { Wed Sep 23 08:46:42 2015 : Debug: (5) &DHCP-Message-Type = DHCP-Offer Wed Sep 23 08:46:42 2015 : Debug: (5) &DHCP-Server-IP-Address = 10.200.0.1 Wed Sep 23 08:46:42 2015 : Debug: (5) } # update reply = noop Wed Sep 23 08:46:42 2015 : Debug: (5) } # if (ok) = noop Wed Sep 23 08:46:42 2015 : Debug: (5) ... skipping else for request 5: Preceding "if" was taken Wed Sep 23 08:46:42 2015 : Debug: (5) modsingle[post-auth]: calling linelog-dhcp (rlm_linelog) for request 5 Wed Sep 23 08:46:42 2015 : Debug: %{%{reply:DHCP-Message-Type}:-%{request:DHCP-Message-Type}} Wed Sep 23 08:46:42 2015 : Debug: Parsed xlat tree: Wed Sep 23 08:46:42 2015 : Debug: if { Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Message-Type Wed Sep 23 08:46:42 2015 : Debug: } Wed Sep 23 08:46:42 2015 : Debug: else { Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Message-Type Wed Sep 23 08:46:42 2015 : Debug: } Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: EXPAND %{%{reply:DHCP-Message-Type}:-%{request:DHCP-Message-Type}} Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: --> DHCP-Offer Wed Sep 23 08:46:42 2015 : Debug: /usr/local/var/log/radius-dhcp/linelog-dhcp.log Wed Sep 23 08:46:42 2015 : Debug: Parsed xlat tree: Wed Sep 23 08:46:42 2015 : Debug: literal --> /usr/local/var/log/radius-dhcp/linelog-dhcp.log Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: EXPAND /usr/local/var/log/radius-dhcp/linelog-dhcp.log Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: --> /usr/local/var/log/radius-dhcp/linelog-dhcp.log Wed Sep 23 08:46:42 2015 : Debug: %S <-- Transaction-ID: %{DHCP-Transaction-Id} OFFER: %{reply:DHCP-Your-IP-Address} to [%{DHCP-Client-Hardware-Address}] ... Wed Sep 23 08:46:42 2015 : Debug: Parsed xlat tree: Wed Sep 23 08:46:42 2015 : Debug: percent --> S Wed Sep 23 08:46:42 2015 : Debug: literal --> <-- Transaction-ID: Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Transaction-Id Wed Sep 23 08:46:42 2015 : Debug: literal --> OFFER: Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Your-IP-Address Wed Sep 23 08:46:42 2015 : Debug: literal --> to [ Wed Sep 23 08:46:42 2015 : Debug: attribute --> DHCP-Client-Hardware-Address Wed Sep 23 08:46:42 2015 : Debug: literal --> ] ... Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: EXPAND %S <-- Transaction-ID: %{DHCP-Transaction-Id} OFFER: %{reply:DHCP-Your-IP-Address} to [%{DHCP-Client-Hardware-Address}] ... Wed Sep 23 08:46:42 2015 : Debug: (5) linelog-dhcp: --> 2015-09-23 08:46:42 <-- Transaction-ID: 899772427 OFFER: to [00:0c:29:06:ca:30] ... Wed Sep 23 08:46:42 2015 : Debug: (5) modsingle[post-auth]: returned from linelog-dhcp (rlm_linelog) for request 5 Wed Sep 23 08:46:42 2015 : Debug: (5) [linelog-dhcp] = ok Wed Sep 23 08:46:42 2015 : Debug: (5) modsingle[post-auth]: calling ok (rlm_always) for request 5 Wed Sep 23 08:46:42 2015 : Debug: (5) modsingle[post-auth]: returned from ok (rlm_always) for request 5 Wed Sep 23 08:46:42 2015 : Debug: (5) [ok] = ok Wed Sep 23 08:46:42 2015 : Debug: (5) } # dhcp DHCP-Discover = ok Wed Sep 23 08:46:42 2015 : Debug: (5) DHCP: Failed to find DHCP-Client-IP-Address or DHCP-Your-IP-Address for request; not responding Wed Sep 23 08:46:42 2015 : Debug: (5) Not sending reply to client. Wed Sep 23 08:46:42 2015 : Debug: (5) Finished request Wed Sep 23 08:46:42 2015 : Debug: (5) Cleaning up request packet ID 899772427 with timestamp +39
On Sep 23, 2015, at 2:35 AM, Бен Томпсон <b.thompson@latera.ru> wrote:
I am probably doing something wrong, but I can't figure out why I seem to be loosing attributes during the processing of a DHCP request. ... What I can't understand is why the attribute cannot be found later on in the processing of the request. This server is running the latest 3.0. and it is successfully processing other DHCP packets. The only difference I can see with this packet is that is from a locally attached client wheras the other clients are behind relays.
Attributes don't just disappear. They're removed only when requested.
I would be grateful for any help.
Here is the full debug:
It's difficult to read that with the timestamps, and the forced wrapping at 80 columns. I'd suggest adding a simple "linelog" modules that writes something to a file, and then name that file using reply:DHCP-Your-IP-Address. Then, put references to that module all through the "discover" section. You should see the attribute exist after "perl" runs. Then some time later, it doesn't exist. That at least tells you WHERE the attribute is disappearing. Alan DeKok.
On 23 September 2015 at 15:48, Alan DeKok <aland@deployingradius.com> wrote:
It's difficult to read that with the timestamps, and the forced wrapping at 80 columns.
I'd suggest adding a simple "linelog" modules that writes something to a file, and then name that file using reply:DHCP-Your-IP-Address.
Then, put references to that module all through the "discover" section. You should see the attribute exist after "perl" runs. Then some time later, it doesn't exist. That at least tells you WHERE the attribute is disappearing.
Hi Alan Thanks for your advice. I tried linelog and found that even when I insert it directly after the call to "perl", the attribute is empty. I am at a loss to figure out what is happening here. Any help would be appreciated. Here is the full debug: Received DHCP-Discover of Id 05683745 from 0.0.0.0:68 to 255.255.255.255:67 DHCP-Opcode = Client-Message DHCP-Hardware-Type = Ethernet DHCP-Hardware-Address-Length = 6 DHCP-Hop-Count = 0 DHCP-Transaction-Id = 90715973 DHCP-Number-of-Seconds = 0 DHCP-Flags = 0 DHCP-Client-IP-Address = 0.0.0.0 DHCP-Your-IP-Address = 0.0.0.0 DHCP-Server-IP-Address = 0.0.0.0 DHCP-Gateway-IP-Address = 0.0.0.0 DHCP-Client-Hardware-Address = 00:0c:29:06:ca:30 DHCP-Message-Type = DHCP-Discover DHCP-Auto-Config = 1 DHCP-Client-Identifier = 0x01000c2906ca30 DHCP-Requested-IP-Address = 169.254.133.106 DHCP-Hostname = "home-cc7ad47a41" DHCP-Vendor-Class-Identifier = 0x4d53465420352e30 DHCP-Parameter-Request-List = DHCP-Subnet-Mask DHCP-Parameter-Request-List = DHCP-Domain-Name DHCP-Parameter-Request-List = DHCP-Router-Address DHCP-Parameter-Request-List = DHCP-Domain-Name-Server DHCP-Parameter-Request-List = DHCP-NETBIOS-Name-Servers DHCP-Parameter-Request-List = DHCP-NETBIOS-Node-Type DHCP-Parameter-Request-List = DHCP-NETBIOS DHCP-Parameter-Request-List = DHCP-Perform-Router-Discovery DHCP-Parameter-Request-List = DHCP-Static-Routes DHCP-Parameter-Request-List = DHCP-Site-specific-25 DHCP-Parameter-Request-List = DHCP-Vendor DHCP-Vendor = 0xdc00 (2) Received code 1025 Id 90715973 from 0.0.0.0:68 to 255.255.255.255:67 length 306 (2) DHCP-Opcode = Client-Message (2) DHCP-Hardware-Type = Ethernet (2) DHCP-Hardware-Address-Length = 6 (2) DHCP-Hop-Count = 0 (2) DHCP-Transaction-Id = 90715973 (2) DHCP-Number-of-Seconds = 0 (2) DHCP-Flags = 0 (2) DHCP-Client-IP-Address = 0.0.0.0 (2) DHCP-Your-IP-Address = 0.0.0.0 (2) DHCP-Server-IP-Address = 0.0.0.0 (2) DHCP-Gateway-IP-Address = 0.0.0.0 (2) DHCP-Client-Hardware-Address = 00:0c:29:06:ca:30 (2) DHCP-Message-Type = DHCP-Discover (2) DHCP-Auto-Config = 1 (2) DHCP-Client-Identifier = 0x01000c2906ca30 (2) DHCP-Requested-IP-Address = 169.254.133.106 (2) DHCP-Hostname = "home-cc7ad47a41" (2) DHCP-Vendor-Class-Identifier = 0x4d53465420352e30 (2) DHCP-Parameter-Request-List = DHCP-Subnet-Mask (2) DHCP-Parameter-Request-List = DHCP-Domain-Name (2) DHCP-Parameter-Request-List = DHCP-Router-Address (2) DHCP-Parameter-Request-List = DHCP-Domain-Name-Server (2) DHCP-Parameter-Request-List = DHCP-NETBIOS-Name-Servers (2) DHCP-Parameter-Request-List = DHCP-NETBIOS-Node-Type (2) DHCP-Parameter-Request-List = DHCP-NETBIOS (2) DHCP-Parameter-Request-List = DHCP-Perform-Router-Discovery (2) DHCP-Parameter-Request-List = DHCP-Static-Routes (2) DHCP-Parameter-Request-List = DHCP-Site-specific-25 (2) DHCP-Parameter-Request-List = DHCP-Vendor (2) DHCP-Vendor = 0xdc00 Trying sub-section dhcp DHCP-Discover {...} (2) dhcp DHCP-Discover { (2) linelog-dhcp: EXPAND %{%{reply:DHCP-Message-Type}:-%{request:DHCP-Message-Type}} (2) linelog-dhcp: --> DHCP-Discover (2) linelog-dhcp: EXPAND /usr/local/var/log/radius-dhcp/linelog-dhcp.log (2) linelog-dhcp: --> /usr/local/var/log/radius-dhcp/linelog-dhcp.log (2) linelog-dhcp: EXPAND %S --> Transaction-ID: %{DHCP-Transaction-Id} DISCOVER: [%{DHCP-Client-Hardware-Address}] via (%{DHCP-Gateway-IP-Address}), hop count = %{DHCP-Hop-Count}, Relay = %{DHCP-Relay-Remote-Id}, Hostname = %{DHCP-Hostname} (2) linelog-dhcp: --> 2015-09-23 20:08:44 --> Transaction-ID: 90715973 DISCOVER: [00:0c:29:06:ca:30] via (0.0.0.0), hop count = 0, Relay = , Hostname = home-cc7ad47a41 (2) [linelog-dhcp] = ok (2) update reply { (2) &DHCP-DHCP-Server-Identifier = 10.200.0.1 (2) &DHCP-Flags = 0 (2) } # update reply = noop (2) perl: $RAD_REQUEST{'DHCP-Opcode'} = &request:DHCP-Opcode -> 'Client-Message' (2) perl: $RAD_REQUEST{'DHCP-Hardware-Type'} = &request:DHCP-Hardware-Type -> 'Ethernet' (2) perl: $RAD_REQUEST{'DHCP-Hardware-Address-Length'} = &request:DHCP-Hardware-Address-Length -> '6' (2) perl: $RAD_REQUEST{'DHCP-Hop-Count'} = &request:DHCP-Hop-Count -> '0' (2) perl: $RAD_REQUEST{'DHCP-Transaction-Id'} = &request:DHCP-Transaction-Id -> '90715973' (2) perl: $RAD_REQUEST{'DHCP-Number-of-Seconds'} = &request:DHCP-Number-of-Seconds -> '0' (2) perl: $RAD_REQUEST{'DHCP-Flags'} = &request:DHCP-Flags -> '0' (2) perl: $RAD_REQUEST{'DHCP-Client-IP-Address'} = &request:DHCP-Client-IP-Address -> '0.0.0.0' (2) perl: $RAD_REQUEST{'DHCP-Your-IP-Address'} = &request:DHCP-Your-IP-Address -> '0.0.0.0' (2) perl: $RAD_REQUEST{'DHCP-Server-IP-Address'} = &request:DHCP-Server-IP-Address -> '0.0.0.0' (2) perl: $RAD_REQUEST{'DHCP-Gateway-IP-Address'} = &request:DHCP-Gateway-IP-Address -> '0.0.0.0' (2) perl: $RAD_REQUEST{'DHCP-Client-Hardware-Address'} = &request:DHCP-Client-Hardware-Address -> '00:0c:29:06:ca:30' (2) perl: $RAD_REQUEST{'DHCP-Hostname'} = &request:DHCP-Hostname -> 'home-cc7ad47a41' (2) perl: $RAD_REQUEST{'DHCP-Vendor'} = &request:DHCP-Vendor -> '0xdc00' (2) perl: $RAD_REQUEST{'DHCP-Requested-IP-Address'} = &request:DHCP-Requested-IP-Address -> '169.254.133.106' (2) perl: $RAD_REQUEST{'DHCP-Message-Type'} = &request:DHCP-Message-Type -> 'DHCP-Discover' (2) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[0] = &request:DHCP-Parameter-Request-List -> 'DHCP-Subnet-Mask' (2) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[1] = &request:DHCP-Parameter-Request-List -> 'DHCP-Domain-Name' (2) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[2] = &request:DHCP-Parameter-Request-List -> 'DHCP-Router-Address' (2) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[3] = &request:DHCP-Parameter-Request-List -> 'DHCP-Domain-Name-Server' (2) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[4] = &request:DHCP-Parameter-Request-List -> 'DHCP-NETBIOS-Name-Servers' (2) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[5] = &request:DHCP-Parameter-Request-List -> 'DHCP-NETBIOS-Node-Type' (2) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[6] = &request:DHCP-Parameter-Request-List -> 'DHCP-NETBIOS' (2) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[7] = &request:DHCP-Parameter-Request-List -> 'DHCP-Perform-Router-Discovery' (2) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[8] = &request:DHCP-Parameter-Request-List -> 'DHCP-Static-Routes' (2) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[9] = &request:DHCP-Parameter-Request-List -> 'DHCP-Site-specific-25' (2) perl: $RAD_REQUEST{'DHCP-Parameter-Request-List'}[10] = &request:DHCP-Parameter-Request-List -> 'DHCP-Vendor' (2) perl: $RAD_REQUEST{'DHCP-Vendor-Class-Identifier'} = &request:DHCP-Vendor-Class-Identifier -> '0x4d53465420352e30' (2) perl: $RAD_REQUEST{'DHCP-Client-Identifier'} = &request:DHCP-Client-Identifier -> '0x01000c2906ca30' (2) perl: $RAD_REQUEST{'DHCP-Auto-Config'} = &request:DHCP-Auto-Config -> '1' (2) perl: $RAD_REPLY{'DHCP-Flags'} = &reply:DHCP-Flags -> '0' (2) perl: $RAD_REPLY{'DHCP-DHCP-Server-Identifier'} = &reply:DHCP-DHCP-Server-Identifier -> '10.200.0.1' rlm_perl: XXXRAD_REQUEST: DHCP-Your-IP-Address = 0.0.0.0 rlm_perl: XXXRAD_REQUEST: DHCP-Message-Type = DHCP-Discover rlm_perl: XXXRAD_REQUEST: DHCP-Vendor-Class-Identifier = 0x4d53465420352e30 rlm_perl: XXXRAD_REQUEST: DHCP-Hop-Count = 0 rlm_perl: XXXRAD_REQUEST: DHCP-Number-of-Seconds = 0 rlm_perl: XXXRAD_REQUEST: DHCP-Client-IP-Address = 0.0.0.0 rlm_perl: XXXRAD_REQUEST: DHCP-Gateway-IP-Address = 0.0.0.0 rlm_perl: XXXRAD_REQUEST: DHCP-Hardware-Type = Ethernet rlm_perl: XXXRAD_REQUEST: DHCP-Flags = 0 rlm_perl: XXXRAD_REQUEST: DHCP-Hardware-Address-Length = 6 rlm_perl: XXXRAD_REQUEST: DHCP-Hostname = home-cc7ad47a41 rlm_perl: XXXRAD_REQUEST: DHCP-Opcode = Client-Message rlm_perl: XXXRAD_REQUEST: DHCP-Transaction-Id = 90715973 rlm_perl: XXXRAD_REQUEST: DHCP-Parameter-Request-List = ARRAY(0x18beb58) rlm_perl: XXXRAD_REQUEST: DHCP-Client-Hardware-Address = 00:0c:29:06:ca:30 rlm_perl: XXXRAD_REQUEST: DHCP-Server-IP-Address = 0.0.0.0 rlm_perl: XXXRAD_REQUEST: DHCP-Requested-IP-Address = 169.254.133.106 rlm_perl: XXXRAD_REQUEST: DHCP-Auto-Config = 1 rlm_perl: XXXRAD_REQUEST: DHCP-Vendor = 0xdc00 rlm_perl: XXXRAD_REQUEST: DHCP-Client-Identifier = 0x01000c2906ca30 rlm_perl: XXXRAD_REPLY: DHCP-Your-IP-Address = 10.200.0.50 rlm_perl: XXXRAD_REPLY: DHCP-Domain-Name-Server = ARRAY(0x15b92c8) rlm_perl: XXXRAD_REPLY: DHCP-WWW-Server-Address = www.censored rlm_perl: XXXRAD_REPLY: DHCP-Time-Offset = 2 rlm_perl: XXXRAD_REPLY: DHCP-Relay-Circuit-Id = rlm_perl: XXXRAD_REPLY: DHCP-SMTP-Server-Address = smtp.censored rlm_perl: XXXRAD_REPLY: DHCP-POP3-Server-Address = mail.censored rlm_perl: XXXRAD_REPLY: DHCP-Relay-Remote-Id = rlm_perl: XXXRAD_REPLY: DHCP-Site-specific-25 = 0x100a010ac80001100a020ac80001100a0a0ac800010cac100ac800010cac200ac8000108ef0ac80032 rlm_perl: XXXRAD_REPLY: DHCP-Boot-Filename = hydra.bin rlm_perl: XXXRAD_REPLY: DHCP-IP-Address-Lease-Time = 300 rlm_perl: XXXRAD_REPLY: DHCP-Time-Server = time.censored rlm_perl: XXXRAD_REPLY: DHCP-DHCP-Server-Identifier = 10.200.0.1 rlm_perl: XXXRAD_REPLY: DHCP-Subnet-Mask = 255.255.255.0 rlm_perl: XXXRAD_REPLY: DHCP-NNTP-Server-Address = ntp.censored rlm_perl: XXXRAD_REPLY: DHCP-Router-Address = 10.200.0.1 rlm_perl: XXXRAD_REPLY: DHCP-Static-Routes = ARRAY(0x18723d0) rlm_perl: XXXRAD_REPLY: DHCP-IP-Forward-Enable = 0 rlm_perl: XXXRAD_REPLY: DHCP-Classless-Static-Route = 0x100a010ac80001100a020ac80001100a0a0ac800010cac100ac800010cac200ac8000108ef0ac80032 rlm_perl: XXXRAD_REPLY: DHCP-NTP-Servers = ntp.censored (2) perl: &request:DHCP-Your-IP-Address = $RAD_REQUEST{'DHCP-Your-IP-Address'} -> '0.0.0.0' (2) perl: &request:DHCP-Message-Type = $RAD_REQUEST{'DHCP-Message-Type'} -> 'DHCP-Discover' (2) perl: &request:DHCP-Vendor-Class-Identifier = $RAD_REQUEST{'DHCP-Vendor-Class-Identifier'} -> '0x4d53465420352e30' (2) perl: &request:DHCP-Hop-Count = $RAD_REQUEST{'DHCP-Hop-Count'} -> '0' (2) perl: &request:DHCP-Number-of-Seconds = $RAD_REQUEST{'DHCP-Number-of-Seconds'} -> '0' (2) perl: &request:DHCP-Client-IP-Address = $RAD_REQUEST{'DHCP-Client-IP-Address'} -> '0.0.0.0' (2) perl: &request:DHCP-Gateway-IP-Address = $RAD_REQUEST{'DHCP-Gateway-IP-Address'} -> '0.0.0.0' (2) perl: &request:DHCP-Hardware-Type = $RAD_REQUEST{'DHCP-Hardware-Type'} -> 'Ethernet' (2) perl: &request:DHCP-Flags = $RAD_REQUEST{'DHCP-Flags'} -> '0' (2) perl: &request:DHCP-Hardware-Address-Length = $RAD_REQUEST{'DHCP-Hardware-Address-Length'} -> '6' (2) perl: &request:DHCP-Hostname = $RAD_REQUEST{'DHCP-Hostname'} -> 'home-cc7ad47a41' (2) perl: &request:DHCP-Opcode = $RAD_REQUEST{'DHCP-Opcode'} -> 'Client-Message' (2) perl: &request:DHCP-Transaction-Id = $RAD_REQUEST{'DHCP-Transaction-Id'} -> '90715973' (2) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Subnet-Mask' (2) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Domain-Name' (2) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Router-Address' (2) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Domain-Name-Server' (2) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-NETBIOS-Name-Servers' (2) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-NETBIOS-Node-Type' (2) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-NETBIOS' (2) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Perform-Router-Discovery' (2) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Static-Routes' (2) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Site-specific-25' (2) perl: &request:DHCP-Parameter-Request-List += $RAD_REQUEST{'DHCP-Parameter-Request-List'} -> 'DHCP-Vendor' (2) perl: &request:DHCP-Client-Hardware-Address = $RAD_REQUEST{'DHCP-Client-Hardware-Address'} -> '00:0c:29:06:ca:30' (2) perl: &request:DHCP-Server-IP-Address = $RAD_REQUEST{'DHCP-Server-IP-Address'} -> '0.0.0.0' (2) perl: &request:DHCP-Requested-IP-Address = $RAD_REQUEST{'DHCP-Requested-IP-Address'} -> '169.254.133.106' (2) perl: &request:DHCP-Auto-Config = $RAD_REQUEST{'DHCP-Auto-Config'} -> '1' (2) perl: &request:DHCP-Vendor = $RAD_REQUEST{'DHCP-Vendor'} -> '0xdc00' (2) perl: &request:DHCP-Client-Identifier = $RAD_REQUEST{'DHCP-Client-Identifier'} -> '0x01000c2906ca30' (2) perl: &reply:DHCP-Your-IP-Address = $RAD_REPLY{'DHCP-Your-IP-Address'} -> '10.200.0.50' (2) perl: &reply:DHCP-Domain-Name-Server += $RAD_REPLY{'DHCP-Domain-Name-Server'} -> '10.1.1.253' (2) perl: &reply:DHCP-Domain-Name-Server += $RAD_REPLY{'DHCP-Domain-Name-Server'} -> '10.1.1.254' (2) perl: &reply:DHCP-WWW-Server-Address = $RAD_REPLY{'DHCP-WWW-Server-Address'} -> 'www.censored' (2) perl: &reply:DHCP-Time-Offset = $RAD_REPLY{'DHCP-Time-Offset'} -> '2' (2) perl: &reply:DHCP-SMTP-Server-Address = $RAD_REPLY{'DHCP-SMTP-Server-Address'} -> 'smtp.censored' (2) perl: &reply:DHCP-POP3-Server-Address = $RAD_REPLY{'DHCP-POP3-Server-Address'} -> 'mail.censored' (2) perl: &reply:DHCP-Site-specific-25 = $RAD_REPLY{'DHCP-Site-specific-25'} -> '0x100a010ac80001100a020ac80001100a0a0ac800010cac100ac800010cac200ac8000108ef0ac80032' (2) perl: &reply:DHCP-Boot-Filename = $RAD_REPLY{'DHCP-Boot-Filename'} -> 'hydra.bin' (2) perl: &reply:DHCP-IP-Address-Lease-Time = $RAD_REPLY{'DHCP-IP-Address-Lease-Time'} -> '300' (2) perl: &reply:DHCP-Time-Server = $RAD_REPLY{'DHCP-Time-Server'} -> 'time.censored' (2) perl: &reply:DHCP-DHCP-Server-Identifier = $RAD_REPLY{'DHCP-DHCP-Server-Identifier'} -> '10.200.0.1' (2) perl: &reply:DHCP-Subnet-Mask = $RAD_REPLY{'DHCP-Subnet-Mask'} -> '255.255.255.0' (2) perl: &reply:DHCP-NNTP-Server-Address = $RAD_REPLY{'DHCP-NNTP-Server-Address'} -> 'ntp.censored' (2) perl: &reply:DHCP-Router-Address = $RAD_REPLY{'DHCP-Router-Address'} -> '10.200.0.1' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.1.1.5' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.1.2.1' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.2.2.7' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.2.2.8' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.2.2.9' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.2.2.11' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.1.1.250' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.1.1.252' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.1.1.254' (2) perl: &reply:DHCP-Static-Routes += $RAD_REPLY{'DHCP-Static-Routes'} -> '10.200.0.1' (2) perl: &reply:DHCP-IP-Forward-Enable = $RAD_REPLY{'DHCP-IP-Forward-Enable'} -> '0' (2) perl: &reply:DHCP-Classless-Static-Route = $RAD_REPLY{'DHCP-Classless-Static-Route'} -> '0x100a010ac80001100a020ac80001100a0a0ac800010cac100ac800010cac200ac8000108ef0ac80032' (2) perl: &reply:DHCP-NTP-Servers = $RAD_REPLY{'DHCP-NTP-Servers'} -> 'ntp.censored' (2) [perl] = ok (2) linelog-dhcp-debug: EXPAND default (2) linelog-dhcp-debug: --> default (2) linelog-dhcp-debug: EXPAND /usr/local/var/log/radius-dhcp/linelog-dhcp-%{reply:DHCP-Your-IP-Address}.log (2) linelog-dhcp-debug: --> /usr/local/var/log/radius-dhcp/linelog-dhcp-.log (2) linelog-dhcp-debug: EXPAND foo (2) linelog-dhcp-debug: --> foo (2) [linelog-dhcp-debug] = ok (2) if (ok) { (2) if (ok) -> TRUE (2) if (ok) { (2) update reply { (2) &DHCP-Message-Type = DHCP-Offer (2) &DHCP-Server-IP-Address = 10.200.0.1 (2) } # update reply = noop (2) } # if (ok) = noop (2) ... skipping else for request 2: Preceding "if" was taken (2) linelog-dhcp: EXPAND %{%{reply:DHCP-Message-Type}:-%{request:DHCP-Message-Type}} (2) linelog-dhcp: --> DHCP-Offer (2) linelog-dhcp: EXPAND /usr/local/var/log/radius-dhcp/linelog-dhcp.log (2) linelog-dhcp: --> /usr/local/var/log/radius-dhcp/linelog-dhcp.log (2) linelog-dhcp: EXPAND %S <-- Transaction-ID: %{DHCP-Transaction-Id} OFFER: %{reply:DHCP-Your-IP-Address} to [%{DHCP-Client-Hardware-Address}] ... (2) linelog-dhcp: --> 2015-09-23 20:08:44 <-- Transaction-ID: 90715973 OFFER: to [00:0c:29:06:ca:30] ... (2) [linelog-dhcp] = ok (2) [ok] = ok (2) } # dhcp DHCP-Discover = ok (2) DHCP: Failed to find DHCP-Client-IP-Address or DHCP-Your-IP-Address for request; not responding (2) Not sending reply to client. (2) Finished request (2) Cleaning up request packet ID 90715973 with timestamp +6
I tried linelog and found that even when I insert it directly after the call to "perl", the attribute is empty. I am at a loss to figure out what is happening here. Any help would be appreciated.
I finally found out that the problem was caused by some attributes without values in the reply from rlm_perl
rlm_perl: XXXRAD_REPLY: DHCP-Relay-Circuit-Id =
rlm_perl: XXXRAD_REPLY: DHCP-Relay-Remote-Id =
Once I killed the source of these two attriibutes in the perl script, all other attibutes were returned fine.
On Sep 24, 2015, at 2:36 PM, Бен Томпсон <b.thompson@latera.ru> wrote:
I finally found out that the problem was caused by some attributes without values in the reply from rlm_perl
rlm_perl: XXXRAD_REPLY: DHCP-Relay-Circuit-Id =
rlm_perl: XXXRAD_REPLY: DHCP-Relay-Remote-Id =
Once I killed the source of these two attriibutes in the perl script, all other attibutes were returned fine.
Hmm... if you're running a recent version of the server, it will complain that it can't create attributes with empty values. Alan DeKok.
participants (2)
-
Alan DeKok -
Бен Томпсон