Java tutorial
/** * 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.hadoop.metrics; import java.io.IOException; import java.lang.management.ManagementFactory; import java.util.concurrent.atomic.AtomicLong; import org.apache.commons.codec.binary.Base64; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; import org.apache.hadoop.fs.FileStatus; /** * Tracing class for recording client-side API calls and RPC calls. */ public class APITrace { private static final Log API_TRACE_LOG = LogFactory.getLog(APITrace.class); private static final long baseTime = System.nanoTime(); private static AtomicLong nextEventId = new AtomicLong(1); private static AtomicLong nextStreamId = new AtomicLong(1); private static String pid = getPid(); // start auto(callIds) public static final int CALL_COLLAPSED = 1; public static final int CALL_getName = 2; public static final int CALL_getFileBlockLocations = 3; public static final int CALL_open = 4; public static final int CALL_append = 5; public static final int CALL_create = 6; public static final int CALL_create1 = 7; public static final int CALL_createNonRecursive = 8; public static final int CALL_createNonRecursive1 = 9; public static final int CALL_setReplication = 10; public static final int CALL_hardLink = 11; public static final int CALL_rename = 12; public static final int CALL_delete = 13; public static final int CALL_delete1 = 14; public static final int CALL_listStatus = 15; public static final int CALL_mkdirs = 16; public static final int CALL_iterativeGetOpenFiles = 17; public static final int CALL_getUsed = 18; public static final int CALL_getDefaultBlockSize = 19; public static final int CALL_getDefaultReplication = 20; public static final int CALL_getContentSummary = 21; public static final int CALL_getFileStatus = 22; public static final int CALL_getFileChecksum = 23; public static final int CALL_setVerifyChecksum = 24; public static final int CALL_close = 25; public static final int CALL_setOwner = 26; public static final int CALL_setTimes = 27; public static final int CALL_setPermission = 28; public static final int CALL_seek = 29; public static final int CALL_getPos = 30; public static final int CALL_seekToNewSource = 31; public static final int CALL_read = 32; public static final int CALL_readFully = 33; public static final int CALL_readFully1 = 34; public static final int CALL_read1 = 35; public static final int CALL_read2 = 36; public static final int CALL_read3 = 37; public static final int CALL_skip = 38; public static final int CALL_available = 39; public static final int CALL_close1 = 40; public static final int CALL_mark = 41; public static final int CALL_reset = 42; public static final int CALL_sync = 43; public static final int CALL_write = 44; public static final int CALL_write1 = 45; public static final int CALL_write2 = 46; public static final int CALL_flush = 47; public static final int CALL_close2 = 48; // pseudo event for tracing of info besides API calls public static final int COMMENT_msg = 49; // we only support static methods private APITrace() { }; private static String getPid() { // Generally .getName() will return "UNIX-PID@MACHINE-NAME", but this is JVM specific. If the // string follows this format, we just return the UNIX-PID. Otherwise, we return the entire ID. String name = ManagementFactory.getRuntimeMXBean().getName(); String parts[] = name.split("@"); if (parts.length == 2) { return parts[0]; } return name; } /** * Record a method call and its return value in the log. * * @param entry the System.nanoTime timestamp for method entry * @param callIndex index into callTable * @param returnValue value returned by traced method * @param argValues arguments passed to traced method * @param streamId unique identifier for stream, or -1 if not applicable */ public static void logCall(long entryTime, long returnTime, int callIndex, Object returnValue, Object argValues[], long streamId) { if (!API_TRACE_LOG.isInfoEnabled()) { return; } // determine elapsed time long elapsed = returnTime; elapsed -= entryTime; entryTime -= baseTime; // TODO: for the first entry, we get negatives for entryTime. // is this something weird in order the Java instantiates? // append universal fields (i.e., ones that occur for every call) StringBuilder line = new StringBuilder(); line.append(pid + ","); line.append(nextEventId.getAndIncrement() + ","); line.append(entryTime + ","); line.append(elapsed + ","); line.append(callIndex + ","); line.append(streamId + ","); line.append(escape(returnValue)); // append the args to the method call if (argValues != null) { for (int i = 0; i < argValues.length; i++) { line.append("," + escape(argValues[i])); } } API_TRACE_LOG.info(line); } // convert private static String escape(Object val) { if (val == null) { return "null"; } else if (val instanceof TraceableStream) { TraceableStream ts = (TraceableStream) val; return ts.getStreamTracer().getStreamId().toString(); } else if (val instanceof FileStatus) { FileStatus stat = (FileStatus) val; String properties = "isdir=" + stat.isDir() + ",len=" + stat.getLen(); try { return "#" + SimpleBase64.encode(properties.toString().getBytes("UTF-8")); } catch (java.io.UnsupportedEncodingException e) { return "CouldNotEncode"; } } else if (val instanceof FileStatus[]) { FileStatus stat[] = (FileStatus[]) val; return Integer.toString(stat.length); } else if (val instanceof Long) { return Long.toString((Long) val); } else if (val instanceof Integer) { return Integer.toString((Integer) val); } else if (val instanceof Short) { return Integer.toString((Short) val); } else { try { return "#" + SimpleBase64.encode(val.toString().getBytes("UTF-8")); } catch (java.io.UnsupportedEncodingException e) { return "CouldNotEncode"; } } } protected static long nextStreamId() { return nextStreamId.getAndIncrement(); } /** * Represents a call to a method we trace, and records time info, args, etc. */ public static class CallEvent { private long entryTime; // CallEvent objects should be created at the beginning of a traced method public CallEvent() { entryTime = System.nanoTime(); } public void logCall(int callIndex, Object returnValue, Object argValues[], long streamId, long returnTime) { APITrace.logCall(entryTime, returnTime, callIndex, returnValue, argValues, streamId); } public void logCall(int callIndex, Object returnValue, Object argValues[], long streamId) { long returnTime = System.nanoTime(); APITrace.logCall(entryTime, returnTime, callIndex, returnValue, argValues, streamId); } public void logCall(int callIndex, Object returnValue, Object argValues[]) { logCall(callIndex, returnValue, argValues, -1); } } public static interface TraceableStream { StreamTracer getStreamTracer(); } /** * Interface for all tracing of streams. This serves two purposes beyond what * APITrace provides: (1) track stream IDs, (2) collapse many small calls. * Collapsing many small calls is useful, as some workloads (e.g., HBase) * perform many 1-byte writes. */ public static class StreamTracer { private long streamId; // variables for collapsing calls private CallEvent collapsedCall; private int callCount; private int byteCount; private long returnTime; private static final int maxByteCount = 4096; public StreamTracer() { streamId = nextStreamId(); reset(); } public Long getStreamId() { return streamId; } // log a call that cannot be collapsed public synchronized void logCall(CallEvent event, int callIndex, Object returnValue, Object argValues[]) { flush(); event.logCall(callIndex, returnValue, argValues, getStreamId()); } // log an I/O call that can be collapsed with other calls public synchronized void logIOCall(CallEvent call, long incVal) { if (byteCount + incVal > maxByteCount) { flush(); } // increment aggregates that describe the I/Os if (this.collapsedCall == null) { this.collapsedCall = call; } callCount++; byteCount += incVal; returnTime = System.nanoTime(); if (byteCount >= maxByteCount) { flush(); } } // write log entry for all the small calls that are buffered so far private void flush() { if (collapsedCall == null) { return; } collapsedCall.logCall(CALL_COLLAPSED, null, new Object[] { callCount, byteCount }, getStreamId(), returnTime); reset(); } private void reset() { collapsedCall = null; callCount = 0; byteCount = 0; returnTime = 0; } } }