bugsnag-php icon indicating copy to clipboard operation
bugsnag-php copied to clipboard

startSession immediately triggers deliverSessions

Open alcohol opened this issue 2 years ago • 1 comments

Perhaps the behaviour I am about to describe is intentional, in which case this would be more of a feature (change) request than a bug report.

We currently use a Symfony EventSubscriber to automatically track sessions; see code:

<?php declare(strict_types=1);

namespace Vendor\Events\EventSubscriber;

use Bugsnag\Client;
use Symfony\Component\DependencyInjection\Attribute\Autowire;
use Symfony\Component\EventDispatcher\EventSubscriberInterface;
use Symfony\Component\HttpKernel\Event\RequestEvent;
use Symfony\Component\HttpKernel\Event\TerminateEvent;
use Symfony\Component\HttpKernel\KernelEvents;

class BugsnagSubscriber implements EventSubscriberInterface
{
    public function __construct(
        #[Autowire(value: '%kernel.environment%')]
        private readonly string $kernelEnvironment,
        private readonly Client $bugsnag
    ) {
    }

    public function onKernelRequest(RequestEvent $event): void
    {
        if ('docker' === $this->kernelEnvironment || ! $event->isMainRequest()) {
            return;
        }

        $this->bugsnag->startSession();
    }

    public function onKernelTerminate(TerminateEvent $event): void
    {
        if ('docker' === $this->kernelEnvironment || ! $event->isMainRequest()) {
            return;
        }

        $this->bugsnag->getSessionTracker()->sendSessions();
    }

    /** @return array<string, array{string, int}|array{string, int}[]|string|string[][]> */
    public static function getSubscribedEvents(): array
    {
        return [
            KernelEvents::REQUEST => ['onKernelRequest', 256],
            KernelEvents::TERMINATE => ['onKernelTerminate', 256],
        ];
    }
}

Recently our application suddenly became much slower on our production environment. Doing some quick profiling revealed that an http call to sessions.bugsnag.com was the root cause of this slowdown (the call took over 6 seconds on average).

Note: this was due to networking issues at digital ocean, not bugsnag itself.

I found this peculiar at first since we call deliverSessions in a kernel.terminate event in Symfony, which in theory means that I would have expected the call to sessions.bugsnag.com to happen after we had already delivered a response to the client.

Doing some quick reviewing of the code however, I learned that simply calling startSession already immediately triggers deliverSessions due to:

startSession calling incrementSessions https://github.com/bugsnag/bugsnag-php/blob/7fff8512b237a57323f600975ada6376e2b912c1/src/SessionTracker.php#L156

This $lastSent variable defaulting to 0 https://github.com/bugsnag/bugsnag-php/blob/7fff8512b237a57323f600975ada6376e2b912c1/src/SessionTracker.php#L300

Meaning this conditional is always true https://github.com/bugsnag/bugsnag-php/blob/7fff8512b237a57323f600975ada6376e2b912c1/src/SessionTracker.php#L302

Is this expected / intentional behaviour?

alcohol avatar Aug 09 '23 12:08 alcohol

Hi @alcohol. This is something that we are aware of as an area of potential improvement. It is on our backlog to address as soon as priorities allow. We will post here as soon as we have any updates.

johnkiely1 avatar Aug 09 '23 14:08 johnkiely1