Locking While Placing Orders 12.04/13.07

[darrell73s]

Hi folks,

I'm having an issue when placing multiple orders around the same time as each other. To closely mimic my actual business process, I'm placing an order for 1 configurable good, and since I'm using demo data, I'm using the small PIZZA. This creates a production run after the order is placed.

I've configured jMeter to place orders in the ecommerce store for DemoCustomer which consist of a small PIZZA (quantity 1), and have configured 10 worker threads (to simulate users) placing this order (I can make the jMeter test available if desired). Within seconds of the first orders being placed, I see locks on the InventoryItem entity (and occasionally ProductCalculatedInfo), however these locks continue to build up and never seem to release. This results in either none, or very few users being able to place orders. Even after waiting for 2 minutes, the locks are not released, and the users continue to wait. Ultimately, I've found that I need to restart postgreSQL and OFBiz in order to clear the locks, and get to a state where orders can be placed again.

Interestingly, I've been able to trigger this behavior on 12.04.02, 12.04.05, and 13.07. I also tested this out using the OOTB derby instance also, and while I don't have a way to examine the locks explicitly, I was seeing results in jMeter which aligned with what I was seeing when the locks were occurring in PostgreSQL.

With my setup, all of my configurations are default, out of the box unless noted otherwise:
 - out of box 12.04.02, 12.04.05, 13.07 instances loaded with demo data (connection pool min pool size: 2, max pool size: 250)
 - postgreSQL 9.3 with default configuration; increased max connections from 100 to 1000

I'm wondering if any of you have run into this issue before, or have any tips on how this could be addressed.
 
Thanks!

[Mike Z]

Download "pgtune", run it against your postgresql configuration file, and
make the recommended adjustments.  Ofbiz has over 800 tables which is not
supported well by defaults.

On Wed, Oct 1, 2014 at 2:30 PM, darrell73s <[hidden email]> wrote:

> Hi folks,
>
> I'm having an issue when placing multiple orders around the same time as
> each other. To closely mimic my actual business process, I'm placing an
> order for 1 configurable good, and since I'm using demo data, I'm using the
> small PIZZA. This creates a production run after the order is placed.
>
> I've configured jMeter to place orders in the ecommerce store for
> DemoCustomer which consist of a small PIZZA (quantity 1), and have
> configured 10 worker threads (to simulate users) placing this order (I can
> make the jMeter test available if desired). Within seconds of the first
> orders being placed, I see locks on the InventoryItem entity (and
> occasionally ProductCalculatedInfo), however these locks continue to build
> up and never seem to release. This results in either none, or very few
> users
> being able to place orders. Even after waiting for 2 minutes, the locks are
> not released, and the users continue to wait. Ultimately, I've found that I
> need to restart postgreSQL and OFBiz in order to clear the locks, and get
> to
> a state where orders can be placed again.
>
> Interestingly, I've been able to trigger this behavior on 12.04.02,
> 12.04.05, and 13.07. I also tested this out using the OOTB derby instance
> also, and while I don't have a way to examine the locks explicitly, I was
> seeing results in jMeter which aligned with what I was seeing when the
> locks
> were occurring in PostgreSQL.
>
> With my setup, all of my configurations are default, out of the box unless
> noted otherwise:
>  - out of box 12.04.02, 12.04.05, 13.07 instances loaded with demo data
> (connection pool min pool size: 2, max pool size: 250)
>  - postgreSQL 9.3 with default configuration; increased max connections
> from
> 100 to 1000
>
> I'm wondering if any of you have run into this issue before, or have any
> tips on how this could be addressed.
>
> Thanks!
>
>
>
> --
> View this message in context:
> http://ofbiz.135035.n4.nabble.com/Locking-While-Placing-Orders-12-04-13-07-tp4656365.html
> Sent from the OFBiz - User mailing list archive at Nabble.com.
>

[Jacopo Cappellato-4]

Hi,

I *may* have a solution for this, because yesterday I was able to recreate a similar issue and fix it.
If you are available to do some tests with me let me know and I will share the details of the fix that I am testing at the moment.

Jacopo



On Oct 1, 2014, at 11:30 PM, darrell73s <[hidden email]> wrote:

> Hi folks,
>
> I'm having an issue when placing multiple orders around the same time as
> each other. To closely mimic my actual business process, I'm placing an
> order for 1 configurable good, and since I'm using demo data, I'm using the
> small PIZZA. This creates a production run after the order is placed.
>
> I've configured jMeter to place orders in the ecommerce store for
> DemoCustomer which consist of a small PIZZA (quantity 1), and have
> configured 10 worker threads (to simulate users) placing this order (I can
> make the jMeter test available if desired). Within seconds of the first
> orders being placed, I see locks on the InventoryItem entity (and
> occasionally ProductCalculatedInfo), however these locks continue to build
> up and never seem to release. This results in either none, or very few users
> being able to place orders. Even after waiting for 2 minutes, the locks are
> not released, and the users continue to wait. Ultimately, I've found that I
> need to restart postgreSQL and OFBiz in order to clear the locks, and get to
> a state where orders can be placed again.
>
> Interestingly, I've been able to trigger this behavior on 12.04.02,
> 12.04.05, and 13.07. I also tested this out using the OOTB derby instance
> also, and while I don't have a way to examine the locks explicitly, I was
> seeing results in jMeter which aligned with what I was seeing when the locks
> were occurring in PostgreSQL.
>
> With my setup, all of my configurations are default, out of the box unless
> noted otherwise:
> - out of box 12.04.02, 12.04.05, 13.07 instances loaded with demo data
> (connection pool min pool size: 2, max pool size: 250)
> - postgreSQL 9.3 with default configuration; increased max connections from
> 100 to 1000
>
> I'm wondering if any of you have run into this issue before, or have any
> tips on how this could be addressed.
>
> Thanks!
>
>
>
> --
> View this message in context: http://ofbiz.135035.n4.nabble.com/Locking-While-Placing-Orders-12-04-13-07-tp4656365.html
> Sent from the OFBiz - User mailing list archive at Nabble.com.

[darrell73s]

Thanks Mike, I was seeing similar behavior with Derby so I was thinking that the issue was database agnostic, but I will run pgTune on my instance to see what sorts of settings I can experiment with.

That's good to hear Jacopo, I'm available to do some testing, just let me know how I can help. The next place I was going to investigate was the fact that I'm using a configurable good vs. a finished good in my orders. In your testing, has this variable been a factor in producing the issue?

Thanks again,
Darrell

[Jacopo Cappellato-4]

Hi Darrell,

I have a bad news and a good news.
The bad news is that what you are experiencing is probably due to a limitation of the OFBiz inventory reservation engine: under heavy load there is a lot of db lock contention in the InventoryItem table especially if you are placing orders for the same product (that reserve the same inventory item). Unfortunately I don't have a fix for this issue but you could see if it is actually the problem you are facing by disabling inventory reservations (go to Catalog->Stores, select the store and set to No: Check Inventory, Require Inventory, Reserve Inventory, Balance Res On Order Creation): these settings should speed up your tests.
The good news is that yesterday I faced (running a JMeter load test on order creation) a Java deadlock, caused by FOP, and I was able to fix it (this can happen, under unlucky timing, when two OFBiz threads generate two order confirmation emails): if you see that you system hangs you can get a Java thread dump (let me know if you don't know how to get it) and this should tell you if you are having such a deadlock; for this issue I have a fix (I have patched the fop1.1 distribution) and I can send you the jar file if you want to give it a try (however fop1.1. works only for the 13.07 and the trunk, if my memory serves).

Jacopo

On Oct 2, 2014, at 4:30 PM, darrell73s <[hidden email]> wrote:

> Thanks Mike, I was seeing similar behavior with Derby so I was thinking that
> the issue was database agnostic, but I will run pgTune on my instance to see
> what sorts of settings I can experiment with.
>
> That's good to hear Jacopo, I'm available to do some testing, just let me
> know how I can help. The next place I was going to investigate was the fact
> that I'm using a configurable good vs. a finished good in my orders. In your
> testing, has this variable been a factor in producing the issue?
>
> Thanks again,
> Darrell
>
>
>
> --
> View this message in context: http://ofbiz.135035.n4.nabble.com/Locking-While-Placing-Orders-12-04-13-07-tp4656365p4656409.html
> Sent from the OFBiz - User mailing list archive at Nabble.com.

[darrell73s]

Hi Jacopo,

Thanks for the quick responses. I believe you hit the nail right on the head with the inventory recommendation! I turned the fields off which you mentioned and now there appears to be no issue inputting orders at the volume I mention above. Interestingly, I haven't come across the fop issue you mention but I'll keep that in mind in case I do.

In one of my applications, I actually discovered the "Balance Res On Order Creation" store option a few months ago which was causing some contention, and summarily disabled that option.

Out of the options you mentioned, the only ones set to "Y" in my applications are: "Check Inventory" and "Reserve Inventory". I don't have an issue tweaking these options, but just wanted to get a better idea as to the full impact of these two options, maybe you could quickly explain, or point me to some documentation on these options? I will also examine the code.

In the future, inventory will become a requirement, so I just don't want to put myself in a position where disabling these options will cause me to stop tracking certain data which will cause trouble down the road. Maybe this isn't an issue, but just wanted to throw that concern out there.
 
I currently also utilize the "quick ship" feature and wanted to confirm the impact on using that feature after making the change (I seem to remember some interaction between store inventory options and quick shipping).

I'm mainly concerned with the impact on existing orders that have gone into the system with the flags as they are now, and the potential impact of those flags on the "quick ship" feature that I'm also using.

Thanks!
Darrell

[darrell73s]

Jacopo, all,

I checked into the "quick ship" feature and confirmed my thought earlier: it appears that quick ship will not work without the store having the "Reserve Inventory" set to "Y".

As I mentioned previously, I'm using the PIZZA, a configurable good, which creates a Production Run on order creation. If I create ten sales orders for example, and run the production run associated to the order item in the 10th (last) order, a pizza is created, and put into inventory. The oldest order seems to be assigned to this inventory item.

This makes sense because when the production run is completed (via productionRunProduce) and the inventory item is created, "balanceInventoryItems" is called with the store's ReserveOrderEnumId set to "FIFO Received". However, I see that 'priorityOrderId' and 'priorityOrderItemSeqId' is being passed to balanceInventoryItems also (and have confirmed that the fields are populated), so I'm wondering why the orderId/orderItemSeqId which is passed isn't receiving priority on the inventory item being produced?

Hopefully you can shed some light on that for me

Thanks,
Darrell

[Jacopo Cappellato-4]

Hi Darrell,

sorry for the late response, please see inline:

On Oct 6, 2014, at 4:20 PM, darrell73s <[hidden email]> wrote:

> Jacopo, all,
>
> I checked into the "quick ship" feature and confirmed my thought earlier: it
> appears that quick ship will not work without the store having the "Reserve
> Inventory" set to "Y".

Yes, reservations are definitely needed if you have to manage the warehouse (reserve, pick, pack, ship).
I have asked you to disable the flag just to confirm that the bottleneck was the db lock contention on the InventoryItem records.
Unfortunately there is not an easy fix for this issue that shows up when you have medium-high traffic (caused by concurrent order creation/reservations and picking/packing) over the same inventory items.
Scott and I discussed some possible solutions for this issue, but they will require some rather complex refactoring of the inventory reservation logic; in my opinion this is something we should tackle because it will help to scale OFBiz much more than it is possible now, but I doubt it will happen today or tomorrow.
However, now that we know where the bottleneck is, there are a few things you can do to alleviate this issue.
For example you can create several inventory items for the same product; you can easily do this using Facility->Receive Product (every time you receive products a new inventory item is created).
For example, if in your load tests you want to place orders for 10000 units of WG-1111 then, instead of receiving in one shot 10000 units you could perform the receive process 10 or 100 times (generating 10 or 100 inventory items with a quantity on hand of 1000 or 100 units each); please consider that if you do not receive anything, the first time you place an order the system will create one inventory item and then will use it for all the orders, causing the db lock contention issues.

>
> As I mentioned previously, I'm using the PIZZA, a configurable good, which
> creates a Production Run on order creation. If I create ten sales orders for
> example, and run the production run associated to the order item in the 10th
> (last) order, a pizza is created, and put into inventory. The oldest order
> seems to be assigned to this inventory item.
>
> This makes sense because when the production run is completed (via
> productionRunProduce) and the inventory item is created,
> "balanceInventoryItems" is called with the store's ReserveOrderEnumId set to
> "FIFO Received". However, I see that 'priorityOrderId' and
> 'priorityOrderItemSeqId' is being passed to balanceInventoryItems also (and
> have confirmed that the fields are populated), so I'm wondering why the
> orderId/orderItemSeqId which is passed isn't receiving priority on the
> inventory item being produced?

This sounds like an issue and we will have to check the code, there may be a bug; did you try to disable/enable balanceInventoryItems?

Regards,

Jacopo

>
> Hopefully you can shed some light on that for me
>
> Thanks,
> Darrell
>
>
>
> --
> View this message in context: http://ofbiz.135035.n4.nabble.com/Locking-While-Placing-Orders-12-04-13-07-tp4656365p4656554.html
> Sent from the OFBiz - User mailing list archive at Nabble.com.

[Jacques Le Roux]

Le 07/10/2014 07:10, Jacopo Cappellato a écrit :

> Hi Darrell,
>
> sorry for the late response, please see inline:
>
> On Oct 6, 2014, at 4:20 PM, darrell73s <[hidden email]> wrote:
>
>> Jacopo, all,
>>
>> I checked into the "quick ship" feature and confirmed my thought earlier: it
>> appears that quick ship will not work without the store having the "Reserve
>> Inventory" set to "Y".
> Yes, reservations are definitely needed if you have to manage the warehouse (reserve, pick, pack, ship).
> I have asked you to disable the flag just to confirm that the bottleneck was the db lock contention on the InventoryItem records.
> Unfortunately there is not an easy fix for this issue that shows up when you have medium-high traffic (caused by concurrent order creation/reservations and picking/packing) over the same inventory items.
> Scott and I discussed some possible solutions for this issue, but they will require some rather complex refactoring of the inventory reservation logic; in my opinion this is something we should tackle because it will help to scale OFBiz much more than it is possible now, but I doubt it will happen today or tomorrow.

I think I will be interested to participate at this effort, if we can coordinate it somehow

Jacques

> However, now that we know where the bottleneck is, there are a few things you can do to alleviate this issue.
> For example you can create several inventory items for the same product; you can easily do this using Facility->Receive Product (every time you receive products a new inventory item is created).
> For example, if in your load tests you want to place orders for 10000 units of WG-1111 then, instead of receiving in one shot 10000 units you could perform the receive process 10 or 100 times (generating 10 or 100 inventory items with a quantity on hand of 1000 or 100 units each); please consider that if you do not receive anything, the first time you place an order the system will create one inventory item and then will use it for all the orders, causing the db lock contention issues.
>
>> As I mentioned previously, I'm using the PIZZA, a configurable good, which
>> creates a Production Run on order creation. If I create ten sales orders for
>> example, and run the production run associated to the order item in the 10th
>> (last) order, a pizza is created, and put into inventory. The oldest order
>> seems to be assigned to this inventory item.
>>
>> This makes sense because when the production run is completed (via
>> productionRunProduce) and the inventory item is created,
>> "balanceInventoryItems" is called with the store's ReserveOrderEnumId set to
>> "FIFO Received". However, I see that 'priorityOrderId' and
>> 'priorityOrderItemSeqId' is being passed to balanceInventoryItems also (and
>> have confirmed that the fields are populated), so I'm wondering why the
>> orderId/orderItemSeqId which is passed isn't receiving priority on the
>> inventory item being produced?
> This sounds like an issue and we will have to check the code, there may be a bug; did you try to disable/enable balanceInventoryItems?
>
> Regards,
>
> Jacopo
>
>> Hopefully you can shed some light on that for me
>>
>> Thanks,
>> Darrell
>>
>>
>>
>> --
>> View this message in context: http://ofbiz.135035.n4.nabble.com/Locking-While-Placing-Orders-12-04-13-07-tp4656365p4656554.html
>> Sent from the OFBiz - User mailing list archive at Nabble.com.
>
>

[Jacopo Cappellato-4]

On Oct 2, 2014, at 5:13 PM, Jacopo Cappellato <[hidden email]> wrote:

> The good news is that yesterday I faced (running a JMeter load test on order creation) a Java deadlock, caused by FOP, and I was able to fix it (this can happen, under unlucky timing, when two OFBiz threads generate two order confirmation emails): if you see that you system hangs you can get a Java thread dump (let me know if you don't know how to get it) and this should tell you if you are having such a deadlock; for this issue I have a fix (I have patched the fop1.1 distribution) and I can send you the jar file if you want to give it a try (however fop1.1. works only for the 13.07 and the trunk, if my memory serves).

A small update on the deadlock issue that can happen in Freemarker; the fix that I have proposed to the FOP community has been committed to the FOP trunk:

https://issues.apache.org/jira/browse/FOP-2157

This fix will be included in the next FOP release (2.0): unfortunately the release date is still not set but in the meantime you can apply the patches included in the Jira ticket and build a FOP jar locally.

Jacopo

[darrell73s]

Apologies for reviving such an old thread, but I've been monitoring one of my systems, and have some new information on this...

Thanks for that Jacopo, I read the issue you posted in the FOP JIRA, and my thread dump doesn't appear to show any indications of FOP being an issue.

However, I was doing some more thorough checking of my thread dump taken the last time a similar type of issue occurred in my system. Using the PostgreSQL monitoring tool, I can see multiple transactions waiting for the ProductCalculatedInfo table with one connection in "idle in transaction" state.

Thread dump confirms that they are all waiting during order creation, when the "countProductQuantityOrdered" service is called and is trying to perform the update.

A quick search showed this JIRA issue: https://issues.apache.org/jira/browse/OFBIZ-5065 which indicates that the poster experienced deadlock on ProductCalculatedInfo when invoking the 'storeOrder' service. Workaround is said to be to add "require-new-transaction=true" to the service definition. I noticed that this service is there in 13.07 (with same definition as in 12.04), but the service does not appear to exist in the trunk version of ofbiz. Because the issue presents itself seemingly randomly (no issue for 2 weeks, or sometimes only a day) my thought was that it could be a timing issue of some sort.

I wanted to get a sense of whether or not anyone other than the reporter has run into this issue, and if it was able to be solved other than to use the posted workaround -- as, from my understanding, creating a new transaction runs the risk of incorrect product counts (i.e. higher than actual) should the parent transaction be rolled back for some reason after the new transaction is committed. I'll defer to you folks for confirmation on this however.

Thanks!
Darrell

[Jacopo Cappellato-4]

Hi Darrell,

thanks for the further information, I am sure that it will be useful to others and I am sure you are not the only one experiencing this.
I don't have a solution but I have posted some comments to the Jira ticket you have mentioned in your last mail (OFBIZ-5065).

Jacopo

On Jan 20, 2015, at 10:28 AM, darrell73s <[hidden email]> wrote:

> Apologies for reviving such an old thread, but I've been monitoring one of my
> systems, and have some new information on this...
>
> Thanks for that Jacopo, I read the issue you posted in the FOP JIRA, and my
> thread dump doesn't appear to show any indications of FOP being an issue.
>
> However, I was doing some more thorough checking of my thread dump taken the
> last time a similar type of issue occurred in my system. Using the
> PostgreSQL monitoring tool, I can see multiple transactions waiting for the
> ProductCalculatedInfo table with one connection in "idle in transaction"
> state.
>
> Thread dump confirms that they are all waiting during order creation, when
> the "countProductQuantityOrdered" service is called and is trying to perform
> the update.
>
> A quick search showed this JIRA issue:
> https://issues.apache.org/jira/browse/OFBIZ-5065 which indicates that the
> poster experienced deadlock on ProductCalculatedInfo when invoking the
> 'storeOrder' service. Workaround is said to be to add
> "require-new-transaction=true" to the service definition. I noticed that
> this service is there in 13.07 (with same definition as in 12.04), but the
> service does not appear to exist in the trunk version of ofbiz. Because the
> issue presents itself seemingly randomly (no issue for 2 weeks, or sometimes
> only a day) my thought was that it could be a timing issue of some sort.
>
> I wanted to get a sense of whether or not anyone other than the reporter has
> run into this issue, and if it was able to be solved other than to use the
> posted workaround -- as, from my understanding, creating a new transaction
> runs the risk of incorrect product counts (i.e. higher than actual) should
> the parent transaction be rolled back for some reason after the new
> transaction is committed. I'll defer to you folks for confirmation on this
> however.
>
> Thanks!
> Darrell
>
>
>
> --
> View this message in context: http://ofbiz.135035.n4.nabble.com/Locking-While-Placing-Orders-12-04-13-07-tp4656365p4662053.html
> Sent from the OFBiz - User mailing list archive at Nabble.com.

[Jacques Le Roux]

I believe the best answer to this issue is Scott's
http://mail-archives.apache.org/mod_mbox/ofbiz-dev/201410.mbox/%3C0DF5FBE0-BA9F-43BF-AF93-33B0F84608C8@...%3E

Jacques

Le 20/01/2015 10:28, darrell73s a écrit :

> Apologies for reviving such an old thread, but I've been monitoring one of my
> systems, and have some new information on this...
>
> Thanks for that Jacopo, I read the issue you posted in the FOP JIRA, and my
> thread dump doesn't appear to show any indications of FOP being an issue.
>
> However, I was doing some more thorough checking of my thread dump taken the
> last time a similar type of issue occurred in my system. Using the
> PostgreSQL monitoring tool, I can see multiple transactions waiting for the
> ProductCalculatedInfo table with one connection in "idle in transaction"
> state.
>
> Thread dump confirms that they are all waiting during order creation, when
> the "countProductQuantityOrdered" service is called and is trying to perform
> the update.
>
> A quick search showed this JIRA issue:
> https://issues.apache.org/jira/browse/OFBIZ-5065 which indicates that the
> poster experienced deadlock on ProductCalculatedInfo when invoking the
> 'storeOrder' service. Workaround is said to be to add
> "require-new-transaction=true" to the service definition. I noticed that
> this service is there in 13.07 (with same definition as in 12.04), but the
> service does not appear to exist in the trunk version of ofbiz. Because the
> issue presents itself seemingly randomly (no issue for 2 weeks, or sometimes
> only a day) my thought was that it could be a timing issue of some sort.
>
> I wanted to get a sense of whether or not anyone other than the reporter has
> run into this issue, and if it was able to be solved other than to use the
> posted workaround -- as, from my understanding, creating a new transaction
> runs the risk of incorrect product counts (i.e. higher than actual) should
> the parent transaction be rolled back for some reason after the new
> transaction is committed. I'll defer to you folks for confirmation on this
> however.
>
> Thanks!
> Darrell
>
>
>
> --
> View this message in context: http://ofbiz.135035.n4.nabble.com/Locking-While-Placing-Orders-12-04-13-07-tp4656365p4662053.html
> Sent from the OFBiz - User mailing list archive at Nabble.com.
>

[darrell73s]

Thanks Jacopo and Jacques...

Because this happens intermittently in my system, I would suspect a timing-related scenario in line with what Scott mentions in his mail. I will continue to monitor my system, and if the problem presents itself again, and I'm able to isolate the issue to the count service (potentially by temporarily disabling the service) I will report back with the results.

Thanks!
Darrell

Jacques Le Roux wrote

I believe the best answer to this issue is Scott's
<a href="http://mail-archives.apache.org/mod_mbox/ofbiz-dev/201410.mbox/%">http://mail-archives.apache.org/mod_mbox/ofbiz-dev/201410.mbox/%[hidden email]%3E

Jacques