search

forcedotcom / phoenix

BSD 3-Clause "New" or "Revised" License
558 stars 227 forks source link

PhoenixIOException in 3.0.0 #686

Closed rtvt123 closed 10 years ago

rtvt123 commented 10 years ago

getting this exception with the most recent master build (3.0.0-SNAPSHOT) when trying to connect with JDBC driver EDIT: this makes Phoenix 3.0.0 unusable so we reverted back to ver. 2.2.2

com.salesforce.phoenix.exception.PhoenixIOException: org.apache.hadoop.hbase.DoNotRetryIOException: SYSTEM.TABLE,,1389143180863.005553c475a9e7c77bcc242f7092f294.: com.salesforce.phoenix.expression.function.CeilDecimalExpression cannot be cast to com.salesforce.phoenix.expression.function.SingleAggregateFunction at com.salesforce.phoenix.util.ServerUtil.parseServerException(ServerUtil.java:107) at com.salesforce.phoenix.iterate.ParallelIterators.getIterators(ParallelIterators.java:217) at com.salesforce.phoenix.iterate.ConcatResultIterator.getIterators(ConcatResultIterator.java:54) at com.salesforce.phoenix.iterate.ConcatResultIterator.currentIterator(ConcatResultIterator.java:76) at com.salesforce.phoenix.iterate.ConcatResultIterator.next(ConcatResultIterator.java:96) at com.salesforce.phoenix.iterate.GroupedAggregatingResultIterator.next(GroupedAggregatingResultIterator.java:78) at com.salesforce.phoenix.iterate.UngroupedAggregatingResultIterator.next(UngroupedAggregatingResultIterator.java:49) at com.salesforce.phoenix.compile.PostDDLCompiler$1.execute(PostDDLCompiler.java:195) at com.salesforce.phoenix.query.ConnectionQueryServicesImpl.updateData(ConnectionQueryServicesImpl.java:1240) at com.salesforce.phoenix.schema.MetaDataClient.createTable(MetaDataClient.java:355) at com.salesforce.phoenix.compile.CreateTableCompiler$1.execute(CreateTableCompiler.java:83) at com.salesforce.phoenix.jdbc.PhoenixStatement$ExecutableCreateTableStatement.executeUpdate(PhoenixStatement.java:357) at com.salesforce.phoenix.jdbc.PhoenixStatement.executeUpdate(PhoenixStatement.java:1036) at com.salesforce.phoenix.query.ConnectionQueryServicesImpl.init(ConnectionQueryServicesImpl.java:1217) at com.salesforce.phoenix.jdbc.PhoenixDriver.getConnectionQueryServices(PhoenixDriver.java:87) at com.salesforce.phoenix.jdbc.PhoenixEmbeddedDriver.connect(PhoenixEmbeddedDriver.java:115) at java.sql.DriverManager.getConnection(DriverManager.java:571) at java.sql.DriverManager.getConnection(DriverManager.java:233)

rtvt123 commented 10 years ago

Re-opening as I'm keep getting these when creating a new table or altering a new table, it happens sporadically,something like 2 out of 3 attempts to "create table" or the first "alter table" statement using phoenix/bin/sqlline.sh (or any other client) throw these errs (using hbase 0.94.13)

CREATE TABLE my_schema.my_table_3 ( id BIGINT not null primary key); Error: com.salesforce.phoenix.exception.PhoenixIOException: org.apache.hadoop.hbase.DoNotRetryIOException: MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239.: com.salesforce.phoenix.expression.DateSubtractExpression cannot be cast to com.salesforce.phoenix.expression.function.SingleAggregateFunction (state=08000,code=101)

hbase master log:

2014-01-13 11:39:59,068 DEBUG org.apache.hadoop.hbase.client.ClientScanner: Creating scanner over .META. starting at key 'MY_SCHEMA.MY_TABLE_3,,' 2014-01-13 11:39:59,068 DEBUG org.apache.hadoop.hbase.client.ClientScanner: Advancing internal scanner to startKey at 'MY_SCHEMA.MY_TABLE_3,,' 2014-01-13 11:39:59,197 INFO org.apache.hadoop.hbase.master.handler.CreateTableHandler: Attempting to create the table MY_SCHEMA.MY_TABLE_3 2014-01-13 11:39:59,244 INFO org.apache.hadoop.hbase.regionserver.HRegion: creating HRegion MY_SCHEMA.MY_TABLE_3 HTD == 'MY_SCHEMA.MY_TABLE_3', {METHOD => 'table_att', coprocessor$1 => '|com.salesforce.phoenix.coprocessor.ScanRegionObserver|1|', coprocessor$2 => '|com.salesforce.phoenix.coprocessor.UngroupedAggregateRegionObserver|1|', coprocessor$3 => '|com.salesforce.phoenix.coprocessor.GroupedAggregateRegionObserver|1|', coprocessor$4 => '|com.salesforce.phoenix.coprocessor.ServerCachingEndpointImpl|1|', coprocessor$5 => '|com.salesforce.hbase.index.Indexer|1073741823|com.salesforce.hbase.index.codec.class=com.salesforce.phoenix.index.PhoenixIndexCodec,index.builder=com.salesforce.phoenix.index.PhoenixIndexBuilder'}, {NAME => '_0', DATA_BLOCK_ENCODING => 'FAST_DIFF', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', VERSIONS => '3', COMPRESSION => 'NONE', MIN_VERSIONS => '0', TTL => '2147483647', KEEP_DELETED_CELLS => 'true', BLOCKSIZE => '65536', IN_MEMORY => 'false', ENCODE_ON_DISK => 'true', BLOCKCACHE => 'true'} RootDir = hdfs://localhost:9000/hbase/.tmp Table name == MY_SCHEMA.MY_TABLE_3 2014-01-13 11:39:59,254 DEBUG org.apache.hadoop.hbase.util.FSUtils: Creating file=hdfs://localhost:9000/hbase/.tmp/MY_SCHEMA.MY_TABLE_3/66f0980c802930a309077c7145de1239/.tmp/.regioninfo with permission=rwxrwxrwx 2014-01-13 11:39:59,255 INFO org.apache.hadoop.hbase.util.FSUtils: FileSystem doesn't support getDefaultReplication 2014-01-13 11:39:59,255 INFO org.apache.hadoop.hbase.util.FSUtils: FileSystem doesn't support getDefaultBlockSize 2014-01-13 11:39:59,294 INFO org.apache.hadoop.hbase.regionserver.HRegion: Setting up tabledescriptor config now ... 2014-01-13 11:39:59,294 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Instantiated MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239. 2014-01-13 11:39:59,294 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Closing MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239.: disabling compactions & flushes 2014-01-13 11:39:59,294 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Updates disabled for region MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239. 2014-01-13 11:39:59,294 INFO org.apache.hadoop.hbase.regionserver.HRegion: Closed MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239. 2014-01-13 11:39:59,305 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Added 1 regions in META

hbase regionserver log:

2014-01-13 11:39:59,375 INFO org.apache.hadoop.hbase.regionserver.RegionCoprocessorHost: Load coprocessor com.salesforce.phoenix.coprocessor.ScanRegionObserver from HTD of MY_SCHEMA.MY_TABLE_3 successfully. 2014-01-13 11:39:59,375 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Instantiated MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239. 2014-01-13 11:39:59,408 INFO org.apache.hadoop.hbase.regionserver.Store: time to purge deletes set to 0ms in store _0 2014-01-13 11:39:59,408 INFO org.apache.hadoop.hbase.regionserver.Store: hbase.hstore.compaction.min = 3 2014-01-13 11:39:59,412 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239.; next sequenceid=1 2014-01-13 11:39:59,412 INFO com.salesforce.hbase.index.Indexer: Found some outstanding index updates that didn't succeed during WAL replay - attempting to replay now. 2014-01-13 11:39:59,412 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x1437ec66b280002 Attempting to transition node 66f0980c802930a309077c7145de1239 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING 2014-01-13 11:39:59,438 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x1437ec66b280002 Successfully transitioned node 66f0980c802930a309077c7145de1239 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING 2014-01-13 11:39:59,439 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Post open deploy tasks for region=MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239., daughter=false 2014-01-13 11:39:59,444 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Updated row MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239. with server=localhost,60020,1389401381702 2014-01-13 11:39:59,444 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Done with post open deploy task for region=MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239., daughter=false 2014-01-13 11:39:59,444 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x1437ec66b280002 Attempting to transition node 66f0980c802930a309077c7145de1239 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED 2014-01-13 11:39:59,480 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x1437ec66b280002 Successfully transitioned node 66f0980c802930a309077c7145de1239 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED 2014-01-13 11:39:59,480 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: region transitioned to opened in zookeeper: {NAME => 'MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239.', STARTKEY => '', ENDKEY => '', ENCODED => 66f0980c802930a309077c7145de1239,}, server: localhost,60020,1389401381702 2014-01-13 11:39:59,480 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Opened MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239. on server:localhost,60020,1389401381702 2014-01-13 11:40:00,433 ERROR org.apache.hadoop.hbase.regionserver.HRegionServer: Failed openScanner org.apache.hadoop.hbase.DoNotRetryIOException: MY_SCHEMA.MY_TABLE_3,,1389631199066.66f0980c802930a309077c7145de1239.: com.salesforce.phoenix.expression.DateSubtractExpression cannot be cast to com.salesforce.phoenix.expression.function.SingleAggregateFunction at com.salesforce.phoenix.util.ServerUtil.throwIOException(ServerUtil.java:83) at com.salesforce.phoenix.coprocessor.BaseScannerRegionObserver.postScannerOpen(BaseScannerRegionObserver.java:61) at org.apache.hadoop.hbase.regionserver.RegionCoprocessorHost.postScannerOpen(RegionCoprocessorHost.java:1316) at org.apache.hadoop.hbase.regionserver.HRegionServer.internalOpenScanner(HRegionServer.java:2563) at org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:2531) at sun.reflect.GeneratedMethodAccessor16.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.apache.hadoop.hbase.ipc.WritableRpcEngine$Server.call(WritableRpcEngine.java:323) at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1426) Caused by: java.lang.ClassCastException: com.salesforce.phoenix.expression.DateSubtractExpression cannot be cast to com.salesforce.phoenix.expression.function.SingleAggregateFunction at com.salesforce.phoenix.expression.aggregator.ServerAggregators.deserialize(ServerAggregators.java:136) at com.salesforce.phoenix.coprocessor.UngroupedAggregateRegionObserver.doPostScannerOpen(UngroupedAggregateRegionObserver.java:200) at com.salesforce.phoenix.coprocessor.BaseScannerRegionObserver.postScannerOpen(BaseScannerRegionObserver.java:59) ... 8 more 2014-01-13 11:40:00,436 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Client tried to access missing scanner -1 2014-01-13 11:43:32,959 DEBUG org.apache.hadoop.hbase.regionserver.Store: Skipping major compaction of ESSENTIALS because one (major) compacted file only and oldestTime 1389631412959ms is < ttl=9223372036854775807 2014-01-13 11:43:32,959 DEBUG org.apache.hadoop.hbase.regionserver.Store: Skipping major compaction of INDUCTION because one (major) compacted file only and oldestTime 4:

rtvt123 commented 10 years ago

one of these steps worked: