Skip to content

Commit

Permalink
IGNITE-8798 Move transaction recovery logging to INFO level
Browse files Browse the repository at this point in the history
Signed-off-by: Ivan Rakov <irakov@apache.org>
  • Loading branch information
ezagumennov authored and glukos committed Jun 19, 2018
1 parent b37f8a2 commit 49a565c
Show file tree
Hide file tree
Showing 3 changed files with 72 additions and 68 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -120,8 +120,8 @@ public GridCacheTxRecoveryFuture(GridCacheSharedContext<?, ?> cctx,

if (node != null)
nodes.put(node.id(), node);
else if (log.isDebugEnabled())
log.debug("Transaction node left (will ignore) " + e.getKey());
else if (log.isInfoEnabled())
log.info("Transaction node left (will ignore) " + e.getKey());
}

for (UUID nodeId : e.getValue()) {
Expand All @@ -130,8 +130,8 @@ else if (log.isDebugEnabled())

if (node != null)
nodes.put(node.id(), node);
else if (log.isDebugEnabled())
log.debug("Transaction node left (will ignore) " + e.getKey());
else if (log.isInfoEnabled())
log.info("Transaction node left (will ignore) " + e.getKey());
}
}
}
Expand Down Expand Up @@ -179,21 +179,21 @@ public void prepare() {
try {
cctx.io().send(nearNodeId, req, tx.ioPolicy());

if (msgLog.isDebugEnabled()) {
msgLog.debug("Recovery fut, sent request near tx [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nearNodeId + ']');
if (msgLog.isInfoEnabled()) {
msgLog.info("Recovery fut, sent request near tx [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nearNodeId + ']');
}
}
catch (ClusterTopologyCheckedException ignore) {
fut.onNodeLeft(nearNodeId);
}
catch (IgniteCheckedException e) {
if (msgLog.isDebugEnabled()) {
msgLog.debug("Recovery fut, failed to send request near tx [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nearNodeId +
", err=" + e + ']');
if (msgLog.isInfoEnabled()) {
msgLog.info("Recovery fut, failed to send request near tx [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nearNodeId +
", err=" + e + ']');
}

fut.onError(e);
Expand Down Expand Up @@ -298,21 +298,21 @@ private void proceedPrepare() {
try {
cctx.io().send(id, req, tx.ioPolicy());

if (msgLog.isDebugEnabled()) {
msgLog.debug("Recovery fut, sent request to backup [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + id + ']');
if (msgLog.isInfoEnabled()) {
msgLog.info("Recovery fut, sent request to backup [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + id + ']');
}
}
catch (ClusterTopologyCheckedException ignored) {
fut.onNodeLeft(id);
}
catch (IgniteCheckedException e) {
if (msgLog.isDebugEnabled()) {
msgLog.debug("Recovery fut, failed to send request to backup [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + id +
", err=" + e + ']');
if (msgLog.isInfoEnabled()) {
msgLog.info("Recovery fut, failed to send request to backup [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + id +
", err=" + e + ']');
}

fut.onError(e);
Expand All @@ -337,21 +337,21 @@ private void proceedPrepare() {
try {
cctx.io().send(nodeId, req, tx.ioPolicy());

if (msgLog.isDebugEnabled()) {
msgLog.debug("Recovery fut, sent request to primary [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nodeId + ']');
if (msgLog.isInfoEnabled()) {
msgLog.info("Recovery fut, sent request to primary [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nodeId + ']');
}
}
catch (ClusterTopologyCheckedException ignored) {
fut.onNodeLeft(nodeId);
}
catch (IgniteCheckedException e) {
if (msgLog.isDebugEnabled()) {
msgLog.debug("Recovery fut, failed to send request to primary [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nodeId +
", err=" + e + ']');
if (msgLog.isInfoEnabled()) {
msgLog.info("Recovery fut, failed to send request to primary [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nodeId +
", err=" + e + ']');
}

fut.onError(e);
Expand Down Expand Up @@ -398,22 +398,24 @@ public void onResult(UUID nodeId, GridCacheTxRecoveryResponse res) {
mini.onResult(res);
}
else {
if (msgLog.isDebugEnabled()) {
msgLog.debug("Tx recovery fut, failed to find mini future [txId=" + tx.nearXidVersion() +
if (msgLog.isInfoEnabled()) {
msgLog.info("Tx recovery fut, failed to find mini future [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nodeId +
", res=" + res +
", fut=" + this + ']');
}
}
}
else {
if (msgLog.isInfoEnabled()) {
msgLog.info("Tx recovery fut, response for finished future [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nodeId +
", res=" + res +
", fut=" + this + ']');
}
}
}
else {
msgLog.debug("Tx recovery fut, response for finished future [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nodeId +
", res=" + res +
", fut=" + this + ']');
}
}

/**
Expand Down Expand Up @@ -502,14 +504,16 @@ public IgniteInternalTx tx() {
}
else {
if (err instanceof ClusterTopologyCheckedException && nearTxCheck) {
if (log.isDebugEnabled())
log.debug("Failed to check transaction on near node, " +
"ignoring [err=" + err + ", tx=" + tx + ']');
if (log.isInfoEnabled()) {
log.info("Failed to check transaction on near node, " +
"ignoring [err=" + err + ", tx=" + tx + ']');
}
}
else {
if (log.isDebugEnabled())
log.debug("Failed to check prepared transactions, " +
"invalidating transaction [err=" + err + ", tx=" + tx + ']');
if (log.isInfoEnabled()) {
log.info("Failed to check prepared transactions, " +
"invalidating transaction [err=" + err + ", tx=" + tx + ']');
}

cctx.tm().salvageTx(tx);
}
Expand Down Expand Up @@ -577,8 +581,8 @@ private IgniteUuid futureId() {
* @param e Error.
*/
private void onError(Throwable e) {
if (log.isDebugEnabled())
log.debug("Failed to get future result [fut=" + this + ", err=" + e + ']');
if (log.isInfoEnabled())
log.info("Failed to get future result [fut=" + this + ", err=" + e + ']');

onDone(e);
}
Expand All @@ -587,11 +591,11 @@ private void onError(Throwable e) {
* @param nodeId Failed node ID.
*/
private void onNodeLeft(UUID nodeId) {
if (msgLog.isDebugEnabled()) {
msgLog.debug("Tx recovery fut, mini future node left [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nodeId +
", nearTxCheck=" + nearTxCheck + ']');
if (msgLog.isInfoEnabled()) {
msgLog.info("Tx recovery fut, mini future node left [txId=" + tx.nearXidVersion() +
", dhtTxId=" + tx.xidVersion() +
", node=" + nodeId +
", nearTxCheck=" + nearTxCheck + ']');
}

if (nearTxCheck) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -1877,17 +1877,17 @@ private void sendCheckPreparedResponse(UUID nodeId,
* @param res Response.
*/
protected void processCheckPreparedTxResponse(UUID nodeId, GridCacheTxRecoveryResponse res) {
if (txRecoveryMsgLog.isDebugEnabled()) {
txRecoveryMsgLog.debug("Received tx recovery response [txId=" + res.version() +
if (txRecoveryMsgLog.isInfoEnabled()) {
txRecoveryMsgLog.info("Received tx recovery response [txId=" + res.version() +
", node=" + nodeId +
", res=" + res + ']');
}

GridCacheTxRecoveryFuture fut = (GridCacheTxRecoveryFuture)ctx.mvcc().future(res.futureId());

if (fut == null) {
if (txRecoveryMsgLog.isDebugEnabled()) {
txRecoveryMsgLog.debug("Failed to find future for tx recovery response [txId=" + res.version() +
if (txRecoveryMsgLog.isInfoEnabled()) {
txRecoveryMsgLog.info("Failed to find future for tx recovery response [txId=" + res.version() +
", node=" + nodeId + ", res=" + res + ']');
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -383,16 +383,16 @@ private void salvageTx(IgniteInternalTx tx, IgniteInternalTx.FinalizationStatus

if (state == ACTIVE || state == PREPARING || state == PREPARED || state == MARKED_ROLLBACK) {
if (!tx.markFinalizing(status)) {
if (log.isDebugEnabled())
log.debug("Will not try to commit invalidate transaction (could not mark finalized): " + tx);
if (log.isInfoEnabled())
log.info("Will not try to commit invalidate transaction (could not mark finalized): " + tx);

return;
}

tx.salvageTx();

if (log.isDebugEnabled())
log.debug("Invalidated transaction because originating node left grid: " + CU.txString(tx));
if (log.isInfoEnabled())
log.info("Invalidated transaction because originating node left grid: " + CU.txString(tx));
}
}

Expand Down Expand Up @@ -2012,12 +2012,12 @@ public IgniteInternalFuture<?> remoteTxFinishFuture(GridCacheVersion nearVer) {
* @param commit Whether transaction should be committed or rolled back.
*/
public void finishTxOnRecovery(final IgniteInternalTx tx, boolean commit) {
if (log.isDebugEnabled())
log.debug("Finishing prepared transaction [tx=" + tx + ", commit=" + commit + ']');
if (log.isInfoEnabled())
log.info("Finishing prepared transaction [tx=" + tx + ", commit=" + commit + ']');

if (!tx.markFinalizing(RECOVERY_FINISH)) {
if (log.isDebugEnabled())
log.debug("Will not try to commit prepared transaction (could not mark finalized): " + tx);
if (log.isInfoEnabled())
log.info("Will not try to commit prepared transaction (could not mark finalized): " + tx);

return;
}
Expand Down Expand Up @@ -2057,8 +2057,8 @@ public void commitIfPrepared(IgniteInternalTx tx, Set<UUID> failedNodeIds) {

cctx.mvcc().addFuture(fut, fut.futureId());

if (log.isDebugEnabled())
log.debug("Checking optimistic transaction state on remote nodes [tx=" + tx + ", fut=" + fut + ']');
if (log.isInfoEnabled())
log.info("Checking optimistic transaction state on remote nodes [tx=" + tx + ", fut=" + fut + ']');

fut.prepare();
}
Expand Down

0 comments on commit 49a565c

Please sign in to comment.