[RADIATOR] logging aborted EAP conversations

[David Zych]

On 8/26/15 12:36 PM, David Zych wrote:
> In theory it looks to me like it ought to be possible to add code to 
> Radius::Context::handle_timeout to examine the state of 
> $Radius::Context::contexts{$id} before it gets destroyed, decide if the 
> context state indicates an aborted conversation, and if so generate a 
> log message.
> 
> In practice, I'm not sure what fields within the context would be best 
> to examine.  It looks like checking for the absence of 
> 'handshake_finished' => 1 might be a good first pass to catch many 
> problem cases, but not necessarily all of them.
> 
> Any advice/ideas?

Below is what I've thrown together so far, and it seems to be doing some good, getting me log messages like:

EAP TTLS context expired before handshake finished: id=eap:D4-F4-6F-XX-XX-XX:xxxxx this_id=2 identity=xxxxx inner_identity=xxxxx first_session_time=1440618940

Limitations of my current hack:

* This only detects if the EAP conversation aborts before the TLS handshake is completed -- which anecdotally is most of what I'm seeing, but it would be nice to be able to detect _any_ case in which the EAP conversation does not complete, even if the problem occurs after the TLS handshake.

* I wish my log message could include additional fields from the last RADIUS request that we did receive.  In particular, Calling-Station-Id is conveniently embedded in the id key, but I'd like to also be able to log the Called-Station-Id and the NAS/Client IP (%c).

And of course it would be ideal if I could eventually do this with a Hook instead of custom modifications to the actual Radiator code.  :)

Thanks,
David


diff -ru radiator-20150716/radiator/lib/perl5/Radius/Context.pm radiator-20150826.dmrz1/radiator/lib/perl5/Radius/Context.pm
--- radiator-20150716/radiator/lib/perl5/Radius/Context.pm      2013-09-06 07:58:44.000000000 -0500
+++ radiator-20150826.dmrz1/radiator/lib/perl5/Radius/Context.pm        2015-08-26 13:39:34.000000000 -0500
@@ -81,6 +81,32 @@
 {
     my ($handle, $id) = @_;
 
+#dmrz
+    my $context = $Radius::Context::contexts{$id};
+    if ($context->{eap_type} == 21) {
+      # detect and log aborted TTLS handshakes
+      unless ($context->{handshake_finished}) {
+        my $msg = "EAP TTLS context expired before handshake finished:";
+        $msg .= " $_=".(defined $context->{$_} ? $context->{$_} : "")
+          foreach (qw(id this_id identity inner_identity first_session_time));
+        &main::log($main::LOG_WARNING, $msg);
+      }
+    } elsif ($context->{eap_type} == 25) {
+      # detect and log aborted PEAP handshakes
+      unless ($context->{handshake_finished}) {
+        my $msg = "EAP PEAP context expired before handshake finished:";
+        $msg .= " $_=".(defined $context->{$_} ? $context->{$_} : "")
+          foreach (qw(id this_id identity inner_identity first_session_time));
+        &main::log($main::LOG_WARNING, $msg);
+      }
+    }
+    ## DEV ONLY!
+    #use Data::Dumper;
+    #open (my $fh, '>>', "/scratch/dmrzhack.out");
+    #print $fh localtime."\n".Dumper($context)."\n";
+    #close $fh;
+#/dmrz
+
     destroy($id);
 }