[LENS-1242] JDBCDriver cancel query is taking huge time

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 2.6
• Component/s: driver-jdbc
• Assignee: Amareshwari Sriramadasu
• Reporter: Amareshwari Sriramadasu
• Created: 29/Jul/16 05:14
• Updated: 25/Oct/16 12:18
• Resolved: 01/Aug/16 12:41

Description

We are seeing Cancel on JDBC is taking huge time in production.

Here are few logs :

28 Jul 2016 05:54:19 [1113a9e8-86cd-43eb-b5bb-ad718a7e87cd] [grizzly-http-server-43] INFO  org.apache.lens.server.query.QueryExecutionServiceImpl - CancelQuery: session:<?xml version="1.0" encoding="UTF-8" standalone="yes"?><lensSessionHandle><publicId>617e95ae-397f-46ea-9b20-f472e614d673</publicId><secretId>761a20c0-80b8-4406-a614-b38e21fa5b34</secretId></lensSessionHandle> query:18a411f0-b62e-48e9-821c-f34da98fedbc
28 Jul 2016 05:54:19 [1113a9e8-86cd-43eb-b5bb-ad718a7e87cd] [grizzly-http-server-43] INFO  org.apache.hadoop.hive.conf.HiveConf - Using the default value passed in for log id: 617e95ae-397f-46ea-9b20-f472e614d673
28 Jul 2016 05:54:19 [1113a9e8-86cd-43eb-b5bb-ad718a7e87cd] [grizzly-http-server-43] INFO  org.apache.hadoop.hive.ql.session.SessionState - Updating thread name to 617e95ae-397f-46ea-9b20-f472e614d673 grizzly-http-server-43
28 Jul 2016 05:54:19 [18a411f0-b62e-48e9-821c-f34da98fedbc] [617e95ae-397f-46ea-9b20-f472e614d673 grizzly-http-server-43] INFO  org.apache.lens.server.query.QueryExecutionServiceImpl - Updating status for 18a411f0-b62e-48e9-821c-f34da98fedbc
28 Jul 2016 05:54:19 [18a411f0-b62e-48e9-821c-f34da98fedbc] [617e95ae-397f-46ea-9b20-f472e614d673 grizzly-http-server-43] INFO  org.apache.lens.server.api.query.QueryContext - Updating status of 18a411f0-b62e-48e9-821c-f34da98fedbc from Progress: 0.0
28 Jul 2016 05:54:56 [18a411f0-b62e-48e9-821c-f34da98fedbc] [StatusPoller] INFO  org.apache.lens.server.query.QueryExecutionServiceImpl - Updating status for 18a411f0-b62e-48e9-821c-f34da98fedbc
 Progress: 0.0
Status: RUNNING
Status Message: 18a411f0-b62e-48e9-821c-f34da98fedbc is running
Is Result Set Available: false
 to Progress: 0.0
Status: RUNNING
Status Message: 18a411f0-b62e-48e9-821c-f34da98fedbc is running
Is Result Set Available: false
28 Jul 2016 06:14:38 [18a411f0-b62e-48e9-821c-f34da98fedbc] [617e95ae-397f-46ea-9b20-f472e614d673 grizzly-http-server-43] INFO  org.apache.lens.driver.jdbc.JDBCDriver - jdbc/prod Cancelled query : 18a411f0-b62e-48e9-821c-f34da98fedbc
28 Jul 2016 06:14:38 [18a411f0-b62e-48e9-821c-f34da98fedbc] [617e95ae-397f-46ea-9b20-f472e614d673 grizzly-http-server-43] INFO  org.apache.lens.server.query.QueryExecutionServiceImpl - Query 18a411f0-b62e-48e9-821c-f34da98fedbc cancelled successfully
28 Jul 2016 06:14:38 [18a411f0-b62e-48e9-821c-f34da98fedbc] [617e95ae-397f-46ea-9b20-f472e614d673 grizzly-http-server-43] INFO  org.apache.lens.server.api.query.QueryContext - Updating status of 18a411f0-b62e-48e9-821c-f34da98fedbc from Progress: 0.0
28 Jul 2016 06:14:38 [18a411f0-b62e-48e9-821c-f34da98fedbc] [617e95ae-397f-46ea-9b20-f472e614d673 grizzly-http-server-43] INFO  org.apache.lens.server.session.LensSessionImpl - Removing 18a411f0-b62e-48e9-821c-f34da98fedbc from active queries for session 617e95ae-397f-46ea-9b20-f472e614d673
28 Jul 2016 06:14:38 [18a411f0-b62e-48e9-821c-f34da98fedbc] [617e95ae-397f-46ea-9b20-f472e614d673 grizzly-http-server-43] INFO  org.apache.hadoop.hive.conf.HiveConf - Using the default value passed in for log id: 617e95ae-397f-46ea-9b20-f472e614d673
28 Jul 2016 06:14:38 [18a411f0-b62e-48e9-821c-f34da98fedbc] [617e95ae-397f-46ea-9b20-f472e614d673 grizzly-http-server-43] INFO  org.apache.hadoop.hive.ql.session.SessionState - Resetting thread name to  grizzly-http-server-43

It took more than 10 minutes for cancelling from above logs.