Friday, October 7, 2011

Dynamically changing app-specific logging under JBoss AS: parallel deployment

01.12.2011. Update: Go read first this post. Then come back here if you want.

Last time I described one way of changing the app-specific logging configuration at runtime. The proposed solution is limited to changing log level only. This post describes what can be done to be able to change the complete logging configuration without redeploying the application.

There are several ways to do it but they share the same basic idea: instead of deploying one artifact (the application with the logging configuration) deploy the application and the logging configuration separately. Later, if some logging detail must be changed, only the separately deployed logging configuration has to be changed. JBoss detects the change and redeploys the configuration. The application keeps running. Important note: if the application has to be redeployed then both deployments must be redeployed.

First things first: in order for this scheme to work the application and the logging configuration must be specially prepared. The steps are:
  1. Configure your application to use the app-specific logging and make sure it really works.

  2. Split your logging configuration in two files. One file remains packaged in the application as jboss-logging.xml. It should look like this:
    <logging xmlns="urn:jboss:logging:6.0" context="MyWonderfulLogContext"> 
    <define-context name="MyWonderfulLogContext"/>
    </logging>
    Only context attribute and define-context element stay in the file. While it is possible to include some other logging configuration in the file I would not recommend it because these definitions can't be changed without redeploying the application itself.

  3. Deploy your application. You will notice that it generates no logging. It is logical: there is after all no logging definitions in jboss-logging.xml of the application.

  4. Prepare the second deployment artifact. The main part of it is the remaining logging configuration. It is the original jboss-logging.xml without define-context element.:
    <logging xmlns="urn:jboss:logging:6.0" context="MyWonderfulLogContext"> 
    <!-- Here come definitions of handlers, loggers, etc -->
    </logging>

  5. Deploy it. There are 3 possibilities:

    • Package it into something JBoss recognizes as a valid deployment (a jar or an ear). The packaging does not have to match the packaging of your application. For example create a file named MyWonderfulLogContext.ear with a single file META-INF/jboss-logging.xml. Deploy this file next to your application. As of this moment you should see some logging being generated. If you need to change the configuration you have to change create jboss-logging.xml, repackage MyWonderfulLogContext.ear and redeploy it.

    • You can also deploy the prepared package exploded. For example, create directory MyWonderfulLogContext.ear in the deploy directory of JBoss, create META-INF subdirectory and copy jboss-logging.xml into it. Later you can just edit this file if you need to change the configuration.

    • Rename the prepared jboss-logging.xml to something like MyWonderfulLogContext-jboss-logging.xml (the name must end with jboss-logging.xml) and copy it into the deploy directory of JBoss. Later you can just edit this file if you need to change the configuration.

      This does not work with out of the box JBoss: it recognizes only the file named 'jboss-logging.xml'. Fortunately it is not hardcoded in some java class but specified as part of the configuration. To enable JBoss to recognize more than just jboss-logging.xml you need to change file JBOSS_HOME/server/<servername>/deployers/jboss-logging.deployer/META-INF/logmanager-jboss-beans.xml. Locate bean named "JBossLoggingMetaDataSchemaResolverDeployer" and change
      <property name="name">jboss-logging.xml</property>
      into
      <property name="suffix">jboss-logging.xml</property>

What makes the parallel deployment scheme work is define-context element in jboss-logging.xml of the main application. As soon as the application is deployed JBoss creates the context object. The loggers used by the application are retrieved from this context object. As long as the application is deployed the context stays around. (Re-)Deploying the second deployment artifact just adds or removes the logging configuration to or from the context.

You can combine this scheme with the JMX bean solution. The JMX bean belongs to the context so it is also available as soon as the context is created (at deployment/startup) and remains valid until the log context is valid.

Friday, September 23, 2011

Dynamically changing app-specific logging under JBoss AS: JMX

01.12.2011. Update: Go read first this post. Then come back here if you want.

I have already blogged on JBoss 6 application specific logging, see here.

The setup works as expected. But I still miss a very important piece of functionality. The logging is not the main (you'd be surprised what some creative people can do!) reason why an application is developed. The logging helps identifying and finding problems in the application. One of the requirements to the logging framework is the ability to change at least some setting without a new deployment of the application:
  1. Changing log levels is a must. If I have a problem with a running application I want to be able to change log levels of some loggers and see the changes being applied as soon as possible.

  2. Changing the output formatting might come handy in some cases. I have been in a situation when I really wanted to change the formatting only once: the output did not include thread names.

  3. Changing where the log is written is not that important. Well, of course, it the log is currently written to nowhere then it is important to be able to change it. But normally the log is written somewhere and it is good enough to investigate a problem.
None of this is possible by default with the application-specific logging in JBoss AS 6. It looks like a crude joke: the standard logging configuration in JBoss is hot-deployable. Any change to <jboss>/server/<server_name>/deploy/jboss-logging.xml is applied almost immediately. There is a JMX MBean (java.util.logging:type=Logging) which can be used to query and change log levels. And if I want to change some configuration in the application-specific logging configuration? Only by redeploying the application.

I must say I find it more and more annoying. It looks suspiciously close to early versions of red hat linux :-) The things seem to work but if I need just a bit more functionality, which I know is there, I need a hammer. Or a debugger this time.

Anyway after some quality swearing, mainly at jboss, but maven and eclipse got their share of attention, and countless attempts to deploy an application and change some configuration files I have found several ways to (partially) change the per-application logging without redeploying the application.

Most of the solutions are just variations of the same approach. They allow changing every detail of the application logging with various degrees of cumbersomeness.

One solution stands really apart. It is quite easy to setup and use, with a single limitation: only log levels can be changed, no other change is possible. But this is exactly what is needed most of the time. The solution offers the possibility to perform changes locally and remotely. Another advantage: if you have already an application with the app-specific logging configured and are just dying to change the log level "right now" you can do it without redeploying the application. The solution is described below:

Changing log levels via JMX.


Changing logging details looks like a perfect candidate for JMX. When I was experimenting with the logging I was a bit surprised by the lack of any logging JMX. JBoss is full with JMX beans, yet there is no JMX related to the logging except the one which comes from JDK: java.util.logging:type=Logging. (JBoss replaces it with its own at startup, but this is beyond the point.)

After inspecting JBoss logging source code I came across some mentioning of JMX. The most promising were classes org.jboss.logmanager.LogContext with its getLoggingMXBean() method and org.jboss.logmanager.LoggingMXBeanImpl implementing java.util.logging.LoggingMXBean interface. So I concentrated on them.

I must say JBoss guys have really interesting sence of humor. It walks like a duck, it swims like a duck, it quacks like a duck, yet it is not a duck. Now I have an example of such a beast. You see, the class is named LoggingMXBeanImpl, it implements LoggingMXBean, the method is getLoggingMXBean, and yet an instance of class org.jboss.logmanager.LoggingMXBeanImpl does not pass the validation rules of the JBoss JMX server. You can't do better than that even on purpose.

Anyway, here is it:
  1. Configure your application to use the app-specific logging. You end up creating a file named jboss-logging.xml that looks like this:
    <logging xmlns="urn:jboss:logging:6.0" context="MyWonderfulLogContext">
    <define-context name="MyWonderfulLogContext"/>

    <!-- Here come definitions of handlers, loggers, etc -->
    ...
    </logging>

  2. Deploy your application; make sure the app-specific logging actually works and the logging goes where it supposed to go.

  3. Create somewhere a file named for example MyWonderfulLog-jboss-beans.xml with the following content:
    <?xml version="1.0" encoding="UTF-8"?>
    <deployment xmlns="urn:jboss:bean-deployer:2.0">
    <bean name="MyWonderfulLogContextMBean" class="java.util.logging.LoggingMXBean">
    <constructor factoryMethod="getLoggingMXBean">
    <factory bean="Logging:CONTEXT:MyWonderfulLogContext"/>
    </constructor>
    <annotation>@org.jboss.aop.microcontainer.aspects.jmx.JMX(
    exposedInterface=java.util.logging.LoggingMXBean.class,
    name="boom.tralala:context=MyWonderfulLogContext",
    registerDirectly=false)</annotation>
    </bean>
    </deployment>
    Attention: the annotation element must be on a single line!

  4. Deploy this file by copying it to <jboss>/server/<server_name>/deploy. If everything went OK and there are no errors in console or in <jboss>/server/<server_name>/log/server.log, then navigate to http://<jboss-host>:<jboss-port>/jmx-console. You should see something like this:




  5. Click on context=MyWonderfulLogContext link and you get to the page that allows you to query some information and, more importantly, change log levels with operation setLoggerLevel. The first parameter is the logger name like 'org.jboss' or 'com.mycompany.app.package'. The second parameter is the logging level like 'INFO' or 'DEBUG'. Go ahead and play with it.

  6. If everything is working you can repackage your application so that there is no need to deploy 2 files, your application and MyWonderfulLog-jboss-beans.xml. Rename the file to jboss-beans.xml and place it next to your jboss-logging.xml, for example, in EAR/META-INF. If you already have jboss-beans.xml just add MyWonderfulLogContextMBean bean definition to your file. Next time you deploy your application you get the logging JMX bean automatically.

That is it.

Oh, yeah. Some technical details:
  1. When JBoss deploys your logging configuration it creates some objects (beans) and registers them internally. These objects are not JMX beans. One of the objects is LogContext and it is registered under the name Logging:CONTEXT:<name attribute of define-context element from jboss-logging.xml>. Thus the bean name <factory bean="Logging:CONTEXT:MyWonderfulLogContext"/> in *-jboss-beans.xml must match the name JBoss uses internally.

  2. Ignoring 'annotation' element the definition can be read as "look up JBoss bean named Logging:CONTEXT:MyWonderfulLogContext, invoke its method getLoggingMXBean and place the result of invocation in the JBoss bean registry under the name MyWonderfulLogContextMBean". There is yet no JMX in sight.

  3. Now comes the annotation element. JBoss allows you to annotate bean instances dynamically. The result looks as if java class of the instance had this annotation. In this case: as if class org.jboss.logmanager.LoggingMXBeanImpl had annotation @org.jboss.aop.microcontainer.aspects.jmx.JMX. The only difference is that the annotation is not there if you have any instance of this class itself but it is there if you have MyWonderfulLogContextMBean bean. Important: the annotation element must be on a single line, and must not start (and probably end) with whitespaces. JBoss annotation parser is very picky.

  4. The annotation itself says that JBoss bean named MyWonderfulLogContextMBean has to be registered as a JMX bean. Attribute 'name' specifies the ObjectName under which the bean has to be registered. It is a good idea to include the name of your LogContext there. And try not to use 'jboss' anywhere in the name to avoid future naming conflicts.

    I have created a JBoss issue and if its fixed JBoss would have to come up with a naming scheme. I doubt 'boom.tralala' would be their first choice but I would not be surprised if they stick 'jboss' somewhere in the name.

    If attribute 'registerDirectly' is true JBoss expects that the bean is already a JMX MBean. Remember I said above that the instance of org.jboss.logmanager.LoggingMXBeanImpl does not pass the validation rules of the JBoss JMX server? This is the reason 'registerDirectly' is set to false. This makes JBoss wrap our instance in an instance of class javax.management.StandardMBean, which is recognized as a valid JMX MBean by the JBoss JMX server.

    And StandardMBean needs to know what interface it is going to represent. This explains attribute 'exposedInterface'.

Next time I explain how to change every aspect of the logging configuration at runtime.

Thursday, September 8, 2011

Assorted facts about JBoss. Fact 3: how to make per-application logging work

01.12.2011. Update: Go read first this post. Then come back here if you want.

I am now busy with some JBoss AS6 related work. One of the things I wanted to be able to do is to have a separate application specific log file. Very easy, very understandable requirement.

Except not under JBoss. It looks like there is a completely new logging subsystem in JBoss AS 6. No advice on how to do it in previous versions would help. And there is not much documentation on how to do it except of some examples here and there and complains that this functionality is broken. There is also a corresponding JBoss issue.

The issue page describes the problem and offers a workaround. The issue is marked as resolved in JBoss AS 6.1.0 Final. The "fix" is actually a proposed workaround; the fact that I immediately did not like.

I have created jboss-logging.xml so that all the logging from my application would go not to ${jboss.server.log.dir}/server.log but to ${jboss.server.log.dir}/my-app.log. After deploying my application I immediately noticed that the fix worked: there was no error. I also got my-app.log next to server.log. All nice and dice. Brand new empty my-app.log no matter what I did in my application. All the logging still went to server.log. So much for the fix.

And it looks like I am not alone. This post mentions the same problem: "My new log file is empty."

But the new wonderful logging subsystem does more for me! When I undeploy my application I get the following exception:
ERROR [org.jboss.deployers.vfs.deployer.kernel.BeanMetaDataDeployer]
Error during undeploy: Logging:REGISTRATION:MyAppLogContext:Anonymous-5: java.lang.NullPointerException
at org.jboss.logging.metadata.GetClassLoaderBeanMetaData.setClassLoader(GetClassLoaderBeanMetaData.java:52)
at org.jboss.deployers.vfs.deployer.kernel.BeanMetaDataDeployer.undeploy(BeanMetaDataDeployer.java:237)
at org.jboss.deployers.vfs.deployer.kernel.BeanMetaDataDeployer.undeploy(BeanMetaDataDeployer.java:58)
Bummer!

After some poking around jboss configuration and the source code I have found a solution. Actually a workaround and a fix.

Workaround:
  1. If you are still working on JBoss AS 6.0.0.Final then you have to apply the workaround described in this issue: change file JBOSS_HOME/server/<servername>/deployers/jboss-logging.deployer/META-INF/logmanager-jboss-beans.xml. Now you have the same configuration as JBoss AS 6.1.0.Final.
  2. Change the logging deployer configuration (file JBOSS_HOME/server/<servername&g;/deployers/jboss-logging.deployer/META-INF/logmanager-jboss-beans.xml) by removing that mode="On Demand" from
    OnDemandJBossLogManagerContextSelector bean:
    <bean name="OnDemandJBossLogManagerContextSelector"
    class="org.jboss.logmanager.LogContextSelectorService"
    mode="On Demand">
    <property name="selector">
    <inject bean="JBossLogManagerContextSelectorService"/>
    </property>
    </bean>
    You can also remove that comment above about lazy loading. It is not true anyway.

Congratulations, you have now your application specific log file and your logging really goes to this file. Unfortunately you will get NPE (see above) when your application is undeployed. This can't be worked around.

The fix is actually a code patch. I have submitted it to JBoss (see here). Unfortunately it means we have to wait until it is accepted and incorporated into some release. For those who are not afraid of javac: you can download the patch from the issue page and build it yourself. You will have to update the logging deployer configuration (file JBOSS_HOME/server/<servername&g;/deployers/jboss-logging.deployer/META-INF/logmanager-jboss-beans.xml). It is also included in the patch.

Friday, August 19, 2011

Assorted facts about JBoss. Fact 2: classloading. Broken by default.

The classloading situation in JBoss is a mess. You know, evolutionary kind of mess. They began with something messy, then started to add more things, configuration parameters, bells and whistles ... Some old classloading problems went away, just to be replaced by new problems.

I had my share of ClassNotFoundExceptions, NoClassDefFoundErrors, and LinkageErrors before. Not all of them were caused by JBoss, but those that were caused by JBoss were the toughest to resolve.

Recently JBoss (JBoss Application Server 6) appeared again on my professional horizon. And one of the first problems I ran into was a LinkageError. Even that problem with StAX API jar happened later.

The deployment of the application fails. Sometimes. And sometimes it is OK. If it fails, the error is
java.lang.LinkageError:

loader constraint violation:
loader (instance of org/jboss/classloader/spi/base/BaseClassLoader)
previously initiated loading for a different type
with name "org/xml/sax/Attributes"
The class name is not always org.xml.sax.Attributes, but it is always a class from org.xml.sax. And if the deployment is OK, the same error happens later, at runtime.

Nothing new. This error screams "Duplicate class". So I looked around and found jtidy-4aug2000r7-dev.jar packaged in EAR/lib (and only there) which has its own copy of org.xml.sax and org.w3c.dom classes. JMX classloader bean for the application confirmed that the classes are coming from the application's EAR.

The reason why the classes are packaged into jtidy-4aug2000r7-dev.jar is not really important here. But I was really surprised (well, initially) that JBoss uses these classes instead of JDK classes. I deployed the application on the stock version of JBoss AS 6 without any modifications of classloading configuration. There was even no jboss-app.xml (I was planning to add it, just in case) let alone other classloading specific files. So I expect JBoss to have JEE compatible classloading behavior.

Initially I did not have time to investigate the problem. After notifying the project owner of the problem the decision is made: remove JTidy jar from EAR/lib and continue. JTidy is used in some really obscure piece of code that is called not that often. We can deal with this later. There is even a chance that this functionality will be rewritten to get rid of JTidy. But now we need a version of the application running in JBoss.

I did just that and went ahead. But I kept wondering. I could not understand why the presence of jtidy-4aug2000r7-dev.jar in EAR/lib causes such an error. It goes against all my knowledge, understanding of and experience with java classloading. Except that I am dealing with JBoss. But even JBoss would not do that, would it?

More importantly that problem might have a much broader effect on the project but I could not even imagine what kind of effect. More likely negative, that I was sure of.

Finally I have got some spare time. I have created a very simple application with a single EJB module with one SessionBean and jtidy-4aug2000r7-dev.jar as a dependency, packaged as an EAR application. After deploying it into JBoss I went into JMX classloader bean and verified that org.xml.sax classes are coming from the test application. The SessionBean has a business method that does Class.forName() and then returns getProtectionDomain().getCodeSource() of the loaded class. I created a simple EJB client application that calls the business method with different class names. All the org.xml.sax and org.w3c.dom classes present in jtidy-4aug2000r7-dev.jar were indeed coming from this jar file.

Next I have created another jar file manually packaging some classes from various places and packages like javax.xml.bind, org.dom4j, org.hibernate, java.text, javax.management, etc. I replaced jtidy jar with this new jar file and repeated the test. Only with java.* classes the business method was returning null which means that only those classes were coming from the primordial class loader. All other classes present in the jar were loaded from it. Well, well, well, JBoss at it again.

Trying to find anything specific about the problem on the net did not help. Classloading problems in JBoss is a really hot topic after all!

If nothing else helps ... Use the Source Luke!

Actually even before going deep I noticed one interesting thing in JBoss JMX Console. It appears that my demo application has a classloader domain JMX even if I did not have JBoss specific deployment descriptors. I clicked on it and again one thing stood out just screaming "Look at me":
ParentPolicyName, MBean Attribute, AFTER_BUT_JAVA_BEFORE.

"After but java before". Sounds familiar. pseudoTransactionEnlistment anyone? Or maybe BOZOSLIVEHERE?

The rest was easy. The biggest problem was to get the right source files quickly. You can't nowadays just download a fat zip or gz file with all the sources in it. After that was done, a bit of grepping and the like reveals the truth:

Class org.jboss.classloader.spi.ParentPolicy with some predefined instances like BEFORE, AFTER, BEFORE_BUT_JAVA_ONLY, etc. The comments around these predefined instances explained the meaning. In my case it was AFTER_BUT_JAVA_BEFORE. Except that the source file claims that AFTER_BUT_JAVA_BEFORE means "Java and Javax classes before, everything else after" and my tests show that javax.* classes also come from the jar file in EAR/lib. A bit more looking around led me to this piece of code in class org.jboss.classloading.spi.dependency.Module:
public ParentPolicy getDeterminedParentPolicy()

{
if (isJ2seClassLoadingCompliance())
return ParentPolicy.BEFORE;
else
return ParentPolicy.AFTER_BUT_ONLY_JAVA_BEFORE;
}

Since I do not have any JBoss specific deployment descriptors isJ2seClassLoadingCompliance() returns false resulting in ParentPolicy.AFTER_BUT_ONLY_JAVA_BEFORE being used. Not AFTER_BUT_JAVA_BEFORE. The comments next to AFTER_BUT_ONLY_JAVA_BEFORE in ParentPolicy.java clearly match the observed behavior: "Java classes before, everything else after". What am I missing?

Turns out there is one more small thing: a copy-paste error in the definition of AFTER_BUT_ONLY_JAVA_BEFORE:
/** Java and Javax classes before, everything else after */

public static final ParentPolicy AFTER_BUT_JAVA_BEFORE =
new ParentPolicy(ClassFilterUtils.JAVA_ONLY,
ClassFilterUtils.EVERYTHING,
"AFTER_BUT_JAVA_BEFORE");

/** Java classes before, everything else after */
public static final ParentPolicy AFTER_BUT_ONLY_JAVA_BEFORE =
new ParentPolicy(ClassFilterUtils.NOTHING_BUT_JAVA,
ClassFilterUtils.EVERYTHING,
"AFTER_BUT_JAVA_BEFORE");
Mystery solved. I have added jboss-app.xml to the EAR with <loader-repository-config>java2ParentDelegation=true</loader-repository-config> (might just as well have added jboss-classloading.xml), redeployed the application and sure enough I have got BEFORE as ParentPolicyName in JMX Console, but more importantly I have now the expected classloading behavior. For each class present the test jar in EAR/lib both JMX Console and my SessionBean load the class not from the test jar but form some other place like JDK or jars from <jboss>/common/lib.

I have mentioned above that I was planning to add jboss-app.xml to the application anyway because I do not trust JBoss. Boy I was right. The end result for me would have been the same but I would have missed all that fun.

But ... Who in their right mind comes up with such interesting classloading logic?? What they were trying to achieve? Why the hell I have to explicitly "opt in" to get the most sensible classloading configuration? *


* Note: ideally. The current state of classloading affairs in JEE containers makes it much harder than necessary. Internal container classes and classes from various third-party jars that container is using leak into an application. This is a big deal even if the application does not have conflicts with those third-party jars. In case of conflicts all bets are off. Granted containers provide some mechanisms to fine tune classloading, but these mechanisms do not always work. Yes, JBoss, it is about you. But I do think that this "delegate to the parent first except when in WAR" is the most sensible classloading configuration and definitely the one to start with and to try to stick to as much as possible.

Monday, August 15, 2011

Assorted facts about JBoss. Fact 1: StAX (Streaming API for XML) and the meaning of -711357515002332258.

Every time I have to do some serious work with JBoss I come across a situation that requires patching JBoss. HelloWorld kinds of applications tend to work, but as soon as things get complicated there is always something...

This time it is JBoss6 and StAX API. You see, there is <jboss>/lib/endorsed directory with some files in it. Normally if you start jboss with <jboss>/bin/run[.bat] the JVM is started with -Djava.endorsed.dirs=<jboss>/lib/endorsed

No problem, it is the desired and documented behavior if one wants to have newer versions of some APIs available in JDK. But <jboss>/lib/endorsed/stax-api.jar is a bit different. It is there for the sake of JDK 1.5. As of JDK 1.6 StAX is part of JDK itself. And it is not like JBoss packages a better or newer version of StAX. So if you run JBoss on JDK 1.6, do yourself a favor: delete <jboss>/lib/endorsed/stax-api.jar right now.

The solution for JDK 1.5 is not so simple because JDK 1.5 does not provide StAX. But first, what is the problem? This is it:
java.io.InvalidClassException: javax.xml.namespace.QName;
local class incompatible: stream classdesc serialVersionUID = -9120448754896609940,
local class serialVersionUID = -711357515002332258
<jboss>/lib/endorsed/stax-api.jar contains more than just StAX classes. It contains some old versions of classes that long ago present in JDK. And because the classes are in an endorsed jar, they override standard JDK classes.

If you look into JDK source code you will see that class javax.xml.namespace.QName goes to some lengths to initialize private static final long serialVersionUID with some known good value. The version packaged in <jboss>/lib/endorsed/stax-api.jar does not define field serialVersionUID leaving you at mercy of the JVM algorithm to calculate serial version UID. Which produces -711357515002332258 in this particular case.

Bad luck if you have a serialized instance of a class which has a non-transient field of type javax.xml.namespace.QName. Or if you have QName as a parameter in one of your remote interfaces.

So I fixed the problem by removing stax-api.jar since I am running under JDK 1.6 and went ahead.

The simplest solution for JDK 1.5 is probably deletion of everything that is not under javax.xml.stream from <jboss>/lib/endorsed/stax-api.jar. There are also stax-api jars around that include only javax.xml.stream.* classes.

But still ... One thing bothered me. This is quite an easy mistake to make especially if this file was added to the endorsed dir some time ago. I can see that it is present in JBoss5; I did not check earlier versions. But come on is it that difficult to review these things for every major release?

I can't be the first one to hit this problem. A bit of googling brought me here (JBPAPP-4223). OK, a bug is reported but I guess nobody is going to do a thing about it. After all it was reported on the 5th of May 2010, JBoss 6.0.0.Final was released half a year later, still with the problem.

And then I found this little gem. The beauty here is the recommendation of the JBoss EJB3 Lead Developer. Just read it. He seriously proposes to add the broken stax-api.jar to the client endorsed jar set. WTF?! JBoss EJB3 Lead Developer? No kidding?

Am I really surprised? Not at all.

Thursday, August 11, 2011

Mule, HTTP and transaction management

Mule has support for transactions, see here. So if the inbound and outbound endpoints are transactional, like JDBC or JMS, it is easy to make sure the messages are handled transactional.

It is not so easy if an endpoint is not transactional. For example we have a configuration with a jms:inbound-endpoint and an http:outbound-endpoint. A message is retrieved from the queue and sent via HTTP to some receiver. Of course the message must be removed from the queue only if it is successfully received (or handled) by the receiver.

The inbound-endpoint configuration is easy:
    <inbound>

<jms:inbound-endpoint queue="${queue_name}" connector-ref="jmsConnector">
<jms:transaction action="ALWAYS_BEGIN"/>
</jms:inbound-endpoint>
</inbound>

ALWAYS_BEGIN ensures that a new transaction is started and a message is received in this transaction.

This leaves the outbound-endpoint. Just saying
        <http:outbound-endpoint address="${http_address}"/>

is not enough because it automatically means action="NONE". Mule throws an exception complaining that the outbound endpoint cannot join the active transaction because it is configured with action="NONE". Fair enough, let's change this into
        <http:outbound-endpoint address="${http_address}">

<http:transaction action="JOIN_IF_POSSIBLE"/>
</http:outbound-endpoint>

But this does not work because "http:transaction" is not recognized as a valid element. Ooops. This is logical, HTTP is not transactional per definition. But we really need JMS to be transactional.

The solution?
        <http:outbound-endpoint address="${http_address}">

<jms:transaction action="JOIN_IF_POSSIBLE"/>
</http:outbound-endpoint>

Mule is happy with this and it does the right thing. If there is a problem connecting to the target or sending the message to it HTTP endpoint makes sure that the message gets "exception payload" set. This triggers Mule transaction support to rollback the active transaction.

This is not a generic solution, but it suits us: no messages are lost; the message is back in the queue and is redelivered later. The only problem with this approach is that the transaction can be rolled back after the message was successfully received by the HTTP receiver. This results in redelivery of the same message to the HTTP receiver which must be able to handle this.

But this is not a big deal in our case. It is so happens that most of the time the message ends up in a dispatcher that looks in its registry for subscribers. The first successful delivery of the message caused subscribers to unsubscribe so the dispatcher just silently drops the message.

In some other cases the message is just notification of some kind so nobody really cares if the same notification appears twice.

The only case when this might cause some trouble in our system is when such a message results in a creation of a BPEL process instance. Most of the time the newly created instance fails with "conflicting receive" error because the instance created after the first message delivery is still running and the process has some <onMessage> with a correlation set. But these cases are easily recognized by the administrators. And I must say if one is using BPEL then "conflicting receive" is the least of one's worry.

Tuesday, July 5, 2011

Fairy tale of developer's heaven

Ah maven! Promises of repeatable and portable builds... Fairy tales of developer's heaven...

Shall I tell one as well?

From time to time I do some things on a JEE project being developed by some other people. The resulting EAR file is quite dependent on some JEE container. Recently a decision was made to migrate the project to another JEE container. It is not a one-off migration effort: we need to be able to build the project for the original container and for the new one. I was asked to look into that.

One possibility to handle this is to have a separate branch for each container. Just thinking about all coming cross merges makes me cry.

Another possibility is to have a single branch and just package additional container specific deployment descriptors here and there. Nice and simple, perfectly JEE compliant ...

Except for one seemingly small detail. The project is using say version 1 of a particular 3rd party dependency. Unfortunately the project with this version can't be deployed into the newly targeted container. Fortunately there is already version 2 of the dependency, and the project built against this version can be deployed in the new container. Unfortunately it is precisely the other way around with version 2: the old container can't handle it.

And it is not that we can build the project against one of the versions and then just package differently: the versions are not binary compatible. There are also some minor source-code compatibility issues, but they can be relatively simply solved. Anyway, bottom line: if we build our project against one of the versions of the library it will not work with the other. We really need to compile our software against the correct version of the library and then package accordingly.

So far so good. The situation is probably quite common, and not very difficult to handle. Normally.

But the project is using maven, more specifically, maven 2.2.1. So far it worked pretty well for the project except for some of maven's WAR/EAR packaging "features". But for this new deployment target I hit a wall.

The end result I wanted to achieve: one checks out the source code, sets up the container specific environment, runs 'mvn install' and gets a set of properly versioned container specific artifacts, say, application-X.Y-container1.ear or application-X.Y-container2.ear. The "properly versioned" part is very important. This way we can refer to the correct versions of artifacts in our poms, we can properly release container specific versions of the project, etc.

The very first question was: how do we achieve that versioning scheme in maven? The 3rd party library is used in all ejb and almost all jar modules making them depend on the library. Web modules also depend on it (indirectly, via ejb/jar modules). The same is true for the ear module.

Why, it is easy I thought. I define a property, say, 'target.container', then put it in <artifactid> or <version> tag so the project's poms have <artifactid>usermanager-ejb-${target.container}</artifactid> or <version>0.1-${target.container}-SNAPSHOT</version> in their maven coordinates. Then I start maven with -Dtarget.container=container1 (or container2). This results in <artifactid>usermanager-ejb-container1</artifactid> or <artifactid>usermanager-ejb-container2</artifactid> (or version <version>0.1-container1-SNAPSHOT</version> or <version>0.1-container2-SNAPSHOT</version>) at build time. Problem solved.

Funny thing: it worked. Damn, I should have been more suspicious. I ended up trying both variants, and both worked when maven was executed from command line. That was actually the last thing that worked. Following hours made me really unhappy.

First I noticed that Eclipse (m2eclipse plugin) does not really like my new poms. It kept complaining that it could not find the project's poms and their dependencies. Executing 'maven install' from Eclipse produced a lot of warnings like "'artifactId' contains an expression but should be a constant." That prompted me to move ${target.container} from <artifactid> to <version>. And again, running maven from command line worked. Eclipse kept complaining.

Googling the message I came across a lot of posts related to the same issue. The message from these posts was clear: maven does not support it.

Strange, because maven documentation does not clearly spells it. For example, POM Reference does not say that artifactId or version must be constant. In fact, the very same POM Reference says here:

Maven properties are value placeholder, like properties in Ant. Their values are accessible anywhere within a POM by using the notation ${X}, where X is the property.


Yet people claim that it should not work, and if it works then it is a bug. For example, here or here.

And it looks like maven finally began enforcing this stupidity in version 3. Which is a pity. The funniest thing here is the reason why. Take for example MNG-4297:
Maven currently allows properties in the groupId, artifactId and version of a pom. This causes artifacts to be produced that require full inheritance and interpolation before they can be uniquely identified. It also poses potential problems if the properties are defined in settings, env or profiles where the consumer can't exactly identify the artifact after the fact.


I am just speechless. Between things like downloaded newer versions of plugins (wow, they fixed this one actually), disappeared artifacts from public repositories, rearranged and/or moved public repositories they finally nailed the real problem preventing maven users to have reproducible builds: property-based project coordinates. Strange, last time I looked maven still supports profiles and properties in general...

Anyway, it looks like the way to do what I want is classifiers. They are mentioned here:

The Maven provided solution for your situation is 'classifiers'.


and are really awesome described here (5.5.3. Platform Classifiers). These guys work for Sonatype, so they should know a thing or two about maven you would think, right? Just replace <classifier>win</classifier> with <classifier>container1</classifier> and <classifier>linux</classifier> with <classifier>container2</classifier>, and we are back in business.

Damn you, people who like to misinform others.

I went ahead and modified poms. Build the project from the command line produced some strange results, for example maven built modules 1-6 successfully and then failed building module 7 because of my mistake in the module's pom. I fixed the problem, ran 'mvn install' for module 7, it completed without failure. Then I ran 'mvn clean install' for the parent project, and it failed building module 5 because some classes from one of the dependencies were not found. Huh?

Finally after some more pom changes the build managed to produce an EAR which was successfully deployed in the old container. Then I cleaned up some poms, added some things to <dependencyManagement> here and there, and executed 'mvn clean install' again. I was not able to deploy the resulting EAR in the old container because of some missing classes. It turned out about 1/3 of jars were missing from EAR/lib this time. WTF?!

Running mvn dependency:tree and analyzing its result explained why: there were no dependencies under the dependencies with classifiers! Time to ask google again.

Apparently maven cannot handle transitive dependencies of a dependency with a classifier, see for example MNG-2759. The story is a bit more complicated because this works sometimes for some people. This worked at least once for me. But most of the time it does not work. And maven is not planning to fix it: MNG-2759 has status "Won't Fix".

Yeah, use classifiers if you need some quality headache. Thanks for advice, guys!

The only solution is to spell all dependencies explicitly everywhere I use a module with a classifier. Thanks, but no, thanks. I already have to do it too many times. <dependencyManagement>, <dependency>, WAR packaging exclusion, EAR packaging to make sure that what is excluded from WAR is packaged in EAR/lib.....

What can I say? Indeed, maven is really a "project ... comprehension tool".

And what I am going to do with all this mess? Nothing, really. I have dropped the requirement of having properly versioned artifacts. I have just removed all the classifiers. The profiles stay. So any time I build a project I get a version 0.1-SNAPSHOT which happens to be for one of the containers. Which one? It depends on the chosen profile. This all means more work during release, but frankly I do not care at the moment. Do you want to refer to the released version of one of the submodules in your pom file? You'd better be absolutely sure you know which version you use. Do you want to refer to a SNAPSHOT version?

Reproducible builds and maven? Do not make me laugh.