You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@phoenix.apache.org by F21 <f2...@gmail.com> on 2016/08/31 01:21:57 UTC
Tephra errors when trying to create a transactional table in Phoenix
4.8.0
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:
<?xml version="1.0"?>
<?xml-stylesheet type="text/xsl" href="configuration.xsl"?>
<configuration>
<property>
<name>hbase.rootdir</name>
<value>hdfs://mycluster/hbase</value>
</property>
<property>
<name>zookeeper.znode.parent</name>
<value>/hbase</value>
</property>
<property>
<name>hbase.cluster.distributed</name>
<value>true</value>
</property>
<property>
<name>hbase.zookeeper.quorum</name>
<value>m9edd51-zookeeper.m9edd51</value>
</property>
<property>
<name>data.tx.snapshot.dir</name>
<value>/tmp/tephra/snapshots</value>
</property>
<property>
<name>data.tx.timeout</name>
<value>60</value>
</property>
<property>
<name>phoenix.transactions.enabled</name>
<value>true</value>
</property>
</configuration>
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 = 40000
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
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2016-08-31 01:10:42,936 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
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
This seems very similar to PHOENIX-2504
(https://issues.apache.org/jira/browse/PHOENIX-2504), but that appears
to be fixed in 4.8.0?
Any ideas why this might be happening?
Cheers,
Francis
Re: Tephra errors when trying to create a transactional table in
Phoenix 4.8.0
Posted by F21 <f2...@gmail.com>.
Hey James,
I have created PHOENIX-3235[1] with the full log.
Cheers,
Francis
[1] https://issues.apache.org/jira/browse/PHOENIX-3235
On 1/09/2016 10:40 AM, James Taylor wrote:
> Hi Francis,
> Is thatthe 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 <f21.groups@gmail.com
> <ma...@gmail.com>> 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=<NA>
> 2016-08-31 22:31:43,783 INFO [main] zookeeper.ZooKeeper: Client
> environment:os.name <http://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 <http://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=90000
> 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
> <http://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
> <http://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
> <http://172.18.0.2:2181>, sessionid = 0x156e2ba5ba50004,
> negotiated timeout = 40000
> 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 = 10000
> 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
> <http://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]
> zookeeper.LeaderElection: Stepping down as leader due to
> disconnect: m9edd51-zookeeper.m9edd51 for /tx.service/leader
> 2016-08-31 22:32:43,428 INFO [leader-election-tx.service-leader]
> rpc.ThriftRPCServer: Request to stop RPC server for TTransactionServer
> 2016-08-31 22:32:43,430 INFO [ThriftRPCServer]
> rpc.ThriftRPCServer: Done running RPC server for TTransactionServer
> 2016-08-31 22:32:43,431 INFO [ThriftRPCServer]
> tephra.TransactionManager: Shutting down gracefully...
> 2016-08-31 22:32:43,432 INFO [tx-clean-timeout]
> tephra.TransactionManager: Exiting thread tx-clean-timeout
> 2016-08-31 22:32:43,432 INFO [tx-metrics]
> tephra.TransactionManager: Exiting thread tx-metrics
> 2016-08-31 22:32:43,432 INFO [tx-snapshot]
> tephra.TransactionManager: Writing final snapshot prior to shutdown
> 2016-08-31 22:32:43,510 INFO [tx-snapshot]
> tephra.TransactionManager: Exiting thread tx-snapshot
> 2016-08-31 22:32:43,613 INFO [DefaultMetricsCollector STOPPING]
> metrics.DefaultMetricsCollector: Stopped metrics reporter
> 2016-08-31 22:32:43,614 INFO [ThriftRPCServer]
> tephra.TransactionManager: Took 181.4 ms to stop
> 2016-08-31 22:32:43,614 INFO [ThriftRPCServer]
> rpc.ThriftRPCServer: RPC server for TTransactionServer stopped.
> 2016-08-31 22:32:44,130 INFO
> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> m9edd51-zookeeper.m9edd51/fe80:0:0:0:0:242:ac12:2:2181. Will not
> attempt to authenticate using SASL (unknown error)
> 2016-08-31 22:32:44,130 WARN
> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
> zookeeper.ClientCnxn: Session 0x156e2ba5ba50004 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 22:32:45,452 INFO
> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> m9edd51-zookeeper.m9edd51/172.18.0.2:2181
> <http://172.18.0.2:2181>. Will not attempt to authenticate using
> SASL (unknown error)
> 2016-08-31 22:32:45,453 INFO
> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
> zookeeper.ClientCnxn: Socket connection established to
> m9edd51-zookeeper.m9edd51/172.18.0.2:2181
> <http://172.18.0.2:2181>, initiating session
> 2016-08-31 22:32:45,453 INFO
> [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
> zookeeper.ClientCnxn: Session establishment complete on server
> m9edd51-zookeeper.m9edd51/172.18.0.2:2181
> <http://172.18.0.2:2181>, sessionid = 0x156e2ba5ba50004,
> negotiated timeout = 40000
> 2016-08-31 22:32:45,458 INFO [leader-election-tx.service-leader]
> zookeeper.LeaderElection: Connected to ZK, running election:
> m9edd51-zookeeper.m9edd51 for /tx.service/leader
> 2016-08-31 22:32:45,529 INFO [ThriftRPCServer]
> rpc.ThriftRPCServer: Starting RPC server for TTransactionServer
> 2016-08-31 22:32:45,530 INFO [ThriftRPCServer]
> rpc.ThriftRPCServer: Running RPC server for TTransactionServer
> 2016-08-31 22:32:45,530 INFO [ThriftRPCServer]
> server.TThreadedSelectorServerWithFix: Starting
> TThreadedSelectorServerWithFix
> 2016-08-31 22:32:45,540 INFO [leader-election-tx.service-leader]
> distributed.TransactionService: Transaction Thrift Service started
> successfully on m9edd51-hmaster1.m9edd51/172.18.0.12:15165
> <http://172.18.0.12:15165>
> 2016-08-31 22:35:32,201 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
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> 2016-08-31 22:35:32,311 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
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> 2016-08-31 22:35:32,717 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
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> 2016-08-31 22:35:34,321 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
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
>
> If I run jps, I get the following:
> bash-4.3# jps
> 771 Jps
> 138 HMaster
> 190 TransactionServiceMain
>
> Cheers,
> Francis
>
> On 1/09/2016 4:01 AM, Thomas D'Silva wrote:
>> 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 <f21.groups@gmail.com
>> <javascript:_e(%7B%7D,'cvml','f21.groups@gmail.com');>> 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/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
>> <http://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:
>>
>> <?xml version="1.0"?>
>> <?xml-stylesheet type="text/xsl"
>> href="configuration.xsl"?>
>> <configuration>
>> <property>
>> <name>hbase.rootdir</name>
>> <value>hdfs://mycluster/hbase</value>
>> </property>
>> <property>
>> <name>zookeeper.znode.parent</name>
>> <value>/hbase</value>
>> </property>
>> <property>
>> <name>hbase.cluster.distributed</name>
>> <value>true</value>
>> </property>
>> <property>
>> <name>hbase.zookeeper.quorum</name>
>> <value>m9edd51-zookeeper.m9edd51</value>
>> </property>
>> <property>
>> <name>data.tx.snapshot.dir</name>
>> <value>/tmp/tephra/snapshots</value>
>> </property>
>> <property>
>> <name>data.tx.timeout</name>
>> <value>60</value>
>> </property>
>> <property>
>> <name>phoenix.transactions.enabled</name>
>> <value>true</value>
>> </property>
>> </configuration>
>>
>> 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
>> <http://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
>> <http://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
>> <http://172.18.0.2:2181>, sessionid =
>> 0x156de22abec0004, negotiated timeout = 40000
>> 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
>> <http://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
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>> at java.lang.Thread.run(Thread.java:745)
>> 2016-08-31 01:10:42,936 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
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>> at java.lang.Thread.run(Thread.java:745)
>>
>> This seems very similar to PHOENIX-2504
>> (https://issues.apache.org/jira/browse/PHOENIX-2504
>> <https://issues.apache.org/jira/browse/PHOENIX-2504>),
>> but that appears to be fixed in 4.8.0?
>>
>> Any ideas why this might be happening?
>>
>> Cheers,
>>
>> Francis
>>
>>
>>
>>
>>
>
Re: Tephra errors when trying to create a transactional table in
Phoenix 4.8.0
Posted by James Taylor <ja...@apache.org>.
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 <f2...@gmail.com> 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=<NA>
> 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=90000 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 = 40000
> 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 = 10000
> 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]
> zookeeper.LeaderElection: Stepping down as leader due to disconnect:
> m9edd51-zookeeper.m9edd51 for /tx.service/leader
> 2016-08-31 22:32:43,428 INFO [leader-election-tx.service-leader]
> rpc.ThriftRPCServer: Request to stop RPC server for TTransactionServer
> 2016-08-31 22:32:43,430 INFO [ThriftRPCServer] rpc.ThriftRPCServer: Done
> running RPC server for TTransactionServer
> 2016-08-31 22:32:43,431 INFO [ThriftRPCServer] tephra.TransactionManager:
> Shutting down gracefully...
> 2016-08-31 22:32:43,432 INFO [tx-clean-timeout]
> tephra.TransactionManager: Exiting thread tx-clean-timeout
> 2016-08-31 22:32:43,432 INFO [tx-metrics] tephra.TransactionManager:
> Exiting thread tx-metrics
> 2016-08-31 22:32:43,432 INFO [tx-snapshot] tephra.TransactionManager:
> Writing final snapshot prior to shutdown
> 2016-08-31 22:32:43,510 INFO [tx-snapshot] tephra.TransactionManager:
> Exiting thread tx-snapshot
> 2016-08-31 22:32:43,613 INFO [DefaultMetricsCollector STOPPING] metrics.DefaultMetricsCollector:
> Stopped metrics reporter
> 2016-08-31 22:32:43,614 INFO [ThriftRPCServer] tephra.TransactionManager:
> Took 181.4 ms to stop
> 2016-08-31 22:32:43,614 INFO [ThriftRPCServer] rpc.ThriftRPCServer: RPC
> server for TTransactionServer stopped.
> 2016-08-31 22:32:44,130 INFO [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
> zookeeper.ClientCnxn: Opening socket connection to server
> m9edd51-zookeeper.m9edd51/fe80:0:0:0:0:242:ac12:2:2181. Will not attempt
> to authenticate using SASL (unknown error)
> 2016-08-31 22:32:44,130 WARN [main-SendThread(m9edd51-zookeeper.m9edd51:2181)]
> zookeeper.ClientCnxn: Session 0x156e2ba5ba50004 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 22:32:45,452 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:32:45,453 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:32:45,453 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 = 40000
> 2016-08-31 22:32:45,458 INFO [leader-election-tx.service-leader]
> zookeeper.LeaderElection: Connected to ZK, running election:
> m9edd51-zookeeper.m9edd51 for /tx.service/leader
> 2016-08-31 22:32:45,529 INFO [ThriftRPCServer] rpc.ThriftRPCServer:
> Starting RPC server for TTransactionServer
> 2016-08-31 22:32:45,530 INFO [ThriftRPCServer] rpc.ThriftRPCServer:
> Running RPC server for TTransactionServer
> 2016-08-31 22:32:45,530 INFO [ThriftRPCServer] server.
> TThreadedSelectorServerWithFix: Starting TThreadedSelectorServerWithFix
> 2016-08-31 22:32:45,540 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:35:32,201 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.TransactionServiceThriftHandle
> r.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 java.util.concurrent.ThreadPoolExecutor.runWorker(
> ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> 2016-08-31 22:35:32,311 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.TransactionServiceThriftHandle
> r.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 java.util.concurrent.ThreadPoolExecutor.runWorker(
> ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> 2016-08-31 22:35:32,717 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.TransactionServiceThriftHandle
> r.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 java.util.concurrent.ThreadPoolExecutor.runWorker(
> ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> 2016-08-31 22:35:34,321 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.TransactionServiceThriftHandle
> r.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 java.util.concurrent.ThreadPoolExecutor.runWorker(
> ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
>
> If I run jps, I get the following:
> bash-4.3# jps
> 771 Jps
> 138 HMaster
> 190 TransactionServiceMain
>
> Cheers,
> Francis
>
> On 1/09/2016 4:01 AM, Thomas D'Silva wrote:
>
> 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 <f21.groups@gmail.com
> <javascript:_e(%7B%7D,'cvml','f21.groups@gmail.com');>> 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:
>>>>
>>>> <?xml version="1.0"?>
>>>> <?xml-stylesheet type="text/xsl" href="configuration.xsl"?>
>>>> <configuration>
>>>> <property>
>>>> <name>hbase.rootdir</name>
>>>> <value>hdfs://mycluster/hbase</value>
>>>> </property>
>>>> <property>
>>>> <name>zookeeper.znode.parent</name>
>>>> <value>/hbase</value>
>>>> </property>
>>>> <property>
>>>> <name>hbase.cluster.distributed</name>
>>>> <value>true</value>
>>>> </property>
>>>> <property>
>>>> <name>hbase.zookeeper.quorum</name>
>>>> <value>m9edd51-zookeeper.m9edd51</value>
>>>> </property>
>>>> <property>
>>>> <name>data.tx.snapshot.dir</name>
>>>> <value>/tmp/tephra/snapshots</value>
>>>> </property>
>>>> <property>
>>>> <name>data.tx.timeout</name>
>>>> <value>60</value>
>>>> </property>
>>>> <property>
>>>> <name>phoenix.transactions.enabled</name>
>>>> <value>true</value>
>>>> </property>
>>>> </configuration>
>>>>
>>>> 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.ja
>>>> va: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 = 40000
>>>> 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(Precondition
>>>> s.java:149)
>>>> at org.apache.tephra.TransactionManager.ensureAvailable(Transac
>>>> tionManager.java:709)
>>>> at org.apache.tephra.TransactionManager.startTx(TransactionMana
>>>> ger.java:768)
>>>> at org.apache.tephra.TransactionManager.startShort(TransactionM
>>>> anager.java:728)
>>>> at org.apache.tephra.TransactionManager.startShort(TransactionM
>>>> anager.java:716)
>>>> at org.apache.tephra.distributed.TransactionServiceThriftHandle
>>>> r.startShort(TransactionServiceThriftHandler.java:71)
>>>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>>> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAcce
>>>> ssorImpl.java:62)
>>>> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe
>>>> thodAccessorImpl.java:43)
>>>> at java.lang.reflect.Method.invoke(Method.java:498)
>>>> at org.apache.tephra.rpc.ThriftRPCServer$1.invoke(ThriftRPCServ
>>>> er.java:261)
>>>> at com.sun.proxy.$Proxy17.startShort(Unknown Source)
>>>> at org.apache.tephra.distributed.thrift.TTransactionServer$Proc
>>>> essor$startShort.getResult(TTransactionServer.java:974)
>>>> at org.apache.tephra.distributed.thrift.TTransactionServer$Proc
>>>> essor$startShort.getResult(TTransactionServer.java:959)
>>>> at org.apache.thrift.ProcessFunction.process(ProcessFunction.ja
>>>> va:39)
>>>> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java
>>>> :39)
>>>> at org.apache.thrift.server.AbstractNonblockingServer$FrameBuff
>>>> er.invoke(AbstractNonblockingServer.java:478)
>>>> at org.apache.thrift.server.Invocation.run(Invocation.java:18)
>>>> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>>> Executor.java:1142)
>>>> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>>> lExecutor.java:617)
>>>> at java.lang.Thread.run(Thread.java:745)
>>>> 2016-08-31 01:10:42,936 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(Precondition
>>>> s.java:149)
>>>> at org.apache.tephra.TransactionManager.ensureAvailable(Transac
>>>> tionManager.java:709)
>>>> at org.apache.tephra.TransactionManager.startTx(TransactionMana
>>>> ger.java:768)
>>>> at org.apache.tephra.TransactionManager.startShort(TransactionM
>>>> anager.java:728)
>>>> at org.apache.tephra.TransactionManager.startShort(TransactionM
>>>> anager.java:716)
>>>> at org.apache.tephra.distributed.TransactionServiceThriftHandle
>>>> r.startShort(TransactionServiceThriftHandler.java:71)
>>>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>>> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAcce
>>>> ssorImpl.java:62)
>>>> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe
>>>> thodAccessorImpl.java:43)
>>>> at java.lang.reflect.Method.invoke(Method.java:498)
>>>> at org.apache.tephra.rpc.ThriftRPCServer$1.invoke(ThriftRPCServ
>>>> er.java:261)
>>>> at com.sun.proxy.$Proxy17.startShort(Unknown Source)
>>>> at org.apache.tephra.distributed.thrift.TTransactionServer$Proc
>>>> essor$startShort.getResult(TTransactionServer.java:974)
>>>> at org.apache.tephra.distributed.thrift.TTransactionServer$Proc
>>>> essor$startShort.getResult(TTransactionServer.java:959)
>>>> at org.apache.thrift.ProcessFunction.process(ProcessFunction.ja
>>>> va:39)
>>>> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java
>>>> :39)
>>>> at org.apache.thrift.server.AbstractNonblockingServer$FrameBuff
>>>> er.invoke(AbstractNonblockingServer.java:478)
>>>> at org.apache.thrift.server.Invocation.run(Invocation.java:18)
>>>> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>>> Executor.java:1142)
>>>> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>>> lExecutor.java:617)
>>>> at java.lang.Thread.run(Thread.java:745)
>>>>
>>>> This seems very similar to PHOENIX-2504 (https://issues.apache.org/jir
>>>> a/browse/PHOENIX-2504), but that appears to be fixed in 4.8.0?
>>>>
>>>> Any ideas why this might be happening?
>>>>
>>>> Cheers,
>>>>
>>>> Francis
>>>>
>>>>
>>>>
>>>
>>
>
>
Re: Tephra errors when trying to create a transactional table in
Phoenix 4.8.0
Posted by F21 <f2...@gmail.com>.
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=<NA>
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=90000
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 = 40000
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 = 10000
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]
zookeeper.LeaderElection: Stepping down as leader due to disconnect:
m9edd51-zookeeper.m9edd51 for /tx.service/leader
2016-08-31 22:32:43,428 INFO [leader-election-tx.service-leader]
rpc.ThriftRPCServer: Request to stop RPC server for TTransactionServer
2016-08-31 22:32:43,430 INFO [ThriftRPCServer] rpc.ThriftRPCServer:
Done running RPC server for TTransactionServer
2016-08-31 22:32:43,431 INFO [ThriftRPCServer]
tephra.TransactionManager: Shutting down gracefully...
2016-08-31 22:32:43,432 INFO [tx-clean-timeout]
tephra.TransactionManager: Exiting thread tx-clean-timeout
2016-08-31 22:32:43,432 INFO [tx-metrics] tephra.TransactionManager:
Exiting thread tx-metrics
2016-08-31 22:32:43,432 INFO [tx-snapshot] tephra.TransactionManager:
Writing final snapshot prior to shutdown
2016-08-31 22:32:43,510 INFO [tx-snapshot] tephra.TransactionManager:
Exiting thread tx-snapshot
2016-08-31 22:32:43,613 INFO [DefaultMetricsCollector STOPPING]
metrics.DefaultMetricsCollector: Stopped metrics reporter
2016-08-31 22:32:43,614 INFO [ThriftRPCServer]
tephra.TransactionManager: Took 181.4 ms to stop
2016-08-31 22:32:43,614 INFO [ThriftRPCServer] rpc.ThriftRPCServer: RPC
server for TTransactionServer stopped.
2016-08-31 22:32:44,130 INFO
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] zookeeper.ClientCnxn:
Opening socket connection to server
m9edd51-zookeeper.m9edd51/fe80:0:0:0:0:242:ac12:2:2181. Will not attempt
to authenticate using SASL (unknown error)
2016-08-31 22:32:44,130 WARN
[main-SendThread(m9edd51-zookeeper.m9edd51:2181)] zookeeper.ClientCnxn:
Session 0x156e2ba5ba50004 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 22:32:45,452 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:32:45,453 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:32:45,453 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 = 40000
2016-08-31 22:32:45,458 INFO [leader-election-tx.service-leader]
zookeeper.LeaderElection: Connected to ZK, running election:
m9edd51-zookeeper.m9edd51 for /tx.service/leader
2016-08-31 22:32:45,529 INFO [ThriftRPCServer] rpc.ThriftRPCServer:
Starting RPC server for TTransactionServer
2016-08-31 22:32:45,530 INFO [ThriftRPCServer] rpc.ThriftRPCServer:
Running RPC server for TTransactionServer
2016-08-31 22:32:45,530 INFO [ThriftRPCServer]
server.TThreadedSelectorServerWithFix: Starting
TThreadedSelectorServerWithFix
2016-08-31 22:32:45,540 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:35:32,201 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
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2016-08-31 22:35:32,311 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
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2016-08-31 22:35:32,717 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
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2016-08-31 22:35:34,321 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
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
If I run jps, I get the following:
bash-4.3# jps
771 Jps
138 HMaster
190 TransactionServiceMain
Cheers,
Francis
On 1/09/2016 4:01 AM, Thomas D'Silva wrote:
> 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 <f21.groups@gmail.com
> <ma...@gmail.com>> 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/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
> <http://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:
>
> <?xml version="1.0"?>
> <?xml-stylesheet type="text/xsl" href="configuration.xsl"?>
> <configuration>
> <property>
> <name>hbase.rootdir</name>
> <value>hdfs://mycluster/hbase</value>
> </property>
> <property>
> <name>zookeeper.znode.parent</name>
> <value>/hbase</value>
> </property>
> <property>
> <name>hbase.cluster.distributed</name>
> <value>true</value>
> </property>
> <property>
> <name>hbase.zookeeper.quorum</name>
> <value>m9edd51-zookeeper.m9edd51</value>
> </property>
> <property>
> <name>data.tx.snapshot.dir</name>
> <value>/tmp/tephra/snapshots</value>
> </property>
> <property>
> <name>data.tx.timeout</name>
> <value>60</value>
> </property>
> <property>
> <name>phoenix.transactions.enabled</name>
> <value>true</value>
> </property>
> </configuration>
>
> 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
> <http://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
> <http://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
> <http://172.18.0.2:2181>, sessionid = 0x156de22abec0004,
> negotiated timeout = 40000
> 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
> <http://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
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> 2016-08-31 01:10:42,936 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
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
>
> This seems very similar to PHOENIX-2504
> (https://issues.apache.org/jira/browse/PHOENIX-2504
> <https://issues.apache.org/jira/browse/PHOENIX-2504>), but
> that appears to be fixed in 4.8.0?
>
> Any ideas why this might be happening?
>
> Cheers,
>
> Francis
>
>
>
>
>
Re: Tephra errors when trying to create a transactional table in
Phoenix 4.8.0
Posted by Thomas D'Silva <td...@salesforce.com>.
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 <f2...@gmail.com> 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:
>>>
>>> <?xml version="1.0"?>
>>> <?xml-stylesheet type="text/xsl" href="configuration.xsl"?>
>>> <configuration>
>>> <property>
>>> <name>hbase.rootdir</name>
>>> <value>hdfs://mycluster/hbase</value>
>>> </property>
>>> <property>
>>> <name>zookeeper.znode.parent</name>
>>> <value>/hbase</value>
>>> </property>
>>> <property>
>>> <name>hbase.cluster.distributed</name>
>>> <value>true</value>
>>> </property>
>>> <property>
>>> <name>hbase.zookeeper.quorum</name>
>>> <value>m9edd51-zookeeper.m9edd51</value>
>>> </property>
>>> <property>
>>> <name>data.tx.snapshot.dir</name>
>>> <value>/tmp/tephra/snapshots</value>
>>> </property>
>>> <property>
>>> <name>data.tx.timeout</name>
>>> <value>60</value>
>>> </property>
>>> <property>
>>> <name>phoenix.transactions.enabled</name>
>>> <value>true</value>
>>> </property>
>>> </configuration>
>>>
>>> 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 = 40000
>>> 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(Precondition
>>> s.java:149)
>>> at org.apache.tephra.TransactionManager.ensureAvailable(Transac
>>> tionManager.java:709)
>>> at org.apache.tephra.TransactionManager.startTx(TransactionMana
>>> ger.java:768)
>>> at org.apache.tephra.TransactionManager.startShort(TransactionM
>>> anager.java:728)
>>> at org.apache.tephra.TransactionManager.startShort(TransactionM
>>> anager.java:716)
>>> at org.apache.tephra.distributed.TransactionServiceThriftHandle
>>> r.startShort(TransactionServiceThriftHandler.java:71)
>>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAcce
>>> ssorImpl.java:62)
>>> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe
>>> thodAccessorImpl.java:43)
>>> at java.lang.reflect.Method.invoke(Method.java:498)
>>> at org.apache.tephra.rpc.ThriftRPCServer$1.invoke(ThriftRPCServ
>>> er.java:261)
>>> at com.sun.proxy.$Proxy17.startShort(Unknown Source)
>>> at org.apache.tephra.distributed.thrift.TTransactionServer$Proc
>>> essor$startShort.getResult(TTransactionServer.java:974)
>>> at org.apache.tephra.distributed.thrift.TTransactionServer$Proc
>>> essor$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$FrameBuff
>>> er.invoke(AbstractNonblockingServer.java:478)
>>> at org.apache.thrift.server.Invocation.run(Invocation.java:18)
>>> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>> Executor.java:1142)
>>> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>> lExecutor.java:617)
>>> at java.lang.Thread.run(Thread.java:745)
>>> 2016-08-31 01:10:42,936 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(Precondition
>>> s.java:149)
>>> at org.apache.tephra.TransactionManager.ensureAvailable(Transac
>>> tionManager.java:709)
>>> at org.apache.tephra.TransactionManager.startTx(TransactionMana
>>> ger.java:768)
>>> at org.apache.tephra.TransactionManager.startShort(TransactionM
>>> anager.java:728)
>>> at org.apache.tephra.TransactionManager.startShort(TransactionM
>>> anager.java:716)
>>> at org.apache.tephra.distributed.TransactionServiceThriftHandle
>>> r.startShort(TransactionServiceThriftHandler.java:71)
>>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAcce
>>> ssorImpl.java:62)
>>> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe
>>> thodAccessorImpl.java:43)
>>> at java.lang.reflect.Method.invoke(Method.java:498)
>>> at org.apache.tephra.rpc.ThriftRPCServer$1.invoke(ThriftRPCServ
>>> er.java:261)
>>> at com.sun.proxy.$Proxy17.startShort(Unknown Source)
>>> at org.apache.tephra.distributed.thrift.TTransactionServer$Proc
>>> essor$startShort.getResult(TTransactionServer.java:974)
>>> at org.apache.tephra.distributed.thrift.TTransactionServer$Proc
>>> essor$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$FrameBuff
>>> er.invoke(AbstractNonblockingServer.java:478)
>>> at org.apache.thrift.server.Invocation.run(Invocation.java:18)
>>> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>> Executor.java:1142)
>>> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>> lExecutor.java:617)
>>> at java.lang.Thread.run(Thread.java:745)
>>>
>>> This seems very similar to PHOENIX-2504 (https://issues.apache.org/jir
>>> a/browse/PHOENIX-2504), but that appears to be fixed in 4.8.0?
>>>
>>> Any ideas why this might be happening?
>>>
>>> Cheers,
>>>
>>> Francis
>>>
>>>
>>>
>>
>
Re: Tephra errors when trying to create a transactional table in
Phoenix 4.8.0
Posted by F21 <f2...@gmail.com>.
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:
>>
>> <?xml version="1.0"?>
>> <?xml-stylesheet type="text/xsl" href="configuration.xsl"?>
>> <configuration>
>> <property>
>> <name>hbase.rootdir</name>
>> <value>hdfs://mycluster/hbase</value>
>> </property>
>> <property>
>> <name>zookeeper.znode.parent</name>
>> <value>/hbase</value>
>> </property>
>> <property>
>> <name>hbase.cluster.distributed</name>
>> <value>true</value>
>> </property>
>> <property>
>> <name>hbase.zookeeper.quorum</name>
>> <value>m9edd51-zookeeper.m9edd51</value>
>> </property>
>> <property>
>> <name>data.tx.snapshot.dir</name>
>> <value>/tmp/tephra/snapshots</value>
>> </property>
>> <property>
>> <name>data.tx.timeout</name>
>> <value>60</value>
>> </property>
>> <property>
>> <name>phoenix.transactions.enabled</name>
>> <value>true</value>
>> </property>
>> </configuration>
>>
>> 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 = 40000
>> 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
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>> at java.lang.Thread.run(Thread.java:745)
>> 2016-08-31 01:10:42,936 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
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>> at java.lang.Thread.run(Thread.java:745)
>>
>> This seems very similar to PHOENIX-2504
>> (https://issues.apache.org/jira/browse/PHOENIX-2504), but that
>> appears to be fixed in 4.8.0?
>>
>> Any ideas why this might be happening?
>>
>> Cheers,
>>
>> Francis
>>
>>
>
Re: Tephra errors when trying to create a transactional table in
Phoenix 4.8.0
Posted by F21 <f2...@gmail.com>.
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:
>
> <?xml version="1.0"?>
> <?xml-stylesheet type="text/xsl" href="configuration.xsl"?>
> <configuration>
> <property>
> <name>hbase.rootdir</name>
> <value>hdfs://mycluster/hbase</value>
> </property>
> <property>
> <name>zookeeper.znode.parent</name>
> <value>/hbase</value>
> </property>
> <property>
> <name>hbase.cluster.distributed</name>
> <value>true</value>
> </property>
> <property>
> <name>hbase.zookeeper.quorum</name>
> <value>m9edd51-zookeeper.m9edd51</value>
> </property>
> <property>
> <name>data.tx.snapshot.dir</name>
> <value>/tmp/tephra/snapshots</value>
> </property>
> <property>
> <name>data.tx.timeout</name>
> <value>60</value>
> </property>
> <property>
> <name>phoenix.transactions.enabled</name>
> <value>true</value>
> </property>
> </configuration>
>
> 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 = 40000
> 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
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> 2016-08-31 01:10:42,936 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
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
>
> This seems very similar to PHOENIX-2504
> (https://issues.apache.org/jira/browse/PHOENIX-2504), but that appears
> to be fixed in 4.8.0?
>
> Any ideas why this might be happening?
>
> Cheers,
>
> Francis
>
>