Full disclosure — I’m the author of the previously mentioned talk in TLV DroidCon.
I had a chance to examine this issue across many Android applications, and discuss it with other developers who encountered it — and we all got to the same point: this issue cannot be avoided, only minimized.
I took a closer look at the default implementation of the Android Garbage collector code, to understand better why this exception is thrown and on what could be the possible causes. I even found a possible root cause during experimentation.
The root of the problem is at the point a device «Goes to Sleep» for a while — this means that the OS has decided to lower the battery consumption by stopping most User Land processes for a while, and turning Screen off, reducing CPU cycles, etc. The way this is done — is on a Linux system level where the processes are Paused mid run. This can happen at any time during normal Application execution, but it will stop at a Native system call, as the context switching is done on the kernel level. So — this is where the Dalvik GC joins the story.
The Dalvik GC code (as implemented in the Dalvik project in the AOSP site) is not a complicated piece of code. The basic way it work is covered in my DroidCon slides. What I did not cover is the basic GC loop — at the point where the collector has a list of Objects to finalize (and destroy). The loop logic at the base can be simplified like this:
- take
starting_timestamp, - remove object for list of objects to release,
- release object —
finalize()and call nativedestroy()if required, - take
end_timestamp, - calculate (
end_timestamp - starting_timestamp) and compare against a hard coded timeout value of 10 seconds, - if timeout has reached — throw the
java.util.concurrent.TimeoutExceptionand kill the process.
Now consider the following scenario:
Application runs along doing its thing.
This is not a user facing application, it runs in the background.
During this background operation, objects are created, used and need to be collected to release memory.
Application does not bother with a WakeLock — as this will affect the battery adversely, and seems unnecessary.
This means the Application will invoke the GC from time to time.
Normally the GC runs is completed without a hitch.
Sometimes (very rarely) the system will decide to sleep in the middle of the GC run.
This will happen if you run your application long enough, and monitor the Dalvik memory logs closely.
Now — consider the timestamp logic of the basic GC loop — it is possible for the device to start the run, take a start_stamp, and go to sleep at the destroy() native call on a system object.
When it wakes up and resumes the run, the destroy() will finish, and the next end_stamp will be the time it took the destroy() call + the sleep time.
If the sleep time was long (more than 10 seconds), the java.util.concurrent.TimeoutException will be thrown.
I have seen this in the graphs generated from the analysis python script — for Android System Applications, not just my own monitored apps.
Collect enough logs and you will eventually see it.
Bottom line:
The issue cannot be avoided — you will encounter it if your app runs in the background.
You can mitigate by taking a WakeLock, and prevent the device from sleeping, but that is a different story altogether, and a new headache, and maybe another talk in another con.
You can minimize the problem by reducing GC calls — making the scenario less likely (tips are in the slides).
I have not yet had the chance to go over the Dalvik 2 (a.k.a ART) GC code — which boasts a new Generational Compacting feature, or performed any experiments on an Android Lollipop.
Added 7/5/2015:
After reviewing the Crash reports aggregation for this crash type, it looks like these crashes from version 5.0+ of Android OS (Lollipop with ART) only account for 0.5% of this crash type. This means that the ART GC changes has reduced the frequency of these crashes.
Added 6/1/2016:
Looks like the Android project has added a lot of info on how the GC works in Dalvik 2.0 (a.k.a ART).
You can read about it here — Debugging ART Garbage Collection.
It also discusses some tools to get information on the GC behavior for your app.
Sending a SIGQUIT to your app process will essentially cause an ANR, and dump the application state to a log file for analysis.
When i display image using com.jsos.image.ImageServlet then
my glassfish 4.0 server fire this error please give me solution.
this is working perfectly in java 6 and glassfish 3
My stacktrash is :
[2014-03-07T08:32:38.465-0500] [glassfish 4.0] [WARNING] [] [javax.enterprise.web] [tid: _ThreadID=20 _ThreadName=http-listener-1(2)] [timeMillis: 1394199158465] [levelValue: 900] [[
StandardWrapperValve[fileServlet]: Servlet.service() for servlet fileServlet threw exception
java.io.IOException: java.util.concurrent.TimeoutException
at org.glassfish.grizzly.utils.Exceptions.makeIOException(Exceptions.java:81)
at org.glassfish.grizzly.http.io.OutputBuffer.blockAfterWriteIfNeeded(OutputBuffer.java:958)
at org.glassfish.grizzly.http.io.OutputBuffer.write(OutputBuffer.java:682)
at org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:355)
at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:342)
at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:161)
at utilities.MobileVideoServlet.copy(MobileVideoServlet.java:401)
at utilities.MobileVideoServlet.processRequest(MobileVideoServlet.java:298)
at utilities.MobileVideoServlet.doGet(MobileVideoServlet.java:74)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1682)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:318)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:160)
at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:357)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:260)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:188)
at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:191)
at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:168)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:189)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544)
at java.lang.Thread.run(Thread.java:744)
Caused by: java.util.concurrent.TimeoutException
at java.util.concurrent.FutureTask.get(FutureTask.java:201)
at org.glassfish.grizzly.http.io.OutputBuffer.blockAfterWriteIfNeeded(OutputBuffer.java:951)
... 36 more
]]
Nidheesh
4,30229 gold badges85 silver badges147 bronze badges
asked Mar 10, 2014 at 6:00
1
This problem has been fixed in the latest version of GlassFish, as you can see here.
Update to GlassFish 4.0.1 which in turn may solve your problem.
You can download the updated GlassFish from here.
answered Apr 11, 2014 at 11:21
Aryan VenkatAryan Venkat
6691 gold badge10 silver badges34 bronze badges
1
When i display image using com.jsos.image.ImageServlet then
my glassfish 4.0 server fire this error please give me solution.
this is working perfectly in java 6 and glassfish 3
My stacktrash is :
[2014-03-07T08:32:38.465-0500] [glassfish 4.0] [WARNING] [] [javax.enterprise.web] [tid: _ThreadID=20 _ThreadName=http-listener-1(2)] [timeMillis: 1394199158465] [levelValue: 900] [[
StandardWrapperValve[fileServlet]: Servlet.service() for servlet fileServlet threw exception
java.io.IOException: java.util.concurrent.TimeoutException
at org.glassfish.grizzly.utils.Exceptions.makeIOException(Exceptions.java:81)
at org.glassfish.grizzly.http.io.OutputBuffer.blockAfterWriteIfNeeded(OutputBuffer.java:958)
at org.glassfish.grizzly.http.io.OutputBuffer.write(OutputBuffer.java:682)
at org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:355)
at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:342)
at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:161)
at utilities.MobileVideoServlet.copy(MobileVideoServlet.java:401)
at utilities.MobileVideoServlet.processRequest(MobileVideoServlet.java:298)
at utilities.MobileVideoServlet.doGet(MobileVideoServlet.java:74)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1682)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:318)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:160)
at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:357)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:260)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:188)
at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:191)
at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:168)
at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:189)
at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136)
at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114)
at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838)
at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55)
at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564)
at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544)
at java.lang.Thread.run(Thread.java:744)
Caused by: java.util.concurrent.TimeoutException
at java.util.concurrent.FutureTask.get(FutureTask.java:201)
at org.glassfish.grizzly.http.io.OutputBuffer.blockAfterWriteIfNeeded(OutputBuffer.java:951)
... 36 more
]]
Nidheesh
4,30229 gold badges85 silver badges147 bronze badges
asked Mar 10, 2014 at 6:00
1
This problem has been fixed in the latest version of GlassFish, as you can see here.
Update to GlassFish 4.0.1 which in turn may solve your problem.
You can download the updated GlassFish from here.
answered Apr 11, 2014 at 11:21
Aryan VenkatAryan Venkat
6691 gold badge10 silver badges34 bronze badges
1
I found the following log in the browser container log that seems related to one of the java.util.concurrent.TimeoutException I get at the selenium RemoteWebDriver:
2021-05-28T04:27:49.028002225Z 04:27:49.027 WARN [SpanWrappedHttpHandler.execute] - Unable to execute request: java.util.concurrent.TimeoutException
2021-05-28T04:27:49.028038633Z Build info: version: '4.0.0-beta-4', revision: 'a51085a604'
2021-05-28T04:27:49.028045075Z System info: host: 'dc6d38043afe', ip: '172.18.0.3', os.name: 'Linux', os.arch: 'amd64', os.version: '3.10.0-1127.19.1.el7.x86_64', java.version: '11.0.11'
2021-05-28T04:27:49.028054734Z Driver info: driver.version: unknown
2021-05-28T04:27:49.028064151Z org.openqa.selenium.TimeoutException: java.util.concurrent.TimeoutException
2021-05-28T04:27:49.028068670Z Build info: version: '4.0.0-beta-4', revision: 'a51085a604'
2021-05-28T04:27:49.028078839Z System info: host: 'dc6d38043afe', ip: '172.18.0.3', os.name: 'Linux', os.arch: 'amd64', os.version: '3.10.0-1127.19.1.el7.x86_64', java.version: '11.0.11'
2021-05-28T04:27:49.028088096Z Driver info: driver.version: unknown
2021-05-28T04:27:49.028092825Z at org.openqa.selenium.remote.http.netty.NettyHttpHandler.makeCall(NettyHttpHandler.java:71)
2021-05-28T04:27:49.028097474Z at org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)
2021-05-28T04:27:49.028101742Z at org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:56)
2021-05-28T04:27:49.028105689Z at org.openqa.selenium.remote.http.netty.NettyHttpHandler.execute(NettyHttpHandler.java:51)
2021-05-28T04:27:49.028110047Z at org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)
2021-05-28T04:27:49.028123262Z at org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:56)
2021-05-28T04:27:49.028128762Z at org.openqa.selenium.remote.http.netty.NettyClient.execute(NettyClient.java:105)
2021-05-28T04:27:49.028133181Z at org.openqa.selenium.remote.tracing.TracedHttpClient.execute(TracedHttpClient.java:55)
2021-05-28T04:27:49.028138801Z at org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:100)
2021-05-28T04:27:49.028143791Z at org.openqa.selenium.grid.node.ProtocolConvertingSession.execute(ProtocolConvertingSession.java:75)
2021-05-28T04:27:49.028148369Z at org.openqa.selenium.grid.node.local.SessionSlot.execute(SessionSlot.java:123)
2021-05-28T04:27:49.028153389Z at org.openqa.selenium.grid.node.local.LocalNode.executeWebDriverCommand(LocalNode.java:399)
2021-05-28T04:27:49.028157747Z at org.openqa.selenium.grid.node.ForwardWebDriverCommand.execute(ForwardWebDriverCommand.java:35)
2021-05-28T04:27:49.028171703Z at org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:373)
2021-05-28T04:27:49.028176792Z at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
2021-05-28T04:27:49.028182454Z at org.openqa.selenium.remote.tracing.SpanWrappedHttpHandler.execute(SpanWrappedHttpHandler.java:86)
2021-05-28T04:27:49.028186993Z at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)
2021-05-28T04:27:49.028191241Z at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)
2021-05-28T04:27:49.028215927Z at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
2021-05-28T04:27:49.028220085Z at org.openqa.selenium.grid.node.Node.execute(Node.java:240)
2021-05-28T04:27:49.028224713Z at org.openqa.selenium.grid.web.CombinedHandler.execute(CombinedHandler.java:59)
2021-05-28T04:27:49.028229843Z at org.openqa.selenium.grid.web.RoutableHttpClientFactory$1.execute(RoutableHttpClientFactory.java:66)
2021-05-28T04:27:49.028234722Z at org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:100)
2021-05-28T04:27:49.028239241Z at org.openqa.selenium.grid.router.HandleSession.execute(HandleSession.java:110)
2021-05-28T04:27:49.028244571Z at org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:373)
2021-05-28T04:27:49.028249209Z at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
2021-05-28T04:27:49.028253978Z at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)
2021-05-28T04:27:49.028258407Z at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
2021-05-28T04:27:49.028262795Z at org.openqa.selenium.grid.router.Router.execute(Router.java:91)
2021-05-28T04:27:49.028267664Z at org.openqa.selenium.grid.web.EnsureSpecCompliantResponseHeaders.lambda$apply$0(EnsureSpecCompliantResponseHeaders.java:34)
2021-05-28T04:27:49.028272293Z at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)
2021-05-28T04:27:49.028277102Z at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)
2021-05-28T04:27:49.028281810Z at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
2021-05-28T04:27:49.028286459Z at org.openqa.selenium.remote.http.Route$NestedRoute.handle(Route.java:270)
2021-05-28T04:27:49.028291108Z at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
2021-05-28T04:27:49.028295416Z at org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)
2021-05-28T04:27:49.028299494Z at org.openqa.selenium.remote.http.Route.execute(Route.java:68)
2021-05-28T04:27:49.028303842Z at org.openqa.selenium.remote.AddWebDriverSpecHeaders.lambda$apply$0(AddWebDriverSpecHeaders.java:35)
2021-05-28T04:27:49.028316726Z at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
2021-05-28T04:27:49.028322737Z at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)
2021-05-28T04:27:49.028332185Z at org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)
2021-05-28T04:27:49.028337805Z at org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)
2021-05-28T04:27:49.028342093Z at org.openqa.selenium.netty.server.SeleniumHandler.lambda$channelRead0$0(SeleniumHandler.java:44)
2021-05-28T04:27:49.028346131Z at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
2021-05-28T04:27:49.028350820Z at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
2021-05-28T04:27:49.028355599Z at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2021-05-28T04:27:49.028360658Z at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2021-05-28T04:27:49.028365998Z at java.base/java.lang.Thread.run(Thread.java:829)
2021-05-28T04:27:49.028369967Z Caused by: java.util.concurrent.TimeoutException
2021-05-28T04:27:49.028373874Z at java.base/java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1886)
2021-05-28T04:27:49.028377852Z at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2021)
2021-05-28T04:27:49.028381719Z at org.asynchttpclient.netty.NettyResponseFuture.get(NettyResponseFuture.java:206)
2021-05-28T04:27:49.028390024Z at org.openqa.selenium.remote.http.netty.NettyHttpHandler.makeCall(NettyHttpHandler.java:65)
2021-05-28T04:27:49.028399482Z ... 47 more
2021-05-28T04:27:49.028448714Z 04:27:49.027 WARN [SeleniumSpanExporter$1.lambda$export$0] - {"traceId": "29cfa26fac6fff967616ca4945924213","eventTime": 1622176069026085041,"eventName": "exception","attributes": {"exception.message": "Unable to execute request: java.util.concurrent.TimeoutExceptionnBuild info: version: '4.0.0-beta-4', revision: 'a51085a604'nSystem info: host: 'dc6d38043afe', ip: '172.18.0.3', os.name: 'Linux', os.arch: 'amd64', os.version: '3.10.0-1127.19.1.el7.x86_64', java.version: '11.0.11'nDriver info: driver.version: unknown","exception.stacktrace": "org.openqa.selenium.TimeoutException: java.util.concurrent.TimeoutExceptionnBuild info: version: '4.0.0-beta-4', revision: 'a51085a604'nSystem info: host: 'dc6d38043afe', ip: '172.18.0.3', os.name: 'Linux', os.arch: 'amd64', os.version: '3.10.0-1127.19.1.el7.x86_64', java.version: '11.0.11'nDriver info: driver.version: unknownntat org.openqa.selenium.remote.http.netty.NettyHttpHandler.makeCall(NettyHttpHandler.java:71)ntat org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)ntat org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:56)ntat org.openqa.selenium.remote.http.netty.NettyHttpHandler.execute(NettyHttpHandler.java:51)ntat org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)ntat org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:56)ntat org.openqa.selenium.remote.http.netty.NettyClient.execute(NettyClient.java:105)ntat org.openqa.selenium.remote.tracing.TracedHttpClient.execute(TracedHttpClient.java:55)ntat org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:100)ntat org.openqa.selenium.grid.node.ProtocolConvertingSession.execute(ProtocolConvertingSession.java:75)ntat org.openqa.selenium.grid.node.local.SessionSlot.execute(SessionSlot.java:123)ntat org.openqa.selenium.grid.node.local.LocalNode.executeWebDriverCommand(LocalNode.java:399)ntat org.openqa.selenium.grid.node.ForwardWebDriverCommand.execute(ForwardWebDriverCommand.java:35)ntat org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:373)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.remote.tracing.SpanWrappedHttpHandler.execute(SpanWrappedHttpHandler.java:86)ntat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)ntat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.grid.node.Node.execute(Node.java:240)ntat org.openqa.selenium.grid.web.CombinedHandler.execute(CombinedHandler.java:59)ntat org.openqa.selenium.grid.web.RoutableHttpClientFactory$1.execute(RoutableHttpClientFactory.java:66)ntat org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:100)ntat org.openqa.selenium.grid.router.HandleSession.execute(HandleSession.java:110)ntat org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:373)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.grid.router.Router.execute(Router.java:91)ntat org.openqa.selenium.grid.web.EnsureSpecCompliantResponseHeaders.lambda$apply$0(EnsureSpecCompliantResponseHeaders.java:34)ntat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)ntat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.remote.http.Route$NestedRoute.handle(Route.java:270)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.remote.AddWebDriverSpecHeaders.lambda$apply$0(AddWebDriverSpecHeaders.java:35)ntat org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)ntat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)ntat org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)ntat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)ntat org.openqa.selenium.netty.server.SeleniumHandler.lambda$channelRead0$0(SeleniumHandler.java:44)ntat java.baseu002fjava.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)ntat java.baseu002fjava.util.concurrent.FutureTask.run(FutureTask.java:264)ntat java.baseu002fjava.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)ntat java.baseu002fjava.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)ntat java.baseu002fjava.lang.Thread.run(Thread.java:829)nCaused by: java.util.concurrent.TimeoutExceptionntat java.baseu002fjava.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1886)ntat java.baseu002fjava.util.concurrent.CompletableFuture.get(CompletableFuture.java:2021)ntat org.asynchttpclient.netty.NettyResponseFuture.get(NettyResponseFuture.java:206)ntat org.openqa.selenium.remote.http.netty.NettyHttpHandler.makeCall(NettyHttpHandler.java:65)nt... 47 moren","exception.type": "org.openqa.selenium.TimeoutException","http.flavor": 1,"http.handler_class": "org.openqa.selenium.remote.http.Route$PredicatedRoute","http.host": "selenium:4444","http.method": "POST","http.request_content_length": "16","http.scheme": "HTTP","http.target": "u002fsessionu002f5f7b6d0b-fa5a-4c19-9a64-f521764b4b6cu002fframe","http.user_agent": "seleniumu002f4.0.0-beta-3 (java unix)"}}
2021-05-28T04:27:49.028504950Z
2021-05-28T04:27:49.029534186Z 04:27:49.029 WARN [SeleniumSpanExporter$1.lambda$export$0] - {"traceId": "29cfa26fac6fff967616ca4945924213","eventTime": 1622176069028013648,"eventName": "exception","attributes": {"exception.message": "Unable to execute request for an existing session: java.util.concurrent.TimeoutExceptionnBuild info: version: '4.0.0-beta-4', revision: 'a51085a604'nSystem info: host: 'dc6d38043afe', ip: '172.18.0.3', os.name: 'Linux', os.arch: 'amd64', os.version: '3.10.0-1127.19.1.el7.x86_64', java.version: '11.0.11'nDriver info: driver.version: unknown","exception.stacktrace": "org.openqa.selenium.TimeoutException: java.util.concurrent.TimeoutExceptionnBuild info: version: '4.0.0-beta-4', revision: 'a51085a604'nSystem info: host: 'dc6d38043afe', ip: '172.18.0.3', os.name: 'Linux', os.arch: 'amd64', os.version: '3.10.0-1127.19.1.el7.x86_64', java.version: '11.0.11'nDriver info: driver.version: unknownntat org.openqa.selenium.remote.http.netty.NettyHttpHandler.makeCall(NettyHttpHandler.java:71)ntat org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)ntat org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:56)ntat org.openqa.selenium.remote.http.netty.NettyHttpHandler.execute(NettyHttpHandler.java:51)ntat org.openqa.selenium.remote.http.AddSeleniumUserAgent.lambda$apply$0(AddSeleniumUserAgent.java:42)ntat org.openqa.selenium.remote.http.Filter.lambda$andFinally$1(Filter.java:56)ntat org.openqa.selenium.remote.http.netty.NettyClient.execute(NettyClient.java:105)ntat org.openqa.selenium.remote.tracing.TracedHttpClient.execute(TracedHttpClient.java:55)ntat org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:100)ntat org.openqa.selenium.grid.node.ProtocolConvertingSession.execute(ProtocolConvertingSession.java:75)ntat org.openqa.selenium.grid.node.local.SessionSlot.execute(SessionSlot.java:123)ntat org.openqa.selenium.grid.node.local.LocalNode.executeWebDriverCommand(LocalNode.java:399)ntat org.openqa.selenium.grid.node.ForwardWebDriverCommand.execute(ForwardWebDriverCommand.java:35)ntat org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:373)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.remote.tracing.SpanWrappedHttpHandler.execute(SpanWrappedHttpHandler.java:86)ntat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)ntat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.grid.node.Node.execute(Node.java:240)ntat org.openqa.selenium.grid.web.CombinedHandler.execute(CombinedHandler.java:59)ntat org.openqa.selenium.grid.web.RoutableHttpClientFactory$1.execute(RoutableHttpClientFactory.java:66)ntat org.openqa.selenium.grid.web.ReverseProxyHandler.execute(ReverseProxyHandler.java:100)ntat org.openqa.selenium.grid.router.HandleSession.execute(HandleSession.java:110)ntat org.openqa.selenium.remote.http.Route$PredicatedRoute.handle(Route.java:373)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.grid.router.Router.execute(Router.java:91)ntat org.openqa.selenium.grid.web.EnsureSpecCompliantResponseHeaders.lambda$apply$0(EnsureSpecCompliantResponseHeaders.java:34)ntat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)ntat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.remote.http.Route$NestedRoute.handle(Route.java:270)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.remote.http.Route$CombinedRoute.handle(Route.java:336)ntat org.openqa.selenium.remote.http.Route.execute(Route.java:68)ntat org.openqa.selenium.remote.AddWebDriverSpecHeaders.lambda$apply$0(AddWebDriverSpecHeaders.java:35)ntat org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)ntat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)ntat org.openqa.selenium.remote.ErrorFilter.lambda$apply$0(ErrorFilter.java:44)ntat org.openqa.selenium.remote.http.Filter$1.execute(Filter.java:64)ntat org.openqa.selenium.netty.server.SeleniumHandler.lambda$channelRead0$0(SeleniumHandler.java:44)ntat java.baseu002fjava.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)ntat java.baseu002fjava.util.concurrent.FutureTask.run(FutureTask.java:264)ntat java.baseu002fjava.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)ntat java.baseu002fjava.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)ntat java.baseu002fjava.lang.Thread.run(Thread.java:829)nCaused by: java.util.concurrent.TimeoutExceptionntat java.baseu002fjava.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1886)ntat java.baseu002fjava.util.concurrent.CompletableFuture.get(CompletableFuture.java:2021)ntat org.asynchttpclient.netty.NettyResponseFuture.get(NettyResponseFuture.java:206)ntat org.openqa.selenium.remote.http.netty.NettyHttpHandler.makeCall(NettyHttpHandler.java:65)nt... 47 moren","exception.type": "org.openqa.selenium.TimeoutException","http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.router.HandleSession","http.host": "selenium:4444","http.method": "POST","http.request_content_length": "16","http.scheme": "HTTP","http.target": "u002fsessionu002f5f7b6d0b-fa5a-4c19-9a64-f521764b4b6cu002fframe","http.user_agent": "seleniumu002f4.0.0-beta-3 (java unix)","session.id": "5f7b6d0b-fa5a-4c19-9a64-f521764b4b6c"}}
There is also a message [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt repeating constantly multiple times per second, but I suppose it may not be related, because it also is written when there is no problem happening.
Добрый день!
В логе /BGInetAccess/log/error
стал наблюдать ошибки. с чем может быть связанно?
Клиент: вер. 7.0.941 / 14.03.2018 15:59:29
os: Windows Server 2012 R2; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_121
Сервер: вер. 7.0.1339 / 14.03.2018 21:10:50
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_111
card: вер. 7.0.48 / 14.03.2018 16:03:03
inet: вер. 7.0.843 / 14.03.2018 21:10:59
npay: вер. 7.0.214 / 14.03.2018 16:04:12
phone: вер. 7.0.300 / 14.03.2018 16:04:27
reports: вер. 7.0.240 / 14.03.2018 16:04:51
rscm: вер. 7.0.189 / 14.03.2018 16:04:57
sberbank: вер. 7.0.80 / 14.03.2018 16:05:02
trayinfo: вер. 7.0.181 / 14.03.2018 16:05:14
Код:
java.lang.NullPointerException
connection 04-18/22:05:20 ERROR [sa-p-15-t-46] EventWorker — java.util.concurrent.TimeoutException: Timeout waiting for future results will done. Possible answer not recieved.
ru.bitel.bgbilling.common.BGException: java.util.concurrent.TimeoutException: Timeout waiting for future results will done. Possible answer not recieved.
at ru.bitel.bgbilling.kernel.event.AsyncEventWorker.doTasks(AsyncEventWorker.java:128)
at ru.bitel.bgbilling.modules.inet.access.sa.ServiceActivatorDeviceWorker.runWorker(ServiceActivatorDeviceWorker.java:246)
at ru.bitel.bgbilling.kernel.event.EventWorker.internalRunWorker(EventWorker.java:142)
at ru.bitel.bgbilling.modules.inet.access.sa.ServiceActivatorDeviceWorker.runImpl(ServiceActivatorDeviceWorker.java:152)
at ru.bitel.common.worker.WorkerTask.run(WorkerTask.java:86)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:46)
Caused by: java.util.concurrent.TimeoutException: Timeout waiting for future results will done. Possible answer not recieved.
… 13 more
radius 04-18/22:06:33 ERROR [rdsLstnr-p-8-t-15] InetRadiusProcessor —
может быть биллинг не получает ответа
Полное раскрытие. Я являюсь автором упомянутых выше разговоров в TLV DroidCon.
У меня была возможность изучить эту проблему во многих приложениях Android и обсудить ее с другими разработчиками, которые столкнулись с ней, — и мы все дошли до одной точки: эту проблему нельзя избежать, только минимизировать.
Я более подробно рассмотрел стандартную реализацию кода коллекционера Android Garbage, чтобы лучше понять, почему это исключение выбрано и какие могут быть возможные причины. Я даже нашел возможную основную причину во время экспериментов.
Корень проблемы заключается в том, что устройство «Goes to Sleep» какое-то время — это означает, что ОС решила снизить потребление батареи, остановив большинство процессов User Land на некоторое время и отключив Screen, сокращение циклов процессора и т.д. Как это делается — на уровне системы Linux, где процессы приостанавливаются в середине запуска. Это может произойти в любое время во время обычного выполнения приложения, но оно остановится при системном вызове Native, поскольку переключение контекста выполняется на уровне ядра. Итак — вот где Далвик GC присоединяется к истории.
Код GC Dalvik (как реализован в проекте Dalvik на сайте AOSP) не является сложной частью кода. Основной способ его работы охватывает мои слайды DroidCon. то, что я не рассматривал, — это основной цикл GC — в точке, где сборщик имеет список объектов для завершения (и уничтожения). логика цикла в базе может быть упрощена следующим образом:
- взять start_timestamp,
- удалить объект для списка объектов для выпуска,
- объект выпуска —
finalize()и при необходимости вызовите nativedestroy(), - возьмите
end_timestamp, - вычислить (
end_timestamp - starting_timestamp) и сравнить с жестким временем таймаута 10 секунд, - если время ожидания достигло — выбросьте
concurrent.TimeoutExceptionи убейте процесс.
Теперь рассмотрим следующий сценарий:
Приложение работает, выполняя свою задачу. это не приложение, ориентированное на пользователя, оно работает в фоновом режиме. Во время этой фоновой операции объекты создаются, используются и должны собираться для освобождения памяти. Приложение не беспокоится о Wakelock — так как это может отрицательно сказаться на батарее и кажется ненужным. это означает, что приложение будет время от времени ссылаться на GC. Обычно работы GC завершаются без заминок. Иногда (очень редко) система решит Сон в середине прогона GC. Это произойдет, если вы запустите приложение достаточно долго и внимательно следите за журналами памяти Dalvik. Теперь рассмотрим логику метки времени базового цикла GC — возможно, чтобы устройство запустило запуск, запустило start_stamp и перешло в режим сна при вызове destroy() на системном объекте. когда он просыпается и возобновляет прогон, завершается destroy(), а следующий end_stamp будет временем, когда потребовался вызов destroy() + время сна. Если время сна было длинным — более 10 секунд, будет выведено исключение concurrent.timeout.
Я видел это на графиках, сгенерированных из анализа python script — для системных приложений Android, а не только для моих собственных контролируемых приложений. собрать достаточное количество журналов, вы в конце концов увидите его.
Нижняя строка:
Проблема не может быть устранена — вы столкнетесь с ней, если ваше приложение работает в фоновом режиме. Вы можете смягчить, взяв wakelock и не позволять устройству спать, но это совсем другая история, и новая головная боль, а может быть, еще один разговор в другом con.
Вы можете свести к минимуму проблему за счет сокращения вызовов GC, что делает сценарий менее вероятным. подсказки находятся в слайдах.
У меня еще не было возможности пройти код GC Dalvik 2 (a.k.a ART), который может похвастаться новой функцией Generational Compacting или выполнять любые эксперименты на Android Lollipop.
Добавлено 7/5/2015:
После анализа агрегации отчетов Crash для этого типа сбоя, похоже, что эти сбои от версии 5.0+ для ОС Android (Lollipop with ART) составляют только 0,5% от этого типа сбоя. Это означает, что изменения ART GC уменьшили частоту этих сбоев.
Добавлено 6/1/2016:
Похоже, проект Android добавил много информации о том, как работает GC в Dalvik 2.0 (a.k.a ART). Вы можете прочитать об этом здесь — Отладка коллекции мусора ART
, В нем также рассматриваются некоторые инструменты для получения информации о поведении GC для вашего приложения. Отправка SIGQUIT в процесс вашего приложения будет по существу вызывать ANR и сбросить состояние приложения в файл журнала для анализа.
#spark-streaming #azure-eventhub #watermark
Вопрос:
У меня есть потоковый запрос, передающий данные из Azure Eventhubs в ADLS каждые 5 секунд, и один и тот же потоковый запрос является водяным знаком в течение 1 часа с задержкой в 5 минут.
Код:
val rawStreamQuery = messages.writeStream.format("delta")
.option("checkpointLocation", BASE_LOC "checkpoint/" RAW_SCHEMA_NAME "/" RAW_TASK_TABLE)
.trigger(Trigger.ProcessingTime(RAW_STREAM_TRIGGER_INTERVAL))
.table(RAW_SCHEMA_NAME "." RAW_TASK_TABLE)
rawStreamQuery.withWatermark(watermarkTimeStamp, STREAM_WATERMARK) //5 minutes
.groupBy(window(col(watermarkTimeStamp), STREAM_WINDOW).as("window")) //1 hour
.count()
.select(
lit(commonDataObj.getFeedName).as("feed_name")
, lit(commonDataObj.getStage).as("stage_name")
, col("count").as("record_count")
, col("window").getField("start").as("start_ts")
, col("window").getField("end").as("end_ts")
)
Получаю ошибку ниже.
Caused by: java.util.concurrent.TimeoutException: Futures timed out after [5 minutes]
at scala.concurrent.impl.Promise$DefaultPromise.ready(Promise.scala:259)
at scala.concurrent.impl.Promise$DefaultPromise.result(Promise.scala:263)
at scala.concurrent.Await$.$anonfun$result$1(package.scala:220)
at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:57)
at scala.concurrent.Await$.result(package.scala:146)
at org.apache.spark.eventhubs.client.CachedEventHubsReceiver.createReceiver(CachedEventHubsReceiver.scala:99)
at org.apache.spark.eventhubs.client.CachedEventHubsReceiver.recreateReceiver(CachedEventHubsReceiver.scala:151)
at org.apache.spark.eventhubs.client.CachedEventHubsReceiver.checkCursor(CachedEventHubsReceiver.scala:169)
at org.apache.spark.eventhubs.client.CachedEventHubsReceiver.org$apache$spark$eventhubs$client$CachedEventHubsReceiver$receive(CachedEventHubsReceiver.scala:231)
at org.apache.spark.eventhubs.client.CachedEventHubsReceiver$.receive(CachedEventHubsReceiver.scala:356)
at org.apache.spark.eventhubs.rdd.EventHubsRDD.compute(EventHubsRDD.scala:123)
at org.apache.spark.rdd.RDD.computeOrReadCheckpoint(RDD.scala:356)
at org.apache.spark.rdd.RDD.iterator(RDD.scala:320)
at org.apache.spark.rdd.MapPartitionsRDD.compute(MapPartitionsRDD.scala:60)
at org.apache.spark.rdd.RDD.computeOrReadCheckpoint(RDD.scala:356)
at org.apache.spark.rdd.RDD.iterator(RDD.scala:320)
at org.apache.spark.rdd.MapPartitionsRDD.compute(MapPartitionsRDD.scala:60)
at org.apache.spark.rdd.RDD.computeOrReadCheckpoint(RDD.scala:356)
at org.apache.spark.rdd.RDD.iterator(RDD.scala:320)
at org.apache.spark.rdd.MapPartitionsRDD.compute(MapPartitionsRDD.scala:60)
at org.apache.spark.rdd.RDD.computeOrReadCheckpoint(RDD.scala:356)
at org.apache.spark.rdd.RDD.iterator(RDD.scala:320)
at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59)
at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:99)
at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:52)
at org.apache.spark.scheduler.Task.doRunTask(Task.scala:144)
at org.apache.spark.scheduler.Task.run(Task.scala:117)
at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$9(Executor.scala:640)
at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:1581)
at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:643)
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)
Комментарии:
1. Вам удалось найти решение этой проблемы? У меня возникают похожие проблемы
2. нет … что-то связанное с замком зажигания. подожди, я думаю.. пожалуйста, дайте мне знать, если вы сможете исправить то же самое.
3. У нас уже установлено значение 30 секунд.. кроме того, теперь мы также отключили упреждение искры, установив
spark.databricks.preemption.enabled falseего из-за некоторых комментариев здесь . Однако мы сталкиваемся с этой проблемой нерегулярно; в последний раз наше потоковое задание выполнялось за 130 часов до истечения тайм-аута, поэтому нам придется посмотреть, поможет ли это4. то же самое here..it происходит нерегулярно.. дам вам знать, если что-нибудь всплывет..