Crash: failed to update store after merging range: IO error: Failed to remove dir #37315
Labels
A-kv
Anything in KV that doesn't belong in a more specific category.
B-os-windows
Issues specific to the Windows OS.
C-bug
Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior.
O-community
Originated from the community
Comments
|
Hi @Little-Pan , How have you started the cockroach process? Does the user that started the process have permissions to delete |
|
@tim-o On windows 8.1 x86 OS, start the cockroach by executing the command "cockroach.exe start --insecure --store node-1" in windows cmd.exe, then the cockroach process automaticly creates the node-1 directory. |
|
Hello @Little-Pan I ended up loading up a Windows 8.1 VM and attempted the same steps as you performed. I loaded a single instance, created a database and then attempted the SQL batch delete mentioned, but the node remained running and online after the transaction completed. The SQL itself is unclear, can you send me the schema and the batch delete ... insert attempted so I can try something closer to what you were doing? Let me know if you have any other questions. Cheers, |
|
@ricardocrdb Use a single thread as default in this test case. The table schema definitioncreate table accounts (
id int not null primary key,
name varchar(20) not null,
balance decimal(12, 2) not null
);The test casepublic class BatchInserter
{
// config
final static int BATCH_SIZE = 1000;
final static int ROWS = 100000000;
//final static String JDBC_DRIVER = "org.apache.derby.jdbc.ClientDriver";
//final static String JDBC_DRIVER = "org.postgresql.Driver";
//final static String JDBC_DRIVER = "com.mysql.jdbc.Driver";
//final static String JDBC_DRIVER = "org.h2.Driver";
//final static String JDBC_DRIVER = "org.hsqldb.jdbcDriver";
//final static String JDBC_DRIVER = "org.hsqldb.jdbcDriver";
final static String JDBC_USER = "root";
final static String JDBC_PASS = "";
//final static String JDBC_URL = "jdbc:crate://localhost:5433/";
//final static String JDBC_URL = "jdbc:hsqldb:hsql://localhost/test";
//final static String JDBC_URL = "jdbc:sqlite:D:/project/Database/SQLite/sqlite-web/sqliteweb-go/test.db";
//final static String JDBC_URL = "jdbc:sqlite:D:/project/Database/SQLite/data/test.db";
//final static String JDBC_URL = "jdbc:derby://localhost/test";
//final static String JDBC_URL = "jdbc:postgresql://192.168.145.101:5433/postgres";
final static String JDBC_URL = "jdbc:postgresql://192.168.145.101:26257/bank";
//final static String JDBC_URL = "jdbc:mysql://127.0.0.1:3306/test?useSSL=false&useUnicode=true&characterEncoding=utf-8";
//final static String JDBC_URL = "jdbc:h2:tcp://localhost/test";
//final static String JDBC_URL = "jdbc:ignite:thin://127.0.0.1/";
//final static String JDBC_URL = "jdbc:herddb:server:localhost:7000";
//final static String JDBC_URL = "jdbc:firebirdsql://localhost/bank?charSet=utf-8";
// query
final static String DEL_BY_ID = "delete from accounts where id=?";
final static String QUE_INSERT = "insert into accounts(id, balance, name)values(?,?,?)";
//final static String QUE_UPDATE = "update accounts set balance=balance+1 where id=?";
public static void main(String [] args)throws Exception {
final long ts = System.currentTimeMillis();
int rows = ROWS, bsize = BATCH_SIZE, startc = 0, threads = 1;
for(int i = 0, size = args.length; i < size; ++i){
final int param = Integer.parseInt(args[i]);
switch(i){
case 0:
rows = param;
if(rows < 0){
rows = ROWS;
}
break;
case 1:
bsize = param;
if(bsize < 0){
bsize = BATCH_SIZE;
}
break;
case 2:
startc = param;
if(startc < 0){
startc = 0;
}
break;
case 3:
threads = param;
if(threads < 1){
threads = 1;
}
log("threads = " + threads);
break;
default:
break;
}
}
if(threads == 1){
doInsert(rows, bsize, startc);
}else{
final int r = rows, b = bsize , s = startc;
final Thread[] inserters = new Thread[threads];
for(int i = 0; i < threads; ++i){
final Thread inserter = new Thread(()->{
doInsert(r, b, s);
}, "inserter-"+i);
inserter.start();
inserters[i] = inserter;
}
for(int i = 0; i < threads; ++i){
final Thread inserter = inserters[i];
inserter.join();
}
}
log(String.format("rows: %d, time: %dms", rows, (System.currentTimeMillis()-ts)));
}
static void doInsert(int rows, int bsize, int startc){
Connection conn = null;
try{
PreparedStatement delById = null, queInsert = null;
// do-query
for(int i = startc, size = rows + startc, e = size-1; i < size; ++i){
final long lastm = System.currentTimeMillis();
if(conn == null){
ConnResult res = getConnection();
conn = res.conn;
delById = res.delById;
queInsert = res.queInsert;
}
//delById.clearParameters();
delById.setInt(1, i);
//delById.executeUpdate();
delById.addBatch();
queInsert.setInt(1, i);
//queInsert.setBigDecimal(2, java.math.BigDecimal.ZERO);
queInsert.setDouble(2, i%100000);
queInsert.setString(3, "账号-"+i);
queInsert.addBatch();
if((i%bsize) == 0 || i == e){
delById.executeBatch();
delById.clearBatch();
queInsert.executeBatch();
queInsert.clearBatch();
conn.commit();
releaseConnection(conn);
conn = null;
}
if((i%100000) == 0){
log("i = " + i);
}
}
//
}catch(SQLException cause){
if(cause.getNextException() != null){
cause = cause.getNextException();
}
if(conn != null){
try{
conn.rollback();
}catch(SQLException e){}
}
cause.printStackTrace();
}finally{
if(conn != null){
releaseConnection(conn, true);
}
}
}
static void log(final String message){
final String threadName = Thread.currentThread().getName();
final DateFormat df = new SimpleDateFormat("HH:mm:ss.SSS");
System.out.println(String.format("%s[%s] %s",
df.format(new java.util.Date()), threadName, message));
}
static void releaseConnection(Connection conn){
releaseConnection(conn, false);
}
static void releaseConnection(Connection conn, boolean close){
if(close){
try{
conn.close();
}catch(SQLException e){}
connResult = null;
}
connSem.release();
}
static ConnResult getConnection()throws SQLException {
try{
if(!connSem.tryAcquire(30000L, TimeUnit.SECONDS)){
throw new SQLException("Get connection timeout");
}
}catch(final InterruptedException e){
Thread.currentThread().interrupt();
throw new RuntimeException("Interrupted");
}
boolean failed = true;
Connection conn = null;
try{
// connect
if(connResult != null){
failed = false;
return connResult;
}
if(JDBC_URL.startsWith("jdbc:sqlite:")){
conn = DriverManager.getConnection(JDBC_URL);
}else{
conn = DriverManager.getConnection(JDBC_URL, JDBC_USER, JDBC_PASS);
}
Statement stmt = conn.createStatement();
try{
if(JDBC_URL.startsWith("jdbc:crate:")){
stmt.executeUpdate("create table if not exists accounts(" +
"id bigint not null primary key, balance double, name string not null)");
}else if(JDBC_URL.startsWith("jdbc:sqlite:")){
//stmt.executeUpdate("pragma journal_mode = delete;"); // wal
//stmt.executeUpdate("pragma synchronous = on;"); // off
//stmt.executeUpdate("pragma busy_timeout = 30000;");
} else if(JDBC_URL.startsWith("jdbc:hsqldb:")){
stmt.executeUpdate("create cached table if not exists accounts(" +
"id int not null primary key, balance decimal(12, 2), name varchar(20))");
}else if(JDBC_URL.startsWith("jdbc:derby:")){
// pass
}else if(!JDBC_URL.startsWith("jdbc:firebirdsql:")){
stmt.executeUpdate("create table if not exists accounts(" +
"id int not null primary key, balance decimal(12, 2), name varchar(20))");
}
}catch(SQLException e){
e.printStackTrace();
}
conn.setAutoCommit(false);
stmt.close();
final PreparedStatement delById = conn.prepareStatement(DEL_BY_ID);
final PreparedStatement queInsert = conn.prepareStatement(QUE_INSERT);
connResult = new ConnResult(conn, delById, queInsert);
failed = false;
return connResult;
}finally{
if(failed){
connSem.release();
if(conn != null){
conn.close();
conn = null;
}
}
}
}
static final Semaphore connSem = new Semaphore(1);
static ConnResult connResult;
static class ConnResult
{
Connection conn;
PreparedStatement delById;
PreparedStatement queInsert;
public ConnResult(Connection conn,
PreparedStatement delById,
PreparedStatement queInsert){
this.conn = conn;
this.delById = delById;
this.queInsert = queInsert;
}
}
} |
|
Hey @Little-Pan I have tried numerous times to reproduce the issue on my Windows box, but everything I have tried has worked successfully and the crash did not occur. In reviewing this issue with another engineer, we at this point would like to get an idea of the directory tree structure under the D:\project\Database\cluster\cockroach\cockroach-v19.1.0\node-1\auxiliary\sideloading path on your machine. You can do this by running Let me know if there are any other questions. Cheers, |
|
Hey @Little-Pan Did you have a chance to get that output that was requested? Let me know if possible if you can update the thread. Cheers, |
|
@ricardocrdb It's a strange thing that no any sub directory or file exists in the directory D:\project\Database\cluster\cockroach\cockroach-v19.1.0\node-1\auxiliary\ |
|
Hello @Little-Pan Interesting that it isn't there now, as the errors we were getting were: This indicates that the process had an issue requesting access from the OS, either usually due to permissions or if the files are missing. In this case, it seems like our process was expecting some files to be there, but was unable to access them, as you reported the directory is empty. Can you try replicating this issue on your machine, but designating a different Let me know your findings, and if you have any other questions, feel free to ask. Cheers, |
|
Hi @ricardocrdb I have replicated this issue yesterday by removing the whole data store directory node-1 and creating a new database. |
|
Hey @Little-Pan OK, so essentially just replacing the store got it so you could replicate the issue on your machine. Did you manage to get the Let me know if you can pass that along, and if you have any other questions. Cheers, |
|
Hey @Little-Pan Did you have the output of Cheers, |
|
No sideloading directory, give you the logs: I190531 04:52:51.955712 1 util/log/clog.go:1199 [config] file created at: 2019/05/31 04:52:51
I190531 04:52:51.955712 1 util/log/clog.go:1199 [config] running on machine: zpp-mh
I190531 04:52:51.955712 1 util/log/clog.go:1199 [config] binary: CockroachDB CCL v19.1.0 (x86_64-w64-mingw32, built 2019/04/29 18:46:21, go1.11.6)
I190531 04:52:51.955712 1 util/log/clog.go:1199 [config] arguments: [cockroach start --insecure --store=node-1]
I190531 04:52:51.955712 1 util/log/clog.go:1199 line format: [IWEF]yymmdd hh:mm:ss.uuuuuu goid file:line msg utf8=✓
I190531 04:52:51.955710 1 cli/start.go:1033 logging to directory D:\project\Database\cluster\cockroach\cockroach-v19.1.0\node-1\logs
W190531 04:52:51.956443 1 cli/start.go:1068 RUNNING IN INSECURE MODE!
- Your cluster is open for any client that can access <all your IP addresses>.
- Any user, even root, can log in without providing a password.
- Any user, connecting as root, can read or write any data in your cluster.
- There is no network encryption nor authentication, and thus no confidentiality.
Check out how to secure your cluster: https://www.cockroachlabs.com/docs/v19.1/secure-a-cluster.html
W190531 04:52:51.961724 1 cli/start.go:944 Using the default setting for --cache (128 MiB).
A significantly larger value is usually needed for good performance.
If you have a dedicated server a reasonable setting is --cache=.25 (2.0 GiB).
W190531 04:52:51.961748 1 cli/start.go:957 Using the default setting for --max-sql-memory (128 MiB).
A significantly larger value is usually needed in production.
If you have a dedicated server a reasonable setting is --max-sql-memory=.25 (2.0 GiB).
I190531 04:52:51.961760 1 cli/start.go:1082 CockroachDB CCL v19.1.0 (x86_64-w64-mingw32, built 2019/04/29 18:46:21, go1.11.6)
I190531 04:52:52.062790 1 server/config.go:386 system total memory: 7.9 GiB
I190531 04:52:52.062911 1 server/config.go:388 server configuration:
max offset 500000000
cache size 128 MiB
SQL memory pool size 128 MiB
scan interval 10m0s
scan min idle time 10ms
scan max idle time 1s
event log enabled true
I190531 04:52:52.063005 1 cli/start.go:929 process identity: uid S-1-5-21-2795185149-2501962249-866320209-1001, gid S-1-5-21-2795185149-2501962249-866320209-513
I190531 04:52:52.063045 1 cli/start.go:554 starting cockroach node
I190531 04:52:52.081194 53 storage/engine/rocksdb.go:613 opening rocksdb instance at "D:\\project\\Database\\cluster\\cockroach\\cockroach-v19.1.0\\node-1\\cockroach-temp837623479"
I190531 04:52:52.426054 53 server/server.go:876 [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled
I190531 04:52:52.428767 53 storage/engine/rocksdb.go:613 opening rocksdb instance at "D:\\project\\Database\\cluster\\cockroach\\cockroach-v19.1.0\\node-1"
I190531 04:52:52.456726 53 server/config.go:494 [n?] 1 storage engine initialized
I190531 04:52:52.456745 53 server/config.go:497 [n?] RocksDB cache size: 128 MiB
I190531 04:52:52.456753 53 server/config.go:497 [n?] store 0: RocksDB, max size 0 B, max open file limit 10000
W190531 04:52:52.457965 53 cli/start.go:896 neither --listen-addr nor --advertise-addr was specified.
The server will advertise "zpp-mh" to other nodes, is this routable?
Consider using:
- for local-only servers: --listen-addr=localhost
- for multi-node clusters: --advertise-addr=<host/IP addr>
I190531 04:52:52.550222 53 util/stop/stopper.go:546 [n?] quiescing; tasks left:
1 [async] intent_resolver_ir_batcher
1 [async] intent_resolver_gc_batcher
I190531 04:52:52.550365 53 server/node.go:358 [n?] **** cluster ad4f6217-b7ce-484f-a610-54a2a4751cbe has been created
I190531 04:52:52.550393 53 server/server.go:1422 [n?] **** add additional nodes by specifying --join=zpp-mh:26257
I190531 04:52:52.550754 53 gossip/gossip.go:392 [n1] NodeDescriptor set to node_id:1 address:<network_field:"tcp" address_field:"zpp-mh:26257" > attrs:<> locality:<> ServerVersion:<major_val:19 minor_val:1 patch:0 unstable:0 > build_tag:"v19.1.0" started_at:1559278372550550000
W190531 04:52:52.562527 176 storage/store.go:1525 [n1,s1,r6/1:/Table/{SystemCon…-11}] could not gossip system config: [NotLeaseHolderError] r6: replica (n1,s1):1 not lease holder; lease holder unknown
I190531 04:52:52.563604 53 server/node.go:461 [n1] initialized store [n1,s1]: disk (capacity=350 GiB, available=37 GiB, used=29 KiB, logicalBytes=8.3 KiB), ranges=20, leases=0, queries=0.00, writes=0.00, bytesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=887.00 pMax=7467.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00 pMax=0.00}
I190531 04:52:52.563716 53 storage/stores.go:244 [n1] read 0 node addresses from persistent storage
I190531 04:52:52.568647 53 server/node.go:699 [n1] connecting to gossip network to verify cluster ID...
I190531 04:52:52.568685 53 server/node.go:719 [n1] node connected via gossip and verified as part of cluster "ad4f6217-b7ce-484f-a610-54a2a4751cbe"
I190531 04:52:52.568943 53 server/node.go:542 [n1] node=1: started with [<no-attributes>=D:\project\Database\cluster\cockroach\cockroach-v19.1.0\node-1] engine(s) and attributes []
I190531 04:52:52.569926 53 server/server.go:1582 [n1] starting http server at [::]:8080 (use: zpp-mh:8080)
I190531 04:52:52.569967 53 server/server.go:1584 [n1] starting grpc/postgres server at [::]:26257
I190531 04:52:52.569997 53 server/server.go:1585 [n1] advertising CockroachDB node at zpp-mh:26257
W190531 04:52:52.570087 53 jobs/registry.go:341 [n1] unable to get node liveness: node not in the liveness table
I190531 04:52:52.651193 217 sql/event_log.go:135 [n1,intExec=optInToDiagnosticsStatReporting] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:root}
I190531 04:52:52.681804 201 sql/event_log.go:135 [n1,intExec=set-setting] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:19.1 User:root}
I190531 04:52:52.700916 223 sql/event_log.go:135 [n1,intExec=disableNetTrace] Event: "set_cluster_setting", target: 0, info: {SettingName:trace.debug.enable Value:false User:root}
I190531 04:52:52.770789 281 sql/event_log.go:135 [n1,intExec=initializeClusterSecret] Event: "set_cluster_setting", target: 0, info: {SettingName:cluster.secret Value:b2f71b13-9ae9-4199-a975-8adb2d7c9b46 User:root}
I190531 04:52:52.802246 287 sql/event_log.go:135 [n1,intExec=create-default-db] Event: "create_database", target: 50, info: {DatabaseName:defaultdb Statement:CREATE DATABASE IF NOT EXISTS defaultdb User:root}
I190531 04:52:52.819999 289 sql/event_log.go:135 [n1,intExec=create-default-db] Event: "create_database", target: 51, info: {DatabaseName:postgres Statement:CREATE DATABASE IF NOT EXISTS postgres User:root}
I190531 04:52:52.861141 53 server/server.go:1650 [n1] done ensuring all necessary migrations have run
I190531 04:52:52.861165 53 server/server.go:1653 [n1] serving sql connections
I190531 04:52:52.861371 53 cli/start.go:689 [config] clusterID: ad4f6217-b7ce-484f-a610-54a2a4751cbe
I190531 04:52:52.861419 53 cli/start.go:697 node startup completed:
CockroachDB node starting at 2019-05-31 04:52:52.8612693 +0000 UTC (took 0.9s)
build: CCL v19.1.0 @ 2019/04/29 18:46:21 (go1.11.6)
webui: http://zpp-mh:8080
sql: postgresql://root@zpp-mh:26257?sslmode=disable
client flags: cockroach <client cmd> --host=zpp-mh:26257 --insecure
logs: D:\project\Database\cluster\cockroach\cockroach-v19.1.0\node-1\logs
temp dir: D:\project\Database\cluster\cockroach\cockroach-v19.1.0\node-1\cockroach-temp837623479
external I/O path: D:\project\Database\cluster\cockroach\cockroach-v19.1.0\node-1\extern
store[0]: path=D:\project\Database\cluster\cockroach\cockroach-v19.1.0\node-1
status: initialized new cluster
clusterID: ad4f6217-b7ce-484f-a610-54a2a4751cbe
nodeID: 1
I190531 04:52:52.865994 267 server/server_update.go:67 [n1] no need to upgrade, cluster already at the newest version
I190531 04:52:52.878674 270 sql/event_log.go:135 [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:zpp-mh:26257 Attrs: Locality: ServerVersion:19.1 BuildTag:v19.1.0 StartedAt:1559278372550550000 LocalityAddress:[] XXX_NoUnkeyedLiteral:{} XXX_sizecache:0} ClusterID:ad4f6217-b7ce-484f-a610-54a2a4751cbe StartedAt:1559278372550550000 LastUp:1559278372550550000}
I190531 04:52:54.148752 101 gossip/gossip.go:1510 [n1] node has connected to cluster via gossip
I190531 04:52:54.148877 101 storage/stores.go:263 [n1] wrote 0 node addresses to persistent storage
I190531 04:52:56.099685 272 server/updates.go:266 [n1] A new version is available: 19.1.1, details: https://www.cockroachlabs.com/docs/releases/v19.1.1.html
W190531 04:53:02.570149 189 server/status/runtime.go:423 [n1] unable to get file descriptor usage (will not try again): not implemented on windows
I190531 04:53:02.571402 184 storage/store.go:4220 [n1,s1] sstables (read amplification = 0):
I190531 04:53:02.571657 184 storage/store.go:4221 [n1,s1]
** Compaction Stats [default] **
Level Files Size Score Read(GB) Rn(GB) Rnp1(GB) Write(GB) Wnew(GB) Moved(GB) W-Amp Rd(MB/s) Wr(MB/s) Comp(sec) Comp(cnt) Avg(sec) KeyIn KeyDrop
----------------------------------------------------------------------------------------------------------------------------------------------------------
Sum 0/0 0.00 KB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0
Int 0/0 0.00 KB 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0 0 0.000 0 0
Uptime(secs): 10.1 total, 10.1 interval
Flush(GB): cumulative 0.000, interval 0.000
AddFile(GB): cumulative 0.000, interval 0.000
AddFile(Total Files): cumulative 0, interval 0
AddFile(L0 Files): cumulative 0, interval 0
AddFile(Keys): cumulative 0, interval 0
Cumulative compaction: 0.00 GB write, 0.00 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.0 seconds
Interval compaction: 0.00 GB write, 0.00 MB/s write, 0.00 GB read, 0.00 MB/s read, 0.0 seconds
Stalls(count): 0 level0_slowdown, 0 level0_slowdown_with_compaction, 0 level0_numfiles, 0 level0_numfiles_with_compaction, 0 stop for pending_compaction_bytes, 0 slowdown for pending_compaction_bytes, 0 memtable_compaction, 0 memtable_slowdown, interval 0 total count
estimated_pending_compaction_bytes: 0 B
I190531 04:53:02.863340 189 server/status/runtime.go:500 [n1] runtime stats: 88 MiB RSS, 142 goroutines, 155 MiB/3.9 MiB/172 MiB GO alloc/idle/total, 15 MiB/18 MiB CGO alloc/total, 0.0 CGO/sec, 0.0/0.0 %(u/s)time, 0.0 %gc (10x), 9.2 KiB/12 KiB (r/w)net
I190531 04:53:09.602520 469 storage/replica_consistency.go:198 [n1,consistencyChecker,s1,r4/1:/System{/tsd-tse}] triggering stats recomputation to resolve delta of {ContainsEstimates:true LastUpdateNanos:1559278382632933900 IntentAge:0 GCBytesAge:0 LiveBytes:-6435 LiveCount:-591 KeyBytes:-28476 KeyCount:-591 ValBytes:22041 ValCount:-591 IntentBytes:0 IntentCount:0 SysBytes:0 SysCount:0 XXX_NoUnkeyedLiteral:{} XXX_sizecache:0}
I190531 04:53:13.177835 189 server/status/runtime.go:500 [n1] runtime stats: 102 MiB RSS, 143 goroutines, 162 MiB/784 KiB/176 MiB GO alloc/idle/total, 15 MiB/18 MiB CGO alloc/total, 594.5 CGO/sec, 2.1/0.3 %(u/s)time, 0.0 %gc (0x), 2.3 KiB/705 B (r/w)net
I190531 04:53:15.517102 472 sql/event_log.go:135 [n1,client=[::1]:63306,user=root] Event: "create_database", target: 52, info: {DatabaseName:bank Statement:CREATE DATABASE bank User:root}
I190531 04:53:23.480324 189 server/status/runtime.go:500 [n1] runtime stats: 109 MiB RSS, 144 goroutines, 169 MiB/2.3 MiB/184 MiB GO alloc/idle/total, 16 MiB/18 MiB CGO alloc/total, 234.6 CGO/sec, 1.2/0.2 %(u/s)time, 0.0 %gc (0x), 3.6 KiB/907 B (r/w)net
I190531 04:53:26.948293 472 sql/event_log.go:135 [n1,client=[::1]:63306,user=root] Event: "create_table", target: 53, info: {TableName:defaultdb.public.accounts Statement:CREATE TABLE accounts (id INT8 NOT NULL PRIMARY KEY, balance DECIMAL(12,2), name VARCHAR(20)) User:root}
I190531 04:53:26.951473 506 storage/replica_command.go:247 [n1,split,s1,r20/1:/{Table/24-Max}] initiating a split of this range at key /Table/53 [r21] (zone config)
I190531 04:53:33.809237 189 server/status/runtime.go:500 [n1] runtime stats: 116 MiB RSS, 143 goroutines, 176 MiB/3.5 MiB/193 MiB GO alloc/idle/total, 16 MiB/19 MiB CGO alloc/total, 326.6 CGO/sec, 1.2/0.0 %(u/s)time, 0.0 %gc (0x), 6.0 KiB/651 B (r/w)net
I190531 04:53:44.131248 189 server/status/runtime.go:500 [n1] runtime stats: 122 MiB RSS, 143 goroutines, 182 MiB/1.4 MiB/197 MiB GO alloc/idle/total, 16 MiB/19 MiB CGO alloc/total, 179.6 CGO/sec, 1.4/0.6 %(u/s)time, 0.0 %gc (0x), 25 KiB/2.5 KiB (r/w)net
I190531 04:53:47.671761 566 sql/event_log.go:135 [n1,client=192.168.145.1:63319,user=root] Event: "create_table", target: 54, info: {TableName:bank.public.accounts Statement:CREATE TABLE IF NOT EXISTS accounts (id INT8 NOT NULL PRIMARY KEY, balance DECIMAL(12,2), name VARCHAR(20)) User:root}
I190531 04:53:47.672029 568 storage/replica_command.go:247 [n1,split,s1,r21/1:/{Table/53-Max}] initiating a split of this range at key /Table/54 [r22] (zone config)
I190531 04:53:52.572160 185 gossip/gossip.go:557 [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
gossip connectivity
n1 [sentinel];
I190531 04:53:54.443073 189 server/status/runtime.go:500 [n1] runtime stats: 130 MiB RSS, 142 goroutines, 189 MiB/2.0 MiB/205 MiB GO alloc/idle/total, 16 MiB/20 MiB CGO alloc/total, 380.3 CGO/sec, 1.1/0.4 %(u/s)time, 0.0 %gc (0x), 3.5 KiB/717 B (r/w)net
I190531 04:54:04.715265 189 server/status/runtime.go:500 [n1] runtime stats: 137 MiB RSS, 144 goroutines, 195 MiB/3.5 MiB/214 MiB GO alloc/idle/total, 16 MiB/20 MiB CGO alloc/total, 192.0 CGO/sec, 0.6/0.2 %(u/s)time, 0.0 %gc (0x), 12 KiB/6.2 KiB (r/w)net
I190531 04:54:09.600871 614 sql/lease.go:352 [n1,client=[::1]:63325,user=root] publish: descID=54 (accounts) version=2 mtime=2019-05-31 04:54:09.5918623 +0000 UTC
I190531 04:54:09.609329 614 sql/event_log.go:135 [n1,client=[::1]:63325,user=root] Event: "drop_table", target: 54, info: {TableName:bank.public.accounts Statement:DROP TABLE accounts User:root CascadeDroppedViews:[]}
I190531 04:54:09.611159 614 sql/lease.go:324 publish (1 leases): desc=[{accounts 54 1}]
I190531 04:54:09.664097 614 sql/lease.go:352 [n1,client=[::1]:63325,user=root,scExec] publish: descID=54 (accounts) version=3 mtime=2019-05-31 04:54:09.6637266 +0000 UTC
I190531 04:54:15.033070 189 server/status/runtime.go:500 [n1] runtime stats: 147 MiB RSS, 144 goroutines, 204 MiB/3.0 MiB/222 MiB GO alloc/idle/total, 17 MiB/20 MiB CGO alloc/total, 441.5 CGO/sec, 1.5/0.2 %(u/s)time, 0.0 %gc (0x), 4.1 KiB/980 B (r/w)net
I190531 04:54:17.025956 614 sql/event_log.go:135 [n1,client=[::1]:63325,user=root] Event: "create_table", target: 55, info: {TableName:bank.public.accounts Statement:CREATE TABLE accounts (id INT8 NOT NULL PRIMARY KEY, name VARCHAR(50) NOT NULL, balance DECIMAL(12,2) NOT NULL, memo VARCHAR(50)) User:root}
I190531 04:54:17.026836 676 storage/replica_command.go:247 [n1,split,s1,r22/1:/{Table/54-Max}] initiating a split of this range at key /Table/55 [r23] (zone config)
I190531 04:54:25.317452 189 server/status/runtime.go:500 [n1] runtime stats: 150 MiB RSS, 143 goroutines, 210 MiB/352 KiB/226 MiB GO alloc/idle/total, 16 MiB/20 MiB CGO alloc/total, 332.5 CGO/sec, 1.4/0.8 %(u/s)time, 0.0 %gc (1x), 2.3 KiB/1.1 KiB (r/w)net
I190531 04:54:35.605014 189 server/status/runtime.go:500 [n1] runtime stats: 248 MiB RSS, 152 goroutines, 159 MiB/115 MiB/300 MiB GO alloc/idle/total, 30 MiB/35 MiB CGO alloc/total, 179057.9 CGO/sec, 128.5/8.0 %(u/s)time, 0.0 %gc (10x), 2.3 KiB/1.6 KiB (r/w)net
I190531 04:54:36.215116 865 storage/replica_command.go:247 [n1,split,s1,r23/1:/{Table/55-Max}] initiating a split of this range at key /Table/55/1/20716 [r24] (load at key /Table/55/1/20716 (5777.91 splitQPS, 2671.22 batches/sec, 593.52 raft mutations/sec))
W190531 04:54:38.569601 108 storage/store.go:3708 [n1,s1,r24/1:/{Table/55/1/2…-Max}] handle raft ready: 0.6s [processed=690]
I190531 04:54:45.904405 189 server/status/runtime.go:500 [n1] runtime stats: 268 MiB RSS, 153 goroutines, 161 MiB/112 MiB/300 MiB GO alloc/idle/total, 45 MiB/51 MiB CGO alloc/total, 166537.3 CGO/sec, 126.7/9.0 %(u/s)time, 0.0 %gc (10x), 2.5 KiB/1.6 KiB (r/w)net
I190531 04:54:52.480009 1435 storage/replica_command.go:247 [n1,split,s1,r24/1:/{Table/55/1/2…-Max}] initiating a split of this range at key /Table/55/1/49968 [r25] (load at key /Table/55/1/49968 (7045.65 splitQPS, 4474.49 batches/sec, 973.62 raft mutations/sec))
I190531 04:54:52.571065 185 gossip/gossip.go:557 [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
W190531 04:54:52.573732 685 sql/stats/automatic_stats.go:450 failed to create statistics on table 54: create-stats: table is being dropped
W190531 04:54:55.069642 152 storage/store.go:3708 [n1,s1,r25/1:/{Table/55/1/4…-Max}] handle raft ready: 0.7s [processed=568]
I190531 04:54:56.188990 189 server/status/runtime.go:500 [n1] runtime stats: 287 MiB RSS, 149 goroutines, 205 MiB/72 MiB/300 MiB GO alloc/idle/total, 61 MiB/68 MiB CGO alloc/total, 159502.3 CGO/sec, 127.2/7.1 %(u/s)time, 0.0 %gc (9x), 106 KiB/16 KiB (r/w)net
I190531 04:55:05.289030 1870 storage/replica_command.go:247 [n1,split,s1,r25/1:/{Table/55/1/4…-Max}] initiating a split of this range at key /Table/55/1/68885 [r26] (load at key /Table/55/1/68885 (4837.38 splitQPS, 3470.20 batches/sec, 837.40 raft mutations/sec))
I190531 04:55:06.465114 189 server/status/runtime.go:500 [n1] runtime stats: 246 MiB RSS, 153 goroutines, 260 MiB/16 MiB/300 MiB GO alloc/idle/total, 16 MiB/22 MiB CGO alloc/total, 152959.6 CGO/sec, 135.6/8.7 %(u/s)time, 0.0 %gc (8x), 228 KiB/80 KiB (r/w)net
W190531 04:55:08.054377 166 storage/store.go:3708 [n1,s1,r26/1:/{Table/55/1/6…-Max}] handle raft ready: 0.8s [processed=663]
I190531 04:55:10.395490 2004 storage/replica_command.go:386 [n1,merge,s1,r23/1:/Table/55{-/1/20716}] initiating a merge of r24:/Table/55/1/{20716-49968} [(n1,s1):1, next=2, gen=1] into this range (lhs+rhs has (size=1.6 MiB+2.3 MiB qps=0.00+0.00 --> 0.00qps) below threshold (size=3.8 MiB, qps=0.00))
E190531 04:55:11.966998 146 util/log/crash_reporting.go:546 [n1,s1,r23/1:/Table/55{-/1/20716}] Reported as error c4660ad0fecd43b3af10ef0c1f6c2f92
F190531 04:55:11.967007 146 storage/replica_proposal.go:679 [n1,s1,r23/1:/Table/55{-/1/20716}] failed to update store after merging range: IO error: Failed to remove dir: D:\project\Database\cluster\cockroach\cockroach-v19.1.0\node-1\auxiliary\sideloading\r0XXXX\r24: ϵͳ֒һսָ֨ք·c
goroutine 146 [running]:
github.com/cockroachdb/cockroach/pkg/util/log.getStacks(0xc000058100, 0xc000058120, 0x54cd400, 0x1b)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:1020 +0xdb
github.com/cockroachdb/cockroach/pkg/util/log.(*loggingT).outputLogEntry(0x5736ea0, 0xc000000004, 0x54cd41d, 0x1b, 0x2a7, 0xc00b4300f0, 0xe8)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:876 +0x961
github.com/cockroachdb/cockroach/pkg/util/log.addStructured(0x3c2cb20, 0xc00d359530, 0x4, 0x2, 0x35269d9, 0x2e, 0xc008f3a3c8, 0x1, 0x1)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/structured.go:85 +0x2df
github.com/cockroachdb/cockroach/pkg/util/log.logDepth(0x3c2cb20, 0xc00d359530, 0x1, 0x4, 0x35269d9, 0x2e, 0xc008f3a3c8, 0x1, 0x1)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/log.go:71 +0x93
github.com/cockroachdb/cockroach/pkg/util/log.Fatalf(0x3c2cb20, 0xc00d359530, 0x35269d9, 0x2e, 0xc008f3a3c8, 0x1, 0x1)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/log.go:182 +0x85
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).handleReplicatedEvalResult(0xc00d70af00, 0x3c2cb20, 0xc00d359530, 0x0, 0x0, 0x0, 0xc00d0b8300, 0x0, 0x0, 0x0, ...)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_proposal.go:679 +0x10ec
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).handleEvalResultRaftMuLocked(0xc00d70af00, 0x3c2cb20, 0xc00d359530, 0xc00d3278c0, 0x1, 0x0, 0x0, 0xc00d0b8300, 0x0, 0x0, ...)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_proposal.go:842 +0xb1
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).processRaftCommand(0xc00d70af00, 0x3c2cb20, 0xc00d359530, 0xc00e74f158, 0x8, 0x6, 0x7a94, 0x100000001, 0x1, 0x1, ...)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_raft.go:2006 +0x8f2
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).handleRaftReadyRaftMuLocked(0xc00d70af00, 0x3c2cb20, 0xc00d3595c0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_raft.go:816 +0x13e6
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).handleRaftReady(0xc00d70af00, 0x3c2cb20, 0xc00d3595c0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_raft.go:505 +0x13e
github.com/cockroachdb/cockroach/pkg/storage.(*Store).processReady(0xc000d0a000, 0x3c2cb20, 0xc00d3595c0, 0x17)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:3697 +0x12f
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc00058e280, 0x3c2cb20, 0xc000a9c060)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:214 +0x25f
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3c2cb20, 0xc000a9c060)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:165 +0x45
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc000349400, 0xc0004e6f30, 0xc0003493f0)
/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:200 +0xe8
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0xaf
****************************************************************************
This node experienced a fatal error (printed above), and as a result the
process is terminating.
Fatal errors can occur due to faulty hardware (disks, memory, clocks) or a
problem in CockroachDB. With your help, the support team at Cockroach Labs
will try to determine the root cause, recommend next steps, and we can
improve CockroachDB based on your report.
Please submit a crash report by following the instructions here:
https://github.com/cockroachdb/cockroach/issues/new/choose
If you would rather not post publicly, please contact us directly at:
support@cockroachlabs.com
The Cockroach Labs team appreciates your feedback. |
|
cockroach/c-deps/libroach/engine.cc Line 441 in 639445d ^- this is not the windows path separator, not sure it matters (but this is the method generating the error in the first post) cc @ajwerner To build a windows test binary: |
awoods187
added
the
C-bug
kenliu
added
B-os-windows
|
Hi @Little-Pan , |
|
@darinpp Microsoft NTFS. |
|
I've got a similar error in v19.1.5 on Windows, just committing transactions with 100 simple inserts each in a loop: The system cannot find the file specified. The auxiliary directory was empty at this point. After creating an empty directory tree for the full path from the error message, the nodes came back up. |
|
Hey @Little-Pan & @zeeZ 19.2 is out, and should have a number of commits that addressed this type of issue. Can you please try the latest version and let me know if you have any problems? |
|
Running the same test in 19.2 did not cause this crash for me anymore. |
|
@ricardocrdb OK, the test passed in v19.2. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Describe the problem
*
F190505 05:15:48.910027 145 storage/replica_proposal.go:679 [n1,s1,r21/1:/Table/53{-/1/22372}] failed to update store after merging range: IO error: Failed to remove dir: D:\project\Database\cluster\cockroach\cockroach-v19.1.0\node-1\auxiliary\sideloading\r0XXXX\r22: ϵͳ�Ҳ���ָ����·����
goroutine 145 [running]:
github.com/cockroachdb/cockroach/pkg/util/log.getStacks(0xc000058100, 0xc000058120, 0x54cd400, 0x1b)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:1020 +0xdb
github.com/cockroachdb/cockroach/pkg/util/log.(*loggingT).outputLogEntry(0x5736ea0, 0xc000000004, 0x54cd41d, 0x1b, 0x2a7, 0xc0004f6870, 0xe8)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:876 +0x961
To Reproduce
F190505 05:15:48.910027 145 storage/replica_proposal.go:679 [n1,s1,r21/1:/Table/53{-/1/22372}] failed to update store after merging range: IO error: Failed to remove dir: D:\project\Database\cluster\cockroach\cockroach-v19.1.0\node-1\auxiliary\sideloading\r0XXXX\r22: ϵͳ�Ҳ���ָ����·����
goroutine 145 [running]:
github.com/cockroachdb/cockroach/pkg/util/log.getStacks(0xc000058100, 0xc000058120, 0x54cd400, 0x1b)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:1020 +0xdb
github.com/cockroachdb/cockroach/pkg/util/log.(*loggingT).outputLogEntry(0x5736ea0, 0xc000000004, 0x54cd41d, 0x1b, 0x2a7, 0xc0004f6870, 0xe8)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:876 +0x961
github.com/cockroachdb/cockroach/pkg/util/log.addStructured(0x3c2cb20, 0xc00d6f8e70, 0x4, 0x2, 0x35269d9, 0x2e, 0xc009e563c8, 0x1, 0x1)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/structured.go:85 +0x2df
github.com/cockroachdb/cockroach/pkg/util/log.logDepth(0x3c2cb20, 0xc00d6f8e70, 0x1, 0x4, 0x35269d9, 0x2e, 0xc009e563c8, 0x1, 0x1)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/log.go:71 +0x93
github.com/cockroachdb/cockroach/pkg/util/log.Fatalf(0x3c2cb20, 0xc00d6f8e70, 0x35269d9, 0x2e, 0xc009e563c8, 0x1, 0x1)
/go/src/github.com/cockroachdb/cockroach/pkg/util/log/log.go:182 +0x85
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).handleReplicatedEvalResult(0xc00bf9a500, 0x3c2cb20, 0xc00d6f8e70, 0x0, 0x0, 0x0, 0xc010b8ef00, 0x0, 0x0, 0x0, ...)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_proposal.go:679 +0x10ec
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).handleEvalResultRaftMuLocked(0xc00bf9a500, 0x3c2cb20, 0xc00d6f8e70, 0xc00f6a06e0, 0x1, 0x0, 0x0, 0xc010b8ef00, 0x0, 0x0, ...)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_proposal.go:842 +0xb1
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).processRaftCommand(0xc00bf9a500, 0x3c2cb20, 0xc00d6f8e70, 0xc01035c338, 0x8, 0x6, 0x6812, 0x100000001, 0x1, 0x1, ...)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_raft.go:2006 +0x8f2
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).handleRaftReadyRaftMuLocked(0xc00bf9a500, 0x3c2cb20, 0xc00d6f8f00, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_raft.go:816 +0x13e6
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).handleRaftReady(0xc00bf9a500, 0x3c2cb20, 0xc00d6f8f00, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_raft.go:505 +0x13e
github.com/cockroachdb/cockroach/pkg/storage.(*Store).processReady(0xc000a7c000, 0x3c2cb20, 0xc00d6f8f00, 0x15)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:3697 +0x12f
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc000aac300, 0x3c2cb20, 0xc000aa2150)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:214 +0x25f
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3c2cb20, 0xc000aa2150)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:165 +0x45
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc000267810, 0xc0004d6ea0, 0xc000267800)
/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:200 +0xe8
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0xaf
This node experienced a fatal error (printed above), and as a result the
process is terminating.
Fatal errors can occur due to faulty hardware (disks, memory, clocks) or a
problem in CockroachDB. With your help, the support team at Cockroach Labs
will try to determine the root cause, recommend next steps, and we can
improve CockroachDB based on your report.
Please submit a crash report by following the instructions here:
If you would rather not post publicly, please contact us directly at:
The Cockroach Labs team appreciates your feedback.
Expected behavior
The cockroach should continue to run.
Environment:
The text was updated successfully, but these errors were encountered: