Commit | Line | Data |
---|---|---|
8d138742 CE |
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"> | |
d9898ee8 | 5 | <head> |
8d138742 CE |
6 | <meta http-equiv="Content-Type" content="" /> |
7 | ||
d9898ee8 | 8 | <title>Debugging authentication problems</title> |
9 | </head> | |
10 | ||
11 | <body bgcolor="#FFFFFF"> | |
8d138742 CE |
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> | |
24 | DEBUG_LOGIN=1 # turn on authentication debugging | |
25 | DEBUG_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 -- | |
d9898ee8 | 73 | # telnet x.x.x.x 110 |
74 | user USERNAME | |
75 | pass PASSWORD | |
76 | stat | |
77 | quit | |
78 | ||
79 | -- to debug IMAP -- | |
80 | # telnet x.x.x.x 143 | |
81 | a login USERNAME PASSWORD | |
82 | a examine inbox | |
83 | a 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 | |
8d138742 CE |
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> | |
108 | Oct 17 11:25:37 commodore authdaemond: modules="authuserdb authpam authpgsql authldap authmysql authcustom", daemons=5 | |
d9898ee8 | 109 | Oct 17 11:25:37 commodore authdaemond: Installing libauthuserdb |
110 | Oct 17 11:25:37 commodore authdaemond: Installation complete: authuserdb | |
111 | Oct 17 11:25:37 commodore authdaemond: Installing libauthpam | |
112 | Oct 17 11:25:37 commodore authdaemond: Installation complete: authpam | |
113 | Oct 17 11:25:37 commodore authdaemond: Installing libauthpgsql | |
114 | Oct 17 11:25:37 commodore authdaemond: libauthpgsql.so: cannot open shared object file: No such file or directory | |
115 | Oct 17 11:25:37 commodore authdaemond: Installing libauthldap | |
116 | Oct 17 11:25:37 commodore authdaemond: libauthldap.so: cannot open shared object file: No such file or directory | |
117 | Oct 17 11:25:37 commodore authdaemond: Installing libauthmysql | |
118 | Oct 17 11:25:37 commodore authdaemond: libauthmysql.so: cannot open shared object file: No such file or directory | |
119 | Oct 17 11:25:37 commodore authdaemond: Installing libauthcustom | |
8d138742 CE |
120 | Oct 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 | ||
d9898ee8 | 146 | <dd>The user was authenticated successfully</dd> |
8d138742 CE |
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> | |
174 | Apr 14 14:07:15 billdog authdaemond: received auth request, service=pop3, authtype=login | |
d9898ee8 | 175 | Apr 14 14:07:15 billdog authdaemond: authcustom: trying this module |
176 | Apr 14 14:07:15 billdog authdaemond: authcustom: nothing implemented in do_auth_custom() | |
177 | Apr 14 14:07:15 billdog authdaemond: authcustom: REJECT - try next module | |
178 | Apr 14 14:07:15 billdog authdaemond: authcram: trying this module | |
179 | Apr 14 14:07:15 billdog authdaemond: cram: only supports authtype=cram-* | |
180 | Apr 14 14:07:15 billdog authdaemond: authcram: REJECT - try next module | |
181 | Apr 14 14:07:15 billdog authdaemond: authuserdb: trying this module | |
182 | Apr 14 14:07:15 billdog authdaemond: userdb: opened /etc/userdb.dat | |
183 | Apr 14 14:07:15 billdog authdaemond: userdb: looking up 'brian' | |
184 | Apr 14 14:07:15 billdog authdaemond: userdb: entry not found | |
185 | Apr 14 14:07:15 billdog authdaemond: authuserdb: REJECT - try next module | |
186 | Apr 14 14:07:15 billdog authdaemond: authpam: trying this module | |
187 | 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> | |
188 | Apr 14 14:07:15 billdog authdaemond: pam_service=pop3, pam_username=brian | |
189 | Apr 14 14:07:15 billdog authdaemond: dopam successful | |
8d138742 CE |
190 | Apr 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 | |
d9898ee8 | 233 | or |
234 | # cd /path/to/sources | |
235 | # cd authlib | |
8d138742 CE |
236 | # nroff -mandoc authlib.7.in | less |
237 | </pre> | |
238 | ||
239 | <p>If you are using userdb authentication, you definitely need to | |
b0322a85 CE |
240 | read <a href="makeuserdb.html">man makeuserdb</a>, <a href= |
241 | "userdb.html">man userdb</a>, and <a href="userdbpw.html">man | |
8d138742 CE |
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> | |
d9898ee8 | 369 | </body> |
370 | </html> |