Re: Ofbiz issue

Wed, 04 Feb 2009 15:57:48 -0800
Unless something else is happening this is not actually an indicator of a problem, but rather that the wait semaphore that keeps two instances of this service from running is functioning properly. One instance of the service is taking long enough that the next one times out and never runs. Also, it is for the "purgeOldJobs" service and doesn't appear to have anything to do with the cleanSyncRemoveInfo service. 

-David


On Feb 4, 2009, at 4:51 PM, Andrew Dubroff wrote:


Hi all --


I am relatively new to ofbiz and am experiencing the following  
issue. I

wonder if anybody might point me in the right direction to fix the

underlying problem. During the cleanSyncRemveInfo job, there are two  
items
that seem to be giving the job a hard time, and it's unclear why. It  
seems

to provoke the second error you see below (the purgeOldJobs job).

Thanks in advance,
Andy

2009-01-17 00:00:17,489 (default-invoker-Thread-207093) [
EntitySyncServices.java:599:INFO ] Running cleanSyncRemoveInfo
2009-01-17 00:00:17,493 (default-invoker-Thread-207093) [

EntitySyncServices.java:628:INFO ] In cleanSyncRemoveInfo removed  
[0] values

with TX timestamp before [2009-01-16 23:36:17.492]
2009-01-17 00:00:17,501 (default-invoker-Thread-207092) [

JobInvoker.java:230:INFO ] Invoker [default-invoker-Thread-207092]  
received

job [BackOrder Notification] from poller
[org.ofbiz.service.job.jobpol...@41d47b2b]
2009-01-17 00:00:17,521 (default-invoker-Thread-207092)
[PersistedServiceJob.java:138:INFO ]

org.ofbiz.service.job.persistedservice...@2ddb0b5e[17393] -- Next  
runtime:

1232258400000
2009-01-17 00:00:17,528 (default-invoker-Thread-207092) [
InventoryServices.java:373:INFO ] OOS Inventory Items: 2
2009-01-17 00:00:17,530 (default-invoker-Thread-207092) [
InventoryServices.java:407:INFO ] Reservations for item: 1
2009-01-17 00:00:17,530 (default-invoker-Thread-207092) [

InventoryServices.java:430:INFO ] Promised Date: 2008-04-24  
14:17:30.699

2009-01-17 00:00:17,530 (default-invoker-Thread-207092) [
InventoryServices.java:445:INFO ] Next Ship Date: null
2009-01-17 00:00:17,530 (default-invoker-Thread-207092) [

InventoryServices.java:454:INFO ] Promised Date + 1: 2008-04-23  
14:17:30.699

2009-01-17 00:00:17,531 (default-invoker-Thread-207092) [
InventoryServices.java:455:INFO ] Now: 2009-01-17 00:00:17.53
2009-01-17 00:00:17,531 (default-invoker-Thread-207092) [
InventoryServices.java:464:INFO ] We won't ship on time, getting
notification info
2009-01-17 00:00:17,531 (default-invoker-Thread-207092) [

InventoryServices.java:482:INFO ] Ship date is >30 past the promised  
date

2009-01-17 00:00:17,531 (default-invoker-Thread-207092) [
InventoryServices.java:492:INFO ] Flagging the item to auto-cancel
2009-01-17 00:00:17,534 (default-invoker-Thread-207092) [
InventoryServices.java:407:INFO ] Reservations for item: 1
2009-01-17 00:00:17,534 (default-invoker-Thread-207092) [

InventoryServices.java:430:INFO ] Promised Date: 2008-06-25  
14:06:35.953

2009-01-17 00:00:17,534 (default-invoker-Thread-207092) [
InventoryServices.java:445:INFO ] Next Ship Date: null
2009-01-17 00:00:17,534 (default-invoker-Thread-207092) [

InventoryServices.java:454:INFO ] Promised Date + 1: 2008-06-24  
14:06:35.953

2009-01-17 00:00:17,534 (default-invoker-Thread-207092) [
InventoryServices.java:455:INFO ] Now: 2009-01-17 00:00:17.534
2009-01-17 00:00:17,534 (default-invoker-Thread-207092) [
InventoryServices.java:464:INFO ] We won't ship on time, getting
notification info
2009-01-17 00:00:17,534 (default-invoker-Thread-207092) [

InventoryServices.java:482:INFO ] Ship date is >30 past the promised  
date

2009-01-17 00:00:17,534 (default-invoker-Thread-207092) [
InventoryServices.java:492:INFO ] Flagging the item to auto-cancel
2009-01-17 00:00:17,538 (default-invoker-Thread-207092) [

InventoryServices.java:589:ERROR] OI: ACCO10030 SEQID: 00001  
cancelAll: true

cancelDate: 2008-07-25 14:06:35.953
2009-01-17 00:00:17,541 (default-invoker-Thread-207092) [

InventoryServices.java:589:ERROR] OI: WSCO10000 SEQID: 00001  
cancelAll: true

cancelDate: 2008-05-24 14:17:30.699
2009-01-17 00:05:19,595 (default-invoker-Thread-207075) [

ServiceSemaphore.java:91 :WARN ] Service [purgeOldJobs] with wait  
semaphore

exceeded wait timeout, waited [302.173], wait started at 2009-01-17
00:00:17.422
2009-01-17 00:05:19,596 (default-invoker-Thread-207075) [
GenericServiceJob.java:116:ERROR]
---- exception report
----------------------------------------------------------
Async-Service failed.
Exception: org.ofbiz.service.semaphore.SemaphoreWaitException

Message: Service [purgeOldJobs] with wait semaphore exceeded wait  
timeout,

waited [302.173], wait started at 2009-01-17 00:00:17.422
---- stack trace
---------------------------------------------------------------

org.ofbiz.service.semaphore.SemaphoreWaitException: Service  
[purgeOldJobs]
with wait semaphore exceeded wait timeout, waited [302.173], wait  
started at

2009-01-17 00:00:17.422

org 
.ofbiz 
.service.semaphore.ServiceSemaphore.waitOrFail(ServiceSemaphore.java: 
92)
org 
.ofbiz 
.service.semaphore.ServiceSemaphore.acquire(ServiceSemaphore.java:53)
org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java: 
245)
org.ofbiz.service.ServiceDispatcher.runSync(ServiceDispatcher.java: 
213)
org.ofbiz.service.GenericDispatcher.runSync(GenericDispatcher.java: 
149)
org.ofbiz.service.job.GenericServiceJob.exec(GenericServiceJob.java: 
69)

org.ofbiz.service.job.JobInvoker.run(JobInvoker.java:240)
java.lang.Thread.run(Thread.java:619)
--------------------------------------------------------------------------------
























					Reply via email to