redimension_store fails: Operation 'read' failed


#1

using SciDB 12.3. I’m trying to load 150 million rows from a csv file into SciDB via a raw array, it fails during redimension_store.

I have converted a csv with 150 million rows to a scidb file, and then loaded it into a raw array in SciDB

 iquery -aq " show(raw)"
[("raw<value_num:double NULL,value_min:double NULL,value_max:double NULL,value_display:string NULL,qualifier:string NULL,substance_id:int64,modified_by:string NULL,experiment_id:int64,project_id:int64 NULL,rslt_context_id:int64 NULL,assay_id:int64> [line=0:*,100000,0]")]

I now want to use redimension_store to transfer the data to my correctly dimensioned array:

iquery -aq "show(result)"
[("result<value_num:double NULL,value_min:double NULL,value_max:double NULL,value_display:string NULL,qualifier:string NULL,modified_by:string NULL,project_id:int64 NULL,rslt_context_id:int64 NULL> [substance_id=842122:125307028,250000,0,experiment_id=18:4573,1,0,assay_id=20:4578,1,0]")]

iquery -naq "redimension_store(raw, result)"

It runs for about 4 minutes (22 instances running) and then fails. The first time it failed on instance 3, the most recent time instance 14. Here is the log for the coordinator:

2012-12-04 19:08:53,144 [0x4217c940] [DEBUG]: Generated queryID: instanceID=0, time=1354666133, clock=1140020000, nextID=117, queryID=1102006314026
2012-12-04 19:08:53,144 [0x4217c940] [DEBUG]: Allocating query (1102006314026)
2012-12-04 19:08:53,144 [0x4217c940] [DEBUG]: Number of allocated queries = 1
2012-12-04 19:08:53,144 [0x4217c940] [DEBUG]: Initialized query (1102006314026)
2012-12-04 19:08:53,144 [0x4217c940] [DEBUG]: Parsing query(1102006314026): redimension_store(raw, result)
2012-12-04 19:08:53,148 [0x4217c940] [DEBUG]: Inferred schema for operator scan: raw@1<value_num:double NULL,value_min:double NULL,value_max:double NULL,value_display:string NULL,qualifier:string NULL,substance_id:int64,modified_by:string NULL,experiment_id:int64,project_id:int64 NULL,rslt_context_id:int64 NULL,assay_id:int64> [lineraw=0:155594432,100000,0]
2012-12-04 19:08:53,149 [0x4217c940] [DEBUG]: Acquiring 2 array locks for query 1102006314026
2012-12-04 19:08:53,149 [0x4217c940] [DEBUG]: Acquiring lock: Lock: arrayName=raw, arrayId=0, queryId=1102006314026, instanceId=0, instanceRole=COORD, lockMode=1, arrayVersion=0, arrayVersionId=0, timestamp=1685
2012-12-04 19:08:53,149 [0x4217c940] [DEBUG]: SystemCatalog::lockArray: Lock: arrayName=raw, arrayId=0, queryId=1102006314026, instanceId=0, instanceRole=COORD, lockMode=1, arrayVersion=0, arrayVersionId=0, timestamp=1685
2012-12-04 19:08:53,150 [0x4217c940] [DEBUG]: Acquiring lock: Lock: arrayName=result, arrayId=0, queryId=1102006314026, instanceId=0, instanceRole=COORD, lockMode=2, arrayVersion=0, arrayVersionId=0, timestamp=1685
2012-12-04 19:08:53,150 [0x4217c940] [DEBUG]: SystemCatalog::lockArray: Lock: arrayName=result, arrayId=0, queryId=1102006314026, instanceId=0, instanceRole=COORD, lockMode=2, arrayVersion=0, arrayVersionId=0, timestamp=1685
2012-12-04 19:08:53,153 [0x4217c940] [DEBUG]: Inferred schema for operator scan: raw@1<value_num:double NULL,value_min:double NULL,value_max:double NULL,value_display:string NULL,qualifier:string NULL,substance_id:int64,modified_by:string NULL,experiment_id:int64,project_id:int64 NULL,rslt_context_id:int64 NULL,assay_id:int64> [lineraw=0:155594432,100000,0]
2012-12-04 19:08:53,154 [0x4217c940] [DEBUG]: Inferred schema for operator scan: raw@1<value_num:double NULL,value_min:double NULL,value_max:double NULL,value_display:string NULL,qualifier:string NULL,substance_id:int64,modified_by:string NULL,experiment_id:int64,project_id:int64 NULL,rslt_context_id:int64 NULL,assay_id:int64> [lineraw=0:155594432,100000,0]
2012-12-04 19:08:53,154 [0x4217c940] [DEBUG]: Inferred schema for operator redimension_store: result<value_num:double NULL,value_min:double NULL,value_max:double NULL,value_display:string NULL,qualifier:string NULL,modified_by:string NULL,project_id:int64 NULL,rslt_context_id:int64 NULL> [substance_id=842122:125307028,250000,0,experiment_id=18:4573,1,0,assay_id=20:4578,1,0]
2012-12-04 19:08:53,155 [0x4217c940] [DEBUG]: The query is prepared
2012-12-04 19:08:53,155 [0x4217c940] [DEBUG]: The result preparation of query is sent to the client
2012-12-04 19:08:53,155 [0x4207b940] [DEBUG]: Executing query(1102006314026): redimension_store(raw, result)
2012-12-04 19:08:53,155 [0x4207b940] [DEBUG]: Creating Habilis optimizer instance
2012-12-04 19:08:53,157 [0x4207b940] [DEBUG]: Query is optimized
2012-12-04 19:08:53,157 [0x4207b940] [DEBUG]: The physical plan is detected as DML
2012-12-04 19:08:53,157 [0x4207b940] [DEBUG]: 
[pPlan]:
>[pInstance] PhysicalFlipStore agg 0 ddl 0 tile 0 children 1
  schema result<value_num:double NULL,value_min:double NULL,value_max:double NULL,value_display:string NULL,qualifier:string NULL,modified_by:string NULL,project_id:int64 NULL,rslt_context_id:int64 NULL> [substance_id=842122:125307028,250000,0,experiment_id=18:4573,1,0,assay_id=20:4578,1,0]ck of array result for query 1102006314026
  props sgm 1 sgo 1
  distr roro
  bound start [842122, 18, 20] end [125307028, 4573, 4578] density 1 cells 2585236188175228 chunks 10343860392 est_bytes 8.37617e+17
>>[pInstance] physicalScan agg 0 ddl 0 tile 1 children 0
   schema raw@1<value_num:double NULL,value_min:double NULL,value_max:double NULL,value_display:string NULL,qualifier:string NULL,substance_id:int64,modified_by:string NULL,experiment_id:int64,project_id:int64 NULL,rslt_context_id:int64 NULL,assay_id:int64> [lineraw=0:155594432,100000,0]ng chunk map: 0 seconds
   props sgm 1 sgo 1
   distr roro
   bound start [0] end [155594432] density 1 cells 155594433 chunks 1556 est_bytes 3.73428e+10

2012-12-04 19:08:53,157 [0x4207b940] [DEBUG]: (Pre)Single executing queryID: 1102006314026
2012-12-04 19:08:53,163 [0x4207b940] [DEBUG]: Create array result@1(41) in query 1102006314026
2012-12-04 19:08:53,164 [0x4207b940] [DEBUG]: Query is serialized: [pPlan]:
>[pInstance] PhysicalFlipStore agg 0 ddl 0 tile 0 children 1
2:125307028,250000,0,experiment_id=18:4573,1,0,assay_id=20:4578,1,0]
  props sgm 1 sgo 1
  distr roro
  bound start [842122, 18, 20] end [125307028, 4573, 4578] density 1 cells 2585236188175228 chunks 10343860392 est_bytes 8.37617e+17
>>[pInstance] physicalScan agg 0 ddl 0 tile 1 children 0
xt_id:int64 NULL,assay_id:int64> [lineraw=0:155594432,100000,0]
   props sgm 1 sgo 1
   distr roro
   bound start [0] end [155594432] density 1 cells 155594433 chunks 1556 est_bytes 3.73428e+10

2012-12-04 19:08:53,164 [0x4207b940] [DEBUG]: Prepare physical plan was sent out
2012-12-04 19:08:53,164 [0x4207b940] [DEBUG]: Waiting confirmation about preparing physical plan in queryID from 22 instances
2012-12-04 19:08:53,166 [0x41c77940] [DEBUG]: Notify on processing query 1102006314026 from instance 12
2012-12-04 19:08:53,166 [0x42883940] [DEBUG]: Notify on processing query 1102006314026 from instance 11
2012-12-04 19:08:53,166 [0x4237e940] [DEBUG]: Notify on processing query 1102006314026 from instance 9
2012-12-04 19:08:53,167 [0x42b86940] [DEBUG]: Notify on processing query 1102006314026 from instance 6
2012-12-04 19:08:53,167 [0x42a85940] [DEBUG]: Notify on processing query 1102006314026 from instance 5
2012-12-04 19:08:53,167 [0x42782940] [DEBUG]: Notify on processing query 1102006314026 from instance 4
2012-12-04 19:08:53,167 [0x4227d940] [DEBUG]: Notify on processing query 1102006314026 from instance 7
2012-12-04 19:08:53,167 [0x42883940] [DEBUG]: Notify on processing query 1102006314026 from instance 20
2012-12-04 19:08:53,167 [0x41f7a940] [DEBUG]: Notify on processing query 1102006314026 from instance 18
2012-12-04 19:08:53,167 [0x4247f940] [DEBUG]: Notify on processing query 1102006314026 from instance 22
2012-12-04 19:08:53,167 [0x4237e940] [DEBUG]: Notify on processing query 1102006314026 from instance 21
2012-12-04 19:08:53,167 [0x41d78940] [DEBUG]: Notify on processing query 1102006314026 from instance 3
2012-12-04 19:08:53,167 [0x42580940] [DEBUG]: Notify on processing query 1102006314026 from instance 2
2012-12-04 19:08:53,167 [0x41e79940] [DEBUG]: Notify on processing query 1102006314026 from instance 14
2012-12-04 19:08:53,167 [0x42a85940] [DEBUG]: Notify on processing query 1102006314026 from instance 16
2012-12-04 19:08:53,167 [0x41c77940] [DEBUG]: Notify on processing query 1102006314026 from instance 19
2012-12-04 19:08:53,167 [0x4247f940] [DEBUG]: Notify on processing query 1102006314026 from instance 10
2012-12-04 19:08:53,167 [0x42681940] [DEBUG]: Notify on processing query 1102006314026 from instance 1
2012-12-04 19:08:53,167 [0x42b86940] [DEBUG]: Notify on processing query 1102006314026 from instance 8
2012-12-04 19:08:53,167 [0x4217c940] [DEBUG]: Notify on processing query 1102006314026 from instance 15
2012-12-04 19:08:53,167 [0x42782940] [DEBUG]: Notify on processing query 1102006314026 from instance 13
2012-12-04 19:08:53,167 [0x41e79940] [DEBUG]: Notify on processing query 1102006314026 from instance 17
2012-12-04 19:08:53,168 [0x4207b940] [DEBUG]: Execute physical plan was sent out
2012-12-04 19:08:53,168 [0x4207b940] [INFO ]: Executing query(1102006314026): redimension_store(raw, result)
2012-12-04 19:08:53,169 [0x4207b940] [DEBUG]: Request shared lock of array raw@1 for query 1102006314026
2012-12-04 19:08:53,169 [0x4207b940] [DEBUG]: Granted shared lock of array raw@1 for query 1102006314026
2012-12-04 19:08:53,169 [0x4207b940] [DEBUG]: Request exclusive lock of array result for query 1102006314026
2012-12-04 19:08:53,169 [0x4207b940] [DEBUG]: Granted exclusive lock of array result for query 1102006314026
2012-12-04 19:08:53,170 [0x4207b940] [DEBUG]: Request shared lock of array result@1 for query 1102006314026
2012-12-04 19:08:53,170 [0x4207b940] [DEBUG]: Granted shared lock of array result@1 for query 1102006314026
2012-12-04 19:09:00,781 [0x4207b940] [DEBUG]: Time for building coordinate indices: 7 seconds
2012-12-04 19:09:52,894 [0x4207b940] [DEBUG]: Failed pwrite call fd 59 src 46912943252544 size 294912 offs 257654784 rc -1 errno 28
2012-12-04 19:09:52,894 [0x4207b940] [DEBUG]: Partial sort time: 52 seconds
2012-12-04 19:09:52,956 [0x4207b940] [DEBUG]: Time for exchanging chunk map: 0 seconds
2012-12-04 19:12:57,203 [0x42681940] [ERROR]: Error on processing query 1102006314026 on instance 14. Message: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026
2012-12-04 19:12:57,297 [0x4217c940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 10, queryID=1102006314026
2012-12-04 19:12:57,297 [0x4217c940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,498 [0x42984940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 22, queryID=1102006314026
2012-12-04 19:12:57,498 [0x42984940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,708 [0x41e79940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 12, queryID=1102006314026
2012-12-04 19:12:57,708 [0x41e79940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,717 [0x42b86940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 4, queryID=1102006314026
2012-12-04 19:12:57,717 [0x42b86940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,719 [0x4227d940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 15, queryID=1102006314026
2012-12-04 19:12:57,719 [0x4227d940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,727 [0x4237e940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 17, queryID=1102006314026
2012-12-04 19:12:57,727 [0x4237e940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,732 [0x42782940] [ERROR]: Error on processing query 1102006314026 on instance 14. Message: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026
2012-12-04 19:12:57,734 [0x41d78940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 4, queryID=1102006314026
2012-12-04 19:12:57,734 [0x41d78940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,737 [0x41c77940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 15, queryID=1102006314026
2012-12-04 19:12:57,737 [0x41c77940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,737 [0x42a85940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 15, queryID=1102006314026
2012-12-04 19:12:57,737 [0x42a85940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,751 [0x41f7a940] [ERROR]: Error on processing query 1102006314026 on instance 14. Message: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026
2012-12-04 19:12:57,941 [0x42580940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 16, queryID=1102006314026
2012-12-04 19:12:57,942 [0x42580940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,945 [0x4247f940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 16, queryID=1102006314026
2012-12-04 19:12:57,945 [0x4247f940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,945 [0x4247f940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 16, queryID=1102006314026
2012-12-04 19:12:57,945 [0x4247f940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,947 [0x42681940] [ERROR]: Error on processing query 1102006314026 on instance 14. Message: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026
2012-12-04 19:12:58,142 [0x4217c940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 9, queryID=1102006314026
2012-12-04 19:12:58,142 [0x4217c940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:13:05,365 [0x4207b940] [DEBUG]: Broadcast ABORT message to all instances for query 1102006314026
2012-12-04 19:13:05,365 [0x4207b940] [DEBUG]: Query::done: queryID=1102006314026, _commitState=0, erorCode=33
2012-12-04 19:13:05,365 [0x4207b940] [ERROR]: executeClientQuery failed to complete: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026
2012-12-04 19:13:05,365 [0x4207b940] [DEBUG]: Query (1102006314026) is being aborted
2012-12-04 19:13:05,365 [0x4207b940] [ERROR]: Query (1102006314026) error handlers (1) are being executed
2012-12-04 19:13:05,365 [0x4207b940] [DEBUG]: Update error handler is invoked for query (1102006314026)
2012-12-04 19:13:05,366 [0x42984940] [DEBUG]: Query (1102006314026) is being aborted
2012-12-04 19:13:05,366 [0x42984940] [DEBUG]: Deallocating query (1102006314026)
2012-12-04 19:13:05,368 [0x4207b940] [DEBUG]: UpdateErrorHandler::handleErrorOnCoordinator: the new version 1 of array result is being rolled back for query (1102006314026)
2012-12-04 19:13:05,372 [0x4207b940] [DEBUG]: End of log at position 251784 rc=104
2012-12-04 19:13:05,372 [0x4207b940] [DEBUG]: End of log at position 0 rc=0
2012-12-04 19:13:05,383 [0x4207b940] [DEBUG]: Free cluster 2200 query 1102006314026
2012-12-04 19:13:05,383 [0x4207b940] [DEBUG]: Free cluster 2400 query 1102006314026
2012-12-04 19:13:05,387 [0x4207b940] [DEBUG]: Releasing locks for query 1102006314026
2012-12-04 19:13:05,387 [0x4207b940] [DEBUG]: SystemCatalog::deleteArrayLocks instanceId = 0 queryId = 1102006314026
2012-12-04 19:13:05,387 [0x4207b940] [DEBUG]: Release lock of array raw@1 for query 1102006314026
2012-12-04 19:13:05,387 [0x4207b940] [DEBUG]: Release lock of array result for query 1102006314026
2012-12-04 19:13:05,387 [0x4207b940] [DEBUG]: Release lock of array result@1 for query 1102006314026
2012-12-04 19:13:05,388 [0x4207b940] [DEBUG]: Disconnected
2012-12-04 19:13:05,677 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:05,677 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:05,677 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 19
2012-12-04 19:13:05,677 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:05,784 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:05,784 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:05,784 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 11
2012-12-04 19:13:05,784 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:06,422 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:06,422 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:06,422 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 7
2012-12-04 19:13:06,422 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:06,629 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:06,629 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:06,629 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 5
2012-12-04 19:13:06,629 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:06,815 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:06,815 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:06,815 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 20
2012-12-04 19:13:06,815 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:07,424 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:07,425 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:07,425 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 10
2012-12-04 19:13:07,425 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:07,661 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:07,662 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:07,662 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 22
2012-12-04 19:13:07,662 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:07,999 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:07,999 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:07,999 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 17
2012-12-04 19:13:07,999 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:07,999 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:07,999 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:07,999 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 15
2012-12-04 19:13:07,999 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:08,035 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:08,035 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:08,035 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 12
2012-12-04 19:13:08,035 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:08,139 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:08,139 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:08,139 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 4
2012-12-04 19:13:08,139 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:08,149 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:08,149 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:08,149 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 16
2012-12-04 19:13:08,149 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:08,266 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:08,266 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:08,266 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 9
2012-12-04 19:13:08,266 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:09,741 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:09,741 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:09,741 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 6
2012-12-04 19:13:09,742 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:10,339 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:10,339 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:10,339 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 1
2012-12-04 19:13:10,339 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:12,482 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:12,482 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:12,482 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 13
2012-12-04 19:13:12,482 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:13,197 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:13,197 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:13,197 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 8
2012-12-04 19:13:13,197 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:13,555 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:13,555 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:13,555 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 3
2012-12-04 19:13:13,555 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:15,123 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:15,123 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:15,123 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 18
2012-12-04 19:13:15,123 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:15,124 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:15,124 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:15,124 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 21
2012-12-04 19:13:15,124 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 19:13:15,467 [0x2af0d18d1010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:15,467 [0x2af0d18d1010] [ERROR]: Exception in message handler: messageType = 12
2012-12-04 19:13:15,467 [0x2af0d18d1010] [ERROR]: Exception in message handler: source instance ID = instance 2
2012-12-04 19:13:15,467 [0x2af0d18d1010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026
2012-12-04 22:35:59,779 [0x2af0d18d1010] [DEBUG]: Waiting for the first message
2012-12-04 22:35:59,779 [0x2af0d18d1010] [DEBUG]: Connection started from CLIENT (127.0.0.1)

Here is the log file for instance 14:

2012-12-04 19:08:53,165 [0x2b0da5e45010] [DEBUG]: Allocating query (1102006314026)
2012-12-04 19:08:53,165 [0x2b0da5e45010] [DEBUG]: Number of allocated queries = 1
2012-12-04 19:08:53,165 [0x42a48940] [DEBUG]: Preparing physical plan: queryID=1102006314026, physicalPlan='22 serialization::archive 7 0 1 11 1 0
0 0 0 1 1 11
1 0 1 0 0 1 1 1 4 scan 12 physicalScan 0 0 1 1 0 1 2 1 0
2 1 0
3 1 0
4 1 0  3 raw -1 -1 1 18446744073709551615 0  0 0 25 5 raw@1 0 0 12 0 0 0 0 9 value_num 0 0 1 0 3 raw 6 double 1 0 0 0 0 0 0 0 0  0 0  1 9 value_min 1 0 3 raw 6 double 1 0 0 0 0 0 0  0 0  2 9 value_max 1 0 3 raw 6 double 1 0 0 0 0 0 0  0 0  3 13 value_display 1 0 3 raw 6 string 1 0 0 0 0 0 0  0 0  4 9 qualifier 1 0 3 raw 6 string 1 0 0 0 0 0 0  0 0  5 12 substance_id 1 0 3 raw 5 int64 0 0 10 8 -1 0 0 0 0 0 0 0 0 0 0  0 0  6 11 modified_by 1 0 3 raw 6 string 1 0 0 0 0 0 0  0 0  7 13 experiment_id 1 0 3 raw 5 int64 0 0 10 8 -1 0 0 0 0 0 0 0 0 0 0  0 0  8 10 project_id 1 0 3 raw 5 int64 1 0 0 0 0 0 0  0 0  9 15 rslt_context_id 1 0 3 raw 5 int64 1 0 0 0 0 0 0  0 0  10 8 assay_id 1 0 3 raw 5 int64 0 0 10 8 -1 0 0 0 0 0 0 0 0 0 0  0 0  11 8 EmptyTag 1 0 3 raw 9 indicator 2 0 10 1 -1 0 0 0  0 0  0 0 1 0 0 0 0 0 4 line 0 0 1 0 0 0 4 line 1 0 3 raw 0 0 155594432 155594432 100000 0 5 int64 0 0  0  1 0 1 0 0  0 0 0 1 1 17 redimension_store 17 PhysicalFlipStore 1 1 2d about ready for physical plan running
5
6
7 1 0  6 result -1 -1 0 0 0  0 8 result@1 9 0 0 9 value_num 0 0 6 double 1 0 0 0 0 0 0  0 0  1 9 value_min 0 0 6 double 1 0 0 0 0 0 0  0 0  2 9 value_max 0 0 6 double 1 0 0 0 0 0 0  0 0  3 13 value_display 0 0 6 string 1 0 0 0 0 0 0  0 0  4 9 qualifier 0 0 6 string 1 0 0 0 0 0 0  0 0  5 11 modified_by 0 0 6 string 1 0 0 0 0 0 0  0 0  6 10 project_id 0 0 5 int64 1 0 0 0 0 0 0  0 0  7 15 rslt_context_id 0 0 5 int64 1 0 0 0 0 0 0  0 0  8 8 EmptyTag 0 0 9 indicator 2 0 10 1 -1 0 0 0  0 0  3 0 12 substance_id 1 0 12 substance_id 0 0 842122 4611686018427387903 -4611686018427387903 125307028 250000 0 5 int64 0 21 NID_39@1:substance_id 0  1 0 1 13 experiment_id 1 0 13 experiment_id 0 0 18 4611686018427387903 -4611686018427387903 4573 1 0 5 int64 0 22 NID_39@1:experiment_id 0  1 0 1 8 assay_id 1 0 8 assay_id 0 0 20 4611686018427387903 -4611686018427387903 4578 1 0 5 int64 0 17 NID_39@1:assay_id 0  1 0 1 0 0 ':43:56,994 [0x42644940] [DEBUG]: SystemCatalog::lockArray: Lock: arrayName=result, arrayId=0, queryId=1101960142528, instanceId=14, instanceRole=WORKER, lockMode=2, arrayVersion=1, arrayVersionId=0, timestamp=853
2012-12-04 19:08:53,165 [0x42a48940] [DEBUG]: Initialized query (1102006314026)
2012-12-04 19:08:53,166 [0x42a48940] [DEBUG]: Physical plan was parsed
2012-12-04 19:08:53,166 [0x42a48940] [DEBUG]: Coordinator is notified about ready for physical plan running
2012-12-04 19:08:53,168 [0x41e3c940] [DEBUG]: Running physical plan: queryID=1102006314026
2012-12-04 19:08:53,168 [0x41e3c940] [INFO ]: Executing query(1102006314026): 
2012-12-04 19:08:53,171 [0x41e3c940] [DEBUG]: Request shared lock of array raw@1 for query 1102006314026
2012-12-04 19:08:53,171 [0x41e3c940] [DEBUG]: Granted shared lock of array raw@1 for query 1102006314026
2012-12-04 19:08:53,171 [0x41e3c940] [DEBUG]: Request exclusive lock of array result for query 1102006314026
2012-12-04 19:08:53,171 [0x41e3c940] [DEBUG]: Granted exclusive lock of array result for query 1102006314026
4
2012-12-04 19:08:53,176 [0x41e3c940] [DEBUG]: Request shared lock of array result@1 for query 1102006314026
2012-12-04 19:08:53,176 [0x41e3c940] [DEBUG]: Granted shared lock of array result@1 for query 1102006314026
2012-12-04 19:09:01,252 [0x41e3c940] [DEBUG]: Time for building coordinate indices: 8 seconds
2012-12-04 19:09:52,894 [0x41e3c940] [DEBUG]: Failed pwrite call fd 58 src 46912681720576 size 417792 offs 231317504 rc -1 errno 28
2012-12-04 19:09:52,894 [0x41e3c940] [DEBUG]: Partial sort time: 51 seconds
2012-12-04 19:09:52,941 [0x41e3c940] [DEBUG]: Time for exchanging chunk map: 0 seconds
2012-12-04 19:12:57,202 [0x41e3c940] [ERROR]: Query ID=1102006314026 encountered the error: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026
2012-12-04 19:12:57,202 [0x41e3c940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 3, sourceInstance = 0, queryID=1102006314026
2012-12-04 19:12:57,202 [0x41e3c940] [DEBUG]: Execution of query 1102006314026 is aborted on worker
2012-12-04 19:12:57,202 [0x41e3c940] [DEBUG]: Query::done: queryID=1102006314026, _commitState=0, erorCode=33
2012-12-04 19:12:57,732 [0x42d4b940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 4, queryID=1102006314026
2012-12-04 19:12:57,732 [0x42d4b940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,751 [0x42240940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 15, queryID=1102006314026
2012-12-04 19:12:57,751 [0x42240940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:12:57,947 [0x42745940] [ERROR]: Error occurred in message handler: SystemException in file: src/query/ops/flip_store/PhysicalFlipStore.cpp function: transformArray line: 887
Error id: scidb::SCIDB_SE_IO::SCIDB_LE_OPERATION_FAILED
Error description: I/O error. Operation 'read' failed.
Failed query id: 1102006314026, messageType = 20, sourceInstance = 16, queryID=1102006314026
2012-12-04 19:12:57,947 [0x42745940] [DEBUG]: Handle error for query 1102006314026
2012-12-04 19:13:05,366 [0x42c4a940] [DEBUG]: Query (1102006314026) is being aborted
2012-12-04 19:13:05,366 [0x42c4a940] [ERROR]: Query (1102006314026) error handlers (1) are being executed
2012-12-04 19:13:05,366 [0x42c4a940] [DEBUG]: Update error handler is invoked for query (1102006314026)
2012-12-04 19:13:05,371 [0x42c4a940] [DEBUG]: End of log at position 255216 rc=104
2012-12-04 19:13:05,371 [0x42c4a940] [DEBUG]: End of log at position 0 rc=0
2012-12-04 19:13:05,383 [0x42c4a940] [DEBUG]: Free cluster 2200 query 1102006314026
2012-12-04 19:13:05,383 [0x42c4a940] [DEBUG]: Free cluster 2300 query 1102006314026
2012-12-04 19:13:05,385 [0x42c4a940] [DEBUG]: Deallocating query (1102006314026)
=1654
2012-12-04 19:13:05,386 [0x42c4a940] [DEBUG]: Release lock of array raw@1 for query 1102006314026
2012-12-04 19:13:05,386 [0x42c4a940] [DEBUG]: Release lock of array result for query 1102006314026
2012-12-04 19:13:05,386 [0x42c4a940] [DEBUG]: Release lock of array result@1 for query 1102006314026
2012-12-04 19:13:05,388 [0x2b0da5e45010] [DEBUG]: Query 1102006314026 is not found
2012-12-04 19:13:05,388 [0x2b0da5e45010] [ERROR]: Exception in message handler: messageType = 25
2012-12-04 19:13:05,388 [0x2b0da5e45010] [ERROR]: Exception in message handler: source instance ID = instance 0
2012-12-04 19:13:05,388 [0x2b0da5e45010] [ERROR]: Exception in message handler: SystemException in file: src/query/Query.cpp function: getQueryByID line: 767
Error id: scidb::SCIDB_SE_QPROC::SCIDB_LE_QUERY_NOT_FOUND
Error description: Query processor error. Query 1102006314026 not found.
Failed query id: 1102006314026

#2

Hi Dave!

Looks like the first failure is here

2012-12-04 19:09:00,781 [0x4207b940] [DEBUG]: Time for building coordinate indices: 7 seconds
2012-12-04 19:09:52,894 [0x4207b940] [DEBUG]: Failed pwrite call fd 59 src 46912943252544 size 294912 offs 257654784 rc -1 errno 28

errno 28 is “no space left on device”. Check the size of the temp partition (SciDB config variable tmp-path)? Could that be set to a partition of limited size…?


#3

Thanks for the quick response. I checked df and nothing was full - all the local drives in fact were at 25% use. I checked config.ini and the command used to start the system and it appears we have not specified tmp-path - does it default to /tmp?

Thanks,
Dave


#4

When you start scidb, it dumps the whole configuration to scidb.log. Take a look there to be absolutely sure.


#5

Thanks, I checked and it reports
tmp-dir : /tmp

I ran the query and while it was running monitored the contents of /tmp, and used df to monitor the filesystem

df showed the 8 GB of available space on the filesystem being used up as the query progressed so that confirms your diagnosis. However, I did not see any additional additional files or any changes to the sizes of the files in /tmp

I subsequently used
du -hs

to monitor /tmp, and also the install directory for SciDB /opt/scidb/12.3 - no change observed

So I’m not sure how to fix the problem - unless /tmp is being written to and I’m not detecting it - providing more space to /tmp will appear to solve the problem.

Thanks,
Dave


#6

We remounted /tmp to a much larger file system - that solved the problem - thank you.

I’m still wondering why there was no file reported in /tmp and none of the existing files in /tmp changed size. Seems like there is something funny going on with the OS

FYI, the raw array had ~150 million rows, 10 attributes (about half are null on average) - about 9 G in the original csv file. The operation peaked at using 17.4 G of space on the file system, based on df

edit: forgot to mention - definitely our mistake for putting /tmp on the small, root file system! Thank you again for troubleshooting the problem.


#7

Dave,

When SciDB creates temporary files, it “unlinks” them right after creation. So the files are in a special state where they will be removed as soon as SciDB decides to close them. The benefit is that temp files are not left laying around - they are removed as soon as possible, even in case the SciDB process dies unexpectedly. The drawback is that you don’t see these files :smile:. They may show up under a more low-level tool like “lsof” maybe.

Is there a more user-friendly way to do this? I’ll think about it…


#8

Thanks for the explanation! I like the idea of removing them as soon as possible. I guess the idea is that if you did it with a “regular” file process, if the system crashes it won’t be around to delete the file. Kind of a neat way to fix that.

One suggestion for the user friendliness: You could touch an empty file whose name explains what is going on (or the file contains text further explaining the process):
scidb_is_using_an_invisible_temp_file_README.txt

that you delete if it finishes - and if that one doesn’t get deleted there is no harm since it is so small (< 1 K)

Thanks again for the explanation,
Dave