@Override public void handleEvent(JmxRemoteTunnelMessage messageEnvelope) { if (messageEnvelope.getCloseConnection()) { reset(); } else { final Message message = (Message) messageEnvelope.getTunneledMessage(); synchronized (this) { if (messageEnvelope.getInitConnection()) { if (messageConnection != null) { logger.warn( "Received a client connection initialization, resetting existing connection"); reset(); } messageConnection = new TunnelingMessageConnection(channel, true); acceptOk = true; notifyAll(); } else if (messageConnection == null) { logger.warn("Received unexpected data message, connection is not yet established"); } else { if (message != null) { messageConnection.incomingNetworkMessage(message); } else { logger.warn("Received tunneled message with no data, resetting connection"); reset(); } } } } }
@Override public synchronized void handleElectionResultMessage(L2StateMessage msg) { Assert.assertEquals(L2StateMessage.ELECTION_RESULT, msg.getType()); debugInfo("Handling election result"); if (state == ELECTION_COMPLETE && !this.winner.equals(msg.getEnrollment())) { // conflict L2StateMessage resultConflict = L2StateMessage.createResultConflictMessage(msg, this.winner); logger.warn( "WARNING :: Election result conflict : Winner local = " + this.winner + " : remote winner = " + msg.getEnrollment()); try { groupManager.sendTo(msg.messageFrom(), resultConflict); } catch (GroupException e) { logger.error("Error sending Election result conflict message : " + resultConflict); } } else { // Agree to the result, abort the election if necessary if (state == ELECTION_IN_PROGRESS) { basicAbort(msg); } L2StateMessage resultAgreed = L2StateMessage.createResultAgreedMessage(msg, msg.getEnrollment()); logger.info("Agreed with Election Result from " + msg.messageFrom() + " : " + resultAgreed); try { groupManager.sendTo(msg.messageFrom(), resultAgreed); } catch (GroupException e) { logger.error("Error sending Election result agreed message : " + resultAgreed); } } }
@Override public synchronized boolean handleStartElectionRequest(L2StateMessage msg) { Assert.assertEquals(L2StateMessage.START_ELECTION, msg.getType()); if (state == ELECTION_IN_PROGRESS && (myVote.isANewCandidate() || !msg.getEnrollment().isANewCandidate())) { // Another node is also joining in the election process, Cast its vote and notify my vote // Note : WE dont want to do this for new candidates when we are not new. Enrollment vote = msg.getEnrollment(); Enrollment old = votes.put(vote.getNodeID(), vote); boolean sendResponse = msg.inResponseTo().isNull(); if (old != null && !vote.equals(old)) { logger.warn( "Received duplicate vote : Replacing with new one : " + vote + " old one : " + old); sendResponse = true; } if (sendResponse) { // This is either not a response to this node initiating election or a duplicate vote. // Either case notify this // nodes vote L2StateMessage response = createElectionStartedMessage(msg, myVote); logger.info("Casted vote from " + msg + " My Response : " + response); try { groupManager.sendTo(msg.messageFrom(), response); } catch (GroupException e) { logger.error("Error sending Votes to : " + msg.messageFrom(), e); } } else { logger.info("Casted vote from " + msg); } return true; } else { logger.info("Ignoring Start Election Request : " + msg + " My state = " + state); return false; } }
private void addJMXConnectors() { // This will make the JobExecutor threads in remote JMX idle timeout after 5s (instead of 5 // minutes) try { Class c = Class.forName("com.sun.jmx.remote.opt.util.JobExecutor"); Method method = c.getMethod("setWaitingTime", Long.TYPE); method.setAccessible(true); method.invoke(null, 5000L); } catch (Exception e) { logger.warn("cannot adjust job executor timeout", e); } JMXServiceURL url = null; try { // LKC-2990 and LKC-3171: Remove the JMX generic optional logging java.util.logging.Logger jmxLogger = java.util.logging.Logger.getLogger("javax.management.remote.generic"); jmxLogger.setLevel(java.util.logging.Level.OFF); } catch (Throwable t) { logger.warn( "Unable to disable default logging in Sun's JMX package; when Terracotta clients go" + " up/down you may see stack traces printed to the log"); } try { final Map environment = new HashMap(); environment.put("jmx.remote.x.server.connection.timeout", Long.valueOf(Long.MAX_VALUE)); ProtocolProvider.addTerracottaJmxProvider(environment); environment.put(TunnelingMessageConnectionServer.TUNNELING_HANDLER, tunnelingHandler); environment.put(EnvHelp.SERVER_CONNECTION_TIMEOUT, String.valueOf(Long.MAX_VALUE)); url = new JMXServiceURL("terracotta", "localhost", 0); // Normally you should NOT do this in the client, but we have a modified version of // jmxremote_optional.jar that // uses a daemon thread to wait for connections so we don't hang the client connServer = JMXConnectorServerFactory.newJMXConnectorServer(url, environment, mBeanServer); connServer.start(); logger.info("Terracotta JMX connector available at[" + url + "]"); } catch (Exception e) { if (url != null) { logger.warn("Unable to start embedded JMX connector for url[" + url + "]", e); } else { logger.warn( "Unable to construct embedded JMX connector URL with params (terracotta, localhost, 0)"); } } }
// private void writeCharArray(char[] chars, TCDataOutput output) { // output.writeInt(chars.length); // for (int i = 0, n = chars.length; i < n; i++) { // output.writeChar(chars[i]); // } // } protected byte[] readByteArray(TCDataInput input) throws IOException { final int length = input.readInt(); if (length >= BYTE_WARN) { logger.warn("Attempting to allocate a large byte array of size: " + length); } final byte[] array = new byte[length]; input.readFully(array); return array; }
private synchronized void openChannel(String serverHost, int serverPort) throws InterruptedException { while (!clientStopped.isSet()) { try { DSO_LOGGER.debug("Trying to open channel...."); final char[] pw; if (config.getSecurityInfo().hasCredentials()) { Assert.assertNotNull(securityManager); pw = securityManager.getPasswordForTC( config.getSecurityInfo().getUsername(), serverHost, serverPort); } else { pw = null; } this.channel.open(pw); DSO_LOGGER.debug("Channel open"); break; } catch (final TCTimeoutException tcte) { CONSOLE_LOGGER.warn("Timeout connecting to server: " + tcte.getMessage()); this.wait(5000); } catch (final ConnectException e) { CONSOLE_LOGGER.warn("Connection refused from server: " + e); this.wait(5000); } catch (final MaxConnectionsExceededException e) { DSO_LOGGER.fatal(e.getMessage()); CONSOLE_LOGGER.fatal(e.getMessage()); throw new IllegalStateException(e.getMessage(), e); } catch (final CommStackMismatchException e) { DSO_LOGGER.fatal(e.getMessage()); CONSOLE_LOGGER.fatal(e.getMessage()); throw new IllegalStateException(e.getMessage(), e); } catch (final IOException ioe) { CONSOLE_LOGGER.warn( "IOException connecting to server: " + serverHost + ":" + serverPort + ". " + ioe.getMessage()); this.wait(5000); } } }
public void addWaitingForAcknowledgement( ChannelID waiter, TransactionID txnID, ChannelID waitee) { TransactionAccount ci = getTransactionAccount(waiter); if (ci != null) { ci.addWaitee(waitee, txnID); } else { logger.warn( "Not adding to Wating for Ack since Waiter not found in the states map: " + waiter); } }
private void basicApply(Collection objectChanges, Map newRoots, boolean force) throws DNAException { List l = new LinkedList(); for (Iterator i = objectChanges.iterator(); i.hasNext(); ) { DNA dna = (DNA) i.next(); TCObject tcobj = null; Assert.assertTrue(dna.isDelta()); try { // This is a major hack to prevent distributed method calls // sent to apps that don't have the right classes from dying // This should be fixed in a better way some day :-) objectManager.getClassFor( Namespace.parseClassNameIfNecessary(dna.getTypeName()), dna.getDefiningLoaderDescription()); tcobj = objectManager.lookup(dna.getObjectID()); } catch (ClassNotFoundException cnfe) { logger.warn("Could not apply change because class not local:" + dna.getTypeName()); continue; } // Important to have a hard reference to the object while we apply // changes so that it doesn't get gc'd on us Object obj = tcobj == null ? null : tcobj.getPeerObject(); l.add(obj); if (obj != null) { try { tcobj.hydrate(dna, force); } catch (ClassNotFoundException cnfe) { logger.warn("Could not apply change because class not local:" + cnfe.getMessage()); throw new TCClassNotFoundException(cnfe); } } } for (Iterator i = newRoots.entrySet().iterator(); i.hasNext(); ) { Entry entry = (Entry) i.next(); String rootName = (String) entry.getKey(); ObjectID newRootID = (ObjectID) entry.getValue(); objectManager.replaceRootIDIfNecessary(rootName, newRootID); } }
@Override public synchronized void handleElectionAbort(L2StateMessage msg) { Assert.assertEquals(L2StateMessage.ABORT_ELECTION, msg.getType()); debugInfo("Handling election abort"); if (state == ELECTION_IN_PROGRESS) { // An existing ACTIVE Node has forced election to quit Assert.assertNotNull(myVote); basicAbort(msg); } else { logger.warn("Ignoring Abort Election Request : " + msg + " My state = " + state); } }
public void acknowledgement(ChannelID waiter, TransactionID txnID, ChannelID waitee) { TransactionAccount transactionAccount = getTransactionAccount(waiter); if (transactionAccount == null) { // This can happen if an ack makes it into the system and the server crashed // leading to a removed state; logger.warn("Waiter not found in the states map: " + waiter); return; } if (transactionAccount.removeWaitee(waitee, txnID)) { acknowledge(waiter, txnID); } }
public void transactionsRelayed(ChannelID channelID, Set serverTxnIDs) { TransactionAccount ci = getTransactionAccount(channelID); if (ci == null) { logger.warn("transactionsRelayed(): TransactionAccount not found for " + channelID); return; } for (Iterator i = serverTxnIDs.iterator(); i.hasNext(); ) { final ServerTransactionID txnId = (ServerTransactionID) i.next(); final TransactionID txnID = txnId.getClientTransactionID(); if (ci.relayTransactionComplete(txnID)) { acknowledge(channelID, txnID); } } }
private void handleStartElectionRequest(L2StateMessage msg) throws GroupException { if (state == ACTIVE_COORDINATOR) { // This is either a new L2 joining a cluster or a renegade L2. Force it to abort GroupMessage abortMsg = L2StateMessage.createAbortElectionMessage( msg, EnrollmentFactory.createTrumpEnrollment(getLocalNodeID(), weightsFactory)); info("Forcing Abort Election for " + msg + " with " + abortMsg); groupManager.sendTo(msg.messageFrom(), abortMsg); } else if (!electionMgr.handleStartElectionRequest(msg)) { // TODO::FIXME:: Commenting so that stage thread is not held up doing election. // startElectionIfNecessary(NodeID.NULL_ID); logger.warn("Not starting election as it was commented out"); } }
private void fireRootCreatedEvent(String rootName, ObjectID id) { for (Iterator iter = rootEventListeners.iterator(); iter.hasNext(); ) { try { ServerTransactionManagerEventListener listener = (ServerTransactionManagerEventListener) iter.next(); listener.rootCreated(rootName, id); } catch (Exception e) { if (logger.isDebugEnabled()) { logger.debug(e); } else { logger.warn("Exception in rootCreated event callback: " + e.getMessage()); } } } }
private synchronized void waitUntilActiveNodeIDNotNull(long timeout) { while (activeNode.isNull() && timeout > 0) { long start = System.currentTimeMillis(); try { wait(timeout); } catch (InterruptedException e) { logger.warn("Interrupted while waiting for ACTIVE to declare WON message ! ", e); break; } timeout = timeout - (System.currentTimeMillis() - start); } debugInfo( "Wait for other active to declare as active over. Declared? activeNodeId.isNull() = " + activeNode.isNull() + ", activeNode=" + activeNode); }
/** * This schedules the shutdown to occur one second after we return from this call because * otherwise JMX will be shutdown and we'll get all sorts of other errors trying to return from * this call. */ @Override public void shutdown() { if (!server.canShutdown()) { String msg = "Server cannot be shutdown because it is not fully started."; logger.error(msg); throw new RuntimeException(msg); } logger.warn("shutdown is invoked by MBean"); final Timer timer = new Timer("TCServerInfo shutdown timer"); final TimerTask task = new TimerTask() { @Override public void run() { server.shutdown(); } }; timer.schedule(task, 1000); }
private synchronized void handleElectionWonMessage(L2StateMessage clusterMsg) { debugInfo("Received election_won or election_already_won msg: " + clusterMsg); Enrollment winningEnrollment = clusterMsg.getEnrollment(); if (state == ACTIVE_COORDINATOR) { // Can't get Election Won from another node : Split brain String error = state + " Received Election Won Msg : " + clusterMsg + ". A Terracotta server tried to join the mirror group as a second ACTIVE"; logger.error(error); if (clusterMsg.getType() == L2StateMessage.ELECTION_WON_ALREADY) { sendNGResponse(clusterMsg.messageFrom(), clusterMsg); } groupManager.zapNode( winningEnrollment.getNodeID(), L2HAZapNodeRequestProcessor.SPLIT_BRAIN, error); } else if (activeNode.isNull() || activeNode.equals(winningEnrollment.getNodeID()) || clusterMsg.getType() == L2StateMessage.ELECTION_WON) { // There is no active server for this node or the other node just detected a failure of ACTIVE // server and ran an // election and is sending the results. This can happen if this node for some reason is not // able to detect that // the active is down but the other node did. Go with the new active. setActiveNodeID(winningEnrollment.getNodeID()); moveToPassiveState(winningEnrollment); if (clusterMsg.getType() == L2StateMessage.ELECTION_WON_ALREADY) { sendOKResponse(clusterMsg.messageFrom(), clusterMsg); } } else { // This is done to solve DEV-1532. Node sent ELECTION_WON_ALREADY message but our ACTIVE is // intact. logger.warn( "Conflicting Election Won Msg : " + clusterMsg + " since I already have a ACTIVE Node : " + activeNode + ". Sending NG response"); // The reason we send a response for ELECTION_WON_ALREADY message is that if we don't agree we // don't want the // other server to send us cluster state messages. sendNGResponse(clusterMsg.messageFrom(), clusterMsg); } }
protected synchronized MessageConnection accept() throws IOException { while (!acceptOk && !stopAccept) { try { wait(); } catch (InterruptedException ie) { logger.warn("Interrupted while waiting for a new connection", ie); throw new IOException("Interrupted while waiting for new connection: " + ie.getMessage()); } } acceptOk = false; MessageConnection rv = messageConnection; if (rv == null) { // if we return null here it will cause an uncaught exception and trigger VM exit prematurely throw new IOException("no connection"); } return rv; }
public void start(Set cids) { synchronized (transactionAccounts) { int sizeB4 = transactionAccounts.size(); transactionAccounts.keySet().retainAll(cids); int sizeAfter = transactionAccounts.size(); if (sizeB4 != sizeAfter) { logger.warn("Cleaned up Transaction Accounts for : " + (sizeB4 - sizeAfter) + " clients"); } } // XXX:: The server could have crashed right after a client crash/disconnect before it had a // chance to remove // transactions from the DB. If we dont do this, then these will stick around for ever and cause // low-water mark to // remain the same for ever and ever. // For Network enabled Active/Passive, when a passive becomes active, this will be called and // the passive (now // active) will correct itself. gtxm.shutdownAllClientsExcept(cids); fireTransactionManagerStartedEvent(cids); }
void shutdownResources() { final TCLogger logger = DSO_LOGGER; if (this.counterManager != null) { try { this.counterManager.shutdown(); } catch (final Throwable t) { logger.error("error shutting down counter manager", t); } finally { this.counterManager = null; } } if (this.tcMemManager != null) { try { this.tcMemManager.shutdown(); } catch (final Throwable t) { logger.error("Error stopping memory manager", t); } finally { this.tcMemManager = null; } } if (this.lockManager != null) { try { this.lockManager.shutdown(false); } catch (final Throwable t) { logger.error("Error stopping lock manager", t); } finally { this.lockManager = null; } } try { this.communicationStageManager.stopAll(); } catch (final Throwable t) { logger.error("Error stopping stage manager", t); } if (this.channel != null) { try { this.channel.close(); } catch (final Throwable t) { logger.error("Error closing channel", t); } finally { this.channel = null; } } if (this.communicationsManager != null) { try { this.communicationsManager.shutdown(); } catch (final Throwable t) { logger.error("Error shutting down communications manager", t); } finally { this.communicationsManager = null; } } if (taskRunner != null) { logger.info("Shutting down TaskRunner"); taskRunner.shutdown(); } CommonShutDownHook.shutdown(); this.cluster.shutdown(); if (this.threadGroup != null) { boolean interrupted = false; try { final long end = System.currentTimeMillis() + TCPropertiesImpl.getProperties() .getLong(TCPropertiesConsts.L1_SHUTDOWN_THREADGROUP_GRACETIME); int threadCount = this.threadGroup.activeCount(); Thread[] t = new Thread[threadCount]; threadCount = this.threadGroup.enumerate(t); final long time = System.currentTimeMillis(); for (int x = 0; x < threadCount; x++) { long start = System.currentTimeMillis(); while (System.currentTimeMillis() < end && t[x].isAlive()) { t[x].join(1000); } logger.info( "Destroyed thread " + t[x].getName() + " time to destroy:" + (System.currentTimeMillis() - start) + " millis"); } logger.info( "time to destroy thread group:" + TimeUnit.SECONDS.convert(System.currentTimeMillis() - time, TimeUnit.MILLISECONDS) + " seconds"); if (this.threadGroup.activeCount() > 0) { logger.warn( "Timed out waiting for TC thread group threads to die - probable shutdown memory leak\n" + "Live threads: " + getLiveThreads(this.threadGroup)); Thread threadGroupCleanerThread = new Thread( this.threadGroup.getParent(), new TCThreadGroupCleanerRunnable(threadGroup), "TCThreadGroup last chance cleaner thread"); threadGroupCleanerThread.setDaemon(true); threadGroupCleanerThread.start(); logger.warn("Spawning TCThreadGroup last chance cleaner thread"); } else { logger.info("Destroying TC thread group"); this.threadGroup.destroy(); } } catch (final Throwable t) { logger.error("Error destroying TC thread group", t); } finally { if (interrupted) { Thread.currentThread().interrupt(); } } } if (TCPropertiesImpl.getProperties() .getBoolean(TCPropertiesConsts.L1_SHUTDOWN_FORCE_FINALIZATION)) System.runFinalization(); }
public TCMemoryManagerJdk14() { rt = Runtime.getRuntime(); if (rt.maxMemory() == Long.MAX_VALUE) { logger.warn("Please specify Max memory using -Xmx flag for Memory manager to work properly"); } }
private void checkSize(Class<?> type, int threshold, int len) { if (len >= threshold) { logger.warn( "Attempt to read a " + type + " array of len: " + len + "; threshold=" + threshold); } }
private void warn(String message, boolean console) { logger.warn(message); if (console) { consoleLogger.warn(message); } }