rooty/yubikey-val
1
0
Fork 0
mirror of https://github.com/Yubico/yubikey-val.git synced 2025-01-20 01:52:15 +01:00
Code Issues Projects Releases Wiki Activity

Unified logging to use Log class defined in ykval-log.php which in turn uses syslog.

Browse Source 
NOTE: ykval common debug function is still available but uses Log class aswell to actually
log message.
This commit is contained in:
Olov Danielson 2010-01-11 12:06:00 +00:00
parent e66dc86f5b
commit a839954882
6 changed files with 119 additions and 102 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

13
ykval-common.php
View File

@ -1,5 +1,7 @@
<?php <?php
require_once('ykval-log.php');
define('S_OK', 'OK'); define('S_OK', 'OK');
define('S_BAD_OTP', 'BAD_OTP'); define('S_BAD_OTP', 'BAD_OTP');
define('S_REPLAYED_OTP', 'REPLAYED_OTP'); define('S_REPLAYED_OTP', 'REPLAYED_OTP');
@ -19,9 +21,15 @@ define('TS_ABS_TOLERANCE', 20);
define('TOKEN_LEN', 32); define('TOKEN_LEN', 32);
global $ykval_common_log;
$ykval_common_log = new Log('ykval-common');
function logdie ($str) function logdie ($str)
{ {
error_log($str); global $ykval_common_log;
$ykval_common_log->log(LOG_EMERG, $str);
die($str . "\n"); die($str . "\n");
} }
@ -66,7 +74,8 @@ function debug() {
$str .= $msg . " "; $str .= $msg . " ";
} }
} }
error_log($str); global $ykval_common_log;
$ykval_common_log->log(LOG_DEBUG, $str);
} }
// Return eg. 2008-11-21T06:11:55Z0711 // Return eg. 2008-11-21T06:11:55Z0711

20
ykval-db.php
View File

@ -39,6 +39,9 @@
* @link http://www.yubico.com/ * @link http://www.yubico.com/
* @link http://code.google.com/p/yubikey-timedelta-server-php/ * @link http://code.google.com/p/yubikey-timedelta-server-php/
*/ */
require_once('ykval-log.php');
class Db class Db
{ {
@ -59,6 +62,8 @@ class Db
$this->db_username=$db_username; $this->db_username=$db_username;
$this->db_password=$db_password; $this->db_password=$db_password;
$this->db_options=$db_options; $this->db_options=$db_options;
$this->myLog=new Log('ykval-db');
} }
/** /**
* function to convert Db timestamps to unixtime(s) * function to convert Db timestamps to unixtime(s)
@ -120,8 +125,7 @@ class Db
try { try {
$this->dbh = new PDO($this->db_dsn, $this->db_username, $this->db_password, $this->db_options); $this->dbh = new PDO($this->db_dsn, $this->db_username, $this->db_password, $this->db_options);
} catch (PDOException $e) { } catch (PDOException $e) {
error_log("hej hopp"); $this->myLog->log(LOG_CRIT, "Database error: " . $e->getMessage());
error_log("Database error: " . $e->getMessage());
$this->dbh=Null; $this->dbh=Null;
return false; return false;
} }
@ -132,14 +136,14 @@ class Db
if($this->dbh) { if($this->dbh) {
$this->result = $this->dbh->query($query); $this->result = $this->dbh->query($query);
if (! $this->result){ if (! $this->result){
error_log('Database error: ' . print_r($this->dbh->errorInfo(), true)); $this->myLog->log(LOG_ERR, 'Database error: ' . print_r($this->dbh->errorInfo(), true));
error_log('Query was: ' . $query); $this->myLog->log(LOG_INFO, 'Query was: ' . $query);
return false; return false;
} }
if ($returnresult) return $this->result; if ($returnresult) return $this->result;
else return true; else return true;
} else { } else {
error_log('No database connection'); $this->myLog->log(LOG_CRIT, 'No database connection');
return false; return false;
} }
} }
@ -217,7 +221,7 @@ class Db
// Insert UPDATE statement at beginning // Insert UPDATE statement at beginning
$query = "UPDATE " . $table . " SET " . $query; $query = "UPDATE " . $table . " SET " . $query;
error_log("query is " . $query); $this->myLog->log(LOG_INFO, "query is " . $query);
return $this->query($query, false); return $this->query($query, false);
} }
@ -306,7 +310,7 @@ or false on failure.
} }
if ($rev==1) $query.= " ORDER BY id DESC"; if ($rev==1) $query.= " ORDER BY id DESC";
if ($nr!=null) $query.= " LIMIT " . $nr; if ($nr!=null) $query.= " LIMIT " . $nr;
// error_log('query is ' .$query);
$result = $this->query($query, true); $result = $this->query($query, true);
if (!$result) return false; if (!$result) return false;
@ -349,7 +353,7 @@ or false on failure.
} }
if ($rev==1) $query.= " ORDER BY id DESC"; if ($rev==1) $query.= " ORDER BY id DESC";
if ($nr!=null) $query.= " LIMIT " . $nr; if ($nr!=null) $query.= " LIMIT " . $nr;
error_log("delete query is " . $query); $this->myLog->log(LOG_INFO, "delete query is " . $query);
return $this->query($query, false); return $this->query($query, false);
} }

4
ykval-queue.php
View File

@ -3,6 +3,7 @@
require_once 'ykval-synclib.php'; require_once 'ykval-synclib.php';
require_once 'ykval-config.php'; require_once 'ykval-config.php';
require_once 'ykval-log.php';
require_once "System/Daemon.php"; require_once "System/Daemon.php";
$appname="ykval-queue"; $appname="ykval-queue";
@ -36,7 +37,7 @@ if ($argc==2 && strcmp($argv[1], "help")==0) {
System_Daemon::start(); // Spawn Deamon! System_Daemon::start(); // Spawn Deamon!
/* Application start */ /* Application start */
$sl = new SyncLib(); $sl = new SyncLib('queue-synclib');
# Loop forever and resync # Loop forever and resync
@ -47,7 +48,6 @@ while ($res==0) {
$res=sleep($baseParams['__YKVAL_SYNC_INTERVAL__']); $res=sleep($baseParams['__YKVAL_SYNC_INTERVAL__']);
} }
error_log("Stopping " . $appname);
System_Daemon::stop(); System_Daemon::stop();
?> ?>

37
ykval-sync.php
View File

@ -7,9 +7,11 @@ $apiKey = '';
header("content-type: text/plain"); header("content-type: text/plain");
debug("Request: " . $_SERVER['QUERY_STRING']); $myLog = new Log('ykval-sync');
$myLog->log(LOG_INFO, "Request: " . $_SERVER['QUERY_STRING']);
$sync = new SyncLib('ykval-sync:synclib');
$sync = new SyncLib('ykval-sync');
if (! $sync->isConnected()) { if (! $sync->isConnected()) {
sendResp(S_BACKEND_ERROR, $apiKey); sendResp(S_BACKEND_ERROR, $apiKey);
exit; exit;
@ -19,17 +21,18 @@ if (! $sync->isConnected()) {
# Verify that request comes from valid server # Verify that request comes from valid server
# #
$sync->log('notice', 'remote request ip is ' . $_SERVER['REMOTE_ADDR']); $myLog->log(LOG_INFO, 'remote request ip is ' . $_SERVER['REMOTE_ADDR']);
$allowed=False; $allowed=False;
foreach ($baseParams['__YKVAL_ALLOWED_SYNC_POOL__'] as $server) { foreach ($baseParams['__YKVAL_ALLOWED_SYNC_POOL__'] as $server) {
$sync->log('notice', 'checking against ip ' . $server); $myLog->log(LOG_DEBUG, 'checking against ip ' . $server);
if ($_SERVER['REMOTE_ADDR'] == $server) { if ($_SERVER['REMOTE_ADDR'] == $server) {
$sync->log('notice', 'server ' . $server . ' is allowed'); $myLog->log(LOG_DEBUG, 'server ' . $server . ' is allowed');
$allowed=True; $allowed=True;
break; break;
} }
} }
if (!$allowed) { if (!$allowed) {
$myLog->log(LOG_NOTICE, 'Operation not allowed from IP ' . $_SERVER['REMOTE_ADDR']);
sendResp(S_OPERATION_NOT_ALLOWED, $apiKey); sendResp(S_OPERATION_NOT_ALLOWED, $apiKey);
exit; exit;
} }
@ -51,18 +54,18 @@ $syncParams=array('modified'=>Null,
# Extract values from HTTP request # Extract values from HTTP request
# #
$tmp_log = "ykval-sync received "; $tmp_log = "Received ";
foreach ($syncParams as $param=>$value) { foreach ($syncParams as $param=>$value) {
$value = getHttpVal($param, Null); $value = getHttpVal($param, Null);
if ($value==Null) { if ($value==Null) {
debug("ykval-sync recevied request with parameter[s] missing"); $myLog->log(LOG_NOTICE, "Recevied request with parameter[s] missing");
sendResp(S_MISSING_PARAMETER, ''); sendResp(S_MISSING_PARAMETER, '');
exit; exit;
} }
$syncParams[$param]=$value; $syncParams[$param]=$value;
$local_log .= "$param=$value "; $local_log .= "$param=$value ";
} }
debug($tmp_log); $myLog->log(LOG_INFO, $tmp_log);
# #
# Get local counter data # Get local counter data
@ -71,13 +74,13 @@ debug($tmp_log);
$yk_publicname = $syncParams['yk_publicname']; $yk_publicname = $syncParams['yk_publicname'];
$localParams = $sync->getLocalParams($yk_publicname); $localParams = $sync->getLocalParams($yk_publicname);
if (!$localParams) { if (!$localParams) {
debug('Invalid Yubikey ' . $yk_publicname); $myLog->log(LOG_NOTICE, 'Invalid Yubikey ' . $yk_publicname);
sendResp(S_BACKEND_ERROR, $apiKey); sendResp(S_BACKEND_ERROR, $apiKey);
exit; exit;
} }
if ($localParams['active'] != 1) { if ($localParams['active'] != 1) {
debug('De-activated Yubikey ' . $yk_publicname); $myLog->log(LOG_NOTICE, 'De-activated Yubikey ' . $yk_publicname);
sendResp(S_BAD_OTP, $apiKey); sendResp(S_BAD_OTP, $apiKey);
exit; exit;
} }
@ -94,8 +97,8 @@ $sync->updateDbCounters($syncParams);
if ($sync->countersHigherThan($localParams, $syncParams)) { if ($sync->countersHigherThan($localParams, $syncParams)) {
/* sync counters are lower than local counters */ /* sync counters are lower than local counters */
$sync->log('warning', 'Remote server out of sync. Local params ' , $localParams); $myLog->log(LOG_WARNING, 'Remote server out of sync. Local params ' , $localParams);
$sync->log('warning', 'Remote server out of sync. Sync params ' , $syncParams); $myLog->log(LOG_WARNING, 'Remote server out of sync. Sync params ' , $syncParams);
} }
if ($sync->countersEqual($localParams, $syncParams)) { if ($sync->countersEqual($localParams, $syncParams)) {
@ -103,16 +106,16 @@ if ($sync->countersEqual($localParams, $syncParams)) {
if ($syncParams['modified']==$localParams['modified']) { if ($syncParams['modified']==$localParams['modified']) {
/* sync modified is equal to local modified. /* sync modified is equal to local modified.
Sync request is unnessecarily sent, we log a "light" warning */ Sync request is unnessecarily sent, we log a "light" warning */
$sync->log('warning', 'Sync request unnessecarily sent'); $myLog->log(LOG_WARNING, 'Sync request unnessecarily sent');
} else { } else {
/* sync modified is not equal to local modified. /* sync modified is not equal to local modified.
We have an OTP replay attempt somewhere in the system */ We have an OTP replay attempt somewhere in the system */
$sync->log('warning', 'Replayed OTP attempt. Modified differs. Local ', $localParams); $myLog->log(LOG_WARNING, 'Replayed OTP attempt. Modified differs. Local ', $localParams);
$sync->log('warning', 'Replayed OTP attempt. Modified differs. Sync ', $syncParams); $myLog->log(LOG_WARNING, 'Replayed OTP attempt. Modified differs. Sync ', $syncParams);
} }
if ($syncParams['nonce']!=$localParams['nonce']) { if ($syncParams['nonce']!=$localParams['nonce']) {
$sync->log('warning', 'Replayed OTP attempt. Nonce differs. Local ', $localParams); $myLog->log(LOG_WARNING, 'Replayed OTP attempt. Nonce differs. Local ', $localParams);
$sync->log('warning', 'Replayed OTP attempt. Nonce differs. Sync ', $syncParams); $myLog->log(LOG_WARNING, 'Replayed OTP attempt. Nonce differs. Sync ', $syncParams);
} }
} }

82
ykval-synclib.php
View File

@ -3,6 +3,7 @@
require_once 'ykval-config.php'; require_once 'ykval-config.php';
require_once 'ykval-common.php'; require_once 'ykval-common.php';
require_once 'ykval-db.php'; require_once 'ykval-db.php';
require_once 'ykval-log.php';
class SyncLib class SyncLib
{ {
@ -11,7 +12,7 @@ class SyncLib
function __construct($logname='ykval-synclib') function __construct($logname='ykval-synclib')
{ {
$this->logname=$logname; $this->myLog = new Log($logname);
global $baseParams; global $baseParams;
$this->syncServers = $baseParams['__YKVAL_SYNC_POOL__']; $this->syncServers = $baseParams['__YKVAL_SYNC_POOL__'];
@ -125,9 +126,9 @@ class SyncLib
else return 0; else return 0;
} }
public function log($level, $msg, $params=NULL) public function log($priority, $msg, $params=NULL)
{ {
$logMsg=$this->logname . ':' . $level . ':' . $msg; $logMsg=$msg;
if ($params) $logMsg .= ' modified=' . $params['modified'] . if ($params) $logMsg .= ' modified=' . $params['modified'] .
' nonce=' . $params['nonce'] . ' nonce=' . $params['nonce'] .
' yk_publicname=' . $params['yk_publicname'] . ' yk_publicname=' . $params['yk_publicname'] .
@ -135,15 +136,16 @@ class SyncLib
' yk_use=' . $params['yk_use'] . ' yk_use=' . $params['yk_use'] .
' yk_high=' . $params['yk_high'] . ' yk_high=' . $params['yk_high'] .
' yk_low=' . $params['yk_low']; ' yk_low=' . $params['yk_low'];
error_log($logMsg); if ($this->myLog) $this->myLog->log($priority, $logMsg);
else error_log("Warning: myLog uninitialized in ykval-synclib.php. Message is " . $logMsg);
} }
function getLocalParams($yk_publicname) function getLocalParams($yk_publicname)
{ {
$this->log("notice", "searching for " . $yk_publicname . " (" . $yk_publicname . ") in local db"); $this->log(LOG_NOTICE, "searching for yk_publicname " . $yk_publicname . " in local db");
$res = $this->db->findBy('yubikeys', 'yk_publicname', $yk_publicname,1); $res = $this->db->findBy('yubikeys', 'yk_publicname', $yk_publicname,1);
if (!$res) { if (!$res) {
$this->log('notice', 'Discovered new identity ' . $yk_publicname); $this->log(LOG_NOTICE, 'Discovered new identity ' . $yk_publicname);
$this->db->save('yubikeys', array('yk_publicname'=>$yk_publicname, $this->db->save('yubikeys', array('yk_publicname'=>$yk_publicname,
'active'=>1, 'active'=>1,
'yk_counter'=>0, 'yk_counter'=>0,
@ -163,10 +165,10 @@ class SyncLib
'yk_high'=>$res['yk_high'], 'yk_high'=>$res['yk_high'],
'yk_low'=>$res['yk_low']); 'yk_low'=>$res['yk_low']);
$this->log("notice", "counter found in db ", $localParams); $this->log(LOG_NOTICE, "counter found in db ", $localParams);
return $localParams; return $localParams;
} else { } else {
$this->log('notice', 'params for identity ' . $yk_publicname . ' not found in database'); $this->log(LOG_NOTICE, 'params for identity ' . $yk_publicname . ' not found in database');
return false; return false;
} }
} }
@ -207,11 +209,11 @@ class SyncLib
'nonce'=>$params['nonce']), 'nonce'=>$params['nonce']),
$condition)) $condition))
{ {
error_log("ykval-synclib:critical: failed to update internal DB with new counters"); $this->log(LOG_CRIT, 'failed to update internal DB with new counters');
return false; return false;
} else { } else {
if ($this->db->rowCount()>0) $this->log("notice", "updated database ", $params); if ($this->db->rowCount()>0) $this->log(LOG_NOTICE, "updated database ", $params);
else $this->log('notice', 'database not updated', $params); else $this->log(LOG_NOTICE, 'database not updated', $params);
return true; return true;
} }
} else return false; } else return false;
@ -241,9 +243,9 @@ class SyncLib
preg_match('/url=(.*)\?/', $answer, $out); preg_match('/url=(.*)\?/', $answer, $out);
$server=$out[1]; $server=$out[1];
debug("deleting server=" . $server); $this->log(LOG_DEBUG, "deleting server=" . $server .
debug("modified=" . $this->otpParams['modified']); " modified=" . $this->otpParams['modified'] .
debug("random_key=" . $this->random_key); " random_key=" . $this->random_key);
$this->db->deleteByMultiple('queue', $this->db->deleteByMultiple('queue',
array("modified"=>$this->otpParams['modified'], array("modified"=>$this->otpParams['modified'],
"random_key"=>$this->random_key, "random_key"=>$this->random_key,
@ -252,19 +254,19 @@ class SyncLib
public function reSync($older_than=60, $timeout) public function reSync($older_than=60, $timeout)
{ {
$this->log('notice', 'starting resync'); $this->log(LOG_NOTICE, 'starting resync');
/* Loop over all unique servers in queue */ /* Loop over all unique servers in queue */
$queued_limit=time()-$older_than; $queued_limit=time()-$older_than;
$res=$this->db->customQuery("select distinct server from queue WHERE queued < " . $queued_limit . " or queued is null"); $res=$this->db->customQuery("select distinct server from queue WHERE queued < " . $queued_limit . " or queued is null");
error_log("found " . $res->rowCount() . " unique servers"); $this->log(LOG_NOTICE, "found " . $res->rowCount() . " unique servers");
foreach ($res as $my_server) { foreach ($res as $my_server) {
error_log("Sending queue request to server on server " . $my_server['server']); $this->log(LOG_INFO, "Sending queue request to server on server " . $my_server['server']);
$res=$this->db->customQuery("select * from queue WHERE (queued < " . $queued_limit . " or queued is null) and server='" . $my_server['server'] . "'"); $res=$this->db->customQuery("select * from queue WHERE (queued < " . $queued_limit . " or queued is null) and server='" . $my_server['server'] . "'");
error_log("found " . $res->rowCount() . " queue entries"); $this->log(LOG_INFO, "found " . $res->rowCount() . " queue entries");
while ($entry=$res->fetch(PDO::FETCH_ASSOC)) { while ($entry=$res->fetch(PDO::FETCH_ASSOC)) {
$this->log('notice', "server=" . $entry['server'] . " , info=" . $entry['info']); $this->log(LOG_NOTICE, "server=" . $entry['server'] . " , info=" . $entry['info']);
$url=$entry['server'] . $url=$entry['server'] .
"?otp=" . $entry['otp'] . "?otp=" . $entry['otp'] .
"&modified=" . $entry['modified'] . "&modified=" . $entry['modified'] .
@ -272,7 +274,7 @@ class SyncLib
/* Send out sync request */ /* Send out sync request */
$this->log('notice', 'url is ' . $url); $this->log(LOG_NOTICE, 'url is ' . $url);
$ch = curl_init($url); $ch = curl_init($url);
curl_setopt($ch, CURLOPT_USERAGENT, "YK-VAL"); curl_setopt($ch, CURLOPT_USERAGENT, "YK-VAL");
curl_setopt($ch, CURLOPT_RETURNTRANSFER, 1); curl_setopt($ch, CURLOPT_RETURNTRANSFER, 1);
@ -283,13 +285,13 @@ class SyncLib
curl_close($ch); curl_close($ch);
if ($response==False) { if ($response==False) {
$this->log('warning', 'Timeout. Stopping queue resync for server ' . $my_server['server']); $this->log(LOG_WARNING, 'Timeout. Stopping queue resync for server ' . $my_server['server']);
break; break;
} }
if (preg_match("/status=OK/", $response)) { if (preg_match("/status=OK/", $response)) {
$resParams=$this->parseParamsFromMultiLineString($response); $resParams=$this->parseParamsFromMultiLineString($response);
$this->log("notice", "response contains ", $resParams); $this->log(LOG_NOTICE, "response contains ", $resParams);
/* Update database counters */ /* Update database counters */
$this->updateDbCounters($resParams); $this->updateDbCounters($resParams);
@ -305,16 +307,16 @@ class SyncLib
last counters (indicating that remote server wasn't synced) last counters (indicating that remote server wasn't synced)
*/ */
if ($this->countersHigherThan($localParams, $resParams)) { if ($this->countersHigherThan($localParams, $resParams)) {
$this->log("warning", "queued:Remote server out of sync, local counters ", $localParams); $this->log(LOG_WARNING, "queued:Remote server out of sync, local counters ", $localParams);
$this->log("warning", "queued:Remote server out of sync, remote counters ", $resParams); $this->log(LOG_WARNING, "queued:Remote server out of sync, remote counters ", $resParams);
} }
/* If received sync response have higher counters than locally saved /* If received sync response have higher counters than locally saved
last counters (indicating that local server wasn't synced) last counters (indicating that local server wasn't synced)
*/ */
if ($this->countersHigherThan($resParams, $localParams)) { if ($this->countersHigherThan($resParams, $localParams)) {
$this->log("warning", "queued:Local server out of sync, local counters ", $localParams); $this->log(LOG_WARNING, "queued:Local server out of sync, local counters ", $localParams);
$this->log("warning", "queued:Local server out of sync, remote counters ", $resParams); $this->log(LOG_WARNING, "queued:Local server out of sync, remote counters ", $resParams);
} }
if ($this->countersHigherThan($resParams, $otpParams) || if ($this->countersHigherThan($resParams, $otpParams) ||
@ -325,12 +327,12 @@ class SyncLib
(indicating REPLAYED_OTP) (indicating REPLAYED_OTP)
*/ */
$this->log("warning", "queued:replayed OTP, remote counters " , $resParams); $this->log(LOG_WARNING, "queued:replayed OTP, remote counters " , $resParams);
$this->log("warning", "queued:replayed OTP, otp counters", $otpParams); $this->log(LOG_WARNING, "queued:replayed OTP, otp counters", $otpParams);
} }
/* Deletion */ /* Deletion */
$this->log('notice', 'deleting queue entry with id=' . $entry['id']); $this->log(LOG_NOTICE, 'deleting queue entry with id=' . $entry['id']);
$this->db->deleteByMultiple('queue', array('id'=>$entry['id'])); $this->db->deleteByMultiple('queue', array('id'=>$entry['id']));
} }
@ -360,7 +362,7 @@ class SyncLib
$ans_arr=$this->retrieveURLasync($urls, $ans_req, $timeout); $ans_arr=$this->retrieveURLasync($urls, $ans_req, $timeout);
if (!is_array($ans_arr)) { if (!is_array($ans_arr)) {
$this->log('warning', 'No responses from validation server pool'); $this->log(LOG_WARNING, 'No responses from validation server pool');
$ans_arr=array(); $ans_arr=array();
} }
@ -374,8 +376,8 @@ class SyncLib
foreach ($ans_arr as $answer){ foreach ($ans_arr as $answer){
/* Parse out parameters from each response */ /* Parse out parameters from each response */
$resParams=$this->parseParamsFromMultiLineString($answer); $resParams=$this->parseParamsFromMultiLineString($answer);
$this->log("notice", "local db contains ", $localParams); $this->log(LOG_NOTICE, "local db contains ", $localParams);
$this->log("notice", "response contains ", $resParams); $this->log(LOG_NOTICE, "response contains ", $resParams);
/* Update internal DB (conditional) */ /* Update internal DB (conditional) */
@ -388,16 +390,16 @@ class SyncLib
(indicating that remote server wasn't synced) (indicating that remote server wasn't synced)
*/ */
if ($this->countersHigherThan($localParams, $resParams)) { if ($this->countersHigherThan($localParams, $resParams)) {
$this->log("warning", "Remote server out of sync, local counters ", $localParams); $this->log(LOG_WARNING, "Remote server out of sync, local counters ", $localParams);
$this->log("warning", "Remote server out of sync, remote counters ", $resParams); $this->log(LOG_WARNING, "Remote server out of sync, remote counters ", $resParams);
} }
/* If received sync response have higher counters than local db /* If received sync response have higher counters than local db
(indicating that local server wasn't synced) (indicating that local server wasn't synced)
*/ */
if ($this->countersHigherThan($resParams, $localParams)) { if ($this->countersHigherThan($resParams, $localParams)) {
$this->log("warning", "Local server out of sync, local counters ", $localParams); $this->log(LOG_WARNING, "Local server out of sync, local counters ", $localParams);
$this->log("warning", "Local server out of sync, remote counters ", $resParams); $this->log(LOG_WARNING, "Local server out of sync, remote counters ", $resParams);
} }
if ($this->countersHigherThan($resParams, $this->otpParams) || if ($this->countersHigherThan($resParams, $this->otpParams) ||
@ -408,8 +410,8 @@ class SyncLib
(indicating REPLAYED_OTP) (indicating REPLAYED_OTP)
*/ */
$this->log("warning", "replayed OTP, remote counters " , $resParams); $this->log(LOG_WARNING, "replayed OTP, remote counters " , $resParams);
$this->log("warning", "replayed OTP, otp counters", $this->otpParams); $this->log(LOG_WARNING, "replayed OTP, otp counters", $this->otpParams);
} else { } else {
/* The answer is ok since a REPLAY was not indicated */ /* The answer is ok since a REPLAY was not indicated */
@ -468,7 +470,7 @@ class SyncLib
$ch = array(); $ch = array();
foreach ($urls as $id => $url) { foreach ($urls as $id => $url) {
error_log("url is " . $url); $this->log(LOG_INFO, "url in retrieveURLasync is " . $url);
$handle = curl_init(); $handle = curl_init();
curl_setopt($handle, CURLOPT_URL, $url); curl_setopt($handle, CURLOPT_URL, $url);
@ -494,14 +496,12 @@ class SyncLib
debug ("YK-KSM multi", $info); debug ("YK-KSM multi", $info);
if ($info['result'] == CURL_OK) { if ($info['result'] == CURL_OK) {
$str = curl_multi_getcontent($info['handle']); $str = curl_multi_getcontent($info['handle']);
debug($str);
if (preg_match("/status=OK/", $str)) { if (preg_match("/status=OK/", $str)) {
$error = curl_error ($info['handle']); $error = curl_error ($info['handle']);
$errno = curl_errno ($info['handle']); $errno = curl_errno ($info['handle']);
$cinfo = curl_getinfo ($info['handle']); $cinfo = curl_getinfo ($info['handle']);
debug("YK-KSM errno/error: " . $errno . "/" . $error, $cinfo); debug("YK-KSM errno/error: " . $errno . "/" . $error, $cinfo);
$ans_count++; $ans_count++;
debug("found entry");
$ans_arr[]="url=" . $cinfo['url'] . "\n" . $str; $ans_arr[]="url=" . $cinfo['url'] . "\n" . $str;
} }

41
ykval-verify.php
View File

@ -7,7 +7,8 @@ $apiKey = '';
header("content-type: text/plain"); header("content-type: text/plain");
debug("Request: " . $_SERVER['QUERY_STRING']); $myLog = new Log('ykval-verify');
$myLog->log(LOG_INFO, "Request: " . $_SERVER['QUERY_STRING']);
/* Detect protocol version */ /* Detect protocol version */
if (preg_match("/\/wsapi\/([0-9]*)\.([0-9]*)\//", $_SERVER['REQUEST_URI'], $out)) { if (preg_match("/\/wsapi\/([0-9]*)\.([0-9]*)\//", $_SERVER['REQUEST_URI'], $out)) {
@ -15,7 +16,7 @@ if (preg_match("/\/wsapi\/([0-9]*)\.([0-9]*)\//", $_SERVER['REQUEST_URI'], $out)
} else { } else {
$protocol_version=1.0; $protocol_version=1.0;
} }
debug("found protocol version " . $protocol_version); $myLog->log(LOG_INFO, "found protocol version " . $protocol_version);
/* Initialize the sync library. Strive to use this instead of custom DB requests, /* Initialize the sync library. Strive to use this instead of custom DB requests,
custom comparisons etc */ custom comparisons etc */
@ -41,7 +42,7 @@ if ($protocol_version>=2.0) {
/* Nonce is required from protocol 2.0 */ /* Nonce is required from protocol 2.0 */
if(!$nonce || strlen($nonce)<16) { if(!$nonce || strlen($nonce)<16) {
debug('Protocol version >= 2.0. Nonce is missing'); $myLog->log(LOG_NOTICE, 'Protocol version >= 2.0. Nonce is missing');
sendResp(S_MISSING_PARAMETER, $apiKey); sendResp(S_MISSING_PARAMETER, $apiKey);
exit; exit;
} }
@ -50,23 +51,23 @@ if ($protocol_version>=2.0) {
if ($protocol_version<2.0) { if ($protocol_version<2.0) {
/* We need to create a nonce manually here */ /* We need to create a nonce manually here */
$nonce = md5(uniqid(rand())); $nonce = md5(uniqid(rand()));
debug('protocol version below 2.0. Created nonce ' . $nonce); $myLog->log(LOG_INFO, 'protocol version below 2.0. Created nonce ' . $nonce);
} }
//// Get Client info from DB //// Get Client info from DB
// //
if ($client <= 0) { if ($client <= 0) {
debug('Client ID is missing'); $myLog->log(LOG_NOTICE, 'Client ID is missing');
sendResp(S_MISSING_PARAMETER, $apiKey); sendResp(S_MISSING_PARAMETER, $apiKey);
exit; exit;
} }
$cd=$sync->getClientData($client); $cd=$sync->getClientData($client);
if(!$cd) { if(!$cd) {
debug('Invalid client id ' . $client); $myLog->log(LOG_NOTICE, 'Invalid client id ' . $client);
sendResp(S_NO_SUCH_CLIENT); sendResp(S_NO_SUCH_CLIENT);
exit; exit;
} }
debug("Client data:", $cd); $myLog->log(LOG_DEBUG,"Client data:", $cd);
//// Check client signature //// Check client signature
// //
@ -86,7 +87,7 @@ if ($h != '') {
$hmac = sign($a, $apiKey); $hmac = sign($a, $apiKey);
// Compare it // Compare it
if ($hmac != $h) { if ($hmac != $h) {
debug('client hmac=' . $h . ', server hmac=' . $hmac); $myLog->log(LOG_DEBUG, 'client hmac=' . $h . ', server hmac=' . $hmac);
sendResp(S_BAD_SIGNATURE, $apiKey); sendResp(S_BAD_SIGNATURE, $apiKey);
exit; exit;
} }
@ -95,12 +96,12 @@ if ($h != '') {
//// Sanity check OTP //// Sanity check OTP
// //
if ($otp == '') { if ($otp == '') {
debug('OTP is missing'); $myLog->log(LOG_NOTICE, 'OTP is missing');
sendResp(S_MISSING_PARAMETER, $apiKey); sendResp(S_MISSING_PARAMETER, $apiKey);
exit; exit;
} }
if (strlen($otp) <= TOKEN_LEN) { if (strlen($otp) <= TOKEN_LEN) {
debug('Too short OTP: ' . $otp); $myLog->log(LOG_NOTICE, 'Too short OTP: ' . $otp);
sendResp(S_BAD_OTP, $apiKey); sendResp(S_BAD_OTP, $apiKey);
exit; exit;
} }
@ -120,7 +121,7 @@ if (!is_array($otpinfo)) {
sendResp(S_BAD_OTP, $apiKey); sendResp(S_BAD_OTP, $apiKey);
exit; exit;
} }
debug("Decrypted OTP:", $otpinfo); $myLog->log(LOG_DEBUG, "Decrypted OTP:", $otpinfo);
//// Get Yubikey from DB //// Get Yubikey from DB
// //
@ -128,14 +129,14 @@ $devId = substr($otp, 0, strlen ($otp) - TOKEN_LEN);
$yk_publicname=$devId; $yk_publicname=$devId;
$localParams = $sync->getLocalParams($yk_publicname); $localParams = $sync->getLocalParams($yk_publicname);
if (!$localParams) { if (!$localParams) {
debug('Invalid Yubikey ' . $yk_publicname); $myLog->log(LOG_NOTICE, 'Invalid Yubikey ' . $yk_publicname);
sendResp(S_BACKEND_ERROR, $apiKey); sendResp(S_BACKEND_ERROR, $apiKey);
exit; exit;
} }
debug("Auth data:", $localParams); $myLog->log(LOG_DEBUG, "Auth data:", $localParams);
if ($localParams['active'] != 1) { if ($localParams['active'] != 1) {
debug('De-activated Yubikey ' . $devId); $myLog->log(LOG_NOTICE, 'De-activated Yubikey ' . $devId);
sendResp(S_BAD_OTP, $apiKey); sendResp(S_BAD_OTP, $apiKey);
exit; exit;
} }
@ -155,7 +156,7 @@ $otpParams=array('modified'=>time(),
/* First check if OTP is seen with the same nonce, in such case we have an replayed request */ /* First check if OTP is seen with the same nonce, in such case we have an replayed request */
if ($sync->countersEqual($localParams, $otpParams) && if ($sync->countersEqual($localParams, $otpParams) &&
$localParams['nonce']==$otpParams['nonce']) { $localParams['nonce']==$otpParams['nonce']) {
debug('Replayed request'); $myLog->log(LOG_WARNING, 'Replayed request');
sendResp(S_REPLAYED_REQUEST, $apikey); sendResp(S_REPLAYED_REQUEST, $apikey);
exit; exit;
} }
@ -179,7 +180,7 @@ if(!$sync->updateDbCounters($otpParams)) {
/* Queue sync requests */ /* Queue sync requests */
if (!$sync->queue($otpParams, $localParams)) { if (!$sync->queue($otpParams, $localParams)) {
debug("ykval-verify:critical:failed to queue sync requests"); $myLog->log(LOG_CRIT, "ykval-verify:critical:failed to queue sync requests");
sendResp(S_BACKEND_ERROR, $apiKey); sendResp(S_BACKEND_ERROR, $apiKey);
exit; exit;
} }
@ -203,7 +204,7 @@ if ($req_answers>0) {
$nr_valid_answers=0; $nr_valid_answers=0;
$sl_success_rate=0; $sl_success_rate=0;
} }
debug("ykval-verify:notice:synclevel=" . $sl . $myLog->log(LOG_INFO, "ykval-verify:notice:synclevel=" . $sl .
" nr servers=" . $nr_servers . " nr servers=" . $nr_servers .
" req answers=" . $req_answers . " req answers=" . $req_answers .
" answers=" . $nr_answers . " answers=" . $nr_answers .
@ -215,7 +216,7 @@ if($syncres==False) {
/* sync returned false, indicating that /* sync returned false, indicating that
either at least 1 answer marked OTP as invalid or either at least 1 answer marked OTP as invalid or
there were not enough answers */ there were not enough answers */
debug("ykval-verify:notice:Sync failed"); $myLog->log(LOG_WARNING, "ykval-verify:notice:Sync failed");
if ($nr_valid_answers!=$nr_answers) { if ($nr_valid_answers!=$nr_answers) {
sendResp(S_REPLAYED_OTP, $apiKey); sendResp(S_REPLAYED_OTP, $apiKey);
exit; exit;
@ -259,7 +260,7 @@ if ($sessionCounter == $seenSessionCounter && $sessionUse > $seenSessionUse) {
} else { } else {
$percent = 1; $percent = 1;
} }
debug("Timestamp seen=" . $seenTs . " this=" . $ts . $myLog->log(LOG_INFO, "Timestamp seen=" . $seenTs . " this=" . $ts .
" delta=" . $tsDiff . ' secs=' . $tsDelta . " delta=" . $tsDiff . ' secs=' . $tsDelta .
' accessed=' . $lastTime .' (' . $ad['accessed'] . ') now=' ' accessed=' . $lastTime .' (' . $ad['accessed'] . ') now='
. $now . ' (' . strftime("%Y-%m-%d %H:%M:%S", $now) . $now . ' (' . strftime("%Y-%m-%d %H:%M:%S", $now)
@ -267,7 +268,7 @@ if ($sessionCounter == $seenSessionCounter && $sessionUse > $seenSessionUse) {
' deviation=' . $deviation . ' secs or '. ' deviation=' . $deviation . ' secs or '.
round(100*$percent) . '%'); round(100*$percent) . '%');
if ($deviation > TS_ABS_TOLERANCE && $percent > TS_REL_TOLERANCE) { if ($deviation > TS_ABS_TOLERANCE && $percent > TS_REL_TOLERANCE) {
debug("OTP failed phishing test"); $myLog->log(LOG_NOTICE, "OTP failed phishing test");
if (0) { if (0) {
sendResp(S_DELAYED_OTP, $apiKey); sendResp(S_DELAYED_OTP, $apiKey);
exit; exit;