| 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 >filename |
| 44 | 2>&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=<null>, sysgroupid=1001, homedir=/home/brian, address=brian, fullname=Brian Candler, maildir=<null>, quota=<null>, options=<null> |
| 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> |