Uptime(secs): 63.0 total, 23.0 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
I200407 11:48:27.762391 98754 server/status/runtime.go:498  [n1] runtime stats: 270 MiB RSS, 194 goroutines, 46 MiB/128 MiB/119 MiB GO alloc/idle/total, 17 MiB/52 MiB CGO alloc/total, 14.2 CGO/sec, 1.6/0.3 %(u/s)time, 0.0 %gc (1x), 2.7 MiB/2.7 MiB (r/w)net
W200407 11:48:28.137204 98723 kv/kvserver/store_raft.go:508  [n1,s1,r23/1:/Table/2{7-8}] handle raft ready: 18.2s [applied=2, batches=1, state_assertions=0]
W200407 11:48:28.137281 98676 kv/kvserver/store_raft.go:508  [n1,s1,r3/1:/System/{NodeLive…-tsd}] handle raft ready: 13.3s [applied=1, batches=1, state_assertions=1]
W200407 11:48:32.850195 98682 kv/kvserver/store_raft.go:508  [n1,s1,r1/1:/{Min-System/NodeL…}] handle raft ready: 10.9s [applied=1, batches=1, state_assertions=0]
W200407 11:48:32.850362 98718 kv/kvserver/store_raft.go:508  [n1,s1,r2/1:/System/NodeLiveness{-Max}] handle raft ready: 10.9s [applied=2, batches=2, state_assertions=1]
I200407 11:48:32.850494 98761 kv/kvserver/node_liveness.go:804  [n1,liveness-hb] retrying liveness update after kvserver.errRetryLiveness: result is ambiguous (context deadline exceeded)
W200407 11:48:32.850515 98761 kv/kvserver/node_liveness.go:546  [n1,liveness-hb] slow heartbeat took 23.6s
W200407 11:48:32.850543 98761 kv/kvserver/node_liveness.go:471  [n1,liveness-hb] failed node liveness heartbeat: operation "node liveness heartbeat" timed out after 4.5s
W200407 11:48:32.850650 98703 kv/kvserver/store_raft.go:508  [n1,s1,r6/1:/Table/{SystemCon…-11}] handle raft ready: 10.9s [applied=3, batches=2, state_assertions=1]
W200407 11:48:32.899612 98676 kv/kvserver/store_raft.go:508  [n1,s1,r3/1:/System/{NodeLive…-tsd}] handle raft ready: 4.8s [applied=1, batches=1, state_assertions=0]
I200407 11:48:32.911770 99535 sql/event_log.go:132  [n1,intExec=initializeClusterSecret] Event: "set_cluster_setting", target: 0, info: {SettingName:cluster.secret Value:71b2af6e-a02a-425e-a0d6-2214be686a1e User:root}
W200407 11:48:34.610083 98709 kv/kvserver/store_raft.go:508  [n1,s1,r2/1:/System/NodeLiveness{-Max}] handle raft ready: 1.7s [applied=1, batches=1, state_assertions=0]
W200407 11:48:34.648670 98689 kv/kvserver/store_raft.go:508  [n1,s1,r1/1:/{Min-System/NodeL…}] handle raft ready: 1.7s [applied=1, batches=1, state_assertions=1]
W200407 11:48:34.652387 99688 kv/kvserver/node_liveness.go:546  [n1,s1,r4/1:/System{/tsd-tse}] slow heartbeat took 18.7s
W200407 11:48:34.652416 99827 kv/kvserver/node_liveness.go:546  [n1,s1,r14/1:/Table/1{8-9}] slow heartbeat took 12.7s
E200407 11:48:34.652419 99688 kv/kvserver/replica_range_lease.go:339  [n1,s1,r4/1:/System{/tsd-tse}] heartbeat failed on epoch increment
E200407 11:48:34.652432 99827 kv/kvserver/replica_range_lease.go:339  [n1,s1,r14/1:/Table/1{8-9}] heartbeat failed on epoch increment
W200407 11:48:34.652503 99877 kv/kvserver/node_liveness.go:546  [n1,s1,r3/1:/System/{NodeLive…-tsd}] slow heartbeat took 6.5s
E200407 11:48:34.652515 99877 kv/kvserver/replica_range_lease.go:339  [n1,s1,r3/1:/System/{NodeLive…-tsd}] heartbeat failed on epoch increment
W200407 11:48:34.652775 98761 kv/kvserver/node_liveness.go:546  [n1,liveness-hb] slow heartbeat took 1.8s
I200407 11:48:34.652791 98761 kv/kvserver/node_liveness.go:461  [n1,liveness-hb] heartbeat failed on epoch increment; retrying
W200407 11:48:34.652831 99954 kv/kvserver/node_liveness.go:546  [n1,s1,r6/1:/Table/{SystemCon…-11}] slow heartbeat took 1.8s
E200407 11:48:34.652845 99954 kv/kvserver/replica_range_lease.go:339  [n1,s1,r6/1:/Table/{SystemCon…-11}] heartbeat failed on epoch increment
W200407 11:48:34.914010 99879 kv/kvserver/node_liveness.go:546  [n1,s1,r8/1:/Table/1{2-3}] slow heartbeat took 2.0s
I200407 11:48:35.020786 98642 gossip/gossip.go:1527  [n1] node has connected to cluster via gossip
I200407 11:48:35.055682 100071 sql/event_log.go:132  [n1,intExec=create-default-db] Event: "create_database", target: 50, info: {DatabaseName:defaultdb Statement:CREATE DATABASE IF NOT EXISTS defaultdb User:root}
I200407 11:48:35.074281 100080 sql/event_log.go:132  [n1,intExec=create-default-db] Event: "create_database", target: 51, info: {DatabaseName:postgres Statement:CREATE DATABASE IF NOT EXISTS postgres User:root}
I200407 11:48:35.147436 98597 server/server.go:1845  [n1] done ensuring all necessary migrations have run
I200407 11:48:35.147484 98597 server/server.go:2081  [n1] serving sql connections
I200407 11:48:35.147624 100282 sqlmigrations/migrations.go:653  [n1] starting wait for upgrade finalization before schema change job migration
I200407 11:48:35.147952 100282 sqlmigrations/migrations.go:685  [n1] starting schema change job migration
I200407 11:48:35.151542 100282 sqlmigrations/migrations.go:897  [schema-change-job-migration] evaluating tables for creating jobs
I200407 11:48:35.151572 100282 sqlmigrations/migrations.go:704  [n1] schema change job migration completed
I200407 11:48:35.151759 100280 server/server_update.go:55  [n1] no need to upgrade, cluster already at the newest version
I200407 11:48:35.158256 100283 sql/event_log.go:132  [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:127.0.0.1:37551 Attrs: Locality: ServerVersion:19.2-16 BuildTag:v20.1.0-beta.4-456-g5a3aae1 StartedAt:1586260057734085224 LocalityAddress:[] ClusterName: SQLAddress:127.0.0.1:41925} ClusterID:d575bbcc-cd75-48ac-921c-b6c7d4848b83 StartedAt:1586260057734085224 LastUp:1586260057734085224}
--- FAIL: TestStatusGetFiles (73.78s)
=== RUN   TestStatusGetFiles/heap
    --- FAIL: TestStatusGetFiles/heap (0.01s)
        status_test.go:409: expected 3 files(s), found 7
        status_test.go:415: expected file name heap3.pprof, found memprof.000000000048134944_2020-04-07T11_47_47.759