Problem with order creation with service order line

[Morten Jensen]

Hi,

This is a complete functional newbie question about products as services.

I want to create a product as a service (that is, in Product tab I have set
"Require Inventory" to N and "Product Type" to service).

But whenever I set-up an order with a single line item of this product and
go to Create Order I keep getting the following error message on screen:

The Following Errors Occurred:
Did not complete the order, the following occurred:The product with ID
PANEL-ENTRY-100 is no longer in stock. Please try reducing the quantity or
removing the product from this order.

Any idea is to what I'm doing wrong here?

In the logs I see the following exceptions:

2015-09-15 16:23:50,761 |-0.0.0.0-8443-exec-6
|ServiceDispatcher             |E| Incoming context (in runSync :
reserveProductInventoryByFacility) does not match expected requirements
org.ofbiz.service.ServiceValidationException: The following required
parameter is missing: [reserveProductInventoryByFacility.facilityId]
    at org.ofbiz.service.ModelService.validate(ModelService.java:551)
~[ofbiz-service.jar:?]
    at
org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:381)
[ofbiz-service.jar:?]
    at
org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:232)
[ofbiz-service.jar:?]
    at
org.ofbiz.service.GenericDispatcherFactory$GenericDispatcher.runSync(GenericDispatcherFactory.java:98)
[ofbiz-service.jar:?]
...
015-09-15 16:23:50,773 |-0.0.0.0-8443-exec-6 |ServiceDispatcher
|T| [[Sync service failed...- total:0.0,since last(Begin):0.0]] - 'order /
reserveProductInventoryByFacility'
2015-09-15 16:23:50,773 |-0.0.0.0-8443-exec-6
|TransactionUtil               |W| [TransactionUtil.setRollbackOnly]
Calling transaction setRollbackOnly; this stack trace shows where this is
happening:
java.lang.Exception: Service [reserveProductInventoryByFacility] threw an
unexpected exception/error
    at
org.ofbiz.entity.transaction.TransactionUtil.setRollbackOnly(TransactionUtil.java:378)
[ofbiz-entity-test.jar:?]
    at
org.ofbiz.entity.transaction.TransactionUtil.rollback(TransactionUtil.java:319)
[ofbiz-entity-test.jar:?]
    at
org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:517)
[ofbiz-service.jar:?]
...
2015-09-15 16:23:50,782 |-0.0.0.0-8443-exec-6
|CallService                   |E| ERROR: Could not complete the Reserve
Store Inventory
[file:/usr/local/share/apache-ofbiz-13.07.02/applications/product/script/org/ofbiz/product/store/ProductStoreServices.xml#reserveStoreInventory]
process [problem invoking the [reserveProductInventoryByFacility] service
with the map named [callServiceMap] containing [{orderItemSeqId=00001,
locale=en, shipGroupSeqId=00001, quantity=1.00,
userLogin=[GenericEntity:UserLogin][createdStamp,2015-08-26
16:25:53.0(java.sql.Timestamp)][createdTxStamp,2015-08-26
16:25:53.0(java.sql.Timestamp)][currentPassword,{SHA}47b56994cbc2b6d10aa1be30f70165adb305a41a(java.lang.String)][disabledDateTime,null()][enabled,Y(java.lang.String)][externalAuthId,null()][hasLoggedOut,N(java.lang.String)][isSystem,null()][lastCurrencyUom,null()][lastLocale,null()][lastTimeZone,null()][lastUpdatedStamp,2015-09-10
20:15:14.0(java.sql.Timestamp)][lastUpdatedTxStamp,2015-09-10
20:15:14.0(java.sql.Timestamp)][partyId,admin(java.lang.String)][passwordHint,null()][requirePasswordChange,null()][successiveFailedLogins,null()][userLdapDn,null()][userLoginId,admin(java.lang.String)],
facilityId=null, requireInventory=N, orderId=10010,
productId=PANEL-ENTRY-100}]: The following required parameter is missing:
[reserveProductInventoryByFacility.facilityId]]
org.ofbiz.service.ServiceValidationException: The following required
parameter is missing: [reserveProductInventoryByFacility.facilityId]
    at org.ofbiz.service.ModelService.validate(ModelService.java:551)
~[ofbiz-service.jar:?]
    at
org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:381)
~[ofbiz-service.jar:?]
...
2015-09-15 16:23:50,797 |-0.0.0.0-8443-exec-6
|TransactionUtil               |I| [TransactionUtil.rollback] transaction
rolled back
2015-09-15 16:23:50,797 |-0.0.0.0-8443-exec-6
|ServiceDispatcher             |T| Sync service [order/storeOrder] finished
in [225] milliseconds
2015-09-15 16:23:50,798 |-0.0.0.0-8443-exec-6
|RequestHandler                |I| Ran Event
[java:org.ofbiz.order.shoppingcart.CheckOutEvents#createOrder] from
[request], result is [error]
2015-09-15 16:23:50,798 |-0.0.0.0-8443-exec-6
|RequestHandler                |E| Request processorder caused an error
with the following message: Did not complete the order, the following
occurred:The product  with ID PANEL-ENTRY-100 is no longer in stock. Please
try reducing the quantity or removing the product from this order.


Thanks in advance for your assistance.

Best regards,
Morten Jensen

[Oleg Andreyev]

 Hi,

Unfortunately such message appears if reservation service is failed, even if the reason is not related to product setup or quantity in stock.
The real error message is: " Incoming context (in runSync :  reserveProductInventoryByFacility) does not match expected requirements  org.ofbiz.service.ServiceValidationException: The following required  parameter is missing: [reserveProductInventoryByFacility.facilityId] "

Attribute facilityId is not provided to service reserveProductInventoryByFacility and this is the real cause. You may want to check inventory facility in product store.

>Вторник, 15 сентября 2015, 17:39 +01:00 от Morten Jensen <[hidden email]>:
>
>Hi,
>
>This is a complete functional newbie question about products as services.
>
>I want to create a product as a service (that is, in Product tab I have set
>"Require Inventory" to N and "Product Type" to service).
>
>But whenever I set-up an order with a single line item of this product and
>go to Create Order I keep getting the following error message on screen:
>
>The Following Errors Occurred:
>Did not complete the order, the following occurred:The product with ID
>PANEL-ENTRY-100 is no longer in stock. Please try reducing the quantity or
>removing the product from this order.
>
>Any idea is to what I'm doing wrong here?
>
>In the logs I see the following exceptions:
>
>2015-09-15 16:23:50,761 |-0.0.0.0-8443-exec-6
>|ServiceDispatcher             |E| Incoming context (in runSync :
>reserveProductInventoryByFacility) does not match expected requirements
>org.ofbiz.service.ServiceValidationException: The following required
>parameter is missing: [reserveProductInventoryByFacility.facilityId]
>    at org.ofbiz.service.ModelService.validate(ModelService.java:551)
>~[ofbiz-service.jar:?]
>    at
>org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:381)
>[ofbiz-service.jar:?]
>    at
>org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:232)
>[ofbiz-service.jar:?]
>    at
>org.ofbiz.service.GenericDispatcherFactory$GenericDispatcher.runSync(GenericDispatcherFactory.java:98)
>[ofbiz-service.jar:?]
>...
>015-09-15 16:23:50,773 |-0.0.0.0-8443-exec-6 |ServiceDispatcher
>|T| [[Sync service failed...- total:0.0,since last(Begin):0.0]] - 'order /
>reserveProductInventoryByFacility'
>2015-09-15 16:23:50,773 |-0.0.0.0-8443-exec-6
>|TransactionUtil               |W| [TransactionUtil.setRollbackOnly]
>Calling transaction setRollbackOnly; this stack trace shows where this is
>happening:
>java.lang.Exception: Service [reserveProductInventoryByFacility] threw an
>unexpected exception/error
>    at
>org.ofbiz.entity.transaction.TransactionUtil.setRollbackOnly(TransactionUtil.java:378)
>[ofbiz-entity-test.jar:?]
>    at
>org.ofbiz.entity.transaction.TransactionUtil.rollback(TransactionUtil.java:319)
>[ofbiz-entity-test.jar:?]
>    at
>org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:517)
>[ofbiz-service.jar:?]
>...
>2015-09-15 16:23:50,782 |-0.0.0.0-8443-exec-6
>|CallService                   |E| ERROR: Could not complete the Reserve
>Store Inventory
>[file:/usr/local/share/apache-ofbiz-13.07.02/applications/product/script/org/ofbiz/product/store/ProductStoreServices.xml#reserveStoreInventory]
>process [problem invoking the [reserveProductInventoryByFacility] service
>with the map named [callServiceMap] containing [{orderItemSeqId=00001,
>locale=en, shipGroupSeqId=00001, quantity=1.00,
>userLogin=[GenericEntity:UserLogin][createdStamp,2015-08-26
>16:25:53.0(java.sql.Timestamp)][createdTxStamp,2015-08-26
>16:25:53.0(java.sql.Timestamp)][currentPassword,{SHA}47b56994cbc2b6d10aa1be30f70165adb305a41a(java.lang.String)][disabledDateTime,null()][enabled,Y(java.lang.String)][externalAuthId,null()][hasLoggedOut,N(java.lang.String)][isSystem,null()][lastCurrencyUom,null()][lastLocale,null()][lastTimeZone,null()][lastUpdatedStamp,2015-09-10
>20:15:14.0(java.sql.Timestamp)][lastUpdatedTxStamp,2015-09-10
>20:15:14.0(java.sql.Timestamp)][partyId,admin(java.lang.String)][passwordHint,null()][requirePasswordChange,null()][successiveFailedLogins,null()][userLdapDn,null()][userLoginId,admin(java.lang.String)],
>facilityId=null, requireInventory=N, orderId=10010,
>productId=PANEL-ENTRY-100}]: The following required parameter is missing:
>[reserveProductInventoryByFacility.facilityId]]
>org.ofbiz.service.ServiceValidationException: The following required
>parameter is missing: [reserveProductInventoryByFacility.facilityId]
>    at org.ofbiz.service.ModelService.validate(ModelService.java:551)
>~[ofbiz-service.jar:?]
>    at
>org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java:381)
>~[ofbiz-service.jar:?]
>...
>2015-09-15 16:23:50,797 |-0.0.0.0-8443-exec-6
>|TransactionUtil               |I| [TransactionUtil.rollback] transaction
>rolled back
>2015-09-15 16:23:50,797 |-0.0.0.0-8443-exec-6
>|ServiceDispatcher             |T| Sync service [order/storeOrder] finished
>in [225] milliseconds
>2015-09-15 16:23:50,798 |-0.0.0.0-8443-exec-6
>|RequestHandler                |I| Ran Event
>[java:org.ofbiz.order.shoppingcart.CheckOutEvents#createOrder] from
>[request], result is [error]
>2015-09-15 16:23:50,798 |-0.0.0.0-8443-exec-6
>|RequestHandler                |E| Request processorder caused an error
>with the following message: Did not complete the order, the following
>occurred:The product  with ID PANEL-ENTRY-100 is no longer in stock. Please
>try reducing the quantity or removing the product from this order.
>
>
>Thanks in advance for your assistance.
>
>Best regards,
>Morten Jensen

[Morten Jensen]

Thanks for your response, much appreciated. To rectify I created a new
facility and assigned the product to the facility in the facilities tab.

However, after doing so I am now suddenly having another problem (insert
into a SERVER_HIT table, which appears to log user activity) that prevents
me from even searching for products when attempting to create an Order
Entry and can't seem to get rid of the Exception:

2015-09-18 07:59:02,134 |-0.0.0.0-8443-exec-1
|ControlServlet                |T| [[[LookupSupplierProduct(Domain:
https://192.168.0.154)] Request Begun, encoding=[UTF-8]- total:0.0,since
last(Begin):0.0]]
2015-09-18 07:59:02,139 |-0.0.0.0-8443-exec-1
|RequestHandler                |I| Rendering View [LookupSupplierProduct],
sessionId=3B1742E9EC7E6A196D9AF46CE0AF484F.jvm1
2015-09-18 07:59:02,142 |-0.0.0.0-8443-exec-1
|ServiceDispatcher             |T| Sync service
[order/catalogPermissionCheck] finished in [1] milliseconds
2015-09-18 07:59:02,143 |-0.0.0.0-8443-exec-1
|ServiceDispatcher             |T| Sync service
[order/getUserPreferenceGroup] finished in [1] milliseconds
2015-09-18 07:59:02,151 |-0.0.0.0-8443-exec-1
|ServiceDispatcher             |T| Sync service [order/executeFind]
finished in [1] milliseconds
2015-09-18 07:59:02,151 |-0.0.0.0-8443-exec-1
|ServiceDispatcher             |T| Sync service [order/performFind]
finished in [2] milliseconds
2015-09-18 07:59:02,157 |-0.0.0.0-8443-exec-1
|ServerHitBin                  |I| Visit delegatorName=default,
ServerHitBin delegatorName=default
2015-09-18 07:59:02,158 |-0.0.0.0-8443-exec-1
|GenericDelegator              |E| Failure in create operation for entity
[ServerHit]: org.ofbiz.entity.GenericEntityException: Error while
inserting:
[GenericEntity:ServerHit][contentId,ordermgr.LookupSupplierProduct(java.lang.String)][createdStamp,2015-09-18
07:59:02.157(java.sql.Timestamp)][createdTxStamp,2015-09-18
07:59:02.157(java.sql.Timestamp)][hitStartDateTime,2015-09-18
07:59:02.134(java.sql.Timestamp)][hitTypeId,REQUEST(java.lang.String)][lastUpdatedStamp,2015-09-18
07:59:02.157(java.sql.Timestamp)][lastUpdatedTxStamp,2015-09-18
07:59:02.157(java.sql.Timestamp)][partyId,admin(java.lang.String)][referrerUrl,
https://192.168.0.154:8443/ordermgr/control/BulkAddProducts(java.lang.String)][requestUrl,https://192.168.0.154:8443/ordermgr/control/LookupSupplierProduct(java.lang.String)][runningTimeMillis,22(java.lang.Long)][serverHostName,ofbiz-dev(java.lang.String)][serverIpAddress,127.0.1.1(java.lang.String)][userLoginId,admin(java.lang.String)][visitId,10601(java.lang.String)]
(SQL Exception while executing the following:INSERT INTO SERVER_HIT
(VISIT_ID, CONTENT_ID, HIT_START_DATE_TIME, HIT_TYPE_ID, NUM_OF_BYTES,
RUNNING_TIME_MILLIS, USER_LOGIN_ID, STATUS_ID, REQUEST_URL, REFERRER_URL,
SERVER_IP_ADDRESS, SERVER_HOST_NAME, LAST_UPDATED_STAMP,
LAST_UPDATED_TX_STAMP, CREATED_STAMP, CREATED_TX_STAMP,
INTERNAL_CONTENT_ID, PARTY_ID, ID_BY_IP_CONTACT_MECH_ID,
REF_BY_WEB_CONTACT_MECH_ID) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?) (Duplicate entry
'10601-ordermgr.LookupSupplierProduct-2015-09-18 07:59:02-REQUEST' for key
'PRIMARY')). Rolling back transaction.

I have tried clearing the SERVER_HIT table to no avail.

Any ideas as to what is going on here - looks like I'm involuntarily
digging a deeper hole for myself here..?

Thanks.
Morten

> Oleg Andreyev Sep 16, 2015; 9:02am
> Re: Problem with order creation with service order line
>  Hi,
>
> Unfortunately such message appears if reservation service is failed, even
> if the reason is not related to product setup or quantity in stock.
> The real error message is: " Incoming context (in runSync :
> reserveProductInventoryByFacility) does not match expected requirements
> org.ofbiz.service.ServiceValidationException: The following required
> parameter is missing: [reserveProductInventoryByFacility.facilityId] "
>
> Attribute facilityId is not provided to service
> reserveProductInventoryByFacility and this is the real cause. You may want
> to check inventory facility in product store.
>
>
>
>
>
>

[Morten Jensen]

Ok, I managed to workaround the duplicate primary key SERVER_HIT logging
problem by turning off logging in
./framework/webapp/config/serverstats.properties ; no idea what the root
cause is (bug?) but I don't need the logging for the testing I'm doing.

Now I can finally create an order with the service product (creating a
facility and adding it to the product despite it being a service seems to
have resolved the problem).

Thanks.
Morten

On Fri, Sep 18, 2015 at 9:47 AM, Morten Jensen <[hidden email]> wrote:

> Thanks for your response, much appreciated. To rectify I created a new
> facility and assigned the product to the facility in the facilities tab.
>
> However, after doing so I am now suddenly having another problem (insert
> into a SERVER_HIT table, which appears to log user activity) that prevents
> me from even searching for products when attempting to create an Order
> Entry and can't seem to get rid of the Exception:
>
> 2015-09-18 07:59:02,134 |-0.0.0.0-8443-exec-1
> |ControlServlet                |T| [[[LookupSupplierProduct(Domain:
> https://192.168.0.154)] Request Begun, encoding=[UTF-8]- total:0.0,since
> last(Begin):0.0]]
> 2015-09-18 07:59:02,139 |-0.0.0.0-8443-exec-1
> |RequestHandler                |I| Rendering View [LookupSupplierProduct],
> sessionId=3B1742E9EC7E6A196D9AF46CE0AF484F.jvm1
> 2015-09-18 07:59:02,142 |-0.0.0.0-8443-exec-1
> |ServiceDispatcher             |T| Sync service
> [order/catalogPermissionCheck] finished in [1] milliseconds
> 2015-09-18 07:59:02,143 |-0.0.0.0-8443-exec-1
> |ServiceDispatcher             |T| Sync service
> [order/getUserPreferenceGroup] finished in [1] milliseconds
> 2015-09-18 07:59:02,151 |-0.0.0.0-8443-exec-1
> |ServiceDispatcher             |T| Sync service [order/executeFind]
> finished in [1] milliseconds
> 2015-09-18 07:59:02,151 |-0.0.0.0-8443-exec-1
> |ServiceDispatcher             |T| Sync service [order/performFind]
> finished in [2] milliseconds
> 2015-09-18 07:59:02,157 |-0.0.0.0-8443-exec-1
> |ServerHitBin                  |I| Visit delegatorName=default,
> ServerHitBin delegatorName=default
> 2015-09-18 07:59:02,158 |-0.0.0.0-8443-exec-1
> |GenericDelegator              |E| Failure in create operation for entity
> [ServerHit]: org.ofbiz.entity.GenericEntityException: Error while
> inserting:
> [GenericEntity:ServerHit][contentId,ordermgr.LookupSupplierProduct(java.lang.String)][createdStamp,2015-09-18
> 07:59:02.157(java.sql.Timestamp)][createdTxStamp,2015-09-18
> 07:59:02.157(java.sql.Timestamp)][hitStartDateTime,2015-09-18
> 07:59:02.134(java.sql.Timestamp)][hitTypeId,REQUEST(java.lang.String)][lastUpdatedStamp,2015-09-18
> 07:59:02.157(java.sql.Timestamp)][lastUpdatedTxStamp,2015-09-18
> 07:59:02.157(java.sql.Timestamp)][partyId,admin(java.lang.String)][referrerUrl,
> https://192.168.0.154:8443/ordermgr/control/BulkAddProducts(java.lang.String)][requestUrl,https://192.168.0.154:8443/ordermgr/control/LookupSupplierProduct(java.lang.String)][runningTimeMillis,22(java.lang.Long)][serverHostName,ofbiz-dev(java.lang.String)][serverIpAddress,127.0.1.1(java.lang.String)][userLoginId,admin(java.lang.String)][visitId,10601(java.lang.String)]
> (SQL Exception while executing the following:INSERT INTO SERVER_HIT
> (VISIT_ID, CONTENT_ID, HIT_START_DATE_TIME, HIT_TYPE_ID, NUM_OF_BYTES,
> RUNNING_TIME_MILLIS, USER_LOGIN_ID, STATUS_ID, REQUEST_URL, REFERRER_URL,
> SERVER_IP_ADDRESS, SERVER_HOST_NAME, LAST_UPDATED_STAMP,
> LAST_UPDATED_TX_STAMP, CREATED_STAMP, CREATED_TX_STAMP,
> INTERNAL_CONTENT_ID, PARTY_ID, ID_BY_IP_CONTACT_MECH_ID,
> REF_BY_WEB_CONTACT_MECH_ID) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
> ?, ?, ?, ?, ?, ?, ?) (Duplicate entry
> '10601-ordermgr.LookupSupplierProduct-2015-09-18 07:59:02-REQUEST' for key
> 'PRIMARY')). Rolling back transaction.
>
> I have tried clearing the SERVER_HIT table to no avail.
>
> Any ideas as to what is going on here - looks like I'm involuntarily
> digging a deeper hole for myself here..?
>
> Thanks.
> Morten
>
>
>
>> Oleg Andreyev Sep 16, 2015; 9:02am
>> Re: Problem with order creation with service order line
>>  Hi,
>>
>> Unfortunately such message appears if reservation service is failed, even
>> if the reason is not related to product setup or quantity in stock.
>> The real error message is: " Incoming context (in runSync :
>> reserveProductInventoryByFacility) does not match expected requirements
>> org.ofbiz.service.ServiceValidationException: The following required
>> parameter is missing: [reserveProductInventoryByFacility.facilityId] "
>>
>> Attribute facilityId is not provided to service
>> reserveProductInventoryByFacility and this is the real cause. You may want
>> to check inventory facility in product store.
>>
>>
>>
>>
>>
>>
>

[Oleg Andreyev-2]

Hi

On Fri, Sep 18, 2015 at 1:22 PM, Morten Jensen <[hidden email]> wrote:

> Ok, I managed to workaround the duplicate primary key SERVER_HIT logging
> problem by turning off logging in
> ./framework/webapp/config/serverstats.properties ; no idea what the root
> cause is (bug?) but I don't need the logging for the testing I'm doing.
>
>
I guess this happen due to missing support for milliseconds in MySQL. Don't
care. If you managed to disable this feature it's okey.