Yubico Forum

Re: Self installed KSM Is working, but VAL says BAD_OTP

2013-09-27T08:54:02+01:00

This is very common in PHP, however you are right we should make it less sensitive to this kind of stuff.

We will look into it and fix it.

Regards,
Tom

Statistics: Posted by Tom — Fri Sep 27, 2013 8:54 am

Re: Self installed KSM Is working, but VAL says BAD_OTP

2013-09-26T10:55:51+01:00

the KSM is outputting empty lines before OK

found the problem right now..

and empty line and the end of config-db.php of the ksm

maybe the validation server should trim all empty lines from the ksm output. then this cant happen anymore.

regards
-andy

Statistics: Posted by andy — Thu Sep 26, 2013 10:55 am

Re: Self installed KSM Is working, but VAL says BAD_OTP

2013-09-26T10:21:25+01:00

Here is the debug output frmo yk log. Maybe i found the error.

Sep 26 11:14:42 radiusa ykval[13672]: LOG_INFO:ykval-verify:[10.20.30.17] Request:

Code:

id=1&nonce=7sdmalkasmdlakmsdaasklmdlak&otp=cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf (at 2013-09-26T11:14:42+02:00 0.27085300 1380186882) HTTP
Sep 26 11:14:42 radiusa ykval[13672]: LOG_DEBUG:ykval-verify:[10.20.30.17] found protocol version 2
Sep 26 11:14:42 radiusa ykval[13672]: LOG_DEBUG:ykval-verify:synclib:db:[10.20.30.17] [cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf] DB query is: SELECT id, secret FROM clients WHERE active='1' AND id='1'
Sep 26 11:14:42 radiusa ykval[13672]: LOG_DEBUG:ykval-verify:[10.20.30.17] [cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf] Client data: id=1  secret=s+RKv23R5l0oyyW81GSHP34ENzM= 
Sep 26 11:14:42 radiusa ykval[13672]: LOG_DEBUG:ykval-verify:[10.20.30.17] [cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf] YK-KSM adding URL : http://localhost/wsapi/decrypt?otp=cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf
Sep 26 11:14:42 radiusa ykval[13672]: LOG_DEBUG:ykval-verify:[10.20.30.17] [cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf] YK-KSM curl multi info :  msg=1  result=0  handle=Resource id #10 
Sep 26 11:14:42 radiusa ykval[13672]: LOG_DEBUG:ykval-verify:[10.20.30.17] [cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf] YK-KSM curl multi content : #012#012OK counter=0001 low=888a high=1c use=02
Sep 26 11:14:42 radiusa ykval[13672]: LOG_DEBUG:ykval-verify:[10.20.30.17] [cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf] YK-KSM curl multi info :  msg=1  result=0  handle=Resource id #11 
Sep 26 11:14:42 radiusa ykval[13672]: LOG_DEBUG:ykval-verify:[10.20.30.17] [cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf] YK-KSM curl multi content : #012#012OK counter=0001 low=888a high=1c use=02
Sep 26 11:14:43 radiusa ykval[13672]: LOG_DEBUG:ykval-verify:[10.20.30.17] [cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf] YK-KSM response:  #012#012OK counter=0001 low=888a high=1c use=02#012 
Sep 26 11:14:43 radiusa ykval[13672]: LOG_DEBUG:ykval-verify:[10.20.30.17] [cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf] SIGN: status=BAD_OTP&t=2013-09-26T09:14:43Z0286 H=E+rCN0K3asRbXyPVvae2lHxK+hk=
Sep 26 11:14:43 radiusa ykval[13672]: LOG_INFO:ykval-verify:[10.20.30.17] [cccccccccccbbuitiicgkkdjfdilgcrueteffbhbcukf] Response: h=E+rCN0K3asRbXyPVvae2lHxK+hk=#015#012t=2013-09-26T09:14:43Z0286#015#012status=BAD_OTP#015#012#015#012 (at 2013-09-26T09:14:43+00:00 0.28631400 1380186883)

on the line YK-KSM response there is the String #012#012OK which should be just OK

no idea where this is coming from. any ideas?

regards
-andy

Statistics: Posted by andy — Thu Sep 26, 2013 10:21 am

Self installed KSM Is working, but VAL says BAD_OTP

2013-09-26T10:53:46+01:00

Hello all,

I have build my own rpms, installed and configured my KSM and VAL Server. The KSM Works

Code:

curl 'http://localhost/wsapi/decrypt?otp=cccccccccccbrrhldidnubirljgdfrhbkffdtuuduebu'

OK counter=0001 low=dbcc high=9d use=00

when using the validation server

Code:

wget -q -O - 'http://localhost/wsapi/2.0/verify?id=1&nonce=asdmalkasmdlakmsdaasklmdlak&otp=cccccccccccbghugkrcvnnefhtbvuhtttcdkneklvcdt'

i am getting the following syslog messages

Successful KSM operation

Code:

Sep 26 10:15:21 radiusa ykval[13673]: LOG_INFO:ykval-verify:[::1] Request: id=1&nonce=asdmalkasmdlakmsdaasklmdlak&otp=cccccccccccbghugkrcvnnefhtbvuhtttcdkneklvcdt (at 2013-09-26T10:15:21+02:00 0.75502000 1380183321) HTTP
Sep 26 10:15:21 radiusa ykksm[13674]: SUCCESS OTP cccccccccccbghugkrcvnnefhtbvuhtttcdkneklvcdt PT bedf73fb07b70100727bf0021d3f60c6 OK counter=0001 low=7b72 high=f0 use=02

Error on VAL

Code:

Sep 26 10:15:22 radiusa ykval[13673]: LOG_INFO:ykval-verify:[::1] [cccccccccccbghugkrcvnnefhtbvuhtttcdkneklvcdt] Response: h=PWxygAr5h+W/ogQEQT2b2vZqZF0=#015#012t=2013-09-26T08:15:22Z0771#015#012status=BAD_OTP#015#012#015#012 (at 2013-09-26T08:15:22+00:00 0.77224500 1380183322)

I have tried alot already and i have no idea what is going wrong. The only thing what should be true is, that he status=BAD_OTP is not true..

any idea how to troubleshoot this?

thanks
-andy

Statistics: Posted by andy — Thu Sep 26, 2013 9:17 am