Cancel item in order never ends ...

[Daniel Martínez-4]

When I try to cancel sales order items (service cancelOrderItem), my
browser waits forever for the server to answer. Ofbiz in the server
keeps eating up memory and process until I manually stop it (stopofbiz.sh)

This happens with both latest versions of trunk and release4 and with
both jdk-1.5 and jdk-1.6. I use local database connection to postgresql8.

The order item is a finished product with a requirement created and
approved for it (no PO created, no inventory received/sent)

I include the log since the call to cancelOrderItem (log is for release4
with jdk-1.6.0), I see incompatibilities between Double and BigDecimal
in the log.

2007-06-19 08:24:33,432 (http-0.0.0.0-8443-Processor4) [    
ControlServlet.java:90 :INFO ] The character encoding of the request is:
[null]. The character encoding we will use for the request and response
is: [UTF-8]
2007-06-19 08:24:33,437 (http-0.0.0.0-8443-Processor4) [    
ControlServlet.java:126:DEBUG] [[[cancelOrderItem] Servlet Starting,
doing setup- total:0.0,since last(Begin):0.0]]
2007-06-19 08:24:33,438 (http-0.0.0.0-8443-Processor4) [    
ControlServlet.java:181:DEBUG] [[[cancelOrderItem] Setup done, doing
Event(s) and View(s)- total:0.0010,since last([cancelOrderItem]...):0.0010]]
2007-06-19 08:24:33,445 (http-0.0.0.0-8443-Processor4) [    
RequestHandler.java:236:INFO ] [Processing Request]: cancelOrderItem
sessionId=CAEB1B2AEE00AE0B9458A2999EC69387.jvm1
2007-06-19 08:24:33,490 (http-0.0.0.0-8443-Processor4) [    
AbstractEngine.java:75 :INFO ] Loaded Service Locations :
[main-rmi=rmi://localhost:1099/RMIDispatcher,
main-http=http://localhost:8080/webtools/control/httpService,
entity-sync-rmi=rmi://localhost:1099/RMIDispatcher,
entity-sync-http=http://localhost:8080/webtools/control/httpService,
rita-rmi=rmi://localhost:1099/RMIDispatcher,
eedcc-test=http://localhost:8080/webtools/control/httpService]
2007-06-19 08:24:33,549 (http-0.0.0.0-8443-Processor4) [    
EntityEcaRule.java:111:INFO ] Running Entity ECA Service:
checkCreateOrderRequirement, triggered by rule on Entity: OrderItem
2007-06-19 08:24:33,654 (http-0.0.0.0-8443-Processor4) [          
UtilXml.java:243:DEBUG] XML Read 0.079s:
file:/paradiso/ofbiz/release4.0/applications/order/script/org/ofbiz/order/order/OrderServices.xml
2007-06-19 08:24:33,770 (http-0.0.0.0-8443-Processor4) [  
PrimaryKeyFinder.java:124:INFO ] Returning null because found incomplete
primary key in find: [GenericEntity:Product]
2007-06-19 08:24:33,782 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:459:DEBUG] Sync service
[entity-default/checkCreateOrderRequirement] finished in [229] milliseconds
2007-06-19 08:24:33,813 (http-0.0.0.0-8443-Processor4) [      
SequenceUtil.java:254:INFO ] Got bank of sequenced IDs for
[OrderStatus]; curSeqId=10080, maxSeqId=10090, bankSize=10
2007-06-19 08:24:33,814 (http-0.0.0.0-8443-Processor4)
[XAConnectionFactory.java:119:WARN ] no xares in rms for con
org.ofbiz.minerva.pool.jdbc.xa.wrapper.XAConnectionImpl@4abf053f
2007-06-19 08:24:33,825 (http-0.0.0.0-8443-Processor4) [    
EntityEcaRule.java:111:INFO ] Running Entity ECA Service:
checkCreateOrderRequirement, triggered by rule on Entity: OrderItem
2007-06-19 08:24:33,829 (http-0.0.0.0-8443-Processor4) [  
PrimaryKeyFinder.java:124:INFO ] Returning null because found incomplete
primary key in find: [GenericEntity:Product]
2007-06-19 08:24:33,838 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
cancelOrderInventoryReservation, triggered by rule on Service:
changeOrderItemStatus
2007-06-19 08:24:33,892 (http-0.0.0.0-8443-Processor4) [          
UtilXml.java:243:DEBUG] XML Read 0.05s:
file:/paradiso/ofbiz/release4.0/applications/product/script/org/ofbiz/product/inventory/InventoryReserveServices.xml
2007-06-19 08:24:33,966 (http-0.0.0.0-8443-Processor4) [          
UtilXml.java:243:DEBUG] XML Read 0.054s:
file:/paradiso/ofbiz/release4.0/applications/product/script/org/ofbiz/product/inventory/InventoryServices.xml
2007-06-19 08:24:33,994 (http-0.0.0.0-8443-Processor4) [    
EntityEcaRule.java:111:INFO ] Running Entity ECA Service:
updateInventoryItemFromDetail, triggered by rule on Entity:
InventoryItemDetail
2007-06-19 08:24:34,007 (http-0.0.0.0-8443-Processor4) [    
EntityEcaRule.java:111:INFO ] Running Entity ECA Service:
checkProductInventoryDiscontinuation, triggered by rule on Entity:
InventoryItem
2007-06-19 08:24:34,009 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:480:DEBUG] [[ASync service started...-
total:0.0,since last(Begin):0.0]] - 'entity-default /
checkProductInventoryDiscontinuation'
2007-06-19 08:24:34,013 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:571:DEBUG] [[ASync service finished...-
total:0.0040,since last(ASync service sta...):0.0040]] - 'entity-default
/ checkProductInventoryDiscontinuation'
2007-06-19 08:24:34,014 (http-0.0.0.0-8443-Processor4) [    
EntityEcaRule.java:111:INFO ] Running Entity ECA Service:
updateSerializedInventoryTotals, triggered by rule on Entity: InventoryItem
2007-06-19 08:24:34,017 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:459:DEBUG] Sync service
[order/createInventoryItemDetail] finished in [107] milliseconds
2007-06-19 08:24:34,063 (http-0.0.0.0-8443-Processor4) [      
SequenceUtil.java:254:INFO ] Got bank of sequenced IDs for
[EntitySyncRemove]; curSeqId=10100, maxSeqId=10110, bankSize=10
2007-06-19 08:24:34,066 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:459:DEBUG] Sync service
[order/cancelOrderItemShipGrpInvRes] finished in [163] milliseconds
2007-06-19 08:24:34,085 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:459:DEBUG] Sync service
[order/cancelOrderInventoryReservation] finished in [245] milliseconds
2007-06-19 08:24:34,086 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
recalcShippingTotal, triggered by rule on Service: changeOrderItemStatus
2007-06-19 08:24:34,102 (http-0.0.0.0-8443-Processor4) [        
UtilNumber.java:84 :WARN ] Could not set decimal rounding mode from
salestax.final.decimals=2. Using default mode of 2.
2007-06-19 08:24:34,116 (http-0.0.0.0-8443-Processor4) [    
OrderServices.java:1461:INFO ] No valid order items found - 0.000
2007-06-19 08:24:34,117 (http-0.0.0.0-8443-Processor4) [    
OrderServices.java:1468:INFO ] New Shipping Total [WS10000 / 00001] : 0.000
2007-06-19 08:24:34,123 (http-0.0.0.0-8443-Processor4) [    
OrderServices.java:1475:INFO ] Old Shipping Total [WS10000 / 00001] : 10.00
2007-06-19 08:24:34,126 (http-0.0.0.0-8443-Processor4) [      
SequenceUtil.java:254:INFO ] Got bank of sequenced IDs for
[OrderAdjustment]; curSeqId=10050, maxSeqId=10060, bankSize=10
2007-06-19 08:24:34,127 (http-0.0.0.0-8443-Processor4) [    
GenericEntity.java:386:WARN ] In entity field [OrderAdjustment.amount]
set the value passed in [java.math.BigDecimal] is not compatible with
the Java type of the field [Double]
2007-06-19 08:24:34,133 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
recalcTaxTotal, triggered by rule on Service: changeOrderItemStatus
2007-06-19 08:24:34,229 (http-0.0.0.0-8443-Processor4) [          
UtilXml.java:243:DEBUG] XML Read 0.042s:
file:/paradiso/ofbiz/release4.0/applications/order/script/org/ofbiz/order/order/OrderSimpleMethods.xml
2007-06-19 08:24:34,236 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
resetGrandTotal, triggered by rule on Service: createOrderAdjustment
2007-06-19 08:24:34,250 (http-0.0.0.0-8443-Processor4) [    
GenericEntity.java:386:WARN ] In entity field [OrderHeader.grandTotal]
set the value passed in [java.math.BigDecimal] is not compatible with
the Java type of the field [Double]
2007-06-19 08:24:34,251 (http-0.0.0.0-8443-Processor4) [    
GenericEntity.java:386:WARN ] In entity field
[OrderHeader.remainingSubTotal] set the value passed in
[java.math.BigDecimal] is not compatible with the Java type of the field
[Double]
2007-06-19 08:24:34,257 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:459:DEBUG] Sync service
[order/createOrderAdjustment] finished in [71] milliseconds
2007-06-19 08:24:34,258 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:459:DEBUG] Sync service [order/recalcTaxTotal]
finished in [124] milliseconds
2007-06-19 08:24:34,258 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
resetGrandTotal, triggered by rule on Service: changeOrderItemStatus
2007-06-19 08:24:34,270 (http-0.0.0.0-8443-Processor4) [    
GenericEntity.java:386:WARN ] In entity field [OrderHeader.grandTotal]
set the value passed in [java.math.BigDecimal] is not compatible with
the Java type of the field [Double]
2007-06-19 08:24:34,270 (http-0.0.0.0-8443-Processor4) [    
GenericEntity.java:386:WARN ] In entity field
[OrderHeader.remainingSubTotal] set the value passed in
[java.math.BigDecimal] is not compatible with the Java type of the field
[Double]
2007-06-19 08:24:34,277 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
checkOrderItemStatus, triggered by rule on Service: changeOrderItemStatus
2007-06-19 08:24:34,302 (http-0.0.0.0-8443-Processor4) [
OrderChangeHelper.java:348:INFO ] Aborting workflow for order WS10000
2007-06-19 08:24:34,305 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
releaseOrderPayments, triggered by rule on Service: changeOrderStatus
2007-06-19 08:24:34,324 (http-0.0.0.0-8443-Processor4)
[PaymentGatewayServices.java:676:WARN ] No OrderPaymentPreference
records available for release
2007-06-19 08:24:34,325 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:112:INFO ] Got false for condition:
[null][][statusId][equals][null][ORDER_COMPLETED][true][String][]
2007-06-19 08:24:34,326 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:112:INFO ] Got false for condition:
[null][][statusId][equals][null][ORDER_APPROVED][true][String][]
2007-06-19 08:24:34,327 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:112:INFO ] Got false for condition:
[null][][statusId][equals][null][ITEM_COMPLETED][true][String][]
2007-06-19 08:24:34,327 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:112:INFO ] Got false for condition:
[null][][statusId][equals][null][ITEM_APPROVED][true][String][]
2007-06-19 08:24:34,327 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:112:INFO ] Got false for condition:
[null][][statusId][equals][null][ITEM_APPROVED][true][String][]
2007-06-19 08:24:34,328 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:459:DEBUG] Sync service
[order/changeOrderItemStatus] finished in [540] milliseconds
2007-06-19 08:24:34,328 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
recreateOrderAdjustments, triggered by rule on Service: cancelOrderItem
2007-06-19 08:24:34,578 (http-0.0.0.0-8443-Processor4) [      
ShoppingCart.java:1422:INFO ] Returned new PaymentInfo - Pm: null /
PmType: EXT_OFFLINE / Amt: null / Ref: null!null
2007-06-19 08:24:34,579 (http-0.0.0.0-8443-Processor4)
[ShoppingCartServices.java:248:INFO ] Added Payment: EXT_OFFLINE / [no max]
2007-06-19 08:24:34,582 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:459:DEBUG] Sync service [order/loadCartFromOrder]
finished in [244] milliseconds
2007-06-19 08:24:34,594 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
resetGrandTotal, triggered by rule on Service: createOrderAdjustment
2007-06-19 08:24:34,606 (http-0.0.0.0-8443-Processor4) [    
GenericEntity.java:386:WARN ] In entity field [OrderHeader.grandTotal]
set the value passed in [java.math.BigDecimal] is not compatible with
the Java type of the field [Double]
2007-06-19 08:24:34,607 (http-0.0.0.0-8443-Processor4) [    
GenericEntity.java:386:WARN ] In entity field
[OrderHeader.remainingSubTotal] set the value passed in
[java.math.BigDecimal] is not compatible with the Java type of the field
[Double]
2007-06-19 08:24:34,611 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:459:DEBUG] Sync service
[order/recreateOrderAdjustments] finished in [282] milliseconds
2007-06-19 08:24:34,611 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
resetGrandTotal, triggered by rule on Service: cancelOrderItem
2007-06-19 08:24:34,623 (http-0.0.0.0-8443-Processor4) [    
GenericEntity.java:386:WARN ] In entity field [OrderHeader.grandTotal]
set the value passed in [java.math.BigDecimal] is not compatible with
the Java type of the field [Double]
2007-06-19 08:24:34,624 (http-0.0.0.0-8443-Processor4) [    
GenericEntity.java:386:WARN ] In entity field
[OrderHeader.remainingSubTotal] set the value passed in
[java.math.BigDecimal] is not compatible with the Java type of the field
[Double]
2007-06-19 08:24:34,627 (http-0.0.0.0-8443-Processor4) [    
ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
sendOrderChangeNotification, triggered by rule on Service: cancelOrderItem
2007-06-19 08:24:34,628 (http-0.0.0.0-8443-Processor4) [
ServiceDispatcher.java:480:DEBUG] [[ASync service started...-
total:0.0,since last(Begin):0.0]] - 'order / sendOrderChangeNotification'
2007-06-19 08:24:34,631 (http-0.0.0.0-8443-Processor4) [      
SequenceUtil.java:254:INFO ] Got bank of sequenced IDs for
[RuntimeData]; curSeqId=10090, maxSeqId=10100, bankSize=10
2007-06-19 08:24:34,638 (http-0.0.0.0-8443-Processor4) [      
SequenceUtil.java:254:INFO ] Got bank of sequenced IDs for [JobSandbox];
curSeqId=10100, maxSeqId=10110, bankSize=10
2007-06-19 08:24:34,714 (default-invoker-Thread-2) [        
JobInvoker.java:211:INFO ] Invoker: default-invoker-Thread-2 received
job -- 1182234274010 from poller - org.ofbiz.service.job.JobPoller@7444f787
2007-06-19 08:24:39,514
(org.ofbiz.service.jms.JmsListenerFactory@609903f4) [
JmsListenerFactory.java:73 :INFO ] JMS Listener Factory Thread Finished;
All listeners connected.
.....
  no more log from console.log, but browser keeps waiting, so I shutdown
ofbiz
.....
Received connection from - /127.0.0.1 : 35996
Shutdown initiated from: 127.0.0.1:35996
...
...
...
2007-06-19 08:25:51,804 (OFBiz_Shutdown_Hook) [  
ContainerLoader.java:93 :INFO ] Shutting down containers
2007-06-19 08:25:51,807 (OFBiz_Shutdown_Hook) [
CatalinaContainer.java:609:ERROR]
---- exception report
----------------------------------------------------------
Exception: org.apache.catalina.LifecycleException
Message: Embedded service has not yet been started
---- stack trace
---------------------------------------------------------------
LifecycleException:  Embedded service has not yet been started
org.apache.catalina.startup.Embedded.stop(Embedded.java:849)
org.ofbiz.catalina.container.CatalinaContainer.stop(CatalinaContainer.java:606)
org.ofbiz.base.container.ContainerLoader.unload(ContainerLoader.java:99)
org.ofbiz.base.start.Start.shutdownServer(Start.java:300)
org.ofbiz.base.start.Start.access$000(Start.java:43)
org.ofbiz.base.start.Start$1.run(Start.java:277)
--------------------------------------------------------------------------------

2007-06-19 08:25:51,808 (OFBiz_Shutdown_Hook) [
ServiceDispatcher.java:176:INFO ] De-Registering dispatcher: RMIDispatcher

-----

Thanks for your help,
--
Daniel

[Scott Gray]

Hi Daniel

Could you create a jira issue with clear steps to recreate the problem
preferably straight from seed data.  I'll take a look when I get a chance in
the next couple of days.

Thanks
Scott

On 19/06/07, Daniel Martínez <[hidden email]> wrote:

>
> When I try to cancel sales order items (service cancelOrderItem), my
> browser waits forever for the server to answer. Ofbiz in the server
> keeps eating up memory and process until I manually stop it (stopofbiz.sh)
>
> This happens with both latest versions of trunk and release4 and with
> both jdk-1.5 and jdk-1.6. I use local database connection to postgresql8.
>
> The order item is a finished product with a requirement created and
> approved for it (no PO created, no inventory received/sent)
>
> I include the log since the call to cancelOrderItem (log is for release4
> with jdk-1.6.0), I see incompatibilities between Double and BigDecimal
> in the log.
>
> 2007-06-19 08:24:33,432 (http-0.0.0.0-8443-Processor4) [
> ControlServlet.java:90 :INFO ] The character encoding of the request is:
> [null]. The character encoding we will use for the request and response
> is: [UTF-8]
> 2007-06-19 08:24:33,437 (http-0.0.0.0-8443-Processor4) [
> ControlServlet.java:126:DEBUG] [[[cancelOrderItem] Servlet Starting,
> doing setup- total:0.0,since last(Begin):0.0]]
> 2007-06-19 08:24:33,438 (http-0.0.0.0-8443-Processor4) [
> ControlServlet.java:181:DEBUG] [[[cancelOrderItem] Setup done, doing
> Event(s) and View(s)- total:0.0010,since last([cancelOrderItem]...):0.0010
> ]]
> 2007-06-19 08:24:33,445 (http-0.0.0.0-8443-Processor4) [
> RequestHandler.java:236:INFO ] [Processing Request]: cancelOrderItem
> sessionId=CAEB1B2AEE00AE0B9458A2999EC69387.jvm1
> 2007-06-19 08:24:33,490 (http-0.0.0.0-8443-Processor4) [
> AbstractEngine.java:75 :INFO ] Loaded Service Locations :
> [main-rmi=rmi://localhost:1099/RMIDispatcher,
> main-http=http://localhost:8080/webtools/control/httpService,
> entity-sync-rmi=rmi://localhost:1099/RMIDispatcher,
> entity-sync-http=http://localhost:8080/webtools/control/httpService,
> rita-rmi=rmi://localhost:1099/RMIDispatcher,
> eedcc-test=http://localhost:8080/webtools/control/httpService]
> 2007-06-19 08:24:33,549 (http-0.0.0.0-8443-Processor4) [
> EntityEcaRule.java:111:INFO ] Running Entity ECA Service:
> checkCreateOrderRequirement, triggered by rule on Entity: OrderItem
> 2007-06-19 08:24:33,654 (http-0.0.0.0-8443-Processor4) [
> UtilXml.java:243:DEBUG] XML Read 0.079s:
>
> file:/paradiso/ofbiz/release4.0/applications/order/script/org/ofbiz/order/order/OrderServices.xml
> 2007-06-19 08:24:33,770 (http-0.0.0.0-8443-Processor4) [
> PrimaryKeyFinder.java:124:INFO ] Returning null because found incomplete
> primary key in find: [GenericEntity:Product]
> 2007-06-19 08:24:33,782 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:459:DEBUG] Sync service
> [entity-default/checkCreateOrderRequirement] finished in [229]
> milliseconds
> 2007-06-19 08:24:33,813 (http-0.0.0.0-8443-Processor4) [
> SequenceUtil.java:254:INFO ] Got bank of sequenced IDs for
> [OrderStatus]; curSeqId=10080, maxSeqId=10090, bankSize=10
> 2007-06-19 08:24:33,814 (http-0.0.0.0-8443-Processor4)
> [XAConnectionFactory.java:119:WARN ] no xares in rms for con
> org.ofbiz.minerva.pool.jdbc.xa.wrapper.XAConnectionImpl@4abf053f
> 2007-06-19 08:24:33,825 (http-0.0.0.0-8443-Processor4) [
> EntityEcaRule.java:111:INFO ] Running Entity ECA Service:
> checkCreateOrderRequirement, triggered by rule on Entity: OrderItem
> 2007-06-19 08:24:33,829 (http-0.0.0.0-8443-Processor4) [
> PrimaryKeyFinder.java:124:INFO ] Returning null because found incomplete
> primary key in find: [GenericEntity:Product]
> 2007-06-19 08:24:33,838 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
> cancelOrderInventoryReservation, triggered by rule on Service:
> changeOrderItemStatus
> 2007-06-19 08:24:33,892 (http-0.0.0.0-8443-Processor4) [
> UtilXml.java:243:DEBUG] XML Read 0.05s:
>
> file:/paradiso/ofbiz/release4.0/applications/product/script/org/ofbiz/product/inventory/InventoryReserveServices.xml
> 2007-06-19 08:24:33,966 (http-0.0.0.0-8443-Processor4) [
> UtilXml.java:243:DEBUG] XML Read 0.054s:
>
> file:/paradiso/ofbiz/release4.0/applications/product/script/org/ofbiz/product/inventory/InventoryServices.xml
> 2007-06-19 08:24:33,994 (http-0.0.0.0-8443-Processor4) [
> EntityEcaRule.java:111:INFO ] Running Entity ECA Service:
> updateInventoryItemFromDetail, triggered by rule on Entity:
> InventoryItemDetail
> 2007-06-19 08:24:34,007 (http-0.0.0.0-8443-Processor4) [
> EntityEcaRule.java:111:INFO ] Running Entity ECA Service:
> checkProductInventoryDiscontinuation, triggered by rule on Entity:
> InventoryItem
> 2007-06-19 08:24:34,009 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:480:DEBUG] [[ASync service started...-
> total:0.0,since last(Begin):0.0]] - 'entity-default /
> checkProductInventoryDiscontinuation'
> 2007-06-19 08:24:34,013 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:571:DEBUG] [[ASync service finished...-
> total:0.0040,since last(ASync service sta...):0.0040]] - 'entity-default
> / checkProductInventoryDiscontinuation'
> 2007-06-19 08:24:34,014 (http-0.0.0.0-8443-Processor4) [
> EntityEcaRule.java:111:INFO ] Running Entity ECA Service:
> updateSerializedInventoryTotals, triggered by rule on Entity:
> InventoryItem
> 2007-06-19 08:24:34,017 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:459:DEBUG] Sync service
> [order/createInventoryItemDetail] finished in [107] milliseconds
> 2007-06-19 08:24:34,063 (http-0.0.0.0-8443-Processor4) [
> SequenceUtil.java:254:INFO ] Got bank of sequenced IDs for
> [EntitySyncRemove]; curSeqId=10100, maxSeqId=10110, bankSize=10
> 2007-06-19 08:24:34,066 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:459:DEBUG] Sync service
> [order/cancelOrderItemShipGrpInvRes] finished in [163] milliseconds
> 2007-06-19 08:24:34,085 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:459:DEBUG] Sync service
> [order/cancelOrderInventoryReservation] finished in [245] milliseconds
> 2007-06-19 08:24:34,086 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
> recalcShippingTotal, triggered by rule on Service: changeOrderItemStatus
> 2007-06-19 08:24:34,102 (http-0.0.0.0-8443-Processor4) [
> UtilNumber.java:84 :WARN ] Could not set decimal rounding mode from
> salestax.final.decimals=2. Using default mode of 2.
> 2007-06-19 08:24:34,116 (http-0.0.0.0-8443-Processor4) [
> OrderServices.java:1461:INFO ] No valid order items found - 0.000
> 2007-06-19 08:24:34,117 (http-0.0.0.0-8443-Processor4) [
> OrderServices.java:1468:INFO ] New Shipping Total [WS10000 / 00001] :
> 0.000
> 2007-06-19 08:24:34,123 (http-0.0.0.0-8443-Processor4) [
> OrderServices.java:1475:INFO ] Old Shipping Total [WS10000 / 00001] :
> 10.00
> 2007-06-19 08:24:34,126 (http-0.0.0.0-8443-Processor4) [
> SequenceUtil.java:254:INFO ] Got bank of sequenced IDs for
> [OrderAdjustment]; curSeqId=10050, maxSeqId=10060, bankSize=10
> 2007-06-19 08:24:34,127 (http-0.0.0.0-8443-Processor4) [
> GenericEntity.java:386:WARN ] In entity field [OrderAdjustment.amount]
> set the value passed in [java.math.BigDecimal] is not compatible with
> the Java type of the field [Double]
> 2007-06-19 08:24:34,133 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
> recalcTaxTotal, triggered by rule on Service: changeOrderItemStatus
> 2007-06-19 08:24:34,229 (http-0.0.0.0-8443-Processor4) [
> UtilXml.java:243:DEBUG] XML Read 0.042s:
>
> file:/paradiso/ofbiz/release4.0/applications/order/script/org/ofbiz/order/order/OrderSimpleMethods.xml
> 2007-06-19 08:24:34,236 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
> resetGrandTotal, triggered by rule on Service: createOrderAdjustment
> 2007-06-19 08:24:34,250 (http-0.0.0.0-8443-Processor4) [
> GenericEntity.java:386:WARN ] In entity field [OrderHeader.grandTotal]
> set the value passed in [java.math.BigDecimal] is not compatible with
> the Java type of the field [Double]
> 2007-06-19 08:24:34,251 (http-0.0.0.0-8443-Processor4) [
> GenericEntity.java:386:WARN ] In entity field
> [OrderHeader.remainingSubTotal] set the value passed in
> [java.math.BigDecimal] is not compatible with the Java type of the field
> [Double]
> 2007-06-19 08:24:34,257 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:459:DEBUG] Sync service
> [order/createOrderAdjustment] finished in [71] milliseconds
> 2007-06-19 08:24:34,258 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:459:DEBUG] Sync service [order/recalcTaxTotal]
> finished in [124] milliseconds
> 2007-06-19 08:24:34,258 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
> resetGrandTotal, triggered by rule on Service: changeOrderItemStatus
> 2007-06-19 08:24:34,270 (http-0.0.0.0-8443-Processor4) [
> GenericEntity.java:386:WARN ] In entity field [OrderHeader.grandTotal]
> set the value passed in [java.math.BigDecimal] is not compatible with
> the Java type of the field [Double]
> 2007-06-19 08:24:34,270 (http-0.0.0.0-8443-Processor4) [
> GenericEntity.java:386:WARN ] In entity field
> [OrderHeader.remainingSubTotal] set the value passed in
> [java.math.BigDecimal] is not compatible with the Java type of the field
> [Double]
> 2007-06-19 08:24:34,277 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
> checkOrderItemStatus, triggered by rule on Service: changeOrderItemStatus
> 2007-06-19 08:24:34,302 (http-0.0.0.0-8443-Processor4) [
> OrderChangeHelper.java:348:INFO ] Aborting workflow for order WS10000
> 2007-06-19 08:24:34,305 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
> releaseOrderPayments, triggered by rule on Service: changeOrderStatus
> 2007-06-19 08:24:34,324 (http-0.0.0.0-8443-Processor4)
> [PaymentGatewayServices.java:676:WARN ] No OrderPaymentPreference
> records available for release
> 2007-06-19 08:24:34,325 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:112:INFO ] Got false for condition:
> [null][][statusId][equals][null][ORDER_COMPLETED][true][String][]
> 2007-06-19 08:24:34,326 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:112:INFO ] Got false for condition:
> [null][][statusId][equals][null][ORDER_APPROVED][true][String][]
> 2007-06-19 08:24:34,327 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:112:INFO ] Got false for condition:
> [null][][statusId][equals][null][ITEM_COMPLETED][true][String][]
> 2007-06-19 08:24:34,327 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:112:INFO ] Got false for condition:
> [null][][statusId][equals][null][ITEM_APPROVED][true][String][]
> 2007-06-19 08:24:34,327 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:112:INFO ] Got false for condition:
> [null][][statusId][equals][null][ITEM_APPROVED][true][String][]
> 2007-06-19 08:24:34,328 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:459:DEBUG] Sync service
> [order/changeOrderItemStatus] finished in [540] milliseconds
> 2007-06-19 08:24:34,328 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
> recreateOrderAdjustments, triggered by rule on Service: cancelOrderItem
> 2007-06-19 08:24:34,578 (http-0.0.0.0-8443-Processor4) [
> ShoppingCart.java:1422:INFO ] Returned new PaymentInfo - Pm: null /
> PmType: EXT_OFFLINE / Amt: null / Ref: null!null
> 2007-06-19 08:24:34,579 (http-0.0.0.0-8443-Processor4)
> [ShoppingCartServices.java:248:INFO ] Added Payment: EXT_OFFLINE / [no
> max]
> 2007-06-19 08:24:34,582 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:459:DEBUG] Sync service [order/loadCartFromOrder]
> finished in [244] milliseconds
> 2007-06-19 08:24:34,594 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
> resetGrandTotal, triggered by rule on Service: createOrderAdjustment
> 2007-06-19 08:24:34,606 (http-0.0.0.0-8443-Processor4) [
> GenericEntity.java:386:WARN ] In entity field [OrderHeader.grandTotal]
> set the value passed in [java.math.BigDecimal] is not compatible with
> the Java type of the field [Double]
> 2007-06-19 08:24:34,607 (http-0.0.0.0-8443-Processor4) [
> GenericEntity.java:386:WARN ] In entity field
> [OrderHeader.remainingSubTotal] set the value passed in
> [java.math.BigDecimal] is not compatible with the Java type of the field
> [Double]
> 2007-06-19 08:24:34,611 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:459:DEBUG] Sync service
> [order/recreateOrderAdjustments] finished in [282] milliseconds
> 2007-06-19 08:24:34,611 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
> resetGrandTotal, triggered by rule on Service: cancelOrderItem
> 2007-06-19 08:24:34,623 (http-0.0.0.0-8443-Processor4) [
> GenericEntity.java:386:WARN ] In entity field [OrderHeader.grandTotal]
> set the value passed in [java.math.BigDecimal] is not compatible with
> the Java type of the field [Double]
> 2007-06-19 08:24:34,624 (http-0.0.0.0-8443-Processor4) [
> GenericEntity.java:386:WARN ] In entity field
> [OrderHeader.remainingSubTotal] set the value passed in
> [java.math.BigDecimal] is not compatible with the Java type of the field
> [Double]
> 2007-06-19 08:24:34,627 (http-0.0.0.0-8443-Processor4) [
> ServiceEcaRule.java:137:INFO ] Running Service ECA Service:
> sendOrderChangeNotification, triggered by rule on Service: cancelOrderItem
> 2007-06-19 08:24:34,628 (http-0.0.0.0-8443-Processor4) [
> ServiceDispatcher.java:480:DEBUG] [[ASync service started...-
> total:0.0,since last(Begin):0.0]] - 'order / sendOrderChangeNotification'
> 2007-06-19 08:24:34,631 (http-0.0.0.0-8443-Processor4) [
> SequenceUtil.java:254:INFO ] Got bank of sequenced IDs for
> [RuntimeData]; curSeqId=10090, maxSeqId=10100, bankSize=10
> 2007-06-19 08:24:34,638 (http-0.0.0.0-8443-Processor4) [
> SequenceUtil.java:254:INFO ] Got bank of sequenced IDs for [JobSandbox];
> curSeqId=10100, maxSeqId=10110, bankSize=10
> 2007-06-19 08:24:34,714 (default-invoker-Thread-2) [
> JobInvoker.java:211:INFO ] Invoker: default-invoker-Thread-2 received
> job -- 1182234274010 from poller -
> org.ofbiz.service.job.JobPoller@7444f787
> 2007-06-19 08:24:39,514
> (org.ofbiz.service.jms.JmsListenerFactory@609903f4) [
> JmsListenerFactory.java:73 :INFO ] JMS Listener Factory Thread Finished;
> All listeners connected.
> .....
>   no more log from console.log, but browser keeps waiting, so I shutdown
> ofbiz
> .....
> Received connection from - /127.0.0.1 : 35996
> Shutdown initiated from: 127.0.0.1:35996
> ...
> ...
> ...
> 2007-06-19 08:25:51,804 (OFBiz_Shutdown_Hook) [
> ContainerLoader.java:93 :INFO ] Shutting down containers
> 2007-06-19 08:25:51,807 (OFBiz_Shutdown_Hook) [
> CatalinaContainer.java:609:ERROR]
> ---- exception report
> ----------------------------------------------------------
> Exception: org.apache.catalina.LifecycleException
> Message: Embedded service has not yet been started
> ---- stack trace
> ---------------------------------------------------------------
> LifecycleException:  Embedded service has not yet been started
> org.apache.catalina.startup.Embedded.stop(Embedded.java:849)
> org.ofbiz.catalina.container.CatalinaContainer.stop(CatalinaContainer.java
> :606)
> org.ofbiz.base.container.ContainerLoader.unload(ContainerLoader.java:99)
> org.ofbiz.base.start.Start.shutdownServer(Start.java:300)
> org.ofbiz.base.start.Start.access$000(Start.java:43)
> org.ofbiz.base.start.Start$1.run(Start.java:277)
>
> --------------------------------------------------------------------------------
>
> 2007-06-19 08:25:51,808 (OFBiz_Shutdown_Hook) [
> ServiceDispatcher.java:176:INFO ] De-Registering dispatcher: RMIDispatcher
>
> -----
>
> Thanks for your help,
> --
> Daniel
>
>

[Daniel Martínez-4]

Scott,

Issue is

https://issues.apache.org/jira/browse/OFBIZ-1088

Thanks!!
--
Daniel

Scott Gray escribió:
> Hi Daniel
>
> Could you create a jira issue with clear steps to recreate the problem
> preferably straight from seed data.  I'll take a look when I get a
> chance in
> the next couple of days.
>
> Thanks
> Scott