diff --git a/conf/log4j.properties b/conf/log4j.properties index 4a2ede95503..c938a2b7e28 100644 --- a/conf/log4j.properties +++ b/conf/log4j.properties @@ -63,3 +63,20 @@ log4j.appender.TRACEFILE.File=${zookeeper.tracelog.dir}/${zookeeper.tracelog.fil log4j.appender.TRACEFILE.layout=org.apache.log4j.PatternLayout ### Notice we are including log4j's NDC here (%x) log4j.appender.TRACEFILE.layout.ConversionPattern=%d{ISO8601} [myid:%X{myid}] - %-5p [%t:%C{1}@%L][%x] - %m%n +# +# zk audit logging +# +zookeeper.auditlog.file=zookeeper_audit.log +zookeeper.auditlog.threshold=INFO +audit.logger=INFO, RFAAUDIT +log4j.logger.org.apache.zookeeper.audit.ZKAuditLogger=${audit.logger} +log4j.additivity.org.apache.zookeeper.audit.ZKAuditLogger=false +log4j.appender.RFAAUDIT=org.apache.log4j.RollingFileAppender +log4j.appender.RFAAUDIT.File=${zookeeper.log.dir}/${zookeeper.auditlog.file} +log4j.appender.RFAAUDIT.layout=org.apache.log4j.PatternLayout +log4j.appender.RFAAUDIT.layout.ConversionPattern=%d{ISO8601} %p %c{2}: %m%n +log4j.appender.RFAAUDIT.Threshold=${zookeeper.auditlog.threshold} + +# Max log file size of 10MB +log4j.appender.RFAAUDIT.MaxFileSize=10MB +log4j.appender.RFAAUDIT.MaxBackupIndex=10 diff --git a/src/java/main/org/apache/zookeeper/Login.java b/src/java/main/org/apache/zookeeper/Login.java index d97d6c1fde4..4b81e2c0327 100644 --- a/src/java/main/org/apache/zookeeper/Login.java +++ b/src/java/main/org/apache/zookeeper/Login.java @@ -286,6 +286,13 @@ public Subject getSubject() { return subject; } + public String getUserName() { + if (principal == null || principal.isEmpty()) { + return System.getProperty("user.name", ""); + } + return principal; + } + public String getLoginContextName() { return loginContextName; } diff --git a/src/java/main/org/apache/zookeeper/ZKUtil.java b/src/java/main/org/apache/zookeeper/ZKUtil.java index a6abf2f42e1..dfbfddb1b32 100644 --- a/src/java/main/org/apache/zookeeper/ZKUtil.java +++ b/src/java/main/org/apache/zookeeper/ZKUtil.java @@ -20,18 +20,22 @@ import java.util.ArrayList; import java.util.Collections; import java.util.Deque; +import java.util.HashMap; import java.util.LinkedList; import java.util.List; +import java.util.Map; import org.apache.zookeeper.AsyncCallback.StringCallback; import org.apache.zookeeper.AsyncCallback.VoidCallback; import org.apache.zookeeper.KeeperException.Code; import org.apache.zookeeper.common.PathUtils; +import org.apache.zookeeper.data.ACL; import org.slf4j.Logger; import org.slf4j.LoggerFactory; public class ZKUtil { private static final Logger LOG = LoggerFactory.getLogger(ZKUtil.class); + private static final Map permCache = new HashMap(); /** * Recursively delete the node with the given path. *

@@ -168,4 +172,53 @@ private static void visitSubTreeDFSHelper(ZooKeeper zk, final String path, return; // ignore } } + + /** + * @param perms + * ACL permissions + * @return string representation of permissions + */ + public static String getPermString(int perms) { + String permString = permCache.get(perms); + if (permString != null) { + return permString; + } + permString = constructPermString(perms); + if (!permString.isEmpty()) { + permCache.put(perms, permString); + } + return permString; + } + + private static String constructPermString(int perms) { + StringBuilder p = new StringBuilder(); + if ((perms & ZooDefs.Perms.CREATE) != 0) { + p.append('c'); + } + if ((perms & ZooDefs.Perms.DELETE) != 0) { + p.append('d'); + } + if ((perms & ZooDefs.Perms.READ) != 0) { + p.append('r'); + } + if ((perms & ZooDefs.Perms.WRITE) != 0) { + p.append('w'); + } + if ((perms & ZooDefs.Perms.ADMIN) != 0) { + p.append('a'); + } + return p.toString(); + } + + public static String aclToString(List acls) { + StringBuilder sb = new StringBuilder(); + for (ACL acl : acls) { + sb.append(acl.getId().getScheme()); + sb.append(":"); + sb.append(acl.getId().getId()); + sb.append(":"); + sb.append(getPermString(acl.getPerms())); + } + return sb.toString(); + } } \ No newline at end of file diff --git a/src/java/main/org/apache/zookeeper/audit/AuditConstants.java b/src/java/main/org/apache/zookeeper/audit/AuditConstants.java new file mode 100644 index 00000000000..63c15d511cd --- /dev/null +++ b/src/java/main/org/apache/zookeeper/audit/AuditConstants.java @@ -0,0 +1,37 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.zookeeper.audit; + +public class AuditConstants { + public static final String SUCCESS = "success"; + public static final String FAILURE = "failure"; + // operation is performed, result is not known yet + public static final String INVOKED = "invoked"; + public static final String KEY_VAL_SEPARATOR = "="; + public static final char PAIR_SEPARATOR = '\t'; + + public static final String OP_START = "serverStart"; + public static final String OP_STOP = "serverStop"; + public static final String OP_CREATE = "create"; + public static final String OP_DELETE = "delete"; + public static final String OP_SETDATA = "setData"; + public static final String OP_SETACL = "setAcl"; + public static final String OP_MULTI_OP = "multiOperation"; + public static final String OP_RECONFIG = "reconfig"; + public static final String OP_DEL_EZNODE_EXP = "ephemeralZNodeDeletionOnSessionCloseOrExpire"; +} diff --git a/src/java/main/org/apache/zookeeper/audit/ZKAuditLogFormatter.java b/src/java/main/org/apache/zookeeper/audit/ZKAuditLogFormatter.java new file mode 100644 index 00000000000..c81cb4be5b2 --- /dev/null +++ b/src/java/main/org/apache/zookeeper/audit/ZKAuditLogFormatter.java @@ -0,0 +1,56 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.zookeeper.audit; + +import java.util.LinkedHashMap; +import java.util.Map; +import java.util.Map.Entry; + +public class ZKAuditLogFormatter { + private Map fieldVsValue = new LinkedHashMap(); + + /** + * Add fields to be logged + */ + public void addField(String key, String value) { + fieldVsValue.put(key, value); + } + + /** + * Gives the string to be logged, ignores fields with null values + */ + public String format() { + StringBuilder buffer = new StringBuilder(); + boolean first = true; + for (Entry entry : fieldVsValue.entrySet()) { + String key = entry.getKey(); + String value = entry.getValue(); + if (null != value) { + // if first field then no need to add the tabs + if (first) { + first = false; + } else { + buffer.append(AuditConstants.PAIR_SEPARATOR); + } + buffer.append(key.toLowerCase()).append(AuditConstants.KEY_VAL_SEPARATOR) + .append(value); + } + } + return buffer.toString(); + } +} diff --git a/src/java/main/org/apache/zookeeper/audit/ZKAuditLogger.java b/src/java/main/org/apache/zookeeper/audit/ZKAuditLogger.java new file mode 100644 index 00000000000..959015e2a2a --- /dev/null +++ b/src/java/main/org/apache/zookeeper/audit/ZKAuditLogger.java @@ -0,0 +1,133 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.zookeeper.audit; + +import org.apache.zookeeper.server.ServerCnxnFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public class ZKAuditLogger { + public static final String SYSPROP_AUDIT_ENABLE = "zookeeper.audit.enable"; + private static final Logger LOG = LoggerFactory.getLogger(ZKAuditLogger.class); + // By default audit logging is disabled + private static boolean auditEnabled = Boolean.getBoolean(SYSPROP_AUDIT_ENABLE); + + /** + * @return true if audit log is enabled + */ + public static boolean isAuditEnabled() { + return auditEnabled; + } + + // @VisisbleForTesting + public static void setAuditEnabled(boolean auditEnabled) { + ZKAuditLogger.auditEnabled = auditEnabled; + } + + /** + * + * Prints audit log based on log level specified + * + */ + public static enum LogLevel { + ERROR { + @Override + public void printLog(String logMsg) { + LOG.error(logMsg); + } + }, + INFO { + @Override + public void printLog(String logMsg) { + LOG.info(logMsg); + } + }; + public abstract void printLog(String logMsg); + } + + public static enum Keys { + USER, OPERATION, RESULT, IP, ACL, ZNODE, SESSION; + } + + public static void logInvoked(String user, String operation) { + log(LogLevel.INFO, user, operation, AuditConstants.INVOKED); + } + + public static void logSuccess(String user, String operation) { + log(LogLevel.INFO, user, operation, AuditConstants.SUCCESS); + } + + public static void logFailure(String user, String operation) { + log(LogLevel.ERROR, user, operation, AuditConstants.FAILURE); + } + + private static void log(LogLevel level, String user, String operation, String logType) { + level.printLog(createLog(user, operation, null, null, null, null, logType)); + } + + public static void logSuccess(String user, String operation, String znode, String acl, + String session, String ip) { + LogLevel.INFO.printLog( + createLog(user, operation, znode, acl, session, ip, AuditConstants.SUCCESS)); + } + + public static void logFailure(String user, String operation, String znode, String acl, + String session, String ip) { + LogLevel.ERROR.printLog( + createLog(user, operation, znode, acl, session, ip, AuditConstants.FAILURE)); + } + + /** + * A helper api for creating an audit log string. + */ + public static String createLog(String user, String operation, String znode, String acl, + String session, String ip, String status) { + ZKAuditLogFormatter fmt = new ZKAuditLogFormatter(); + fmt.addField(Keys.SESSION.name(), session); + fmt.addField(Keys.USER.name(), user); + fmt.addField(Keys.IP.name(), ip); + fmt.addField(Keys.OPERATION.name(), operation); + fmt.addField(Keys.ZNODE.name(), znode); + fmt.addField(Keys.ACL.name(), acl); + fmt.addField(Keys.RESULT.name(), status); + return fmt.format(); + } + + /** + * add audit log for server start and register server stop log + */ + public static void addZKStartStopAuditLog() { + if (isAuditEnabled()) { + ZKAuditLogger.logSuccess(getZKUser(), AuditConstants.OP_START); + Runtime.getRuntime().addShutdownHook(new Thread() { + @Override + public void run() { + ZKAuditLogger.logInvoked(getZKUser(), AuditConstants.OP_STOP); + } + }); + } + } + + /** + * User who has started the ZooKeeper server user, it will be the logged-in + * user. If no user logged-in then system user + */ + public static String getZKUser() { + return ServerCnxnFactory.getUserName(); + } +} diff --git a/src/java/main/org/apache/zookeeper/cli/GetAclCommand.java b/src/java/main/org/apache/zookeeper/cli/GetAclCommand.java index b5feb60794d..1289e549990 100644 --- a/src/java/main/org/apache/zookeeper/cli/GetAclCommand.java +++ b/src/java/main/org/apache/zookeeper/cli/GetAclCommand.java @@ -23,7 +23,7 @@ import org.apache.commons.cli.Parser; import org.apache.commons.cli.PosixParser; import org.apache.zookeeper.KeeperException; -import org.apache.zookeeper.ZooDefs; +import org.apache.zookeeper.ZKUtil; import org.apache.zookeeper.data.ACL; import org.apache.zookeeper.data.Stat; @@ -75,7 +75,7 @@ public boolean exec() throws CliException { for (ACL a : acl) { out.println(a.getId() + ": " - + getPermString(a.getPerms())); + + ZKUtil.getPermString(a.getPerms())); } if (cl.hasOption("s")) { @@ -83,24 +83,4 @@ public boolean exec() throws CliException { } return false; } - - private static String getPermString(int perms) { - StringBuilder p = new StringBuilder(); - if ((perms & ZooDefs.Perms.CREATE) != 0) { - p.append('c'); - } - if ((perms & ZooDefs.Perms.DELETE) != 0) { - p.append('d'); - } - if ((perms & ZooDefs.Perms.READ) != 0) { - p.append('r'); - } - if ((perms & ZooDefs.Perms.WRITE) != 0) { - p.append('w'); - } - if ((perms & ZooDefs.Perms.ADMIN) != 0) { - p.append('a'); - } - return p.toString(); - } } diff --git a/src/java/main/org/apache/zookeeper/server/DataTree.java b/src/java/main/org/apache/zookeeper/server/DataTree.java index f17be307d30..3e829d79423 100644 --- a/src/java/main/org/apache/zookeeper/server/DataTree.java +++ b/src/java/main/org/apache/zookeeper/server/DataTree.java @@ -35,6 +35,8 @@ import org.apache.zookeeper.Watcher.WatcherType; import org.apache.zookeeper.ZooDefs; import org.apache.zookeeper.ZooDefs.OpCode; +import org.apache.zookeeper.audit.AuditConstants; +import org.apache.zookeeper.audit.ZKAuditLogger; import org.apache.zookeeper.common.PathTrie; import org.apache.zookeeper.data.ACL; import org.apache.zookeeper.data.Stat; @@ -1005,8 +1007,10 @@ void killSession(long session, long zxid) { HashSet list = ephemerals.remove(session); if (list != null) { for (String path : list) { + boolean deleted = false; try { deleteNode(path, zxid); + deleted = true; if (LOG.isDebugEnabled()) { LOG .debug("Deleting ephemeral node " + path @@ -1018,6 +1022,20 @@ void killSession(long session, long zxid) { + " while removing ephemeral for dead session 0x" + Long.toHexString(session)); } + String sessionHex = "0x" + Long.toHexString(session); + if (deleted) { + if (ZKAuditLogger.isAuditEnabled()) { + ZKAuditLogger.logSuccess(ZKAuditLogger.getZKUser(), + AuditConstants.OP_DEL_EZNODE_EXP, path, null, + sessionHex, null); + } + } else { + if (ZKAuditLogger.isAuditEnabled()) { + ZKAuditLogger.logFailure(ZKAuditLogger.getZKUser(), + AuditConstants.OP_DEL_EZNODE_EXP, path, null, + sessionHex, null); + } + } } } } diff --git a/src/java/main/org/apache/zookeeper/server/FinalRequestProcessor.java b/src/java/main/org/apache/zookeeper/server/FinalRequestProcessor.java index 345184c6236..3580939f414 100644 --- a/src/java/main/org/apache/zookeeper/server/FinalRequestProcessor.java +++ b/src/java/main/org/apache/zookeeper/server/FinalRequestProcessor.java @@ -30,14 +30,19 @@ import org.apache.zookeeper.OpResult.ErrorResult; import org.apache.zookeeper.OpResult.SetDataResult; import org.apache.zookeeper.Watcher.WatcherType; +import org.apache.zookeeper.ZKUtil; import org.apache.zookeeper.ZooDefs; import org.apache.zookeeper.ZooDefs.OpCode; +import org.apache.zookeeper.audit.AuditConstants; +import org.apache.zookeeper.audit.ZKAuditLogger; import org.apache.zookeeper.common.Time; import org.apache.zookeeper.data.ACL; import org.apache.zookeeper.data.Stat; import org.apache.zookeeper.proto.CheckWatchesRequest; import org.apache.zookeeper.proto.Create2Response; +import org.apache.zookeeper.proto.CreateRequest; import org.apache.zookeeper.proto.CreateResponse; +import org.apache.zookeeper.proto.DeleteRequest; import org.apache.zookeeper.proto.ExistsRequest; import org.apache.zookeeper.proto.ExistsResponse; import org.apache.zookeeper.proto.GetACLRequest; @@ -50,7 +55,9 @@ import org.apache.zookeeper.proto.GetDataResponse; import org.apache.zookeeper.proto.RemoveWatchesRequest; import org.apache.zookeeper.proto.ReplyHeader; +import org.apache.zookeeper.proto.SetACLRequest; import org.apache.zookeeper.proto.SetACLResponse; +import org.apache.zookeeper.proto.SetDataRequest; import org.apache.zookeeper.proto.SetDataResponse; import org.apache.zookeeper.proto.SetWatches; import org.apache.zookeeper.proto.SyncRequest; @@ -154,6 +161,7 @@ public void processRequest(Request request) { Record rsp = null; try { if (request.getHdr() != null && request.getHdr().getType() == OpCode.error) { + addFailedTxnAuditLog(request); /* * When local session upgrading is disabled, leader will * reject the ephemeral node creation due to session expire. @@ -202,7 +210,7 @@ public void processRequest(Request request) { case OpCode.multi: { lastOp = "MULT"; rsp = new MultiResponse() ; - + boolean multiFailed = false; for (ProcessTxnResult subTxnResult : rc.multiResult) { OpResult subResult ; @@ -213,35 +221,44 @@ public void processRequest(Request request) { break; case OpCode.create: subResult = new CreateResult(subTxnResult.path); + addSuccessAudit(request, cnxn, AuditConstants.OP_CREATE, subTxnResult.path); break; case OpCode.create2: case OpCode.createTTL: case OpCode.createContainer: subResult = new CreateResult(subTxnResult.path, subTxnResult.stat); + addSuccessAudit(request, cnxn, AuditConstants.OP_CREATE, subTxnResult.path); break; case OpCode.delete: case OpCode.deleteContainer: subResult = new DeleteResult(); + addSuccessAudit(request, cnxn, AuditConstants.OP_DELETE, subTxnResult.path); break; case OpCode.setData: subResult = new SetDataResult(subTxnResult.stat); + addSuccessAudit(request, cnxn, AuditConstants.OP_SETDATA, subTxnResult.path); break; case OpCode.error: subResult = new ErrorResult(subTxnResult.err) ; + multiFailed = true; break; default: + multiFailed = true; throw new IOException("Invalid type of op"); } ((MultiResponse)rsp).add(subResult); } - + if (multiFailed) { + addFailureAudit(request, cnxn, AuditConstants.OP_MULTI_OP, null); + } break; } case OpCode.create: { lastOp = "CREA"; rsp = new CreateResponse(rc.path); err = Code.get(rc.err); + addAuditLog(request, cnxn, AuditConstants.OP_CREATE, rc.path, null, err); break; } case OpCode.create2: @@ -250,30 +267,38 @@ public void processRequest(Request request) { lastOp = "CREA"; rsp = new Create2Response(rc.path, rc.stat); err = Code.get(rc.err); + addAuditLog(request, cnxn, AuditConstants.OP_CREATE, rc.path, null, err); break; } case OpCode.delete: case OpCode.deleteContainer: { lastOp = "DELE"; err = Code.get(rc.err); + addAuditLog(request, cnxn, AuditConstants.OP_DELETE, rc.path, null, err); break; } case OpCode.setData: { lastOp = "SETD"; rsp = new SetDataResponse(rc.stat); err = Code.get(rc.err); + addAuditLog(request, cnxn, AuditConstants.OP_SETDATA, rc.path, null, err); break; } case OpCode.reconfig: { lastOp = "RECO"; rsp = new GetDataResponse(((QuorumZooKeeperServer)zks).self.getQuorumVerifier().toString().getBytes(), rc.stat); err = Code.get(rc.err); + addAuditLog(request, cnxn, AuditConstants.OP_RECONFIG, rc.path, null, err); break; } case OpCode.setACL: { lastOp = "SETA"; rsp = new SetACLResponse(rc.stat); err = Code.get(rc.err); + /** Here audit enable check is done to avoid getACLs() call in case audit is disabled. */ + if (ZKAuditLogger.isAuditEnabled()) { + addAuditLog(request, cnxn, AuditConstants.OP_SETACL, rc.path, getACLs(request), err); + } break; } case OpCode.closeSession: { @@ -481,4 +506,134 @@ public void shutdown() { LOG.info("shutdown of request processor complete"); } + private void addSuccessAudit(Request request, ServerCnxn cnxn, String op, + String path) { + addSuccessAudit(request, cnxn, op, path, null); + } + + private void addSuccessAudit(Request request, ServerCnxn cnxn, String op, + String path, + String acl) { + if (!ZKAuditLogger.isAuditEnabled()) { + return; + } + ZKAuditLogger.logSuccess(request.getUsers(), op, path, acl, + cnxn.getSessionIdHex(), + cnxn.getHostAddress()); + } + + private void addFailureAudit(Request request, ServerCnxn cnxn, String op, + String path) { + addFailureAudit(request, cnxn, op, path, null); + } + + private void addFailureAudit(Request request, ServerCnxn cnxn, String op, + String path, + String acl) { + if (!ZKAuditLogger.isAuditEnabled()) { + return; + } + ZKAuditLogger.logFailure(request.getUsers(), op, path, acl, + cnxn.getSessionIdHex(), + cnxn.getHostAddress()); + } + + private void addAuditLog(Request request, ServerCnxn cnxn, String op, + String path, String acl, + Code err) { + if (!ZKAuditLogger.isAuditEnabled()) { + return; + } + if (err == Code.OK) { + ZKAuditLogger.logSuccess(request.getUsers(), op, path, acl, + cnxn.getSessionIdHex(), + cnxn.getHostAddress()); + } else { + ZKAuditLogger.logFailure(request.getUsers(), op, path, acl, + cnxn.getSessionIdHex(), + cnxn.getHostAddress()); + } + } + + private String getACLs(Request request) { + ByteBuffer reqData = request.request.duplicate(); + reqData.rewind(); + SetACLRequest setACLRequest = new SetACLRequest(); + try { + ByteBufferInputStream.byteBuffer2Record(reqData, setACLRequest); + } catch (IOException e) { + e.printStackTrace(); + } + return ZKUtil.aclToString(setACLRequest.getAcl()); + } + + private void addFailedTxnAuditLog(Request request) { + if (!ZKAuditLogger.isAuditEnabled()) { + return; + } + String op = AuditConstants.OP_CREATE; + String path = null; + long sessionId = -1; + String address = null; + String acls = null; + ByteBuffer reqData = request.request.duplicate(); + reqData.rewind(); + try { + sessionId = request.cnxn.getSessionId(); + switch (request.type) { + case OpCode.create: + case OpCode.create2: + case OpCode.createContainer: + op = AuditConstants.OP_CREATE; + CreateRequest createRequest = new CreateRequest(); + ByteBufferInputStream.byteBuffer2Record(reqData, createRequest); + path = createRequest.getPath(); + break; + case OpCode.delete: + case OpCode.deleteContainer: + op = AuditConstants.OP_DELETE; + DeleteRequest deleteRequest = new DeleteRequest(); + ByteBufferInputStream.byteBuffer2Record(reqData, deleteRequest); + path = deleteRequest.getPath(); + break; + case OpCode.setData: + op = AuditConstants.OP_SETDATA; + SetDataRequest setDataRequest = new SetDataRequest(); + ByteBufferInputStream.byteBuffer2Record(reqData, + setDataRequest); + path = setDataRequest.getPath(); + break; + case OpCode.setACL: + op = AuditConstants.OP_SETACL; + SetACLRequest setACLRequest = new SetACLRequest(); + ByteBufferInputStream.byteBuffer2Record(reqData, setACLRequest); + path = setACLRequest.getPath(); + acls = ZKUtil.aclToString(setACLRequest.getAcl()); + break; + case OpCode.multi: + op = AuditConstants.OP_MULTI_OP; + break; + case OpCode.reconfig: + op = AuditConstants.OP_RECONFIG; + break; + default: + // This should not happen as audit is logged only from known + // operations. This is added to fix find bug issue. + op = "Unknown"; + break; + } + + if (request.cnxn.getRemoteSocketAddress() != null + && request.cnxn.getRemoteSocketAddress() + .getAddress() != null) { + address = request.cnxn.getRemoteSocketAddress().getAddress() + .getHostAddress(); + } + ZKAuditLogger.logFailure(request.getUsers(), op, path, acls, + "0x" + Long.toHexString(sessionId), address); + } catch (Throwable e) { + LOG.error("Failed to audit log request {} failure", request.type, + e); + } + } } diff --git a/src/java/main/org/apache/zookeeper/server/Request.java b/src/java/main/org/apache/zookeeper/server/Request.java index ede9280441a..fea8e4bc639 100644 --- a/src/java/main/org/apache/zookeeper/server/Request.java +++ b/src/java/main/org/apache/zookeeper/server/Request.java @@ -27,6 +27,7 @@ import org.apache.zookeeper.common.Time; import org.apache.zookeeper.data.Id; import org.apache.zookeeper.server.quorum.flexible.QuorumVerifier; +import org.apache.zookeeper.server.util.AuthUtil; import org.apache.zookeeper.txn.TxnHeader; /** @@ -297,4 +298,31 @@ public void setException(KeeperException e) { public KeeperException getException() { return e; } + + /** + * Returns comma separated list of users authenticated in the current + * session + */ + public String getUsers() { + if (authInfo == null) { + return (String) null; + } + if (authInfo.size() == 1) { + return AuthUtil.getUser(authInfo.get(0)); + } + StringBuilder users = new StringBuilder(); + boolean first = true; + for (Id id : authInfo) { + String user = AuthUtil.getUser(id); + if (user != null) { + if (first) { + first = false; + } else { + users.append(","); + } + users.append(user); + } + } + return users.toString(); + } } diff --git a/src/java/main/org/apache/zookeeper/server/ServerCnxn.java b/src/java/main/org/apache/zookeeper/server/ServerCnxn.java index c60503fe7fc..4ad21f64f2c 100644 --- a/src/java/main/org/apache/zookeeper/server/ServerCnxn.java +++ b/src/java/main/org/apache/zookeeper/server/ServerCnxn.java @@ -22,6 +22,7 @@ import java.io.IOException; import java.io.PrintWriter; import java.io.StringWriter; +import java.net.InetAddress; import java.net.InetSocketAddress; import java.nio.ByteBuffer; import java.security.cert.Certificate; @@ -391,4 +392,26 @@ public void cleanupWriterSocket(PrintWriter pwriter) { } } } + + /** + * Returns the IP address or empty string. + */ + public String getHostAddress() { + InetSocketAddress remoteSocketAddress = getRemoteSocketAddress(); + if (remoteSocketAddress == null) { + return ""; + } + InetAddress address = remoteSocketAddress.getAddress(); + if (address == null) { + return ""; + } + return address.getHostAddress(); + } + + /** + * Get session id in hexadecimal notation. + */ + public String getSessionIdHex() { + return "0x" + Long.toHexString(getSessionId()); + } } diff --git a/src/java/main/org/apache/zookeeper/server/ServerCnxnFactory.java b/src/java/main/org/apache/zookeeper/server/ServerCnxnFactory.java index dbe47a261b7..1f3d179b99b 100644 --- a/src/java/main/org/apache/zookeeper/server/ServerCnxnFactory.java +++ b/src/java/main/org/apache/zookeeper/server/ServerCnxnFactory.java @@ -54,6 +54,7 @@ public abstract class ServerCnxnFactory { */ static final ByteBuffer closeConn = ByteBuffer.allocate(0); + private static String loginUser = System.getProperty("user.name", ""); public abstract int getLocalPort(); public abstract Iterable getConnections(); @@ -238,10 +239,19 @@ protected void configureSaslLogin() throws IOException { try { saslServerCallbackHandler = new SaslServerCallbackHandler(Configuration.getConfiguration()); login = new Login(serverSection, saslServerCallbackHandler, new ZKConfig() ); + loginUser = login.getUserName(); login.startThreadIfNeeded(); } catch (LoginException e) { throw new IOException("Could not configure server because SASL configuration did not allow the " + " ZooKeeper server to authenticate itself properly: " + e); } } + + /** + * User who has started the ZooKeeper server user, it will be the logged-in + * user. If no user logged-in then system user + */ + public static String getUserName() { + return loginUser; + } } diff --git a/src/java/main/org/apache/zookeeper/server/ZooKeeperServerMain.java b/src/java/main/org/apache/zookeeper/server/ZooKeeperServerMain.java index 12b8dcd9204..cb9a1cc4ff4 100644 --- a/src/java/main/org/apache/zookeeper/server/ZooKeeperServerMain.java +++ b/src/java/main/org/apache/zookeeper/server/ZooKeeperServerMain.java @@ -25,6 +25,8 @@ import javax.management.JMException; import org.apache.yetus.audience.InterfaceAudience; +import org.apache.zookeeper.audit.AuditConstants; +import org.apache.zookeeper.audit.ZKAuditLogger; import org.apache.zookeeper.jmx.ManagedUtil; import org.apache.zookeeper.server.admin.AdminServer; import org.apache.zookeeper.server.admin.AdminServer.AdminServerException; @@ -66,21 +68,26 @@ public static void main(String[] args) { LOG.error("Invalid arguments, exiting abnormally", e); LOG.info(USAGE); System.err.println(USAGE); + addServerStartFailureAuditLog(); System.exit(2); } catch (ConfigException e) { LOG.error("Invalid config, exiting abnormally", e); System.err.println("Invalid config, exiting abnormally"); + addServerStartFailureAuditLog(); System.exit(2); } catch (DatadirException e) { LOG.error("Unable to access datadir, exiting abnormally", e); System.err.println("Unable to access datadir, exiting abnormally"); + addServerStartFailureAuditLog(); System.exit(3); } catch (AdminServerException e) { LOG.error("Unable to start AdminServer, exiting abnormally", e); System.err.println("Unable to start AdminServer, exiting abnormally"); + addServerStartFailureAuditLog(); System.exit(4); } catch (Exception e) { LOG.error("Unexpected exception, exiting abnormally", e); + addServerStartFailureAuditLog(); System.exit(1); } LOG.info("Exiting normally"); @@ -156,6 +163,7 @@ public void runFromConfig(ServerConfig config) Integer.getInteger("znode.container.maxPerMinute", 10000) ); containerManager.start(); + ZKAuditLogger.addZKStartStopAuditLog(); // Watch status of ZooKeeper server. It will do a graceful shutdown // if the server is not running or hits an internal error. @@ -182,6 +190,10 @@ public void runFromConfig(ServerConfig config) } } + private static void addServerStartFailureAuditLog() { + ZKAuditLogger.logFailure(ZKAuditLogger.getZKUser(), AuditConstants.OP_START); + } + /** * Shutdown the serving instance */ diff --git a/src/java/main/org/apache/zookeeper/server/quorum/QuorumPeerMain.java b/src/java/main/org/apache/zookeeper/server/quorum/QuorumPeerMain.java index 3da6e20edd4..b37a1f0b6ef 100644 --- a/src/java/main/org/apache/zookeeper/server/quorum/QuorumPeerMain.java +++ b/src/java/main/org/apache/zookeeper/server/quorum/QuorumPeerMain.java @@ -25,6 +25,8 @@ import org.apache.yetus.audience.InterfaceAudience; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import org.apache.zookeeper.audit.AuditConstants; +import org.apache.zookeeper.audit.ZKAuditLogger; import org.apache.zookeeper.jmx.ManagedUtil; import org.apache.zookeeper.server.ServerCnxnFactory; import org.apache.zookeeper.server.ZKDatabase; @@ -84,27 +86,38 @@ public static void main(String[] args) { LOG.error("Invalid arguments, exiting abnormally", e); LOG.info(USAGE); System.err.println(USAGE); + addServerStartFailureAuditLog(); System.exit(2); } catch (ConfigException e) { LOG.error("Invalid config, exiting abnormally", e); System.err.println("Invalid config, exiting abnormally"); + addServerStartFailureAuditLog(); System.exit(2); } catch (DatadirException e) { LOG.error("Unable to access datadir, exiting abnormally", e); System.err.println("Unable to access datadir, exiting abnormally"); + addServerStartFailureAuditLog(); System.exit(3); } catch (AdminServerException e) { LOG.error("Unable to start AdminServer, exiting abnormally", e); System.err.println("Unable to start AdminServer, exiting abnormally"); + addServerStartFailureAuditLog(); System.exit(4); } catch (Exception e) { LOG.error("Unexpected exception, exiting abnormally", e); + addServerStartFailureAuditLog(); System.exit(1); } LOG.info("Exiting normally"); System.exit(0); } + private static void addServerStartFailureAuditLog() { + if (ZKAuditLogger.isAuditEnabled()) { + ZKAuditLogger.logFailure(ZKAuditLogger.getZKUser(), AuditConstants.OP_START); + } + } + protected void initializeAndRun(String[] args) throws ConfigException, IOException, AdminServerException { @@ -198,6 +211,7 @@ public void runFromConfig(QuorumPeerConfig config) quorumPeer.initialize(); quorumPeer.start(); + ZKAuditLogger.addZKStartStopAuditLog(); quorumPeer.join(); } catch (InterruptedException e) { // warn, but generally this is ok diff --git a/src/java/main/org/apache/zookeeper/server/util/AuthUtil.java b/src/java/main/org/apache/zookeeper/server/util/AuthUtil.java new file mode 100644 index 00000000000..abde0361c45 --- /dev/null +++ b/src/java/main/org/apache/zookeeper/server/util/AuthUtil.java @@ -0,0 +1,42 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.zookeeper.server.util; + +import org.apache.zookeeper.data.Id; + +public class AuthUtil { + /** + * Gives user name + * + * @param id + * contains scheme and authentication info + * @return returns null if authentication scheme does not exist or + * authentication provider returns null as user + */ + public static String getUser(Id id) { + if ("digest".equals(id.getScheme())) { + /** + * format is already enforced in server code. so no need to check it + * again, just assume it is in correct format + */ + return id.getId().split(":")[0]; + } else { + return id.getId(); + } + } +} diff --git a/src/java/test/org/apache/zookeeper/audit/AuditLogPerfReading.java b/src/java/test/org/apache/zookeeper/audit/AuditLogPerfReading.java new file mode 100644 index 00000000000..46d4e6534eb --- /dev/null +++ b/src/java/test/org/apache/zookeeper/audit/AuditLogPerfReading.java @@ -0,0 +1,74 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.zookeeper.audit; + +/** + * Audit log performance reading + */ +public class AuditLogPerfReading { + // time taken by create operations + private long create; + // time taken by setData operations + private long setData; + // time taken by delete operations + private long delete; + + public long getCreate() { + return create; + } + + public void setCreate(long create) { + this.create = create; + } + + public long getSetData() { + return setData; + } + + public void setSetData(long setData) { + this.setData = setData; + } + + public long getDelete() { + return delete; + } + + public void setDelete(long delete) { + this.delete = delete; + } + + public String report() { + StringBuilder builder = new StringBuilder(); + builder.append("create="); + builder.append(create); + builder.append(" ms\n"); + builder.append("setData="); + builder.append(setData); + builder.append(" ms\n"); + builder.append("delete="); + builder.append(delete); + builder.append(" ms\n"); + return builder.toString(); + } + + @Override + public String toString() { + return "create=" + create + ", setData=" + setData + ", delete=" + + delete; + } +} \ No newline at end of file diff --git a/src/java/test/org/apache/zookeeper/audit/ZKAuditLogFormatterTest.java b/src/java/test/org/apache/zookeeper/audit/ZKAuditLogFormatterTest.java new file mode 100644 index 00000000000..4d30b1e19e1 --- /dev/null +++ b/src/java/test/org/apache/zookeeper/audit/ZKAuditLogFormatterTest.java @@ -0,0 +1,45 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.zookeeper.audit; + +import static org.junit.Assert.assertEquals; + +import org.junit.Test; + +public class ZKAuditLogFormatterTest { + + @Test + public void testFormat() { + ZKAuditLogFormatter formatter = new ZKAuditLogFormatter(); + formatter.addField("k1", "Value1"); + formatter.addField("k2", "Value2"); + String actual = formatter.format(); + String expected = "k1=Value1\tk2=Value2"; + assertEquals(expected, actual); + } + + @Test + public void testFormatShouldIgnoreKeyIfValueIsNull() { + ZKAuditLogFormatter formatter = new ZKAuditLogFormatter(); + formatter.addField("k1", null); + formatter.addField("k2", "Value2"); + String actual = formatter.format(); + String expected = "k2=Value2"; + assertEquals(expected, actual); + } +} diff --git a/src/java/test/org/apache/zookeeper/audit/ZKAuditLoggerPerformance.java b/src/java/test/org/apache/zookeeper/audit/ZKAuditLoggerPerformance.java new file mode 100644 index 00000000000..20ebf81e4b7 --- /dev/null +++ b/src/java/test/org/apache/zookeeper/audit/ZKAuditLoggerPerformance.java @@ -0,0 +1,151 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.zookeeper.audit; + +import java.io.IOException; +import java.util.concurrent.TimeoutException; + +import org.apache.zookeeper.CreateMode; +import org.apache.zookeeper.KeeperException; +import org.apache.zookeeper.ZooDefs.Ids; +import org.apache.zookeeper.ZooKeeper; +import org.apache.zookeeper.common.Time; +import org.apache.zookeeper.data.Stat; +import org.apache.zookeeper.test.ClientBase.CountdownWatcher; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public class ZKAuditLoggerPerformance { + private static final Logger LOG = LoggerFactory + .getLogger(ZKAuditLoggerPerformance.class); + private ZooKeeper zkClient; + private String parentPath; + private int numberOfRecords; + + public ZKAuditLoggerPerformance(ZooKeeper zkClient, String parentPath, + int numberOfRecords) { + this.zkClient = zkClient; + this.parentPath = parentPath; + this.numberOfRecords = numberOfRecords; + } + + public void create() throws Exception { + for (int i = 0; i < numberOfRecords; i++) { + zkClient.create(getPath(i), "0123456789".getBytes(), + Ids.OPEN_ACL_UNSAFE, + CreateMode.PERSISTENT); + + } + } + + public void setData() throws Exception { + for (int i = 0; i < numberOfRecords; i++) { + zkClient.setData(getPath(i), "9876543210".getBytes(), -1); + } + } + + public void delete() throws Exception { + for (int i = 0; i < numberOfRecords; i++) { + zkClient.delete(getPath(i), -1); + } + } + + public AuditLogPerfReading doOperations() throws Exception { + AuditLogPerfReading perfReading = new AuditLogPerfReading(); + // create + long startTime = Time.currentElapsedTime(); + create(); + perfReading.setCreate(Time.currentElapsedTime() - startTime); + + // setData + startTime = Time.currentElapsedTime(); + setData(); + perfReading.setSetData(Time.currentElapsedTime() - startTime); + + // delete + startTime = Time.currentElapsedTime(); + delete(); + perfReading.setDelete(Time.currentElapsedTime() - startTime); + return perfReading; + } + + private String getPath(int i) { + return parentPath + "zNode" + i; + } + + public static void main(String[] args) { + if (args.length != 3) { + System.err.println( + "USAGE: ZKAuditLoggerPerformance connectionString parentPath numberOfRecords"); + System.exit(1); + } + String cxnString = args[0]; + CountdownWatcher watcher = new CountdownWatcher(); + ZooKeeper zkClient = null; + try { + zkClient = new ZooKeeper(cxnString, 60000, watcher); + watcher.waitForConnected(30000); + } catch (InterruptedException | TimeoutException | IOException e) { + String msg = "ZooKeeper client can not connect to " + cxnString; + logErrorAndExit(e, msg); + } + String parentPath = args[1]; + try { + Stat exists = zkClient.exists(parentPath, false); + if (exists == null) { + System.err.println( + "Parent path '" + parentPath + "' must exist."); + System.exit(1); + } + } catch (KeeperException | InterruptedException e1) { + String msg = "Error while checking the existence of parent path"; + logErrorAndExit(e1, msg); + } + int recordCount = 0; + try { + recordCount = Integer.parseInt(args[2]); + } catch (NumberFormatException e) { + String msg = "Failed to parse '" + args[2] + "' to integer"; + LOG.error(msg, e); + System.err.println(msg); + System.exit(1); + } + ZKAuditLoggerPerformance auditLoggingPerf = new ZKAuditLoggerPerformance( + zkClient, + parentPath, recordCount); + AuditLogPerfReading doOperations = null; + try { + doOperations = auditLoggingPerf.doOperations(); + } catch (Exception e) { + String msg = "Error while doing operations."; + LOG.error(msg, e); + System.err.println(msg); + System.exit(1); + } + System.out + .println("Time taken for " + recordCount + " operations are:"); + System.out.println(doOperations.report()); + System.exit(0); + } + + private static void logErrorAndExit(Exception e, String msg) { + LOG.error(msg, e); + System.err.println(msg + ", error=" + e.getMessage()); + System.exit(1); + } +} diff --git a/src/java/test/org/apache/zookeeper/audit/ZKAuditLoggerTest.java b/src/java/test/org/apache/zookeeper/audit/ZKAuditLoggerTest.java new file mode 100644 index 00000000000..4210240e818 --- /dev/null +++ b/src/java/test/org/apache/zookeeper/audit/ZKAuditLoggerTest.java @@ -0,0 +1,423 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.zookeeper.audit; + +import static org.apache.zookeeper.test.ClientBase.CONNECTION_TIMEOUT; +import static org.junit.Assert.assertEquals; + +import java.io.ByteArrayOutputStream; +import java.io.IOException; +import java.io.LineNumberReader; +import java.io.StringReader; +import java.net.InetAddress; +import java.net.InetSocketAddress; +import java.util.ArrayList; +import java.util.List; + +import org.apache.log4j.Layout; +import org.apache.log4j.Level; +import org.apache.log4j.Logger; +import org.apache.log4j.SimpleLayout; +import org.apache.log4j.WriterAppender; +import org.apache.zookeeper.CreateMode; +import org.apache.zookeeper.KeeperException; +import org.apache.zookeeper.KeeperException.Code; +import org.apache.zookeeper.Op; +import org.apache.zookeeper.PortAssignment; +import org.apache.zookeeper.ZKUtil; +import org.apache.zookeeper.ZooDefs; +import org.apache.zookeeper.ZooKeeper; +import org.apache.zookeeper.data.ACL; +import org.apache.zookeeper.data.Stat; +import org.apache.zookeeper.server.Request; +import org.apache.zookeeper.server.ServerCnxn; +import org.apache.zookeeper.server.quorum.QuorumPeerTestBase; +import org.apache.zookeeper.test.ClientBase; +import org.apache.zookeeper.test.ClientBase.CountdownWatcher; +import org.junit.After; +import org.junit.Assert; +import org.junit.Test; + +public class ZKAuditLoggerTest extends QuorumPeerTestBase { + private static final Logger LOG = Logger.getLogger(ZKAuditLoggerTest.class); + private static int SERVER_COUNT = 3; + private MainThread[] mt; + private ZooKeeper zk; + + @Test + public void testAuditLogs() throws Exception { + System.setProperty(ZKAuditLogger.SYSPROP_AUDIT_ENABLE, "true"); + // setup the logger to capture all logs + Layout layout = new SimpleLayout(); + ByteArrayOutputStream os = new ByteArrayOutputStream(); + WriterAppender appender = new WriterAppender(layout, os); + appender.setImmediateFlush(true); + appender.setThreshold(Level.INFO); + Logger zlogger = Logger.getLogger(ZKAuditLogger.class); + zlogger.addAppender(appender); + try { + mt = startQuorum(); + CountdownWatcher watcher = new CountdownWatcher(); + zk = new ZooKeeper( + "127.0.0.1:" + mt[0].getQuorumPeer().getClientPort(), + ClientBase.CONNECTION_TIMEOUT, watcher); + watcher.waitForConnected(ClientBase.CONNECTION_TIMEOUT); + String expectedAuditLog = getStartLog(); + List logs = readAuditLog(os, SERVER_COUNT); + verifyLogs(expectedAuditLog, logs); + + String path = "/a"; + verifyCreateAuditLogs(os, path); + verifySetDataAuditLogs(os, path); + verifySetACLAuditLogs(os, path); + verifyMultiOperationAuditLogs(os); + verifyDeleteAuditLogs(os, path); + verifyEphemralZNodeAuditLogs(os); + + } finally { + zlogger.removeAppender(appender); + os.close(); + } + } + + private void verifyEphemralZNodeAuditLogs(ByteArrayOutputStream os) + throws Exception { + String ephemralPath = "/ephemral"; + CountdownWatcher watcher2 = new CountdownWatcher(); + ZooKeeper zk2 = new ZooKeeper( + "127.0.0.1:" + mt[0].getQuorumPeer().getClientPort(), + ClientBase.CONNECTION_TIMEOUT, watcher2); + watcher2.waitForConnected(ClientBase.CONNECTION_TIMEOUT); + zk2.create(ephemralPath, "".getBytes(), ZooDefs.Ids.OPEN_ACL_UNSAFE, + CreateMode.EPHEMERAL); + String session2 = "0x" + Long.toHexString(zk2.getSessionId()); + verifyLog(getAuditLog(AuditConstants.OP_CREATE, ephemralPath, + AuditConstants.SUCCESS, null, + session2), readAuditLog(os)); + zk2.close(); + waitForDeletion(zk, ephemralPath, 100); + // verify that ephemeral node deletion on session close are captured + // in audit log + // Because these operations are done by ZooKeeper server itself, + // there are no IP user is zkServer user, not any client user + verifyLogs( + getAuditLog(AuditConstants.OP_DEL_EZNODE_EXP, ephemralPath, + AuditConstants.SUCCESS, + null, session2, ZKAuditLogger.getZKUser(), null), + readAuditLog(os, SERVER_COUNT)); + } + + private void verifyMultiOperationAuditLogs(ByteArrayOutputStream os) + throws InterruptedException, KeeperException, IOException { + List ops = new ArrayList(); + + String multiop = "/b"; + Op create = Op.create(multiop, "".getBytes(), + ZooDefs.Ids.OPEN_ACL_UNSAFE, + CreateMode.PERSISTENT); + Op setData = Op.setData(multiop, "newData".getBytes(), -1); + // check does nothing so it is audit logged + Op check = Op.check(multiop, -1); + Op delete = Op.delete(multiop, -1); + + ops.add(create); + ops.add(setData); + ops.add(check); + ops.add(delete); + + zk.multi(ops); + List multiOpLogs = readAuditLog(os, 3); + // verify that each multi operation success is logged + verifyLog(getAuditLog(AuditConstants.OP_CREATE, multiop), + multiOpLogs.get(0)); + verifyLog(getAuditLog(AuditConstants.OP_SETDATA, multiop), + multiOpLogs.get(1)); + verifyLog(getAuditLog(AuditConstants.OP_DELETE, multiop), + multiOpLogs.get(2)); + + ops = new ArrayList(); + ops.add(create); + ops.add(create); + try { + zk.multi(ops); + } catch (KeeperException exception) { + Code code = exception.code(); + assertEquals(Code.NODEEXISTS, code); + } + + // Verify that multi operation failure is logged, and there is no path + // mentioned in the audit log + verifyLog(getAuditLog(AuditConstants.OP_MULTI_OP, null, + AuditConstants.FAILURE), + readAuditLog(os)); + } + + private void verifyDeleteAuditLogs(ByteArrayOutputStream os, String path) + throws InterruptedException, IOException, KeeperException { + try { + zk.delete(path, -100); + } catch (KeeperException exception) { + Code code = exception.code(); + assertEquals(Code.BADVERSION, code); + } + verifyLog(getAuditLog(AuditConstants.OP_DELETE, path, + AuditConstants.FAILURE), + readAuditLog(os)); + zk.delete(path, -1); + verifyLog(getAuditLog(AuditConstants.OP_DELETE, path), + readAuditLog(os)); + } + + private void verifySetACLAuditLogs(ByteArrayOutputStream os, String path) + throws InterruptedException, IOException, KeeperException { + ArrayList openAclUnsafe = ZooDefs.Ids.OPEN_ACL_UNSAFE; + try { + zk.setACL(path, openAclUnsafe, -100); + } catch (KeeperException exception) { + Code code = exception.code(); + assertEquals(Code.BADVERSION, code); + } + verifyLog(getAuditLog(AuditConstants.OP_SETACL, path, + AuditConstants.FAILURE, + ZKUtil.aclToString(openAclUnsafe)), readAuditLog(os)); + zk.setACL(path, openAclUnsafe, -1); + verifyLog(getAuditLog(AuditConstants.OP_SETACL, path, + AuditConstants.SUCCESS, + ZKUtil.aclToString(openAclUnsafe)), readAuditLog(os)); + } + + private void verifySetDataAuditLogs(ByteArrayOutputStream os, String path) + throws InterruptedException, IOException, KeeperException { + try { + zk.setData(path, "newData".getBytes(), -100); + } catch (KeeperException exception) { + Code code = exception.code(); + assertEquals(Code.BADVERSION, code); + } + verifyLog(getAuditLog(AuditConstants.OP_SETDATA, path, + AuditConstants.FAILURE), + readAuditLog(os)); + zk.setData(path, "newdata".getBytes(), -1); + verifyLog(getAuditLog(AuditConstants.OP_SETDATA, path), + readAuditLog(os)); + } + + private void verifyCreateAuditLogs(ByteArrayOutputStream os, String path) + throws KeeperException, InterruptedException, IOException { + zk.create(path, "".getBytes(), ZooDefs.Ids.OPEN_ACL_UNSAFE, + CreateMode.PERSISTENT); + // success log + verifyLog(getAuditLog(AuditConstants.OP_CREATE, path), + readAuditLog(os)); + try { + zk.create(path, "".getBytes(), ZooDefs.Ids.OPEN_ACL_UNSAFE, + CreateMode.PERSISTENT); + } catch (KeeperException exception) { + Code code = exception.code(); + assertEquals(Code.NODEEXISTS, code); + } + // Verify create operation log + verifyLog(getAuditLog(AuditConstants.OP_CREATE, path, + AuditConstants.FAILURE), + readAuditLog(os)); + } + + private String getStartLog() { + /** + * 

+         * user=userName operation=ZooKeeperServer start  result=success
+         *
+ */ + return ZKAuditLogger.createLog(ZKAuditLogger.getZKUser(), + AuditConstants.OP_START, null, + null, null, null, AuditConstants.SUCCESS); + } + + private String getAuditLog(String operation, String znode) { + return getAuditLog(operation, znode, AuditConstants.SUCCESS); + } + + private String getAuditLog(String operation, String znode, String status) { + return getAuditLog(operation, znode, status, null); + } + + private String getAuditLog(String operation, String znode, String status, + String acl) { + String session = getSession(); + return getAuditLog(operation, znode, status, acl, session); + } + + private String getAuditLog(String operation, String znode, String status, + String acl, + String session) { + String user = getUser(); + String ip = getIp(); + return getAuditLog(operation, znode, status, acl, session, user, ip); + } + + private String getAuditLog(String operation, String znode, String status, + String acl, + String session, String user, String ip) { + + String auditLog = ZKAuditLogger.createLog(user, operation, znode, acl, + session, ip, status); + LOG.info("expected audit log for operation '" + operation + "' is '" + + auditLog + "'"); + return auditLog; + } + + private String getSession() { + return "0x" + Long.toHexString(zk.getSessionId()); + } + + private String getUser() { + ServerCnxn next = getServerCnxn(); + Request request = new Request(next, -1, -1, -1, null, + next.getAuthInfo()); + return request.getUsers(); + } + + private String getIp() { + ServerCnxn next = getServerCnxn(); + InetSocketAddress remoteSocketAddress = next.getRemoteSocketAddress(); + InetAddress address = remoteSocketAddress.getAddress(); + return address.getHostAddress(); + } + + private ServerCnxn getServerCnxn() { + Iterable connections = mt[0].getQuorumPeer() + .getActiveServer() + .getServerCnxnFactory().getConnections(); + ServerCnxn next = connections.iterator().next(); + return next; + } + + private void verifyLog(String expectedLog, String log) { + String searchString = " - "; + int logStartIndex = log.indexOf(searchString); + String auditLog = log.substring(logStartIndex + searchString.length()); + assertEquals(expectedLog, auditLog); + + } + + private void verifyLogs(String expectedLog, List logs) { + for (String log : logs) { + verifyLog(expectedLog, log); + } + } + + private String readAuditLog(ByteArrayOutputStream os) throws IOException { + return readAuditLog(os, 1).get(0); + } + + private List readAuditLog(ByteArrayOutputStream os, + int numberOfLogEntry) + throws IOException { + return readAuditLog(os, numberOfLogEntry, false); + } + + private List readAuditLog(ByteArrayOutputStream os, + int numberOfLogEntry, + boolean skipEphemralDeletion) throws IOException { + List logs = new ArrayList(); + LineNumberReader r = new LineNumberReader( + new StringReader(os.toString())); + String line = ""; + while ((line = r.readLine()) != null) { + if (skipEphemralDeletion + && line.contains(AuditConstants.OP_DEL_EZNODE_EXP)) { + continue; + } + logs.add(line); + } + os.reset(); + assertEquals( + "Expected number of log entries are not generated. Logs are " + + logs, + numberOfLogEntry, logs.size()); + return logs; + + } + + private MainThread[] startQuorum() throws IOException { + final int clientPorts[] = new int[SERVER_COUNT]; + StringBuilder sb = new StringBuilder(); + String server; + + for (int i = 0; i < SERVER_COUNT; i++) { + clientPorts[i] = PortAssignment.unique(); + server = "server." + i + "=127.0.0.1:" + PortAssignment.unique() + + ":" + + PortAssignment.unique() + ":participant;127.0.0.1:" + + clientPorts[i]; + sb.append(server + "\n"); + + } + String currentQuorumCfgSection = sb.toString(); + MainThread mt[] = new MainThread[SERVER_COUNT]; + + // start all the servers + for (int i = 0; i < SERVER_COUNT; i++) { + mt[i] = new MainThread(i, clientPorts[i], currentQuorumCfgSection, + false); + mt[i].start(); + } + + // ensure all servers started + for (int i = 0; i < SERVER_COUNT; i++) { + Assert.assertTrue("waiting for server " + i + " being up", + ClientBase.waitForServerUp("127.0.0.1:" + clientPorts[i], + CONNECTION_TIMEOUT)); + } + return mt; + } + + private void waitForDeletion(ZooKeeper zooKeeper, String path, long timeout) + throws Exception { + long elapsedTime = 0; + long waitInterval = 10; + Stat exists = zooKeeper.exists(path, false); + while (exists != null && elapsedTime < timeout) { + try { + Thread.sleep(waitInterval); + } catch (InterruptedException e) { + Assert.fail("CurrentEpoch update failed"); + } + elapsedTime = elapsedTime + waitInterval; + exists = zooKeeper.exists(path, false); + } + Assert.assertNull("Node " + path + " not deleted in " + timeout + " ms", + exists); + } + + @After + public void tearDown() { + System.clearProperty(ZKAuditLogger.SYSPROP_AUDIT_ENABLE); + System.clearProperty("zookeeper.admin.enableServer"); + for (int i = 0; i < SERVER_COUNT; i++) { + try { + if (mt[i] != null) { + mt[i].shutdown(); + } + } catch (InterruptedException e) { + e.printStackTrace(); + } + } + } + +} diff --git a/src/java/test/org/apache/zookeeper/server/util/AuthUtilTest.java b/src/java/test/org/apache/zookeeper/server/util/AuthUtilTest.java new file mode 100644 index 00000000000..5688923bc7f --- /dev/null +++ b/src/java/test/org/apache/zookeeper/server/util/AuthUtilTest.java @@ -0,0 +1,57 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.apache.zookeeper.server.util; + +import static org.junit.Assert.*; + +import org.apache.zookeeper.data.Id; +import org.junit.Test; + +public class AuthUtilTest { + + @Test + public void testGetUserFromAllAuthenticationScheme() { + System.setProperty("zookeeper.authProvider.sasl", + "org.apache.zookeeper.server.auth.SASLAuthenticationProvider"); + System.setProperty("zookeeper.authProvider.x509", + "org.apache.zookeeper.server.auth.X509AuthenticationProvider"); + + String user = "zkUser"; + Id id = new Id("digest", user + ":password"); + String result = AuthUtil.getUser(id); + assertEquals(user, result); + + String principal = "zkCli/hadoop.hadoop.com"; + id = new Id("sasl", principal); + assertEquals(principal, AuthUtil.getUser(id)); + + String ip = "192.168.1.2"; + id = new Id("ip", ip); + assertEquals(ip, AuthUtil.getUser(id)); + + String certificate = "CN=host-192.168.1.2,OU=OrganizationUnit,O=Organization,L=Location,ST=State,C=IN"; + id = new Id("x509", certificate); + assertEquals(certificate, AuthUtil.getUser(id)); + } + + public void testGetUserShouldReturnNullIfAuthenticationNotConfigured() { + Id id = new Id("invalid Authentication Scheme", "user"); + String result = AuthUtil.getUser(id); + assertNull(result); + } +} diff --git a/zookeeper-docs/src/documentation/content/xdocs/index.xml b/zookeeper-docs/src/documentation/content/xdocs/index.xml index 969e482cabe..e067e39d237 100644 --- a/zookeeper-docs/src/documentation/content/xdocs/index.xml +++ b/zookeeper-docs/src/documentation/content/xdocs/index.xml @@ -66,6 +66,7 @@
  • Hierarchical quorums
  • Observers - non-voting ensemble members that easily improve ZooKeeper's scalability
  • Dynamic Reconfiguration - a guide on how to use dynamic reconfiguration in ZooKeeper
    • +
  • Audit Logging - a guide on how to configure audit logs in ZooKeeper Server and what contents are logged.
    • diff --git a/zookeeper-docs/src/documentation/content/xdocs/site.xml b/zookeeper-docs/src/documentation/content/xdocs/site.xml index 614fa6cc67b..1f36f7590d5 100644 --- a/zookeeper-docs/src/documentation/content/xdocs/site.xml +++ b/zookeeper-docs/src/documentation/content/xdocs/site.xml @@ -52,6 +52,7 @@ See http://forrest.apache.org/docs/linking.html for more info. + diff --git a/zookeeper-docs/src/documentation/content/xdocs/zookeeperAdmin.xml b/zookeeper-docs/src/documentation/content/xdocs/zookeeperAdmin.xml index d82e2347407..131229349ef 100644 --- a/zookeeper-docs/src/documentation/content/xdocs/zookeeperAdmin.xml +++ b/zookeeper-docs/src/documentation/content/xdocs/zookeeperAdmin.xml @@ -974,6 +974,19 @@ server.3=zoo3:2888:3888 than what was allowed in 3.5.3 (1152921504606846975) + + audit.enable + + (Java system property: + zookeeper.audit.enable) + + + New in 3.5.5: + By default audit logs are disabled. Set to "true" to enable it. Default value is "false". See + ZooKeeper audit logs for more information. + + + diff --git a/zookeeper-docs/src/documentation/content/xdocs/zookeeperAuditLogs.xml b/zookeeper-docs/src/documentation/content/xdocs/zookeeperAuditLogs.xml new file mode 100644 index 00000000000..4771b63533b --- /dev/null +++ b/zookeeper-docs/src/documentation/content/xdocs/zookeeperAuditLogs.xml @@ -0,0 +1,205 @@ + + + +
    + ZooKeeper Audit Logging + + + Licensed under the Apache License, Version 2.0 (the "License"); + you may not use this file except in compliance with the License. You may + obtain a copy of the License at http://www.apache.org/licenses/LICENSE-2.0. + + Unless required by applicable law or agreed to in writing, + software distributed under the License is distributed on an "AS IS" + BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or + implied. See the License for the specific language governing permissions + and limitations under the License. + + + + This document contains information about Audit Logs in ZooKeeper. + + +
    + ZooKeeper Audit Logs + Apache ZooKeeper supports audit logs form version 3.5.5. By default audit logs are disabled. To enable audit + logs configure audit.enable=true in conf/zoo.cfg. Audit logs are not logged on all the ZooKeeper servers, but logged + only on the servers where client is connected as depicted in below figure. + + + + + + The audit log captures detailed information for the operations that are selected to be audited. The audit + information is written as a set of key=value pairs for the following keys + + Audit Log Content + + + + Key + Value + + + + + session + client session id + + + user + + comma separated list of users who are associate with a client session. To know who is taken as user in audit logs + refer section + + + + + ip + client IP address + + + operation + any one of the selected operations for audit. Possible values are + (serverStart| serverStop| create| delete| setData| setAcl| multiOperation| reconfig| ephemeralZNodeDeleteOnSessionClose) + + + + znode + path of the znode + + + acl + String representation of znode ACL like cdrwa(create, delete,read, write, admin). This is logged + only for setAcl operation + + + result + result of the operation. Possible values are (success|failure|invoked). Result "invoked" is used + for serverStop operation because stop is logged before ensuring that server actually stopped. + + + + +
    + Below are sample audit logs for all operations, where client is connected from 192.168.1.2, client principal is + zkcli@HADOOP.COM, server principal is zookeeper/192.168.1.3@HADOOP.COM + + user=zookeeper/192.168.1.3 operation=serverStart result=success + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=create znode=/a result=success + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=create znode=/a result=failure + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=setData znode=/a result=failure + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=setData znode=/a result=success + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=setAcl znode=/a acl=world:anyone:cdrwa result=failure + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=setAcl znode=/a acl=world:anyone:cdrwa result=success + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=create znode=/b result=success + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=setData znode=/b result=success + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=delete znode=/b result=success + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=multiOperation result=failure + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=delete znode=/a result=failure + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=delete znode=/a result=success + session=0x19344730001 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=create znode=/ephemral result=success + session=0x19344730001 user=zookeeper/192.168.1.3 operation=ephemeralZNodeDeletionOnSessionCloseOrExpire znode=/ephemral result=success + session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 operation=reconfig znode=/zookeeper/config result=success + user=zookeeper/192.168.1.3 operation=serverStop result=invoked + +
    +
    + ZooKeeper Audit Log Configuration + By default audit logs are disabled. To enable audit logs configure audit.enable=true in conf/zoo.cfg. Audit + logging is done using log4j. Following is the default log4j configuration for audit logs in conf/log4j.properties + + + # + # zk audit logging + # + zookeeper.auditlog.file=zookeeper_audit.log + zookeeper.auditlog.threshold=INFO + audit.logger=INFO, RFAAUDIT + log4j.logger.org.apache.zookeeper.audit.ZKAuditLogger=${audit.logger} + log4j.additivity.org.apache.zookeeper.audit.ZKAuditLogger=false + log4j.appender.RFAAUDIT=org.apache.log4j.RollingFileAppender + log4j.appender.RFAAUDIT.File=${zookeeper.log.dir}/${zookeeper.auditlog.file} + log4j.appender.RFAAUDIT.layout=org.apache.log4j.PatternLayout + log4j.appender.RFAAUDIT.layout.ConversionPattern=%d{ISO8601} %p %c{2}: %m%n + log4j.appender.RFAAUDIT.Threshold=${zookeeper.auditlog.threshold} + + # Max log file size of 10MB + log4j.appender.RFAAUDIT.MaxFileSize=10MB + log4j.appender.RFAAUDIT.MaxBackupIndex=10 + + Change above configuration to customize the auditlog file, number of backups, max file size etc. +
    +
    + Who is taken as user in audit logs? + By default there are only four authentication provider + + + IPAuthenticationProvider + + + SASLAuthenticationProvider + + + X509AuthenticationProvider + + + DigestAuthenticationProvider + + + User is decided based on the configured authentication provider. + + + When IPAuthenticationProvider is configured then authenticated IP is taken as user + + + When SASLAuthenticationProvider is configured then client principal is taken as user + + + + When X509AuthenticationProvider is configured then client certificate is taken as user + + + + When DigestAuthenticationProvider is configured then authenticated user is user + + + + For custom authentication provider whatever is stored in org.apache.zookeeper.data.Id.id is taken as user. + Generally only user name is stored in this field but it is up to the custom authentication provider what they store + in it. For audit logging value of org.apache.zookeeper.data.Id.id would be taken as user. + + In ZooKeeper Server not all the operations are done by clients but some operations are done by the server + itself. For example when client closes the session, ephemeral znodes are delete by the Server. These deletion are + not done by clients directly but it is done the server itself these are called system operations. For these system + operations the user associated with the ZooKeeper server are taken as user while audit logging these operations. For + example if in ZooKeeper server principal is zookeeper/hadoop.hadoop.com@HADOOP.COM then this becomes the system user + and all the system operations will be logged with this user name. + + user=zookeeper/hadoop.hadoop.com@HADOOP.COM operation=serverStart result=success + If there is no user associate with ZooKeeper server then the user who started the ZooKeeper server is taken as + the user. For example if server started by root then root is taken as the system user + + user=root operation=serverStart result=success + Single client can attach multiple authentication schemes to a session, in this case all authenticated schemes + will taken taken as user and will be presented as comma separated list. For example if a client is authenticate with + principal zkcli@HADOOP.COM and ip 127.0.0.1 then create znode audit log will be as: + session=0x10c0bcb0000 user=zkcli@HADOOP.COM,127.0.0.1 ip=127.0.0.1 operation=create znode=/a result=success +
    +
    diff --git a/zookeeper-docs/src/documentation/resources/images/zkAuditLogs.jpg b/zookeeper-docs/src/documentation/resources/images/zkAuditLogs.jpg new file mode 100644 index 00000000000..fd6c3765610 Binary files /dev/null and b/zookeeper-docs/src/documentation/resources/images/zkAuditLogs.jpg differ