邢质坦 created IOTDB-227:
-------------------------
Summary: tsfile is stored on hdfs，but only exist storage group and
time series.
Key: IOTDB-227
URL: https://issues.apache.org/jira/browse/IOTDB-227
Project: Apache IoTDB
Issue Type: Bug
Reporter: 邢质坦
The following exception occurred when I entered the flush command on the iotdb
client.
[root@bigdata-master sbin]# ./start-server.sh
---------------------
Starting IoTDB
---------------------
Maximum memory allocation pool = 3928MB, initial memory allocation pool = 400MB
If you want to change this configuration, please check conf/iotdb-env.sh(Unix
or OS X, if you use Windows, check conf/iotdb-env.bat).
2019-09-19 10:03:04,839 [main] INFO
org.apache.iotdb.db.conf.IoTDBDescriptor:88 - Start to read config file
./../conf/iotdb-engine.properties
2019-09-19 10:03:04,855 [main] INFO
org.apache.iotdb.db.conf.IoTDBDescriptor:108 - The stat_monitor_detect_freq_sec
value is smaller than default, use default value
2019-09-19 10:03:04,856 [main] INFO
org.apache.iotdb.db.conf.IoTDBDescriptor:115 - The
stat_monitor_retain_interval_sec value is smaller than default, use default
value
2019-09-19 10:03:04,857 [main] INFO
org.apache.iotdb.db.conf.IoTDBDescriptor:222 - Time zone has been set to +08:00
2019-09-19 10:03:04,863 [main] INFO
org.apache.iotdb.db.conf.IoTDBConfigCheck:54 - System configuration is ok.
2019-09-19 10:03:04,867 [main] INFO
org.apache.iotdb.db.service.StartupChecks:47 - JMX is enabled to receive remote
connection on port 31999
2019-09-19 10:03:04,869 [main] INFO
org.apache.iotdb.db.service.StartupChecks:57 - JDK veriosn is 8.
2019-09-19 10:03:04,869 [main] INFO org.apache.iotdb.db.service.IoTDB:79 -
Setting up IoTDB...
2019-09-19 10:03:04,925 [main] INFO
org.apache.iotdb.db.engine.version.SimpleFileVersionController:82 - Version
file updated, previous:
/opt/apache-iotdb-0.9.0-SNAPSHOT-incubating/sbin/./../data/system/storage_groups/root.baic2.weldingworkshop.robotlaboratory.plc1/Version-1200,
current:
/opt/apache-iotdb-0.9.0-SNAPSHOT-incubating/sbin/./../data/system/storage_groups/root.baic2.weldingworkshop.robotlaboratory.plc1/Version-1300
2019-09-19 10:03:04,926 [main] INFO
org.apache.iotdb.db.engine.storagegroup.StorageGroupProcessor:206 - recover
Storage Group root.baic2.weldingworkshop.robotlaboratory.plc1
2019-09-19 10:03:05,045 [main] INFO
org.apache.iotdb.tsfile.common.conf.TSFileDescriptor:105 - Start to read config
file ./../conf/tsfile-format.properties
log4j:WARN No appenders could be found for logger
(org.apache.hadoop.util.Shell).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more
info.
2019-09-19 10:03:06,123 [main] INFO
org.apache.iotdb.db.conf.directories.DirectoryManager:80 - folder
hdfs://10.12.20.131:8020/data/data/sequence doesn't exist, create it
2019-09-19 10:03:06,142 [main] INFO
org.apache.iotdb.db.conf.directories.DirectoryManager:80 - folder
hdfs://10.12.20.131:8020/data/data/unsequence doesn't exist, create it
2019-09-19 10:03:06,224 [main] INFO
org.apache.iotdb.db.engine.storagegroup.StorageGroupProcessor:225 -
root.baic2.weldingworkshop.robotlaboratory.plc1 a RecoverMergeTask
root.baic2.weldingworkshop.robotlaboratory.plc1-1568858586214 starts...
2019-09-19 10:03:06,224 [main] INFO
org.apache.iotdb.db.engine.merge.task.RecoverMergeTask:64 -
root.baic2.weldingworkshop.robotlaboratory.plc1-1568858586214 no merge.log,
merge recovery ends
2019-09-19 10:03:06,224 [main] INFO
org.apache.iotdb.db.engine.StorageEngine:93 - Storage Group Processor
root.baic2.weldingworkshop.robotlaboratory.plc1 is recovered successfully
2019-09-19 10:03:06,227 [main] WARN org.apache.iotdb.db.service.JMXService:109
- JMX settings in conf/iotdb-env.sh(Unix or OS X, if you use Windows, check
conf/iotdb-env.bat) have been bypassed as the JMX connector server is already
initialized. Please refer to iotdb-env.sh/bat for JMX configuration info
2019-09-19 10:03:06,229 [main] INFO org.apache.iotdb.db.service.JDBCService:71
- Start latch is null when getting status
2019-09-19 10:03:06,229 [main] INFO org.apache.iotdb.db.service.JDBCService:76
- Stop latch is null when getting status
2019-09-19 10:03:06,229 [main] INFO
org.apache.iotdb.db.service.JDBCService:124 - IoTDB: start JDBC
ServerService...
2019-09-19 10:03:06,288 [main] INFO
org.apache.iotdb.db.service.JDBCService:139 - IoTDB: start JDBC ServerService
successfully, listening on ip 0.0.0.0 port 6667
2019-09-19 10:03:06,292 [main] INFO
org.apache.iotdb.db.cost.statistic.Measurement:142 - start measurement stats
module...
2019-09-19 10:03:06,293 [main] INFO
org.apache.iotdb.db.cost.statistic.Measurement:250 - start the consuming task
in the measurement stats module...
2019-09-19 10:03:06,294 [main] INFO
org.apache.iotdb.db.conf.adapter.ManageDynamicParameters:109 - IoTDB: start
Manage Dynamic Parameters...
2019-09-19 10:03:06,298 [main] INFO
org.apache.iotdb.db.sync.receiver.SyncServerManager:76 - Sync server has
started.
2019-09-19 10:03:06,301 [main] INFO
org.apache.iotdb.db.engine.flush.pool.FlushSubTaskPoolManager:57 - Flush sub
task manager started.
2019-09-19 10:03:06,301 [main] INFO
org.apache.iotdb.db.engine.flush.pool.FlushTaskPoolManager:58 - Flush task
manager started.
2019-09-19 10:03:06,303 [main] INFO
org.apache.iotdb.db.engine.merge.manage.MergeManager:93 - MergeManager started
2019-09-19 10:03:06,305 [main] INFO org.apache.iotdb.db.service.IoTDB:107 -
IoTDB is set up.
2019-09-19 10:03:06,305 [main] INFO org.apache.iotdb.db.service.IoTDB:75 -
IoTDB has started.
2019-09-19 10:06:12,966 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.service.TSServiceImpl:109 - IoTDB: receive open session
request from username root
2019-09-19 10:06:12,989 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.auth.user.BasicUserManager:78 - Admin initialized
2019-09-19 10:06:12,992 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.auth.user.BasicUserManager:78 - Admin initialized
2019-09-19 10:06:12,993 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.auth.authorizer.BasicAuthorizer:63 - Initialization of
Authorizer completes
2019-09-19 10:06:13,018 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.service.TSServiceImpl:139 - IoTDB: Login status: : Login
successfully. User : root
2019-09-19 10:06:13,378 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.engine.storagegroup.TsFileProcessor:127 - create a new
tsfile processor
hdfs://10.12.20.131:8020/data/data/sequence/root.baic2.weldingworkshop.robotlaboratory.plc1/1568858773282-1301.tsfile
2019-09-19 10:06:13,379 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.rescon.MemTablePool:50 - generated a new memtable for
org.apache.iotdb.db.engine.storagegroup.TsFileProcessor@6a05239b, system
memtable size: 1, stack size: 0
2019-09-19 10:06:13,386 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.writelog.node.ExclusiveWriteLogNode:74 - create the WAL
folder
{}../../data/wal/root.baic2.weldingworkshop.robotlaboratory.plc1-1568858773282-1301.tsfile
2019-09-19 10:13:49,171 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:109 - IoTDB: receive open session
request from username root
2019-09-19 10:13:49,172 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:139 - IoTDB: Login status: : Login
successfully. User : root
2019-09-19 10:13:59,239 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:44,110 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:44,110 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:46,242 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:46,242 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:47,700 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:47,701 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:48,669 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:48,670 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:49,706 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:49,706 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:50,819 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:50,820 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:51,423 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:51,423 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:53,678 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:14:53,679 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:15:09,548 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.engine.StorageEngine:206 - Start closing all storage group
processor
2019-09-19 10:15:09,548 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.engine.storagegroup.StorageGroupProcessor:583 - async force
close all files in storage group:
root.baic2.weldingworkshop.robotlaboratory.plc1
2019-09-19 10:15:09,549 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.engine.storagegroup.TsFileProcessor:257 - Async close the
file:
hdfs://10.12.20.131:8020/data/data/sequence/root.baic2.weldingworkshop.robotlaboratory.plc1/1568858773282-1301.tsfile
2019-09-19 10:15:09,550 [pool-1-IoTDB-JDBC-Client-thread-2] INFO
org.apache.iotdb.db.engine.flush.FlushManager:105 - storage group
root.baic2.weldingworkshop.robotlaboratory.plc1 begin to submit a flush thread,
flushing memtable size: 1
2019-09-19 10:15:09,552 [pool-4-IoTDB-Flush-ServerServiceImpl-thread-1] INFO
org.apache.iotdb.db.engine.storagegroup.TsFileProcessor:398 - storage group
root.baic2.weldingworkshop.robotlaboratory.plc1 starts to flush a memtable in a
flush thread
2019-09-19 10:15:09,593 [pool-4-IoTDB-Flush-ServerServiceImpl-thread-1] INFO
org.apache.iotdb.db.engine.flush.MemTableFlushTask:95 - Storage group
root.baic2.weldingworkshop.robotlaboratory.plc1 memtable
org.apache.iotdb.db.engine.memtable.PrimitiveMemTable@516 flushing a memtable
has finished! Time consumption: 37ms
2019-09-19 10:15:09,593 [pool-4-IoTDB-Flush-ServerServiceImpl-thread-1] INFO
org.apache.iotdb.db.writelog.node.ExclusiveWriteLogNode:189 - Log node
root.baic2.weldingworkshop.robotlaboratory.plc1-1568858773282-1301.tsfile
cleaned old file
2019-09-19 10:15:09,595 [pool-4-IoTDB-Flush-ServerServiceImpl-thread-1] INFO
org.apache.iotdb.db.conf.adapter.CompressionRatio:91 - Compression ratio is
2.4006269364716637
2019-09-19 10:15:09,595 [pool-4-IoTDB-Flush-ServerServiceImpl-thread-1] INFO
org.apache.iotdb.db.conf.adapter.CompressionRatio:95 - After updating
compression ratio, trying to adjust parameters, the original parameters:
MemTableSize threshold is 244099872B, TsfileSize threshold is 536870912B,
MemTableNumber is 9
2019-09-19 10:15:09,595 [pool-4-IoTDB-Flush-ServerServiceImpl-thread-1] INFO
org.apache.iotdb.db.conf.adapter.CompressionRatio:103 - After updating
compression ratio, trying to adjust parameters, the modified parameters:
MemTableSize threshold is 244091817B, TsfileSize threshold is 536870912B,
MemTableNumber is 9
2019-09-19 10:15:09,595 [pool-4-IoTDB-Flush-ServerServiceImpl-thread-1] ERROR
org.apache.iotdb.db.engine.storagegroup.TsFileProcessor:447 - meet error when
flush FileMetadata to
hdfs://10.12.20.131:8020/data/data/sequence/root.baic2.weldingworkshop.robotlaboratory.plc1/1568858773282-1301.tsfile,
change system mode to read-only
2019-09-19 10:15:09,598 [IoTDB-MultiFileLogNodeManager-Force-Thread] WARN
org.apache.iotdb.db.writelog.manager.MultiFileLogNodeManager:51 - system mode
is read-only, the force flush WAL task is stopped
2019-09-19 10:15:09,609 [pool-4-IoTDB-Flush-ServerServiceImpl-thread-1] ERROR
org.apache.iotdb.db.engine.storagegroup.TsFileProcessor:453 - truncate
corrupted data meets error
org.apache.hadoop.ipc.RemoteException: Failed to TRUNCATE_FILE
/data/data/sequence/root.baic2.weldingworkshop.robotlaboratory.plc1/1568858773282-1301.tsfile
for DFSClient_NONMAPREDUCE_204038481_1 on 10.12.20.122 because
DFSClient_NONMAPREDUCE_204038481_1 is already the current lease holder.
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.recoverLeaseInternal(FSNamesystem.java:2555)
at
org.apache.hadoop.hdfs.server.namenode.FSDirTruncateOp.truncate(FSDirTruncateOp.java:119)
at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.truncate(FSNamesystem.java:2117)
at
org.apache.hadoop.hdfs.server.namenode.NameNodeRpcServer.truncate(NameNodeRpcServer.java:1073)
at
org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolServerSideTranslatorPB.truncate(ClientNamenodeProtocolServerSideTranslatorPB.java:680)
at
org.apache.hadoop.hdfs.protocol.proto.ClientNamenodeProtocolProtos$ClientNamenodeProtocol$2.callBlockingMethod(ClientNamenodeProtocolProtos.java)
at
org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:524)
at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:1025)
at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:876)
at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:822)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1730)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2682)
at org.apache.hadoop.ipc.Client.call(Client.java:1475)
at org.apache.hadoop.ipc.Client.call(Client.java:1412)
at
org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:229)
at com.sun.proxy.$Proxy13.truncate(Unknown Source)
at
org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.truncate(ClientNamenodeProtocolTranslatorPB.java:313)
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.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:191)
at
org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:102)
at com.sun.proxy.$Proxy14.truncate(Unknown Source)
at org.apache.hadoop.hdfs.DFSClient.truncate(DFSClient.java:2016)
at
org.apache.hadoop.hdfs.DistributedFileSystem$13.doCall(DistributedFileSystem.java:689)
at
org.apache.hadoop.hdfs.DistributedFileSystem$13.doCall(DistributedFileSystem.java:685)
at
org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81)
at
org.apache.hadoop.hdfs.DistributedFileSystem.truncate(DistributedFileSystem.java:696)
at
org.apache.iotdb.tsfile.fileSystem.HDFSOutput.truncate(HDFSOutput.java:91)
at
org.apache.iotdb.tsfile.write.writer.TsFileIOWriter.reset(TsFileIOWriter.java:378)
at
org.apache.iotdb.db.engine.storagegroup.TsFileProcessor.flushOneMemTable(TsFileProcessor.java:451)
at
org.apache.iotdb.db.engine.flush.FlushManager$FlushThread.run(FlushManager.java:92)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2019-09-19 10:15:09,609 [pool-4-IoTDB-Flush-ServerServiceImpl-thread-1] ERROR
org.apache.iotdb.db.engine.storagegroup.TsFileProcessor:455 - marking or ending
file meet error
java.io.FileNotFoundException:
hdfs:/10.12.20.131:8020/data/data/sequence/root.baic2.weldingworkshop.robotlaboratory.plc1/1568858773282-1301.tsfile.resource.temp
(No such file or directory)
at java.io.FileOutputStream.open0(Native Method)
at java.io.FileOutputStream.open(FileOutputStream.java:270)
at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
at java.io.FileOutputStream.<init>(FileOutputStream.java:101)
at
org.apache.iotdb.db.engine.storagegroup.TsFileResource.serialize(TsFileResource.java:108)
at
org.apache.iotdb.db.engine.storagegroup.TsFileProcessor.endFile(TsFileProcessor.java:468)
at
org.apache.iotdb.db.engine.storagegroup.TsFileProcessor.flushOneMemTable(TsFileProcessor.java:445)
at
org.apache.iotdb.db.engine.flush.FlushManager$FlushThread.run(FlushManager.java:92)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2019-09-19 10:15:22,644 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
2019-09-19 10:15:22,645 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.service.TSServiceImpl:152 - IoTDB: receive close session
2019-09-19 10:15:38,722 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.service.TSServiceImpl:109 - IoTDB: receive open session
request from username root
2019-09-19 10:15:38,723 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.service.TSServiceImpl:139 - IoTDB: Login status: : Login
successfully. User : root
2019-09-19 10:15:45,907 [pool-1-IoTDB-JDBC-Client-thread-1] INFO
org.apache.iotdb.db.service.TSServiceImpl:176 - IoTDB: receive close operation
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
