Yubico Forum ...visit our web-store at 2014-07-31T21:51:17+01:00 https://forum.yubico.com/feed.php?f=31&t=1380 2014-07-31T21:51:17+01:00 2014-07-31T21:51:17+01:00 https://forum.yubico.com/viewtopic.php?t=1380&p=5456#p5456 <![CDATA[Re: [BUG] User lookup failed after long inactivity]]> https://github.com/Yubico/yubiauth/pull/3/files ?
Since this is happening in the morning after long inactivity, I have a hunch it might be caused by the database issue described in the link. The fix hasn't yet been included in a release, but it will be as soon as the next release is made. If this fixes your problem then that's all the more reason to release a new version soon!

Statistics: Posted by dain — Thu Jul 31, 2014 9:51 pm

]]> 2014-07-31T08:58:08+01:00 2014-07-31T08:58:08+01:00 https://forum.yubico.com/viewtopic.php?t=1380&p=5454#p5454 <![CDATA[Re: [BUG] User lookup failed after long inactivity]]>
Code:
[DEBUG] 2014-07-31 07:15:47 yubiauth.core.controller: User lookup on: u'USERNAME' of type: <type 'unicode'> failed
[INFO] 2014-07-31 07:15:47 yubiauth.core.ldapauth: LDAP authentication successful. Bind DN: "valid DN", server: ldap://DC.domain
[DEBUG] 2014-07-31 07:15:47 yubiauth.core.controller: User lookup on: u'USERNAME' of type: <type 'unicode'> failed
[INFO] 2014-07-31 07:15:47 yubiauth.core.controller: User created: USERNAME
[INFO] 2014-07-31 07:15:47 yubiauth.client.controller: Auto-created LDAP user: USERNAME
[INFO] 2014-07-31 07:15:47 yubiauth.core.ldapauth: LDAP authentication successful. Bind DN: "valid DN", server: ldap://DC.domain
[DEBUG] 2014-07-31 07:15:47 yubico.client: Sending HTTP request to http://localhost/wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPeicirlbuikdvelfvdckebtlenlgtfbbi&nonce=c1sm3X3wZ79AF1KRpRQRw8S8W&h=WAUg3M8WKHCALomptui2T8Acars= (thread=Thread-3)
[DEBUG] 2014-07-31 07:15:47 yubico.client: Using custom CA bunde: /usr/lib/ssl/certs/ca-certificates.crt
[INFO] 2014-07-31 07:15:47 requests.packages.urllib3.connectionpool: Starting new HTTP connection (1): localhost
[DEBUG] 2014-07-31 07:15:47 requests.packages.urllib3.connectionpool: "GET /wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPeicirlbuikdvelfvdckebtlenlgtfbbi&nonce=c1sm3X3wZ79AF1KRpRQRw8S8W&h=WAUg3M8WKHCALomptui2T8Acars= HTTP/1.1" 200 166
[DEBUG] 2014-07-31 07:15:47 yubico.client: Received response from http://localhost/wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPeicirlbuikdvelfvdckebtlenlgtfbbi&nonce=c1sm3X3wZ79AF1KRpRQRw8S8W&h=WAUg3M8WKHCALomptui2T8Acars= (thread=Thread-3): h=XS54K49cuMs4NXF9it5eOCsaqdU=
t=2014-07-31T05:15:47Z0342
otp=SOMEVALIDOTPeicirlbuikdvelfvdckebtlenlgtfbbi
nonce=c1sm3X3wZ79AF1KRpRQRw8S8W
sl=0
status=OK


[DEBUG] 2014-07-31 07:16:22 yubiauth.core.controller: User lookup on: u'USERNAME' of type: <type 'unicode'> failed
[INFO] 2014-07-31 07:16:22 yubiauth.core.ldapauth: LDAP authentication successful. Bind DN: "valid DN", server: ldap://DC.domain
[DEBUG] 2014-07-31 07:16:22 yubiauth.core.controller: User lookup on: u'USERNAME' of type: <type 'unicode'> failed
[INFO] 2014-07-31 07:16:22 yubiauth.core.controller: User created: USERNAME
[INFO] 2014-07-31 07:16:22 yubiauth.client.controller: Auto-created LDAP user: USERNAME
[INFO] 2014-07-31 07:16:22 yubiauth.core.ldapauth: LDAP authentication successful. Bind DN: "valid DN", server: ldap://DC.domain
[DEBUG] 2014-07-31 07:16:22 yubico.client: Sending HTTP request to http://localhost/wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPvitthtlhengircnnjbrhehdejtbhlduf&nonce=ciS2hbWa1SCiFS5hDofCySDAz&h=J7O%2BbMvHIgZuMwwT582KvzWCWlY= (thread=Thread-4)
[DEBUG] 2014-07-31 07:16:22 yubico.client: Using custom CA bunde: /usr/lib/ssl/certs/ca-certificates.crt
[INFO] 2014-07-31 07:16:22 requests.packages.urllib3.connectionpool: Starting new HTTP connection (1): localhost
[DEBUG] 2014-07-31 07:16:22 requests.packages.urllib3.connectionpool: "GET /wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPvitthtlhengircnnjbrhehdejtbhlduf&nonce=ciS2hbWa1SCiFS5hDofCySDAz&h=J7O%2BbMvHIgZuMwwT582KvzWCWlY= HTTP/1.1" 200 168
[DEBUG] 2014-07-31 07:16:22 yubico.client: Received response from http://localhost/wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPvitthtlhengircnnjbrhehdejtbhlduf&nonce=ciS2hbWa1SCiFS5hDofCySDAz&h=J7O%2BbMvHIgZuMwwT582KvzWCWlY= (thread=Thread-4): h=5HTjSoaRIUdAtgPZ4NLjvbM6XWQ=
t=2014-07-31T05:16:22Z0337
otp=SOMEVALIDOTPvitthtlhengircnnjbrhehdejtbhlduf
nonce=ciS2hbWa1SCiFS5hDofCySDAz
sl=0
status=OK

[DEBUG] 2014-07-31 07:18:46 yubiauth.core.controller: User lookup username=USERNAME successful
[INFO] 2014-07-31 07:18:46 yubiauth.core.ldapauth: LDAP authentication successful. Bind DN: "valid DN", server: ldap://DC.domain
[DEBUG] 2014-07-31 07:18:46 yubico.client: Sending HTTP request to http://localhost/wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPfbdvlbetfbuhjivhiekucjfudnfffeld&nonce=3xDQ8sNG8pUws3QAN2SEzIxT7&h=DJdFxxYkT9trwYPzOKOxUZ5j%2BZs= (thread=Thread-4)
[DEBUG] 2014-07-31 07:18:46 yubico.client: Using custom CA bunde: /usr/lib/ssl/certs/ca-certificates.crt
[INFO] 2014-07-31 07:18:46 requests.packages.urllib3.connectionpool: Starting new HTTP connection (1): localhost
[DEBUG] 2014-07-31 07:18:46 requests.packages.urllib3.connectionpool: "GET /wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPfbdvlbetfbuhjivhiekucjfudnfffeld&nonce=3xDQ8sNG8pUws3QAN2SEzIxT7&h=DJdFxxYkT9trwYPzOKOxUZ5j%2BZs= HTTP/1.1" 200 169
[DEBUG] 2014-07-31 07:18:46 yubico.client: Received response from http://localhost/wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPfbdvlbetfbuhjivhiekucjfudnfffeld&nonce=3xDQ8sNG8pUws3QAN2SEzIxT7&h=DJdFxxYkT9trwYPzOKOxUZ5j%2BZs= (thread=Thread-4): h=ENnMR7uM5t25G82+6xTbLjB6tjM=
t=2014-07-31T05:18:46Z0908
otp=SOMEVALIDOTPfbdvlbetfbuhjivhiekucjfudnfffeld
nonce=3xDQ8sNG8pUws3QAN2SEzIxT7
sl=0
status=OK


[INFO] 2014-07-31 07:18:46 yubiauth.client.controller: Authentication successful. Username: USERNAME, password: <valid password>, OTP: SOMEVALIDOTPfbdvlbetfbuhjivhiekucjfudnfffeld
[DEBUG] 2014-07-31 07:19:07 yubiauth.core.controller: User lookup username=USERNAME successful
[INFO] 2014-07-31 07:19:07 yubiauth.core.ldapauth: LDAP authentication successful. Bind DN: "valid DN", server: ldap://DC.domain
[INFO] 2014-07-31 07:19:07 yubiauth.client.controller: Authentication failed. Username: USERNAME, password: <valid password>, OTP: None
[DEBUG] 2014-07-31 07:19:32 yubiauth.core.controller: User lookup on: u'USERNAME' of type: <type 'unicode'> failed
[INFO] 2014-07-31 07:19:32 yubiauth.core.ldapauth: LDAP authentication successful. Bind DN: "valid DN", server: ldap://DC.domain
[DEBUG] 2014-07-31 07:19:32 yubiauth.core.controller: User lookup on: u'USERNAME' of type: <type 'unicode'> failed
[INFO] 2014-07-31 07:19:32 yubiauth.core.controller: User created: USERNAME
[INFO] 2014-07-31 07:19:32 yubiauth.client.controller: Auto-created LDAP user: USERNAME
[INFO] 2014-07-31 07:19:32 yubiauth.core.ldapauth: LDAP authentication successful. Bind DN: "valid DN", server: ldap://DC.domain
[DEBUG] 2014-07-31 07:19:32 yubico.client: Sending HTTP request to http://localhost/wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPhefgcnijlglviedndegihgurevbjiklb&nonce=TIltn5hrFVCdjnxOF5qtbfu8z&h=KmtZGkMalGwpZNmBNeMNLCyZ4C8= (thread=Thread-2)
[DEBUG] 2014-07-31 07:19:32 yubico.client: Using custom CA bunde: /usr/lib/ssl/certs/ca-certificates.crt
[INFO] 2014-07-31 07:19:32 requests.packages.urllib3.connectionpool: Starting new HTTP connection (1): localhost
[DEBUG] 2014-07-31 07:19:32 requests.packages.urllib3.connectionpool: "GET /wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPhefgcnijlglviedndegihgurevbjiklb&nonce=TIltn5hrFVCdjnxOF5qtbfu8z&h=KmtZGkMalGwpZNmBNeMNLCyZ4C8= HTTP/1.1" 200 168
[DEBUG] 2014-07-31 07:19:32 yubico.client: Received response from http://localhost/wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPhefgcnijlglviedndegihgurevbjiklb&nonce=TIltn5hrFVCdjnxOF5qtbfu8z&h=KmtZGkMalGwpZNmBNeMNLCyZ4C8= (thread=Thread-2): h=HEOeSFbpxqlX2qd2mNBUAkxLlTQ=
t=2014-07-31T05:19:32Z0597
otp=SOMEVALIDOTPhefgcnijlglviedndegihgurevbjiklb
nonce=TIltn5hrFVCdjnxOF5qtbfu8z
sl=0
status=OK


[DEBUG] 2014-07-31 07:20:37 yubiauth.core.controller: User lookup username=USERNAME successful
[INFO] 2014-07-31 07:20:37 yubiauth.core.ldapauth: LDAP authentication successful. Bind DN: "valid DN", server: ldap://DC.domain
[DEBUG] 2014-07-31 07:20:37 yubico.client: Sending HTTP request to http://localhost/wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPffufikbddfgtutnurefuufgebuneubvn&nonce=eGkxxkQc0r7FOzU7TPBRdc612&h=uS%2Bdmtea6iatYQlAjlx6k7uUymA= (thread=Thread-4)
[DEBUG] 2014-07-31 07:20:37 yubico.client: Using custom CA bunde: /usr/lib/ssl/certs/ca-certificates.crt
[INFO] 2014-07-31 07:20:37 requests.packages.urllib3.connectionpool: Starting new HTTP connection (1): localhost
[DEBUG] 2014-07-31 07:20:37 requests.packages.urllib3.connectionpool: "GET /wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPffufikbddfgtutnurefuufgebuneubvn&nonce=eGkxxkQc0r7FOzU7TPBRdc612&h=uS%2Bdmtea6iatYQlAjlx6k7uUymA= HTTP/1.1" 200 168
[DEBUG] 2014-07-31 07:20:37 yubico.client: Received response from http://localhost/wsapi/2.0/verify?id=1&otp=SOMEVALIDOTPffufikbddfgtutnurefuufgebuneubvn&nonce=eGkxxkQc0r7FOzU7TPBRdc612&h=uS%2Bdmtea6iatYQlAjlx6k7uUymA= (thread=Thread-4): h=oUHZozwSxlkGoYUE9GFmuAPmCzk=
t=2014-07-31T05:20:37Z0878
otp=SOMEVALIDOTPffufikbddfgtutnurefuufgebuneubvn
nonce=eGkxxkQc0r7FOzU7TPBRdc612
sl=0
status=OK


[INFO] 2014-07-31 07:20:37 yubiauth.client.controller: Authentication successful. Username: USERNAME, password: <valid password>, OTP: SOMEVALIDOTPffufikbddfgtutnurefuufgebuneubvn

Statistics: Posted by Tobias — Thu Jul 31, 2014 8:58 am

]]> 2014-05-07T14:09:21+01:00 2014-05-07T14:09:21+01:00 https://forum.yubico.com/viewtopic.php?t=1380&p=5250#p5250 <![CDATA[[BUG] User lookup failed after long inactivity]]>
Every time I trying to login in the morning, I have to retry exactly 6 times. Here is log:

[DEBUG] 2014-05-07 05:52:43 yubiauth.core.controller: User lookup on: u'myusername' of type: <type 'unicode'> failed
[INFO] 2014-05-07 05:52:43 yubiauth.client.controller: Authentication failed. No such user: myusername
[DEBUG] 2014-05-07 05:52:49 yubiauth.core.controller: User lookup on: u'myusername' of type: <type 'unicode'> failed
[INFO] 2014-05-07 05:52:49 yubiauth.client.controller: Authentication failed. No such user: myusername
[DEBUG] 2014-05-07 05:52:57 yubiauth.core.controller: User lookup on: u'myusername' of type: <type 'unicode'> failed
[INFO] 2014-05-07 05:52:57 yubiauth.client.controller: Authentication failed. No such user: myusername
[DEBUG] 2014-05-07 05:53:59 yubiauth.core.controller: User lookup on: u'myusername' of type: <type 'unicode'> failed
[INFO] 2014-05-07 05:53:59 yubiauth.client.controller: Authentication failed. No such user: myusername
[DEBUG] 2014-05-07 05:54:04 yubiauth.core.controller: User lookup on: u'myusername' of type: <type 'unicode'> failed
[INFO] 2014-05-07 05:54:04 yubiauth.client.controller: Authentication failed. No such user: myusername
[DEBUG] 2014-05-07 05:54:10 yubiauth.core.controller: User lookup username=myusername successful
[DEBUG] 2014-05-07 05:54:10 yubico.client: Sending HTTP request to https://api.yubico.com/wsapi/2.0/verify?id=16386&otp=XXXX&nonce=XXX&h=XXX= (thread=Thread-41)

I have already increased debug level. Can not find where to dig further.

Thank you

Details:

root@yubix-u-nj:~# dpkg -l | grep yub
ii python-yubiadmin 0.1.7-1~ppa1~precise1 Web interface for configuring Yubico services
ii python-yubiauth 0.3.8-1~ppa1~precise1 User management system with YubiKey validation
ii python-yubico-client 1.9.1-1~ppa1~precise1 Python Yubico Client
ii yubikey-ksm 1.13-1~ppa1~precise1 Key Storage Module for YubiKey One-Time Password (OTP) tokens
ii yubikey-val 2.24-1~ppa1~precise1 One-Time Password (OTP) validation server for YubiKey tokens
ii yubix 0.5.6~ppa2~precise1 Sets up and configures basic YubiKey servers

root@yubix-u-nj:~# uname -a
Linux yubix-u-nj 3.11.0-19-generic #33~precise1-Ubuntu SMP Wed Mar 12 21:16:27 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

Statistics: Posted by nvitaly — Wed May 07, 2014 2:09 pm

]]>