Yubico Forum :: View topic - YubiRadiusVA - Authentication fails if one of the YRVA fails

Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:[127.0.0.1] Request: id=1&nonce=dbd034d222b3837618a4c46f2726aaa2&otp=--- MY YUBIKEY OTP ---&h=f9QhPNglNI45%2BC6zzkblZA38%2BXE= (at 2012-08-

09T10:54:39+02:00 0.70370900 1344502479) HTTP
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: SELECT id, secret FROM clients WHERE active AND id='1'
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:[127.0.0.1] [--- MY YUBIKEY OTP ---] Client data: id=1 secret=s1lgixvlvNAtrqJeYH4VPLkJxT0=
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-common:SIGN: id=1&nonce=dbd034d222b3837618a4c46f2726aaa2&otp=--- MY YUBIKEY OTP --- H=f9QhPNglNI45+C6zzkblZA38+XE=
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:[127.0.0.1] [--- MY YUBIKEY OTP ---] Decrypted OTP: session_counter=10 low=53616 high=114 session_use=5
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] searching for yk_publicname --- MY YUBIKEY --- in local db
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: SELECT * FROM yubikeys WHERE yk_publicname = '--- MY YUBIKEY ---' LIMIT 1
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] yubikey found in db modified=1344502391 nonce=6e9d071896eea37f8f7516954613aa3e yk_publicname=--- MY YUBIKEY

--- yk_counter=10 yk_use=4 yk_high=114 yk_low=52911
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:[127.0.0.1] [--- MY YUBIKEY OTP ---] Auth data: modified=1344502391 nonce=6e9d071896eea37f8f7516954613aa3e active=1 yk_publicname=--- MY YUBIKEY ---

yk_counter=10 yk_use=4 yk_high=114 yk_low=52911
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: UPDATE yubikeys SET modified='1344502479', yk_counter='10', yk_use='5', yk_low='53616',

yk_high='114', nonce='dbd034d222b3837618a4c46f2726aaa2' WHERE yk_publicname = '--- MY YUBIKEY ---' and (10>yk_counter or (10=yk_counter and 5>yk_use))
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] updated database modified=1344502479 nonce=dbd034d222b3837618a4c46f2726aaa2 yk_publicname=--- MY YUBIKEY ---

yk_counter=10 yk_use=5 yk_high=114 yk_low=53616
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: INSERT INTO queue (queued,modified,otp,server,server_nonce,info) VALUES

('1344502479','1344502479','--- MY YUBIKEY OTP ---','http://172.30.66.73/wsapi/2.0/sync','8bb7650ce1a22250609b600c26ab8401','yk_publicname=--- MY YUBIKEY ---

&yk_counter=10&yk_use=5&yk_high=114&yk_low=53616&nonce=dbd034d222b3837618a4c46f2726aaa2,local_counter=10&local_use=4')
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: SELECT * FROM queue WHERE modified = '1344502479' and server_nonce =

'8bb7650ce1a22250609b600c26ab8401'
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] url in retrieveURLasync is http://172.30.66.73/wsapi/2.0/sync?otp=--- MY YUBIKEY OTP ---

&modified=1344502479&yk_publicname=--- MY YUBIKEY ---&yk_counter=10&yk_use=5&yk_high=114&yk_low=53616&nonce=dbd034d222b3837618a4c46f2726aaa2
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-common:YK-KSM errno/error: 0/ url=http://172.30.66.73/wsapi/2.0/sync?otp=--- MY YUBIKEY OTP ---&modified=1344502479&yk_publicname=--- MY YUBIKEY ---

&yk_counter=10&yk_use=5&yk_high=114&yk_low=53616&nonce=dbd034d222b3837618a4c46f2726aaa2 content_type=text/plain http_code=200 header_size=245 request_size=268 filetime=-1 ssl_verify_result=0 redirect_count=0

total_time=0.042231 namelookup_time=5.4E-5 connect_time=0.000512 pretransfer_time=0.000517 size_upload=0 size_download=214 speed_download=5067 speed_upload=0 download_content_length=214 upload_content_length=0

starttransfer_time=0.042209 redirect_time=0 certinfo=Array
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] local db contains modified=1344502391 nonce=6e9d071896eea37f8f7516954613aa3e yk_publicname=--- MY YUBIKEY

--- yk_counter=10 yk_use=4 yk_high=114 yk_low=52911
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] response contains modified=1344502391 nonce=6e9d071896eea37f8f7516954613aa3e yk_publicname=--- MY YUBIKEY

--- yk_counter=10 yk_use=4 yk_high=114 yk_low=52911
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] OTP contains modified=1344502479 nonce=dbd034d222b3837618a4c46f2726aaa2 yk_publicname=--- MY YUBIKEY ---

yk_counter=10 yk_use=5 yk_high=114 yk_low=53616
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: UPDATE yubikeys SET modified='1344502391', yk_counter='10', yk_use='4', yk_low='52911',

yk_high='114', nonce='6e9d071896eea37f8f7516954613aa3e' WHERE yk_publicname = '--- MY YUBIKEY ---' and (10>yk_counter or (10=yk_counter and 4>yk_use))
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] database not updated modified=1344502391 nonce=6e9d071896eea37f8f7516954613aa3e yk_publicname=--- MY YUBIKEY

--- yk_counter=10 yk_use=4 yk_high=114 yk_low=52911
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] deleting server=http://172.30.66.73/wsapi/2.0/sync modified=1344502479

server_nonce=8bb7650ce1a22250609b600c26ab8401
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: DELETE FROM queue WHERE modified = '1344502479' and server_nonce =

'8bb7650ce1a22250609b600c26ab8401' and server = 'http://172.30.66.73/wsapi/2.0/sync'
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: UPDATE queue SET queued=NULL WHERE server_nonce = '8bb7650ce1a22250609b600c26ab8401'
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:[127.0.0.1] [--- MY YUBIKEY OTP ---] ykval-verify:notice:synclevel=60 nr servers=1 req answers=1 answers=1 valid answers=1 sl success rate=100 timeout=1
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:[127.0.0.1] [--- MY YUBIKEY OTP ---] Timestamp seen=7524015 this=7524720 delta=705 secs=88.125 accessed=1344502391 (2012-08-09 10:53:11) now=1344502479

(2012-08-09 10:54:39) elapsed=88 deviation=0.125 secs or 0%
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-common:SIGN: nonce=dbd034d222b3837618a4c46f2726aaa2&otp=--- MY YUBIKEY OTP ---&sl=100&status=OK&t=2012-08-09T08:54:39Z0895 H=CcI6ldcs5iB3xKbt3mE9d9HByGo=
Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-common:Response: h=CcI6ldcs5iB3xKbt3mE9d9HByGo=#015#012t=2012-08-09T08:54:39Z0895#015#012otp=--- MY YUBIKEY OTP ---

#015#012nonce=dbd034d222b3837618a4c46f2726aaa2#015#012sl=100#015#012status=OK#015#012#015#012 (at 2012-08-09T08:54:39+00:00 0.89565800 1344502479)

Author:	remcobierings [ Thu Aug 09, 2012 1:56 pm ]
Post subject:	YubiRadiusVA - Authentication fails if one of the YRVA fails
We've got two YubiRadius VirtualAppliances which are in sync. But when i shutdown one of the two YRVA, authentification fails on the running still running YRVA. The IP adresses of the YRVA are: 172.30.66.72 yubico01.iam.ia 172.30.66.73 yubico02.iam.ia I've added some logging of the working and not working situation: Working situation (2 active in sync YRVA): Code: Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:[127.0.0.1] Request: id=1&nonce=dbd034d222b3837618a4c46f2726aaa2&otp=--- MY YUBIKEY OTP ---&h=f9QhPNglNI45%2BC6zzkblZA38%2BXE= (at 2012-08- 09T10:54:39+02:00 0.70370900 1344502479) HTTP Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: SELECT id, secret FROM clients WHERE active AND id='1' Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:[127.0.0.1] [--- MY YUBIKEY OTP ---] Client data: id=1 secret=s1lgixvlvNAtrqJeYH4VPLkJxT0= Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-common:SIGN: id=1&nonce=dbd034d222b3837618a4c46f2726aaa2&otp=--- MY YUBIKEY OTP --- H=f9QhPNglNI45+C6zzkblZA38+XE= Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:[127.0.0.1] [--- MY YUBIKEY OTP ---] Decrypted OTP: session_counter=10 low=53616 high=114 session_use=5 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] searching for yk_publicname --- MY YUBIKEY --- in local db Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: SELECT * FROM yubikeys WHERE yk_publicname = '--- MY YUBIKEY ---' LIMIT 1 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] yubikey found in db modified=1344502391 nonce=6e9d071896eea37f8f7516954613aa3e yk_publicname=--- MY YUBIKEY --- yk_counter=10 yk_use=4 yk_high=114 yk_low=52911 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:[127.0.0.1] [--- MY YUBIKEY OTP ---] Auth data: modified=1344502391 nonce=6e9d071896eea37f8f7516954613aa3e active=1 yk_publicname=--- MY YUBIKEY --- yk_counter=10 yk_use=4 yk_high=114 yk_low=52911 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: UPDATE yubikeys SET modified='1344502479', yk_counter='10', yk_use='5', yk_low='53616', yk_high='114', nonce='dbd034d222b3837618a4c46f2726aaa2' WHERE yk_publicname = '--- MY YUBIKEY ---' and (10>yk_counter or (10=yk_counter and 5>yk_use)) Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] updated database modified=1344502479 nonce=dbd034d222b3837618a4c46f2726aaa2 yk_publicname=--- MY YUBIKEY --- yk_counter=10 yk_use=5 yk_high=114 yk_low=53616 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: INSERT INTO queue (queued,modified,otp,server,server_nonce,info) VALUES ('1344502479','1344502479','--- MY YUBIKEY OTP ---','http://172.30.66.73/wsapi/2.0/sync','8bb7650ce1a22250609b600c26ab8401','yk_publicname=--- MY YUBIKEY --- &yk_counter=10&yk_use=5&yk_high=114&yk_low=53616&nonce=dbd034d222b3837618a4c46f2726aaa2,local_counter=10&local_use=4') Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: SELECT * FROM queue WHERE modified = '1344502479' and server_nonce = '8bb7650ce1a22250609b600c26ab8401' Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] url in retrieveURLasync is http://172.30.66.73/wsapi/2.0/sync?otp=--- MY YUBIKEY OTP --- &modified=1344502479&yk_publicname=--- MY YUBIKEY ---&yk_counter=10&yk_use=5&yk_high=114&yk_low=53616&nonce=dbd034d222b3837618a4c46f2726aaa2 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-common:YK-KSM errno/error: 0/ url=http://172.30.66.73/wsapi/2.0/sync?otp=--- MY YUBIKEY OTP ---&modified=1344502479&yk_publicname=--- MY YUBIKEY --- &yk_counter=10&yk_use=5&yk_high=114&yk_low=53616&nonce=dbd034d222b3837618a4c46f2726aaa2 content_type=text/plain http_code=200 header_size=245 request_size=268 filetime=-1 ssl_verify_result=0 redirect_count=0 total_time=0.042231 namelookup_time=5.4E-5 connect_time=0.000512 pretransfer_time=0.000517 size_upload=0 size_download=214 speed_download=5067 speed_upload=0 download_content_length=214 upload_content_length=0 starttransfer_time=0.042209 redirect_time=0 certinfo=Array Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] local db contains modified=1344502391 nonce=6e9d071896eea37f8f7516954613aa3e yk_publicname=--- MY YUBIKEY --- yk_counter=10 yk_use=4 yk_high=114 yk_low=52911 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] response contains modified=1344502391 nonce=6e9d071896eea37f8f7516954613aa3e yk_publicname=--- MY YUBIKEY --- yk_counter=10 yk_use=4 yk_high=114 yk_low=52911 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] OTP contains modified=1344502479 nonce=dbd034d222b3837618a4c46f2726aaa2 yk_publicname=--- MY YUBIKEY --- yk_counter=10 yk_use=5 yk_high=114 yk_low=53616 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: UPDATE yubikeys SET modified='1344502391', yk_counter='10', yk_use='4', yk_low='52911', yk_high='114', nonce='6e9d071896eea37f8f7516954613aa3e' WHERE yk_publicname = '--- MY YUBIKEY ---' and (10>yk_counter or (10=yk_counter and 4>yk_use)) Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] database not updated modified=1344502391 nonce=6e9d071896eea37f8f7516954613aa3e yk_publicname=--- MY YUBIKEY --- yk_counter=10 yk_use=4 yk_high=114 yk_low=52911 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [--- MY YUBIKEY OTP ---] deleting server=http://172.30.66.73/wsapi/2.0/sync modified=1344502479 server_nonce=8bb7650ce1a22250609b600c26ab8401 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: DELETE FROM queue WHERE modified = '1344502479' and server_nonce = '8bb7650ce1a22250609b600c26ab8401' and server = 'http://172.30.66.73/wsapi/2.0/sync' Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [--- MY YUBIKEY OTP ---] DB query is: UPDATE queue SET queued=NULL WHERE server_nonce = '8bb7650ce1a22250609b600c26ab8401' Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:[127.0.0.1] [--- MY YUBIKEY OTP ---] ykval-verify:notice:synclevel=60 nr servers=1 req answers=1 answers=1 valid answers=1 sl success rate=100 timeout=1 Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-verify:[127.0.0.1] [--- MY YUBIKEY OTP ---] Timestamp seen=7524015 this=7524720 delta=705 secs=88.125 accessed=1344502391 (2012-08-09 10:53:11) now=1344502479 (2012-08-09 10:54:39) elapsed=88 deviation=0.125 secs or 0% Aug 9 10:54:39 yubico01 ykval[16269]: LOG_DEBUG:ykval-common:SIGN: nonce=dbd034d222b3837618a4c46f2726aaa2&otp=--- MY YUBIKEY OTP ---&sl=100&status=OK&t=2012-08-09T08:54:39Z0895 H=CcI6ldcs5iB3xKbt3mE9d9HByGo= Aug 9 10:54:39 yubico01 ykval[16269]: LOG_INFO:ykval-common:Response: h=CcI6ldcs5iB3xKbt3mE9d9HByGo=#015#012t=2012-08-09T08:54:39Z0895#015#012otp=--- MY YUBIKEY OTP --- #015#012nonce=dbd034d222b3837618a4c46f2726aaa2#015#012sl=100#015#012status=OK#015#012#015#012 (at 2012-08-09T08:54:39+00:00 0.89565800 1344502479) Not working situation yubico02.iam.ia powered off: Code: Aug 9 10:57:03 yubico01 ykval[16270]: LOG_INFO:ykval-verify:[127.0.0.1] Request: id=1&nonce=68074094b8a386bfc4966dc00fb344e0&otp= --- MY YUBIKEY OTP ---&h=2OCW3/eEWwXF1Cd70AzNERtrU9U= (at 2012-08-09T10:57:03+02:00 0.88526200 1344502623) HTTP Aug 9 10:57:03 yubico01 ykval[16270]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [ --- MY YUBIKEY OTP ---] DB query is: SELECT id, secret FROM clients WHERE active AND id='1' Aug 9 10:57:03 yubico01 ykval[16270]: LOG_DEBUG:ykval-verify:[127.0.0.1] [ --- MY YUBIKEY OTP ---] Client data: id=1 secret=s1lgixvlvNAtrqJeYH4VPLkJxT0= Aug 9 10:57:03 yubico01 ykval[16270]: LOG_DEBUG:ykval-common:SIGN: id=1&nonce=68074094b8a386bfc4966dc00fb344e0&otp= --- MY YUBIKEY OTP --- H=2OCW3/eEWwXF1Cd70AzNERtrU9U= Aug 9 10:57:04 yubico01 ykval[16270]: LOG_DEBUG:ykval-verify:[127.0.0.1] [ --- MY YUBIKEY OTP ---] Decrypted OTP: session_counter=10 low=54768 high=114 session_use=6 Aug 9 10:57:04 yubico01 ykval[16270]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [ --- MY YUBIKEY OTP ---] searching for yk_publicname djcccbcccbrd in local db Aug 9 10:57:04 yubico01 ykval[16270]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [ --- MY YUBIKEY OTP ---] DB query is: SELECT * FROM yubikeys WHERE yk_publicname = 'djcccbcccbrd' LIMIT 1 Aug 9 10:57:04 yubico01 ykval[16270]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [ --- MY YUBIKEY OTP ---] yubikey found in db modified=1344502479 nonce=dbd034d222b3837618a4c46f2726aaa2 yk_publicname=djcccbcccbrd yk_counter=10 yk_use=5 yk_high=114 yk_low=53616 Aug 9 10:57:04 yubico01 ykval[16270]: LOG_DEBUG:ykval-verify:[127.0.0.1] [ --- MY YUBIKEY OTP ---] Auth data: modified=1344502479 nonce=dbd034d222b3837618a4c46f2726aaa2 active=1 yk_publicname=djcccbcccbrd yk_counter=10 yk_use=5 yk_high=114 yk_low=53616 Aug 9 10:57:04 yubico01 ykval[16270]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [ --- MY YUBIKEY OTP ---] DB query is: UPDATE yubikeys SET modified='1344502624', yk_counter='10', yk_use='6', yk_low='54768', yk_high='114', nonce='68074094b8a386bfc4966dc00fb344e0' WHERE yk_publicname = 'djcccbcccbrd' and (10>yk_counter or (10=yk_counter and 6>yk_use)) Aug 9 10:57:04 yubico01 ykval[16270]: LOG_INFO:ykval-verify:synclib:[127.0.0.1] [ --- MY YUBIKEY OTP ---] updated database modified=1344502624 nonce=68074094b8a386bfc4966dc00fb344e0 yk_publicname=djcccbcccbrd yk_counter=10 yk_use=6 yk_high=114 yk_low=54768 Aug 9 10:57:04 yubico01 ykval[16270]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [ --- MY YUBIKEY OTP ---] DB query is: INSERT INTO queue (queued,modified,otp,server,server_nonce,info) VALUES ('1344502624','1344502624',' --- MY YUBIKEY OTP ---','http://172.30.66.73/wsapi/2.0/sync','fb3ce2b60e28af2cf4d2f2032e2d89da','yk_publicname=djcccbcccbrd&yk_counter=10&yk_use=6&yk_high=114&yk_low=54768&nonce=68074094b8a386bfc4966dc00fb344e0,local_counter=10&local_use=5') Aug 9 10:57:04 yubico01 ykval[16270]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [ --- MY YUBIKEY OTP ---] DB query is: SELECT * FROM queue WHERE modified = '1344502624' and server_nonce = 'fb3ce2b60e28af2cf4d2f2032e2d89da' Aug 9 10:57:04 yubico01 ykval[16270]: LOG_DEBUG:ykval-verify:synclib:[127.0.0.1] [ --- MY YUBIKEY OTP ---] url in retrieveURLasync is http://172.30.66.73/wsapi/2.0/sync?otp= --- MY YUBIKEY OTP ---&modified=1344502624&yk_publicname=djcccbcccbrd&yk_counter=10&yk_use=6&yk_high=114&yk_low=54768&nonce=68074094b8a386bfc4966dc00fb344e0 Aug 9 10:57:06 yubico01 ykval[16270]: LOG_WARNING:ykval-verify:synclib:[127.0.0.1] [ --- MY YUBIKEY OTP ---] No responses from validation server pool Aug 9 10:57:06 yubico01 ykval[16270]: LOG_DEBUG:ykval-verify:synclib:db:[127.0.0.1] [ --- MY YUBIKEY OTP ---] DB query is: UPDATE queue SET queued=NULL WHERE server_nonce = 'fb3ce2b60e28af2cf4d2f2032e2d89da' Aug 9 10:57:06 yubico01 ykval[16270]: LOG_INFO:ykval-verify:[127.0.0.1] [ --- MY YUBIKEY OTP ---] ykval-verify:notice:synclevel=60 nr servers=1 req answers=1 answers=0 valid answers=0 sl success rate=0 timeout=1 Aug 9 10:57:06 yubico01 ykval[16270]: LOG_WARNING:ykval-verify:[127.0.0.1] [ --- MY YUBIKEY OTP ---] ykval-verify:notice:Sync failed Aug 9 10:57:06 yubico01 ykval[16270]: LOG_DEBUG:ykval-common:SIGN: nonce=68074094b8a386bfc4966dc00fb344e0&otp= --- MY YUBIKEY OTP ---&sl=0&status=NOT_ENOUGH_ANSWERS&t=2012-08-09T08:57:06Z0037 H=1gEpAlbSfF3zcnKohnk4lkN4Dr0= Aug 9 10:57:06 yubico01 ykval[16270]: LOG_INFO:ykval-common:Response: h=1gEpAlbSfF3zcnKohnk4lkN4Dr0=#015#012t=2012-08-09T08:57:06Z0037#015#012otp= --- MY YUBIKEY OTP ---#015#012nonce=68074094b8a386bfc4966dc00fb344e0#015#012sl=0#015#012status=NOT_ENOUGH_ANSWERS#015#012#015#012 (at 2012-08-09T08:57:06+00:00 0.03761800 1344502626) Aug 9 10:57:07 yubico01 ykval[2241]: LOG_INFO:ykval-queue:synclib:server=http://172.30.66.73/wsapi/2.0/sync , info=yk_publicname=djcccbcccbrd&yk_counter=10&yk_use=6&yk_high=114&yk_low=54768&nonce=68074094b8a386bfc4966dc00fb344e0,local_counter=10&local_use=5 Aug 9 10:57:07 yubico01 ykval[2241]: LOG_DEBUG:ykval-queue:synclib:url is http://172.30.66.73/wsapi/2.0/sync?otp= --- MY YUBIKEY OTP ---&modified=1344502624&yk_publicname=djcccbcccbrd&yk_counter=10&yk_use=6&yk_high=114&yk_low=54768&nonce=68074094b8a386bfc4966dc00fb344e0 [b]Aug 9 10:57:29 yubico01 ykval[2241]: LOG_INFO:ykval-queue:synclib:server=http://172.30.66.73/wsapi/2.0/sync ,[/b] info=yk_publicname=djcccbcccbrd&yk_counter=10&yk_use=6&yk_high=114&yk_low=54768&nonce=68074094b8a386bfc4966dc00fb344e0,local_counter=10&local_use=5 Aug 9 10:57:29 yubico01 ykval[2241]: LOG_DEBUG:ykval-queue:synclib:url is http://172.30.66.73/wsapi/2.0/sync?otp= --- MY YUBIKEY OTP ---&modified=1344502624&yk_publicname=djcccbcccbrd&yk_counter=10&yk_use=6&yk_high=114&yk_low=54768&nonce=68074094b8a386bfc4966dc00fb344e0 As you see above when i try to authenticate on yubico01.iam.ia, yubico01 tries to make an connection with yubico02.iam.ia 172.30.66.73. I hope someone can help me, with this stange problem. We need to go live with our yubiradius servers. Kind regards, Remco Bierings

Author:	kevbo [ Thu Aug 09, 2012 2:47 pm ]
Post subject:	Re: YubiRadiusVA - Authentication fails if one of the YRVA f
I was just logging in to ask the exact same question. Odd. We thought that the VPN appliance wasn't properly failing over, until we dug into the logs and noticed the same behavior as you: server 2 quits sending status=OK when server 1 is down, and instead sends status=NOT_ENOUGH_ANSWERS. Bring server 1 back up, and server 2 starts working. Kind of the opposite of what we want. One thing that I wasn't sure about: I set up synchronization parameters on each unit. Was that right, or should synchronization only be set up one-way?

Author:	kevbo [ Fri Aug 10, 2012 6:55 pm ]
Post subject:	Re: YubiRadiusVA - Authentication fails if one of the YRVA f
Sorry to be a pain, but Yubico: bump? This actually makes a cluster less useful than a single machine, because now, if one goes out, they both do. Is there something wrong with the software, or the configuration? We want to go live with this next week, and we're seriously considering taking down the mirror machine. Thanks.

Author:	samir [ Mon Aug 13, 2012 11:01 am ]
Post subject:	Re: YubiRadiusVA - Authentication fails if one of the YRVA f
Hello, We do not recommend customers to use only two servers for synchronization because if one server is down, all data will be centralized to the remaining server and if that server also fails then there will be data loss. If you still interested in using 2 servers for synchronization, please set the sync level to 0. We recommend you to have four servers and set the sync level to 25% to have each request sync with at least one other server. You can set the default sync level required in the validation server(s) but the clients can also tell the servers how much sync they require per request For more information about the sync level, please refer the below link: http://code.google.com/p/yubikey-val-server-php/ Here are the step by step instructions to set the sync level. 1) SSH to the YubiRADIUS 2) Navigate to the location '/etc/ykval' 3) Open the ykval-config.php file # vim ykval-config.php 4) Set the $baseParams['__YKVAL_SYNC_DEFAULT_LEVEL__'] value as per your requirement. 5) Save the file 6) restart the ykval sync service /etc/init.d/ykval-queue restart Hope this helps! Thanks and best regards, Samir.

Author:	kevbo [ Mon Aug 13, 2012 8:06 pm ]
Post subject:	Re: YubiRadiusVA - Authentication fails if one of the YRVA f
Out of curiosity, how do you get to a minimum of 4? I could see three. Also, I want to make sure I understand how to set up the synchronization in the YubiRadius GUI. Does _each_ server need a shared secret with _each other_ server? So, if you have two servers: A has a secret for B listed B has a secret for B listed If you have three servers: A has a secret for B listed A has a secret for C listed B has a secret for A listed B has a secret for C listed C has a secret for A listed C has a secret for B listed And 12 for 4 servers... Is that right? Kevin

Yubico Forum https://forum.yubico.com/

YubiRadiusVA - Authentication fails if one of the YRVA fails https://forum.yubico.com/viewtopic.php?f=5&t=843	Page 1 of 1

Author:	kevbo [ Tue Nov 27, 2012 6:36 am ]
Post subject:	Re: YubiRadiusVA - Authentication fails if one of the YRVA f
So, I'm finally back to this. I don't understand, well, several things: 1) Why do you recommend 4? If you have 4 running, how many can be _failed_ and have authentication still proceed? 2) I don't understand the "25%" setting. The .php file seems to default to 60%, so at the very least, for the 25% setting to stick, I'd need to edit both the file and the template, right? If this is a setting that users will need to change, maybe it should be in the GUI? 3) To continue, I don't understand what that setting means. Can you explain what it means? 4) I only have 3 physical machines. Making more VMs than that seems kind of silly. Can I set it up so that there are 3 VMs in the cluster and a user can be validated if only 2 of the 3 are responding? How would I do that? (I can't figure out a reliable way to do this with my 3 machines without setting at least 2 VMs up on each physical machine....I want my authentication to proceed if one of my physical machines is down, regardless. I need to be able to reboot them every once in a while.)

Page 1 of 1	All times are UTC + 1 hour
Powered by phpBB® Forum Software © phpBB Group https://www.phpbb.com/