Esper

Timer thread caught unhandled exception in named window with time_batch

Details

  • Type: Bug Bug
  • Status: Closed Closed
  • Priority: Major Major
  • Resolution: Cannot Reproduce
  • Affects Version/s: 3.3
  • Fix Version/s: 3.2
  • Component/s: Core
  • Labels:
    None
  • Environment:
    OSX 10.6.2, Java 1.6.0_17
  • Number of attachments :
    1

Description

When trying to use named window with win:time_batch, Esper will get an unhandled exception after couple minutes.

The EPL used to create named window:
CREATE WINDOW everestDataWindow.win:time_batch(60 sec) as select * from Metric

The EPL to insert data:
INSERT INTO everestDataWindow SELECT * FROM Metric(app='worker')

The on select EPL used to select in named window when Latency event shows up:
on Latency(app='worker') as latency
SELECT *
FROM everestDataWindow as win
WHERE latency.hostname = win.hostname
AND latency.colo = win.colo
AND ( win.name like 'worker.p%.50th' OR
win.name like 'worker.services.p%.99th' OR )

And here's the stack trace:
2010-02-23 17:08:25,678 [com.espertech.esper.Timer-default-0] ERROR com.espertech.esper.timer.EPLTimerTask - Timer thread caught unhandled exception: null
java.util.ConcurrentModificationException
at java.util.LinkedHashMap$LinkedHashIterator.nextEntry(LinkedHashMap.java:373)
at java.util.LinkedHashMap$KeyIterator.next(LinkedHashMap.java:384)
at java.util.AbstractCollection.toArray(AbstractCollection.java:171)
at com.espertech.esper.view.window.TimeBatchViewRStream.sendBatch(TimeBatchViewRStream.java:207)
at com.espertech.esper.view.window.TimeBatchViewRStream$1.scheduledTrigger(TimeBatchViewRStream.java:290)
at com.espertech.esper.core.EPRuntimeImpl.processStatementScheduleMultiple(EPRuntimeImpl.java:874)
at com.espertech.esper.core.EPRuntimeImpl.processScheduleHandles(EPRuntimeImpl.java:610)
at com.espertech.esper.core.EPRuntimeImpl.processSchedule(EPRuntimeImpl.java:491)
at com.espertech.esper.core.EPRuntimeImpl.processTimeEvent(EPRuntimeImpl.java:462)
at com.espertech.esper.core.EPRuntimeImpl.processEvent(EPRuntimeImpl.java:365)
at com.espertech.esper.core.EPRuntimeImpl.sendEvent(EPRuntimeImpl.java:210)
at com.espertech.esper.core.EPRuntimeImpl.timerCallback(EPRuntimeImpl.java:184)
at com.espertech.esper.timer.EPLTimerTask.run(EPLTimerTask.java:61)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205)
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:637)

Activity

Hide
Thomas Bernhardt added a comment -

Hi Mark,

what version of Esper is this please?
We have not been able to reproduce, our test case is attached.

Best regards
Tom

Show
Thomas Bernhardt added a comment - Hi Mark, what version of Esper is this please? We have not been able to reproduce, our test case is attached. Best regards Tom
Hide
Mark Lin added a comment -

Tom,

We are running 3.3.0. However, as of late, I don't see this particular error anymore, however, as number of events start to increase, I am starting to see many of these error. And when they occur, although application doesn't crash, esper no longer process events. The EPL are essentially the same ones I pasted above, the big difference is we are sending 2X events.

2010-03-15 19:52:23,692 [com.espertech.esper.Timer-default-0] ERROR com.espertech.esper.timer.EPLTimerTask - Timer thread caught unhandled exception: 5602
java.lang.ArrayIndexOutOfBoundsException: 5602
at java.util.LinkedList.toArray(LinkedList.java:915)
at com.espertech.esper.view.window.TimeBatchView.sendBatch(TimeBatchView.java:223)
at com.espertech.esper.view.window.TimeBatchView$1.scheduledTrigger(TimeBatchView.java:311)
at com.espertech.esper.core.EPRuntimeImpl.processStatementScheduleSingle(EPRuntimeImpl.java:909)
at com.espertech.esper.core.EPRuntimeImpl.processScheduleHandles(EPRuntimeImpl.java:538)
at com.espertech.esper.core.EPRuntimeImpl.processSchedule(EPRuntimeImpl.java:491)
at com.espertech.esper.core.EPRuntimeImpl.processTimeEvent(EPRuntimeImpl.java:462)
at com.espertech.esper.core.EPRuntimeImpl.processEvent(EPRuntimeImpl.java:365)
at com.espertech.esper.core.EPRuntimeImpl.sendEvent(EPRuntimeImpl.java:210)
at com.espertech.esper.core.EPRuntimeImpl.timerCallback(EPRuntimeImpl.java:184)
at com.espertech.esper.timer.EPLTimerTask.run(EPLTimerTask.java:61)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205)
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:619)

Thanks,
Mark

Show
Mark Lin added a comment - Tom, We are running 3.3.0. However, as of late, I don't see this particular error anymore, however, as number of events start to increase, I am starting to see many of these error. And when they occur, although application doesn't crash, esper no longer process events. The EPL are essentially the same ones I pasted above, the big difference is we are sending 2X events. 2010-03-15 19:52:23,692 [com.espertech.esper.Timer-default-0] ERROR com.espertech.esper.timer.EPLTimerTask - Timer thread caught unhandled exception: 5602 java.lang.ArrayIndexOutOfBoundsException: 5602 at java.util.LinkedList.toArray(LinkedList.java:915) at com.espertech.esper.view.window.TimeBatchView.sendBatch(TimeBatchView.java:223) at com.espertech.esper.view.window.TimeBatchView$1.scheduledTrigger(TimeBatchView.java:311) at com.espertech.esper.core.EPRuntimeImpl.processStatementScheduleSingle(EPRuntimeImpl.java:909) at com.espertech.esper.core.EPRuntimeImpl.processScheduleHandles(EPRuntimeImpl.java:538) at com.espertech.esper.core.EPRuntimeImpl.processSchedule(EPRuntimeImpl.java:491) at com.espertech.esper.core.EPRuntimeImpl.processTimeEvent(EPRuntimeImpl.java:462) at com.espertech.esper.core.EPRuntimeImpl.processEvent(EPRuntimeImpl.java:365) at com.espertech.esper.core.EPRuntimeImpl.sendEvent(EPRuntimeImpl.java:210) at com.espertech.esper.core.EPRuntimeImpl.timerCallback(EPRuntimeImpl.java:184) at com.espertech.esper.timer.EPLTimerTask.run(EPLTimerTask.java:61) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205) 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:619) Thanks, Mark
Hide
Mark Lin added a comment -

I am very much java newbie, please pardon my immature attempt to debug.

Additional info for this exception, java.lang.ArrayIndexOutOfBoundsException: 5602

Here's the line for TimeBatchView.java:223:

newData = currentBatch.toArray(new EventBean[currentBatch.size()]);

And the small piece in LinkedList.toArray function that caused the exception:

if (a.length < size)
a = (T[])java.lang.reflect.Array.newInstance(
a.getClass().getComponentType(), size);
int i = 0;
int i = 0;
Object[] result = a;
for (Entry<E> e = header.next; e != header; e = e.next)
result[i++] = e.element; //This is the exception line

The exception indicates that an array has been accessed with an illegal index. I am guess there might a case where the linked list grows after array allocation but before the for loop. So I added the code to monitor currentBatch size and a try clause around currentBatch.toArray.

String _name = this.statementContext.getStatementName();
try {
if (! currentBatch.isEmpty())

{ Integer bs = currentBatch.size(); log.debug(_name + " batch size: " + bs); newData = currentBatch.toArray(new EventBean[bs]); }

} catch(Exception e) { log.error(_name + " current size: " + currentBatch.size() + " exception: " + e.getMessage()); }

When I eventually reproduce the problem, it did look like list grew before the loop, the exception tells us which index it tried to use.

2010-03-19 01:11:56,556 [com.espertech.esper.Timer-default-0] INFO com.espertech.esper.view.window.TimeBatchView - everestLatencyEvent batch size: 4763
2010-03-19 01:11:56,558 [com.espertech.esper.Timer-default-0] ERROR com.espertech.esper.view.window.TimeBatchView - everestLatencyEvent current size: 4774 exception: 4766

I guess I can make a copy of the currentBatch to ensure it wont grow while doing toArray, but I am afraid to break other things. Or maybe someway to stop updating the batch without losing any event, but I couldn't find that. Any advice?

Thanks,
Mark

Show
Mark Lin added a comment - I am very much java newbie, please pardon my immature attempt to debug. Additional info for this exception, java.lang.ArrayIndexOutOfBoundsException: 5602 Here's the line for TimeBatchView.java:223: newData = currentBatch.toArray(new EventBean[currentBatch.size()]); And the small piece in LinkedList.toArray function that caused the exception: if (a.length < size) a = (T[])java.lang.reflect.Array.newInstance( a.getClass().getComponentType(), size); int i = 0; int i = 0; Object[] result = a; for (Entry<E> e = header.next; e != header; e = e.next) result[i++] = e.element; //This is the exception line The exception indicates that an array has been accessed with an illegal index. I am guess there might a case where the linked list grows after array allocation but before the for loop. So I added the code to monitor currentBatch size and a try clause around currentBatch.toArray. String _name = this.statementContext.getStatementName(); try { if (! currentBatch.isEmpty()) { Integer bs = currentBatch.size(); log.debug(_name + " batch size: " + bs); newData = currentBatch.toArray(new EventBean[bs]); } } catch(Exception e) { log.error(_name + " current size: " + currentBatch.size() + " exception: " + e.getMessage()); } When I eventually reproduce the problem, it did look like list grew before the loop, the exception tells us which index it tried to use. 2010-03-19 01:11:56,556 [com.espertech.esper.Timer-default-0] INFO com.espertech.esper.view.window.TimeBatchView - everestLatencyEvent batch size: 4763 2010-03-19 01:11:56,558 [com.espertech.esper.Timer-default-0] ERROR com.espertech.esper.view.window.TimeBatchView - everestLatencyEvent current size: 4774 exception: 4766 I guess I can make a copy of the currentBatch to ensure it wont grow while doing toArray, but I am afraid to break other things. Or maybe someway to stop updating the batch without losing any event, but I couldn't find that. Any advice? Thanks, Mark

People

  • Assignee:
    Unassigned
    Reporter:
    Mark Lin
Vote (0)
Watch (1)

Dates

  • Created:
    Updated:
    Resolved: