STORM-2384 Add log statements when spout skips calling nextTuple.

[aandis]

STORM-2384

[HeartSaVioR]

Looks good, but we need to throttle log flooding. Maybe one line per 1 sec or less?

[HeartSaVioR]

Other approach is lowering log level to debug and let users change the log level on the fly.

[aandis]

@HeartSaVioR changed log level to debug.

[srdo]

By default this will get logged once per millisecond if the spout is throttled. That might be a bit much IMO.

This is just me nitpicking, but I think it would be nicer if the log was moved to https://github.com/apache/storm/blob/master/storm-core/src/jvm/org/apache/storm/spout/SleepSpoutWaitStrategy.java. It's being called three lines above where the logs are inserted, and it knows about the empty emit streak. It's also something users can make their own implementations for, so if we log on e.g. every 1000 skipped nextTuple calls and a user needs it logged on every 5000 (or periodically), they can easily change it.

[HeartSaVioR]

@srdo
Yes agreed that it will still lots of log messages there... Need to throttle even with debug level.
Btw, adding log message to ISpoutWaitStrategy doesn't help for resolving STORM-2384 since it doesn't know why there's empty emit. It's even called when nextTuple doesn't emit normally.

@aandis Could you implement throttling log message with removing duplicated log messages for given period (say N secs)?

[srdo]

@HeartSaVioR That makes sense.

[aandis]

@HeartSaVioR does Log4j support that? I couldn't find anything on the topic. I think I'll need to write a custom class which stores the last logged message and logs new message immediately if it's not a duplicate and log them N seconds apart otherwise.

[HeartSaVioR]

@aandis Yes I meant custom utility class. :) I wrote one previously (not having it) and it was small enough so it would be easy to write one.