[jira] [Assigned] (ASTERIXDB-2323) LogFlusher failed after repeating insert operation a lot of times

["Till (JIRA)" <ji...@apache.org>]

     [ https://issues.apache.org/jira/browse/ASTERIXDB-2323?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Till reassigned ASTERIXDB-2323:
-------------------------------

    Assignee: Xikui Wang  (was: Chen Luo)

> LogFlusher failed after repeating insert operation a lot of times
> -----------------------------------------------------------------
>
>                 Key: ASTERIXDB-2323
>                 URL: https://issues.apache.org/jira/browse/ASTERIXDB-2323
>             Project: Apache AsterixDB
>          Issue Type: Bug
>            Reporter: Xikui Wang
>            Assignee: Xikui Wang
>            Priority: Major
>         Attachments: nc-local2.log
>
>
> I'm running an experiment which inserts records into dataset. Each insert contains a frame of data and records have a unique increasing primary key. After a lot of inserts, the LogFlluser fails which causes the system to hang. Here is the log snippet (JobID roughly equals the number of inserts that I tried). The full log is attached too.
> {code}
> 15:40:41.783 [Worker:local2] INFO org.apache.hyracks.control.common.work.WorkQueue - Executing: StartTasks
> 15:40:41.783 [Worker:local2] INFO org.apache.hyracks.control.nc.work.StartTasksWork - Initializing TAID:TID:ANID:ODID:3:0:0:0 -> [FeedMeta [org.apache.asterix.runtime.operators.LSMPrimaryUpsertOperatorDescriptor@6ba3bb2f ], AlgebricksMeta [stream-project [2], commit]] for JID:0.27223
> 15:40:41.783 [Worker:local2] INFO org.apache.hyracks.control.nc.work.StartTasksWork - input: 0: CDID:2
> 15:40:41.820 [Worker:local2] INFO org.apache.hyracks.control.common.work.WorkQueue - Executing: NotifyTaskCompleteWork:TAID:TID:ANID:ODID:3:0:0:0
> 15:40:41.821 [Worker:local2] INFO org.apache.hyracks.control.common.work.WorkQueue - Executing: CleanupJoblet
> 15:40:41.821 [Worker:local2] INFO org.apache.hyracks.control.nc.work.CleanupJobletWork - Cleaning up after job: JID:0.27214
> 15:40:41.882 [Worker:local2] INFO org.apache.hyracks.control.nc.Joblet - Freeing leaked 163840 bytes
> 15:40:41.882 [Worker:local2] WARN org.apache.hyracks.control.common.work.WorkQueue - Work CleanupJoblet waited 1 times (~0ms), blocked 1 times (~0ms)
> 15:40:41.882 [Worker:local2] INFO org.apache.hyracks.control.common.work.WorkQueue - Executing: NotifyTaskCompleteWork:TAID:TID:ANID:ODID:3:0:0:0
> 15:40:41.882 [Worker:local2] INFO org.apache.hyracks.control.common.work.WorkQueue - Executing: NotifyTaskCompleteWork:TAID:TID:ANID:ODID:3:0:0:0
> 15:40:41.882 [Worker:local2] INFO org.apache.hyracks.control.common.work.WorkQueue - Executing: NotifyTaskCompleteWork:TAID:TID:ANID:ODID:3:0:0:0
> 15:40:41.882 [Worker:local2] INFO org.apache.hyracks.control.common.work.WorkQueue - Executing: CleanupJoblet
> 15:40:41.882 [Worker:local2] INFO org.apache.hyracks.control.nc.work.CleanupJobletWork - Cleaning up after job: JID:0.27215
> 15:40:41.883 [Executor-2:local2] ERROR org.apache.asterix.transaction.management.service.logging.LogFlusher - LogFlusher is terminating abnormally. System is in unusable state.
> java.lang.IllegalStateException: java.lang.IllegalStateException
>  at org.apache.asterix.transaction.management.service.logging.LogBuffer.internalFlush(LogBuffer.java:204) ~[asterix-transactions-0.9.4-SNAPSHOT.jar:0.9.4-SNAPSHOT]
>  at org.apache.asterix.transaction.management.service.logging.LogBuffer.flush(LogBuffer.java:174) ~[asterix-transactions-0.9.4-SNAPSHOT.jar:0.9.4-SNAPSHOT]
>  at org.apache.asterix.transaction.management.service.logging.LogFlusher.call(LogManager.java:711) [asterix-transactions-0.9.4-SNAPSHOT.jar:0.9.4-SNAPSHOT]
>  at org.apache.asterix.transaction.management.service.logging.LogFlusher.call(LogManager.java:666) [asterix-transactions-0.9.4-SNAPSHOT.jar:0.9.4-SNAPSHOT]
>  at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_151]
>  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_151]
>  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_151]
>  at java.lang.Thread.run(Thread.java:748) [?:1.8.0_151]
> Caused by: java.lang.IllegalStateException
>  at org.apache.asterix.transaction.management.service.logging.LogBufferTailReader.next(LogBufferTailReader.java:49) ~[asterix-transactions-0.9.4-SNAPSHOT.jar:0.9.4-SNAPSHOT]
>  at org.apache.asterix.transaction.management.service.logging.LogBuffer.batchUnlock(LogBuffer.java:245) ~[asterix-transactions-0.9.4-SNAPSHOT.jar:0.9.4-SNAPSHOT]
>  at org.apache.asterix.transaction.management.service.logging.LogBuffer.internalFlush(LogBuffer.java:201) ~[asterix-transactions-0.9.4-SNAPSHOT.jar:0.9.4-SNAPSHOT]
>  ... 7 more
> 15:41:32.392 [Checkpoint Thread (31)] INFO org.apache.asterix.transaction.management.service.recovery.CheckpointManager - Attemping soft checkpoint...
> {code}



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)