diff --git a/source/java/org/alfresco/filesys/server/SrvSession.java b/source/java/org/alfresco/filesys/server/SrvSession.java index cbb509a3d2..f4d3fb071d 100644 --- a/source/java/org/alfresco/filesys/server/SrvSession.java +++ b/source/java/org/alfresco/filesys/server/SrvSession.java @@ -27,7 +27,6 @@ package org.alfresco.filesys.server; import java.net.InetAddress; import javax.transaction.Status; -import javax.transaction.SystemException; import javax.transaction.UserTransaction; import org.alfresco.error.AlfrescoRuntimeException; @@ -36,7 +35,11 @@ import org.alfresco.filesys.server.auth.ClientInfo; import org.alfresco.filesys.server.core.SharedDevice; import org.alfresco.filesys.server.core.SharedDeviceList; import org.alfresco.filesys.server.filesys.FilesysTransaction; +import org.alfresco.repo.transaction.AlfrescoTransactionSupport; import org.alfresco.service.transaction.TransactionService; +import org.alfresco.util.transaction.SpringAwareUserTransaction; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; /** * Server Session Base Class @@ -45,6 +48,9 @@ import org.alfresco.service.transaction.TransactionService; */ public abstract class SrvSession { + // Logging + + private static final Log logger = LogFactory.getLog(SrvSession.class); // Network server this session is associated with @@ -102,9 +108,6 @@ public abstract class SrvSession private ThreadLocal m_tx = new ThreadLocal(); -// UserTransaction m_transaction; -// private boolean m_readOnlyTrans; - // Request and transaction counts protected int m_reqCount; @@ -505,6 +508,11 @@ public abstract class SrvSession private final boolean beginTransaction(TransactionService transService, boolean readOnly) throws AlfrescoRuntimeException { + // DEBUG + + if ( logger.isDebugEnabled()) + logger.debug( "Begin transaction readOnly=" + readOnly); + boolean created = false; // Get the filesystem transaction @@ -514,6 +522,11 @@ public abstract class SrvSession { filesysTx = new FilesysTransaction(); m_tx.set( filesysTx); + + // DEBUG + + if ( logger.isDebugEnabled()) + logger.debug("Created FilesysTransaction"); } // If there is an active transaction check that it is the required type @@ -535,6 +548,11 @@ public abstract class SrvSession // Rollback the current transaction tx.rollback(); + + // DEBUG + + if ( logger.isDebugEnabled()) + logger.debug("Rolled back existing transaction"); } } catch ( Exception ex) @@ -552,15 +570,21 @@ public abstract class SrvSession tx.commit(); m_transConvCount++; } - catch ( Exception ex) + catch ( Throwable ex) { - throw new AlfrescoRuntimeException("Failed to commit read-only transaction, " + ex.getMessage()); + ex.printStackTrace(); +// throw new AlfrescoRuntimeException("Failed to commit read-only transaction, " + ex.getMessage()); } finally { // Clear the active transaction filesysTx.clearTransaction(); + + // DEBUG + + if ( logger.isDebugEnabled()) + logger.debug("Cleared existing transaction (read/write)"); } } } @@ -571,15 +595,46 @@ public abstract class SrvSession { try { - UserTransaction userTrans = transService.getUserTransaction(readOnly); - userTrans.begin(); + // Create the transaction + + UserTransaction userTrans = null; + + if ( AlfrescoTransactionSupport.getTransactionId() != null) { + + // Create a non-propagating transaction as there is an active transaction + + userTrans = transService.getNonPropagatingUserTransaction(readOnly); + + // DEBUG + + if ( logger.isDebugEnabled()) + logger.debug("%%%%% Transaction active id=" + AlfrescoTransactionSupport.getTransactionId() + ", started=" + AlfrescoTransactionSupport.getTransactionStartTime()); + } + else { + + // Create a normal transaction + + userTrans = transService.getUserTransaction(readOnly); + } + // Start the transaction + + userTrans.begin(); + created = true; // Store the transaction filesysTx.setTransaction( userTrans, readOnly); m_transCount++; + + // DEBUG + + if ( logger.isDebugEnabled()) { + logger.debug("Created transaction readOnly=" + readOnly + ", tx=" + userTrans + ", txSts=" + userTrans.getStatus()); + SpringAwareUserTransaction springTx = (SpringAwareUserTransaction) userTrans; + logger.debug(" Tx details readOnly=" + springTx.isReadOnly() + ", txStatus=" + springTx.getStatus() + ",id=" + AlfrescoTransactionSupport.getTransactionId()); + } } catch (Exception ex) { @@ -614,7 +669,9 @@ public abstract class SrvSession { // Commit or rollback the transaction - if ( tx.getStatus() == Status.STATUS_MARKED_ROLLBACK) + if ( tx.getStatus() == Status.STATUS_MARKED_ROLLBACK || + tx.getStatus() == Status.STATUS_ROLLEDBACK || + tx.getStatus() == Status.STATUS_ROLLING_BACK) { // Transaction is marked for rollback @@ -629,13 +686,19 @@ public abstract class SrvSession } catch ( Exception ex) { - throw new AlfrescoRuntimeException("Failed to end transaction", ex); + ex.printStackTrace(); +// throw new AlfrescoRuntimeException("Failed to end transaction", ex); } finally { // Clear the current transaction filesysTx.clearTransaction(); + + // DEBUG + + if ( logger.isDebugEnabled()) + logger.debug("Cleared existing transaction (end)"); } } diff --git a/source/java/org/alfresco/filesys/server/auth/AlfrescoRpcAuthenticator.java b/source/java/org/alfresco/filesys/server/auth/AlfrescoRpcAuthenticator.java index 1952e63c7a..9dabd7e6e6 100644 --- a/source/java/org/alfresco/filesys/server/auth/AlfrescoRpcAuthenticator.java +++ b/source/java/org/alfresco/filesys/server/auth/AlfrescoRpcAuthenticator.java @@ -261,6 +261,11 @@ public class AlfrescoRpcAuthenticator implements RpcAuthenticator { // Clear the authentication, null user should not be allowed to do any service calls m_authComponent.clearCurrentSecurityContext(); + + // DEBUG + + if ( logger.isDebugEnabled()) + logger.debug("Clear security context, client=" + client); } else if ( client.isGuest() == false) { @@ -272,12 +277,22 @@ public class AlfrescoRpcAuthenticator implements RpcAuthenticator { m_authComponent.setCurrentUser( client.getUserName()); client.setAuthenticationToken( m_authComponent.getCurrentAuthentication()); + + // DEBUG + + if ( logger.isDebugEnabled()) + logger.debug("Set user name=" + client.getUserName() + ", token=" + client.getAuthenticationToken()); } else { // Set the authentication context for the request m_authComponent.setCurrentAuthentication( client.getAuthenticationToken()); + + // DEBUG + + if ( logger.isDebugEnabled()) + logger.debug("Set user using auth token, token=" + client.getAuthenticationToken()); } } else @@ -285,7 +300,16 @@ public class AlfrescoRpcAuthenticator implements RpcAuthenticator { // Enable guest access for the request m_authComponent.setGuestUserAsCurrentUser(); + + // DEBUG + + if ( logger.isDebugEnabled()) + logger.debug("Set guest user"); } + + // Commit the authentication transaction + + sess.endTransaction(); } /** diff --git a/source/java/org/alfresco/filesys/server/oncrpc/nfs/NFSServer.java b/source/java/org/alfresco/filesys/server/oncrpc/nfs/NFSServer.java index 9ab71693ef..2a2a7c9b0f 100644 --- a/source/java/org/alfresco/filesys/server/oncrpc/nfs/NFSServer.java +++ b/source/java/org/alfresco/filesys/server/oncrpc/nfs/NFSServer.java @@ -1666,8 +1666,7 @@ public class NFSServer extends RpcNetworkServer implements RpcProcessor { // Write to the network file - disk.writeFile(sess, conn, netFile, rpc.getBuffer(), rpc - .getPosition(), count, offset); + disk.writeFile(sess, conn, netFile, rpc.getBuffer(), rpc.getPosition(), count, offset); } // Get file information for the path and pack the response @@ -1707,8 +1706,7 @@ public class NFSServer extends RpcNetworkServer implements RpcProcessor { // DEBUG if (logger.isDebugEnabled() && hasDebugFlag(DBG_ERROR)) { - logger.debug("Write Exception: netFile=" + netFile + ", cache=" + sess.getFileCache().numberOfEntries()); - logger.debug(ex); + logger.debug("Write Exception: netFile=" + netFile + ", cache=" + sess.getFileCache().numberOfEntries(), ex); } } @@ -1902,6 +1900,9 @@ public class NFSServer extends RpcNetworkServer implements RpcProcessor { } catch (AccessDeniedException ex) { errorSts = NFS.StsAccess; + + if ( logger.isDebugEnabled()) + logger.debug("Create error:", ex); } catch (Exception ex) { errorSts = NFS.StsServerFault; @@ -1909,7 +1910,7 @@ public class NFSServer extends RpcNetworkServer implements RpcProcessor { // DEBUG if (logger.isDebugEnabled() && hasDebugFlag(DBG_ERROR)) - logger.debug("Create Exception: " + ex.toString()); + logger.debug("Create Exception: " + ex.toString(), ex); } // Check for a failure status @@ -3241,8 +3242,7 @@ public class NFSServer extends RpcNetworkServer implements RpcProcessor { // DEBUG if (logger.isDebugEnabled() && hasDebugFlag(DBG_SEARCH)) - logger.debug("ReadDir return entries=" + entCnt + ", eof=" - + search.hasMoreFiles()); + logger.debug("ReadDir return entries=" + (entCnt - 1) + ", eof=" + search.hasMoreFiles()); } catch (BadHandleException ex) { errorSts = NFS.StsBadHandle; @@ -3612,7 +3612,7 @@ public class NFSServer extends RpcNetworkServer implements RpcProcessor { // DEBUG if (logger.isDebugEnabled() && hasDebugFlag(DBG_SEARCH)) - logger.debug("ReadDirPlus return entries=" + entCnt + ", eof=" + (search.hasMoreFiles() ? false : true)); + logger.debug("ReadDirPlus return entries=" + (entCnt - 1) + ", eof=" + (search.hasMoreFiles() ? false : true)); } catch (BadHandleException ex) { errorSts = NFS.StsBadHandle; diff --git a/source/java/org/alfresco/filesys/server/oncrpc/nfs/NetworkFileCache.java b/source/java/org/alfresco/filesys/server/oncrpc/nfs/NetworkFileCache.java index d1e6e49f84..905655942d 100644 --- a/source/java/org/alfresco/filesys/server/oncrpc/nfs/NetworkFileCache.java +++ b/source/java/org/alfresco/filesys/server/oncrpc/nfs/NetworkFileCache.java @@ -277,6 +277,12 @@ public class NetworkFileCache { // Close the file via the disk interface try { + + // DEBUG + + if ( logger.isDebugEnabled()) + logger.debug( "NFSFileExpiry: Closing file " + fentry.getFile().getFullName()); + // Set the current user using the session that last accessed the file diff --git a/source/java/org/alfresco/filesys/smb/server/repo/ContentDiskDriver.java b/source/java/org/alfresco/filesys/smb/server/repo/ContentDiskDriver.java index 42ba8a383a..8808c3a5d0 100644 --- a/source/java/org/alfresco/filesys/smb/server/repo/ContentDiskDriver.java +++ b/source/java/org/alfresco/filesys/smb/server/repo/ContentDiskDriver.java @@ -567,6 +567,10 @@ public class ContentDiskDriver extends AlfrescoDiskDriver implements DiskInterfa */ public FileInfo getFileInformation(SrvSession session, TreeConnection tree, String path) throws IOException { + // Start a transaction + + session.beginReadTransaction(transactionService); + // Get the device root ContentContext ctx = (ContentContext) tree.getContext(); @@ -598,7 +602,6 @@ public class ContentDiskDriver extends AlfrescoDiskDriver implements DiskInterfa { // Get the file information for the node - session.beginReadTransaction(transactionService); finfo = cifsHelper.getFileInformation(nodeRef); } @@ -624,10 +627,6 @@ public class ContentDiskDriver extends AlfrescoDiskDriver implements DiskInterfa if ( fstate.hasNodeRef() == false) { - // Create the transaction - - session.beginReadTransaction(transactionService); - // Get the node for the folder path fstate.setNodeRef( getNodeForPath( tree, paths[0])); @@ -674,7 +673,6 @@ public class ContentDiskDriver extends AlfrescoDiskDriver implements DiskInterfa { // Get the file information for the node - session.beginReadTransaction(transactionService); finfo = cifsHelper.getFileInformation(nodeRef); // DEBUG @@ -688,10 +686,6 @@ public class ContentDiskDriver extends AlfrescoDiskDriver implements DiskInterfa if ( finfo == null) { - // Start a transaction - - session.beginReadTransaction(transactionService); - String[] paths = FileName.splitPath( path); if ( paths[0] != null && paths[0].length() > 1) @@ -737,6 +731,13 @@ public class ContentDiskDriver extends AlfrescoDiskDriver implements DiskInterfa } catch (FileNotFoundException e) { + // Check if there is a transaction active + + if ( session.hasUserTransaction() == false) { + System.out.println("***** getFileInformation() - no transaction active"); + e.printStackTrace(); + } + // a valid use case if (logger.isDebugEnabled()) logger.debug("Getting file information - File not found: \n" + @@ -1458,7 +1459,7 @@ public class ContentDiskDriver extends AlfrescoDiskDriver implements DiskInterfa // DEBUG if ( logger.isDebugEnabled()) - logger.debug("Creaste file, state=" + fstate); + logger.debug("Create file, state=" + fstate); } } diff --git a/source/java/org/alfresco/repo/content/replication/ReplicatingContentStore.java b/source/java/org/alfresco/repo/content/replication/ReplicatingContentStore.java index 558e2012b7..c29ae22137 100644 --- a/source/java/org/alfresco/repo/content/replication/ReplicatingContentStore.java +++ b/source/java/org/alfresco/repo/content/replication/ReplicatingContentStore.java @@ -88,7 +88,7 @@ import org.apache.commons.logging.LogFactory; * *

No Replication

*

- * Content is not written to the primary store only. The other stores are + * Content is written to the primary store only. The other stores are * only used to retrieve content and the primary store is not updated with * the content. * diff --git a/source/java/org/alfresco/repo/transaction/RetryingTransactionHelper.java b/source/java/org/alfresco/repo/transaction/RetryingTransactionHelper.java index a294c8e5af..5797358c30 100644 --- a/source/java/org/alfresco/repo/transaction/RetryingTransactionHelper.java +++ b/source/java/org/alfresco/repo/transaction/RetryingTransactionHelper.java @@ -51,7 +51,7 @@ import org.springframework.dao.DeadlockLoserDataAccessException; public class RetryingTransactionHelper { private static final String MSG_READ_ONLY = "permissions.err_read_only"; - private static Logger fgLogger = Logger.getLogger(RetryingTransactionHelper.class); + private static Logger logger = Logger.getLogger(RetryingTransactionHelper.class); /** * Exceptions that trigger retries. @@ -71,12 +71,12 @@ public class RetryingTransactionHelper /** * Reference to the TransactionService instance. */ - private TransactionService fTxnService; + private TransactionService txnService; /** * The maximum number of retries. -1 for infinity. */ - private int fMaxRetries; + private int maxRetries; /** * Whether the the transactions may only be reads @@ -86,7 +86,7 @@ public class RetryingTransactionHelper /** * Random number generator for retry delays. */ - private Random fRandom; + private Random random; /** * Callback interface @@ -108,7 +108,7 @@ public class RetryingTransactionHelper */ public RetryingTransactionHelper() { - fRandom = new Random(System.currentTimeMillis()); + this.random = new Random(System.currentTimeMillis()); } // Setters. @@ -117,7 +117,7 @@ public class RetryingTransactionHelper */ public void setTransactionService(TransactionService service) { - fTxnService = service; + this.txnService = service; } /** @@ -125,7 +125,7 @@ public class RetryingTransactionHelper */ public void setMaxRetries(int maxRetries) { - fMaxRetries = maxRetries; + this.maxRetries = maxRetries; } /** @@ -199,7 +199,7 @@ public class RetryingTransactionHelper // Track the last exception caught, so that we // can throw it if we run out of retries. RuntimeException lastException = null; - for (int count = 0; fMaxRetries < 0 || count < fMaxRetries; ++count) + for (int count = 0; maxRetries < 0 || count < maxRetries; ++count) { UserTransaction txn = null; boolean isNew = false; @@ -207,11 +207,11 @@ public class RetryingTransactionHelper { if (requiresNew) { - txn = fTxnService.getNonPropagatingUserTransaction(); + txn = txnService.getNonPropagatingUserTransaction(); } else { - txn = fTxnService.getUserTransaction(readOnly); + txn = txnService.getUserTransaction(readOnly); } // Only start a transaction if required. This check isn't necessary as the transactional // behaviour ensures that the appropriate propogation is performed. It is a useful and @@ -239,11 +239,11 @@ public class RetryingTransactionHelper txn.commit(); } } - if (fgLogger.isDebugEnabled()) + if (logger.isDebugEnabled()) { if (count != 0) { - fgLogger.debug( + logger.debug( "Transaction succeeded after " + count + " retries on thread " + Thread.currentThread().getName()); } @@ -271,21 +271,29 @@ public class RetryingTransactionHelper { try { - if (txn.getStatus() != Status.STATUS_ROLLEDBACK) + int txnStatus = txn.getStatus(); + // We can only rollback if a transaction was started (NOT NO_TRANSACTION) and + // if that transaction has not been rolled back (NOT ROLLEDBACK). + // If an exception occurs while the transaction is being created (e.g. no database connection) + // then the status will be NO_TRANSACTION. + if (txnStatus != Status.STATUS_NO_TRANSACTION && txnStatus != Status.STATUS_ROLLEDBACK) { txn.rollback(); } } catch (IllegalStateException e1) { + logger.error(e); throw new AlfrescoRuntimeException("Failure during rollback: " + cb, e1); } catch (SecurityException e1) { + logger.error(e); throw new AlfrescoRuntimeException("Failure during rollback: " + cb, e1); } catch (SystemException e1) { + logger.error(e); throw new AlfrescoRuntimeException("Failure during rollback: " + cb, e1); } } @@ -299,7 +307,7 @@ public class RetryingTransactionHelper // The sleep interval increases with the number of retries. try { - Thread.sleep(fRandom.nextInt(500 * count + 500)); + Thread.sleep(random.nextInt(500 * count + 500)); } catch (InterruptedException ie) {