Mon gets flooded with log messages for default log level

[Aanchal Agrawal]

Hi,

With reference to commit f7d1902ccf9d5bb97cda626d718c3bb02f991a6d, 'Paxos' default level has been increased to 1.
This cause mon to get flooded with the following message, thus causes OS Drive(160GB) to get filled in 4-5 hours.

Log Snippet ::
==================
2014-09-01 16:35:11.527734 7f7efe706700 1 mon.rack6-ramp-***@0(leader).paxos(paxos active c 1..712) is_readable now=2014-09-01 16:35:11.527735 lease_expire=2014-09-01 16:35:13.637940 has v0 lc 712
2014-09-01 16:35:11.527773 7f7efe706700 1 mon.rack6-ramp-***@0(leader).paxos(paxos active c 1..712) is_readable now=2014-09-01 16:35:11.527774 lease_expire=2014-09-01 16:35:13.637940 has v0 lc 712
2014-09-01 16:35:11.527807 7f7efe706700 1 mon.rack6-ramp-***@0(leader).paxos(paxos active c 1..712) is_readable now=2014-09-01 16:35:11.527807 lease_expire=2014-09-01 16:35:13.637940 has v0 lc 712
2014-09-01 16:35:11.527840 7f7efe706700 1 mon.rack6-ramp-***@0(leader).paxos(paxos active c 1..712) is_readable now=2014-09-01 16:35:11.527840 lease_expire=2014-09-01 16:35:13.637940 has v0 lc 712
2014-09-01 16:35:11.527874 7f7efe706700 1 mon.rack6-ramp-***@0(leader).paxos(paxos active c 1..712) is_readable now=2014-09-01 16:35:11.527875 lease_expire=2014-09-01 16:35:13.637940 has v0 lc 712
==================

==================
src/mon/Paxos.cc
dout(1) << "is_readable now=" << ceph_clock_now(g_ceph_context) << " lease_expire=" << lease_expire
<< " has v" << v << " lc " << last_committed << dendl;
==================

Incrementing 'log level' of this message to 2 or something else will solve this problem of mon space getting full quickly.

Moreover is this message that useful to get printed with default debug level '1'?
Let me know if I am missing something here.

Thanks,
Aanchal

________________________________

PLEASE NOTE: The information contained in this electronic mail message is intended only for the use of the designated recipient(s) named above. If the reader of this message is not the intended recipient, you are hereby notified that you have received this message in error and that any review, dissemination, distribution, or copying of this message is strictly prohibited. If you have received this communication in error, please notify the sender by telephone or e-mail (as shown above) immediately and destroy any and all copies of this message in your possession (whether hard copies or electronically stored copies).

--
To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Aanchal Agrawal]

Any help on this ...

-----Original Message-----
From: Aanchal Agrawal
Sent: Friday, September 05, 2014 5:56 PM
To: ceph-***@vger.kernel.org
Subject: Mon gets flooded with log messages for default log level

Hi,

With reference to commit f7d1902ccf9d5bb97cda626d718c3bb02f991a6d, 'Paxos' default level has been increased to 1.
This cause mon to get flooded with the following message, thus causes OS Drive(160GB) to get filled in 4-5 hours.

Log Snippet ::
==================
2014-09-01 16:35:11.527734 7f7efe706700 1 mon.rack6-ramp-***@0(leader).paxos(paxos active c 1..712) is_readable now=2014-09-01 16:35:11.527735 lease_expire=2014-09-01 16:35:13.637940 has v0 lc 712
2014-09-01 16:35:11.527773 7f7efe706700 1 mon.rack6-ramp-***@0(leader).paxos(paxos active c 1..712) is_readable now=2014-09-01 16:35:11.527774 lease_expire=2014-09-01 16:35:13.637940 has v0 lc 712
2014-09-01 16:35:11.527807 7f7efe706700 1 mon.rack6-ramp-***@0(leader).paxos(paxos active c 1..712) is_readable now=2014-09-01 16:35:11.527807 lease_expire=2014-09-01 16:35:13.637940 has v0 lc 712
2014-09-01 16:35:11.527840 7f7efe706700 1 mon.rack6-ramp-***@0(leader).paxos(paxos active c 1..712) is_readable now=2014-09-01 16:35:11.527840 lease_expire=2014-09-01 16:35:13.637940 has v0 lc 712
2014-09-01 16:35:11.527874 7f7efe706700 1 mon.rack6-ramp-***@0(leader).paxos(paxos active c 1..712) is_readable now=2014-09-01 16:35:11.527875 lease_expire=2014-09-01 16:35:13.637940 has v0 lc 712 ==================

==================
src/mon/Paxos.cc
dout(1) << "is_readable now=" << ceph_clock_now(g_ceph_context) << " lease_expire=" << lease_expire
<< " has v" << v << " lc " << last_committed << dendl; ==================

Incrementing 'log level' of this message to 2 or something else will solve this problem of mon space getting full quickly.

Moreover is this message that useful to get printed with default debug level '1'?
Let me know if I am missing something here.

Thanks,
Aanchal

________________________________

PLEASE NOTE: The information contained in this electronic mail message is intended only for the use of the designated recipient(s) named above. If the reader of this message is not the intended recipient, you are hereby notified that you have received this message in error and that any review, dissemination, distribution, or copying of this message is strictly prohibited. If you have received this communication in error, please notify the sender by telephone or e-mail (as shown above) immediately and destroy any and all copies of this message in your possession (whether hard copies or electronically stored copies).

--
To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Sage Weil]

Note that you can make these messages stop with

debug mon = 0

in your ceph.conf. It looks like you are right, though: that
is_readable() dout line is spamming things. We can fix that in the next
release.

https://github.com/ceph/ceph/pull/2421

Thanks!
sage

Post by Aanchal Agrawal
Any help on this ...
-----Original Message-----
From: Aanchal Agrawal
Sent: Friday, September 05, 2014 5:56 PM
Subject: Mon gets flooded with log messages for default log level
Hi,
With reference to commit f7d1902ccf9d5bb97cda626d718c3bb02f991a6d, 'Paxos' default level has been increased to 1.
This cause mon to get flooded with the following message, thus causes OS Drive(160GB) to get filled in 4-5 hours.
==================
==================
src/mon/Paxos.cc
dout(1) << "is_readable now=" << ceph_clock_now(g_ceph_context) << " lease_expire=" << lease_expire
<< " has v" << v << " lc " << last_committed << dendl; ==================
Incrementing 'log level' of this message to 2 or something else will solve this problem of mon space getting full quickly.
Moreover is this message that useful to get printed with default debug level '1'?
Let me know if I am missing something here.
Thanks,
Aanchal
________________________________
PLEASE NOTE: The information contained in this electronic mail message is intended only for the use of the designated recipient(s) named above. If the reader of this message is not the intended recipient, you are hereby notified that you have received this message in error and that any review, dissemination, distribution, or copying of this message is strictly prohibited. If you have received this communication in error, please notify the sender by telephone or e-mail (as shown above) immediately and destroy any and all copies of this message in your possession (whether hard copies or electronically stored copies).
--
To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
More majordomo info at http://vger.kernel.org/majordomo-info.html

--
To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Somnath Roy]

But, Sage, it is not happening all the time. For some reason, in some cases it is waiting for the maps to be readable. Could you please let us know why it can happen in some scenario ?
By not dumping this unusual scenario , will we be missing anything ?

Thanks & Regards
Somnath

-----Original Message-----
From: ceph-devel-***@vger.kernel.org [mailto:ceph-devel-***@vger.kernel.org] On Behalf Of Sage Weil
Sent: Monday, September 08, 2014 6:59 AM
To: Aanchal Agrawal
Cc: ceph-***@vger.kernel.org; Gregory Farnum; Joao Eduardo Luis
Subject: RE: Mon gets flooded with log messages for default log level

Note that you can make these messages stop with

debug mon = 0

in your ceph.conf. It looks like you are right, though: that
is_readable() dout line is spamming things. We can fix that in the next release.

https://github.com/ceph/ceph/pull/2421

Thanks!
sage

Post by Aanchal Agrawal
Any help on this ...
-----Original Message-----
From: Aanchal Agrawal
Sent: Friday, September 05, 2014 5:56 PM
Subject: Mon gets flooded with log messages for default log level
Hi,
With reference to commit f7d1902ccf9d5bb97cda626d718c3bb02f991a6d, 'Paxos' default level has been increased to 1.
This cause mon to get flooded with the following message, thus causes OS Drive(160GB) to get filled in 4-5 hours.
==================
2014-09-01 16:35:11.527734 7f7efe706700 1
now=2014-09-01 16:35:11.527735 lease_expire=2014-09-01 16:35:13.637940
has v0 lc 712
2014-09-01 16:35:11.527773 7f7efe706700 1
now=2014-09-01 16:35:11.527774 lease_expire=2014-09-01 16:35:13.637940
has v0 lc 712
2014-09-01 16:35:11.527807 7f7efe706700 1
now=2014-09-01 16:35:11.527807 lease_expire=2014-09-01 16:35:13.637940
has v0 lc 712
2014-09-01 16:35:11.527840 7f7efe706700 1
now=2014-09-01 16:35:11.527840 lease_expire=2014-09-01 16:35:13.637940
has v0 lc 712
2014-09-01 16:35:11.527874 7f7efe706700 1
now=2014-09-01 16:35:11.527875 lease_expire=2014-09-01 16:35:13.637940
has v0 lc 712 ==================
==================
src/mon/Paxos.cc
dout(1) << "is_readable now=" << ceph_clock_now(g_ceph_context) << " lease_expire=" << lease_expire
<< " has v" << v << " lc " << last_committed << dendl; ==================
Incrementing 'log level' of this message to 2 or something else will solve this problem of mon space getting full quickly.
Moreover is this message that useful to get printed with default debug level '1'?
Let me know if I am missing something here.
Thanks,
Aanchal
________________________________
PLEASE NOTE: The information contained in this electronic mail message is intended only for the use of the designated recipient(s) named above. If the reader of this message is not the intended recipient, you are hereby notified that you have received this message in error and that any review, dissemination, distribution, or copying of this message is strictly prohibited. If you have received this communication in error, please notify the sender by telephone or e-mail (as shown above) immediately and destroy any and all copies of this message in your possession (whether hard copies or electronically stored copies).
--
To unsubscribe from this list: send the line "unsubscribe ceph-devel"
info at http://vger.kernel.org/majordomo-info.html

--
To unsubscribe from this list: send the line "unsubscribe ceph-devel" in the body of a message to ***@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
--
To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Sage Weil]

Hi Somnath,

Post by Somnath Roy
But, Sage, it is not happening all the time. For some reason, in some
cases it is waiting for the maps to be readable. Could you please let us
know why it can happen in some scenario ? By not dumping this unusual
scenario , will we be missing anything ?

The is_readable method is called from a bunch of different contexts..
generally when a message is received or when a previously received
and queued message gets reexamined after an election or paxos round.

In either case, I think you're right that dout(1) is overkill; we've
changed it to 5. It is useful for debugging, but level 5 should be just
fine I think.

sage

Post by Somnath Roy
Thanks & Regards
Somnath
-----Original Message-----
Sent: Monday, September 08, 2014 6:59 AM
To: Aanchal Agrawal
Subject: RE: Mon gets flooded with log messages for default log level
Note that you can make these messages stop with
debug mon = 0
in your ceph.conf. It looks like you are right, though: that
is_readable() dout line is spamming things. We can fix that in the next release.
https://github.com/ceph/ceph/pull/2421
Thanks!
sage

Post by Aanchal Agrawal
Any help on this ...
-----Original Message-----
From: Aanchal Agrawal
Sent: Friday, September 05, 2014 5:56 PM
Subject: Mon gets flooded with log messages for default log level
Hi,
With reference to commit f7d1902ccf9d5bb97cda626d718c3bb02f991a6d, 'Paxos' default level has been increased to 1.
This cause mon to get flooded with the following message, thus causes OS Drive(160GB) to get filled in 4-5 hours.
==================
2014-09-01 16:35:11.527734 7f7efe706700 1
now=2014-09-01 16:35:11.527735 lease_expire=2014-09-01 16:35:13.637940
has v0 lc 712
2014-09-01 16:35:11.527773 7f7efe706700 1
now=2014-09-01 16:35:11.527774 lease_expire=2014-09-01 16:35:13.637940
has v0 lc 712
2014-09-01 16:35:11.527807 7f7efe706700 1
now=2014-09-01 16:35:11.527807 lease_expire=2014-09-01 16:35:13.637940
has v0 lc 712
2014-09-01 16:35:11.527840 7f7efe706700 1
now=2014-09-01 16:35:11.527840 lease_expire=2014-09-01 16:35:13.637940
has v0 lc 712
2014-09-01 16:35:11.527874 7f7efe706700 1
now=2014-09-01 16:35:11.527875 lease_expire=2014-09-01 16:35:13.637940
has v0 lc 712 ==================
==================
src/mon/Paxos.cc
dout(1) << "is_readable now=" << ceph_clock_now(g_ceph_context) << " lease_expire=" << lease_expire
<< " has v" << v << " lc " << last_committed << dendl; ==================
Incrementing 'log level' of this message to 2 or something else will solve this problem of mon space getting full quickly.
Moreover is this message that useful to get printed with default debug level '1'?
Let me know if I am missing something here.
Thanks,
Aanchal
________________________________
PLEASE NOTE: The information contained in this electronic mail message is intended only for the use of the designated recipient(s) named above. If the reader of this message is not the intended recipient, you are hereby notified that you have received this message in error and that any review, dissemination, distribution, or copying of this message is strictly prohibited. If you have received this communication in error, please notify the sender by telephone or e-mail (as shown above) immediately and destroy any and all copies of this message in your possession (whether hard copies or electronically stored copies).
--
To unsubscribe from this list: send the line "unsubscribe ceph-devel"
info at http://vger.kernel.org/majordomo-info.html

--
--
To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
More majordomo info at http://vger.kernel.org/majordomo-info.html

--
To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html