Re: chaining AUTH methods -- adding GoogleAuthenticator 2nd Factor to pubkey auth? can't get the GA prompt :-/

[Dmt Ops <opsdmt@xxxxxxxxx>]

testing goole-authenticator's standalone functionality, it

    > cd google-authenticator/libpam/
    > ./demo
        Verification code:  123456
        Login failed
        Invalid verification code
    >

fails with an INVALID code, and

    > ./demo
        Verification code:  XXXXXX
    >

succeeds with a VALID code.

turning up the sshd server debug level to DEBUG3, entering a similarly
VALID GA verification code, the code is declared "invalid",

    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_respond [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_send entering:
type 108 [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_respond: waiting
for MONITOR_ANS_PAM_RESPOND [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive_expect
entering: type 109 [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive entering
[preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive entering
    Dec 23 10:37:24 server sshd[22322]: debug3: monitor_read: checking
request 108
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_answer_pam_respond
    Dec 23 10:37:24 server sshd[22322]: debug2: PAM: sshpam_respond
entering, 1 responses
    Dec 23 10:37:24 server sshd[22322]: debug3: ssh_msg_send: type 6
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_send entering:
type 109
>>>    Dec 23 10:37:24 server sshd(pam_google_authenticator)[22326]:
Invalid verification code
    Dec 23 10:37:24 server sshd[22326]: debug3: ssh_msg_send: type 7
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_respond:
pam_respond returned 1 [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_query [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_send entering:
type 106 [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_query: waiting
for MONITOR_ANS_PAM_QUERY [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive_expect
entering: type 107 [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive entering
[preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive entering
    Dec 23 10:37:24 server sshd[22322]: debug3: monitor_read: checking
request 106
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_answer_pam_query
    Dec 23 10:37:24 server sshd[22322]: debug3: PAM: sshpam_query entering
    Dec 23 10:37:24 server sshd[22322]: debug3: ssh_msg_recv entering
    Dec 23 10:37:24 server sshd[22322]: debug3: PAM: Authentication failure
    Dec 23 10:37:24 server sshd[22322]: error: PAM: Cannot make/remove an
entry for the specified session for root from 2001:xxx:xxxx:xxx::107
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_send entering:
type 107
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_query: pam_query
returned -1 [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug2: auth2_challenge_start:
devices <empty> [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_free_ctx [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_send entering:
type 110 [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_free_ctx: waiting
for MONITOR_ANS_PAM_FREE_CTX [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive_expect
entering: type 111 [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive entering
[preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive entering
    Dec 23 10:37:24 server sshd[22322]: debug3: monitor_read: checking
request 110
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_answer_pam_free_ctx
    Dec 23 10:37:24 server sshd[22322]: debug3: PAM: sshpam_free_ctx
entering
    Dec 23 10:37:24 server sshd[22322]: debug3: PAM: sshpam_thread_cleanup
entering
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_send entering:
type 111
    Dec 23 10:37:24 server sshd[22322]: debug2: monitor_read: 110 used
once, disabling now
    Dec 23 10:37:24 server sshd[22322]: Failed keyboard-interactive/pam for
root from 2001:xxx:xxxx:xxx::107 port 49831 ssh2
    Dec 23 10:37:24 server sshd[22322]: debug3: userauth_finish: failure
partial=0 next methods="keyboard-interactive" [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug1: userauth-request for user
root service ssh-connection method keyboard-interactive [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug1: attempt 3 failures 2
[preauth]
    Dec 23 10:37:24 server sshd[22322]: debug2: input_userauth_request: try
method keyboard-interactive [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug1: keyboard-interactive devs
[preauth]
    Dec 23 10:37:24 server sshd[22322]: debug1: auth2_challenge: user=root
devs= [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug1: kbdint_alloc: devices 'pam'
[preauth]
    Dec 23 10:37:24 server sshd[22322]: debug2: auth2_challenge_start:
devices pam [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug2: kbdint_next_device: devices
<empty> [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug1: auth2_challenge_start:
trying authentication method 'pam' [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_init_ctx [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_send entering:
type 104 [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_init_ctx: waiting
for MONITOR_ANS_PAM_INIT_CTX [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive_expect
entering: type 105 [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive entering
[preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive entering
    Dec 23 10:37:24 server sshd[22322]: debug3: monitor_read: checking
request 104
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_answer_pam_init_ctx
    Dec 23 10:37:24 server sshd[22322]: debug3: PAM: sshpam_init_ctx
entering
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_send entering:
type 105
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_query [preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_send entering:
type 106 [preauth]
    Dec 23 10:37:24 server sshd[22327]: debug3: PAM: sshpam_thread_conv
entering, 1 messages
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_query: waiting
for MONITOR_ANS_PAM_QUERY [preauth]
    Dec 23 10:37:24 server sshd[22327]: debug3: ssh_msg_send: type 1
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive_expect
entering: type 107 [preauth]
    Dec 23 10:37:24 server sshd[22327]: debug3: ssh_msg_recv entering
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive entering
[preauth]
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_receive entering
    Dec 23 10:37:24 server sshd[22322]: debug3: monitor_read: checking
request 106
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_answer_pam_query
    Dec 23 10:37:24 server sshd[22322]: debug3: PAM: sshpam_query entering
    Dec 23 10:37:24 server sshd[22322]: debug3: ssh_msg_recv entering
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_request_send entering:
type 107
    Dec 23 10:37:24 server sshd[22322]: debug3: mm_sshpam_query: pam_query
returned 0 [preauth]
    Dec 23 10:37:24 server sshd[22322]: Postponed keyboard-interactive for
root from 2001:xxx:xxxx:xxx::107 port 49831 ssh2 [preauth]
_______________________________________________
openssh-unix-dev mailing list
openssh-unix-dev@xxxxxxxxxxx
https://lists.mindrot.org/mailman/listinfo/openssh-unix-dev