I0619 23:49:37.927078 179374 run-with-timeout.cc:134] Running on host dev-server-mbautin-4cpu-15gb-1 I0619 23:49:37.928614 179374 run-with-timeout.cc:141] PATH environment variable: /n/jenkins/linuxbrew/linuxbrew-20181203T161736-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/bin:/net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/python_virtual_env/bin:/net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build-support/python-wrappers:/net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/python_virtual_env/bin:/u/users/mbautin/code/yugabyte/build-support/python-wrappers:/net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/python_virtual_env/bin:/u/users/mbautin/sw/node/current/bin:/usr/local/go/bin:/u/users/mbautin/bin:/net/dev-server-mbautin-4cpu-15gb-1/share/sw/cmake/current/bin:/share/sw/vim/vim-v8.1.0266/bin:/u/users/mbautin/.rbenv/shims:/u/users/mbautin/.rbenv/bin:/u/users/mbautin/zapcc-20170802-175507/bin:/n/tools/vim/vim-v8.0.0617/bin:/u/users/mbautin/code/devtools/bin:/u/users/mbautin/code/google-styleguide/cpplint:/u/users/mbautin/.local/bin:/u/users/mbautin/tools/arcanist/bin:/usr/local/bin:/u/users/mbautin/code/mbdev/bin:/usr/java/default/bin:/opt/yugabyte/yb-server/bin:/opt/yugabyte/yugaware/bin:/usr/lib64/ccache:/usr/local/bin:/usr/bin:/opt/apache-maven-3.3.9/bin:/n/tools/spark/current/bin:/usr/sbin I0619 23:49:37.928647 179374 run-with-timeout.cc:149] Starting child process with a timeout of 601 seconds I0619 23:49:37.929543 179374 run-with-timeout.cc:158] Child process pid: 179375 Note: Google Test filter = CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot [==========] Running 1 test from 1 test case. [----------] Global test environment set-up. [----------] 1 test from CreateInitialSysCatalogSnapshotTest [ RUN ] CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot I0619 23:49:38.417345 179375 test_util.cc:118] Environment variable ASAN_OPTIONS: I0619 23:49:38.418498 179375 test_util.cc:118] Environment variable LSAN_OPTIONS: I0619 23:49:38.418506 179375 test_util.cc:118] Environment variable UBSAN_OPTIONS: I0619 23:49:38.418510 179375 test_util.cc:118] Environment variable TSAN_OPTIONS: I0619 23:49:38.418637 179375 create_initial_sys_catalog_snapshot.cc:44] Creating initial system catalog snapshot at: /u/users/mbautin/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/share/initial_sys_catalog_snapshot I0619 23:49:38.418759 179375 external_mini_cluster.cc:184] Env var YB_EXTRA_MASTER_FLAGS not specified, not setting extra flags from it I0619 23:49:38.418787 179375 external_mini_cluster.cc:184] Env var YB_EXTRA_TSERVER_FLAGS not specified, not setting extra flags from it I0619 23:49:38.419281 179375 mem_tracker.cc:242] MemTracker: hard memory limit is 8.000000 GB I0619 23:49:38.419307 179375 mem_tracker.cc:244] MemTracker: soft memory limit is 6.800000 GB I0619 23:49:38.422869 179375 external_mini_cluster.cc:330] Starting cluster with option bind_to_unique_loopback_addresses=true I0619 23:49:38.422904 179375 external_mini_cluster.cc:333] Starting 1 masters I0619 23:49:38.424774 179375 net_util.cc:507] Selected random free RPC port 19201 I0619 23:49:38.424844 179375 external_mini_cluster.cc:937] Using an auto-assigned port 19201 to start an external mini-cluster master I0619 23:49:38.425232 179375 net_util.cc:507] Selected random free RPC port 23095 I0619 23:49:38.425520 179375 external_mini_cluster.cc:184] Env var YB_EXTRA_DAEMON_FLAGS not specified, not setting extra flags from it I0619 23:49:38.425551 179375 external_mini_cluster.cc:1683] Running [m-1]: /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/tests-pgwrapper/../bin/yb-master yb-master --fs_data_dirs=/tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0 --rpc_bind_addresses=127.0.0.1:19201 --webserver_interface=localhost --webserver_port=23095 --master_addresses=127.0.0.1:19201 --callhome_enabled=false --metrics_log_interval_ms=1000 --log_dir= --enable_tracing --memory_limit_hard_bytes=1073741824 --logtostderr --retryable_rpc_single_call_timeout_ms=10000 --hide_pg_catalog_table_creation_logs --client_read_write_timeout_ms=120000 --memory_limit_hard_bytes=2147483648 --use_initial_sys_catalog_snapshot --create_initial_sys_catalog_snapshot --initial_sys_catalog_snapshot_path=/u/users/mbautin/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/share/initial_sys_catalog_snapshot --master_auto_run_initdb --enable_leader_failure_detection=true --master_auto_run_initdb --server_dump_info_path=/tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/info.pb --server_dump_info_format=pb --rpc_server_allow_ephemeral_ports --logbuflevel=-1 --use_libbacktrace --metric_node_name=test_invocation_2019-06-19T23_49_37_20159_5138_179311 --fatal_details_path_prefix=/net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/yb-test-logs/tests-pgwrapper__create_initial_sys_catalog_snapshot/CreateInitialSysCatalogSnapshotTest_CreateInitialSysCatalogSnapshot.fatal_failure_details.m-1 --minicluster_daemon_id=m-1 [m-1] I0619 23:49:38.745502 179383 master_main.cc:93] NumCPUs determined to be: 4 [m-1] I0619 23:49:38.747594 179383 mem_tracker.cc:242] MemTracker: hard memory limit is 2.000000 GB [m-1] I0619 23:49:38.747632 179383 mem_tracker.cc:244] MemTracker: soft memory limit is 1.700000 GB [m-1] I0619 23:49:38.751709 179383 master_main.cc:114] Initializing master server... [m-1] I0619 23:49:38.752501 179383 server_base.cc:415] Could not load existing FS layout: Not found (yb/util/env_posix.cc:1497): /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/instance: No such file or directory (error 2) [m-1] I0619 23:49:38.752570 179383 server_base.cc:416] Creating new FS layout [m-1] I0619 23:49:38.759341 179383 fs_manager.cc:388] Generated new instance metadata in path /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/instance: [m-1] uuid: "2b54150c9b764b16b5a4e11d09175bce" [m-1] format_stamp: "Formatted at 2019-06-19 23:49:38 on dev-server-mbautin-4cpu-15gb-1" [m-1] I0619 23:49:38.761386 179383 fs_manager.cc:232] Opened local filesystem: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0 [m-1] uuid: "2b54150c9b764b16b5a4e11d09175bce" [m-1] format_stamp: "Formatted at 2019-06-19 23:49:38 on dev-server-mbautin-4cpu-15gb-1" [m-1] I0619 23:49:38.762035 179383 server_base.cc:200] Auto setting FLAGS_num_reactor_threads to 4 [m-1] I0619 23:49:38.767339 179383 master_main.cc:117] Starting Master server... [m-1] I0619 23:49:38.771934 179383 webserver.cc:147] Starting webserver on localhost:23095 [m-1] I0619 23:49:38.772017 179383 webserver.cc:152] Document root: /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/www [m-1] I0619 23:49:38.778280 179383 net_util.cc:294] Address 127.0.0.1:23095 for localhost:23095 duplicates an earlier resolved entry. [m-1] I0619 23:49:38.778944 179383 webserver.cc:239] Webserver started. Bound to: http://127.0.0.1:23095/ [m-1] I0619 23:49:38.779332 179383 rpc_server.cc:167] RPC server started. Bound to: 127.0.0.1:19201 [m-1] I0619 23:49:38.780030 179383 server_base.cc:279] Dumped server information to /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/info.pb [m-1] I0619 23:49:38.780171 179383 server_base.cc:454] Using private ip address 127.0.0.1 [m-1] I0619 23:49:38.781466 179402 sys_catalog.cc:260] Creating new SysCatalogTable data I0619 23:49:38.786317 179375 external_mini_cluster.cc:1732] Started [m-1] /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/tests-pgwrapper/../bin/yb-master as pid 179383 I0619 23:49:38.786511 179375 external_mini_cluster.cc:338] Starting 1 tablet servers [m-1] I0619 23:49:38.788496 179402 sys_catalog.cc:310] Determining permanent_uuid for [127.0.0.1:19201] [m-1] I0619 23:49:38.794531 179404 server_base.cc:454] Using private ip address 127.0.0.1 [m-1] I0619 23:49:38.796054 179402 sys_catalog.cc:325] Setting up raft configuration: opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } [m-1] I0619 23:49:38.796281 179402 consensus_meta.cc:248] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Updating active role from UNKNOWN_ROLE to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [m-1] I0619 23:49:38.800817 179402 server_base.cc:454] Using private ip address 127.0.0.1 [m-1] I0619 23:49:38.801044 179402 tablet_peer.cc:982] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [state=BOOTSTRAPPING]: Changed state from NOT_STARTED to BOOTSTRAPPING [m-1] I0619 23:49:38.801658 179402 consensus_meta.cc:248] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Updating active role from UNKNOWN_ROLE to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [m-1] I0619 23:49:38.801710 179402 tablet_bootstrap_if.cc:75] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Bootstrap starting. [m-1] I0619 23:49:38.802260 179402 transaction_participant.cc:659] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Start [m-1] I0619 23:49:38.802531 179402 docdb_rocksdb_util.cc:402] Auto setting FLAGS_rocksdb_max_background_flushes to 1 [m-1] I0619 23:49:38.802567 179402 docdb_rocksdb_util.cc:421] Auto setting FLAGS_rocksdb_max_background_compactions to 1 [m-1] I0619 23:49:38.802572 179402 docdb_rocksdb_util.cc:428] Auto setting FLAGS_rocksdb_base_background_compactions to 1 [m-1] I0619 23:49:38.802747 179402 tablet.cc:431] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Creating RocksDB database in dir /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/data/rocksdb/table-sys.catalog.uuid/tablet-00000000000000000000000000000000 [m-1] I0619 23:49:38.807366 179402 tablet.cc:526] Opening RocksDB at: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/data/rocksdb/table-sys.catalog.uuid/tablet-00000000000000000000000000000000 [m-1] I0619 23:49:38.808151 179402 db_impl.cc:491] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Creating manifest 1 [m-1] I0619 23:49:38.819372 179402 version_set.cc:2803] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Recovered from manifest file:/tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/data/rocksdb/table-sys.catalog.uuid/tablet-00000000000000000000000000000000/MANIFEST-000001 succeeded,manifest_file_number is 1, next_file_number is 3, last_sequence is 1125899906842624, log_number is 0,prev_log_number is 0,max_column_family is 0, flushed_values is [m-1] I0619 23:49:38.819425 179402 version_set.cc:2811] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Column family [default] (ID 0), log number is 0 [m-1] I0619 23:49:38.822872 179402 tablet.cc:540] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Opening intents DB at: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/data/rocksdb/table-sys.catalog.uuid/tablet-00000000000000000000000000000000.intents [m-1] I0619 23:49:38.823168 179402 db_impl.cc:491] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Creating manifest 1 [m-1] I0619 23:49:38.828732 179402 version_set.cc:2803] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Recovered from manifest file:/tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/data/rocksdb/table-sys.catalog.uuid/tablet-00000000000000000000000000000000.intents/MANIFEST-000001 succeeded,manifest_file_number is 1, next_file_number is 3, last_sequence is 1125899906842624, log_number is 0,prev_log_number is 0,max_column_family is 0, flushed_values is [m-1] I0619 23:49:38.828835 179402 version_set.cc:2811] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Column family [default] (ID 0), log number is 0 [m-1] I0619 23:49:38.830890 179402 tablet.cc:575] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Successfully opened a RocksDB database at /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/data/rocksdb/table-sys.catalog.uuid/tablet-00000000000000000000000000000000, obj: 0x30ec000 [m-1] I0619 23:49:38.831010 179402 tablet_bootstrap.cc:414] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Time spent opening tablet: real 0.029s user 0.007s sys 0.005s [m-1] I0619 23:49:38.831296 179402 tablet_bootstrap.cc:352] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: No blocks or log segments found. Creating new log. [m-1] I0619 23:49:38.831918 179402 log.cc:400] durable_wal_write is turned on. [m-1] I0619 23:49:38.836733 179402 tablet_bootstrap_if.cc:75] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: No bootstrap required, opened a new log [m-1] I0619 23:49:38.865713 179402 consensus_meta.cc:248] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Updating active role from UNKNOWN_ROLE to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [m-1] I0619 23:49:38.867230 179402 consensus_meta.cc:248] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [m-1] I0619 23:49:38.867319 179402 raft_consensus.cc:354] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Replica starting. Triggering 0 pending operations. Active config: opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } [m-1] I0619 23:49:38.867434 179402 raft_consensus.cc:384] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Consensus starting up: Expiring fail detector timer to make a prompt election more likely [m-1] I0619 23:49:38.867620 179402 raft_consensus.cc:875] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2b54150c9b764b16b5a4e11d09175bce, State: 1, Role: FOLLOWER, Watermarks: {Received: { term: 0 index: 0 } Committed: { term: 0 index: 0 }} Leader: { term: 0 index: 0 }, new leader: , initial_fd_wait: 0.000s [m-1] I0619 23:49:38.867666 179402 consensus_meta.cc:248] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [m-1] I0619 23:49:38.868207 179402 consensus_queue.cc:206] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated op: 0.0, Majority replicated op: 0.0, Committed index: 0.0, Last appended: 0.0, Current term: 0, Majority size: -1, State: QUEUE_OPEN, Mode: NON_LEADER [m-1] I0619 23:49:38.868283 179402 raft_consensus.cc:2815] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Calling mark dirty synchronously for reason code CONSENSUS_STARTED [m-1] I0619 23:49:38.868393 179402 sys_catalog.cc:351] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [sys.catalog]: SysCatalogTable state changed. Locked=0. Reason: RaftConsensus started. Latest consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } } [m-1] I0619 23:49:38.868470 179402 sys_catalog.cc:355] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [sys.catalog]: This master's current role is: FOLLOWER [m-1] I0619 23:49:38.868520 179402 tablet_peer.cc:982] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [state=RUNNING]: Changed state from BOOTSTRAPPING to RUNNING [m-1] I0619 23:49:38.868559 179402 sys_catalog.cc:351] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [sys.catalog]: SysCatalogTable state changed. Locked=0. Reason: Started TabletPeer. Latest consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } } [m-1] I0619 23:49:38.868590 179402 sys_catalog.cc:355] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [sys.catalog]: This master's current role is: FOLLOWER [m-1] I0619 23:49:38.869136 179407 raft_consensus.cc:813] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: ReportFailDetected: Starting NORMAL_ELECTION... [m-1] I0619 23:49:38.869222 179407 raft_consensus.cc:496] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Triggering leader pre-election, mode=NORMAL_ELECTION [m-1] I0619 23:49:38.869328 179407 raft_consensus.cc:2876] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Snoozing failure detection for 3.275s [m-1] I0619 23:49:38.869429 179407 raft_consensus.cc:535] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Starting pre-election with config: opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } [m-1] I0619 23:49:38.869578 179402 db_impl.cc:2166] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: SetOptions() on column family [default], inputs: [m-1] I0619 23:49:38.869624 179402 db_impl.cc:2169] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_stop_writes_trigger: 48 [m-1] I0619 23:49:38.869628 179402 db_impl.cc:2169] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_slowdown_writes_trigger: 24 [m-1] I0619 23:49:38.869632 179407 leader_election.cc:240] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [CANDIDATE]: Term 1 pre-election: Election decided. Result: candidate won. [m-1] I0619 23:49:38.869632 179402 db_impl.cc:2174] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: [default] SetOptions succeeded [m-1] I0619 23:49:38.869716 179402 mutable_cf_options.cc:83] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: write_buffer_size: 134217728 [m-1] I0619 23:49:38.869721 179402 mutable_cf_options.cc:85] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_write_buffer_number: 2 [m-1] I0619 23:49:38.869724 179402 mutable_cf_options.cc:87] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: arena_block_size: 1048576 [m-1] I0619 23:49:38.869727 179402 mutable_cf_options.cc:89] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_bits: 0 [m-1] I0619 23:49:38.869736 179402 mutable_cf_options.cc:91] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_probes: 6 [m-1] I0619 23:49:38.869740 179402 mutable_cf_options.cc:93] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_huge_page_tlb_size: 0 [m-1] I0619 23:49:38.869743 179402 mutable_cf_options.cc:95] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_successive_merges: 0 [m-1] I0619 23:49:38.869746 179402 mutable_cf_options.cc:97] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: filter_deletes: 0 [m-1] I0619 23:49:38.869750 179402 mutable_cf_options.cc:99] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: disable_auto_compactions: 1 [m-1] I0619 23:49:38.869753 179402 mutable_cf_options.cc:101] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: soft_pending_compaction_bytes_limit: 0 [m-1] I0619 23:49:38.869756 179402 mutable_cf_options.cc:103] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: hard_pending_compaction_bytes_limit: 0 [m-1] I0619 23:49:38.869760 179402 mutable_cf_options.cc:105] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_file_num_compaction_trigger: 5 [m-1] I0619 23:49:38.869762 179402 mutable_cf_options.cc:107] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_slowdown_writes_trigger: 24 [m-1] I0619 23:49:38.869765 179402 mutable_cf_options.cc:109] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_stop_writes_trigger: 48 [m-1] I0619 23:49:38.869768 179402 mutable_cf_options.cc:111] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_grandparent_overlap_factor: 10 [m-1] I0619 23:49:38.869771 179402 mutable_cf_options.cc:113] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: expanded_compaction_factor: 25 [m-1] I0619 23:49:38.869774 179402 mutable_cf_options.cc:115] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: source_compaction_factor: 1 [m-1] I0619 23:49:38.869777 179402 mutable_cf_options.cc:117] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: target_file_size_base: 2097152 [m-1] I0619 23:49:38.869781 179402 mutable_cf_options.cc:119] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: target_file_size_multiplier: 1 [m-1] I0619 23:49:38.869783 179402 mutable_cf_options.cc:121] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_base: 10485760 [m-1] I0619 23:49:38.869786 179402 mutable_cf_options.cc:123] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_multiplier: 10 [m-1] I0619 23:49:38.869792 179402 mutable_cf_options.cc:131] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_multiplier_additional: 1, 1, 1, 1, 1, 1, 1 [m-1] I0619 23:49:38.869796 179402 mutable_cf_options.cc:133] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: verify_checksums_in_compaction: 1 [m-1] I0619 23:49:38.869798 179402 mutable_cf_options.cc:135] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_sequential_skip_in_iterations: 8 [m-1] I0619 23:49:38.870085 179407 raft_consensus.cc:2876] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Snoozing failure detection for 3.095s [m-1] I0619 23:49:38.870127 179407 raft_consensus.cc:2769] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Leader pre-election won for term 1 [m-1] I0619 23:49:38.870182 179407 raft_consensus.cc:496] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Triggering leader election, mode=NORMAL_ELECTION [m-1] I0619 23:49:38.870206 179407 raft_consensus.cc:2876] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Snoozing failure detection for 3.227s [m-1] I0619 23:49:38.870231 179407 raft_consensus.cc:2937] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 0 FOLLOWER]: Advancing to term 1 [m-1] I0619 23:49:38.870599 179402 db_impl.cc:2166] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: SetOptions() on column family [default], inputs: [m-1] I0619 23:49:38.870615 179402 db_impl.cc:2169] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: disable_auto_compactions: false [m-1] I0619 23:49:38.870617 179402 db_impl.cc:2174] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: [default] SetOptions succeeded [m-1] I0619 23:49:38.870627 179402 mutable_cf_options.cc:83] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: write_buffer_size: 134217728 [m-1] I0619 23:49:38.870635 179402 mutable_cf_options.cc:85] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_write_buffer_number: 2 [m-1] I0619 23:49:38.870640 179402 mutable_cf_options.cc:87] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: arena_block_size: 1048576 [m-1] I0619 23:49:38.870643 179402 mutable_cf_options.cc:89] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_bits: 0 [m-1] I0619 23:49:38.870651 179402 mutable_cf_options.cc:91] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_probes: 6 [m-1] I0619 23:49:38.870654 179402 mutable_cf_options.cc:93] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_huge_page_tlb_size: 0 [m-1] I0619 23:49:38.870657 179402 mutable_cf_options.cc:95] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_successive_merges: 0 [m-1] I0619 23:49:38.870661 179402 mutable_cf_options.cc:97] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: filter_deletes: 0 [m-1] I0619 23:49:38.870667 179402 mutable_cf_options.cc:99] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: disable_auto_compactions: 0 [m-1] I0619 23:49:38.870671 179402 mutable_cf_options.cc:101] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: soft_pending_compaction_bytes_limit: 0 [m-1] I0619 23:49:38.870674 179402 mutable_cf_options.cc:103] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: hard_pending_compaction_bytes_limit: 0 [m-1] I0619 23:49:38.870676 179402 mutable_cf_options.cc:105] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_file_num_compaction_trigger: 5 [m-1] I0619 23:49:38.870684 179402 mutable_cf_options.cc:107] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_slowdown_writes_trigger: 24 [m-1] I0619 23:49:38.870689 179402 mutable_cf_options.cc:109] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_stop_writes_trigger: 48 [m-1] I0619 23:49:38.870697 179402 mutable_cf_options.cc:111] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_grandparent_overlap_factor: 10 [m-1] I0619 23:49:38.870700 179402 mutable_cf_options.cc:113] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: expanded_compaction_factor: 25 [m-1] I0619 23:49:38.870703 179402 mutable_cf_options.cc:115] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: source_compaction_factor: 1 [m-1] I0619 23:49:38.870712 179402 mutable_cf_options.cc:117] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: target_file_size_base: 2097152 [m-1] I0619 23:49:38.870714 179402 mutable_cf_options.cc:119] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: target_file_size_multiplier: 1 [m-1] I0619 23:49:38.870723 179402 mutable_cf_options.cc:121] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_base: 10485760 [m-1] I0619 23:49:38.870728 179402 mutable_cf_options.cc:123] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_multiplier: 10 [m-1] I0619 23:49:38.870733 179402 mutable_cf_options.cc:131] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_multiplier_additional: 1, 1, 1, 1, 1, 1, 1 [m-1] I0619 23:49:38.870736 179402 mutable_cf_options.cc:133] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: verify_checksums_in_compaction: 1 [m-1] I0619 23:49:38.870744 179402 mutable_cf_options.cc:135] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_sequential_skip_in_iterations: 8 [m-1] I0619 23:49:38.871227 179402 db_impl.cc:2166] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: SetOptions() on column family [default], inputs: [m-1] I0619 23:49:38.871237 179402 db_impl.cc:2169] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_stop_writes_trigger: 48 [m-1] I0619 23:49:38.871240 179402 db_impl.cc:2169] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_slowdown_writes_trigger: 24 [m-1] I0619 23:49:38.871243 179402 db_impl.cc:2174] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: [default] SetOptions succeeded [m-1] I0619 23:49:38.871246 179402 mutable_cf_options.cc:83] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: write_buffer_size: 134217728 [m-1] I0619 23:49:38.871249 179402 mutable_cf_options.cc:85] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_write_buffer_number: 2 [m-1] I0619 23:49:38.871253 179402 mutable_cf_options.cc:87] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: arena_block_size: 1048576 [m-1] I0619 23:49:38.871255 179402 mutable_cf_options.cc:89] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_bits: 0 [m-1] I0619 23:49:38.871258 179402 mutable_cf_options.cc:91] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_probes: 6 [m-1] I0619 23:49:38.871263 179402 mutable_cf_options.cc:93] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_huge_page_tlb_size: 0 [m-1] I0619 23:49:38.871264 179402 mutable_cf_options.cc:95] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_successive_merges: 0 [m-1] I0619 23:49:38.871268 179402 mutable_cf_options.cc:97] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: filter_deletes: 0 [m-1] I0619 23:49:38.871270 179402 mutable_cf_options.cc:99] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: disable_auto_compactions: 1 [m-1] I0619 23:49:38.871273 179402 mutable_cf_options.cc:101] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: soft_pending_compaction_bytes_limit: 0 [m-1] I0619 23:49:38.871275 179402 mutable_cf_options.cc:103] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: hard_pending_compaction_bytes_limit: 0 [m-1] I0619 23:49:38.871279 179402 mutable_cf_options.cc:105] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_file_num_compaction_trigger: 5 [m-1] I0619 23:49:38.871281 179402 mutable_cf_options.cc:107] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_slowdown_writes_trigger: 24 [m-1] I0619 23:49:38.871284 179402 mutable_cf_options.cc:109] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_stop_writes_trigger: 48 [m-1] I0619 23:49:38.871287 179402 mutable_cf_options.cc:111] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_grandparent_overlap_factor: 10 [m-1] I0619 23:49:38.871289 179402 mutable_cf_options.cc:113] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: expanded_compaction_factor: 25 [m-1] I0619 23:49:38.871294 179402 mutable_cf_options.cc:115] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: source_compaction_factor: 1 [m-1] I0619 23:49:38.871296 179402 mutable_cf_options.cc:117] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: target_file_size_base: 2097152 [m-1] I0619 23:49:38.871299 179402 mutable_cf_options.cc:119] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: target_file_size_multiplier: 1 [m-1] I0619 23:49:38.871302 179402 mutable_cf_options.cc:121] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_base: 10485760 [m-1] I0619 23:49:38.871305 179402 mutable_cf_options.cc:123] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_multiplier: 10 [m-1] I0619 23:49:38.871310 179402 mutable_cf_options.cc:131] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_multiplier_additional: 1, 1, 1, 1, 1, 1, 1 [m-1] I0619 23:49:38.871313 179402 mutable_cf_options.cc:133] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: verify_checksums_in_compaction: 1 [m-1] I0619 23:49:38.871316 179402 mutable_cf_options.cc:135] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_sequential_skip_in_iterations: 8 [m-1] I0619 23:49:38.871729 179402 db_impl.cc:2166] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: SetOptions() on column family [default], inputs: [m-1] I0619 23:49:38.871748 179402 db_impl.cc:2169] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: disable_auto_compactions: false [m-1] I0619 23:49:38.871753 179402 db_impl.cc:2174] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: [default] SetOptions succeeded [m-1] I0619 23:49:38.871757 179402 mutable_cf_options.cc:83] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: write_buffer_size: 134217728 [m-1] I0619 23:49:38.871762 179402 mutable_cf_options.cc:85] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_write_buffer_number: 2 [m-1] I0619 23:49:38.871764 179402 mutable_cf_options.cc:87] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: arena_block_size: 1048576 [m-1] I0619 23:49:38.871767 179402 mutable_cf_options.cc:89] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_bits: 0 [m-1] I0619 23:49:38.871770 179402 mutable_cf_options.cc:91] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_probes: 6 [m-1] I0619 23:49:38.871773 179402 mutable_cf_options.cc:93] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: memtable_prefix_bloom_huge_page_tlb_size: 0 [m-1] I0619 23:49:38.871776 179402 mutable_cf_options.cc:95] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_successive_merges: 0 [m-1] I0619 23:49:38.871778 179402 mutable_cf_options.cc:97] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: filter_deletes: 0 [m-1] I0619 23:49:38.871781 179402 mutable_cf_options.cc:99] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: disable_auto_compactions: 0 [m-1] I0619 23:49:38.871789 179402 mutable_cf_options.cc:101] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: soft_pending_compaction_bytes_limit: 0 [m-1] I0619 23:49:38.871793 179402 mutable_cf_options.cc:103] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: hard_pending_compaction_bytes_limit: 0 [m-1] I0619 23:49:38.871798 179402 mutable_cf_options.cc:105] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_file_num_compaction_trigger: 5 [m-1] I0619 23:49:38.871800 179402 mutable_cf_options.cc:107] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_slowdown_writes_trigger: 24 [m-1] I0619 23:49:38.871803 179402 mutable_cf_options.cc:109] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: level0_stop_writes_trigger: 48 [m-1] I0619 23:49:38.871806 179402 mutable_cf_options.cc:111] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_grandparent_overlap_factor: 10 [m-1] I0619 23:49:38.871809 179402 mutable_cf_options.cc:113] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: expanded_compaction_factor: 25 [m-1] I0619 23:49:38.871812 179402 mutable_cf_options.cc:115] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: source_compaction_factor: 1 [m-1] I0619 23:49:38.871815 179402 mutable_cf_options.cc:117] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: target_file_size_base: 2097152 [m-1] I0619 23:49:38.871819 179402 mutable_cf_options.cc:119] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: target_file_size_multiplier: 1 [m-1] I0619 23:49:38.871821 179402 mutable_cf_options.cc:121] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_base: 10485760 [m-1] I0619 23:49:38.871824 179402 mutable_cf_options.cc:123] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_multiplier: 10 [m-1] I0619 23:49:38.871829 179402 mutable_cf_options.cc:131] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_bytes_for_level_multiplier_additional: 1, 1, 1, 1, 1, 1, 1 [m-1] I0619 23:49:38.871831 179402 mutable_cf_options.cc:133] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: verify_checksums_in_compaction: 1 [m-1] I0619 23:49:38.871834 179402 mutable_cf_options.cc:135] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: max_sequential_skip_in_iterations: 8 [m-1] I0619 23:49:38.874500 179407 consensus_meta.cc:248] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 1 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [m-1] I0619 23:49:38.874555 179407 raft_consensus.cc:535] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 1 FOLLOWER]: Starting election with config: opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } [m-1] I0619 23:49:38.878367 179407 leader_election.cc:240] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. [m-1] I0619 23:49:38.878526 179402 sys_catalog.cc:542] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [sys.catalog]: configured and running, proceeding with master startup. [m-1] I0619 23:49:38.878602 179407 raft_consensus.cc:2876] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 1 FOLLOWER]: Snoozing failure detection for 3.164s [m-1] I0619 23:49:38.878628 179407 raft_consensus.cc:2783] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 1 FOLLOWER]: Leader election won for term 1 [m-1] I0619 23:49:38.878684 179407 consensus_meta.cc:248] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Updating active role from FOLLOWER to LEADER. Consensus state: current_term: 1 leader_uuid: "2b54150c9b764b16b5a4e11d09175bce" config { opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [m-1] I0619 23:49:38.878715 179407 raft_consensus.cc:2815] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 1 LEADER]: Calling mark dirty synchronously for reason code NEW_LEADER_ELECTED [m-1] I0619 23:49:38.878737 179407 sys_catalog.cc:351] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [sys.catalog]: SysCatalogTable state changed. Locked=1. Reason: New leader 2b54150c9b764b16b5a4e11d09175bce elected. Latest consensus state: current_term: 1 leader_uuid: "2b54150c9b764b16b5a4e11d09175bce" config { opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } } [m-1] I0619 23:49:38.878744 179407 sys_catalog.cc:355] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [sys.catalog]: This master's current role is: LEADER [m-1] I0619 23:49:38.879364 179383 master_main.cc:120] Master server successfully started. [m-1] I0619 23:49:38.879245 179407 raft_consensus.cc:832] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 1 LEADER]: Becoming Leader. State: Replica: 2b54150c9b764b16b5a4e11d09175bce, State: 1, Role: LEADER, Watermarks: {Received: { term: 0 index: 0 } Committed: { term: 0 index: 0 }} Leader: { term: 0 index: 0 } [m-1] I0619 23:49:38.879539 179383 total_mem_watcher.cc:73] Root memtracker limit: 2147483648 (2048 MiB); this server will stop if memory usage exceeds 200% of that: 4294967296 bytes (4096 MiB). [m-1] I0619 23:49:38.879622 179407 consensus_queue.cc:188] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [LEADER]: Queue going to LEADER mode. State: All replicated op: 0.0, Majority replicated op: 0.0, Committed index: 0.0, Last appended: 0.0, Current term: 1, Majority size: 1, State: QUEUE_OPEN, Mode: LEADER, active raft config: opid_index: -1 peers { permanent_uuid: "2b54150c9b764b16b5a4e11d09175bce" member_type: VOTER last_known_private_addr { host: "127.0.0.1" port: 19201 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } [m-1] I0619 23:49:38.879721 179407 raft_consensus.cc:851] Sending NO_OP at op { term: 0 index: 0 } [m-1] I0619 23:49:38.884984 179410 catalog_manager.cc:497] Loading table and tablet metadata into memory for term 1 [m-1] I0619 23:49:38.885118 179410 catalog_manager.cc:530] VisitSysCatalog: Wait on leader_lock_ for any existing operations to finish. [m-1] I0619 23:49:38.885191 179410 catalog_manager.cc:540] VisitSysCatalog: Acquire catalog manager lock_ before loading sys catalog.. [m-1] I0619 23:49:38.885303 179410 catalog_manager.cc:648] RunLoaders: Loading tables into memory. I0619 23:49:38.886049 179375 external_mini_cluster.cc:1261] Found peer leader at index 0. [m-1] I0619 23:49:38.886288 179410 catalog_manager.cc:653] RunLoaders: Loading tablets into memory. [m-1] I0619 23:49:38.886394 179410 catalog_manager.cc:658] RunLoaders: Loading namespaces into memory. I0619 23:49:38.886615 179375 net_util.cc:507] Selected random free RPC port 15681 I0619 23:49:38.886780 179375 net_util.cc:507] Selected random free RPC port 16748 I0619 23:49:38.886889 179375 net_util.cc:507] Selected random free RPC port 19191 I0619 23:49:38.887018 179375 net_util.cc:507] Selected random free RPC port 22095 [m-1] I0619 23:49:38.886430 179410 catalog_manager.cc:664] RunLoaders: Loading user-defined types into memory. [m-1] I0619 23:49:38.886476 179410 catalog_manager.cc:670] RunLoaders: Loading cluster configuration into memory. [m-1] I0619 23:49:38.886492 179410 catalog_manager.cc:675] RunLoaders: Loading roles into memory. [m-1] I0619 23:49:38.886502 179410 catalog_manager.cc:681] RunLoaders: Loading Redis config into memory. [m-1] I0619 23:49:38.886512 179410 catalog_manager.cc:687] RunLoaders: Loading sys config into memory. [m-1] I0619 23:49:38.899073 179408 replica_state.cc:745] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce [term 1 LEADER]: Advanced the committed_op_id across terms. Last committed operation was: { term: 0 index: 0 } New committed index is: { term: 1 index: 1 } I0619 23:49:38.908773 179375 net_util.cc:507] Selected random free RPC port 15403 I0619 23:49:38.909132 179375 net_util.cc:507] Selected random free RPC port 18696 I0619 23:49:38.909265 179375 net_util.cc:507] Selected random free RPC port 16157 I0619 23:49:38.909361 179375 net_util.cc:507] Selected random free RPC port 19446 I0619 23:49:38.909710 179375 external_mini_cluster.cc:184] Env var YB_EXTRA_DAEMON_FLAGS not specified, not setting extra flags from it I0619 23:49:38.909744 179375 external_mini_cluster.cc:1683] Running [ts-1]: /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/tests-pgwrapper/../bin/yb-tserver yb-tserver --fs_data_dirs=/tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0 --rpc_bind_addresses=127.188.175.0:15681 --webserver_interface=127.188.175.0 --webserver_port=16748 --redis_proxy_bind_address=127.188.175.0:19191 --redis_proxy_webserver_port=22095 --pgsql_proxy_bind_address=127.188.175.0:16157 --pgsql_proxy_webserver_port=19446 --cql_proxy_bind_address=127.188.175.0:15403 --cql_proxy_webserver_port=18696 --start_cql_proxy=true --start_pgsql_proxy=true --tserver_master_addrs=127.0.0.1:19201 --tablet_server_svc_num_threads=64 --ts_consensus_svc_num_threads=20 --callhome_enabled=false --metrics_log_interval_ms=1000 --log_dir= --enable_tracing --memory_limit_hard_bytes=1073741824 --logtostderr --retryable_rpc_single_call_timeout_ms=10000 --yb_num_shards_per_tserver=1 --timestamp_history_retention_interval_sec=0 --server_dump_info_path=/tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0/yb-data/tserver/info.pb --server_dump_info_format=pb --rpc_server_allow_ephemeral_ports --logbuflevel=-1 --use_libbacktrace --metric_node_name=test_invocation_2019-06-19T23_49_37_20159_5138_179311 --fatal_details_path_prefix=/net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/yb-test-logs/tests-pgwrapper__create_initial_sys_catalog_snapshot/CreateInitialSysCatalogSnapshotTest_CreateInitialSysCatalogSnapshot.fatal_failure_details.ts-1 --minicluster_daemon_id=ts-1 [m-1] I0619 23:49:38.911175 179410 catalog_manager.cc:1083] Created default namespace: system [id=00000000000000000000000000000001] [m-1] I0619 23:49:38.916790 179410 catalog_manager.cc:1083] Created default namespace: system_schema [id=00000000000000000000000000000002] [m-1] I0619 23:49:38.922533 179410 catalog_manager.cc:1083] Created default namespace: system_auth [id=00000000000000000000000000000003] [m-1] I0619 23:49:38.928043 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:38.932868 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:38.933187 179410 catalog_manager.cc:1005] Inserted new system.peers table info into CatalogManager maps [m-1] I0619 23:49:38.937268 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000373a700 -> [id=7f5b713862f0477d9daeba6c417dee82], tablets: [0x0000000002b85200 -> eac665945279486b99967ef8fbdfbb0c (table [id=7f5b713862f0477d9daeba6c417dee82])] [m-1] I0619 23:49:38.941916 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000002b85200 -> eac665945279486b99967ef8fbdfbb0c (table [id=7f5b713862f0477d9daeba6c417dee82])] [m-1] I0619 23:49:38.942220 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:38.942386 179410 catalog_manager.cc:1005] Inserted new system.local table info into CatalogManager maps [m-1] I0619 23:49:38.946571 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000373ae00 -> [id=905b386953754539aa7f1e9450d8487d], tablets: [0x0000000002b85800 -> b8d622e41dd643b0a168b2e0e3ec0229 (table [id=905b386953754539aa7f1e9450d8487d])] [m-1] I0619 23:49:38.951104 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000002b85800 -> b8d622e41dd643b0a168b2e0e3ec0229 (table [id=905b386953754539aa7f1e9450d8487d])] [m-1] I0619 23:49:38.951337 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:38.951505 179410 catalog_manager.cc:1005] Inserted new system_schema.keyspaces table info into CatalogManager maps [m-1] I0619 23:49:38.956024 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000373b500 -> [id=0f9d937d2f8a4cfc9ee1adb5219235f4], tablets: [0x0000000002b85e00 -> 297e5492c0a34f4dab4ef50f634b81ca (table [id=0f9d937d2f8a4cfc9ee1adb5219235f4])] [m-1] I0619 23:49:38.960397 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000002b85e00 -> 297e5492c0a34f4dab4ef50f634b81ca (table [id=0f9d937d2f8a4cfc9ee1adb5219235f4])] [m-1] I0619 23:49:38.960638 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:38.960762 179410 catalog_manager.cc:1005] Inserted new system_schema.tables table info into CatalogManager maps [m-1] I0619 23:49:38.965324 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000373bc00 -> [id=4c727296415f455ca2060ace24a981b7], tablets: [0x0000000002b86400 -> b409d72c2f794e2ca21239bb22b7ad68 (table [id=4c727296415f455ca2060ace24a981b7])] [m-1] I0619 23:49:38.970577 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000002b86400 -> b409d72c2f794e2ca21239bb22b7ad68 (table [id=4c727296415f455ca2060ace24a981b7])] [m-1] I0619 23:49:38.970816 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:38.971069 179410 catalog_manager.cc:1005] Inserted new system_schema.columns table info into CatalogManager maps [m-1] I0619 23:49:38.975581 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000373c300 -> [id=2b19f9be9f6b4dae86ea69799c97c488], tablets: [0x0000000002b86a00 -> 48ce6da78c4d455c8507f710c1c152b0 (table [id=2b19f9be9f6b4dae86ea69799c97c488])] [m-1] I0619 23:49:38.980824 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000002b86a00 -> 48ce6da78c4d455c8507f710c1c152b0 (table [id=2b19f9be9f6b4dae86ea69799c97c488])] [m-1] I0619 23:49:38.981164 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:38.981294 179410 catalog_manager.cc:1005] Inserted new system.size_estimates table info into CatalogManager maps [m-1] I0619 23:49:38.986294 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000373ca00 -> [id=dffa45d791c74f6d8991a7d74a7788a1], tablets: [0x0000000002b87000 -> 90001fc1c76d4887a58547756fac4f9a (table [id=dffa45d791c74f6d8991a7d74a7788a1])] [m-1] I0619 23:49:38.991103 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000002b87000 -> 90001fc1c76d4887a58547756fac4f9a (table [id=dffa45d791c74f6d8991a7d74a7788a1])] [m-1] I0619 23:49:38.991278 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:38.991370 179410 catalog_manager.cc:1005] Inserted new system_schema.aggregates table info into CatalogManager maps [m-1] I0619 23:49:38.996080 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000373d100 -> [id=907b2a5ae7224e5c87fa47d745a241e2], tablets: [0x0000000002b87600 -> 6993f82310b0494aa230a48175ed6c6f (table [id=907b2a5ae7224e5c87fa47d745a241e2])] [m-1] I0619 23:49:39.000372 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000002b87600 -> 6993f82310b0494aa230a48175ed6c6f (table [id=907b2a5ae7224e5c87fa47d745a241e2])] [m-1] I0619 23:49:39.000546 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:39.000680 179410 catalog_manager.cc:1005] Inserted new system_schema.functions table info into CatalogManager maps [m-1] I0619 23:49:39.005674 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000373d800 -> [id=6e084dbe447d4a129c864aa93897d341], tablets: [0x000000000384e000 -> 74ecd8de5ac24e68be0b72326e07397a (table [id=6e084dbe447d4a129c864aa93897d341])] [m-1] I0619 23:49:39.010113 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x000000000384e000 -> 74ecd8de5ac24e68be0b72326e07397a (table [id=6e084dbe447d4a129c864aa93897d341])] [m-1] I0619 23:49:39.010349 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:39.010520 179410 catalog_manager.cc:1005] Inserted new system_schema.indexes table info into CatalogManager maps [m-1] I0619 23:49:39.014348 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000385a000 -> [id=a9277190e5aa4372a4b9edfbda73e0d9], tablets: [0x000000000384e600 -> 81f8bda2b81349ceb0383553d0a2939a (table [id=a9277190e5aa4372a4b9edfbda73e0d9])] [m-1] I0619 23:49:39.019341 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x000000000384e600 -> 81f8bda2b81349ceb0383553d0a2939a (table [id=a9277190e5aa4372a4b9edfbda73e0d9])] [m-1] I0619 23:49:39.019783 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:39.019915 179410 catalog_manager.cc:1005] Inserted new system_schema.triggers table info into CatalogManager maps [m-1] I0619 23:49:39.024246 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000385a700 -> [id=8335b0187e42411ea84d311e03e4c14b], tablets: [0x000000000384ec00 -> 356c320e292f4d679cf773dca7fb851f (table [id=8335b0187e42411ea84d311e03e4c14b])] [m-1] I0619 23:49:39.029881 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x000000000384ec00 -> 356c320e292f4d679cf773dca7fb851f (table [id=8335b0187e42411ea84d311e03e4c14b])] [m-1] I0619 23:49:39.030146 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:39.030275 179410 catalog_manager.cc:1005] Inserted new system_schema.views table info into CatalogManager maps [m-1] I0619 23:49:39.035003 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000385ae00 -> [id=3daad24302de4986abf8bdb890d2674d], tablets: [0x000000000384f200 -> aacfc2fff6484a20a578fcaa537b6296 (table [id=3daad24302de4986abf8bdb890d2674d])] [m-1] I0619 23:49:39.039711 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x000000000384f200 -> aacfc2fff6484a20a578fcaa537b6296 (table [id=3daad24302de4986abf8bdb890d2674d])] [m-1] I0619 23:49:39.039882 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:39.039993 179410 catalog_manager.cc:1005] Inserted new system_schema.types table info into CatalogManager maps [m-1] I0619 23:49:39.044037 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000385b500 -> [id=b1ff475f99cc4324a7bb5aa91c69286a], tablets: [0x0000000003850400 -> f0ae6d8a96dc42e699cddae0efe6b012 (table [id=b1ff475f99cc4324a7bb5aa91c69286a])] [m-1] I0619 23:49:39.048686 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000003850400 -> f0ae6d8a96dc42e699cddae0efe6b012 (table [id=b1ff475f99cc4324a7bb5aa91c69286a])] [m-1] I0619 23:49:39.048894 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:39.049015 179410 catalog_manager.cc:1005] Inserted new system.partitions table info into CatalogManager maps [m-1] I0619 23:49:39.053546 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000385bc00 -> [id=c6ae7a04d6a64dc2be3528748a549dd7], tablets: [0x0000000003850a00 -> 2e88231fdbd44c63a60f30e2c0f5c2ce (table [id=c6ae7a04d6a64dc2be3528748a549dd7])] [m-1] I0619 23:49:39.058313 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000003850a00 -> 2e88231fdbd44c63a60f30e2c0f5c2ce (table [id=c6ae7a04d6a64dc2be3528748a549dd7])] [m-1] I0619 23:49:39.058444 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:39.058598 179410 catalog_manager.cc:1005] Inserted new system_auth.roles table info into CatalogManager maps [m-1] I0619 23:49:39.062240 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000385c300 -> [id=c705765c48374ba5a56a28c76e42de2b], tablets: [0x0000000003851000 -> e3ddf279d42f41e59a875ff03ff6a120 (table [id=c705765c48374ba5a56a28c76e42de2b])] [m-1] I0619 23:49:39.066833 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000003851000 -> e3ddf279d42f41e59a875ff03ff6a120 (table [id=c705765c48374ba5a56a28c76e42de2b])] [m-1] I0619 23:49:39.067010 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:39.067111 179410 catalog_manager.cc:1005] Inserted new system_auth.role_permissions table info into CatalogManager maps [m-1] I0619 23:49:39.070508 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000385ca00 -> [id=c7219a3b4d1b407ea02b8bbffac33663], tablets: [0x0000000003851600 -> e4dbb2aae5c44a5b9f63253518dbc916 (table [id=c7219a3b4d1b407ea02b8bbffac33663])] [m-1] I0619 23:49:39.074708 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000003851600 -> e4dbb2aae5c44a5b9f63253518dbc916 (table [id=c7219a3b4d1b407ea02b8bbffac33663])] [m-1] I0619 23:49:39.074856 179410 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:49:39.075155 179410 catalog_manager.cc:1005] Inserted new system_auth.resource_role_permissions_index table info into CatalogManager maps [m-1] I0619 23:49:39.079025 179410 catalog_manager.cc:1010] Wrote table to system catalog: 0x000000000385d100 -> [id=fdf34775d15b44218087df079786644e], tablets: [0x0000000003870000 -> 99fc78daa8014c9a98cc36d9146f8cd5 (table [id=fdf34775d15b44218087df079786644e])] [m-1] I0619 23:49:39.082798 179410 catalog_manager.cc:1027] Wrote tablets to system catalog: [0x0000000003870000 -> 99fc78daa8014c9a98cc36d9146f8cd5 (table [id=fdf34775d15b44218087df079786644e])] [ts-1] I0619 23:49:39.289172 179412 tablet_server_main.cc:133] NumCPUs determined to be: 4 [ts-1] I0619 23:49:39.290189 179412 tablet_server_main.cc:143] Setting tcmalloc max thread cache bytes to: 268435456 [m-1] I0619 23:49:39.385179 179410 permissions_manager.cc:95] Created role: cassandra [m-1] I0619 23:49:39.390337 179410 catalog_manager.cc:779] initdb has never been run on this cluster, running it [m-1] I0619 23:49:39.390553 179410 catalog_manager.cc:518] Completed load of sys catalog in term 1 [m-1] I0619 23:49:39.390627 179417 catalog_manager.cc:789] Waiting to give the tablet server a chance to come up [ts-1 stdout] The files belonging to this database system will be owned by user "mbautin". [ts-1 stdout] This user must also own the server process. [ts-1 stdout] [ts-1 stdout] The database cluster will be initialized with locales [ts-1 stdout] COLLATE: C [ts-1 stdout] CTYPE: en_US.UTF-8 [ts-1 stdout] MESSAGES: en_US.UTF-8 [ts-1 stdout] MONETARY: en_US.UTF-8 [ts-1 stdout] NUMERIC: en_US.UTF-8 [ts-1 stdout] TIME: en_US.UTF-8 [ts-1 stdout] The default database encoding has accordingly been set to "UTF8". [ts-1 stdout] The default text search configuration will be set to "english". [ts-1 stdout] [ts-1 stdout] Data page checksums are disabled. [ts-1 stdout] [ts-1 stdout] creating directory /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0/pg_data ... ok [ts-1 stdout] creating subdirectories ... ok [ts-1 stdout] selecting default max_connections ... 100 [ts-1 stdout] selecting default shared_buffers ... 128MB [ts-1 stdout] selecting dynamic shared memory implementation ... posix [ts-1 stdout] creating configuration files ... ok [ts-1 stdout] running bootstrap script ... ok [ts-1 stdout] syncing data to disk ... ok [ts-1] In YugaByte DB, setting LC_COLLATE to C and all other locale settings to en_US.UTF-8 by default. Locale support will be enhanced as part of addressing https://github.com/YugaByte/yugabyte-db/issues/1557I0619 23:49:41.048084 179412 pg_wrapper.cc:158] initdb completed successfully. Database initialized at /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0/pg_data [ts-1] I0619 23:49:41.048219 179412 tablet_server_main.cc:167] Starting PostgreSQL server listening on 127.188.175.0, port 16157 [ts-1] I0619 23:49:41.048305 179412 pg_wrapper.cc:278] Starting PostgreSQL server [ts-1] I0619 23:49:41.051535 179412 pg_wrapper.cc:120] PostgreSQL server running as pid 179426 [ts-1] I0619 23:49:41.053858 179412 mem_tracker.cc:242] MemTracker: hard memory limit is 1.000000 GB [ts-1] I0619 23:49:41.053908 179412 mem_tracker.cc:244] MemTracker: soft memory limit is 0.850000 GB [ts-1] I0619 23:49:41.056589 179412 encrypted_file_factory.cc:114] Created encrypted file factory [ts-1] I0619 23:49:41.056812 179412 tablet_server_main.cc:179] Initializing tablet server... [ts-1] I0619 23:49:41.057364 179412 server_base.cc:415] Could not load existing FS layout: Not found (yb/util/env_posix.cc:1497): /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0/yb-data/tserver/instance: No such file or directory (error 2) [ts-1] I0619 23:49:41.057402 179412 server_base.cc:416] Creating new FS layout [ts-1] I0619 23:49:41.063771 179412 fs_manager.cc:388] Generated new instance metadata in path /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0/yb-data/tserver/instance: [ts-1] uuid: "0e5fa4611bc0439c9761a9ac223a9cda" [ts-1] format_stamp: "Formatted at 2019-06-19 23:49:41 on dev-server-mbautin-4cpu-15gb-1" [ts-1] I0619 23:49:41.078656 179412 fs_manager.cc:232] Opened local filesystem: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0 [ts-1] uuid: "0e5fa4611bc0439c9761a9ac223a9cda" [ts-1] format_stamp: "Formatted at 2019-06-19 23:49:41 on dev-server-mbautin-4cpu-15gb-1" [ts-1] I0619 23:49:41.079560 179412 server_base.cc:200] Auto setting FLAGS_num_reactor_threads to 4 [ts-1] I0619 23:49:41.086170 179412 ts_tablet_manager.cc:418] max_bootstrap_threads=3 [ts-1] I0619 23:49:41.086637 179412 server_base.cc:454] Using private ip address 127.188.175.0 [ts-1] I0619 23:49:41.087118 179412 tablet_server_main.cc:181] Starting tablet server... [ts-1] I0619 23:49:41.087405 179439 async_initializer.cc:73] Starting to init ybclient [ts-1] I0619 23:49:41.090626 179412 webserver.cc:147] Starting webserver on 127.188.175.0:16748 [ts-1] I0619 23:49:41.090678 179412 webserver.cc:152] Document root: /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/www [ts-1] I0619 23:49:41.091591 179412 webserver.cc:239] Webserver started. Bound to: http://127.188.175.0:16748/ [ts-1] I0619 23:49:41.092288 179412 rpc_server.cc:167] RPC server started. Bound to: 127.188.175.0:15681 [ts-1] I0619 23:49:41.092999 179412 server_base.cc:279] Dumped server information to /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0/yb-data/tserver/info.pb [ts-1] I0619 23:49:41.094712 179439 async_initializer.cc:77] Successfully built ybclient [ts-1] I0619 23:49:41.095511 179412 tablet_server_main.cc:183] Tablet server successfully started. [ts-1] I0619 23:49:41.100334 179412 tablet_server_main.cc:203] Starting redis server... [ts-1] I0619 23:49:41.100584 179412 fs_manager.cc:232] Opened local filesystem: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0 [ts-1] uuid: "0e5fa4611bc0439c9761a9ac223a9cda" [ts-1] format_stamp: "Formatted at 2019-06-19 23:49:41 on dev-server-mbautin-4cpu-15gb-1" [ts-1] I0619 23:49:41.103377 179443 heartbeater.cc:299] P 0e5fa4611bc0439c9761a9ac223a9cda: Connected to a leader master server at 127.0.0.1:19201 [ts-1] I0619 23:49:41.103569 179443 heartbeater.cc:357] P 0e5fa4611bc0439c9761a9ac223a9cda: Registering TS with master... [ts-1] I0619 23:49:41.103624 179443 server_base.cc:454] Using private ip address 127.188.175.0 [ts-1] I0619 23:49:41.103801 179443 heartbeater.cc:366] P 0e5fa4611bc0439c9761a9ac223a9cda: Sending a full tablet report to master... [m-1] I0619 23:49:41.106243 179403 ts_manager.cc:142] Registered new tablet server { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" instance_seqno: 1560988181090437 } with Master, full list: [{0e5fa4611bc0439c9761a9ac223a9cda, 0x0000000002640790 -> { permanent_uuid: 0e5fa4611bc0439c9761a9ac223a9cda registration: 0x0000000002e175c0 -> common { private_rpc_addresses { host: "127.188.175.0" port: 15681 } http_addresses { host: "127.188.175.0" port: 16748 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } placement_uuid: "" } capabilities: 2189743739 placement_id: cloud1:datacenter1:rack1 }}] [m-1] I0619 23:49:41.106773 179403 catalog_manager.cc:3435] 0e5fa4611bc0439c9761a9ac223a9cda now has full report for 0 tablets. [m-1] I0619 23:49:41.106804 179403 catalog_manager.cc:3441] 0e5fa4611bc0439c9761a9ac223a9cda sent full tablet report with 0 tablets. [ts-1] I0619 23:49:41.186043 179412 webserver.cc:147] Starting webserver on 127.188.175.0:22095 [ts-1] I0619 23:49:41.186103 179412 webserver.cc:152] Document root: /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/www [ts-1] I0619 23:49:41.186424 179412 webserver.cc:239] Webserver started. Bound to: http://127.188.175.0:22095/ [ts-1] I0619 23:49:41.187577 179412 rpc_server.cc:167] RPC server started. Bound to: 127.188.175.0:19191 [ts-1] I0619 23:49:41.187999 179412 server_base.cc:279] Dumped server information to /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0/yb-data/tserver/info.pb-redis [ts-1] I0619 23:49:41.188033 179412 tablet_server_main.cc:205] Redis server successfully started. [ts-1] I0619 23:49:41.188560 179412 tablet_server_main.cc:225] Starting CQL server... [ts-1] I0619 23:49:41.188762 179412 fs_manager.cc:232] Opened local filesystem: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0 [ts-1] uuid: "0e5fa4611bc0439c9761a9ac223a9cda" [ts-1] format_stamp: "Formatted at 2019-06-19 23:49:41 on dev-server-mbautin-4cpu-15gb-1" [ts-1] I0619 23:49:41.192219 179465 async_initializer.cc:73] Starting to init ybclient [ts-1] I0619 23:49:41.192440 179412 webserver.cc:147] Starting webserver on 127.188.175.0:18696 [ts-1] I0619 23:49:41.192494 179412 webserver.cc:152] Document root: /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/www [ts-1] I0619 23:49:41.192806 179412 webserver.cc:239] Webserver started. Bound to: http://127.188.175.0:18696/ [ts-1] I0619 23:49:41.193351 179412 rpc_server.cc:167] RPC server started. Bound to: 127.188.175.0:15403 [ts-1] I0619 23:49:41.198927 179412 server_base.cc:279] Dumped server information to /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/ts-0/yb-data/tserver/info.pb-cql [ts-1] I0619 23:49:41.199043 179412 tablet_server_main.cc:227] CQL server successfully started. [ts-1] I0619 23:49:41.199066 179465 async_initializer.cc:77] Successfully built ybclient I0619 23:49:41.208436 179375 external_mini_cluster.cc:1732] Started [ts-1] /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/tests-pgwrapper/../bin/yb-tserver as pid 179412 I0619 23:49:41.210224 179375 external_mini_cluster.cc:1135] 1 TS(s) registered with Master [ts-1] 2019-06-19 23:49:41.293 UTC [179426] LOG: YugaByte is ENABLED in PostgreSQL. Transactions are enabled. [ts-1] 2019-06-19 23:49:41.298 UTC [179426] LOG: listening on IPv4 address "127.188.175.0", port 16157 [ts-1] 2019-06-19 23:49:41.321 UTC [179468] LOG: database system was shut down at 2019-06-19 23:49:40 UTC [ts-1] WARNING: Logging before InitGoogleLogging() is written to STDERR [ts-1] I0619 23:49:41.323295 179469 webserver.cc:147] Starting webserver on 127.188.175.0:19446 [ts-1] I0619 23:49:41.323578 179469 webserver.cc:152] Document root: /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/www [ts-1] I0619 23:49:41.324406 179469 webserver.cc:239] Webserver started. Bound to: http://127.188.175.0:19446/ [ts-1] 2019-06-19 23:49:41.333 UTC [179426] LOG: database system is ready to accept connections [m-1] I0619 23:50:39.399533 179417 catalog_manager.cc:791] Finished waiting to give the tablet server a chance to come up [m-1] I0619 23:50:39.399655 179417 pg_wrapper.cc:181] Running initdb to initialize YSQL cluster with master addresses {127.0.0.1:19201} [m-1 stdout] The files belonging to this database system will be owned by user "mbautin". [m-1 stdout] This user must also own the server process. [m-1 stdout] [m-1 stdout] The database cluster will be initialized with locales [m-1 stdout] COLLATE: C [m-1 stdout] CTYPE: en_US.UTF-8 [m-1 stdout] MESSAGES: en_US.UTF-8 [m-1 stdout] MONETARY: en_US.UTF-8 [m-1 stdout] NUMERIC: en_US.UTF-8 [m-1 stdout] TIME: en_US.UTF-8 [m-1 stdout] The default database encoding has accordingly been set to "UTF8". [m-1 stdout] The default text search configuration will be set to "english". [m-1 stdout] [m-1 stdout] Data page checksums are disabled. [m-1 stdout] [m-1 stdout] creating directory /tmp/tmp_pg_data_615188689 ... ok [m-1 stdout] creating subdirectories ... ok [m-1 stdout] selecting default max_connections ... 100 [m-1 stdout] selecting default shared_buffers ... 128MB [m-1 stdout] selecting dynamic shared memory implementation ... posix [m-1 stdout] creating configuration files ... ok [m-1] In YugaByte DB, setting LC_COLLATE to C and all other locale settings to en_US.UTF-8 by default. Locale support will be enhanced as part of addressing https://github.com/YugaByte/yugabyte-db/issues/1557I0619 23:50:41.496574 180106 ybc_util.cc:68] Setting flag client_read_write_timeout_ms to the value of the env var FLAGS_client_read_write_timeout_ms: 120000 [m-1] I0619 23:50:41.497474 180106 ybc_util.cc:68] Setting flag yb_num_shards_per_tserver to the value of the env var FLAGS_yb_num_shards_per_tserver: 8 [m-1] I0619 23:50:41.497488 180106 ybc_util.cc:68] Setting flag fs_wal_dirs to the value of the env var FLAGS_fs_wal_dirs: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0 [m-1] I0619 23:50:41.497512 180106 ybc_util.cc:68] Setting flag retryable_rpc_single_call_timeout_ms to the value of the env var FLAGS_retryable_rpc_single_call_timeout_ms: 10000 [m-1] I0619 23:50:41.497525 180106 ybc_util.cc:68] Setting flag rpc_bind_addresses to the value of the env var FLAGS_rpc_bind_addresses: 127.0.0.1:19201 [m-1] I0619 23:50:41.497531 180106 ybc_util.cc:68] Setting flag rpc_server_allow_ephemeral_ports to the value of the env var FLAGS_rpc_server_allow_ephemeral_ports: true [m-1] I0619 23:50:41.497539 180106 ybc_util.cc:68] Setting flag num_reactor_threads to the value of the env var FLAGS_num_reactor_threads: 4 [m-1] I0619 23:50:41.497545 180106 ybc_util.cc:68] Setting flag metrics_log_interval_ms to the value of the env var FLAGS_metrics_log_interval_ms: 1000 [m-1] I0619 23:50:41.497552 180106 ybc_util.cc:68] Setting flag server_dump_info_format to the value of the env var FLAGS_server_dump_info_format: pb [m-1] I0619 23:50:41.497558 180106 ybc_util.cc:68] Setting flag server_dump_info_path to the value of the env var FLAGS_server_dump_info_path: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/info.pb [m-1] I0619 23:50:41.497568 180106 ybc_util.cc:68] Setting flag webserver_interface to the value of the env var FLAGS_webserver_interface: localhost [m-1] I0619 23:50:41.497575 180106 ybc_util.cc:68] Setting flag webserver_port to the value of the env var FLAGS_webserver_port: 23095 [m-1] I0619 23:50:41.497582 180106 ybc_util.cc:68] Setting flag use_libbacktrace to the value of the env var FLAGS_use_libbacktrace: true [m-1] I0619 23:50:41.497593 180106 ybc_util.cc:68] Setting flag heap_profile_path to the value of the env var FLAGS_heap_profile_path: /tmp/yb-master.179383 [m-1] I0619 23:50:41.497598 180106 ybc_util.cc:68] Setting flag fs_data_dirs to the value of the env var FLAGS_fs_data_dirs: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0 [m-1] I0619 23:50:41.497606 180106 ybc_util.cc:68] Setting flag fatal_details_path_prefix to the value of the env var FLAGS_fatal_details_path_prefix: /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/yb-test-logs/tests-pgwrapper__create_initial_sys_catalog_snapshot/CreateInitialSysCatalogSnapshotTest_CreateInitialSysCatalogSnapshot.fatal_failure_details.m-1 [m-1] I0619 23:50:41.497617 180106 ybc_util.cc:68] Setting flag log_filename to the value of the env var FLAGS_log_filename: yb-master [m-1] I0619 23:50:41.497623 180106 ybc_util.cc:68] Setting flag minicluster_daemon_id to the value of the env var FLAGS_minicluster_daemon_id: m-1 [m-1] I0619 23:50:41.497629 180106 ybc_util.cc:68] Setting flag default_memory_limit_to_ram_ratio to the value of the env var FLAGS_default_memory_limit_to_ram_ratio: 0.10000000000000001 [m-1] I0619 23:50:41.497637 180106 ybc_util.cc:68] Setting flag memory_limit_hard_bytes to the value of the env var FLAGS_memory_limit_hard_bytes: 2147483648 [m-1] I0619 23:50:41.497644 180106 ybc_util.cc:68] Setting flag metric_node_name to the value of the env var FLAGS_metric_node_name: test_invocation_2019-06-19T23_49_37_20159_5138_179311 [m-1] I0619 23:50:41.497655 180106 ybc_util.cc:68] Setting flag enable_tracing to the value of the env var FLAGS_enable_tracing: true [m-1] I0619 23:50:41.497669 180106 ybc_util.cc:68] Setting flag pggate_master_addresses to the value of the env var FLAGS_pggate_master_addresses: {127.0.0.1:19201} [m-1] I0619 23:50:41.497685 180106 ybc_util.cc:68] Setting flag log_dir to the value of the env var FLAGS_log_dir: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/logs [m-1] I0619 23:50:41.497692 180106 ybc_util.cc:68] Setting flag logbuflevel to the value of the env var FLAGS_logbuflevel: -1 [m-1] I0619 23:50:41.497699 180106 ybc_util.cc:68] Setting flag logtostderr to the value of the env var FLAGS_logtostderr: true [m-1] I0619 23:50:41.497705 180106 ybc_util.cc:68] Setting flag stderrthreshold to the value of the env var FLAGS_stderrthreshold: 3 [m-1] I0619 23:50:41.498647 180106 mem_tracker.cc:242] MemTracker: hard memory limit is 2.000000 GB [m-1] I0619 23:50:41.498672 180106 mem_tracker.cc:244] MemTracker: soft memory limit is 1.700000 GB [m-1] I0619 23:50:41.499475 180108 async_initializer.cc:73] Starting to init ybclient [m-1] I0619 23:50:41.516089 180108 async_initializer.cc:77] Successfully built ybclient [m-1] I0619 23:50:41.550146 179403 catalog_manager.cc:3715] CreateNamespace from 127.0.0.1:46142: name: "template1" [m-1] database_type: YQL_DATABASE_PGSQL [m-1] namespace_id: "00000001000030008000000000000000" [m-1] next_pg_oid: 10000 [m-1] I0619 23:50:41.555734 179403 catalog_manager.cc:3807] Created namespace template1 [id=00000001000030008000000000000000] [m-1] W0619 23:50:41.557368 180113 reactor.cc:380] pggate_ybclient_R000: Client call yb.master.MasterService.IsInitDbDone has no timeout set for connection id: { remote: 127.0.0.1:19201 idx: 0 protocol: 0x00007fce2d422278 -> tcp } [m-1] I0619 23:50:41.558650 180106 pg_ddl.cc:141] PgCreateTable: creating a transactional table: template1.pg_proc [m-1] I0619 23:50:41.561127 179403 catalog_manager.cc:1662] CreateTable from 127.0.0.1:46142: pg_proc [m-1] I0619 23:50:41.561295 179403 catalog_manager.cc:1659] CreateTable from 127.0.0.1:46142: [m-1] name: "transactions" [m-1] schema { [m-1] columns { [m-1] name: "key" [m-1] type { [m-1] main: BINARY [m-1] } [m-1] is_key: true [m-1] is_hash_key: true [m-1] is_nullable: false [m-1] is_static: false [m-1] is_counter: false [m-1] sorting_type: 0 [m-1] order: 0 [m-1] } [m-1] } [m-1] num_tablets: 1 [m-1] table_type: TRANSACTION_STATUS_TABLE_TYPE [m-1] namespace { [m-1] name: "system" [m-1] } [m-1] I0619 23:50:41.561709 179403 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] I0619 23:50:41.569315 179403 catalog_manager.cc:1904] Successfully created table transactions [id=e089c91034904135accd8168737735af] per request from 127.0.0.1:46142 [m-1] I0619 23:50:41.569752 179403 partition.cc:388] Creating partitions with num_tablets: 1 [ts-1] I0619 23:50:41.582585 180116 tablet_service.cc:601] Processing CreateTablet for tablet 201492fb94de461286b09472fb03df35 (table=transactions [id=e089c91034904135accd8168737735af]), partition=hash_split: [, ) [ts-1] I0619 23:50:41.582828 180116 ts_tablet_manager.cc:1457] Get and update data/wal directory assignment map for table: e089c91034904135accd8168737735af [ts-1] I0619 23:50:41.588999 180116 ts_tablet_manager.cc:572] Created tablet metadata for table: e089c91034904135accd8168737735af, tablet: 201492fb94de461286b09472fb03df35 [ts-1] I0619 23:50:41.589318 180116 consensus_meta.cc:248] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Updating active role from UNKNOWN_ROLE to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [ts-1] I0619 23:50:41.594224 180116 ts_tablet_manager.cc:1138] Registered tablet 201492fb94de461286b09472fb03df35 [ts-1] I0619 23:50:41.613662 180117 ts_tablet_manager.cc:950] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Bootstrapping tablet [ts-1] I0619 23:50:41.613814 180117 tablet_peer.cc:982] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [state=BOOTSTRAPPING]: Changed state from NOT_STARTED to BOOTSTRAPPING [ts-1] I0619 23:50:41.614552 180117 consensus_meta.cc:248] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Updating active role from UNKNOWN_ROLE to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [ts-1] I0619 23:50:41.614606 180117 tablet_bootstrap_if.cc:75] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Bootstrap starting. [ts-1] I0619 23:50:41.615329 180117 tablet_bootstrap.cc:414] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Time spent opening tablet: real 0.000s user 0.000s sys 0.000s [ts-1] I0619 23:50:41.615926 180117 tablet_bootstrap.cc:352] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: No blocks or log segments found. Creating new log. [ts-1] I0619 23:50:41.616627 180117 log.cc:402] interval_durable_wal_write_ms is turned on to sync every 1000 ms. [ts-1] I0619 23:50:41.648325 180117 tablet_bootstrap_if.cc:75] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: No bootstrap required, opened a new log [ts-1] I0619 23:50:41.648568 180117 ts_tablet_manager.cc:955] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Time spent bootstrapping tablet: real 0.035s user 0.004s sys 0.000s [ts-1] I0619 23:50:41.649108 180117 consensus_meta.cc:248] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Updating active role from UNKNOWN_ROLE to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [ts-1] I0619 23:50:41.651499 180117 consensus_meta.cc:248] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [ts-1] I0619 23:50:41.651568 180117 raft_consensus.cc:354] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Replica starting. Triggering 0 pending operations. Active config: opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } [ts-1] I0619 23:50:41.651682 180117 raft_consensus.cc:384] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Consensus starting up: Expiring fail detector timer to make a prompt election more likely [ts-1] I0619 23:50:41.651885 180117 raft_consensus.cc:875] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0e5fa4611bc0439c9761a9ac223a9cda, State: 1, Role: FOLLOWER, Watermarks: {Received: { term: 0 index: 0 } Committed: { term: 0 index: 0 }} Leader: { term: 0 index: 0 }, new leader: , initial_fd_wait: 0.000s [ts-1] I0619 23:50:41.651922 180117 consensus_meta.cc:248] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [ts-1] I0619 23:50:41.663290 180121 raft_consensus.cc:813] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: ReportFailDetected: Starting NORMAL_ELECTION... [ts-1] I0619 23:50:41.663307 180117 consensus_queue.cc:206] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated op: 0.0, Majority replicated op: 0.0, Committed index: 0.0, Last appended: 0.0, Current term: 0, Majority size: -1, State: QUEUE_OPEN, Mode: NON_LEADER [ts-1] I0619 23:50:41.663401 180121 raft_consensus.cc:496] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Triggering leader pre-election, mode=NORMAL_ELECTION [ts-1] I0619 23:50:41.663414 180117 raft_consensus.cc:2815] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Calling mark dirty synchronously for reason code CONSENSUS_STARTED [ts-1] I0619 23:50:41.663504 180121 raft_consensus.cc:2876] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Snoozing failure detection for 3.076s [ts-1] I0619 23:50:41.663579 180121 raft_consensus.cc:535] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Starting pre-election with config: opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } [ts-1] I0619 23:50:41.663904 180121 leader_election.cc:240] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [CANDIDATE]: Term 1 pre-election: Election decided. Result: candidate won. [ts-1] I0619 23:50:41.663960 180117 tablet_peer.cc:982] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [state=RUNNING]: Changed state from BOOTSTRAPPING to RUNNING [ts-1] I0619 23:50:41.664708 180117 ts_tablet_manager.cc:991] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Time spent starting tablet: real 0.016s user 0.005s sys 0.000s [ts-1] I0619 23:50:41.664799 180117 ts_tablet_manager.cc:1697] Deleted transition in progress creating tablet for tablet 201492fb94de461286b09472fb03df35 [ts-1] I0619 23:50:41.665005 180121 raft_consensus.cc:2876] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Snoozing failure detection for 3.017s [ts-1] I0619 23:50:41.665036 180121 raft_consensus.cc:2769] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Leader pre-election won for term 1 [ts-1] I0619 23:50:41.665055 180121 raft_consensus.cc:496] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Triggering leader election, mode=NORMAL_ELECTION [ts-1] I0619 23:50:41.665060 180121 raft_consensus.cc:2876] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Snoozing failure detection for 3.113s [ts-1] I0619 23:50:41.665069 180121 raft_consensus.cc:2937] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 0 FOLLOWER]: Advancing to term 1 [ts-1] I0619 23:50:41.670044 180121 consensus_meta.cc:248] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 1 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [ts-1] I0619 23:50:41.670117 180121 raft_consensus.cc:535] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 1 FOLLOWER]: Starting election with config: opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } [ts-1] I0619 23:50:41.673745 180121 leader_election.cc:240] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. [ts-1] I0619 23:50:41.673949 180121 raft_consensus.cc:2876] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 1 FOLLOWER]: Snoozing failure detection for 3.072s [ts-1] I0619 23:50:41.673970 180121 raft_consensus.cc:2783] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 1 FOLLOWER]: Leader election won for term 1 [ts-1] I0619 23:50:41.674037 180121 consensus_meta.cc:248] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda: Updating active role from FOLLOWER to LEADER. Consensus state: current_term: 1 leader_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" config { opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0 [ts-1] I0619 23:50:41.674057 180121 raft_consensus.cc:2815] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 1 LEADER]: Calling mark dirty synchronously for reason code NEW_LEADER_ELECTED [ts-1] I0619 23:50:41.674125 180121 raft_consensus.cc:832] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 1 LEADER]: Becoming Leader. State: Replica: 0e5fa4611bc0439c9761a9ac223a9cda, State: 1, Role: LEADER, Watermarks: {Received: { term: 0 index: 0 } Committed: { term: 0 index: 0 }} Leader: { term: 0 index: 0 } [ts-1] I0619 23:50:41.674306 180121 consensus_queue.cc:188] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [LEADER]: Queue going to LEADER mode. State: All replicated op: 0.0, Majority replicated op: 0.0, Committed index: 0.0, Last appended: 0.0, Current term: 1, Majority size: 1, State: QUEUE_OPEN, Mode: LEADER, active raft config: opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } [ts-1] I0619 23:50:41.674381 180121 raft_consensus.cc:851] Sending NO_OP at op { term: 0 index: 0 } [m-1] I0619 23:50:41.679529 179403 catalog_manager.cc:3679] Peer 0e5fa4611bc0439c9761a9ac223a9cda sent full tablet report for 201492fb94de461286b09472fb03df35. Consensus state: current_term: 1 config { opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } } [ts-1] I0619 23:50:41.679965 180124 replica_state.cc:745] T 201492fb94de461286b09472fb03df35 P 0e5fa4611bc0439c9761a9ac223a9cda [term 1 LEADER]: Advanced the committed_op_id across terms. Last committed operation was: { term: 0 index: 0 } New committed index is: { term: 1 index: 1 } [m-1] I0619 23:50:41.684725 180119 catalog_manager.cc:3644] Tablet: 201492fb94de461286b09472fb03df35 reported consensus state change. New consensus state: current_term: 1 leader_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" config { opid_index: -1 peers { permanent_uuid: "0e5fa4611bc0439c9761a9ac223a9cda" member_type: VOTER last_known_private_addr { host: "127.188.175.0" port: 15681 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }from 0e5fa4611bc0439c9761a9ac223a9cda [m-1] W0619 23:50:42.989493 179387 log.cc:686] Time spent Fsync log took a long time: real 0.090s user 0.000s sys 0.000s [m-1] I0619 23:50:46.486835 179387 log.cc:546] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Max segment size 1048576 reached. Starting new segment allocation. [m-1] I0619 23:50:46.493141 179387 env_posix.cc:617] Closing file /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/wals/table-sys.catalog.uuid/tablet-00000000000000000000000000000000/.tmp.newsegmentCs6Zyy with 2 blocks [m-1] I0619 23:50:46.493257 179387 env_posix.cc:623] /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/wals/table-sys.catalog.uuid/tablet-00000000000000000000000000000000/.tmp.newsegmentCs6Zyy: Truncating file from size: 1052672 to size: 1049286. Preallocated size: 1048576 [m-1] I0619 23:50:46.497851 179387 log.cc:454] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Rolled over to a new segment: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/wals/table-sys.catalog.uuid/tablet-00000000000000000000000000000000/wal-000000002 [m-1] I0619 23:50:53.439366 179387 log.cc:546] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Max segment size 2097152 reached. Starting new segment allocation. [m-1] I0619 23:50:53.445392 179387 env_posix.cc:617] Closing file /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/wals/table-sys.catalog.uuid/tablet-00000000000000000000000000000000/.tmp.newsegmentXyofbk with 2 blocks [m-1] I0619 23:50:53.445436 179387 env_posix.cc:623] /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/wals/table-sys.catalog.uuid/tablet-00000000000000000000000000000000/.tmp.newsegmentXyofbk: Truncating file from size: 2101248 to size: 2097234. Preallocated size: 2097152 [m-1] I0619 23:50:53.451360 179387 log.cc:454] T 00000000000000000000000000000000 P 2b54150c9b764b16b5a4e11d09175bce: Rolled over to a new segment: /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375/minicluster-data/master-0/yb-data/master/wals/table-sys.catalog.uuid/tablet-00000000000000000000000000000000/wal-000000003 [m-1] I0619 23:50:54.925268 180106 pg_ddl.cc:141] PgCreateTable: creating a transactional table: template1.pg_type [m-1] I0619 23:50:54.926431 179403 catalog_manager.cc:1662] CreateTable from 127.0.0.1:46142: pg_type [m-1] I0619 23:50:54.926555 179403 partition.cc:388] Creating partitions with num_tablets: 1 [m-1] 2019-06-19 23:50:55.679 UTC [180106] FATAL: unrecognized type "anyarray" [m-1] 2019-06-19 23:50:55.679 UTC [180106] WARNING: cannot remove relcache entry for "pg_proc" because it has nonzero refcount [m-1] 2019-06-19 23:50:55.679 UTC [180106] WARNING: cannot remove relcache entry for "pg_type" because it has nonzero refcount [m-1] W0619 23:50:55.683619 180113 outbound_call.cc:171] Failed to schedule invoking callback on response for request yb.tserver.TabletServerService.UpdateTransaction to 127.0.0.1: Aborted (yb/rpc/thread_pool.cc:249): Service is shutting down [m-1] W0619 23:50:55.686538 180114 outbound_call.cc:171] Failed to schedule invoking callback on response for request yb.tserver.TabletServerService.AbortTransaction to 127.188.175.0: Aborted (yb/rpc/thread_pool.cc:249): Service is shutting down [m-1] W0619 23:50:55.687992 180114 rpc.cc:156] Aborted (yb/rpc/rpc.cc:155): Failed to schedule: 0x00000000027d1c80 -> AbortTransaction: tablet_id: "201492fb94de461286b09472fb03df35" transaction_id: "\226\002\tL\363@F<\212\220YC\204\367:A" propagated_hybrid_time: 6393807895264874496, retrier: { task_id: -1 state: kScheduling deadline: 17309.188s } [ts-1] I0619 23:50:55.688490 179434 tcp_stream.cc:292] { local: 127.188.175.0:15681 remote: 127.0.0.1:50866 }: Recv failed: Network error (yb/util/net/socket.cc:590): recvmsg error: Connection reset by peer (error 104) [m-1] child process exited with exit code 1initdb: removing data directory "/tmp/tmp_pg_data_615188689" [m-1] I0619 23:50:55.706691 179417 pg_wrapper.cc:206] initdb took 16306 ms [m-1] E0619 23:50:55.706761 179417 pg_wrapper.cc:210] initdb failed: Runtime error (yb/yql/pgwrapper/pg_wrapper.cc:140): /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/postgres/bin/initdb failed with exit code 256 [m-1] E0619 23:50:55.706828 179417 catalog_manager.cc:4389] initdb failed: Runtime error (yb/yql/pgwrapper/pg_wrapper.cc:140): /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/postgres/bin/initdb failed with exit code 256 E0619 23:50:56.084017 179375 external_mini_cluster.cc:1003] master reported an initdb error: Runtime error (yb/yql/pgwrapper/pg_wrapper.cc:140): /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/postgres/bin/initdb failed with exit code 256 ../../src/yb/yql/pgwrapper/pg_wrapper_test_base.cc:69: Failure Failed Bad status: Runtime error (yb/integration-tests/external_mini_cluster.cc:1004): initdb failed: Runtime error (yb/yql/pgwrapper/pg_wrapper.cc:140): /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/postgres/bin/initdb failed with exit code 256 Test failure stack trace: ../../src/yb/yql/pgwrapper/pg_wrapper_test_base.cc:69: @ 0x7f73bc66ec4a yb::pgwrapper::PgWrapperTestBase::SetUp() ../../src/yb/yql/pgwrapper/create_initial_sys_catalog_snapshot.cc:32: @ 0x406576 yb::pgwrapper::CreateInitialSysCatalogSnapshotTest::SetUp() I0619 23:50:56.506422 179375 external_mini_cluster.cc:1774] { daemon_id: m-1 bound_rpc: :0 } Starting Shutdown() I0619 23:50:56.506494 179375 external_mini_cluster.cc:1817] Killing /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/tests-pgwrapper/../bin/yb-master with pid 179383 with SIGKILL I0619 23:50:56.519313 179375 external_mini_cluster.cc:1774] { daemon_id: ts-1 bound_rpc: :0 } Starting Shutdown() I0619 23:50:56.519383 179375 external_mini_cluster.cc:1817] Killing /net/dev-server-mbautin-4cpu-15gb-1/share/code/yugabyte/build/debug-gcc-dynamic-enterprise-ninja/tests-pgwrapper/../bin/yb-tserver with pid 179412 with SIGKILL [m-1 stdout] running bootstrap script ... [ts-1] 2019-06-19 23:50:56.519 UTC [179426] LOG: received fast shutdown request [ts-1] 2019-06-19 23:50:56.522 UTC [179426] LOG: aborting any active transactions [ts-1] 2019-06-19 23:50:56.522 UTC [179469] FATAL: terminating background worker "YSQL webserver" due to administrator command I0619 23:50:56.530057 179375 test_util.cc:95] ----------------------------------------------- I0619 23:50:56.530092 179375 test_util.cc:96] Had fatal failures, leaving test files at /tmp/yb_test.tmp.1146.32628.13588.pid179311/create_initial_sys_catalog_snapshot.CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot.1560988178398087-179375 [ FAILED ] CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot (78115 ms) [----------] 1 test from CreateInitialSysCatalogSnapshotTest (78115 ms total) [----------] Global test environment tear-down [==========] 1 test from 1 test case ran. (78116 ms total) [ PASSED ] 0 tests. [ FAILED ] 1 test, listed below: [ FAILED ] CreateInitialSysCatalogSnapshotTest.CreateInitialSysCatalogSnapshot 1 FAILED TEST I0619 23:50:56.546316 179374 run-with-timeout.cc:196] subprocess.Wait finished, waitpid() returned 256 I0619 23:50:56.546409 179374 run-with-timeout.cc:203] Waiting for reaper thread to join I0619 23:50:56.546504 179376 run-with-timeout.cc:181] Reaper thread: finished=1, subprocess_is_running=0 I0619 23:50:56.546612 179374 run-with-timeout.cc:207] Child process returned exit code 1 I0619 23:50:56.546619 179374 run-with-timeout.cc:222] Returning exit code 1 I0619 23:50:56.546667 179374 run-with-timeout.cc:224] Total time taken: 78.617 sec