Project

General

Profile

« Previous | Next » 

Revision 5157

Added by daigle over 14 years ago

Beefed up the logging

View differences:

src/edu/ucsb/nceas/metacat/AuthLdap.java
52 52
import edu.ucsb.nceas.metacat.properties.PropertyService;
53 53
import edu.ucsb.nceas.utilities.PropertyNotFoundException;
54 54

  
55
import java.io.IOException;
55 56
import java.lang.InstantiationException;
56 57
import java.net.URLDecoder;
57 58
import java.util.Iterator;
......
124 125
	 *            the password to use for authentication
125 126
	 * @returns boolean true if authentication successful, false otherwise
126 127
	 */
127

  
128 128
	public boolean authenticate(String user, String password) throws ConnectException {
129 129
		String ldapUrl = this.ldapUrl;
130 130
		String ldapsUrl = this.ldapsUrl;
......
140 140
		String uid = user.substring(0, user.indexOf(","));
141 141
		user = user.substring(user.indexOf(","), user.length());
142 142

  
143
		logMetacat.debug("identifier: " + identifier);
144
		logMetacat.debug("uid: " + uid);
145
		logMetacat.debug("user: " + user);
143
		logMetacat.debug("AuthLdap.authenticate - identifier: " + identifier + 
144
				", uid: " + uid +", user: " + user);
146 145

  
147 146
		try {
148 147
			// Check the usename as passed in
149
			logMetacat.info("Calling ldapAuthenticate");
150
			logMetacat.info("with user as identifier: " + identifier);
148
			logMetacat.info("AuthLdap.authenticate - Calling ldapAuthenticate" +
149
				" with user as identifier: " + identifier);
151 150

  
152 151
			authenticated = ldapAuthenticate(identifier, password, (new Boolean(
153 152
					PropertyService.getProperty("ldap.onlySecureConnection")))
154 153
					.booleanValue());
155 154
			// if not found, try looking up a valid DN then auth again
156 155
			if (!authenticated) {
157
				logMetacat.info("Not Authenticated");
158
				logMetacat.info("Looking up DN for: " + identifier);
156
				logMetacat.info("AuthLdap.authenticate - Not Authenticated");
157
				logMetacat.info("AuthLdap.authenticate - Looking up DN for: " + identifier);
159 158
				identifier = getIdentifyingName(identifier, ldapUrl, ldapBase);
160 159
				if (identifier == null) {
161
					logMetacat.info("No DN found from getIdentifyingName");
160
					logMetacat.info("AuthLdap.authenticate - No DN found from getIdentifyingName");
162 161
					return authenticated;
163 162
				}
164 163

  
165
				logMetacat.info("DN found from getIdentifyingName: " + identifier);
164
				logMetacat.info("AuthLdap.authenticate - DN found from getIdentifyingName: " + identifier);
166 165
				String decoded = URLDecoder.decode(identifier);
167
				logMetacat.info("DN decoded: " + decoded);
166
				logMetacat.info("AuthLdap.authenticate - DN decoded: " + decoded);
168 167
				identifier = decoded;
169 168
				String refUrl = "";
170 169
				String refBase = "";
171 170
				if (identifier.startsWith("ldap")) {
172
					logMetacat.debug("identifier starts with \"ldap\"");
171
					logMetacat.debug("AuthLdap.authenticate - identifier starts with \"ldap\"");
173 172

  
174 173
					refUrl = identifier.substring(0, identifier.lastIndexOf("/") + 1);
175 174
					int position = identifier.indexOf(",");
......
178 177
					refBase = identifier.substring(position2 + 1);
179 178
					identifier = identifier.substring(identifier.lastIndexOf("/") + 1);
180 179

  
181
					logMetacat.info("Calling ldapAuthenticate:");
182
					logMetacat.info("with user as identifier: " + identifier);
183
					logMetacat.info("and refUrl as: " + refUrl);
184
					logMetacat.info("and refBase as: " + refBase);
180
					logMetacat.info("AuthLdap.authenticate - Calling ldapAuthenticate: " +
181
						"with user as identifier: " + identifier + " and refUrl as: " + 
182
						refUrl + " and refBase as: " + refBase);
185 183

  
186 184
					authenticated = ldapAuthenticate(identifier, password, refUrl,
187 185
							refBase, (new Boolean(PropertyService
188 186
									.getProperty("ldap.onlySecureReferalsConnection")))
189 187
									.booleanValue());
190 188
				} else {
191
					logMetacat.info("identifier doesnt start with ldap");
189
					logMetacat.info("AuthLdap.authenticate - identifier doesnt start with ldap");
192 190
					identifier = identifier + "," + ldapBase;
193 191

  
194
					logMetacat.info("Calling ldapAuthenticate");
195
					logMetacat.info("with user as identifier: " + identifier);
192
					logMetacat.info("AuthLdap.authenticate - Calling ldapAuthenticate" + 
193
							"with user as identifier: " + identifier);
196 194

  
197 195
					authenticated = ldapAuthenticate(identifier, password, (new Boolean(
198 196
							PropertyService.getProperty("ldap.onlySecureConnection")))
199 197
							.booleanValue());
200 198
				}
201 199
			}
202
		} catch (NullPointerException e) {
203
			logMetacat.error("NullPointerException while authenticating in "
204
					+ "AuthLdap.authenticate: " + e);
205
			e.printStackTrace();
200
		} catch (NullPointerException npe) {
201
			logMetacat.error("AuthLdap.authenticate - NullPointerException while authenticating in "
202
					+ "AuthLdap.authenticate: " + npe);
203
			npe.printStackTrace();
206 204

  
207
			throw new ConnectException("NullPointerException while authenticating in "
208
					+ "AuthLdap.authenticate: " + e);
209
		} catch (NamingException e) {
210
			logMetacat.error("Naming exception while authenticating in "
211
					+ "AuthLdap.authenticate: " + e);
212
			e.printStackTrace();
213
		} catch (Exception e) {
214
			logMetacat.error(e.getMessage());
205
			throw new ConnectException("AuthLdap.authenticate - NullPointerException while authenticating in "
206
					+ "AuthLdap.authenticate: " + npe);
207
		} catch (NamingException ne) {
208
			logMetacat.error("AuthLdap.authenticate - Naming exception while authenticating in "
209
					+ "AuthLdap.authenticate: " + ne);
210
			ne.printStackTrace();
211
		} catch (PropertyNotFoundException pnfe) {
212
			logMetacat.error("AuthLdap.authenticate - Property exception while authenticating in "
213
					+ "AuthLdap.authenticate: " + pnfe.getMessage());
215 214
		}
216 215

  
217 216
		return authenticated;
......
250 249

  
251 250
		String server = "";
252 251
		String userDN = "";
253
		logMetacat.info("dn is: " + dn);
252
		logMetacat.info("AuthLdap.ldapAuthenticate - dn is: " + dn);
254 253

  
255 254
		int position = dn.lastIndexOf("/");
256
		logMetacat.debug("position is: " + position);
255
		logMetacat.debug("AuthLdap.ldapAuthenticate - position is: " + position);
257 256
		if (position == -1) {
258 257
			server = rootServer;
259 258
			if (dn.indexOf(userDN) < 0) {
......
261 260
			} else {
262 261
				userDN = dn;
263 262
			}
264
			logMetacat.info("userDN is: " + userDN);
263
			logMetacat.info("AuthLdap.ldapAuthenticate - userDN is: " + userDN);
265 264

  
266 265
		} else {
267 266
			server = dn.substring(0, position + 1);
268 267
			userDN = dn.substring(position + 1);
269
			logMetacat.info("server is: " + server);
270
			logMetacat.info("userDN is: " + userDN);
268
			logMetacat.info("AuthLdap.ldapAuthenticate - server is: " + server);
269
			logMetacat.info("AuthLdap.ldapAuthenticate - userDN is: " + userDN);
271 270
		}
272 271

  
273
		logMetacat.warn("Trying to authenticate: " + userDN);
274
		logMetacat.warn("          Using server: " + server);
272
		logMetacat.warn("AuthLdap.ldapAuthenticate - Trying to authenticate: " + 
273
				userDN + " Using server: " + server);
275 274

  
276 275
		LdapContext ctx = null;
277 276
		double startTime;
......
296 295
				ctx.addToEnvironment(Context.SECURITY_CREDENTIALS, password);
297 296
				ctx.reconnect(null);
298 297
				stopTime = System.currentTimeMillis();
299
				logMetacat.info("Connection time thru " + ldapsUrl + " was: "
298
				logMetacat.info("AuthLdap.ldapAuthenticate - Connection time thru " + ldapsUrl + " was: "
300 299
						+ (stopTime - startTime) / 1000 + " seconds.");
301 300
				authenticated = true;
302
			} catch (Exception ioe) {
303
				logMetacat.info("Caught IOException in login while negotiating TLS: "
301
			} catch (IOException ioe) {
302
				logMetacat.info("AuthLdap.ldapAuthenticate - Caught IOException in login while negotiating TLS: "
304 303
						+ ioe.getMessage());
305 304

  
306 305
				if (secureConnectionOnly) {
307 306
					return authenticated;
308 307

  
309 308
				} else {
310
					logMetacat.info("Trying to authenticate without TLS");
309
					logMetacat.info("AuthLdap.ldapAuthenticate - Trying to authenticate without TLS");
311 310
					env.put(Context.SECURITY_AUTHENTICATION, "simple");
312 311
					env.put(Context.SECURITY_PRINCIPAL, userDN);
313 312
					env.put(Context.SECURITY_CREDENTIALS, password);
......
315 314
					startTime = System.currentTimeMillis();
316 315
					ctx = new InitialLdapContext(env, null);
317 316
					stopTime = System.currentTimeMillis();
318
					logMetacat.info("Connection time thru " + ldapsUrl + " was: "
317
					logMetacat.info("AuthLdap.ldapAuthenticate - Connection time thru " + ldapsUrl + " was: "
319 318
							+ (stopTime - startTime) / 1000 + " seconds.");
320 319
					authenticated = true;
321 320
				}
322 321
			}
323 322
		} catch (AuthenticationException ae) {
323
			logMetacat.warn("Authentication exception: " + ae.getMessage());
324 324
			authenticated = false;
325 325
		} catch (javax.naming.InvalidNameException ine) {
326
			logMetacat.error("An invalid DN was provided!");
327
		} catch (NamingException e) {
328
			logMetacat.warn("Caught NamingException in login: " + e.getClass().getName());
329
			logMetacat.info(e.toString() + "  " + e.getRootCause());
326
			logMetacat.error("AuthLdap.ldapAuthenticate - An invalid DN was provided: " + ine.getMessage());
327
		} catch (NamingException ne) {
328
			logMetacat.warn("AuthLdap.ldapAuthenticate - Caught NamingException in login: " + ne.getClass().getName());
329
			logMetacat.info(ne.toString() + "  " + ne.getRootCause());
330 330
		}
331 331

  
332 332
		return authenticated;
......
963 963
	 */
964 964
	private Hashtable getSubtrees(String user, String password, String ldapUrl,
965 965
			String ldapBase) throws ConnectException {
966
		logMetacat.debug("AuthLdap.getSubtrees - getting subtrees for user: " + user + 
967
				", ldapUrl: " + ldapUrl + ", ldapBase: " + ldapBase);
966 968
		Hashtable trees = new Hashtable();
967 969

  
968 970
		// Identify service provider to use
......
1000 1002
			while (namingEnum.hasMore()) {
1001 1003

  
1002 1004
				SearchResult sr = (SearchResult) namingEnum.next();
1005
				logMetacat.debug("AuthLdap.getSubtrees - search result: " + sr.toString());
1003 1006

  
1004 1007
				Attributes attrs = sr.getAttributes();
1005 1008
				NamingEnumeration enum1 = attrs.getAll(); // "dc" and "ref"
......
1019 1022
									.lastIndexOf("/") + 1));
1020 1023
						} else {
1021 1024
							// this is a referral - so organization name is
1022
							// appended in
1023
							// front of the ldapbase.... later it is stripped
1024
							// out
1025
							// in getPrincipals
1026
							trees.put("["
1027
									+ refName
1028
									+ "="
1029
									+ refValue
1030
									+ "]"
1031
									+ attrValue.substring(attrValue.lastIndexOf("/") + 1,
1025
							// appended in front of the ldapbase.... later it is 
1026
							// stripped out in getPrincipals
1027
							trees.put("[" + refName + "=" + refValue + "]" + 
1028
									attrValue.substring(attrValue.lastIndexOf("/") + 1,
1032 1029
											attrValue.length()), attrValue.substring(0,
1033
									attrValue.lastIndexOf("/") + 1));
1030
													attrValue.lastIndexOf("/") + 1));
1034 1031

  
1035 1032
							// trees.put(refName + "=" + refValue + "," +
1036
							// ldapBase,
1037
							// attrValue.substring(0, attrValue.lastIndexOf("/")
1033
							// ldapBase, attrValue.substring(0, attrValue.lastIndexOf("/")
1038 1034
							// + 1));
1039 1035
						}
1040 1036

  
......
1060 1056
			ctx.close();
1061 1057

  
1062 1058
		} catch (NamingException e) {
1063
			logMetacat.error("Problem getting subtrees in AuthLdap.getSubtrees:" + e);
1059
			logMetacat.error("AuthLdap.getSubtrees - Problem getting subtrees in AuthLdap.getSubtrees:" + e);
1064 1060
			throw new ConnectException(
1065 1061
					"Problem getting subtrees in AuthLdap.getSubtrees:" + e);
1066 1062
		}
......
1093 1089
		while (keyEnum.hasMoreElements()) {
1094 1090
			this.ldapBase = (String) keyEnum.nextElement();
1095 1091
			this.ldapUrl = (String) subtrees.get(ldapBase);
1096
			logMetacat.info("ldapBase " + ldapBase);
1097
			logMetacat.info("ldapUrl " + ldapUrl);
1092
			logMetacat.info("AuthLdap.getPrincipals - ldapBase: " + ldapBase + 
1093
					", ldapUrl: " + ldapUrl);
1098 1094
			/*
1099 1095
			 * code to get the organization name from ldapBase
1100 1096
			 */
1101 1097
			String orgName = this.ldapBase;
1102 1098
			if (orgName.startsWith("[")) {
1103 1099
				// if orgName starts with [ then it is a referral URL...
1104
				// (see code in getSubtress)
1105
				// hence orgName can be retrieved by getting the string between
1106
				// 'o=' and ']'
1107
				// also the string between [ and ] needs to be striped out from
1108
				// this.ldapBase
1100
				// (see code in getSubtress) hence orgName can be retrieved by 
1101
				// getting the string between 'o=' and ']' also the string between 
1102
				// [ and ] needs to be striped out from this.ldapBase
1109 1103
				this.ldapBase = orgName.substring(orgName.indexOf("]") + 1);
1110 1104
				if (orgName != null && orgName.indexOf("o=") > -1) {
1111 1105
					orgName = orgName.substring(orgName.indexOf("o=") + 2);
......
1122 1116
					}
1123 1117
				}
1124 1118
			}
1125
			logMetacat.info("org name is  " + orgName);
1119
			logMetacat.info("AuthLdap.getPrincipals - org name is  " + orgName);
1126 1120
			out.append("  <authSystem URI=\"" + this.ldapUrl + this.ldapBase
1127 1121
					+ "\" organization=\"" + orgName + "\">\n");
1128 1122

  
1129 1123
			// get all groups for directory context
1130 1124
			String[][] groups = getGroups(user, password);
1131
			logMetacat.debug("after getting groups " + groups);
1125
			logMetacat.debug("AuthLdap.getPrincipals - after getting groups " + groups);
1132 1126
			String[][] users = getUsers(user, password);
1133
			logMetacat.debug("after getting users " + users);
1127
			logMetacat.debug("AuthLdap.getPrincipals - after getting users " + users);
1134 1128
			int userIndex = 0;
1135 1129

  
1136 1130
			// for the groups and users that belong to them

Also available in: Unified diff