Sorry, my previous email was not formatted correctly.

Everyone, I have a problem and would would be grateful if you could have a quick look at it for me. I am trying to use the Option 82 data from a DHCP request, but for some reason the Circuit ID is changing during the processing of the request.

Here is the reqest coming in and then getting processed by the linelog module:

Received DHCP-Request of id 721fc604 from 10.180.1.1:67 to 10.160.0.254:67
0: 01 01 06 01 72 1f c6 04 00 a5 00 00 0a b4 01 05
16: 00 00 00 00 00 00 00 00 0a b4 01 01 50 af 73 18
32: ed 98 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 03 0c 07 73 75 70 70 6f 72 74 37 0d 01 1c
256: 02 03 0f 06 77 0c 2c 2f 1a 79 2a 52 12 01 08 00
272: 06 04 b1 01 00 00 01 02 06 00 03 0f 1a e3 2c ff
288: 00 00 00 00 00 00 00 00 00 00 00 00
ššš DHCP-Opcode = Client-Message
ššš DHCP-Hardware-Type = Ethernet
ššš DHCP-Hardware-Address-Length = 6
ššš DHCP-Hop-Count = 1
ššš DHCP-Transaction-Id = 1914684932
ššš DHCP-Number-of-Seconds = 165
ššš DHCP-Flags = 0
ššš DHCP-Client-IP-Address = 10.180.1.5
ššš DHCP-Your-IP-Address = 0.0.0.0
ššš DHCP-Server-IP-Address = 0.0.0.0
ššš DHCP-Gateway-IP-Address = 10.180.1.1
ššš DHCP-Client-Hardware-Address = 50:af:73:18:ed:98
ššš DHCP-Message-Type += DHCP-Request
ššš DHCP-Hostname += 'support'
ššš DHCP-Parameter-Request-List += DHCP-Subnet-Mask
ššš DHCP-Parameter-Request-List += DHCP-Broadcast-Address
ššš DHCP-Parameter-Request-List += DHCP-Time-Offset
ššš DHCP-Parameter-Request-List += DHCP-Router-Address
ššš DHCP-Parameter-Request-List += DHCP-Domain-Name
ššš DHCP-Parameter-Request-List += DHCP-Domain-Name-Server
ššš DHCP-Parameter-Request-List += DHCP-Domain-Search
ššš DHCP-Parameter-Request-List += DHCP-Hostname
ššš DHCP-Parameter-Request-List += DHCP-NETBIOS-Name-Servers
ššš DHCP-Parameter-Request-List += DHCP-NETBIOS
ššš DHCP-Parameter-Request-List += DHCP-Interface-MTU-Size
ššš DHCP-Parameter-Request-List += DHCP-Classless-Static-Route
ššš DHCP-Parameter-Request-List += DHCP-NTP-Servers
ššš DHCP-Relay-Circuit-Id = 0x000604b101000001
Mon Feb 24 16:51:36 2014 : Debug: Trying sub-section dhcp DHCP-Request {...}
Mon Feb 24 16:51:36 2014 : Debug: (0)š dhcp DHCP-Request {
Mon Feb 24 16:51:36 2014 : Debug: (0)šš modsingle[post-auth]: calling linelog-dhcp (rlm_linelog) for request 0
Mon Feb 24 16:51:36 2014 : Debug: %{%{reply:DHCP-Message-Type}:-
%{request:DHCP-Message-Type}}
Mon Feb 24 16:51:36 2014 : Debug: Parsed xlat tree:
Mon Feb 24 16:51:36 2014 : Debug: if {
Mon Feb 24 16:51:36 2014 : Debug:šššš attribute: DHCP-Message-Type
Mon Feb 24 16:51:36 2014 : Debug:šššš {
Mon Feb 24 16:51:36 2014 : Debug:šššššššš refš 2
Mon Feb 24 16:51:36 2014 : Debug:šššššššš list 2
Mon Feb 24 16:51:36 2014 : Debug:šššššššš tag -128
Mon Feb 24 16:51:36 2014 : Debug:šššš }
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: else {
Mon Feb 24 16:51:36 2014 : Debug:šššš attribute: DHCP-Message-Type
Mon Feb 24 16:51:36 2014 : Debug:šššš {
Mon Feb 24 16:51:36 2014 : Debug:šššššššš refš 2
Mon Feb 24 16:51:36 2014 : Debug:šššššššš list 1
Mon Feb 24 16:51:36 2014 : Debug:šššššššš tag -128
Mon Feb 24 16:51:36 2014 : Debug:šššš }
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: (0) linelog-dhcp :šššš expand: "%{%{reply:DHCP-Message-Type}:-%{request:DHCP-Message-Type}}" -> 'DHCP-Request'
Mon Feb 24 16:51:36 2014 : Debug: /usr/local/var/log/radius/linelog-dhcp.log
Mon Feb 24 16:51:36 2014 : Debug: Parsed xlat tree:
Mon Feb 24 16:51:36 2014 : Debug: literal: '/usr/local/var/log/radius/linelog-dhcp.log'
Mon Feb 24 16:51:36 2014 : Debug: (0) linelog-dhcp :šššš expand: "/usr/local/var/log/radius/linelog-dhcp.log" -> '/usr/local/var/log/radius/linelog-dhcp.log'
Mon Feb 24 16:51:36 2014 : Debug: %S --> Transaction-ID: %{DHCP-Transaction-Id} REQUEST: [%{DHCP-Client-Hardware-Address}] via (%{DHCP-Gateway-IP-Address}), hop count = %{DHCP-Hop-Count}, Relay = %{DHCP-Relay-Remote-Id} / %{DHCP-Relay-Circuit-Id} ...
Mon Feb 24 16:51:36 2014 : Debug: Parsed xlat tree:
Mon Feb 24 16:51:36 2014 : Debug: literal (with %): 'S'
Mon Feb 24 16:51:36 2014 : Debug: literal: ' --> Transaction-ID: '
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Transaction-Id
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug:šššš refš 2
Mon Feb 24 16:51:36 2014 : Debug:šššš list 1
Mon Feb 24 16:51:36 2014 : Debug:šššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: ' REQUEST: ['
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Client-Hardware-Address
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug:šššš refš 2
Mon Feb 24 16:51:36 2014 : Debug:šššš list 1
Mon Feb 24 16:51:36 2014 : Debug:šššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: '] via ('
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Gateway-IP-Address
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug:šššš refš 2
Mon Feb 24 16:51:36 2014 : Debug:šššš list 1
Mon Feb 24 16:51:36 2014 : Debug:šššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: '), hop count = '
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Hop-Count
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug:šššš refš 2
Mon Feb 24 16:51:36 2014 : Debug:šššš list 1
Mon Feb 24 16:51:36 2014 : Debug:šššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: ', Relay = '
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Relay-Remote-Id
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug:šššš refš 2
Mon Feb 24 16:51:36 2014 : Debug:šššš list 1
Mon Feb 24 16:51:36 2014 : Debug:šššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: ' / '
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Relay-Circuit-Id
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug:šššš refš 2
Mon Feb 24 16:51:36 2014 : Debug:šššš list 1
Mon Feb 24 16:51:36 2014 : Debug:šššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: ' ...'
Mon Feb 24 16:51:36 2014 : Debug: (0) linelog-dhcp :šššš expand: "%S --> Transaction-ID: %{DHCP-Transaction-Id} REQUEST: [%{DHCP-Client-Hardware-Address}] via (%{DHCP-Gateway-IP-Address}), hop count = %{DHCP-Hop-Count}, Relay = %{DHCP-Relay-Remote-Id} / %{DHCP-Relay-Circuit-Id} ..." -> '2014-02-24 16:51:36 --> Transaction-ID: 1914684932 REQUEST: [50:af:73:18:ed:98] via (10.180.1.1), hop count = 1, Relay = 0x00030f1ae32c / 0x5d20766961202800 ...'
Mon Feb 24 16:51:36 2014 : Debug: (0)šš modsingle[post-auth]: returned from linelog-dhcp (rlm_linelog) for request 0
Mon Feb 24 16:51:36 2014 : Debug: (0)šš [linelog-dhcp] = ok

As you can see, the attribute DHCP-Relay-Circuit-Id starts of with value "0x000604b101000001" but by the time it is processed by linelog it has value "0x5d20766961202800"

Here is the full debug output: http://pastebin.com/b9RXPRD0



On 24 February 2014 21:28, โลฮ ๔ฯอะำฯฮ <b.thompson@latera.ru> wrote:
olks, I have hit a problem and would would be grateful if you could have a quick look at it for me. I am trying to use the Option 82 data from a DHCP request, but for some reason the Circuit ID is changing during the procession for the request.

Here is the reqest coming in and then getting processed by the linelog module:

Received DHCP-Request of id 721fc604 from 10.180.1.1:67 to 10.160.0.254:67
0: 01 01 06 01 72 1f c6 04 00 a5 00 00 0a b4 01 05
16: 00 00 00 00 00 00 00 00 0a b4 01 01 50 af 73 18
32: ed 98 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 03 0c 07 73 75 70 70 6f 72 74 37 0d 01 1c
256: 02 03 0f 06 77 0c 2c 2f 1a 79 2a 52 12 01 08 00
272: 06 04 b1 01 00 00 01 02 06 00 03 0f 1a e3 2c ff
288: 00 00 00 00 00 00 00 00 00 00 00 00
ššš DHCP-Opcode = Client-Message
ššš DHCP-Hardware-Type = Ethernet
ššš DHCP-Hardware-Address-Length = 6
ššš DHCP-Hop-Count = 1
ššš DHCP-Transaction-Id = 1914684932
ššš DHCP-Number-of-Seconds = 165
ššš DHCP-Flags = 0
ššš DHCP-Client-IP-Address = 10.180.1.5
ššš DHCP-Your-IP-Address = 0.0.0.0
ššš DHCP-Server-IP-Address = 0.0.0.0
ššš DHCP-Gateway-IP-Address = 10.180.1.1
ššš DHCP-Client-Hardware-Address = 50:af:73:18:ed:98
ššš DHCP-Message-Type += DHCP-Request
ššš DHCP-Hostname += 'support'
ššš DHCP-Parameter-Request-List += DHCP-Subnet-Mask
ššš DHCP-Parameter-Request-List += DHCP-Broadcast-Address
ššš DHCP-Parameter-Request-List += DHCP-Time-Offset
ššš DHCP-Parameter-Request-List += DHCP-Router-Address
ššš DHCP-Parameter-Request-List += DHCP-Domain-Name
ššš DHCP-Parameter-Request-List += DHCP-Domain-Name-Server
ššš DHCP-Parameter-Request-List += DHCP-Domain-Search
ššš DHCP-Parameter-Request-List += DHCP-Hostname
ššš DHCP-Parameter-Request-List += DHCP-NETBIOS-Name-Servers
ššš DHCP-Parameter-Request-List += DHCP-NETBIOS
ššš DHCP-Parameter-Request-List += DHCP-Interface-MTU-Size
ššš DHCP-Parameter-Request-List += DHCP-Classless-Static-Route
ššš DHCP-Parameter-Request-List += DHCP-NTP-Servers
ššš DHCP-Relay-Circuit-Id = 0x000604b101000001
Mon Feb 24 16:51:36 2014 : Debug: Trying sub-section dhcp DHCP-Request {...}
Mon Feb 24 16:51:36 2014 : Debug: (0)š dhcp DHCP-Request {
Mon Feb 24 16:51:36 2014 : Debug: (0)šš modsingle[post-auth]: calling linelog-dhcp (rlm_linelog) for request 0
Mon Feb 24 16:51:36 2014 : Debug: %{%{reply:DHCP-Message-Type}:-
%{request:DHCP-Message-Type}}
Mon Feb 24 16:51:36 2014 : Debug: Parsed xlat tree:
Mon Feb 24 16:51:36 2014 : Debug: if {
Mon Feb 24 16:51:36 2014 : Debug: ššš attribute: DHCP-Message-Type
Mon Feb 24 16:51:36 2014 : Debug: ššš {
Mon Feb 24 16:51:36 2014 : Debug: ššš ššš refš 2
Mon Feb 24 16:51:36 2014 : Debug: ššš ššš list 2
Mon Feb 24 16:51:36 2014 : Debug: ššš ššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: ššš }
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: else {
Mon Feb 24 16:51:36 2014 : Debug: ššš attribute: DHCP-Message-Type
Mon Feb 24 16:51:36 2014 : Debug: ššš {
Mon Feb 24 16:51:36 2014 : Debug: ššš ššš refš 2
Mon Feb 24 16:51:36 2014 : Debug: ššš ššš list 1
Mon Feb 24 16:51:36 2014 : Debug: ššš ššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: ššš }
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: (0) linelog-dhcp : ššš expand: "%{%{reply:DHCP-Message-Type}:-%{request:DHCP-Message-Type}}" -> 'DHCP-Request'
Mon Feb 24 16:51:36 2014 : Debug: /usr/local/var/log/radius/linelog-dhcp.log
Mon Feb 24 16:51:36 2014 : Debug: Parsed xlat tree:
Mon Feb 24 16:51:36 2014 : Debug: literal: '/usr/local/var/log/radius/linelog-dhcp.log'
Mon Feb 24 16:51:36 2014 : Debug: (0) linelog-dhcp : ššš expand: "/usr/local/var/log/radius/linelog-dhcp.log" -> '/usr/local/var/log/radius/linelog-dhcp.log'
Mon Feb 24 16:51:36 2014 : Debug: %S --> Transaction-ID: %{DHCP-Transaction-Id} REQUEST: [%{DHCP-Client-Hardware-Address}] via (%{DHCP-Gateway-IP-Address}), hop count = %{DHCP-Hop-Count}, Relay = %{DHCP-Relay-Remote-Id} / %{DHCP-Relay-Circuit-Id} ...
Mon Feb 24 16:51:36 2014 : Debug: Parsed xlat tree:
Mon Feb 24 16:51:36 2014 : Debug: literal (with %): 'S'
Mon Feb 24 16:51:36 2014 : Debug: literal: ' --> Transaction-ID: '
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Transaction-Id
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug: ššš refš 2
Mon Feb 24 16:51:36 2014 : Debug: ššš list 1
Mon Feb 24 16:51:36 2014 : Debug: ššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: ' REQUEST: ['
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Client-Hardware-Address
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug: ššš refš 2
Mon Feb 24 16:51:36 2014 : Debug: ššš list 1
Mon Feb 24 16:51:36 2014 : Debug: ššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: '] via ('
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Gateway-IP-Address
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug: ššš refš 2
Mon Feb 24 16:51:36 2014 : Debug: ššš list 1
Mon Feb 24 16:51:36 2014 : Debug: ššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: '), hop count = '
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Hop-Count
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug: ššš refš 2
Mon Feb 24 16:51:36 2014 : Debug: ššš list 1
Mon Feb 24 16:51:36 2014 : Debug: ššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: ', Relay = '
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Relay-Remote-Id
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug: ššš refš 2
Mon Feb 24 16:51:36 2014 : Debug: ššš list 1
Mon Feb 24 16:51:36 2014 : Debug: ššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: ' / '
Mon Feb 24 16:51:36 2014 : Debug: attribute: DHCP-Relay-Circuit-Id
Mon Feb 24 16:51:36 2014 : Debug: {
Mon Feb 24 16:51:36 2014 : Debug: ššš refš 2
Mon Feb 24 16:51:36 2014 : Debug: ššš list 1
Mon Feb 24 16:51:36 2014 : Debug: ššš tag -128
Mon Feb 24 16:51:36 2014 : Debug: }
Mon Feb 24 16:51:36 2014 : Debug: literal: ' ...'
Mon Feb 24 16:51:36 2014 : Debug: (0) linelog-dhcp : ššš expand: "%S --> Transaction-ID: %{DHCP-Transaction-Id} REQUEST: [%{DHCP-Client-Hardware-Address}] via (%{DHCP-Gateway-IP-Address}), hop count = %{DHCP-Hop-Count}, Relay = %{DHCP-Relay-Remote-Id} / %{DHCP-Relay-Circuit-Id} ..." -> '2014-02-24 16:51:36 --> Transaction-ID: 1914684932 REQUEST: [50:af:73:18:ed:98] via (10.180.1.1), hop count = 1, Relay = 0x00030f1ae32c / 0x5d20766961202800 ...'
Mon Feb 24 16:51:36 2014 : Debug: (0)šš modsingle[post-auth]: returned from linelog-dhcp (rlm_linelog) for request 0
Mon Feb 24 16:51:36 2014 : Debug: (0)šš [linelog-dhcp] = ok

As you can see, the attribute DHCP-Relay-Circuit-Id starts of with value "0x000604b101000001" but by the time it is processed by linelog it has value "0x5d20766961202800"

Here is the full debug output: http://pastebin.com/b9RXPRD0


On 21 February 2014 19:02, โลฮ ๔ฯอะำฯฮ <b.thompson@latera.ru> wrote:
Thanks for the info. It is looking better with 3.0.1. I will share my oracle configs once I have proved that they work.


On 21 February 2014 16:41, Alan DeKok <aland@deployingradius.com> wrote:
โลฮ ๔ฯอะำฯฮ wrote:
> radiusd: FreeRADIUS Version 3.1.0 (git #10ffd5b), for host

š Don't use the "master" branch. šUse an official release.

š Alan DeKok.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html



--
โลฮ ๔ฯอะำฯฮ,
ษฮึลฮลา ฯิฤลฬม ืฮลฤาลฮษั ษ ิลศะฯฤฤลาึหษ,
หฯอะมฮษั "์มิลาม" | www.latera.ru
š
ิลฬ.: +7 (499) 940-95-05, ฤฯย. 221



--
โลฮ ๔ฯอะำฯฮ,
ษฮึลฮลา ฯิฤลฬม ืฮลฤาลฮษั ษ ิลศะฯฤฤลาึหษ,
หฯอะมฮษั "์มิลาม" | www.latera.ru
š
ิลฬ.: +7 (499) 940-95-05, ฤฯย. 221



--
โลฮ ๔ฯอะำฯฮ,
ษฮึลฮลา ฯิฤลฬม ืฮลฤาลฮษั ษ ิลศะฯฤฤลาึหษ,
หฯอะมฮษั "์มิลาม" | www.latera.ru
š
ิลฬ.: +7 (499) 940-95-05, ฤฯย. 221
E-mail: b.thompson@latera.ru