@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);
}
}
