Deprecated: Function get_magic_quotes_gpc() is deprecated in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 99

Deprecated: The each() function is deprecated. This message will be suppressed on further calls in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 619

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1169

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176

Warning: Cannot modify header information - headers already sent by (output started at /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php:99) in /hermes/walnacweb04/walnacweb04ab/b2791/pow.jasaeld/htdocs/De1337/nothing/index.php on line 1176
8000 pipeline logging: add cause chain when logging by yaauie · Pull Request #16677 · elastic/logstash · GitHub
Nothing Special   »   [go: up one dir, main page]

Skip to content

Conversation

yaauie
Copy link
Member
@yaauie yaauie commented Nov 14, 2024

Release notes

  • Improves logging while handling exceptions in the pipeline, ensuring that chained exceptions propagate enough information to be actionable.

What does this PR do?

Adds a helper to normalize an exception and its cause chain for logging, and uses that helper to add context whenever logging an exception from the pipeline implementation

Why is it important/What is the impact to the user?

Often an exception is caught and a wrapper of that exception is re-thrown; logging only the outermost exception can make it difficult to chase down the root cause.

Checklist

  • My code follows the style guidelines of this project
  • I have commented my code, particularly in hard-to-understand areas
  • [ ] I have made corresponding changes to the documentation
  • [ ] I have made corresponding change to the default configuration files (and/or docker env variab 8000 les)
  • [ ] I have added tests that prove my fix is effective or that my feature works

Logs

Before:

Log entries context contains:

  • error: a string with the exception's message
  • exception: a string with the exception's class
  • stacktrace: a string with the exception's newline-concatenated backtrace
[2024-11-14T19:05:47,364][ERROR][logstash.javapipeline    ][ocp4-logs-app] Pipeline worker error, the pipeline will be stopped {:pipeline_id=>"ocp4-logs-app", :exception=>"Java::OrgLogstashAckedqueue::QueueRuntimeException", :error=>"deserialize invocation error", :stacktrace=>"org.logstash.ackedqueue.Queue.deserialize(Queue.java:753)\norg.logstash.ackedqueue.Batch.deserializeElements(Batch.java:89)\norg.logstash.ackedqueue.Batch.<init>(Batch.java:49)\norg.logstash.ackedqueue.Queue.readPageBatch(Queue.java:681)\norg.logstash.ackedqueue.Queue.readBatch(Queue.java:614)\norg.logstash.ackedqueue.ext.JRubyAckedQueueExt.readBatch(JRubyAckedQueueExt.java:158)\norg.logstash.ackedqueue.AckedReadBatch.create(AckedReadBatch.java:49)\norg.logstash.ext.JrubyAckedReadClientExt.readBatch(JrubyAckedReadClientExt.java:87)\norg.logstash.execution.WorkerLoop.run(WorkerLoop.java:82)\njava.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\njava.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)\njava.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\njava.base/java.lang.reflect.Method.invoke(Method.java:569)\norg.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:300)\norg.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:164)\norg.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:32)\norg.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:193)\norg.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:346)\norg.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:66)\norg.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:118)\norg.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:136)\norg.jruby.runtime.IRBlockBody.call(IRBlockBody.java:66)\norg.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58)\norg.jruby.runtime.Block.call(Block.java:144)\norg.jruby.RubyProc.call(RubyProc.java:354)\norg.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:111)\njava.base/java.lang.Thread.run(Thread.java:840)", :thread=>"#<Thread:0x46da0cfb /Users/rye/src/elastic/logstash@main/logstash-core/lib/logstash/java_pipeline.rb:138 sleep>"}

After:

Log entries context contains:

  • error: a string with the exception's message
  • exception: a string with the exception's class
  • stacktrace: a string with the exception's newline-concatenated backtrace
  • cause (optional): a hash containing the exception's cause in the same format:
    • error: a string with the cause's message
    • exception: a string with the cause class
    • stacktrace: a string with the cause newline-concatenated backtrace
    • cause (optional): a hash containing the cause's cause in the same format
      • [...]
[2024-11-14T19:05:47,364][ERROR][logstash.javapipeline    ][ocp4-logs-app] Pipeline worker error, the pipeline will be stopped {:pipeline_id=>"ocp4-logs-app", :exception=>"Java::OrgLogstashAckedqueue::QueueRuntimeException", :error=>"deserialize invocation error", :stacktrace=>"org.logstash.ackedqueue.Queue.deserialize(Queue.java:753)\norg.logstash.ackedqueue.Batch.deserializeElements(Batch.java:89)\norg.logstash.ackedqueue.Batch.<init>(Batch.java:49)\norg.logstash.ackedqueue.Queue.readPageBatch(Queue.java:681)\norg.logstash.ackedqueue.Queue.readBatch(Queue.java:614)\norg.logstash.ackedqueue.ext.JRubyAckedQueueExt.readBatch(JRubyAckedQueueExt.java:158)\norg.logstash.ackedqueue.AckedReadBatch.create(AckedReadBatch.java:49)\norg.logstash.ext.JrubyAckedReadClientExt.readBatch(JrubyAckedReadClientExt.java:87)\norg.logstash.execution.WorkerLoop.run(WorkerLoop.java:82)\njava.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\njava.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)\njava.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\njava.base/java.lang.reflect.Method.invoke(Method.java:569)\norg.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:300)\norg.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:164)\norg.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:32)\norg.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:193)\norg.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:346)\norg.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:66)\norg.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:118)\norg.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:136)\norg.jruby.runtime.IRBlockBody.call(IRBlockBody.java:66)\norg.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58)\norg.jruby.runtime.Block.call(Block.java:144)\norg.jruby.RubyProc.call(RubyProc.java:354)\norg.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:111)\njava.base/java.lang.Thread.run(Thread.java:840)", :cause=>{:exception=>"Java::JavaLang::IllegalAccessException", :error=>"fake", :stacktrace=>"org.logstash.ackedqueue.Queue.deserialize(Queue.java:750)\norg.logstash.ackedqueue.Batch.deserializeElements(Batch.java:89)\norg.logstash.ackedqueue.Batch.<init>(Batch.java:49)\norg.logstash.ackedqueue.Queue.readPageBatch(Queue.java:681)\norg.logstash.ackedqueue.Queue.readBatch(Queue.java:614)\norg.logstash.ackedqueue.ext.JRubyAckedQueueExt.readBatch(JRubyAckedQueueExt.java:158)\norg.logstash.ackedqueue.AckedReadBatch.create(AckedReadBatch.java:49)\norg.logstash.ext.JrubyAckedReadClientExt.readBatch(JrubyAckedReadClientExt.java:87)\norg.logstash.execution.WorkerLoop.run(WorkerLoop.java:82)\njava.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\njava.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)\njava.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\njava.base/java.lang.reflect.Method.invoke(Method.java:569)\norg.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:300)\norg.jruby.javasupport.JavaMethod.invokeDirect(JavaMethod.java:164)\norg.jruby.java.invokers.InstanceMethodInvoker.call(InstanceMethodInvoker.java:32)\norg.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:193)\norg.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:346)\norg.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:66)\norg.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:118)\norg.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:136)\norg.jruby.runtime.IRBlockBody.call(IRBlockBody.java:66)\norg.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58)\norg.jruby.runtime.Block.call(Block.java:144)\norg.jruby.RubyProc.call(RubyProc.java:354)\norg.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:111)\njava.base/java.lang.Thread.run(Thread.java:840)"}, :thread=>"#<Thread:0x46da0cfb /Users/rye/src/elastic/logstash@main/logstash-core/lib/logstash/java_pipeline.rb:138 sleep>"}

@yaauie yaauie requested a review from jsvd November 14, 2024 19:27
Copy link

Quality Gate passed Quality Gate passed

Issues
0 New issues
0 Fixed issues
0 Accepted issues

Measures
0 Security Hotspots
No data about Coverage
No data about Duplication

See analysis details on SonarQube

@elasticmachine
Copy link
Collaborator

💚 Build Succeeded

Copy link
Member
@jsvd jsvd left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

much much better for the users, yay.
overall I'd like to have a couple of tests ensuring unwind_cause_chain (and more specifically cause_chain) behaves correctly on "edge" cases (e.g. 1 exception without cause, active_exception is nil, etc).
This aside, LGTM

@yaauie
Copy link
Member Author
yaauie commented Nov 19, 2024
8000

I'll backfill some tests onto this.

Copy link
Contributor
mergify bot commented Mar 5, 2025

This pull request does not have a backport label. Could you fix it @yaauie? 🙏
To fixup this pull request, you need to add the backport labels for the needed
branches, such as:

  • backport-8./d is the label to automatically backport to the 8./d branch. /d is the digit.
  • backport-8.x is the label to automatically backport to the 8.x branch.

Copy link
Contributor
mergify bot commented Mar 5, 2025

backport-8.x has been added to help with the transition to the new branch 8.x.
If you don't need it please use backport-skip label.

@mergify mergify bot added the backport-8.x Automated backport to the 8.x branch with mergify label Mar 5, 2025
@jsvd jsvd added backport-9.0 Automated backport to the 9.0 branch with mergify backport-8.19 Automated backport to the 8.19 branch backport-9.1 Automated backport to the 9.1 branch and removed backport-8.x Automated backport to the 8.x branch with mergify labels Aug 8, 2025
@jsvd jsvd merged commit 9b9790c into elastic:main Aug 8, 2025
7 checks passed
mergify bot pushed a commit that referenced this pull request Aug 8, 2025
Often an exception is caught and a wrapper of that exception is re-thrown; logging only the outermost exception can make it difficult to chase down the root cause.

This commit adds a helper to normalize an exception and its cause chain for logging, and uses that helper to add context whenever logging an exception from the pipeline implementation

(cherry picked from commit 9b9790c)
mergify bot pushed a commit that referenced this pull request Aug 8, 2025
Often an exception is caught and a wrapper of that exception is re-thrown; logging only the outermost exception can make it difficult to chase down the root cause.

This commit adds a helper to normalize an exception and its cause chain for logging, and uses that helper to add context whenever logging an exception from the pipeline implementation

(cherry picked from commit 9b9790c)
mergify bot pushed a commit that referenced this pull request Aug 8, 2025
Often an exception is caught and a wrapper of that exception is re-thrown; logging only the outermost exception can make it difficult to chase down the root cause.

This commit adds a helper to normalize an exception and its cause chain for logging, and uses that helper to add context whenever logging an exception from the pipeline implementation

(cherry picked from commit 9b9790c)
jsvd pushed a commit that referenced this pull request Aug 8, 2025
Often an exception is caught and a wrapper of that exception is re-thrown; logging only the outermost exception can make it difficult to chase down the root cause.

This commit adds a helper to normalize an exception and its cause chain for logging, and uses that helper to add context whenever logging an exception from the pipeline implementation

(cherry picked from commit 9b9790c)

Co-authored-by: Rye Biesemeyer <yaauie@users.noreply.github.com>
jsvd pushed a commit that referenced this pull request Aug 8, 2025
Often an exception is caught and a wrapper of that exception is re-thrown; logging only the outermost exception can make it difficult to chase down the root cause.

This commit adds a helper to normalize an exception and its cause chain for logging, and uses that helper to add context whenever logging an exception from the pipeline implementation

(cherry picked from commit 9b9790c)

Co-authored-by: Rye Biesemeyer <yaauie@users.noreply.github.com>
jsvd pushed a commit that referenced this pull request Aug 8, 2025
Often an exception is caught and a wrapper of that exception is re-thrown; logging only the outermost exception can make it difficult to chase down the root cause.

This commit adds a helper to normalize an exception and its cause chain for logging, and uses that helper to add context whenever logging an exception from the pipeline implementation

(cherry picked from commit 9b9790c)

Co-authored-by: Rye Biesemeyer <yaauie@users.noreply.github.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

backport-8.19 Automated backport to the 8.19 branch backport-9.0 Automated backport to the 9.0 branch with mergify backport-9.1 Automated backport to the 9.1 branch

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

0