The dashboard drew forty rows in 3.1 seconds, and when I finally put a counter on the query log it came back with 122 queries. That was week two of my first real Laravel project, after four years where every ORM I touched was Doctrine. The cause was not exotic. It was the N+1 that every Laravel tutorial warns about, and I walked straight into it, because Eloquent’s lazy loading is invisible at the point of use in a way Doctrine’s proxies never were for me.
Context: I am at an offshore shop now, which means several clients and whatever stack each one already has. This one is an operations dashboard, Laravel 5.6 on PHP 7.1, MySQL 5.7, five of us for three months. Laravel 5.6 shipped on 7 February 2018, gets bug fixes until 7 August and security fixes until February 2019, and the next major release is due in August under the six month cadence. Coming from Symfony, where a minor line I picked in 2015 was still getting patches in 2018, that release window was the first thing I had to make peace with.
The habits I had to put down
My Symfony reflex is a constructor. Every dependency arrives as an argument, the service definition says so out loud, and if a class needs six things the constructor makes that embarrassing in a useful way. Laravel offers the same thing and then offers facades, which are the path of least resistance everywhere in the documentation.
I read how facades actually work before I formed an opinion, and the mechanism is less alarming than the syntax suggests: the base Facade class uses __callStatic() to forward the call to an object resolved from the container, and each facade only declares a getFacadeAccessor() returning a container binding key. Cache::get() is not a static method on a cache class. It is a resolve plus a call. So the testing story holds up, and Cache::shouldReceive('get') does work.
The documentation names the real risk itself, and it names it better than I would have: class scope creep. A constructor with nine arguments is a visible smell in review. Nine facade imports at the top of a 400 line controller reads as normal Laravel. We ended up with a house rule after the third code review argument: constructor injection in anything under app/Services or app/Jobs, facades allowed in controllers, routes, and Artisan commands. Not principled. It survived the project.
Convention over configuration was the other adjustment, and it cut both ways. On a greenfield table Eloquent’s guesses are free: a Shipment model finds shipments, a belongsTo guesses customer_id, and I write nothing. Our client’s schema was fourteen years old with tbl_ prefixes, two composite keys, and one table whose primary key was a varchar invoice number. So most models carried $table, $primaryKey, $incrementing = false and $keyType = 'string' anyway. Convention is a discount on new work, not on inherited work. Doctrine’s mapping files are more typing on day one and exactly the same amount of typing on day four hundred.
122 queries down to 4
The dashboard lists forty rows per page. Each row shows the customer, the assigned agent, and a count of attachments. In Blade that reads beautifully and each property access is a round trip to MySQL.
Before guessing I wanted a number, so I registered a listener in AppServiceProvider, which is the documented way to see every query the request runs:
public function boot()
{
if (config('app.debug')) {
DB::listen(function ($query) {
Log::channel('queries')->debug($query->sql, [
'bindings' => $query->bindings,
'ms' => $query->time,
]);
});
}
}122 lines in the log for one page load, and 120 of them were three statements repeated forty times each. The fix is two methods, both in the relationships documentation under Eager Loading:
// Before: 122 queries, 3.1s
$orders = Order::query()
->whereBetween('placed_at', [$from, $to])
->latest('placed_at')
->paginate(40);
// After: 4 queries, 380ms
$orders = Order::query()
->with(['customer:id,name,tier', 'agent:id,name'])
->withCount('attachments')
->whereBetween('placed_at', [$from, $to])
->latest('placed_at')
->paginate(40);with() turns forty lookups into one where in per relation. withCount() puts an attachments_count column on each model with a subselect instead of loading 1,900 attachment rows we never render. The column list after the colon earns its keep: our customers table has a notes longtext nobody on the dashboard reads. If you use that form, include id or the relation cannot be matched back.
Four queries and 380ms, measured on the staging box with production row counts. The honest comparison to Doctrine: Doctrine lazy loads too, and I have shipped exactly this bug in Symfony. The difference is where the mistake lives. In Doctrine the query sits in a repository method, so a slow list view sends me to one file that already has a DQL string I can add a join fetch to. In Eloquent the query is assembled at the callsite and the N+1 is written in the Blade template, forty lines away, by someone who was thinking about markup. That is a real difference in how the bug hides, and it is not the pattern’s fault.
The other method I now reach for is loadMissing(), for formatter classes that get handed a model from anywhere and need one relation without re-querying it.
Active record, fairly
Laravel’s own documentation calls Eloquent a simple ActiveRecord implementation, and the tradeoff is exactly the one the pattern always has. Two places where it cost us something real.
First, mass assignment. Eloquent blocks it by default and you open it with $fillable as a whitelist or $guarded as a blacklist. One of our models had protected $guarded = [];, which means everything is assignable, put there during seeding work in the first fortnight. The update endpoint took $request->all(). A client with a normal user account could set approved_by and approved_at on their own record. Nobody did, we caught it in a security pass in week six, and the fix was $fillable on all eighteen models plus a review rule that an empty $guarded gets a comment explaining itself. A Doctrine entity has no equivalent hole because nothing binds request keys to properties unless you write a form type or a DTO that says so. This is the one place where I think the data mapper is different, and safer by default.
Second, tests. A model that is also a query builder is a model you cannot construct in a unit test without a database. Our status transition rules lived on the model, so testing them meant migrations, a factory, and 40 seconds of suite time we did not need. We pulled the rules into a plain class that takes two strings and returns a bool, and the model calls it. That is what I would have written in Symfony on the first day, and I only reached for it after the suite got slow.
Against that, one honest win. php artisan make:model Order -m gives me model, migration, and the convention that ties them, and a new developer on the team found our code by guessing filenames. Over three months that saved more hours than the two problems above cost.
The logging rewrite is the feature I actually use
5.6 moved logging into a real config file, config/logging.php, with named channels, a stack driver that fans one message out to several handlers, per channel level thresholds, and a tap array for getting at the Monolog instance directly. Ours ended up like this:
'channels' => [
'stack' => [
'driver' => 'stack',
'channels' => ['daily', 'slack'],
],
'daily' => [
'driver' => 'daily',
'path' => storage_path('logs/laravel.log'),
'level' => 'debug',
'days' => 14,
],
'slack' => [
'driver' => 'slack',
'url' => env('LOG_SLACK_WEBHOOK_URL'),
'level' => 'critical',
],
'queries' => [
'driver' => 'daily',
'path' => storage_path('logs/queries.log'),
'level' => 'debug',
'days' => 3,
],
'imports' => [
'driver' => 'daily',
'path' => storage_path('logs/imports.log'),
'level' => 'info',
'days' => 7,
],
],The nightly import used to write 40 MB a night into the application log and drown everything else. Now it writes to its own channel with Log::channel('imports') and the on-call log is readable again. The tap option is the part I did not expect: a one method class receiving the logger, resolved through the container, so a request id on every line is nine lines in app/Logging instead of a bundle extension and a compiler pass.
Being fair to Symfony: MonologBundle has done channels, handler stacks, and per handler levels in YAML for years, and I had all of it on the last project. 5.6 is Laravel catching up to a baseline, not inventing one. A tap class beats wiring a formatter service by enough that I noticed.
Queues on one server, and the report we generated three times
The dashboard has two queued jobs: a PDF export and a nightly aggregate. Workers are long lived processes, they hold the booted application in memory, and they need a supervisor. The documented Supervisor block, adjusted for us:
[program:app-worker]
process_name=%(program_name)s_%(process_num)02d
command=php /var/www/app/artisan queue:work redis --sleep=3 --tries=3
autostart=true
autorestart=true
user=www-data
numprocs=4
redirect_stderr=true
stdout_logfile=/var/www/app/worker.logTwo things bit us. Workers do not see new code, so php artisan queue:restart has to be in the deploy script or you spend an afternoon debugging a fix that is already on disk. And without --tries a failing job is retried forever; we watched one malformed export attempt 400 times before anyone looked.
Then the scheduler. Three app servers, one cron entry each, one schedule:run per minute each. The nightly aggregate ran three times and the client got three emails with three slightly different numbers, because the three runs did not see the same set of committed rows. 5.6 added onOneServer() for exactly this, and the first server to claim the task takes an atomic lock:
$schedule->command('app:aggregate:daily')
->dailyAt('01:15')
->onOneServer();There is a prerequisite in the note above that method and it is not decoration: the default cache driver must be memcached or redis, and every server must talk to the same cache. Ours was file, which means three local locks and three reports, which is exactly the bug I was trying to kill. Moving the default cache store to Redis was the actual fix. withoutOverlapping() carries the same requirement and is worth adding to any task whose runtime you cannot predict.
Two 5.6 features we could not use
Argon2 hashing is in 5.6 through a new config/hashing.php with a driver setting, and the note in the documentation is blunt: the Argon2 driver needs PHP 7.2.0 or greater. We are on 7.1, so bcrypt stays, with rounds raised from the default to 12 after timing it at 210ms on the app box. The PHP upgrade is on the plan for the fourth quarter and this is now one of the reasons on the ticket.
Dynamic rate limiting is the other one. Instead of hardcoding throttle:60,1 you pass an attribute name, throttle:rate_limit,1, and the middleware reads the maximum off the authenticated user model. Good feature, useless to us: our API callers authenticate with a shared integration token that does not resolve to a user row, so there is no attribute to read. We left the hardcoded number and wrote down why.
Blade components and slots we did use, and they replaced eleven partials that each took a differently named array of variables. A component is a view with {{ $slot }} in it, named slots are just variables you echo, and @slot fills them:
@component('components.panel')
@slot('title')
Exceptions this week
@endslot
{{ $table }}
@endcomponentUnder all of this, 5.6 moved its Symfony components to the 4.0 series, which released in November 2017 and needs PHP 7.1.3, the same floor Laravel 5.6 sets. So the HTTP kernel, console, and routing underneath my new framework are code I have been reading for four years. That was oddly steadying in the first fortnight.
The list view is at 4 queries and 380ms and the client has stopped mentioning speed. Two of the report queries are still raw SQL because I could not express a running total over a pivot table in Eloquent without three subqueries, and I do not know yet whether that is Eloquent’s ceiling or mine. Next is the PHP 7.2 upgrade, which is what the Argon2 driver is waiting on, and which I expect to be the more interesting write-up.
Sources
- Laravel 5.6 release notes: release date of 7 February 2018, the support windows, the six month major release cadence, the Symfony 4.0 component bump, and the feature list I worked through.
- Logging (5.6):
config/logging.php, channel drivers, thestackdriver, per channel levels, and thetaparray. - Eloquent relationships (5.6): eager loading and the N+1 problem,
with(), column selection,withCount(), andloadMissing(). - Eloquent getting started (5.6): the ActiveRecord description, and
$fillableversus$guardedfor mass assignment. - Facades (5.6):
__callStatic(),getFacadeAccessor(), testability, and the class scope creep warning I quoted. - Queues (5.6): the Supervisor configuration block,
numprocs,--tries, and why workers needqueue:restarton deploy. - Task scheduling (5.6):
onOneServer(), its memcached or Redis cache requirement, andwithoutOverlapping(). - Hashing (5.6):
config/hashing.php, the bcryptroundsoption, and the PHP 7.2.0 requirement for the Argon2 driver.