Re: LDAP + OTP

7 Jun 2024

      On Fri, 2024-06-07 at 08:11 -0400, Alan DeKok wrote:
...
On Jun 6, 2024, at 9:31 PM, Jon Gerdes <gerdesj@blueloop.net> wrote:
...
I am trying to get a MFA setup working with an initial LDAP direct bind against Microsoft AD (MAD) and then a second
pass with the same username and a OTP.  I can get both the LDAP and OTP working fine individually.
  That's good.
...
I am using the wiki Howto: https://wiki.freeradius.org/guide/2FA-Active-Directory-plus-Proxy as a model.  This howto
uses "State" to determine which Auth-Type it is at in the process.  At the end of the howto there is a section that
describes filtering out the State attribute for Pre-Proxy and I think this is where I am getting things wrong.
  If you're not proxying, then you don't need to do anything in the pre-proxy section.
...
I'm not sure what "State" is.  I am unable to find docs about it but it is the only input difference I can see when
running "freeradius -fX" so I think I need to filter it out.  I'm not sure why I should filter it out either!
  The State attribute is defined in RFC 2865.  It's just a magic cookie which the server uses to track a multi-packet authentication session.
  i.e. if step one is "get password", and step two is "get OTP", then the server uses State in the reply to step (1) in order to know that it's at step (2).
...
If attr_filter is what I should do to get this to work, I'd be grateful for some help.  I've also deviated from the
howto example by trying to decompose "challenge" into what it actually does:
update control {
   Response-Packet-Type := Access-Challenge
{
  That should be OK.
...
With the site-enabled config below, the debug logs show that the initial user/pass against LDAP works fine and State
gets set to a 16 random char.  Then it tries to do a second pass and I can see the username and password (which is now
the PIN for the OTP) passed through and so is the "State" that got set by stage one.  This second pass fails
  What does that mean?  "fails" is so generic as to be useless for debugging.
...
and when I
compare the logs against just the OTP method that works, "State" is the only additional input.
  Don't compare the logs.  *Understand* them.
...
server active-directory {
  http://wiki.freeradius.org/list-help
  Which says (a) post the debug output, and (b) don't post configs.  Please read the documentation and follow it.
  We ask for the debug logs because they tell us what the server is actually doing.  The configuration tells us what you told the server to do.  But the
configuration files do *not* include packets received by the server.  So they're missing a critical piece which is required to debug the problem.
  Alan DeKok.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Alan

Thank you for your response.  Here is the full debug output.  I've only obfuscated my AD password, everything else is a copy/paste from my terminal.  The PIN
that I entered is the correct one.  PrivacyIdea returns wrong otp pin but I think that is because I am passing through "State" to it.  I'll see if I can get a
log at the PI end to see what it receives as a PIN.

If I remove the LDAP related stuff and do just the Auth-Type perl part, it works fine.  ie I enter my username and the PIN as the password and the push token
works and I am granted access.  Also, if I remove the PI related parts and just do the LDAP, that works too.

Cheers
Jon

# freeradius -fX
FreeRADIUS Version 3.0.26
Copyright (C) 1999-2021 The FreeRADIUS server project and contributors
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License
For more information about these matters, see the file named COPYRIGHT
Starting - reading configuration files ...
including dictionary file /usr/share/freeradius/dictionary
including dictionary file /usr/share/freeradius/dictionary.dhcp
including dictionary file /usr/share/freeradius/dictionary.vqp
including dictionary file /etc/freeradius/3.0/dictionary
including configuration file /etc/freeradius/3.0/radiusd.conf
including configuration file /etc/freeradius/3.0/proxy.conf
including configuration file /etc/freeradius/3.0/clients.conf
including files in directory /etc/freeradius/3.0/mods-enabled/
including configuration file /etc/freeradius/3.0/mods-enabled/utf8
including configuration file /etc/freeradius/3.0/mods-enabled/realm
including configuration file /etc/freeradius/3.0/mods-enabled/unix
including configuration file /etc/freeradius/3.0/mods-enabled/radutmp
including configuration file /etc/freeradius/3.0/mods-enabled/echo
including configuration file /etc/freeradius/3.0/mods-enabled/sradutmp
including configuration file /etc/freeradius/3.0/mods-enabled/linelog
including configuration file /etc/freeradius/3.0/mods-enabled/preprocess
including configuration file /etc/freeradius/3.0/mods-enabled/expr
including configuration file /etc/freeradius/3.0/mods-enabled/ntlm_auth
including configuration file /etc/freeradius/3.0/mods-enabled/unpack
including configuration file /etc/freeradius/3.0/mods-enabled/chap
including configuration file /etc/freeradius/3.0/mods-enabled/expiration
including configuration file /etc/freeradius/3.0/mods-enabled/detail
including configuration file /etc/freeradius/3.0/mods-enabled/cache_eap
including configuration file /etc/freeradius/3.0/mods-enabled/mods-perl-privacyidea
including configuration file /etc/freeradius/3.0/mods-enabled/detail.log
including configuration file /etc/freeradius/3.0/mods-enabled/dynamic_clients
including configuration file /etc/freeradius/3.0/mods-enabled/files
including configuration file /etc/freeradius/3.0/mods-enabled/passwd
including configuration file /etc/freeradius/3.0/mods-enabled/exec
including configuration file /etc/freeradius/3.0/mods-enabled/attr_filter
including configuration file /etc/freeradius/3.0/mods-enabled/logintime
including configuration file /etc/freeradius/3.0/mods-enabled/soh
including configuration file /etc/freeradius/3.0/mods-enabled/ldap
including configuration file /etc/freeradius/3.0/mods-enabled/replicate
including configuration file /etc/freeradius/3.0/mods-enabled/mschap
including configuration file /etc/freeradius/3.0/mods-enabled/digest
including configuration file /etc/freeradius/3.0/mods-enabled/always
including files in directory /etc/freeradius/3.0/policy.d/
including configuration file /etc/freeradius/3.0/policy.d/operator-name
including configuration file /etc/freeradius/3.0/policy.d/moonshot-targeted-ids
including configuration file /etc/freeradius/3.0/policy.d/rfc7542
including configuration file /etc/freeradius/3.0/policy.d/cui
including configuration file /etc/freeradius/3.0/policy.d/control
including configuration file /etc/freeradius/3.0/policy.d/abfab-tr
including configuration file /etc/freeradius/3.0/policy.d/eap
including configuration file /etc/freeradius/3.0/policy.d/debug
including configuration file /etc/freeradius/3.0/policy.d/filter
including configuration file /etc/freeradius/3.0/policy.d/canonicalization
including configuration file /etc/freeradius/3.0/policy.d/accounting
including configuration file /etc/freeradius/3.0/policy.d/dhcp
including files in directory /etc/freeradius/3.0/sites-enabled/
including configuration file /etc/freeradius/3.0/sites-enabled/radius-accounting
including configuration file /etc/freeradius/3.0/sites-enabled/ldap
main {
 security {
        user = "freerad"
        group = "freerad"
        allow_core_dumps = no
 }
        name = "freeradius"
        prefix = "/usr"
        localstatedir = "/var"
        logdir = "/var/log/freeradius"
        run_dir = "/var/run/freeradius"
}
main {
        name = "freeradius"
        prefix = "/usr"
        localstatedir = "/var"
        sbindir = "/usr/sbin"
        logdir = "/var/log/freeradius"
        run_dir = "/var/run/freeradius"
        libdir = "/usr/lib/freeradius"
        radacctdir = "/var/log/freeradius/radacct"
        hostname_lookups = no
        max_request_time = 30
        cleanup_delay = 5
        max_requests = 16384
        postauth_client_lost = no
        pidfile = "/var/run/freeradius/freeradius.pid"
        checkrad = "/usr/sbin/checkrad"
        debug_level = 0
        proxy_requests = yes
 log {
        stripped_names = no
        auth = yes
        auth_badpass = no
        auth_goodpass = no
        colourise = yes
        msg_denied = "You are already logged in - access denied"
 }
 resources {
 }
 security {
        max_attributes = 200
        reject_delay = 1.000000
        status_server = yes
 }
}
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
        retry_delay = 5
        retry_count = 3
        default_fallback = no
        dead_time = 120
        wake_all_if_all_dead = no
 }
 realm blueloop.net {
 }
radiusd: #### Loading Clients ####
Debugger not attached
systemd watchdog is disabled
 # Creating Auth-Type = AD
 # Creating Auth-Type = Perl
radiusd: #### Instantiating modules ####
 modules {
  # Loaded module rlm_utf8
  # Loading module "utf8" from file /etc/freeradius/3.0/mods-enabled/utf8
  # Loaded module rlm_realm
  # Loading module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm
  realm IPASS {
        format = "prefix"
        delimiter = "/"
        ignore_default = no
        ignore_null = no
  }
  # Loading module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm
  realm suffix {
        format = "suffix"
        delimiter = "@"
        ignore_default = no
        ignore_null = no
  }
  # Loading module "bangpath" from file /etc/freeradius/3.0/mods-enabled/realm
  realm bangpath {
        format = "prefix"
        delimiter = "!"
        ignore_default = no
        ignore_null = no
  }
  # Loading module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm
  realm realmpercent {
        format = "suffix"
        delimiter = "%"
        ignore_default = no
        ignore_null = no
  }
  # Loading module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm
  realm ntdomain {
        format = "prefix"
        delimiter = "\\"
        ignore_default = no
        ignore_null = no
  }
  # Loaded module rlm_unix
  # Loading module "unix" from file /etc/freeradius/3.0/mods-enabled/unix
  unix {
        radwtmp = "/var/log/freeradius/radwtmp"
  }
Creating attribute Unix-Group
  # Loaded module rlm_radutmp
  # Loading module "radutmp" from file /etc/freeradius/3.0/mods-enabled/radutmp
  radutmp {
        filename = "/var/log/freeradius/radutmp"
        username = "%{User-Name}"
        case_sensitive = yes
        check_with_nas = yes
        permissions = 384
        caller_id = yes
  }
  # Loaded module rlm_exec
  # Loading module "echo" from file /etc/freeradius/3.0/mods-enabled/echo
  exec echo {
        wait = yes
        program = "/bin/echo %{User-Name}"
        input_pairs = "request"
        output_pairs = "reply"
        shell_escape = yes
  }
  # Loading module "sradutmp" from file /etc/freeradius/3.0/mods-enabled/sradutmp
  radutmp sradutmp {
        filename = "/var/log/freeradius/sradutmp"
        username = "%{User-Name}"
        case_sensitive = yes
        check_with_nas = yes
        permissions = 420
        caller_id = no
  }
  # Loaded module rlm_linelog
  # Loading module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog
  linelog {
        filename = "/var/log/freeradius/linelog"
        escape_filenames = no
        syslog_severity = "info"
        permissions = 384
        format = "This is a log message for %{User-Name}"
        reference = "messages.%{%{reply:Packet-Type}:-default}"
  }
  # Loading module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog
  linelog log_accounting {
        filename = "/var/log/freeradius/linelog-accounting"
        escape_filenames = no
        syslog_severity = "info"
        permissions = 384
        format = ""
        reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}"
  }
  # Loaded module rlm_preprocess
  # Loading module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess
  preprocess {
        huntgroups = "/etc/freeradius/3.0/mods-config/preprocess/huntgroups"
        hints = "/etc/freeradius/3.0/mods-config/preprocess/hints"
        with_ascend_hack = no
        ascend_channels_per_line = 23
        with_ntdomain_hack = no
        with_specialix_jetstream_hack = no
        with_cisco_vsa_hack = no
        with_alvarion_vsa_hack = no
  }
  # Loaded module rlm_expr
  # Loading module "expr" from file /etc/freeradius/3.0/mods-enabled/expr
  expr {
        safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
  }
  # Loading module "ntlm_auth" from file /etc/freeradius/3.0/mods-enabled/ntlm_auth
  exec ntlm_auth {
        wait = yes
        program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}"
        shell_escape = yes
  }
  # Loaded module rlm_unpack
  # Loading module "unpack" from file /etc/freeradius/3.0/mods-enabled/unpack
  # Loaded module rlm_chap
  # Loading module "chap" from file /etc/freeradius/3.0/mods-enabled/chap
  # Loaded module rlm_expiration
  # Loading module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration
  # Loaded module rlm_detail
  # Loading module "detail" from file /etc/freeradius/3.0/mods-enabled/detail
  detail {
        filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
        header = "%t"
        permissions = 384
        locking = no
        escape_filenames = no
        log_packet_header = no
  }
  # Loaded module rlm_cache
  # Loading module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap
  cache cache_eap {
        driver = "rlm_cache_rbtree"
        key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}"
        ttl = 15
        max_entries = 0
        epoch = 0
        add_stats = no
  }
  # Loaded module rlm_perl
  # Loading module "perl-privacyidea" from file /etc/freeradius/3.0/mods-enabled/mods-perl-privacyidea
  perl perl-privacyidea {
        filename = "/usr/share/privacyidea/freeradius/privacyidea_radius.pm"
        func_authorize = "authorize"
        func_authenticate = "authenticate"
        func_post_auth = "post_auth"
        func_accounting = "accounting"
        func_preacct = "preacct"
        func_checksimul = "checksimul"
        func_detach = "detach"
        func_xlat = "xlat"
        func_pre_proxy = "pre_proxy"
        func_post_proxy = "post_proxy"
        func_recv_coa = "recv_coa"
        func_send_coa = "send_coa"
  }
Perl version: 5.34.0
  # Loading module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
  detail auth_log {
        filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d"
        header = "%t"
        permissions = 384
        locking = no
        escape_filenames = no
        log_packet_header = no
  }
  # Loading module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
  detail reply_log {
        filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d"
        header = "%t"
        permissions = 384
        locking = no
        escape_filenames = no
        log_packet_header = no
  }
  # Loading module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
  detail pre_proxy_log {
        filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d"
        header = "%t"
        permissions = 384
        locking = no
        escape_filenames = no
        log_packet_header = no
  }
  # Loading module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
  detail post_proxy_log {
        filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d"
        header = "%t"
        permissions = 384
        locking = no
        escape_filenames = no
        log_packet_header = no
  }
  # Loaded module rlm_dynamic_clients
  # Loading module "dynamic_clients" from file /etc/freeradius/3.0/mods-enabled/dynamic_clients
  # Loaded module rlm_files
  # Loading module "files" from file /etc/freeradius/3.0/mods-enabled/files
  files {
        filename = "/etc/freeradius/3.0/mods-config/files/authorize"
        acctusersfile = "/etc/freeradius/3.0/mods-config/files/accounting"
        preproxy_usersfile = "/etc/freeradius/3.0/mods-config/files/pre-proxy"
  }
  # Loaded module rlm_passwd
  # Loading module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwd
  passwd etc_passwd {
        filename = "/etc/passwd"
        format = "*User-Name:Crypt-Password:"
        delimiter = ":"
        ignore_nislike = no
        ignore_empty = yes
        allow_multiple_keys = no
        hash_size = 100
  }
  # Loading module "exec" from file /etc/freeradius/3.0/mods-enabled/exec
  exec {
        wait = no
        input_pairs = "request"
        shell_escape = yes
        timeout = 10
  }
  # Loaded module rlm_attr_filter
  # Loading module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter
  attr_filter attr_filter.post-proxy {
        filename = "/etc/freeradius/3.0/mods-config/attr_filter/post-proxy"
        key = "%{Realm}"
        relaxed = no
  }
  # Loading module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter
  attr_filter attr_filter.pre-proxy {
        filename = "/etc/freeradius/3.0/mods-config/attr_filter/pre-proxy"
        key = "%{Realm}"
        relaxed = no
  }
  # Loading module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter
  attr_filter attr_filter.access_reject {
        filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_reject"
        key = "%{User-Name}"
        relaxed = no
  }
  # Loading module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter
  attr_filter attr_filter.access_challenge {
        filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_challenge"
        key = "%{User-Name}"
        relaxed = no
  }
  # Loading module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter
  attr_filter attr_filter.accounting_response {
        filename = "/etc/freeradius/3.0/mods-config/attr_filter/accounting_response"
        key = "%{User-Name}"
        relaxed = no
  }
  # Loading module "attr_filter.coa" from file /etc/freeradius/3.0/mods-enabled/attr_filter
  attr_filter attr_filter.coa {
        filename = "/etc/freeradius/3.0/mods-config/attr_filter/coa"
        key = "%{User-Name}"
        relaxed = no
  }
  # Loaded module rlm_logintime
  # Loading module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime
  logintime {
        minimum_timeout = 60
  }
  # Loaded module rlm_soh
  # Loading module "soh" from file /etc/freeradius/3.0/mods-enabled/soh
  soh {
        dhcp = yes
  }
  # Loaded module rlm_ldap
  # Loading module "ldap" from file /etc/freeradius/3.0/mods-enabled/ldap
  ldap {
        server = "ldap://dc2.blueloop.net"
   sasl {
   }
   user {
        scope = "sub"
        access_positive = yes
    sasl {
    }
   }
   group {
        scope = "sub"
        name_attribute = "cn"
        cacheable_name = no
        cacheable_dn = no
        allow_dangling_group_ref = no
   }
   client {
        scope = "sub"
        base_dn = ""
   }
   profile {
   }
   options {
        ldap_debug = 0
        net_timeout = 10
        res_timeout = 20
        srv_timelimit = 20
        idle = 60
        probes = 3
        interval = 30
   }
   tls {
        ca_file = "/etc/ssl/certs/ca-certificates.crt"
        start_tls = yes
   }
  }
Creating attribute LDAP-Group
  # Loaded module rlm_replicate
  # Loading module "replicate" from file /etc/freeradius/3.0/mods-enabled/replicate
  # Loaded module rlm_mschap
  # Loading module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap
  mschap {
        use_mppe = yes
        require_encryption = no
        require_strong = no
        with_ntdomain_hack = yes
   passchange {
   }
        allow_retry = yes
        winbind_retry_with_normalised_username = no
  }
  # Loaded module rlm_digest
  # Loading module "digest" from file /etc/freeradius/3.0/mods-enabled/digest
  # Loaded module rlm_always
  # Loading module "reject" from file /etc/freeradius/3.0/mods-enabled/always
  always reject {
        rcode = "reject"
        simulcount = 0
        mpp = no
  }
  # Loading module "fail" from file /etc/freeradius/3.0/mods-enabled/always
  always fail {
        rcode = "fail"
        simulcount = 0
        mpp = no
  }
  # Loading module "ok" from file /etc/freeradius/3.0/mods-enabled/always
  always ok {
        rcode = "ok"
        simulcount = 0
        mpp = no
  }
  # Loading module "handled" from file /etc/freeradius/3.0/mods-enabled/always
  always handled {
        rcode = "handled"
        simulcount = 0
        mpp = no
  }
  # Loading module "invalid" from file /etc/freeradius/3.0/mods-enabled/always
  always invalid {
        rcode = "invalid"
        simulcount = 0
        mpp = no
  }
  # Loading module "userlock" from file /etc/freeradius/3.0/mods-enabled/always
  always userlock {
        rcode = "userlock"
        simulcount = 0
        mpp = no
  }
  # Loading module "notfound" from file /etc/freeradius/3.0/mods-enabled/always
  always notfound {
        rcode = "notfound"
        simulcount = 0
        mpp = no
  }
  # Loading module "noop" from file /etc/freeradius/3.0/mods-enabled/always
  always noop {
        rcode = "noop"
        simulcount = 0
        mpp = no
  }
  # Loading module "updated" from file /etc/freeradius/3.0/mods-enabled/always
  always updated {
        rcode = "updated"
        simulcount = 0
        mpp = no
  }
  # Instantiating module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm
  # Instantiating module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm
  # Instantiating module "bangpath" from file /etc/freeradius/3.0/mods-enabled/realm
  # Instantiating module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm
  # Instantiating module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm
  # Instantiating module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog
  # Instantiating module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog
  # Instantiating module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess
reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/huntgroups
reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/hints
  # Instantiating module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration
  # Instantiating module "detail" from file /etc/freeradius/3.0/mods-enabled/detail
  # Instantiating module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap
rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked
  # Instantiating module "perl-privacyidea" from file /etc/freeradius/3.0/mods-enabled/mods-perl-privacyidea
  # Instantiating module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output
  # Instantiating module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
  # Instantiating module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
  # Instantiating module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log
  # Instantiating module "files" from file /etc/freeradius/3.0/mods-enabled/files
reading pairlist file /etc/freeradius/3.0/mods-config/files/authorize
reading pairlist file /etc/freeradius/3.0/mods-config/files/accounting
reading pairlist file /etc/freeradius/3.0/mods-config/files/pre-proxy
  # Instantiating module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwd
rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no
  # Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter
reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/post-proxy
  # Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter
reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/pre-proxy
  # Instantiating module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter
reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_reject
  # Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter
reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_challenge
  # Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter
reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/accounting_response
  # Instantiating module "attr_filter.coa" from file /etc/freeradius/3.0/mods-enabled/attr_filter
reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/coa
  # Instantiating module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime
  # Instantiating module "ldap" from file /etc/freeradius/3.0/mods-enabled/ldap
rlm_ldap: libldap vendor: OpenLDAP, version: 20517
rlm_ldap (ldap): Couldn't find configuration for accounting, will return NOOP for calls from this section
rlm_ldap (ldap): Couldn't find configuration for post-auth, will return NOOP for calls from this section
rlm_ldap (ldap): Initialising connection pool
   pool {
        start = 5
        min = 5
        max = 10
        spare = 3
        uses = 0
        lifetime = 0
        cleanup_interval = 30
        idle_timeout = 60
        retry_delay = 1
        spread = no
   }
rlm_ldap (ldap): Opening additional connection (0), 1 of 10 pending slots used
rlm_ldap (ldap): Connecting to ldap://dc2.blueloop.net:389 ldap://dc3.blueloop.net:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (1), 1 of 9 pending slots used
rlm_ldap (ldap): Connecting to ldap://dc2.blueloop.net:389 ldap://dc3.blueloop.net:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (2), 1 of 8 pending slots used
rlm_ldap (ldap): Connecting to ldap://dc2.blueloop.net:389 ldap://dc3.blueloop.net:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (3), 1 of 7 pending slots used
rlm_ldap (ldap): Connecting to ldap://dc2.blueloop.net:389 ldap://dc3.blueloop.net:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (4), 1 of 6 pending slots used
rlm_ldap (ldap): Connecting to ldap://dc2.blueloop.net:389 ldap://dc3.blueloop.net:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
  # Instantiating module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap
rlm_mschap (mschap): using internal authentication
  # Instantiating module "reject" from file /etc/freeradius/3.0/mods-enabled/always
  # Instantiating module "fail" from file /etc/freeradius/3.0/mods-enabled/always
  # Instantiating module "ok" from file /etc/freeradius/3.0/mods-enabled/always
  # Instantiating module "handled" from file /etc/freeradius/3.0/mods-enabled/always
  # Instantiating module "invalid" from file /etc/freeradius/3.0/mods-enabled/always
  # Instantiating module "userlock" from file /etc/freeradius/3.0/mods-enabled/always
  # Instantiating module "notfound" from file /etc/freeradius/3.0/mods-enabled/always
  # Instantiating module "noop" from file /etc/freeradius/3.0/mods-enabled/always
  # Instantiating module "updated" from file /etc/freeradius/3.0/mods-enabled/always
 } # modules
radiusd: #### Loading Virtual Servers ####
server { # from file /etc/freeradius/3.0/radiusd.conf
} # server
server radius_accounting { # from file /etc/freeradius/3.0/sites-enabled/radius-accounting
 # Loading preacct {...}
 # Loading accounting {...}
} # server radius_accounting
server active-directory { # from file /etc/freeradius/3.0/sites-enabled/ldap
 # Loading authenticate {...}
Compiling Auth-Type AD for attr Auth-Type
Compiling Auth-Type Perl for attr Auth-Type
 # Loading authorize {...}
} # server active-directory
radiusd: #### Opening IP addresses and Ports ####
listen {
        type = "acct"
        ipaddr = 10.77.10.10
        port = 1813
        clients = "external"
  client ts {
        ipaddr = ts.blueloop.net IPv4 address [10.77.14.139]
        require_message_authenticator = no
        secret = <<< secret >>>
   limit {
        max_connections = 16
        lifetime = 0
        idle_timeout = 30
   }
  }
  client jg {
        ipaddr = jgpc2.blueloop.net IPv4 address [10.77.16.31]
        require_message_authenticator = no
        secret = <<< secret >>>
   limit {
        max_connections = 16
        lifetime = 0
        idle_timeout = 30
   }
  }
  client jglaptop {
        ipaddr = 10.77.252.9
        require_message_authenticator = no
        secret = <<< secret >>>
   limit {
        max_connections = 16
        lifetime = 0
        idle_timeout = 30
   }
  }
  client remote-test {
        ipaddr = 10.77.10.27
        require_message_authenticator = no
        secret = <<< secret >>>
   limit {
        max_connections = 16
        lifetime = 0
        idle_timeout = 30
   }
  }
}
listen {
        type = "auth"
        ipaddr = 10.77.10.10
        port = 1812
        clients = "external"
}
Listening on acct address 10.77.10.10 port 1813 bound to server radius_accounting
Listening on auth address 10.77.10.10 port 1812 bound to server active-directory
Ready to process requests
(0) Received Access-Request Id 24 from 10.77.10.27:53932 to 10.77.10.10:1812 length 77
(0)   User-Name = "gerdesj"
(0)   NAS-IP-Address = 127.0.1.1
(0)   NAS-Port-Type = Virtual
(0)   User-Password = "***Correct-AD-Password***"
(0)   Message-Authenticator = 0xa022bc116286181734fa14a04a16b4ce
(0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/ldap
(0)   authorize {
(0)     if (!State) {
(0)     if (!State)  -> TRUE
(0)     if (!State)  {
(0)       if (&User-Password) {
(0)       if (&User-Password)  -> TRUE
(0)       if (&User-Password)  {
(0)         update control {
(0)           EXPAND %{User-Name}@blueloop.net
(0)              --> gerdesj@blueloop.net
(0)           Ldap-UserDN := gerdesj@blueloop.net
(0)           Auth-Type := AD
(0)         } # update control = noop
(0)       } # if (&User-Password)  = noop
(0)       ... skipping else: Preceding "if" was taken
(0)     } # if (!State)  = noop
(0)     ... skipping else: Preceding "if" was taken
(0)   } # authorize = noop
(0) Found Auth-Type = AD
(0) # Executing group from file /etc/freeradius/3.0/sites-enabled/ldap
(0)   Auth-Type AD {
rlm_ldap (ldap): Reserved connection (0)
(0) ldap: Login attempt by "gerdesj"
(0) ldap: Using user DN from request "gerdesj@blueloop.net"
(0) ldap: Waiting for bind result...
(0) ldap: Bind successful
(0) ldap: Bind as user "gerdesj@blueloop.net" was successful
rlm_ldap (ldap): Released connection (0)
(0)     [ldap] = ok
(0)     if (ok) {
(0)     if (ok)  -> TRUE
(0)     if (ok)  {
(0)       update reply {
(0)         EXPAND %{randstr:aaaaaaaaaaaaaaaa}
(0)            --> f4lq1EoYCe3a2wme
(0)         State := 0x66346c7131456f594365336132776d65
(0)         Reply-Message := "Please enter PIN"
(0)       } # update reply = noop
(0)       update control {
(0)         Response-Packet-Type := Access-Challenge
(0)       } # update control = noop
(0)     } # if (ok)  = noop
(0)   } # Auth-Type AD = ok
(0) Using Post-Auth-Type Challenge
(0) Post-Auth-Type sub-section not found.  Ignoring.
(0) Sent Access-Challenge Id 24 from 10.77.10.10:1812 to 10.77.10.27:53932 length 56
(0)   State := 0x66346c7131456f594365336132776d65
(0)   Reply-Message := "Please enter PIN"
(0) Finished request
Waking up in 4.9 seconds.
(0) Cleaning up request packet ID 24 with timestamp +54 due to cleanup_delay was reached
Ready to process requests
(1) Received Access-Request Id 25 from 10.77.10.27:58695 to 10.77.10.10:1812 length 95
(1)   User-Name = "gerdesj"
(1)   NAS-IP-Address = 127.0.1.1
(1)   NAS-Port-Type = Virtual
(1)   State = 0x66346c7131456f594365336132776d65
(1)   User-Password = "3128"
(1)   Message-Authenticator = 0x2d33eaf02ddbb606ea1d6016c606db2f
(1) session-state: No cached attributes
(1) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/ldap
(1)   authorize {
(1)     if (!State) {
(1)     if (!State)  -> FALSE
(1)     else {
(1) perl-privacyidea:   $RAD_REQUEST{'User-Name'} = &request:User-Name -> 'gerdesj'
(1) perl-privacyidea:   $RAD_REQUEST{'User-Password'} = &request:User-Password -> '3128'
(1) perl-privacyidea:   $RAD_REQUEST{'NAS-IP-Address'} = &request:NAS-IP-Address -> '127.0.1.1'
(1) perl-privacyidea:   $RAD_REQUEST{'State'} = &request:State -> '0x66346c7131456f594365336132776d65'
(1) perl-privacyidea:   $RAD_REQUEST{'NAS-Port-Type'} = &request:NAS-Port-Type -> 'Virtual'
(1) perl-privacyidea:   $RAD_REQUEST{'Message-Authenticator'} = &request:Message-Authenticator -> '0x2d33eaf02ddbb606ea1d6016c606db2f'
(1) perl-privacyidea: &request:User-Password = $RAD_REQUEST{'User-Password'} -> '3128'
(1) perl-privacyidea: &request:Message-Authenticator = $RAD_REQUEST{'Message-Authenticator'} -> '0x2d33eaf02ddbb606ea1d6016c606db2f'
(1) perl-privacyidea: &request:NAS-IP-Address = $RAD_REQUEST{'NAS-IP-Address'} -> '127.0.1.1'
(1) perl-privacyidea: &request:User-Name = $RAD_REQUEST{'User-Name'} -> 'gerdesj'
(1) perl-privacyidea: &request:State = $RAD_REQUEST{'State'} -> '0x66346c7131456f594365336132776d65'
(1) perl-privacyidea: &request:NAS-Port-Type = $RAD_REQUEST{'NAS-Port-Type'} -> 'Virtual'
(1)       [perl-privacyidea] = ok
(1)       if (ok || updated) {
(1)       if (ok || updated)  -> TRUE
(1)       if (ok || updated)  {
(1)         update control {
(1)           Auth-Type := Perl
(1)         } # update control = noop
(1)       } # if (ok || updated)  = noop
(1)     } # else = ok
(1)   } # authorize = ok
(1) Found Auth-Type = Perl
(1) # Executing group from file /etc/freeradius/3.0/sites-enabled/ldap
(1)   Auth-Type Perl {
(1) perl-privacyidea:   $RAD_REQUEST{'User-Name'} = &request:User-Name -> 'gerdesj'
(1) perl-privacyidea:   $RAD_REQUEST{'User-Password'} = &request:User-Password -> '3128'
(1) perl-privacyidea:   $RAD_REQUEST{'NAS-IP-Address'} = &request:NAS-IP-Address -> '127.0.1.1'
(1) perl-privacyidea:   $RAD_REQUEST{'State'} = &request:State -> '0x66346c7131456f594365336132776d65'
(1) perl-privacyidea:   $RAD_REQUEST{'NAS-Port-Type'} = &request:NAS-Port-Type -> 'Virtual'
(1) perl-privacyidea:   $RAD_REQUEST{'Message-Authenticator'} = &request:Message-Authenticator -> '0x2d33eaf02ddbb606ea1d6016c606db2f'
(1) perl-privacyidea:   $RAD_CHECK{'Auth-Type'} = &control:Auth-Type -> 'Perl'
(1) perl-privacyidea:   $RAD_CONFIG{'Auth-Type'} = &control:Auth-Type -> 'Perl'
rlm_perl: Config File /etc/privacyidea/rlm_perl.ini found!
rlm_perl: Debugging config: false
rlm_perl: Default URL https://localhost/validate/check 
rlm_perl: Looking for config for auth-type Perl
rlm_perl: Password encoding guessed: ascii
rlm_perl: Setting client IP to 127.0.1.1.
rlm_perl: Auth-Type: Perl
rlm_perl: url: https://localhost/validate/check
rlm_perl: user sent to privacyidea: gerdesj
rlm_perl: realm sent to privacyidea: blueloop.net
rlm_perl: resolver sent to privacyidea: 
rlm_perl: client sent to privacyidea: 127.0.1.1
rlm_perl: state sent to privacyidea: f4lq1EoYCe3a2wme
rlm_perl: urlparam pass  
rlm_perl: urlparam realm  
rlm_perl: urlparam state  
rlm_perl: urlparam user  
rlm_perl: urlparam client  
rlm_perl: Request timeout: 10 
rlm_perl: Not verifying SSL certificate!
rlm_perl: elapsed time for privacyidea call: 1.182513
rlm_perl: privacyIDEA Result status is true!
rlm_perl: privacyIDEA access denied for gerdesj realm='blueloop.net'
rlm_perl: return RLM_MODULE_REJECT
(1) perl-privacyidea: &request:User-Password = $RAD_REQUEST{'User-Password'} -> '3128'
(1) perl-privacyidea: &request:Message-Authenticator = $RAD_REQUEST{'Message-Authenticator'} -> '0x2d33eaf02ddbb606ea1d6016c606db2f'
(1) perl-privacyidea: &request:NAS-IP-Address = $RAD_REQUEST{'NAS-IP-Address'} -> '127.0.1.1'
(1) perl-privacyidea: &request:User-Name = $RAD_REQUEST{'User-Name'} -> 'gerdesj'
(1) perl-privacyidea: &request:State = $RAD_REQUEST{'State'} -> '0x66346c7131456f594365336132776d65'
(1) perl-privacyidea: &request:NAS-Port-Type = $RAD_REQUEST{'NAS-Port-Type'} -> 'Virtual'
(1) perl-privacyidea: &reply:Reply-Message = $RAD_REPLY{'Reply-Message'} -> 'wrong otp pin'
(1) perl-privacyidea: &control:Auth-Type = $RAD_CHECK{'Auth-Type'} -> 'Perl'
(1)     [perl-privacyidea] = reject
(1)   } # Auth-Type Perl = reject
(1) Failed to authenticate the user
(1) Using Post-Auth-Type Reject
(1) Post-Auth-Type sub-section not found.  Ignoring.
(1) Login incorrect: [gerdesj] (from client remote-test port 0)
(1) Delaying response for 1.000000 seconds
Waking up in 0.9 seconds.
(1) Sending delayed response
(1) Sent Access-Reject Id 25 from 10.77.10.10:1812 to 10.77.10.27:58695 length 35
(1)   Reply-Message = "wrong otp pin"
Waking up in 3.9 seconds.
(1) Cleaning up request packet ID 25 with timestamp +72 due to cleanup_delay was reached
Ready to process requests