README.authdebug.html.in

   1 <html>
   2 <head>
   3   <meta http-equiv="Content-Type" content="">
   4   <title>Debugging authentication problems</title>
   5 </head>
   6
   7 <body bgcolor="#FFFFFF">
   8 <h1 align="center">Debugging authentication problems</h1>
   9
  10 <p>A common problem after installing the Courier authentication library is
  11 that authentication, using authtest, doesn't work. This document shows how to
  12 use courier's debugging features to pinpoint the problem.</p>
  13
  14 <h2>1. Turn on debugging</h2>
  15
  16 <p>For courier-imap, you need to set one of the following values in
  17 @sysconfdir@/authdaemonrc:</p>
  18 <pre>DEBUG_LOGIN=1    # turn on authentication debugging
  19 DEBUG_LOGIN=2    # turn on authentication debugging AND show passwords</pre>
  20
  21 <p>This setting is located at the very end of the configuration file.</p>
  22
  23 <p>After changing this setting, restart the authentication daemon by running
  24 the "authdaemond stop" and "authdaemond start" commands.</p>
  25
  26 <p>At this point, all debugging output goes to syslog at level 'debug', which
  27 is normally not shown. You will probably need to change your
  28 <code>/etc/syslog.conf</code> file to be able to see these messages. If you
  29 have an existing entry which says "mail.info" (which means facility 'mail',
  30 level 'info' or higher) then you can just change this to "mail.debug".
  31 Alternatively you can add a new entry like this:</p>
  32 <pre>*.debug                        /var/log/debug</pre>
  33
  34 <p>Don't forget to create this file, and to send a HUP signal to syslogd to
  35 make it re-read its configuration:</p>
  36 <pre># touch /var/log/debug
  37 # killall -1 syslogd</pre>
  38
  39 <p>If you don't want to mess around with your syslog configuration, you can
  40 also start <code>authdaemond</code> manually, and log its output to a
  41 file:</p>
  42
  43 <p><code>@libexecdir@/courier-authlib/authdaemond &gt;filename
  44 2&gt;&amp;1</code></p>
  45
  46 <h2>2. Issue a manual login</h2>
  47
  48 <p>You can use the authtest command to verify authentication, or go ahead and
  49 install Courier-IMAP.</p>
  50
  51 <p>For courier-imap, you will get much better information by not using a mail
  52 client and manually logging in using 'telnet'. The transcript of this telnet
  53 session may give useful information as to what is going on. If you are going
  54 to report a problem to the mailing list, you should certainly include this
  55 transcript as well as the corresponding debugging output.</p>
  56 <pre>-- to debug POP3 --
  57 # telnet x.x.x.x 110
  58 user USERNAME
  59 pass PASSWORD
  60 stat
  61 quit
  62
  63 -- to debug IMAP --
  64 # telnet x.x.x.x 143
  65 a login USERNAME PASSWORD
  66 a examine inbox
  67 a logout
  68
  69 -- to debug POP3 over SSL --
  70 # openssl s_client -connect x.x.x.x:995
  71 (then use same commands as POP3 example)
  72
  73 -- to debug IMAP over SSL --
  74 # openssl s_client -connect x.x.x.x:993
  75 (then use same commands as IMAP example)</pre>
  76
  77 <p>This isn't an option for sqwebmail of course - just login through the web
  78 interface and check the authentication debug log which is generated.</p>
  79
  80 <h2>3. Interpret the debug output</h2>
  81
  82 <p>First, a brief explanation of courier's authentication system. There are a
  83 number of standalone <b>authentication modules</b>. An authentication module
  84 exists for every authentication method. Each authentication module is
  85 installed as a shared library. When <strong>authdaemond</strong> starts, it
  86 attempts to load and initialize the authentication modules, logging the
  87 following messages to syslog:</p>
  88 <pre>Oct 17 11:25:37 commodore authdaemond: modules="authuserdb authpam authpgsql authldap authmysql authcustom", daemons=5
  89 Oct 17 11:25:37 commodore authdaemond: Installing libauthuserdb
  90 Oct 17 11:25:37 commodore authdaemond: Installation complete: authuserdb
  91 Oct 17 11:25:37 commodore authdaemond: Installing libauthpam
  92 Oct 17 11:25:37 commodore authdaemond: Installation complete: authpam
  93 Oct 17 11:25:37 commodore authdaemond: Installing libauthpgsql
  94 Oct 17 11:25:37 commodore authdaemond: libauthpgsql.so: cannot open shared object file: No such file or directory
  95 Oct 17 11:25:37 commodore authdaemond: Installing libauthldap
  96 Oct 17 11:25:37 commodore authdaemond: libauthldap.so: cannot open shared object file: No such file or directory
  97 Oct 17 11:25:37 commodore authdaemond: Installing libauthmysql
  98 Oct 17 11:25:37 commodore authdaemond: libauthmysql.so: cannot open shared object file: No such file or directory
  99 Oct 17 11:25:37 commodore authdaemond: Installing libauthcustom
 100 Oct 17 11:25:37 commodore authdaemond: Installation complete: authcustom</pre>
 101
 102 <p>The first message lists all authentication modules that were compiled, and
 103 indicates that <strong>authdaemond</strong> will spawn five processes to
 104 handle all authentication requests. This is followed by messages indicating
 105 that indicate which authentication modules were installed.</p>
 106
 107 <p>In this example, authdaemond did not load the authpgsql, authldap, and
 108 authmysql modules. That's because in this case the Courier authentication
 109 library is installed by the system's package manager. The LDAP, MySQL, and
 110 PostgreSQL support was placed into optional sub-packages which are not
 111 installed. Even though all of these modules were initially compiled, the
 112 optional authentication modules were not installed.</p>
 113
 114 <p>This is normal. authdaemond will simply ignore any authentication module
 115 it cannot find, and will activate only those modules that are available. When
 116 an authentication request comes in, all of the modules will be executed, one
 117 after the other, resulting in one of three conditions:</p>
 118 <dl>
 119   <dt>ACCEPT</dt>
 120     <dd>The user was authenticated successfully</dd>
 121   <dt>REJECT</dt>
 122     <dd>The module did not know this username, or the user gave invalid
 123       credentials. The request is passed to the next module.</dd>
 124   <dt>TEMPFAIL</dt>
 125     <dd>The module suffered an internal failure, such as inability to contact
 126       an external database. The login is rejected, and no further modules are
 127       tried.</dd>
 128 </dl>
 129
 130 <p>In a typical Courier installation the authentication request is sent, via
 131 a filesystem socket, to a pool of <b>authdaemond</b> processes (note the
 132 extra "d" on the end) which perform the actual work. authdaemond, in turn,
 133 contains other authentication modules such as authpam, authmysql, and so
 134 on.</p>
 135
 136 <p>If <code>authdaemond</code> is running successfully, then it will in turn
 137 run each of the modules it is linked against. If any one returns REJECT then
 138 the next is tried; if any returns TEMPFAIL or ACCEPT then no further modules
 139 are tried.</p>
 140
 141 <p>So a typical example might look like this:</p>
 142 <pre>Apr 14 14:07:15 billdog authdaemond: received auth request, service=pop3, authtype=login
 143 Apr 14 14:07:15 billdog authdaemond: authcustom: trying this module
 144 Apr 14 14:07:15 billdog authdaemond: authcustom: nothing implemented in do_auth_custom()
 145 Apr 14 14:07:15 billdog authdaemond: authcustom: REJECT - try next module
 146 Apr 14 14:07:15 billdog authdaemond: authcram: trying this module
 147 Apr 14 14:07:15 billdog authdaemond: cram: only supports authtype=cram-*
 148 Apr 14 14:07:15 billdog authdaemond: authcram: REJECT - try next module
 149 Apr 14 14:07:15 billdog authdaemond: authuserdb: trying this module
 150 Apr 14 14:07:15 billdog authdaemond: userdb: opened /etc/userdb.dat
 151 Apr 14 14:07:15 billdog authdaemond: userdb: looking up 'brian'
 152 Apr 14 14:07:15 billdog authdaemond: userdb: entry not found
 153 Apr 14 14:07:15 billdog authdaemond: authuserdb: REJECT - try next module
 154 Apr 14 14:07:15 billdog authdaemond: authpam: trying this module
 155 Apr 14 14:07:15 billdog authdaemond: authpam: sysusername=brian, sysuserid=&lt;null&gt;, sysgroupid=1001, homedir=/home/brian, address=brian, fullname=Brian Candler, maildir=&lt;null&gt;, quota=&lt;null&gt;, options=&lt;null&gt;
 156 Apr 14 14:07:15 billdog authdaemond: pam_service=pop3, pam_username=brian
 157 Apr 14 14:07:15 billdog authdaemond: dopam successful
 158 Apr 14 14:07:15 billdog authdaemond: authpam: ACCEPT, username brian</pre>
 159
 160 <p>What's happening here?</p>
 161 <ul>
 162   <li>The request was received by 'authdaemond'</li>
 163   <li>It tries 'authcustom' - this module does nothing unless you have
 164     customised it yourself, so it REJECTs the request</li>
 165   <li>It tried 'authcram', but since this was a request with authtype=login
 166     (rather than authtype=cram-md5, say), this module cannot handle it so it
 167     REJECTs</li>
 168   <li>'authuserdb' has a go. In this case there is an /etc/userdb.dat file
 169     for it to look in, but the requested username 'brian' does not exist in
 170     there, so it REJECTs</li>
 171   <li>'authpam' has a go. It finds the username and home directory in
 172     /etc/passwd, and then calls the PAM subsystem to authenticate. The
 173     authentication is successful.</li>
 174 </ul>
 175
 176 <p>So, in principle, debugging is straightforward. Watch the modules operate,
 177 search for the one which you <i>think</i> should be authenticating the user,
 178 and if it is not, check for REJECT (user not known or password mismatch) or
 179 TEMPFAIL (internal error) status. Additional messages should indicate why
 180 this status was returned.</p>
 181
 182 <h2>4. Read the documentation</h2>
 183
 184 <p>Most of the configuration files like authldaprc, authmysql are well
 185 documented with comments.</p>
 186
 187 <p>For the nitty-gritty details of authentication modules, see <a
 188 href="http://www.courier-mta.org/authlib.html">man authlib</a>. There is
 189 probably a copy of this manpage installed on your system; if that command
 190 doesn't work, try one of these:</p>
 191 <pre># man -M @prefix@/man authlib
 192 or
 193 # cd /path/to/sources
 194 # cd authlib
 195 # nroff -mandoc authlib.7.in | less</pre>
 196
 197 <p>If you are using userdb authentication, you definitely need to read <a
 198 href="http://www.courier-mta.org/makeuserdb.html">man makeuserdb</a>, <a
 199 href="http://www.courier-mta.org/userdb.html">man userdb</a>, and <a
 200 href="http://www.courier-mta.org/userdbpw.html">man userdbpw</a>.</p>
 201
 202 <h2>5. Use the mailing list</h2>
 203
 204 <p>Please read through the common problems and solutions at the bottom of
 205 this document. The next thing to do, of course, is search the web to see if
 206 your particular problem has been seen before and solved. <a
 207 href="http://www.google.com">Google</a> is very good for this.</p>
 208
 209 <p>If you still cannot work out what the problem is, then you can ask on the
 210 <a
 211 href="http://lists.sourceforge.net/mailman/listinfo/courier-imap">courier-imap</a>
 212 or <a href="mailto:sqwebmail-subscribe@inter7.com">sqwebmail</a> mailing
 213 lists. But before you post, please gather together all the following
 214 information:</p>
 215 <ul>
 216   <li>The operating system and version you are running</li>
 217   <li>The version of courier-imap/sqwebmail you have installed</li>
 218   <li>The <code>./configure</code> command line you gave to build it</li>
 219   <li>If you didn't build it yourself, where you got the package from (and if
 220     possible, find out from the packager what options they used to build
 221   it)</li>
 222   <li>The versions of any other relevant software which you are linking
 223     against, e.g. vpopmail, openldap, mysql, pgsql</li>
 224   <li>The transcript of the 'telnet' session you used to test
 225   [courier-imap]</li>
 226   <li>The corresponding debug output which was generated for that session</li>
 227   <li>The contents of the 'pop3d' and 'imapd' configuration files
 228     [courier-imap]</li>
 229   <li>The contents of the any other relevant configuration files, e.g.
 230     authldaprc, authmysqlrc</li>
 231   <li>A copy of the database entry you are trying to authenticate against:
 232     e.g. the line from your userdb file, an LDAP entry, a row from your mysql
 233     table, the line in /etc/password, etc.</li>
 234 </ul>
 235
 236 <p>If you include all this, you are <i>much</i> more likely to get a helpful
 237 response.</p>
 238 <hr>
 239
 240 <h2>Frequently seen authentication problems and solutions</h2>
 241
 242 <p>See also the <a href="http://www.courier-mta.org/FAQ.html">Courier MTA
 243 FAQ</a></p>
 244
 245 <h3>I get intermittent authentication problems with vpopmail</h3>
 246
 247 <p>This is a known problem with vpopmail 5.2.1 and earlier. You need to
 248 upgrade to 5.2.2 or later, and then recompile courier-authlib.</p>
 249
 250 <h3>Compiling fails with "cannot find -lvpopmail"</h3>
 251
 252 <p>This is usually a permissions problem on the vpopmail library. Try:</p>
 253 <pre># chmod +rx /home/vpopmail /home/vpopmail/lib</pre>
 254 Alternatively, it might be a problem finding the vpopmail headers or library,
 255 in which case try:
 256 <pre># CPPFLAGS="-I/home/vpopmail/include"; export CPPFLAGS
 257 # LDFLAGS="-L/home/vpopmail/lib"; export LDFLAGS
 258 # ./configure ...</pre>
 259
 260 <h3>When I try to login with POP3 using telnet, the server disconnects
 261 immediately after the "PASS" command, without giving a -ERR response</h3>
 262
 263 <p>The reason for this error will probably be found in your mail logs.
 264 Usually it indicates either that the home directory does not exist (chdir
 265 failed), or the Maildir has not been created. See 'man maildirmake'.</p>
 266
 267 <h3>PAM authentication says "pam_start failed, result 4 [Hint: bad PAM
 268 configuration?]"</h3>
 269
 270 <p>Probably your PAM configuration is bad. If you have /etc/pam.d/other, then
 271 try simply removing /etc/pam.d/pop3 and /etc/pam.d/imap and see if it works
 272 (this is sufficient for FreeBSD). Otherwise, try copying one of your existing
 273 /etc/pam.d/xxx files to /etc/pam.d/pop3, imap or webmail respectively. <br>
 274 The result value is a PAM_XXXX constant from
 275 <code>/usr/include/security/pam_constants.h</code> (this file may be in a
 276 different location on your system). Under FreeBSD, 4 is PAM_SYSTEM_ERR.</p>
 277
 278 <h3>When I connect on the SSL ports (995 or 993), the server accepts the
 279 connection but then immediately disconnects</h3>
 280
 281 <p>You probably didn't install any SSL certificates. Courier-imap comes with
 282 scripts you can run to do this for you:</p>
 283 <pre># @prefix@/sbin/mkimapdcert
 284 # @prefix@/sbin/mkpop3dcert</pre>
 285
 286 <h3>I expected the authentication library to compile authmysql (or some other
 287 module), but it's not there</h3>
 288
 289 <p>If the mysql authentication module did not compile, then perhaps
 290 ./configure was unable to find your mysql libraries (you can read through the
 291 file 'config.log' in the source directory to see what it found). You may need
 292 to force it to look in the right place, as follows:</p>
 293 <pre># ./configure --with-authmsql --with-mysql-libs=/usr/local/mysql/lib  \
 294               --with-mysql-includes=/usr/local/mysql/include</pre>
 295
 296 <p>On some systems (e.g. FreeBSD), the mysqlclient library depends on the
 297 math and compression libraries. For these systems, try:</p>
 298 <pre># LDFLAGS="-lm -lz" ./configure --with-authmysql ... same as before</pre>
 299
 300 <h3>The POP3/IMAP server says "Temporary problem, please try again later"
 301 when a bad password is entered</h3>
 302
 303 <p><code>authdaemond</code> tries each of the configured authentication
 304 modules in turn, until either one accepts the login, or they have all
 305 rejected it (in which case the usual "Login failed" error is returned, and
 306 the user can try again).</p>
 307
 308 <p>However, if one of these modules is unable to run because some resource is
 309 not available, then it gives a "temporary failure" response and no further
 310 modules are tried. You should find the exact cause in your mail logs, but
 311 typically it means that you have a module like 'authmysql' in your module
 312 list, but the mysql database is not running.</p>
 313
 314 <p>So unless you actually do have account data in mysql (in which case you
 315 need to fix your mysql setup), you should remove 'authmysql' and any other
 316 modules you do not use from <code>authmodulelist</code> in
 317 <code>authdaemonrc</code>.</p>
 318 </body>
 319 </html>