You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@tomee.apache.org by "Artur Wroblewski (JIRA)" <ji...@apache.org> on 2008/11/17 13:23:44 UTC

[jira] Commented: (OPENEJB-950) Turning on transaction logging results in the IllegalArgumentException: can't parse argument number

    [ https://issues.apache.org/jira/browse/OPENEJB-950?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12648151#action_12648151 ] 

Artur Wroblewski commented on OPENEJB-950:
------------------------------------------

i can confirm the problem.

the workaround is to set 'Transaction' logger to info level, i.e.

log4j.category.Transaction = INFO

> Turning on transaction logging results in the IllegalArgumentException: can't parse argument number
> ---------------------------------------------------------------------------------------------------
>
>                 Key: OPENEJB-950
>                 URL: https://issues.apache.org/jira/browse/OPENEJB-950
>             Project: OpenEJB
>          Issue Type: Bug
>    Affects Versions: 3.1
>         Environment: Windows XP, JDK 1.5 (and 1.6), OpenEJB 3.1 build: 20081009-03:31
>            Reporter: Tobias Rho
>
> Hello OpenEJB Developers!
> I am using OpenEJB embedded in a wicket web application running on Jetty.
> Now I wanted to trace JPA / JTA operations in my test environment and turned the "transaction" logging level to "debug".
> Here are the relevant snippets from my configuration:
> ====== Turned on external logging configuration in test case setup =========
> ....
>         System.setProperty("openejb.logger.external", "true");
>         p.put(Context.INITIAL_CONTEXT_FACTORY, "org.apache.openejb.client.LocalInitialContextFactory");
> ....
> ====== Extract from my log4j.properties file ========
> log4j.rootLogger                   = fatal,C
> ...
> log4j.category.Transaction         = debug
> ...
> log4j.appender.C                           = org.apache.log4j.ConsoleAppender
> log4j.appender.C.layout                    = org.apache.log4j.SimpleLayout
> =======================================
> This led to an endless loop in the method org.apache.openejb.util.Memoizer.compute(..)
> on several debug messages emitted by the class org.apache.openejb.core.transaction.JtaTransactionPolicy.
> Here is an example message copied from the source code:
> JtaTransactionPolicy.beginTransaction(JtaTransactionPolicy.java:235)
>         txLogger.debug("TX {}: Started transaction {}", transactionType, transaction);
> The message key (ok, this cannot be a key anyway) is not found in
> \openejb-core-3.1.jar\org\apache\openejb\util\resources\Messages.properties
> so "TX {}: Started transaction {}" is passed on to java.text.MessageFormat.
> But MessageFormat.makeFormat(..) expects arguments numbers in the braces and throws an IllegalArgumentException.
> I solved the problem for myself by replacing all occurences of "{}" in all debug messages in this file (see below) and
> copied the resulting class to openejb-core-3.1.jar.
> Maybe the reason for this bug is that I my JDK version is not compatible?
> makeFormat(..)  could have had a default behaviour replacing all {} with {<{} position>} in a JDK < 1.5....?
> Anyway, replacing JtaTransactionPolicy with my variant would be helpful for my configuration.
> ============ Stack Trace =============
> java.util.concurrent.ExecutionException: java.lang.IllegalArgumentException: can't parse argument number
>     at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:205)
>     at java.util.concurrent.FutureTask.get(FutureTask.java:80)
>     at org.apache.openejb.util.Memoizer.compute(Memoizer.java:53)
>     at org.apache.openejb.util.Logger.formatMessage(Logger.java:185)
>     at org.apache.openejb.util.Logger.debug(Logger.java:234)
>     at org.apache.openejb.core.transaction.JtaTransactionPolicy.beginTransaction(JtaTransactionPolicy.java:235)
>     at org.apache.openejb.core.transaction.TxRequired.<init>(TxRequired.java:54)
>     at org.apache.openejb.core.transaction.JtaTransactionPolicyFactory.createTransactionPolicy(JtaTransactionPolicyFactory.java:36)
>     at org.apache.openejb.core.transaction.EjbTransactionUtil.createTransactionPolicy(EjbTransactionUtil.java:55)
>     at org.apache.openejb.core.stateless.StatelessContainer._invoke(StatelessContainer.java:200)
>     at org.apache.openejb.core.stateless.StatelessContainer.invoke(StatelessContainer.java:169)
>     at org.apache.openejb.core.ivm.EjbObjectProxyHandler.businessMethod(EjbObjectProxyHandler.java:217)
>     at org.apache.openejb.core.ivm.EjbObjectProxyHandler._invoke(EjbObjectProxyHandler.java:77)
>     at org.apache.openejb.core.ivm.BaseEjbProxyHandler.invoke(BaseEjbProxyHandler.java:286)
>     at $Proxy28.getUserFor(Unknown Source)
>     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>     at java.lang.reflect.Method.invoke(Method.java:585)
>     at org.apache.wicket.proxy.LazyInitProxyFactory$JdkHandler.invoke(LazyInitProxyFactory.java:416)
>     at org.apache.wicket.proxy.$Proxy27.getUserFor(Unknown Source)
>     at de.trho.login.CreateUserAccountPage$1.onValidate(CreateUserAccountPage.java:89)
> ...
> Caused by: java.lang.IllegalArgumentException: can't parse argument number
>     at java.text.MessageFormat.makeFormat(MessageFormat.java:1330)
>     at java.text.MessageFormat.applyPattern(MessageFormat.java:450)
>     at java.text.MessageFormat.<init>(MessageFormat.java:350)
>     at org.apache.openejb.util.Logger$4.compute(Logger.java:108)
>     at org.apache.openejb.util.Logger$4.compute(Logger.java:107)
>     at org.apache.openejb.util.Memoizer$1.call(Memoizer.java:42)
>     at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
>     at java.util.concurrent.FutureTask.run(FutureTask.java:123)
>     at org.apache.openejb.util.Memoizer.compute(Memoizer.java:49)
>     ... 60 more
> ================ Modified JtaTransactionPolicy File =======================
> /**
>  * Licensed to the Apache Software Foundation (ASF) under one or more
>  * contributor license agreements.  See the NOTICE file distributed with
>  * this work for additional information regarding copyright ownership.
>  * The ASF licenses this file to You under the Apache License, Version 2.0
>  * (the "License"); you may not use this file except in compliance with
>  * the License.  You may obtain a copy of the License at
>  *
>  *     http://www.apache.org/licenses/LICENSE-2.0
>  *
>  * Unless required by applicable law or agreed to in writing, software
>  * distributed under the License is distributed on an "AS IS" BASIS,
>  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
>  * See the License for the specific language governing permissions and
>  * limitations under the License.
>  */package org.apache.openejb.core.transaction;
> import java.rmi.RemoteException;
> import java.util.Map;
> import java.util.LinkedHashMap;
> import java.util.List;
> import java.util.LinkedList;
> import java.util.ArrayList;
> import javax.transaction.HeuristicMixedException;
> import javax.transaction.HeuristicRollbackException;
> import javax.transaction.InvalidTransactionException;
> import javax.transaction.RollbackException;
> import javax.transaction.Status;
> import javax.transaction.Transaction;
> import javax.transaction.TransactionManager;
> import javax.transaction.TransactionSynchronizationRegistry;
> import javax.transaction.Synchronization;
> import javax.transaction.xa.XAResource;
> import org.apache.openejb.ApplicationException;
> import org.apache.openejb.SystemException;
> import org.apache.openejb.loader.SystemInstance;
> import org.apache.openejb.util.LogCategory;
> import org.apache.openejb.util.Logger;
> public abstract class JtaTransactionPolicy implements TransactionPolicy {
>     protected final static Logger logger = Logger.getInstance(LogCategory.OPENEJB, "org.apache.openejb.util.resources");
>     protected final static Logger txLogger = Logger.getInstance(LogCategory.TRANSACTION, "org.apache.openejb.util.resources");
>     protected final TransactionType transactionType;
>     protected final TransactionManager transactionManager;
>     private final TransactionSynchronizationRegistry synchronizationRegistry;
>     private Map<Object,Object> resources;
>     private final List<TransactionSynchronization> synchronizations = new LinkedList<TransactionSynchronization>();
>     private boolean rollbackOnly;
>     public JtaTransactionPolicy(TransactionType transactionType, TransactionManager transactionManager) {
>         this.transactionType = transactionType;
>         this.transactionManager = transactionManager;
>         synchronizationRegistry = SystemInstance.get().getComponent(TransactionSynchronizationRegistry.class);
>     }
>     public TransactionType getTransactionType() {
>         return transactionType;
>     }
>     protected abstract Transaction getCurrentTrasaction();
>     public boolean isTransactionActive() {
>         Transaction trasaction = getCurrentTrasaction();
>         if (trasaction == null) {
>             return false;
>         }
>         try {
>             int status = trasaction.getStatus();
>             return status == Status.STATUS_ACTIVE || status == Status.STATUS_MARKED_ROLLBACK;
>         } catch (javax.transaction.SystemException e) {
>             return false;
>         }
>     }
>     public boolean isRollbackOnly() {
>         Transaction trasaction = getCurrentTrasaction();
>         if (trasaction != null)  {
>             try {
>                 int status = trasaction.getStatus();
>                 return status == Status.STATUS_MARKED_ROLLBACK;
>             } catch (javax.transaction.SystemException e) {
>                 return false;
>             }
>         } else {
>             return rollbackOnly;
>         }
>     }
>     public void setRollbackOnly() {
>         Transaction trasaction = getCurrentTrasaction();
>         if (trasaction != null)  {
>             setRollbackOnly(trasaction);
>         } else {
>             rollbackOnly = true;
>         }
>     }
>     public Object getResource(Object key) {
>         if (isTransactionActive()) {
>             return synchronizationRegistry.getResource(key);
>         }
>         if (resources == null) {
>             return null;
>         }
>         return resources.get(key);
>     }
>     public void putResource(Object key, Object value) {
>         if (isTransactionActive()) {
>             synchronizationRegistry.putResource(key, value);
>         }
>         if (resources == null) {
>             resources = new LinkedHashMap<Object,Object>();
>         }
>         resources.put(key, value);
>     }
>     public Object removeResource(Object key) {
>         if (isTransactionActive()) {
>             Object value = synchronizationRegistry.getResource(key);
>             synchronizationRegistry.putResource(key, null);
>             return value;
>         }
>         if (resources == null) {
>             return null;
>         }
>         return resources.remove(key);
>     }
>     public void registerSynchronization(final TransactionSynchronization synchronization) {
>         if (isTransactionActive()) {
>             synchronizationRegistry.registerInterposedSynchronization(new Synchronization() {
>                 public void beforeCompletion() {
>                     synchronization.beforeCompletion();
>                 }
>                 public void afterCompletion(int s) {
>                     TransactionSynchronization.Status status;
>                     if (s == Status.STATUS_COMMITTED) {
>                         status = TransactionSynchronization.Status.COMMITTED;
>                     } else if (s == Status.STATUS_ROLLEDBACK) {
>                         status = TransactionSynchronization.Status.ROLLEDBACK;
>                     } else {
>                         status = TransactionSynchronization.Status.UNKNOWN;
>                     }
>                     synchronization.afterCompletion(status);
>                 }
>             });
>         } else {
>             synchronizations.add(synchronization);
>         }
>     }
>     protected void fireNonTransactionalCompletion() {
>         for (TransactionSynchronization synchronization : new ArrayList<TransactionSynchronization>(synchronizations)) {
>             try {
>                 synchronization.beforeCompletion();
>             } catch (Throwable e) {
>                 logger.error("Exception thrown from beforeCompletion() of TransactionSynchronization " + synchronization);
>             }
>         }
>         TransactionSynchronization.Status status = isRollbackOnly() ? TransactionSynchronization.Status.ROLLEDBACK : TransactionSynchronization.Status.COMMITTED;
>         for (TransactionSynchronization synchronization : new ArrayList<TransactionSynchronization>(synchronizations)) {
>             try {
>                 synchronization.afterCompletion(status);
>             } catch (Exception e) {
>                 logger.error("Exception thrown from afterCompletion(" + status + ") of TransactionSynchronization " + synchronization);
>             }
>         }
>     }
>     public void enlistResource(XAResource xaResource) throws SystemException {
>         Transaction transaction = getCurrentTrasaction();
>         if (transaction != null) {
>             try {
>                 if (transaction.enlistResource(xaResource)) {
>                     return;
>                 }
>             } catch (Exception e) {
>                 throw new SystemException("Unable to enlist xa resource in the transaction", e);
>             }
>         }
>         throw new SystemException("Unable to enlist xa resource in the transaction");
>     }
>     public String toString() {
>         return transactionType.toString();
>     }
>     protected Transaction getTransaction() throws SystemException {
>         try {
>             return transactionManager.getTransaction();
>         } catch (javax.transaction.SystemException e) {
>             txLogger.error("The Transaction Manager has encountered an unexpected error condition while attempting to obtain current transaction: {0}", e.getMessage());
>             throw new SystemException(e);
>         }
>     }
>     protected void setRollbackOnly(Transaction tx) {
>         try {
>             if (tx != null && tx.getStatus() == Status.STATUS_ACTIVE) {
>                 tx.setRollbackOnly();
>                 txLogger.debug("TX {0}: setRollbackOnly() on transaction {1}", transactionType, tx);
>             }
>         } catch (Exception e) {
>             txLogger.error("Exception during setRollbackOnly()", e);
>             throw new IllegalStateException("No transaction active", e);
>         }
>     }
>     protected Transaction beginTransaction() throws SystemException {
>         Transaction transaction;
>         try {
>             transactionManager.begin();
>             transaction = transactionManager.getTransaction();
>         } catch (Exception e) {
>             txLogger.error("The Transaction Manager has encountered an unexpected error condition while attempting to begin a new transaction: {0}", e.getMessage());
>             throw new SystemException(e);
>         }
>         if (transaction == null) {
>             throw new SystemException("Failed to begin a new transaction");
>         }
>         txLogger.debug("TX {0}: Started transaction {1}", transactionType, transaction);
>         return transaction;
>     }
>     protected Transaction suspendTransaction() throws SystemException {
>         try {
>             Transaction tx = transactionManager.suspend();
>             txLogger.info("TX {0}: Suspended transaction {1}", transactionType, tx);
>             return tx;
>         } catch (javax.transaction.SystemException se) {
>             txLogger.error("Exception during suspend()", se);
>             throw new SystemException(se);
>         }
>     }
>     protected void resumeTransaction(Transaction tx) throws SystemException {
>         try {
>             if (tx == null) {
>                 txLogger.debug("TX {0}: No transaction to resume", transactionType);
>             } else {
>                 txLogger.debug("TX {0}: Resuming transaction {1}",transactionType, tx);
>                 transactionManager.resume(tx);
>             }
>         } catch (InvalidTransactionException ite) {
>             txLogger.error("Could not resume the client's transaction, the transaction is no longer valid: {}", ite.getMessage());
>             throw new SystemException(ite);
>         } catch (IllegalStateException e) {
>             txLogger.error("Could not resume the client's transaction: {0}", e.getMessage());
>             throw new SystemException(e);
>         } catch (javax.transaction.SystemException e) {
>             txLogger.error("Could not resume the client's transaction: The transaction reported a system exception: {0}", e.getMessage());
>             throw new SystemException(e);
>         }
>     }
>     protected void completeTransaction(Transaction tx) throws SystemException, ApplicationException {
>         boolean shouldRollback;
>         try {
>             shouldRollback = tx.getStatus() != Status.STATUS_ACTIVE;
>         } catch (javax.transaction.SystemException e) {
>             txLogger.error("The Transaction Manager has encountered an unexpected error condition while attempting to obtain transaction status: {0}", e.getMessage());
>             throw new SystemException(e);
>         }
>         if (shouldRollback) {
>             rollbackTransaction(tx);
>             return;
>         }
>         try {
>             txLogger.debug("TX {0}: Committing transaction {1}", transactionType, tx);
>             if (tx.equals(transactionManager.getTransaction())) {
>                 transactionManager.commit();
>             } else {
>                 tx.commit();
>             }
>         } catch (RollbackException e) {
>             txLogger.debug("The transaction has been rolled back rather than commited: {0}", e.getMessage());
>             Throwable txe = new TransactionRolledbackException("Transaction was rolled back, presumably because setRollbackOnly was called during a synchronization").initCause(e);
>             throw new ApplicationException(txe);
>         } catch (HeuristicMixedException e) {
>             txLogger.debug("A heuristic decision was made, some relevant updates have been committed while others have been rolled back: {0}", e.getMessage());
>             throw new ApplicationException(new RemoteException("A heuristic decision was made, some relevant updates have been committed while others have been rolled back").initCause(e));
>         } catch (HeuristicRollbackException e) {
>             txLogger.debug("A heuristic decision was made while commiting the transaction, some relevant updates have been rolled back: {0}", e.getMessage());
>             throw new ApplicationException(new RemoteException("A heuristic decision was made while commiting the transaction, some relevant updates have been rolled back").initCause(e));
>         } catch (SecurityException e) {
>             txLogger.error("The current thread is not allowed to commit the transaction: {0}", e.getMessage());
>             throw new SystemException(e);
>         } catch (IllegalStateException e) {
>             txLogger.error("The current thread is not associated with a transaction: {0}", e.getMessage());
>             throw new SystemException(e);
>         } catch (javax.transaction.SystemException e) {
>             txLogger.error("The Transaction Manager has encountered an unexpected error condition while attempting to commit the transaction: {0}", e.getMessage());
>             throw new SystemException(e);
>         }
>     }
>     protected void rollbackTransaction(Transaction tx) throws SystemException {
>         try {
>             txLogger.debug("TX {0}: Rolling back transaction {1}", transactionType, tx);
>             if (tx.equals(transactionManager.getTransaction())) {
>                 transactionManager.rollback();
>             } else {
>                 tx.rollback();
>             }
>         } catch (IllegalStateException e) {
>             logger.error("The TransactionManager reported an exception while attempting to rollback the transaction: " + e.getMessage());
>             throw new SystemException(e);
>         } catch (javax.transaction.SystemException e) {
>             logger.error("The TransactionManager reported an exception while attempting to rollback the transaction: " + e.getMessage());
>             throw new SystemException(e);
>         }
>     }
> }

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.