[QPID-2938] Logging excessive warnings in Timer code affects performance.

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 0.6
• Fix Version/s: 0.10
• Component/s: C++ Broker
• Assignee: Alan Conway
• Reporter: Alan Conway
• Created: 10/Nov/10 18:39
• Updated: 29/Jul/13 18:52
• Resolved: 17/Nov/10 19:16

Description

The Timer code logs a warning if a timer callback is started late or overruns the start time for the next callback.

In cases where there are a lot of these warnings, the time taken to do the logging itself severly worsens the situation. You can provoke such a warnings storm by starting a broker in a cluster and running:

qpid-cpp-benchmark -q4 --send-arg --ttl=10000

The log shows timer events that are increaesingly late and overrun by up to 30 seconds, and the test is very slow to complete, I gave up after 2 minutes when the lateness was up to 90 seconds.

This warning storm has also been seen with out clustering but with a store, see https://bugzilla.redhat.com/show_bug.cgi?id=629756