Yubico Forum https://forum.yubico.com/ |
|
[BUG] User lookup failed after long inactivity https://forum.yubico.com/viewtopic.php?f=31&t=1380 |
Page 1 of 1 |
Author: | nvitaly [ Wed May 07, 2014 2:09 pm ] |
Post subject: | [BUG] User lookup failed after long inactivity |
Hello, 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 |
Author: | Tobias [ Thu Jul 31, 2014 8:58 am ] |
Post subject: | Re: [BUG] User lookup failed after long inactivity |
Same here, after some logon tries it works. Same versions. 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 |
Author: | dain [ Thu Jul 31, 2014 9:51 pm ] |
Post subject: | Re: [BUG] User lookup failed after long inactivity |
Can you try making the change shown here: 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! |
Page 1 of 1 | All times are UTC + 1 hour |
Powered by phpBB® Forum Software © phpBB Group https://www.phpbb.com/ |