d9898ee8 |
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> |