Login takes up to 2 min Since 2.6.4

[bassrock]

It seems like something has changed in Symfony 2.6.4. Since I upgraded our install from 2.6.3 logins are taking anywhere up to 2 min. We are using FOSUserBundle and the logs look exactly normal that it is loading from the database. I am using a pdosession handler locally and a dynamodb session handler on AWS and they both are experiencing the same issues.

Can you provide a profile of the differences? First by simply looking in the symfony profiler and see where most time is being spent.

[jakzal]

@bassrock we'll need more details as @jrobeson suggested. Could you provide a simplified standard edition based project that suffers the same issue, or a profile of your app (tools like blackfire, xhprof or xdebug will help)?

[bassrock]

Yes will get that today

[bassrock]

Unable to get a good profile result. But the issue occurs as follows:

1. Login as a user.
2. Logout
3. Login as a second user.

On the third step it will either take a long time to login or it will go back to the login page saying invalid csrf token.

@bassrock : well that's not happening for anybody else as far as we can tell. So we need a way to reproduce it.

[bassrock]

understandable. I will keep trying to get some actual data here.

[mvrhov]

@bassrock: https://blackfire.io/ should work for you

[bassrock]

@jrobeson got the profile right here:
https://blackfire.io/profiles/1681f091-4c22-45c6-89a7-e6c71fb41445/graph

While looking at it I noticed that file_get_contents was called a lot. looking at my code I do have this as login listener:

/**
 * @DI\Service("Demo.fos_user.listener.lastlogin")
 * @DI\Tag("kernel.event_subscriber")
 */
class LastLoginListener implements \Symfony\Component\EventDispatcher\EventSubscriberInterface
{
    /** @var \FOS\UserBundle\Model\UserManagerInterface  */
    protected $userManager;
    protected $service = 'api.ipinfodb.com';
    protected $version = 'v3';
    protected $apiKey = '';
    protected $errors = array();

    /**
     * @DI\InjectParams({
     *     "userManagerInterface"             = @DI\Inject("fos_user.user_manager")
     * })
     */
    public function __construct(\FOS\UserBundle\Model\UserManagerInterface $userManagerInterface)
    {
        $this->userManager = $userManagerInterface;
    }

    public static function getSubscribedEvents()
    {
        return array(
            FOSUserEvents::SECURITY_IMPLICIT_LOGIN => 'onImplicitLogin',
            SecurityEvents::INTERACTIVE_LOGIN => 'onSecurityInteractiveLogin',
        );
    }

    public function onImplicitLogin(UserEvent $event)
    {
        $user = $event->getUser();

        $user->setLastLogin(new \DateTime());
        $this->userManager->updateUser($user);
    }

    public function onSecurityInteractiveLogin(InteractiveLoginEvent $event)
    {
        $user = $event->getAuthenticationToken()->getUser();

        if ($user instanceof UserInterface) {
            $user->setLastLogin(new \DateTime());
            $theDate = new \DateTime();
            $aGrabbedLoginObject = new \Demo\UserBundle\Entity\Login();
            $aGrabbedLoginObject->setLoginDate($theDate);

            //IP Stuff
            $ipaddress = $event->getRequest()->getClientIp();

            $aGrabbedLoginObject->setIpAddress($ipaddress);

            $this->setKey('test');

            $locations = $this->getCity($ipaddress);

            if (isset($locations->latitude)) {
                $aGrabbedLoginObject->setLatitude($locations->latitude);
            }

            if (isset($locations->longitude)) {
                $aGrabbedLoginObject->setLongitude($locations->longitude);
            }

            if (isset($locations->cityName)) {
                $aGrabbedLoginObject->setCityName($locations->cityName);
            }

            if (isset($locations->regionName)) {
                $aGrabbedLoginObject->setRegionName($locations->regionName);
            }

            if (isset($locations->zipCode)) {
                $aGrabbedLoginObject->setZipcode($locations->zipCode);
            }

            if (isset($locations->countryCode)) {
                $aGrabbedLoginObject->setCountryCode($locations->countryCode);
            }

            if (isset($locations->timeZone)) {
                $aGrabbedLoginObject->setTimezone($locations->timeZone);
            }

            $user->addLogin($aGrabbedLoginObject);
            $aGrabbedLoginObject->setUser($user);

            $this->userManager->updateUser($user);
        }
    }

    public function setKey($key)
    {
        if (!empty($key)) {
            $this->apiKey = $key;
        }
    }

    public function getCountry($host)
    {
        return $this->getResult($host, 'ip-country');
    }

    public function getCity($host)
    {
        return $this->getResult($host, 'ip-city');
    }

    private function getResult($host, $name)
    {
        $ip = @gethostbyname($host);

        if (preg_match('/^(?:25[0-5]|2[0-4]\d|1\d\d|[1-9]\d|\d)(?:[.](?:25[0-5]|2[0-4]\d|1\d\d|[1-9]\d|\d)){3}$/', $ip)) {
            $json = @file_get_contents('http://'.$this->service.'/'.$this->version.'/'.$name.'/?key='.$this->apiKey.'&ip='.$ip.'&format=json');

            try {
                $result = json_decode($json);

                return $result;
            } catch (\Exception $e) {
                return;
            }
        }

        return;
    }
}

Is it possible my login listener is getting called multiple times slowing down the login process. Or that doctrine is hydrating all the last login objects of a user when it should not be as it is slow on my qa and production servers but not on local machines that get db wipes every few days?

[bassrock]

Reworking the login listener and will repost a profiler with Exta_Lazy enabled and one that doesnt call the ipinfodb.com api multiple times. Hopefully that is actually the issue.

[merk]

Youre' making multiple calls to an external service on login, the fault is not with symfony but with the listener you posted.

A better approach would be to offload this information collection to a separate asynchronous process that doesnt impact the user experience on login.

Additionally you can use a service like Maxmind that does not have external queries and returns Country/City information from a local database. See http://php.net/manual/en/book.geoip.php

[bassrock]

Hm yep it looks like it may have been it. Removed the code in the event and it seems to have solved it. Weird it started to act up randomly as it was working fine before.