You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lens.apache.org by "Ankit Kailaswar (JIRA)" <ji...@apache.org> on 2017/08/18 09:46:03 UTC
[jira] [Commented] (LENS-1461) Lens services state are not
persisted correctly
[ https://issues.apache.org/jira/browse/LENS-1461?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16131977#comment-16131977 ]
Ankit Kailaswar commented on LENS-1461:
---------------------------------------
There were few issues found while persisting service states and using it to start lens server.
1. Session service is not getting persisted properly on few occasions. session service try to serialize few sessions which are invalid using its session handles throwing an exception uncaught at service level. Other services are getting persisted successfully.
{panel:title=lens server log |borderStyle=dashed|borderColor=#ccc|titleBGColor=#F7D6C1|bgColor=#FFFFCE}
14 Aug 2017 20:13:49 6daca8db-deb9-4ab0-ba2d-3f5e474ad545 Lens-server-snapshotter-Thread-1 WARN org.apache.lens.server.BaseLensService - {color:red} *Session cbc183be-8f05-4356-bb56-6ba43217518b not found* {color}
org.apache.hive.service.cli.HiveSQLException: Invalid SessionHandle: SessionHandle cbc183be-8f05-4356-bb56-6ba43217518b
at org.apache.hive.service.cli.session.SessionManager.getSession(SessionManager.java:389) ~hive-service-2.1.3-inm.jar:2.1.3-inm
at org.apache.lens.server.BaseLensService.getSession(BaseLensService.java:366) ~classes/:na
at org.apache.lens.server.session.HiveSessionService.writeExternal(HiveSessionService.java:425) classes/:na
at org.apache.lens.server.LensServices.persistState(LensServices.java:369) classes/:na
at org.apache.lens.server.LensServices.persistLensServiceState(LensServices.java:354) classes/:na
at org.apache.lens.server.LensServices.access$100(LensServices.java:63) classes/:na
at org.apache.lens.server.LensServices$1.run(LensServices.java:305) classes/:na
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) na:1.8.0_72
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) na:1.8.0_72
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) na:1.8.0_72
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) na:1.8.0_72
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) na:1.8.0_72
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) na:1.8.0_72
at java.lang.Thread.run(Thread.java:745) na:1.8.0_72
14 Aug 2017 20:13:49 ba8c2672-53a0-44ad-9d50-fc53e2286143 grizzly-http-server-12 INFO hive.metastore - Closed a connection to metastore, current connections: 282
14 Aug 2017 20:13:49 ba8c2672-53a0-44ad-9d50-fc53e2286143 grizzly-http-server-12 INFO org.apache.lens.server.BaseLensService - Closed session <?xml version="1.0" encoding="UTF-8" standalone="yes"?><lensSessionHandle><publicId>cbc183be-8f05-4356-bb56-6ba43217518b</publicId><secretId>33a980a2-206c-4dbc-b3d9-ffa3a6b6de87</secretId></lensSessionHandle> for yoda-admin user
14 Aug 2017 20:13:49 6daca8db-deb9-4ab0-ba2d-3f5e474ad545 Lens-server-snapshotter-Thread-1 ERROR org.apache.lens.server.LensServices - Error while persisting state for service session
javax.ws.rs.ClientErrorException: Session cbc183be-8f05-4356-bb56-6ba43217518b is invalid <?xml version="1.0" encoding="UTF-8" standalone="yes"?><lensSessionHandle><publicId>cbc183be-8f05-4356-bb56-6ba43217518b</publicId><secretId>33a980a2-206c-4dbc-b3d9-ffa3a6b6de87</secretId></lensSessionHandle>
at org.apache.lens.server.BaseLensService.getSession(BaseLensService.java:370) ~classes/:na
at org.apache.lens.server.session.HiveSessionService.writeExternal(HiveSessionService.java:425) ~classes/:na
at org.apache.lens.server.LensServices.persistState(LensServices.java:369) classes/:na
at org.apache.lens.server.LensServices.persistLensServiceState(LensServices.java:354) classes/:na
at org.apache.lens.server.LensServices.access$100(LensServices.java:63) classes/:na
at org.apache.lens.server.LensServices$1.run(LensServices.java:305) classes/:na
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) na:1.8.0_72
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) na:1.8.0_72
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) na:1.8.0_72
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) na:1.8.0_72
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) na:1.8.0_72
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) na:1.8.0_72
at java.lang.Thread.run(Thread.java:745) na:1.8.0_72
Caused by: org.apache.hive.service.cli.HiveSQLException: Invalid SessionHandle: SessionHandle cbc183be-8f05-4356-bb56-6ba43217518b
at org.apache.hive.service.cli.session.SessionManager.getSession(SessionManager.java:389) ~hive-service-2.1.3-inm.jar:2.1.3-inm
at org.apache.lens.server.BaseLensService.getSession(BaseLensService.java:366) ~classes/:na
... 12 common frames omitted
{panel}
This is causing other states to be persisted with updated time while session service persisted state is older than other causing lens to loose session info for session created during these period.
This can be fixed by catching exception for invalid sessions and continuing without serializing it.
2. At the time of startup lens tries to start respective service from last persisted state for each service. For session service it tries to deserialize all sessions from persisted state. For few sessions session handles were serialized as null causing deserialisation of such sessions to to fail and throw exception caught but not handled causing startup to fail.
{panel:title=lens server log |borderStyle=dashed|borderColor=#ccc|titleBGColor=#F7D6C1|bgColor=#FFFFCE}
14 Aug 2017 18:53:16 6236aa77-07ff-424a-be02-1c9b11de8862 main {color:red} *ERROR org.apache.lens.server.LensServices - Could not recover from persisted state* {color}
java.io.EOFException: null
at java.io.DataInputStream.readUnsignedShort(DataInputStream.java:340) ~na:1.8.0_72
at java.io.ObjectInputStream$BlockDataInputStream.readUnsignedShort(ObjectInputStream.java:2818) ~na:1.8.0_72
at java.io.ObjectInputStream$BlockDataInputStream.readUTF(ObjectInputStream.java:2874) ~na:1.8.0_72
at java.io.ObjectInputStream.readUTF(ObjectInputStream.java:1073) ~na:1.8.0_72
at org.apache.lens.server.session.LensSessionImpl$LensSessionPersistInfo.readExternal(LensSessionImpl.java:678) ~classes/:na
at org.apache.lens.server.session.HiveSessionService.readExternal(HiveSessionService.java:453) ~classes/:na
at org.apache.lens.server.LensServices.setupPersistedState(LensServices.java:335) ~classes/:na
at org.apache.lens.server.LensServices.init(LensServices.java:268) ~classes/:na
at org.apache.lens.server.LensServer.startServices(LensServer.java:136) classes/:na
at org.apache.lens.server.LensServer.<init>(LensServer.java:88) classes/:na
at org.apache.lens.server.LensServer.createLensServer(LensServer.java:77) classes/:na
at org.apache.lens.server.LensServer.main(LensServer.java:192) classes/:na
14 Aug 2017 18:53:16 6236aa77-07ff-424a-be02-1c9b11de8862 main ERROR org.apache.lens.server.LensServer - Error while creating Lens server
java.lang.RuntimeException: Could not recover from persisted state
at org.apache.lens.server.LensServices.init(LensServices.java:271) ~classes/:na
at org.apache.lens.server.LensServer.startServices(LensServer.java:136) ~classes/:na
at org.apache.lens.server.LensServer.<init>(LensServer.java:88) ~classes/:na
at org.apache.lens.server.LensServer.createLensServer(LensServer.java:77) ~classes/:na
at org.apache.lens.server.LensServer.main(LensServer.java:192) ~classes/:na
Caused by: java.io.EOFException: null
at java.io.DataInputStream.readUnsignedShort(DataInputStream.java:340) ~na:1.8.0_72
at java.io.ObjectInputStream$BlockDataInputStream.readUnsignedShort(ObjectInputStream.java:2818) ~na:1.8.0_72
at java.io.ObjectInputStream$BlockDataInputStream.readUTF(ObjectInputStream.java:2874) ~na:1.8.0_72
at java.io.ObjectInputStream.readUTF(ObjectInputStream.java:1073) ~na:1.8.0_72
at org.apache.lens.server.session.LensSessionImpl$LensSessionPersistInfo.readExternal(LensSessionImpl.java:678) ~classes/:na
at org.apache.lens.server.session.HiveSessionService.readExternal(HiveSessionService.java:453) ~classes/:na
at org.apache.lens.server.LensServices.setupPersistedState(LensServices.java:335) ~classes/:na
at org.apache.lens.server.LensServices.init(LensServices.java:268) ~classes/:na
... 4 common frames omitted
14 Aug 2017 18:53:16 6236aa77-07ff-424a-be02-1c9b11de8862 main INFO org.apache.lens.server.LensServices - {color:red} *Stopping lens server* {color}
14 Aug 2017 18:53:16 6236aa77-07ff-424a-be02-1c9b11de8862 main ERROR org.apache.lens.server.LensServer - {color:red} *Error stopping services* {color}
java.lang.NullPointerException: null
at org.apache.lens.server.query.QueryExecutionServiceImpl.prepareStopping(QueryExecutionServiceImpl.java:1428) ~classes/:na
at org.apache.lens.server.LensServices.stop(LensServices.java:408) ~classes/:na
at org.apache.lens.server.LensServer.main(LensServer.java:202) ~classes/:na
{panel}
root cause :
we persist session service by serializing each active "lens" session. session service stores lens session handles for each service and uses it get session info that needs to be serialized. It gets session object for lens in following sequence,
1. create new hive session handle from lens session handle
2. get hive session object from session manager using this newly created hive session handle
3. downcast hive session object "HiveSession" to "LensSessionImpl" assuming its instance of "LensSessionImpl" since it was created as a instance of "LensSessionImpl"
4. serialize it
It works fine when it is valid session for both hive and lens.
session timeout for lens and hive are 1 day and 3 days respectievely. For a session which is 2 days old session manager returns valid object for HiveSession but its no longer a instance of "LensSessionImpl" since lens session already expired. causing downcasting to initialize lens related member variable(LensSessionHandle, db, username, password etc) to null causing deserializer to fail for them.
Proposed Fix,
1. While deserializing we can catch exception and ignoring invalid "lens" session. This will fix the issue of lens failing to start due to invalid lens session.
2. downcasting is done in getsession() method in LensSessionImpl and referenced at lot of places. That might be causing other bugs apart from mentioned above. We have to avoid downcasting or need to have conditional downcasting using RTTI.
3. We need to have constraint that lens session timeout is always greater than or equal to hive session timeout. That way session manager will always throw invalid session exception.
> Lens services state are not persisted correctly
> -----------------------------------------------
>
> Key: LENS-1461
> URL: https://issues.apache.org/jira/browse/LENS-1461
> Project: Apache Lens
> Issue Type: Bug
> Components: server
> Reporter: Ankit Kailaswar
> Assignee: Ankit Kailaswar
>
> Lens services state are not persisted correctly causing lens to fail at startup.
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)