Error, Restart and Log subroutines

13/05/2024

Understanding the intricate mechanisms behind Error, Restart, and Log subroutines is crucial for mastering VCL. This article delves into these essential elements, clarifying their roles, interactions, and practical applications. While Restart isn't a subroutine in the conventional sense, it plays a pivotal role in the overall process. We'll explore where each component fits within the VCL workflow, what they are designed to accomplish, and how they interact with each other and the broader system.

We’re exploring the Error, Restart, and Log subroutines, but a heads-up: Restart isn’t technically a subroutine in the usual sense.

For our learning objectives, let’s focus on understanding these elements:

Where they fit into the overall process
What they’re supposed to do
How they interact with each other and other parts of the system.

VCL_error

How requests come in VCL_error ?

As you can see from the diagram, we can call vcl_error from almost everywhere, except for the deliver and log processes.You can spot this on the diagram by looking for the red arrows.

How requests come out of VCL_error ?

The default exit for vcl_erorr is return(deliver), or it can also be return(deliver_stale) if there’s stale content. And restart to return back to recv

VCL_error use cases

Here’s some uses cases for VCL_error :

Synthetic responses

A synthetic response is one that Varnish can generate without needing to connect to your origin server. For example, it can create error responses like 404, 500, or redirects like 301. Typically, with synthetic responses, we create a custom HTML page that gets stored in our VCL file.

Here’s an example, in vcl_recv I trigger an error 600 if req.url.path == "/anything/404"

sub vcl_recv {
  #FASTLY recv

  if(req.url.path == "/anything/404"){
    error 600;
  }


  return(lookup);
}

🔍 Maybe you are wondering where this 600 code comes from…

The status codes used for Error handling in Fastly typically fall into specific ranges. Fastly reserves the 800 range for internal codes, which is why the pre-built « Force TLS Error » uses code 801. Developers should use codes in the 600 to 700 range when triggering Error from other subroutines.

Then we end up in the error subroutine, where I can build my synthetic response :

sub vcl_error {
  #FASTLY error

  if(obj.status == 600){
    set obj.status = 404; 
    set obj.http.Content-Type = "text/html";
    synthetic {"
    <html>
        <head>
            <meta charset="UTF-8">
        </head>

        <body>
                <h1>Not Found 🤷‍♂️ </h1>
        </body>
    </html>
    "};
  }

  return(deliver);
}

VCL_error recap :

Error responses go directly to the delivery stage, skipping any caching processes.

Restart

Firstly Restart is not a subroutine, it’s not on list. Restart it’s its own transition call

How restart works :

• Restart goes back to the start of vcl_recv.
• Restart goes back to the Delivery Node.
• Limited to THREE restarts per POP.
• Restart disables : Clustering and Shielding
• Benefits of Disabling Clustering and Shielding.

Restart goes back to the Delivery Node

As you can see here, when a restart occurs, we go back to the delivery node :

Limited to THREE restarts per POP

With shielding ON you can restart up to 6 time, 3 time on one edge pop and 3 time on the shielding one.

Clustering and shielding with restart

We get a request, it hits one ofour Edge POPs, it gets assigned to a Delivery Node, Delivery Node goes through a
whole process of finding the Fetch Node on the Edge POP, Edge POP doesn’thave it, goes to the Shield POP, rinse and repeat for Delivery and Fetch.

Step 1

So our Fetch Node on the Shield POP makes the request, the origin gets back a 5xx error,either a 500 or a 503. (We are then a step one (1) in the diagram)

Step 2

You can see that logic there in vcl_fetch. We see the 5xx, and the Fetch Nodes says, « Ah, we got to restart. » So now it’s headed back to theDelivery Node on the Shield POP.

The Delivery Node then runs through VCL and makes its own attempt to reach the origin so it’s a fallback. We get the same 5xx error, and the Delivery Node goes, « All right. Well, I can’t restart anymore. »

Step 3

It passes it back to the Edge POP, the Fetch Node runs vcl_fetch on the response, sees again the 503 that was handed back, restarts, Delivery Node now attempts to make its own connection and gets back the last 503 or 500 error. You then, if there’s any logic to rewrite it or anything else, clean it up with a synthetic response, you hand off the eventual response to the end user

NB : in this step (3) the delivery nod eon the edge pop goes directly to the origin because we now already that the path though the shield node already failed.

Use cases for Restart

Retry an unsuccessful request to the same or an alternative
Perform authentication at the edge. See https://www.fastly.com/blog/patterns-for-authentication-at-the-edge
Follow redirects when the origin returns a 301/302.
Ignore a previously cached object and go to the origin even for a hit, without purging the object.

VCL_log

« `vcl_log« is a function used to log messages for debugging, monitoring, or auditing purposes. It allows Varnish administrators and developers to track the behavior of the Cache by recording specific events, actions, or errors.

vcl_log is a function used in Varnish Cache’s configuration language (VCL) to log messages for debugging, monitoring, or auditing purposes. It allows Varnish administrators and developers to track the behavior of Varnish Cache by recording specific events, actions, or errors.

Here are some situations where vcl_log can be useful:

Debugging: When troubleshooting issues with Varnish Cache, vcl_log can be used to output relevant information to the log files. This can help in diagnosing problems such as cache misses, backend connection issues, or incorrect VCL configurations.
Monitoring: By strategically placing vcl_log statements in the VCL code, administrators can monitor the flow of requests through Varnish Cache. This can provide insights into traffic patterns, request handling times, and cache hit rates, aiding in performance optimization and capacity planning.
Auditing: vcl_log can also be used to log specific events or actions for auditing purposes. For example, logging requests that match certain criteria, recording cache invalidations, or tracking user sessions can help maintain accountability and ensure compliance with security or regulatory requirements.
Custom Logging: VCL allows for flexible customization of logging based on specific requirements. With vcl_log, administrators can define their own log formats and selectively log relevant information, tailoring the logging behavior to suit the needs of their infrastructure and applications.

How requests come in VCL_log ?

The transition call from deliver into log is return(deliver)

How requests come out of VCL_log ?

The transition call to end vcl_log is also return(deliver)

Conclusion

Okay, let’s go over what we’ve learned. First, Error lets us use fake responses on the Edge POPs. When we Restart, it sends the request back to Recv on the Delivery Node and turns off Clustering and Shielding. Each POP can only Restart three times (three on the Edge, three on the Shield). Finally, Log runs at the end, so you can set up and gather logging information.

Error, Restart and Log subroutines / Varnish Configuration Language ( VCL )