@Hitesh, Is there an option to limit the time spent clearing the backlog?
@Slava - If you are not using the Tez UI then perhaps you can disable timeline
integration or you could use an option, if such exists per question above, to
limit the final sync into ATS.
Bikas
> Subject: Re: hung AM due to timeline timeout
> From: hit...@apache.org
> Date: Wed, 3 Aug 2016 19:10:53 -0700
> To: user@tez.apache.org
>
> It might worth filing a YARN jira to get it backported to 2.6.x and 2.7.x. At
> the very least, it will simplify rebuilding the timeline-server jar against
> the CDH version that you are running.
>
> — Hitesh
>
> > On Aug 3, 2016, at 4:42 PM, Slava Markeyev <slava.marke...@upsight.com>
> > wrote:
> >
> > Thanks for the info Hitesh. Unfortunately it seems that RollingLevelDB is
> > only in trunk. I may have to backport it to 2.6.2 (version I use). I did
> > notice that the leveldb does grow to tens of gb which may be an indication
> > of pruning not happening often enough (or at all?). I also need to fix the
> > logging as the logs for the timeline server don't seem to be very active
> > beyond it starting up.
> >
> > For the job I posted before here is the associated eventQueueBacklog log
> > line.
> > 2016-08-03 19:23:27,932 [INFO] [AMShutdownThread]
> > |ats.ATSHistoryLoggingService|: Stopping ATSService, eventQueueBacklog=17553
> > I'll look into lowering tez.yarn.ats.event.flush.timeout.millis while
> > trying to look into the timelineserver.
> >
> > Thanks for your help,
> > Slava
> >
> > On Wed, Aug 3, 2016 at 2:45 PM, Hitesh Shah <hit...@apache.org> wrote:
> > Hello Slava,
> >
> > Can you check for a log line along the lines of "Stopping ATSService,
> > eventQueueBacklog=“ to see how backed up is the event queue to YARN
> > timeline?
> >
> > I have noticed this in quite a few installs with YARN Timeline where YARN
> > Timeline is using the simple Level DB impl and not the RollingLevelDB
> > storage class. The YARN timeline ends up hitting some bottlenecks around
> > the time when the data purging happens ( takes a global lock on level db ).
> > The Rolling level db storage impl solved this problem by using separate
> > level dos for different time intervals and just throwing out the level db
> > instead of trying to do a full scan+purge.
> >
> > Another workaround though not a great one is to set
> > “tez.yarn.ats.event.flush.timeout.millis” to a value say 60000 i.e. 1 min.
> > This implies that the Tez AM will try for at max 1 min to flush the queue
> > to YARN timeline before giving up and shutting down the Tez AM.
> >
> > A longer term option is the YARN Timeline version 1.5 work currently slated
> > to be released in hadoop 2.8.0 which uses HDFS for writes instead of the
> > current web service based approach. This has a far better perf throughput
> > for writes albeit with a delay on the read path as the Timeline server
> > scans HDFS for new updates. The tez changes for this are already available
> > in the source code under the hadoop28 profile though the documentation for
> > this is still pending.
> >
> > thanks
> > — Hitesh
> >
> >
> >
> >
> >
> > > On Aug 3, 2016, at 2:02 PM, Slava Markeyev <slava.marke...@upsight.com>
> > > wrote:
> > >
> > > I'm running into an issue that occurs fairly often (but not consistently
> > > reproducible) where yarn reports a negative value for memory allocation
> > > eg (-2048) and a 0 vcore allocation despite the AM actually running. For
> > > example the AM reports a runtime of 1hrs, 29mins, 40sec while the dag
> > > only 880 seconds.
> > >
> > > After some investigating I've noticed that the AM has repeated issues
> > > contacting the timeline server after the dag is complete (error trace
> > > below). This seems to be delaying the shutdown sequence. It seems to
> > > retry every minute before either giving up or succeeding but I'm not sure
> > > which. What's the best way to debug why this would be happening and
> > > potentially shortening the timeout retry period as I'm more concerned
> > > with job completion than logging it to the timeline server. This doesn't
> > > seem to be happening consistently to all tez jobs only some.
> > >
> > > I'm using hive 1.1.0 and tez 0.7.1 on cdh5.4.10 (hadoop 2.6).
> > >
> > > 2016-08-03 19:18:22,881 [INFO] [ContainerLauncher #112]
> > > |impl.ContainerManagementProtocolProxy|: Opening proxy : nodexxxx:45454
> > > 2016-08-03 19:18:23,292 [WARN] [HistoryEventHandlingThread]
> > > |security.UserGroupInformation|: PriviledgedActionException as:xxxxx
> > > (auth:SIMPLE) cause:java.net.SocketTimeoutException: Read timed out
> > > 2016-08-03 19:18:23,292 [ERROR] [HistoryEventHandlingThread]
> > > |impl.TimelineClientImpl|: Failed to get the response from the timeline
> > > server.
> > > com.sun.jersey.api.client.ClientHandlerException:
> > > java.net.SocketTimeoutException: Read timed out
> > > at
> > > com.sun.jersey.client.urlconnection.URLConnectionClientHandler.handle(URLConnectionClientHandler.java:149)
> > > at
> > > org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl$TimelineJerseyRetryFilter$1.run(TimelineClientImpl.java:226)
> > > at
> > > org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl$TimelineClientConnectionRetry.retryOn(TimelineClientImpl.java:162)
> > > at
> > > org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl$TimelineJerseyRetryFilter.handle(TimelineClientImpl.java:237)
> > > at com.sun.jersey.api.client.Client.handle(Client.java:648)
> > > at com.sun.jersey.api.client.WebResource.handle(WebResource.java:670)
> > > at
> > > com.sun.jersey.api.client.WebResource.access$200(WebResource.java:74)
> > > at
> > > com.sun.jersey.api.client.WebResource$Builder.post(WebResource.java:563)
> > > at
> > > org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl.doPostingObject(TimelineClientImpl.java:472)
> > > at
> > > org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl.doPosting(TimelineClientImpl.java:321)
> > > at
> > > org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl.putEntities(TimelineClientImpl.java:301)
> > > at
> > > org.apache.tez.dag.history.logging.ats.ATSHistoryLoggingService.handleEvents(ATSHistoryLoggingService.java:349)
> > > at
> > > org.apache.tez.dag.history.logging.ats.ATSHistoryLoggingService.access$700(ATSHistoryLoggingService.java:53)
> > > at
> > > org.apache.tez.dag.history.logging.ats.ATSHistoryLoggingService$1.run(ATSHistoryLoggingService.java:190)
> > > at java.lang.Thread.run(Thread.java:745)
> > > Caused by: java.net.SocketTimeoutException: Read timed out
> > > at java.net.SocketInputStream.socketRead0(Native Method)
> > > at java.net.SocketInputStream.read(SocketInputStream.java:152)
> > > at java.net.SocketInputStream.read(SocketInputStream.java:122)
> > > at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
> > > at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
> > > at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
> > > at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:689)
> > > at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:633)
> > > at
> > > sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1324)
> > > at
> > > java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:468)
> > > at
> > > org.apache.hadoop.security.authentication.client.AuthenticatedURL.extractToken(AuthenticatedURL.java:253)
> > > at
> > > org.apache.hadoop.security.authentication.client.PseudoAuthenticator.authenticate(PseudoAuthenticator.java:77)
> > > at
> > > org.apache.hadoop.security.token.delegation.web.DelegationTokenAuthenticator.authenticate(DelegationTokenAuthenticator.java:127)
> > > at
> > > org.apache.hadoop.security.authentication.client.AuthenticatedURL.openConnection(AuthenticatedURL.java:216)
> > > at
> > > org.apache.hadoop.security.token.delegation.web.DelegationTokenAuthenticatedURL.openConnection(DelegationTokenAuthenticatedURL.java:322)
> > > at
> > > org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl$TimelineURLConnectionFactory$1.run(TimelineClientImpl.java:501)
> > > at
> > > org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl$TimelineURLConnectionFactory$1.run(TimelineClientImpl.java:498)
> > > at java.security.AccessController.doPrivileged(Native Method)
> > > at javax.security.auth.Subject.doAs(Subject.java:415)
> > > at
> > > org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1707)
> > > at
> > > org.apache.hadoop.yarn.client.api.impl.TimelineClientImpl$TimelineURLConnectionFactory.getHttpURLConnection(TimelineClientImpl.java:498)
> > > at
> > > com.sun.jersey.client.urlconnection.URLConnectionClientHandler._invoke(URLConnectionClientHandler.java:159)
> > > at
> > > com.sun.jersey.client.urlconnection.URLConnectionClientHandler.handle(URLConnectionClientHandler.java:147)
> > > ... 14 more
> > >
> > > and finally
> > >
> > > 2016-08-03 20:32:51,041 [INFO] [AMShutdownThread]
> > > |ats.ATSHistoryLoggingService|: Event queue empty, stopping ATS Service
> > > 2016-08-03 20:32:51,131 [INFO] [AMShutdownThread]
> > > |launcher.ContainerLauncherImpl|: Stopping
> > > container_e12_1470097176422_30703_01_002211
> > >
> > >
> > > Thanks,
> > > Slava
> > >
> > > --
> > > Slava Markeyev | Engineering | Upsight
> >
> >
> >
> >
> > --
> > Slava Markeyev | Engineering | Upsight
>
