Re: Performance issues and strange logs
Assuming that the errors and warnings are not a big deal, can you suggest any reasons that we would have connections stacking up and timing out? The use case is likely heavier on write than would be standard for LDAP, but it seems the failure threshold (number of connections) is very low. This is hosted on a multi-core machine (virtual machine) and when it gets bad, our operations people say that a single core of the machine is pegged at 100% CPU while others are essentially idle. Are there parts of Apache DS that have thread affinity and would be stuck to a single processor? Any thoughts would be appreciated, Craig On Wednesday, October 12, 2011, Emmanuel Lecharny wrote: On 10/12/11 10:24 PM, Craig Setera wrote: Hello, Hi, which ADS version are you using ? Is it still 1.5.5 ? Last week I was asking about indexing and performance gains from those indexes. The question stemmed from some performance problems that we are currently having in our environment. In that environment, we are seeing extremely poor performance and Apache DS getting bogged down after a relatively small number of connections (under 100). When that happens, the connections start to stack up and eventually time out. I was surprised by the performance, but was looking at things like indexing and disabling sync on write as ways to improve the situation. Now, I've received some logs from testing and I'm beginning to wonder if there is something else going on. I'm seeing many entries in the logs that look like: [18:27:52] WARN [org.apache.directory.server.**ldap.LdapSession] - AbandonableRequest with messageId 2 not found in outstandingRequests. [18:27:53] WARN [org.apache.directory.shared.**asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. [18:27:53] WARN [org.apache.directory.shared.**asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. [18:27:53] WARN [org.apache.directory.server.**ldap.LdapSession] - AbandonableRequest with messageId 2 not found in outstandingRequests. [18:27:53] WARN [org.apache.directory.shared.**asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. [18:27:53] WARN [org.apache.directory.shared.**asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. This message just means that some data has been received, decoded correctly, but we have still some remaining bytes in the buffer. It's a warning, not an error. The remaining bytes will be decoded later. Nothing to be scared about. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com
Re: Performance issues and strange logs
On 10/13/11 5:31 PM, Craig Setera wrote: Assuming that the errors and warnings are not a big deal, can you suggest any reasons that we would have connections stacking up and timing out? The use case is likely heavier on write than would be standard for LDAP, but it seems the failure threshold (number of connections) is very low. This is hosted on a multi-core machine (virtual machine) and when it gets bad, our operations people say that a single core of the machine is pegged at 100% CPU while others are essentially idle. Are there parts of Apache DS that have thread affinity and would be stuck to a single processor? Ok, 1.5.5 is pretty old, and depends on MINA-2.0.0-M6. This version of the NIO framework sometime gets stuck with 100% CPU (it's a JVM bug) when some session are closed just after having been opened (basically, the selector loop get crazy and eats 100% CPU looping). It might be the reason why you see this 100% CPU for some sessions (as we have one selector per CPU, the other sessions might be ok). I would suggest you switch to at least 1.5.7, but even better to 2.0.0-M3. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com
Re: Performance issues and strange logs
Is it possible to switch out just MINA or would that break something? On Thursday, October 13, 2011, Emmanuel Lecharny wrote: On 10/13/11 5:31 PM, Craig Setera wrote: Assuming that the errors and warnings are not a big deal, can you suggest any reasons that we would have connections stacking up and timing out? The use case is likely heavier on write than would be standard for LDAP, but it seems the failure threshold (number of connections) is very low. This is hosted on a multi-core machine (virtual machine) and when it gets bad, our operations people say that a single core of the machine is pegged at 100% CPU while others are essentially idle. Are there parts of Apache DS that have thread affinity and would be stuck to a single processor? Ok, 1.5.5 is pretty old, and depends on MINA-2.0.0-M6. This version of the NIO framework sometime gets stuck with 100% CPU (it's a JVM bug) when some session are closed just after having been opened (basically, the selector loop get crazy and eats 100% CPU looping). It might be the reason why you see this 100% CPU for some sessions (as we have one selector per CPU, the other sessions might be ok). I would suggest you switch to at least 1.5.7, but even better to 2.0.0-M3. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com
Re: Performance issues and strange logs
On 10/13/11 5:53 PM, Craig Setera wrote: Is it possible to switch out just MINA or would that break something? It *should* be possible, as the MINA API has been frozen in 2.0.0-RC1. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com
Re: Performance issues and strange logs
We have a custom interceptor plugged in to 1.5.5. Did anything change in 1.5.7 that would break that? If not, we may be best off to just move to 1.5.7. Thanks again, craig On Thursday, October 13, 2011, Emmanuel Lécharny wrote: On 10/13/11 5:53 PM, Craig Setera wrote: Is it possible to switch out just MINA or would that break something? It *should* be possible, as the MINA API has been frozen in 2.0.0-RC1. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com
Re: Performance issues and strange logs
On Thu, Oct 13, 2011 at 12:52 PM, Craig Setera cr...@mfoundry.com wrote: We have a custom interceptor plugged in to 1.5.5. Did anything change in 1.5.7 that would break that? If not, we may be best off to just move to 1.5.7. hard to tell without knowing(at least in a very high level view) what this interceptor does Thanks again, craig On Thursday, October 13, 2011, Emmanuel Lécharny wrote: On 10/13/11 5:53 PM, Craig Setera wrote: Is it possible to switch out just MINA or would that break something? It *should* be possible, as the MINA API has been frozen in 2.0.0-RC1. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com -- Kiran Ayyagari
Re: Performance issues and strange logs
High-level... does alteration of the values of some of our schema attributes. So, it sits in the flow and alters the data for those particular attributes as they flow through. On Thursday, October 13, 2011, Kiran Ayyagari wrote: On Thu, Oct 13, 2011 at 12:52 PM, Craig Setera cr...@mfoundry.comjavascript:; wrote: We have a custom interceptor plugged in to 1.5.5. Did anything change in 1.5.7 that would break that? If not, we may be best off to just move to 1.5.7. hard to tell without knowing(at least in a very high level view) what this interceptor does Thanks again, craig On Thursday, October 13, 2011, Emmanuel Lécharny wrote: On 10/13/11 5:53 PM, Craig Setera wrote: Is it possible to switch out just MINA or would that break something? It *should* be possible, as the MINA API has been frozen in 2.0.0-RC1. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com javascript:; -- Kiran Ayyagari -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com
Re: Performance issues and strange logs
On Thu, Oct 13, 2011 at 2:10 PM, Craig Setera cr...@mfoundry.com wrote: High-level... does alteration of the values of some of our schema attributes. So, it sits in the flow and alters the data for those particular attributes as they flow through. ok, should work in the latest code without any issues (might require fixing some imports) On Thursday, October 13, 2011, Kiran Ayyagari wrote: On Thu, Oct 13, 2011 at 12:52 PM, Craig Setera cr...@mfoundry.comjavascript:; wrote: We have a custom interceptor plugged in to 1.5.5. Did anything change in 1.5.7 that would break that? If not, we may be best off to just move to 1.5.7. hard to tell without knowing(at least in a very high level view) what this interceptor does Thanks again, craig On Thursday, October 13, 2011, Emmanuel Lécharny wrote: On 10/13/11 5:53 PM, Craig Setera wrote: Is it possible to switch out just MINA or would that break something? It *should* be possible, as the MINA API has been frozen in 2.0.0-RC1. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com javascript:; -- Kiran Ayyagari -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com -- Kiran Ayyagari
Re: Performance issues and strange logs
Oh... Hopefully it works without recompile or this gets trickier. I guess we will find out soon enough. Thanks, Craig On Thursday, October 13, 2011, Kiran Ayyagari wrote: On Thu, Oct 13, 2011 at 2:10 PM, Craig Setera cr...@mfoundry.comjavascript:; wrote: High-level... does alteration of the values of some of our schema attributes. So, it sits in the flow and alters the data for those particular attributes as they flow through. ok, should work in the latest code without any issues (might require fixing some imports) -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com
Re: Performance issues and strange logs
On 10/13/11 6:52 PM, Craig Setera wrote: We have a custom interceptor plugged in to 1.5.5. Did anything change in 1.5.7 that would break that? If not, we may be best off to just move to 1.5.7. I don't know. Can you post the interceptor method's signatures? -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com
Re: Performance issues and strange logs
Unfortunately, it appears there was a lot of refactoring between 1.5.5 and
1.5.7. It looks like MINA was updated in 1.5.6... do you have any idea if
the refactoring in that case would be less than what I'm seeing?
Thanks again,
Craig
On Thursday, October 13, 2011, Craig Setera wrote:
Oh... Hopefully it works without recompile or this gets trickier. I guess
we will find out soon enough.
Thanks,
Craig
--
Craig Setera
Director, Product Engineering
mFoundry
p 415.324.5801
cr...@mfoundry.com javascript:_e({}, 'cvml', 'cr...@mfoundry.com');
--
Craig Setera
Director, Product Engineering
mFoundry
p 415.324.5801
cr...@mfoundry.com
Re: Performance issues and strange logs
Looks like our emails crossed along the way. The breakage is pretty extensive. I can work through it, but wondering if 1.5.6 would be any better? On Thursday, October 13, 2011, Emmanuel Lécharny wrote: On 10/13/11 6:52 PM, Craig Setera wrote: We have a custom interceptor plugged in to 1.5.5. Did anything change in 1.5.7 that would break that? If not, we may be best off to just move to 1.5.7. I don't know. Can you post the interceptor method's signatures? -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com
Re: Performance issues and strange logs
On 10/13/11 10:43 PM, Craig Setera wrote: Unfortunately, it appears there was a lot of refactoring between 1.5.5 and 1.5.7. It looks like MINA was updated in 1.5.6... do you have any idea if the refactoring in that case would be less than what I'm seeing? Again, it's hard to tell. If you provide your interceptor's method signatures, I can check. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com
Re: Performance issues and strange logs
I appreciate the offer. Unfortunately, it is quite a lot of code. I'm going to try a new version of MINA inside of 1.5.5 and see what happens. On Thursday, October 13, 2011, Emmanuel Lecharny wrote: On 10/13/11 10:43 PM, Craig Setera wrote: Unfortunately, it appears there was a lot of refactoring between 1.5.5 and 1.5.7. It looks like MINA was updated in 1.5.6... do you have any idea if the refactoring in that case would be less than what I'm seeing? Again, it's hard to tell. If you provide your interceptor's method signatures, I can check. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com
Re: Performance issues and strange logs
On 10/13/11 11:01 PM, Craig Setera wrote: I appreciate the offer. Unfortunately, it is quite a lot of code. I'm going to try a new version of MINA inside of 1.5.5 and see what happens. Just the method's signature, not the code. If there is some issue with 1.5.7, it will be around the signatures. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com
Re: Performance issues and strange logs
Having connected my code to the 1.5.7 code it is more than that. I think I may have reached into more internals for my implementation than I should have and that that is the primary problem. With that said, my initial tests with Mina 2.0.4 underneath 1.5.5 seem to be working. Is there anything I would want to look for that might not be obvious in that scenario? Thanks yet again, Craig On Thursday, October 13, 2011, Emmanuel Lécharny wrote: On 10/13/11 11:01 PM, Craig Setera wrote: I appreciate the offer. Unfortunately, it is quite a lot of code. I'm going to try a new version of MINA inside of 1.5.5 and see what happens. Just the method's signature, not the code. If there is some issue with 1.5.7, it will be around the signatures. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com
Re: Performance issues and strange logs
On 10/13/11 11:22 PM, Craig Setera wrote: Having connected my code to the 1.5.7 code it is more than that. I think I may have reached into more internals for my implementation than I should have and that that is the primary problem. With that said, my initial tests with Mina 2.0.4 underneath 1.5.5 seem to be working. Is there anything I would want to look for that might not be obvious in that scenario? Not that much. May be compare the LdapServer class, we may have changed the way we have initialized the MINA layer there (the startNetwork method, from the top of my head). -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com
Performance issues and strange logs
Hello, Last week I was asking about indexing and performance gains from those indexes. The question stemmed from some performance problems that we are currently having in our environment. In that environment, we are seeing extremely poor performance and Apache DS getting bogged down after a relatively small number of connections (under 100). When that happens, the connections start to stack up and eventually time out. I was surprised by the performance, but was looking at things like indexing and disabling sync on write as ways to improve the situation. Now, I've received some logs from testing and I'm beginning to wonder if there is something else going on. I'm seeing many entries in the logs that look like: [18:27:52] WARN [org.apache.directory.server.ldap.LdapSession] - AbandonableRequest with messageId 2 not found in outstandingRequests. [18:27:53] WARN [org.apache.directory.shared.asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. [18:27:53] WARN [org.apache.directory.shared.asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. [18:27:53] WARN [org.apache.directory.server.ldap.LdapSession] - AbandonableRequest with messageId 2 not found in outstandingRequests. [18:27:53] WARN [org.apache.directory.shared.asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. [18:27:53] WARN [org.apache.directory.shared.asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. I'm beginning to wonder if there is something else going on here that isn't purely about performance... something that is causing the server to freak out a bit and stack up the connections. Can anyone offer any insights into what these errors might mean and if they might be contributing to performance issues? Thanks, Craig -- Craig Setera Director, Product Engineering mFoundry p 415.324.5801 cr...@mfoundry.com
Re: Performance issues and strange logs
On 10/12/11 10:24 PM, Craig Setera wrote: Hello, Hi, which ADS version are you using ? Is it still 1.5.5 ? Last week I was asking about indexing and performance gains from those indexes. The question stemmed from some performance problems that we are currently having in our environment. In that environment, we are seeing extremely poor performance and Apache DS getting bogged down after a relatively small number of connections (under 100). When that happens, the connections start to stack up and eventually time out. I was surprised by the performance, but was looking at things like indexing and disabling sync on write as ways to improve the situation. Now, I've received some logs from testing and I'm beginning to wonder if there is something else going on. I'm seeing many entries in the logs that look like: [18:27:52] WARN [org.apache.directory.server.ldap.LdapSession] - AbandonableRequest with messageId 2 not found in outstandingRequests. [18:27:53] WARN [org.apache.directory.shared.asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. [18:27:53] WARN [org.apache.directory.shared.asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. [18:27:53] WARN [org.apache.directory.server.ldap.LdapSession] - AbandonableRequest with messageId 2 not found in outstandingRequests. [18:27:53] WARN [org.apache.directory.shared.asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. [18:27:53] WARN [org.apache.directory.shared.asn1.ber.Asn1Decoder] - The PDU has been fully decoded but there are still bytes in the buffer. This message just means that some data has been received, decoded correctly, but we have still some remaining bytes in the buffer. It's a warning, not an error. The remaining bytes will be decoded later. Nothing to be scared about. -- Regards, Cordialement, Emmanuel Lécharny www.iktek.com
