NIFI-1636: Print Stacktrace When Unexpected OnTrigger Exception Caught#285
NIFI-1636: Print Stacktrace When Unexpected OnTrigger Exception Caught#285rickysaltzer wants to merge 1 commit intoapache:masterfrom
Conversation
| session.commit(); | ||
| } catch (final Throwable t) { | ||
| getLogger().error("{} failed to process due to {}; rolling back session", new Object[]{this, t}); | ||
| StringWriter stacktraceWriter = new StringWriter(); |
There was a problem hiding this comment.
This logic needs to be in the logger and that is its intent. You will note that the throwable is being passed into it. The stack traces are getting logged when debug level is engaged for a given logger. This allows the user to control whether they are generated or not. That said...it is clearly counterintuitive and we need to improve.
There was a problem hiding this comment.
That makes sense @joewitt. Should legitimate unexpected exceptions be surfaced to INFO by default? I feel like these are uncommon enough to warrant it, but I could be wrong.
There was a problem hiding this comment.
I would say generally no. They are uncommon in general but when they happen they happen in bursts. As a general rule I think we should strive to make what the user sees be something a lot more friendly than a wild stack trace. But, the logs should have them. We did discuss this on dev list a while back and there were some great inputs from various folks. We def need to do something here.
There was a problem hiding this comment.
I wonder if it would make sense to surface the shorthand message to the user in the UI but log the stacktrace to the log file. I imagine this would take some re-working.
There was a problem hiding this comment.
that is actually the current behavior/intent. I think the change needed is to simply get rid of the 'if debug enabled' stuff we did in the logger and instead just always log the stacktrace when it is there. This is what Adam Taft had advocated for previously as I recall. I now see why he was saying it. So yeah in the UI it should be a short and ideally meaningful message (not always possible) and if a throwable shows up we should put the whole stack trace in the logs.
The current idea that a user will go in an do debug enabled....just has proven to be a failed experiment in my view and as someone who advocated for that I now think i was wrong.
There was a problem hiding this comment.
So if I understand correctly, this happens now but only in DEBUG mode. What we would like to see is that behavior but even if we're in INFO mode. That is, shortened version logged to the UI and the stacktrace logged to the log file?
There was a problem hiding this comment.
Right. So i think the short version is in the UI now. But you want the stacktrace too. We should make that available in the logs. And this class is what controls that I believe https://github.com/apache/nifi/blob/master/nifi-commons/nifi-logging-utils/src/main/java/org/apache/nifi/logging/NiFiLog.java You'll see it has some ifDebugEnabled guards. We should probably just toss those out. @markap14 what say you?
There was a problem hiding this comment.
Yep that would be the easiest way, and I can go ahead and throw this mess I added in above.
There was a problem hiding this comment.
I should clarify...i agree with you this is confusing and not quite doing what we want. We need to fix it. Can you share a screenshot of what you see for a given error in the UI vs what shows in the logs and then let's agree on what it should ideally be and then figure out how to get there :-)
There was a problem hiding this comment.
Sure thing, my battery just died so I will as soon as able. Thanks!
Logs the stacktrace to the default log file, and emits the shortened version for the UI.
|
@joewitt posted a new version of the patch. I tested it out on my local machine and it seems to work as expected. That is, the stacktrace is logged to the |
|
Ricky Could you please take a look at https://issues.apache.org/jira/browse/NIFI-1447 and see if it's what you are looking for? If I remember correctly we don't really want to log stack traces unless we're in DEBUG mode and that is what the above JIRA addresses. |
|
Also, you may want to amend the commit message "Unepected" unless its a new English word I haven't learned yet ;) |
rickysaltzer
changed the title
|
Thanks, @olegz! Thankfully that wasn't the commit message :). I took a look at NIFI-1447, and I believe this could be what I'm looking for. I understand the concern for overly verbose logging in the case of a FlowFile getting stuck in some sort of infinite loop. Regarding NIFI-1447, are uncaught stacktraces logged at |
|
They were logged at DEBUG only level and that was the issue since you would not be able to see them, but now if there is an error the stack trace will be printed |
|
@rickysaltzer where do you think we are with this one? I mean, do you think NIFI-1447 solved your issue or this PR is still valid? |
|
@rickysaltzer Was combing over PRs in rounding up items for 0.7.0. Curious if the effort highlighted by Oleg makes this particular PR OBE. Thanks! |
|
@rickysaltzer - is the PR still relevant? Would you mind if we close otherwise? |
|
@trixpan thanks for the reminder, closing... |
5 participants
No description provided.