Hello Vipin, Can you please check CheckoutEvents.createOrder() is setting orderId in request attribute on *checkOutHelper.createOrder* success. It seems that orderId is null for some reason in request attribute that end up with error *Problems getting order header. Cannot check external gateways*.
Kind Regards, Ankush Upadhyay Senior Technical Consultant *HotWax Systems* *Enterprise open source experts* cell: +91-8109201285 office: 0731-409-3684 http://www.hotwaxsystems.com On Tue, Dec 31, 2019 at 10:58 AM vipin nirwal <[email protected]> wrote: > Hi Jacques, > > Thanks for the pointer. > I will try to check by putting more debug log. Will let you know if there > is any finding which could be helpful. > > BR// > Vipin Nirwal > > On Mon, Dec 30, 2019 at 1:55 PM Jacques Le Roux < > [email protected]> wrote: > > > I guess you noticed the 1st issue: > > > > 2019-12-23 16:22:24,850 |sse-nio-8443-exec-20 > > |ServiceUtil |E| {errorMessage=Problems getting order > > header. Cannot check external > > gateways!:WSCO10034, responseMessage=error} > > > > I guess this is the error which starts the time-out. > > > > Check CheckOutHelper::checkExternalPayment, it can be 2 types of errors: > > > > * Not able to retrieve the OrderHeader (weird) > > * Able to retrieve the OrderHeader but another error occurs then > > > > Debug by adding log statement in CheckOutHelper::checkExternalPayment... > > > > HTH > > > > Jacques > > > > > > Le 23/12/2019 à 17:42, vipin nirwal a écrit : > > > Hi Jacques, > > > > > > I forwarded you the wrong logs. I had these error when i put shipping > > address country as India but when i changed it to USA then there were no > > > errors. Thanks for your suggestion. > > > I am attaching the correct logs. It is showing transaction time out. > But > > i am not able to figure out the reason of time out. > > > > > > On Mon, Dec 23, 2019 at 3:48 PM Jacques Le Roux < > > [email protected] <mailto:[email protected]>> > wrote: > > > > > > Hi Vipin, > > > > > > If you look at the error.log it's crystal clear: > > > > > > 2019-12-23 05:57:38,307 |sse-nio-8443-exec-21 > > |TransactionUtil |E| [TransactionUtil.rollback] > > > java.lang.Exception: Stack Trace > > > at > > > org.apache.ofbiz.entity.transaction.TransactionUtil.rollback(TransactionUtil.java:314) > > [ofbiz.jar:?] > > > at > > > org.apache.ofbiz.entity.transaction.TransactionUtil.rollback(TransactionUtil.java:290) > > [ofbiz.jar:?] > > > at > > > org.apache.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:559) > > [ofbiz.jar:?] > > > at > > > org.apache.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:240) > > [ofbiz.jar:?] > > > at > > > org.apache.ofbiz.service.GenericDispatcherFactory$GenericDispatcher.runSync(GenericDispatcherFactory.java:103) > > [ofbiz.jar:?] > > > at > > > org.apache.ofbiz.order.shoppingcart.shipping.ShippingEvents.getExternalShipEstimate(ShippingEvents.java:354) > > [ofbiz.jar:?] > > > at > > > org.apache.ofbiz.order.shoppingcart.shipping.ShippingEvents.getShipGroupEstimate(ShippingEvents.java:238) > > [ofbiz.jar:?] > > > at > > > org.apache.ofbiz.order.shoppingcart.shipping.ShippingEstimateWrapper.loadEstimates(ShippingEstimateWrapper.java:119) > > [ofbiz.jar:?] > > > at > > > org.apache.ofbiz.order.shoppingcart.shipping.ShippingEstimateWrapper.<init>(ShippingEstimateWrapper.java:96) > > [ofbiz.jar:?] > > > [....] > > > 2019-12-23 05:57:38,308 |sse-nio-8443-exec-21 > > |ShippingEvents |E| Error getting external shipment cost > > estimate: Rate inquiry is > > > only > > > valid for US destinations. > > > 2019-12-23 05:57:38,308 |sse-nio-8443-exec-21 > > |ServiceUtil |E| {errorMessage=A problem occurred > > calculating shipping. Fees > > > will be > > > calculated offline., responseMessage=error} > > > 2019-12-23 05:57:38,310 |sse-nio-8443-exec-21 > > |ServiceUtil |E| {errorMessage=Rate inquiry is only > valid > > for US destinations., > > > responseMessage=error} > > > 2019-12-23 05:57:38,310 |sse-nio-8443-exec-21 > > |ServiceDispatcher |E| Error in Service [uspsRateInquire]: > Rate > > inquiry is only valid > > > for US > > > destinations. > > > 2019-12-23 05:57:38,310 |sse-nio-8443-exec-21 > > |TransactionUtil |E| [TransactionUtil.rollback] > > > [....] > > > > > > You get this error multiple times (72 exactly) it cumulates and the > > DB can't handle it. > > > > > > You need 1st to fix this issue. I suggest you use no external > > shipment cost estimates for you profiling > > > > > > Jacques > > > > > > Le 23/12/2019 à 07:32, vipin nirwal a écrit : > > > > Hi Jacques, > > > > > > > > Attaching the logs. > > > > I restarted the postgres DB and submit order was quick for both > > products. But as i am testing again and again, GZ-2644 is going with same > > > > latency(very quick, 2-3 sec). But WG-5569 starts taking time in > > submit order slowly and eventually will start failing. > > > > > > > > I am comparing both products and trying to see if any difference > > that is causing this issue. > > > > > > > > BR// > > > > Vipin Nirwal > > > > > > > > > > > > > > > > On Sat, Dec 21, 2019 at 6:36 PM Jacques Le Roux < > > [email protected] <mailto:[email protected]> > > > <mailto:[email protected] <mailto: > > [email protected]>>> wrote: > > > > > > > > Hi Wipin, > > > > > > > > One thing we know now is that the issue is related to > > "WG-5569". That's an interesting point. Unfortunately I did not find > > query_lock.txt very > > > > useful. > > > > > > > > As it could be a lot of things, I think a look at the log is > > needed. It would help if you could extract relevant parts... I mean those > > > related with > > > > the lock and a bit around... > > > > > > > > Thanks > > > > > > > > Jacques > > > > > > > > Le 20/12/2019 à 15:19, vipin nirwal a écrit : > > > > > Hi Jacques/Humera, > > > > > > > > > > Thanks for your support. > > > > > > > > > > When I ran flow with a different product, I did not see any > > latency in submit order. See attached jmeter log. > > > > > > > > > > But when I am running flow with product id “WG-5569’, I am > > getting latency while submitting order. See attached txt file for query > > which is > > > > taking > > > > > exclusive lock. > > > > > Any pointer/hint why this is happening, is really > > appreciable. > > > > > > > > > > BR// > > > > > Vipin Nirwal > > > > > > > > > > On Fri, Dec 20, 2019 at 2:23 PM vipin nirwal < > > [email protected] <mailto:[email protected]> <mailto: > > [email protected] > > > <mailto:[email protected]>> <mailto:[email protected] > <mailto: > > [email protected]> > > > > <mailto:[email protected] <mailto:[email protected] > >>>> > > wrote: > > > > > > > > > > Hi Jacques, > > > > > > > > > > I am using 18.12 release. > > > > > > > > > > BR// > > > > > Vipin Nirwal > > > > > > > > > > On Fri, Dec 20, 2019 at 2:07 PM Jacques Le Roux < > > [email protected] <mailto:[email protected]> > > > <mailto:[email protected] <mailto: > > [email protected]>> > > > > <mailto:[email protected] <mailto: > > [email protected]> <mailto:[email protected] > > > <mailto:[email protected]>>>> wrote: > > > > > > > > > > Hi Vipin, > > > > > > > > > > Since, AFAIK, we did not ask yet and that's pretty > > needed as this stage, which version are you using? > > > > > > > > > > Thanks > > > > > > > > > > Jacques > > > > > > > > > > Le 20/12/2019 à 07:53, vipin nirwal a écrit : > > > > > > Hi Humera, > > > > > > > > > > > > Thanks for your reply. > > > > > > > > > > > > I compared both HTTP request and did not find > any > > difference. Seems ok to > > > > > > me. When i am running concurrent user from jmeter > > (only 5 threads) and same > > > > > > time, i am trying to submit order from UI, its > > taking around 30-40 sec or > > > > > > even more from UI too. > > > > > > > > > > > > I logged the queries which are taking longer in > > postgres and found this > > > > > > query every time. But when i am doing explain on > > this query then its very > > > > > > quickly updating. > > > > > > > > > > > > 2019-12-20 06:41:12.772 UTC [13411] LOG: > duration: > > 96233.642 ms execute > > > > > > <unnamed>: UPDATE public.PRODUCT_CALCULATED_INFO > > SET > > > > > > TOTAL_QUANTITY_ORDERED=$1, TOTAL_TIMES_VIEWED=$2, > > > > > > AVERAGE_CUSTOMER_RATING=$3, > LAST_UPDATED_STAMP=$4, > > > > > > LAST_UPDATED_TX_STAMP=$5, CREATED_STAMP=$6, > > CREATED_TX_STAMP=$7 WHERE > > > > > > PRODUCT_ID=$8 > > > > > > 2019-12-20 06:41:12.772 UTC [13411] DETAIL: > > parameters: $1 = '84.000000', > > > > > > $2 = NULL, $3 = NULL, $4 = '2019-12-20 > > 06:39:36.537+00', $5 = '2019-12-20 > > > > > > 06:39:36.527+00', $6 = '2019-12-18 > > 12:33:35.924+00', $7 = '2019-12-18 > > > > > > 12:33:35.901+00', $8 = 'WG-5569' > > > > > > 2019-12-20 06:42:48.667 UTC [12179] LOG: > duration: > > 192255.312 ms execute > > > > > > <unnamed>: UPDATE public.PRODUCT_CALCULATED_INFO > > SET > > > > > > TOTAL_QUANTITY_ORDERED=$1, TOTAL_TIMES_VIEWED=$2, > > > > > > AVERAGE_CUSTOMER_RATING=$3, > LAST_UPDATED_STAMP=$4, > > > > > > LAST_UPDATED_TX_STAMP=$5, CREATED_STAMP=$6, > > CREATED_TX_STAMP=$7 WHERE > > > > > > PRODUCT_ID=$8 > > > > > > 2019-12-20 06:42:48.667 UTC [12179] DETAIL: > > parameters: $1 = '84.000000', > > > > > > $2 = NULL, $3 = NULL, $4 = '2019-12-20 > > 06:39:36.41+00', $5 = '2019-12-20 > > > > > > 06:39:36.403+00', $6 = '2019-12-18 > > 12:33:35.924+00', $7 = '2019-12-18 > > > > > > 12:33:35.901+00', $8 = 'WG-5569' > > > > > > 2019-12-20 06:43:36.832 UTC [12180] LOG: > duration: > > 240242.603 ms execute > > > > > > <unnamed>: UPDATE public.PRODUCT_CALCULATED_INFO > > SET > > > > > > TOTAL_QUANTITY_ORDERED=$1, TOTAL_TIMES_VIEWED=$2, > > > > > > AVERAGE_CUSTOMER_RATING=$3, > LAST_UPDATED_STAMP=$4, > > > > > > LAST_UPDATED_TX_STAMP=$5, CREATED_STAMP=$6, > > CREATED_TX_STAMP=$7 WHERE > > > > > > PRODUCT_ID=$8 > > > > > > 2019-12-20 06:43:36.832 UTC [12180] DETAIL: > > parameters: $1 = '84.000000', > > > > > > $2 = NULL, $3 = NULL, $4 = '2019-12-20 > > 06:39:36.588+00', $5 = '2019-12-20 > > > > > > 06:39:36.582+00', $6 = '2019-12-18 > > 12:33:35.924+00', $7 = '2019-12-18 > > > > > > 12:33:35.901+00', $8 = 'WG-5569' > > > > > > > > > > > > BR// > > > > > > Vipin Nirwal > > > > > > > > > > > > > > > > > > > > > > > > On Fri, Dec 20, 2019 at 10:38 AM Humera Khan < > > [email protected] <mailto:[email protected]> > > > <mailto:[email protected] <mailto: > > [email protected]>> > > > > <mailto:[email protected] <mailto: > > [email protected]> <mailto:[email protected] > > > <mailto:[email protected]>>>> > > > > > > wrote: > > > > > > > > > > > >> Hi Vipin, > > > > > >> > > > > > >> As per the attached JMeter result, status for > the > > submit_order request is a > > > > > >> warning. There may be an issue related to the > > cookie or any other request > > > > > >> header. Please compare the HTTP request of > JMeter > > with the request in > > > > > >> browser. > > > > > >> > > > > > >> HTH! > > > > > >> > > > > > >> Best Regards, > > > > > >> Humera Khan > > > > > >> > > > > > >> > > > > > >> On Thu, Dec 19, 2019 at 9:55 PM vipin nirwal < > > [email protected] <mailto:[email protected]> <mailto: > > [email protected] > > > <mailto:[email protected]>> <mailto:[email protected] > <mailto: > > [email protected]> > > > > <mailto:[email protected] <mailto:[email protected] > >>>> > > wrote: > > > > > >> > > > > > >>> Hi Jacques, > > > > > >>> > > > > > >>> Thanks for your response. > > > > > >>> I tried with out of the box derby DB too. I am > > trying with only 5 > > > > > >>> concurrent user but still submit order is > giving > > hard time to me. > > > > > >>> > > > > > >>> Looking at jmeter result, it seems submit order > > API is running in > > > > > >>> sequence. Taking longer time in each submit > > call. Attached is jmeter > > > > > >> result. > > > > > >>> I debug a bit more. CheckOutEvents.createOrder > > is taking longer time in > > > > > >>> execution. Due to this , we are not able to get > > OrderHeader in > > > > > >>> CheckOutHelper.checkExternalPayment method. > > Thats why i was getting above > > > > > >>> error. Is there any other setting i am missing? > > > > > >>> > > > > > >>> PS. If i am trying to submit order in UI, then > > its not taking more than > > > > > >> 10 > > > > > >>> sec. I tried to increase the transaction time > > out( you suggested in some > > > > > >>> thread , modify TransactionUtil class. Then all > > order were successful but > > > > > >>> again taking more time). > > > > > >>> I am trying this, if there will be any other > > finding, will update. > > > > > >>> > > > > > >>> BR// > > > > > >>> Vipin Nirwal > > > > > >>> > > > > > >>> On Thu, Dec 19, 2019 at 6:46 PM Jacques Le > Roux < > > > > > >>> [email protected] <mailto: > > [email protected]> <mailto:[email protected] > > > <mailto:[email protected]>> <mailto: > > [email protected] <mailto:[email protected]> > > > > <mailto:[email protected] <mailto: > > [email protected]>>>> wrote: > > > > > >>> > > > > > >>>> Hi Vipin, > > > > > >>>> > > > > > >>>> I can see only a reason: an issue to access > > your OFBiz database. I don't > > > > > >>>> remember such problems reported earlier. Maybe > > you are forcing too much > > > > > >>>> with > > > > > >>>> Jmeter and you get deadlocks in the DB. > > > > > >>>> > > > > > >>>> Jacques > > > > > >>>> > > > > > >>>> Le 18/12/2019 à 06:19, vipin nirwal a écrit : > > > > > >>>>> Hi, > > > > > >>>>> > > > > > >>>>> I am facing a weird issue. First submit order > > is taking longer like > > > > > >>>> 12-20sec . Afterwards each order takes quite > > longer to submit. If > > > > > >>>> processing time is being increased more than 1 > > minutes then all order > > > > > >> start > > > > > >>>> failing. I am getting below error message for > > failed order. > > > > > >>>>> <div id="content-messages" > > class="content-messages errorMessage" > > > > > >>>>> > > > > > >> > > > onclick="document.getElementById('content-messages').parentNode.removeChild(this)"> > > > > > >>>>> <p>The Following Errors Occurred:</p> > > > > > >>>>> <p>Problems getting order header. Cannot > > check external > > > > > >>>> gateways!</p> > > > > > >>>>> </div> > > > > > >>>>> > > > > > >>>>> This error is coming from > > CheckOutEvents.checkExternalPayment method. > > > > > >>>> Though few orders are submitted successfully. > > > > > >>>>> Please let me know if someone faced this > issue > > or any solution for > > > > > >>>> this. Is there any > > > > > >>>>> PS. I am using apache jmeter to submit order. > > > > > >>>>> > > > > > >>>>> BR// > > > > > >>>>> Vipin Nirwal > > > > > >>>>> > > > > > >>>>> > > > > > >>> > > > > > >>> -- > > > > > >>> Thanks & Regards > > > > > >>> Vipin Nirwal > > > > > >>> > > > > > > > > > > > > > > > > > > > > > > > > > > -- > > > > > Thanks & Regards > > > > > Vipin Nirwal > > > > > > > > > > > > > > > > > > > > -- > > > > > Thanks & Regards > > > > > Vipin Nirwal > > > > > > > > > > > > > > > > -- > > > > Thanks & Regards > > > > Vipin Nirwal > > > > > > > > > > > > -- > > > Thanks & Regards > > > Vipin Nirwal > > > > > -- > Thanks & Regards > Vipin Nirwal >
