Coupling error: class file file:/home/runger/.netbeans/dev/var/cache/index/0.8/s128/classes/system/context/LogContext.sig, source file file:/home/runger/dev/app/main/core/sfdc/java/src/system/context/LogContext.java ----- Sig file content: ------------------------------------------- GM1;Nsystem.context.LogContext;;Ljava.lang.Object;Lcommon.util.Establishable;;NPolledStatsTask;Ma;NGCStats;Ma;NData;Ma;; EM1000000001;N;()()V;; AM40019;INCOMMON_LOG_FIELD_COUNT;I13;; AM4001a;INLOG_MEM_BUFFER_SIZE;I100000;; AM4001a;INsampleInterval;I5000;; AM4001a;INgcSampleInterval;I10000;R;;; AM4001a;Ljava.lang.String;NLOG_NA;LN/A;; AM40019;Ljava.lang.String;NRECORDS;Lr;; AM40019;Ljava.lang.String;NFIELD_SEP;L:;; AM40019;Ljava.lang.String;NPARAM_SEP;L\b;; AM4001c;Ljava.util.logging.Logger;Nlogger;X;; AM1a;INavailableProcessors;X;R;;; AM1a;RSizeStatistic;NtotalRequests;X;; AM1a;RSizeStatistic;NtotalApiRequests;X;; AM1a;RStandardStatistic;NresponseTimeStat;X;; AM4001a;[Ljava.lang.String;NINFO_PARAMS;X;; AM4001a;RCounter;NrequestPerSec;X;; AM4001a;RCounter;NapexRequestPerSec;X;; AM4001a;RCounter;NapexPagesRequest;X;; AM4001a;RCounter;NstaticResourceRequest;X;; AM4001a;RCounter2;NresponseTime;X;; AM4001a;RCounter2;NcpuUsage;X;; AM4001a;RCounter;NgcPerMinute;X;; AM4001a;RCounter2;NgcUsage;X;; AM4001a;RStandardStatistic;NgcTotalCount;X;; AM4001a;RStandardStatistic;NgcTotalTimeSecs;X;; AM4001a;RStandardStatistic;NgcYoungGenSize;X;; AM4001a;RStandardStatistic;NgcOldGenSize;X;; AM4001a;RStandardStatistic;NgcPermGenSize;X;; AM4001a;RGauge;NtotalOpenFileDescriptors;X;; AM4a;JNlastCpuTimeNanos;X;; AM4a;JNlastCpuTimeAtNanos;X;; AM4a;DNcpuUsagePercent;X;; AM4001a;Ljava.lang.management.ThreadMXBean;NTHREAD_BEAN;X;; AM1a;Lcom.sun.management.OperatingSystemMXBean;NOS_BEAN;X;; AM1a;ZNCPU_TRACKING_ENABLED;X;; AM1a;ZNUNIX_BEAN_AVAILABLE;X;; AMa;Ljava.lang.reflect.Method;NFD_COUNT_METHOD;X;; AM1a;ZNCPU_HACK;X;; EM1;NgetOneMinuteAverageGCUsage;()()D;; EM8;NgetGCStats;()()Lsystem.context.LogContext$GCStats;;; AM4001a;Ljava.util.concurrent.atomic.AtomicLong;NtotalRequestCount;X;; AM4001a;Ljava.util.concurrent.atomic.AtomicLong;NtotalApiRequestCount;X;; AM4001a;Ljava.util.concurrent.atomic.AtomicLong;NtotalApexRequestCount;X;; AM4001a;Ljava.util.concurrent.atomic.AtomicLong;NtotalApexPagesRequestCount;X;; AM4001a;Ljava.util.concurrent.atomic.AtomicLong;NtotalStaticResourceRequestCount;X;; AM4001a;Ljava.util.concurrent.atomic.AtomicLong;NtotalRequestTime;X;; AM4001a;Ljava.util.concurrent.atomic.AtomicLong;NtotalCpuTime;X;; AM2;Lsystem.context.LogContext$Data;Ndata;X;; AM40014;Lsystem.context.LogData;NlogData;X;; AM4000a;Ljava.lang.ThreadLocal;Ntl;X;; EM9;NgetContext;()()Lsystem.context.LogContext;;; EM2;NisEstablishedInstance;()()Z;; EM1;Nestablished;()()Z;; EM1;NgetWhenEstablished;()()J;; EM1;NgetEstablishedType;()()Ljava.lang.String;;; EM1;NgetWhereEstablished;()()[Ljava.lang.StackTraceElement;;; EM1;NgetWhoEstablished;()()Ljava.lang.String;;; EM1;NgetTimeTracker;()()Lcommon.perf.TimeTracker;;; EM9;Nestablish;(M200000000;Ljava.lang.String;NlogName;)()V;; EM9;Nestablish;(M200000000;Ljava.lang.String;NlogName;M200000000;Ljava.lang.String;NremoteAddr;)()V;; EM8;NestablishUserAndOrgIds;(M200000000;Ljava.lang.String;NuserId;M200000000;Ljava.lang.String;NorgId;)()V;; EM8;NsetApiQueryString;(M200000000;Ljava.lang.String;NapiQueryString;)()V;; EM9;NisEstablished;()()Z;; EM9;NincrementApexRequestCount;()()V;; EM9;NincrementApexPagesRequestCount;()()V;; EM9;NincrementStaticResourceRequestCount;()()V;; EM9;Nrelease;()()V;; EM1;NestablishableRelease;()()V;; EM2;NestablishableRelease;(M200000000;ZNdoLog;)()V;; EM2;NgetOracleStats;()()Lsystem.context.OracleStatistics;;; EM0;NpushOracleStatistics;(M200000000;Lsystem.context.OracleStatistics;NoracleStats;)()V;; EM9;NisHttp;(M200000000;Ljavax.servlet.http.HttpServletRequest;Nrequest;)()Z;; EM9;Nrelease;(M200000000;ZNdoLog;)()V;; EM2;NlogInefficientRequests;()()V;; EM0;NgetInefficientRequestMessage;(M200000000;Ljava.lang.String;Ninefficiency;M200000000;Ljava.lang.Exception;Ne;)()Ljava.lang.String;;; EMa;NgetOrgIdFromContext;(M200000000;Lsystem.context.LogContext;Nc;)()Ljava.lang.String;;; EMa;NgetUserIdFromContext;(M200000000;Lsystem.context.LogContext;Nc;)()Ljava.lang.String;;; EMa;NappendAdditionalParams;(M200000000;Lsystem.context.LogData;NlogData;)()V;; EM9;NgetRuntime;()()J;; EM2;NgetRuntimeInstance;()()J;; EM9;NgetStartTime;()()J;; EM9;NgetCpuUsage;()()J;; EM9;NgetOverallCpuPercent;()()D;; EM8;NgetThreadCpuTimeNanos;(M200000000;JNthreadId;)()J;; EM9;NgetLogName;()()Ljava.lang.String;;; EM9;NsetLogName;(M200000000;Ljava.lang.String;NlogName;)()V;; EM9;NgetLogRecordType;()()RLogRecordEnum;;; EM9;NsetSuppressLogging;(M200000000;ZNs;)()V;; EM9;NgetGackUniqueId;()()Ljava.lang.String;;; EM9;NsetGackUniqueId;(M200000000;Ljava.lang.String;NgackUniqueId;)()V;; EM9;NaddSearchQueryTime;(M200000000;JNdeltaInMs;)()V;; EM9;NaddCacheServerTime;(M200000000;JNdeltaInMs;)()V;; EM9;NaddFetch;()()V;; EM9;NapiLog;(M200000000;Ljava.lang.String;Ns;)()V;; EM9;NapiLog;(M200000000;INi;)()V;; EM9;Nlog;(M200000000;Ljava.lang.String;Ns;)()V;; EM9;Nlog;(M200000000;INi;)()V;; EM9;NaddLogField;(M200000000;RLogRecordFieldEnum;Nkey;M200000000;QT;Nvalue;)()V;; EM9;NaddExtraLogField;(M200000000;Ljava.lang.String;Nkey;M200000000;Ljava.lang.String;Nvalue;)()V;; EM9;NsetApexLogStatus;(M200000000;Ljava.lang.String;Nstatus;)()V;; EM9;NsetApexLogSent;(M200000000;ZNclear;)()V;; EM9;NappendApexLog;(M200000000;Ljava.lang.String;NlogEntry;)()V;; EM9;NappendApexLog;(M200000000;Ljava.lang.CharSequence;NlogEntry;M200000000;ZNappendNewline;)()V;; EMa;NappendApexLogInternal;(M200000000;Ljava.lang.CharSequence;NlogEntry;M200000000;ZNappendNewline;)()V;; EM9;NgetApexLog;()()RBufferedAppendable;;; EM9;NclearApexLog;()()V;; EM9;NgetApexLogLength;()()I;; EM9;NgetApexUserLogCount;()()I;; EM9;NupdateApexUserLogCount;(M200000000;Ljava.lang.String;NuserId;M200000000;INlogCount;)(Ljava.sql.SQLException;)V;; EMa;NsetApexUserLogCount;(M200000000;INlogCount;)()V;; AM4000a;INMAX_LOG_ENTRIES_PER_ORG;X;; AM4000a;INMAX_STATUS_LENGTH;X;; EMa;NpersistDebugLog;(M200000000;RBufferedAppendable;Nlog;M200000000;Ljava.lang.String;NlogStatus;)()V;; W; ----- Source file content: ---------------------------------------- /* * Copyright 1999-2004, salesforce.com All Rights Reserved Company Confidential */ package system.context; import java.io.IOException; import java.io.Writer; import java.lang.management.*; import java.lang.reflect.Method; import java.sql.Clob; import java.sql.SQLException; import java.util.*; import java.util.concurrent.atomic.AtomicLong; import java.util.logging.Level; import java.util.logging.Logger; import javax.servlet.http.HttpServletRequest; import platform.util.gack.GackLevel; import platform.util.logging.*; import platform.util.logging.fieldtypes.LogFieldType; import com.caucho.util.HashMapImpl; import com.salesforce.login.Login; import com.sun.management.OperatingSystemMXBean; import system.filter.StatsOnlyFilter; import system.init.Globals; import system.loadbalancer.LoadBalancerStats; import system.monitor.MemTracker; import system.plsql.*; import system.security.session.Session; import shared.logging.*; import shared.statistic.*; import shared.util.*; import common.apex.ApexContext; import common.cache.CacheManager; import common.perf.TimeTracker; import common.request.*; import common.search.client.ui.AbstractSearchResults; import common.search.client.ui.SearchPage; import common.sql.SfdcOptimizerTrace; import common.udd.Udd; import common.udd.constants.ApexLogFields; import common.udd.constants.UserPreferenceTypeEnum; import common.util.*; import common.util.database.ProtectedConnection; import admin.util.SysAdmin; import tools.LogPlayback; /** * @author davem * @since 134 */ public class LogContext implements Establishable { public static final int COMMON_LOG_FIELD_COUNT = 13; private static final int LOG_MEM_BUFFER_SIZE = 100000; private static final int sampleInterval = 5000; // In ms must be a factor of 60000 @TestAccessible private static final int gcSampleInterval = sampleInterval * 2; private static final String LOG_NA = "N/A"; public static final String RECORDS = "r"; public static final String FIELD_SEP = ":"; public static final String PARAM_SEP = ";"; protected static final Logger logger = SFDCLog.open(LogContext.class); @TestAccessible private static final int availableProcessors; private static final SizeStatistic totalRequests; private static final SizeStatistic totalApiRequests; private static final StandardStatistic responseTimeStat; // Starting in 140 retURL and startURL were logged to look for redirect security violations. private static final String[] INFO_PARAMS = {"retURL", "startURL", "delID", "lid", SysAdmin.pOID.getParameterName()}; private static final OneFiveFifteenStatistic.Counter requestPerSec = new OneFiveFifteenStatistic.Counter("System", "AveRequestPerSec", sampleInterval); private static final OneFiveFifteenStatistic.Counter apexRequestPerSec = new OneFiveFifteenStatistic.Counter("System", "AveApexRequestPerSec", sampleInterval); private static final OneFiveFifteenStatistic.Counter apexPagesRequest = new OneFiveFifteenStatistic.Counter("System", "AveApexPageUsage", sampleInterval); private static final OneFiveFifteenStatistic.Counter staticResourceRequest = new OneFiveFifteenStatistic.Counter("System", "AveStaticResourceUsage", sampleInterval); private static final OneFiveFifteenStatistic.Counter2 responseTime = new OneFiveFifteenStatistic.Counter2("System", "AveResponseTime", sampleInterval); private static final OneFiveFifteenStatistic.Counter2 cpuUsage = new OneFiveFifteenStatistic.Counter2("System", "AveCPUUsage", gcSampleInterval); // Although we have new persistent stats now, leave these two old ones as they are being used by the PingPage etc. private static final OneFiveFifteenStatistic.Counter gcPerMinute = new OneFiveFifteenStatistic.Counter("System", "AveGCPerMinute", gcSampleInterval); private static final OneFiveFifteenStatistic.Counter2 gcUsage = new OneFiveFifteenStatistic.Counter2("System", "AveGCUsage", gcSampleInterval); // persistent GC stats private static final StandardStatistic gcTotalCount = new StandardStatistic("System", "GC Count"); private static final StandardStatistic gcTotalTimeSecs = new StandardStatistic("System", "GC Time Seconds"); private static final StandardStatistic gcYoungGenSize = new StandardStatistic("System", "Heap Size Young Gen"); private static final StandardStatistic gcOldGenSize = new StandardStatistic("System", "Heap Size Old Gen"); private static final StandardStatistic gcPermGenSize = new StandardStatistic("System", "Heap Size Perm Gen"); private static final OneFiveFifteenStatistic.Gauge totalOpenFileDescriptors = new OneFiveFifteenStatistic.Gauge("System", "AveOpenFileDescriptors", gcSampleInterval); private static volatile long lastCpuTimeNanos; private static volatile long lastCpuTimeAtNanos; private static volatile double cpuUsagePercent; /** We need the ThreadMXBean to track cpu usage of requests */ private static final ThreadMXBean THREAD_BEAN = ManagementFactory.getThreadMXBean(); private static final OperatingSystemMXBean OS_BEAN; private static final boolean CPU_TRACKING_ENABLED; private static final boolean UNIX_BEAN_AVAILABLE; private static Method FD_COUNT_METHOD; private static final boolean CPU_HACK; static { totalRequests = new SizeStatistic("System", "totalRequests"); totalApiRequests = new SizeStatistic("System", "totalApiRequests"); SizeStatistic fileDescriptors = new SizeStatistic("System", "fileDescriptors"); responseTimeStat = new StandardStatistic("System", "responseTime"); CPU_HACK = false; // System.getProperty("os.name").startsWith("Linux") && System.getProperty("os.version").startsWith("2.4"); if (THREAD_BEAN.isThreadCpuTimeSupported()) { if (!THREAD_BEAN.isThreadCpuTimeEnabled()) THREAD_BEAN.setThreadCpuTimeEnabled(true); CPU_TRACKING_ENABLED = true; } else { CPU_TRACKING_ENABLED = false; } StatisticSet s = system.init.CommonInitializer.getGlobalStatistics(); s.add(totalRequests); s.add(totalApiRequests); s.add(responseTimeStat); s.add(requestPerSec); s.add(apexRequestPerSec); s.add(apexPagesRequest); s.add(staticResourceRequest); s.add(responseTime); s.add(cpuUsage); s.add(gcPerMinute); s.add(gcUsage); s.add(gcTotalCount); s.add(gcTotalTimeSecs); s.add(gcPermGenSize); s.add(gcYoungGenSize); s.add(gcOldGenSize); java.lang.management.OperatingSystemMXBean osBean = ManagementFactory.getOperatingSystemMXBean(); availableProcessors = osBean == null ? 2 : osBean.getAvailableProcessors(); if (osBean instanceof com.sun.management.OperatingSystemMXBean) { OS_BEAN = (com.sun.management.OperatingSystemMXBean) osBean; // NOTE: Do not change the average sample time without changing the Debug.globalTimer.schedule(new ProtectedTimerTask(new PolledStatsTask()), 0, sampleInterval); } else { OS_BEAN = null; // does this ever happen? } if (System.getProperty("os.name").startsWith("Windows")) { UNIX_BEAN_AVAILABLE = false; } else { UNIX_BEAN_AVAILABLE = true; if (UNIX_BEAN_AVAILABLE) { try { Class UNIX_BEAN_CLASS = Class.forName("com.sun.management.UnixOperatingSystemMXBean"); Method m = UNIX_BEAN_CLASS.getMethod("getMaxFileDescriptorCount"); Object val = m.invoke(OS_BEAN, (Object[])null); if (val != null) { fileDescriptors.update((Long)val); } FD_COUNT_METHOD = UNIX_BEAN_CLASS.getMethod("getOpenFileDescriptorCount"); } catch (Exception e) { logger.log(Level.INFO, "Error loading UnixOperatingSystemMXBean", e); } } s.add(fileDescriptors); s.add(totalOpenFileDescriptors); } // Setup LogNameSource for this application SFDCLogFormatter.setLogNameSource(new LogNameSource() { public String getName() { return getLogName(); } }); // Setup ContextListener for shared classes shared.util.ContextManager.setContextListener(new ContextListener() { public void establish(String name) { ThreadTracker tt = ThreadTracker.getThreadTracker(); tt.getAndSetTrackContext(ThreadTracker.TRACK_LOG_CONTEXT | ThreadTracker.TRACK_DB_CONTEXT); LogContext.establish(name); DBContext.getContext().setOkayForPljavaToEstablishConnection(); } public void release() { try { DBContext.getContext().release(); } finally { LogContext.release(false); } } }); } private static class PolledStatsTask extends TimerTask { //long lastNanoCPUTime; // in nano seconds //long lastNanoCPUClockTime; // in nano seconds //long lastGCCPUTime; // in ms long lastGcClockTime; // in ms PolledStatsTask() {} private long getCpuTimeNanos(long gcMilliTime) { long ret = (OS_BEAN != null) ? OS_BEAN.getProcessCpuTime() : 0; return (CPU_HACK) ? ret + (totalCpuTime.get() + gcMilliTime) * 1000000 : ret; } @Override public void run() { // Do the request time long count = totalRequestCount.get(); long requestTime = totalRequestTime.get(); totalRequests.update(count); totalApiRequests.update(totalApiRequestCount.get()); if (count > 0) { responseTimeStat.update(requestTime / count); responseTime.update(requestTime, count); } requestPerSec.update(count * 1000 / sampleInterval); apexRequestPerSec.update(totalApexRequestCount.get() * 1000 / sampleInterval); apexPagesRequest.update(totalApexPagesRequestCount.get() * 1000 / sampleInterval); staticResourceRequest.update(totalStaticResourceRequestCount.get() * 1000 / sampleInterval); // Do the GC time long curTime = System.currentTimeMillis(); if (curTime >= lastGcClockTime + gcSampleInterval) { lastGcClockTime = curTime; // Sample the GC here GCStats gc = getGCStats(); gcPerMinute.update(gc.count * 60000 / gcSampleInterval); gcUsage.update(gc.timeMs * 100, curTime); // persistent GC stat gcTotalCount.update(gc.count); gcTotalTimeSecs.update(gc.timeMs / 1000); gcYoungGenSize.update(gc.youngGenSize); gcOldGenSize.update(gc.oldGenSize); gcPermGenSize.update(gc.permGenSize); // Do the CPU time // The CPU time changes very slowly on Linux so this is executed less frequently the GC time is passed for a hack long cpuTimeNanos = getCpuTimeNanos(gc.timeMs); long curNanoTime = System.nanoTime(); cpuUsage.update(cpuTimeNanos * 100, curNanoTime * availableProcessors); if (lastCpuTimeNanos > 0) cpuUsagePercent = ((double) cpuTimeNanos - lastCpuTimeNanos) / (curNanoTime - lastCpuTimeAtNanos) / availableProcessors; lastCpuTimeNanos = cpuTimeNanos; lastCpuTimeAtNanos = curNanoTime; // Sample the file descriptors if (UNIX_BEAN_AVAILABLE && OS_BEAN != null) { try { Object val = FD_COUNT_METHOD.invoke(OS_BEAN, (Object[])null); if (val != null) { totalOpenFileDescriptors.update((Long)val); } } catch (Exception e) { // Skip error because this will fill up the logs } } } } } public double getOneMinuteAverageGCUsage() { return gcUsage.getOneMinuteAverage(); } static GCStats getGCStats() { List gcBeans = ManagementFactory.getGarbageCollectorMXBeans(); long count = 0, time = 0; for (GarbageCollectorMXBean bean : gcBeans) { long val = bean.getCollectionCount(); if (val > 0) count += val; val = bean.getCollectionTime(); if (val > 0) time += val; } long permGenSize = 0, youngGenSize = 0, oldGenSize = 0; for (MemoryPoolMXBean pool : ManagementFactory.getMemoryPoolMXBeans()) { if (pool.getType() == MemoryType.HEAP) { if (pool.getName().equals("Eden Space")) { youngGenSize = pool.getUsage().getUsed(); } else if (pool.getName().equals("Tenured Gen")) { oldGenSize = pool.getUsage().getUsed(); } } else if (pool.getName().equals("Perm Gen")) { permGenSize = pool.getUsage().getUsed(); } } return new GCStats(count, time, youngGenSize, oldGenSize, permGenSize); } private static class GCStats { final long count; final long timeMs; final long youngGenSize; final long oldGenSize; final long permGenSize; private GCStats(long count, long time, long youngGenSize, long oldGenSize, long permGenSize) { this.count = count; this.timeMs = time; this.youngGenSize = youngGenSize; this.oldGenSize = oldGenSize; this.permGenSize = permGenSize; } } private static class Data { private final long startTime; private final long startCpuUsage; private final long startGcTime; private final String whoEstablished; private String logName; private boolean suppressLogging; private final String remoteAddr; private String gackUniqueId; private final AtomicLong searchQueryTime; private final AtomicLong cacheServerTime; private final AtomicLong fetchCount; private String orgId = null; private String userId = null; private String apiQueryString = null; // For keeping & persisting of the ApexLog private BufferedAppendable apexLog; private String apexLogStatus = null; // during the context lifetime, callers can indicate there was some trouble private boolean apexLogSent; // set when this is flushed out private int apexUserLogCount = - 1; private boolean apexUserLogCountInvalid; //TimeTracker trackes time taken for events. private final TimeTracker timeTracker = TimeTracker.getInstance(); private OracleStatistics oracleStatistics; private long startMem; Data(String logName, String remoteAddr) { this.whoEstablished = Thread.currentThread().getName(); this.startTime = System.currentTimeMillis(); this.startCpuUsage = (CPU_TRACKING_ENABLED ? THREAD_BEAN.getCurrentThreadCpuTime() : -1); this.startGcTime = getGCStats().timeMs; this.logName = logName; this.remoteAddr = remoteAddr; this.searchQueryTime = new AtomicLong(0); this.cacheServerTime = new AtomicLong(0); this.fetchCount = new AtomicLong(0); this.startMem = MemTracker.getThreadCount(); } private void destroyApexLog() { try { if (this.apexLog != null) this.apexLog.cleanUp(); } catch (IOException ex) { new BaseSfdcGack(GackLevel.SEVERE, ex).send(); } finally { this.apexLog = null; } } } private static final AtomicLong totalRequestCount = new AtomicLong(); private static final AtomicLong totalApiRequestCount = new AtomicLong(); private static final AtomicLong totalApexRequestCount = new AtomicLong(); private static final AtomicLong totalApexPagesRequestCount = new AtomicLong(); private static final AtomicLong totalStaticResourceRequestCount = new AtomicLong(); private static final AtomicLong totalRequestTime = new AtomicLong(); private static final AtomicLong totalCpuTime = new AtomicLong(); private Data data; protected final LogData logData = new LogDataImpl(); private static ThreadLocal tl = new ThreadLocal() { @Override protected LogContext initialValue() { return new LogContext(); } }; /** Get a LogContext for the calling thread */ public static LogContext getContext() { return tl.get(); } private boolean isEstablishedInstance() { return this.data != null; } public boolean established() { return isEstablishedInstance(); } public long getWhenEstablished() { if (this.data == null) return -1; return this.data.startTime; } public String getEstablishedType() { return "LogContext"; } /** * Not tracked currently for LogContext. */ public StackTraceElement[] getWhereEstablished() { return null; } public String getWhoEstablished() { if (this.data == null) return null; return this.data.whoEstablished; } public TimeTracker getTimeTracker() { if (data == null) { throw new NullPointerException("Context not established"); } assert data.timeTracker != null; return data.timeTracker; } public static void establish(String logName) { establish(logName, LOG_NA); } public static void establish(String logName, String remoteAddr) { LogContext c = getContext(); c.data = new Data(logName, remoteAddr); ThreadTracker.getThreadTracker().setLogContext( new ThreadTrackersLogContext(Thread.currentThread().getId(), c.data.startTime, c.data.startCpuUsage)); } static void establishUserAndOrgIds(String userId, String orgId) { LogContext c = getContext(); if (c.isEstablishedInstance()) { c.data.userId = userId; c.data.orgId = orgId; } } static void setApiQueryString(String apiQueryString){ LogContext c = getContext(); if (c.isEstablishedInstance()) { c.data.apiQueryString = apiQueryString; } } public static boolean isEstablished() { return getContext().isEstablishedInstance(); } public static void incrementApexRequestCount() { totalApexRequestCount.incrementAndGet(); } public static void incrementApexPagesRequestCount() { totalApexPagesRequestCount.incrementAndGet(); } public static void incrementStaticResourceRequestCount() { totalStaticResourceRequestCount.incrementAndGet(); } public static void release() { release(true); } public void establishableRelease() { establishableRelease(true); } private void establishableRelease(boolean doLog) { if (!established()) return; // no LogContext, so nothing to do try { boolean isUserContextEstablished = UserContext.get().established(); long cpuTime = (isUserContextEstablished || doLog) ? (CPU_TRACKING_ENABLED ? (THREAD_BEAN.getCurrentThreadCpuTime() - data.startCpuUsage) / 1000000 : 0) : 0; long objectAllocations = MemTracker.ENABLED ? MemTracker.getThreadCount() - data.startMem : 0; if (isUserContextEstablished) { // if we're doing bt, we log the request twice for the load balancer, once for the 62 org and once for the org we're looking at String orgId = UserContext.get().getOrganizationId(); String loggedInOrgId = UserContext.get().getOrganizationIdForLoggedInUser(); if (orgId != null) { if (orgId.equals(loggedInOrgId)) { LoadBalancerStats.get().logRequestEnd(orgId, cpuTime); } else { LoadBalancerStats.get().logRequestEnd(orgId, cpuTime / 2); LoadBalancerStats.get().logRequestEnd(loggedInOrgId, cpuTime / 2); } } // Persist Apex logs, first making sure any residual Apex log stuff is flushed out. ApexContext ac = UserContext.get().getApexContextOrNull(); if (ac != null) ac.flushDebugLog(); Data tdata = getContext().data; if (tdata != null) { persistDebugLog(getApexLog(), tdata.apexLogStatus); // Double check if (RequestContext.get().established() && !ApiContext.isApi() && ApexContext.isDebugLogUIEnabled() && tdata.apexLog != null && !tdata.apexLogSent) { new BaseSfdcGack(GackLevel.SEVERE, "LogContext.release: showApexLog.AppBodyFooter not called.").send(); } // Help out ftests if (tdata.apexLog != null && TestContext.isRunningTests() && TestContext.getTestValue(TestContext.APEX_PRESERVE_STATEMENTLOG) != null) { Object val = TestContext.getTestValue(TestContext.APEX_PRESERVE_STATEMENTLOG); try { // Add it in or start the accumulation if (val instanceof Appendable) { // Add this into the current accumulation. StringBuilder buf = ((StringBuilder)val); buf.append("\n"); tdata.apexLog.appendTo(buf); } else { TestContext.pushTestValue(TestContext.APEX_PRESERVE_STATEMENTLOG, tdata.apexLog.getContents(0)); } } catch (IOException ex) { new BaseSfdcGack(GackLevel.SEVERE, ex).send(); } } tdata.destroyApexLog(); } } if (doLog) { long runTime = LogContext.getRuntime(); totalRequestCount.incrementAndGet(); if (logData.getLogRecordType() == LogRecordEnum.API) totalApiRequestCount.incrementAndGet(); totalRequestTime.addAndGet(runTime); totalCpuTime.addAndGet(cpuTime); // Log the request. if (!data.suppressLogging) { UserInfo uInfo = UserContext.get().getUserInfo(true); logData.addLogField(CommonLogRecord.ORGANIZATIONID_basic, getOrgIdFromContext(this)); logData.addLogField(CommonLogRecord.USERID_basic, getUserIdFromContext(this)); logData.addLogField(CommonLogRecord.RUNTIME_basic, runTime); logData.addLogField(CommonLogRecord.CPUTIME_basic, cpuTime); String remoteAddr = ""; try { remoteAddr = RequestContext.get().established() ? RequestContext.get().getRequest().getRemoteAddr() : data.remoteAddr; } catch (Exception x) { // we've seen NPE's in caucho from the waiting page threads. } logData.addLogField(CommonLogRecord.REMOTEADDR_basic, remoteAddr); logData.addLogField(CommonLogRecord.LOGNAME_basic, TextUtil.replaceColonWithHexAscii(data.logName)); logData.addLogField(CommonLogRecord.CACHETIME_common, data.cacheServerTime.get()); logData.addLogField(CommonLogRecord.SEARCHTIME_common, data.searchQueryTime.get()); logData.addLogField(CommonLogRecord.REQUESTSTATUS_common, RequestContext.get().getStatus() != null ? RequestContext.get().getStatus().toString() : null); ApexContext apexContext = UserContext.get().getApexContextOrNull(); logData.addLogField(CommonLogRecord.APEXEXECUTIONTIME_common, apexContext == null ? 0L : apexContext.getExecutionTime()); logData.addLogField(CommonLogRecord.APEXCALLOUTTIME_common, apexContext == null ? 0L : apexContext.getCalloutTime()); logData.addLogField(CommonLogRecord.TIMETRACKER_common, data.timeTracker.getLogString()); List children = logData.getChildContexts(); // not api request; print out url and other UI-based info if (logData.getLogRecordType() == LogRecordEnum.URI) { // Log the organizationId if it's a selfservice user. This was added in 124 to track CSS usage. logData.addLogField(URILogRecord.ISSSUSER_U, uInfo != null && uInfo.isSSUser()); } OracleStatistics oracleStats = null; if (DBContext.getContext().isGatheringOracleStatistics() || this.data.oracleStatistics != null) { oracleStats = getOracleStats(); String oraStatsString = oracleStats != null ? oracleStats.toString() : null; if (MemTracker.ENABLED){ if (oraStatsString != null) // This is really a java stat, not an oracle stat, but it won't be there at all unless // you're using the special perfjdk, so I didn't want to create a new field for it. oraStatsString += objectAllocations + "j"; } logData.addLogField(LogRecordFieldEnum.oracleStats_common, oraStatsString); } appendAdditionalParams(logData); logData.commitLogData(logger); // Record summary statistics for stats-only output mode // We could just send the log string, since it has pretty much all the data we want, but it's not always constant // and might be trickier for clients to parse. if (StatsOnlyFilter.isStatsOnlyMode()) { StatsOnlyFilter.addStatistic("clockTime", runTime); StatsOnlyFilter.addStatistic("appserverCpuTime", cpuTime); StatsOnlyFilter.addStatistic("gcTime", getGCStats().timeMs - data.startGcTime); StatsOnlyFilter.addStatistic("db_fetches", data.fetchCount.get()); if (oracleStats != null) oracleStats.addToStatsOnlyFilter(); StatsOnlyFilter.addStatistic("cacheTime", data.cacheServerTime.get()); StatsOnlyFilter.addStatistic("searchTime", data.searchQueryTime.get()); StatsOnlyFilter.addAttribute("optimizerTrace", SfdcOptimizerTrace.getTraceAsString()); } if (children != null) { // children share all common attributes, so add all those params. Map> childCommonParams = new HashMapImpl>(); Map> parentParams = logData.getLogFields(); for (LogRecordFieldEnum fieldEnum: LogRecordEnum.Common.getLogContextParams()) { childCommonParams.put(fieldEnum, parentParams.get(fieldEnum)); } for (LogData cld : children) { cld.addAllLogFields(childCommonParams); cld.commitLogData(logger); } } } logInefficientRequests(); } } finally { data.timeTracker.reset(); data = null; try { ThreadTracker.getThreadTracker().setLogContext(null); } finally { logData.release(); } } } /** * @return may return null */ private OracleStatistics getOracleStats() { // see if we have anything local. OracleStatistics local = (this.data != null) ? this.data.oracleStatistics : null; // see if there are any left on DBContext OracleStatistics dbCtx = null; if (DBContext.getContext().isGatheringOracleStatistics()) { dbCtx = DBContext.getContext().getOracleStatistics(); } if (local == null) return dbCtx; return local.combine(dbCtx); } /** * If DBContext gets released before the LogContext does, then we need to push in the current stats * * @param oracleStats if null, then it will be ignored. */ void pushOracleStatistics(OracleStatistics oracleStats) { if (this.data == null || oracleStats == null) return; if (this.data.oracleStatistics == null) { this.data.oracleStatistics = oracleStats; } else { this.data.oracleStatistics = this.data.oracleStatistics.combine(oracleStats); } } public static boolean isHttp(HttpServletRequest request) { if(request == null) { return false; } return TextUtil.isNullEmptyOrWhitespace(RequestContext.get().getCipherSuite(request)); } public static void release(boolean doLog) { getContext().establishableRelease(doLog); } private void logInefficientRequests() { if (DBContext.getContext().established()){ String inefficiency = DBContext.getContext().getInefficiencies(); if (inefficiency != null){ try { logger.info(getInefficientRequestMessage(inefficiency, new Exception())); } catch (Exception e) { // ignore exception while logging } } } } String getInefficientRequestMessage(String inefficiency, Exception e) { StringBuilder msgBody = new StringBuilder(128); if (UserContext.get().established()){ msgBody.append(UserContext.get().getOrganizationId()).append(":"); msgBody.append(UserContext.get().getUserId()).append(":"); } else { msgBody.append(data.orgId == null ? "" : data.orgId).append(":"); msgBody.append(data.userId == null ? "" : data.userId).append(":"); } msgBody.append("Inefficient request: ").append(inefficiency); if (data.apiQueryString != null){ msgBody.append(":").append("Api query = ").append(data.apiQueryString); } msgBody.append("\n"); if (logger.isLoggable(Level.FINER)) { msgBody.append(ErrorNotification.generateClientHeaders(RequestContext.get().getRequest())); msgBody.append(ErrorNotification.generateParameters(RequestContext.get().getRequest())); msgBody.append("Thread (ID,Name): ").append(Thread.currentThread().getId()).append(","); msgBody.append(Thread.currentThread().getName()).append("\n"); msgBody.append("stack trace:\n"); for (StackTraceElement element : e.getStackTrace()) { msgBody.append(element.toString()).append("\n"); } } return msgBody.toString(); } /** * Get the org id from the context data first if it's set * otherwise try to obtain from the UserContext * see http://bugforce/bug/bugDetail.jsp?id=100000000000izY for more details * * @param c * @return */ private static String getOrgIdFromContext(LogContext c) { return c.data.orgId == null ? UserContext.get().getOrganizationIdForLoggedInUser() : c.data.orgId; } /** * Similar to getOrgId, we should first try to get it from the context data * @param c * @return */ private static String getUserIdFromContext(LogContext c) { return c.data.userId == null ? UserContext.get().getUserId(true) : c.data.userId; } /** * Append any additional parameters from the query string that need logging. */ private static void appendAdditionalParams(LogData logData) { QueryString qs = RequestContext.get().getQueryString(); if (qs != null) { for (String param : INFO_PARAMS) { String val = qs.get(param); if (null != val) { logData.addExtraLogParam(param, TextUtil.stripIsoControlAndOddUnicode(val)); } } } // Search results-specific parameters if (qs != null) { String searchResultPos = qs.get(AbstractSearchResults.SEARCH_RESULTS_POSITION); String searchResultKp = qs.get(AbstractSearchResults.SEARCH_RESULTS_KEY_PREFIX); if (searchResultPos != null && searchResultKp != null) { HttpServletRequest req = RequestContext.get().getRequest(); if (req != null) { String referer = req.getHeader("Referer"); if (SearchPage.isSearchPage(referer)) { logData.addExtraLogParam(AbstractSearchResults.SEARCH_RESULTS_POSITION, searchResultPos); logData.addExtraLogParam(AbstractSearchResults.SEARCH_RESULTS_KEY_PREFIX, searchResultKp); // append sort and filter params String hasFilter = qs.get(AbstractSearchResults.SEARCH_RESULTS_HAS_FILTER); String hasSort = qs.get(AbstractSearchResults.SEARCH_RESULTS_HAS_SORT); String isTag = qs.get(AbstractSearchResults.SEARCH_RESULTS_IS_TAG); if (hasFilter != null) { logData.addExtraLogParam(AbstractSearchResults.SEARCH_RESULTS_HAS_FILTER, hasFilter); } if (hasSort != null) { logData.addExtraLogParam(AbstractSearchResults.SEARCH_RESULTS_HAS_SORT, hasSort); } if (isTag != null) { logData.addExtraLogParam(AbstractSearchResults.SEARCH_RESULTS_IS_TAG, isTag); } } } } } // This is currently only used by LogPlayback. If more areas require knowledge of the portal id, // this should be pushed up to where User Id and Org Id are. Many people will have to be notified // of this change as many places expect the format of the logs to be very specific. // //app/docs/devdocs/LoggingFormat.doc must be updated with the changes. if (UserContext.get().getPortalInfo() != null) { logData.addExtraLogParam(LogPlayback.PORTAL_ID_KEY, UserContext.get().getPortalInfoAssertNotNull().getPortalId()); } //log machine id for app requests HttpServletRequest req = RequestContext.get().getRequest(); LogContext c = getContext(); if (req != null) { String cookies = Login.getLoginIpCookies(req); //If there isn't already a cookie, there isn't a machine ID, so no reason to log this if(!TextUtil.isNullEmptyOrWhitespace(cookies)) { String machineId = LoginIpCookieInfo.getInstance(getOrgIdFromContext(c), getUserIdFromContext(c), cookies).getMachineId(); if (machineId.length() > 0) { logData.addExtraLogParam(LoginIpCookieInfo.MACHINE_ID, machineId); } } } //log session id hash for all requests if session is not null Session session = RequestContext.get().getSession(); if (session != null) { String sessionIdHash = session.getSessionHashValue(); if (sessionIdHash.length() > 0) { logData.addExtraLogParam(Session.SESSION_ID_HASH, sessionIdHash); } } if (c.logData.getLogRecordType() == LogRecordEnum.URI || c.logData.getLogRecordType() == LogRecordEnum.API) { // Log whether it was https if(isHttp(req)) { logData.addExtraLogParam("isHttp", "true"); } } } public static long getRuntime() { return getContext().getRuntimeInstance(); } private long getRuntimeInstance() { Data tdata = this.data; return (tdata != null) ? (System.currentTimeMillis() - tdata.startTime) : 0; } public static long getStartTime() { Data tdata = getContext().data; return (tdata != null) ? tdata.startTime : 0; } /** * Returns the number of milliseconds of cpu consumed by the current thread */ public static long getCpuUsage() { Data tdata = getContext().data; return tdata != null && CPU_TRACKING_ENABLED ? (THREAD_BEAN.getCurrentThreadCpuTime() - tdata.startCpuUsage) / 1000000 : -1; } /** * Returns the percent (0.0-1.0) of cpu that's currently (-ish) being used by all threads */ public static double getOverallCpuPercent() { return cpuUsagePercent; } /** * Gets the CPU usage, in nanoseconds, for the given thread id. * * @return -1 if CPU tracking is disabled. */ static long getThreadCpuTimeNanos(long threadId) { if (!CPU_TRACKING_ENABLED) return -1; return THREAD_BEAN.getThreadCpuTime(threadId); } public static String getLogName() { Data tdata = getContext().data; return tdata != null ? tdata.logName : ""; } public static void setLogName(String logName) { Data tdata = getContext().data; if (tdata != null) tdata.logName = logName; } public static LogRecordEnum getLogRecordType() { LogData ldata = getContext().logData; return ldata != null ? ldata.getLogRecordType() : LogRecordEnum.Undefined; } public static void setSuppressLogging(boolean s) { Data tdata = getContext().data; if (tdata != null) tdata.suppressLogging = s; } public static String getGackUniqueId() { Data tdata = getContext().data; return tdata != null ? tdata.gackUniqueId : ""; } public static void setGackUniqueId(String gackUniqueId) { Data tdata = getContext().data; if (tdata != null) tdata.gackUniqueId = gackUniqueId; } /** * Adds this delta, in milliseconds, to the amount of time this request * has spent doing search querying. This is the amount of time we spent on * the query servers. Does not include time spent access checking or getting the * database data associated with the results. */ public static void addSearchQueryTime(long deltaInMs) { assert deltaInMs >= 0 : "Delta must be non-negative: " + deltaInMs; Data tdata = getContext().data; if (tdata != null) tdata.searchQueryTime.addAndGet(deltaInMs); } /** * Adds this delta, in milliseconds, to the amount of time this request * has spent doing search accessing the cache server. */ public static void addCacheServerTime(long deltaInMs) { assert deltaInMs >= 0 : "Delta must be non-negative: " + deltaInMs; Data tdata = getContext().data; if (tdata != null) tdata.cacheServerTime.addAndGet(deltaInMs); } /** * A fetch means a call to rs.next(). Only collected in development mode */ public static void addFetch() { Data tdata = getContext().data; if (tdata != null) tdata.fetchCount.incrementAndGet(); } /** * Log API information. Used to control logging better than the standard logger.info does. * Absolutely do not have ':'s in this string * @param s the string to log if we aren't suppressing logging. */ public static void apiLog(String s) { log(s); } public static void apiLog(int i) { log(i); } /** * Absolutely do not have ':'s in this string. * @param s */ public static void log(String s) { String cleaned = TextUtil.replaceCrLfWithSpaces(s); getContext().logData.log(cleaned); } public static void log(int i) { log(String.valueOf(i)); } public static void addLogField(LogRecordFieldEnum key, T value) { getContext().logData.addLogField(key, value); } public static void addExtraLogField(String key, String value){ getContext().logData.addExtraLogParam(key, value); } // ApexLog persistence related code. public static void setApexLogStatus(String status) { Data tdata = getContext().data; if (tdata != null) tdata.apexLogStatus = status; } public static void setApexLogSent(boolean clear) { Data tdata = getContext().data; if (tdata != null) tdata.apexLogSent = clear; } public static void appendApexLog(String logEntry) { appendApexLogInternal(logEntry, true); } public static void appendApexLog(CharSequence logEntry, boolean appendNewline) { appendApexLogInternal(logEntry, appendNewline); } /** * Allocate if necessary and append the logEntry first appending a newline as indicated. * * @param logEntry String to append * @param appendNewline whether to append a newline */ private static void appendApexLogInternal(CharSequence logEntry, boolean appendNewline) { // don't bother creating a StringBuilder and updating the map for zero-length strings if (logEntry == null || logEntry.length() == 0) return; Data tdata = getContext().data; if (tdata != null) { if (tdata.apexLog == null) { tdata.apexLog = new BufferedAppendable(LOG_MEM_BUFFER_SIZE); } try { if (appendNewline) { tdata.apexLog.append('\n'); } tdata.apexLog.append(logEntry); } catch (IOException ex) { new BaseSfdcGack(GackLevel.SEVERE, ex).send(); } } } public static BufferedAppendable getApexLog() { Data tdata = getContext().data; return tdata == null ? null : tdata.apexLog; } public static void clearApexLog() { Data tdata = getContext().data; if (tdata != null) { tdata.apexLog.init(); } } /** * Return the current length of the Apex log. * * @return length of the log. */ public static int getApexLogLength() { Data tdata = getContext().data; if (tdata != null && tdata.apexLog != null) { return tdata.apexLog.length(); } return 0; } public static int getApexUserLogCount() { // Get it the first time from user preferences. Otherwise use the cached value. Once we've changed the value in the context of this request // it is invalid to get the count. If we need to we can use CApex.getUserLogCount. Data tdata = getContext().data; if (tdata != null) { assert !tdata.apexUserLogCountInvalid : "Attempt to get invalid user log count"; if (tdata.apexUserLogCount == -1) { tdata.apexUserLogCount = UserContext.get().getUserPreferences().getInt(UserPreferenceTypeEnum.APEX_DEBUG_LOG_MONITOR_COUNT); } return tdata.apexUserLogCount; } else { assert true : "Attempt to get user log count from unestablished LogContext"; return 0; } } // This is called from LogContext.setUserLogCount and ApexDebugLogEdit. public static void updateApexUserLogCount(String userId, int logCount) throws SQLException { CUserPreference.setUserPref3NcAuto(UserContext.get().getOrganizationId(), userId, Integer.parseInt(UserPreferenceTypeEnum.APEX_DEBUG_LOG_MONITOR_COUNT.getDbValue()), Integer.toString(logCount)); if (CacheManager.get().isDistributedCache()) { ProtectedConnection conn = DBContext.getContext().getAdditionalConnection("Updating apex user log count"); try { CacheManager.get().invalidateObject(conn, new UserPreferences(UserContext.get().getOrganizationId(), userId)); conn.commit(); } finally { DBContext.getContext().releaseAdditionalConnection(conn); } } else { CacheManager.get().invalidateUserPreferences(UserContext.get().getUserId().equals(userId) ? UserContext.get().getUserInfo() : UserInfo.getInstance(UserContext.get().getOrganizationId(), userId)); DBContext.getContext().commitCacheConnection(); } } private static void setApexUserLogCount(int logCount) { // Set our local value and make it consistent with the DB value in an autonomous transaction if (logCount < 0) logCount = 0; Data tdata = getContext().data; if (tdata != null) { tdata.apexUserLogCount = logCount; try { updateApexUserLogCount(UserContext.get().getUserId(), logCount); tdata.apexUserLogCountInvalid = true; } catch (SQLException x) { new BaseSfdcGack(GackLevel.INFO, "Could not ApexContext.setUserLogCount(CUserPreference.setUserPref3NcAuto)", x).send(); } } else { assert true : "Attempt to set user log count from unestablished LogContext"; } } /** * Called to persist a log. * * @param log the log to persist * @param status the status of the request */ private static int MAX_LOG_ENTRIES_PER_ORG = -1; private static int MAX_STATUS_LENGTH = -1; private static void persistDebugLog(BufferedAppendable log, String logStatus) { if (log == null || log.length() == 0) return; int logCount = getApexUserLogCount(); if (logCount == 0) return; // Initialize the constants when it's safe to do so if (MAX_LOG_ENTRIES_PER_ORG < 0) { MAX_LOG_ENTRIES_PER_ORG = Globals.getConfig().getInt("ApexLogs","MaxLogsPerOrg"); // This may become an org dependent setting MAX_STATUS_LENGTH = Udd.getFieldCommon(ApexLogFields.Status).getColumnCommons()[0].getMaxLength(); } long executionTime = System.currentTimeMillis() - getStartTime(); String application = "Unknown"; if (logStatus == null) logStatus = LC.getLabel("Apex", "ApexDebugLogSuccess"); switch (getLogRecordType()) { case API: // Private internal apis do not require a session id. e.g. workflow application = RequestContext.get().getSession() != null ? RequestContext.get().getSession().getApiClientId() : "Unknown"; break; case Web: case URI: application = "Browser"; break; default: application = "Unknown"; break; } try { int execTime = executionTime > Integer.MAX_VALUE ? Integer.MAX_VALUE : (int)executionTime; // This does use an autonomous transaction, ultimately calling CUserPreference.setUserPref3Auto setApexUserLogCount(--logCount); // Write the data out as a clob on a second connection so that we can commit and also avoid problems with buffer lengths into plsql // and also avoid issues inside an autonomous transaction doing DBMS_LOB.WRITE ProtectedConnection pc = DBContext.getContext().getAdditionalConnection("Persisting debug logs"); try { ClobOutParam clobOut = new ClobOutParam(); CApexLog.insertLogData(pc, UserContext.get().getUserId(), MAX_LOG_ENTRIES_PER_ORG, log.length(), ApiContext.isApi() ? "Api" : "Application", // request e.g. Application/Api getLogName(), // operation e.g. url path or operation (e.g /003/e) application, // application e.g. 'Browser' or API Client Id or 'Unknown' logStatus.substring(0, Math.min(logStatus.length(), MAX_STATUS_LENGTH)), // status e.g.'Success' or exception, i.e. 'System.Exception: Too many SOQL queries: 21' execTime, // duration in ms clobOut ); Clob clob = clobOut.getClob(); Writer w = clob.setCharacterStream(1L); log.appendTo(w); w.close(); pc.commit(); } finally { DBContext.getContext().releaseAdditionalConnection(pc); } } catch (Exception e) { // An exception here should not disrupt the other behaviour. new BaseSfdcGack(GackLevel.INFO, "Could not persist Apex debug log", e).send(); } } } ----- Tree: ------------------------------------------------------- private static final OneFiveFifteenStatistic.Counter requestPerSec = new OneFiveFifteenStatistic.Counter("System", "AveRequestPerSec", sampleInterval) ----- Coupling Error: --------------------------------------------- com.sun.tools.javac.util.CouplingAbort at com.sun.tools.javac.model.LazyTreeLoader.couplingError(LazyTreeLoader.java:57) at com.sun.tools.javac.comp.MemberEnter.visitVarDef(MemberEnter.java:721) at com.sun.tools.javac.tree.JCTree$JCVariableDecl.accept(JCTree.java:713) at com.sun.tools.javac.comp.MemberEnter.memberEnter(MemberEnter.java:420) at com.sun.tools.javac.comp.MemberEnter.memberEnter(MemberEnter.java:432) at com.sun.tools.javac.comp.MemberEnter.finishClass(MemberEnter.java:444) at com.sun.tools.javac.comp.MemberEnter.finish(MemberEnter.java:1122) at com.sun.tools.javac.comp.MemberEnter.complete(MemberEnter.java:1089) at com.sun.tools.javac.code.Symbol.complete(Symbol.java:401) at com.sun.tools.javac.code.Symbol$ClassSymbol.complete(Symbol.java:784) at com.sun.tools.javac.comp.Enter.complete(Enter.java:609) at com.sun.tools.javac.comp.Enter.main(Enter.java:587) at com.sun.tools.javac.main.JavaCompiler.enterTrees(JavaCompiler.java:843) at com.sun.tools.javac.api.JavacTaskImpl.enter(JavacTaskImpl.java:357) at com.sun.tools.javac.api.JavacTaskImpl.enterTrees(JavacTaskImpl.java:389) at org.netbeans.modules.java.source.usages.RepositoryUpdater.batchCompile(RepositoryUpdater.java:2935) at org.netbeans.modules.java.source.usages.RepositoryUpdater.access$4600(RepositoryUpdater.java:162) at org.netbeans.modules.java.source.usages.RepositoryUpdater$CompileWorker.parseFiles(RepositoryUpdater.java:2073) at org.netbeans.modules.java.source.usages.RepositoryUpdater$CompileWorker.updateFolder(RepositoryUpdater.java:2170) at org.netbeans.modules.java.source.usages.RepositoryUpdater$CompileWorker.scanRoots(RepositoryUpdater.java:1762) at org.netbeans.modules.java.source.usages.RepositoryUpdater$CompileWorker.access$2500(RepositoryUpdater.java:1238) at org.netbeans.modules.java.source.usages.RepositoryUpdater$CompileWorker$1.run(RepositoryUpdater.java:1386) at org.netbeans.modules.java.source.usages.RepositoryUpdater$CompileWorker$1.run(RepositoryUpdater.java:1280) at org.netbeans.modules.java.source.usages.ClassIndexManager.writeLock(ClassIndexManager.java:105) at org.netbeans.modules.java.source.usages.RepositoryUpdater$CompileWorker.run(RepositoryUpdater.java:1277) at org.netbeans.modules.java.source.usages.RepositoryUpdater$CompileWorker.run(RepositoryUpdater.java:1238) at org.netbeans.api.java.source.JavaSource$CompilationJob.run(JavaSource.java:1559) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269) at java.util.concurrent.FutureTask.run(FutureTask.java:123) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) at java.lang.Thread.run(Thread.java:595)