Yubico Forum

...visit our web-store at store.yubico.com
It is currently Tue Jan 30, 2018 11:46 am

View unanswered posts | View active topics


Board index » Yubico Software » Server Side Software

All times are UTC + 1 hour




Post new topic Reply to topic  Page 1 of 1
  [ 5 posts ] 
  Print view Previous topic | Next topic 
Author Message
bjankowski
PostPosted: Wed Apr 04, 2012 2:22 pm 
Offline

Joined: Wed Apr 04, 2012 2:12 pm
Posts: 6
Hi
I'm trying to integrate Juniper SA2500, AD 2008 and Yubiradius for 2 stage auth. I've already managed to import all users from ldap(s), and validate Yubikeys in Yubicloud. User has got assigned an Yubikey. However, when I try to troubleshoot auth. on sample user I get:
Code:
Sending Access-Request of id 191 to 127.0.0.1 port 1812
   User-Name = "user.1"
   User-Password = "PASSWORDccccccbcniktbvrkrurkihvdftecldbhcnebfdrvcihg"
   NAS-IP-Address = 127.0.1.1
   NAS-Port = 0
rad_recv: Access-Reject packet from host 127.0.0.1 port 1812, id=191, length=20

In syslog:
Code:
Apr  4 18:56:03 yrva35 ykmap[2145]: LOG_DEBUG:ykmap-synclib:dsi:db:DB query is: select distinct server from queue WHERE queued < 1333545953 or queued is null
Apr  4 18:56:03 yrva35 ykmap[2145]: LOG_INFO:ykmap-synclib:dsi:db:Database error: Array#012(#012    [0] => HY000#012    [1] => 7#012    [2] => no connection to the server#012)
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-verify:[127.0.0.1] Request:
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-common:Reading the appended from sys_settings table
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM sys_settings WHERE key = 'append_otp_to_un_or_passwd'
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-verify:[127.0.0.1]  : user.1 :  missing parameter(s)
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-common:Reading the appended from sys_settings table
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM sys_settings WHERE key = 'temp_passwd_length'
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-common:Reading default domain => params [user: user.1]
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM globalconf WHERE 1 = '1'
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-db:DB query is: SELECT d.domain FROM users u INNER JOIN domains d ON u.domain_id = d.id WHERE u.active = true AND d.active = true AND LOWER(u.login_name) = LOWER('user.1') ORDER BY d.id LIMIT 1
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_INFO:ykropval-common:Reading rop configuration => params [user: user.1, domain: mydomain.local]
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM globalconf WHERE 1 = '1'
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM users u, domains d WHERE d.active = true AND u.active = true AND d.id = u.domain_id AND LOWER(u.login_name) = LOWER('user.1') AND LOWER(d.domain) = LOWER('mydomain.local')
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM ldap_config WHERE domain_id = '149'
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-common:Finding the domain_id
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-db:DB query is: SELECT id FROM domains where active = true and domain ='mydomain.local'
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-common:Finding the domain_id
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_DEBUG:ykropval-db:DB query is: SELECT id FROM domains where active = true and domain ='mydomain.local'
Apr  4 18:56:08 yrva35 ykropval[953]: LOG_INFO:ykropval-common:Error Invalid authentication
Apr  4 18:56:13 yrva35 ykmap[2145]: LOG_DEBUG:ykmap-synclib:dsi:db:DB query is: select distinct server from queue WHERE queued < 1333545963 or queued is null
Apr  4 18:56:13 yrva35 ykmap[2145]: LOG_INFO:ykmap-synclib:dsi:db:Database error: Array#012(#012    [0] => HY000#012    [1] => 7#012    [2] => no connection to the server#012)
Apr  4 18:56:23 yrva35 ykmap[2145]: LOG_DEBUG:ykmap-synclib:dsi:db:DB query is: select distinct server from queue WHERE queued < 1333545973 or queued is null
Apr  4 18:56:23 yrva35 ykmap[2145]: LOG_INFO:ykmap-synclib:dsi:db:Database error: Array#012(#012    [0] => HY000#012    [1] => 7#012    [2] => no connection to the server#012)


In reports it seems that user/pass values are not properly passed:
Code:
YubiRADIUS Virtual Appliance - Authentication Log Report (All records)
Time Range: Upto 2012-04-04 18:59:08
Generated On: 2012-04-04 18:59:08
Timestamp,Username,YubiKey Public ID,Authentication Status
2012-04-04 18:55:13,@,,LDAP validation failed
2012-04-04 18:54:47,@,,LDAP validation failed
2012-04-04 18:53:28,@,,LDAP validation failed


Thx for your help!
Top
 Profile  
Reply with quote  

Share On:
Share on Facebook FacebookShare on Twitter TwitterShare on Tumblr TumblrShare on Google+ Google+

samir
PostPosted: Fri Apr 06, 2012 10:50 am 
Offline
Yubico Team
Yubico Team

Joined: Mon Feb 22, 2010 9:49 am
Posts: 183
If you are using the YubiCloud validation service for validating the OTPs, please verify you have configured the correct Client ID and corresponding API Key in your YRVA settings (the following steps use a pre-created Client ID and API key that can work but for security reasons we recommend you to create a new Client ID and API key by visiting link https://upgrade.yubico.com/getapikey/):
a) In the YRVA Webmin console, navigate to Global Configuration >> Validation Server and select the YubiCloud-Online Validation Service
b) Set the Client ID: 4233 (or your Client ID)
c) API key: 'H9xX7BeTIbhYK3xCb/PSEeRVNvY=' (without quotes) (or the API key corresponding to your Client ID)

If the problem still persists, please configure the log files, make a few authentication attempts and send the log files to [url]support@yubico.com[/url]along with the following details:

1) Version of the YubiRADIUS virtual appliance (YRVA) you are using
2) The OTP validation server you have configured i.e. YubiCloud or on-board OTP validation server in YRVA

To enable logging, following these steps:
I. Login to webmin console for YubiRADIUS
II. Go to "System" >> "System Logs"
III. Click on log file (ykropval, etc. mentioned below)
IV. Select "all" option in "priorities" field of "Message types to log" section
V. Please click on "save" button to save the changes.
VI. Please repeat step 3, 4 and 5 for other log files mentioned below.
VII. Please click on "Apply Changes" button on System Logs page
VIII. Go to "Servers" >> "YubiRADIUS Virtual Appliance"
IX. Navigate 'Global Configuration' >> 'FreeRADIUS' menu, please enable FreeRADIUS Logging
X. Could you please ssh to the YRVA instance and restart the rsyslog process by executing the following command:
/etc/init.d/rsyslog restart
XI. Please try to reassign and test the user with YubiKey credentials.

Please send the following log files to [url]support@yubico.com[/url]
/var/log/syslog
/var/log/messages
/var/log/ykval.log
/var/log/ykropval.log
/var/log/ykmap.log
/var/log/freeradius/radius.log

Thanks!

Samir.
Top
 Profile  
Reply with quote  
bjankowski
PostPosted: Tue Apr 10, 2012 8:50 am 
Offline

Joined: Wed Apr 04, 2012 2:12 pm
Posts: 6
Hello samir,
I've verified my Client ID and API Key, and it seems to be working since I am able to successfully authenticate my OTP against YubiCloud.
I'll send my log files asap.

Moreover, is there any official howto/tutorial regarding integration with Juniper SA solutuions?
Cheers!
Top
 Profile  
Reply with quote  
bjankowski
PostPosted: Thu Apr 12, 2012 9:53 am 
Offline

Joined: Wed Apr 04, 2012 2:12 pm
Posts: 6
Hello again!
From what I managed to work out my problem was because the DB was corrupt... Basically, I've decided to reinstall and use ver. 3.51, however I still cannot get it to work with LDAP(S).

I've imported users and OTP validation against Yubicloud works, but when i troubleshoot sample user i get „Failed to bind to LDAP server”... any suggestions?

Code:
Apr 12 16:19:53 yrva35 ykval[1830]: LOG_DEBUG:ykval-queue:synclib:db:DB query is: select distinct server from queue WHERE queued < 1334227783 or queued is null
Apr 12 16:19:53 yrva35 ykval[1830]: LOG_INFO:ykval-queue:synclib:found 0 unique servers
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] Request:
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-common:Reading the appended from sys_settings table
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM sys_settings WHERE key = 'append_otp_to_un_or_passwd'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1]  : a.user :  missing parameter(s)
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-common:Reading the appended from sys_settings table
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM sys_settings WHERE key = 'temp_passwd_length'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-common:Reading default domain => params [user: a.user]
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM globalconf WHERE 1 = '1'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT d.domain FROM users u INNER JOIN domains d ON u.domain_id = d.id WHERE u.active = true AND d.active = true AND LOWER(u.login_name) = LOWER('a.user') ORDER BY d.id LIMIT 1
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_INFO:ykropvApr 12 16:19:53 yrva35 ykval[1830]: LOG_DEBUG:ykval-queue:synclib:db:DB query is: select distinct server from queue WHERE queued < 1334227783 or queued is null
Apr 12 16:19:53 yrva35 ykval[1830]: LOG_INFO:ykval-queue:synclib:found 0 unique servers
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] Request:
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-common:Reading the appended from sys_settings table
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM sys_settings WHERE key = 'append_otp_to_un_or_passwd'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1]  : a.user :  missing parameter(s)
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-common:Reading the appended from sys_settings table
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM sys_settings WHERE key = 'temp_passwd_length'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-common:Reading default domain => params [user: a.user]
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM globalconf WHERE 1 = '1'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT d.domain FROM users u INNER JOIN domains d ON u.domain_id = d.id WHERE u.active = true AND d.active = true AND LOWER(u.login_name) = LOWER('a.user') ORDER BY d.id LIMIT 1
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_INFO:ykropval-common:Reading rop configuration => params [user: a.user, domain: mydomain.local]
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM globalconf WHERE 1 = '1'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM users u, domains d WHERE d.active = true AND u.active = true AND d.id = u.domain_id AND LOWER(u.login_name) = LOWER('a.user') AND LOWER(d.domain) = LOWER('mydomain.local')
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM ldap_config WHERE domain_id = '290'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-common:Finding the domain_id
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM globalconf WHERE 1 = '1'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT id FROM domains where active = true and LOWER(domain) = LOWER('mydomain.local')
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT temp_passwd FROM users where active = true and domain_id = '290' and LOWER(login_name) = LOWER('a.user') and user_name != ''
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] otp: ccccccbcnikugvkdnbdujbjjvcllughuirefltfcflrt verified
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] Authenticating with LDAP/AD...
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] LDAP server url: ldaps://192.1.1.1:636/
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] LDAP server optional url: ldaps://:636/
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] LDAP protocol version: 3
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] Trying to bind to LDAP server with RDN: CN=206557,OU=93020000,OU=93000000,OU=90000000,OU=00000000,OU=OrgUnits,DC=UW,DC=local
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] LDAP protocol version: 3
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_ERR:ykropval-verify:[127.0.0.1] Failed to bind to LDAP server
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: INSERT INTO authentication_logs (user_name, yk_publicname, auth_status, auth_cause, auth_details) VALUES ('a.user@mydomain.local','ccccccbcniku','0','0','LDAP validation failed')
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-common:SIGN: status=AUTHENTICATION_ERROR&t=2012-04-12T10:49:59Z0389 H=Hw5N1yGALVa84fRUHQ0Kg2rAGTQ=
Apr 12 16:20:00 yrva35 ykmap[1821]: LOG_DEBUG:ykmap-synclib:dsi:db:DB query is: select distinct server from queue WHERE queued < 1334227790 or queued is null
Apr 12 16:20:03 yrva35 ykval[1830]: LOG_INFO:ykval-queue:synclib:starting resync
al-common:Reading rop configuration => params [user: a.user, domain: mydomain.local]
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM globalconf WHERE 1 = '1'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM users u, domains d WHERE d.active = true AND u.active = true AND d.id = u.domain_id AND LOWER(u.login_name) = LOWER('a.user') AND LOWER(d.domain) = LOWER('mydomain.local')
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM ldap_config WHERE domain_id = '290'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-common:Finding the domain_id
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT * FROM globalconf WHERE 1 = '1'
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT id FROM domains where active = true and LOWER(domain) = LOWER('mydomain.local')
Apr 12 16:19:58 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: SELECT temp_passwd FROM users where active = true and domain_id = '290' and LOWER(login_name) = LOWER('a.user') and user_name != ''
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] otp: ccccccbcnikugvkdnbdujbjjvcllughuirefltfcflrt verified
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] Authenticating with LDAP/AD...
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] LDAP server url: ldaps://192.1.1.1:636/
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] LDAP server optional url: ldaps://:636/
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] LDAP protocol version: 3
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] Trying to bind to LDAP server with RDN: CN=206557,OU=93020000,OU=93000000,OU=90000000,OU=00000000,OU=OrgUnits,DC=UW,DC=local
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-verify:[127.0.0.1] LDAP protocol version: 3
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_ERR:ykropval-verify:[127.0.0.1] Failed to bind to LDAP server
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-db:DB query is: INSERT INTO authentication_logs (user_name, yk_publicname, auth_status, auth_cause, auth_details) VALUES ('a.user@mydomain.local','ccccccbcniku','0','0','LDAP validation failed')
Apr 12 16:19:59 yrva35 ykropval[13175]: LOG_DEBUG:ykropval-common:SIGN: status=AUTHENTICATION_ERROR&t=2012-04-12T10:49:59Z0389 H=Hw5N1yGALVa84fRUHQ0Kg2rAGTQ=
Apr 12 16:20:00 yrva35 ykmap[1821]: LOG_DEBUG:ykmap-synclib:dsi:db:DB query is: select distinct server from queue WHERE queued < 1334227790 or queued is null
Apr 12 16:20:03 yrva35 ykval[1830]: LOG_INFO:ykval-queue:synclib:starting resync

Cheers!
Top
 Profile  
Reply with quote  
bjankowski
PostPosted: Mon Apr 23, 2012 2:16 pm 
Offline

Joined: Wed Apr 04, 2012 2:12 pm
Posts: 6
So it turned out it was a problem with gnuTLS i debian with self-sgined certs. I managed to work it out using ldapsearch (ldap-utils).
Bug desc. here:https://bugs.launchpad.net/ubuntu/+source/gnutls13/+bug/397636

What I did was to disable certificate check in /etc/ldap.conf option TLS_REQCERT
Top
 Profile  
Reply with quote  
Display posts from previous:  Sort by  
Post new topic Reply to topic  Page 1 of 1
  [ 5 posts ] 

Board index » Yubico Software » Server Side Software

All times are UTC + 1 hour


Who is online

Users browsing this forum: No registered users and 1 guest

You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot post attachments in this forum

Search for:
Jump to:  
cron
Powered by phpBB® Forum Software © phpBB Group