Duo flow authn audit

[Paul B. Henson]

I'm testing 4.3.1 and trying out the new authn audit functionality. I
enabled it in authn.properties:

	idp.authn.audit.enabled = true


I updated logback.xml to tentatively log all authn audit entries to a
single file:

    <appender name="IDP_AUTHN_AUDIT" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <File>${idp.logfiles}/idp-authn-audit.log</File>

        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${idp.logfiles}/idp-authn-audit-%d{yyyy-MM-dd}.log.gz</fileNamePattern>
            <maxHistory>${idp.loghistory}</maxHistory>
        </rollingPolicy>

        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <charset>UTF-8</charset>
            <Pattern>%date{ISO8601} - %msg - [%mdc{idp.remote_addr}/%mdc{idp.jsessionid}]%n</Pattern>
        </encoder>
    </appender>

    <logger name="Shibboleth-Audit.Password" level="ALL" additivity="false">
        <appender-ref ref="IDP_AUTHN_AUDIT"/>
    </logger>
    <logger name="Shibboleth-Audit.IPAddress" level="ALL" additivity="false">
        <appender-ref ref="IDP_AUTHN_AUDIT"/>
    </logger>
    <logger name="Shibboleth-Audit.Duo" level="ALL" additivity="false">
        <appender-ref ref="IDP_AUTHN_AUDIT"/>
    </logger>


I'm using the MFA flow with Password and legacy Duo; when I do a test
authentication, I see the entry for Password:

2023-04-06 20:32:27,217 - 10.104.223.16|2023-04-07T03:32:27.217045Z|https://sp.test.calstate.edu/shibboleth-sp|_ebb2a4c7c4aee5aefafbbbfa8ee3e469||authn/Password|krb5|henson|henson|Success|Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101 Firefox/102.0 - [10.104.223.16/node015g9whs3v312ww5z4pa6pa0dy227]


but nothing for Duo? The process log shows:

2023-04-06 20:39:05,752 - 10.104.223.16/node01mi82c31ylgv5i4x3uzls9spl40 - INFO [net.shibboleth.idp.authn.impl.KerberosCredentialValidator:210] - Credential Validator krb5: Login by 'henson' succeeded
2023-04-06 20:39:13,269 - 10.104.223.16/node01mi82c31ylgv5i4x3uzls9spl40 - INFO [net.shibboleth.idp.authn.duo.impl.ValidateDuoWebResponse:207] - Profile Action ValidateDuoWebResponse: Duo authentication succeeded for 'henson'
2023-04-06 20:39:13,287 - 10.104.223.16/node01mi82c31ylgv5i4x3uzls9spl40 - INFO [net.shibboleth.idp.authn.impl.FinalizeAuthentication:196] - Profile Action FinalizeAuthentication: Principal henson authenticated


I expected to see authn audit logs for Duo too? Am I missing something?
Misconfigured something?

Thanks...


-- 
Paul B. Henson  |  (909) 979-6361  |  http://www.cpp.edu/~henson/
Operating Systems and Network Analyst  |  henson at cpp.edu
California State Polytechnic University  |  Pomona CA 91768