You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@sentry.apache.org by Vamsee Yarlagadda <va...@cloudera.com> on 2017/02/03 04:42:14 UTC

Review Request 56271: SENTRY-1621: HMSFollower to retry connecting to HMS upon connection loss

-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/56271/
-----------------------------------------------------------

Review request for sentry, Alexander Kolbasov, Hao Hao, kalyan kumar kalvagadda, and Vadim Spector.


Repository: sentry


Description
-------

Looking at the existing logic of HMSFollower, upon the connection loss to HMS the client never attempts to reconnect to HMS but rather just errors out with "Broken pipe" indefinitely.

```bash
org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe
	at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)
    ...
    ...
Caused by: java.net.SocketException: Broken pipe
	at java.net.SocketOutputStream.socketWrite0(Native Method)
	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
    ...
	...
```

To improve this, we can extend HMSFollower to scan for SocketException errors and if received, it can instead reconnect to HMS.


Diffs
-----

  sentry-hdfs/sentry-hdfs-common/src/main/java/org/apache/sentry/hdfs/FullUpdateInitializer.java a1f970b1e6f14eedca057eb84df72de955d6f0c1 
  sentry-provider/sentry-provider-db/src/main/java/org/apache/sentry/service/thrift/HMSFollower.java 1f05ba9cb6483251821f2965808dfd0711e70c63 

Diff: https://reviews.apache.org/r/56271/diff/


Testing
-------

Ran the scenario of:
1. Start with Sentry + HMS connected.
2. Stop the HMS and verify the broken pipe errors reported on Sentry side and it's attempts to establish a new connection.
3. Start the HMS and verify the subsequent attempt of HMS client connection succeeds and processes transactions.

```bash
##########################################  FIRST STEP ##################################################
2017-02-02 19:59:43,724 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
2017-02-02 19:59:43,729 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
2017-02-02 19:59:43,729 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
2017-02-02 19:59:43,753 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
2017-02-02 19:59:43,760 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
2017-02-02 19:59:43,864 INFO hive.metastore: Opened a connection to metastore, current connections: 1
2017-02-02 19:59:43,865 INFO hive.metastore: Connected to metastore.
2017-02-02 19:59:43,865 INFO org.apache.sentry.service.thrift.HMSFollower: Secure connection established with HMS
2017-02-02 19:59:43,865 INFO org.apache.sentry.service.thrift.HMSFollower: HMSFollower of Sentry successfully connected to HMS
2017-02-02 19:59:43,978 INFO org.apache.sentry.service.thrift.HMSFollower: Before fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
2017-02-02 19:59:45,005 INFO org.apache.sentry.service.thrift.HMSFollower: #### Hive full update initialization complete !!
2017-02-02 19:59:45,008 INFO org.apache.sentry.service.thrift.HMSFollower: After fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
2017-02-02 19:59:45,009 INFO org.apache.sentry.service.thrift.HMSFollower: Successfully fetched hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
2017-02-02 19:59:45,096 INFO org.apache.sentry.service.thrift.HMSFollower: CurrentEventID = 0. Processing 0 events
....
##########################################  SECOND STEP ##################################################
2017-02-02 20:00:03,314 ERROR org.apache.sentry.service.thrift.HMSFollower: ThriftException occured fetching Notification entries, will try
org.apache.thrift.transport.TTransportException
	at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:132)
	at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
    ...
    ...
2017-02-02 20:00:03,317 ERROR org.apache.sentry.service.thrift.HMSFollower: Encountered Socket Exception during fetching Notification entries, will reconnect to HMS
org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe
	at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)
	at org.apache.thrift.transport.TSaslTransport.flush(TSaslTransport.java:501)
	at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
    ...
    ...
Caused by: java.net.SocketException: Broken pipe
	at java.net.SocketOutputStream.socketWrite0(Native Method)
	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
    ...
    ...

2017-02-02 20:00:03,323 INFO hive.metastore: Closed a connection to metastore, current connections: 0
2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
2017-02-02 20:00:03,443 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
2017-02-02 20:00:03,449 WARN hive.metastore: Failed to connect to the MetaStore Server...
2017-02-02 20:00:03,449 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
2017-02-02 20:00:03,449 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
2017-02-02 20:00:03,759 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread finished
2017-02-02 20:00:04,449 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
2017-02-02 20:00:04,451 WARN hive.metastore: Failed to connect to the MetaStore Server...
2017-02-02 20:00:04,451 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
2017-02-02 20:00:05,452 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
2017-02-02 20:00:05,453 WARN hive.metastore: Failed to connect to the MetaStore Server...
2017-02-02 20:00:05,453 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
2017-02-02 20:00:06,456 ERROR org.apache.sentry.service.thrift.HMSFollower: Failed to setup secure connection to HMS.
2017-02-02 20:00:06,456 ERROR org.apache.sentry.service.thrift.HMSFollower: HMSFollower cannot connect to HMS!!
java.security.PrivilegedActionException: MetaException(message:Could not connect to meta store using any of the URIs provided. Most recent failure: org.apache.thrift.transport.TTransportException: java.net.ConnectException: Connection refused
	at org.apache.thrift.transport.TSocket.open(TSocket.java:226)
	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:266)
    ...
    ...
Caused by: java.net.ConnectException: Connection refused
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
    ...
    ...
Caused by: MetaException(message:Could not connect to meta store using any of the URIs provided. Most recent failure: org.apache.thrift.transport.TTransportException: java.net.ConnectException: Connection refused
	at org.apache.thrift.transport.TSocket.open(TSocket.java:226)
	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:266)
    ...
    ...
Caused by: java.net.ConnectException: Connection refused
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
    ...
    ...
    
##########################################  THIRD STEP ##################################################
2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
2017-02-02 20:01:29,277 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
2017-02-02 20:01:29,279 WARN hive.metastore: Failed to connect to the MetaStore Server...
2017-02-02 20:01:29,279 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
2017-02-02 20:01:29,279 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
2017-02-02 20:01:30,202 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread finished
2017-02-02 20:01:30,279 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
2017-02-02 20:01:30,311 INFO hive.metastore: Opened a connection to metastore, current connections: 1
2017-02-02 20:01:30,311 INFO hive.metastore: Connected to metastore.
2017-02-02 20:01:30,311 INFO org.apache.sentry.service.thrift.HMSFollower: Secure connection established with HMS
2017-02-02 20:01:30,311 INFO org.apache.sentry.service.thrift.HMSFollower: HMSFollower of Sentry successfully connected to HMS
2017-02-02 20:01:30,437 INFO org.apache.sentry.service.thrift.HMSFollower: Before fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
2017-02-02 20:01:31,451 INFO org.apache.sentry.service.thrift.HMSFollower: #### Hive full update initialization complete !!
2017-02-02 20:01:31,454 INFO org.apache.sentry.service.thrift.HMSFollower: After fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
2017-02-02 20:01:31,454 INFO org.apache.sentry.service.thrift.HMSFollower: Successfully fetched hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
2017-02-02 20:01:31,516 INFO org.apache.sentry.service.thrift.HMSFollower: CurrentEventID = 0. Processing 0 events

```


Thanks,

Vamsee Yarlagadda


Re: Review Request 56271: SENTRY-1621: HMSFollower to retry connecting to HMS upon connection loss

Posted by Vamsee Yarlagadda <va...@cloudera.com>.

> On Feb. 3, 2017, 5:03 a.m., Alexander Kolbasov wrote:
> > sentry-provider/sentry-provider-db/src/main/java/org/apache/sentry/service/thrift/HMSFollower.java, line 269
> > <https://reviews.apache.org/r/56271/diff/1/?file=1622914#file1622914line269>
> >
> >     can client.close() throw any exception? If it does, you'll miss resetting of kerberos context.

By the function definition, it doesn't have any checked exceptions.


- Vamsee


-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/56271/#review164087
-----------------------------------------------------------


On Feb. 3, 2017, 4:42 a.m., Vamsee Yarlagadda wrote:
> 
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/56271/
> -----------------------------------------------------------
> 
> (Updated Feb. 3, 2017, 4:42 a.m.)
> 
> 
> Review request for sentry, Alexander Kolbasov, Hao Hao, kalyan kumar kalvagadda, and Vadim Spector.
> 
> 
> Repository: sentry
> 
> 
> Description
> -------
> 
> Looking at the existing logic of HMSFollower, upon the connection loss to HMS the client never attempts to reconnect to HMS but rather just errors out with "Broken pipe" indefinitely.
> 
> ```bash
> org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe
> 	at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)
>     ...
>     ...
> Caused by: java.net.SocketException: Broken pipe
> 	at java.net.SocketOutputStream.socketWrite0(Native Method)
> 	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
>     ...
> 	...
> ```
> 
> To improve this, we can extend HMSFollower to scan for SocketException errors and if received, it can instead reconnect to HMS.
> 
> 
> Diffs
> -----
> 
>   sentry-hdfs/sentry-hdfs-common/src/main/java/org/apache/sentry/hdfs/FullUpdateInitializer.java a1f970b1e6f14eedca057eb84df72de955d6f0c1 
>   sentry-provider/sentry-provider-db/src/main/java/org/apache/sentry/service/thrift/HMSFollower.java 1f05ba9cb6483251821f2965808dfd0711e70c63 
> 
> Diff: https://reviews.apache.org/r/56271/diff/
> 
> 
> Testing
> -------
> 
> Ran the scenario of:
> 1. Start with Sentry + HMS connected.
> 2. Stop the HMS and verify the broken pipe errors reported on Sentry side and it's attempts to establish a new connection.
> 3. Start the HMS and verify the subsequent attempt of HMS client connection succeeds and processes transactions.
> 
> ```bash
> ##########################################  FIRST STEP ##################################################
> 2017-02-02 19:59:43,724 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 19:59:43,729 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 19:59:43,729 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 19:59:43,753 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 19:59:43,760 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 19:59:43,864 INFO hive.metastore: Opened a connection to metastore, current connections: 1
> 2017-02-02 19:59:43,865 INFO hive.metastore: Connected to metastore.
> 2017-02-02 19:59:43,865 INFO org.apache.sentry.service.thrift.HMSFollower: Secure connection established with HMS
> 2017-02-02 19:59:43,865 INFO org.apache.sentry.service.thrift.HMSFollower: HMSFollower of Sentry successfully connected to HMS
> 2017-02-02 19:59:43,978 INFO org.apache.sentry.service.thrift.HMSFollower: Before fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,005 INFO org.apache.sentry.service.thrift.HMSFollower: #### Hive full update initialization complete !!
> 2017-02-02 19:59:45,008 INFO org.apache.sentry.service.thrift.HMSFollower: After fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,009 INFO org.apache.sentry.service.thrift.HMSFollower: Successfully fetched hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,096 INFO org.apache.sentry.service.thrift.HMSFollower: CurrentEventID = 0. Processing 0 events
> ....
> ##########################################  SECOND STEP ##################################################
> 2017-02-02 20:00:03,314 ERROR org.apache.sentry.service.thrift.HMSFollower: ThriftException occured fetching Notification entries, will try
> org.apache.thrift.transport.TTransportException
> 	at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:132)
> 	at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
>     ...
>     ...
> 2017-02-02 20:00:03,317 ERROR org.apache.sentry.service.thrift.HMSFollower: Encountered Socket Exception during fetching Notification entries, will reconnect to HMS
> org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe
> 	at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)
> 	at org.apache.thrift.transport.TSaslTransport.flush(TSaslTransport.java:501)
> 	at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
>     ...
>     ...
> Caused by: java.net.SocketException: Broken pipe
> 	at java.net.SocketOutputStream.socketWrite0(Native Method)
> 	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
>     ...
>     ...
> 
> 2017-02-02 20:00:03,323 INFO hive.metastore: Closed a connection to metastore, current connections: 0
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 20:00:03,443 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:03,449 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:03,449 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:03,449 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 20:00:03,759 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread finished
> 2017-02-02 20:00:04,449 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:04,451 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:04,451 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:05,452 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:05,453 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:05,453 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:06,456 ERROR org.apache.sentry.service.thrift.HMSFollower: Failed to setup secure connection to HMS.
> 2017-02-02 20:00:06,456 ERROR org.apache.sentry.service.thrift.HMSFollower: HMSFollower cannot connect to HMS!!
> java.security.PrivilegedActionException: MetaException(message:Could not connect to meta store using any of the URIs provided. Most recent failure: org.apache.thrift.transport.TTransportException: java.net.ConnectException: Connection refused
> 	at org.apache.thrift.transport.TSocket.open(TSocket.java:226)
> 	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:266)
>     ...
>     ...
> Caused by: java.net.ConnectException: Connection refused
> 	at java.net.PlainSocketImpl.socketConnect(Native Method)
> 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
>     ...
>     ...
> Caused by: MetaException(message:Could not connect to meta store using any of the URIs provided. Most recent failure: org.apache.thrift.transport.TTransportException: java.net.ConnectException: Connection refused
> 	at org.apache.thrift.transport.TSocket.open(TSocket.java:226)
> 	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:266)
>     ...
>     ...
> Caused by: java.net.ConnectException: Connection refused
> 	at java.net.PlainSocketImpl.socketConnect(Native Method)
> 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
>     ...
>     ...
>     
> ##########################################  THIRD STEP ##################################################
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 20:01:29,277 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:01:29,279 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:01:29,279 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:01:29,279 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 20:01:30,202 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread finished
> 2017-02-02 20:01:30,279 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:01:30,311 INFO hive.metastore: Opened a connection to metastore, current connections: 1
> 2017-02-02 20:01:30,311 INFO hive.metastore: Connected to metastore.
> 2017-02-02 20:01:30,311 INFO org.apache.sentry.service.thrift.HMSFollower: Secure connection established with HMS
> 2017-02-02 20:01:30,311 INFO org.apache.sentry.service.thrift.HMSFollower: HMSFollower of Sentry successfully connected to HMS
> 2017-02-02 20:01:30,437 INFO org.apache.sentry.service.thrift.HMSFollower: Before fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,451 INFO org.apache.sentry.service.thrift.HMSFollower: #### Hive full update initialization complete !!
> 2017-02-02 20:01:31,454 INFO org.apache.sentry.service.thrift.HMSFollower: After fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,454 INFO org.apache.sentry.service.thrift.HMSFollower: Successfully fetched hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,516 INFO org.apache.sentry.service.thrift.HMSFollower: CurrentEventID = 0. Processing 0 events
> 
> ```
> 
> 
> Thanks,
> 
> Vamsee Yarlagadda
> 
>


Re: Review Request 56271: SENTRY-1621: HMSFollower to retry connecting to HMS upon connection loss

Posted by Alexander Kolbasov <ak...@gmail.com>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/56271/#review164087
-----------------------------------------------------------


Fix it, then Ship it!




Ship It!


sentry-provider/sentry-provider-db/src/main/java/org/apache/sentry/service/thrift/HMSFollower.java (line 262)
<https://reviews.apache.org/r/56271/#comment235649>

    can client.close() throw any exception? If it does, you'll miss resetting of kerberos context.


- Alexander Kolbasov


On Feb. 3, 2017, 4:42 a.m., Vamsee Yarlagadda wrote:
> 
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/56271/
> -----------------------------------------------------------
> 
> (Updated Feb. 3, 2017, 4:42 a.m.)
> 
> 
> Review request for sentry, Alexander Kolbasov, Hao Hao, kalyan kumar kalvagadda, and Vadim Spector.
> 
> 
> Repository: sentry
> 
> 
> Description
> -------
> 
> Looking at the existing logic of HMSFollower, upon the connection loss to HMS the client never attempts to reconnect to HMS but rather just errors out with "Broken pipe" indefinitely.
> 
> ```bash
> org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe
> 	at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)
>     ...
>     ...
> Caused by: java.net.SocketException: Broken pipe
> 	at java.net.SocketOutputStream.socketWrite0(Native Method)
> 	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
>     ...
> 	...
> ```
> 
> To improve this, we can extend HMSFollower to scan for SocketException errors and if received, it can instead reconnect to HMS.
> 
> 
> Diffs
> -----
> 
>   sentry-hdfs/sentry-hdfs-common/src/main/java/org/apache/sentry/hdfs/FullUpdateInitializer.java a1f970b1e6f14eedca057eb84df72de955d6f0c1 
>   sentry-provider/sentry-provider-db/src/main/java/org/apache/sentry/service/thrift/HMSFollower.java 1f05ba9cb6483251821f2965808dfd0711e70c63 
> 
> Diff: https://reviews.apache.org/r/56271/diff/
> 
> 
> Testing
> -------
> 
> Ran the scenario of:
> 1. Start with Sentry + HMS connected.
> 2. Stop the HMS and verify the broken pipe errors reported on Sentry side and it's attempts to establish a new connection.
> 3. Start the HMS and verify the subsequent attempt of HMS client connection succeeds and processes transactions.
> 
> ```bash
> ##########################################  FIRST STEP ##################################################
> 2017-02-02 19:59:43,724 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 19:59:43,729 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 19:59:43,729 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 19:59:43,753 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 19:59:43,760 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 19:59:43,864 INFO hive.metastore: Opened a connection to metastore, current connections: 1
> 2017-02-02 19:59:43,865 INFO hive.metastore: Connected to metastore.
> 2017-02-02 19:59:43,865 INFO org.apache.sentry.service.thrift.HMSFollower: Secure connection established with HMS
> 2017-02-02 19:59:43,865 INFO org.apache.sentry.service.thrift.HMSFollower: HMSFollower of Sentry successfully connected to HMS
> 2017-02-02 19:59:43,978 INFO org.apache.sentry.service.thrift.HMSFollower: Before fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,005 INFO org.apache.sentry.service.thrift.HMSFollower: #### Hive full update initialization complete !!
> 2017-02-02 19:59:45,008 INFO org.apache.sentry.service.thrift.HMSFollower: After fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,009 INFO org.apache.sentry.service.thrift.HMSFollower: Successfully fetched hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,096 INFO org.apache.sentry.service.thrift.HMSFollower: CurrentEventID = 0. Processing 0 events
> ....
> ##########################################  SECOND STEP ##################################################
> 2017-02-02 20:00:03,314 ERROR org.apache.sentry.service.thrift.HMSFollower: ThriftException occured fetching Notification entries, will try
> org.apache.thrift.transport.TTransportException
> 	at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:132)
> 	at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
>     ...
>     ...
> 2017-02-02 20:00:03,317 ERROR org.apache.sentry.service.thrift.HMSFollower: Encountered Socket Exception during fetching Notification entries, will reconnect to HMS
> org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe
> 	at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)
> 	at org.apache.thrift.transport.TSaslTransport.flush(TSaslTransport.java:501)
> 	at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
>     ...
>     ...
> Caused by: java.net.SocketException: Broken pipe
> 	at java.net.SocketOutputStream.socketWrite0(Native Method)
> 	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
>     ...
>     ...
> 
> 2017-02-02 20:00:03,323 INFO hive.metastore: Closed a connection to metastore, current connections: 0
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 20:00:03,443 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:03,449 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:03,449 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:03,449 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 20:00:03,759 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread finished
> 2017-02-02 20:00:04,449 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:04,451 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:04,451 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:05,452 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:05,453 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:05,453 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:06,456 ERROR org.apache.sentry.service.thrift.HMSFollower: Failed to setup secure connection to HMS.
> 2017-02-02 20:00:06,456 ERROR org.apache.sentry.service.thrift.HMSFollower: HMSFollower cannot connect to HMS!!
> java.security.PrivilegedActionException: MetaException(message:Could not connect to meta store using any of the URIs provided. Most recent failure: org.apache.thrift.transport.TTransportException: java.net.ConnectException: Connection refused
> 	at org.apache.thrift.transport.TSocket.open(TSocket.java:226)
> 	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:266)
>     ...
>     ...
> Caused by: java.net.ConnectException: Connection refused
> 	at java.net.PlainSocketImpl.socketConnect(Native Method)
> 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
>     ...
>     ...
> Caused by: MetaException(message:Could not connect to meta store using any of the URIs provided. Most recent failure: org.apache.thrift.transport.TTransportException: java.net.ConnectException: Connection refused
> 	at org.apache.thrift.transport.TSocket.open(TSocket.java:226)
> 	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:266)
>     ...
>     ...
> Caused by: java.net.ConnectException: Connection refused
> 	at java.net.PlainSocketImpl.socketConnect(Native Method)
> 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
>     ...
>     ...
>     
> ##########################################  THIRD STEP ##################################################
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 20:01:29,277 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:01:29,279 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:01:29,279 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:01:29,279 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 20:01:30,202 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread finished
> 2017-02-02 20:01:30,279 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:01:30,311 INFO hive.metastore: Opened a connection to metastore, current connections: 1
> 2017-02-02 20:01:30,311 INFO hive.metastore: Connected to metastore.
> 2017-02-02 20:01:30,311 INFO org.apache.sentry.service.thrift.HMSFollower: Secure connection established with HMS
> 2017-02-02 20:01:30,311 INFO org.apache.sentry.service.thrift.HMSFollower: HMSFollower of Sentry successfully connected to HMS
> 2017-02-02 20:01:30,437 INFO org.apache.sentry.service.thrift.HMSFollower: Before fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,451 INFO org.apache.sentry.service.thrift.HMSFollower: #### Hive full update initialization complete !!
> 2017-02-02 20:01:31,454 INFO org.apache.sentry.service.thrift.HMSFollower: After fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,454 INFO org.apache.sentry.service.thrift.HMSFollower: Successfully fetched hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,516 INFO org.apache.sentry.service.thrift.HMSFollower: CurrentEventID = 0. Processing 0 events
> 
> ```
> 
> 
> Thanks,
> 
> Vamsee Yarlagadda
> 
>


Re: Review Request 56271: SENTRY-1621: HMSFollower to retry connecting to HMS upon connection loss

Posted by Vamsee Yarlagadda <va...@cloudera.com>.

> On Feb. 3, 2017, 8:28 p.m., Hao Hao wrote:
> > sentry-provider/sentry-provider-db/src/main/java/org/apache/sentry/service/thrift/HMSFollower.java, line 265
> > <https://reviews.apache.org/r/56271/diff/1/?file=1622914#file1622914line265>
> >
> >     Could there be any other exception impiles needs to reconnect to HMS?

SocketException should handle all possible cases that has to do with unable to access socket.
https://docs.oracle.com/javase/7/docs/api/java/net/SocketException.html

Atleast this should cover a good set of cases to begin with. We can expand more as we see it but more or less all connection related issues must be caught by this.


- Vamsee


-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/56271/#review164158
-----------------------------------------------------------


On Feb. 3, 2017, 4:42 a.m., Vamsee Yarlagadda wrote:
> 
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/56271/
> -----------------------------------------------------------
> 
> (Updated Feb. 3, 2017, 4:42 a.m.)
> 
> 
> Review request for sentry, Alexander Kolbasov, Hao Hao, kalyan kumar kalvagadda, and Vadim Spector.
> 
> 
> Repository: sentry
> 
> 
> Description
> -------
> 
> Looking at the existing logic of HMSFollower, upon the connection loss to HMS the client never attempts to reconnect to HMS but rather just errors out with "Broken pipe" indefinitely.
> 
> ```bash
> org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe
> 	at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)
>     ...
>     ...
> Caused by: java.net.SocketException: Broken pipe
> 	at java.net.SocketOutputStream.socketWrite0(Native Method)
> 	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
>     ...
> 	...
> ```
> 
> To improve this, we can extend HMSFollower to scan for SocketException errors and if received, it can instead reconnect to HMS.
> 
> 
> Diffs
> -----
> 
>   sentry-hdfs/sentry-hdfs-common/src/main/java/org/apache/sentry/hdfs/FullUpdateInitializer.java a1f970b1e6f14eedca057eb84df72de955d6f0c1 
>   sentry-provider/sentry-provider-db/src/main/java/org/apache/sentry/service/thrift/HMSFollower.java 1f05ba9cb6483251821f2965808dfd0711e70c63 
> 
> Diff: https://reviews.apache.org/r/56271/diff/
> 
> 
> Testing
> -------
> 
> Ran the scenario of:
> 1. Start with Sentry + HMS connected.
> 2. Stop the HMS and verify the broken pipe errors reported on Sentry side and it's attempts to establish a new connection.
> 3. Start the HMS and verify the subsequent attempt of HMS client connection succeeds and processes transactions.
> 
> ```bash
> ##########################################  FIRST STEP ##################################################
> 2017-02-02 19:59:43,724 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 19:59:43,729 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 19:59:43,729 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 19:59:43,753 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 19:59:43,760 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 19:59:43,864 INFO hive.metastore: Opened a connection to metastore, current connections: 1
> 2017-02-02 19:59:43,865 INFO hive.metastore: Connected to metastore.
> 2017-02-02 19:59:43,865 INFO org.apache.sentry.service.thrift.HMSFollower: Secure connection established with HMS
> 2017-02-02 19:59:43,865 INFO org.apache.sentry.service.thrift.HMSFollower: HMSFollower of Sentry successfully connected to HMS
> 2017-02-02 19:59:43,978 INFO org.apache.sentry.service.thrift.HMSFollower: Before fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,005 INFO org.apache.sentry.service.thrift.HMSFollower: #### Hive full update initialization complete !!
> 2017-02-02 19:59:45,008 INFO org.apache.sentry.service.thrift.HMSFollower: After fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,009 INFO org.apache.sentry.service.thrift.HMSFollower: Successfully fetched hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,096 INFO org.apache.sentry.service.thrift.HMSFollower: CurrentEventID = 0. Processing 0 events
> ....
> ##########################################  SECOND STEP ##################################################
> 2017-02-02 20:00:03,314 ERROR org.apache.sentry.service.thrift.HMSFollower: ThriftException occured fetching Notification entries, will try
> org.apache.thrift.transport.TTransportException
> 	at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:132)
> 	at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
>     ...
>     ...
> 2017-02-02 20:00:03,317 ERROR org.apache.sentry.service.thrift.HMSFollower: Encountered Socket Exception during fetching Notification entries, will reconnect to HMS
> org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe
> 	at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)
> 	at org.apache.thrift.transport.TSaslTransport.flush(TSaslTransport.java:501)
> 	at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
>     ...
>     ...
> Caused by: java.net.SocketException: Broken pipe
> 	at java.net.SocketOutputStream.socketWrite0(Native Method)
> 	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
>     ...
>     ...
> 
> 2017-02-02 20:00:03,323 INFO hive.metastore: Closed a connection to metastore, current connections: 0
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 20:00:03,443 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:03,449 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:03,449 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:03,449 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 20:00:03,759 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread finished
> 2017-02-02 20:00:04,449 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:04,451 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:04,451 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:05,452 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:05,453 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:05,453 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:06,456 ERROR org.apache.sentry.service.thrift.HMSFollower: Failed to setup secure connection to HMS.
> 2017-02-02 20:00:06,456 ERROR org.apache.sentry.service.thrift.HMSFollower: HMSFollower cannot connect to HMS!!
> java.security.PrivilegedActionException: MetaException(message:Could not connect to meta store using any of the URIs provided. Most recent failure: org.apache.thrift.transport.TTransportException: java.net.ConnectException: Connection refused
> 	at org.apache.thrift.transport.TSocket.open(TSocket.java:226)
> 	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:266)
>     ...
>     ...
> Caused by: java.net.ConnectException: Connection refused
> 	at java.net.PlainSocketImpl.socketConnect(Native Method)
> 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
>     ...
>     ...
> Caused by: MetaException(message:Could not connect to meta store using any of the URIs provided. Most recent failure: org.apache.thrift.transport.TTransportException: java.net.ConnectException: Connection refused
> 	at org.apache.thrift.transport.TSocket.open(TSocket.java:226)
> 	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:266)
>     ...
>     ...
> Caused by: java.net.ConnectException: Connection refused
> 	at java.net.PlainSocketImpl.socketConnect(Native Method)
> 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
>     ...
>     ...
>     
> ##########################################  THIRD STEP ##################################################
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 20:01:29,277 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:01:29,279 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:01:29,279 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:01:29,279 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 20:01:30,202 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread finished
> 2017-02-02 20:01:30,279 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:01:30,311 INFO hive.metastore: Opened a connection to metastore, current connections: 1
> 2017-02-02 20:01:30,311 INFO hive.metastore: Connected to metastore.
> 2017-02-02 20:01:30,311 INFO org.apache.sentry.service.thrift.HMSFollower: Secure connection established with HMS
> 2017-02-02 20:01:30,311 INFO org.apache.sentry.service.thrift.HMSFollower: HMSFollower of Sentry successfully connected to HMS
> 2017-02-02 20:01:30,437 INFO org.apache.sentry.service.thrift.HMSFollower: Before fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,451 INFO org.apache.sentry.service.thrift.HMSFollower: #### Hive full update initialization complete !!
> 2017-02-02 20:01:31,454 INFO org.apache.sentry.service.thrift.HMSFollower: After fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,454 INFO org.apache.sentry.service.thrift.HMSFollower: Successfully fetched hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,516 INFO org.apache.sentry.service.thrift.HMSFollower: CurrentEventID = 0. Processing 0 events
> 
> ```
> 
> 
> Thanks,
> 
> Vamsee Yarlagadda
> 
>


Re: Review Request 56271: SENTRY-1621: HMSFollower to retry connecting to HMS upon connection loss

Posted by Hao Hao <ha...@cloudera.com>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/56271/#review164158
-----------------------------------------------------------


Fix it, then Ship it!





sentry-provider/sentry-provider-db/src/main/java/org/apache/sentry/service/thrift/HMSFollower.java (line 258)
<https://reviews.apache.org/r/56271/#comment235743>

    Could there be any other exception impiles needs to reconnect to HMS?


- Hao Hao


On Feb. 3, 2017, 4:42 a.m., Vamsee Yarlagadda wrote:
> 
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/56271/
> -----------------------------------------------------------
> 
> (Updated Feb. 3, 2017, 4:42 a.m.)
> 
> 
> Review request for sentry, Alexander Kolbasov, Hao Hao, kalyan kumar kalvagadda, and Vadim Spector.
> 
> 
> Repository: sentry
> 
> 
> Description
> -------
> 
> Looking at the existing logic of HMSFollower, upon the connection loss to HMS the client never attempts to reconnect to HMS but rather just errors out with "Broken pipe" indefinitely.
> 
> ```bash
> org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe
> 	at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)
>     ...
>     ...
> Caused by: java.net.SocketException: Broken pipe
> 	at java.net.SocketOutputStream.socketWrite0(Native Method)
> 	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
>     ...
> 	...
> ```
> 
> To improve this, we can extend HMSFollower to scan for SocketException errors and if received, it can instead reconnect to HMS.
> 
> 
> Diffs
> -----
> 
>   sentry-hdfs/sentry-hdfs-common/src/main/java/org/apache/sentry/hdfs/FullUpdateInitializer.java a1f970b1e6f14eedca057eb84df72de955d6f0c1 
>   sentry-provider/sentry-provider-db/src/main/java/org/apache/sentry/service/thrift/HMSFollower.java 1f05ba9cb6483251821f2965808dfd0711e70c63 
> 
> Diff: https://reviews.apache.org/r/56271/diff/
> 
> 
> Testing
> -------
> 
> Ran the scenario of:
> 1. Start with Sentry + HMS connected.
> 2. Stop the HMS and verify the broken pipe errors reported on Sentry side and it's attempts to establish a new connection.
> 3. Start the HMS and verify the subsequent attempt of HMS client connection succeeds and processes transactions.
> 
> ```bash
> ##########################################  FIRST STEP ##################################################
> 2017-02-02 19:59:43,724 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 19:59:43,729 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 19:59:43,729 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 19:59:43,753 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 19:59:43,760 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 19:59:43,864 INFO hive.metastore: Opened a connection to metastore, current connections: 1
> 2017-02-02 19:59:43,865 INFO hive.metastore: Connected to metastore.
> 2017-02-02 19:59:43,865 INFO org.apache.sentry.service.thrift.HMSFollower: Secure connection established with HMS
> 2017-02-02 19:59:43,865 INFO org.apache.sentry.service.thrift.HMSFollower: HMSFollower of Sentry successfully connected to HMS
> 2017-02-02 19:59:43,978 INFO org.apache.sentry.service.thrift.HMSFollower: Before fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,005 INFO org.apache.sentry.service.thrift.HMSFollower: #### Hive full update initialization complete !!
> 2017-02-02 19:59:45,008 INFO org.apache.sentry.service.thrift.HMSFollower: After fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,009 INFO org.apache.sentry.service.thrift.HMSFollower: Successfully fetched hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 19:59:45,096 INFO org.apache.sentry.service.thrift.HMSFollower: CurrentEventID = 0. Processing 0 events
> ....
> ##########################################  SECOND STEP ##################################################
> 2017-02-02 20:00:03,314 ERROR org.apache.sentry.service.thrift.HMSFollower: ThriftException occured fetching Notification entries, will try
> org.apache.thrift.transport.TTransportException
> 	at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:132)
> 	at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
>     ...
>     ...
> 2017-02-02 20:00:03,317 ERROR org.apache.sentry.service.thrift.HMSFollower: Encountered Socket Exception during fetching Notification entries, will reconnect to HMS
> org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe
> 	at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)
> 	at org.apache.thrift.transport.TSaslTransport.flush(TSaslTransport.java:501)
> 	at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
>     ...
>     ...
> Caused by: java.net.SocketException: Broken pipe
> 	at java.net.SocketOutputStream.socketWrite0(Native Method)
> 	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
>     ...
>     ...
> 
> 2017-02-02 20:00:03,323 INFO hive.metastore: Closed a connection to metastore, current connections: 0
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 20:00:03,435 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 20:00:03,443 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:03,449 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:03,449 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:03,449 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 20:00:03,759 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread finished
> 2017-02-02 20:00:04,449 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:04,451 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:04,451 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:05,452 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:00:05,453 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:00:05,453 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:00:06,456 ERROR org.apache.sentry.service.thrift.HMSFollower: Failed to setup secure connection to HMS.
> 2017-02-02 20:00:06,456 ERROR org.apache.sentry.service.thrift.HMSFollower: HMSFollower cannot connect to HMS!!
> java.security.PrivilegedActionException: MetaException(message:Could not connect to meta store using any of the URIs provided. Most recent failure: org.apache.thrift.transport.TTransportException: java.net.ConnectException: Connection refused
> 	at org.apache.thrift.transport.TSocket.open(TSocket.java:226)
> 	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:266)
>     ...
>     ...
> Caused by: java.net.ConnectException: Connection refused
> 	at java.net.PlainSocketImpl.socketConnect(Native Method)
> 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
>     ...
>     ...
> Caused by: MetaException(message:Could not connect to meta store using any of the URIs provided. Most recent failure: org.apache.thrift.transport.TTransportException: java.net.ConnectException: Connection refused
> 	at org.apache.thrift.transport.TSocket.open(TSocket.java:226)
> 	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:266)
>     ...
>     ...
> Caused by: java.net.ConnectException: Connection refused
> 	at java.net.PlainSocketImpl.socketConnect(Native Method)
> 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
>     ...
>     ...
>     
> ##########################################  THIRD STEP ##################################################
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.HMSFollower: Making a kerberos connection to HMS
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.HMSFollower: Using kerberos principal: sentry/vamsee-sentry-1.vpc.cloudera.com@VPC.CLOUDERA.COM
> 2017-02-02 20:01:29,266 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Logging in with new Context
> 2017-02-02 20:01:29,277 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:01:29,279 WARN hive.metastore: Failed to connect to the MetaStore Server...
> 2017-02-02 20:01:29,279 INFO hive.metastore: Waiting 1 seconds before next connection attempt.
> 2017-02-02 20:01:29,279 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread started
> 2017-02-02 20:01:30,202 INFO org.apache.sentry.service.thrift.SentryKerberosContext: Sentry Ticket renewer thread finished
> 2017-02-02 20:01:30,279 INFO hive.metastore: Trying to connect to metastore with URI thrift://vamsee-sentry-1.vpc.cloudera.com:9083
> 2017-02-02 20:01:30,311 INFO hive.metastore: Opened a connection to metastore, current connections: 1
> 2017-02-02 20:01:30,311 INFO hive.metastore: Connected to metastore.
> 2017-02-02 20:01:30,311 INFO org.apache.sentry.service.thrift.HMSFollower: Secure connection established with HMS
> 2017-02-02 20:01:30,311 INFO org.apache.sentry.service.thrift.HMSFollower: HMSFollower of Sentry successfully connected to HMS
> 2017-02-02 20:01:30,437 INFO org.apache.sentry.service.thrift.HMSFollower: Before fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,451 INFO org.apache.sentry.service.thrift.HMSFollower: #### Hive full update initialization complete !!
> 2017-02-02 20:01:31,454 INFO org.apache.sentry.service.thrift.HMSFollower: After fetching hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,454 INFO org.apache.sentry.service.thrift.HMSFollower: Successfully fetched hive full snapshot, Current NotificationID = CurrentNotificationEventId(eventId:0).
> 2017-02-02 20:01:31,516 INFO org.apache.sentry.service.thrift.HMSFollower: CurrentEventID = 0. Processing 0 events
> 
> ```
> 
> 
> Thanks,
> 
> Vamsee Yarlagadda
> 
>