Patrick McLain

Fun With MongoDB Atlas Analytics Nodes

2022-09-28T11:00:00+00:00

Fun With MongoDB Atlas Analytics Nodes

Our data teams maintain a few workflows where application data is fetched from our operational APIs. This is generally done for a handful of applications touching multiple datasets and applying business logic without any materialized view of the resulting data. This is a separate issues we are addressing, so I won’t rant about it further.

Initially the data team was calling the same services and deployments as our end-users and this worked… until it didn’t. As you can imagine, one day the competing requests between users and data exhausted resources and our service performance was degraded. The quick fix was creating a separate deployment of these services in our kubernetes cluster connected to analytics nodes in MongoDB Atlas for workload isolation.

Use analytics nodes to isolate queries which you do not wish to contend with your operational workload. Analytics nodes help handle data analysis operations, such as reporting queries from BI Connector for Atlas. Analytics nodes have distinct replica set tags which allow you to direct queries to desired regions.

Analytics Nodes for Workload Isolation

With the isolated deployments above our requests have a read preference for the secondary MongoDB node and can read from the primary node if the secondary is unavailable. The data lake requests are routed to a separate deployment of the same service connected to an analytics node. This accomplished in the application connections string by specifying the readPreference and readPreferenceTags.

Operational Services

readPreference=secondaryPreferred&readPreferenceTags=workloadType:OPERATIONAL

Data Feed Services

readPreference=secondaryPreferred&readPreferenceTags=nodeType:ANALYTICS

Those familiar with the documentation of the secondaryPreferred read preference have probably already noticed our error. Unfortunately, we were not. This solved our issues, and we were serving requests for users and data feeds without issues for months.

One day we noticed a typo in our data feed connection string our feed deployments had not been reading from our analytics nodes. They were instead reading from the secondary nodes.

We fixed the connection string and felt as if we had dodged a bullet. Now our workloads were properly isolated, and we were safe.

In reality that desired behavior was not happening. As soon as the analytics node stopped responding to reads our primary node, already under heavy write load, saw an increase in read operations eventually degrading the primary node’s performance and promoting the secondary node as the primary. During this period our user facing services would degrade as read performance suffered. Why would this happen? We thought this risk was mitigated by isolating the workloads.

Analytics nodes are located in the same shard as the primary and secondary nodes. The secondary node has higher priority resource access than the analytics nodes. This makes sense, keeping the replication lag as low as possible on the secondary and protecting the operational workloads. This can create high replication lag for the analytics node during periods with high write throughput.

Turns out MongoDB was doing exactly what we told it to do in our feed deployment connection string.

When the read preference includes a tag set list (an array of tag sets), the client attempts to find secondary members with matching tags (trying the tag sets in order until a match is found). If matching secondaries are found, the client selects a random secondary from the nearest group of matching secondaries. If no secondaries have matching tags, the client ignores tags and reads from the primary.

secondaryPreferred read preference

Using the readPreference=secondaryPreferred read preference with readPreferenceTags=nodeType:ANALYTICS we were instructing MongoDB to read from the primary node when the analytics nodes were unavailable. We had not fully isolated the workflow. We had actually linked the feed services to our primary operation node by mistake.

We actually wanted the behavior of readPreference=secondary.

Operations read only from the secondary members of the set. If no secondaries are available, then this read operation produces an error or exception.

secondary read preference

Changing the read preference from secondaryPreferred to secondary on our feed deployment connection strings matched our intention and restored stability to our user facing services.

TLDR; sometimes you have to RTFM

Mind the Gap (Lies from the APM)

2021-08-28T11:00:00+00:00

Mind the Gap (Lies from the APM)

I was troubleshooting reports of slowness in a headless Magento 2 implementation. We had evidence some customer cart interactions were responding in 2+ minutes and often with a 500 status. The first place I generally start looking is the APM. Much to my surprise the p99 response time for our application instances rarely exceeded 3 seconds. There was no indication that responses where taking multiple minutes.

The application instances sit behind a load balancer, so we decided looked at the p99 response time for the load balancer targets. The p99 reported by the load balancer matched what we were seeing when reproducing with user reports. Interestingly, there was no correlation between the loadbalancer p99 and application p99. In fact there was a HUGE gap.

As a developer, this is the point where I stop looking at the application code and start looking at the infrastructure. The APM doesn’t show the application being slow. Digging into server logs we noticed php-fpm was routinely hitting the pm.max_children limit on all instances. The obvious quick fix was spinning up more instances increasing the available php-fpm processes. We stopped seeing warnings about hitting the process limit, but the gap in response time between the loadbalancer and application didn’t move.

The next step was looking for patterns in the slow responses hiding the load balancer logs. Since this was an AWS ALB we could query the logs from S3 easily using Athena. Honestly this is probably where the investigation should have started. It was painfully clear there were a couple Magento API endpoints creating our troubles and all of them cart related. This is worst case scenario working in ecommerce where rule #1 is “Don’t break checkout”.

We confirmed the issue application related and critical. We started noticing E_ERROR: Allowed memory size of 792723456 bytes exhausted (tried to allocate 16384 bytes) in the error log with a truncated traces, but stemming from quote load and total collection. At this point we knew:

The slow requests primarily happened for POST /V1/carts/mine and GET /V1/carts/mine/items.
The APM reported no issues for these transactions.
Memory was exhausting during when loading some quotes.
Once the error started for a user it was reproducible for every request using the customer token.

At this point my working theory was a rouge loop with a certain quote state would loop infinitely until exhausting available memory. I knew it was very likely the PHP module responsible for APM reporting will not send data if the process exits abruptly. Next I cloned a couple carts to my local environment until the issue reproduced and started stepping through with Xdebug.

Eventually I found a plugin in Klaviyo’s Magento 2 module causing the infinite loop when a quote has a coupon code and requires a recollection triggered by an admin saving one of the quote products or an applicable catalog rule. When these two things happen the plugin triggers recursively and cart becomes unusable. I opened a bug on the repo and wrote a quick plugin on their plugin guarding against the loop.

Dead Letter and Retry Queues for Magento 2

2021-08-23T11:00:00+00:00

Dead Letter and Retry Queues for Magento 2

Magento 2 offers out of the box support for message queues in RabbitMQ. Queueing allows sending messages to a queue for either synchronous or asynchronous consumption. This is a walk-through for creating dead letter and retry queues with Magento 2.

Check out the RabbitMQ docs for a good primer on dead lettering. The retry queue will rely on dead lettering and a default message ttl docs.

This assumes you are already familiar with queue configuration in Magento 2. Take a look at the DevDocs for a refresher.

IMPORTANT

Support for arguments during queue creation was added in Magento v2.4.2. You will need a patch for this PR for this to work on earlier versions.

The dead letter and message ttl arguments must be set during queue creation, meaning they cannot be added this to existing queues.

Desired Topology

We’re going to create three queues:

myqueue - The primary queue for publishing and consumption. Messages hit this queue and result in three possible outcomes. First, the message is processed successfully and acknowledged. Second, the message is rejected and sent to myqueue.dlq. Third, message consumption fails but the determines the message should be retry and sends it to myqueue.retry.
myqueue.dlq - This is the dead letter queue where rejected messages are sent. Nothing consumes this queue, it’s primary purpose is for monitoring and logging.
myqueue.retry - Queue where messages are held awaiting retry. Nothing consumes this queue directly. Instead, messages on the queue have a ttl and are left until ttl expiration. Then the message is dead-lettered to myqueue for consumption.

Below is what this topology would look like in your module’s etc/queue_topology.xml.

<?xml version="1.0"?>
<config xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:noNamespaceSchemaLocation="urn:magento:framework-message-queue:etc/topology.xsd">
    <exchange name="myqueue.exchange" type="topic" connection="amqp">
        <binding id="myqueue.binding" topic="myqueue.topic" destinationType="queue" destination="myqueue">
            <arguments>
                <argument name="x-dead-letter-exchange" xsi:type="string">myqueue.exchange</argument>
                <argument name="x-dead-letter-routing-key" xsi:type="string">myqueue.topic.dlq</argument>
            </arguments>
        </binding>
        <binding id="myqueue.binding.dlq" topic="myqueue.topic.dlq" destinationType="queue" destination="myqueue.dlq"/>
        <binding id="myqueue.binding.retry" topic="myqueue.topic.retry" destinationType="queue" destination="myqueue.retry">
            <arguments>
                <argument name="x-dead-letter-exchange" xsi:type="string">myqueue.exchange</argument>
                <argument name="x-dead-letter-routing-key" xsi:type="string">myqueue.topic</argument>
                <argument name="x-message-ttl" xsi:type="number">60000</argument>
            </arguments>
        </binding>
    </exchange>
</config>

Except… When you run setup:upgrade you’ll see errors in the logs when creating myqueue.retry.

AMQP topology installation failed: PRECONDITION_FAILED - invalid arg ‘x-message-ttl’ for queue ‘myqueue.retry’ in vhost ‘/’: {unacceptable_type,longstr}

I didn’t dig too deep into this. On the surface it appears the xsi:type of the argument is not translating to the argument type when reading the configs. My admittedly “hacky” solution for this is an after plugin when getting the topology.

etc/di.xml

<?xml version="1.0" ?>
<config xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:noNamespaceSchemaLocation="urn:magento:framework:ObjectManager/etc/config.xsd">
    <type name="Magento\Framework\MessageQueue\Topology\Config\Data">
        <plugin name="vendor_message_queue_topology_config" type="Vendor\MessageQueue\Plugin\Topology\Config\Data"/>
    </type>
</config>

Plugin/Topology/Config/Data.php

<?php
declare(strict_types=1);

namespace Vendor\MessageQueue\Plugin\Topology\Config;

class Data
{
    private const ARGUMENTS_TYPES = [
        'x-message-ttl' => self::TYPE_INT,
    ];

    private const TYPE_INT = 'int';

    /**
     * @param \Magento\Framework\MessageQueue\Topology\Config\Data $subject
     * @param array|mixed|null $result
     * @return array|mixed|null
     */
    public function afterGet(
        \Magento\Framework\MessageQueue\Topology\Config\Data $subject,
        $result
    ) {
        if (!is_array($result)) {
            return $result;
        }

        foreach ($result as $exchangeKey => $exchangeConfig) {
            if ($exchangeConfig['connection'] !== 'amqp') {
                continue;
            }

            foreach ($exchangeConfig['bindings'] as $bindingKey => $binding) {
                foreach ($binding['arguments'] ?? [] as $argument => $value) {
                    if (isset(self::ARGUMENTS_TYPES[$argument])) {
                        $result[$exchangeKey]['bindings'][$bindingKey]['arguments'][$argument] = $this->convertType(self::ARGUMENTS_TYPES[$argument], $value);
                    }
                }
            }
        }

        return $result;
    }

    private function convertType(string $type, $value)
    {
        switch ($type) {
            case self::TYPE_INT:
                $value = (int) $value;
        }

        return $value;
    }
}

That’s it. Now if you consumer throws an error the message will be sent to the dead letter queue. You can also add logic in the consumer to handle certain errors that may justify a retry. Retry messages can be re-published using the retry topic and they will park in the retry queue until they expire.

Remember to Memoize Your Extension Attributes

2021-02-10T11:00:00+00:00

Remember to Memoize Your Extension Attributes

TLDR; If your repository is memoizing data, it’s extension attributes should probably be doing the same.

We’ve been prepping our sites for some additional traffic and part of the process has been analysing some of our database calls looking for erroneous queries. The site is based on Magento 2 Commerce with B2B.

One of the tables with the highest throughput was company_payment. A table containing the allowed payment methods for each company within our application. Strangely, when looking at the call stack all the calls were being firing after getting a company entity from the repository. This is odd because almost every M2 repository class includes memoization for reducing database requests for the same data within a request. I did see a memoization mechanism when I looked at class source.

Below is an example of the memoization method commonly used in Magento 2 for repositories.

public function get($entityId)
{
    if (!isset($this->instances[$entityId])) {
        /** @var Entity $entity */
        $entity = $this->entityFactory->create();
        $entity->load($entityId);
        if (!$entity->getId()) {
            throw NoSuchEntityException::singleField('id', $entityId);
        }
        $this->instances[$entityId] = $entity;
    }
    return $this->instances[$entityId];

I could see the throughput was more than 2x for company_payment compared to company.

The culprit was hiding in the call stack…

Company payments are added to the company entities as extension attributes. The after plugin on \Magento\Company\Api\CompanyRepositoryInterface::get does not include any memoization. Even though the repository was recycling the previously loaded object the after plugin did not, and was going back to the database with every call.

My temporary solution was adding a preference for the plugin and memoizing the payment method data per company. It’s a micro-optimization and probably a waste time, oh-well.

Our Old Friend Race Condition

2020-12-20T11:00:00+00:00

Our Old Friend Race Condition

If bugs were villains, Race Condition would be a super-villain. –toddbc

tldr; We introduced a race condition that accounted for ~30% of all throughput and didn’t even notice.

A few weeks ago we removed most of the high throughput Magento API endpoints powering our mobile applications. We have purpose built backend services that were the source of truth for the data and using Magento as the API gateway had become a bottleneck. There was a noticeable reduction in throughput on our Magento instances, but it was less than what I’d privately estimated.

I’m often wrong, but I like to understand why when I am. I began by charting throughput by route in New Relic. This showed a clear spike on throughput for the /customer/account/login route.

This raised an immediate red flag of an active brute force attack on user accounts. I then facet the chart by application, we run multiple instances of this same application, for determining which instance was under attack. Much to my surprise it was all of them! While possible, an attack spanning all instances and beginning immediately following a release didn’t seem plausible. Next stop was the access logs.

I began reviewing access logs for patterns in IP, user agent, referrer, etc… There wasn’t much insight. The IP addresses varied and had a healthy mix of ranges and there user agents appeared normal. If this was brute force attack, it wasn’t coming from an inexperienced script kiddie. There was a distinct pattern for the referrer which was almost always /customer/account.

A note about Magento and the customer dashboard. /customer/account is a protected route and requires an authenticated user. When accessed by an unauthenticated user, the application redirects you /customer/account/login. Why would an attacker access the login page via a redirect from the customer dashboard? I started doubting this was a brute force attack and began exploring the possibility that we had a bug.

If not an attack, we were likely redirecting authenticated users to the login page in error. We use Magento’s New Relic reported feature making proving this theory easy. The New Relic integration adds the customer name as a custom parameter when reporting to the APM. Running a query comparing requests for /customer/account/login with and without this parameter set was eye-opening.

We clearly have an issue in the application. Time to review the release notes.

We’ve been actively replacing Magento’s native customer account section with a React app and enabled this app replacing order history the same time this anomaly began. The traffic was coming from the account landing page and not order history. I moved on and started looking at how the React app determines user state. Determining user state is done by reaching out to an express server and this was working without issue. Digging further the app also looks for the presence of some Magento customer section data, a bit of legacy code from a very early iteration. In the absence of this data React sends the user to the login page. Could this be causing our issues?

I logged in and navigated to the account dashboard. Everything worked as expected. I then deleted Magento’s local storage cache and reloaded the page. After the page loaded, I was redirected to /customer/account/login and back to /customer/account. This infinitely repeated until I navigated back to a Magento rendered page which restored the missing data from local storage. I know had a promising hypothesis and a reproducible bug. What change surfaced this issue?

Magento’s local storage cache is populated from /customer/section/load via ajax and triggered by a number of client side events. Within this storage is user-specific data for personalizing content without busting the full page cacheability of server side rendered pages. I reviewed telemetry for /customer/section/load looking for possible issues preventing it from returning the data expected by our React app, but didn’t find anything. Getting frustrated I returned to the site and clicked around desperately trying to recreate the issue organically.

Eventually I logged in and immediately clicked the prominent order history link on the homepage. This took me to the order history page, but redirect me to /customer/account and into the infinite redirect loop. WTF! I had initially ruled out the inclusion of the React order history in my investigation, and they now looked related. Clicking the order history link on the homepage could route you to the React app before the customer section data had loaded via ajax. Prior to the React order history the only entrypoint to our React app was a link in a dropdown… that was rendered using the ajax result of /customer/section/load.

The link for order history is interactive almost immediately following the first paint and our users use it a lot! The referrer information for the order history page also indicates it the first place a user goes after login. This behavior explains why we missed this in development and QA. Our test scripts only navigate to order history following order placement. Internally we aren’t acting like customers who are logging in multiple times a day for the sole purpose of checking the status of pending orders.

The variance between our expected user journey and reality let this slip through the cracks.

The Right Data in the Wrong Place

2020-12-16T11:00:00+00:00

The Right Data in the Wrong Place

We encountered a bottleneck in a database table used for storing customer specific product and pricing details. Each of the customers on our B2B ecommerce application have contract product lists and prices. The Magento frontend pulls this data from a backend service and stores it in database.

The original structure worked well in the early days of the application when the business rules where relatively simple and traffic was low. At its inception it was basic information that could have a longer lifetime, 24hrs. The basic schema was similar to:

customer_id	product_id	price	updated_at
1	1	99.0000	2020-12-14 17:42:33

The application uses this table when building the catalog and pricing information displayed to our end-users. It was simple and got the job done. Fast forward 18 months and the business requirements and user base had grown. The table now included inventory and flag allowing backorders. This reduced the useable lifetime of the data, since we wanted the inventory information displayed as close to realtime as possible. The lower the lifetime, the higher the write throughput on the table. As throughput increased this table became a recurring source of pain and frequently overwhelmed our Azure MySql PaaS, especially during sudden spikes in traffic.

As the downtime caused by the table increased we began looking for optimizations. We started began planning how to move the data out of MySql. The initial proposal was to pull the data directly from the backend service. On the surface this made sense. We would be using real-time data on the frontend and the backend service response times were between 5-10ms. When we POC’s this approach there was one major issue… the actual response times between our application and the backend were much higher, 250-500ms. This wouldn’t work because this data is used on almost evert page load and API response. We needed stability, but not at the cost of 500ms on every response.

So WTF was the difference between service response times and what the actual time experienced by our service? Network latency. First our microservices were on a separate vnet. Second we weren’t communicating directly with the services. The traffic was routed through an Azure application gateway, then a Zuul gateway and finally to the service. All of these are fixable, but we were becoming desperate and needed the fastest workable solution.

We would live with the backend service response times for the now and the questions shifted to:

How frequently were we willing to pay the 250-500ms network tax?
Where can put the data if not MySql?

The product owners took care of the first question. We could use 15 minutes as the TTL. It was a reasonable compromise. Now we needed a storage solution… Hello Redis. Magento uses caches heavily and Redis is a common cache backend storage mechanism. We began exploring the idea of using Redis as our storage engine.

The POC results looked great. On a cache miss we would fetch the data from our microservice and save the response in Redis with a 15 minute TTL. Because we had already optimized the networking between the application and Redis instances the time spent fetching the data from Redis was ~6ms. I cleaned up POC code and prepped a non-prod environment for a load test. The load test results were awful. Turns out we were nearing capacity on our Azure Redis PaaS and the additional read/write load pushed it over the edge. I started checking the size of the data. I didn’t think it was that large and it averaged ~15kb per user.

We were already using the largest Redis instance available in Azure and I needed to determine where the strain was coming from. The Azure’s Redis monitoring isn’t that insightful and I needed a way of segregating each of the 23, :(, backend cache types for profiling. I spun up a second Redis instance for testing. The plan was simple, separate each backend cache type to the second instance and run the load tests… In practice I had zero idea how to do this.

Magento 2’s env.php has options for configuring up to three different Redis instances for caching: sessions, backend cache and full page cache. Full page cache is really just a backend cache type, so I figured reverse engineering how Magento’s core handles the split would be a good starting point. I found the definition for the full_page cache backend in app/etc/di.xml

<type name="Magento\Framework\App\Cache\Type\FrontendPool">
    <arguments>
        <argument name="typeFrontendMap" xsi:type="array">
            <item name="full_page" xsi:type="string">page_cache</item>
        </argument>
    </arguments>
</type>

Digging a little further into how the application bootstraps, this is referred considered a primary configuration type and loaded/parsed near the beginning of the request flow. Further you can drop additional di.xml files in app/etc//. I gave it a shot creating app/etc/abi/di.xml

<?xml version="1.0"?>
<config xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:noNamespaceSchemaLocation="urn:magento:framework:ObjectManager/etc/config.xsd">
    <type name="Magento\Framework\App\Cache\Frontend\Pool">
        <arguments>
            <argument name="frontendSettings" xsi:type="array">
                <item name="secondary" xsi:type="array">
                    <item name="backend_options" xsi:type="array">
                        <item name="cache_dir" xsi:type="string">secondary_cache</item>
                    </item>
                </item>
            </argument>
        </arguments>
    </type>
    <type name="Magento\Framework\App\Cache\Type\FrontendPool">
        <arguments>
            <argument name="typeFrontendMap" xsi:type="array">
                <item name="my_custom_cache" xsi:type="string">secondary</item>
            </argument>
        </arguments>
    </type>
</config>

What does the above do? It creates a new cache backend type named secondary, terrible name used for testing only. Any items in the typeFrontendMap can be directed to the secondary cache instance. Now I could configure the new cache instance in env.php

<?php
return [
    'cache' => [
        'frontend' => [
            'default' => [
                ...
            ],
            'secondary' => [
                'backend' => 'Cm_Cache_Backend_Redis',
                'backend_options' => [
                    'server' => 'secondary Redis instance',
                    'port' => '6379',
                    'password' => '',
                    'database' => 0,
                    'persistent' => '',
                    'force_standalone' => '0',
                    'connect_retries' => '1',
                    'read_timeout' => '10',
                    'automatic_cleaning_factor' => '0',
                    'compress_data' => '1',
                    'compress_tags' => '1',
                    'compress_threshold' => '20480',
                    'compression_lib' => 'gzip'
                ]
            ],
        ],
    ],
];

I now have a setup allowing the isolation of a single cache type on its own Redis instance. I started with the custom cache types and one by one built the application with the cache type to profile defined in the custom di.xml then load testing. This gave me concrete data about the resource consumption of each cache type under load.

I grew frustrated as I cycled through the custom cache types. The second Redis was barely breaking 2% utilization during the tests. The results didn’t match my expectations. The issue had to be caused by a custom cache type. It couldn’t be a native Magento cache type… Could it? I spent a very long day repeating the test. Update di.xml, build, deploy, load test. The process was painful. After ruling out the custom cache types I started testing the Magento ones. I worked through them based on my assumptions around their write throughput. Every cycle returned near identical results until I had a single cache type remaining config.

The config cache type doesn’t have a large write throughput, but is very read heavy with every request. I isolated the config cache on the second Redis instance and began the last load test of the day. BOOM! The config cache consumed ~35% of the available resources. I finally found the culprit. But why? The read/write load was what I expected, writes were low and reads were high. Why was the read throughput straining Redis? I started inspecting what was stored in the instance. There were a few keys, specifically compiled di.xml for the various scoped around 1MB, even gzipped. This is huge as Redis tends to recommend keeping data below 100KB.

Ultimately I wasn’t prepared for a refactor of Magento’s core config cache and wound up running a separate Redis instance dedicated to the config cache. We moved forward storing the product and inventory in Redis as planned and eliminated the application outages caused by having the data in MySql.

The Cost of Loading in a Loop

2020-12-15T11:00:00+00:00

The Cost of Loading in a Loop

We recently saw some pretty dramatic performance degradation on an API endpoint consumed by our mobile applications. This particular endpoint is responsible for supplying our mobile apps with category and product data on open and it’s degraded performance meant the apps were very slow and clunky when starting up. We run multiple instances of this application, all running the same code rebranded and containing customer specific data. I mention this because it provides the opportunity to gauge performance of each instance where the only variable is the size and structure of our customers’ data.

Triaging the issue it was very apparent the performance was not great across all instances, but it was particularly bad for a single instance. I was happy to see this because it usually points to inefficient data loading and those tend to be low effort/high impact fixes. I grabbed a copy of non-prod data exhibiting the same behavior and got my envrionment ready for some profiling.

I like to use Blackfire for profiling. It’s very easy to install and visualize profiles. You can always use xdebug’s profiling, which is equally easy in most instances. My preference for Blackfire comes from past experience with PhpStorm and KCachegrind crashing when loading the profiler output from the bloatware that is Magento.

Blackfire’s client ran 10 requests to my problem endpoint and I started looking at the stack for trouble spots. The recorded response time was 3.54s, OUCH! Taking a look at the call graph I was trying to spot function calls with a high percentage of total time with multiple calls. I stumbled across getBrandItems called 147x accounting for 59% (2.09s) of my response time. Perfect, time to look at the code.

This endpoint returns the category tree and products for the mobile app. When building the response, each category is passed into getBrandItems to populate the category items. The application was going back to the database for every category, 147 in this instance, and retrieving the products per category. This could be better, but I was also curious how much product overlap there was between categories. I analyzed a few response payloads and counted the number of instances for each SKU.

The payloads had an average of 206 unique products. There were usually ~50 products appearing only once, ~150 appearing twice and ~6 appearing three times! Not only were we making too many round trips to the database, we were often fetching the same data.

Now that we’ve identified the problem via the profiler data and a little legwork it was optimization time. In a perfect world we’d have started looking at what this endpoint returns, but we can’t break the existing service contract so we have to work with what’s currently in place. The looped product loads are the main bottleneck and I began there.

Prior to entering the loop we have a collection of categories we need the child products of. Within Magento we can use these category IDs as search criteria for the product repository. This will let us load all the products needed in for the response with a single query. I now had all the products for the categories in a single collection and the product data included a list of associated category IDs. But the category associations aren’t in a format I could easily use without iterating over all the products for each category. My database was the biggest bottleneck here and the improvement would have been significant even doing something lazy and silly like the pseudo code below

foreach ($categories as $category) {
    $categoryProducts = [];
    foreach ($products as $product) {
        if (in_array($category->getId(), $product->getCategoryIds())) {
            $categoryProducts[] = $product;
        }
    }
    $category->setProducts($categoryProducts);
}

…but this meant I would iterate over the same data 147 times. Instead I can pre-sort the product into a hash map using the category ID as the key. This will let me iterate over the products once and use the result when iterating through the categories. The ned result looked something like this

$categoryProductsMap = [];
foreach ($products as $product) {
    foreach ($product->getCategoryIds() as $categoryId) {
        $categoryProductsMap[$categoryId][] = $product;
    }
}

foreach ($categories as $category) {
    $category->setProducts($categoryProductsMap[$category->getId()] ?? []);
}

With the actual code in place I went back re-ran the Blackfire CLI and profiled the endpoint. The results looked great! Blackfire reported a 52% reduction in response time with only a 7% increase in memory consumption.

The refactor reduced the total time of the getBrands function from 2.12s to 134ms!

Magento 2 Deploy with Anistrano

2020-08-12T17:00:00+00:00

Magento 2 Deploy with Anistrano

I’ve inherited range of Magento 2 continuous delivery pipelines. Most suffering from excessive downtime during deployments. Ideally, downtime should only be needed when there is a need for running setup:upgrade. Here is an example of deployment steps developed by a prominent Adobe partner who will rename nameless:

Build application
Put site in maintenance mode
Push build artifact to all nodes
Stop Magento cron
Run setup:upgrade
Restart php-fpm and nginx
Remove site from maintenance mode

The entire process leaves the site inaccessible for about 8 minutes, deploying to 4-5 nodes. Executing setup:upgrade accounts for 30 seconds of the downtime. The pipeline puts the site in maintenance mode before pushing code to the nodes because code was going directly into the document root. There is also no reason for taking the site down when stopping the crons in our case. In the event of a rollback we are left repeating the entire process.

Meet Anistrano

Anistrano is an Anisble port of Capistrano. This particular pipeline was already using Ansible for deployment tasks making Anistrano a great fit. The Anistrano docs provide a great primer on the main workflow. I recommend reading the docs if you are unfamiliar with Capistrano or Anistrano.

Building the POC

I set out building a quick POC for experimenting with Anistrano and Magento2. Ansitrano natively solves issues with the existing CD job.

Natively separates deploy steps for a clearer view on what happens when.
Is not writing directly to the live document root during the entire process.
Retains prior releases on nodes in case you need to rollback.

Here’s the workflow I originally envisioned:

Update Code - Push build artifact to remote hosts. Anistrano creates a unique release directory for each deploy attempt and removes the need existing need for taking the site down while pushing the code.
1. Unpack and remove the artifact archive.
2. Ensure proper ownership of the unpacked build.
Symlink Shared Items - Anistrano allows sharing directories and files between releases. For the POC I am sharing var, pub/media and app/etc/env.php
Before Symlinking Release to Document Root
1. Check database schema status with the new release with setup:db:status. We’ll use the output of the command for determining if the site should be placed in maintenance mode and running setup:upgrade.
2. If the database schema is out of date we add the maintenance flag to the new release putting the site in maintenance mode as soon as the document root symlink is updated.
After Symlinking Release to Document Root
1. Restart php-fpm. This clears opcache and prevents potential issues from swapping the symlinked document root when validate_timestamps is disabled (it should be on production servers).
2. Run setup:upgrade if the schema requires update. Otherwise, we flush the cache.
3. Remove the site from maintenance mode if needed.

This limits downtime to about 45s when setup:upgrade. The downtime is just a few seconds when not updating the schema. You can find the Ansitrano tasks used in this POC on GitHub

Building Magento 2 with Jenkins

2020-08-12T11:00:00+00:00

Building Magento 2 with Jenkins

I often find myself needing a clean Magento 2 environment. The version required generally depends on what I’m doing and means I switch relatively often. I’m lazy and wanted something that just works by pushing a button or two. I had stood up a Jenkins instance the prior week and thought I’d use that for creating the build artifacts and eventually deploying. Here I will focus on the build and archive generation process.

Since I’m often switching between similar versions I want to avoid the build process when deploying if possible. For example, if I’ve already built 2.4.0 and 2.3.5 I should not need to rebuild them when switching versions. I found a few different approaches such as writing the archive to AWS S3 or Artifactory. I wanted to use my existing infrastructure and decided on installing the copyArtifacts Jenkins plugin.

We’ll be performing the build withing a docker container based on one of the official PHP images php:7.3-cli. You can view the Dockerfile on GitLab. The final version is very basic. We install a few packages for meeting Magento’s minimum requirements along with composer.

An oddity within the Dockerfile is copying a generic store configuration. I’m performing the build from the Magento GitHub repository for running develop branches between releases. This means I won’t have a complete config.php file available at build time. COPY files/store-config.php /var/store-config.php will fill in the gaps for running setup:static-content:deploy.

With the Dockerfile ready we’ll start writing the Jenkinsfile used for the build. Here’s the initial pipeline for preparing the workspace for build. The stage is configured for running inside the PHP Docker container.

Build parameters for inputting the tag or branch and select letting the pipeline know if the input is a tag or branch.
Add Magento composer auth from a Jenkins stored credential.
Checkout the Magento source from GitHub using the provided reference.

pipeline {
    agent {
        node {
            label 'master'
        }
    }

    parameters {
        choice(
            name: 'reference_type',
            choices: [
                'tag',
                'branch'
            ]
        )
        string(
            name: 'reference',
            defaultValue: '2.4.0'
        )
    }

    stages {
        stage('Build') {
            agent {
                dockerfile {
                    filename 'Dockerfile'
                    dir 'docker/'
                    label 'master'
                    args '-v $HOME/jenkins_home/.composer:$HOME/.composer'
                }
            }

            steps {
                script {
                    withCredentials([
                        usernamePassword(
                            credentialsId: "magento-repo", // user/pass credential
                            usernameVariable: "username",
                            passwordVariable: "password"
                        )
                    ]) {
                        sh """
                            composer global config -a http-basic.repo.magento.com "$username" "$password"
                        """
                    }
                }

                script {
                    if ( "${env.reference_type}" == 'branch' ) {
                        env.build_from = "refs/heads/${env.reference}"
                    }

                    else if ( "${env.reference_type}" == 'tag' ) {
                        env.build_from = "refs/tags/${env.reference}"
                    }
                }

                checkout([
                    $class: 'GitSCM',
                    branches: [[name: "${env.build_from}"]],
                    userRemoteConfigs: [[name: 'source', url: "https://github.com/magento/magento2.git"]]
                ])
            }
        }
    }
}

We can now add our build commands into the stage. The build steps are basic:

Clear generated/code, generated/metadata and pub/static
composer install with the --optimize-autoloader --no-interaction options
Create a config.php by enabling all modules. You would not do this with a standard Magento project. Your config.php should be commited to source control.
A hack merging the new config.php with a boilerplate store config. Again this is only needed because it isn’t a proper project.
Run setup:di:compile and setup:static-content:deploy
Clear .git. I don’t usually do this, but it adds 250MB of bloat to the build artifact. In this case it isn’t worth the overhead.
Create an archive of the whole thing.

Here’s the end result

    sh 'rm -rf generated/code generated/metadata pub/static/frontend pub/static/adminhtml'
    sh 'composer install --optimize-autoloader --no-interaction'
    sh 'php bin/magento module:enable --all'
    sh 'php -r \'$config = include("app/etc/config.php"); $stores = include("/var/store-config.php"); file_put_contents("app/etc/config.php", "<?php\\nreturn\\n" . var_export(array_merge($config, $stores), true) . ";");\''
    sh 'php bin/magento setup:di:compile'
    sh 'php bin/magento setup:static-content:deploy -f'
    sh 'rm -rf .git/'
    sh 'mkdir build'
    sh 'tar --exclude=build/output.tar.gz -zcf build/output.tar.gz .'

Finally, I need Jenkins to archive the artifact and define which jobs can access via copyArtifacts. Right after the last build step I add:

archiveArtifacts artifacts: 'build/output.tar.gz', followSymlinks: false, onlyIfSuccessful: true

letting Jenkins know the location of the build artifact. Then adding the following to the pipeline configuration before the parameters:

options {
    copyArtifactPermission('m2-demo-store/DeployDemoStore')
}

That a job named m2-demo-store/DeployDemoStore access to the build artifact. I’ll work on the deploy job another day. You can see find the complete Jenkinsfile on GitHub

The Consumer is too Fast

2020-08-07T10:00:00+00:00

The Consumer is too Fast

I was recently reviewing a PR moving a RabbitMQ task into a cronjob. This alone was a bit of a red flag, but the commit message piqued my interest.

Move request to cron the queue consumer is too fast Some requests send with the incorrect order status because the queue consumer is processing them before they are ready.

For context, this is a Magento 2 application and the consumer in question is responsible for sending orders to a backend system when it reaches the complete status. The PR under review was fixing a reported issue where some orders send with a processing status.

There isn’t a lot of magic to this process. If an order status changes to complete it is published to RabbitMQ.

Here is the actual logic controlling the publishing, edited for brevity. Orders should never be in the queue unless the order is complete.

if ($order->getState() === 'complete') {
    $this->publisher->publish(
        'our.queue',
        (int) $order->getEntityId()
    );
}

At this point I’m still convinced moving from the message queue to cron is not the ideal solution, but am very curious how orders are sending before reaching completion. Looking at the observer configuration I see the publish happens on the sales_order_save_after event.

This event fires before the transaction commits to the database and I’m pretty confident is causing a race condition. Changing the event to the sales_order_save_commit_after should fix our problem.