Re: Tephra errors when trying to create a transactional table in Phoenix 4.8.0

[James Taylor]

Hi Francis,
Is that the complete log for the transaction manager and if not would you
mind attaching that to a new JIRA?
Thanks,
James

On Wednesday, August 31, 2016, F21  wrote:

> Hey Thomas,
>
> Where are the Transaction Manager logs located? I have a
> /tmp/tephra-/tephra-service--m9edd51-hmaster1.m9edd51.log, which was
> where I got the logs from yesterday. There wasn't any information on
> whether the Transaction Manager crashed or not:
>
> Here's the last half of the logs:
> 2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client
> environment:java.io.tmpdir=/tmp
> 2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client
> environment:java.compiler=
> 2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client
> environment:os.name=Linux
> 2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client
> environment:os.arch=amd64
> 2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client
> environment:os.version=4.4.0-36-generic
> 2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client
> environment:user.name=hadoop
> 2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client
> environment:user.home=/opt/hbase
> 2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client
> environment:user.dir=/opt/hbase
> 2016-08-31 22:31:43,784 INFO  [main] zookeeper.ZooKeeper: Initiating
> client connection, connectString=m9edd51-zookeeper.m9edd51
> sessionTimeout=9 watcher=org.apache.tephra.zookeeper.
> TephraZKClientService$5@45c7e403
> 2016-08-31 22:31:43,824 INFO  
> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> m9edd51-zookeeper.m9edd51/172.18.0.2:2181. Will not attempt to
> authenticate using SASL (unknown error)
> 2016-08-31 22:31:43,829 INFO  
> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
> zookeeper.ClientCnxn: Socket connection established to
> m9edd51-zookeeper.m9edd51/172.18.0.2:2181, initiating session
> 2016-08-31 22:31:43,835 INFO  
> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
> zookeeper.ClientCnxn: Session establishment complete on server
> m9edd51-zookeeper.m9edd51/172.18.0.2:2181, sessionid = 0x156e2ba5ba50004,
> negotiated timeout = 4
> 2016-08-31 22:31:43,881 INFO  [main] inmemory.InMemoryTransactionService:
> Configuring TransactionService, address: 0.0.0.0, port: 15165, threads: 20,
> io threads: 2, max read buffer (bytes): 16777216
> 2016-08-31 22:31:43,882 INFO  [main] tephra.TransactionServiceMain:
> Starting TransactionServiceMain
> 2016-08-31 22:31:43,890 INFO  [main] zookeeper.LeaderElection: Start
> leader election on m9edd51-zookeeper.m9edd51/tx.service/leader with guid
> 9fd6dcfa-72eb-4705-a79f-aad1ec914945
> 2016-08-31 22:31:43,953 INFO  [leader-election-tx.service-leader] 
> metrics.DefaultMetricsCollector:
> Configured metrics report to emit every 60 seconds
> 2016-08-31 22:31:44,177 INFO  [ThriftRPCServer] tephra.TransactionManager:
> Starting transaction manager.
> 2016-08-31 22:31:44,179 INFO  [DefaultMetricsCollector STARTING] 
> metrics.DefaultMetricsCollector:
> Started metrics reporter
> 2016-08-31 22:31:44,309 WARN  [HDFSTransactionStateStorage STARTING]
> util.NativeCodeLoader: Unable to load native-hadoop library for your
> platform... using builtin-java classes where applicable
> 2016-08-31 22:31:45,041 INFO  [HDFSTransactionStateStorage STARTING]
> persist.HDFSTransactionStateStorage: Using snapshot dir
> /tmp/tephra/snapshots
> 2016-08-31 22:31:45,118 INFO  [ThriftRPCServer] 
> persist.HDFSTransactionStateStorage:
> Creating snapshot dir at /tmp/tephra/snapshots
> 2016-08-31 22:31:45,212 INFO  [ThriftRPCServer] 
> persist.HDFSTransactionStateStorage:
> No snapshot files found in /tmp/tephra/snapshots
> 2016-08-31 22:31:45,214 INFO  [ThriftRPCServer] tephra.TransactionManager:
> Starting periodic timed-out transaction cleanup every 10 seconds with
> default timeout of 60 seconds.
> 2016-08-31 22:31:45,215 INFO  [ThriftRPCServer] tephra.TransactionManager:
> Starting periodic snapshot thread, frequency = 300 seconds, location =
> /tmp/tephra/snapshots
> 2016-08-31 22:31:45,215 INFO  [ThriftRPCServer] tephra.TransactionManager:
> Starting periodic Metrics Emitter thread, frequency = 1
> 2016-08-31 22:31:45,242 INFO  [ThriftRPCServer] rpc.ThriftRPCServer:
> Starting RPC server for TTransactionServer
> 2016-08-31 22:31:45,255 INFO  [ThriftRPCServer] rpc.ThriftRPCServer:
> Running RPC server for TTransactionServer
> 2016-08-31 22:31:45,255 INFO  [ThriftRPCServer] server.
> TThreadedSelectorServerWithFix: Starting TThreadedSelectorServerWithFix
> 2016-08-31 22:31:45,359 INFO  [leader-election-tx.service-leader]
> distributed.TransactionService: Transaction Thrift Service started
> successfully on m9edd51-hmaster1.m9edd51/172.18.0.12:15165
> 2016-08-31 22:32:43,325 INFO  
> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
> zookeeper.ClientCnxn: Unable to read additional data from server sessionid
> 

Re: Tephra errors when trying to create a transactional table in Phoenix 4.8.0

[F21]

Hey Thomas,

Where are the Transaction Manager logs located? I have a 
/tmp/tephra-/tephra-service--m9edd51-hmaster1.m9edd51.log, which was 
where I got the logs from yesterday. There wasn't any information on 
whether the Transaction Manager crashed or not:


Here's the last half of the logs:
2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client 
environment:java.io.tmpdir=/tmp
2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client 
environment:java.compiler=
2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client 
environment:os.name=Linux
2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client 
environment:os.arch=amd64
2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client 
environment:os.version=4.4.0-36-generic
2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client 
environment:user.name=hadoop
2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client 
environment:user.home=/opt/hbase
2016-08-31 22:31:43,783 INFO  [main] zookeeper.ZooKeeper: Client 
environment:user.dir=/opt/hbase
2016-08-31 22:31:43,784 INFO  [main] zookeeper.ZooKeeper: Initiating 
client connection, connectString=m9edd51-zookeeper.m9edd51 
sessionTimeout=9 
watcher=org.apache.tephra.zookeeper.TephraZKClientService$5@45c7e403
2016-08-31 22:31:43,824 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] zookeeper.ClientCnxn: 
Opening socket connection to server 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181. Will not attempt to 
authenticate using SASL (unknown error)
2016-08-31 22:31:43,829 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] zookeeper.ClientCnxn: 
Socket connection established to 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181, initiating session
2016-08-31 22:31:43,835 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] zookeeper.ClientCnxn: 
Session establishment complete on server 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181, sessionid = 
0x156e2ba5ba50004, negotiated timeout = 4
2016-08-31 22:31:43,881 INFO  [main] 
inmemory.InMemoryTransactionService: Configuring TransactionService, 
address: 0.0.0.0, port: 15165, threads: 20, io threads: 2, max read 
buffer (bytes): 16777216
2016-08-31 22:31:43,882 INFO  [main] tephra.TransactionServiceMain: 
Starting TransactionServiceMain
2016-08-31 22:31:43,890 INFO  [main] zookeeper.LeaderElection: Start 
leader election on m9edd51-zookeeper.m9edd51/tx.service/leader with guid 
9fd6dcfa-72eb-4705-a79f-aad1ec914945
2016-08-31 22:31:43,953 INFO  [leader-election-tx.service-leader] 
metrics.DefaultMetricsCollector: Configured metrics report to emit every 
60 seconds
2016-08-31 22:31:44,177 INFO  [ThriftRPCServer] 
tephra.TransactionManager: Starting transaction manager.
2016-08-31 22:31:44,179 INFO  [DefaultMetricsCollector STARTING] 
metrics.DefaultMetricsCollector: Started metrics reporter
2016-08-31 22:31:44,309 WARN  [HDFSTransactionStateStorage STARTING] 
util.NativeCodeLoader: Unable to load native-hadoop library for your 
platform... using builtin-java classes where applicable
2016-08-31 22:31:45,041 INFO  [HDFSTransactionStateStorage STARTING] 
persist.HDFSTransactionStateStorage: Using snapshot dir 
/tmp/tephra/snapshots
2016-08-31 22:31:45,118 INFO  [ThriftRPCServer] 
persist.HDFSTransactionStateStorage: Creating snapshot dir at 
/tmp/tephra/snapshots
2016-08-31 22:31:45,212 INFO  [ThriftRPCServer] 
persist.HDFSTransactionStateStorage: No snapshot files found in 
/tmp/tephra/snapshots
2016-08-31 22:31:45,214 INFO  [ThriftRPCServer] 
tephra.TransactionManager: Starting periodic timed-out transaction 
cleanup every 10 seconds with default timeout of 60 seconds.
2016-08-31 22:31:45,215 INFO  [ThriftRPCServer] 
tephra.TransactionManager: Starting periodic snapshot thread, frequency 
= 300 seconds, location = /tmp/tephra/snapshots
2016-08-31 22:31:45,215 INFO  [ThriftRPCServer] 
tephra.TransactionManager: Starting periodic Metrics Emitter thread, 
frequency = 1
2016-08-31 22:31:45,242 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: 
Starting RPC server for TTransactionServer
2016-08-31 22:31:45,255 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: 
Running RPC server for TTransactionServer
2016-08-31 22:31:45,255 INFO  [ThriftRPCServer] 
server.TThreadedSelectorServerWithFix: Starting 
TThreadedSelectorServerWithFix
2016-08-31 22:31:45,359 INFO  [leader-election-tx.service-leader] 
distributed.TransactionService: Transaction Thrift Service started 
successfully on m9edd51-hmaster1.m9edd51/172.18.0.12:15165
2016-08-31 22:32:43,325 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] zookeeper.ClientCnxn: 
Unable to read additional data from server sessionid 0x156e2ba5ba50004, 
likely server has closed socket, closing socket connection and 
attempting reconnect
2016-08-31 22:32:43,427 INFO  [leader-election-tx.service-leader] 
zookeeper.LeaderElection: Disconnected from ZK: 
m9edd51-zookeeper.m9edd51 for /tx.service/leader
2016-08-31 22:32:43,427 INFO  [leader-election-tx.service-leader] 

Re: Tephra errors when trying to create a transactional table in Phoenix 4.8.0

[Thomas D'Silva]

Can you check the Transaction Manager logs and see if there are any error?
Also can you do a jps and see confirm the Transaction Manager is running ?

On Wed, Aug 31, 2016 at 2:12 AM, F21  wrote:

> Just another update. Even though the logs says that the transaction
> manager is not running, it is actually running.
>
> I confirmed this by checking the output of ps and connecting to the
> transaction manager:
>
> bash-4.3# ps
> PID   USER TIME   COMMAND
> 1 root   0:01 bash /run-hbase-phoenix.sh
>   137 hadoop 0:19 /usr/lib/jvm/java-1.8-openjdk/bin/java
> -Dproc_master -XX:OnOutOfMemoryError=kill -9 %p -XX:+UseConcMarkSweepGC
> -XX:PermSize=128m -XX:Ma
>   189 hadoop 0:08 /usr/lib/jvm/java-1.8-openjdk/bin/java
> -XX:+UseConcMarkSweepGC -cp /opt/hbase/bin/../lib/*:/opt/h
> base/bin/../conf/:/opt/hbase/phoenix-c
>   542 root   0:00 /bin/bash
>  9035 root   0:00 sleep 1
>  9036 root   0:00 ps
>
> bash-4.3# wget localhost:15165
> Connecting to localhost:15165 (127.0.0.1:15165)
> wget: error getting response: Connection reset by peer
>
>
> On 31/08/2016 3:25 PM, F21 wrote:
>
>> This only seems to be a problem when I have HBase running in fully
>> distributed mode (1 master, 1 regionserver and 1 zookeeper node in
>> different docker images).
>>
>> If I have HBase running in standalone mode with HBase and Phoenix and the
>> Query server in 1 docker image, it works correctly.
>>
>> On 31/08/2016 11:21 AM, F21 wrote:
>>
>>> I have HBase 1.2.2 and Phoenix 4.8.0 running on my HBase master running
>>> on alpine linux with OpenJDK JRE 8.
>>>
>>> This is my hbase-site.xml:
>>>
>>> 
>>> 
>>> 
>>>   
>>> hbase.rootdir
>>> hdfs://mycluster/hbase
>>>   
>>>   
>>> zookeeper.znode.parent
>>> /hbase
>>>   
>>>   
>>> hbase.cluster.distributed
>>> true
>>>   
>>>   
>>> hbase.zookeeper.quorum
>>> m9edd51-zookeeper.m9edd51
>>>   
>>>   
>>> data.tx.snapshot.dir
>>> /tmp/tephra/snapshots
>>>   
>>>   
>>> data.tx.timeout
>>> 60
>>>   
>>>   
>>> phoenix.transactions.enabled
>>> true
>>>   
>>> 
>>>
>>> I am able to start the master correctly. I am also able to create
>>> non-transactional table.
>>>
>>> However, if I create a transactional table, I get this error: ERROR
>>> [TTransactionServer-rpc-0] thrift.ProcessFunction: Internal error
>>> processing startShort
>>>
>>> This is what I see in the logs:
>>>
>>> 2016-08-31 01:08:33,560 WARN 
>>> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
>>> zookeeper.ClientCnxn: Session 0x156de22abec0004 for server null, unexpected
>>> error, closing socket connection and attempting reconnect
>>> java.net.ConnectException: Connection refused
>>> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>>> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl
>>> .java:717)
>>> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientC
>>> nxnSocketNIO.java:361)
>>> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.
>>> java:1081)
>>> 2016-08-31 01:08:33,616 INFO  [DefaultMetricsCollector STOPPING]
>>> metrics.DefaultMetricsCollector: Stopped metrics reporter
>>> 2016-08-31 01:08:33,623 INFO  [ThriftRPCServer]
>>> tephra.TransactionManager: Took 170.7 ms to stop
>>> 2016-08-31 01:08:33,623 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: RPC
>>> server for TTransactionServer stopped.
>>> 2016-08-31 01:08:34,776 INFO 
>>> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
>>> zookeeper.ClientCnxn: Opening socket connection to server
>>> m9edd51-zookeeper.m9edd51/172.18.0.2:2181. Will not attempt to
>>> authenticate using SASL (unknown error)
>>> 2016-08-31 01:08:34,777 INFO 
>>> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
>>> zookeeper.ClientCnxn: Socket connection established to
>>> m9edd51-zookeeper.m9edd51/172.18.0.2:2181, initiating session
>>> 2016-08-31 01:08:34,778 INFO 
>>> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
>>> zookeeper.ClientCnxn: Session establishment complete on server
>>> m9edd51-zookeeper.m9edd51/172.18.0.2:2181, sessionid =
>>> 0x156de22abec0004, negotiated timeout = 4
>>> 2016-08-31 01:08:34,783 INFO [leader-election-tx.service-leader]
>>> zookeeper.LeaderElection: Connected to ZK, running election:
>>> m9edd51-zookeeper.m9edd51 for /tx.service/leader
>>> 2016-08-31 01:08:34,815 INFO  [ThriftRPCServer] rpc.ThriftRPCServer:
>>> Starting RPC server for TTransactionServer
>>> 2016-08-31 01:08:34,815 INFO  [ThriftRPCServer] rpc.ThriftRPCServer:
>>> Running RPC server for TTransactionServer
>>> 2016-08-31 01:08:34,816 INFO  [ThriftRPCServer]
>>> server.TThreadedSelectorServerWithFix: Starting
>>> TThreadedSelectorServerWithFix
>>> 2016-08-31 01:08:34,822 INFO [leader-election-tx.service-leader]
>>> distributed.TransactionService: Transaction Thrift Service started
>>> successfully on m9edd51-hmaster1.m9edd51/172.18.0.12:15165
>>> 2016-08-31 01:10:42,830 ERROR [TTransactionServer-rpc-0]
>>> 

Re: Tephra errors when trying to create a transactional table in Phoenix 4.8.0

[F21]

Just another update. Even though the logs says that the transaction 
manager is not running, it is actually running.


I confirmed this by checking the output of ps and connecting to the 
transaction manager:


bash-4.3# ps
PID   USER TIME   COMMAND
1 root   0:01 bash /run-hbase-phoenix.sh
  137 hadoop 0:19 /usr/lib/jvm/java-1.8-openjdk/bin/java 
-Dproc_master -XX:OnOutOfMemoryError=kill -9 %p -XX:+UseConcMarkSweepGC 
-XX:PermSize=128m -XX:Ma
  189 hadoop 0:08 /usr/lib/jvm/java-1.8-openjdk/bin/java 
-XX:+UseConcMarkSweepGC -cp 
/opt/hbase/bin/../lib/*:/opt/hbase/bin/../conf/:/opt/hbase/phoenix-c

  542 root   0:00 /bin/bash
 9035 root   0:00 sleep 1
 9036 root   0:00 ps

bash-4.3# wget localhost:15165
Connecting to localhost:15165 (127.0.0.1:15165)
wget: error getting response: Connection reset by peer

On 31/08/2016 3:25 PM, F21 wrote:
This only seems to be a problem when I have HBase running in fully 
distributed mode (1 master, 1 regionserver and 1 zookeeper node in 
different docker images).


If I have HBase running in standalone mode with HBase and Phoenix and 
the Query server in 1 docker image, it works correctly.


On 31/08/2016 11:21 AM, F21 wrote:
I have HBase 1.2.2 and Phoenix 4.8.0 running on my HBase master 
running on alpine linux with OpenJDK JRE 8.


This is my hbase-site.xml:




  
hbase.rootdir
hdfs://mycluster/hbase
  
  
zookeeper.znode.parent
/hbase
  
  
hbase.cluster.distributed
true
  
  
hbase.zookeeper.quorum
m9edd51-zookeeper.m9edd51
  
  
data.tx.snapshot.dir
/tmp/tephra/snapshots
  
  
data.tx.timeout
60
  
  
phoenix.transactions.enabled
true
  


I am able to start the master correctly. I am also able to create 
non-transactional table.


However, if I create a transactional table, I get this error: ERROR 
[TTransactionServer-rpc-0] thrift.ProcessFunction: Internal error 
processing startShort


This is what I see in the logs:

2016-08-31 01:08:33,560 WARN 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] 
zookeeper.ClientCnxn: Session 0x156de22abec0004 for server null, 
unexpected error, closing socket connection and attempting reconnect

java.net.ConnectException: Connection refused
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
at 
sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
at 
org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
at 
org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
2016-08-31 01:08:33,616 INFO  [DefaultMetricsCollector STOPPING] 
metrics.DefaultMetricsCollector: Stopped metrics reporter
2016-08-31 01:08:33,623 INFO  [ThriftRPCServer] 
tephra.TransactionManager: Took 170.7 ms to stop
2016-08-31 01:08:33,623 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: 
RPC server for TTransactionServer stopped.
2016-08-31 01:08:34,776 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] 
zookeeper.ClientCnxn: Opening socket connection to server 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181. Will not attempt to 
authenticate using SASL (unknown error)
2016-08-31 01:08:34,777 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] 
zookeeper.ClientCnxn: Socket connection established to 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181, initiating session
2016-08-31 01:08:34,778 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] 
zookeeper.ClientCnxn: Session establishment complete on server 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181, sessionid = 
0x156de22abec0004, negotiated timeout = 4
2016-08-31 01:08:34,783 INFO [leader-election-tx.service-leader] 
zookeeper.LeaderElection: Connected to ZK, running election: 
m9edd51-zookeeper.m9edd51 for /tx.service/leader
2016-08-31 01:08:34,815 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: 
Starting RPC server for TTransactionServer
2016-08-31 01:08:34,815 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: 
Running RPC server for TTransactionServer
2016-08-31 01:08:34,816 INFO  [ThriftRPCServer] 
server.TThreadedSelectorServerWithFix: Starting 
TThreadedSelectorServerWithFix
2016-08-31 01:08:34,822 INFO [leader-election-tx.service-leader] 
distributed.TransactionService: Transaction Thrift Service started 
successfully on m9edd51-hmaster1.m9edd51/172.18.0.12:15165
2016-08-31 01:10:42,830 ERROR [TTransactionServer-rpc-0] 
thrift.ProcessFunction: Internal error processing startShort

java.lang.IllegalStateException: Transaction Manager is not running.
at 
com.google.common.base.Preconditions.checkState(Preconditions.java:149)
at 
org.apache.tephra.TransactionManager.ensureAvailable(TransactionManager.java:709)
at 
org.apache.tephra.TransactionManager.startTx(TransactionManager.java:768)
at 
org.apache.tephra.TransactionManager.startShort(TransactionManager.java:728)
at 
org.apache.tephra.TransactionManager.startShort(TransactionManager.java:716)
at 

Re: Tephra errors when trying to create a transactional table in Phoenix 4.8.0

[F21]

This only seems to be a problem when I have HBase running in fully 
distributed mode (1 master, 1 regionserver and 1 zookeeper node in 
different docker images).


If I have HBase running in standalone mode with HBase and Phoenix and 
the Query server in 1 docker image, it works correctly.


On 31/08/2016 11:21 AM, F21 wrote:
I have HBase 1.2.2 and Phoenix 4.8.0 running on my HBase master 
running on alpine linux with OpenJDK JRE 8.


This is my hbase-site.xml:




  
hbase.rootdir
hdfs://mycluster/hbase
  
  
zookeeper.znode.parent
/hbase
  
  
hbase.cluster.distributed
true
  
  
hbase.zookeeper.quorum
m9edd51-zookeeper.m9edd51
  
  
data.tx.snapshot.dir
/tmp/tephra/snapshots
  
  
data.tx.timeout
60
  
  
phoenix.transactions.enabled
true
  


I am able to start the master correctly. I am also able to create 
non-transactional table.


However, if I create a transactional table, I get this error: ERROR 
[TTransactionServer-rpc-0] thrift.ProcessFunction: Internal error 
processing startShort


This is what I see in the logs:

2016-08-31 01:08:33,560 WARN 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] 
zookeeper.ClientCnxn: Session 0x156de22abec0004 for server null, 
unexpected error, closing socket connection and attempting reconnect

java.net.ConnectException: Connection refused
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
at 
sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
at 
org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
at 
org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
2016-08-31 01:08:33,616 INFO  [DefaultMetricsCollector STOPPING] 
metrics.DefaultMetricsCollector: Stopped metrics reporter
2016-08-31 01:08:33,623 INFO  [ThriftRPCServer] 
tephra.TransactionManager: Took 170.7 ms to stop
2016-08-31 01:08:33,623 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: 
RPC server for TTransactionServer stopped.
2016-08-31 01:08:34,776 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] 
zookeeper.ClientCnxn: Opening socket connection to server 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181. Will not attempt to 
authenticate using SASL (unknown error)
2016-08-31 01:08:34,777 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] 
zookeeper.ClientCnxn: Socket connection established to 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181, initiating session
2016-08-31 01:08:34,778 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] 
zookeeper.ClientCnxn: Session establishment complete on server 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181, sessionid = 
0x156de22abec0004, negotiated timeout = 4
2016-08-31 01:08:34,783 INFO  [leader-election-tx.service-leader] 
zookeeper.LeaderElection: Connected to ZK, running election: 
m9edd51-zookeeper.m9edd51 for /tx.service/leader
2016-08-31 01:08:34,815 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: 
Starting RPC server for TTransactionServer
2016-08-31 01:08:34,815 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: 
Running RPC server for TTransactionServer
2016-08-31 01:08:34,816 INFO  [ThriftRPCServer] 
server.TThreadedSelectorServerWithFix: Starting 
TThreadedSelectorServerWithFix
2016-08-31 01:08:34,822 INFO  [leader-election-tx.service-leader] 
distributed.TransactionService: Transaction Thrift Service started 
successfully on m9edd51-hmaster1.m9edd51/172.18.0.12:15165
2016-08-31 01:10:42,830 ERROR [TTransactionServer-rpc-0] 
thrift.ProcessFunction: Internal error processing startShort

java.lang.IllegalStateException: Transaction Manager is not running.
at 
com.google.common.base.Preconditions.checkState(Preconditions.java:149)
at 
org.apache.tephra.TransactionManager.ensureAvailable(TransactionManager.java:709)
at 
org.apache.tephra.TransactionManager.startTx(TransactionManager.java:768)
at 
org.apache.tephra.TransactionManager.startShort(TransactionManager.java:728)
at 
org.apache.tephra.TransactionManager.startShort(TransactionManager.java:716)
at 
org.apache.tephra.distributed.TransactionServiceThriftHandler.startShort(TransactionServiceThriftHandler.java:71)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:498)
at 
org.apache.tephra.rpc.ThriftRPCServer$1.invoke(ThriftRPCServer.java:261)

at com.sun.proxy.$Proxy17.startShort(Unknown Source)
at 
org.apache.tephra.distributed.thrift.TTransactionServer$Processor$startShort.getResult(TTransactionServer.java:974)
at 
org.apache.tephra.distributed.thrift.TTransactionServer$Processor$startShort.getResult(TTransactionServer.java:959)
at 

Tephra errors when trying to create a transactional table in Phoenix 4.8.0

[F21]

I have HBase 1.2.2 and Phoenix 4.8.0 running on my HBase master running 
on alpine linux with OpenJDK JRE 8.


This is my hbase-site.xml:




  
hbase.rootdir
hdfs://mycluster/hbase
  
  
zookeeper.znode.parent
/hbase
  
  
hbase.cluster.distributed
true
  
  
hbase.zookeeper.quorum
m9edd51-zookeeper.m9edd51
  
  
data.tx.snapshot.dir
/tmp/tephra/snapshots
  
  
data.tx.timeout
60
  
  
phoenix.transactions.enabled
true
  


I am able to start the master correctly. I am also able to create 
non-transactional table.


However, if I create a transactional table, I get this error: ERROR 
[TTransactionServer-rpc-0] thrift.ProcessFunction: Internal error 
processing startShort


This is what I see in the logs:

2016-08-31 01:08:33,560 WARN 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] zookeeper.ClientCnxn: 
Session 0x156de22abec0004 for server null, unexpected error, closing 
socket connection and attempting reconnect

java.net.ConnectException: Connection refused
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
at 
sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
at 
org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
at 
org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
2016-08-31 01:08:33,616 INFO  [DefaultMetricsCollector STOPPING] 
metrics.DefaultMetricsCollector: Stopped metrics reporter
2016-08-31 01:08:33,623 INFO  [ThriftRPCServer] 
tephra.TransactionManager: Took 170.7 ms to stop
2016-08-31 01:08:33,623 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: RPC 
server for TTransactionServer stopped.
2016-08-31 01:08:34,776 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] zookeeper.ClientCnxn: 
Opening socket connection to server 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181. Will not attempt to 
authenticate using SASL (unknown error)
2016-08-31 01:08:34,777 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] zookeeper.ClientCnxn: 
Socket connection established to 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181, initiating session
2016-08-31 01:08:34,778 INFO 
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] zookeeper.ClientCnxn: 
Session establishment complete on server 
m9edd51-zookeeper.m9edd51/172.18.0.2:2181, sessionid = 
0x156de22abec0004, negotiated timeout = 4
2016-08-31 01:08:34,783 INFO  [leader-election-tx.service-leader] 
zookeeper.LeaderElection: Connected to ZK, running election: 
m9edd51-zookeeper.m9edd51 for /tx.service/leader
2016-08-31 01:08:34,815 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: 
Starting RPC server for TTransactionServer
2016-08-31 01:08:34,815 INFO  [ThriftRPCServer] rpc.ThriftRPCServer: 
Running RPC server for TTransactionServer
2016-08-31 01:08:34,816 INFO  [ThriftRPCServer] 
server.TThreadedSelectorServerWithFix: Starting 
TThreadedSelectorServerWithFix
2016-08-31 01:08:34,822 INFO  [leader-election-tx.service-leader] 
distributed.TransactionService: Transaction Thrift Service started 
successfully on m9edd51-hmaster1.m9edd51/172.18.0.12:15165
2016-08-31 01:10:42,830 ERROR [TTransactionServer-rpc-0] 
thrift.ProcessFunction: Internal error processing startShort

java.lang.IllegalStateException: Transaction Manager is not running.
at 
com.google.common.base.Preconditions.checkState(Preconditions.java:149)
at 
org.apache.tephra.TransactionManager.ensureAvailable(TransactionManager.java:709)
at 
org.apache.tephra.TransactionManager.startTx(TransactionManager.java:768)
at 
org.apache.tephra.TransactionManager.startShort(TransactionManager.java:728)
at 
org.apache.tephra.TransactionManager.startShort(TransactionManager.java:716)
at 
org.apache.tephra.distributed.TransactionServiceThriftHandler.startShort(TransactionServiceThriftHandler.java:71)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:498)
at 
org.apache.tephra.rpc.ThriftRPCServer$1.invoke(ThriftRPCServer.java:261)

at com.sun.proxy.$Proxy17.startShort(Unknown Source)
at 
org.apache.tephra.distributed.thrift.TTransactionServer$Processor$startShort.getResult(TTransactionServer.java:974)
at 
org.apache.tephra.distributed.thrift.TTransactionServer$Processor$startShort.getResult(TTransactionServer.java:959)
at 
org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)

at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
at 
org.apache.thrift.server.AbstractNonblockingServer$FrameBuffer.invoke(AbstractNonblockingServer.java:478)

at org.apache.thrift.server.Invocation.run(Invocation.java:18)
at