PERL and EAL-TLS Modul -> Failed to create pair &request:EAP-Message = $RAD_REQUEST{'EAP-Message'}
Hello all, i'm using source complied version 3.0.12 on an SUSE SLES 12 SP1 x64. EAP-TLS is working fine without PERL. Now I would like to add PERL to do some stuff too. But with enabled perl module it results in error and REJECT. This is my default server server default { listen { type = auth ipaddr = * port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { ipaddr = * port = 0 type = acct limit { } } authorize { filter_username preprocess auth_log GoPerl EAP } authenticate { EAP } accounting { detail } } This is a snip of the perl script the authorize part. It default return "OK" for testing. I have added RAD_REPLY values for testing too. sub authorize { # # For debugging purposes only # &log_request_attributes; # # # Here's where your authorization code comes # # You can call another function from here: # &test_call; $RAD_REPLY{"Tunnel-Private-Group-id"} = "2"; $RAD_REPLY{"Tunnel-Type"} = "VLAN"; $RAD_REPLY{"Tunnel-Medium-Type"} = "IEEE-802"; return RLM_MODULE_OK; } In that constellation I've got the error " ERROR: (5) GoPerl: Failed to create pair &request:EAP-Message = $RAD_REQUEST{'EAP-Message'} ->" and "There was no response configured: rejecting request ... Using Post-Auth-Type Reject" I have found this https://github.com/FreeRADIUS/freeradius-server/issues/1697, I have changed as "dhpark21" described but then I have many errors at perl modul RAD_REQUEST and RAD_REPLY -> undef then perl modul will not be executed but working with EAP-TLS. Hope someone could help. That is a snip of the debug: --------------------------------------- Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'User-Name'} = &request:User-Name -> 'host/~~~~~~~~~' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'NAS-IP-Address'} = &request:NAS-IP-Address -> ~~~~~~~~~ Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'NAS-Port'} = &request:NAS-Port -> '60000' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'Service-Type'} = &request:Service-Type -> 'Framed-User' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'Framed-MTU'} = &request:Framed-MTU -> '9216' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'State'} = &request:State -> '0x217dacef257ba1999dff0cf1ce39de5f' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'Called-Station-Id'} = &request:Called-Station-Id -> ~~~~~~~~~ Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'Calling-Station-Id'} = &request:Calling-Station-Id -> ~~~~~~~~~ Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'Proxy-State'} = &request:Proxy-State -> '0x8b16a47700000efc' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'NAS-Port-Type'} = &request:NAS-Port-Type -> 'Ethernet' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'Event-Timestamp'} = &request:Event-Timestamp -> 'Nov 4 2016 09:09:42 CET' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'EAP-Message'} = &request:EAP-Message -> '0x020605d40dc00000073016030106f00b0005a000059d00059a30820596308204ffa0030201020213160000d0096957d9bd45cc808400060000d009300d06092a864886f70d01010b0500308198311e301c06092a864886f70d010901160f6564764065766f736f66742e636f6d310b30090603550406130244453110300e060355040813074261766172696131123010060355040713094e7572656d6265726731153013060355040a130c45766f736f667420476d624831153013060355040b130c45766f736f667420476d6248311530130603550403130c45766f736f667420476d6248301e170d3136303831353134303134305a170d3138303831353134303134305a301f311d301b0603550403131445564f30323130302e65766f736f66742e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100afc52515cdb53d2173c492869d2fdf296c2afde310c301240746d2140f93482d2a08c4cda93eed450533635c932804c1776fd15f69ac8942a15a529b4689adf2a0f9db8613f250e91601a964e7611e0815e10d225df9e22ca0119c58f9dede6cc8775ef0f5add475325cd3ad87a93065a1948f9a53d01f10e66ec141fc83a32b571b5ad910a98a016044c39c8832e40fcf6d88cbb5b11a4173877464016d1fc786c28c5d2a04a215e8eecaa6b62241d88bf6d0ca789def' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'Message-Authenticator'} = &request:Message-Authenticator -> '0x2bebafeecaeb11596c759f7208148ddf' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'NAS-Port-Id'} = &request:NAS-Port-Id -> ~~~~~~~~~ Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'Cisco-AVPair'}[0] = &request:Cisco-AVPair -> 'service-type=Framed' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'Cisco-AVPair'}[1] = &request:Cisco-AVPair -> 'audit-session-id=0A016E020002255B4748D1E8' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: $RAD_REQUEST{'Cisco-AVPair'}[2] = &request:Cisco-AVPair -> 'method=dot1x' SOFT ASSERT FAILED src/modules/rlm_perl/rlm_perl.c[703]: *vps Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:Message-Authenticator = $RAD_REQUEST{'Message-Authenticator'} -> '0x2bebafeecaeb11596c759f7208148ddf' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:NAS-Port-Type = $RAD_REQUEST{'NAS-Port-Type'} -> 'Ethernet' Fri Nov 4 09:09:42 2016 : ERROR: (5) GoPerl: Failed to create pair &request:EAP-Message = $RAD_REQUEST{'EAP-Message'} -> '0x020605d40dc00000073016030106f00b0005a000059d00059a30820596308204ffa0030201020213160000d0096957d9bd45cc808400060000d009300d06092a864886f70d01010b0500308198311e301c06092a864886f70d010901160f6564764065766f736f66742e636f6d310b30090603550406130244453110300e060355040813074261766172696131123010060355040713094e7572656d6265726731153013060355040a130c45766f736f667420476d624831153013060355040b130c45766f736f667420476d6248311530130603550403130c45766f736f667420476d6248301e170d3136303831353134303134305a170d3138303831353134303134305a301f311d301b0603550403131445564f30323130302e65766f736f66742e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100afc52515cdb53d2173c492869d2fdf296c2afde310c301240746d2140f93482d2a08c4cda93eed450533635c932804c1776fd15f69ac8942a15a529b4689adf2a0f9db8613f250e91601a964e7611e0815e10d225df9e22ca0119c58f9dede6cc8775ef0f5add475325cd3ad87a93065a1948f9a53d01f10e66ec141fc83a32b571b5ad910a98a016044c39c8832e40fcf6d88cbb5b11a4173877464016d1fc786c28c5d2a04a215e8eecaa6b62241d88bf6d0ca789def' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:Calling-Station-Id = $RAD_REQUEST{'Calling-Station-Id'} -> ~~~~~~~~~ Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:Proxy-State = $RAD_REQUEST{'Proxy-State'} -> '0x8b16a47700000efc' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:Event-Timestamp = $RAD_REQUEST{'Event-Timestamp'} -> 'Nov 4 2016 09:09:42 CET' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:Framed-MTU = $RAD_REQUEST{'Framed-MTU'} -> '9216' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:NAS-IP-Address = $RAD_REQUEST{'NAS-IP-Address'} -> ~~~~~~~~~ Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:Cisco-AVPair += $RAD_REQUEST{'Cisco-AVPair'} -> 'service-type=Framed' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:Cisco-AVPair += $RAD_REQUEST{'Cisco-AVPair'} -> 'audit-session-id=0A016E020002255B4748D1E8' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:Cisco-AVPair += $RAD_REQUEST{'Cisco-AVPair'} -> 'method=dot1x' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:User-Name = $RAD_REQUEST{'User-Name'} -> ~~~~~~~~~ Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:State = $RAD_REQUEST{'State'} -> '0x217dacef257ba1999dff0cf1ce39de5f' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:Called-Station-Id = $RAD_REQUEST{'Called-Station-Id'} -> ~~~~~~~~~ Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:NAS-Port-Id = $RAD_REQUEST{'NAS-Port-Id'} -> ~~~~~~~~~ Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:NAS-Port = $RAD_REQUEST{'NAS-Port'} -> '60000' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &request:Service-Type = $RAD_REQUEST{'Service-Type'} -> 'Framed-User' SOFT ASSERT FAILED src/modules/rlm_perl/rlm_perl.c[703]: *vps Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &reply:Tunnel-Type = $RAD_REPLY{'Tunnel-Type'} -> 'VLAN' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &reply:Tunnel-Private-Group-id = $RAD_REPLY{'Tunnel-Private-Group-id'} -> '2' Fri Nov 4 09:09:42 2016 : Debug: (5) GoPerl: &reply:Tunnel-Medium-Type = $RAD_REPLY{'Tunnel-Medium-Type'} -> 'IEEE-802' Fri Nov 4 09:09:42 2016 : Debug: (5) modsingle[authorize]: returned from GoPerl (rlm_perl) Fri Nov 4 09:09:42 2016 : Debug: (5) [GoPerl] = ok Fri Nov 4 09:09:42 2016 : Debug: (5) modsingle[authorize]: calling EAP (rlm_eap) Fri Nov 4 09:09:42 2016 : Debug: (5) EAP: Got EAP_START message Fri Nov 4 09:09:42 2016 : Debug: (5) modsingle[authorize]: returned from EAP (rlm_eap) Fri Nov 4 09:09:42 2016 : Debug: (5) [EAP] = handled Fri Nov 4 09:09:42 2016 : Debug: (5) } # authorize = handled Fri Nov 4 09:09:42 2016 : Debug: (5) There was no response configured: rejecting request Fri Nov 4 09:09:42 2016 : Debug: (5) Using Post-Auth-Type Reject Fri Nov 4 09:09:42 2016 : Debug: (5) Post-Auth-Type sub-section not found. Ignoring. Fri Nov 4 09:09:42 2016 : Debug: (5) Delaying response for 1.000000 seconds Fri Nov 4 09:09:42 2016 : Debug: Waking up in 0.3 seconds. Fri Nov 4 09:09:43 2016 : Debug: Waking up in 0.6 seconds. Fri Nov 4 09:09:43 2016 : Debug: (5) Sending delayed response Fri Nov 4 09:09:43 2016 : Debug: (5) Sent Access-Reject Id 113 from ~~~~~~~~~to ~~~~~~~~~length 52 Fri Nov 4 09:09:43 2016 : Debug: (5) Tunnel-Type = VLAN Fri Nov 4 09:09:43 2016 : Debug: (5) Tunnel-Private-Group-Id = "2" Fri Nov 4 09:09:43 2016 : Debug: (5) Tunnel-Medium-Type = IEEE-802 Fri Nov 4 09:09:43 2016 : Debug: (5) EAP-Message = 0x0100000501 Fri Nov 4 09:09:43 2016 : Debug: (5) Proxy-State = 0x8b16a47700000efc Fri Nov 4 09:09:43 2016 : Debug: Waking up in 3.9 seconds. Fri Nov 4 09:09:47 2016 : Debug: (0) Cleaning up request packet ID 108 with timestamp +21 Fri Nov 4 09:09:47 2016 : Debug: (1) Cleaning up request packet ID 109 with timestamp +21 Fri Nov 4 09:09:47 2016 : Debug: (2) Cleaning up request packet ID 110 with timestamp +21 Fri Nov 4 09:09:47 2016 : Debug: (3) Cleaning up request packet ID 111 with timestamp +21 Fri Nov 4 09:09:47 2016 : Debug: (4) Cleaning up request packet ID 112 with timestamp +21 Fri Nov 4 09:09:47 2016 : Debug: (5) Cleaning up request packet ID 113 with timestamp +21 Fri Nov 4 09:09:47 2016 : Info: Ready to process requests Fri Nov 4 09:09:47 2016 : Debug: (6) Received Access-Request Id 114 from ~~~~~~~~~to ~~~~~~~~~length 300 Fri Nov 4 09:09:47 2016 : Debug: (6) User-Name = "host/EVO02100.evosoft.com" Fri Nov 4 09:09:47 2016 : Debug: (6) Service-Type = Framed-User Fri Nov 4 09:09:47 2016 : Debug: (6) Framed-MTU = 9216 Fri Nov 4 09:09:47 2016 : Debug: (6) Called-Station-Id = "~~~~~~~~~" Fri Nov 4 09:09:47 2016 : Debug: (6) Calling-Station-Id = "~~~~~~~~~" Fri Nov 4 09:09:47 2016 : Debug: (6) EAP-Message = 0x0201001e01686f73742f45564f30323130302e65766f736f66742e636f6d Fri Nov 4 09:09:47 2016 : Debug: (6) Message-Authenticator = 0xe22b7d268bf88355559f7445f864ad63 Fri Nov 4 09:09:47 2016 : Debug: (6) NAS-IP-Address = ~~~~~~~~~ Fri Nov 4 09:09:47 2016 : Debug: (6) NAS-Port = 60000 Fri Nov 4 09:09:47 2016 : Debug: (6) NAS-Port-Id = "~~~~~~~~~" Fri Nov 4 09:09:47 2016 : Debug: (6) NAS-Port-Type = Ethernet Fri Nov 4 09:09:47 2016 : Debug: (6) Cisco-AVPair = "service-type=Framed" Fri Nov 4 09:09:47 2016 : Debug: (6) Cisco-AVPair = "audit-session-id=0A016E020002255B4748D1E8" Fri Nov 4 09:09:47 2016 : Debug: (6) Cisco-AVPair = "method=dot1x" Fri Nov 4 09:09:47 2016 : Debug: (6) Proxy-State = 0x8b16a47700000efd Fri Nov 4 09:09:47 2016 : Debug: (6) session-state: No State attribute Best Regards, Paul
On Nov 4, 2016, at 4:36 AM, Poltorak, Paul (CT DD DS EVO O BFD TM&ISEC 1) <Paul.Poltorak@evosoft.com> wrote: i'm using source complied version 3.0.12 on an SUSE SLES 12 SP1 x64. EAP-TLS is working fine without PERL. Now I would like to add PERL to do some stuff too. But with enabled perl module it results in error and REJECT.
Please try the v3.0.x branch from github: https://github.com/FreeRADIUS/freeradius-server/archive/v3.0.x.zip I've pushed changes which will produce a more meaningful error message. That will help narrow down why this is happening. Alan DeKok.
Please try the v3.0.x branch from github:
https://github.com/FreeRADIUS/freeradius-server/archive/v3.0.x.zip
I've pushed changes which will produce a more meaningful error message. That will help narrow down why this is happening.
Hello Alan, Installed v3.0.x with enabled developer debug (maybe it helps too) because I did not see any more logging with that version. I hope attaching of files is working, attached the radius -XXX output. BR Paul
On Nov 4, 2016, at 9:29 AM, Poltorak, Paul (CT DD DS EVO O BFD TM&ISEC 1) <Paul.Poltorak@evosoft.com> wrote:
Installed v3.0.x with enabled developer debug (maybe it helps too) because I did not see any more logging with that version. I hope attaching of files is working, attached the radius -XXX output.
It's still using the rlm_perl from 3.0.12. Not the new one. Please delete the old rlm_perl, and be sure that the server is using *only* the new modules. Alan DeKok.
Attached the new debug with the new rlm_perl
On 04-11-16 16:09, Poltorak, Paul (CT DD DS EVO O BFD TM&ISEC 1) wrote:
Attached the new debug with the new rlm_perl
In packet 5, the input EAP-Message is 240 bytes, but the string in Perl is way longer. I would guess it's a missing null terminator -- Herwin Weststrate
On Nov 4, 2016, at 11:18 AM, Herwin Weststrate <herwin@quarantainenet.nl> wrote:
On 04-11-16 16:09, Poltorak, Paul (CT DD DS EVO O BFD TM&ISEC 1) wrote:
Attached the new debug with the new rlm_perl
In packet 5, the input EAP-Message is 240 bytes, but the string in Perl is way longer. I would guess it's a missing null terminator
That's it. I've pushed a fix. Alan DeKok.
That's it. I've pushed a fix. I've tried new version but same error.
To be sure that i use the github version with the fix, i have deleted everything from "/usr/local/bin", "/usr/local/sbin" and "/usr/local/lib" downloaded from githup recompiled and tried again. Still the same error at packet five. Mon Nov 7 09:29:00 2016 : ERROR: (5) GoPerl: Failed to create pair - Length of Hex String is not even, got 1021 bytes Mon Nov 7 09:29:00 2016 : ERROR: (5) GoPerl: &request:EAP-Message = $RAD_REQUEST{'EAP-Message'} -> What could it be?
participants (3)
-
Alan DeKok -
Herwin Weststrate -
Poltorak, Paul (CT DD DS EVO O BFD TM&ISEC 1)