You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hudi.apache.org by "sivabalan narayanan (Jira)" <ji...@apache.org> on 2021/11/23 00:29:00 UTC

[jira] [Closed] (HUDI-2666) async compaction failing with timeline mismatches between server and client when metadata is enabled

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

sivabalan narayanan closed HUDI-2666.
-------------------------------------
    Resolution: Duplicate

> async compaction failing with timeline mismatches between server and client when metadata is enabled
> ----------------------------------------------------------------------------------------------------
>
>                 Key: HUDI-2666
>                 URL: https://issues.apache.org/jira/browse/HUDI-2666
>             Project: Apache Hudi
>          Issue Type: Sub-task
>          Components: Writer Core
>    Affects Versions: 0.10.0
>            Reporter: sivabalan narayanan
>            Assignee: sivabalan narayanan
>            Priority: Blocker
>             Fix For: 0.10.0
>
>
> async compaction in data table fails due to timeline mismatches between server and client when metadata is enabled. Ran a local deltastreamer continuous mode for MOR with metadata enable and ran into this issue when compaction was attempted in data table. 
>  
> {code:java}
> // 21/11/01 21:20:24 INFO RequestHandler: Syncing view as client passed last known instant 20211101211957 as last known instant but server has the following last instant on timeline :Option{val=[20211101211957__commit__COMPLETED]}
> 21/11/01 21:20:24 INFO HoodieBackedTableMetadata: Metadata read for 1 keys took [baseFileRead, logMerge] [0, 0] ms
> 21/11/01 21:20:24 INFO BaseTableMetadata: Listed file in partition from metadata: partition=2019-11-25, #files=4
> 21/11/01 21:20:24 INFO FileSystemViewManager: Creating InMemory based view for basePath file:/tmp/hudi-deltastreamer-ny
> 21/11/01 21:20:24 INFO AbstractTableFileSystemView: Took 0 ms to read  0 instants, 0 replaced file groups
> 21/11/01 21:20:24 INFO AbstractTableFileSystemView: addFilesToView: NumFiles=4, NumFileGroups=1, FileGroupsCreationTime=0, StoreTimeTaken=0
> 21/11/01 21:20:24 ERROR RequestHandler: Got runtime exception servicing request partition=2019-11-25&maxinstant=20211101211928&basepath=file%3A%2Ftmp%2Fhudi-deltastreamer-ny&lastinstantts=20211101211957&timelinehash=13c65050b73c007140b10ac6141a98f66a34e958ebc98ea76b09bd6422549cb7
> java.lang.IllegalArgumentException: Last known instant from client was 20211101211957 but server has the following timeline [[20211101211815__deltacommit__COMPLETED], [20211101211848__deltacommit__COMPLETED], [20211101211928__deltacommit__COMPLETED], [20211101211957__commit__COMPLETED]]
> 	at org.apache.hudi.common.util.ValidationUtils.checkArgument(ValidationUtils.java:40)
> 	at org.apache.hudi.timeline.service.RequestHandler$ViewHandler.handle(RequestHandler.java:510)
> 	at io.javalin.security.SecurityUtil.noopAccessManager(SecurityUtil.kt:22)
> 	at io.javalin.Javalin.lambda$addHandler$0(Javalin.java:606)
> 	at io.javalin.core.JavalinServlet$service$2$1.invoke(JavalinServlet.kt:46)
> 	at io.javalin.core.JavalinServlet$service$2$1.invoke(JavalinServlet.kt:17)
> 	at io.javalin.core.JavalinServlet$service$1.invoke(JavalinServlet.kt:143)
> 	at io.javalin.core.JavalinServlet$service$2.invoke(JavalinServlet.kt:41)
> 	at io.javalin.core.JavalinServlet.service(JavalinServlet.kt:107)
> 	at io.javalin.core.util.JettyServerUtil$initialize$httpHandler$1.doHandle(JettyServerUtil.kt:72)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
> 	at org.apache.hudi.org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
> 	at org.apache.hudi.org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1668)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:61)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:174)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
> 	at org.apache.hudi.org.eclipse.jetty.server.Server.handle(Server.java:502)
> 	at org.apache.hudi.org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:370)
> 	at org.apache.hudi.org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:267)
> 	at org.apache.hudi.org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
> 	at org.apache.hudi.org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
> 	at org.apache.hudi.org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
> 	at java.lang.Thread.run(Thread.java:748)
> 21/11/01 21:20:24 WARN ExceptionMapper: Uncaught exception
> java.lang.IllegalArgumentException: Last known instant from client was 20211101211957 but server has the following timeline [[20211101211815__deltacommit__COMPLETED], [20211101211848__deltacommit__COMPLETED], [20211101211928__deltacommit__COMPLETED], [20211101211957__commit__COMPLETED]]
> 	at org.apache.hudi.common.util.ValidationUtils.checkArgument(ValidationUtils.java:40)
> 	at org.apache.hudi.timeline.service.RequestHandler$ViewHandler.handle(RequestHandler.java:510)
> 	at io.javalin.security.SecurityUtil.noopAccessManager(SecurityUtil.kt:22)
> 	at io.javalin.Javalin.lambda$addHandler$0(Javalin.java:606)
> 	at io.javalin.core.JavalinServlet$service$2$1.invoke(JavalinServlet.kt:46)
> 	at io.javalin.core.JavalinServlet$service$2$1.invoke(JavalinServlet.kt:17)
> 	at io.javalin.core.JavalinServlet$service$1.invoke(JavalinServlet.kt:143)
> 	at io.javalin.core.JavalinServlet$service$2.invoke(JavalinServlet.kt:41)
> 	at io.javalin.core.JavalinServlet.service(JavalinServlet.kt:107)
> 	at io.javalin.core.util.JettyServerUtil$initialize$httpHandler$1.doHandle(JettyServerUtil.kt:72)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
> 	at org.apache.hudi.org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
> 	at org.apache.hudi.org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1668)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:61)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:174)
> 	at org.apache.hudi.org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
> 	at org.apache.hudi.org.eclipse.jetty.server.Server.handle(Server.java:502)
> 	at org.apache.hudi.org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:370)
> 	at org.apache.hudi.org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:267)
> 	at org.apache.hudi.org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
> 	at org.apache.hudi.org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
> 	at org.apache.hudi.org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
> 	at org.apache.hudi.org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
> 	at java.lang.Thread.run(Thread.java:748)
> 21/11/01 21:20:24 INFO HoodieActiveTimeline: Loaded instants upto : Option{val=[==>20211101212009__deltacommit__REQUESTED]}
> 21/11/01 21:20:24 ERROR PriorityBasedFileSystemView: Got error running preferred function. Trying secondary
> org.apache.hudi.exception.HoodieRemoteException: Server Error
> 	at org.apache.hudi.common.table.view.RemoteHoodieTableFileSystemView.getLatestBaseFilesFromParams(RemoteHoodieTableFileSystemView.java:241)
> 	at org.apache.hudi.common.table.view.RemoteHoodieTableFileSystemView.getLatestBaseFilesBeforeOrOn(RemoteHoodieTableFileSystemView.java:248)
> 	at org.apache.hudi.common.table.view.PriorityBasedFileSystemView.execute(PriorityBasedFileSystemView.java:97)
> 	at org.apache.hudi.common.table.view.PriorityBasedFileSystemView.getLatestBaseFilesBeforeOrOn(PriorityBasedFileSystemView.java:134)
> 	at org.apache.hudi.index.HoodieIndexUtils.getLatestBaseFilesForPartition(HoodieIndexUtils.java:54)
> 	at org.apache.hudi.index.HoodieIndexUtils.lambda$getLatestBaseFilesForAllPartitions$ff6885d8$1(HoodieIndexUtils.java:74)
> 	at org.apache.hudi.client.common.HoodieSparkEngineContext.lambda$flatMap$7d470b86$1(HoodieSparkEngineContext.java:134)
> 	at org.apache.spark.api.java.JavaRDDLike$$anonfun$fn$1$1.apply(JavaRDDLike.scala:125)
> 	at org.apache.spark.api.java.JavaRDDLike$$anonfun$fn$1$1.apply(JavaRDDLike.scala:125)
> 	at scala.collection.Iterator$$anon$12.nextCur(Iterator.scala:435)
> 	at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:441)
> 	at scala.collection.Iterator$class.foreach(Iterator.scala:891)
> 	at scala.collection.AbstractIterator.foreach(Iterator.scala:1334)
> 	at scala.collection.generic.Growable$class.$plus$plus$eq(Growable.scala:59)
> 	at scala.collection.mutable.ArrayBuffer.$plus$plus$eq(ArrayBuffer.scala:104)
> 	at scala.collection.mutable.ArrayBuffer.$plus$plus$eq(ArrayBuffer.scala:48)
> 	at scala.collection.TraversableOnce$class.to(TraversableOnce.scala:310)
> 	at scala.collection.AbstractIterator.to(Iterator.scala:1334)
> 	at scala.collection.TraversableOnce$class.toBuffer(TraversableOnce.scala:302)
> 	at scala.collection.AbstractIterator.toBuffer(Iterator.scala:1334)
> 	at scala.collection.TraversableOnce$class.toArray(TraversableOnce.scala:289)
> 	at scala.collection.AbstractIterator.toArray(Iterator.scala:1334)
> 	at org.apache.spark.rdd.RDD$$anonfun$collect$1$$anonfun$15.apply(RDD.scala:990)
> 	at org.apache.spark.rdd.RDD$$anonfun$collect$1$$anonfun$15.apply(RDD.scala:990)
> 	at org.apache.spark.SparkContext$$anonfun$runJob$5.apply(SparkContext.scala:2101)
> 	at org.apache.spark.SparkContext$$anonfun$runJob$5.apply(SparkContext.scala:2101)
> 	at org.apache.spark.scheduler.ResultTask.runTask(ResultTask.scala:90)
> 	at org.apache.spark.scheduler.Task.run(Task.scala:123)
> 	at org.apache.spark.executor.Executor$TaskRunner$$anonfun$10.apply(Executor.scala:408)
> 	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:1360)
> 	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:414)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> 	at java.lang.Thread.run(Thread.java:748)
> Caused by: org.apache.http.client.HttpResponseException: Server Error
> 	at org.apache.http.impl.client.AbstractResponseHandler.handleResponse(AbstractResponseHandler.java:70)
> 	at org.apache.http.client.fluent.Response.handleResponse(Response.java:90)
> 	at org.apache.http.client.fluent.Response.returnContent(Response.java:97)
> 	at org.apache.hudi.common.table.view.RemoteHoodieTableFileSystemView.executeRequest(RemoteHoodieTableFileSystemView.java:179)
> 	at org.apache.hudi.common.table.view.RemoteHoodieTableFileSystemView.getLatestBaseFilesFromParams(RemoteHoodieTableFileSystemView.java:237)
> 	... 33 more
> 21/11/01 21:20:24 INFO AbstractTableFileSystemView: Building file system view for partition (2019-11-25)
> {code}
>  
>  



--
This message was sent by Atlassian Jira
(v8.20.1#820001)