Project

General

Profile

Bug #21028 » ceph-osd.69.log

Artem Karamyshev, 08/17/2017 06:01 PM

 
2017-08-17 18:05:57.776598 7fae72299700 0 -- 172.28.6.131:6803/15073 >> 172.28.1.20:0/2595858835 conn(0x7fae9e98e800 :6803 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=1).handle_connect_msg accept replacing existing (lossy) channel (new one lossy=1)
2017-08-17 18:19:37.960961 7fae5d2b6700 0 log_channel(cluster) log [DBG] : 5.df7 scrub starts
2017-08-17 18:19:38.157093 7fae5d2b6700 0 log_channel(cluster) log [DBG] : 5.df7 scrub ok
2017-08-17 18:26:44.020700 7fae5b2b2700 0 log_channel(cluster) log [DBG] : 4.ae scrub starts
2017-08-17 18:26:44.156961 7fae5b2b2700 0 log_channel(cluster) log [DBG] : 4.ae scrub ok
2017-08-17 18:36:43.137739 7fae71a98700 0 -- 172.28.6.3:6847/1015073 >> 172.28.6.4:6866/27817 conn(0x7faea26b4800 :6847 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept connect_seq 15 vs existing csq=15 existing_state=STATE_STANDBY
2017-08-17 18:36:43.138696 7fae71a98700 0 -- 172.28.6.3:6847/1015073 >> 172.28.6.4:6866/27817 conn(0x7faea26b4800 :6847 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept connect_seq 16 vs existing csq=15 existing_state=STATE_STANDBY
2017-08-17 18:39:25.081697 7fae64ac5700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.1.4/rpm/el7/BUILD/ceph-12.1.4/src/rocksdb/db/db_impl_write.cc:684] reusing log 734 from recycle list
2017-08-17 18:39:25.081860 7fae64ac5700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.1.4/rpm/el7/BUILD/ceph-12.1.4/src/rocksdb/db/db_impl_write.cc:725] [default] New memtable created with log file: #741. Immutable memtables: 0.
2017-08-17 18:39:25.091390 7fae552a6700 4 rocksdb: (Original Log Time 2017/08/17-18:39:25.081926) [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.1.4/rpm/el7/BUILD/ceph-12.1.4/src/rocksdb/db/db_impl_compaction_flush.cc:1158] Calling FlushMemTableToOutputFile with column family [default], flush slots available 1, compaction slots allowed 1, compaction slots scheduled 1
2017-08-17 18:39:25.091412 7fae552a6700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.1.4/rpm/el7/BUILD/ceph-12.1.4/src/rocksdb/db/flush_job.cc:264] [default] [JOB 34] Flushing memtable with next log file: 741
2017-08-17 18:39:25.091456 7fae552a6700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1502984365091425, "job": 34, "event": "flush_started", "num_memtables": 1, "num_entries": 640290, "num_deletes": 73661, "memory_usage": 260061464}
2017-08-17 18:39:25.091462 7fae552a6700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.1.4/rpm/el7/BUILD/ceph-12.1.4/src/rocksdb/db/flush_job.cc:293] [default] [JOB 34] Level-0 flush table #742: started
2017-08-17 18:39:25.310298 7fae552a6700 4 rocksdb: EVENT_LOG_v1 {"time_micros": 1502984365310279, "cf_name": "default", "job": 34, "event": "table_file_creation", "file_number": 742, "file_size": 8139842, "table_properties": {"data_size": 7706663, "index_size": 123390, "filter_size": 308800, "raw_key_size": 6077225, "raw_average_key_size": 52, "raw_value_size": 5829968, "raw_average_value_size": 50, "num_data_blocks": 1881, "num_entries": 116416, "filter_policy_name": "rocksdb.BuiltinBloomFilter", "kDeletedKeys": "48672", "kMergeOperands": "2958"}}
2017-08-17 18:39:25.310318 7fae552a6700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.1.4/rpm/el7/BUILD/ceph-12.1.4/src/rocksdb/db/flush_job.cc:319] [default] [JOB 34] Level-0 flush table #742: 8139842 bytes OK
2017-08-17 18:39:25.327933 7fae552a6700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.1.4/rpm/el7/BUILD/ceph-12.1.4/src/rocksdb/db/db_impl_files.cc:242] adding log 736 to recycle list
2017-08-17 18:39:25.327951 7fae552a6700 4 rocksdb: (Original Log Time 2017/08/17-18:39:25.310331) [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.1.4/rpm/el7/BUILD/ceph-12.1.4/src/rocksdb/db/memtable_list.cc:360] [default] Level-0 commit table #742 started
2017-08-17 18:39:25.327956 7fae552a6700 4 rocksdb: (Original Log Time 2017/08/17-18:39:25.327870) [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.1.4/rpm/el7/BUILD/ceph-12.1.4/src/rocksdb/db/memtable_list.cc:383] [default] Level-0 commit table #742: memtable #1 done
2017-08-17 18:39:25.327958 7fae552a6700 4 rocksdb: (Original Log Time 2017/08/17-18:39:25.327886) EVENT_LOG_v1 {"time_micros": 1502984365327879, "job": 34, "event": "flush_finished", "lsm_state": [1, 3, 0, 0, 0, 0, 0], "immutable_memtables": 0}
2017-08-17 18:39:25.327962 7fae552a6700 4 rocksdb: (Original Log Time 2017/08/17-18:39:25.327912) [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.1.4/rpm/el7/BUILD/ceph-12.1.4/src/rocksdb/db/db_impl_compaction_flush.cc:132] [default] Level summary: base level 1 max bytes base 268435456 files[1 3 0 0 0 0 0] max score 0.71
2017-08-17 18:39:25.327971 7fae552a6700 4 rocksdb: [/home/jenkins-build/build/workspace/ceph-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos7/DIST/centos7/MACHINE_SIZE/huge/release/12.1.4/rpm/el7/BUILD/ceph-12.1.4/src/rocksdb/db/db_impl_files.cc:388] [JOB 34] Try to delete WAL files size 245595380, prev total WAL file size 245665302, number of live WAL files 2.
2017-08-17 18:41:50.495913 7fae72299700 0 -- 172.28.6.3:6847/1015073 >> 172.28.4.130:6809/24279 conn(0x7faeac8f4000 :6847 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept connect_seq 17 vs existing csq=17 existing_state=STATE_STANDBY
2017-08-17 18:41:50.496609 7fae72299700 0 -- 172.28.6.3:6847/1015073 >> 172.28.4.130:6809/24279 conn(0x7faeac8f4000 :6847 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept connect_seq 18 vs existing csq=17 existing_state=STATE_STANDBY
2017-08-17 18:47:02.182711 7fae5cab5700 0 log_channel(cluster) log [DBG] : 5.5ba scrub starts
2017-08-17 18:47:02.355241 7fae5cab5700 0 log_channel(cluster) log [DBG] : 5.5ba scrub ok
2017-08-17 18:55:14.245908 7fae6dad7700 0 log_channel(cluster) log [WRN] : 1 slow requests, 1 included below; oldest blocked for > 30.113067 secs
2017-08-17 18:55:14.245921 7fae6dad7700 0 log_channel(cluster) log [WRN] : slow request 30.113067 seconds old, received at 2017-08-17 18:54:44.132765: osd_op(client.102678393.0:2104386 5.a08 5:10585d96:::rbd_data.1da7137e2e8611.0000000000000000:head [stat,write 1049600~512] snapc 0=[] ondisk+write+known_if_redirected e28759) currently op_applied

(4-4/4)