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