Debug logging doesn't show username

[kuboslav]

I've got a problem with debug logging – if an error occured error log doesn't show which user causes error.
Example:

Code: Select all

[2012-02-08 14:51:18] security.DEBUG: Read SecurityContext from the session [] []
[2012-02-08 14:51:18] security.DEBUG: Reloading user from user provider. [] []
[2012-02-08 14:51:19] security.DEBUG: Username "" was reloaded from user provider. [] []
[2012-02-08 14:51:19] request.ERROR: Symfony\Component\HttpKernel\Exception\NotFoundHttpException: No route found for "GET /app_dev.ph/foo/bar" (uncaught exception) at /var/www/website/app/cache/prod/classes.php line 4560 [] []
[2012-02-08 14:51:19] security.DEBUG: Write SecurityContext in the session [] []

Have anyone idea what can causes that username is missing in log? any suggestion will be appreciated.

[blogsh]

What user provider to you use? If you use the EntityUserProvider, how does your User entity class look like? Normally the value of UserEntity::getUsername should be printed there...

[kuboslav]

What user provider to you use? If you use the EntityUserProvider, how does your User entity class look like? Normally the value of UserEntity::getUsername should be printed there...

Thank you for reaction.

I use my custom User provider and User entity method getUsername returns e-mail address, which is username.

Can that error causes, that I use sometimes Controllers as Services?

Code: Select all

<?php

namespace Acme\GeneralBundle\Entity;

use Symfony\Component\Security\Core\User\UserInterface;
use Symfony\Component\Security\Core\User\AdvancedUserInterface;

use Doctrine\ORM\Mapping as ORM;
use Doctrine\Common\Collections\ArrayCollection;

use Symfony\Bridge\Doctrine\Validator\Constraints\UniqueEntity;
use Symfony\Component\Validator\Constraints as Assert;

/**
 * Acme\GeneralBundle\Entity\User
 *
 * @ORM\Table()
 * @ORM\HasLifecycleCallbacks 
 * @ORM\Entity(repositoryClass="Acme\GeneralBundle\Entity\UserRepository")
 * @UniqueEntity(
 *  fields = "username",
 *  message = "E-mailová adresa již registrovaná"
 * )
 */
class User implements AdvancedUserInterface, \Serializable
{
    const ROLE_DEFAULT = 'ROLE_USER';
   
    /**
     * @var integer $id
     *
     * @ORM\Column(name="id", type="integer")
     * @ORM\Id
     * @ORM\GeneratedValue(strategy="AUTO")
     */
    private $id;

    /**
     * @var integer $uid
     *
     * @ORM\Column(name="uid", type="string", length=10, unique=true)
     */   
    private $uid;
   
    /**
     * @var integer $District_id
     *
     * @ORM\Column(name="District_id", type="integer", nullable=true)
     */
    private $District_id;

    /**
     * @var integer $avatar_id
     *
     * @ORM\Column(name="avatar_id", type="integer", nullable=true)
     */
    private $avatar_id;
   
    /**
     * @var string $username
     * @Assert\Email(
     *  message = "{{ value }} není platná e-mailová adresa",
     *  checkMX = true
     * )
     * @ORM\Column(name="username", type="string", length=50, unique=true)
     */   
    private $username;

    /**
     * @var string $name
     * @Assert\NotBlank(
     *  message = "Jméno musí být alespoň 6 znaků dlouhé"
     * )
     * @Assert\MinLength(
     *  limit = 6,
     *  message = "Jméno musí být alespoň 6 znaků dlouhé"
     * )
     * @ORM\Column(name="name", type="string", length=50)
     */   
    private $name;
   
    /**
     * @var string $password
     * @Assert\MinLength(
     *  limit = 8,
     *  message = "Heslo musí mít alespoň 8 znaků"
     * )
     * @ORM\Column(name="password", type="string", length=100)
     */
    private $password;

    /**
     * @var string $email
     * @Assert\Email(
     *  message = "{{ value }} není platná e-mailová adresa",
     *  checkMX = true
     * )
     * @ORM\Column(name="email", type="string", length="150", nullable=true)
     */   
    private $email;

    /**
     * @var string $salt
     *
     * @ORM\Column(name="salt", type="string", length=20)
     */
    private $salt;

    /**
     * @var array $roles
     *
     * @ORM\Column(name="roles", type="array")
     */
    private $roles;

    /**
     * @var \DateTime $lastLogin
     *
     * @ORM\Column(name="lastLogin", type="datetime", nullable=true)
     */
    private $lastLogin;

    /**
     * @var string $confirmationToken
     *
     * @ORM\Column(name="confirmationToken", type="string", length=50,  nullable=true)
     */
    private $confirmationToken;

    /**
     * @var string $recoveryToken
     *
     * @ORM\Column(name="recoveryToken", type="string", length=50,  nullable=true)
     */
    private $recoveryToken;
   
    /**
     * @var string $recoveryValidTo
     *
     * @ORM\Column(name="recoveryValidTo", type="datetime", nullable=true)
     */
    private $recoveryValidTo;   
   
    /**
     * @var boolean $enabled
     *
     * @ORM\Column(name="enabled", type="boolean")
     */
    private $enabled;

    /**
     * @var boolean $notify
     *
     * @ORM\Column(name="notify", type="boolean")
     */
    private $notify;
   
    /**
     * @var string $company
     *
     * @ORM\Column(name="company", type="string", length="150", nullable=true)
     */
    private $company;

    /**
     * @var string $phone
     *
     * @ORM\Column(name="phone", type="string", length="50", nullable=true)
     */
    private $phone;   

    /**
     * @var string $address
     *
     * @ORM\Column(name="address", type="string", length="255", nullable=true)
     */
    private $address;

    /**
     * @var string $address
     *
     * @ORM\Column(name="slug", type="string", length="255", nullable=true)
     */   
    private $slug;
   
    /**
     * @Assert\NotNull(
     *  message = "Musíte zvolit oblast",
     *  groups = {"District"}
     * )
     * @ORM\ManyToOne(targetEntity="District")
     */       
    private $District;
   
    /**
     * @ORM\ManyToMany(targetEntity="District")
     */
    private $Districts;
   
    /**
     * @ORM\OneToMany(targetEntity="Post", mappedBy="user")
     */
    private $posts;

    /**
     * @ORM\ManyToOne(targetEntity="Avatar", inversedBy="users")
     */   
    private $avatar;

    public function __construct()
    {
        $this->setSalt(
            substr(
                base_convert(sha1(uniqid(mt_rand(), true)), 16, 36),
                0, 20
            )
        );
        $this->setUid(
            substr(mt_rand(), 0, 10 )               
        );
        $this->confirmationToken = null;
        $this->recoveryToken = null;
        $this->recoveryValidTo = null;
        $this->enabled = false;
        $this->posts = new ArrayCollection;       
        $this->roles = new ArrayCollection;
        $this->Districts = new ArrayCollection;
        $this->lastLogin = null;
        $this->slug = '';
        $this->notify = false;
    }

    /**
     * Get id
     *
     * @return integer
     */
    public function getId()
    {
        return $this->id;
    }

    /**
     * Set uid
     *
     * @param integer $uid
     */
    public function setUid($uid)
    {
        $this->uid = $uid;
    }
   
    /**
     * Get uid
     *
     * @return integer
     */
    public function getUid()
    {
        return $this->uid;
    }
   
    /**
     * Set username
     *
     * @param string $username
     */
    public function setUsername($username)
    {
        $this->username = $username;
    }

    /**
     * Get username
     *
     * @return string
     */
    public function getUsername()
    {
        return $this->username;
    }

    /**
     * Set password
     *
     * @param string $password
     */
    public function setPassword($password)
    {
        $this->password = $password;
    }

    /**
     * Get password
     *
     * @return string
     */
    public function getPassword()
    {
        return $this->password;
    }

    /**
     * Set email
     *
     * @param string $email
     */
    public function setEmail($email)
    {
        $this->email = $email;
    }

    /**
     * Get email
     *
     * @return string
     */
    public function getEmail()
    {
        return $this->email;
    }

    /**
     * Set salt
     *
     * @param string $salt
     */
    public function setSalt($salt)
    {
        $this->salt = $salt;
    }

    /**
     * Get salt
     *
     * @return string
     */
    public function getSalt()
    {
        return $this->salt;
    }

    /**
     * Set roles
     *
     * @param array $roles
     */
    public function setRoles($roles)
    {
        $this->roles = $roles;
    }

    /**
     * Get roles
     *
     * @return array
     */
    public function getRoles()
    {
        $roles = $this->roles->toArray();
       
        $roles[] = static::ROLE_DEFAULT;       
       
        return array_unique($roles);
    }

    /**
     * Set lastLogin
     *
     * @param \DateTime $lastLogin
     */
    public function setLastLogin(\DateTime $lastLogin)
    {
        $this->lastLogin = $lastLogin;
    }

    /**
     * Get lastLogin
     *
     * @return \DateTime
     */
    public function getLastLogin()
    {
        return $this->lastLogin;
    }

    public function getSlug()
    {
        return $this->slug;
    }
   
    public function setSlug($slug)
    {
        $this->slug = $slug;
    }


    /**
     * Set confirmationToken
     *
     * @param string $confirmationToken
     */
    public function setConfirmationToken($confirmationToken)
    {
        $this->confirmationToken = $confirmationToken;
    }

    /**
     * Get confirmationToken
     *
     * @return string
     */
    public function getConfirmationToken()
    {
        return $this->confirmationToken;
    }

    /**
     * Set recoveryToken
     *
     * @param string $recoveryToken
     */
    public function setRecoveryToken($recoveryToken)
    {
        $this->recoveryToken = $recoveryToken;
    }

    /**
     * Get recoveryToken
     *
     * @return string
     */
    public function getRecoveryToken()
    {
        return $this->recoveryToken;
    }   
   
    /**
     * Set recoveryValidTo
     *
     * @param \DateTime $recoveryValidTo
     */
    public function setRecoveryValidTo(\DateTime $recoveryValidTo)
    {
        $this->recoveryValidTo = $recoveryValidTo;
    }

    /**
     * Get recoveryValidTo
     *
     * @return \DateTime
     */
    public function getRecoveryValidTo()
    {
        return $this->recoveryValidTo;
    }   
   
    /**
     * Set enabled
     *
     * @param boolean $enabled
     */
    public function setEnabled($enabled)
    {
        $this->enabled = $enabled;
    }

    /**
     * Set District_id
     *
     * @param integer $District_id
     */
    public function setDistrictId($District_id)
    {
        $this->District_id = $District_id;
    }
   
    /**
     * Get District_id
     *
     * @return integer
     */
    public function getDistrictId()
    {
        return $this->District_id;
    }   
   
    /**
     * Set District
     *
     * @param Acme\GeneralBundle\Entity\District $District
     */
    public function setDistrict(\Acme\GeneralBundle\Entity\District $District)
    {
        $this->District = $District;
    }

    /**
     * Get District
     *
     * @return \Acme\GeneralBundle\Entity\District
     */
    public function getDistrict()
    {
        return $this->District;
    }   
   

    /**
     * Set avatar_id
     *
     * @param integer $avatar_id
     */
    public function setAvatarId($avatar_id)
    {
        $this->avatar_id = $avatar_id;
    }
   
    /**
     * Get avatar_id
     *
     * @return integer
     */
    public function getAvatarId()
    {
        return $this->avatar_id;
    }
   
    /**
     * Get avatar
     * @return \Acme\GeneralBundle\Entity\Avatar
     */
    public function getAvatar()
    {
        return $this->avatar;
    }
   
    /**
     * Set avatar
     * @param \Acme\GeneralBundle\Entity\Avatar
     */
    public function setAvatar(\Acme\GeneralBundle\Entity\Avatar $avatar)
    {
        $this->avatar = $avatar;
    }
   
    /**
     * Add Districts
     *
     * @param Acme\GeneralBundle\Entity\District $Districts
     */
    public function addDistrict(\Acme\GeneralBundle\Entity\District $Districts)
    {
        $this->Districts[] = $Districts;
    }

    /**
     * Get Districts
     *
     * @return Doctrine\Common\Collections\Collection
     */
    public function getDistricts()
    {
        return $this->Districts;
    }   

    public function equals(UserInterface $user)
    {
        if($user instanceof User === false)
        {
            return false;
        }
       
        if($user->getUsername() !== $this->getUsername())
        {
            return false;
        }
       
        if($user->getPassword() !== $this->getPassword())
        {
            return false;
        }
       
        return true;
    }

    public function eraseCredentials() {
        return true;       
    }

    public function isAccountNonExpired() {
        return true;       
    }

    public function isAccountNonLocked() {
        return true;       
    }

    public function isCredentialsNonExpired() {
        return true;
    }

    public function isEnabled()
    {
        return $this->enabled;       
    }

    /**
     * Add posts
     *
     * @param Acme\GeneralBundle\Entity\Post $posts
     */
    public function addPost(\Acme\GeneralBundle\Entity\Post $posts)
    {
        $this->posts[] = $posts;
    }

    /**
     * Get posts
     *
     * @return Doctrine\Common\Collections\Collection
     */
    public function getPosts()
    {
        return $this->posts;
    }   
   
    /**
     * Set notify
     *
     * @param boolean $notify
     */
    public function setNotify($notify)
    {
        $this->notify = $notify;
    }
   
    /**
     * Get notify
     *
     * @param boolean $notify
     */
    public function getNotify()
    {
        return $this->notify;
    }   

    /**
     * Set company
     *
     * @param string $company
     */
    public function setCompany($company)
    {
        $this->company = $company;
    }

    /**
     * Get comapny
     *
     * @return string
     */
    public function getCompany()
    {
        return $this->company;
    }   


    public function getName()
    {
        return $this->name;
    }
   
    public function setName($name)
    {
        $this->name = $name;
    }
   
    public function getPhone()
    {
        return $this->phone;
    }
   
    public function setPhone($phone)
    {
        $this->phone = $phone;
    }
   
    /**
     * @Assert\True(
     *  message = "Neplatný formát telefonního čísla."
     * );
     */       
    public function isPhoneValid()
    {
        if ($this->phone ) return (bool) preg_match( "/(((\+|00)42\d)? ?\d{3} ?\d{3} ?\d{3})/", $this->phone );
        else return true;
    }
   
    public function getAddress()
    {
        return $this->address;
    }
   
    public function setAddress($address)
    {
        $this->address = $address;
    }

   
    public function serialize()
    {
        return serialize($this->id);
    }

    public function unserialize($data)
    {
        $this->id = unserialize($data);
    }
   
    /**
     * @ORM\PrePersist()
     * @ORM\PreUpdate()
     */   
    public function makeSlug()
    {
        setlocale(LC_CTYPE, 'cs_CZ.utf-8');
       
        $url = $this->name;
        $url = preg_replace('~[^\\pL0-9_]+~u', '-', $url);
        $url = trim($url, "-");
        $url = iconv("utf-8", "us-ascii//TRANSLIT", $url);
        $url = strtolower($url);
        $url = preg_replace('~[^-a-z0-9_]+~', '', $url);
        $this->setSlug($url);
    }
   
}

[kuboslav]

I find out that this message is added to monolog in Symfony\Component\Security\Http\Firewall\ContextListener on line 137. When I use var_export to show User entity which is used in debugger I see this:

Code: Select all

Acme\GeneralBundle\Entity\User::__set_state(array(
   'id' => 3,
   'uid' => NULL,
   'District_id' => NULL,
   'avatar_id' => NULL,
   'username' => NULL,
   'name' => NULL,
   'password' => NULL,
   'email' => NULL,
   'salt' => NULL,
   'roles' => NULL,
   'lastLogin' => NULL,
   'confirmationToken' => NULL,
   'recoveryToken' => NULL,
   'recoveryValidTo' => NULL,
   'enabled' => NULL,
   'notify' => NULL,
   'company' => NULL,
   'phone' => NULL,
   'address' => NULL,
   'slug' => NULL,
   'Disctrict' => NULL,
   'Districts' => NULL,
   'posts' => NULL,
   'avatar' => NULL,
))

Everything is NULL, but id is correct . I suppose it causes something in my UserEntityRepository:

Code: Select all

class UserRepository extends EntityRepository implements UserProviderInterface
{

    public function loadUserByUsername($username)
    {
        $q = $this
            ->createQueryBuilder('u')
            ->where('u.username = :email')
            ->setParameter('email', $username)
            ->setMaxResults(1)
            ->getQuery()
        ;
       
        try {
           
            $user = $q->getSingleResult();
           
        } catch (NoResultException $e) {
           
            throw new UsernameNotFoundException(sprintf('Uživatel "%s" nenalezen.', $username), null, 0, $e);
        }

        return $user;               
    }

    public function refreshUser(UserInterface $user)
    {
        $class = get_class($user);
        if (!$this->supportsClass($class))
        {
            throw new UnsupportedUserException(sprintf('Instance třídy "%s" nejsou podporovány.', $class));
        }

        return $this->loadUserByUsername($user->getUsername());       
    }

    public function supportsClass($class)
    {
        return $this->getEntityName() === $class || is_subclass_of($class, $this->getEntityName());       
    }
}

[blogsh]

Is the message

Code: Select all

security.INFO: User "......" has been authenticated successfully [] []

displayed correctly?
And is it only the log message that isn't displayed correctly or do you have problems with login/refreshing in general?

[kuboslav]

Yes, the message security.INFO: User "......" has been authenticated successfully [] [] is displayed correctly. The message Username "" was reloaded from user provider is the only one. My entity provider is written according cookbook.

[blogsh]

I'm sorry, but I don't have a clue. You could try to follow the way of the UserToken through the system and identify the method where it is populated with the right name and why it isn't done before.

[TheDevilOnLin]

I had the same issue and it took me a lot of digging to figure this out.

The problem is that you don't serialize the username in the serialize function of the User object.

Many people use the following for their serialization functions:

Code: Select all

public function serialize()
{
    return serialize($this->id);
}

public function unserialize($data)
{
    $this->id= unserialize($data);
}


This way only the id is known when loading the user from the session token (note this also breaks the ?_switch_user=_exit functionality).

To fix this you should use the following code:

Code: Select all

public function serialize()
{
    return serialize(array($this->id,$this->username));
}

public function unserialize($data)
{
    list($this->id,$this->username) = unserialize($data);
}


This way the username AND id are available and the issue is fixed.

NOTE: The 'refreshUser' function of your custom user provider will NEVER be used as it will be overruled by the EntityUserProvider!