I came across the Spring story some time ago but did not have time to write about it then. I would probably spend time writing about it now but recently I had to refresh my knowledge of JBoss and CXF.
Besides Spring usage, JBoss CXF integration has more nice things to offer. They are more subtle but they definitely deserve to be mentioned.
Remember that little jbossws-cxf.xml? It has its own secrets.
First of all there are several locations where JBoss WS code looks for it. Do you know where exactly the file is packaged in jar/war/whatever? If you think the correct location is META-INF/ for jars and WEB-INF/ for wars, you are close but it is only part of the story. This is the location that the WS deployer checks for jbossws-cxf.xml at application startup. Note that JBoss does not use classloading to locate this file, it goes straight to the jar/war and checks if the file is present. If it is there it is processed together with some other JBoss CXF specific deployment descriptors that the deployer can find at this moment. If no META-INF/jbossws-cxf.xml or WEB-INF/jbossws-cxf.xml is found the deployer does not look at other deployment descriptors even if they are present. This is important because whatever JBoss manages to find at this moment is used for configuration of WS services and injection of WS client references. Well, may be.
Of other places where JBoss WS deployer looks the most important is META-INF/cxf/jbossws-cxf.xml. Pay attention to that cxf in the path. JBoss: consistent as ever; flexible as nothing ever before. It gives you possibility to place config files in at least two different places. There are of course notable differences. First one is already explained above: the deployer is loading config files only if it detects META-INF/jbossws-cxf.xml or WEB-INF/jbossws-cxf.xml. Then it loads that file and also META-INF/cxf/jbossws-cxf.xml if present. So if you have only META-INF/cxf/jbossws-cxf.xml, the deployer will not see at application startup.
Another difference is that uses classloading to load a single META-INF/cxf/jbossws-cxf.xml. This, of course, is a source of some amusement if you happen to have multiple jars with META-INF/cxf/jbossws-cxf.xml. JBoss has some jars with that file already, like server/<server_name>/deployers/jbossws.deployer/jbossws-cxf-client.jar. If you also have META-INF/cxf/jbossws-cxf.xml in your application then which file is loaded depends on the classloading configuration. I do not know how important things from jbossws-cxf-client.jar are but you definitely do not want to miss your configuration.
Location is covered; time to look at the moment when JBoss looks for the file. It does it not only during application startup, as described above. If you use WS API like javax.xml.ws.Service.create() JBoss will do it again. Basically it is the same story except that it never loads META-INF/jbossws-cxf.xml or WEB-INF/jbossws-cxf.xml. It just goes straight to all those other JBoss CXF specific deployment descriptors that it can find, including META-INF/cxf/jbossws-cxf.xml. This process might use a different classloader than the one used during deployment so the loaded configuration might differ significantly from the one loaded during application startup.
A nice finishing touch comes from Spring XML parsing code. Most likely it is somehow configured from JBoss but I did not care to find out where and how. Deployer triggers (META-INF/jbossws-cxf.xml or WEB-INF/jbossws-cxf.xml) are parsed with XSD validation on, all other files are parsed with validation off. It seems to be a minor difference unless you want the configuration from jbossws-cxf.xml applied to the WS objects you get back from Service.create() and Service.getPort().
Basically you can use <jaxws:client> to provide custom configuration on a per-client basis, the same way as you can use <jaxws:endpoint> to configure your endpoints. But there is great confusion around <jaxws:client>: it looks like it is ignored by JBoss or CXF. For example interceptors configured on a CXF bus are used properly but interceptors configured on <jaxws:client> are not.
The reason is that you need quite crazy identification string for your <jaxws:client>. Things that are perfectly OK for <jaxws:endpoint> won't work for <jaxws:client>. Why? Because it is JBoss of course!
Some JBoss documentation suggests you have to use <jaxws:client id="{your.service.namespace}YourPortName" >. This kind of ID is not valid according to Spring XML schema. If you put it in your META-INF/jbossws-cxf.xml or WEB-INF/jbossws-cxf.xml, the application startup will fail with XSD validation error. To be fair to JBoss it looks like this particular naming convention is coming from CXF and not from JBoss.
But it is still not all! <jaxws:client id="{your.service.namespace}YourPortName" > does not work. It does not work if you rely on @Resource or @WebServiceRef, or, at least, it did not work for me when I tried, but I did not try hard. It does not work for javax.xml.ws.Service.create(), and I needed it to work so I wasted most of my time on this use case.
Still other sources say that <jaxws:client id="{your.service.namespace}YourPortName" createdFromAPI="true"> is a way to go. It still does not work! It took me quite some time poking in CXF and Spring code under debugger to find out the version that worked for me: <jaxws:client id="{your.service.namespace}YourPortName.jaxws-client.proxyFactory">.
Basically it is CXF that ends up looking up a Spring bean named "{your.service.namespace}YourPortName.jaxws-client.proxyFactory" to get its configuration. The funniest thing is that both versions of configuration register a bean with this name. But for whatever reason when a bean is created with createdFromAPI="true", it is registered all right but it is not found later by CXF. And if it is created with ".jaxws-client.proxyFactory" suffix it is registered and successfully found by CXF.
I stopped looking further. I found enough to make my application work. But I still wonder: how could I miss it in the beginning? Nice, intuitive, easily discoverable configuration. Unforgivable.
Showing posts with label JBoss. Show all posts
Showing posts with label JBoss. Show all posts
Wednesday, September 26, 2012
Friday, September 7, 2012
Assorted facts about JBoss. Fact 6: JBoss and CXF: match made in heaven.
Bored? Want to learn something new? Or waste some time? Need quality headache?
My advice: look at web services and try to make something just a bit more complicated than "hello world" under JBoss. You will never forget it.
JBoss 6 uses CXF under the hood to support WS-related sections of EJB specification. Both products have their strong points but JBoss is definitely the leader in the "most creative WTF" contest.
JBoss supports declarative configuration of both web service implementation and web service client. All you need is to create a JBoss specific deployment descriptor, a file called jbossws-cxf.xml, and package it with your application. The nice touch here is that this deployment descriptor is Spring-based. This alone makes JBoss leading contester.
It is not that I have anything against Spring. Well, I actually have a lot to say about it, but it deserves a separate post.
No, really, just think about it: first you come up with a way to configure the server using XML, supporting hundreds of different schemas, all based on the same XML configuration parser library. And then you say "screw it, I fancy Spring here".
They did not go as far as packaging Spring with JBoss. Why? Who knows. Having said A they might just well have said B. But no, they use classloading to detect at runtime if Spring is present. Only if Spring is there JBoss goes ahead and reads jbossws-cxf.xml. Wow, say good bye to all hard work you put into creating that jbossws-cxf.xml - it is not used anyway. But you do not know that yet.
After some googling and digging you realize that you need Spring. Sigh. But you do need that configuration from jbossws-cxf.xml! Being "standard obeying" you bite the bullet package Spring with your application. (Being lazy you just drop Spring into server/<server_name>/lib. You save yourself a lot of time but miss a lot of fun.) Redeploy and ... your precious jbossws-cxf.xml is not loaded.
Things are looking up: you are not bored any more. You spend some time double checking your deployment and redeploying it. Nope, still not loaded. If you study jboss logs carefully you might spot this small message Spring not available, skipping check for user provided jbossws-cxf.xml / cxf.xml configuration files. If you know your way about JBoss jmx console you go and check your application's classloader and try to load some Spring classes via it. They are loaded just fine. WTF?
Remember that runtime classloading check I mentioned above? Turns out it runs very early during application deployment, before the classloaders for the application are set up. As a result the check is using the classloader of the WS deployer coming from server/<server_name>/deployers/jbossws.deployer. Surprise!
It is getting more and more interesting. You have to have Spring and you can't package it with your application. Right, but you need to make this application work. Forget about standards and keeping things where they belong. Spring to server/<server_name>/lib, JBoss restart, wow! Congratulations, you made it.
I leave the question of the proper place for Spring jars as an exercise. Instead let's look at more fun that JBoss-CXF integration might bring.
This is how I first got involved in this matter: I had an EJB application that used JMS. For reasons not important here it was decided that the application should use Apache ActiveMQ. No problem, I tested it locally under JBoss 6.1, it looked OK, and so the application was deployed in an integration environment, together with ActiveMQ resource adapter. So far so good. Later more applications were added to that environment. One of them failed to start. There were some classloading errors involving Spring classes. The application was a war that internally used Spring so Spring was packaged into WEB-INF/lib and the classloading was properly configured (WEB-INF/lib jars first). I was asked to look into the problem because there was another Spring in classpath: from ActiveMQ which is using Spring internally.
Of course removing ActiveMQ RA solved the problem for that application. Changing classloading rules of the application (to parent first) "solved" the problem as well.
Digging further I realized what has happened. JBoss classloader architecture is notoriously broken so the Spring classes from ActiveMQ leak into every application. When this failing application (with the original configuration WEB-INF/lib jars first) was starting JBoss WS deployer noticed some WS annotations and went ahead with whatever it supposed to do, including looking for Spring and jbossws-cxf.xml. Spring was there leaked from ActiveMQ. (Remember, the classloader at this moment is the one from jbossws.deployer.) The application did not have jbossws-cxf.xml but the harm was done: some instances of Spring classes were created along the way and remained referenced from CXF objects.
The application startup continued and JBoss finally created the application specific classloader and the rest of the startup code was executed using this classloader. Along the way CXF was involved again and it noticed those Spring instances created before so it went ahead with more Spring dance. But this time all the Spring classes were coming from WEB-INF/lib with predictable result: ClassCastException.
Of course changing classloading configuration would fix the problem in this case. Spring classes would always come from ActiveMQ keeping CXF happy. Well, until some other application, RA, whatever, that has Spring packaged is deployed in the same server. And do not forget that it can be a different version of Spring jars. Care to resolve this mess?
Priceless! Never attribute to malice that which ... I am not sure. Sometimes I think somebody at RedHat came up with this brilliant business idea of how to make more money out of JBoss support ...
My advice: look at web services and try to make something just a bit more complicated than "hello world" under JBoss. You will never forget it.
JBoss 6 uses CXF under the hood to support WS-related sections of EJB specification. Both products have their strong points but JBoss is definitely the leader in the "most creative WTF" contest.
JBoss supports declarative configuration of both web service implementation and web service client. All you need is to create a JBoss specific deployment descriptor, a file called jbossws-cxf.xml, and package it with your application. The nice touch here is that this deployment descriptor is Spring-based. This alone makes JBoss leading contester.
It is not that I have anything against Spring. Well, I actually have a lot to say about it, but it deserves a separate post.
No, really, just think about it: first you come up with a way to configure the server using XML, supporting hundreds of different schemas, all based on the same XML configuration parser library. And then you say "screw it, I fancy Spring here".
They did not go as far as packaging Spring with JBoss. Why? Who knows. Having said A they might just well have said B. But no, they use classloading to detect at runtime if Spring is present. Only if Spring is there JBoss goes ahead and reads jbossws-cxf.xml. Wow, say good bye to all hard work you put into creating that jbossws-cxf.xml - it is not used anyway. But you do not know that yet.
After some googling and digging you realize that you need Spring. Sigh. But you do need that configuration from jbossws-cxf.xml! Being "standard obeying" you bite the bullet package Spring with your application. (Being lazy you just drop Spring into server/<server_name>/lib. You save yourself a lot of time but miss a lot of fun.) Redeploy and ... your precious jbossws-cxf.xml is not loaded.
Things are looking up: you are not bored any more. You spend some time double checking your deployment and redeploying it. Nope, still not loaded. If you study jboss logs carefully you might spot this small message Spring not available, skipping check for user provided jbossws-cxf.xml / cxf.xml configuration files. If you know your way about JBoss jmx console you go and check your application's classloader and try to load some Spring classes via it. They are loaded just fine. WTF?
Remember that runtime classloading check I mentioned above? Turns out it runs very early during application deployment, before the classloaders for the application are set up. As a result the check is using the classloader of the WS deployer coming from server/<server_name>/deployers/jbossws.deployer. Surprise!
It is getting more and more interesting. You have to have Spring and you can't package it with your application. Right, but you need to make this application work. Forget about standards and keeping things where they belong. Spring to server/<server_name>/lib, JBoss restart, wow! Congratulations, you made it.
I leave the question of the proper place for Spring jars as an exercise. Instead let's look at more fun that JBoss-CXF integration might bring.
This is how I first got involved in this matter: I had an EJB application that used JMS. For reasons not important here it was decided that the application should use Apache ActiveMQ. No problem, I tested it locally under JBoss 6.1, it looked OK, and so the application was deployed in an integration environment, together with ActiveMQ resource adapter. So far so good. Later more applications were added to that environment. One of them failed to start. There were some classloading errors involving Spring classes. The application was a war that internally used Spring so Spring was packaged into WEB-INF/lib and the classloading was properly configured (WEB-INF/lib jars first). I was asked to look into the problem because there was another Spring in classpath: from ActiveMQ which is using Spring internally.
Of course removing ActiveMQ RA solved the problem for that application. Changing classloading rules of the application (to parent first) "solved" the problem as well.
Digging further I realized what has happened. JBoss classloader architecture is notoriously broken so the Spring classes from ActiveMQ leak into every application. When this failing application (with the original configuration WEB-INF/lib jars first) was starting JBoss WS deployer noticed some WS annotations and went ahead with whatever it supposed to do, including looking for Spring and jbossws-cxf.xml. Spring was there leaked from ActiveMQ. (Remember, the classloader at this moment is the one from jbossws.deployer.) The application did not have jbossws-cxf.xml but the harm was done: some instances of Spring classes were created along the way and remained referenced from CXF objects.
The application startup continued and JBoss finally created the application specific classloader and the rest of the startup code was executed using this classloader. Along the way CXF was involved again and it noticed those Spring instances created before so it went ahead with more Spring dance. But this time all the Spring classes were coming from WEB-INF/lib with predictable result: ClassCastException.
Of course changing classloading configuration would fix the problem in this case. Spring classes would always come from ActiveMQ keeping CXF happy. Well, until some other application, RA, whatever, that has Spring packaged is deployed in the same server. And do not forget that it can be a different version of Spring jars. Care to resolve this mess?
Priceless! Never attribute to malice that which ... I am not sure. Sometimes I think somebody at RedHat came up with this brilliant business idea of how to make more money out of JBoss support ...
Friday, August 24, 2012
Assorted facts about JBoss. Fact 5: you want control over transaction in @Singleton lifecycle methods? Tough luck.
First, some theory, namely from EJB 3.1 specification (emphasis mine):
Of course it all started with something much more complex. After a seemingly minor change our application started to give problems during JBoss shutdown. JBoss hanged for some time and then started to spew "transaction rolled back" exceptions.
Finding the change that had caused the problem was easy. Why was it a problem? Too much software is too clever for its own good nowadays. This time it was a piece of code (also from JBoss - ha-ha) that managed to hook itself into the ongoing container transaction. The "minor" change caused this software to try ending the ongoing transaction, which it had no rights to do.
Fixing the problem seemed easy: we did not really need the @PreDestroy method to be transactional so adding appropriate @TransactionAttribute to it looked like a solution. Of course it did not work otherwise I would not write this post.
Investigating the problem led to this simple test class:
Deploying it under JBoss we use (6.1.0.Final) and then undeploying it results in the following message in the server console:
Looks perfect, JBoss dutifully runs our @PreDestroy in a transaction. Let's add @TransactionAttribute(TransactionAttributeType.NOT_SUPPORTED) to the method and repeat the test. Result:
Barring ID difference, the output is exactly the same! Next step: move the annotation to the class itself. Finally I have got what I was expecting:
Apparently JBoss ignores @TransactionAttribute on a @PreDestroy method (and on a @PostConstruct - I verified that).
This behavior is also very clear to see from the stack trace. In case of annotation on the method or no annotation at all:
Annotation on the class:
Can happen. Who cares that this is clearly specified in the EJB 3.1 spec. And it does not matter that JBoss developers knew about this particular nuance of the EJB 3.1 spec.
There is a solution after all. Except for the case that we actually have: we need a transaction in @PostConstruct and at the same time we need "no transaction" in @PreDestroy. Oops. Of course nothing that can't be fixed but it still makes me think how many of such "small things" are around.
For some time already I try all my test things under JBoss 7 as well, using the latest and greatest JBoss 7.1.1.Final. After all, JBoss 6 is the thing from the past, or so RedHat says.
Can JBoss 7 handle this simple test case? Nope. Even the code that worked under JBoss 6 with @TransactionAttribute on the bean class does not work as expected under JBoss 7. It looks like there is no way to control transactions on @Singleton lifecycle methods in JBoss 7. There is no way: I was quite surprised by this so I checked the sources. There was some code that looked at annotations but it was replaced by hardcoded requiresNew somewhere during 7.0 beta. Way to go, guys. Who needs that EJB spec compliance anyway?
Section "4.3.4 Session Bean Life cycle Callback Interceptor Methods"The same is applicable for PostConstruct as well. And then more:
The following lifecycle event callbacks are supported for session beans. Lifecycle callback interceptor methods may be defined directly on the bean class
...
The PreDestroy lifecycle callback interceptor methods for singleton beans execute in a transaction context determined by the bean's transaction management type and any applicable transaction attribute.
Section "4.8.3 Transaction Semantics of Initialization and Destruction"Simple enough, is it not? But such "simple" things not working correctly can cost a lot of effort to find.
PostConstruct and PreDestroy methods of Singletons with container-managed transactions are transactional. From the bean developer's view there is no client of a PostConstruct or PreDestroy method.
A PostConstruct or PreDestroy method of a Singleton with container-managed transactions has transaction attribute REQUIRED, REQUIRES_NEW, or NOT_SUPPORTED (Required , RequiresNew, or NotSupported if the deployment descriptor is used to specify the transaction attribute).
Of course it all started with something much more complex. After a seemingly minor change our application started to give problems during JBoss shutdown. JBoss hanged for some time and then started to spew "transaction rolled back" exceptions.
Finding the change that had caused the problem was easy. Why was it a problem? Too much software is too clever for its own good nowadays. This time it was a piece of code (also from JBoss - ha-ha) that managed to hook itself into the ongoing container transaction. The "minor" change caused this software to try ending the ongoing transaction, which it had no rights to do.
Fixing the problem seemed easy: we did not really need the @PreDestroy method to be transactional so adding appropriate @TransactionAttribute to it looked like a solution. Of course it did not work otherwise I would not write this post.
Investigating the problem led to this simple test class:
package p1;
import javax.annotation.PostConstruct;
import javax.annotation.PreDestroy;
import javax.ejb.*;
import javax.naming.InitialContext;
import javax.transaction.TransactionManager;
@Singleton
@Startup
public class TeBean {
@PostConstruct
public void startIt() throws Exception {
System.err.println("TeBean.startIt");
}
@PreDestroy
public void stopIt() throws Exception {
TransactionManager tm = (TransactionManager)new InitialContext().lookup("java:/TransactionManager");
if (tm != null) {
System.err.println("TeBean.stopIt, transaction: [" + tm.getTransaction() + "] ");
} else {
System.err.println("TeBean.stopIt, no transaction manager");
}
}
}Deploying it under JBoss we use (6.1.0.Final) and then undeploying it results in the following message in the server console:
TeBean.stopIt, transaction: [TransactionImple < ac, BasicAction: 0:ffffc0a8016f:... status: ActionStatus.RUNNING >]
Looks perfect, JBoss dutifully runs our @PreDestroy in a transaction. Let's add @TransactionAttribute(TransactionAttributeType.NOT_SUPPORTED) to the method and repeat the test. Result:
TeBean.stopIt, transaction: [TransactionImple < ac, BasicAction: 0:ffffc0a8016f:... status: ActionStatus.RUNNING >]
Barring ID difference, the output is exactly the same! Next step: move the annotation to the class itself. Finally I have got what I was expecting:
TeBean.stopIt, transaction: [null]
Apparently JBoss ignores @TransactionAttribute on a @PreDestroy method (and on a @PostConstruct - I verified that).
This behavior is also very clear to see from the stack trace. In case of annotation on the method or no annotation at all:
TeBean.stopIt() line: 24 ... CMTTxInterceptor.invokeInOurTx(TransactionalInvocationContext, TransactionManager) line: 247 CMTTxInterceptor.requiresNew(TransactionalInvocationContext) line: 392 CMTTxInterceptor.invoke(TransactionalInvocationContext) line: 211
Annotation on the class:
TeBean.stopIt() line: 24 ... CMTTxInterceptor.invokeInNoTx(TransactionalInvocationContext) line: 234 CMTTxInterceptor.notSupported(TransactionalInvocationContext) line: 329 CMTTxInterceptor.invoke(TransactionalInvocationContext) line: 207
Can happen. Who cares that this is clearly specified in the EJB 3.1 spec. And it does not matter that JBoss developers knew about this particular nuance of the EJB 3.1 spec.
There is a solution after all. Except for the case that we actually have: we need a transaction in @PostConstruct and at the same time we need "no transaction" in @PreDestroy. Oops. Of course nothing that can't be fixed but it still makes me think how many of such "small things" are around.
For some time already I try all my test things under JBoss 7 as well, using the latest and greatest JBoss 7.1.1.Final. After all, JBoss 6 is the thing from the past, or so RedHat says.
Can JBoss 7 handle this simple test case? Nope. Even the code that worked under JBoss 6 with @TransactionAttribute on the bean class does not work as expected under JBoss 7. It looks like there is no way to control transactions on @Singleton lifecycle methods in JBoss 7. There is no way: I was quite surprised by this so I checked the sources. There was some code that looked at annotations but it was replaced by hardcoded requiresNew somewhere during 7.0 beta. Way to go, guys. Who needs that EJB spec compliance anyway?
Tuesday, July 17, 2012
How good intentions can grind SSL to a halt
We were running a load test of our application installed at the customer. The set up was quite complicated: several nodes running the application at the customer site and a single test server outside of the customer network struggling to send a lot of messages to the customer. The servers running there were in turn sending separate ack messages to our test server.
It also involved a firewall at the customer site, HTTPS with client authentication, custom key- and trust stores, XML digital signatures, Oracle database and Oracle AQ queues and more. And JBoss as the application server.
The setup was working all right but the customer has very strict performance requirements which we had to meet. Hence the tests.
After solving couple of obvious and not so obvious problems we reached quite a good throughput. Not what we wanted but reasonable. The problem was that when we tried to increase the load the hell broke loose.
The log files contained a large number of "send failed" messages with HTTP status code 403 and some HTML page clearly coming from the customer's firewall. The HTML was a generic "you are not allowed in" error message. The customer also reported seeing a log of "read timeout" messages in the firewall's logs.
The firewall was not really a dummy thing in our setup. It also handled SSL at the customer side. Our test server sent HTTPS messages to the firewall which did authentication magic and then passed the request to one of the nodes using HTTP. On the way back the application sent the ack messages as HTTP requests to the firewall which then initiated HTTPS to our test server.
403 errors happened both on our test server and on the servers at the customer, but the pattern was different. Under a moderate load the errors were happening at the customer side, not many, comparing to the number of messages. And first errors came quite quickly. There were no errors on the test server.
Increasing the load did not change the situation until we reached some threshold. The situation at the customer side did not change, but we immediately started to see 403 messages on our test server. Much, much more than at the customer side.
How such a problem can be analyzed? There are probably several ways but I describe what I did.
The best way is of course to patch wss4j. I do not have a problem with patching but unfortunately it is not a solution in our case. In many cases we can't control the environment. Quite often our application is installed into a "standard" jboss environment of a client. Normally our application is the only application in this environment but we still allowed doing only some configuration changes like JAVA_OPTS and such.
Another possibility is to make sure bouncycastle is loaded explicitly for example via jre/lib/security/java.security. But again, it is not always allowed. In addition it just does not feel right: that jdk is not used only by our application and bouncycastle is definitely not present by default in classpath.
One can repackage bouncycastle to remove class org.bouncycastle.jce.provider.BouncyCastleProvider. Or try and mess with classloading preventing this class to be loaded. But these solutions look even less attractive.
SecurityManager can help as well because adding a provider is hooked into it, but using a SecurityManager brings its own share of nuances. For starters it requires understanding SecurityManager. Good luck with it :-)
WSSConfig class has a possibility to disable this stupid functionality so going this way can also solve the problem. The only challenge here is to do it soon enough before WSSConfig manages to screw up things. The best way is building a separate jar with some JBoss deployment descriptor so that the code is triggered during JBoss startup.
To continue testing I have added some code to our application that does two things. First it disables WSSConfig's automatic provider loading. And then it checks if bouncycastle is already loaded and which DH keypair generator is used by default. If I get bouncycastle's keypair generator I just move bouncycastle to the end of the list. Yes I know I am changing the environment I have no right to touch :-) but we need to continue testing. Later I probably just move this code into a separate JBoss specific jar.
And for the authors of this wonderful library, wss4j ... Guys, there is still room for improvement. Maybe my hard drive is not partitioned optimally? Or how about patching KDE2 under FreeBSD? There are so many unsolved problems around. Do not let common sense stop you.
It also involved a firewall at the customer site, HTTPS with client authentication, custom key- and trust stores, XML digital signatures, Oracle database and Oracle AQ queues and more. And JBoss as the application server.
The setup was working all right but the customer has very strict performance requirements which we had to meet. Hence the tests.
After solving couple of obvious and not so obvious problems we reached quite a good throughput. Not what we wanted but reasonable. The problem was that when we tried to increase the load the hell broke loose.
The log files contained a large number of "send failed" messages with HTTP status code 403 and some HTML page clearly coming from the customer's firewall. The HTML was a generic "you are not allowed in" error message. The customer also reported seeing a log of "read timeout" messages in the firewall's logs.
The firewall was not really a dummy thing in our setup. It also handled SSL at the customer side. Our test server sent HTTPS messages to the firewall which did authentication magic and then passed the request to one of the nodes using HTTP. On the way back the application sent the ack messages as HTTP requests to the firewall which then initiated HTTPS to our test server.
403 errors happened both on our test server and on the servers at the customer, but the pattern was different. Under a moderate load the errors were happening at the customer side, not many, comparing to the number of messages. And first errors came quite quickly. There were no errors on the test server.
Increasing the load did not change the situation until we reached some threshold. The situation at the customer side did not change, but we immediately started to see 403 messages on our test server. Much, much more than at the customer side.
How such a problem can be analyzed? There are probably several ways but I describe what I did.
- Switch on SSL logging on our test server: -Djavax.net.debug=ssl and rerun the tests.
- Analyze the logs. The logs were already quite large and SSL debug setting added a lot more info. And the test server was both sending and receiving HTTPS messages. So analyzing the logs took some time. But eventually I started to see a pattern.
<timestamp> INFO [STDOUT] (<thread name>) *** ClientHello, Unknown-3.3 <timestamp> INFO [STDOUT] (<thread name>) *** ... <timestamp + [10-20-30sec]> INFO [STDOUT] (<thread name>) INFO %% Created: [Session-101, TLS_DHE_RSA_WITH_AES_128_CBC_SHA] <timestamp + [20-30sec]> INFO [STDOUT] (<thread name>) *** ServerHello, TLSv1 ... <timestamp + [20-30sec]> INFO [STDOUT] (<thread name>) *** ServerHelloDone <timestamp + [20-30sec]> INFO [STDOUT] (<thread name>) WRITE: TLSv1 Alert, length = 2 <timestamp + [20-30sec]> INFO [STDOUT] (<thread name>) Exception sending alert: java.net.SocketException: Broken pipe
So the server thread receives a ClientHello SSL message and then does something for dozens of seconds before trying to send ServerHello message. And then is it too late: the sending side has closed the connection.
- When the same thread was again involved, the log was different:
<timestamp> INFO [STDOUT] (<thread name>) *** ClientHello, Unknown-3.3 <timestamp> INFO [STDOUT] (<thread name>) *** <timestamp> INFO [STDOUT] (<thread name>) %% Resuming [Session-78, TLS_DHE_RSA_WITH_AES_128_CBC_SHA] <timestamp> INFO [STDOUT] (<thread name>) *** ServerHello, TLSv1 … <timestamp + [200-300ms]> INFO [STDOUT] (<thread name>) *** <timestamp + [200-300ms]> INFO [STDOUT] (<thread name>) *** READ: TLSv1 Application Data, length = 208 ...
The delay was happening only if a new SSL session was created. It did not happen for all the created sessions though. In some cases there was some delay between ClientHello and ServerHello but not that large: well under 10 seconds.
- Googling did not help. The most messages describe "reverse DNS lookup" problem which I believed had nothing to do with our problem. Just in case I tried to verify this with a simple test application which did not experienced any delays doing reverse DNS lookup, both for known and unknown addresses.
- Everything I have seen so far could match 403s in the log at the customer side. The problem happened only if a new SSL session was created which did not happen that often. This explained why there were not that many 403s. And the reason for the errors starting to appear almost immediately was also clear: more SSL sessions had to be created to cope with more connection attempts from the customer to our test server.
- The question remained: what was causing the delays. Since I am lazy I did not want waste my time on running some network traffic analysers. Good move in hindsight.
Simple HTTPS tests in my development environment were OK. Reproducing the complete setup locally was out of the question. And debugging on the server ... well, I tried it, but it was extremely slow most of the time. SSH tunnel, VM server, whatever.
Instead I have started the tests again and fired jstack -l <jboss_pid> in the loop redirecting the output to individual files.
As soon I noticed 'broken pipe' messages in the log I stopped the test, found the thread name which logged 'broken pipe' and looked at the output of jstack to see what the thread was doing between outputting ClientHello and ServerHello. Not much, apparently:
"<thread-name>" daemon prio=10 tid=0x00002aab10d17000 nid=0x354b waiting for monitor entry [0x0000000053617000] java.lang.Thread.State: BLOCKED (on object monitor) at java.security.SecureRandom.nextBytes(SecureRandom.java:433) - waiting to lock <0x00002aaacfc89bf0> (a java.security.SecureRandom) at java.math.BigInteger.randomBits(BigInteger.java:479) ... at org.bouncycastle.crypto.generators.DHParametersHelper.generateSafePrimes(Unknown Source) at org.bouncycastle.crypto.generators.DHParametersGenerator.generateParameters(Unknown Source) at org.bouncycastle.jce.provider.JDKKeyPairGenerator$DH.generateKeyPair(Unknown Source) at com.sun.net.ssl.internal.ssl.DHCrypt.<init>(DHCrypt.java:76) ... at com.sun.net.ssl.internal.ssl.ServerHandshaker.clientHello(ServerHandshaker.java:425)
This "waiting to lock <0x00002aaacfc89bf0>" was in almost every jstack output, and then multiple times. There was of course one thread holding the lock, and the thread was also processing ClientHello and generating DH (Diffie-Hellman) key pair.
- OK, I found the bottleneck but what's next? One thing that bothered me was that bouncycastle in the stack trace, but first I concentrated on the BigInteger generation. Unfortunately, because I lost some time on that, on reading about /dev/random, /dev/urandom, and various post about the default java's SecureRandom being not that fast. But trying to switch to something else involved quite some work.
- I decided to look at bouncycastle. As it happened the application had bouncycastle packaged because it used some of the classes but we never needed it to be a security provider. But the fact that is was there in the stack trace clearly proved that it was installed as a security provider. Fortunately the tests we were doing did not use the functionality that relied on bouncycastle so I just deleted the jars and executed the tests again.
I actually ran the tests several times, with and without bouncycastle. Every run with bouncycastle had some 'broken pipe' messages in the log. Every run without it had none. And there were no delays between ClientHello and ServerHello messages.
- Well, is bouncycastle that slow? I was not sure but I doubted. So more googling, looking at the sources of bouncycastle and the cryptoproviders that come with JDK provided the explanation.
When the SSL server code needs to generate a "Diffie-Hellman" key pair for a new session, it knows only the required key strength. It asks java for a key pair generator and uses it to generate a key pair of the required strength. To generate the key pair some DH parameters (this includes large random prime numbers) are needed. A newly created bouncycastle key pair generator generates parameters first time it is used. The SSL code never reuses key pair generators.
Result: bouncycastle has to generate large random prime numbers for each new key pair. The default JDK DH code generates DH parameters only once and then caches them so every newly created key pair generator just reuses what is there!
Interestingly the latest version of bouncycastle (1.47) has added some caching but is it per thread and if I am not mistaken DH parameters have to be cached explicitly.
- I verified that my findings were correct with a small test application that generated a DH key pair using a default crypto provider and bouncycastle. 4 threads doing it in parallel with the default provider took less than 100 ms and with bouncycastle more than a minute.
- OK, the delays are explained. But why bouncycastle ended up being registered as a security provider? For my test application I had to explicitly add it with Security.addProvider(). And even then it was not used if I just asked for a DH keypair generator, it was only used when I explicitly asked for a DH keypair generator from bouncycastle.
And it is not mentioned anywhere in JDK/JRE or JBoss startup or deploy files. It means that there is somewhere some piece of code that not only loads bouncycastle provider but also registers it before at least some of the JDK's default providers.
Another round of tests, this time with -Djava.security.debug=provider. This produces enough information to understand when a provider is loaded. The log output clearly shows that bouncycastle is not there during startup of JBoss or after the startup completed. But almost immediately after I started to send test data some output about bouncycastle was added to the log.
Unfortunately java.security.debug does not help with the most important question: what component/jar/whatever is loading a provider.
- Last step: I modified BouncyCastleProvider so that it now prints a stack trace to the log. Another test run and we have the winner:
java.lang.Exception: XXYYZZ at org.bouncycastle.jce.provider.BouncyCastleProvider.<init>(BouncyCastleProvider.java:78) at sun.reflect.xxx ... at java.lang.Class.newInstance(Class.java:308) at org.apache.ws.security.WSSConfig.loadProvider(WSSConfig.java:569) ... at org.apache.ws.security.WSSConfig.<init>(WSSConfig.java:304) ... at org.apache.ws.security.message.WSSecTimestamp.<init>This class comes from wss4j. And what a beauty it is! You can find the full source code on the internet, for example here.
The important parts are:
/** * a static boolean flag that determines whether default JCE providers * should be added at the time of construction. * * These providers, and the order in which they are added, can interfere * with some JVMs (such as IBMs). */ private static boolean addJceProviders = true; /** * Set the value of the internal addJceProviders flag. This flag * turns on (or off) automatic registration of known JCE providers * that provide necessary cryptographic algorithms for use with WSS4J. * By default, this flag is true, for backwards compatibility. You may * wish (or need) to initialize the JCE manually, e.g., in some JVMs. */ public static void setAddJceProviders(boolean value) { addJceProviders = value; } private synchronized void staticInit() { ... if (addJceProviders) { addJceProvider("BC", "org.bouncycastle.jce.provider.BouncyCastleProvider"); } ... } ... private boolean loadProvider(String id, String className) { ... // Install the provider after the SUN provider (see WSS-99) // Otherwise fall back to the old behaviour of inserting // the provider in position 2. For AIX, install it after // the IBMJCE provider. // int ret = 0; for (int i = 0; i < provs.length; i++) { if ("SUN".equals(provs[i].getName()) || "IBMJCE".equals(provs[i].getName())) { ret = java.security.Security.insertProviderAt( (java.security.Provider) c.newInstance(), i + 2); break; } } if (ret == 0) { ret = java.security.Security.insertProviderAt( (java.security.Provider) c.newInstance(), 2); } ... }
Wow! Not only these ... alternatively thinking ... individuals mess the environment they have no business to touch, they do it by default so if I do not want it I have to opt-out. They also knew that whatever they were doing can cause problems. They were at least once bitten by this code (WSS-99). But the code is still there. Some people just never learn. Unfortunately they lay rakes and let other people step on them.
And the reason? It is there, in WSS-99: so that they can get to the strong encryption algorithms on some JDKs. Road to hell is paved with good intentions.
Newsflash, guys: whatever you are doing is wrong. You have no business altering the runtime environment like that. Your jar is just a small piece of big pile of code running on a server. And the problem you just so creatively "solved" could have been solved in a much less obtrusive way, and only for those environments where the problem really existed.
But no, "we know better" kicks in again.
The best way is of course to patch wss4j. I do not have a problem with patching but unfortunately it is not a solution in our case. In many cases we can't control the environment. Quite often our application is installed into a "standard" jboss environment of a client. Normally our application is the only application in this environment but we still allowed doing only some configuration changes like JAVA_OPTS and such.
Another possibility is to make sure bouncycastle is loaded explicitly for example via jre/lib/security/java.security. But again, it is not always allowed. In addition it just does not feel right: that jdk is not used only by our application and bouncycastle is definitely not present by default in classpath.
One can repackage bouncycastle to remove class org.bouncycastle.jce.provider.BouncyCastleProvider. Or try and mess with classloading preventing this class to be loaded. But these solutions look even less attractive.
SecurityManager can help as well because adding a provider is hooked into it, but using a SecurityManager brings its own share of nuances. For starters it requires understanding SecurityManager. Good luck with it :-)
WSSConfig class has a possibility to disable this stupid functionality so going this way can also solve the problem. The only challenge here is to do it soon enough before WSSConfig manages to screw up things. The best way is building a separate jar with some JBoss deployment descriptor so that the code is triggered during JBoss startup.
To continue testing I have added some code to our application that does two things. First it disables WSSConfig's automatic provider loading. And then it checks if bouncycastle is already loaded and which DH keypair generator is used by default. If I get bouncycastle's keypair generator I just move bouncycastle to the end of the list. Yes I know I am changing the environment I have no right to touch :-) but we need to continue testing. Later I probably just move this code into a separate JBoss specific jar.
And for the authors of this wonderful library, wss4j ... Guys, there is still room for improvement. Maybe my hard drive is not partitioned optimally? Or how about patching KDE2 under FreeBSD? There are so many unsolved problems around. Do not let common sense stop you.
Thursday, December 1, 2011
Assorted facts about JBoss. Fact 4: per-application logging is broken
You came here to read about setting up the per-application logging in JBoss 6? Congratulations, this is the right place to be. I have posted some info on this subject before. But if you have not read those posts no need to hurry. And if you have read them and followed the advice then forget it and undo the changes.
The per-application logging in JBoss 6 is broken beyond any possibility of repair. Even more, activating per-application logging makes the situation much worse.
Why the hell?! Need to scratch some itch? Look at the bug database, there is so much to do. "No, it is not for us, let's invent something new." And release this piece of ... software, half baked, and forget about any documentation.
So many words unspoken! Or rather unwritten; spoken they were, and a lot.
Back to the topic: why does it not work? To understand it you need first to understand how it really works.
The per-application logging configuration is bound to a classloader that loads jboss-logging.xml file with <define-context> element. When some component (your application code, some jar that come with JBoss, does not matter) invokes getLogger() the execution ends up in JBoss LogManager class. If the requested logger does not exist it has to be created. If the per-application logging is activated some helper class (ClassLoaderLogContextSelector) traverses the invocation stack starting from the most recent entry. For each entry (class) in the invocation stack the check is done whether the entry's classloader has a bound logging configuration. If such a configuration exists it is used and the traversal is stopped. If no classloader-bound logging configuration is found after the traversal the default one (coming from (deploy/jboss-logging.xml) is used.
For example, if your application with a custom jboss-logging.xml calls getLogger() then your class is very close to the top of the invocation stack:
It works even when getLogger() is used by code in some jar packaged with JBoss when your application uses that code. The invocation stack is longer, the traversal takes more time, but this is the only difference:
A lot actually:
Nicely implemented feature, isn't it?
You might be tempted to package more 3rd party jars in your application and play some classloading tricks to make sure that the classes are loaded from the application-packaged jars and not from JBoss-provided jars. Don't!
The question remains: is it actually possible to have the application-specific logging in JBoss 6?
Of course! Scrum solved that problem long time ago: a team decides what they want to have done and as they progress they can redefine what "done" means. Pretty neat and useful. You can do the same here: you can define what "application-specific" means in your case and then implement it.
Jokes aside there is not much you can actually do. The simplest and most sane solution is to forget about all that JBoss woodoo with the application-specific logging. Rollback the workaround for bug JBAS-9407. Use the default logging configuration in deploy/jboss-logging.xml. You can direct the output from your classes to a separate file. All the logging from the shared classes still goes to server.log by default. Directing the output from the shared classes to your application's log file is a bad thing to do: imagine if every application tries to do this. Including thread names in the logging output helps matching the records from the default JBoss log (server.log) back to your application if necessary.
JBoss, you never stops to amuse me!
The per-application logging in JBoss 6 is broken beyond any possibility of repair. Even more, activating per-application logging makes the situation much worse.
Why the hell?! Need to scratch some itch? Look at the bug database, there is so much to do. "No, it is not for us, let's invent something new." And release this piece of ... software, half baked, and forget about any documentation.
So many words unspoken! Or rather unwritten; spoken they were, and a lot.
Back to the topic: why does it not work? To understand it you need first to understand how it really works.
The per-application logging configuration is bound to a classloader that loads jboss-logging.xml file with <define-context> element. When some component (your application code, some jar that come with JBoss, does not matter) invokes getLogger() the execution ends up in JBoss LogManager class. If the requested logger does not exist it has to be created. If the per-application logging is activated some helper class (ClassLoaderLogContextSelector) traverses the invocation stack starting from the most recent entry. For each entry (class) in the invocation stack the check is done whether the entry's classloader has a bound logging configuration. If such a configuration exists it is used and the traversal is stopped. If no classloader-bound logging configuration is found after the traversal the default one (coming from (deploy/jboss-logging.xml) is used.
For example, if your application with a custom jboss-logging.xml calls getLogger() then your class is very close to the top of the invocation stack:
Some JBoss logging codeThe traversal algorithm starts with Some JBoss logging codeand goes down until it finds <your class>.getLogger(). The application has a per-application logging which is bound to the application's classloader, the very same classloader that has loaded <your class>. Bingo, the logger the application code gets back from JBoss will use the application's custom configuration.
Some more JBoss logging code
<your class>.getLogger()
Some other code from the application
Some JBoss EJB/servlet/you name it invocation code, a lot of it actually
Thread.run()
It works even when getLogger() is used by code in some jar packaged with JBoss when your application uses that code. The invocation stack is longer, the traversal takes more time, but this is the only difference:
Some JBoss logging codeSo what is wrong with this?
Some more JBoss logging code
<library class>.getLogger()
Some other library code, can be a lot
Some code from the application calling the library
Some other code from the application
Some JBoss EJB/servlet/you name it invocation code, a lot of it actually
Thread.run()
A lot actually:
- What a performance hog this is! Worst of all the code that does not use the per-application logging suffers the most because all the entries in the invocation stack must be checked before JBoss decides to use the default logging configuration. And stack traces under JBoss are known to be looooong. Like hundreds of entries long. To be fair JBoss warns about this problem in deployers/jboss-logging.deployer/META-INF/logmanager-jboss-beans.xml:
<!--
Of course being JBoss code it does not actually works this way. Bug JBAS-9407 strikes back: the proposed workaround activates this stack traversal algorithm even if no component is using the per-application logging. My patch attached to this bug fixes this and makes sure the stack scanning is activated only if a component with the per-application logging configuration is deployed. But being activated the traversal code is always executed when a logger is created, regardless what component/module asks for a logger.
~ These two beans define the per-classloader log context selector which allows per-deployment logging. Since
~ enabling this feature may have a performance impact in certain cases, it's started up lazily (on demand)
~ when a separate log context is defined in a user deployment.
--> - One might say this is not a big problem. After all the traversal is performed only if a new logger is created and not every time it is used to output something. And because loggers are cached it does not matter how many times getLogger() is invoked, creation and hence the traversal happens only once.
But exactly this fact (traversal at creation) is one of the reasons why the per-application logging is broken. Let's look at the example above, the one with the application using some library. Here is the stack trace again:Some JBoss logging code
Your application calls the library, for example, JPA. JPA provider classes, Hibernate under JBoss, call getLogger(). JBoss finds the application classes in the invocation stack, so the application logging configuration is used also for Hibernate classes. Logging output from Hibernate goes to your logging file. Sun is shining, life is good. You go ahead and deploy a second application that uses JPA and per-application logging. The log file for the second application is created. Logging from the application classes goes there. But not the logging from Hibernate: it goes to the log file of the first application. Surprise!
Some more JBoss logging code
<library class>.getLogger()
Some other library code, can be a lot
Some code from the application calling the library
Some other code from the application
Some JBoss EJB/servlet/you name it invocation code, a lot of it actually
Thread.run()
The reason is clear: when the Hibernate logger was created the classes from the first application were on the stack, so the logger became "bound" to the configuration loaded from the first application.
In reality it gets much more interesting: some Hibernate logging output goes to the default JBoss log (Hibernate code is executed during the application deployment/startup), other might go to this application's log, yet another might go to some other application's log. It all depends on the invocation stack at the moment of creation of the logger. Кто первый встал, того и тапки, which roughly translates to "The first man gets the oyster, the second man gets the shell".
And what happens if the first application is undeployed? Where Hibernate log goes then? I did not bother to check this: nothing good anyway. - As it were enough. You see, when I am talking about application-specific logging I really want the logging from the shared classes still go to the application log when the shared classes execute on behalf of the application. Even if there is yet no class from the application on the stack. For example, JBoss code that runs before invoking a servlet or an EJB business method from the application. Or a web service: there is a lot going on before the application code is invoked: XML parsing, unmarshaling, you name it. Where the logging, including error stack traces, goes? Most likely to the default logging: there is after all no classes from the application on the stack yet. Or to some other log file: the first man gets the oyster, remember?
- It can get even stranger. What I have seen in my tests is that the app-specific logging is activated pretty late in the deployed process. If any of the application code calls getLogger() before the logging configuration is hooked up the logging from the application classes goes to the wrong place: to the default logging. Most often there is a static Logger field in a class. This results in getLogger() being invoked during the loading of the class. For example, JPA provider loads classes looking for annotations. Or CXF code looks for JAX-WS annotations. All this loading is happening before the logging configuration is bound to the application classloader.
This problem can be somewhat compensated by not using a static Logger field, but it is applicable only to the code you control and not to 3rd party code. There can also be situations where static initializer does something worth logging.
Nicely implemented feature, isn't it?
You might be tempted to package more 3rd party jars in your application and play some classloading tricks to make sure that the classes are loaded from the application-packaged jars and not from JBoss-provided jars. Don't!
- This won't buy you anything except maybe the server upgrade. The memory consumption will skyrocket, especially if there are multiple applications doing this.
- This might help you with problems 2 and 3 above. Problems 1 and 4 remain.
- You need to understand Java classloading pretty good. Then you have to forget it and learn the mess that JBoss made of it. And even then most likely it will not work. JBoss will not even deploy your application no matter how hard you try.
For example just packaging Hibernate jars in a simplest EJB application that has otherwise no Hibernate or any other persistency dependencies is enough. If the application has JBoss classloading config that instruct JBoss to look for classes first in jars packaged with the application and only then in the parent (JBoss) clasloader the application will not deploy. While I have quite good understanding of JBoss classloading I would not even try to make this application deployable because I also understand the reason why it fails.
Feel lucky? Give it a try. At best you can make this scheme work with some 3rd party jars but not with the most important and interesting, like Hibernate or CXF.
The question remains: is it actually possible to have the application-specific logging in JBoss 6?
Of course! Scrum solved that problem long time ago: a team decides what they want to have done and as they progress they can redefine what "done" means. Pretty neat and useful. You can do the same here: you can define what "application-specific" means in your case and then implement it.
Jokes aside there is not much you can actually do. The simplest and most sane solution is to forget about all that JBoss woodoo with the application-specific logging. Rollback the workaround for bug JBAS-9407. Use the default logging configuration in deploy/jboss-logging.xml. You can direct the output from your classes to a separate file. All the logging from the shared classes still goes to server.log by default. Directing the output from the shared classes to your application's log file is a bad thing to do: imagine if every application tries to do this. Including thread names in the logging output helps matching the records from the default JBoss log (server.log) back to your application if necessary.
JBoss, you never stops to amuse me!
Tuesday, November 15, 2011
Standalone HornetQ and JBoss, part 2: making it work without embedded server
Rant mode off.
Actually it is not that bad. It is just so happened that HornetQ standalone ended up being last on the list of things I have tried. And it became the last straw.
In reality the biggest single WTF was not HornetQ but ActiveMQ acknowledging received messages despite timed out transaction. The biggest collection of WTFs in a single place was of course (and is, and probably will be forever) OracleAQ.
But back to configuring JBoss AS 6 to work with the standalone HornetQ.
The situation now is still not complete because no destination objects are registered in JBoss JNDI. JBoss can be started but deploying an application that uses @Resource will still fail. The good thing: the embedded HornetQ is out of picture.
The remaining piece of configuration depends actually on how the application uses JMS. If the application contains some MDBs to receive messages from destinations, then it is possible to skip JNDI registration completely. Whether it is a good idea is another question. Just add something like this to the MDB code or the equivalent configuration to its deployment descriptor:
The key here is the property named "UseJNDI". The default value is true and the destination has to be registered in the JNDI. Setting the property to false skips JNDI lookup. After all, JNDI registration is just a bit more than a mapping from say "jms/hq/AQueue" JNDI name to the queue name ("TestQueue") known to the server. The HornetQ resource adapter will use "TestQueue" as the queue name in its communication with the server.
If the application needs that kind of indirection or if it sends messages and relies on @Resource injection line that:
This is what is missing in HornetQ documentation. This and also the way to make it easier and less verbose:
Create a file named jboss-beans.xml in META-INF (or WEB-INF) directory of your application if you want to deploy the configuration with your application. Or create a file named <something meaningful>- jboss-beans.xml in JBOSS_HOME/server/<servername>/deploy. Copy the following to the file:
This configuration creates a JNDI entry under name "jms/hq/AQueue" and makes sure that is it the correct class (org.hornetq.jms.client.HornetQQueue which implements javax.jms.Queue). This entry represents a queue named "TestQueue" on a server. Note: "on a server". As I have mentioned in the previous post this object is just a mapping to the destination name and it comes alive only with the correct ConnectionFactory/ConnectorFactory.
That is it. Hey, HornetQ, was it difficult to document?
Actually it is not that bad. It is just so happened that HornetQ standalone ended up being last on the list of things I have tried. And it became the last straw.
In reality the biggest single WTF was not HornetQ but ActiveMQ acknowledging received messages despite timed out transaction. The biggest collection of WTFs in a single place was of course (and is, and probably will be forever) OracleAQ.
But back to configuring JBoss AS 6 to work with the standalone HornetQ.
- The most important thing is to use JBoss AS 6.1.0.Final and not 6.0. Details are here. This is something I already knew and it is not specific to the standalone configuration of HornetQ, but it is worth mentioning here anyway.
- JBoss will be configured to talk to the external standalone HornetQ. The embedded HornetQ will be removed. This is what I want to achieve. Yes, it is possible to go for the standalone HornetQ environment and still run the embedded HornetQ just in case. But I find it pointless. Note also that no new resource adapter is added to JBoss. Instead the configuration of the existing one is changed.
- Move JBOSS_HOME/server/<servername>/deploy/hornetq/jms-ds.xml to JBOSS_HOME/server/<servername>/deploy. This is where outbound connection factories are defined. The file will have to be changed, see below.
- Delete JBOSS_HOME/server/<servername>/deploy/hornetq directory. This is where the configuration of the embedded HornetQ lives.
- Delete JBOSS_HOME/server/<servername>/deployers/hornetq-deployers-jboss-beans.xml. This file specifies how HornetQ specific configuration files should be read to initialize embedded HornetQ server and its destination objects. No embedded HornetQ means no need to read these configuration files.
- Change the resource adapter configuration file: JBOSS_HOME/server/<servername>/deploy/jms-ra.rar/META-INF/ra.xml. This is actually documented here: 32.4.4.1.1. Configuring the Incoming Adaptor or here: HORNETQ_HOME/examples/javaee/jca-remote/readme.html, section "configuring the incoming Adapter". Basically you need to change two RA properties:
<config-property>
The incoming messages will be received from the standalone HornetQ server available at localhost:5445.
<description>
The transport type. Multiple connectors can be configured by using a comma separated list,
i.e. org.hornetq.core.remoting.impl.invm.InVMConnectorFactory,org.hornetq.core.remoting.impl.invm.InVMConnectorFactory.
</description>
<config-property-name>ConnectorClassName</config-property-name>
<config-property-type>java.lang.String</config-property-type>
<!-- <config-property-value>org.hornetq.core.remoting.impl.invm.InVMConnectorFactory</config-property-value> -->
<config-property-value>org.hornetq.core.remoting.impl.netty.NettyConnectorFactory</config-property-value>
</config-property>
<config-property>
<description>The transport configuration. These values must be in the form of key=val;key=val;,
if multiple connectors are used then each set must be separated by a comma i.e. host=host1;port=5445,host=host2;port=5446.
Each set of params maps to the connector classname specified.
</description>
<config-property-name>ConnectionParameters</config-property-name>
<config-property-type>java.lang.String</config-property-type>
<!-- <config-property-value>server-id=0</config-property-value> -->
<config-property-value>host=127.0.0.1;port=5445</config-property-value>
</config-property> - Change the connection factory configuration file (jms-ds.xml copied to deploy directory at step 3 above). It is also documented 32.4.4.1.2. Configuring the outgoing adaptor or here: HORNETQ_HOME/examples/javaee/jca-remote/readme.html, section "configuring the outgoing Adapter". This is what the resulting file looks like:
<connection-factories>
<tx-connection-factory>
<jndi-name>jms/HornetQ/XACF</jndi-name>
<xa-transaction/>
<rar-name>jms-ra.rar</rar-name>
<connection-definition>org.hornetq.ra.HornetQRAConnectionFactory</connection-definition>
<config-property name="SessionDefaultType" type="java.lang.String">javax.jms.Topic</config-property>
<config-property name="ConnectorClassName" type="java.lang.String">org.hornetq.core.remoting.impl.netty.NettyConnectorFactory</config-property>
<config-property name="ConnectionParameters" type="java.lang.String">host=127.0.0.1;port=5445</config-property>
<max-pool-size>20</max-pool-size>
</tx-connection-factory>
</connection-factories>
The situation now is still not complete because no destination objects are registered in JBoss JNDI. JBoss can be started but deploying an application that uses @Resource will still fail. The good thing: the embedded HornetQ is out of picture.
The remaining piece of configuration depends actually on how the application uses JMS. If the application contains some MDBs to receive messages from destinations, then it is possible to skip JNDI registration completely. Whether it is a good idea is another question. Just add something like this to the MDB code or the equivalent configuration to its deployment descriptor:
@MessageDriven(activationConfig = {
@ActivationConfigProperty(propertyName = "destinationType", propertyValue = "javax.jms.Queue"),
@ActivationConfigProperty(propertyName = "destination", propertyValue = "TestQueue"),
@ActivationConfigProperty(propertyName = "UseJNDI", propertyValue = "false"),
})The key here is the property named "UseJNDI". The default value is true and the destination has to be registered in the JNDI. Setting the property to false skips JNDI lookup. After all, JNDI registration is just a bit more than a mapping from say "jms/hq/AQueue" JNDI name to the queue name ("TestQueue") known to the server. The HornetQ resource adapter will use "TestQueue" as the queue name in its communication with the server.
If the application needs that kind of indirection or if it sends messages and relies on @Resource injection line that:
@Resource(mappedName = "jms/hq/AQueue")then some more configuration is needed. This configuration can be done at the server level so the destinations are available to all applications as soon as the server is started or at the application level. Note: I did not actually test the application level configuration. There might be initialization order problems: JNDI name must be available for injection but it is not yet there.
private Queue queue;
This is what is missing in HornetQ documentation. This and also the way to make it easier and less verbose:
Create a file named jboss-beans.xml in META-INF (or WEB-INF) directory of your application if you want to deploy the configuration with your application. Or create a file named <something meaningful>- jboss-beans.xml in JBOSS_HOME/server/<servername>/deploy. Copy the following to the file:
<?xml version="1.0" encoding="UTF-8"?>
<deployment xmlns="urn:jboss:bean-deployer:2.0">
<bean name="HQ_JNDIBindingService" class="org.jboss.naming.JNDIBindingService">
<property name="bindings">
<bean class="org.jboss.naming.JNDIBindings">
<property name="bindings">
<array elementClass="org.jboss.naming.JNDIBinding">
<bean class="org.jboss.naming.JNDIBinding">
<property name="name">jms/hq/AQueue</property>
<property name="value">
<!-- Use org.hornetq.jms.client.HornetQTopic for topic -->
<bean class="org.hornetq.jms.client.HornetQQueue">
<constructor>
<parameter>TestQueue</parameter>
</constructor>
</bean>
</property>
</bean>
<!-- You can add here more <bean class="org.jboss.naming.JNDIBinding"> definitions for other destinations -->
</array>
</property>
</bean>
</property>
</bean>
</deployment>
This configuration creates a JNDI entry under name "jms/hq/AQueue" and makes sure that is it the correct class (org.hornetq.jms.client.HornetQQueue which implements javax.jms.Queue). This entry represents a queue named "TestQueue" on a server. Note: "on a server". As I have mentioned in the previous post this object is just a mapping to the destination name and it comes alive only with the correct ConnectionFactory/ConnectorFactory.
That is it. Hey, HornetQ, was it difficult to document?
Standalone HornetQ and JBoss
For the last couple of weeks I have been busy playing with JBoss and various JMS implementations, like Apache ActiveMQ, HornetQ and even OracleAQ. As usual, with different degree of success. This post is about trying to make HornetQ standalone work with JBoss.
HornetQ comes bundled with JBoss AS 6 as its default JMS provider. As such HornetQ runs embedded in JBoss JVM process. HornetQ home page mentions a lot of nice feature HornetQ has, for example "Solid high availability" or "Flexible clustering". These feature are available only when HornetQ runs as standalone server.
Shall we try it? No problem, HornetQ is downloaded and started. The minor inconvenience is the lack of any admin user interface. All the configuration must be done via config files or via JMX. Fortunately I need just a single queue for testing purposes. TestQueue is created, HornetQ server is restarted. So far so good.
Now it is time to configure JBoss side. I must say this is ... interesting. Very interesting.
Rant mode on.
It is unbelievable: HornetQ comes from the same company as JBoss AS so it must be easy, right? It is even documented, there are samples, and yet...
First of all there is no documentation on how to configure JBoss AS 6 to completely switch from the embedded HornetQ configuration to standalone. The available documentation describes only how to connect to the standalone server. As if it were enough. The documentation says nothing about the rest of HornetQ configuration files in JBoss.
Guess what, it is not enough. I tried to deploy my tests application and immediately got complaints from JBoss saying that my nice TestQueue is not there.
Nowhere could I find any description on how to make a queue configured in the standalone HornetQ server be visible in the JBoss JNDI tree so that @Resource injection worked.
Next thing I tried was adding my queue in JBOSS_HOME/server/<servername>/deploy/hornetq/hornetq-jms.xml. This looked like a very strange thing to do, but this actually worked. Wow, HornetQ is smart! The corresponding JNDI entry is created, the application is deployed and I can send messages and receive them with an MDB.
There are even couple of JMX mbeans corresponding to my test queue available in JBoss JMX console. Except the attributes of those JMX mbeans do not really match the expected values and operations do not do the expected things. It looks like no messages ever went through the queue. What gives?
Nothing new actually: documentation that is incomplete; adding new functionality is much more important than making it work in the useful configurations, you name it. Works in JBoss as embedded? Good enough, let's move on. Need to do something different? Good luck with that.
So why it works and how?
All the configuration files under deploy/hornetq are related to the embedded HornetQ. Adding a queue/topic definition to hornetq-jms.xml adds the destination to the embedded server. The JMX mbeans are created to manage this local destination. And do not get me started on the story of two JMX beans per queue/topic and the difference between "core" HornetQ and "jms" HornetQ. Layered architecture in practice.
As part of a queue/topic creation HornetQ registers it in JBoss JNDI. This registered object is more or less the destination's name on the server. Yes, the object is an implementation of javax.jms.Queue/Topic interface but this does not really matter. It is useless by itself. The "magic" happens only in combination with the configured ConnectionFactory (for the outbound communication) or ConnectorFactory (for the inbound communication). Is it local "InVM" connection? Then the embedded server is doing the work. Is it "Netty" connection pointing to the standalone HornetQ? Then messages go to/from that server.
The net result: since there is no documented way to register such "destination names" in JBoss JNDI directly one must keep the embedded HornetQ running. And then for each remote destination one must create the corresponding local destination to get the correct JNDI objects in place as a side effect. Really a way to go, HornetQ! Clear and understandable architecture. And you get (for free!) a pair of useless JMX mbeans per destination so that you can waste your time trying to understand what the hell is going on with the messages.
It is even more interesting for people who want to use HornetQ from other application servers. There is no <adminobject> in ra.xml (<adminobject>s are those "destination names" in JNDI). Naturally, since embedded HornetQ creates them programmatically. It works in JBoss as embedded? Good enough then.
HornetQ comes bundled with JBoss AS 6 as its default JMS provider. As such HornetQ runs embedded in JBoss JVM process. HornetQ home page mentions a lot of nice feature HornetQ has, for example "Solid high availability" or "Flexible clustering". These feature are available only when HornetQ runs as standalone server.
Shall we try it? No problem, HornetQ is downloaded and started. The minor inconvenience is the lack of any admin user interface. All the configuration must be done via config files or via JMX. Fortunately I need just a single queue for testing purposes. TestQueue is created, HornetQ server is restarted. So far so good.
Now it is time to configure JBoss side. I must say this is ... interesting. Very interesting.
Rant mode on.
It is unbelievable: HornetQ comes from the same company as JBoss AS so it must be easy, right? It is even documented, there are samples, and yet...
First of all there is no documentation on how to configure JBoss AS 6 to completely switch from the embedded HornetQ configuration to standalone. The available documentation describes only how to connect to the standalone server. As if it were enough. The documentation says nothing about the rest of HornetQ configuration files in JBoss.
Guess what, it is not enough. I tried to deploy my tests application and immediately got complaints from JBoss saying that my nice TestQueue is not there.
Nowhere could I find any description on how to make a queue configured in the standalone HornetQ server be visible in the JBoss JNDI tree so that @Resource injection worked.
Next thing I tried was adding my queue in JBOSS_HOME/server/<servername>/deploy/hornetq/hornetq-jms.xml. This looked like a very strange thing to do, but this actually worked. Wow, HornetQ is smart! The corresponding JNDI entry is created, the application is deployed and I can send messages and receive them with an MDB.
There are even couple of JMX mbeans corresponding to my test queue available in JBoss JMX console. Except the attributes of those JMX mbeans do not really match the expected values and operations do not do the expected things. It looks like no messages ever went through the queue. What gives?
Nothing new actually: documentation that is incomplete; adding new functionality is much more important than making it work in the useful configurations, you name it. Works in JBoss as embedded? Good enough, let's move on. Need to do something different? Good luck with that.
So why it works and how?
All the configuration files under deploy/hornetq are related to the embedded HornetQ. Adding a queue/topic definition to hornetq-jms.xml adds the destination to the embedded server. The JMX mbeans are created to manage this local destination. And do not get me started on the story of two JMX beans per queue/topic and the difference between "core" HornetQ and "jms" HornetQ. Layered architecture in practice.
As part of a queue/topic creation HornetQ registers it in JBoss JNDI. This registered object is more or less the destination's name on the server. Yes, the object is an implementation of javax.jms.Queue/Topic interface but this does not really matter. It is useless by itself. The "magic" happens only in combination with the configured ConnectionFactory (for the outbound communication) or ConnectorFactory (for the inbound communication). Is it local "InVM" connection? Then the embedded server is doing the work. Is it "Netty" connection pointing to the standalone HornetQ? Then messages go to/from that server.
The net result: since there is no documented way to register such "destination names" in JBoss JNDI directly one must keep the embedded HornetQ running. And then for each remote destination one must create the corresponding local destination to get the correct JNDI objects in place as a side effect. Really a way to go, HornetQ! Clear and understandable architecture. And you get (for free!) a pair of useless JMX mbeans per destination so that you can waste your time trying to understand what the hell is going on with the messages.
It is even more interesting for people who want to use HornetQ from other application servers. There is no <adminobject> in ra.xml (<adminobject>s are those "destination names" in JNDI). Naturally, since embedded HornetQ creates them programmatically. It works in JBoss as embedded? Good enough then.
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:
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.
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:
- Configure your application to use the app-specific logging and make sure it really works.
- 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">
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.
<define-context name="MyWonderfulLogContext"/>
</logging> - 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.
- 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> - 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:
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 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:
That is it.
Oh, yeah. Some technical details:
Next time I explain how to change every aspect of the logging configuration at runtime.
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:
- 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.
- 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.
- 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.
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:
- 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> - Deploy your application; make sure the app-specific logging actually works and the logging goes where it supposed to go.
- Create somewhere a file named for example MyWonderfulLog-jboss-beans.xml with the following content:
<?xml version="1.0" encoding="UTF-8"?>
Attention: the annotation element must be on a single line!
<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> - 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:
- 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.
- 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:
- 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.
- 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.
- 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.
- 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:
After some poking around jboss configuration and the source code I have found a solution. Actually a workaround and a fix.
Workaround:
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.
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:
Bummer!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)
After some poking around jboss configuration and the source code I have found a solution. Actually a workaround and a fix.
Workaround:
- 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.
- 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:
You can also remove that comment above about lazy loading. It is not true anyway.<bean name="OnDemandJBossLogManagerContextSelector"
class="org.jboss.logmanager.LogContextSelectorService"
mode="On Demand">
<property name="selector">
<inject bean="JBossLogManagerContextSelectorService"/>
</property>
</bean>
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
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":
"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:
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:
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.
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
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.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"
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:
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./** 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");
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:
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.
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:
<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.java.io.InvalidClassException: javax.xml.namespace.QName;
local class incompatible: stream classdesc serialVersionUID = -9120448754896609940,
local class serialVersionUID = -711357515002332258
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.
Subscribe to:
Posts (Atom)