Project

General

Profile

Bug #8947 » ceph-osd.0.log

log for crashed osd - Mallikarjun Biradar, 07/28/2014 08:15 AM

 
-52> 2014-07-25 18:27:00.388024 7fcf7593c700 5 -- op tracker -- , seq: 2274, time: 2014-07-25 18:27:00.162807, event: header_read, op: pg_info(1 pgs e82:6.2c)
-51> 2014-07-25 18:27:00.388036 7fcf7593c700 5 -- op tracker -- , seq: 2274, time: 2014-07-25 18:27:00.162808, event: throttled, op: pg_info(1 pgs e82:6.2c)
-50> 2014-07-25 18:27:00.388047 7fcf7593c700 5 -- op tracker -- , seq: 2274, time: 2014-07-25 18:27:00.162849, event: all_read, op: pg_info(1 pgs e82:6.2c)
-49> 2014-07-25 18:27:00.388057 7fcf7593c700 5 -- op tracker -- , seq: 2274, time: 2014-07-25 18:27:00.388020, event: dispatched, op: pg_info(1 pgs e82:6.2c)
-48> 2014-07-25 18:27:00.388068 7fcf7593c700 5 -- op tracker -- , seq: 2274, time: 2014-07-25 18:27:00.388066, event: waiting_for_osdmap, op: pg_info(1 pgs e82:6.2c)
-47> 2014-07-25 18:27:00.388081 7fcf7593c700 5 -- op tracker -- , seq: 2274, time: 2014-07-25 18:27:00.388078, event: started, op: pg_info(1 pgs e82:6.2c)
-46> 2014-07-25 18:27:00.388104 7fcf7593c700 5 -- op tracker -- , seq: 2274, time: 2014-07-25 18:27:00.388100, event: done, op: pg_info(1 pgs e82:6.2c)
-45> 2014-07-25 18:27:00.388116 7fcf6d92c700 2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 42294 > 104857600
-44> 2014-07-25 18:27:00.388121 7fcf7593c700 1 -- 10.66.26.5:6802/14571 <== osd.1 10.242.24.111:6801/31290 1200 ==== pg_info(1 pgs e82:4.42) v4 ==== 706+0+0 (2804748993 0 0) 0x5efe700 con 0x3885760
-43> 2014-07-25 18:27:00.388139 7fcf7593c700 5 -- op tracker -- , seq: 2275, time: 2014-07-25 18:27:00.162874, event: header_read, op: pg_info(1 pgs e82:4.42)
-42> 2014-07-25 18:27:00.388150 7fcf7593c700 5 -- op tracker -- , seq: 2275, time: 2014-07-25 18:27:00.162874, event: throttled, op: pg_info(1 pgs e82:4.42)
-41> 2014-07-25 18:27:00.388161 7fcf7593c700 5 -- op tracker -- , seq: 2275, time: 2014-07-25 18:27:00.162917, event: all_read, op: pg_info(1 pgs e82:4.42)
-40> 2014-07-25 18:27:00.388172 7fcf7593c700 5 -- op tracker -- , seq: 2275, time: 2014-07-25 18:27:00.388134, event: dispatched, op: pg_info(1 pgs e82:4.42)
-39> 2014-07-25 18:27:00.388184 7fcf7593c700 5 -- op tracker -- , seq: 2275, time: 2014-07-25 18:27:00.388181, event: waiting_for_osdmap, op: pg_info(1 pgs e82:4.42)
-38> 2014-07-25 18:27:00.388197 7fcf7593c700 5 -- op tracker -- , seq: 2275, time: 2014-07-25 18:27:00.388194, event: started, op: pg_info(1 pgs e82:4.42)
-37> 2014-07-25 18:27:00.388202 7fcf6d92c700 2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 42294 > 104857600
-36> 2014-07-25 18:27:00.388217 7fcf7593c700 5 -- op tracker -- , seq: 2275, time: 2014-07-25 18:27:00.388215, event: done, op: pg_info(1 pgs e82:4.42)
-35> 2014-07-25 18:27:00.388234 7fcf7593c700 1 -- 10.66.26.5:6802/14571 <== osd.1 10.242.24.111:6801/31290 1201 ==== pg_info(1 pgs e82:6.2a) v4 ==== 706+0+0 (983638987 0 0) 0x397d880 con 0x3885760
-34> 2014-07-25 18:27:00.388251 7fcf7593c700 5 -- op tracker -- , seq: 2276, time: 2014-07-25 18:27:00.163018, event: header_read, op: pg_info(1 pgs e82:6.2a)
-33> 2014-07-25 18:27:00.388263 7fcf7593c700 5 -- op tracker -- , seq: 2276, time: 2014-07-25 18:27:00.163020, event: throttled, op: pg_info(1 pgs e82:6.2a)
-32> 2014-07-25 18:27:00.388274 7fcf7593c700 5 -- op tracker -- , seq: 2276, time: 2014-07-25 18:27:00.163111, event: all_read, op: pg_info(1 pgs e82:6.2a)
-31> 2014-07-25 18:27:00.388286 7fcf7593c700 5 -- op tracker -- , seq: 2276, time: 2014-07-25 18:27:00.388247, event: dispatched, op: pg_info(1 pgs e82:6.2a)
-30> 2014-07-25 18:27:00.388297 7fcf7593c700 5 -- op tracker -- , seq: 2276, time: 2014-07-25 18:27:00.388294, event: waiting_for_osdmap, op: pg_info(1 pgs e82:6.2a)
-29> 2014-07-25 18:27:00.388300 7fcf6d92c700 2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 42294 > 104857600
-28> 2014-07-25 18:27:00.388311 7fcf7593c700 5 -- op tracker -- , seq: 2276, time: 2014-07-25 18:27:00.388308, event: started, op: pg_info(1 pgs e82:6.2a)
-27> 2014-07-25 18:27:00.388333 7fcf7593c700 5 -- op tracker -- , seq: 2276, time: 2014-07-25 18:27:00.388330, event: done, op: pg_info(1 pgs e82:6.2a)
-26> 2014-07-25 18:27:00.388350 7fcf7593c700 1 -- 10.66.26.5:6802/14571 <== osd.1 10.242.24.111:6801/31290 1202 ==== pg_info(1 pgs e82:6.40) v4 ==== 714+0+0 (1500871088 0 0) 0x609e380 con 0x3885760
-25> 2014-07-25 18:27:00.388367 7fcf7593c700 5 -- op tracker -- , seq: 2277, time: 2014-07-25 18:27:00.163166, event: header_read, op: pg_info(1 pgs e82:6.40)
-24> 2014-07-25 18:27:00.388379 7fcf7593c700 5 -- op tracker -- , seq: 2277, time: 2014-07-25 18:27:00.163167, event: throttled, op: pg_info(1 pgs e82:6.40)
-23> 2014-07-25 18:27:00.388390 7fcf7593c700 5 -- op tracker -- , seq: 2277, time: 2014-07-25 18:27:00.163247, event: all_read, op: pg_info(1 pgs e82:6.40)
-22> 2014-07-25 18:27:00.388400 7fcf7593c700 5 -- op tracker -- , seq: 2277, time: 2014-07-25 18:27:00.388363, event: dispatched, op: pg_info(1 pgs e82:6.40)
-21> 2014-07-25 18:27:00.388411 7fcf7593c700 5 -- op tracker -- , seq: 2277, time: 2014-07-25 18:27:00.388409, event: waiting_for_osdmap, op: pg_info(1 pgs e82:6.40)
-20> 2014-07-25 18:27:00.388424 7fcf7593c700 5 -- op tracker -- , seq: 2277, time: 2014-07-25 18:27:00.388421, event: started, op: pg_info(1 pgs e82:6.40)
-19> 2014-07-25 18:27:00.388445 7fcf7593c700 5 -- op tracker -- , seq: 2277, time: 2014-07-25 18:27:00.388442, event: done, op: pg_info(1 pgs e82:6.40)
-18> 2014-07-25 18:27:00.388470 7fcf6d92c700 2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 42294 > 104857600
-17> 2014-07-25 18:27:00.388474 7fcf7593c700 1 -- 10.66.26.5:6802/14571 <== osd.1 10.242.24.111:6801/31290 1203 ==== pg_info(1 pgs e82:4.4b) v4 ==== 706+0+0 (985224243 0 0) 0x5f76fc0 con 0x3885760
-16> 2014-07-25 18:27:00.388488 7fcf7593c700 5 -- op tracker -- , seq: 2278, time: 2014-07-25 18:27:00.163270, event: header_read, op: pg_info(1 pgs e82:4.4b)
-15> 2014-07-25 18:27:00.388501 7fcf7593c700 5 -- op tracker -- , seq: 2278, time: 2014-07-25 18:27:00.163271, event: throttled, op: pg_info(1 pgs e82:4.4b)
-14> 2014-07-25 18:27:00.388513 7fcf7593c700 5 -- op tracker -- , seq: 2278, time: 2014-07-25 18:27:00.163315, event: all_read, op: pg_info(1 pgs e82:4.4b)
-13> 2014-07-25 18:27:00.388495 7fcf63117700 -1 *** Caught signal (Aborted) **
in thread 7fcf63117700

ceph version andisk-sprint-2-drop-3-390-g2dbd85c (2dbd85c94cf27a1ff0419c5ea9359af7fe30e9b6)
1: /usr/bin/ceph-osd() [0x974a1f]
2: (()+0x10340) [0x7fcf85f3b340]
3: (gsignal()+0x39) [0x7fcf8420ff79]
4: (abort()+0x148) [0x7fcf84213388]
5: (__gnu_cxx::__verbose_terminate_handler()+0x155) [0x7fcf84b1b6b5]
6: (()+0x5e836) [0x7fcf84b19836]
7: (()+0x5e863) [0x7fcf84b19863]
8: (()+0x5eaa2) [0x7fcf84b19aa2]
9: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x1f2) [0xa5a692]
10: (ReplicatedPG::agent_estimate_atime_temp(hobject_t const&, int*, int*)+0x12e) [0x7ad25e]
11: (ReplicatedPG::agent_maybe_evict(std::tr1::shared_ptr<ObjectContext>&)+0x7a) [0x7e1a2a]
12: (ReplicatedPG::agent_work(int)+0xf45) [0x7fb1d5]
13: (OSDService::agent_entry()+0x557) [0x6090c7]
14: (OSDService::AgentThread::entry()+0xd) [0x67201d]
15: (()+0x8182) [0x7fcf85f33182]
16: (clone()+0x6d) [0x7fcf842d430d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

-12> 2014-07-25 18:27:00.388539 7fcf6d92c700 2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 42294 > 104857600
-11> 2014-07-25 18:27:00.388525 7fcf7593c700 5 -- op tracker -- , seq: 2278, time: 2014-07-25 18:27:00.388484, event: dispatched, op: pg_info(1 pgs e82:4.4b)
-10> 2014-07-25 18:27:00.388560 7fcf7593c700 5 -- op tracker -- , seq: 2278, time: 2014-07-25 18:27:00.388557, event: waiting_for_osdmap, op: pg_info(1 pgs e82:4.4b)
-9> 2014-07-25 18:27:00.388571 7fcf7593c700 5 -- op tracker -- , seq: 2278, time: 2014-07-25 18:27:00.388568, event: started, op: pg_info(1 pgs e82:4.4b)
-8> 2014-07-25 18:27:00.388589 7fcf7593c700 5 -- op tracker -- , seq: 2278, time: 2014-07-25 18:27:00.388586, event: done, op: pg_info(1 pgs e82:4.4b)
-7> 2014-07-25 18:27:00.388603 7fcf7593c700 1 -- 10.66.26.5:6802/14571 <== osd.1 10.242.24.111:6801/31290 1204 ==== pg_info(1 pgs e82:6.57) v4 ==== 714+0+0 (3282611884 0 0) 0x376d640 con 0x3885760
-6> 2014-07-25 18:27:00.388623 7fcf7593c700 5 -- op tracker -- , seq: 2279, time: 2014-07-25 18:27:00.163393, event: header_read, op: pg_info(1 pgs e82:6.57)
-5> 2014-07-25 18:27:00.388595 7fcf70131700 1 -- 10.66.26.5:6813/14571 <== osd.3 10.242.24.154:6805/25202 1 ==== osd_op_reply(1 obj7 [list-snaps] v0'0 uv0 ack = -2 ((2) No such file or directory)) v6 ==== 171+0+0 (1446310934 0 0) 0x3b83c00 con 0x531a100
-4> 2014-07-25 18:27:00.388635 7fcf7593c700 5 -- op tracker -- , seq: 2279, time: 2014-07-25 18:27:00.163395, event: throttled, op: pg_info(1 pgs e82:6.57)
-3> 2014-07-25 18:27:00.388646 7fcf7593c700 5 -- op tracker -- , seq: 2279, time: 2014-07-25 18:27:00.163443, event: all_read, op: pg_info(1 pgs e82:6.57)
-2> 2014-07-25 18:27:00.388657 7fcf7593c700 5 -- op tracker -- , seq: 2279, time: 2014-07-25 18:27:00.388618, event: dispatched, op: pg_info(1 pgs e82:6.57)
-1> 2014-07-25 18:27:00.388669 7fcf7593c700 5 -- op tracker -- , seq: 2279, time: 2014-07-25 18:27:00.388666, event: waiting_for_osdmap, op: pg_info(1 pgs e82:6.57)
0> 2014-07-25 18:27:00.388682 7fcf7593c700 5 -- op tracker -- , seq: 2279, time: 2014-07-25 18:27:00.388679, event: started, op: pg_info(1 pgs e82:6.57)
--- logging levels ---
0/ 5 none
0/ 1 lockdep
0/ 1 context
1/ 1 crush
1/ 5 mds
1/ 5 mds_balancer
1/ 5 mds_locker
1/ 5 mds_log
1/ 5 mds_log_expire
1/ 5 mds_migrator
0/ 1 buffer
0/ 1 timer
0/ 1 filer
0/ 1 striper
0/ 1 objecter
0/ 5 rados
0/ 5 rbd
0/ 5 journaler
0/ 5 objectcacher
0/ 5 client
0/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 keyvaluestore
1/ 3 journal
0/ 5 ms
1/ 5 mon
0/10 monc
1/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
-2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 10000
max_new 1000
log_file /var/log/ceph/ceph-osd.0.log
--- end dump of recent events ---

(1-1/5)