[JAVA-1117] 2.12.0-rc0 logs JMX InstanceAlreadyExistsException at WARNING level Created: 19/Feb/14 Updated: 06/Apr/23 Resolved: 26/Feb/14 |
|
| Status: | Closed |
| Project: | Java Driver |
| Component/s: | Monitoring |
| Affects Version/s: | 2.12.0 |
| Fix Version/s: | 2.12.0 |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | Alexej Kubarev | Assignee: | Unassigned |
| Resolution: | Done | Votes: | 0 |
| Labels: | rc | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Environment: |
JDK 7u51 (Linux and OSX) |
||
| Issue Links: |
|
||||||||
| Backwards Compatibility: | Fully Compatible | ||||||||
| Description |
|
When running several WAR files under one appserver, and both WAR files create one or several MongoClient instances, with 2.12.0-rc0 we start seeing
This happens for the second WAR file starting (first one works fine, even though it started several instances of MongoClient). If we load only one of the WAR files (no matter which) this does not happen. This is working fine if using 2.11.4 (and a few earlier versions, for sure) of the driver but broke in 2.12.0-rc0 |
| Comments |
| Comment by Jeffrey Yemin [ 27/Feb/14 ] | |
|
That's great. Thanks for checking. | |
| Comment by Alexej Kubarev [ 27/Feb/14 ] | |
|
Seems to be the same behavior as with 2.11.4. | |
| Comment by Jeffrey Yemin [ 27/Feb/14 ] | |
|
Hi Alexej, If possible, can you test with the SNAPSHOT build available at https://oss.sonatype.org/content/repositories/snapshots/org/mongodb/mongo-java-driver/2.12.0-SNAPSHOT/mongo-java-driver-2.12.0-20140227.021034-55.jar. Thanks, | |
| Comment by Githook User [ 26/Feb/14 ] | |
|
Author: {u'username': u'jyemin', u'name': u'Jeff Yemin', u'email': u'jeff.yemin@10gen.com'}Message: | |
| Comment by Jeffrey Yemin [ 26/Feb/14 ] | |
|
You are right about the external dependencies, though I might consider an optional dependency if we could make that work. That would require a layer of indirection that checked for the existence of SLF4J on the classpath. The driver already does something similar with JMX. Please open a new JIRA issue for this if you wouldn't mind. It's not going to make 2.12 but we can consider it for 3.0. Thanks, | |
| Comment by Alexej Kubarev [ 26/Feb/14 ] | |
|
I see. If this is the only chan ge it does make sense to revert back to original log level. I know this is a bit off-topic but in the context of searching for the reason for logs not to appear - I've started thinking: If you believe it's possible I can do a change and submit it as a Pull Request, as this is a very fast and easy change that requires simply changing the imports. Also logger.debug() much more optimised in SLF4J as it allows placeholders and does not evaluate value of placeholders if debug is not enabled - performance gain. | |
| Comment by Jeffrey Yemin [ 26/Feb/14 ] | |
|
I changed the title and metadata to reflect the fact that this exception is not actually being thrown, just logged at a different level. | |
| Comment by Jeffrey Yemin [ 25/Feb/14 ] | |
|
We've decided to revert to the 2.11.x behavior, which means
| |
| Comment by Jeffrey Yemin [ 25/Feb/14 ] | |
|
The Java driver is just using java.util.logging (JUL). Since you are getting the WARNING in your logs, it means that JUL calls are being forwarded properly. What doesn't seem to be working is the application of Log4J levels to JUL, and I'm not sure why that is. Regardless, I'm pretty sure that there is an INFO level message that is being logged in 2.11.x and swallowed by log4j, so the only difference in behavior between 2.11.x and 2.12.x is the log level. Given the severity, I think WARNING is more appropriate than INFO, so I'm not inclined to change that. What I would consider changing is the clusterId, so that its guaranteed to be unique across class loaders. The only way to do this reliably is to use either GUIDs or ObjectIds as cluster identifiers, instead of integers. I'm going to talk this over with some other driver developers, and I'll get back to you. | |
| Comment by Alexej Kubarev [ 25/Feb/14 ] | |
|
Hi Jeff, This is crazy but for all libraries i have tested so far except mongodb java driver it works fine to enable/disable logging.
We have slf4j-api, jcl-over-slf4j and jul-to-slf4j (naturally log4j and slf4j-log4j12 too). Is mongo driver using something else? Because I can't figure out at this point why there is no driver output. Even if i put rootLogger=INFO and simply disable some of internal classes and springframework - still no luck getting those. | |
| Comment by Jeffrey Yemin [ 25/Feb/14 ] | |
|
Hi Alexej, Are you saying that you aren't getting anything logged at all in "com.mongodb", or just not that line? If so, something is not right, since you should at the very least be getting this one: https://github.com/mongodb/mongo-java-driver/blob/2.11.x/src/main/com/mongodb/Mongo.java#L330. | |
| Comment by Alexej Kubarev [ 25/Feb/14 ] | |
|
Hi Jeff, during application startup nothing is happening for both INFO and DEBUG of com.mongodb. | |
| Comment by Alexej Kubarev [ 25/Feb/14 ] | |
|
Hi Jeff, working on getting those logs for you (will take a few minutes). As for the clusterIds - we are getting 3 errors, one for each clusterId. But only after the first web-app deployed, so this is happening during second webapp initialization. And if this would turn out to be the only difference (which is possible), what would your recommendation be on avoiding it? | |
| Comment by Jeffrey Yemin [ 25/Feb/14 ] | |
|
Can you turn up your logging to INFO on com.mongdb and run again with 2.11.4? I want to see if this is being logged: https://github.com/mongodb/mongo-java-driver/blob/2.11.x/src/main/com/mongodb/DBPortPool.java#L89 If so, then the only real difference here is the level of logging (INFO vs WARNING). One other thing isn't clear to me. In the description, the log message indicates a clusterId of 3. Is that the only WARNING logged, or are there earlier ones for clusterId 1 and 2 as well? Thanks, | |
| Comment by Alexej Kubarev [ 25/Feb/14 ] | |
|
Hi Jeff, No, we are not providing that property | |
| Comment by Jeffrey Yemin [ 25/Feb/14 ] | |
|
Hi Alexej, After looking at the diffs between 2.11 and 2.12, I have an additional question: are you setting the description property on MongoClientOptions, and if so, are the MongoClient instances each constructed with different values for that property? I ask because of this piece of code that's in 2.11 but not 2.12: https://github.com/mongodb/mongo-java-driver/blob/2.11.x/src/main/com/mongodb/DBPortPool.java#L132-133. Thanks, | |
| Comment by Jeffrey Yemin [ 20/Feb/14 ] | |
|
Thank you for testing the RC and for the bug report. We will address this in the final release. |