Sandbox v2.6.5 with SAP HANA Spark Controller

[#1]

Hello,

we are running sandbox 2.6.5 with Spark2 v2.3.0 and SAP HANA SparkController v2.3.5 on top. The Ambari dashboard shows all services as up and running, everything seems fine:

Now, we wish to connect from our HANA database (running on IP 10.118.169.32) to Hadoop via the SparkController. We configured the connection in HANA Studio client tool using these properties:

The connection is successfully established and we can see the table that we wish to access:

However, when we run a simple select query, it just runs for about 10 minutes, until the connection is closed. No data is returned:

internal error: Error opening the cursor for the remote database Connection has been closed. for query SELECT COUNT(*) FROM "foodmart"."customer"

In the hana_controller.log we can see that the SQL query was accepted and the execution plan is processed =>

19/06/06 11:39:28 DEBUG NetworkUtils: Inbound Message => 'Message Type => 'PING'; Message Id => '693201651063748'; Request Id => '35d3a519-002a-0016-b033-31a660011a59';'
19/06/06 11:39:28 DEBUG HanaMessageHandler: Received Request from: '172.18.0.3'; Message Type => 'PING'
19/06/06 11:39:28 DEBUG NetworkUtils: Outbound Message => 'Message Type => 'PONG'; Message Id => '693201670667961'; Request Id => '35d3a519-002a-0016-b033-31a660011a59';'
19/06/06 11:39:28 DEBUG NetworkUtils: Inbound Message => 'Message Type => 'START_SESSION'; Message Id => '693201689176436'; Request Id => '35d3a519-002a-0016-b033-31a660011a5b'; Session Id => '3878625230891646998-12696546365132577370';'
19/06/06 11:39:28 DEBUG HanaMessageHandler: Received Request from: '172.18.0.3'; Message Type => 'START_SESSION'
19/06/06 11:39:28 INFO CommandRouterDefault: Current Assignments => NONE; Incoming Assignment => '3878625230891646998-12696546365132577370#35d3a519-002a-0016-b033-31a660011a5b'
19/06/06 11:39:28 INFO RequestHandler: Bound Message to Orchestrator: '35d3a519-002a-0016-b033-31a660011a5b'
19/06/06 11:39:28 INFO RequestHandler: Retrieving Bound Message: '35d3a519-002a-0016-b033-31a660011a5b'
19/06/06 11:39:28 DEBUG RequestHandler: Relaying Message to Client: 'CONTINUE_SESSION'
19/06/06 11:39:28 DEBUG NetworkUtils: Outbound Message => 'Message Type => 'CONTINUE_SESSION'; Message Id => '693201720489241'; Request Id => '35d3a519-002a-0016-b033-31a660011a5b'; Session Id => '3878625230891646998-12696546365132577370';'
19/06/06 11:39:28 DEBUG NetworkUtils: Inbound Message => 'Message Type => 'CONTINUE_SESSION'; Message Id => '693201726088539'; Request Id => '35d3a519-002a-0016-b033-31a660011a5b'; Session Id => '3878625230891646998-12696546365132577370';'
19/06/06 11:39:28 DEBUG HanaMessageHandler: Received Request from: '172.18.0.3'; Message Type => 'CONTINUE_SESSION'
19/06/06 11:39:28 INFO CommandRouterDefault: Current Assignments => 3878625230891646998-12696546365132577370#35d3a519-002a-0016-b033-31a660011a5b -> Actor[akka://SAPHanaSpark/user/Controller/HanaSparkRouter/$a#1995820509]; Incoming Assignment => '3878625230891646998-12696546365132577370#35d3a519-002a-0016-b033-31a660011a5b'
19/06/06 11:39:28 INFO RequestHandler: Retrieving Bound Message: '35d3a519-002a-0016-b033-31a660011a5b'
19/06/06 11:39:28 INFO HanaSparkFacade: Inside appraise session: hanaes (auth:SIMPLE)
19/06/06 11:39:28 DEBUG Session: Connecting User: 'root'
19/06/06 11:39:28 DEBUG RequestHandler: Relaying Message to Client: 'SESSION_OPENED'
19/06/06 11:39:28 DEBUG NetworkUtils: Outbound Message => 'Message Type => 'SESSION_OPENED'; Message Id => '693201738786757'; Request Id => '35d3a519-002a-0016-b033-31a660011a5b'; Session Id => '3878625230891646998-12696546365132577370';'
19/06/06 11:39:28 DEBUG RequestHandler: Finished executing: 'START_SESSION'. Returning to the pool
19/06/06 11:39:28 DEBUG ChannelManager: New Session is added: '3878625230891646998-12696546365132577370'
19/06/06 11:39:28 DEBUG NetworkUtils: Inbound Message => 'Message Type => 'PING'; Message Id => '693201743893250'; Request Id => '35d3a519-002a-0016-b033-31a660011a5c';'
19/06/06 11:39:28 DEBUG HanaMessageHandler: Received Request from: '172.18.0.3'; Message Type => 'PING'
19/06/06 11:39:28 DEBUG NetworkUtils: Outbound Message => 'Message Type => 'PONG'; Message Id => '693201746082223'; Request Id => '35d3a519-002a-0016-b033-31a660011a5c';'
19/06/06 11:39:28 DEBUG NetworkUtils: Inbound Message => 'Message Type => 'PING'; Message Id => '693201748509338'; Request Id => '35d3a519-002a-0016-b033-31a660011a5d';'
19/06/06 11:39:28 DEBUG HanaMessageHandler: Received Request from: '172.18.0.3'; Message Type => 'PING'
19/06/06 11:39:28 DEBUG NetworkUtils: Outbound Message => 'Message Type => 'PONG'; Message Id => '693201750304135'; Request Id => '35d3a519-002a-0016-b033-31a660011a5d';'
19/06/06 11:39:28 DEBUG NetworkUtils: Inbound Message => 'Message Type => 'PING'; Message Id => '693201752596927'; Request Id => '35d3a519-002a-0016-b033-31a660011a5e';'
19/06/06 11:39:28 DEBUG HanaMessageHandler: Received Request from: '172.18.0.3'; Message Type => 'PING'
19/06/06 11:39:28 DEBUG NetworkUtils: Outbound Message => 'Message Type => 'PONG'; Message Id => '693201753461377'; Request Id => '35d3a519-002a-0016-b033-31a660011a5e';'
19/06/06 11:39:28 DEBUG NetworkUtils: Inbound Message => 'Message Type => 'QUERY_EXECUTE'; Message Id => '693201755190134'; Request Id => '35d3a519-002a-0016-b033-31a660011a5f'; Session Id => '3878625230891646998-12696546365132577370';'
19/06/06 11:39:28 DEBUG HanaMessageHandler: Received Request from: '172.18.0.3'; Message Type => 'QUERY_EXECUTE'
19/06/06 11:39:28 INFO CommandRouterDefault: Current Assignments => NONE; Incoming Assignment => '3878625230891646998-12696546365132577370#35d3a519-002a-0016-b033-31a660011a5f'
19/06/06 11:39:28 INFO RequestHandler: Bound Message to Orchestrator: '35d3a519-002a-0016-b033-31a660011a5f'
19/06/06 11:39:28 INFO RequestHandler: Retrieving Bound Message: '35d3a519-002a-0016-b033-31a660011a5f'
19/06/06 11:39:28 DEBUG HanaExecPlan: <?xml version="1.0"?><hana:queryplan xmlns:hana="http://www.sap.com/hana"><select><sql>SELECT COUNT(*) AS CA_10261569202013848859 FROM "foodmart"."customer" "Hadoop_customer" </sql><typeInfo><column><name>COL0</name><type>4</type></column></typeInfo><parameters/><hints/><relocators/></select></hana:queryplan>
19/06/06 11:39:28 DEBUG RequestHandler: Chosen Engine ID: 'sparksql'
19/06/06 11:39:28 DEBUG DataRouteRegistry: Registering Query Execution with requestId: '147BF43D222C974CC039F0B3C6E6356C'
19/06/06 11:39:28 INFO AsyncExecutor: Running with User Privilege 'root'
19/06/06 11:39:28 DEBUG RequestHandler: Unblocked Relay
19/06/06 11:39:28 DEBUG RequestHandler: Relaying Message to Client: 'QUERY_ACCEPTED'
19/06/06 11:39:28 DEBUG NetworkUtils: Outbound Message => 'Message Type => 'QUERY_ACCEPTED'; Message Id => '693201797735164'; Request Id => '35d3a519-002a-0016-b033-31a660011a5f'; Session Id => '3878625230891646998-12696546365132577370';'
19/06/06 11:39:28 INFO HanaSparkFacade: HanaSelectTask (SQL): SELECT COUNT(*) AS CA_10261569202013848859 FROM `foodmart`.`customer` `Hadoop_customer`
19/06/06 11:39:29 INFO SparkCompositeCatalog: Looking for table: 'foodmart.customer'
19/06/06 11:39:30 DEBUG HanaHiveSQLContext: resolveRelations23 - hti.table = 'customer'; rel = ''SubqueryAlias customer
+- 'UnresolvedCatalogRelation `foodmart`.`customer`, org.apache.hadoop.hive.ql.io.orc.OrcSerde
'
19/06/06 11:39:30 DEBUG DistributedDataSetFactoryImpl: Query plan:
'Project ['COUNT(1) AS CA_10261569202013848859#39]
+- 'SubqueryAlias Hadoop_customer
   +- 'SubqueryAlias customer
      +- 'SubqueryAlias customer
         +- 'UnresolvedCatalogRelation `foodmart`.`customer`, org.apache.hadoop.hive.ql.io.orc.OrcSerde

19/06/06 11:39:30 INFO SparkFacade$$anon$1: Created broadcast 0 from 
19/06/06 11:39:31 INFO SparkFacade$$anon$1: Starting job: transferDatafromPartitions at SparkFacade.scala:299
19/06/06 11:39:31 INFO SparkFacade$$anon$1: Created broadcast 1 from broadcast at DAGScheduler.scala:1039
19/06/06 11:39:33 INFO SparkFacade$$anon$1: Created broadcast 2 from broadcast at DAGScheduler.scala:1039
19/06/06 11:39:35 DEBUG SmartReverseProxyHandler: Starting Channel Tag: 'sandbox-hdp.hortonworks.com:49372'
19/06/06 11:39:35 DEBUG SmartReverseProxyHandler: Message Type => 'DATA_SOURCE_LOCATION'
19/06/06 11:39:35 DEBUG DataRouteRegistry: Registering End Point for requestId: '147BF43D222C974CC039F0B3C6E6356C' ('3878625230891646998-12696546365132577370', '35d3a519-002a-0016-b033-31a660011a5f'), transferId: 'Result:0'
19/06/06 11:39:35 DEBUG NetworkUtils: Inbound Message => 'Message Type => 'DATA_SOURCE_LOCATION'; Message Id => '693208692846518'; Request Id => '35d3a519-002a-0016-b033-31a660011a5f'; Session Id => '3878625230891646998-12696546365132577370';'
19/06/06 11:39:35 DEBUG HanaMessageHandler: Received Request from: 'sandbox-hdp.hortonworks.com'; Message Type => 'DATA_SOURCE_LOCATION'
19/06/06 11:39:35 INFO CommandRouterDefault: Current Assignments => 3878625230891646998-12696546365132577370#35d3a519-002a-0016-b033-31a660011a5f -> Actor[akka://SAPHanaSpark/user/Controller/HanaSparkRouter/$b#-336533065]; Incoming Assignment => '3878625230891646998-12696546365132577370#35d3a519-002a-0016-b033-31a660011a5f'
19/06/06 11:39:35 INFO RequestHandler: Retrieving Bound Message: '35d3a519-002a-0016-b033-31a660011a5f'
19/06/06 11:39:35 INFO RequestHandler: Forwarding Data Vent: 'QUERY_DATA_SOURCE'; Direction: '0'
19/06/06 11:39:35 DEBUG RequestHandler: Data Transfer End Point: '172.18.0.2:7861'
19/06/06 11:39:35 DEBUG RequestHandler: Relaying Message to Client: 'QUERY_DATA_SOURCE'
19/06/06 11:39:35 DEBUG NetworkUtils: Outbound Message => 'Message Type => 'QUERY_DATA_SOURCE'; Message Id => '693208699630324'; Request Id => '35d3a519-002a-0016-b033-31a660011a5f'; Session Id => '3878625230891646998-12696546365132577370';'
19/06/06 11:49:35 DEBUG HanaMessageHandler: Channel is unregistered... Closing all sessions
19/06/06 11:49:35 DEBUG ChannelManager: Closing All Sessions
19/06/06 11:49:35 DEBUG ChannelManager: Session is closed: '3878625230891646998-12696546365132577370'

We need help to figure out, why the result is not coming back. This is our first Hadoop installation, we do not know what the root cause could possibly be. Maybe there is an issue with the IP or port that is mentioned in line "Data Transfer End Point"?

Your advice on how to pinpoint and resolve the root cause would be greatly appreciated.

Thank you very much and best regards,

Bernhard

[#2]

Hi Bernhard Sauerteig,

We are trying to connect spark controller through hana studio and are able to connect to the spark controller but cannot read any tables. We have ranger enabled and it is throwing permission denied error while accessing databases. Can you please let us know if we need to make any config settings associated with ranger. Thanks in advance.

Thanks,

Harshini

[#3]

Hi,

we have exactly the same issue... querying an external table as suggested does not help.

We have also completely deleted Ranger and Knox from the Sandbox.

The port we use is 8090. 8090 and 8091 are published in the hdp docker container.

Does anyone know how to resolve the issue?

[#4]

I think we have to configure the sandbox-proxy container  as proxy host in the sparkcontroller config. I will try that next and report the result

[#5]

I have the solution now:

In the "Custom hanaes-site" set sap.hana.es.dmz.proxy.host=sandbox-proxy

And in the Remote Datasource in HANA:

CREATE REMOTE SOURCE “proxy_spark" ADAPTER "sparksql" CONFIGURATION 'server=<SANDBOX-VM IP>;port=8090;ssl_mode=disabled;proxy_host=<SANDBOX-VM IP>' WITH CREDENTIAL TYPE 'PASSWORD' USING 'user=hanaes;password=hanaes';

With WebHcat server enabled I got some errors, that the port is not free, so either use another port, that is published in the sandbox-proxy or disable webhcat server.

Normally 8090 + 8091 should be free to use according to the docs