Project

General

Profile

Bug #1195 » mds.alpha.log

Sam Lang, 06/17/2011 09:38 AM

 
2011-06-15 12:45:15.675830 7f836ff2f740 ceph version .commit: . process: cmds. pid: 31959
2011-06-15 12:45:15.683365 7f836cae3700 mds-1.0 ms_handle_connect on 192.168.60.104:6789/0
2011-06-15 12:45:32.499375 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 12:46:13.662289 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 12:46:21.654278 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 12:46:06.654125, we are laggy!
2011-06-15 12:46:22.198614 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 12:55:43.136757 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 13:27:38.864343 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:27:23.560788, we are laggy!
2011-06-15 13:27:46.290287 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:27:27.560908, we are laggy!
2011-06-15 13:27:46.290335 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 13:27:46.561166 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:27:31.561026, we are laggy!
2011-06-15 13:27:58.260148 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:27:35.561153, we are laggy!
2011-06-15 13:27:58.260457 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:27:39.561263, we are laggy!
2011-06-15 13:27:58.261769 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 13:33:14.571882 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:32:59.571742, we are laggy!
2011-06-15 13:33:44.286428 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 13:33:44.369282 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 13:34:03.123570 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 13:34:12.675925 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 13:57:30.621665 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:57:15.621533, we are laggy!
2011-06-15 13:57:54.156660 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:57:23.621784, we are laggy!
2011-06-15 13:57:54.156894 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:57:27.621900, we are laggy!
2011-06-15 13:57:54.157058 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:57:35.622153, we are laggy!
2011-06-15 13:57:54.157087 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 13:58:00.050914 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 13:58:13.628922 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 13:58:22.623363 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:58:07.623200, we are laggy!
2011-06-15 13:58:42.954177 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 13:58:47.924745 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 13:58:50.279575 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 13:59:00.758632 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 13:59:06.624735 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 13:58:51.624629, we are laggy!
2011-06-15 13:59:30.770455 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 13:59:30.900541 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 14:09:02.645374 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 14:08:47.645262, we are laggy!
2011-06-15 14:09:28.764815 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 14:09:28.977217 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 14:14:22.657972 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 14:14:07.657835, we are laggy!
2011-06-15 14:15:28.953816 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 14:15:28.953887 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 14:16:18.661894 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 14:16:03.661782, we are laggy!
2011-06-15 14:16:21.650848 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 15:33:10.823562 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 15:32:55.823448, we are laggy!
2011-06-15 15:35:02.828693 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 15:34:47.828544, we are laggy!
2011-06-15 15:38:14.835238 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 15:37:59.835101, we are laggy!
2011-06-15 15:38:26.835804 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 15:38:11.835648, we are laggy!
2011-06-15 15:38:36.391601 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 15:38:19.835880, we are laggy!
2011-06-15 15:38:36.391669 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 15:39:46.839197 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 15:39:31.839078, we are laggy!
2011-06-15 15:40:27.417368 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 15:40:27.894792 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 15:40:07.840172, we are laggy!
2011-06-15 15:40:27.894926 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 15:40:11.840283, we are laggy!
2011-06-15 15:40:27.895172 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 15:44:58.849711 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 15:44:43.849593, we are laggy!
2011-06-15 15:45:18.885287 7f836cae3700 mds-1.0 handle_mds_map standby
2011-06-15 15:45:25.857878 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 16:06:10.894556 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 16:05:55.894419, we are laggy!
2011-06-15 16:06:17.559070 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-15 16:06:34.895392 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 16:06:19.895283, we are laggy!
2011-06-15 16:06:40.442530 7f836b8df700 mds-1.0 beacon_kill last_acked_stamp 2011-06-15 16:06:23.895399, we are laggy!
2011-06-15 16:06:40.442585 7f836cae3700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-16 15:49:29.267183 7f836cae3700 monclient: hunting for new mon
2011-06-16 15:49:29.267327 7f836cae3700 mds-1.0 ms_handle_reset on 192.168.60.104:6789/0
2011-06-16 15:49:29.267641 7f836b9e0700 -- 192.168.60.134:6800/31959 >> 192.168.60.129:6789/0 pipe(0x7f8364000b10 sd=5 pgs=0 cs=0 l=0).fault first fault
*** Caught signal (Terminated) **
in thread 0x7f836ff2f740. Shutting down.
2011-06-16 18:40:51.113283 7f28d985e740 ceph version .commit: . process: cmds. pid: 15049
2011-06-16 18:40:51.120089 7f28d5c11700 mds-1.0 ms_handle_connect on 192.168.60.134:6789/0
2011-06-16 18:40:58.277861 7f28d5c11700 mds-1.0 handle_mds_map standby
2011-06-16 18:41:01.238407 7f28d5c11700 mds-1.0 handle_mds_map standby
2011-06-16 18:41:04.127722 7f28d5c11700 mds-1.0 handle_mds_map standby
2011-06-16 18:41:05.263049 7f28d5c11700 mds-1.0 handle_mds_map standby
2011-06-16 18:41:11.325824 7f28d5c11700 mds-1.0 handle_mds_map standby
2011-06-16 18:41:59.249346 7f28d4a0d700 mds-1.0 beacon_kill last_acked_stamp 2011-06-16 18:41:44.249186, we are laggy!
2011-06-16 18:42:03.243331 7f28d5c11700 mds-1.0 handle_mds_map standby
2011-06-16 18:42:03.243601 7f28d5c11700 mds-1.0 handle_mds_beacon no longer laggy
2011-06-16 18:42:19.630489 7f28d5c11700 mds-1.0 handle_mds_map standby
2011-06-16 18:42:39.684799 7f28d5c11700 mds0.4 handle_mds_map i am now mds0.4
2011-06-16 18:42:39.684866 7f28d5c11700 mds0.4 handle_mds_map state change up:standby --> up:replay
2011-06-16 18:42:39.684895 7f28d5c11700 mds0.4 replay_start
2011-06-16 18:42:39.684926 7f28d5c11700 mds0.4 recovery set is
2011-06-16 18:42:39.684948 7f28d5c11700 mds0.4 need osdmap epoch 213, have 194
2011-06-16 18:42:39.684968 7f28d5c11700 mds0.4 waiting for osdmap 213 (which blacklists prior instance)
2011-06-16 18:42:39.685036 7f28d5c11700 mds0.cache handle_mds_failure mds0 : recovery peers are
2011-06-16 18:42:39.749409 7f28d5c11700 mds0.4 ms_handle_connect on 192.168.60.134:6804/15406
2011-06-16 18:42:39.750019 7f28d5c11700 mds0.4 ms_handle_connect on 192.168.60.135:6800/15479
2011-06-16 18:42:39.750088 7f28d5c11700 mds0.4 ms_handle_connect on 192.168.60.104:6810/16472
2011-06-16 18:42:39.750250 7f28d5c11700 mds0.4 ms_handle_connect on 192.168.60.135:6812/15828
2011-06-16 18:42:39.750764 7f28d5c11700 mds0.4 ms_handle_connect on 192.168.60.129:6804/4162
2011-06-16 18:42:40.776528 7f28d5c11700 mds0.4 ms_handle_connect on 192.168.60.134:6813/17187
2011-06-16 18:42:40.776629 7f28d5c11700 mds0.4 ms_handle_connect on 192.168.60.135:6803/15561
2011-06-16 18:42:46.774224 7f28d5c11700 mds0.cache creating system inode with ino:100
2011-06-16 18:42:46.774726 7f28d5c11700 mds0.cache creating system inode with ino:1
2011-06-16 18:42:46.775439 7f28d5c11700 mds0.4 ms_handle_connect on 192.168.60.134:6807/16267
2011-06-16 18:42:46.776330 7f28d5c11700 mds0.4 ms_handle_connect on 192.168.60.109:6810/7022
2011-06-16 18:42:46.776422 7f28d5c11700 mds0.4 ms_handle_connect on 192.168.60.132:6812/11667
*** Caught signal (Aborted) **
in thread 0x7f28d25f7700
ceph version (commit:)
1: (ceph::BackTrace::BackTrace(int)+0x2d) [0xa66ab7]
2: /usr/ceph/bin/cmds() [0xa9e73f]
3: (()+0xfc60) [0x7f28d8ecbc60]
4: (gsignal()+0x35) [0x7f28d83bad05]
5: (abort()+0x186) [0x7f28d83beab6]
6: (()+0x6cd7b) [0x7f28d83f3d7b]
7: (()+0x78a8f) [0x7f28d83ffa8f]
8: (cfree()+0x73) [0x7f28d84038e3]
9: (EMetaBlob::fullbit::update_inode(MDS*, CInode*)+0x1cc) [0x804376]
10: (EMetaBlob::replay(MDS*, LogSegment*)+0x1579) [0x80598f]
11: (EUpdate::replay(MDS*)+0x44) [0x8092e4]
12: (MDLog::_replay_thread()+0xd9a) [0x9fdf1c]
13: (MDLog::ReplayThread::entry()+0x1c) [0x7df302]
14: (Thread::_entry_func(void*)+0x23) [0x9fe9c5]
15: (()+0x6d8c) [0x7f28d8ec2d8c]
16: (clone()+0x6d) [0x7f28d846d04d]
2011-06-17 09:53:59.350736 7f64fe7ed740 ceph version .commit: . process: cmds. pid: 27315
2011-06-17 09:53:59.359362 7f64faba0700 mds-1.0 ms_handle_connect on 192.168.60.109:6789/0
2011-06-17 09:54:12.255661 7f64faba0700 mds-1.0 handle_mds_map standby
2011-06-17 09:54:43.583092 7f64f999c700 mds-1.0 beacon_kill last_acked_stamp 2011-06-17 09:54:28.582918, we are laggy!
2011-06-17 09:54:43.719134 7f64faba0700 mds0.8 handle_mds_map i am now mds0.8
2011-06-17 09:54:43.719205 7f64faba0700 mds0.8 handle_mds_map state change up:standby --> up:replay
2011-06-17 09:54:43.719230 7f64faba0700 mds0.8 replay_start
2011-06-17 09:54:43.719258 7f64faba0700 mds0.8 recovery set is
2011-06-17 09:54:43.719279 7f64faba0700 mds0.8 need osdmap epoch 236, have 225
2011-06-17 09:54:43.719298 7f64faba0700 mds0.8 waiting for osdmap 236 (which blacklists prior instance)
2011-06-17 09:54:43.719367 7f64faba0700 mds0.cache handle_mds_failure mds0 : recovery peers are
2011-06-17 09:54:43.827716 7f64faba0700 mds0.8 ms_handle_connect on 192.168.60.134:6804/27676
2011-06-17 09:54:43.844237 7f64faba0700 mds0.8 ms_handle_connect on 192.168.60.135:6800/29907
2011-06-17 09:54:43.844386 7f64faba0700 mds0.8 ms_handle_connect on 192.168.60.104:6810/13056
2011-06-17 09:54:43.844644 7f64faba0700 mds0.8 ms_handle_connect on 192.168.60.135:6812/30240
2011-06-17 09:54:43.848175 7f64faba0700 mds0.8 ms_handle_connect on 192.168.60.129:6804/29568
2011-06-17 09:54:44.671588 7f64faba0700 mds0.8 ms_handle_connect on 192.168.60.134:6813/29442
2011-06-17 09:54:44.672581 7f64faba0700 mds0.8 ms_handle_connect on 192.168.60.135:6803/29988
2011-06-17 09:54:47.583256 7f64f999c700 mds0.8 beacon_kill last_acked_stamp 2011-06-17 09:54:32.583116, we are laggy!
2011-06-17 09:55:42.841168 7f64faba0700 mds0.cache creating system inode with ino:100
2011-06-17 09:55:42.841647 7f64faba0700 mds0.cache creating system inode with ino:1
2011-06-17 09:55:42.842536 7f64faba0700 mds0.8 ms_handle_connect on 192.168.60.134:6807/28501
2011-06-17 09:55:42.843236 7f64faba0700 mds0.8 ms_handle_connect on 192.168.60.132:6812/25705
2011-06-17 09:55:42.843494 7f64faba0700 mds0.8 ms_handle_connect on 192.168.60.109:6810/736
*** Caught signal (Aborted) **
in thread 0x7f64f35f5700
ceph version (commit:)
1: (ceph::BackTrace::BackTrace(int)+0x2d) [0xa66ab7]
2: /usr/ceph/bin/cmds() [0xa9e73f]
3: (()+0xfc60) [0x7f64fde5ac60]
4: (gsignal()+0x35) [0x7f64fd349d05]
5: (abort()+0x186) [0x7f64fd34dab6]
6: (()+0x6cd7b) [0x7f64fd382d7b]
7: (()+0x78a8f) [0x7f64fd38ea8f]
8: (cfree()+0x73) [0x7f64fd3928e3]
9: (EMetaBlob::fullbit::update_inode(MDS*, CInode*)+0x1cc) [0x804376]
10: (EMetaBlob::replay(MDS*, LogSegment*)+0x1579) [0x80598f]
11: (EUpdate::replay(MDS*)+0x44) [0x8092e4]
12: (MDLog::_replay_thread()+0xd9a) [0x9fdf1c]
13: (MDLog::ReplayThread::entry()+0x1c) [0x7df302]
14: (Thread::_entry_func(void*)+0x23) [0x9fe9c5]
15: (()+0x6d8c) [0x7f64fde51d8c]
16: (clone()+0x6d) [0x7f64fd3fc04d]
2011-06-17 11:26:49.987207 7f8e53eaa740 ceph version .commit: . process: cmds. pid: 24005
2011-06-17 11:26:49.999843 7f8e5025d700 mds-1.0 ms_handle_connect on 192.168.60.109:6789/0
2011-06-17 11:27:01.921209 7f8e5025d700 mds-1.0 handle_mds_map standby
2011-06-17 11:27:02.976069 7f8e5025d700 mds-1.0 handle_mds_map standby
2011-06-17 11:27:11.981112 7f8e5025d700 mds0.12 handle_mds_map i am now mds0.12
2011-06-17 11:27:11.981192 7f8e5025d700 mds0.12 handle_mds_map state change up:standby --> up:replay
2011-06-17 11:27:11.981242 7f8e5025d700 mds0.12 replay_start
2011-06-17 11:27:11.981274 7f8e5025d700 mds0.12 recovery set is
2011-06-17 11:27:11.981295 7f8e5025d700 mds0.12 need osdmap epoch 252, have 245
2011-06-17 11:27:11.981315 7f8e5025d700 mds0.12 waiting for osdmap 252 (which blacklists prior instance)
2011-06-17 11:27:11.981616 7f8e5025d700 mds0.cache handle_mds_failure mds0 : recovery peers are
2011-06-17 11:27:11.986031 7f8e5025d700 mds0.12 ms_handle_connect on 192.168.60.135:6800/4842
2011-06-17 11:27:11.986934 7f8e5025d700 mds0.12 ms_handle_connect on 192.168.60.129:6804/4702
2011-06-17 11:27:12.000632 7f8e5025d700 mds0.12 ms_handle_connect on 192.168.60.104:6810/20964
2011-06-17 11:27:12.001663 7f8e5025d700 mds0.12 ms_handle_connect on 192.168.60.134:6804/24364
2011-06-17 11:27:12.004669 7f8e5025d700 mds0.12 ms_handle_connect on 192.168.60.104:6804/20843
2011-06-17 11:27:25.996883 7f8e5025d700 mds0.12 ms_handle_connect on 192.168.60.135:6812/5219
2011-06-17 11:27:36.678925 7f8e5025d700 mds0.12 ms_handle_connect on 192.168.60.135:6803/4926
2011-06-17 11:27:36.682667 7f8e5025d700 mds0.12 ms_handle_connect on 192.168.60.134:6813/26110
2011-06-17 11:27:56.895876 7f8e5025d700 mds0.cache creating system inode with ino:100
2011-06-17 11:27:56.896335 7f8e5025d700 mds0.cache creating system inode with ino:1
2011-06-17 11:27:56.897251 7f8e5025d700 mds0.12 ms_handle_connect on 192.168.60.134:6807/25185
2011-06-17 11:27:56.897957 7f8e5025d700 mds0.12 ms_handle_connect on 192.168.60.132:6812/32408
2011-06-17 11:27:56.898781 7f8e5025d700 mds0.12 ms_handle_connect on 192.168.60.109:6810/8954
*** Caught signal (Aborted) **
in thread 0x7f8e4ca41700
ceph version (commit:)
1: (ceph::BackTrace::BackTrace(int)+0x2d) [0xa66ab7]
2: /usr/ceph/bin/cmds() [0xa9e73f]
3: (()+0xfc60) [0x7f8e53517c60]
4: (gsignal()+0x35) [0x7f8e52a06d05]
5: (abort()+0x186) [0x7f8e52a0aab6]
6: (()+0x6cd7b) [0x7f8e52a3fd7b]
7: (()+0x78a8f) [0x7f8e52a4ba8f]
8: (cfree()+0x73) [0x7f8e52a4f8e3]
9: (EMetaBlob::fullbit::update_inode(MDS*, CInode*)+0x1cc) [0x804376]
10: (EMetaBlob::replay(MDS*, LogSegment*)+0x1579) [0x80598f]
11: (EUpdate::replay(MDS*)+0x44) [0x8092e4]
12: (MDLog::_replay_thread()+0xd9a) [0x9fdf1c]
13: (MDLog::ReplayThread::entry()+0x1c) [0x7df302]
14: (Thread::_entry_func(void*)+0x23) [0x9fe9c5]
15: (()+0x6d8c) [0x7f8e5350ed8c]
16: (clone()+0x6d) [0x7f8e52ab904d]
2011-06-17 11:32:58.032876 7f9969f33740 ceph version .commit: . process: cmds. pid: 31371
2011-06-17 11:32:58.033387 7f9969f33740 -- 0.0.0.0:6800/31371 accepter.bind ms_addr is 0.0.0.0:6800/31371 need_addr=1
2011-06-17 11:32:58.038369 7f9969f33740 -- 0.0.0.0:6800/31371 messenger.start
2011-06-17 11:32:58.038477 7f9969f33740 -- 0.0.0.0:6800/31371 accepter.start
2011-06-17 11:32:58.039125 7f9969f33740 mds-1.0 168 MDSCacheObject
2011-06-17 11:32:58.039170 7f9969f33740 mds-1.0 2192 CInode
2011-06-17 11:32:58.039189 7f9969f33740 mds-1.0 16 elist<>::item *7=112
2011-06-17 11:32:58.039208 7f9969f33740 mds-1.0 360 inode_t
2011-06-17 11:32:58.039231 7f9969f33740 mds-1.0 56 nest_info_t
2011-06-17 11:32:58.039249 7f9969f33740 mds-1.0 32 frag_info_t
2011-06-17 11:32:58.039268 7f9969f33740 mds-1.0 40 SimpleLock *5=200
2011-06-17 11:32:58.039286 7f9969f33740 mds-1.0 48 ScatterLock *3=144
2011-06-17 11:32:58.039319 7f9969f33740 mds-1.0 472 CDentry
2011-06-17 11:32:58.039337 7f9969f33740 mds-1.0 16 elist<>::item
2011-06-17 11:32:58.039353 7f9969f33740 mds-1.0 40 SimpleLock
2011-06-17 11:32:58.039370 7f9969f33740 mds-1.0 1560 CDir
2011-06-17 11:32:58.039673 7f9969f33740 mds-1.0 16 elist<>::item *2=32
2011-06-17 11:32:58.039697 7f9969f33740 mds-1.0 192 fnode_t
2011-06-17 11:32:58.039714 7f9969f33740 mds-1.0 56 nest_info_t *2
2011-06-17 11:32:58.039731 7f9969f33740 mds-1.0 32 frag_info_t *2
2011-06-17 11:32:58.039749 7f9969f33740 mds-1.0 168 Capability
2011-06-17 11:32:58.039767 7f9969f33740 mds-1.0 32 xlist<>::item *2=64
2011-06-17 11:32:58.040093 7f9969f33740 -- 0.0.0.0:6800/31371 --> 192.168.60.104:6789/0 -- auth(proto 0 30 bytes) v1 -- ?+0 0x29f3a90 con 0x29f3710
2011-06-17 11:32:58.041748 7f99652e4700 -- 192.168.60.134:6800/31371 learned my addr 192.168.60.134:6800/31371
2011-06-17 11:32:58.041871 7f99652e4700 mds-1.0 MDS::ms_get_authorizer type=mon
2011-06-17 11:32:58.042630 7f99662e6700 mds-1.0 ms_handle_connect on 192.168.60.104:6789/0
2011-06-17 11:32:59.440321 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 1 ==== auth_reply(proto 1 0 Success) v1 ==== 24+0+0 (4036561064 0 0) 0x29f3a90 con 0x29f3710
2011-06-17 11:32:59.440514 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mon_subscribe({monmap=0+}) v1 -- ?+0 0x29f3ca0 con 0x29f3710
2011-06-17 11:32:59.440832 7f9969f33740 mds-1.0 beacon_send up:boot seq 1 (currently up:boot)
2011-06-17 11:32:59.440953 7f9969f33740 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:boot seq 1 v0) v1 -- ?+0 0x29f3ec0 con 0x29f3710
2011-06-17 11:32:59.441094 7f9969f33740 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mon_subscribe({monmap=0+,osdmap=0}) v1 -- ?+0 0x29f5320 con 0x29f3710
2011-06-17 11:32:59.441191 7f9969f33740 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mon_subscribe({mdsmap=0+,monmap=0+,osdmap=0}) v1 -- ?+0 0x29f3ec0 con 0x29f3710
2011-06-17 11:32:59.441480 7f9969f33740 mds-1.0 open_logger
2011-06-17 11:32:59.497150 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 2 ==== mon_map v1 ==== 625+0+0 (3503596045 0 0) 0x29f5f80 con 0x29f3710
2011-06-17 11:32:59.497501 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 3 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (1282756199 0 0) 0x29f5f80 con 0x29f3710
2011-06-17 11:32:59.498578 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 4 ==== mon_map v1 ==== 625+0+0 (3503596045 0 0) 0x29f62f0 con 0x29f3710
2011-06-17 11:32:59.500274 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 5 ==== osd_map(260,260) v1 ==== 15259+0+0 (2366231345 0 0) 0x29f5cd0 con 0x29f3710
2011-06-17 11:32:59.501350 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 6 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (1282756199 0 0) 0x29f5f80 con 0x29f3710
2011-06-17 11:32:59.501437 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 7 ==== mdsmap(e 3042) v1 ==== 531+0+0 (813477938 0 0) 0x29fa280 con 0x29f3710
2011-06-17 11:32:59.501496 7f99662e6700 mds-1.0 handle_mds_map epoch 3042 from mon3
2011-06-17 11:32:59.501615 7f99662e6700 mds-1.0 my compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:32:59.501661 7f99662e6700 mds-1.0 mdsmap compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:32:59.501721 7f99662e6700 mds-1.-1 map says i am 192.168.60.134:6800/31371 mds-1.-1 state down:dne
2011-06-17 11:32:59.501767 7f99662e6700 mds-1.-1 not in map yet
2011-06-17 11:32:59.501847 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 8 ==== mon_map v1 ==== 625+0+0 (3503596045 0 0) 0x29f62f0 con 0x29f3710
2011-06-17 11:32:59.502525 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 9 ==== osd_map(260,260) v1 ==== 15259+0+0 (2366231345 0 0) 0x29f6260 con 0x29f3710
2011-06-17 11:32:59.502773 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 10 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (1282756199 0 0) 0x29f6260 con 0x29f3710
2011-06-17 11:33:03.441161 7f99650e2700 mds-1.-1 beacon_send up:boot seq 2 (currently down:dne)
2011-06-17 11:33:03.441306 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:boot seq 2 v3042) v1 -- ?+0 0x29f6260 con 0x29f3710
2011-06-17 11:33:04.441522 7f99650e2700 mds-1.bal get_load no root, no load
2011-06-17 11:33:04.441768 7f99650e2700 mds-1.bal get_load mdsload<[0,0 0]/[0,0 0], req 0, hr 0, qlen 0, cpu 0.32>
2011-06-17 11:33:06.478549 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 11 ==== mdsmap(e 3043) v1 ==== 738+0+0 (3451507813 0 0) 0x29f68c0 con 0x29f3710
2011-06-17 11:33:06.478622 7f99662e6700 mds-1.-1 handle_mds_map epoch 3043 from mon3
2011-06-17 11:33:06.478702 7f99662e6700 mds-1.-1 my compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:33:06.478729 7f99662e6700 mds-1.-1 mdsmap compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:33:06.478754 7f99662e6700 mds-1.-1 map says i am 192.168.60.134:6800/31371 mds-1.-1 state down:dne
2011-06-17 11:33:06.478773 7f99662e6700 mds-1.-1 not in map yet
2011-06-17 11:33:07.441446 7f99650e2700 mds-1.-1 beacon_send up:boot seq 3 (currently down:dne)
2011-06-17 11:33:07.441559 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:boot seq 3 v3043) v1 -- ?+0 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:08.095429 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 12 ==== mdsmap(e 3044) v1 ==== 939+0+0 (3825283206 0 0) 0x29f6850 con 0x29f3710
2011-06-17 11:33:08.095493 7f99662e6700 mds-1.-1 handle_mds_map epoch 3044 from mon3
2011-06-17 11:33:08.095578 7f99662e6700 mds-1.-1 my compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:33:08.095602 7f99662e6700 mds-1.-1 mdsmap compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:33:08.095627 7f99662e6700 mds-1.-1 map says i am 192.168.60.134:6800/31371 mds-1.-1 state down:dne
2011-06-17 11:33:08.095647 7f99662e6700 mds-1.-1 not in map yet
2011-06-17 11:33:09.441577 7f99650e2700 mds-1.bal get_load no root, no load
2011-06-17 11:33:09.441701 7f99650e2700 mds-1.bal get_load mdsload<[0,0 0]/[0,0 0], req 0, hr 0, qlen 0, cpu 0.62>
2011-06-17 11:33:10.655183 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 13 ==== mdsmap(e 3045) v1 ==== 1145+0+0 (2947328772 0 0) 0x29f66f0 con 0x29f3710
2011-06-17 11:33:10.655302 7f99662e6700 mds-1.-1 handle_mds_map epoch 3045 from mon3
2011-06-17 11:33:10.655474 7f99662e6700 mds-1.-1 my compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:33:10.655527 7f99662e6700 mds-1.-1 mdsmap compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:33:10.655574 7f99662e6700 mds-1.-1 map says i am 192.168.60.134:6800/31371 mds-1.-1 state down:dne
2011-06-17 11:33:10.655620 7f99662e6700 mds-1.-1 not in map yet
2011-06-17 11:33:10.690292 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 14 ==== mdsbeacon(4603/alpha up:boot seq 3 v3045) v2 ==== 107+0+0 (1533945468 0 0) 0x29f6260 con 0x29f3710
2011-06-17 11:33:10.690439 7f99662e6700 mds-1.-1 handle_mds_beacon up:boot seq 3 rtt 3.248834
2011-06-17 11:33:11.441816 7f99650e2700 mds-1.-1 beacon_send up:boot seq 4 (currently down:dne)
2011-06-17 11:33:11.441917 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:boot seq 4 v3045) v1 -- ?+0 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:11.920009 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 15 ==== mdsmap(e 3046) v1 ==== 1347+0+0 (213666887 0 0) 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:11.920071 7f99662e6700 mds-1.-1 handle_mds_map epoch 3046 from mon3
2011-06-17 11:33:11.920167 7f99662e6700 mds-1.-1 my compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:33:11.920191 7f99662e6700 mds-1.-1 mdsmap compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:33:11.920217 7f99662e6700 mds-1.0 map says i am 192.168.60.134:6800/31371 mds-1.0 state up:standby
2011-06-17 11:33:11.920237 7f99662e6700 mds-1.0 handle_mds_map standby
2011-06-17 11:33:14.441680 7f99650e2700 mds-1.bal get_load no root, no load
2011-06-17 11:33:14.441816 7f99650e2700 mds-1.bal get_load mdsload<[0,0 0]/[0,0 0], req 0, hr 0, qlen 0, cpu 0.65>
2011-06-17 11:33:15.442070 7f99650e2700 mds-1.0 beacon_send up:standby seq 5 (currently up:standby)
2011-06-17 11:33:15.442193 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:standby seq 5 v3046) v1 -- ?+0 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:16.102838 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 16 ==== mdsbeacon(4603/alpha up:boot seq 4 v3046) v2 ==== 107+0+0 (2888026487 0 0) 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:16.102931 7f99662e6700 mds-1.0 handle_mds_beacon up:boot seq 4 rtt 4.661037
2011-06-17 11:33:16.308734 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 17 ==== mdsbeacon(4603/alpha up:standby seq 5 v3046) v2 ==== 107+0+0 (3385758865 0 0) 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:16.308826 7f99662e6700 mds-1.0 handle_mds_beacon up:standby seq 5 rtt 0.866662
2011-06-17 11:33:19.441753 7f99650e2700 mds-1.bal get_load no root, no load
2011-06-17 11:33:19.441945 7f99650e2700 mds-1.bal get_load mdsload<[0,0 0]/[0,0 0], req 0, hr 0, qlen 0, cpu 1>
2011-06-17 11:33:19.442320 7f99650e2700 mds-1.0 beacon_send up:standby seq 6 (currently up:standby)
2011-06-17 11:33:19.442390 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:standby seq 6 v3046) v1 -- ?+0 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:23.442648 7f99650e2700 mds-1.0 beacon_send up:standby seq 7 (currently up:standby)
2011-06-17 11:33:23.442827 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:standby seq 7 v3046) v1 -- ?+0 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:24.441849 7f99650e2700 mds-1.bal get_load no root, no load
2011-06-17 11:33:24.442049 7f99650e2700 mds-1.bal get_load mdsload<[0,0 0]/[0,0 0], req 0, hr 0, qlen 0, cpu 1.4>
2011-06-17 11:33:27.443037 7f99650e2700 mds-1.0 beacon_send up:standby seq 8 (currently up:standby)
2011-06-17 11:33:27.443139 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:standby seq 8 v3046) v1 -- ?+0 0x7f9960000d10 con 0x29f3710
2011-06-17 11:33:29.441947 7f99650e2700 mds-1.bal get_load no root, no load
2011-06-17 11:33:29.442162 7f99650e2700 mds-1.bal get_load mdsload<[0,0 0]/[0,0 0], req 0, hr 0, qlen 0, cpu 1.28>
2011-06-17 11:33:30.153093 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 18 ==== mdsbeacon(4603/alpha up:standby seq 6 v3046) v2 ==== 107+0+0 (2504572084 0 0) 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:30.153216 7f99662e6700 mds-1.0 handle_mds_beacon up:standby seq 6 rtt 10.710850
2011-06-17 11:33:30.153524 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 19 ==== mdsbeacon(4603/alpha up:standby seq 7 v3046) v2 ==== 107+0+0 (1569814264 0 0) 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:30.153600 7f99662e6700 mds-1.0 handle_mds_beacon up:standby seq 7 rtt 6.710819
2011-06-17 11:33:30.153701 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 20 ==== mdsbeacon(4603/alpha up:standby seq 8 v3046) v2 ==== 107+0+0 (1994623160 0 0) 0x29f6260 con 0x29f3710
2011-06-17 11:33:30.153750 7f99662e6700 mds-1.0 handle_mds_beacon up:standby seq 8 rtt 2.710634
2011-06-17 11:33:31.443294 7f99650e2700 mds-1.0 beacon_send up:standby seq 9 (currently up:standby)
2011-06-17 11:33:31.443409 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:standby seq 9 v3046) v1 -- ?+0 0x7f9960000bb0 con 0x29f3710
2011-06-17 11:33:34.443207 7f99650e2700 mds-1.bal get_load no root, no load
2011-06-17 11:33:34.443345 7f99650e2700 mds-1.bal get_load mdsload<[0,0 0]/[0,0 0], req 0, hr 0, qlen 0, cpu 1.66>
2011-06-17 11:33:35.443658 7f99650e2700 mds-1.0 beacon_send up:standby seq 10 (currently up:standby)
2011-06-17 11:33:35.443747 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:standby seq 10 v3046) v1 -- ?+0 0x7f9960000bb0 con 0x29f3710
2011-06-17 11:33:38.903519 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 21 ==== mdsbeacon(4603/alpha up:standby seq 9 v3046) v2 ==== 107+0+0 (3191489268 0 0) 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:38.903586 7f99662e6700 mds-1.0 handle_mds_beacon up:standby seq 9 rtt 7.460207
2011-06-17 11:33:39.443332 7f99650e2700 mds-1.bal get_load no root, no load
2011-06-17 11:33:39.443495 7f99650e2700 mds-1.bal get_load mdsload<[0,0 0]/[0,0 0], req 0, hr 0, qlen 0, cpu 2.25>
2011-06-17 11:33:39.443961 7f99650e2700 mds-1.0 beacon_send up:standby seq 11 (currently up:standby)
2011-06-17 11:33:39.444031 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:standby seq 11 v3046) v1 -- ?+0 0x7f9960000e90 con 0x29f3710
2011-06-17 11:33:43.444271 7f99650e2700 mds-1.0 beacon_send up:standby seq 12 (currently up:standby)
2011-06-17 11:33:43.444406 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:standby seq 12 v3046) v1 -- ?+0 0x7f9960000e90 con 0x29f3710
2011-06-17 11:33:44.443426 7f99650e2700 mds-1.bal get_load no root, no load
2011-06-17 11:33:44.443565 7f99650e2700 mds-1.bal get_load mdsload<[0,0 0]/[0,0 0], req 0, hr 0, qlen 0, cpu 2.79>
2011-06-17 11:33:46.443517 7f99650e2700 mds-1.0 beacon_kill last_acked_stamp 2011-06-17 11:33:31.443373, we are laggy!
2011-06-17 11:33:47.444619 7f99650e2700 mds-1.0 beacon_send up:standby seq 13 (currently up:standby)
2011-06-17 11:33:47.444717 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:standby seq 13 v3046) v1 -- ?+0 0x7f9960000c50 con 0x29f3710
2011-06-17 11:33:48.468638 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 22 ==== mdsmap(e 3047) v1 ==== 1141+0+0 (3746278597 0 0) 0x29f6260 con 0x29f3710
2011-06-17 11:33:48.468778 7f99662e6700 mds-1.0 handle_mds_map epoch 3047 from mon3
2011-06-17 11:33:48.468946 7f99662e6700 mds-1.0 my compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:33:48.469002 7f99662e6700 mds-1.0 mdsmap compat compat={},rocompat={},incompat={1=base v0.20,2=client writeable ranges,3=default file layouts on dirs,4=dir inode in separate object}
2011-06-17 11:33:48.469055 7f99662e6700 mds0.16 map says i am 192.168.60.134:6800/31371 mds0.16 state up:replay
2011-06-17 11:33:48.469093 7f99662e6700 mds0.16 peer mds gid 4423 removed from map
2011-06-17 11:33:48.469141 7f99662e6700 -- 192.168.60.134:6800/31371 mark_down 192.168.60.129:6816/4594 -- pipe dne
2011-06-17 11:33:48.469204 7f99662e6700 mds0.16 handle_mds_map i am now mds0.16
2011-06-17 11:33:48.469243 7f99662e6700 mds0.16 handle_mds_map state change up:standby --> up:replay
2011-06-17 11:33:48.469296 7f99662e6700 mds0.16 replay_start
2011-06-17 11:33:48.469363 7f99662e6700 mds0.cache set_recovery_set
2011-06-17 11:33:48.469404 7f99662e6700 mds0.16 recovery set is
2011-06-17 11:33:48.469471 7f99662e6700 mds0.16 need osdmap epoch 271, have 260
2011-06-17 11:33:48.469516 7f99662e6700 mds0.16 waiting for osdmap 271 (which blacklists prior instance)
2011-06-17 11:33:48.469593 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mon_subscribe({mdsmap=3048+,monmap=2+,osdmap=261}) v1 -- ?+0 0x29f6e70 con 0x29f3710
2011-06-17 11:33:48.469762 7f99662e6700 mds0.cache handle_mds_failure mds0
2011-06-17 11:33:48.469818 7f99662e6700 mds0.cache handle_mds_failure mds0 : recovery peers are
2011-06-17 11:33:48.469857 7f99662e6700 mds0.cache wants_resolve
2011-06-17 11:33:48.469891 7f99662e6700 mds0.cache got_resolve
2011-06-17 11:33:48.469924 7f99662e6700 mds0.cache rejoin_sent
2011-06-17 11:33:48.469967 7f99662e6700 mds0.cache rejoin_gather
2011-06-17 11:33:48.470001 7f99662e6700 mds0.cache rejoin_ack_gather
2011-06-17 11:33:48.470055 7f99662e6700 mds0.migrator handle_mds_failure_or_stop mds0
2011-06-17 11:33:48.470210 7f99662e6700 mds0.cache show_subtrees - no subtrees
2011-06-17 11:33:49.443536 7f99650e2700 mds0.16 is_laggy 18.000124 > 15 since last acked beacon
2011-06-17 11:33:49.443593 7f99650e2700 mds0.16 tick bailing out since we seem laggy
2011-06-17 11:33:49.983412 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 23 ==== mdsbeacon(4603/alpha up:standby seq 10 v3047) v2 ==== 107+0+0 (1670409093 0 0) 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:49.983552 7f99662e6700 mds0.16 handle_mds_beacon up:standby seq 10 rtt 14.539824
2011-06-17 11:33:49.983593 7f99662e6700 mds0.16 handle_mds_beacon no longer laggy
2011-06-17 11:33:49.983963 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 24 ==== mdsbeacon(4603/alpha up:standby seq 11 v3047) v2 ==== 107+0+0 (2873729481 0 0) 0x29f5ca0 con 0x29f3710
2011-06-17 11:33:49.984068 7f99662e6700 mds0.16 handle_mds_beacon up:standby seq 11 rtt 10.540061
2011-06-17 11:33:50.228546 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 25 ==== osd_map(261,271) v1 ==== 15214+0+0 (1700782707 0 0) 0x29f6260 con 0x29f3710
2011-06-17 11:33:50.229766 7f99662e6700 mds0.16 boot_start 1: opening inotable
2011-06-17 11:33:50.229839 7f99662e6700 mds0.inotable: load
2011-06-17 11:33:50.230176 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.135:6800/6941 -- osd_op(mds0.16:1 mds0_inotable [read 0~0] 1.b893) v1 -- ?+0 0x29fc110 con 0x29fbd90
2011-06-17 11:33:50.230248 7f99662e6700 mds0.16 boot_start 1: opening sessionmap
2011-06-17 11:33:50.230303 7f99662e6700 mds0.sessionmap load
2011-06-17 11:33:50.230512 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6810/23038 -- osd_op(mds0.16:2 mds0_sessionmap [read 0~0] 1.c60b) v1 -- ?+0 0x29fca30 con 0x29fc6b0
2011-06-17 11:33:50.230563 7f99662e6700 mds0.16 boot_start 1: opening anchor table
2011-06-17 11:33:50.230605 7f99662e6700 mds0.anchortable: load
2011-06-17 11:33:50.230786 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.135:6812/7294 -- osd_op(mds0.16:3 mds_anchortable [read 0~0] 1.f6a7) v1 -- ?+0 0x29fd620 con 0x29fd2a0
2011-06-17 11:33:50.230835 7f99662e6700 mds0.16 boot_start 1: opening snap table
2011-06-17 11:33:50.230876 7f99662e6700 mds0.snaptable: load
2011-06-17 11:33:50.231160 7f9969f31700 mds0.16 MDS::ms_get_authorizer type=osd
2011-06-17 11:33:50.231997 7f995ffff700 mds0.16 MDS::ms_get_authorizer type=osd
2011-06-17 11:33:50.232137 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.134:6804/31727 -- osd_op(mds0.16:4 mds_snaptable [read 0~0] 1.70ad) v1 -- ?+0 0x29fc110 con 0x29fe0f0
2011-06-17 11:33:50.232230 7f99662e6700 mds0.16 boot_start 1: opening mds log
2011-06-17 11:33:50.232272 7f995fefe700 mds0.16 MDS::ms_get_authorizer type=osd
2011-06-17 11:33:50.232597 7f99662e6700 mds0.log open discovering log bounds
2011-06-17 11:33:50.232888 7f995fdfd700 mds0.16 MDS::ms_get_authorizer type=osd
2011-06-17 11:33:50.233089 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.129:6804/6864 -- osd_op(mds0.16:5 200.00000000 [read 0~0] 1.3494) v1 -- ?+0 0x29fca30 con 0x2a051a0
2011-06-17 11:33:50.233244 7f99662e6700 mds0.16 ms_handle_connect on 192.168.60.135:6800/6941
2011-06-17 11:33:50.233303 7f99662e6700 mds0.16 ms_handle_connect on 192.168.60.104:6810/23038
2011-06-17 11:33:50.233362 7f99662e6700 mds0.16 ms_handle_connect on 192.168.60.135:6812/7294
2011-06-17 11:33:50.233425 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 26 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (1282756199 0 0) 0x29f6e70 con 0x29f3710
2011-06-17 11:33:50.233499 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 27 ==== mdsbeacon(4603/alpha up:standby seq 12 v3047) v2 ==== 107+0+0 (3667672015 0 0) 0x29f73c0 con 0x29f3710
2011-06-17 11:33:50.233551 7f99662e6700 mds0.16 handle_mds_beacon up:standby seq 12 rtt 6.789181
2011-06-17 11:33:50.233639 7f99662e6700 mds0.16 ms_handle_connect on 192.168.60.134:6804/31727
2011-06-17 11:33:50.233705 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 28 ==== mdsbeacon(4603/alpha up:standby seq 13 v3047) v2 ==== 107+0+0 (306573699 0 0) 0x29f7630 con 0x29f3710
2011-06-17 11:33:50.233755 7f99662e6700 mds0.16 handle_mds_beacon up:standby seq 13 rtt 2.789063
2011-06-17 11:33:50.233837 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd25 192.168.60.135:6800/6941 1 ==== osd_op_reply(1 mds0_inotable [read 0~29] = 0) v1 ==== 99+0+29 (3586614461 0 1403865816) 0x29f6260 con 0x29fbd90
2011-06-17 11:33:50.233912 7f99662e6700 mds0.inotable: load_2 got 29 bytes
2011-06-17 11:33:50.233953 7f99662e6700 mds0.inotable: load_2 loaded v0
2011-06-17 11:33:50.234211 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd13 192.168.60.104:6810/23038 1 ==== osd_op_reply(2 mds0_sessionmap [read 0~17] = 0) v1 ==== 101+0+17 (281506306 0 2334645356) 0x29fd620 con 0x29fc6b0
2011-06-17 11:33:50.234291 7f99662e6700 mds0.sessionmap dump
2011-06-17 11:33:50.234346 7f99662e6700 mds0.sessionmap _load_finish v 0, 0 sessions, 17 bytes
2011-06-17 11:33:50.234381 7f99662e6700 mds0.sessionmap dump
2011-06-17 11:33:50.235057 7f995fafa700 mds0.16 MDS::ms_get_authorizer type=osd
2011-06-17 11:33:50.235557 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd1 192.168.60.134:6804/31727 1 ==== osd_op_reply(4 mds_snaptable [read 0~41] = 0) v1 ==== 99+0+41 (3268743993 0 2312406677) 0x29f6260 con 0x29fe0f0
2011-06-17 11:33:50.235628 7f99662e6700 mds0.snaptable: load_2 got 41 bytes
2011-06-17 11:33:50.235676 7f99662e6700 mds0.snaptable: load_2 loaded v0
2011-06-17 11:33:50.235792 7f99662e6700 mds0.16 ms_handle_connect on 192.168.60.129:6804/6864
2011-06-17 11:33:50.236798 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd16 192.168.60.129:6804/6864 1 ==== osd_op_reply(5 200.00000000 [read 0~84] = 0) v1 ==== 98+0+84 (1664878906 0 2694473009) 0x29f6260 con 0x2a051a0
2011-06-17 11:33:50.237143 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.135:6803/7045 -- osd_op(mds0.16:6 200.00000001 [stat 0~0] 1.f474 rwordered) v1 -- ?+0 0x7f9960001a10 con 0x7f99600016c0
2011-06-17 11:33:50.237356 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.134:6813/1086 -- osd_op(mds0.16:7 200.00000002 [stat 0~0] 1.2dbb rwordered) v1 -- ?+0 0x7f99600025b0 con 0x7f9960002230
2011-06-17 11:33:50.237785 7f995f5f5700 mds0.16 MDS::ms_get_authorizer type=osd
2011-06-17 11:33:50.238062 7f995f6f6700 mds0.16 MDS::ms_get_authorizer type=osd
2011-06-17 11:33:50.238317 7f99662e6700 mds0.16 ms_handle_connect on 192.168.60.134:6813/1086
2011-06-17 11:33:50.238733 7f99662e6700 mds0.16 ms_handle_connect on 192.168.60.135:6803/7045
2011-06-17 11:33:50.240291 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd26 192.168.60.135:6803/7045 1 ==== osd_op_reply(6 200.00000001 [stat 0~0] = 0) v1 ==== 98+0+16 (2370172073 0 695366059) 0x29fca30 con 0x7f99600016c0
2011-06-17 11:33:51.444857 7f99650e2700 mds0.16 beacon_send up:replay seq 14 (currently up:replay)
2011-06-17 11:33:51.444956 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:replay seq 14 v3047) v1 -- ?+0 0x7f9960001a10 con 0x29f3710
2011-06-17 11:33:54.443659 7f99650e2700 mds0.bal get_load no root, no load
2011-06-17 11:33:54.443812 7f99650e2700 mds0.bal get_load mdsload<[0,0 0]/[0,0 0], req 0, hr 0, qlen 0, cpu 3.43>
2011-06-17 11:33:55.445115 7f99650e2700 mds0.16 beacon_send up:replay seq 15 (currently up:replay)
2011-06-17 11:33:55.445232 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:replay seq 15 v3047) v1 -- ?+0 0x7f9960001a10 con 0x29f3710
2011-06-17 11:33:58.218255 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 29 ==== mdsbeacon(4603/alpha up:replay seq 14 v3047) v2 ==== 107+0+0 (3468269838 0 0) 0x29fca30 con 0x29f3710
2011-06-17 11:33:58.218346 7f99662e6700 mds0.16 handle_mds_beacon up:replay seq 14 rtt 6.773415
2011-06-17 11:33:58.608588 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 30 ==== mdsbeacon(4603/alpha up:replay seq 15 v3047) v2 ==== 107+0+0 (106976066 0 0) 0x29fca30 con 0x29f3710
2011-06-17 11:33:58.608729 7f99662e6700 mds0.16 handle_mds_beacon up:replay seq 15 rtt 3.163518
2011-06-17 11:33:59.443752 7f99650e2700 mds0.bal get_load no root, no load
2011-06-17 11:33:59.443923 7f99650e2700 mds0.bal get_load mdsload<[0,0 0]/[0,0 0], req 0, hr 0, qlen 0, cpu 3.96>
2011-06-17 11:33:59.445369 7f99650e2700 mds0.16 beacon_send up:replay seq 16 (currently up:replay)
2011-06-17 11:33:59.445444 7f99650e2700 -- 192.168.60.134:6800/31371 --> 192.168.60.104:6789/0 -- mdsbeacon(4603/alpha up:replay seq 16 v3047) v1 -- ?+0 0x7f9960001a10 con 0x29f3710
2011-06-17 11:33:59.640009 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd4 192.168.60.134:6813/1086 1 ==== osd_op_reply(7 200.00000002 [stat 0~0] = -2 (No such file or directory)) v1 ==== 98+0+0 (2879877330 0 0) 0x29fca30 con 0x7f9960002230
2011-06-17 11:33:59.809455 7f99662e6700 -- 192.168.60.134:6800/31371 <== mon3 192.168.60.104:6789/0 31 ==== mdsbeacon(4603/alpha up:replay seq 16 v3047) v2 ==== 107+0+0 (2556192142 0 0) 0x29fca30 con 0x29f3710
2011-06-17 11:33:59.809549 7f99662e6700 mds0.16 handle_mds_beacon up:replay seq 16 rtt 0.364129
2011-06-17 11:34:00.042820 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd29 192.168.60.135:6812/7294 1 ==== osd_op_reply(3 mds_anchortable [read 0~29] = 0) v1 ==== 101+0+29 (3580080342 0 218791405) 0x29fca30 con 0x29fd2a0
2011-06-17 11:34:00.042911 7f99662e6700 mds0.anchortable: load_2 got 29 bytes
2011-06-17 11:34:00.042936 7f99662e6700 mds0.anchortable: load_2 loaded v0
2011-06-17 11:34:00.043000 7f99662e6700 mds0.16 boot_start 2: loading/discovering base inodes
2011-06-17 11:34:00.043030 7f99662e6700 mds0.cache creating system inode with ino:100
2011-06-17 11:34:00.043246 7f99662e6700 mds0.cache.ino(100) fetch
2011-06-17 11:34:00.043360 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.129:6804/6864 -- osd_op(mds0.16:8 100.00000000 [getxattr inode] 1.5ab3) v1 -- ?+0 0x7f99600137d0 con 0x2a051a0
2011-06-17 11:34:00.043519 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.109:6810/12603 -- osd_op(mds0.16:9 100.00000000.inode [read 0~0] 1.e07f) v1 -- ?+0 0x7f9960015140 con 0x7f9960013ea0
2011-06-17 11:34:00.043553 7f99662e6700 mds0.cache creating system inode with ino:1
2011-06-17 11:34:00.043593 7f99662e6700 mds0.cache.ino(1) fetch
2011-06-17 11:34:00.043708 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.132:6812/1918 -- osd_op(mds0.16:10 1.00000000 [getxattr inode] 1.daff) v1 -- ?+0 0x7f9960017140 con 0x7f9960015d60
2011-06-17 11:34:00.043875 7f99662e6700 -- 192.168.60.134:6800/31371 --> 192.168.60.134:6807/32552 -- osd_op(mds0.16:11 1.00000000.inode [read 0~0] 1.e14) v1 -- ?+0 0x7f9960017cd0 con 0x7f9960017950
2011-06-17 11:34:00.045607 7f995f0f0700 mds0.16 MDS::ms_get_authorizer type=osd
2011-06-17 11:34:00.045935 7f99662e6700 mds0.16 ms_handle_connect on 192.168.60.134:6807/32552
2011-06-17 11:34:00.046530 7f995f2f2700 mds0.16 MDS::ms_get_authorizer type=osd
2011-06-17 11:34:00.047085 7f99662e6700 mds0.16 ms_handle_connect on 192.168.60.109:6810/12603
2011-06-17 11:34:00.056435 7f995f1f1700 mds0.16 MDS::ms_get_authorizer type=osd
2011-06-17 11:34:00.057699 7f99662e6700 mds0.16 ms_handle_connect on 192.168.60.132:6812/1918
2011-06-17 11:34:00.071118 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd24 192.168.60.132:6812/1918 1 ==== osd_op_reply(10 1.00000000 [getxattr] = -61 (No data available)) v1 ==== 96+0+0 (2441581540 0 0) 0x29fcdc0 con 0x7f9960015d60
2011-06-17 11:34:00.471501 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd8 192.168.60.109:6810/12603 1 ==== osd_op_reply(9 100.00000000.inode [read 0~396] = 0) v1 ==== 104+0+396 (305859003 0 2127911631) 0x2a044d0 con 0x7f9960013ea0
2011-06-17 11:34:01.402613 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd2 192.168.60.134:6807/32552 1 ==== osd_op_reply(11 1.00000000.inode [read 0~425] = 0) v1 ==== 102+0+425 (272039163 0 2119463851) 0x29f5ca0 con 0x7f9960017950
2011-06-17 11:34:01.470460 7f99662e6700 mds0.cache.ino(1) _fetched got 0 and 425
2011-06-17 11:34:01.470515 7f99662e6700 mds0.cache.ino(1) magic is 'ceph fs volume v011' (expecting 'ceph fs volume v011')
2011-06-17 11:34:01.470586 7f99662e6700 mds0.cache.ino(1) decode_snap_blob snaprealm(1 seq 1 lc 0 cr 0 cps 1 snaps={} 0x7f99600153e0)
2011-06-17 11:34:01.470685 7f99662e6700 mds0.cache.ino(1) _fetched [inode 1 [...2,head] / auth v1 snaprealm=0x7f99600153e0 f(v0 1=0+1) n(v0 1=0+1) (iversion lock) 0x7f9960002e40]
2011-06-17 11:34:01.987104 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd16 192.168.60.129:6804/6864 2 ==== osd_op_reply(8 100.00000000 [getxattr] = -61 (No data available)) v1 ==== 98+0+0 (3667286071 0 0) 0x2a044d0 con 0x2a051a0
2011-06-17 11:34:02.062461 7f99662e6700 mds0.cache.ino(100) _fetched got 0 and 396
2011-06-17 11:34:02.062513 7f99662e6700 mds0.cache.ino(100) magic is 'ceph fs volume v011' (expecting 'ceph fs volume v011')
2011-06-17 11:34:02.062565 7f99662e6700 mds0.cache.ino(100) decode_snap_blob snaprealm(100 seq 1 lc 0 cr 0 cps 1 snaps={} 0x7f9960001a10)
2011-06-17 11:34:02.062608 7f99662e6700 mds0.cache.ino(100) _fetched [inode 100 [...2,head] ~mds0/ auth v1 snaprealm=0x7f9960001a10 f(v0 11=1+10) n(v0 11=1+10) (iversion lock) 0x7f99600025b0]
2011-06-17 11:34:02.062641 7f99662e6700 mds0.16 boot_start 3: replaying mds log
2011-06-17 11:34:02.062683 7f99662e6700 mds0.log replay start, from 4194304 to 4236561
2011-06-17 11:34:02.062908 7f995ecec700 mds0.log _replay_thread start
2011-06-17 11:34:02.063079 7f995ecec700 -- 192.168.60.134:6800/31371 --> 192.168.60.135:6803/7045 -- osd_op(mds0.16:12 200.00000001 [read 0~42257] 1.f474) v1 -- ?+0 0x29f5ee0 con 0x7f99600016c0
2011-06-17 11:34:02.071762 7f99662e6700 -- 192.168.60.134:6800/31371 <== osd26 192.168.60.135:6803/7045 2 ==== osd_op_reply(12 200.00000001 [read 0~42257] = 0) v1 ==== 98+0+42257 (2661274980 0 1829589854) 0x29f5ca0 con 0x7f99600016c0
2011-06-17 11:34:02.072064 7f995ecec700 mds0.log _replay 4194304~115 / 4236561 2011-06-15 12:45:28.366506: ESubtreeMap 0 subtrees , 0 ambiguous [metablob]
2011-06-17 11:34:02.072111 7f995ecec700 mds0.journal ESubtreeMap.replay -- reconstructing (auth) subtree spanning tree
2011-06-17 11:34:02.072137 7f995ecec700 mds0.journal EMetaBlob.replay 0 dirlumps by unknown0
2011-06-17 11:34:02.072171 7f995ecec700 mds0.cache show_subtrees - no subtrees
2011-06-17 11:34:02.072267 7f995ecec700 mds0.log _replay 4194423~655 / 4236561 2011-06-15 12:46:06.718436: ESubtreeMap 2 subtrees , 0 ambiguous [metablob 1, 2 dirs]
2011-06-17 11:34:02.072294 7f995ecec700 mds0.journal ESubtreeMap.replay -- reconstructing (auth) subtree spanning tree
2011-06-17 11:34:02.072318 7f995ecec700 mds0.journal EMetaBlob.replay 2 dirlumps by unknown0
2011-06-17 11:34:02.072337 7f995ecec700 mds0.journal EMetaBlob.replay dir 1
2011-06-17 11:34:02.072382 7f995ecec700 mds0.cache force_dir_fragment * on [inode 1 [...2,head] / auth v1 snaprealm=0x7f99600153e0 f(v0 1=0+1) n(v0 1=0+1) (iversion lock) 0x7f9960002e40]
2011-06-17 11:34:02.072417 7f995ecec700 mds0.cache force_dir_fragment no frags under *
2011-06-17 11:34:02.072594 7f995ecec700 mds0.cache adjust_subtree_auth -1,-2 -> -2,-2 on [dir 1 / [2,head] auth v=0 cv=0/0 state=1073741824 f() n() hs=0+0,ss=0+0 0x2a10010]
2011-06-17 11:34:02.072619 7f995ecec700 mds0.cache show_subtrees - no subtrees
2011-06-17 11:34:02.072679 7f995ecec700 mds0.cache current root is [dir 1 / [2,head] auth v=0 cv=0/0 state=1073741824 f() n() hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.072717 7f995ecec700 mds0.cache.dir(1) setting dir_auth=-2,-2 from -1,-2 on [dir 1 / [2,head] auth v=0 cv=0/0 state=1073741824 f() n() hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.072745 7f995ecec700 mds0.cache.dir(1) new subtree root, adjusting auth_pins
2011-06-17 11:34:02.072772 7f995ecec700 mds0.cache show_subtrees
2011-06-17 11:34:02.072840 7f995ecec700 mds0.cache |__-2 auth [dir 1 / [2,head] auth v=0 cv=0/0 dir_auth=-2 state=1073741824 f() n() hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.072875 7f995ecec700 mds0.journal EMetaBlob.replay added dir [dir 1 / [2,head] auth v=0 cv=0/0 dir_auth=-2 state=1073741824 f() n() hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.072912 7f995ecec700 mds0.journal EMetaBlob.replay updated dir [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.072939 7f995ecec700 mds0.journal EMetaBlob.replay dir 100
2011-06-17 11:34:02.072976 7f995ecec700 mds0.cache force_dir_fragment * on [inode 100 [...2,head] ~mds0/ auth v1 snaprealm=0x7f9960001a10 f(v0 11=1+10) n(v0 11=1+10) (iversion lock) 0x7f99600025b0]
2011-06-17 11:34:02.073002 7f995ecec700 mds0.cache force_dir_fragment no frags under *
2011-06-17 11:34:02.073090 7f995ecec700 mds0.cache adjust_subtree_auth -1,-2 -> -2,-2 on [dir 100 ~mds0/ [2,head] auth v=0 cv=0/0 state=1073741824 f() n() hs=0+0,ss=0+0 0x2a10628]
2011-06-17 11:34:02.073116 7f995ecec700 mds0.cache show_subtrees
2011-06-17 11:34:02.073156 7f995ecec700 mds0.cache |__-2 auth [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.073195 7f995ecec700 mds0.cache current root is [dir 100 ~mds0/ [2,head] auth v=0 cv=0/0 state=1073741824 f() n() hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.073227 7f995ecec700 mds0.cache.dir(100) setting dir_auth=-2,-2 from -1,-2 on [dir 100 ~mds0/ [2,head] auth v=0 cv=0/0 state=1073741824 f() n() hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.073250 7f995ecec700 mds0.cache.dir(100) new subtree root, adjusting auth_pins
2011-06-17 11:34:02.073272 7f995ecec700 mds0.cache show_subtrees
2011-06-17 11:34:02.073311 7f995ecec700 mds0.cache |__-2 auth [dir 100 ~mds0/ [2,head] auth v=0 cv=0/0 dir_auth=-2 state=1073741824 f() n() hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.073344 7f995ecec700 mds0.cache |__-2 auth [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.073375 7f995ecec700 mds0.journal EMetaBlob.replay added dir [dir 100 ~mds0/ [2,head] auth v=0 cv=0/0 dir_auth=-2 state=1073741824 f() n() hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.073408 7f995ecec700 mds0.journal EMetaBlob.replay updated dir [dir 100 ~mds0/ [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 11=1+10) n(v0 11=1+10) hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.073449 7f995ecec700 mds0.cache adjust_bounded_subtree_auth -2,-2 -> 0,-2 on [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010] bound_dfs []
2011-06-17 11:34:02.073489 7f995ecec700 mds0.cache adjust_bounded_subtree_auth -2,-2 -> 0,-2 on [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010] bounds
2011-06-17 11:34:02.073517 7f995ecec700 mds0.cache show_subtrees
2011-06-17 11:34:02.073558 7f995ecec700 mds0.cache |__-2 auth [dir 100 ~mds0/ [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 11=1+10) n(v0 11=1+10) hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.073593 7f995ecec700 mds0.cache |__-2 auth [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.073636 7f995ecec700 mds0.cache current root is [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.073669 7f995ecec700 mds0.cache.dir(1) setting dir_auth=0,-2 from -2,-2 on [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.073699 7f995ecec700 mds0.cache show_subtrees
2011-06-17 11:34:02.073740 7f995ecec700 mds0.cache |__-2 auth [dir 100 ~mds0/ [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 11=1+10) n(v0 11=1+10) hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.073776 7f995ecec700 mds0.cache |__ 0 auth [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=0 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.073817 7f995ecec700 mds0.cache adjust_bounded_subtree_auth -2,-2 -> 0,-2 on [dir 100 ~mds0/ [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 11=1+10) n(v0 11=1+10) hs=0+0,ss=0+0 | subtree 0x2a10628] bound_dfs []
2011-06-17 11:34:02.073851 7f995ecec700 mds0.cache adjust_bounded_subtree_auth -2,-2 -> 0,-2 on [dir 100 ~mds0/ [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 11=1+10) n(v0 11=1+10) hs=0+0,ss=0+0 | subtree 0x2a10628] bounds
2011-06-17 11:34:02.073876 7f995ecec700 mds0.cache show_subtrees
2011-06-17 11:34:02.073913 7f995ecec700 mds0.cache |__-2 auth [dir 100 ~mds0/ [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 11=1+10) n(v0 11=1+10) hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.073945 7f995ecec700 mds0.cache |__ 0 auth [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=0 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.073982 7f995ecec700 mds0.cache current root is [dir 100 ~mds0/ [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 11=1+10) n(v0 11=1+10) hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.074013 7f995ecec700 mds0.cache.dir(100) setting dir_auth=0,-2 from -2,-2 on [dir 100 ~mds0/ [2,head] auth v=1 cv=0/0 dir_auth=-2 state=1073741824 f(v0 11=1+10) n(v0 11=1+10) hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.074040 7f995ecec700 mds0.cache show_subtrees
2011-06-17 11:34:02.074079 7f995ecec700 mds0.cache |__ 0 auth [dir 100 ~mds0/ [2,head] auth v=1 cv=0/0 dir_auth=0 state=1073741824 f(v0 11=1+10) n(v0 11=1+10) hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.074114 7f995ecec700 mds0.cache |__ 0 auth [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=0 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.074143 7f995ecec700 mds0.cache show_subtrees
2011-06-17 11:34:02.074181 7f995ecec700 mds0.cache |__ 0 auth [dir 100 ~mds0/ [2,head] auth v=1 cv=0/0 dir_auth=0 state=1073741824 f(v0 11=1+10) n(v0 11=1+10) hs=0+0,ss=0+0 | subtree 0x2a10628]
2011-06-17 11:34:02.074216 7f995ecec700 mds0.cache |__ 0 auth [dir 1 / [2,head] auth v=1 cv=0/0 dir_auth=0 state=1073741824 f(v0 1=0+1) n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010]
2011-06-17 11:34:02.074269 7f995ecec700 mds0.log _replay 4195082~179 / 4236561 2011-06-15 12:51:37.004156: ESession client4132 192.168.60.134:0/3706 open cmapv 1
2011-06-17 11:34:02.074302 7f995ecec700 mds0.journal ESession.replay sessionmap 0 < 1 open client4132 192.168.60.134:0/3706
2011-06-17 11:34:02.074335 7f995ecec700 mds0.journal opened session client4132 192.168.60.134:0/3706
2011-06-17 11:34:02.074375 7f995ecec700 mds0.log _replay 4195265~179 / 4236561 2011-06-15 12:53:33.418325: ESession client4132 192.168.60.134:0/3706 close cmapv 2
2011-06-17 11:34:02.074401 7f995ecec700 mds0.journal ESession.replay sessionmap 1 < 2 close client4132 192.168.60.134:0/3706
2011-06-17 11:34:02.074429 7f995ecec700 mds0.journal removed session client4132 192.168.60.134:0/3706
2011-06-17 11:34:02.074465 7f995ecec700 mds0.log _replay 4195448~179 / 4236561 2011-06-15 12:53:47.386877: ESession client4136 192.168.60.134:0/1940014 open cmapv 3
2011-06-17 11:34:02.074491 7f995ecec700 mds0.journal ESession.replay sessionmap 2 < 3 open client4136 192.168.60.134:0/1940014
2011-06-17 11:34:02.074527 7f995ecec700 mds0.journal opened session client4136 192.168.60.134:0/1940014
2011-06-17 11:34:02.074568 7f995ecec700 mds0.log _replay 4195631~103 / 4236561 2011-06-15 12:53:51.200837: EOpen [metablob], 0 open files
2011-06-17 11:34:02.074596 7f995ecec700 mds0.journal EOpen.replay
2011-06-17 11:34:02.074619 7f995ecec700 mds0.journal EMetaBlob.replay 0 dirlumps by unknown0
2011-06-17 11:34:02.074713 7f995ecec700 mds0.log _replay 4195738~1456 / 4236561 2011-06-15 12:53:55.689047: EUpdate mkdir [metablob 1, 2 dirs alloc_ino=10000000000 prealloc_ino=[10000000001~3e8] v2]
2011-06-17 11:34:02.074740 7f995ecec700 mds0.journal EMetaBlob.replay 2 dirlumps by client4136
2011-06-17 11:34:02.074777 7f995ecec700 mds0.cache.ino(1) decode_snap_blob snaprealm(1 seq 1 lc 0 cr 0 cps 1 snaps={} 0x7f99600153e0)
2011-06-17 11:34:02.074818 7f995ecec700 mds0.journal EMetaBlob.replay updated root [inode 1 [...2,head] / auth v2 snaprealm=0x7f99600153e0 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 1=0+1) (iversion lock) | dirfrag dirty 0x7f9960002e40]
2011-06-17 11:34:02.074841 7f995ecec700 mds0.journal EMetaBlob.replay dir 1
2011-06-17 11:34:02.074878 7f995ecec700 mds0.cache.dir(1) mark_dirty (was clean) [dir 1 / [2,head] auth v=3 cv=0/0 dir_auth=0 state=1073741824 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 rc2011-06-15 12:53:55.578140 2=0+2)/n(v0 1=0+1) hs=0+0,ss=0+0 | subtree 0x2a10010] version 3
2011-06-17 11:34:02.074919 7f995ecec700 mds0.journal EMetaBlob.replay dirty nestinfo on [dir 1 / [2,head] auth v=3 cv=0/0 dir_auth=0 state=1610612736 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 rc2011-06-15 12:53:55.578140 2=0+2)/n(v0 1=0+1) hs=0+0,ss=0+0 | subtree dirty 0x2a10010]
2011-06-17 11:34:02.074966 7f995ecec700 mds0.locker mark_updated_scatterlock (inest sync dirty) - added at 2011-06-17 11:34:02.074948
2011-06-17 11:34:02.075003 7f995ecec700 mds0.journal EMetaBlob.replay updated dir [dir 1 / [2,head] auth v=3 cv=0/0 dir_auth=0 state=1610612736 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 rc2011-06-15 12:53:55.578140 2=0+2)/n(v0 1=0+1) hs=0+0,ss=0+0 | subtree dirty 0x2a10010]
2011-06-17 11:34:02.075093 7f995ecec700 mds0.cache.dir(1) add_null_dentry [dentry #1/d1 [2,head] auth NULL (dversion lock) pv=0 v=3 inode=0 0x29f7ae0]
2011-06-17 11:34:02.075151 7f995ecec700 mds0.journal EMetaBlob.replay added [dentry #1/d1 [2,head] auth NULL (dversion lock) v=2 inode=0 | dirty 0x29f7ae0]
2011-06-17 11:34:02.075214 7f995ecec700 mds0.cache.dir(1) link_primary_inode [dentry #1/d1 [2,head] auth NULL (dversion lock) v=2 inode=0 | dirty 0x29f7ae0] [inode 10000000000 [...2,head] #10000000000/ auth v2 f() n(v0 1=0+1) (iversion lock) 0x7f99600036d0]
2011-06-17 11:34:02.075255 7f995ecec700 mds0.journal EMetaBlob.replay added [inode 10000000000 [...2,head] /d1/ auth v2 f() n(v0 1=0+1) (iversion lock) | dirty 0x7f99600036d0]
2011-06-17 11:34:02.075278 7f995ecec700 mds0.journal EMetaBlob.replay dir 10000000000
2011-06-17 11:34:02.075311 7f995ecec700 mds0.cache force_dir_fragment * on [inode 10000000000 [...2,head] /d1/ auth v2 f() n(v0 1=0+1) (iversion lock) | dirty 0x7f99600036d0]
2011-06-17 11:34:02.075334 7f995ecec700 mds0.cache force_dir_fragment no frags under *
2011-06-17 11:34:02.075425 7f995ecec700 mds0.journal EMetaBlob.replay added dir [dir 10000000000 /d1/ [2,head] auth v=0 cv=0/0 state=1073741824 f() n() hs=0+0,ss=0+0 0x2a10c40]
2011-06-17 11:34:02.075457 7f995ecec700 mds0.cache.dir(10000000000) mark_dirty (was clean) [dir 10000000000 /d1/ [2,head] auth v=1 cv=0/0 state=1073741824 f() n() hs=0+0,ss=0+0 0x2a10c40] version 1
2011-06-17 11:34:02.075492 7f995ecec700 mds0.journal EMetaBlob.replay clean nestinfo on [dir 10000000000 /d1/ [2,head] auth v=1 cv=0/0 state=1610612736 f() n() hs=0+0,ss=0+0 | dirty 0x2a10c40]
2011-06-17 11:34:02.075520 7f995ecec700 mds0.journal EMetaBlob.replay updated dir [dir 10000000000 /d1/ [2,head] auth v=1 cv=0/0 state=1610612738|complete f() n() hs=0+0,ss=0+0 | dirty 0x2a10c40]
2011-06-17 11:34:02.075555 7f995ecec700 mds0.journal EMetaBlob.replay noting opened inode [inode 10000000000 [...2,head] /d1/ auth v2 f() n(v0 1=0+1) (inest sync dirty) (ifile sync dirty) (iversion lock) | dirtyscattered dirfrag dirty 0x7f99600036d0]
2011-06-17 11:34:02.075589 7f995ecec700 mds0.journal EMetaBlob.replay inotable v 2 - 1 == table 0 allocated+used 10000000000 prealloc [10000000001~3e8]
2011-06-17 11:34:02.075614 7f995ecec700 mds0.inotable: replay_alloc_id 10000000000
2011-06-17 11:34:02.075642 7f995ecec700 mds0.inotable: replay_alloc_ids [10000000001~3e8]
2011-06-17 11:34:02.075675 7f995ecec700 mds0.journal EMetaBlob.replay sessionmap v4 -(1|2) == table 3 prealloc [10000000001~3e8] used 0
2011-06-17 11:34:02.075699 7f995ecec700 mds0.journal (session prealloc [])
2011-06-17 11:34:02.075722 7f995ecec700 mds0.journal EMetaBlob.replay request client4136:4 4
2011-06-17 11:34:02.075806 7f995ecec700 mds0.log _replay 4197198~1219 / 4236561 2011-06-15 12:54:41.470741: EUpdate setlayout [metablob 1, 1 dirs]
2011-06-17 11:34:02.075832 7f995ecec700 mds0.journal EMetaBlob.replay 1 dirlumps by unknown0
2011-06-17 11:34:02.075864 7f995ecec700 mds0.cache.ino(1) decode_snap_blob snaprealm(1 seq 1 lc 0 cr 0 cps 1 snaps={} 0x7f99600153e0)
2011-06-17 11:34:02.075899 7f995ecec700 mds0.journal EMetaBlob.replay updated root [inode 1 [...2,head] / auth v3 snaprealm=0x7f99600153e0 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 1=0+1) (inest sync dirty) (ifile sync dirty) (iversion lock) | dirtyscattered dirfrag dirty 0x7f9960002e40]
2011-06-17 11:34:02.075922 7f995ecec700 mds0.journal EMetaBlob.replay dir 1
2011-06-17 11:34:02.075959 7f995ecec700 mds0.cache.dir(1) mark_dirty (already dirty) [dir 1 / [2,head] auth v=5 cv=0/0 dir_auth=0 state=1610612736 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 rc2011-06-15 12:53:55.578140 2=0+2)/n(v0 1=0+1) hs=1+0,ss=0+0 dirty=1 | child subtree dirty 0x2a10010] version 5
2011-06-17 11:34:02.075997 7f995ecec700 mds0.journal EMetaBlob.replay dirty nestinfo on [dir 1 / [2,head] auth v=5 cv=0/0 dir_auth=0 state=1610612736 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 rc2011-06-15 12:53:55.578140 2=0+2)/n(v0 1=0+1) hs=1+0,ss=0+0 dirty=1 | child subtree dirty 0x2a10010]
2011-06-17 11:34:02.076023 7f995ecec700 mds0.locker mark_updated_scatterlock (inest sync dirty) - already on list since 2011-06-17 11:34:02.074948
2011-06-17 11:34:02.076057 7f995ecec700 mds0.journal EMetaBlob.replay updated dir [dir 1 / [2,head] auth v=5 cv=0/0 dir_auth=0 state=1610612736 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 rc2011-06-15 12:53:55.578140 2=0+2)/n(v0 1=0+1) hs=1+0,ss=0+0 dirty=1 | child subtree dirty 0x2a10010]
2011-06-17 11:34:02.076113 7f995ecec700 mds0.journal EMetaBlob.replay for [2,head] had [dentry #1/d1 [2,head] auth (dversion lock) v=4 inode=0x7f99600036d0 | inodepin dirty 0x29f7ae0]
2011-06-17 11:34:02.076153 7f995ecec700 mds0.journal EMetaBlob.replay for [2,head] had [inode 10000000000 [...2,head] /d1/ auth v4 f() n(v0 1=0+1) (inest sync dirty) (ifile sync dirty) (iversion lock) | dirtyscattered dirfrag dirty 0x7f99600036d0]
2011-06-17 11:34:02.076179 7f995ecec700 mds0.journal EMetaBlob.replay request client4136:7 7
2011-06-17 11:34:02.076231 7f995ecec700 mds0.log _replay 4198421~195 / 4236561 2011-06-15 12:54:59.051579: ESession client4136 192.168.60.134:0/1940014 close cmapv 5 (1000 inos, v3)
2011-06-17 11:34:02.076261 7f995ecec700 mds0.journal ESession.replay sessionmap 4 < 5 close client4136 192.168.60.134:0/1940014
2011-06-17 11:34:02.076290 7f995ecec700 mds0.journal removed session client4136 192.168.60.134:0/1940014
2011-06-17 11:34:02.076309 7f995ecec700 mds0.journal ESession.replay inotable 2 < 3 remove
2011-06-17 11:34:02.076332 7f995ecec700 mds0.inotable: replay_release_ids [10000000001~3e8]
2011-06-17 11:34:02.076373 7f995ecec700 mds0.log _replay 4198620~179 / 4236561 2011-06-15 12:55:01.071624: ESession client4140 192.168.60.134:0/4585 open cmapv 6
2011-06-17 11:34:02.076399 7f995ecec700 mds0.journal ESession.replay sessionmap 5 < 6 open client4140 192.168.60.134:0/4585
2011-06-17 11:34:02.076426 7f995ecec700 mds0.journal opened session client4140 192.168.60.134:0/4585
2011-06-17 11:34:02.076523 7f995ecec700 mds0.log _replay 4198803~1859 / 4236561 2011-06-15 12:55:14.610715: EUpdate mknod [metablob 1, 2 dirs alloc_ino=10000000001 prealloc_ino=[10000000002~3e8] v5]
2011-06-17 11:34:02.076548 7f995ecec700 mds0.journal EMetaBlob.replay 2 dirlumps by client4140
2011-06-17 11:34:02.076580 7f995ecec700 mds0.cache.ino(1) decode_snap_blob snaprealm(1 seq 1 lc 0 cr 0 cps 1 snaps={} 0x7f99600153e0)
2011-06-17 11:34:02.076615 7f995ecec700 mds0.journal EMetaBlob.replay updated root [inode 1 [...2,head] / auth v4 snaprealm=0x7f99600153e0 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 1=0+1) (inest sync dirty) (ifile sync dirty) (iversion lock) | dirtyscattered dirfrag dirty 0x7f9960002e40]
2011-06-17 11:34:02.076638 7f995ecec700 mds0.journal EMetaBlob.replay dir 1
2011-06-17 11:34:02.076675 7f995ecec700 mds0.cache.dir(1) mark_dirty (already dirty) [dir 1 / [2,head] auth v=7 cv=0/0 dir_auth=0 state=1610612736 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 rc2011-06-15 12:55:14.610557 3=1+2)/n(v0 1=0+1) hs=1+0,ss=0+0 dirty=1 | child subtree dirty 0x2a10010] version 7
2011-06-17 11:34:02.076713 7f995ecec700 mds0.journal EMetaBlob.replay dirty nestinfo on [dir 1 / [2,head] auth v=7 cv=0/0 dir_auth=0 state=1610612736 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 rc2011-06-15 12:55:14.610557 3=1+2)/n(v0 1=0+1) hs=1+0,ss=0+0 dirty=1 | child subtree dirty 0x2a10010]
2011-06-17 11:34:02.076737 7f995ecec700 mds0.locker mark_updated_scatterlock (inest sync dirty) - already on list since 2011-06-17 11:34:02.074948
2011-06-17 11:34:02.076769 7f995ecec700 mds0.journal EMetaBlob.replay updated dir [dir 1 / [2,head] auth v=7 cv=0/0 dir_auth=0 state=1610612736 f(v0 m2011-06-15 12:53:55.578140 2=0+2) n(v0 rc2011-06-15 12:55:14.610557 3=1+2)/n(v0 1=0+1) hs=1+0,ss=0+0 dirty=1 | child subtree dirty 0x2a10010]
2011-06-17 11:34:02.076822 7f995ecec700 mds0.journal EMetaBlob.replay for [2,head] had [dentry #1/d1 [2,head] auth (dversion lock) v=6 inode=0x7f99600036d0 | inodepin dirty 0x29f7ae0]
*** Caught signal (Aborted) **
in thread 0x7f995ecec700
ceph version (commit:)
1: (ceph::BackTrace::BackTrace(int)+0x2d) [0xa66ab7]
2: /usr/ceph/bin/cmds() [0xa9e73f]
3: (()+0xfc60) [0x7f99695a0c60]
4: (gsignal()+0x35) [0x7f9968a8fd05]
5: (abort()+0x186) [0x7f9968a93ab6]
6: (()+0x6cd7b) [0x7f9968ac8d7b]
7: (()+0x78a8f) [0x7f9968ad4a8f]
8: (cfree()+0x73) [0x7f9968ad88e3]
9: (EMetaBlob::fullbit::update_inode(MDS*, CInode*)+0x1cc) [0x804376]
10: (EMetaBlob::replay(MDS*, LogSegment*)+0x1579) [0x80598f]
11: (EUpdate::replay(MDS*)+0x44) [0x8092e4]
12: (MDLog::_replay_thread()+0xd9a) [0x9fdf1c]
13: (MDLog::ReplayThread::entry()+0x1c) [0x7df302]
14: (Thread::_entry_func(void*)+0x23) [0x9fe9c5]
15: (()+0x6d8c) [0x7f9969597d8c]
16: (clone()+0x6d) [0x7f9968b4204d]
(2-2/2)