Thursday, August 16, 2018

pipeline.debug - a GUI tool for runtime debugging Sitecore pipelines

TL;DR

pipeline.debug is a tool that lets you inject flexible debug processors to any pipeline during runtime.

You can read the documentation and download sourcecode at: https://github.com/alphasolutionsrepo/pipeline.debug


Adding a debug processor to the httpRequestBegin pipeline.




Background

Every once in a while, I encounter a bug that leaves me scratching my head: Sitecore doesn’t find an item which clearly exists, the language isn’t resolved correctly or dispatching an email campaign breaks down without any log messages etc.

The reasons of such errors can be multiple things: Custom code that interferes with Sitecore, Sitecore Modules interfering with each other, or API-usage bordering what is intended and tested by Sitecore.

Debugging such cases often ends up with having to reflect Sitecore code, followed by adding custom logging code to verify my suspicions or further pinpoint the reason for the behaviour.
This custom code comes in many forms, as Sitecore thankfully allows us to override code in multiple ways. Since the backbone of Sitecore is built on the pipeline architecture, this is one of the most common places to inject debugging functionality.
Creating such debug pipelines isn’t difficult, but in cases where errors only happen on production, it can require several deploy cycles to get to the bottom of an issue.

After one too many of such debugging sessions, I made a tool to inject debug processors during runtime. Every time I’ve had to use it, I tweaked it a bit. Now it’s reached a point where I feel it might be worth sharing with the Sitecore community.

Introducing pipeline.debug

pipeline.debug is a tool that lets you inject flexible debug processors to any pipeline during runtime. By reflection it’s possible to output any value from the pipeline arguments or the Sitecore.Context.

To ease the use of this, selecting debug variables is possible via discovery, which reflects and shows  available fields and properties under the args and context regardless of protection level.

Adding the name and value of the cookies in the request via discovery.


Furthermore, it allows for constraints on logging, such that not all requests to a given pipeline is necessarily logged. For instance, adding a debug processor to httpRequestBegin, will give you a lot of output on a production environment. To help mitigate this I’ve implemented filters for url, site, language and session.

The resulting debug output can be logged to either memory, file or both.

Example of the cookie output from the processor

As this is all done runtime, the processors will be cleared when the application recycles. Sometimes you want to be able to set it up easily again (or maybe you just want to set it up on multiple CD servers), so it’s possible to export and import the settings for easy reuse.

Documentation and distribution

The project is shared on github, which also holds the available documentation. Check it out here: https://github.com/alphasolutionsrepo/pipeline.debug

Alternatively you can install it via Nuget from this repository: https://www.myget.org/F/pipelinedebug/api/v2

Lastly it can be downloaded as an update package from the Sitecore Marketplace https://marketplace.sitecore.net/Modules/P/pipelinedebug.aspx

Examples of debugging

Being the resident bugsquasher, I've had plenty of occasions where debugging pipelines has been necessary. I will share a couple of such episodes, as inspiration as to when and why you would use a tool like pipeline.debug.

The virtual language

We had a danish webpage, where the about-us (om-os) and underlying pages always resulted in a 404 response - this wouldn't happen on development or test, only on production.

By adding a debugprocessor to the httpRequestBegin pipeline just before the ItemResolver, we could identify that the first part of the itempath "/om-os" had been removed. By further adding debugprocessors before and after the StripLanguage processor in the preprocessRequest pipeline, we identified that this indeed was the step that identified "om-os" as a language.

At this point we needed to add a custom debugging step to figure out exactly what was happening. It turns out that testing whether something is a valid language, is done by Sitecore through LanguageProviders GetCultureBuilder, which attempts creating a culture from a given name, and checks whether the name contains the string "unknown language". Since our production server was in danish localization, this string was not "unknown language" but a danish translation thereof, resulting in Sitecore believing that this part of the link was a language, on production only.

The failing payments

A webpage started experiencing customer feedback and log errors, that an order could not be created, after returning from payment. Returning from the payment provider triggered a pipeline to finalize the order. So we added debugprocessors here to verify what was happening.

We could identify that for all failed attempts, the order was first attempted to be finalized from a specific IP address. This was due to the payment provider adding a new payment option with a different flow, in which - if the customer completed the flow, but never clicked "return to homepage" -  the payment provider called the success url themselves. Since this was not a part of the customers session, the basket was not found and the finalization failed.