diff --git a/LICENSE b/LICENSE new file mode 100644 index 0000000..7a77415 --- /dev/null +++ b/LICENSE @@ -0,0 +1,176 @@ +Apache License +Version 2.0, January 2004 +http://www.apache.org/licenses/ + +TERMS AND CONDITIONS FOR USE, REPRODUCTION, AND DISTRIBUTION + +1. Definitions. + +"License" shall mean the terms and conditions for use, reproduction, +and distribution as defined by Sections 1 through 9 of this document. + +"Licensor" shall mean the copyright owner or entity authorized by +the copyright owner that is granting the License. + +"Legal Entity" shall mean the union of the acting entity and all +other entities that control, are controlled by, or are under common +control with that entity. For the purposes of this definition, +"control" means (i) the power, direct or indirect, to cause the +direction or management of such entity, whether by contract or +otherwise, or (ii) ownership of fifty percent (50%) or more of the +outstanding shares, or (iii) beneficial ownership of such entity. + +"You" (or "Your") shall mean an individual or Legal Entity +exercising permissions granted by this License. + +"Source" form shall mean the preferred form for making modifications, +including but not limited to software source code, documentation +source, and configuration files. + +"Object" form shall mean any form resulting from mechanical +transformation or translation of a Source form, including but +not limited to compiled object code, generated documentation, +and conversions to other media types. + +"Work" shall mean the work of authorship, whether in Source or +Object form, made available under the License, as indicated by a +copyright notice that is included in or attached to the work +(an example is provided in the Appendix below). + +"Derivative Works" shall mean any work, whether in Source or Object +form, that is based on (or derived from) the Work and for which the +editorial revisions, annotations, elaborations, or other modifications +represent, as a whole, an original work of authorship. For the purposes +of this License, Derivative Works shall not include works that remain +separable from, or merely link (or bind by name) to the interfaces of, +the Work and Derivative Works thereof. + +"Contribution" shall mean any work of authorship, including +the original version of the Work and any modifications or additions +to that Work or Derivative Works thereof, that is intentionally +submitted to Licensor for inclusion in the Work by the copyright owner +or by an individual or Legal Entity authorized to submit on behalf of +the copyright owner. For the purposes of this definition, "submitted" +means any form of electronic, verbal, or written communication sent +to the Licensor or its representatives, including but not limited to +communication on electronic mailing lists, source code control systems, +and issue tracking systems that are managed by, or on behalf of, the +Licensor for the purpose of discussing and improving the Work, but +excluding communication that is conspicuously marked or otherwise +designated in writing by the copyright owner as "Not a Contribution." + +"Contributor" shall mean Licensor and any individual or Legal Entity +on behalf of whom a Contribution has been received by Licensor and +subsequently incorporated within the Work. + +2. Grant of Copyright License. Subject to the terms and conditions of +this License, each Contributor hereby grants to You a perpetual, +worldwide, non-exclusive, no-charge, royalty-free, irrevocable +copyright license to reproduce, prepare Derivative Works of, +publicly display, publicly perform, sublicense, and distribute the +Work and such Derivative Works in Source or Object form. + +3. Grant of Patent License. Subject to the terms and conditions of +this License, each Contributor hereby grants to You a perpetual, +worldwide, non-exclusive, no-charge, royalty-free, irrevocable +(except as stated in this section) patent license to make, have made, +use, offer to sell, sell, import, and otherwise transfer the Work, +where such license applies only to those patent claims licensable +by such Contributor that are necessarily infringed by their +Contribution(s) alone or by combination of their Contribution(s) +with the Work to which such Contribution(s) was submitted. If You +institute patent litigation against any entity (including a +cross-claim or counterclaim in a lawsuit) alleging that the Work +or a Contribution incorporated within the Work constitutes direct +or contributory patent infringement, then any patent licenses +granted to You under this License for that Work shall terminate +as of the date such litigation is filed. + +4. Redistribution. You may reproduce and distribute copies of the +Work or Derivative Works thereof in any medium, with or without +modifications, and in Source or Object form, provided that You +meet the following conditions: + +(a) You must give any other recipients of the Work or +Derivative Works a copy of this License; and + +(b) You must cause any modified files to carry prominent notices +stating that You changed the files; and + +(c) You must retain, in the Source form of any Derivative Works +that You distribute, all copyright, patent, trademark, and +attribution notices from the Source form of the Work, +excluding those notices that do not pertain to any part of +the Derivative Works; and + +(d) If the Work includes a "NOTICE" text file as part of its +distribution, then any Derivative Works that You distribute must +include a readable copy of the attribution notices contained +within such NOTICE file, excluding those notices that do not +pertain to any part of the Derivative Works, in at least one +of the following places: within a NOTICE text file distributed +as part of the Derivative Works; within the Source form or +documentation, if provided along with the Derivative Works; or, +within a display generated by the Derivative Works, if and +wherever such third-party notices normally appear. The contents +of the NOTICE file are for informational purposes only and +do not modify the License. You may add Your own attribution +notices within Derivative Works that You distribute, alongside +or as an addendum to the NOTICE text from the Work, provided +that such additional attribution notices cannot be construed +as modifying the License. + +You may add Your own copyright statement to Your modifications and +may provide additional or different license terms and conditions +for use, reproduction, or distribution of Your modifications, or +for any such Derivative Works as a whole, provided Your use, +reproduction, and distribution of the Work otherwise complies with +the conditions stated in this License. + +5. Submission of Contributions. Unless You explicitly state otherwise, +any Contribution intentionally submitted for inclusion in the Work +by You to the Licensor shall be under the terms and conditions of +this License, without any additional terms or conditions. +Notwithstanding the above, nothing herein shall supersede or modify +the terms of any separate license agreement you may have executed +with Licensor regarding such Contributions. + +6. Trademarks. This License does not grant permission to use the trade +names, trademarks, service marks, or product names of the Licensor, +except as required for reasonable and customary use in describing the +origin of the Work and reproducing the content of the NOTICE file. + +7. Disclaimer of Warranty. Unless required by applicable law or +agreed to in writing, Licensor provides the Work (and each +Contributor provides its Contributions) on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or +implied, including, without limitation, any warranties or conditions +of TITLE, NON-INFRINGEMENT, MERCHANTABILITY, or FITNESS FOR A +PARTICULAR PURPOSE. You are solely responsible for determining the +appropriateness of using or redistributing the Work and assume any +risks associated with Your exercise of permissions under this License. + +8. Limitation of Liability. In no event and under no legal theory, +whether in tort (including negligence), contract, or otherwise, +unless required by applicable law (such as deliberate and grossly +negligent acts) or agreed to in writing, shall any Contributor be +liable to You for damages, including any direct, indirect, special, +incidental, or consequential damages of any character arising as a +result of this License or out of the use or inability to use the +Work (including but not limited to damages for loss of goodwill, +work stoppage, computer failure or malfunction, or any and all +other commercial damages or losses), even if such Contributor +has been advised of the possibility of such damages. + +9. Accepting Warranty or Additional Liability. While redistributing +the Work or Derivative Works thereof, You may choose to offer, +and charge a fee for, acceptance of support, warranty, indemnity, +or other liability obligations and/or rights consistent with this +License. However, in accepting such obligations, You may act only +on Your own behalf and on Your sole responsibility, not on behalf +of any other Contributor, and only if You agree to indemnify, +defend, and hold each Contributor harmless for any liability +incurred by, or claims asserted against, such Contributor by reason +of your accepting any such warranty or additional liability. + +END OF TERMS AND CONDITIONS diff --git a/README.md b/README.md index bb741ac..dbaee1d 100644 --- a/README.md +++ b/README.md @@ -1,9 +1,39 @@ -Run Jaeger... +# boshdebugtracer - docker run -d --name jaeger -e COLLECTOR_ZIPKIN_HTTP_PORT=9411 -p 5775:5775/udp -p 6831:6831/udp -p 6832:6832/udp -p 5778:5778 -p 16686:16686 -p 14268:14268 -p 9411:9411 jaegertracing/all-in-one:1.12 +To visualize what BOSH is busy doing during a task. -Pipe the task... +It's taking an after-the-fact approach at profiling by reading the debug logs and pretending it knows what BOSH was thinking while it happened. You probably shouldn't fully trust the accuracy of the results. - bosh task --debug 1234 | go run ./cmd/boshtaskdebugjaeger +alpha/experiment/buggy/use-at-your-own-risk + + +## Quick Start + +Run [Jaeger](https://www.jaegertracing.io/) (the tooling and UI) locally according to their [Getting started](https://www.jaegertracing.io/docs/1.12/getting-started/) guide... + + docker run -d --name jaeger \ + -e COLLECTOR_ZIPKIN_HTTP_PORT=9411 \ + -p 5775:5775/udp \ + -p 6831:6831/udp \ + -p 6832:6832/udp \ + -p 5778:5778 \ + -p 16686:16686 \ + -p 14268:14268 \ + -p 9411:9411 \ + jaegertracing/all-in-one:1.12 + +Pipe the deployment task... + + bosh task --debug 1234 | go run ./cmd/boshtaskdebugjaeger Open the URL it prints (something like http://localhost:16686/trace/1cfa67194cc4d8ef). + + +## Screenshot + +![Screenshot](docs/example.png) + + +# License + +[Apache License, Version 2.0](LICENSE) diff --git a/cmd/boshtaskdebugjaeger/main.go b/cmd/boshtaskdebugjaeger/main.go index 145019f..d55a594 100644 --- a/cmd/boshtaskdebugjaeger/main.go +++ b/cmd/boshtaskdebugjaeger/main.go @@ -16,7 +16,9 @@ func main() { ctx := &context.Context{} parsers := taskdebug.Parser - observer := jaeger.NewObserver(ctx) + observer := jaeger.NewObserver(ctx, jaeger.ObserverOptions{ + IncludeLogReferences: false, + }) observer.Begin() defer observer.Commit() @@ -32,8 +34,6 @@ func main() { } for _, p := range parsers { - // fmt.Printf("IN: %#+v\n", l) - // fmt.Printf("TO: %#+v\n", p) l, err = p.Parse(l) if err != nil { panic(err) diff --git a/docs/example.png b/docs/example.png new file mode 100644 index 0000000..0829023 Binary files /dev/null and b/docs/example.png differ diff --git a/log/taskdebug/jaeger/observer.go b/log/taskdebug/jaeger/observer.go index a76d7f7..06e5aa6 100644 --- a/log/taskdebug/jaeger/observer.go +++ b/log/taskdebug/jaeger/observer.go @@ -29,14 +29,21 @@ type Observer struct { lastMessage taskdebug.RawMessage emulatedStage string updatingInstanceGroups []string + + includeLogReferences bool +} + +type ObserverOptions struct { + IncludeLogReferences bool } var _ observer.Observer = &Observer{} -func NewObserver(ctx *context.Context) *Observer { +func NewObserver(ctx *context.Context, o ObserverOptions) *Observer { return &Observer{ - ctx: ctx, - tracers: map[string]tracer{}, + ctx: ctx, + tracers: map[string]tracer{}, + includeLogReferences: o.IncludeLogReferences, } } @@ -276,11 +283,8 @@ func (l *Observer) startPackageCompilation(msg taskdebug.RawMessage) error { opentracing.Tag{Key: "stemcell_os", Value: msg.Tags["stemcell_os"]}, opentracing.Tag{Key: "stemcell_version", Value: msg.Tags["stemcell_version"]}, ) - // sp.LogFields( - // opentracinglog.String("type", "start"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + + l.addSpanLogReference(sp, "start", msg) ctx := l.ctx.Open( context.Annotation{Key: "compilation.package", Value: msg.Tags["package"]}, @@ -399,11 +403,7 @@ func (l *Observer) startEmulatedStage(msg taskdebug.RawMessage, stage string) er opentracing.ChildOf(l.rootSpan.Context()), opentracing.StartTime(msg.LogTime), ) - // sp.LogFields( - // opentracinglog.String("type", "start"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "start", msg) ctx := l.ctx.Open(context.Annotation{Key: "emulated_stage", Value: stage}) ctx.Set("tracing.span", sp) @@ -423,11 +423,7 @@ func (l *Observer) endEmulatedStage(msg taskdebug.RawMessage) error { } sp := spU.(opentracing.Span) - // sp.LogFields( - // opentracinglog.String("type", "start"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "start", msg) sp.FinishWithOptions( opentracing.FinishOptions{FinishTime: msg.LogTime}, ) @@ -447,11 +443,7 @@ func (l *Observer) process(msg taskdebug.ProcessMessage) error { opentracing.Tag{Key: "director.instance.id", Value: msg.InstanceID}, opentracing.Tag{Key: "host.ip", Value: msg.IP}, ) - // sp.LogFields( - // opentracinglog.String("type", "start"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "start", msg) l.rootSpan = sp @@ -486,17 +478,9 @@ func (l *Observer) sequel(msg taskdebug.SequelMessage) error { opentracing.ChildOf(l.findParentSpan(l.getDefaultAnnotations(msg.RawMessage)...).Context()), opentracing.StartTime(msg.LogTime.Add(-1*msg.Duration)), ) - // sp.LogFields( - // opentracinglog.String("type", "start"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) - - // sp.LogFields( - // opentracinglog.String("type", "finish"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "start", msg) + + l.addSpanLogReference(sp, "finish", msg) sp.FinishWithOptions( opentracing.FinishOptions{FinishTime: msg.LogTime}, ) @@ -512,18 +496,10 @@ func (l *Observer) natsSentHM(msg taskdebug.NATSMessageMessage) error { opentracing.StartTime(msg.LogTime), opentracing.ChildOf(parentSpan.Context()), ) - // sp.LogFields( - // opentracinglog.String("type", "start"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "start", msg) // no response expected, so finish immediately - // sp.LogFields( - // opentracinglog.String("type", "finish"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "finish", msg) sp.FinishWithOptions( opentracing.FinishOptions{FinishTime: msg.LogTime}, ) @@ -561,11 +537,7 @@ func (l *Observer) natsSentAgent(msg taskdebug.NATSMessageSentAgentMessage) erro opentracing.StartTime(msg.LogTime), opentracing.ChildOf(parentSpan.Context()), ) - // sp.LogFields( - // opentracinglog.String("type", "start"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "start", msg) ctx.Set("tracing.span", sp) ctx.Set("nats.sent", msg) @@ -588,11 +560,7 @@ func (l *Observer) natsSentAgent(msg taskdebug.NATSMessageSentAgentMessage) erro opentracing.StartTime(msg.LogTime), opentracing.ChildOf(parentSpan.Context()), ) - // sp.LogFields( - // opentracinglog.String("type", "start"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "start", msg) ctx := l.ctx.Open( context.Annotation{Key: "agent.id", Value: strings.TrimPrefix(msg.Channel, "agent.")}, @@ -610,11 +578,7 @@ func (l *Observer) natsSentAgent(msg taskdebug.NATSMessageSentAgentMessage) erro opentracing.StartTime(msg.LogTime), opentracing.ChildOf(parentSpan.Context()), ) - // sp.LogFields( - // opentracinglog.String("type", "start"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "start", msg) ctx := l.ctx.Open(context.Annotation{Key: "nats.reply_to", Value: msg.PayloadReplyTo}) ctx.Set("tracing.span", sp) @@ -631,11 +595,7 @@ func (l *Observer) natsReceived(msg taskdebug.NATSMessageMessage) error { } sp := spU.(opentracing.Span) - // sp.LogFields( - // opentracinglog.String("type", "finish"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "finish", msg) sp.FinishWithOptions(opentracing.FinishOptions{FinishTime: msg.LogTime}) sentMsgU, ok := scope.Get("nats.sent") @@ -669,11 +629,7 @@ func (l *Observer) natsReceived(msg taskdebug.NATSMessageMessage) error { } sp := spU.(opentracing.Span) - // sp.LogFields( - // opentracinglog.String("type", "finish"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "finish", msg) sp.FinishWithOptions(opentracing.FinishOptions{FinishTime: msg.LogTime}) { // cheat and assume this is the last step of updating an instance @@ -706,11 +662,7 @@ func (l *Observer) externalCPIRequest(msg taskdebug.ExternalCPIRequestMessage) e opentracing.StartTime(msg.LogTime), opentracing.ChildOf(l.findParentSpan(l.getDefaultAnnotations(msg.RawMessage)...).Context()), ) - // sp.LogFields( - // opentracinglog.String("type", "start"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "start", msg) ctx := l.ctx.Open(context.Annotation{Key: "external_cpi.correlation", Value: msg.Correlation}) ctx.Set("tracing.span", sp) @@ -726,11 +678,7 @@ func (l *Observer) externalCPIResponse(msg taskdebug.ExternalCPIMessage) error { } sp := spU.(opentracing.Span) - // sp.LogFields( - // opentracinglog.String("type", "finish"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "finish", msg) sp.FinishWithOptions(opentracing.FinishOptions{FinishTime: msg.LogTime}) return nil @@ -742,11 +690,7 @@ func (l *Observer) cpiAWSRPC(msg taskdebug.CPIAWSRPCMessage) error { opentracing.StartTime(msg.LogTime.Add(-1*msg.Duration)), opentracing.ChildOf(l.findParentSpan(context.Annotations{{Key: "external_cpi.correlation", Value: msg.Correlation}}).Context()), ) - // sp.LogFields( - // opentracinglog.String("type", "finish"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "finish", msg) sp.FinishWithOptions(opentracing.FinishOptions{FinishTime: msg.LogTime}) return nil @@ -766,11 +710,7 @@ func (l *Observer) lock(msg taskdebug.LockMessage) error { opentracing.StartTime(msg.LogTime), opentracing.ChildOf(l.findParentSpan(l.getDefaultAnnotations(msg.RawMessage)...).Context()), ) - // sp.LogFields( - // opentracinglog.String("type", "start"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "start", msg) ctx := l.ctx.Open(context.Annotation{Key: "lock.name", Value: msg.Name}) ctx.Set("tracing.span", sp) @@ -783,11 +723,7 @@ func (l *Observer) lock(msg taskdebug.LockMessage) error { opentracing.StartTime(msg.LogTime), opentracing.ChildOf(l.findParentSpan(context.Annotations{{Key: "lock.name", Value: msg.Name}}).Context()), ) - // sp.LogFields( - // opentracinglog.String("type", "finish"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "finish", msg) sp.FinishWithOptions(opentracing.FinishOptions{FinishTime: msg.LogTime}) } else if msg.Event == "Deleted" { scope := l.ctx.Open(context.Annotation{Key: "lock.name", Value: msg.Name}) @@ -804,18 +740,10 @@ func (l *Observer) lock(msg taskdebug.LockMessage) error { opentracing.StartTime(msg.LogTime), opentracing.ChildOf(parentSpan.Context()), ) - // sp.LogFields( - // opentracinglog.String("type", "finish"), - // opentracinglog.Int64("line", msg.LineOffset()), - // opentracinglog.String("msg", msg.LineData()), - // ) + l.addSpanLogReference(sp, "finish", msg) sp.FinishWithOptions(opentracing.FinishOptions{FinishTime: msg.LogTime}) - parentSpan.LogFields( - opentracinglog.String("type", "finish"), - opentracinglog.Int64("line", msg.LineOffset()), - opentracinglog.String("msg", msg.LineData()), - ) + l.addSpanLogReference(parentSpan, "finish", msg) parentSpan.FinishWithOptions(opentracing.FinishOptions{FinishTime: msg.LogTime}) } else { panic(fmt.Sprintf("logical inconsistency: unexpected lock event: %s", msg.Event)) @@ -823,3 +751,15 @@ func (l *Observer) lock(msg taskdebug.LockMessage) error { return nil } + +func (l *Observer) addSpanLogReference(sp opentracing.Span, event string, msg log.Line) { + if !l.includeLogReferences { + return + } + + sp.LogFields( + opentracinglog.String("type", event), + opentracinglog.Int64("line", msg.LineOffset()), + opentracinglog.String("msg", msg.LineData()), + ) +}