Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

teamcity: failed test: TestImportCSVStmt #34577

Closed
cockroach-teamcity opened this issue Feb 5, 2019 · 1 comment
Closed

teamcity: failed test: TestImportCSVStmt #34577

cockroach-teamcity opened this issue Feb 5, 2019 · 1 comment
Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Milestone
19.1

Comments

@cockroach-teamcity
Copy link
Member

The following tests appear to have failed on master (testrace): TestImportCSVStmt/schema-in-query-transform-only, TestImportCSVStmt, TestImportCSVStmt/schema-in-file-auto-gzip, TestImportCSVStmt/schema-in-file-no-decompress, TestImportCSVStmt/empty-with-files, TestImportCSVStmt/empty-file, TestImportCSVStmt/schema-in-file-auto-decompress, TestImportCSVStmt/schema-in-query-opts, TestImportCSVStmt/schema-in-file-sstsize, TestImportCSVStmt/schema-in-file-explicit-gzip, TestImportCSVStmt/schema-in-file-implicit-gzip

You may want to check for open issues.

#1125801:

TestImportCSVStmt/schema-in-query-opts
... 15:45:53.308308 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/55/2/"S"/3191 - /Table/55/3/3139/"T"/PrefixEnd that contains live data
I190205 15:45:53.313971 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/55/3/3139/"T"/PrefixEnd - /Table/57/1/741 that contains live data
I190205 15:45:53.419670 18948 storage/replica_command.go:244  [n1,s1,r181/1:/{Table/59/3/1…-Max}] initiating a split of this range at key /Table/59/3/1930/"G"/PrefixEnd [r183] (manual)
I190205 15:45:53.485692 9718 server/status/runtime.go:464  [n2] runtime stats: 1.3 GiB RSS, 678 goroutines, 124 MiB/41 MiB/204 MiB GO alloc/idle/total, 140 MiB/178 MiB CGO alloc/total, 8792.8 CGO/sec, 139.2/12.0 %(u/s)time, 0.9 %gc (6x), 3.1 MiB/3.1 MiB (r/w)net
I190205 15:45:53.489108 18716 storage/replica_command.go:244  [n2,s2,r179/2:/Table/59/{2/NULL/…-3/1228/…}] initiating a split of this range at key /Table/59/2/NULL/4745 [r99] (manual)
I190205 15:45:53.897881 18964 storage/replica_command.go:244  [n1,s1,r183/1:/{Table/59/3/1…-Max}] initiating a split of this range at key /Table/59/3/2632/!NULL [r184] (manual)
I190205 15:45:54.174530 18716 storage/replica_command.go:244  [n2,s2,r99/2:/Table/59/{2/NULL/…-3/1228/…}] initiating a split of this range at key /Table/59/2/"E"/2111 [r100] (manual)
I190205 15:45:54.391989 10023 server/status/runtime.go:464  [n3] runtime stats: 1.3 GiB RSS, 684 goroutines, 110 MiB/54 MiB/204 MiB GO alloc/idle/total, 141 MiB/179 MiB CGO alloc/total, 5824.2 CGO/sec, 137.7/11.7 %(u/s)time, 0.6 %gc (5x), 3.2 MiB/3.2 MiB (r/w)net
I190205 15:45:54.705364 19131 storage/replica_command.go:244  [n1,s1,r184/1:/{Table/59/3/2…-Max}] initiating a split of this range at key /Table/59/3/3334/"G"/PrefixEnd [r185] (manual)
I190205 15:45:54.891786 18716 storage/replica_command.go:244  [n2,s2,r100/2:/Table/59/{2/"E"/2…-3/1228/…}] initiating a split of this range at key /Table/59/2/"J"/946 [r161] (manual)
I190205 15:45:55.491313 19145 storage/replica_command.go:244  [n1,s1,r185/1:/{Table/59/3/3…-Max}] initiating a split of this range at key /Table/59/3/4036/!NULL [r186] (manual)
I190205 15:45:55.742998 18716 storage/replica_command.go:244  [n2,s2,r161/2:/Table/59/{2/"J"/9…-3/1228/…}] initiating a split of this range at key /Table/59/2/"N"/3394 [r162] (manual)
I190205 15:45:56.293282 19166 storage/replica_command.go:244  [n1,s1,r186/1:/{Table/59/3/4…-Max}] initiating a split of this range at key /Table/59/3/4738/"G"/PrefixEnd [r187] (manual)
I190205 15:45:57.029143 18716 storage/replica_command.go:244  [n2,s2,r162/2:/Table/59/{2/"N"/3…-3/1228/…}] initiating a split of this range at key /Table/59/2/"S"/1683 [r163] (manual); delayed split for 0.2s to avoid Raft snapshot
I190205 15:45:57.191897 19303 storage/replica_command.go:244  [n1,s1,r187/1:/{Table/59/3/4…-Max}] initiating a split of this range at key /Table/60 [r188] (manual)
I190205 15:45:57.719705 18716 storage/replica_command.go:244  [n2,s2,r163/2:/Table/59/{2/"S"/1…-3/1228/…}] initiating a split of this range at key /Table/59/2/"X"/830 [r164] (manual)
I190205 15:45:58.073591 18716 storage/replica_command.go:244  [n2,s2,r164/2:/Table/59/{2/"X"/8…-3/1228/…}] initiating a split of this range at key /Table/59/3/257/"X"/PrefixEnd [r165] (manual)
I190205 15:45:58.321655 18716 storage/replica_command.go:244  [n2,s2,r165/2:/Table/59/3/{257/"X…-1228/!…}] initiating a split of this range at key /Table/59/3/527/"H" [r166] (manual)
        import_stmt_test.go:1180: job 3 did not match:
            Description: "IMPORT TABLE csv3.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///csv/data-0-opts', 'nodelocal:///csv/data-1-opts', 'nodelocal:///csv/data-2-opts', 'nodelocal:///csv/data-3-opts', 'nodelocal:///csv/data-4-opts') WITH comment = '#', delimiter = '|', \"nullif\" = '', skip = '2'" != "CREATE STATISTICS __auto__ FROM [53] AS OF SYSTEM TIME '-30s'"



TestImportCSVStmt
...napshot in 32ms [clear=0ms batch=0ms entries=29ms commit=1ms]
I190205 15:44:29.716561 9181 storage/replica_command.go:798  [n1,replicate,s1,r3/1:/System/{NodeLive…-tsd}] change replicas (ADD_REPLICA (n2,s2):3): read existing descriptor r3:/System/{NodeLivenessMax-tsd} [(n1,s1):1, (n3,s3):2, next=3, gen=0]
I190205 15:44:29.759756 9181 storage/replica_raft.go:372  [n1,s1,r3/1:/System/{NodeLive…-tsd}] proposing ADD_REPLICA((n2,s2):3): updated=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I190205 15:44:29.828949 9181 storage/store_snapshot.go:762  [n1,replicate,s1,r17/1:/Table/2{1-2}] sending preemptive snapshot f08ea40c at applied index 18
I190205 15:44:29.830380 9181 storage/store_snapshot.go:805  [n1,replicate,s1,r17/1:/Table/2{1-2}] streamed snapshot to (n3,s3):?: kv pairs: 8, log entries: 8, rate-limit: 8.0 MiB/sec, 0.05s
I190205 15:44:29.844361 10467 storage/replica_raftstorage.go:805  [n3,s3,r17/?:{-}] applying preemptive snapshot at index 18 (id=f08ea40c, encoded size=1514, 1 rocksdb batches, 8 log entries)
I190205 15:44:29.846510 10467 storage/replica_raftstorage.go:811  [n3,s3,r17/?:/Table/2{1-2}] applied preemptive snapshot in 2ms [clear=0ms batch=0ms entries=1ms commit=0ms]
I190205 15:44:29.877549 9181 storage/replica_command.go:798  [n1,replicate,s1,r17/1:/Table/2{1-2}] change replicas (ADD_REPLICA (n3,s3):3): read existing descriptor r17:/Table/2{1-2} [(n1,s1):1, (n2,s2):2, next=3, gen=0]
I190205 15:44:29.976374 9181 storage/replica_raft.go:372  [n1,s1,r17/1:/Table/2{1-2}] proposing ADD_REPLICA((n3,s3):3): updated=[(n1,s1):1 (n2,s2):2 (n3,s3):3] next=4
I190205 15:44:30.001917 9181 storage/store_snapshot.go:762  [n1,replicate,s1,r9/1:/Table/1{3-4}] sending preemptive snapshot 6376f577 at applied index 91
I190205 15:44:30.007103 9181 storage/store_snapshot.go:805  [n1,replicate,s1,r9/1:/Table/1{3-4}] streamed snapshot to (n3,s3):?: kv pairs: 202, log entries: 81, rate-limit: 8.0 MiB/sec, 0.02s
I190205 15:44:30.013739 10583 storage/replica_raftstorage.go:805  [n3,s3,r9/?:{-}] applying preemptive snapshot at index 91 (id=6376f577, encoded size=76219, 1 rocksdb batches, 81 log entries)
I190205 15:44:30.050148 10583 storage/replica_raftstorage.go:811  [n3,s3,r9/?:/Table/1{3-4}] applied preemptive snapshot in 36ms [clear=0ms batch=0ms entries=34ms commit=1ms]
I190205 15:44:30.053272 9181 storage/replica_command.go:798  [n1,replicate,s1,r9/1:/Table/1{3-4}] change replicas (ADD_REPLICA (n3,s3):3): read existing descriptor r9:/Table/1{3-4} [(n1,s1):1, (n2,s2):2, next=3, gen=0]
I190205 15:44:30.093936 9181 storage/replica_raft.go:372  [n1,s1,r9/1:/Table/1{3-4}] proposing ADD_REPLICA((n3,s3):3): updated=[(n1,s1):1 (n2,s2):2 (n3,s3):3] next=4
I190205 15:44:30.111979 9181 storage/store_snapshot.go:762  [n1,replicate,s1,r15/1:/Table/{19-20}] sending preemptive snapshot ff7ffd2e at applied index 16
I190205 15:44:30.112773 9181 storage/store_snapshot.go:805  [n1,replicate,s1,r15/1:/Table/{19-20}] streamed snapshot to (n2,s2):?: kv pairs: 7, log entries: 6, rate-limit: 8.0 MiB/sec, 0.01s
I190205 15:44:30.117196 10568 storage/replica_raftstorage.go:805  [n2,s2,r15/?:{-}] applying preemptive snapshot at index 16 (id=ff7ffd2e, encoded size=1243, 1 rocksdb batches, 6 log entries)
I190205 15:44:30.120432 10568 storage/replica_raftstorage.go:811  [n2,s2,r15/?:/Table/{19-20}] applied preemptive snapshot in 3ms [clear=0ms batch=0ms entries=1ms commit=0ms]
I190205 15:44:30.122896 9181 storage/replica_command.go:798  [n1,replicate,s1,r15/1:/Table/{19-20}] change replicas (ADD_REPLICA (n2,s2):3): read existing descriptor r15:/Table/{19-20} [(n1,s1):1, (n3,s3):2, next=3, gen=0]
I190205 15:44:30.203601 9181 storage/replica_raft.go:372  [n1,s1,r15/1:/Table/{19-20}] proposing ADD_REPLICA((n2,s2):3): updated=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I190205 15:44:30.590345 10497 sql/event_log.go:135  [n1,client=127.0.0.1:39388,user=root] Event: "set_cluster_setting", target: 0, info: {SettingName:kv.import.batch_size Value:10KB User:root}



TestImportCSVStmt/schema-in-file-sstsize
...9/3/1{228/!NULL-930/"G"/PrefixEnd} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=19 KiB+19 KiB qps=1.74+0.00 --> 1.74qps) below threshold (size=37 KiB, qps=1.74))
I190205 15:46:31.766307 9983 storage/store.go:2669  [n3,s3,r171/3:/Table/59/{1/2293-3/527/"…}] removing replica r166/3
I190205 15:46:31.770352 9656 storage/store.go:2669  [n2,s2,r171/2:/Table/59/{1/2293-3/527/"…}] removing replica r166/2
I190205 15:46:31.770578 9383 storage/store.go:2669  [n1,s1,r171/1:/Table/59/{1/2293-3/527/"…}] removing replica r166/1
I190205 15:46:31.793186 23415 storage/replica_command.go:244  [n2,s2,r169/2:/Table/61/3/{2732/"…-3440/"…}] initiating a split of this range at key /Table/61/3/3138/"S" [r201] (manual)
I190205 15:46:31.799512 23331 storage/replica_command.go:383  [n3,merge,s3,r171/3:/Table/59/{1/2293-3/1228/…}] initiating a merge of r181:/Table/59/3/1{228/!NULL-930/"G"/PrefixEnd} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=234 KiB+19 KiB qps=5.56+0.00 --> 5.56qps) below threshold (size=253 KiB, qps=5.56))
I190205 15:46:32.194213 23264 storage/replica_command.go:244  [n2,s2,r170/2:/Table/61/3/{1958/"…-2732/"…}] initiating a split of this range at key /Table/61/3/2066/"M" [r202] (manual)
I190205 15:46:32.343280 9971 storage/store.go:2669  [n3,s3,r171/3:/Table/59/{1/2293-3/1228/…}] removing replica r181/3
I190205 15:46:32.385282 9571 storage/store.go:2669  [n2,s2,r171/2:/Table/59/{1/2293-3/1228/…}] removing replica r181/2
I190205 15:46:32.395709 9373 storage/store.go:2669  [n1,s1,r171/1:/Table/59/{1/2293-3/1228/…}] removing replica r181/1
I190205 15:46:32.494135 23453 storage/replica_command.go:383  [n3,merge,s3,r171/3:/Table/59/{1/2293-3/1930/…}] initiating a merge of r183:/Table/{59/3/1930/"G"/PrefixEnd-61/1/741} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=2] into this range (lhs+rhs has (size=253 KiB+101 KiB qps=10.68+2.57 --> 13.25qps) below threshold (size=354 KiB, qps=13.25))
I190205 15:46:33.527614 9944 storage/store.go:2669  [n3,s3,r171/3:/Table/59/{1/2293-3/1930/…}] removing replica r183/3
I190205 15:46:33.528439 9718 server/status/runtime.go:464  [n2] runtime stats: 1.4 GiB RSS, 677 goroutines, 107 MiB/55 MiB/204 MiB GO alloc/idle/total, 166 MiB/206 MiB CGO alloc/total, 4034.1 CGO/sec, 132.9/14.9 %(u/s)time, 0.6 %gc (5x), 4.7 MiB/4.7 MiB (r/w)net
I190205 15:46:33.535969 9708 storage/store.go:2669  [n2,s2,r171/2:/Table/59/{1/2293-3/1930/…}] removing replica r183/2
I190205 15:46:33.566322 9391 storage/store.go:2669  [n1,s1,r171/1:/Table/59/{1/2293-3/1930/…}] removing replica r183/1
I190205 15:46:33.731482 23600 storage/replica_command.go:244  [n1,s1,r222/1:/Table/6{1/3/3440…-2}] initiating a split of this range at key /Table/61/3/4106/"Y"/PrefixEnd [r224] (manual)
I190205 15:46:34.359997 23617 storage/replica_command.go:244  [n1,s1,r224/1:/Table/6{1/3/4106…-2}] initiating a split of this range at key /Table/61/3/4369/"B" [r225] (manual)
I190205 15:46:34.417634 10023 server/status/runtime.go:464  [n3] runtime stats: 1.4 GiB RSS, 678 goroutines, 85 MiB/80 MiB/204 MiB GO alloc/idle/total, 176 MiB/214 MiB CGO alloc/total, 4088.3 CGO/sec, 136.3/16.0 %(u/s)time, 0.7 %gc (6x), 4.1 MiB/4.1 MiB (r/w)net
I190205 15:46:34.485315 23672 storage/replica_command.go:244  [n1,s1,r224/1:/Table/6{1/3/4106…-2}] initiating a split of this range at key /Table/61/3/4930/"Q" [r226] (manual)
I190205 15:46:34.785574 23678 storage/replica_command.go:244  [n1,s1,r225/1:/Table/6{1/3/4369…-2}] initiating a split of this range at key /Table/61/3/4930/"Q" [r227] (manual)
        import_stmt_test.go:1180: job 4 did not match:
            Description: "IMPORT TABLE csv4.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///csv/data-0', 'nodelocal:///csv/data-1', 'nodelocal:///csv/data-2', 'nodelocal:///csv/data-3', 'nodelocal:///csv/data-4') WITH sstsize = '10K'" != "CREATE STATISTICS __auto__ FROM [55] AS OF SYSTEM TIME '-30s'"



TestImportCSVStmt/schema-in-query-transform-only
...MiB (r/w)net
------- Stdout: -------
I190205 15:46:36.198466 10497 sql/event_log.go:135  [n1,client=127.0.0.1:39388,user=root] Event: "create_database", target: 62, info: {DatabaseName:csv5 Statement:CREATE DATABASE csv5 User:root}
I190205 15:46:36.257508 23836 storage/replica_command.go:244  [n3,split,s3,r171/3:/Table/{59/1/2293-61/1/741}] initiating a split of this range at key /Table/61 [r45] (zone config)
I190205 15:46:36.263107 23862 storage/replica_command.go:383  [n1,merge,s1,r157/1:/Table/59/1/{783-1538}] initiating a merge of r159:/Table/59/1/{1538-2293} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=19 KiB+19 KiB qps=0.00+0.00 --> 0.00qps) below threshold (size=39 KiB, qps=0.00))
I190205 15:46:36.637346 9940 storage/store.go:2669  [n3,s3,r157/3:/Table/59/1/{783-1538}] removing replica r159/3
W190205 15:46:36.639994 23876 storage/intentresolver/intent_resolver.go:412  failed to push during intent resolution: failed to push id=8977949c key=/Local/Range/Table/59/1/2293/RangeDescriptor rw=false pri=0.00497703 stat=PENDING epo=0 ts=1549381596.257643255,0 orig=1549381596.257643255,0 max=0.000000000,0 wto=false seq=9
I190205 15:46:36.644551 9696 storage/store.go:2669  [n2,s2,r157/2:/Table/59/1/{783-1538}] removing replica r159/2
I190205 15:46:36.647251 9218 storage/store.go:2669  [n1,s1,r157/1:/Table/59/1/{783-1538}] removing replica r159/1
I190205 15:46:36.693007 23885 storage/replica_command.go:383  [n1,merge,s1,r189/1:/Table/59{-/1/783}] initiating a merge of r157:/Table/59/1/{783-2293} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=2] into this range (lhs+rhs has (size=20 KiB+39 KiB qps=0.00+0.00 --> 0.00qps) below threshold (size=58 KiB, qps=0.00))
I190205 15:46:36.934785 9217 storage/store.go:2669  [n1,s1,r189/1:/Table/59{-/1/783}] removing replica r157/1
I190205 15:46:36.935994 9685 storage/store.go:2669  [n2,s2,r189/2:/Table/59{-/1/783}] removing replica r157/2
I190205 15:46:36.960820 9988 storage/store.go:2669  [n3,s3,r189/3:/Table/59{-/1/783}] removing replica r157/3
I190205 15:46:37.824784 24114 storage/replica_command.go:383  [n1,merge,s1,r189/1:/Table/59{-/1/2293}] initiating a merge of r171:/Table/{59/1/2293-61} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=16] into this range (lhs+rhs has (size=58 KiB+335 KiB qps=4.14+4.23 --> 8.37qps) below threshold (size=393 KiB, qps=8.37))
I190205 15:46:38.304632 9218 storage/store.go:2669  [n1,s1,r189/1:/Table/59{-/1/2293}] removing replica r171/1
I190205 15:46:38.309282 9659 storage/store.go:2669  [n2,s2,r189/2:/Table/59{-/1/2293}] removing replica r171/2
I190205 15:46:38.320676 9932 storage/store.go:2669  [n3,s3,r189/3:/Table/59{-/1/2293}] removing replica r171/3
I190205 15:46:41.475978 9425 server/status/runtime.go:464  [n1] runtime stats: 1.5 GiB RSS, 704 goroutines, 120 MiB/45 MiB/204 MiB GO alloc/idle/total, 205 MiB/244 MiB CGO alloc/total, 4115.7 CGO/sec, 154.8/14.5 %(u/s)time, 0.6 %gc (6x), 2.8 MiB/2.8 MiB (r/w)net
I190205 15:46:43.551677 9718 server/status/runtime.go:464  [n2] runtime stats: 1.5 GiB RSS, 664 goroutines, 124 MiB/40 MiB/204 MiB GO alloc/idle/total, 178 MiB/218 MiB CGO alloc/total, 6611.0 CGO/sec, 161.0/14.9 %(u/s)time, 0.9 %gc (6x), 2.9 MiB/2.9 MiB (r/w)net
        import_stmt_test.go:1180: job 5 did not match:
            Description: "IMPORT TABLE \"\".\"\".t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///csv/data-0-opts', 'nodelocal:///csv/data-1-opts', 'nodelocal:///csv/data-2-opts', 'nodelocal:///csv/data-3-opts', 'nodelocal:///csv/data-4-opts') WITH comment = '#', delimiter = '|', \"nullif\" = '', skip = '2', transform = 'nodelocal:///5'" != "IMPORT TABLE csv3.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///csv/data-0-opts', 'nodelocal:///csv/data-1-opts', 'nodelocal:///csv/data-2-opts', 'nodelocal:///csv/data-3-opts', 'nodelocal:///csv/data-4-opts') WITH comment = '#', delimiter = '|', \"nullif\" = '', skip = '2'"



TestImportCSVStmt/schema-in-file-auto-gzip
...n2] runtime stats: 1.8 GiB RSS, 668 goroutines, 134 MiB/93 MiB/270 MiB GO alloc/idle/total, 276 MiB/314 MiB CGO alloc/total, 5416.2 CGO/sec, 148.2/13.3 %(u/s)time, 1.0 %gc (5x), 3.1 MiB/3.1 MiB (r/w)net
I190205 15:49:13.874319 9655 storage/store.go:2669  [n2,s2,r352/2:/Table/72/{2/"D"/1…-3/1409/…}] removing replica r359/2
I190205 15:49:13.907150 9396 storage/store.go:2669  [n1,s1,r352/1:/Table/72/{2/"D"/1…-3/1409/…}] removing replica r359/1
I190205 15:49:13.922589 9970 storage/store.go:2669  [n3,s3,r352/3:/Table/72/{2/"D"/1…-3/1409/…}] removing replica r359/3
I190205 15:49:13.968811 40899 storage/replica_command.go:383  [n2,merge,s2,r352/2:/Table/72/{2/"D"/1…-3/2075/…}] initiating a merge of r360:/Table/72/3/2{075/"V"/PrefixEnd-742/"M"/PrefixEnd} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=177 KiB+18 KiB qps=14.80+0.00 --> 14.80qps) below threshold (size=195 KiB, qps=14.80))
I190205 15:49:14.254075 9663 storage/store.go:2669  [n2,s2,r352/2:/Table/72/{2/"D"/1…-3/2075/…}] removing replica r360/2
I190205 15:49:14.254901 9962 storage/store.go:2669  [n3,s3,r352/3:/Table/72/{2/"D"/1…-3/2075/…}] removing replica r360/3
I190205 15:49:14.273908 9373 storage/store.go:2669  [n1,s1,r352/1:/Table/72/{2/"D"/1…-3/2075/…}] removing replica r360/1
I190205 15:49:14.386641 41004 storage/replica_command.go:383  [n2,merge,s2,r352/2:/Table/72/{2/"D"/1…-3/2742/…}] initiating a merge of r371:/Table/72/3/{2742/"M"/PrefixEnd-3409/"D"/PrefixEnd} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=195 KiB+18 KiB qps=14.80+0.00 --> 14.80qps) below threshold (size=213 KiB, qps=14.80))
I190205 15:49:14.604264 10023 server/status/runtime.go:464  [n3] runtime stats: 1.8 GiB RSS, 664 goroutines, 101 MiB/129 MiB/270 MiB GO alloc/idle/total, 267 MiB/305 MiB CGO alloc/total, 5077.3 CGO/sec, 145.9/12.9 %(u/s)time, 1.3 %gc (6x), 3.1 MiB/3.1 MiB (r/w)net
I190205 15:49:14.755133 9960 storage/store.go:2669  [n3,s3,r352/3:/Table/72/{2/"D"/1…-3/2742/…}] removing replica r371/3
I190205 15:49:14.756828 9360 storage/store.go:2669  [n1,s1,r352/1:/Table/72/{2/"D"/1…-3/2742/…}] removing replica r371/1
I190205 15:49:14.764673 9710 storage/store.go:2669  [n2,s2,r352/2:/Table/72/{2/"D"/1…-3/2742/…}] removing replica r371/2
I190205 15:49:14.850049 41077 storage/replica_command.go:383  [n2,merge,s2,r352/2:/Table/72/{2/"D"/1…-3/3409/…}] initiating a merge of r372:/Table/72/3/{3409/"D"/PrefixEnd-4076/"U"/PrefixEnd} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=213 KiB+18 KiB qps=14.80+0.00 --> 14.80qps) below threshold (size=232 KiB, qps=14.80))
I190205 15:49:15.103217 9707 storage/store.go:2669  [n2,s2,r352/2:/Table/72/{2/"D"/1…-3/3409/…}] removing replica r372/2
I190205 15:49:15.107447 41088 storage/replica_command.go:383  [n3,merge,s3,r372/3:/Table/72/3/{3409/"…-4076/"…}] initiating a merge of r373:/Table/72/3/4{076/"U"/PrefixEnd-743/"L"/PrefixEnd} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=18 KiB+18 KiB qps=0.00+0.00 --> 0.00qps) below threshold (size=36 KiB, qps=0.00))
I190205 15:49:15.114366 9376 storage/store.go:2669  [n1,s1,r352/1:/Table/72/{2/"D"/1…-3/3409/…}] removing replica r372/1
I190205 15:49:15.108894 9965 storage/store.go:2669  [n3,s3,r352/3:/Table/72/{2/"D"/1…-3/3409/…}] removing replica r372/3
        import_stmt_test.go:1180: job 11 did not match:
            Description: "IMPORT TABLE csv11.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:////csv/data-0.gz', 'nodelocal:////csv/data-1.gz', 'nodelocal:////csv/data-2.gz', 'nodelocal:////csv/data-3.gz', 'nodelocal:////csv/data-4.gz') WITH decompress = 'auto'" != "IMPORT TABLE csv7.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///empty.csv', 'nodelocal:///csv/data-0', 'nodelocal:///csv/data-1', 'nodelocal:///csv/data-2', 'nodelocal:///csv/data-3', 'nodelocal:///csv/data-4')"



TestImportCSVStmt/schema-in-file-explicit-gzip
...qps) below threshold (size=74 KiB, qps=8.79))
I190205 15:48:44.500762 37798 storage/replica_command.go:244  [n2,s2,r374/2:/{Table/72/3/4…-Max}] initiating a split of this range at key /Table/73 [r375] (manual)
I190205 15:48:44.549525 10023 server/status/runtime.go:464  [n3] runtime stats: 1.7 GiB RSS, 669 goroutines, 129 MiB/100 MiB/270 MiB GO alloc/idle/total, 275 MiB/314 MiB CGO alloc/total, 4873.3 CGO/sec, 134.6/12.6 %(u/s)time, 0.6 %gc (5x), 4.0 MiB/4.0 MiB (r/w)net
I190205 15:48:44.617783 9361 storage/store.go:2669  [n1,s1,r310/1:/Table/70/{1/3282-2/"B"/4…}] removing replica r318/1
I190205 15:48:44.629011 9943 storage/store.go:2669  [n3,s3,r310/3:/Table/70/{1/3282-2/"B"/4…}] removing replica r318/3
I190205 15:48:44.629912 9675 storage/store.go:2669  [n2,s2,r310/2:/Table/70/{1/3282-2/"B"/4…}] removing replica r318/2
I190205 15:48:44.681619 37744 storage/replica_command.go:383  [n1,merge,s1,r310/1:/Table/70/{1/3282-2/"F"/2…}] initiating a merge of r321:/Table/70/2/"{F"/2086-H"/4531} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=74 KiB+13 KiB qps=8.79+0.00 --> 8.79qps) below threshold (size=87 KiB, qps=8.79))
I190205 15:48:44.979755 37711 storage/replica_command.go:383  [n2,merge,s2,r205/2:/Table/70/2/"{T"/2749-X"/206}] initiating a merge of r334:/Table/70/{2/"X"/206-3/115/"L"/PrefixEnd} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=18 KiB+18 KiB qps=0.00+0.00 --> 0.00qps) below threshold (size=37 KiB, qps=0.00))
I190205 15:48:45.600896 9390 storage/store.go:2669  [n1,s1,r310/1:/Table/70/{1/3282-2/"F"/2…}] removing replica r321/1
I190205 15:48:45.612026 9666 storage/store.go:2669  [n2,s2,r310/2:/Table/70/{1/3282-2/"F"/2…}] removing replica r321/2
I190205 15:48:45.612316 9962 storage/store.go:2669  [n3,s3,r310/3:/Table/70/{1/3282-2/"F"/2…}] removing replica r321/3
I190205 15:48:46.177309 9370 storage/store.go:2669  [n1,s1,r205/1:/Table/70/2/"{T"/2749-X"/206}] removing replica r334/1
I190205 15:48:46.186624 9702 storage/store.go:2669  [n2,s2,r205/2:/Table/70/2/"{T"/2749-X"/206}] removing replica r334/2
I190205 15:48:46.195238 9940 storage/store.go:2669  [n3,s3,r205/3:/Table/70/2/"{T"/2749-X"/206}] removing replica r334/3
I190205 15:48:46.521926 37763 storage/replica_command.go:383  [n1,merge,s1,r205/1:/Table/70/{2/"T"/2…-3/115/"…}] initiating a merge of r0:{-} [<no replicas>, next=0, gen=0] into this range (lhs+rhs has (size=18 KiB+18 KiB qps=0.00+0.00 --> 0.00qps) below threshold (size=37 KiB, qps=0.00))
I190205 15:48:46.694912 37974 storage/replica_command.go:383  [n1,merge,s1,r310/1:/Table/70/{1/3282-2/"H"/4…}] initiating a merge of r323:/Table/70/2/"{H"/4531-L"/1962} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=87 KiB+18 KiB qps=3.64+0.00 --> 3.64qps) below threshold (size=105 KiB, qps=3.64))
I190205 15:48:46.958556 9572 storage/store.go:2669  [n2,s2,r310/2:/Table/70/{1/3282-2/"H"/4…}] removing replica r323/2
I190205 15:48:46.958639 9931 storage/store.go:2669  [n3,s3,r310/3:/Table/70/{1/3282-2/"H"/4…}] removing replica r323/3
I190205 15:48:46.966733 9353 storage/store.go:2669  [n1,s1,r310/1:/Table/70/{1/3282-2/"H"/4…}] removing replica r323/1
I190205 15:48:47.056668 37955 storage/replica_command.go:383  [n1,merge,s1,r310/1:/Table/70/{1/3282-2/"L"/1…}] initiating a merge of r326:/Table/70/2/"{L"/1962-O"/4409} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=2] into this range (lhs+rhs has (size=105 KiB+18 KiB qps=2.87+0.00 --> 2.87qps) below threshold (size=124 KiB, qps=2.87))
        import_stmt_test.go:1180: job 10 did not match:
            Description: "IMPORT TABLE csv10.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:////csv/data-0.gz', 'nodelocal:////csv/data-1.gz', 'nodelocal:////csv/data-2.gz', 'nodelocal:////csv/data-3.gz', 'nodelocal:////csv/data-4.gz') WITH decompress = 'gzip'" != "CREATE STATISTICS __auto__ FROM [57] AS OF SYSTEM TIME '-30s'"



TestImportCSVStmt/schema-in-file-no-decompress
...:2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=77 KiB+18 KiB qps=8.31+0.00 --> 8.31qps) below threshold (size=95 KiB, qps=8.31))
I190205 15:48:18.262394 34915 storage/replica_command.go:383  [n3,merge,s3,r235/3:/Table/68{-/1/741}] initiating a merge of r268:/Table/68/1/{741-1456} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=19 KiB+19 KiB qps=0.00+0.00 --> 0.00qps) below threshold (size=38 KiB, qps=0.00))
I190205 15:48:18.543910 9692 storage/store.go:2669  [n2,s2,r231/2:/Table/68/{1/3894-2/"J"/5…}] removing replica r277/2
I190205 15:48:18.544685 9970 storage/store.go:2669  [n3,s3,r231/3:/Table/68/{1/3894-2/"J"/5…}] removing replica r277/3
I190205 15:48:18.546606 9398 storage/store.go:2669  [n1,s1,r231/1:/Table/68/{1/3894-2/"J"/5…}] removing replica r277/1
I190205 15:48:18.668508 35025 storage/replica_command.go:383  [n2,merge,s2,r231/2:/Table/68/{1/3894-2/"M"/2…}] initiating a merge of r278:/Table/68/2/"{M"/2977-Q"/459} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=95 KiB+18 KiB qps=11.85+0.00 --> 11.85qps) below threshold (size=114 KiB, qps=11.85))
I190205 15:48:18.804684 9972 storage/store.go:2669  [n3,s3,r235/3:/Table/68{-/1/741}] removing replica r268/3
I190205 15:48:18.807841 9216 storage/store.go:2669  [n1,s1,r235/1:/Table/68{-/1/741}] removing replica r268/1
I190205 15:48:18.824604 9673 storage/store.go:2669  [n2,s2,r235/2:/Table/68{-/1/741}] removing replica r268/2
I190205 15:48:18.938022 9961 storage/store.go:2669  [n3,s3,r231/3:/Table/68/{1/3894-2/"M"/2…}] removing replica r278/3
I190205 15:48:18.938148 9699 storage/store.go:2669  [n2,s2,r231/2:/Table/68/{1/3894-2/"M"/2…}] removing replica r278/2
I190205 15:48:18.938178 9392 storage/store.go:2669  [n1,s1,r231/1:/Table/68/{1/3894-2/"M"/2…}] removing replica r278/1
I190205 15:48:18.998217 35075 storage/replica_command.go:383  [n2,merge,s2,r231/2:/Table/68/{1/3894-2/"Q"/4…}] initiating a merge of r279:/Table/{68/2/"Q"/459-70/1/741} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=14] into this range (lhs+rhs has (size=114 KiB+207 KiB qps=11.85+0.00 --> 11.85qps) below threshold (size=321 KiB, qps=11.85))
I190205 15:48:19.179428 9689 storage/store.go:2669  [n2,s2,r231/2:/Table/68/{1/3894-2/"Q"/4…}] removing replica r279/2
I190205 15:48:19.183186 9925 storage/store.go:2669  [n3,s3,r231/3:/Table/68/{1/3894-2/"Q"/4…}] removing replica r279/3
I190205 15:48:19.188801 9360 storage/store.go:2669  [n1,s1,r231/1:/Table/68/{1/3894-2/"Q"/4…}] removing replica r279/1
I190205 15:48:19.261447 35120 storage/replica_command.go:383  [n3,merge,s3,r235/3:/Table/68{-/1/1456}] initiating a merge of r271:/Table/68/1/{1456-2171} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=2] into this range (lhs+rhs has (size=38 KiB+19 KiB qps=7.82+0.00 --> 7.82qps) below threshold (size=57 KiB, qps=7.82))
I190205 15:48:19.773107 9956 storage/store.go:2669  [n3,s3,r235/3:/Table/68{-/1/1456}] removing replica r271/3
I190205 15:48:19.780647 9676 storage/store.go:2669  [n2,s2,r235/2:/Table/68{-/1/1456}] removing replica r271/2
I190205 15:48:19.822569 9359 storage/store.go:2669  [n1,s1,r235/1:/Table/68{-/1/1456}] removing replica r271/1
I190205 15:48:19.930892 35169 storage/replica_command.go:383  [n3,merge,s3,r235/3:/Table/68{-/1/2171}] initiating a merge of r47:/Table/68/1/{2171-3894} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=3] into this range (lhs+rhs has (size=57 KiB+45 KiB qps=7.82+0.00 --> 7.82qps) below threshold (size=102 KiB, qps=7.82))
        import_stmt_test.go:1180: job 9 did not match:
            Description: "IMPORT TABLE csv9.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///csv/data-0', 'nodelocal:///csv/data-1', 'nodelocal:///csv/data-2', 'nodelocal:///csv/data-3', 'nodelocal:///csv/data-4') WITH decompress = 'none'" != "IMPORT TABLE csv6.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///empty.csv')"



TestImportCSVStmt/empty-file
...I190205 15:46:46.412696 25246 ccl/importccl/read_import_proc.go:75  [n2] could not fetch file size; falling back to per-file progress: <nil>
I190205 15:46:46.771227 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/59/1/783 - /Table/59/1/2293 that contains live data
I190205 15:46:46.771767 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/59/1/1538 - /Table/59/1/2293 that contains live data
I190205 15:46:46.772160 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/59/1/2293 - /Table/61 that contains live data
I190205 15:46:46.772614 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/59/3/527/"H" - /Table/59/3/1228/!NULL that contains live data
I190205 15:46:46.773024 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/59/3/1228/!NULL - /Table/59/3/1930/"G"/PrefixEnd that contains live data
I190205 15:46:46.773891 9419 storage/compactor/compactor.go:329  [n1,s1,compactor] purging suggested compaction for range /Table/59/1/783 - /Table/59/1/2293 that contains live data
I190205 15:46:46.774292 9419 storage/compactor/compactor.go:329  [n1,s1,compactor] purging suggested compaction for range /Table/59/1/1538 - /Table/59/1/2293 that contains live data
I190205 15:46:46.774571 9419 storage/compactor/compactor.go:329  [n1,s1,compactor] purging suggested compaction for range /Table/59/1/2293 - /Table/61 that contains live data
I190205 15:46:46.774862 9419 storage/compactor/compactor.go:329  [n1,s1,compactor] purging suggested compaction for range /Table/59/3/527/"H" - /Table/59/3/1228/!NULL that contains live data
I190205 15:46:46.775374 9419 storage/compactor/compactor.go:329  [n1,s1,compactor] purging suggested compaction for range /Table/59/3/1228/!NULL - /Table/59/3/1930/"G"/PrefixEnd that contains live data
I190205 15:46:46.775643 9419 storage/compactor/compactor.go:329  [n1,s1,compactor] purging suggested compaction for range /Table/59/3/1930/"G"/PrefixEnd - /Table/61/1/741 that contains live data
I190205 15:46:46.779141 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/59/3/1930/"G"/PrefixEnd - /Table/61/1/741 that contains live data
I190205 15:46:46.782340 9584 storage/compactor/compactor.go:329  [n2,s2,compactor] purging suggested compaction for range /Table/59/1/783 - /Table/59/1/2293 that contains live data
I190205 15:46:46.782781 9584 storage/compactor/compactor.go:329  [n2,s2,compactor] purging suggested compaction for range /Table/59/1/1538 - /Table/59/1/2293 that contains live data
I190205 15:46:46.783025 9584 storage/compactor/compactor.go:329  [n2,s2,compactor] purging suggested compaction for range /Table/59/1/2293 - /Table/61 that contains live data
I190205 15:46:46.783330 9584 storage/compactor/compactor.go:329  [n2,s2,compactor] purging suggested compaction for range /Table/59/3/527/"H" - /Table/59/3/1228/!NULL that contains live data
I190205 15:46:46.783738 9584 storage/compactor/compactor.go:329  [n2,s2,compactor] purging suggested compaction for range /Table/59/3/1228/!NULL - /Table/59/3/1930/"G"/PrefixEnd that contains live data
I190205 15:46:46.784040 9584 storage/compactor/compactor.go:329  [n2,s2,compactor] purging suggested compaction for range /Table/59/3/1930/"G"/PrefixEnd - /Table/61/1/741 that contains live data
        import_stmt_test.go:1180: job 6 did not match:
            Description: "IMPORT TABLE csv6.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///empty.csv')" != "IMPORT TABLE csv4.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///csv/data-0', 'nodelocal:///csv/data-1', 'nodelocal:///csv/data-2', 'nodelocal:///csv/data-3', 'nodelocal:///csv/data-4') WITH sstsize = '10K'"



TestImportCSVStmt/empty-with-files
...431856 9680 storage/store.go:2669  [n2,s2,r195/2:/Table/61/{1/741-2/"H"/5…}] removing replica r219/2
I190205 15:47:14.478623 10023 server/status/runtime.go:464  [n3] runtime stats: 1.5 GiB RSS, 693 goroutines, 113 MiB/49 MiB/204 MiB GO alloc/idle/total, 196 MiB/241 MiB CGO alloc/total, 4374.1 CGO/sec, 129.1/10.3 %(u/s)time, 0.4 %gc (5x), 4.2 MiB/4.2 MiB (r/w)net
I190205 15:47:14.846411 27800 storage/replica_command.go:244  [n1,s1,r254/1:/Table/66/{1/3601-2/"N"/40}] initiating a split of this range at key /Table/66/1/4316 [r256] (manual)
I190205 15:47:15.166378 27552 sql/event_log.go:135  [n1] Event: "create_statistics", target: 59, info: {StatisticName:__auto__ Statement:CREATE STATISTICS __auto__ FROM [59] AS OF SYSTEM TIME '-30s'}
I190205 15:47:15.497140 28752 storage/replica_command.go:244  [n1,s1,r255/1:/Table/66/3/{207/"Z…-1345/"…}] initiating a split of this range at key /Table/66/3/679/"D" [r257] (manual)
I190205 15:47:16.086039 27800 storage/replica_command.go:244  [n1,s1,r256/1:/Table/66/{1/4316-2/"N"/40}] initiating a split of this range at key /Table/66/2/"A"/755 [r258] (manual)
I190205 15:47:17.035940 27800 storage/replica_command.go:244  [n1,s1,r258/1:/Table/66/2/"{A"/755-N"/40}] initiating a split of this range at key /Table/66/2/"D"/3124 [r259] (manual); delayed split for 0.2s to avoid Raft snapshot
I190205 15:47:17.274823 27800 storage/replica_command.go:244  [n1,s1,r259/1:/Table/66/2/"{D"/3124-N"/40}] initiating a split of this range at key /Table/66/2/"H"/502 [r260] (manual)
I190205 15:47:17.660537 27800 storage/replica_command.go:244  [n1,s1,r260/1:/Table/66/2/"{H"/502-N"/40}] initiating a split of this range at key /Table/66/2/"J"/2609 [r261] (manual)
I190205 15:47:18.416877 29007 storage/replica_command.go:383  [n3,merge,s3,r45/3:/Table/61{-/1/741}] initiating a merge of r195:/Table/6{1/1/741-4} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=3] into this range (lhs+rhs has (size=19 KiB+385 KiB qps=0.00+0.00 --> 0.00qps) below threshold (size=404 KiB, qps=0.00))
I190205 15:47:18.424049 29021 storage/replica_command.go:244  [n1,s1,r247/1:/{Table/66/3/2…-Max}] initiating a split of this range at key /Table/66/3/2789/"H"/PrefixEnd [r262] (manual)
I190205 15:47:18.904310 9976 storage/store.go:2669  [n3,s3,r45/3:/Table/61{-/1/741}] removing replica r195/3
I190205 15:47:18.912157 9698 storage/store.go:2669  [n2,s2,r45/2:/Table/61{-/1/741}] removing replica r195/2
I190205 15:47:18.932267 9387 storage/store.go:2669  [n1,s1,r45/1:/Table/61{-/1/741}] removing replica r195/1
I190205 15:47:19.170474 29021 storage/replica_command.go:244  [n1,s1,r262/1:/{Table/66/3/2…-Max}] initiating a split of this range at key /Table/66/3/3456/"Y"/PrefixEnd [r263] (manual); delayed split for 0.2s to avoid Raft snapshot
I190205 15:47:19.445831 29021 storage/replica_command.go:244  [n1,s1,r263/1:/{Table/66/3/3…-Max}] initiating a split of this range at key /Table/66/3/4123/"P"/PrefixEnd [r264] (manual)
I190205 15:47:19.785597 29021 storage/replica_command.go:244  [n1,s1,r264/1:/{Table/66/3/4…-Max}] initiating a split of this range at key /Table/66/3/4790/"G"/PrefixEnd [r265] (manual)
I190205 15:47:20.201673 29021 storage/replica_command.go:244  [n1,s1,r265/1:/{Table/66/3/4…-Max}] initiating a split of this range at key /Table/67 [r266] (manual)
        import_stmt_test.go:1180: job 7 did not match:
            Description: "IMPORT TABLE csv7.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///empty.csv', 'nodelocal:///csv/data-0', 'nodelocal:///csv/data-1', 'nodelocal:///csv/data-2', 'nodelocal:///csv/data-3', 'nodelocal:///csv/data-4')" != "IMPORT TABLE \"\".\"\".t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///csv/data-0-opts', 'nodelocal:///csv/data-1-opts', 'nodelocal:///csv/data-2-opts', 'nodelocal:///csv/data-3-opts', 'nodelocal:///csv/data-4-opts') WITH comment = '#', delimiter = '|', \"nullif\" = '', skip = '2', transform = 'nodelocal:///5'"



TestImportCSVStmt/schema-in-file-implicit-gzip
... that contains live data
I190205 15:49:28.936264 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/72/3/1409/"F" - /Table/72/3/2075/"V"/PrefixEnd that contains live data
I190205 15:49:28.936762 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/72/3/2075/"V"/PrefixEnd - /Table/72/3/2742/"M"/PrefixEnd that contains live data
I190205 15:49:28.940269 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/72/3/2742/"M"/PrefixEnd - /Table/72/3/3409/"D"/PrefixEnd that contains live data
I190205 15:49:28.940858 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/72/3/3409/"D"/PrefixEnd - /Table/72/3/4076/"U"/PrefixEnd that contains live data
I190205 15:49:28.941405 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/72/3/4076/"U"/PrefixEnd - /Table/72/3/4743/"L"/PrefixEnd that contains live data
I190205 15:49:28.941766 10001 storage/compactor/compactor.go:329  [n3,s3,compactor] purging suggested compaction for range /Table/72/3/4743/"L"/PrefixEnd - /Table/74 that contains live data
I190205 15:49:29.480936 42326 storage/replica_command.go:244  [n3,s3,r299/3:/Table/76/{1/2886-2/"C"/3…}] initiating a split of this range at key /Table/76/1/3601 [r300] (manual); delayed split for 0.2s to avoid Raft snapshot
I190205 15:49:29.858119 42326 storage/replica_command.go:244  [n3,s3,r300/3:/Table/76/{1/3601-2/"C"/3…}] initiating a split of this range at key /Table/76/1/4316 [r431] (manual)
I190205 15:49:30.220748 42326 storage/replica_command.go:244  [n3,s3,r431/3:/Table/76/{1/4316-2/"C"/3…}] initiating a split of this range at key /Table/76/1/4840 [r432] (manual)
I190205 15:49:30.636010 42902 storage/replica_command.go:244  [n2,s2,r416/2:/Table/7{6/2/"Z"/…-7}] initiating a split of this range at key /Table/76/3/537/"R"/PrefixEnd [r418] (manual)
I190205 15:49:30.844356 42859 storage/replica_command.go:244  [n2,s2,r418/2:/Table/7{6/3/537/…-7}] initiating a split of this range at key /Table/76/3/1204/"I"/PrefixEnd [r419] (manual)
I190205 15:49:31.082817 42799 storage/replica_command.go:244  [n2,s2,r419/2:/Table/7{6/3/1204…-7}] initiating a split of this range at key /Table/76/3/1871/"Z"/PrefixEnd [r420] (manual)
I190205 15:49:31.478737 42864 storage/replica_command.go:244  [n2,s2,r420/2:/Table/7{6/3/1871…-7}] initiating a split of this range at key /Table/76/3/2538/"Q"/PrefixEnd [r421] (manual)
I190205 15:49:31.701016 9425 server/status/runtime.go:464  [n1] runtime stats: 1.8 GiB RSS, 665 goroutines, 131 MiB/97 MiB/270 MiB GO alloc/idle/total, 276 MiB/317 MiB CGO alloc/total, 5454.5 CGO/sec, 143.2/12.4 %(u/s)time, 1.0 %gc (5x), 4.3 MiB/4.3 MiB (r/w)net
I190205 15:49:31.730360 42965 storage/replica_command.go:244  [n2,s2,r421/2:/Table/7{6/3/2538…-7}] initiating a split of this range at key /Table/76/3/3205/"H"/PrefixEnd [r422] (manual)
I190205 15:49:32.005952 42968 storage/replica_command.go:244  [n2,s2,r422/2:/Table/7{6/3/3205…-7}] initiating a split of this range at key /Table/76/3/3872/"Y"/PrefixEnd [r423] (manual)
I190205 15:49:32.359731 42948 storage/replica_command.go:244  [n2,s2,r423/2:/Table/7{6/3/3872…-7}] initiating a split of this range at key /Table/76/3/4539/"P"/PrefixEnd [r424] (manual)
I190205 15:49:32.726263 43032 storage/replica_command.go:244  [n2,s2,r424/2:/Table/7{6/3/4539…-7}] initiating a split of this range at key /Table/76/3/4889/"B" [r425] (manual)
        import_stmt_test.go:1180: job 12 did not match:
            Description: "IMPORT TABLE csv12.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:////csv/data-0.gz', 'nodelocal:////csv/data-1.gz', 'nodelocal:////csv/data-2.gz', 'nodelocal:////csv/data-3.gz', 'nodelocal:////csv/data-4.gz')" != "CREATE STATISTICS __auto__ FROM [59] AS OF SYSTEM TIME '-30s'"



TestImportCSVStmt/schema-in-query-transform-only
...ly (7.870s)

------- Stdout: -------
I190205 15:46:36.198466 10497 sql/event_log.go:135  [n1,client=127.0.0.1:39388,user=root] Event: "create_database", target: 62, info: {DatabaseName:csv5 Statement:CREATE DATABASE csv5 User:root}
I190205 15:46:36.257508 23836 storage/replica_command.go:244  [n3,split,s3,r171/3:/Table/{59/1/2293-61/1/741}] initiating a split of this range at key /Table/61 [r45] (zone config)
I190205 15:46:36.263107 23862 storage/replica_command.go:383  [n1,merge,s1,r157/1:/Table/59/1/{783-1538}] initiating a merge of r159:/Table/59/1/{1538-2293} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=19 KiB+19 KiB qps=0.00+0.00 --> 0.00qps) below threshold (size=39 KiB, qps=0.00))
I190205 15:46:36.637346 9940 storage/store.go:2669  [n3,s3,r157/3:/Table/59/1/{783-1538}] removing replica r159/3
W190205 15:46:36.639994 23876 storage/intentresolver/intent_resolver.go:412  failed to push during intent resolution: failed to push id=8977949c key=/Local/Range/Table/59/1/2293/RangeDescriptor rw=false pri=0.00497703 stat=PENDING epo=0 ts=1549381596.257643255,0 orig=1549381596.257643255,0 max=0.000000000,0 wto=false seq=9
I190205 15:46:36.644551 9696 storage/store.go:2669  [n2,s2,r157/2:/Table/59/1/{783-1538}] removing replica r159/2
I190205 15:46:36.647251 9218 storage/store.go:2669  [n1,s1,r157/1:/Table/59/1/{783-1538}] removing replica r159/1
I190205 15:46:36.693007 23885 storage/replica_command.go:383  [n1,merge,s1,r189/1:/Table/59{-/1/783}] initiating a merge of r157:/Table/59/1/{783-2293} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=2] into this range (lhs+rhs has (size=20 KiB+39 KiB qps=0.00+0.00 --> 0.00qps) below threshold (size=58 KiB, qps=0.00))
I190205 15:46:36.934785 9217 storage/store.go:2669  [n1,s1,r189/1:/Table/59{-/1/783}] removing replica r157/1
I190205 15:46:36.935994 9685 storage/store.go:2669  [n2,s2,r189/2:/Table/59{-/1/783}] removing replica r157/2
I190205 15:46:36.960820 9988 storage/store.go:2669  [n3,s3,r189/3:/Table/59{-/1/783}] removing replica r157/3
I190205 15:46:37.824784 24114 storage/replica_command.go:383  [n1,merge,s1,r189/1:/Table/59{-/1/2293}] initiating a merge of r171:/Table/{59/1/2293-61} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=16] into this range (lhs+rhs has (size=58 KiB+335 KiB qps=4.14+4.23 --> 8.37qps) below threshold (size=393 KiB, qps=8.37))
I190205 15:46:38.304632 9218 storage/store.go:2669  [n1,s1,r189/1:/Table/59{-/1/2293}] removing replica r171/1
I190205 15:46:38.309282 9659 storage/store.go:2669  [n2,s2,r189/2:/Table/59{-/1/2293}] removing replica r171/2
I190205 15:46:38.320676 9932 storage/store.go:2669  [n3,s3,r189/3:/Table/59{-/1/2293}] removing replica r171/3
I190205 15:46:41.475978 9425 server/status/runtime.go:464  [n1] runtime stats: 1.5 GiB RSS, 704 goroutines, 120 MiB/45 MiB/204 MiB GO alloc/idle/total, 205 MiB/244 MiB CGO alloc/total, 4115.7 CGO/sec, 154.8/14.5 %(u/s)time, 0.6 %gc (6x), 2.8 MiB/2.8 MiB (r/w)net
I190205 15:46:43.551677 9718 server/status/runtime.go:464  [n2] runtime stats: 1.5 GiB RSS, 664 goroutines, 124 MiB/40 MiB/204 MiB GO alloc/idle/total, 178 MiB/218 MiB CGO alloc/total, 6611.0 CGO/sec, 161.0/14.9 %(u/s)time, 0.9 %gc (6x), 2.9 MiB/2.9 MiB (r/w)net
        import_stmt_test.go:1180: job 5 did not match:
            Description: "IMPORT TABLE \"\".\"\".t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///csv/data-0-opts', 'nodelocal:///csv/data-1-opts', 'nodelocal:///csv/data-2-opts', 'nodelocal:///csv/data-3-opts', 'nodelocal:///csv/data-4-opts') WITH comment = '#', delimiter = '|', \"nullif\" = '', skip = '2', transform = 'nodelocal:///5'" != "IMPORT TABLE csv3.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///csv/data-0-opts', 'nodelocal:///csv/data-1-opts', 'nodelocal:///csv/data-2-opts', 'nodelocal:///csv/data-3-opts', 'nodelocal:///csv/data-4-opts') WITH comment = '#', delimiter = '|', \"nullif\" = '', skip = '2'"



TestImportCSVStmt/schema-in-file-auto-decompress
...9  [n2,s2,r253/2:/Table/66/{2/"X"/2…-3/207/"…}] removing replica r255/2
I190205 15:47:42.000020 31351 storage/replica_command.go:244  [n1,s1,r301/1:/{Table/68/3/3…-Max}] initiating a split of this range at key /Table/68/3/4625/"X"/PrefixEnd [r302] (manual)
I190205 15:47:42.163710 31265 storage/replica_command.go:383  [n1,merge,s1,r253/1:/Table/66/{2/"X"/2…-3/679/"…}] initiating a merge of r257:/Table/66/3/{679/"D"-1345/"T"/PrefixEnd} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=0] into this range (lhs+rhs has (size=31 KiB+18 KiB qps=7.00+0.00 --> 7.00qps) below threshold (size=50 KiB, qps=7.00))
I190205 15:47:42.601689 31364 storage/replica_command.go:244  [n1,s1,r302/1:/{Table/68/3/4…-Max}] initiating a split of this range at key /Table/69 [r303] (manual)
I190205 15:47:42.678384 9679 storage/store.go:2669  [n2,s2,r253/2:/Table/66/{2/"X"/2…-3/679/"…}] removing replica r257/2
I190205 15:47:42.679762 9949 storage/store.go:2669  [n3,s3,r253/3:/Table/66/{2/"X"/2…-3/679/"…}] removing replica r257/3
I190205 15:47:42.682405 9359 storage/store.go:2669  [n1,s1,r253/1:/Table/66/{2/"X"/2…-3/679/"…}] removing replica r257/1
I190205 15:47:43.116256 31374 storage/replica_command.go:383  [n1,merge,s1,r253/1:/Table/66/{2/"X"/2…-3/1345/…}] initiating a merge of r230:/Table/66/3/{1345/"T"/PrefixEnd-4123/"P"/PrefixEnd} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=5] into this range (lhs+rhs has (size=50 KiB+76 KiB qps=5.73+0.00 --> 5.73qps) below threshold (size=126 KiB, qps=5.73))
I190205 15:47:43.585859 9718 server/status/runtime.go:464  [n2] runtime stats: 1.6 GiB RSS, 665 goroutines, 118 MiB/44 MiB/204 MiB GO alloc/idle/total, 188 MiB/229 MiB CGO alloc/total, 4823.8 CGO/sec, 128.7/10.9 %(u/s)time, 1.0 %gc (5x), 3.8 MiB/3.8 MiB (r/w)net
I190205 15:47:43.800947 9371 storage/store.go:2669  [n1,s1,r253/1:/Table/66/{2/"X"/2…-3/1345/…}] removing replica r230/1
I190205 15:47:43.804959 9571 storage/store.go:2669  [n2,s2,r253/2:/Table/66/{2/"X"/2…-3/1345/…}] removing replica r230/2
I190205 15:47:43.811448 9988 storage/store.go:2669  [n3,s3,r253/3:/Table/66/{2/"X"/2…-3/1345/…}] removing replica r230/3
E190205 15:47:44.017308 31451 storage/queue.go:826  [n3,replicaGC,s3,r230/3:/Table/66/3/{1345/"…-4123/"…}] r230 was not found on s3
I190205 15:47:44.084158 31457 storage/replica_command.go:383  [n1,merge,s1,r253/1:/Table/66/{2/"X"/2…-3/4123/…}] initiating a merge of r264:/Table/66/3/4{123/"P"/PrefixEnd-790/"G"/PrefixEnd} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=126 KiB+18 KiB qps=3.84+0.00 --> 3.84qps) below threshold (size=144 KiB, qps=3.84))
I190205 15:47:44.496473 10023 server/status/runtime.go:464  [n3] runtime stats: 1.6 GiB RSS, 660 goroutines, 104 MiB/58 MiB/204 MiB GO alloc/idle/total, 180 MiB/219 MiB CGO alloc/total, 4483.0 CGO/sec, 129.9/11.0 %(u/s)time, 1.0 %gc (5x), 3.8 MiB/3.8 MiB (r/w)net
I190205 15:47:44.631655 9683 storage/store.go:2669  [n2,s2,r253/2:/Table/66/{2/"X"/2…-3/4123/…}] removing replica r264/2
I190205 15:47:44.632087 9964 storage/store.go:2669  [n3,s3,r253/3:/Table/66/{2/"X"/2…-3/4123/…}] removing replica r264/3
I190205 15:47:44.638683 9385 storage/store.go:2669  [n1,s1,r253/1:/Table/66/{2/"X"/2…-3/4123/…}] removing replica r264/1
I190205 15:47:44.901120 31395 storage/replica_command.go:383  [n1,merge,s1,r253/1:/Table/66/{2/"X"/2…-3/4790/…}] initiating a merge of r265:/Table/6{6/3/4790/"G"/PrefixEnd-7} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=1] into this range (lhs+rhs has (size=144 KiB+5.7 KiB qps=3.84+0.00 --> 3.84qps) below threshold (size=150 KiB, qps=3.84))
        import_stmt_test.go:1180: job 8 did not match:
            Description: "IMPORT TABLE csv8.public.t (a INT8 PRIMARY KEY, b STRING, INDEX (b), INDEX (a, b)) CSV DATA ('nodelocal:///csv/data-0', 'nodelocal:///csv/data-1', 'nodelocal:///csv/data-2', 'nodelocal:///csv/data-3', 'nodelocal:///csv/data-4') WITH decompress = 'auto'" != "CREATE STATISTICS __auto__ FROM [61] AS OF SYSTEM TIME '-30s'"

Please assign, take a look and update the issue accordingly.
@cockroach-teamcity cockroach-teamcity added this to the 2.2 milestone Feb 5, 2019
@cockroach-teamcity cockroach-teamcity added C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. labels Feb 5, 2019
@danhhz
Copy link
Contributor

danhhz commented Feb 5, 2019

Duplicate of #34568

@danhhz danhhz marked this as a duplicate of #34568 Feb 5, 2019
@danhhz danhhz closed this as completed Feb 5, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Projects
None yet
Milestone
19.1
Development

No branches or pull requests
2 participants
@danhhz @cockroach-teamcity