From owner-freebsd-questions@freebsd.org Sun Mar 17 23:26:47 2019 Return-Path: Delivered-To: freebsd-questions@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 32936154E662 for ; Sun, 17 Mar 2019 23:26:47 +0000 (UTC) (envelope-from plmahan@gmail.com) Received: from mail-vs1-xe2d.google.com (mail-vs1-xe2d.google.com [IPv6:2607:f8b0:4864:20::e2d]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (Client CN "smtp.gmail.com", Issuer "GTS CA 1O1" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id BB19E957E0 for ; Sun, 17 Mar 2019 23:26:45 +0000 (UTC) (envelope-from plmahan@gmail.com) Received: by mail-vs1-xe2d.google.com with SMTP id g127so1328356vsd.6 for ; Sun, 17 Mar 2019 16:26:45 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:from:date:message-id:subject:to; bh=mXXMfePo/v1OSVU+6nE15dSpb7aGtJfLQGO5LcoAUB4=; b=oAlqLPTWl6mtRKUwFlIn+msUl5CYWiYTqVFEp5fTxZOIoFGGY3ROezpO9Up3eKpqUk LQA3TRsO7DASUdC/a6fdgW7/tNF8bwhdsdb0FDvhaMuMKYkuueJkHV2CThL2VWdPCwpG QB0oxjZmymO2EGfjTV7T9XW07XsKIhX2Yhdvu0v4dhdbmARsiaDkEVjFTu/qOKYhp3rW edcFL6hwulvuBMGjWgPxAMq7tC3/WGSR8BvsKm9vFkc3Sg2F6z2EEpKmDNXPnlnXLlgb BVeLV68fXoAEWc50nm3KzSMgicW9um2EVmMnmjTYJub7SBWXxRIId00LFigXVnNoNKxY vfSA== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:from:date:message-id:subject:to; bh=mXXMfePo/v1OSVU+6nE15dSpb7aGtJfLQGO5LcoAUB4=; b=Mk2swLD9GJSbtzc0gsu+aNuv9wkyaSfjz+v53uqN9Jyyu1AG2EIvBuSfl5x8YnvOWN xjnwDjYfi+Ez6ydqielBtImadjJY9L2LHT8V2Gve5H+U3BhfM9PaW0usgOmdCrPWLn3J LjqB2z3ET8iVn4F4dfF10dNXdO+kbe/165uQrGO2s6qmY9BbzIUch/c4jT419Ss9w90w geg6xsR4HARoRIG9yPaTybJlI+6JIhb8z2K9VZ90oUinDkkaLKQBD3uDl/Bs9LR243Nx i5QNZDm0N4lGalz3q3nebtjJlWehUxmmreIyGCMgXnndhn5FupvIcJ4HNfzU3wmTi9LX 0asA== X-Gm-Message-State: APjAAAVlbtaMjWqjSOd4FK6TL0G3ifz3zxCpUaKmx3LXkMjYkRjMSX8B a1gGpKWO8tQVmuKa4TUHleZfTzUKga59y8Y4smHLsv21 X-Google-Smtp-Source: APXvYqzE0mU4Wo44rNrdA5dYh5yTPRf+WLAUJDpYDlWlr4bg0G3ItbS6KuzJHMHOv/QjfVrY9c45iNjn7c9jrcGGF8U= X-Received: by 2002:a67:e907:: with SMTP id c7mr8146624vso.221.1552865204787; Sun, 17 Mar 2019 16:26:44 -0700 (PDT) MIME-Version: 1.0 From: Patrick Mahan Date: Sat, 16 Mar 2019 00:00:52 -0900 Message-ID: Subject: Understanding PAM debug output To: User Questions X-Rspamd-Queue-Id: BB19E957E0 X-Spamd-Bar: ----- Authentication-Results: mx1.freebsd.org; dkim=pass header.d=gmail.com header.s=20161025 header.b=oAlqLPTW; dmarc=pass (policy=none) header.from=gmail.com; spf=pass (mx1.freebsd.org: domain of plmahan@gmail.com designates 2607:f8b0:4864:20::e2d as permitted sender) smtp.mailfrom=plmahan@gmail.com X-Spamd-Result: default: False [-5.85 / 15.00]; R_SPF_ALLOW(-0.20)[+ip6:2607:f8b0:4000::/36]; FREEMAIL_FROM(0.00)[gmail.com]; TO_DN_ALL(0.00)[]; MX_GOOD(-0.01)[cached: alt3.gmail-smtp-in.l.google.com]; DKIM_TRACE(0.00)[gmail.com:+]; DMARC_POLICY_ALLOW(-0.50)[gmail.com,none]; NEURAL_HAM_SHORT(-0.91)[-0.911,0]; FROM_EQ_ENVFROM(0.00)[]; RCVD_TLS_LAST(0.00)[]; MIME_TRACE(0.00)[0:+,1:+]; FREEMAIL_ENVFROM(0.00)[gmail.com]; ASN(0.00)[asn:15169, ipnet:2607:f8b0::/32, country:US]; DATE_IN_PAST(1.00)[]; DWL_DNSWL_NONE(0.00)[gmail.com.dwl.dnswl.org : 127.0.5.0]; ARC_NA(0.00)[]; NEURAL_HAM_MEDIUM(-1.00)[-0.999,0]; R_DKIM_ALLOW(-0.20)[gmail.com:s=20161025]; FROM_HAS_DN(0.00)[]; TO_MATCH_ENVRCPT_ALL(0.00)[]; NEURAL_HAM_LONG(-1.00)[-1.000,0]; MIME_GOOD(-0.10)[multipart/alternative,text/plain]; PREVIOUSLY_DELIVERED(0.00)[freebsd-questions@freebsd.org]; RCPT_COUNT_ONE(0.00)[1]; IP_SCORE(-2.93)[ip: (-9.76), ipnet: 2607:f8b0::/32(-2.74), asn: 15169(-2.09), country: US(-0.07)]; RCVD_IN_DNSWL_NONE(0.00)[d.2.e.0.0.0.0.0.0.0.0.0.0.0.0.0.0.2.0.0.4.6.8.4.0.b.8.f.7.0.6.2.list.dnswl.org : 127.0.5.0]; RCVD_COUNT_TWO(0.00)[2] Content-Type: text/plain; charset="UTF-8" X-Content-Filtered-By: Mailman/MimeDel 2.1.29 X-BeenThere: freebsd-questions@freebsd.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: User questions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 17 Mar 2019 23:26:47 -0000 All, FreeBSD 11.2-Release-p7 I am debugging an authentication problem with /usr/lib/pam_unix.so.6. I have pam.d service setup with - auth required pam_unix.so debug nullok local_pass account required pam_unix.so debug try_first_pass local_pass Yet, my application is failing. Looking at the output from /var/log/debug.log I see - Mar 17 14:54:41 ns auth: in pam_vprompt(): entering Mar 17 14:54:41 ns auth: in pam_get_item(): entering: PAM_CONV Mar 17 14:54:41 ns auth: in pam_get_item(): returning PAM_SUCCESS Mar 17 14:54:41 ns auth: in pam_vprompt(): returning PAM_SUCCESS Mar 17 14:54:41 ns auth: in pam_set_item(): entering: PAM_AUTHTOK Mar 17 14:54:41 ns auth: in pam_set_item(): returning PAM_SUCCESS Mar 17 14:54:41 ns auth: in pam_get_item(): entering: PAM_AUTHTOK Mar 17 14:54:41 ns auth: in pam_get_item(): returning PAM_SUCCESS Mar 17 14:54:41 ns auth: in pam_get_authtok(): returning PAM_SUCCESS Mar 17 14:54:41 ns auth: in pam_sm_authenticate(): Got password Mar 17 14:54:41 ns auth: in openpam_get_option(): entering: 'no_warn' Mar 17 14:54:41 ns auth: in openpam_get_option(): returning NULL Mar 17 14:54:41 ns auth: in pam_vprompt(): entering Mar 17 14:54:41 ns auth: in pam_get_item(): entering: PAM_CONV Mar 17 14:54:41 ns auth: in pam_get_item(): returning PAM_SUCCESS Mar 17 14:54:41 ns auth: in pam_vprompt(): returning PAM_SUCCESS Mar 17 14:54:41 ns auth: in openpam_dispatch(): /usr/lib/pam_unix.so.6: pam_sm_authenticate(): authentication error However, looking at the sources for /usr/lib/pam_unix.so.6 I see that there should also be a log message for "Got user:" at line 105 in /usr/src/lib/libpam/modules/pam_unix/pam_unix.c. Am I looking at the wrong code? Doing a recursive grep under /usr/src looking for "Got password" turns up - root@ns:/usr/src # find . -name "*.c" -exec grep -H "Got password" {} \; ./lib/libpam/modules/pam_krb5/pam_krb5.c: PAM_LOG("Got password"); ./lib/libpam/modules/pam_krb5/pam_krb5.c: PAM_LOG("Got password"); ./lib/libpam/modules/pam_unix/pam_unix.c: PAM_LOG("Got password"); ./lib/libpam/modules/pam_radius/pam_radius.c: PAM_LOG("Got password"); So am I looking at the wrong source code? Thanks, Patrick