gistfile1.txt

2011-06-01 10:47:00.127133 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 7 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4d80 con 0xff1640
2011-06-01 10:47:00.127157 7f172d805700 osd0 24 _dispatch 0xfd4d80 ping v1
2011-06-01 10:47:00.127179 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:00.353834 7f1734012700 osd0 24 tick
2011-06-01 10:47:00.353891 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.05 < max 0.5 = yes
2011-06-01 10:47:00.353905 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:00.353913 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:00.636982 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 7 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2000 con 0xff1dc0
2011-06-01 10:47:00.637010 7f172d805700 osd0 24 _dispatch 0xff2000 ping v1
2011-06-01 10:47:00.637035 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:00.940708 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 8 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2480 con 0xff13c0
2011-06-01 10:47:00.940733 7f172d805700 osd0 24 _dispatch 0xff2480 ping v1
2011-06-01 10:47:00.940754 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:00.955744 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:00.955781 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:00.955694 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:00.955791 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:01.051942 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000127
2011-06-01 10:47:01.051969 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:01.051983 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:01.051994 7f173200e700 journal commit_start
2011-06-01 10:47:01.052002 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:01.354066 7f1734012700 osd0 24 tick
2011-06-01 10:47:01.354123 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = no, randomly backing off
2011-06-01 10:47:01.354139 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:01.354147 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:01.354154 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:02.255986 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:02.256023 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:02.255937 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:02.256041 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:02.354304 7f1734012700 osd0 24 tick
2011-06-01 10:47:02.354362 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = no, randomly backing off
2011-06-01 10:47:02.541696 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 12 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4a80 con 0xff1280
2011-06-01 10:47:02.541723 7f172d805700 osd0 24 _dispatch 0xfd4a80 ping v1
2011-06-01 10:47:02.541749 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:03.354517 7f1734012700 osd0 24 tick
2011-06-01 10:47:03.354573 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = no, randomly backing off
2011-06-01 10:47:03.456206 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:03.456244 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:03.456157 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:03.456254 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:04.354712 7f1734012700 osd0 24 tick
2011-06-01 10:47:04.354769 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = no, randomly backing off
2011-06-01 10:47:04.356440 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:04.356476 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:04.356391 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:04.356487 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:04.472514 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 8 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4d80 con 0xff1000
2011-06-01 10:47:04.472537 7f172d805700 osd0 24 _dispatch 0xfd4d80 ping v1
2011-06-01 10:47:04.472546 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:04.856674 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:04.856712 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:04.856626 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:04.856722 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:05.127306 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 8 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2480 con 0xff1640
2011-06-01 10:47:05.127335 7f172d805700 osd0 24 _dispatch 0xff2480 ping v1
2011-06-01 10:47:05.127349 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:05.354927 7f1734012700 osd0 24 tick
2011-06-01 10:47:05.354985 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = yes
2011-06-01 10:47:05.354998 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:05.355007 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:05.637088 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 8 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2a80 con 0xff1dc0
2011-06-01 10:47:05.637112 7f172d805700 osd0 24 _dispatch 0xff2a80 ping v1
2011-06-01 10:47:05.637122 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:05.756913 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:05.756949 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:05.756864 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:05.756960 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:05.940881 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 9 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2300 con 0xff13c0
2011-06-01 10:47:05.940907 7f172d805700 osd0 24 _dispatch 0xff2300 ping v1
2011-06-01 10:47:05.940921 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:06.052132 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000127
2011-06-01 10:47:06.052168 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:06.052180 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:06.052190 7f173200e700 journal commit_start
2011-06-01 10:47:06.052200 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:06.355156 7f1734012700 osd0 24 tick
2011-06-01 10:47:06.355213 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = no, randomly backing off
2011-06-01 10:47:06.355229 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:06.355237 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:06.355245 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:06.657137 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:06.657174 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:06.657088 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:06.657185 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:07.355394 7f1734012700 osd0 24 tick
2011-06-01 10:47:07.355451 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = no, randomly backing off
2011-06-01 10:47:07.541728 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 13 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4900 con 0xff1280
2011-06-01 10:47:07.541754 7f172d805700 osd0 24 _dispatch 0xfd4900 ping v1
2011-06-01 10:47:07.541764 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:07.657377 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:07.657412 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:07.657310 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:07.657423 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:08.355589 7f1734012700 osd0 24 tick
2011-06-01 10:47:08.355646 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = no, randomly backing off
2011-06-01 10:47:08.457607 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:08.457643 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:08.457558 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:08.457653 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:09.355801 7f1734012700 osd0 24 tick
2011-06-01 10:47:09.355858 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = no, randomly backing off
2011-06-01 10:47:09.472623 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 9 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4180 con 0xff1000
2011-06-01 10:47:09.472650 7f172d805700 osd0 24 _dispatch 0xfd4180 ping v1
2011-06-01 10:47:09.472664 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:09.657838 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:09.657875 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:09.657789 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:09.657885 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:10.127439 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 9 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2000 con 0xff1640
2011-06-01 10:47:10.127467 7f172d805700 osd0 24 _dispatch 0xff2000 ping v1
2011-06-01 10:47:10.127492 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:10.356013 7f1734012700 osd0 24 tick
2011-06-01 10:47:10.356070 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = no, randomly backing off
2011-06-01 10:47:10.637237 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 9 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2900 con 0xff1dc0
2011-06-01 10:47:10.637271 7f172d805700 osd0 24 _dispatch 0xff2900 ping v1
2011-06-01 10:47:10.637286 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:10.858076 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:10.858123 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:10.858027 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:10.858134 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:10.940999 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 10 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4300 con 0xff13c0
2011-06-01 10:47:10.941027 7f172d805700 osd0 24 _dispatch 0xfd4300 ping v1
2011-06-01 10:47:10.941051 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:11.052325 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000122
2011-06-01 10:47:11.052353 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:11.052379 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:11.052395 7f173200e700 journal commit_start
2011-06-01 10:47:11.052412 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:11.356206 7f1734012700 osd0 24 tick
2011-06-01 10:47:11.356263 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = yes
2011-06-01 10:47:11.356277 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:11.356285 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:11.356294 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:11.356305 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:11.356313 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:11.858307 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:11.858344 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:11.858258 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:11.858355 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:12.356445 7f1734012700 osd0 24 tick
2011-06-01 10:47:12.356502 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = no, randomly backing off
2011-06-01 10:47:12.458543 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:12.458579 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:12.458494 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:12.458590 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:12.541863 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 14 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4c00 con 0xff1280
2011-06-01 10:47:12.541880 7f172d805700 osd0 24 _dispatch 0xfd4c00 ping v1
2011-06-01 10:47:12.541894 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:13.356659 7f1734012700 osd0 24 tick
2011-06-01 10:47:13.356717 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = yes
2011-06-01 10:47:13.356731 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:13.356739 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:13.758773 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:13.758810 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:13.758724 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:13.758821 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:14.356889 7f1734012700 osd0 24 tick
2011-06-01 10:47:14.356946 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = no, randomly backing off
2011-06-01 10:47:14.472782 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 10 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4600 con 0xff1000
2011-06-01 10:47:14.472814 7f172d805700 osd0 24 _dispatch 0xfd4600 ping v1
2011-06-01 10:47:14.472837 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:14.758988 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:14.759025 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:14.758938 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:14.759035 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:15.127563 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 10 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2180 con 0xff1640
2011-06-01 10:47:15.127590 7f172d805700 osd0 24 _dispatch 0xff2180 ping v1
2011-06-01 10:47:15.127615 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:15.357085 7f1734012700 osd0 24 tick
2011-06-01 10:47:15.357141 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.04 < max 0.5 = yes
2011-06-01 10:47:15.357155 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:15.357163 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:15.359224 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:15.359262 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:15.359175 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:15.359272 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:15.637385 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 10 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2780 con 0xff1dc0
2011-06-01 10:47:15.637411 7f172d805700 osd0 24 _dispatch 0xff2780 ping v1
2011-06-01 10:47:15.637426 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:15.941117 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 11 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4780 con 0xff13c0
2011-06-01 10:47:15.941144 7f172d805700 osd0 24 _dispatch 0xfd4780 ping v1
2011-06-01 10:47:15.941169 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:16.052561 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000148
2011-06-01 10:47:16.052589 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:16.052608 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:16.052621 7f173200e700 journal commit_start
2011-06-01 10:47:16.052638 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:16.357311 7f1734012700 osd0 24 tick
2011-06-01 10:47:16.357368 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:16.357383 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:16.357391 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:16.357399 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:16.659462 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:16.659499 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:16.659413 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:16.659509 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:16.659518 7f17296fc700 osd0 24 i have no heartbeat peers; checking mon for new map
2011-06-01 10:47:16.659538 7f17296fc700 -- 192.168.100.7:6801/12738 --> mon0 192.168.100.7:6789/0 -- mon_subscribe({monmap=2+,osdmap=25}) v1 -- ?+0 0xfec000
2011-06-01 10:47:16.660009 7f172d805700 -- 192.168.100.7:6801/12738 <== mon0 192.168.100.7:6789/0 10 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (2684212871 0 0) 0xfd4180 con 0xfeb280
2011-06-01 10:47:17.357547 7f1734012700 osd0 24 tick
2011-06-01 10:47:17.357604 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:17.542011 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 15 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2000 con 0xff1280
2011-06-01 10:47:17.542034 7f172d805700 osd0 24 _dispatch 0xff2000 ping v1
2011-06-01 10:47:17.542049 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:17.859729 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:17.859766 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:17.859680 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:17.859777 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:18.357758 7f1734012700 osd0 24 tick
2011-06-01 10:47:18.357815 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:18.659965 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:18.660002 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:18.659917 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:18.660013 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:19.357953 7f1734012700 osd0 24 tick
2011-06-01 10:47:19.358010 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:19.460201 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:19.460238 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:19.460152 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:19.460248 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:19.472917 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 11 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4480 con 0xff1000
2011-06-01 10:47:19.472944 7f172d805700 osd0 24 _dispatch 0xfd4480 ping v1
2011-06-01 10:47:19.472958 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:20.127629 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 11 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4a80 con 0xff1640
2011-06-01 10:47:20.127652 7f172d805700 osd0 24 _dispatch 0xfd4a80 ping v1
2011-06-01 10:47:20.127661 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:20.358184 7f1734012700 osd0 24 tick
2011-06-01 10:47:20.358240 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:20.460443 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:20.460480 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:20.460394 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:20.460490 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:20.637562 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 11 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2600 con 0xff1dc0
2011-06-01 10:47:20.637589 7f172d805700 osd0 24 _dispatch 0xff2600 ping v1
2011-06-01 10:47:20.637603 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:20.941188 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 12 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4480 con 0xff13c0
2011-06-01 10:47:20.941211 7f172d805700 osd0 24 _dispatch 0xfd4480 ping v1
2011-06-01 10:47:20.941221 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:21.052791 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000152
2011-06-01 10:47:21.052819 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:21.052844 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:21.052859 7f173200e700 journal commit_start
2011-06-01 10:47:21.052876 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:21.358386 7f1734012700 osd0 24 tick
2011-06-01 10:47:21.358451 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:21.358466 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:21.358474 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:21.358482 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:21.360679 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:21.360715 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:21.360631 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:21.360726 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:21.860916 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:21.860953 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:21.860867 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:21.860963 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:22.358631 7f1734012700 osd0 24 tick
2011-06-01 10:47:22.358688 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:22.542203 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 16 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2300 con 0xff1280
2011-06-01 10:47:22.542229 7f172d805700 osd0 24 _dispatch 0xff2300 ping v1
2011-06-01 10:47:22.542244 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:23.261155 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:23.261191 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:23.261106 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:23.261202 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:23.358829 7f1734012700 osd0 24 tick
2011-06-01 10:47:23.358886 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = yes
2011-06-01 10:47:23.358900 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:23.358908 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:24.061371 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:24.061407 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:24.061322 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:24.061418 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:24.359058 7f1734012700 osd0 24 tick
2011-06-01 10:47:24.359115 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:24.473097 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 12 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2600 con 0xff1000
2011-06-01 10:47:24.473129 7f172d805700 osd0 24 _dispatch 0xff2600 ping v1
2011-06-01 10:47:24.473146 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:24.561603 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:24.561640 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:24.561554 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:24.561651 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:25.127738 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 12 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2d80 con 0xff1640
2011-06-01 10:47:25.127762 7f172d805700 osd0 24 _dispatch 0xff2d80 ping v1
2011-06-01 10:47:25.127771 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:25.161840 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:25.161876 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:25.161791 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:25.161894 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:25.359271 7f1734012700 osd0 24 tick
2011-06-01 10:47:25.359327 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:25.637683 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 12 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000600 con 0xff1dc0
2011-06-01 10:47:25.637710 7f172d805700 osd0 24 _dispatch 0x1000600 ping v1
2011-06-01 10:47:25.637726 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:25.662087 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:25.662124 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:25.662038 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:25.662135 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:25.941304 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 13 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4180 con 0xff13c0
2011-06-01 10:47:25.941327 7f172d805700 osd0 24 _dispatch 0xfd4180 ping v1
2011-06-01 10:47:25.941336 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:26.053027 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000149
2011-06-01 10:47:26.053056 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:26.053081 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:26.053096 7f173200e700 journal commit_start
2011-06-01 10:47:26.053113 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:26.162325 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:26.162361 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:26.162276 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:26.162371 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:26.359479 7f1734012700 osd0 24 tick
2011-06-01 10:47:26.359536 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:26.359551 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:26.359560 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:26.359567 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:26.962558 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:26.962595 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:26.962509 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:26.962605 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:27.359695 7f1734012700 osd0 24 tick
2011-06-01 10:47:27.359752 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:27.542382 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 17 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2a80 con 0xff1280
2011-06-01 10:47:27.542408 7f172d805700 osd0 24 _dispatch 0xff2a80 ping v1
2011-06-01 10:47:27.542422 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:28.262794 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:28.262831 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:28.262745 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:28.262842 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:28.359910 7f1734012700 osd0 24 tick
2011-06-01 10:47:28.359967 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = yes
2011-06-01 10:47:28.359980 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:28.359996 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:29.263005 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:29.263042 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:29.262956 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:29.263053 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:29.360145 7f1734012700 osd0 24 tick
2011-06-01 10:47:29.360202 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:29.473201 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 13 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2000 con 0xff1000
2011-06-01 10:47:29.473225 7f172d805700 osd0 24 _dispatch 0xff2000 ping v1
2011-06-01 10:47:29.473241 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:30.127905 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 13 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2c00 con 0xff1640
2011-06-01 10:47:30.127935 7f172d805700 osd0 24 _dispatch 0xff2c00 ping v1
2011-06-01 10:47:30.127952 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:30.163224 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:30.163261 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:30.163176 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:30.163271 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:30.360357 7f1734012700 osd0 24 tick
2011-06-01 10:47:30.360414 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = yes
2011-06-01 10:47:30.360428 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:30.360436 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:30.637783 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 13 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000480 con 0xff1dc0
2011-06-01 10:47:30.637809 7f172d805700 osd0 24 _dispatch 0x1000480 ping v1
2011-06-01 10:47:30.637824 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:30.941455 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 14 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4780 con 0xff13c0
2011-06-01 10:47:30.941482 7f172d805700 osd0 24 _dispatch 0xfd4780 ping v1
2011-06-01 10:47:30.941507 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:31.053267 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000152
2011-06-01 10:47:31.053295 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:31.053314 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:31.053327 7f173200e700 journal commit_start
2011-06-01 10:47:31.053342 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:31.063462 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:31.063499 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:31.063413 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:31.063509 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:31.360568 7f1734012700 osd0 24 tick
2011-06-01 10:47:31.360625 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:31.360640 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:31.360648 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:31.360655 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:32.360803 7f1734012700 osd0 24 tick
2011-06-01 10:47:32.360860 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = yes
2011-06-01 10:47:32.360874 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:32.360882 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:32.363695 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:32.363739 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:32.363646 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:32.363750 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:32.542455 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 18 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2480 con 0xff1280
2011-06-01 10:47:32.542481 7f172d805700 osd0 24 _dispatch 0xff2480 ping v1
2011-06-01 10:47:32.542495 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:33.163940 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:33.163976 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:33.163891 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:33.163987 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:33.361030 7f1734012700 osd0 24 tick
2011-06-01 10:47:33.361087 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = yes
2011-06-01 10:47:33.361101 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:33.361109 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:34.361257 7f1734012700 osd0 24 tick
2011-06-01 10:47:34.361314 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = yes
2011-06-01 10:47:34.361328 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:34.361336 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:34.364170 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:34.364207 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:34.364121 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:34.364217 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:34.473343 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 14 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2780 con 0xff1000
2011-06-01 10:47:34.473369 7f172d805700 osd0 24 _dispatch 0xff2780 ping v1
2011-06-01 10:47:34.473383 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:35.128033 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 14 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2900 con 0xff1640
2011-06-01 10:47:35.128061 7f172d805700 osd0 24 _dispatch 0xff2900 ping v1
2011-06-01 10:47:35.128086 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:35.361484 7f1734012700 osd0 24 tick
2011-06-01 10:47:35.361541 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.03 < max 0.5 = no, randomly backing off
2011-06-01 10:47:35.464406 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:35.464443 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:35.464357 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:35.464454 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:35.637911 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 14 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000300 con 0xff1dc0
2011-06-01 10:47:35.637937 7f172d805700 osd0 24 _dispatch 0x1000300 ping v1
2011-06-01 10:47:35.637951 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:35.941578 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 15 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4600 con 0xff13c0
2011-06-01 10:47:35.941601 7f172d805700 osd0 24 _dispatch 0xfd4600 ping v1
2011-06-01 10:47:35.941610 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:36.053496 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000153
2011-06-01 10:47:36.053524 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:36.053549 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:36.053573 7f173200e700 journal commit_start
2011-06-01 10:47:36.053588 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:36.064641 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:36.064677 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:36.064592 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:36.064687 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:36.361652 7f1734012700 osd0 24 tick
2011-06-01 10:47:36.361708 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:36.361723 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:36.361732 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:36.361739 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:37.361935 7f1734012700 osd0 24 tick
2011-06-01 10:47:37.361987 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:37.464857 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:37.464894 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:37.464809 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:37.464905 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:37.542632 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 19 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4300 con 0xff1280
2011-06-01 10:47:37.542658 7f172d805700 osd0 24 _dispatch 0xfd4300 ping v1
2011-06-01 10:47:37.542672 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:38.165096 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:38.165133 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:38.165048 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:38.165143 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:38.362193 7f1734012700 osd0 24 tick
2011-06-01 10:47:38.362245 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:39.362443 7f1734012700 osd0 24 tick
2011-06-01 10:47:39.362495 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:39.365332 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:39.365369 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:39.365283 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:39.365379 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:39.473547 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 15 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2180 con 0xff1000
2011-06-01 10:47:39.473577 7f172d805700 osd0 24 _dispatch 0xff2180 ping v1
2011-06-01 10:47:39.473591 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:40.128096 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 15 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2c00 con 0xff1640
2011-06-01 10:47:40.128131 7f172d805700 osd0 24 _dispatch 0xff2c00 ping v1
2011-06-01 10:47:40.128142 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:40.362694 7f1734012700 osd0 24 tick
2011-06-01 10:47:40.362746 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = yes
2011-06-01 10:47:40.362757 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:40.362766 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:40.638081 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 15 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000180 con 0xff1dc0
2011-06-01 10:47:40.638115 7f172d805700 osd0 24 _dispatch 0x1000180 ping v1
2011-06-01 10:47:40.638140 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:40.665570 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:40.665607 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:40.665522 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:40.665618 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:40.941637 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 16 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4c00 con 0xff13c0
2011-06-01 10:47:40.941661 7f172d805700 osd0 24 _dispatch 0xfd4c00 ping v1
2011-06-01 10:47:40.941670 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:41.053741 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000151
2011-06-01 10:47:41.053769 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:41.053794 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:41.053811 7f173200e700 journal commit_start
2011-06-01 10:47:41.053825 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:41.362961 7f1734012700 osd0 24 tick
2011-06-01 10:47:41.363013 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = yes
2011-06-01 10:47:41.363024 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:41.363033 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:41.363041 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:41.363048 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:41.363055 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:41.865803 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:41.865840 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:41.865754 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:41.865851 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:42.363236 7f1734012700 osd0 24 tick
2011-06-01 10:47:42.363288 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:42.466047 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:42.466083 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:42.465998 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:42.466094 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:42.542803 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 20 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000780 con 0xff1280
2011-06-01 10:47:42.542830 7f172d805700 osd0 24 _dispatch 0x1000780 ping v1
2011-06-01 10:47:42.542844 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:43.363476 7f1734012700 osd0 24 tick
2011-06-01 10:47:43.363528 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:43.866282 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:43.866319 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:43.866233 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:43.866329 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:44.363726 7f1734012700 osd0 24 tick
2011-06-01 10:47:44.363778 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:44.473648 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 16 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4a80 con 0xff1000
2011-06-01 10:47:44.473672 7f172d805700 osd0 24 _dispatch 0xfd4a80 ping v1
2011-06-01 10:47:44.473688 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:44.666512 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:44.666556 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:44.666463 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:44.666567 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:45.128262 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 16 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2000 con 0xff1640
2011-06-01 10:47:45.128291 7f172d805700 osd0 24 _dispatch 0xff2000 ping v1
2011-06-01 10:47:45.128309 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:45.363973 7f1734012700 osd0 24 tick
2011-06-01 10:47:45.364025 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:45.638161 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 16 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000000 con 0xff1dc0
2011-06-01 10:47:45.638187 7f172d805700 osd0 24 _dispatch 0x1000000 ping v1
2011-06-01 10:47:45.638208 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:45.941851 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 17 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4600 con 0xff13c0
2011-06-01 10:47:45.941879 7f172d805700 osd0 24 _dispatch 0xfd4600 ping v1
2011-06-01 10:47:45.941904 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:45.966738 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:45.966775 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:45.966689 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:45.966785 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:46.053981 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000154
2011-06-01 10:47:46.054008 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:46.054033 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:46.054049 7f173200e700 journal commit_start
2011-06-01 10:47:46.054066 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:46.364224 7f1734012700 osd0 24 tick
2011-06-01 10:47:46.364276 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = yes
2011-06-01 10:47:46.364288 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:46.364296 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:46.364304 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:46.364312 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:46.364319 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:46.666971 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:46.667007 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:46.666922 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:46.667017 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:46.667025 7f17296fc700 osd0 24 i have no heartbeat peers; checking mon for new map
2011-06-01 10:47:46.667045 7f17296fc700 -- 192.168.100.7:6801/12738 --> mon0 192.168.100.7:6789/0 -- mon_subscribe({monmap=2+,osdmap=25}) v1 -- ?+0 0xfec8c0
2011-06-01 10:47:46.667446 7f172d805700 -- 192.168.100.7:6801/12738 <== mon0 192.168.100.7:6789/0 11 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (2684212871 0 0) 0xfd4900 con 0xfeb280
2011-06-01 10:47:47.167238 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:47.167275 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:47.167189 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:47.167286 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:47.364500 7f1734012700 osd0 24 tick
2011-06-01 10:47:47.364559 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = yes
2011-06-01 10:47:47.364571 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:47.364579 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:47.542847 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 21 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000480 con 0xff1280
2011-06-01 10:47:47.542872 7f172d805700 osd0 24 _dispatch 0x1000480 ping v1
2011-06-01 10:47:47.542894 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:48.267468 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:48.267505 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:48.267420 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:48.267516 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:48.364776 7f1734012700 osd0 24 tick
2011-06-01 10:47:48.364828 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:49.067711 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:49.067747 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:49.067662 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:49.067758 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:49.365019 7f1734012700 osd0 24 tick
2011-06-01 10:47:49.365071 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:49.473772 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 17 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000780 con 0xff1000
2011-06-01 10:47:49.473798 7f172d805700 osd0 24 _dispatch 0x1000780 ping v1
2011-06-01 10:47:49.473812 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:49.867943 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:49.867980 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:49.867894 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:49.867991 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:50.128270 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 17 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2a80 con 0xff1640
2011-06-01 10:47:50.128293 7f172d805700 osd0 24 _dispatch 0xff2a80 ping v1
2011-06-01 10:47:50.128303 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:50.365264 7f1734012700 osd0 24 tick
2011-06-01 10:47:50.365316 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:50.638356 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 17 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000d80 con 0xff1dc0
2011-06-01 10:47:50.638382 7f172d805700 osd0 24 _dispatch 0x1000d80 ping v1
2011-06-01 10:47:50.638396 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:50.668183 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:50.668219 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:50.668134 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:50.668230 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:50.941868 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 18 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2c00 con 0xff13c0
2011-06-01 10:47:50.941891 7f172d805700 osd0 24 _dispatch 0xff2c00 ping v1
2011-06-01 10:47:50.941900 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:51.054211 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000143
2011-06-01 10:47:51.054239 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:51.054277 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:51.054291 7f173200e700 journal commit_start
2011-06-01 10:47:51.054307 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:51.365497 7f1734012700 osd0 24 tick
2011-06-01 10:47:51.365549 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:51.365562 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:51.365570 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:51.365578 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:51.568422 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:51.568459 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:51.568373 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:51.568469 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:52.068666 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:52.068705 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:52.068611 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:52.068715 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:52.365787 7f1734012700 osd0 24 tick
2011-06-01 10:47:52.365841 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = yes
2011-06-01 10:47:52.365852 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:52.365861 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:52.543064 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 22 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000600 con 0xff1280
2011-06-01 10:47:52.543091 7f172d805700 osd0 24 _dispatch 0x1000600 ping v1
2011-06-01 10:47:52.543105 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:52.568906 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:52.568943 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:52.568857 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:52.568954 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:53.366053 7f1734012700 osd0 24 tick
2011-06-01 10:47:53.366106 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:53.769137 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:53.769174 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:53.769089 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:53.769185 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:54.366300 7f1734012700 osd0 24 tick
2011-06-01 10:47:54.366352 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:54.469356 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:54.469392 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:54.469308 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:54.469403 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:54.473959 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 18 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000180 con 0xff1000
2011-06-01 10:47:54.473985 7f172d805700 osd0 24 _dispatch 0x1000180 ping v1
2011-06-01 10:47:54.473999 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:55.128456 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 18 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2d80 con 0xff1640
2011-06-01 10:47:55.128480 7f172d805700 osd0 24 _dispatch 0xff2d80 ping v1
2011-06-01 10:47:55.128500 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:47:55.169591 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:55.169628 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:55.169543 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:55.169639 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:55.366548 7f1734012700 osd0 24 tick
2011-06-01 10:47:55.366600 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:55.638560 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 18 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000c00 con 0xff1dc0
2011-06-01 10:47:55.638588 7f172d805700 osd0 24 _dispatch 0x1000c00 ping v1
2011-06-01 10:47:55.638602 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:47:55.669830 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:55.669867 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:55.669782 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:55.669877 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:55.942011 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 19 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2180 con 0xff13c0
2011-06-01 10:47:55.942034 7f172d805700 osd0 24 _dispatch 0xff2180 ping v1
2011-06-01 10:47:55.942044 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:47:56.054443 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000134
2011-06-01 10:47:56.054471 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:47:56.054495 7f173200e700 journal commit_start nothing to do
2011-06-01 10:47:56.054509 7f173200e700 journal commit_start
2011-06-01 10:47:56.054525 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:47:56.366799 7f1734012700 osd0 24 tick
2011-06-01 10:47:56.366852 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:56.366865 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:47:56.366873 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:47:56.366881 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:47:56.670065 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:56.670102 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:56.670016 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:56.670112 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:57.367077 7f1734012700 osd0 24 tick
2011-06-01 10:47:57.367129 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:57.543218 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 23 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4780 con 0xff1280
2011-06-01 10:47:57.543244 7f172d805700 osd0 24 _dispatch 0xfd4780 ping v1
2011-06-01 10:47:57.543258 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:47:57.770313 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:57.770350 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:57.770264 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:57.770360 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:58.367331 7f1734012700 osd0 24 tick
2011-06-01 10:47:58.367383 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:47:58.370551 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:58.370599 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:58.370502 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:58.370610 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:59.367580 7f1734012700 osd0 24 tick
2011-06-01 10:47:59.367632 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = yes
2011-06-01 10:47:59.367644 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:47:59.367652 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:47:59.474038 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 19 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000300 con 0xff1000
2011-06-01 10:47:59.474063 7f172d805700 osd0 24 _dispatch 0x1000300 ping v1
2011-06-01 10:47:59.474078 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:47:59.770802 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:47:59.770839 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:47:59.770753 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:47:59.770849 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:00.128618 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 19 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2600 con 0xff1640
2011-06-01 10:48:00.128649 7f172d805700 osd0 24 _dispatch 0xff2600 ping v1
2011-06-01 10:48:00.128666 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:48:00.367848 7f1734012700 osd0 24 tick
2011-06-01 10:48:00.367900 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:48:00.638635 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 19 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000a80 con 0xff1dc0
2011-06-01 10:48:00.638661 7f172d805700 osd0 24 _dispatch 0x1000a80 ping v1
2011-06-01 10:48:00.638676 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:48:00.771042 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:00.771079 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:48:00.770993 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:48:00.771089 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:00.942118 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 20 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2900 con 0xff13c0
2011-06-01 10:48:00.942141 7f172d805700 osd0 24 _dispatch 0xff2900 ping v1
2011-06-01 10:48:00.942150 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:48:01.054671 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000144
2011-06-01 10:48:01.054698 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:48:01.054725 7f173200e700 journal commit_start nothing to do
2011-06-01 10:48:01.054741 7f173200e700 journal commit_start
2011-06-01 10:48:01.054758 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:48:01.368098 7f1734012700 osd0 24 tick
2011-06-01 10:48:01.368162 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = yes
2011-06-01 10:48:01.368174 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:48:01.368183 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:48:01.368191 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:48:01.368198 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:48:01.368206 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:48:01.771276 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:01.771313 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:48:01.771227 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:48:01.771324 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:02.368405 7f1734012700 osd0 24 tick
2011-06-01 10:48:02.368458 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:48:02.543350 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 24 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4180 con 0xff1280
2011-06-01 10:48:02.543376 7f172d805700 osd0 24 _dispatch 0xfd4180 ping v1
2011-06-01 10:48:02.543390 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:48:03.171521 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:03.171558 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:48:03.171472 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:48:03.171569 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:03.368654 7f1734012700 osd0 24 tick
2011-06-01 10:48:03.368706 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:48:04.368906 7f1734012700 osd0 24 tick
2011-06-01 10:48:04.368958 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:48:04.471747 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:04.471785 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:48:04.471699 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:48:04.471795 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:04.474226 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721306 192.168.100.7:0/1011731 20 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4a80 con 0xff1000
2011-06-01 10:48:04.474255 7f172d805700 osd0 24 _dispatch 0xfd4a80 ping v1
2011-06-01 10:48:04.474269 7f172d805700 osd0 24 ping from client1721306
2011-06-01 10:48:05.128691 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720602 192.168.100.2:0/1018565 20 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2300 con 0xff1640
2011-06-01 10:48:05.128715 7f172d805700 osd0 24 _dispatch 0xff2300 ping v1
2011-06-01 10:48:05.128724 7f172d805700 osd0 24 ping from client1720602
2011-06-01 10:48:05.171963 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:05.171999 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:48:05.171914 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:48:05.172010 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:05.369155 7f1734012700 osd0 24 tick
2011-06-01 10:48:05.369207 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.02 < max 0.5 = no, randomly backing off
2011-06-01 10:48:05.638681 7f172d805700 -- 192.168.100.7:6801/12738 <== client1721307 192.168.100.7:0/1011744 20 ==== ping v1 ==== 0+0+0 (0 0 0) 0x1000900 con 0xff1dc0
2011-06-01 10:48:05.638702 7f172d805700 osd0 24 _dispatch 0x1000900 ping v1
2011-06-01 10:48:05.638713 7f172d805700 osd0 24 ping from client1721307
2011-06-01 10:48:05.942225 7f172d805700 -- 192.168.100.7:6801/12738 <== client1720510 192.168.100.2:0/1031296 21 ==== ping v1 ==== 0+0+0 (0 0 0) 0xff2780 con 0xff13c0
2011-06-01 10:48:05.942248 7f172d805700 osd0 24 _dispatch 0xff2780 ping v1
2011-06-01 10:48:05.942259 7f172d805700 osd0 24 ping from client1720510
2011-06-01 10:48:06.054911 7f173200e700 filestore(/data/osd0) sync_entry woke after 5.000151
2011-06-01 10:48:06.054939 7f173200e700 journal commit_start op_seq 555709, applied_seq 555709, committed_seq 555709
2011-06-01 10:48:06.054964 7f173200e700 journal commit_start nothing to do
2011-06-01 10:48:06.054980 7f173200e700 journal commit_start
2011-06-01 10:48:06.054995 7f173200e700 filestore(/data/osd0) sync_entry waiting for max_interval 5.000000
2011-06-01 10:48:06.369406 7f1734012700 osd0 24 tick
2011-06-01 10:48:06.369458 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.01 < max 0.5 = yes
2011-06-01 10:48:06.369470 7f1734012700 osd0 24 sched_scrub
2011-06-01 10:48:06.369485 7f1734012700 osd0 24 sched_scrub done
2011-06-01 10:48:06.369494 7f1734012700 osd0 24 do_mon_report
2011-06-01 10:48:06.369502 7f1734012700 osd0 24 send_alive up_thru currently 0 want 0
2011-06-01 10:48:06.369509 7f1734012700 osd0 24 send_pg_stats
2011-06-01 10:48:06.572157 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:06.572198 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:48:06.572121 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:48:06.572210 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:07.172401 7f17296fc700 osd0 24 update_osd_stat osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:07.172437 7f17296fc700 osd0 24 heartbeat: stat(2011-06-01 10:48:07.172352 oprate=0 qlen=0 recent_qlen=0 rdlat=0 / 0 fshedin=0)
2011-06-01 10:48:07.172448 7f17296fc700 osd0 24 heartbeat: osd_stat(15207 MB used, 131 GB avail, 146 GB total, peers []/[])
2011-06-01 10:48:07.369706 7f1734012700 osd0 24 tick
2011-06-01 10:48:07.369758 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.01 < max 0.5 = no, randomly backing off
2011-06-01 10:48:07.543506 7f172d805700 -- 192.168.100.7:6801/12738 <== mds0 192.168.100.7:6800/3403 25 ==== ping v1 ==== 0+0+0 (0 0 0) 0xfd4480 con 0xff1280
2011-06-01 10:48:07.543532 7f172d805700 osd0 24 _dispatch 0xfd4480 ping v1
2011-06-01 10:48:07.543546 7f172d805700 osd0 24 ping from mds0
2011-06-01 10:48:08.369960 7f1734012700 osd0 24 tick
2011-06-01 10:48:08.370013 7f1734012700 osd0 24 scrub_should_schedule loadavg 0.01 < max 0.5 = no, randomly backing off