Posts

Tideways 2024.3 Release

We strive to improve clarity and user-friendliness, and have thus focused our efforts on several features that align with this objective. Our new Sidebar Menu, the Release Tracking Feature and an increased comparison range for Releases and Markers as well as the possibility to show error messages in notifications all fall into this category.

Summary:

PHP 8.4 support from the start

PHP 8.4 will be released at the end of November 2024 and Tideways – as always – supports  it from the start with the PHP Extension Release 5.14.0.

The last versions of the PHP extension also added new instrumentations: DNS functions, password hashing and sending e-mails are now visible in the Timeline Profiler.

Turn navigation into an intuitive experience: Our new Sidebar Menu

We are convinced that the new Sidebar Menu improves usability and discoverability and makes the overall navigation experience more intuitive. With an increasing amount of primary features in Tideways, the top navigation no longer provided enough room to accommodate them anymore. A sidebar navigation proved to be the most effective approach to meet this challenge and enhance its user-friendliness.

There are new shortcuts in the sidebar navigation:

  • If you click on the Tideways logo or the organization, a popup will open, allowing you to swiftly navigate between all your organizations and projects.
  • From the footer navigation, you can access user and organization settings.
  • Main features such as Tracepoints, Incidents or Slow SQL queries are now available directly from the sidebar navigation.

In the line of improving our menu, it is now possible to jump directly to the relevant performance details of a trace via the widget “Go”.

We decided to switch to the new Sidebar Menu completely and activate it for everyone by default. You will be able to go back to the old sidebar navigation from the “User Settings” until the end of the year 2024; thereafter, only the new Sidebar Menu will be available.

Compare Aggregated Traces directly from Incident and Release Tracking

What was previously feasible at the monitoring level has now become feasible also at the profiling level.

Now, it is possible to identify the leading cause behind a change in performance, rather than simply observing that a change happened. 

Subsequently, it has become more convenient to compare performance data from two distinct time periods.

You can instruct Tideways to compute an aggregate of traces from before and after the comparison time and Tideways will immediately show you the differential flame graph that allows spotting the degraded calls such as SQL queries.

There are three possibilities to start into this performance comparison 

  1. Set/Add markers. To display performance before and after a selected date, you can set/add a named marker. This is useful to reference important events in the project lifecycle and allows a swift comparison between the before and after. A significant event could be, for instance, the start of an email marketing campaign.
  1. Use the Release Tracking Feature: Since markers do not support automated notifications, the Release Tracking Feature should be used to compare performance prior to and subsequent to releases. You can see a list of recent releases on the left side of the release tracking screen: 

Below the details, which show a before-and-after comparison, transactions for this timeframe are listed:

3. Response Time Incident: When a response time incident is triggered the Tideways UI now shows the most degraded and improved transactions in the timeframe before and after the start of the incident.

Increased Comparison Range for Releases and Markers

Comparing data sets from different time periods can be very revealing when you want to evaluate the performance of a website. By extending the time frame from a maximum of 90 minutes to a maximum of one day, a whole day’s worth of data can now be included in the comparison of release events or markers. Fluctuations can be factored out much better, and thus results are more meaningful. You get more insight into what has really changed.

Crawler Detection

Crawlers can be recognized in Tideways and are now displayed with the tag “crawler”. Using filters, only the traces that were triggered by crawlers can be shown.

The identification of crawlers works based on user agents. It is not enabled by default and can be enabled with php.ini configuration change: tideways.features.crawler_detection=1

Allow opt-in to show error messages in notifications

We’re pleased to announce that we’ve built this feature in response to quite a few customer requests and that it’s ready for use now. They asked us to make it easier for them to see exception messages directly in notifications, and we’re delighted to have done that for them.

Exception messages can be the key to determining the cause of an error easily. Since they could potentially contain private data, we initially decided against including them in notifications. 

However, as their importance can’t be underestimated, we now allow toggling to include error messages in email, Slack or Microsoft Teams notifications. The inclusion of error messages remains disabled by default due to privacy concerns.

Don’t get spooked by bad PHP performance. Try Tideways and get your remedy!

PHP 8.4 Property Hooks: Can we get rid of getters/setters now? A benchmark.

The upcoming PHP 8.4 release will include the brand-new feature “property hooks”, a mechanism to add logic to a class property when read from or written to. One benefit of this feature is that you do not need to protect property access with a private property and public getter/setter methods anymore.

You can find out how this feature works in the RFC and other places, but in the spirit of this blog we want to focus solely on the performance implications.

We would like to know if there is a noticeable effect on performance when we design applications from scratch with public properties backed by hooks and without getters/setters? 

Or, more drastically, is it a winning strategy to leave the getters/setters behind, never look back, maybe even rewrite our existing applications?

From a macro-perspective, the answer is no.

Looking at a call graph for our own Transaction settings list view, we see that even when rendering a large amount of 100 Doctrine entities, calls to their getters account for a minimal amount of time in the request, fractions of milliseconds.

Changing the code to use public properties and property hooks will not significantly alter the application performance.

Nevertheless, it’s interesting to dive into a benchmark of property hooks vs. getter/setters, to understand if both approaches have a similar performance. If they do, it is unnecessary to consider performance, when deciding between the two. And that reduces mental load.

Establishing Baseline: Public Property vs Getter/Setter

It’s a well-known fact that public property access is faster than going through a getter method to access a private property. We can set up a benchmark with hyperfine to calculate that difference to be roughly 60% slower for getters/setters with these code examples:

Public Properties are rarely used, despite their speed, due to the importance of other concerns:

  1. Information Hiding: Using getters/setters allows us to avoid exposing how the data is stored in the class.
  2. Changing a public property to a getter in the future requires numerous refactorings, or the use of magic __get methods, Both of these are unnecessary risks that can be avoided by using getter/setter methods from the start.

With property hooks, both concerns can be addressed by adding property hooks, when the access to the public property should be restricted in any way.

Comparing Public Property with Hook vs. Getter

So, let’s add a property hook example for reading and writing that resembles the logic of the getter and setter methods.

Both approaches are very close to each other with only a 9% performance difference.

So the result is clear: Performance should not be a concern when you decide to use either properties with hooks or getter/setter methods for accessing properties on classes. This is especially true because, as we saw at the beginning, property access usually accounts for only a small part of the total request time.

The case for benchmarking: Hook performance improvements during PHP 8.4 alpha

While it is important to know that both approaches have similar performance characteristics, micro-benchmarking new features vs. old alternatives serves another purpose. 

We wanted to write this blog post directly after property hooks were merged because from our experience we expected the conclusion to be that performance is not a concern.

But when we ran the numbers with an early PHP 8.4 alpha, we realized that property hooks were about 200% slower than getters. 

Turns out, the implementation of property hooks was not optimal, and we reported this behavior to the property hook feature authors Ilija and Larry. The fix required another amending RFC, but was approved by PHP RFC voters, leading us to the performance we have now during the PHP 8.4 release candidate phase.

An AI would never be able to dive this deep into technical topics surrounding PHP performance! Follow us on LinkedIn or X and subscribe to our newsletter to get the latest posts.

Let’s dive in and find out what is causing performance bottlenecks! Without Tideways, you’re likely to fish in murky waters attempting to figure it out. Try our free trial today and be enlightened.

Choosing a PHP Library based on Performance

Sometimes, performance is the primary requirement when you are picking a third-party library to solve a task in your application. 

For CPU intensive work, there are often similar alternatives that you can choose from:

  • Serialization with Serde, JMS Serializer or others
  • Crawler Detection with jaybizzle/crawler-detect or matomo/device-detector
  • Dates and Times with nesbot/carbon or cakephp/chronos

To find out which one of them is more performant for your use-case, you can set up an experiment with microtime/hr_time calls and run them against each other.

But: this provides fewer insights than running your tests directly with a Profiler such as XHProf or Tideways!

Comparing Performance of PHP Crawler Detection Libraries

For the use-case of crawler detection inside Shopware, I recently wondered which library to use when trying to detect if the current request is made by a crawler.

Naturally, you would say, let’s use PHPs native get_browser function. But there are also specialized libraries such as jaybizzle/crawler-detect or matomo/device-detector

Consulting their respective documentations, I came up with the following code snippet to test their speed:



use Jaybizzle\CrawlerDetect\CrawlerDetect;
use DeviceDetector\Parser\Bot AS BotParser;

require_once 'vendor/autoload.php';

$crawler = ['jaybizzle' => 0, 'device-detector' => 0, 'get_browser' => 0];

$bots = file(__DIR__ . '/bots.txt');
$bots = array_slice($bots, 0, $argv[1] ?? count($bots));

$crawlerDetect = new CrawlerDetect;
$botParser = new BotParser();

foreach ($bots as $bot) {
    $bot = trim($bot);

    if($crawlerDetect->isCrawler($bot)) {
        $crawler['jaybizzle']++;
    }

    $botParser->setUserAgent($bot);
    $result = $botParser->parse();

    if (!is_null($result)) {
        $crawler['device-detector']++;
    }

    $result = get_browser($bot);
    if ($result->crawler) {
        $crawler['get_browser']++;
    }
}
var_dump($crawler);

I searched for different sources of example user-agents and compiled a list of roughly 2700 ones, then generated a Tideways profiling trace from the CLI for the snippet with:

tideways run php crawler.php

The result disqualifies PHPs internal get_browser because it is pretty slow. 

Both userland libraries are within 12% of each other, with 767ms vs. 685ms.

That gives me confidence that either one of them is quick enough to be used in a request testing just the one user agent of the current user.

To verify this, I generate another callgraph where each is testing the same single HTTP header and get surprised. Now matomo/device-detector is 10x slower than jaybizzle/crawler-detect.

The reason is that matomo/device-detector initializes a regular expression once, calling AbstractParser::getRegexes, which takes roughly 18ms. The actual test of the user agent against the initialized regex is quite fast. In comparison, jaybizzle/Crawler-Detect code-generates their regex as a build step.

As a result, I’d rather pick jaybizzle/crawler-detect for my use-case of detecting a crawler in a single request, as 2ms is acceptable but 20ms is already a bit too much.

This does not disqualify matomo/device-detector in general, it could primarily be used inside a background job when analyzing many user agents at the same time, so this library might not be optimized for my use-case.

An AI would never be able to dive this deep into technical topics surrounding PHP performance! Follow us on LinkedIn or X and subscribe to our newsletter to get the latest posts.

Let’s dive in and find out what is causing bottlenecks, lazy loading times and errors! Without Tideways, you’re likely to fish in murky waters attempting to figure it out. Try our free trial today and be enlightened.

Dealing with MySQL Lock Timeouts: Bail faster

When using MySQL and InnoDB you will inevitably run into lock timeouts sometime, somewhere. 

We have recently started seeing this with some of our Shopware 6 customers in their storefronts or worker queues, so I was reminded to go back to 2017 in our codebase when we put a fix in place.

In our case, this happened on tables that were constantly written to from many different sources in the code base. But it only happened once every few hours or days in worker or cron jobs, and usually fixed itself by retrying the task, or even the function call itself at the code level.

In Tideways you’ll get a notification about the lock timeout as an exception, and you’ll see that it happens sporadically. In the case represented in the following screenshot this has happened a few times in the last days, always around 21:00:

One downside to MySQL lock timeouts is the default wait time: 50 seconds! This is a time where your web server, workers or cron jobs are idle. In our case when a backlog happened it quickly spiraled out of control and all workers suddenly had to wait.

Dealing with this timeout can make the difference from your application failing from the backpressure of requests or tasks that do not get processed fast enough and ties into decreasing timeouts across the board, a topic that we have blogged and podcasted about before.

If your code reaches the wait timeout failure and stops execution completely, a 1-second wait should be fine. Our write heavy worker tasks therefore change the timeout at the beginning of each task:

$this->connection->exec('SET innodb_lock_wait_timeout=1');

Or, you can change this setting directly in the MySQL server so that it doesn’t have to be a concern of your application.

If the occasional lock timeouts are acceptable and your application can recover from them, then this is a much simpler solution than re-architecturing your data write access to avoid the locks altogether.

What an AI would never be able to tell you the way we can! Follow us on LinkedIn or X and subscribe to our newsletter to take a deep dive into technical issues surrounding PHP performance.

You’ll never know until you try … our free trial!

Tideways 2024.2 Release

Get the cake, Tideways is turning ten!

Exactly on this day ten years ago, we lifted the veil on Tideways’ predecessor and thus began our exciting journey that continues to this day.

We would like to celebrate by presenting interesting new features to you.

Summary:

You can also watch a recording of our webinar on the topic, where Benjamin connects all these new features into a small story of improving a Shopware 6 plugin.

Differential Flame Graph

Differential Flame Graphs are a visual representation of a comparison between two sets of profiling data and is a beneficial tool for quickly identifying the root causes of performance problems. To benefit best from the findings, in Tideways they are presented in a comprehensible comparison box which shows the comparison base and the target, a summary and an example span. Unlike before, it’s now possible to see at a glance why a trace has become faster or slower.

It’s useful for instance to check whether a change in the source code, a system update or a configuration change improved performance or brought about a regression. It’s also possible to compare traces from different time periods or of different system states.

The color code depicts the most common way Differential Flame Graphs are presented. Red colors, alert you to an increase in execution time or resource usage. Blue, on the other hand, depicts a decrease. There are different shades of blue and red to depict minor or major decreases and increases. Neutral colors mean that no significant change has occurred.

Our Differential Flame Graph is interactive; you can hover over or click on the different areas to get more specific information.

The high level of detail helps to find an unwanted outlier in time or memory consumption faster.

Share Trace Comparison

The comparison of two traces can now be shared with persons who don’t have a Tideways account or are not members of the respective organization. This is an immensely helpful addition to the existing feature that already allowed the sharing of a single trace.

You can click the share action directly from a trace comparison and share a link to it. That makes investigating performance problems and validating improvements much easier.

When sharing a trace in Slack or in other chat / social media tools, a preview is generated to offer the message receivers a summary:

Dynamic Instrumentation for Functions from the UI

Dynamically instrumented functions are a new feature within Tideways to improve Profiling data and in turn identify performance problems even faster.

Previously, instrumentation was either defined within the Tideways extensions and could be added by changing the code to use the attribute #[WithSpan]. Now you can add instrumentation to your functions by simply clicking the “Dynamically Instrument Function” button from the callgraph interface. 

No changes in your application code or deployment of a new version needed!

Transaction Failure Rate Alerts

What failure rate is acceptable for individual transactions? To find out what causes errors in one specific transaction, a failure threshold can be set for each individual transaction. The failure threshold is based on a list of predefined percentages and can be configured via the transaction settings page. 

To that end, you can set up a notification under “Project Settings > Notifications”. You then get notified via Slack or email or other supported integrations when the failure rate for a transaction increases and it needs attention to be resolved. 

For more details on how to configure it view our documentation.

IDE Integrations

You can now use the “Open in IDE” icon in Errors and Callgraphs. This makes it easier to directly switch from Tideways into the code and start fixing a bug or performance problem.

At the moment you can configure this integration for PhpStorm and VSCode. For third party libraries you can also directly jump to the code on GitHub without the need to configure anything.

For more details view our documentation.

PHP Extension:

Improved Stacktraces from Third Party Libraries

For libraries such as Doctrine, Guzzle and Laravel, stacktraces in the Timeline Profiler are now modified to show primarily frames from your code-base and not from the library. Before, due to the limiting of the stackframes size they sometimes included only frames from the library itself and no indication where in the application they occurred. Relevant ones were sometimes cut off. Now, the stacktrace is cut off to show primarily application-code function calls.

In addition we reduced the default duration for a span to keep its stacktrace from 5ms to 3ms and increased the number of stacktraces Tideways keeps per trace across plans.

FrankenPHP Support

FrankenPHP Tideways

Tideways is the first APM solution that fully supports FrankenPHP, including worker mode. Starting from PHP extension 5.8.0, Tideways supports FrankenPHP.

Worker mode only loads your framework once into memory. Subsequently, it sends requests to the same instance of your application and doesn’t spin up a new instance for every new web request. 

That means that one gives up the shared nothing of for example PHP-FPM or even FrankenPHP without worker mode but saves time and optimizes performance. 

For more details on how to use FrankenPHP with Tideways see our changelog entry and our documentation.

WoltLab Suite Support

Tideways now also includes instrumentation of WoltLab Suite out of the box. The Tideways PHP Extension will automatically detect which type of page of your community has been accessed to automatically fill in the transaction name, making the collected data useful without requiring manual changes on your end.

You’ll never know until you try … our free trial!

New in PHP 8.4: engine optimization of sprintf() to string interpolation

PHPs compiler and bytecode cache OPcache not only cache the compile step from PHP source code to virtual machine bytecode, they also include optimizations that can produce faster bytecode:

For example PHP can:

  • optimize empty functions away. You can see this in a Callgraph Profiler when the function is not appearing in the result. 
  • already compute the result of constant compile time expressions into their result, for example 1 + 1 as 2.
  • replace calls to often used functions with logic directly in the VM to avoid the function call overhead of the engine. We wrote about these compiler optimized functions on this blog before.

For PHP 8.4 Tideways sponsored the work of our colleague Tim to add another compiler optimization for the function sprintf().

If you call the function with a format string containing only %s placeholders the engine will compile the call to sprintf() directly into the equivalent string interpolation, removing the overhead of the function call and avoiding repeatedly parsing the format string.

Taking an example from our code-base, we build many of our Redis cache keys using sprintf() and a pattern like this:

private function key(string $type, int $identifier): string
{
 return sprintf('last_ts_%s_%s', $type, $identifier);
}

With this optimization, the engine will automatically rewrite it to look like this code:

private function key(string $type, int $identifier): string
{
  return "last_ts_{$type}_{$identifier}";
}

This optimization will happen automatically during compilation of any PHP script and requires no work on your end.

We quickly followed up on this initial optimization with another pull request to add support for the %d placeholder.

Support for just these two placeholders allows the optimization to apply to more than 90% of the format strings encountered in the landing page of PHP’s Symfony Benchmark.

Given the widespread use of sprintf() in common PHP code (616 times in Tideways own backend code) this is an optimization that will make a small but significant contribution for the overall PHP performance.

With this optimization in mind, it also enables you to write or rewrite string manipulation code that is already performance sensitive to use sprintf() for better readability without making it slower.

What an AI would never be able to tell you the way we can! Follow us on LinkedIn or X and subscribe to our newsletter to take a deep dive into technical issues surrounding PHP performance.

You’ll never know until you try … our free trial!

Properly restart Opcache after deployment

When you are deploying code to a server and not with containers then it is critical to know how to properly restart Opcache.

Why? Opcache never throws old files out of the cache. 

Therefore, if a new version is deployed in a completely new directory, all files from the old version will remain in the cache and clog it. The cache may be full with files from old versions and the new file version of the application would not be saved in the cache, leading to Opcache recompiling them over and over again at great cost to performance.

There are two possible solutions to this problem. The first and the simplest one, but also the one with a catch, is to restart the “php-fpm” process after the deployment of the new version. But then currently processed requests are aborted during the short time of the restart.

The second and more sustainable solution is to use gordalina/cachetool or an alternative such as chop. The documentation recommends this two steps to install the tool:

curl -sLO https://github.com/gordalina/cachetool/releases/latest/download/cachetool.phar
chmod +x cachetool.phar

And then run the following command on the CLI:

php cachetool.phar opcache:reset

Cachetool automatically detects PHP-FPM with this approach:

  1. Look for Unix sockets called “php*.sock” in /usr/run/ and /usr/run/php directories
  2. Assume PHP-FPM runs on 127.0.0.1:9000 

If your PHP-FPM uses unix sockets in a different directory, or runs on a different IP and port, then you can explicitly pass this with an argument:

php cachetool.phar opcache:reset --fcgi=/var/run/php/php8.2-fpm-profiler.sock

You only need to reset OPcache once, when you operate PHP-FPM with multiple separate pools, for example when separating slow backend and regular frontend traffic with pools as we have discussed on this blog before. This resets the cache across all pools.

What an AI would never be able to tell you the way we can! Follow us on LinkedIn or X and subscribe to our newsletter to take a deep dive into technical issues surrounding PHP performance.

You’ll never know until you try … our free trial!

Measuring the DOM Namespace Reconciliation Performance Fix

This is the story of the manufacturing of seven-league boots for a function that is responsible for processing XML/HTML data in the PHP library. Optimizations in the PHP standard library, like here in ext/dom, have the potential to speed up the performance of applications significantly by an upgrade to the current PHP version. I don’t want to spill the beans right at the beginning but the performance optimization from PHP 8.2 to PHP 8.3 in percent is … no, I’ll show you later to keep up the suspense.

Let’s start at the beginning and work our way through the story of this particular bugfix, which began in 2019 when I was working on the RFC “DOM Living Standard“. I stumbled upon this performance problem which was brought to my attention by a Wikimedia programmer and thereupon created a bug report with “reproduce case“. This resulted in Niels Dossche authoring a performance fix.

What this performance improvement means can be seen in a Profiler such as Tideways. Using the new #[WithSpan] feature for the Timeline of the Tideways Profiler it is possible to see the duration of calls to certain functions of your codebase. I modified the code for reproduce case to include the attribute like this:

You can see in the Profiler that the “addParagraphs” function becomes slower with each call even though it does exactly the same and should accordingly be about as fast every time. 

Furthermore, by looking at the  “Callgraph”, it becomes possible to exactly pinpoint the place where the application is slow: The DOMNode::appendChild function taking 91% of the time.

PHP 8.2 Callgraph

PHP 8.3 compared to PHP 8.2 makes the performance improvement visible:

It sounds like magic was involved but the 94% performance increase was achieved by an optimization in the PHP standard library (in this particular example in ext/dom). The potential to make many applications faster by upgrading to the latest PHP version or at least a more recent version is sometimes underestimated.

Tideways 2024.1 Release

You can now unpack the Christmas present that was promised to you at the end of 2023! As you may have already read in the Flamegraph Feature Preview, this exciting new feature of the Profiler is now the focus of our first release in 2024.

The Flamegraph complements the Timeline and Callgraph features and visualizes Aggregated Traces. The goal was to provide profiling information across many traces and thereby gaining new and deeper insights into performance. The aggregated spans the Flamegraph makes visible in its easy-for-the-eye color scheme are very useful to get a representative average over many samples.

Summary:

Aggregated Traces

Tracepoints can now paint a representative average picture for all its traces. This gives a statistically more correct view of the trace by smoothing the effects of outliers.

Tideways computes an aggregated summary trace by averaging the data from all collected traces. The aggregated traces are visualized with a Flamegraph and thereby make an in-depth performance analysis possible.

When callgraph data is available for the tracepoint, these are also averaged in the aggregated trace.

This feature is only available to customers with current Tideways plans.

More information:

Feature Preview: Flamegraphs

The new Flamegraph Feature gives you a different visualization of existing data than you currently have with the Timeline spans and as such is a useful tool to measure time and memory consumption. It’s a well-known visualization, as it is used in many other performance tools. Tideways uses the inverted “icicle graph” which helps to avoid scrolling when starting at the top. For complex Timelines, Flamegraphs are usually more compact, since they aggregate lots of small spans of the same category into one frame.

We are planning to make improvements to the PHP Extension to supply more and more detailed data before we mark this feature as complete. For now it’s marked as a feature preview in the UI.

More information:

Missing Data Alerts

This feature proactively notifies you when there is no data flow, it identifies gaps or interruptions in data collection, thereby ensuring the reliability of data-driven processes.

For new projects created since early March it is activated by default for a timespan of 24 hours without discernible data flow. 

For existing projects the alert has to be created under Project Settings > Notifications for now. We plan to automatically create it for all existing projects in the next few weeks.

You can create and change that under “Notifications” and choose between different time periods of 1 to 24 hours, according to your specific business requirements. It helps you to quickly identify issues to minimize disruptions and improve operational resilience.

More information:

Ignore Control-Flow Framework Exceptions

Tideways now ignores a preselected list of framework exceptions by default that were used for control-flow and not to signal an actual error. 

This solves the problem that exceptions such as Symfony’s NotFoundHttpException or Shopware’s CustomerNotFoundException would create many entries in the exception tracking, including notifications, and a Tideways user would react to them by ignoring them, being distracted, or finding the button to ignore them.

Now we turn this around, these exceptions are ignored by default but if you need to see them you can configure that in the Project Settings => Exception Tracking => Ignored Exceptions menu.

Feature Preview: Sidebar Menu

We also implemented the Sidebar Menu which is aimed at improving usability, discoverability and making our overall navigation experience more intuitive. What’s more, the Sidebar Menu leaves more room for the profiling information. 

At present, both menus are available and the Sidebar Menu can be tested but due to the various advantages we are considering switching to the Sidebar Menu completely. Every user can take a look at the new layout by switching to it in User Settings: There you’ll find a button “Enable Sidebar Menu” under “Feature Preview: Sidebar Menu”.

PHP Extension 5.7 Release

To derive the most benefit from the new features it is necessary to install the latest version of the PHP Extension. We improved the quality of the PHP Extension 5.7 so that all our new features can be used to their fullest to support you in the best possible way.

New Shopware 6 Instrumentations

Tideways now has improved Shopware 6 instrumentation. Important functions of the Shopware API on product detail, category and other core pages are automatically instrumented with spans in the timeline to provide better context.

In addition, we have made Tideways compatible with the upcoming Shopware 6.6 release.

RdKafka Instrumentation

Tideways 5.7 includes instrumentation for Kafka producers using the rdkafka PHP extension. You’ll now start to see various Kafka-related spans within your timeline.

\Tideways\Profiler::markAsCliTransaction()

Tideways already automatically separates transactions using PHP’s CLI interface into the separate :cli service to prevent long-running cleanup tasks from skewing the number of web requests, making the performance profile incorrect for both the regular requests and the cleanup tasks.

As the CLI interface might not be available with all hosting providers, it forces them to run such cleanup tasks by means of a regular HTTP request. This will most likely intermingle them with the regular web requests by default.

Calling the new \Tideways\Profiler::markAsCliTransaction() method will cause the current request to be sorted into the corresponding :cli service, just as if it was executed using the CLI interface. Shopware 5’s web-based cronjobs are automatically detected to make use of this new functionality.

MongoDB Experimental

We improved the instrumentation support for MongoDB. You can now see the exact query that was sent. Query parameters are eliminated so that we can guarantee no personal information is transmitted to Tideways.

tideways.enable_cli now defaults to 1

The INI setting tideways.enable_cli now defaults to 1 instead of 0. Nevertheless, you can disable it and change it back. We are changing this default, because many users do this change eventually themselves already, often in response to struggling why no traces are collected on the CLI.

tideways.dynamic_tracepoints.enable_* now default to 1

Another improvement concerns the INI settings tideways.dynamic_tracepoints.enable_web and tideways.dynamic_tracepoints.enable_cli which now also default to 1 and will be activated with the next update. We are changing this default, because the tracepoints feature has been available for several years, many edge case problems have been addressed and we see no risk in activating it by default.

macOS Builds

Just to remind you that Tideways can be installed on macOS M1/M2/M3 (ARM) and Intel systems with the help of Homebrew, including the installation of PHP Extension, Daemon and CLI. We outlined for you how to get started with Tideways on macOS with Homebrew.

Docker Image for tideways-daemon

There is now a public docker image to use for the tideways-daemon where we previously only provided a Dockerfile in the documentation. The image is available under ghcr.io/tideways/daemon and we have updated the documentation to show it used with Docker and docker-compose.

Documentation: Install with Docker

Tideways 2023.2 Release

Since our last release announcement in April we have been working on a number of new features for Tideways that we are now happy to share with you. This is the second and final release for 2023.

From here the team will be looking ahead to 2024, the 10th anniversary of Tideways’ launch, and preparing some amazing new features and improvements.

Summary:

  • PHP 8.3 Support
  • #[WithSpan] Attribute
  • Redis Instrumentation Improvements
  • Automatic Service Detection for Shopware 5, 6 and Magento 2
  • Report PHP Notices & Warnings
  • Related Errors for Failure Rate Incidents
  • Support for Previous Exceptions
  • Transaction Failure Rates Beta
  • Trends of SQL, HTTP and other layers in History
  • Slack App

PHP 8.3 Support

PHP 8.3 will be released next week, on November 23rd 2023 and Tideways supports it from the start with PHP Extension release 5.6.4.

#[WithSpan] Attribute for Custom Instrumentation

Starting with Tideways PHP Extension 5.6 the attribute #[WithSpan] from the Tideways\Profiler namespace is available to automatically create a custom span for the Timeline Profiler during Profiling.

Redis Key Instrumentation 

When setting the new INI option „tideways.features.redis_keys=1“ in your php.ini, Tideways will now keep the key for every Redis operation and show them in the Timeline Profiler.

Automatic Service Detection for Shopware 5, 6 and Magento 2

Previously Tideways already had automatic service detection for Shopware 6, and with the extension 5.6 release this is extended to Shopware 5 and Magento 2.

With the automatic service detection, transactions for backend/API of these three e-commerce systems are assigned to a second service „api“ or „backend“, depending on the system.

The automatic service detection has lowest priority and you can always overwrite it by setting tideways.service ini, TIDEWAYS_SERVICE environment variable, call \Tideways\Profiler:.setServiceName at runtime or by simply disabling automatic service detection with „tideways.features.automatic_service_detection=0“.

Reporting of Notices and Warnings

Tideways now supports reporting of notices and warnings as part of the Error Tracking, completing support for the various types of errors that a PHP script can produce. 

Support for reporting notices and warnings is disabled by default and needs to be activated by setting tideways.features.warnings=1 and/or tideways.features.notices=1.

Support for Previous Exceptions

The Tideways PHP Extension now reports all previous exceptions in addition to the exception that crashed a request. The stacktrace of the previous exceptions and their messages are shown in the UI now.

Transaction Failure Rate Alerting (Beta)

In addition to service-level failure rate alerting, Tideways now supports failure rate alerting on the transaction level. This has many different use-cases, for example:

  • strict zero-error cronjob monitoring
  • better identification of failing project features that would not raise the service-wide failure rate. 
  • individual alerting in combination with response time targets – a feature released earlier this year.

In addition related errors that could be the cause of the increased failure rate are displayed for these incidents. Service-wide failure rate notifications also include Related Errors if available.

This feature can be activated from the Beta Features organization settings before it can be used. 

Trends of SQL, HTTP and other layers in History

The weekly report already included a report of the downstream layer performance of each service and a comparison to the previous week. This information is now also shown in the Trends section of the history report and allows a comparison on the day, week or granularity level across the complete retention of history data for a project.

Slack App for Tideways

You can now integrate notifications from Tideways with a Slack app – in addition to the previously available support using the legacy “Incoming Webhook” integration. This provides admins of the Slack workspace more control when integrating with Tideways.

The PHP stat cache explained

90% of the time when I explain how the stat cache works in PHP, people are surprised because they expected it to work differently. It was invented to solve a very limited problem when you call several file system related operations on the same file in quick succession.

Why should you know how it works? Because sometimes you need to work around the cache with the clearstatcache() function to get PHP code to run without errors.

Historical Context

Let us start at the beginning. What is stat? It is a C-level API call to the filesystem to query the metadata of a file, such as user, group, readability, writability, size, modification times. And PHP wraps this call with its own function that is also called stat and also uses this function internally in different places.

Historically, this has been an expensive operation to perform.

A number of PHP functions need this, PHP’s stat itself of course, but also file_exists, is_readable, is_writable and many more.

PHP’s stat cache

That is where the PHP stat cache comes into play: It caches the result of low-level stat operations. With one important caveat. The cache only caches this information for exactly one file. The last one that used the cache. And it caches this on the request-level, it is not a cross-request or process cache like OPcache.

This means that if PHP performs a low-level stat operation on a file and it wasn’t in the stat cache before, it will overwrite the previously stored stat data for the previous file.

How is the stat cache implemented?

If the stat cache were to be implemented in PHP, it would look something like this:

<?php
class FileStat
{
    private static string $CurrentStatFile;
    private static PhpStreamStatBuffer $ssd;

    public function stat(string $path)
    {
        if ($path === self::$CurrentStatFile) {
            return self::$ssd;
        }

        $statBuffer = new PhpStreamStatBuffer(stat($path));
        self::$CurrentStatFile = $path;
        self::$ssd = $statBuffer;

        return $statBuffer;
    }
}

Conclusion

So what does this tell us about the stat cache? Is it useful? It is hard to tell, especially on modern Linux and with SSD disks. But I didn’t measure, a topic for future research.

But if you want to make use of it, remember that you cannot interleave operations on multiple files, they would cause the cache to be overwritten.

You’ll find the complete list of functions that use the stat-cache in the documentation of the clearstatcache() function.

Tideways 2023.1 Release

In the 4 months since the last release (2022.4), we have been working on a number of new features and improvements that we are pleased to share with you today as part of our 2023.1 release of Tideways.

In addition to the new features, we also revamped our pricing and plans at the end of March under the umbrella of “Tideways 6”. The main difference is that all plans now include all features and are now limited by transactions as the primary metric.

Summary:

Monitoring for tagged transactions

In 2022.3 we added support for cached and uncached tags assigned to traces. As part of the Tideways 6 release, we are extending this feature to monitor tagged transactions individually. You can view the minute-by-minute performance of the transaction as a whole and broken down by any tags assigned.

In addition to the “cached” and “uncached” tags set automatically for Shopware 6 projects or via the markPageCacheHit/markPageCacheMiss APIs, the PHP extension now includes a new Profiler::setTags() function for setting up to 3 tags per request.

More Information:

Performance Budgeting with Response Time Targets

In preparation for supporting performance budgeting, we renamed “Errors” to “Failures” in the previous release. With the addition of Response Time Targets, Tideways can now mark requests as failed if they take longer than a configured response time in milliseconds.
This configuration is available at the service level and, with the new Tideways 6 plans, at the transaction level.

Combined with the existing failure rate notifications, this enables fine-grained performance budgeting and alerting.

More Information:

Profiling Spaces

One of the missing pieces in Tideways’ organization, project, and pricing is a space where you can collect profiling data for any PHP script you want to test around, analyze open source code you depend on, or small projects that are not monitored.
With the new Tideways 6 plans, we are introducing Profiling Spaces as a secondary mechanism for grouping profiling data besides projects.

In a Profiling Space, you can only trigger traces via Chrome Extension, CLI or Magic Query parameters.

A limit of profiles per day depending on the selected plan is the main restriction in the use of profiling spaces.

More Information:

Trace sharing

You can now share traces with people outside your organization. Each trace has a Share Trace button that initiates the process. You configure the duration of the sharing and a unique link is generated that requires no authentication to view.

For existing organizations, only administrators can share a trace at this time. You can change which users are allowed to share in the organization’s user settings.

For new organizations created after this release, all users can share traces by default.

More information:

Performance improvements for multi-host projects

For projects with a large number of hosts, starting with 5 or more, we have added an additional aggregation step for the monitoring data, which significantly improves the performance of the UI for the service and transaction monitoring screens. When looking at a 24-hour time frame of the project this often shaves several seconds off the response time.

Variable Timeframe in Error Count Chart

In addition to showing hourly error counts for the last 3 days, the Error Details screen now has the option to show minute-by-minute data for the last 2 hours, or longer time frames of 5, 14, or 30 days (depending on the retention days of the project license).

PHP Performance in 2022: A Year in Review

Now that 2022 is over, its time to review newsworthy topics about performance in the PHP language.

As this is the first time we are doing this type of blog post, please let us know your thoughts about this format and if we forgot important topics.

PHP 8.2 release 

With each new release of PHP, there are performance improvements to the engine or individual parts of the language. A list of performance related changes in the PHP 8.2.0 release from this year includes the following topics, discussed in more detail below:

  • Packed Arrays (List Arrays) are stored in a more efficient data structure, leading to reduced memory footprint and better performance.
  • stripos() performance improved significantly
  • Performance of different functions in mbstring extension improved
  • new memory_reset_peak_usage() function introduced

Tideways also already supports PHP 8.2 and a handful of customers are already running it in production.

More efficient packed arrays (lists)

Arrays in PHP are lists, hashmaps or both at the same time. For the “array as list with items indexed by 0” use case, PHP 8.2 ships with a more memory-efficient representation, contributed by Dmitry Stogov in #7491

This change significantly reduces the memory overhead of the array structure.

A test script that creates an array list of integers with 100 items reduces memory usage from 4,3 MB to 2,3 MB (3v4l.org):

<?php

function build_list() {
    $list = [];

    for ($i = 0; $i < 100000; $i++) {
        $list[] = $i;
    }
}

var_dump(memory_get_peak_usage() / 1024 / 1024);

stripos() performance improved

Before PHP 8.2, stripos would lowercase the string and then use strips internally, which has suboptimal performance semantics for a few edge cases.

In PHP 8.2 Ilija Tovilo added a custom stripos implementation in PR #7852 that exhibits better performance characteristics for all use-cases.

Performance of different functions in mbstring extension improved

Alex Dowad is consistently working on improving the mbstring extension and PHP 8.2 includes a large range of PRs that increase the performance of different functions in mbstring for different character sets.

New memory_reset_peak_usage() function introduced

With the new function memory_reset_peak_usage() contributed to PHP 8.2 by Patrick Allaert in #8151, the value for the memory_get_peak_usage() resets to the currently used memory. This function is helpful for PHP scripts that perform multiple tasks, such as daemons, workers and cronjobs, to accurately measure each task’s peak memory impact.

Franken PHP

A new experimental web server for PHP was released called FrankenPHP. It is written in Go and uses the Embed SAPI to run PHP requests as threads within the Go web server.  

The interaction between Go and PHP is possible with a recent 8.2 version and higher, It also requires  PHP to be compiled with ZTS (Zend Thread Safety). 

FrankenPHP is an interesting project to watch because it is the first time a „SAPI“ directly includes a powerful web server (based on Caddy). This could simplify deployment of PHP applications compared to running both Nginx/Apache and PHP-FPM.

FrankenPHP is also the only PHP SAPI that provides HTTP 103 Early Hint support to increase performance for certain sites.

Revolt Event Loop released stable version

With PHP 8.1 Fibers were introduced to allow cooperative multi-tasking. Now in 2022, the first projects are now building on Fibers to provide new frameworks and features to PHP users.

The revolt/event-loop  is a Composer package that provides the basic building blocks for a Fiber-based event loop. It released the first stable version 1.0 in November 2022.

React-PHP and amphp are currently integrating Revolt in their event loop implementations.

Did we miss anything important? Let us know [email protected] or @tideways on Twitter.

Photo by Jason Leung on Unsplash

A story of Lazy Loading File System Operations for better dev system performance

In this blog post I want to share a story of a performance bottleneck using the filesystem that we experienced in our development setup.

In the Tideways backend, we have a simple homegrown database migration tool that scans a directory for .sql files and applies them if not already done. It is a very old piece of code that I used since before the times of doctrine/migrations. It is much simpler but works for us.

To avoid the development system running with an outdated schema after git pulling commits with SQL schema changes, this database migration tool checks for missing migrations to apply on every single request (in the development environment).

This check only requires 1 SQL select to fetch the already applied changes from the changelog table and one glob to fetch the list of all schema files. Should be quick and straightforward! Right? The high-level code looks something like this:

Looking at the callgraph however, shows a bottleneck in file_get_contents:

We have 450 SQL migrations already, and for checking the current status the content of each SQL file is loaded into memory in DbDeploy::getAllMigrations().

The MigrationStatus::hasOutstandingMigrations() method shown above does not need the SQL file contents, so we can refactor the code to call file_get_contents at the last possible moment.

This lazy loading pattern is widespread when it comes to database operations but also makes sense for the file operations here. The virtual filesystem of our development environment, which makes file operations considerably slower than with a non-virtual filesystem, adds extra time to these operations.

After refactoring away the file_get_contents calls from the DbDeploy::getAllMigrations() method into Migration::getSQL() that is only called directly before executing the changes, we see improvements.

A 90ms improvement by comparing a callgraph before and after the change:

  • File I/O drops from 128ms to 49ms
  • Overall response drops from 246ms to 154ms
  • file_get_contents duration improves by 90ms

A nice gain, considering it runs on every request in the development environment!

Tideways 2022.4 Release

This post contains a comprehensive list of all the features that we worked on and deployed over the last 3 months, all included in this 2022.4 release.

PHP Extension

We have released PHP extension version 5.5.12 with the following changes:

PHP 8.2 Support

The end of the year brings another new PHP version 8.2, due to be released on 7th December 2022. Tideways is already fully compatible with PHP 8.2.

This is the first PHP release that includes work sponsored by the PHP Foundation. Tideways is a major sponsor of the foundation and we are very proud to support the PHP language by funding developers to work on it. In fact we have increased our support to $15.000 this year.

One notable change in PHP 8.2 that affects Tideways is the improvement of the Observer API to include internal functions, which should further reduce the overhead of Tideways in Callgraph mode.

Monitoring

Rename “Errors “to “Failures”

The “Errors “metric used in Tideways’s monitoring, weekly report, and history components is now named “Failures”.

This is done primarily to avoid confusion with the Errors/Exception Tracking due to slightly different semantics.

“Failures “in the monitoring component can either be:

  • Requests aborted by Exceptions or Fatal Errors
  • Requests sending an HTTP status code of 500 or above (without exception)

Default Service of new projects is now “app”

Previously the first and default service of a new project was called “web “.

We changed this default to “app “for all new projects created since October. Existing projects will keep “web “as their default service if in use.

This rename is due to a change in the service feature we are currently preparing and to increase clarity for users.

Splunk OnCall (VictorOps) support for alerting

Customers can now integrate with Splunk OnCall (formerly VictorOps) to send notifications.

Documentation: Splunk OnCall

Profiler

Filter Traces by specific Day

In addition to selecting traces by pre-defined ranges such as “Last Day “or “Last 7 days “, users can now filter traces by a specific day.

Account Management

Two-Factor Authentication

Tideways now supports adding Two-Factor Authentication to user accounts. In addition, organization admins can require all members of an organization to use Two-Factor authentication for access.
Documentation: Two-Factor Authentication

Single Sign On with Azure Active Directory

Tideways now supports Azure Active Directory SSO. Contact [email protected] to get access to this feature.
Documentation: Azure AD SSO

Improve Settings Visibility for all members of an organization

The current settings of an organization and its projects are now visible to regular and privileged users. This helps users to understand how Tideways is configured so that they know when and how to ask an admin for changes.

Journey of Profiling a Slow Development Setup

While working on the migration from Vagrant to Docker with Compose in our development setup, we were seeing extremely slow responses in the browser and I immediately made a mistake to assume I know the problem without measuring.

A story in 7 acts.

1. Making the wrong assumptions

From common experience, the first thing to blame was Docker Volume Performance. So I optimized the obvious issues, that you can find in the many Docker on Mac Performance blog posts around the web:

  • Set the volume to :delegated or :cached (Edit: Turns out this is moot, but you’ll find it on the internet everywhere)
  • Do not share the Composer and NPM/Yarn dependency folders into the container
  • Enable the new experimental VirtioFS filesystem in Docker Desktop for Mac
  • Regenerate the Symfony cache via docker-compose exec to make sure the cache generation is not holding up the request.

2. Reality breaks assumptions: Why is cache generation quick?

At that point I had a realization:

Using „docker-compose exec app php /app/bin/console cache:clear“ generated the cache in 3-4 seconds. If volume performance was the problem, then this CLI script should also be slow. Yet 3-4 seconds is pretty quick for generating the cache of our large Symfony application.

So it is most likely not be Docker volumes that are slow, but something in the Nginx, PHP-FPM or our application stack.

3. Identify where slowness comes from

To identify where to dig next, I executed the front controller „index.php“ script from the CLI as well.

$ docker-compose exec app php /app/web/index.php

This gave a long 60 second response, which leads me to conclude that our PHP application is slow and not Nginx or PHP-FPM. I call this divide and conquer debugging, splitting up the potential causes and eliminating them one by one.

4. Identify what causes the slowness

I installed the tideways CLI into the Docker container next and re-ran the index.php script from the CLI with:

docker-compose exec app tideways run php /app/web/index.php

Clicking on the output response to find out where the 60 seconds are coming from: Our own code making a HTTP request to a host that is not available using file_get_contents:

This is only a debug call, so its using file_get_contents and its default timeout of 60 seconds is what is causing the problem.

5. Setting Timeouts on HTTP calls

A case of not following our own advice of always setting timeouts on HTTP calls. We have a blog post on „Using HTTP Client Timeouts in PHP“ and Tideways itself warns when the default socket timeout is not adjusted to a lower value through an observation.

So changing the code to use a timeout:

private function queryMailcatchMails() : array
{
    $context = stream_context_create([
        'http' => ['timeout' => 1.0, 'ignore_errors' => true],
    ]);
    $data = @file_get_contents("http://mailcatcher.local:1025/api/messages", false, $context);

    // ...
}

Still the same slow response! Turns out, since mailcatcher.local is a domain that does not resolve with DNS, PHP is hanging in dns resolving, which for some reason is not affected by the stream timeout settings!

6. Rewriting with Symfony HttpClient

So I did a rewrite with Symfony HTTP Cilent for the code, since we use that in many other places of the code base already:

private function queryMailcatchMails() : array
{
    $client = HttpClient::create();
    try {
        $response = $client->request(
            'GET',
            'http://mailcatcher.local:1025',
            options: ['timeout' => 1, 'max_duration' => 1]
        );
        $file = $response->getContent();
    } catch (TransportExceptionInterface $e) {
        return ['count' => 0, 'last' => []];
    }

    // ...
}

That did not work either, because of a bug in Symfony HttpClient only seting CURLOPT_TIMEOUT but not CURLOPT_CONNECTIONTIMEOUT. We still have 20 seconds spent in HTTP requests.

I have filed a bug report and will spend some time proposing a PR in the next few weeks.

7. Fixing the underlying problem: New hostname

This journey started with the migration from Vagrant to Docker, the mailcatcher.local domain was used in Vagrant, but it did not exist in Docker (yet). Once the mailcatcher service was running in the Docker Compose setup and the code changed to talk to the right HTTP host everything was fast again.

Here you can see the comparison of the old vs the new code in a callgraph comparison in Tideways: curl_multi_exec is now 19 seconds or 95% faster than before.

The moral of the story: don’t make assumptions without measuring, otherwise you might spend a lot of time optimizing something that is not slow.

In our case the Docker volumes were quick and response anyways, the problem was in the application and specifically the unavailable HTTP host.

Tideways 2022.3 Release

In this post we post a comprehensive list of all the features that we have worked on and deployed over the last 3 months, all included in this 2022.3 release.

Monitoring

Page Cache Hit Rate for Services and Transactions

Monitoring for services and transactions now supports calculating the hit rate for PHP-based page caches. For example, if you have a full page cache storing the HTML on the filesystem, Redis or any system, then using the Tideways Profiler API, you can mark a response as cache hit or miss. The hit rate is then calculated on the service and transaction level automatically:

For Shopware 6 applications, automatic instrumentation into the Page Cache API is provided so that no code changes are necessary to calculate the cache hit rate.

In addition to the monitoring, there is also a new observation for the page cache hit rate, letting you know if it’s not doing it’s job. You can find more information in the Page Cache Hit Rate observation documentation.

One more for Shopware 6, there are extras; the product and category details pages have their own page cache hit rate observations.

Change the Default Environment Name

The environment support in Tideways previously had the hardcoded default environment “production” that received the primary load of traces. It is now possible to change the default environment to something other than “production”. See the documentation on how environments work and how to configure them if you want to make use of this change.

Profiler

Tagging Traces as Cached or Uncached

Using the page cache hit rate API introduced in the previous section, traces that are either cached or uncached are tagged as such in the trace list and details now:

There is a new filter “Tags” so that you can select “Cached” or “Uncached”. We are planning to add other tags and an API to add custom tags.

Callgraph Profiler: preg API regular expression profiling

With PHP Extension 5.5.8, the Callgraph Profiler includes support for argument capturing for the PHP functions preg_match, preg_match_all, preg_replace and preg_split. These functions are often performance bottlenecks due to inefficiencies in the patterns combined with their excessive use. By capturing the first 30 characters of all patterns, we group the functions in the callgraph, making it much easier to identify which regular expressions are performance bottlenecks and which are not.

Timeline Profiler: Shopware 6 Data Access Layer

The Timeline Profiler now includes timespans for the Shopware 6 Data Access Layer, similar to our instrumentation of Doctrine or Propel ORMs. For product and category DAL this even includes the Criteria query.

Exception Tracking

Resolve All Errors

We added a “Resolve All” button in the exception tracking list that allows resolving all open errors. This action only applies to the currently selected environment, service and optionally transaction(s).

This can be helpful when you want to reset the notifications and occurrences without having to create a release event.

Exceptions across Environments

Exceptions will now be tracked separately by environment starting October 1st 2022. The change is dated since its a backwards incompatible break from the previous behavior. You can opt into the feature using the “Beta Features” section of Tideways.

This change to exceptions by environment includes occurrences, stacktraces and notifications. When you are using different environments, then enabling this feature will initially trigger new notifications for all errors in non-production environments.

When triggering a release for an environment and service, only errors of these will get reset and notify again, according to your notification filter settings.

Chrome Extension

Building on the changes in the 2022.2 release, we have improved the Chrome Extension further:

  • Show that profiling is still in progress when triggering traces for the next 15 or 60 seconds. This provides better feedback about the current state of a profiling session and prevents the trigger buttons from being clicked multiple times and causing confusion.
  • Improve rendering of projects and previously collected traces in the Chrome extension popup screen.

Your chrome extension was auto-updated to version 1.5.2 a few weeks ago, which already includes these changes.

Commandline Interface (CLI)

We have relased the tideways CLI tool as version 1.0.0 now, it required very little changes and bugfixes in the past years, so that a 0-point version number does not communicate the stability of it well.

One user facing changes is included in this release:

  • Bugfix: Always query backend for traces, even when executed PHP command failed with non-zero exit code. This is important when running for example phpunit, psalm or php-stan under Tideways profiling, while they throw errors.

Tideways 2022.2 Release

In this new release, there are changes to many different parts of the Tideways stack. This includes new releases to the PHP extension (5.5.2), daemon (1.7.26, 1.7.28), CLI (0.4.6), and Chrome Web Extension (1.5.1).

Add Generic Markers to Charts

In addition to the existing Release and Deployment events, it is now possible to add generic markers to the performance charts to indicate an event for example “Beginning of E-Mail Marketing Campaign”, or “OpCache Configuration Change” or “MySQL Upgrade”. Performance before and after the marker event is comparable to allow investigation of its effects on the application.

You can create markers through a new button called “Add Marker” that is now present on the Application/Service performance screens and for selected snapshots. In addition, markers can be created through the event REST API or the CLI.

Smarter Long SQL Statement Truncation

SELECT statements longer than 4000 characters are now using a smart parser in the PHP extension to keep all parts beginning with the FROM clause instead of the column list during truncation.

Before the new version 5.5 release (May 2022) of the PHP extension, very long SQL statements were truncated to 4000 characters to reduce the payloads sent from PHP extension to the daemon over socket or TCP/IP. This could produce truncated SELECT statements that did not include the FROM, JOIN or WHERE parts because the column list was already very large, for example including a subselect or entities with many fields in Doctrine ORM.

Chrome Extension shows triggered traces

The Tideways Chrome extension will now store links to the resulting traces when using the “Take Profile” feature. This will allow you to keep going back to the last ten recently generated traces by clicking on the Tideways extension icon inside Chrome.

Before this change, it was necessary to click on the traces immediately in the popup to avoid losing the links.

Navigate between Referenced Traces

When you trigger traces through the Chrome extension, CLI or tracepoints, all traces include a shared reference UUID generated at the time and stored in our database. The trace view screen now has a new tab called “References”, which shows all referenced traces.

New and Updated Instrumentation in PHP Extension

The version 5.5.2 release of the PHP extension includes a few other notable changes:

  • The transaction name of cached requests in Shopware 6 is now correctly detected. Previously the fallback transaction name “public/index.php” was used.
  • We improved the Symfony instrumentation for event listeners and transaction name detection.
  • Improved Laravel exception tracking support
  • A bug was fixed for curl multi instrumentation incorrectly batching spans together, leading to information inaccuracy in the Profiler.

Other notable changes

There are a few other notable changes:

  • The Performance Metrics REST API was improved to include median and all downstream layeImproved The Performance Metrics REST API to include median and all downstream layers in the response.
  • The weekly report and export charts now show the requests as a second y-axis.
  • Updated the CLI tool to allow sending events for any environment via the –environment flag. Previously the environment was hardcoded to “production”.
  • SQL Connect operations are now identified as “CONNECT” in the Timeline Profiler instead of “OTHER”.

Refactoring with Deprecations

Deprecating old code and replacing it with new and improved APIs is an established process in software development. In the core of PHP APIs are provided to trigger and to get notified of deprecations.

  1. If a feature in PHP is deprecated, the language triggers a notification message with the E_DEPRECATED level.
  2. As a developer, library or framework author, deprecations can be triggered directly from PHP code using the function trigger_error() with the E_DEPRECATED or E_USER_DEPRECATED levels.

As a PHP application developer you can then hook into all triggered deprecations using a user defined error handler. You can use this API to collect deprecations and fix them.

A Refactoring Workflow using Deprecations

A common workflow to slowly and safely improve your code, without potentially breaking usages of your old code is a strategy of introducing new APIs and deprecating the old ones. Both APIs are then maintained until all usages of the old API is replaced with the new API.

A checklist of this workflow looks as follows:

  1. Introduce a new API that improves upon the old API.
  2. Add a call to trigger_error in the old API (unless its called by the new API)
  3. Roll out this change to production and start logging the deprecations with Tideways.
  4. Replace ocurring deprecations where you haven’t replaced the old with the new API
  5. Remove the old API as soon as you are confident the old API is not used anymore, potentially by not seeing the deprecation message anymore for several days.

If you can replace the old API with the new one in a single step, then you don’t need the indirection through using deprecations. But when an API is used wide spread throughout the code base this approach allows you to do a gradual migration instead of a big bang refactoring that introduces the risk of bugs.

Example: Deprecating an API

Lets see an example. We have a method that allows querying from a database table using many parameters to influence the query conditions, the example is directly taken from Tideways own code-basis:

<?php

interface TracepointRuleRepository
{
    /**
     * @return array<TracepointRule>
     */
    public function findAllTracepointRules(
        int $applicationId,
        bool $activeOnly = false,
        string $service = '',
        string $environment = '') : array;
}

We have recently added two new parameters to this API for $service and $environment. Because many optional parameters are a code smell, we decided to refactor this code to what we call the “Criteria API Pattern” in our team. More generally the pattern is called Parameter Object.

First we introduce the Criteria object:

<?php

class TracepointCriteria extends Struct
{
    public bool $activeOnly = false;
    public string $service = '';
    public string $environment = '';
}

Then we introduce a new method on the interface and the coresponding implementation:

<?php

interface TracepointRuleRepository
{
    /**
     * @return array<TracepointRule>
     */
    public function findMatching(int $applicationId, TracepointCriteria $criteria) : array;
}

The important part is not to change the original old API and keep it around. Instead we modify this code to trigger a deprecation:

<?php

class TracepointRuleOrmRepository implements TracepointRuleRepository
{
    /**
     * @return array<TracepointRule>
     */
    public function findAllTracepointRules(
        int $applicationId,
        bool $activeOnly = false,
        string $service = '',
        string $environment = '') : array
    {
        @trigger_error("findAllTracepointRules() is deprecated, use findByCriteria() instead.", E_USER_DEPRECATED);

        // original implementation
    }
}

After enabling deprecations tracking in Tideways, these deprecations now look like in the following screenshot:

A deprecation in Tideways

You can see the stacktrace to this deprecation and if you start fixing occurrences, until the deprecation is not triggered again.

For the new implementation of the findMatching method there are now three approaches we can take:

  1. Completly implement the new method from scratch and keep the old method.
  2. Implement the new method from scratch, but call the newly implement method from the old, deprecated method.
  3. Call the deprecated code from the new method. This is the most tricky, because we have to avoid that the deprecation is being triggered. We can do this by passing a parameter that controls the behavior.
<?php

class TracepointRuleOrmRepository implements TracepointRuleRepository
{
    /**
     * @return array<TracepointRule>
     */
    public function findAllTracepointRules(
        int $applicationId,
        bool $activeOnly = false,
        string $service = '',
        string $environment = '',
        bool $triggerDeprecation = true) : array
    {
        if ($triggerDeprecation) {
            @trigger_error("findAllTracepointRules() is deprecated, use findByCriteria() instead.", E_USER_DEPRECATED);
        }

        // original implementation
    }

    public function findMatching(int $applicationId, TracepointCriteria $criteria) : array
    {
        return $this->findAllTracepointRules(
            $applicationId,
            $criteria->activeOnly,
            $criteria->service,
            $criteria->environment,
            false
        );
    }
}

Shopware 6.4.11 NavigationLoader performance improvements evaluated

During Shopware Community Unconference 2022, we heard a lot about an internal performance week at Shopware, where they took tie to optimize different parts of the core of the Shopware platform. These were mostly performance problems that also affect our customers. Naturally, we are super excited about them their release in version 6.4.11. In this blog post we will look at one improvement to category navigation loading.

Comparing two Callgraphs of NavigationLoader

If you have a category-heavy Shopware 6 store, fetching and rendering the navigation menu would be a slow operation, we have seen from 100-500ms depending on the number of categories for different customers. Even smaller category trees required a disproportionate amount of time to render. We verified this with a demo shop, which the following numbers are taken from.

Comparing the performance of the NavigationLoader::loadTree function before and after the update to 6.4.11 shows roughly 15% performance gain for a store with 3097 categories (generated by the framework:demodata command).

We can see the gain by searching for all calls to the NavigationLoader class in the callgraph table view.

The whole tree fetching takes 163ms in the old code and just 14ms in the new code. What was changed?

Reducing Loop Complexity to Improve Performance

The commit to fix this performance bottleneck is not straightforward by glancing at it, but with a bit of time we can see that instead of an O(N^2) loop through all categories to build the navigation tree, it is now iterated only O(2N) times. See the Big O Notation for complexity of an algorithm if you are unfamiliar with this notation.

A quadratic complexity means that for each category all categories are iterated once again. For 2 categories we have 4 iterations, for 1,000 categories we have 1,000,000 iterations. This perfectly explains why the performance gets so much slower for large numbers of categories and you can see evidence of this in the Tideways Callgraph screenshot above.

CategoryEntity::getParentId was called 277409 times more often in the old code. This is a very simple getter, but the number of calls in the old algorithm made up for 41ms of execution, 25% of the 163ms the NavigationLoader took in total.

The new algorithm only iterates over all the categories twice.

The benefit of this performance improvement cannot be understated because it is a positive effect on all uncached pages in the store: Homepage, category pages, product pages, everything.

How was this data generated and measured?

Using the Ansible automation of the Shopware 6 Benchmarking Tool, we have set up a 2 machine cluster on Digitalocean for this test, with one web node including Redis and one database node with MySQL, both having 4 Cores, 8 GB RAM, and SSDs. The shown numbers should not be considered as absolute improvements, instead, you should see a similar performance improvement in relation to the total request time.

Tideways 2022.1 Release

This new release of Tideways includes tracking exceptions with codes, improved notifications, improved trace filtering and sorting, several new features for the Callgraph Profiler and changes to the PHP extension.

Exceptions with Codes

Previously when an exception was tracked by Tideways that had a non-zero Exception code, then this code was not transmitted to Tideways as additional debugging information. If your application code uses Exception codes to convey information this then from PHP Extension 5.4.36 and daemon 1.7.24 Tideways will collect and show it:

Improved Notifications

A few improvements to notifications are in this release.

The response time and error rate notifications now only trigger if a minimum number of requests / minute threshold was crossed. This avoids flapping notifications during the times your application has low traffic, for example nights and weekends. For all existing notifications the threshold has been retroactively set to 10 requests / minute, for new ones it starts at 25 requests / minute.

For the New Error/Exception notification there is a new filter to notify or suppress errors by their lifecycle status: New, Reopened or still open after release.

Notifications sent to integrations also include this lifecycle kind in their messaging:

Lastly, when previewing an integration in the configuration, there is now a visual feedback the preview was triggered.

Improved Trace Filtering

In addition to pre-defined ranges of milliseconds, the response time, SQL duration and other response and count based filters in the Search Traces UI now allow to specify custom ranges with minimum and maximum values.

In addition to sorting by date or response time, traces can now be sorted by Memory Usage:

New Features in Callgraph Profiler

The folding of function calls has been improved by rendering dedicated nodes in the callgraph that state “number of folded calls (click to expand)”. This textual representation gives a much better clue what call folding is about and how you can work with it in the callgraph. By clicking on a folded call notice, the hidden calls in the chain will become visible.

The Profiler now gives a little hint about compiler optimizable functions. To avoid falling into a micro optimization trap, this hint is only shown when the calls are responsible for at least 5% of a requests response time, starting at which case the compiler optimization could realistically provide a benefit.

The Tideways reference documentation contains a new page explaining Compiler Optimized Functions in detail and how to automatically benefit from this optimization by using php-cs-fixer.

New and Updated Instrumentation in PHP Extension

With the release of PHP Extension version 5.4.38 and two previous releases in the last few months a number of new automated instrumentation is now included in Tideways:

  • Support for detecting the Glue API service in Spryker based applications
  • Support for argument capturing entity names from Shopware 6 Data Access Layer APIs (Changelog)
  • Elasticsearch Query Payloads now get truncated to a maximum of 4000 characters to avoid extremely large search queries from slowing down serialization and transmission of traces to the daemon and breaking rendering in the trace UI.
  • Timeline Profiler Spans created with the programmatic \Tideways\Profiler::createSpan API now receive special handling in the UI and are clearly marked as using the custom API.

Shopware 6 Benchmarking

In collaboration with Shopware we have released the first beta version of a new open-source tool for benachmarking and load-testing Shopware 6 stores using pre-defined and configurable scenarios and user behavior patterns. See this example PDF report for a demo shop.

2021.3 Release

This quarterly release of Tideways includes Distributed Tracing and Profiling, Traces in the History, and many more features.

In this blog post, we will provide a detailed overview of all the changes. There was also a webinar on the release that you can follow here:

Distributed Tracing and Profiling

In more complex projects where several applications or microservices communicate with each other, profiling becomes more powerful when it can propagate to each sub-request that takes part in a trace. With distributed tracing, the software industry has developed an approach to combine data from multiple related requests. Tideways joins this effort by releasing distributed tracing and profiling across multiple related HTTP requests.

When triggering a trace via Chrome Extension or CLI, Tideways passes information about the parent trace to the child via HTTP headers and combines the results on the backend into a single trace to look at.

This improvement means the Timeline visualization is shown in a single view:

The callgraphs for each participating request can be selected and explored as well.

This feature is available to projects with a “Pro” license.

Trace History

Tideways now stores a few selected traces as part of the application’s history, longer than the regular retention of 5-30 days, depending on the license.

These stored traces allow comparisons of performance through detailed analysis over long periods of time. In combination with our revamped trace comparison that was part of the last 2021.2 release, this gives more insights into long-term changes of application performance.

Every day 1-5 traces are stored as part of the history, and they are selected from the transactions with the highest impact in every service.

This new feature is available to projects with the latest “Standard” or “Pro” license.

Documentation: Trace History

Compact Slack Notifications

Slack messages from bots can quickly claim a lot of real estate on the screen and crowd out other important messages. Depending on how a channel is used, more compact notifications are essential to allow a high number of messages on the same screen. Configuration for Tideways Slack Notifications now allows users to select between a new compact message mode and the already existing detailed message mode.

The documentation shows examples of both compact and detailed messages and how to configure the mode.

cURL Timers in Timeline Profiler

The Timeline Profiler now collects timing information for cURL based HTTP Requests that are available from curl_getinfo at runtime and shows them in the span details panel.

You can find more information about the available timers in the changelog.

PHP 8.1 Support

Tideways now supports PHP 8.1, starting with the PHP extension 5.4.26. The PHP 8.1 support covers all existing functionality of PHP from previous versions. However, support for the new Fibers feature is not implemented yet. This means that code using fibers may produce confusing timeline and profiling results.

Reduced Daemon Overhead under Heavy Load

Usually, the tideways-daemon processing all monitoring and profiling data has a very low CPU and memory profile. However, we observed that when many PHP requests are processed within a second and the sample rate is high, then the load can sometimes increase. This has lad us to refactor the daemon in two specific ways:

  • Serialization of data between PHP extension and daemon was optimized to use a more CPU and memory efficient Go library.
  • Parallel processing can now use a worker connection pool that limits the amount of processed monitoring and profiling payloads in parallel. This is currently an opt-in feature that you can enable with the –use-connection-pool flag. (Documentation)

Several customers have reported significantly better CPU and memory usage of the daemon with these two changes enabled.

Log all tasks the Shopware 6 queue processes

The Shopware 6 software architecture heavily relies on a message queue to process tasks in the background. This is a fundamental change of how Shopware works compared to version 5, which did not have a message queue.

To fully leverage the benefits of Shopware 6 you should make use of the message queue as much as possible. Shopware can already do the following tasks in the background out of the box:

  • Store and Index Imported Products / Categories via the Sync API
  • Indexing of all entities
  • Warmup product and category pages in the HTTP Cache
  • Generate Thumbnails for Images
  • Generate Sitemap
  • Product Exports (Google Shopping Feed, …)
  • several others…

This has a lot of performance benefits, but it also introduces an operational risk: What if there is a bug, an error or any kind of problem in the queue? Will I see this and can I debug it?

You can make use of the canonical log line pattern to essentially generate yourself a more powerful equivalent of the webservers “access.log” for every task that the message queue processes. The output will look like this:

2021-08-15 10:39:58 ProductIndexing data=1791edec1f04464a8a4074423501e781 duration=0.190
2021-08-15 11:30:48 UpdateThumbnails mediaIds=102ac62ba27347a688030a05c1790db7 duration=0.015
2021-08-15 11:32:16 DeleteFile files=shirt_red_600x600_800x800.jpg duration=0.002
2021-08-15 12:08:25 WarmUp route=frontend.detail.page domain=http://shopware6.tideways.io cache_id=cc3e1493bc874b62b16c11cd291826f9 duration=0.003
2021-08-15 12:08:25 WarmUp route=frontend.navigation.page domain=http://shopware6.tideways.io cache_id=cc3e1493bc874b62b16c11cd291826f9 duration=0.002

This can easily be achieved, because the message queue is based on the Symfony Messenger component and it can be extended via so called Middleware.

We create a middleware class with the following structure:

namespace Shopware\Production\Messenger;

use Symfony\Component\Messenger\Envelope;
use Symfony\Component\Messenger\Middleware\StackInterface;

class TaskLoggingMiddleware implements MiddlewareInterface
{
    function handle(Envelope $envelope, StackInterface $stack): Envelope
    {
        return $stack->next()->handle($envelope, $stack);
    }
}

And we register it as a service that is a message queue middleware with this Symfony container service definition:

# config/packages/framework.yaml
framework:
  messenger:
    buses:
      messenger.bus.shopware:
        middleware:
          - "Shopware\\Core\\Framework\\MessageQueue\\Midleware\\RetryMiddleware"
          - "Shopware\\Production\\Messenger\\TaskLoggingMiddleware"

services:
- "Shopware\\Production\\Messenger\\TaskLoggingMiddleware": ~

This will run the middleware whenever a task is processed in the Shopware Message queue. Next up is the implementation of logging what is happening:

  • map each task into a task name
  • extract arguments from all known message task types to enhance the log output
  • handle errors in tasks
  • write the task processing to a file

On the macro level I use the following implementation for handle:

public function handle(Envelope $envelope, StackInterface $stack): Envelope
{
    $message = $envelope->getMessage();
    $taskName = $this->getTaskName($message);
    $args = $this->extractArgumentsFromMessage($message);

    $start = microtime(true);
    try {
        return $stack->next()->handle($envelope, $stack);
    } catch (HandlerFailedException $e) {
        $args = $this->addExceptionToArgs($e, $args);

        throw $e;
    } finally {
        $this->logTaskProcessing($taskName, $args, $start);
    }
}

The try catch finally makes sure that regardless of an Exception, we always “logTaskProcessing” to store information about the processed task. We have two methods for mapping the message to a human readable task name and extract the arguments at the beginning and when an Exception occurs, we extract the exception class and message into the arguments.

The interesting part is “extractArgumentsFromMessage”, which has special code for a lot of the different Shopware internal messages, for example “EntityIndexingMessage”, “WarmUpMessage” or “ScheduledTask”.

private function extractArgumentsFromMessage($message)
{
    if ($message instanceof EntityIndexingMessage) {
        $data = $message->getData();

        if (is_array($data)) {
            return ['data' => implode(',', $data)];
        }
    } else if ($message instanceof ScheduledTask) {
        return ['taskId' => $message->getTaskId()];
    } else if ($message instanceof DeleteImportExportFile ||
              $message instanceof DeleteFileMessage) {
       return ['files' => implode(',', array_map(
           function ($f) { return basename($f); },
           $message->getFiles())
       )];
    } else if ($message instanceof GenerateThumbnailsMessage) {
       return ['mediaIds' => implode(',', $message->getMediaIds())];
    } else if ($message instanceof WarmUpMessage) {
       return [
           'route' => $message->getRoute(),
           'domain' => $message->getDomain(), 
           'cache_id' => $message->getCacheId()
       ];
    }

    return [];
}

When you add your own messages to Shopware, you should extend this method to add arguments to your tasks as well for the log file.

You can find the full code of the TaskLoggingMiddleware in this Gist. We are working to turn this into a Composer package in the near future.

Combining this with Tideways, you can even get aggregated performance insights and profiling for Message Queue on top using the “tideways/symfony-messenger-middleware” package.

Related content:

Tideways 2021.2 Release

This quarterly release of Tideways includes External HTTP Monitoring, Observations about PHP Metrics and Application Configuration, a redesigned Callgraph Compare screen, the ability to name traces, a new GitHub app to synchronize users into an organization and many other features.

Update to PHP Extension 5.4 and Daemon 1.7 to access all new features of this release.

In this blog post we will provide a detailed overview of all the changes. We have also recorded a webinar that summarizes and shows all these features if you prefer video.

We also made a decision not to use the seasons for naming releases as Summer/Winter can mean something entirely different depending on your hemisphere. Instead we will now number our quarterly releases with the year as a prefix, starting with 2021.2 for this release.

External HTTP Monitoring

Almost every application needs to integrate with one or many other applications through HTTP-based APIs. These integrations are often the cause of failures and slowdowns and deserve thorough monitoring. 

Tideways now supports this with a minute by minute monitoring of every external HTTP host that your application communicates with, recording typical average response times and problem response times and the failure rate of HTTP 500+ requests in proportion to successful requests.

Each HTTP host can be viewed in detail where a list of all traces calling the host are listed in every plan. In the pro plan Tideways also tracks the performance of requests to the external HTTP host over time.

For HTTP Hosts that are monitored by a Service within the same Tideways project you can manually link them to each other through the Services Settings page by linking the primary hostname. The UI then allows to simply switch from HTTP Monitoring directly to the service.

Observing PHP and Application Metrics

Performance does not solely depend on code and databases, but also on PHP and Application configuration and metrics. The most important configuration values for PHP are OPcache related and for many frameworks there are important configuration options that influence performance.

Starting with this release Tideways will observe PHP configuration and runtime metrics as well as known application configuration options that affect performance and make Observations about them.

You’ll find the observations module under “Issues” then “Observations” in the Tideways UI and it will show you all observations in either error, warning or pass state. 

For now the observations are related to OPcache, Realpath Cache, Timeouts and other core PHP metrics. A handful of Shopware 5 and 6 specific observations start our work on application specific observations for now. Each observation provides information about cause and remedy including a detailed documentation page with explanations. Here you an see an application that has the OPCache Interned strings setting configured too low:

Compare Callgraph Redesign

Last year we completely redesigned the callgraph screen to provide a unified UI with better navigation and more information on a single screen. When comparing two callgraphs with each other it now uses the same unified UI.

Start with visiting a trace with callgraph that you want to compare to another. The navigation contains a link to “Compare”. Select the trace to compare with the current trace and the following screen will show the “Callgraph” compare.

There is also the familiar callgraph view that now shows a diff of the two compared callgraphs:

Give Traces Names

To better aid the performance optimization process you can now give traces a name that describes them and helps you to organize them for reference and comparison.

Click on the “Edit” button next to the transaction name of a trace and enter a name or description of what the trace represents for you.

You can find a list of all the traces you named on the “Traces” “History” screen.

Retry failed data collection requests from Daemon

Starting from version 1.7 of the daemon package, failed network requests with monitoring and profiling payloads for the backend are now retried for a few times instead of dropped immediately. This prevents the occasional one minute drop of data that was happening before, because of network problems and will help with the rare cases where the backend suffers from a downtime.

The retry mechanism works with two failsaves: It only stores up to 50 MB of payloads in memory and retries to send them for a maximum of 5 times in intervals of 60 seconds.

Symfony Messenger and Shopware 6 Worker Integration

While Tideways already supports instrumenting worker queues written in PHP, they currently need custom instrumentation of the processing loop to start and stop individual traces for each processed job/task.

If you are using Symfony Messenger or Shopware 6 worker queues then you can now use our Composer package instead, that makes this instrumentation quick to setup and integrate in your application.

GitHub App to synchronize Users into Teams

Tideways already allowed you to synchronize users from GitHub teams into an organization using their OAuth authentication. But since their OAuth tokens are tied to single users and not to a GitHub organization, this required the user that set up the synchronization to stay a GitHub admin to keep the synchronization working.

We have now migrated to a GitHub app that provides the team synchronization features. You can install the GitHub app between your GitHub and Tideways organizations through the “Integrations” admin screen in Tideways.

Afterwards you can create new teams and link them with a GitHub team in your organization.

Documentation: Synchronize Github Teams

PHP 8 and JIT Support

While Tideways already supported PHP 8 since its release in December 2020, it did not yet work in conjunction with the JIT. We have now rectified this by using the new Zend Observer API which supports both Profiling and JIT to work in combination. As a side effect it should reduce the overhead of Tideways on PHP 8 even more than with the previous profiling hooks that we used.

New Features and Changes in Profiler PHP Extension

The Profiling PHP Extension got new instrumentation since the last release that will collect new or more detailed information in the Timeline and Callgraph Profilers:

  • Magento 1: Added automatic transaction detection for SOAP and REST API
  • Shopware 5: Detect HtmlMinCompressor::minify in Timeline Profiler as common source for bottleneck
  • Laravel: Added Blade template names as tags to nodes in the Callgraph
  • Zend Framework/Laminas: Added template names as tags to nodes in the Callgraph
  • Improved cURL Multi Instrumentation to work when curl_multi_remove_handle is not used.

Additional changes in the extension include:

  • New INI setting tideways.traces_max_seconds that defaults to 60 seconds. Traces running for longer than this threshold will stop collecting timeline data as viewing very long traces that take longer in most cases adds no new information that cannot already be seen in the first 60 seconds.
  • Runtime metrics of PHP about Opcache and others are exported to the daemon in intervals of 60 seconds. This can be disabled by setting tideways.features.stats=0
  • Better Process / SAPI Information about FPM is sent to daemon, so that Tideways can detect multiple PHP-FPM pools and correctly see runtime metrics for each of them.
  • All HTTP requests are always monitored to allow the new HTTP monitoring feature to observe 100% of all HTTP calls. You can disable this to only observe HTTP calls made in sampled traces by setting tideways.features.monitor_http=0

That is everything for now. If you want to see some of these new features in action you can view a recording of our webinar about all these features.

Innocent looking array_unique – 2 Stories of performance hogs in Shopware 6 and Tideways own backend code base

This post tells a story of a performance mistake that is quickly made even by experienced developers: The expectation that a built-in PHP function has better performance than a better suited data structure written in PHP.

The protagonist in these stories is array_unique, a function that takes a list of values and removes duplicate entries to return a list of each value occurring only once.

Take these two code examples, the first from Shopware 6.3:

$this->tags = array_unique(array_merge($this->tags, array_values($tags)));

The second one from our own Tideways backend code:

$versions[$row['version']]['organizations'][] = $row['organization_id'];
$versions[$row['version']]['unique'] = count(array_unique(
    $versions[$row['version']]['organizations']
));

On a first glance these snippets look innocent: append new values to an array and then make sure they aren’t duplicates of previously known values by applying array_unique.

With the help of Tideways Profiler, we found both are executed in loops and perform the unique operation many thousands of times.

The algorithmic complexity of array_unique was improved in PHP 7.2, but it is still “just” O(n), meaning for larger arrays the operation can take a while. Here is the code of array_unique translated to how it would look like in PHP:

function array_unique(array $values) {
    $seen = [];
    $uniqueValues = [];
    
    foreach ($values as $value) {
        if (!isset($seen[$value])) {
            $uniqueValues[] = $value;
            $seen[$value] = true;
        }
    }
    
    return $uniqueValues;
}

This is an efficient enough algorithm, but only if you don’t repeatedly do the operation over and over again. There are two solutions to this performance problem:

  • Calculate array_unique only once at the end of the loop, while appending duplicates to the array during the loop. This strategy is simple, but might cause memory problems if the array is very large or the elements are long strings.
  • Incrementally calculate uniqueness by keeping the array of $seen values around over all merges of new elements.

The second solution is easy to implement with PHP Arrays by storing the values as keys and not appending them as values. Technically this means using the $seen array from the code example as data structure:

Both code examples from the beginning of the post can be rewritten by storing the values as array keys:

foreach ($tags as $tag) {
     $this->tags[$tag] = true;
}

The list of unique tags is then fetched using array_keys($this->tags) later. We found that this change was already made from Shopware 6.3 to 6.4 in the following commit.
We rewrote our own Tideways backend code to make use of the same approach, using array keys:

$versions[$row['version']]['organizations'][$row['organization_id']] = true;
$versions[$row['version']]['unique'] = count(
    $versions[$row['version']]['organizations']
);

This benefits from using the O(1) complexity of adding an element to an array (hashmap) and array_unique is not needed anymore.

Looking at a comparison of both optimizations in Tideways Callgraph Profiler shows how massive the gains are for these changes.

In Shopware 6.3, we replaced the old CacheTagCollection code with the code from 6.4 and the performance improved from 7,3 minutes to 51 seconds for the Product Export, an improvement of 88% of which 4,08 minutes (54%) can be attributed to the removal of array_unique and another 40 seconds to the use of array_merge in the same line. Conclusion: Upgrade to Shopware 6.4!

In the case of Tidways own backend code, removing array_unique reduces 925ms from the original request that takes 1,87 seconds, a rough 50% improvement.

And here is the moral of our story: array_unique should generally be called for any array only once, not over and over again.

Intrigued by PHP performance story-telling? We are currently looking for a Developer Advocate to write about bottlenecks just like this.

What’s new? Winter Release 2021

Winter is clearly over here, the sun is shining, which means it is time to sum up everything that is new in the Tideways Winter 2021 release.

  • HTTP Status Code Monitoring
  • Deployments UI
  • Incidents UI
  • Improvements to Error/Exception Workflow
  • Filtering by Custom Annotations in Traces List
  • Improvements to Autoloading Layer Computation
  • PHPStorm IDE Stubs
  • Dialog to change Billing E-Mail Addresses

Aside from this blog post explaining the new features in detail and the documentation, we also recorded the 34 minute webinar about the release:

Tideways Winter Season 2021 Release Webinar

HTTP Status Code Monitoring

To complement the requests and errors counters in monitoring, Tideways now also tracks the HTTP status codes that an application responds with. This will enable a better understanding of the type of traffic that might cause a change in performance.

The common client and server error codes are tracked individually and other codes are grouped into 100s, 200s, 300s, 400s and 500s.

See the documentation for details

Deployments UI

In addition to viewing deployment comparisons from notifications or from the markers on the monitoring chart there is now a list of all deployments under “Issues” and then select “Deployments”.

Incidents UI

In addition to viewing incidents from notifications or markers on the monitoring chart there is now a list of all incidents triggered by response time or error rate notifications under “Issues” and then select “Incidents”.

Improvements to Errors/Exception Workflow

The workflow options for each error or exception have been rephrased to be more clear.

You now “Ignore” an exception from error notifications and prevent the errors from being counted towards the global “Errors” number in monitoring. Previously this workflow operation was called “Not Error”.

This is done based on the fingerprint of the error/exception, which is computed based on the class name of the error and its stacktrace.

You can then strengthen to “Always Ignore” to ignore exceptions based on their class name only, regardless of where the error occurs in terms of stacktrace.

Lastly, ignored errors and exceptions are not filtered on the daemon anymore, so that you can still see when and how often an ignored error occurred.

See the documentation for details

Filtering by Custom Annotations in Traces List

The advanced query syntax for trace filtering now allows for conditions on custom metadata annotations that are added to a trace.

If you add a custom annotation “user_id” to every trace then a query could look like this:

annotations.user_id = '100' 

Additionally, we improved the error handling for invalid syntax, including better error messages shown in the UI.

The documentation on the advanced query syntax has gotten an update as well to show all options and examples.

Improvements to Autoloading Layer Computation

In last season’s release, Autoloading was added to the downstream layers in monitoring. We made a conceptual mistake where autoloading included File I/O and compile time that was seperately counted already, effectively counting this information twice. This is now fixed and in downstream layers the autoloading timer counts the duration autoloading spent in everything except File I/O and Compiliation.

PHPStorm IDE Stubs

When working with the Tideways PHP Extension API, IDEs cannot usually provide autocomplete details. With the IDE Stub Composer package added to a project autocomplete information becomes available.

Just require the package to load the stub code into your projects vendor dependencies:

composer require --dev tideways/ext-tideways-stubs 

See the documentation for details

Dialog to change Billing E-Mail Addresses

In the billing administration it is now possible to change the billing e-mail address as a self-service operation, including adding additional billing e-mail recipients.

See the documentation for details

Photo by Jean-Daniel Calame on Unsplash

Autumn Launch: PHP 8, Autoloading Performance, Deprecation Tracking, Alerting Improvements

This autumn launch for Tideways includes new features and improvements that we worked on the last three months. These are (in no particular order):

  • Add support for PHP 8.0 and announce deprecation of PHP 5 support
  • Autoloading Performance in Layer Monitoring and Profiler
  • Deprecation Tracking
  • Improvements to Alerting: Filter for Service/Environments
  • Weekly Report: Make included services in weekly e-mail configurable
  • Add new “All” Services Filter-Option in Traces and Issues List
  • APCu Performance in Layer Monitoring and Profiler
  • New Apt and RPM Package Repository and Migration Timeline

Aside from this blog post explaining the new features in detail and the documentation, we also invite you to view the recording of our 30 minute webinar “New Features and Improvements launched in autumn 2020” scheduled for 25th November 2020, 15:00 Europe/Berlin.

Tideways Autumn 2020 Launch Webinar

To benefit from all these changes you need to upgrade your Tideways PHP Extension to version 5.3.4 and Tideways Daemon to version 1.6.24.

PHP 8 Support and PHP 5 Deprecation

The latest Tideways PHP extension version 5.3.4 (released today) includes support for the upcoming PHP 8.0 version, that will be released next week (November 26th 2020), and it includes support for the new Observer API for profiling right from the start.

In addition we are announcing to deprecate support for Tideways on all PHP 5 versions. All our release packages for Tideways will continue to include PHP 5 builds of Tideways, but only of the Tideways branch 5.2 (latest release as of today is 5.2.6). If necessary we will update PHP 5 builds with important bugfixes or security patches, but new features are not targeted for PHP 5 anymore.

Autoloading Performance

PHPs autoloading has a significant impact on performance of applications that you should be aware of. With this newest release of Tideways, we now track the autoloading performance impact in both monitoring and profiling. This means you can see the average time spent in autoloading aggregated by every minute in the layer tooltip:

And in the summary section of every collected trace:

As was the case before, you can then dive into a Callgraph to see where exactly time is spent during autoloading:

Deprecation Tracking

Tracking deprecations triggered in your PHP applications is now possible using Tideways. This hooks into PHPs E_USER_DEPRECATED and E_DEPRECATED error levels, collects and aggregates deprecations and shows them as a new issue type in the “Issues” screen of your Tideways projects.

With this feature it is easy to get an overview of all deprecations in PHP core or libraries that your application is causing, so that you can update the syntax and APIs before upgrading your dependencies.

Alerting Improvements: Fine-Grained Service and Environment Filters

Instead of having to select exactly one service and environment, configuration for notifications is now more flexible, allowing fine-grained control which services and environments should be included when checking for incident conditions.

This is achieved by adding a free-form filter syntax:

  • Using the star (*) is a wildcard matching all services or environments
  • Using the service or environment by name includes them in the notification checks
  • Prefixing a service or environment with ! excludes them from being checked.

Examples: “web worker” or “* !cli”

See the documentation for details

Include More Services in Weekly Report

Before this release, only the default service of a project was included in the weekly report e-mail. You can now configure which services to include and exclude from the weekly report on the “Services” configuration screen.

See the documentation for details

APCu Layer in Monitoring and Profiling

Usage of APCu is now tracked as a seperate layer in monitoring and profiling of Tideways. This gives you an average time spent in APCu and concrete times for individual traces.

View Traces and Issues from All Services

Previously you could only view traces and issues from one service of a project at a time. We have now added an option to show traces and issues from “All” services on a single screen.

New Package Repository

Our Debian and CentOS (RPM) package repositories have always been served directly from AWS S3 using open-source publishing tools and custom tools that we have added on top. To increase automation, convenience and security on our end, we recently migrated package publishing to Bintray, but are still mirroring packages from there to the old S3.

For now nothing has to change for you, but at the end of 2021 we will stop publishng to the S3 repository. Until then, you should perform these two steps:

  1. Trust our new GPG key for the [email protected] e-mail address
  2. Change the URL for package updating from the AWS S3 to the Bintray endpoint.

See more details in the documentation

Photo by Jeremy Thomas on Unsplash

Summer Release: Slow SQL Query Log, Callgraph Profiler, Memory Tracepoints

This Summer Release of Tideways builds on the previous Beta Announcements in May’s Spring Release and marks the general availability of

  • Slow SQL Query Log
  • Unified Callgraph UI
  • Events and Templates in Callgraph Profiler
  • Memory Tracepoints

This new functionality is fully available by updating the Tideways PHP Extension to version 5.2.4 and the Daemon to version 1.6.18.

In addition to rolling out new features, we also renamed the concept of “Application” in Tideways to “Project” and we provide a detailed explanation why at the end of this post.

Slow SQL Query Log

One major source of performance bottlenecks in PHP applications are slow SQL queries for a variety of reasons: Not using indexes, using the wrong index, using temporary tables and much more.

Tideways new Slow SQL Query Log provides a classic database slow query log with the application context to quickly identify and fix the faulty query:

  • Transaction, Controller and Action Names
  • URL and further information from the HTTP request context
  • Stacktrace with all functions

The Slow SQL Query log is using the same UI and workflows that Errors/Exceptions are and both are now grouped under a new main navigation module called “Issues”.

You can configure alerts to be sent when new Slow SQL queries occur in your application.

Unified Callgraph UI

The “Calls” and “Callgraph” tabs in Tideways Profiler have been merged into a single screen to improve the insights into your profiling data. This is the most significant change to the Callgraph UI in over three years. Previously with both separated it often happened that while stepping through callgraph data, you lost the context when switching between both views.

Both calls table and callgraph data is now shown on a single screen and completely synchronized. We achieved this by making use of the full width of the screen and without loosing information that was previously shown.

This change was carefully done with a lot of users feedback and our own tests.

Now that the new Callgraph UI is live for everyone, we are still looking for your feedback: Does it improve or deteriorate your experience with the Callgraph data?

Events and Templates in Callgraph Profiler

A central problem of the Callgraph Profiler until now has been that every function was only present once, with all outgoing and incoming children and parents pointing to it. For applications using centralized Event and Template libraries this makes it harder to find the root cause of a performance problem.

From PHP Extension 5.2 on function nodes in the Callgraph can be split up by a “tag”. This is represented in the UI by adding an argument to the function node with the name of an Event or Template for example.

See this example for a Symfony EventDispatcher function call.

Previously this would be shown as just a single entry in the Calls table and it would be difficult to find out which event is responsible for which share of the EventDispatchers performamce.

Memory Tracepoints

In the Winter release this year we shipped Tracepoints to give you a powerful tool to select the Traces you are interested in. We supplemented this with the Callgraph Tracepoint feature in Spring. Tracepoints so far have focussed on response time as filter criterion.

Starting with Tideways Daemon 1.6.18 you can now change the filter criterion to be memory usage of a trace. This is helpful to get traces including callgraphs for requests that are using excessive amounts of memory.

Renaming Tideways Concept “Application” to “Project”

Since the beginning Tideways used the name “Application” in the UI to represent what is better called a “Project”. The reason we think this name change is necessary can be explained by contrasting different project types.

For Tideways it does not matter if you have a monolithic applications with a single codebase, a few applications composed together or microservice architectures with many small applications. If they belong together they compose a “Project” that should be monitored and profiled together.

We have seen users create multiple Tideways applications, when a single one would provide the same insights. We hope the use of “Project” makes it clearer which applications and services should be grouped together in Tideways and which should be separated.

Every project can be grouped into individual units by the following dimensions:

  • Services should be used to view the project from different perspectives: Different user groups interacting with a monolith application or different microservices.
  • Environments should be used to split the project into their installations or deployments: Production, Multiple Production Instances by Region, Staging, Acceptance and Development.

Spring Release: Tracepoints, Callgraphs, Slow SQL Log and Deprecations

We are releasing a new stable minor version of the Tideways PHP extension 5.1 today, which will include a few new features that we have been writing about before and a few new ones that we have cooked up in the last few weeks.

The following packages have received updates:

  • tideways-php to version 5.1.14
  • tieways-daemon to version 1.6.10
  • tideways-proxy to version 0.1.34

Using Tracepoints to Trigger Callgraphs

We have written about trace boosting with Tracepoints a few times before. Now we have tested the dynamic callgraph tracepoints feature in great depth and are ready to release a stable version of it. In the Tracepoint form, you can now click the “Activate Callgraph Profiler” checkbox and select how long the Tideways PHP extension should be elevated to Callgraph Profiler mode:

Once the tracepoint is activated the collected callgraphs are highlighted separately from regular timeline traces in the UI:

By default, dynamic tracepoints is still deactivated, but there are just a few PHP.ini settings explained in this documentation page to get it running.

Automated Builds for Alpine, ARM and FreeBSD

You can now use Tideways with Alpine Linux (musl), ARM architecture and the FreeBSD operating system, as we have automated builds for these systems and they are now listed on the Downloads page. Builds for these systems are now fully automated and artifacts are released at the same time as the already supported operating systems and architectures are released.

In addition we have stopped building packages for i386 architectures as our logs indicate that nobody is using them.

In Beta now: Slow SQL Query Logging

Tideways now collects slow SQL queries from your application very similar to the MySQL slow log functionality, but enhanced with a PHP stack trace, transaction name and other context information. Slow queries are aggregated and de-duplicated similarly to exceptions and presented in a similar user interface:

This feature is available for beta testers with the PHP extension 5.1 installed. Please write to [email protected] if you want to be part of the beta test and see the documentation how to activate it.

In Beta now: Unified Callgraph Screen

We have but a lot of work into a prototype to merge the “Calls” and “Callgraph” tab in a single unified screen. The benefit here is that you don’t have to force reloads of the UI when switching between those two modes. The tricky thing about this new screen is that we have to make use of the full screen, and adjust elements on the screen much more to different display sizes.

For this change we are dependent on feedback from you, so we have published this beta early. This beta feature does not need to be enabled for you directly, it is available to everyone.

In Beta soon: Deprecations

Reusing the already familiar Error/Exception Tracking feature we have added Deprecation Tracking as another feature to Tideways. If you enable tideways.features.deprecations=1 in the new PHP extension 5.1, we will collect the following deprecations triggered in your PHP application:

  • trigger_error with E_DEPRECATED or E_USER_DEPRECATED, even if error_reporting is not enabled for these error types.
  • Engine deprecations triggered by using a deprecated feature of PHP itself, but only if userland error handlers don’t interfere with this. This is a restriction of the PHP engine itself and we are actively working to improve this for the upcoming PHP 8.

This feature is available for beta testers with the PHP extension 5.1 installed. Please write to [email protected] if you want to be part of the beta test.

Five Challenges for Running Reliable PHP Background Processes

BONUS: We have discussed this topic with an expert in the PHP community in our podcast:

PHP isn’t typically thought of as a solution when creating worker or background processes, jobs that typically can last for an extended period. These can be tasks such as image processing, file repair, and mass email batch jobs.

Typically, PHP is linked with HTTP requests, requests which are short in duration and stateless in nature. However, just because of this enduring association, it doesn’t mean that PHP can’t be used for background processes. On the contrary.

If you’re considering developing background processes in PHP, then this post is for you. I’m going to step you through five points that you need to keep in mind. Hopefully, by the end, you’ll have less stress and effort as a result.

Use Angel Processes

Background jobs can die.

They can die for many reasons, including out of memory exceptions, connection errors, as well as a number of other conditions. Given that this could happen and to avoid manual intervention to restart the job, it’s helpful to make use of an angel process.

An angel process offers three key advantages:

  • Can start a job, if it’s not already started
  • Can restart a failed job
  • Provides debugging and logging capabilities. For example, Supervisor and Systemctl can centralize job logging and show a job’s status and history.

The angel process isn’t responsible for anything else. Consequently, the logic should be quite rudimentary, and its load should be quite light at any given time. However, there are a couple of conditions that you need to be aware of, when writing them.

Handle Failed Jobs

No matter what language you write your jobs in, you have to know when they fail and be able to restart them when they do. PHP is no exception.

So, how do you do this? You could roll your own solution, such as a shell script, but there are many existing solutions already available. As a result, you should never need to write your own.

Here is a selection of them, delimited by operating system:

Package Description Operating System
Supervisor Available for UNIX/Linux systems, Supervisor provides a simple, centralized, efficient, and extensible approach to controlling many processes. It’s been tested on Linux, Mac OS X, Solaris, and FreeBSD. You may be able to use it on Windows in combination with Cygwin.
Systemd Available for UNIX/Linux systems, systemd was designed as a replacement for UNIX System V and the BSD init system. Initially developed at Red Hat, it includes features such as on-demand starting of daemons, snapshot support, and process tracking. Linux
Gearman To quote the official documentation, it: ” provides a generic application framework to farm out work to other machines or processes that are better suited to do the work.” Written in C, it’s available for Linux and Windows.
The Windows Service Control Manager It provides functionality similar to Supervisor and Systemd for Windows servers. Windows

For more information about supervisord, check out this post on Servers for Hackers. And for more information on Gearman and PHP, check out this post by Matthew Weier O’Phinney. If you’re considering using Gearman, be aware that it requires an angel process for its own workers. It’s too much to cover in this post, however I just wanted you to be aware of this fact.

Monitor Background Jobs

As background jobs can last for quite some time, it’s helpful to be able to inspect their state when required. There’s often nothing worse than knowing that a job is still active, yet to have no information about how much or how little progress its made, how long it takes to complete, and any problems that it has encountered during processing.

Given that, it’s handy, though arguably not essential, to have some form of monitoring available. This could be something quite rudimentary, such as printing out a list of the currently active jobs, their start time, expected completion time, and the number of failures that they have encountered to the terminal.

The output might look like the following from Supervisor:

$ sudo supervisorctl status alertActionWorker:alertActionWorker00                 RUNNING   pid 2349, uptime 0:01:35 createErrorWorker:createErrorWorker00                 RUNNING   pid 2345, uptime 0:01:35 createProfileWorker:createProfileWorker00             RUNNING   pid 2346, uptime 0:01:35 notificationWorker:notificationWorker00               RUNNING   pid 2350, uptime 0:01:35 recordMeasurementsWorker:recordMeasurementsWorker00   RUNNING   pid 2339, uptime 0:01:35 

It could also go as far as a comprehensive dashboard, such as the monitoring in Tideways:

Tideways Background Jobs MonitoringTideways Background Jobs Monitoring

Whichever way you go, ensure that your job is storing some form of statistical information that can be periodically polled and collated.

Many vendors provide built-in functionality to store this information, such as Microsoft’s Azure platform. Alternatively, you can store your own in one of the open-source databases, such as PostgreSQL, MySQL, or SQLite.

Tune Memory Usage and Restart Jobs Periodically

PHP wasn’t designed with long-running processes and tasks in mind. It was designed for shorter tasks based around the nature of an HTTP request. As such, long-running tasks can be problematic, mostly because of memory consumption.

There are a couple of things that you can do to help reduce memory consumption. These include:

  • Garbage Collection Analysis: Performing garbage collection analysis to help identify how your worker process uses variables and how PHP’s garbage collector interacts with your script.
  • Avoid Global and Class Static Variables.
  • Use cursor-like behavior for iterating over information, such as arrays, lists, and collections. By doing this, only a limited amount of memory is used at any one time.

By doing these three things, the likelihood of writing code that leaks memory is reduced, which in turn reduces the likelihood of needing to kill a process arbitrarily.

Implement Exponential Backoff When Auto Restarting

Long-running jobs will inevitably encounter some form of network collision or outages that temporarily prevent them from continuing to execute. These can be caused by too many users being active at one point in time, one or more servers or network devices between the client and the end server being down, or even something as drastic as a DDOS attack.

The question is, what to do when these occur? One common approach is to implement Exponential Backoff in your application. Exponential Backoff is a way of spacing out repeated worker restarts for longer intervals until either:

  1. A maximum number of retries is reached.
  2. A maximum backoff time is reached.

It’s important to note that the time between the restarts is a random interval, up to a maximum defined value. Because value is random, it helps avoid the possibility that another background process may choose the same interval and begin executing at the same time as the current client, resulting in the same outage occurring.

The net effect of implementing an Exponential Backoff algorithm is that processes:

  1. Can eventually complete successfully while not colliding with other processes.
  2. Avoid creating excessive server load.

Conclusion

That’s been a broad introduction to five challenges which PHP developers face when developing worker (background) processes. While not extensive, it’s provided an excellent introduction to them with the hope that these challenges can be avoided in the applications that you and your team are developing.