Timesheet REST returns empty worklogged set upon transition

Issue #610 resolved
Former user created an issue

I'm using your REST to sum up the hours on a particular work item so I can pass it along to another system. (See HourCollector.groovy for the code involved with gathering that info.) This code works great with one exception. When transitioning between statuses, a screen is presented allowing the user to enter time. When such worklogs are entered, our instance locks up for some time, and afterward, I'm returned an empty set for all hours entered.

Screenshot of custom listener:

Capture.PNG

Here's an excerpt from our log file for a successful run when they're logging time in the usual manner:

2015-03-11 14:52:50,426 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] -------- Begin Hour Collector ---------------
2015-03-11 14:52:50,473 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] user: worthar || number: 70201 || project: 10604 || date: 2015-03-11
2015-03-11 14:52:50,473 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] URL: http://rnod-jira01.is.ad.igt.com:8080/rest/timesheet-gadget/1.0/raw-timesheet.json?targetUser=worthar&projectid=10604&startDate=2015-03-11&endDate=2015-03-11
2015-03-11 14:52:50,707 http-bio-8080-exec-5 WARN automation 892x1606x2 uwsnpv 10.210.44.18 /rest/timesheet-gadget/1.0/raw-timesheet.json [atlassian.jira.util.ParameterUtils] Could not parse: 2015-03-11 into a date
2015-03-11 14:52:50,707 http-bio-8080-exec-5 WARN automation 892x1606x2 uwsnpv 10.210.44.18 /rest/timesheet-gadget/1.0/raw-timesheet.json [atlassian.jira.util.ParameterUtils] Could not parse: 2015-03-11 into a date
2015-03-11 14:52:50,738 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] response: 200
2015-03-11 14:52:50,801 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] [[3600], [3600, 3600], [3600]]
2015-03-11 14:52:50,801 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] 3600
2015-03-11 14:52:50,801 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] 3600
2015-03-11 14:52:50,801 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] 3600
2015-03-11 14:52:50,801 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] 3600
2015-03-11 14:52:50,801 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] push to DB: worthar || 70201 || 14400 || 6352880 || 0040 || 2015-03-11
2015-03-11 14:52:50,816 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] row not found.  need to insert a new row.
2015-03-11 14:52:50,816 http-bio-443-exec-13 DEBUG worthar 892x1605x1 1tfhzu2 10.21.100.13 /secure/CreateWorklog.jspa [com.custom.HourCollector] -------- End Hour Collector ---------------

Here's an excerpt from the log file when attempting to transition this same issue to the next status and logging an hour while doing so. A few things to note as well:

  • I have some other custom code start and finish before the end of HourCollector. Ignore. That occurs because of the length of time it takes before I get a response
  • The stack traces I hope might be helpful
  • I'm calling the same URL as above that was previously successful
  • I removed this code while logging time and transitioning to confirm that it was this call to the REST that was causing the issue.
  • I've attached our workflow in case you care to test it on your side.
2015-03-11 14:53:11,331 http-bio-443-exec-23 DEBUG worthar 893x1624x1 1tfhzu2 10.21.100.13 /secure/CommentAssignIssue.jspa [com.custom.HourCollector] -------- Begin Hour Collector ---------------
2015-03-11 14:53:11,331 http-bio-443-exec-23 DEBUG worthar 893x1624x1 1tfhzu2 10.21.100.13 /secure/CommentAssignIssue.jspa [com.custom.HourCollector] user: worthar || number: 70201 || project: 10604 || date: 2015-03-11
2015-03-11 14:53:11,331 http-bio-443-exec-23 DEBUG worthar 893x1624x1 1tfhzu2 10.21.100.13 /secure/CommentAssignIssue.jspa [com.custom.HourCollector] URL: http://rnod-jira01.is.ad.igt.com:8080/rest/timesheet-gadget/1.0/raw-timesheet.json?targetUser=worthar&projectid=10604&startDate=2015-03-11&endDate=2015-03-11
2015-03-11 14:53:11,690 http-bio-8080-exec-10 WARN automation 893x1625x2 11vkbwm 10.210.44.18 /rest/timesheet-gadget/1.0/raw-timesheet.json [atlassian.jira.util.ParameterUtils] Could not parse: 2015-03-11 into a date
2015-03-11 14:53:11,690 http-bio-8080-exec-10 WARN automation 893x1625x2 11vkbwm 10.210.44.18 /rest/timesheet-gadget/1.0/raw-timesheet.json [atlassian.jira.util.ParameterUtils] Could not parse: 2015-03-11 into a date
2015-03-11 14:53:51,626 QuartzScheduler_Worker-0 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector running ----
2015-03-11 14:53:51,626 QuartzScheduler_Worker-0 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector ended   ----
2015-03-11 14:53:51,704 QuartzScheduler_Worker-0 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook running ----
2015-03-11 14:53:51,720 QuartzScheduler_Worker-0 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] entry: {"WorkDate" : "03/11/2015","EmployeeID" : "70201","CostCenter" : "101514","Network" : "6352880","Activity" : "0040","SubActivity" : "","HoursWorked" : "4"}
2015-03-11 14:53:52,141 QuartzScheduler_Worker-0 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] 201 || Created || https://api.igt-dev.com/sap/opu/odata/sap/ALLTIME/Times(ID='000008189107',EmployeeID='00070201')
2015-03-11 14:53:52,141 QuartzScheduler_Worker-0 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] Response was 201
2015-03-11 14:53:52,141 QuartzScheduler_Worker-0 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] found: 000008189107
2015-03-11 14:53:52,157 QuartzScheduler_Worker-0 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook ended   ----
2015-03-11 14:55:51,671 QuartzScheduler_Worker-3 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector running ----
2015-03-11 14:55:51,671 QuartzScheduler_Worker-3 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector ended   ----
2015-03-11 14:55:51,905 QuartzScheduler_Worker-3 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook running ----
2015-03-11 14:55:51,905 QuartzScheduler_Worker-3 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook ended   ----
2015-03-11 14:57:51,684 QuartzScheduler_Worker-1 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector running ----
2015-03-11 14:57:51,684 QuartzScheduler_Worker-1 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector ended   ----
2015-03-11 14:57:51,777 QuartzScheduler_Worker-1 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook running ----
2015-03-11 14:57:51,777 QuartzScheduler_Worker-1 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook ended   ----
2015-03-11 14:59:51,635 QuartzScheduler_Worker-3 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector running ----
2015-03-11 14:59:51,635 QuartzScheduler_Worker-3 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector ended   ----
2015-03-11 14:59:51,869 QuartzScheduler_Worker-3 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook running ----
2015-03-11 14:59:51,869 QuartzScheduler_Worker-3 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook ended   ----
2015-03-11 15:01:51,679 QuartzScheduler_Worker-3 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector running ----
2015-03-11 15:01:51,679 QuartzScheduler_Worker-3 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector ended   ----
2015-03-11 15:01:51,772 QuartzScheduler_Worker-3 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook running ----
2015-03-11 15:01:51,772 QuartzScheduler_Worker-3 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook ended   ----
2015-03-11 15:03:51,614 QuartzScheduler_Worker-1 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector running ----
2015-03-11 15:03:51,630 QuartzScheduler_Worker-1 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector ended   ----
2015-03-11 15:03:51,708 QuartzScheduler_Worker-1 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook running ----
2015-03-11 15:03:51,708 QuartzScheduler_Worker-1 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook ended   ----
2015-03-11 15:05:51,658 QuartzScheduler_Worker-3 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector running ----
2015-03-11 15:05:51,658 QuartzScheduler_Worker-3 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector ended   ----
2015-03-11 15:05:51,752 QuartzScheduler_Worker-3 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook running ----
2015-03-11 15:05:51,767 QuartzScheduler_Worker-3 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook ended   ----
2015-03-11 15:07:51,905 QuartzScheduler_Worker-0 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector running ----
2015-03-11 15:07:51,905 QuartzScheduler_Worker-0 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector ended   ----
2015-03-11 15:07:52,030 QuartzScheduler_Worker-0 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook running ----
2015-03-11 15:07:52,030 QuartzScheduler_Worker-0 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook ended   ----
2015-03-11 15:09:51,638 QuartzScheduler_Worker-1 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector running ----
2015-03-11 15:09:51,638 QuartzScheduler_Worker-1 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector ended   ----
2015-03-11 15:09:51,716 QuartzScheduler_Worker-1 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook running ----
2015-03-11 15:09:51,731 QuartzScheduler_Worker-1 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook ended   ----
2015-03-11 15:11:51,666 QuartzScheduler_Worker-2 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector running ----
2015-03-11 15:11:51,666 QuartzScheduler_Worker-2 DEBUG ServiceRunner    Token Collector [onresolve.jira.groovy.TokenCollector] ---- Service TokenCollector ended   ----
2015-03-11 15:11:52,025 QuartzScheduler_Worker-2 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook running ----
2015-03-11 15:11:52,056 QuartzScheduler_Worker-2 DEBUG ServiceRunner    ESS Hook [onresolve.jira.groovy.ESSHook] ---- Service ESSHook ended   ----
2015-03-11 15:13:11,337 http-bio-8080-exec-10 WARN automation 893x1625x2 11vkbwm 10.210.44.18 /rest/timesheet-gadget/1.0/raw-timesheet.json [core.entity.jdbc.SQLProcessor] Invalid state, the PreparedStatement object is closed.
2015-03-11 15:13:11,337 StreamsCompletionService::thread-685 ERROR worthar 898x1635x6 1tfhzu2 10.21.100.13 /plugins/servlet/streams [atlassian.streams.internal.LocalActivityProvider] Error building feed
java.lang.RuntimeException: Error creating BulkIterator
    at com.atlassian.streams.jira.changehistory.BulkIssueHistoryReader$1.iterator(BulkIssueHistoryReader.java:60)
    at com.atlassian.streams.jira.JiraStreamsActivityProvider$ChangeHistoryQuery.<init>(JiraStreamsActivityProvider.java:188)
    at com.atlassian.streams.jira.JiraStreamsActivityProvider$ChangeHistoryQuery.<init>(JiraStreamsActivityProvider.java:173)
    at com.atlassian.streams.jira.JiraStreamsActivityProvider.extractActivity(JiraStreamsActivityProvider.java:138)
    at com.atlassian.streams.jira.JiraStreamsActivityProvider.access$100(JiraStreamsActivityProvider.java:47)
    at com.atlassian.streams.jira.JiraStreamsActivityProvider$1.call(JiraStreamsActivityProvider.java:102)
    at com.atlassian.streams.jira.JiraStreamsActivityProvider$1.call(JiraStreamsActivityProvider.java:95)
    at com.atlassian.streams.internal.LocalActivityProvider$FeedFetcher.doInTransaction(LocalActivityProvider.java:201)
    at com.atlassian.streams.internal.LocalActivityProvider$FeedFetcher.doInTransaction(LocalActivityProvider.java:184)
    at com.atlassian.sal.core.transaction.HostContextTransactionTemplate$1.doInTransaction(HostContextTransactionTemplate.java:25)
    at com.atlassian.jira.DefaultHostContextAccessor.doInTransaction(DefaultHostContextAccessor.java:34)  <+2> (DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at com.atlassian.plugin.osgi.hostcomponents.impl.DefaultComponentRegistrar$ContextClassLoaderSettingInvocationHandler.invoke(DefaultComponentRegistrar.java:129)
    at $Proxy405.doInTransaction(Unknown Source)  <+2> (DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at com.atlassian.plugin.osgi.bridge.external.HostComponentFactoryBean$DynamicServiceInvocationHandler.invoke(HostComponentFactoryBean.java:154)
    at $Proxy405.doInTransaction(Unknown Source)
    at com.atlassian.sal.core.transaction.HostContextTransactionTemplate.execute(HostContextTransactionTemplate.java:21)  <+2> (DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
    at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:58)
    at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:62)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.osgi.service.util.internal.aop.ServiceTCCLInterceptor.invokeUnprivileged(ServiceTCCLInterceptor.java:56)
    at org.springframework.osgi.service.util.internal.aop.ServiceTCCLInterceptor.invoke(ServiceTCCLInterceptor.java:39)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.osgi.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:59)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
    at $Proxy1699.execute(Unknown Source)
    at com.atlassian.streams.internal.LocalActivityProvider$1$1.get(LocalActivityProvider.java:125)
    at com.atlassian.streams.internal.LocalActivityProvider$1$1.get(LocalActivityProvider.java:122)
    at com.atlassian.streams.jira.JiraSessionManager.withSession(JiraSessionManager.java:19)
    at com.atlassian.streams.common.SwitchingSessionManager.withSession(SwitchingSessionManager.java:30)  <+2> (DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
    at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:58)
    at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:62)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.osgi.service.util.internal.aop.ServiceTCCLInterceptor.invokeUnprivileged(ServiceTCCLInterceptor.java:56)
    at org.springframework.osgi.service.util.internal.aop.ServiceTCCLInterceptor.invoke(ServiceTCCLInterceptor.java:39)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.osgi.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:59)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
    at $Proxy1706.withSession(Unknown Source)
    at com.atlassian.streams.internal.LocalActivityProvider$1.call(LocalActivityProvider.java:121)
    at com.atlassian.streams.internal.LocalActivityProvider$1.call(LocalActivityProvider.java:117)
    at com.atlassian.streams.internal.FeedBuilder$ToFeedCallable$1.call(FeedBuilder.java:115)
    at com.atlassian.streams.internal.FeedBuilder$ToFeedCallable$1.call(FeedBuilder.java:110)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    at com.atlassian.util.concurrent.LimitedExecutor$Runner.run(LimitedExecutor.java:93)
    at com.atlassian.sal.core.executor.ThreadLocalDelegateRunnable.run(ThreadLocalDelegateRunnable.java:38)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.NullPointerException
    at net.sourceforge.jtds.jdbc.JtdsStatement.close(JtdsStatement.java:868)
    at net.sourceforge.jtds.jdbc.JtdsPreparedStatement.close(JtdsPreparedStatement.java:487)
    at org.apache.commons.dbcp.DelegatingStatement.close(DelegatingStatement.java:168)
    at org.apache.commons.dbcp.DelegatingStatement.close(DelegatingStatement.java:168)
    at org.ofbiz.core.entity.jdbc.SQLProcessor.close(SQLProcessor.java:280)
    at org.ofbiz.core.entity.GenericDAO.select(GenericDAO.java:467)
    at org.ofbiz.core.entity.GenericHelperDAO.findByPrimaryKey(GenericHelperDAO.java:78)
    at org.ofbiz.core.entity.GenericDelegator.findByPrimaryKey(GenericDelegator.java:541)
    at org.ofbiz.core.entity.GenericDelegator.findByPrimaryKey(GenericDelegator.java:576)
    at com.atlassian.jira.ofbiz.DefaultOfBizDelegator.findByPrimaryKey(DefaultOfBizDelegator.java:414)
    at com.atlassian.jira.ofbiz.DefaultOfBizDelegator.findByPrimaryKey(DefaultOfBizDelegator.java:406)
    at com.atlassian.jira.ofbiz.DefaultOfBizDelegator.findById(DefaultOfBizDelegator.java:397)
    at com.atlassian.jira.issue.managers.DefaultIssueManager.getIssue(DefaultIssueManager.java:107)
    at com.atlassian.jira.issue.managers.DefaultIssueManager.getIssueObject(DefaultIssueManager.java:295)
    at com.atlassian.jira.issue.AbstractIssue.getParentObject(AbstractIssue.java:66)
    at com.atlassian.jira.issue.IssueImpl.getParentObject(IssueImpl.java:1044)
    at com.atlassian.jira.security.WorkflowBasedPermissionManager.addParentPermissionsIfSubTask(WorkflowBasedPermissionManager.java:142)
    at com.atlassian.jira.security.WorkflowBasedPermissionManager.hasPermission(WorkflowBasedPermissionManager.java:79)
    at com.atlassian.jira.security.AbstractPermissionManager.hasPermission(AbstractPermissionManager.java:122)
    at com.atlassian.jira.security.AbstractPermissionManager.hasPermission(AbstractPermissionManager.java:151)  <+2> (DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at com.atlassian.util.profiling.object.ObjectProfiler.profiledInvoke(ObjectProfiler.java:83)
    at com.atlassian.jira.config.component.SwitchingInvocationHandler.invoke(SwitchingInvocationHandler.java:28)
    at $Proxy76.hasPermission(Unknown Source)  <+2> (DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at com.atlassian.plugin.osgi.hostcomponents.impl.DefaultComponentRegistrar$ContextClassLoaderSettingInvocationHandler.invoke(DefaultComponentRegistrar.java:129)
    at $Proxy76.hasPermission(Unknown Source)  <+2> (DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
    at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:58)
    at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:62)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.osgi.service.util.internal.aop.ServiceTCCLInterceptor.invokeUnprivileged(ServiceTCCLInterceptor.java:56)
    at org.springframework.osgi.service.util.internal.aop.ServiceTCCLInterceptor.invoke(ServiceTCCLInterceptor.java:39)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.osgi.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:59)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
    at $Proxy1626.hasPermission(Unknown Source)
    at com.atlassian.streams.jira.search.IssueFinder$1.apply(IssueFinder.java:80)
    at com.atlassian.streams.jira.search.IssueFinder$1.apply(IssueFinder.java:77)
    at com.google.common.base.Predicates$AndPredicate.apply(Predicates.java:338)
    at com.google.common.collect.Iterators$7.computeNext(Iterators.java:645)
    at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
    at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
    at com.google.common.collect.Maps.uniqueIndex(Maps.java:567)
    at com.google.common.collect.Maps.uniqueIndex(Maps.java:527)
    at com.atlassian.jira.issue.changehistory.ChangeHistoryBatch.<init>(ChangeHistoryBatch.java:112)
    at com.atlassian.jira.issue.changehistory.ChangeHistoryBatch.createBatchForIssue(ChangeHistoryBatch.java:66)
    at com.atlassian.jira.issue.changehistory.DefaultChangeHistoryManager.getAllChangeHistories(DefaultChangeHistoryManager.java:102)
    at com.atlassian.jira.issue.changehistory.DefaultChangeHistoryManager.getChangeHistoriesForUser(DefaultChangeHistoryManager.java:95)  <+2> (DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at com.atlassian.plugin.osgi.hostcomponents.impl.DefaultComponentRegistrar$ContextClassLoaderSettingInvocationHandler.invoke(DefaultComponentRegistrar.java:129)
    at $Proxy92.getChangeHistoriesForUser(Unknown Source)  <+2> (DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
    at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:58)
    at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:62)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.osgi.service.util.internal.aop.ServiceTCCLInterceptor.invokeUnprivileged(ServiceTCCLInterceptor.java:56)
    at org.springframework.osgi.service.util.internal.aop.ServiceTCCLInterceptor.invoke(ServiceTCCLInterceptor.java:39)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.osgi.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:59)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
    at $Proxy1544.getChangeHistoriesForUser(Unknown Source)
    at com.atlassian.streams.jira.changehistory.BulkIssueHistoryReader.doGetChangeHistoriesForUser(BulkIssueHistoryReader.java:69)
    at com.atlassian.streams.jira.changehistory.BulkIssueHistoryReader.access$200(BulkIssueHistoryReader.java:28)
    at com.atlassian.streams.jira.changehistory.BulkIssueHistoryReader$BulkIterator.<init>(BulkIssueHistoryReader.java:86)
    at com.atlassian.streams.jira.changehistory.BulkIssueHistoryReader$BulkIterator.<init>(BulkIssueHistoryReader.java:78)
    at com.atlassian.streams.jira.changehistory.BulkIssueHistoryReader$1.iterator(BulkIssueHistoryReader.java:56)
    ... 79 more
2015-03-11 15:13:11,337 http-bio-443-exec-23 DEBUG worthar 893x1624x1 1tfhzu2 10.21.100.13 /secure/CommentAssignIssue.jspa [com.custom.HourCollector] response: 200
2015-03-11 15:13:11,384 http-bio-443-exec-23 DEBUG worthar 893x1624x1 1tfhzu2 10.21.100.13 /secure/CommentAssignIssue.jspa [com.custom.HourCollector] []
2015-03-11 15:13:11,384 http-bio-443-exec-23 DEBUG worthar 893x1624x1 1tfhzu2 10.21.100.13 /secure/CommentAssignIssue.jspa [com.custom.HourCollector] push to DB: worthar || 70201 || 0 || 6352880 || 0040 || 2015-03-11
2015-03-11 15:13:11,399 http-bio-443-exec-23 DEBUG worthar 893x1624x1 1tfhzu2 10.21.100.13 /secure/CommentAssignIssue.jspa [com.custom.HourCollector] row pushed.  need to update this row.
2015-03-11 15:13:11,399 http-bio-443-exec-23 DEBUG worthar 893x1624x1 1tfhzu2 10.21.100.13 /secure/CommentAssignIssue.jspa [com.custom.HourCollector] row found.  need to update that row.
2015-03-11 15:13:11,399 http-bio-443-exec-23 DEBUG worthar 893x1624x1 1tfhzu2 10.21.100.13 /secure/CommentAssignIssue.jspa [com.custom.HourCollector] -------- End Hour Collector ---------------

Comments (13)

  1. Andriy Zhdanov

    Hi Tanner,

    Sorry for delay. Could you please try if it returns correct hours after workflow transition in browser, e.g. http://localhost:2990/jira/rest/timesheet-gadget/1.0/raw-timesheet.json

    Also, does work log look correct after workflow transition in JIRA itself?

    Thank you.

  2. Former user Account Deleted

    Yo! I attached a screenshot of what happens on the front end when attempting to log time from a transition. In short, it won't let me. I think the following might answer your other question.

    URL for both result sets below: URL: http://rnod-jira01.is.ad.igt.com:8080/rest/timesheet-gadget/1.0/raw-timesheet.json?targetUser=worthar&projectid=10604&startDate=2015-03-16&endDate=2015-03-16

    Here's the raw result from the add on for a successful entry:

    result: [startDate:1426489200000, endDate:1426575600000, worklog:[[summary:t20, entries:[[startDate:1426527180000, author:worthar, updated:1426527227620, created:1426527227620, updateAuthorFullName:Wortham.Tanner, updateAuthor:worthar, timeSpent:3600, comment:, authorFullName:Wortham.Tanner], [startDate:1426527540000, author:worthar, updated:1426527594570, created:1426527594570, updateAuthorFullName:Wortham.Tanner, updateAuthor:worthar, timeSpent:3600, comment:, authorFullName:Wortham.Tanner], [startDate:1426527600000, author:worthar, updated:1426527627893, created:1426527627893, updateAuthorFullName:Wortham.Tanner, updateAuthor:worthar, timeSpent:3600, comment:, authorFullName:Wortham.Tanner], [startDate:1426527600000, author:worthar, updated:1426527644070, created:1426527644070, updateAuthorFullName:Wortham.Tanner, updateAuthor:worthar, timeSpent:3600, comment:, authorFullName:Wortham.Tanner], [startDate:1426527660000, author:worthar, updated:1426527700573, created:1426527700573, updateAuthorFullName:Wortham.Tanner, updateAuthor:worthar, timeSpent:1800, comment:, authorFullName:Wortham.Tanner], [startDate:1426527720000, author:worthar, updated:1426527728607, created:1426527728607, updateAuthorFullName:Wortham.Tanner, updateAuthor:worthar, timeSpent:1800, comment:, authorFullName:Wortham.Tanner], [startDate:1426527780000, author:worthar, updated:1426527803847, created:1426527803847, updateAuthorFullName:Wortham.Tanner, updateAuthor:worthar, timeSpent:1800, comment:, authorFullName:Wortham.Tanner], [startDate:1426527780000, author:worthar, updated:1426527834143, created:1426527834143, updateAuthorFullName:Wortham.Tanner, updateAuthor:worthar, timeSpent:1800, comment:, authorFullName:Wortham.Tanner], [startDate:1426527840000, author:worthar, updated:1426527856640, created:1426527856640, updateAuthorFullName:Wortham.Tanner, updateAuthor:worthar, timeSpent:1800, comment:, authorFullName:Wortham.Tanner]], key:MISSWHITE-349]]]
    

    And here's another result on the same issue run immediately after and when I try to log time from a transition. Note that it does not include all the time entries for the entire day. If you look at the stack traces above, you'll also see some badness as the database goes wonky for reasons I don't understand but related either to my code or your plugin:

    result: [startDate:1426489200000, endDate:1426575600000, worklog:[[summary:t20, entries:[[startDate:1426527180000, author:worthar, updated:1426527227620, created:1426527227620, updateAuthorFullName:Wortham.Tanner, updateAuthor:worthar, timeSpent:3600, comment:, authorFullName:Wortham.Tanner]], key:MISSWHITE-349]]]
    
  3. Andriy Zhdanov

    Looks like there is some problem with workflow transition, isn't it? And are there worklogs in issue - work log tab after workflow transition?

  4. Former user Account Deleted

    This problem only presents itself when I'm entering time at transition. Also note that:

    • If I transition without entering time, no error occurs.
    • If I remove my listener that calls Time Sheet and enter time at a transition, no error happens.
    • Time Sheet does not provide the proper time entries when called during the transition. (Look at comment above for evidence.)
    • Our workflow has several transitions. It doesn't matter which transition I attempt to log time. It crashes on all.

    All those facts mean the problem either exists in my code (HourCollector.groovy) or in the plugin itself.

    And are there worklogs in issue - work log tab after workflow transition?

    Yes. That result set provided earlier today was done on the same issue. I did the successful test before I did the failed test. I believe if you sum up the entries in the successful entry above you'll get 6.5h for the successful test, but the failed one returns 1h, which was only the time entry I was attempting to add at the transition and not the enter set as indicated by the URL I had called:

    http://rnod-jira01.is.ad.igt.com:8080/rest/timesheet-gadget/1.0/raw-timesheet.json?targetUser=worthar&projectid=10604&startDate=2015-03-16&endDate=2015-03-16

    Attached is a screenshot of part of the worklog tab as further evidence.

  5. Andriy Zhdanov

    May be there is an exception in jira log when you access timesheet rest endpoint?

    I remember there was similar problem, kind of cycle dependency, when reading worklogs (using rest) in post function of workflow that adds worklog. I can't find it now, but I think solution was to call rest asynchronously, after some time out, when transition is finished.

    Alternatively, you may try standard JIRA rest for the use case, it seems more appropriate, see worklog endpoint.

  6. Former user Account Deleted

    The entries that I pass across to another system are those for a particular user, for a particular project, and for a particular day. I don't believe JIRA's REST has that capability, but yours does. I'm going to see if I can turn up something up that asynchronous stuff you mention. If you happen to find it, feel free to send it my way.

  7. Former user Account Deleted

    May be there is an exception in jira log when you access timesheet rest endpoint?

    This looks like the error. See my initial post for additional context since the entire stack trace exists there.

    2015-03-11 15:13:11,337 http-bio-8080-exec-10 WARN automation 893x1625x2 11vkbwm 10.210.44.18 /rest/timesheet-gadget/1.0/raw-timesheet.json [core.entity.jdbc.SQLProcessor] Invalid state, the PreparedStatement object is closed.
    2015-03-11 15:13:11,337 StreamsCompletionService::thread-685 ERROR worthar 898x1635x6 1tfhzu2 10.21.100.13 /plugins/servlet/streams [atlassian.streams.internal.LocalActivityProvider] Error building feed
    java.lang.RuntimeException: Error creating BulkIterator
    
  8. Andriy Zhdanov

    Yes, but not in plugin. I've just managed to find other similar issue you have had, see issue#497. Not sure if there was anyone else. Will let you know if I find something.

  9. Log in to comment