RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following: RA_Format_Processor::Process - applet upgrade failed Tps-error log show the following: RA_Processor::SetupSecureChannel - Failed to create a secure channel 0- potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. RA_Processor::UpgradeApplet -0 channel create failure And a series of Bad Response when trying to SelectApplet or GetStatus zach _____________________________________________ From: Jack Magne [mailto:jmagne@redhat.com] Sent: Tuesday, December 23, 2008 1:10 PM To: Zach Casper Subject: Re: [Pki-users] ESC Format / Enroll Error The first step would be to take a look at the tps log or smart card server. These can be found at: /var/lib/pki-tps/logs/tps-debug.log Search the bottom of the log for error 19 and it should give you an idea of what TPS was trying to do at the time. Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to Format/Enroll due to the following ESC Error
"Formatting of smart card failed. Error: The Smart Card Server cannot upgrade the software on your smart card."
And Diagnostics show this error:
"Attempting to Format Key, ID: ####### - Key Format failure, Error: 19."
This card comes up as "Formatted" because we've manually installed a version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
------------------------------------------------------------------------
_______________________________________________ Pki-users mailing list Pki-users@redhat.com https://www.redhat.com/mailman/listinfo/pki-users
You might want to play with changing "false" to "true in the CS.cfg for op.enroll.userKey.update.applet.emptyToken.enable=false or the op.format... equivalent , etc. From: Julius Adewumi @GDC4S.com Ph:480-441-6768 Contract Corp:MTSI ________________________________ From: pki-users-bounces@redhat.com [mailto:pki-users-bounces@redhat.com] On Behalf Of Zach Casper Sent: Tuesday, December 23, 2008 12:00 PM To: pki-users@redhat.com Subject: RE: [Pki-users] ESC Format / Enroll Error Tps-debug log shows the following: RA_Format_Processor::Process - applet upgrade failed Tps-error log show the following: RA_Processor::SetupSecureChannel - Failed to create a secure channel 0- potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. RA_Processor::UpgradeApplet -0 channel create failure And a series of Bad Response when trying to SelectApplet or GetStatus zach _____________________________________________ From: Jack Magne [mailto:jmagne@redhat.com] Sent: Tuesday, December 23, 2008 1:10 PM To: Zach Casper Subject: Re: [Pki-users] ESC Format / Enroll Error The first step would be to take a look at the tps log or smart card server. These can be found at: /var/lib/pki-tps/logs/tps-debug.log Search the bottom of the log for error 19 and it should give you an idea of what TPS was trying to do at the time. Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
"Formatting of smart card failed. Error: The Smart Card Server cannot
upgrade the software on your smart card."
And Diagnostics show this error:
"Attempting to Format Key, ID: ####### - Key Format failure, Error: 19."
This card comes up as "Formatted" because we've manually installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
------------------------------------------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
You are having a problem creating a secure channel. Perhaps posting a snippet of the log might help. Adewumi, Julius-p99373 wrote:
You might want to play with changing "false" to "true in the CS.cfg for op.enroll.userKey.update.applet.emptyToken.enable=false or the op.format... equivalent , etc.
/From: Julius Adewumi/ /@GDC4S.com/ /Ph:480-441-6768/ /Contract Corp:MTSI/
------------------------------------------------------------------------ *From:* pki-users-bounces@redhat.com [mailto:pki-users-bounces@redhat.com] *On Behalf Of *Zach Casper *Sent:* Tuesday, December 23, 2008 12:00 PM *To:* pki-users@redhat.com *Subject:* RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following:
RA_Format_Processor::Process – applet upgrade failed
Tps-error log show the following:
RA_Processor::SetupSecureChannel – Failed to create a secure channel 0- potentially due to an RA/TKS key mismatch or differing RA/TKS key versions.
RA_Processor::UpgradeApplet -0 channel create failure
And a series of Bad Response when trying to SelectApplet or GetStatus
zach
_____________________________________________ *From:* Jack Magne [mailto:jmagne@redhat.com] *Sent:* Tuesday, December 23, 2008 1:10 PM *To:* Zach Casper *Subject:* Re: [Pki-users] ESC Format / Enroll Error
The first step would be to take a look at the tps log or smart card server.
These can be found at:
/var/lib/pki-tps/logs/tps-debug.log
Search the bottom of the log for error 19 and it should give you an idea
of what TPS was trying to do at the time.
Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
“Formatting of smart card failed. Error: The Smart Card Server cannot
upgrade the software on your smart card.”
And Diagnostics show this error:
“Attempting to Format Key, ID: ####### - Key Format failure, Error: 19.”
This card comes up as “Formatted” because we’ve manually installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
------------------------------------------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
------------------------------------------------------------------------
_______________________________________________ Pki-users mailing list Pki-users@redhat.com https://www.redhat.com/mailman/listinfo/pki-users
tps-error.log ... [2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel creation failure tps-debug.log ... [2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - Authenticate returns: 0 [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE' [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12' [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00' [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu = (length='20') [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00 [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00 [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='13' [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%56%F5%29%9D%7B%8F%6F%A 7' [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu = (length='2') [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6a 86 [2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - applet upgrade failed [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12' [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00' [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu = (length='2') [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 90 00 [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19' zach _____________________________________________ From: Jack Magne [mailto:jmagne@redhat.com] Sent: Tuesday, December 23, 2008 2:38 PM To: Adewumi, Julius-p99373 Cc: Zach Casper; pki-users@redhat.com Subject: Re: [Pki-users] ESC Format / Enroll Error You are having a problem creating a secure channel. Perhaps posting a snippet of the log might help. Adewumi, Julius-p99373 wrote:
You might want to play with changing "false" to "true in the CS.cfg for op.enroll.userKey.update.applet.emptyToken.enable=false or the op.format... equivalent , etc.
/From: Julius Adewumi/ /@GDC4S.com/ /Ph:480-441-6768/ /Contract Corp:MTSI/
------------------------------------------------------------------------ *From:* pki-users-bounces@redhat.com [mailto:pki-users-bounces@redhat.com] *On Behalf Of *Zach Casper *Sent:* Tuesday, December 23, 2008 12:00 PM *To:* pki-users@redhat.com *Subject:* RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following:
RA_Format_Processor::Process - applet upgrade failed
Tps-error log show the following:
RA_Processor::SetupSecureChannel - Failed to create a secure channel 0- potentially due to an RA/TKS key mismatch or differing RA/TKS key versions.
RA_Processor::UpgradeApplet -0 channel create failure
And a series of Bad Response when trying to SelectApplet or GetStatus
zach
_____________________________________________ *From:* Jack Magne [mailto:jmagne@redhat.com] *Sent:* Tuesday, December 23, 2008 1:10 PM *To:* Zach Casper *Subject:* Re: [Pki-users] ESC Format / Enroll Error
The first step would be to take a look at the tps log or smart card server.
These can be found at:
/var/lib/pki-tps/logs/tps-debug.log
Search the bottom of the log for error 19 and it should give you an idea
of what TPS was trying to do at the time.
Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
"Formatting of smart card failed. Error: The Smart Card Server cannot
upgrade the software on your smart card."
And Diagnostics show this error:
"Attempting to Format Key, ID: ####### - Key Format failure, Error: 19."
This card comes up as "Formatted" because we've manually installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
------------------------------------------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
------------------------------------------------------------------------
_______________________________________________ Pki-users mailing list Pki-users@redhat.com https://www.redhat.com/mailman/listinfo/pki-users
I'll have to take a closer look later but there is a quick thing you can try. Also, remember depending upon your card, if you make too many failed attempts at a secure channel, the card can lock itself up. In /var/lib/pki-tps/conf/CS.cfg you will have a block like this: channel.defKeyVersion=1 channel. defKeyIndex=1 We have experimented with some other cards where the following works: channel.defKeyVersion=0 channel.defKeyIndex=0 Zach Casper wrote:
tps-error.log ... [2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel creation failure
tps-debug.log ... [2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - Authenticate returns: 0 [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE' [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12' [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00' [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu = (length='20') [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00 [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00 [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='13' [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%56%F5%29%9D%7B%8F%6F%A7' [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu = (length='2') [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6a 86 [2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - applet upgrade failed [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12' [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00' [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu = (length='2') [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 90 00 [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
zach
_____________________________________________ *From:* Jack Magne [mailto:jmagne@redhat.com] *Sent:* Tuesday, December 23, 2008 2:38 PM *To:* Adewumi, Julius-p99373 *Cc:* Zach Casper; pki-users@redhat.com *Subject:* Re: [Pki-users] ESC Format / Enroll Error
You are having a problem creating a secure channel. Perhaps posting a
snippet of the log might help.
Adewumi, Julius-p99373 wrote:
You might want to play with changing "false" to "true in the CS.cfg for
op.enroll.userKey.update.applet.emptyToken.enable=false or the
op.format... equivalent , etc.
/From: Julius Adewumi/
/@GDC4S.com/
/Ph:480-441-6768/
/Contract Corp:MTSI/
------------------------------------------------------------------------
*From:* pki-users-bounces@redhat.com
[mailto:pki-users-bounces@redhat.com] *On Behalf Of *Zach Casper
*Sent:* Tuesday, December 23, 2008 12:00 PM
*To:* pki-users@redhat.com
*Subject:* RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following:
RA_Format_Processor::Process – applet upgrade failed
Tps-error log show the following:
RA_Processor::SetupSecureChannel – Failed to create a secure channel
0- potentially due to an RA/TKS key mismatch or differing RA/TKS key
versions.
RA_Processor::UpgradeApplet -0 channel create failure
And a series of Bad Response when trying to SelectApplet or GetStatus
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 1:10 PM
*To:* Zach Casper
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
The first step would be to take a look at the tps log or smart card
server.
These can be found at:
/var/lib/pki-tps/logs/tps-debug.log
Search the bottom of the log for error 19 and it should give you an idea
of what TPS was trying to do at the time.
Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
“Formatting of smart card failed. Error: The Smart Card Server cannot
upgrade the software on your smart card.”
And Diagnostics show this error:
“Attempting to Format Key, ID: ####### - Key Format failure, Error: 19.”
This card comes up as “Formatted” because we’ve manually installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
------------------------------------------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
------------------------------------------------------------------------
_______________________________________________ Pki-users mailing list Pki-users@redhat.com https://www.redhat.com/mailman/listinfo/pki-users
Could there be an issue with the default key our card is loaded with (VISA Key) not being able to create the secure connection? What are the default key(s) used/needed by Dogtag? _____________________________________________ From: Jack Magne [mailto:jmagne@redhat.com] Sent: Tuesday, December 23, 2008 5:35 PM To: Zach Casper Cc: pki-users@redhat.com Subject: Re: [Pki-users] ESC Format / Enroll Error I'll have to take a closer look later but there is a quick thing you can try. Also, remember depending upon your card, if you make too many failed attempts at a secure channel, the card can lock itself up. In /var/lib/pki-tps/conf/CS.cfg you will have a block like this: channel.defKeyVersion=1 channel. defKeyIndex=1 We have experimented with some other cards where the following works: channel.defKeyVersion=0 channel.defKeyIndex=0 Zach Casper wrote:
tps-error.log ... [2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel creation failure
tps-debug.log ... [2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - Authenticate returns: 0 [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE' [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12' [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu = (length='20') [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00 [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00 [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='13' [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%56%F5%29%9D%7B%8F%6F%A 7'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu = (length='2') [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6a 86 [2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - applet upgrade failed [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12' [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu = (length='2') [2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 90 00 [2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
zach
_____________________________________________ *From:* Jack Magne [mailto:jmagne@redhat.com] *Sent:* Tuesday, December 23, 2008 2:38 PM *To:* Adewumi, Julius-p99373 *Cc:* Zach Casper; pki-users@redhat.com *Subject:* Re: [Pki-users] ESC Format / Enroll Error
You are having a problem creating a secure channel. Perhaps posting a
snippet of the log might help.
Adewumi, Julius-p99373 wrote:
You might want to play with changing "false" to "true in the CS.cfg for
op.enroll.userKey.update.applet.emptyToken.enable=false or the
op.format... equivalent , etc.
/From: Julius Adewumi/
/@GDC4S.com/
/Ph:480-441-6768/
/Contract Corp:MTSI/
------------------------------------------------------------------------
*From:* pki-users-bounces@redhat.com
[mailto:pki-users-bounces@redhat.com] *On Behalf Of *Zach Casper
*Sent:* Tuesday, December 23, 2008 12:00 PM
*To:* pki-users@redhat.com
*Subject:* RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following:
RA_Format_Processor::Process - applet upgrade failed
Tps-error log show the following:
RA_Processor::SetupSecureChannel - Failed to create a secure channel
0- potentially due to an RA/TKS key mismatch or differing RA/TKS key
versions.
RA_Processor::UpgradeApplet -0 channel create failure
And a series of Bad Response when trying to SelectApplet or GetStatus
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 1:10 PM
*To:* Zach Casper
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
The first step would be to take a look at the tps log or smart card
server.
These can be found at:
/var/lib/pki-tps/logs/tps-debug.log
Search the bottom of the log for error 19 and it should give you an idea
of what TPS was trying to do at the time.
Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
"Formatting of smart card failed. Error: The Smart Card Server cannot
upgrade the software on your smart card."
And Diagnostics show this error:
"Attempting to Format Key, ID: ####### - Key Format failure, Error: 19."
This card comes up as "Formatted" because we've manually installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
------------------------------------------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
------------------------------------------------------------------------
_______________________________________________ Pki-users mailing list Pki-users@redhat.com https://www.redhat.com/mailman/listinfo/pki-users
Zach: Sorry for the delay.... The default developer keyset we use for our keys with TPS is the standard like follows: tks.defKeySet.auth_key=#40#41...#4f tks.defKeySet.kek_key=#40#41...#4f tks.defKeySet.mac_key=#40#41.. #4f If you look in the CS.cfg file under /var/lib/pki-tks/conf We have an entire procedure documented in the CS 7.3 documentation to perform a key changeover if required. Feel free to post any further logs you might obtain after further testing. thanks, jack Zach Casper wrote:
Could there be an issue with the default key our card is loaded with (VISA Key) not being able to create the secure connection? What are the default key(s) used/needed by Dogtag?
_____________________________________________ *From:* Jack Magne [mailto:jmagne@redhat.com] *Sent:* Tuesday, December 23, 2008 5:35 PM *To:* Zach Casper *Cc:* pki-users@redhat.com *Subject:* Re: [Pki-users] ESC Format / Enroll Error
I'll have to take a closer look later but there is a quick thing you can
try.
Also, remember depending upon your card, if you make too many failed
attempts at a secure channel, the card can lock itself up.
In /var/lib/pki-tps/conf/CS.cfg you will have a block like this:
channel.defKeyVersion=1
channel. defKeyIndex=1
We have experimented with some other cards where the following works:
channel.defKeyVersion=0
channel.defKeyIndex=0
Zach Casper wrote:
tps-error.log
...
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel
creation failure
tps-debug.log
...
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process -
Authenticate returns: 0
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - path =
/usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='20')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6f 10 84 08 a0 00
00 00 03 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 00 00 a5 04 9f 65
01 ff 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg -
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='13'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%56%F5%29%9D%7B%8F%6F%A7'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6a 86
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - applet
upgrade failed
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=43&msg_type=13&operation=5&result=1&message=19'
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 2:38 PM
*To:* Adewumi, Julius-p99373
*Cc:* Zach Casper; pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
You are having a problem creating a secure channel. Perhaps posting a
snippet of the log might help.
Adewumi, Julius-p99373 wrote:
You might want to play with changing "false" to "true in the CS.cfg for
op.enroll.userKey.update.applet.emptyToken.enable=false or the
op.format... equivalent , etc.
/From: Julius Adewumi/
/@GDC4S.com/
/Ph:480-441-6768/
/Contract Corp:MTSI/
*From:* pki-users-bounces@redhat.com
[mailto:pki-users-bounces@redhat.com] *On Behalf Of *Zach Casper
*Sent:* Tuesday, December 23, 2008 12:00 PM
*To:* pki-users@redhat.com
*Subject:* RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following:
RA_Format_Processor::Process – applet upgrade failed
Tps-error log show the following:
RA_Processor::SetupSecureChannel – Failed to create a secure channel
0- potentially due to an RA/TKS key mismatch or differing RA/TKS key
versions.
RA_Processor::UpgradeApplet -0 channel create failure
And a series of Bad Response when trying to SelectApplet or GetStatus
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 1:10 PM
*To:* Zach Casper
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
The first step would be to take a look at the tps log or smart card
server.
These can be found at:
/var/lib/pki-tps/logs/tps-debug.log
Search the bottom of the log for error 19 and it should give you an idea
of what TPS was trying to do at the time.
Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
“Formatting of smart card failed. Error: The Smart Card Server cannot
upgrade the software on your smart card.”
And Diagnostics show this error:
“Attempting to Format Key, ID: ####### - Key Format failure, Error:
19.”
This card comes up as “Formatted” because we’ve manually installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
------------------------------------------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
------------------------------------------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
Thanks Jack. It appears we are using the same keys so on to troubleshooting our error logs. Below are our current logs file contents. When we use the default values: channel.defKeyVersion=1 channel. defKeyIndex=1 Ther error we get is: [2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123' [2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Attributes mail,cn,uid [2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed cn=Test User1 [2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 3 [2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed uid=testuser1 [2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 4 [2009-01-07 11:05:07] ba6ec600 RA_Format_Processor::Process - Authenticate returns: 0 [2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE' [2009-01-07 11:05:07] ba6ec600 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc [2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='12' [2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00' [2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='20') [2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00 [2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00 [2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - [2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='13' [2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent 's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%09%CD%60%A7%11%EC%23%A 5' [2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2') [2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 6a 86 [2009-01-07 11:05:08] ba6ec600 RA_Format_Processor::Process - applet upgrade failed [2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - pdu_len='12' [2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00' [2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2') [2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 90 00 [2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19' When we switch the values to be: channel.defKeyVersion=0 channel. defKeyIndex=0 The error now looks like this: [2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123' [2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Attributes mail,cn,uid [2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed cn=Test User1 [2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 3 [2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed uid=testuser1 [2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 4 [2009-01-07 11:20:41] bacd2d28 RA_Format_Processor::Process - Authenticate returns: 0 [2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE' [2009-01-07 11:20:41] bacd2d28 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc [2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='12' [2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00' [2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='20') [2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00 [2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00 [2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - [2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='13' [2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent 's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%00%00%08%95%74%0B%AC%37%C9%DE%8 0' [2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='30') [2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 71 61 57 01 0e 0d 90 bd [2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - ff 02 00 21 2e 6b ec 9e 33 2b [2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - a5 26 d0 02 e6 64 c9 3c 90 00 [2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - [2009-01-07 11:20:41] bacd2d28 HttpConnection::getResponse - Send request to host localhost.localdomain:13443 servlet /tks/agent/tks/computeSessionKey [2009-01-07 11:20:42] bacd2d28 RA::Engine - Pre-processing content 'HTTP/1.1 200 OK Server: Apache-Coyote/1.1 Content-Type: text/html Content-Length: 8 Date: Wed, 07 Jan 2009 16:20:42 GMT status=3 [2009-01-07 11:20:42] bacd2d28 RA::Engine - Post-processing content 'status=3 [2009-01-07 11:20:42] bacd2d28 RA_Format_Processor::Process - applet upgrade failed [2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - pdu_len='12' [2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00' [2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='2') [2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - 90 00 [2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19' In addition - the following is the pki-tps.tps-error.log snippet [2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel creation failure I'm also bringing John Whitelock, another one of our engineers in on discussions. He just joined the pki-users list. Zach Casper _____________________________________________ From: Jack Magne [mailto:jmagne@redhat.com] Sent: Wednesday, January 07, 2009 1:09 PM To: Zach Casper Cc: pki-users@redhat.com Subject: Re: [Pki-users] ESC Format / Enroll Error Zach: Sorry for the delay.... The default developer keyset we use for our keys with TPS is the standard like follows: tks.defKeySet.auth_key=#40#41...#4f tks.defKeySet.kek_key=#40#41...#4f tks.defKeySet.mac_key=#40#41.. #4f If you look in the CS.cfg file under /var/lib/pki-tks/conf We have an entire procedure documented in the CS 7.3 documentation to perform a key changeover if required. Feel free to post any further logs you might obtain after further testing. thanks, jack Zach Casper wrote:
Could there be an issue with the default key our card is loaded with (VISA Key) not being able to create the secure connection? What are the default key(s) used/needed by Dogtag?
_____________________________________________ *From:* Jack Magne [mailto:jmagne@redhat.com] *Sent:* Tuesday, December 23, 2008 5:35 PM *To:* Zach Casper *Cc:* pki-users@redhat.com *Subject:* Re: [Pki-users] ESC Format / Enroll Error
I'll have to take a closer look later but there is a quick thing you can
try.
Also, remember depending upon your card, if you make too many failed
attempts at a secure channel, the card can lock itself up.
In /var/lib/pki-tps/conf/CS.cfg you will have a block like this:
channel.defKeyVersion=1
channel. defKeyIndex=1
We have experimented with some other cards where the following works:
channel.defKeyVersion=0
channel.defKeyIndex=0
Zach Casper wrote:
tps-error.log
...
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel
creation failure
tps-debug.log
...
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process -
Authenticate returns: 0
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - path =
/usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='20')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6f 10 84 08 a0 00
00 00 03 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 00 00 a5 04 9f 65
01 ff 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg -
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='13'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%56%F5%29%9D%7B%8F%6F%A 7'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6a 86
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - applet
upgrade failed
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=43&msg_type=13&operation=5&result=1&message=19'
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 2:38 PM
*To:* Adewumi, Julius-p99373
*Cc:* Zach Casper; pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
You are having a problem creating a secure channel. Perhaps posting a
snippet of the log might help.
Adewumi, Julius-p99373 wrote:
You might want to play with changing "false" to "true in the CS.cfg
for
op.enroll.userKey.update.applet.emptyToken.enable=false or the
op.format... equivalent , etc.
/From: Julius Adewumi/
/@GDC4S.com/
/Ph:480-441-6768/
/Contract Corp:MTSI/
*From:* pki-users-bounces@redhat.com
[mailto:pki-users-bounces@redhat.com] *On Behalf Of *Zach Casper
*Sent:* Tuesday, December 23, 2008 12:00 PM
*To:* pki-users@redhat.com
*Subject:* RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following:
RA_Format_Processor::Process - applet upgrade failed
Tps-error log show the following:
RA_Processor::SetupSecureChannel - Failed to create a secure channel
0- potentially due to an RA/TKS key mismatch or differing RA/TKS key
versions.
RA_Processor::UpgradeApplet -0 channel create failure
And a series of Bad Response when trying to SelectApplet or GetStatus
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 1:10 PM
*To:* Zach Casper
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
The first step would be to take a look at the tps log or smart card
server.
These can be found at:
/var/lib/pki-tps/logs/tps-debug.log
Search the bottom of the log for error 19 and it should give you an idea
of what TPS was trying to do at the time.
Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
"Formatting of smart card failed. Error: The Smart Card Server
cannot
upgrade the software on your smart card."
And Diagnostics show this error:
"Attempting to Format Key, ID: ####### - Key Format failure, Error:
19."
This card comes up as "Formatted" because we've manually installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
------------------------------------------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
------------------------------------------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
Zach: It looks like with your second test, you have managed to get by the hurdle of the failed "InitializeUpdate" command. This is due to using 0 and 0 for the defKeyVersion and defKeyIndex. Now it looks like the TKS system is not acting as expected. It would be great to have a look at the TKS debug log found in /var/lib/pki-tks/logs I suspect we are having an issue with computing the session key in the TKS. thanks, jack Zach Casper wrote:
Thanks Jack.
It appears we are using the same keys so on to troubleshooting our error logs. Below are our current logs file contents.
When we use the default values:
channel.defKeyVersion=1
channel. defKeyIndex=1
Ther error we get is:
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123'
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Attributes mail,cn,uid
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed cn=Test User1
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 3
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed uid=testuser1
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 4
[2009-01-07 11:05:07] ba6ec600 RA_Format_Processor::Process - Authenticate returns: 0
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2009-01-07 11:05:07] ba6ec600 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='20')
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg -
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='13'
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent 's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%09%CD%60%A7%11%EC%23%A5'
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 6a 86
[2009-01-07 11:05:08] ba6ec600 RA_Format_Processor::Process - applet upgrade failed
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 90 00
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
When we switch the values to be:
channel.defKeyVersion=0
channel. defKeyIndex=0
The error now looks like this:
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123'
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Attributes mail,cn,uid
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed cn=Test User1
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 3
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed uid=testuser1
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 4
[2009-01-07 11:20:41] bacd2d28 RA_Format_Processor::Process - Authenticate returns: 0
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2009-01-07 11:20:41] bacd2d28 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='20')
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg -
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='13'
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent 's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%00%00%08%95%74%0B%AC%37%C9%DE%80'
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='30')
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 71 61 57 01 0e 0d 90 bd
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - ff 02 00 21 2e 6b ec 9e 33 2b
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - a5 26 d0 02 e6 64 c9 3c 90 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg -
[2009-01-07 11:20:41] bacd2d28 HttpConnection::getResponse - Send request to host localhost.localdomain:13443 servlet /tks/agent/tks/computeSessionKey
[2009-01-07 11:20:42] bacd2d28 RA::Engine - Pre-processing content 'HTTP/1.1 200 OK
Server: Apache-Coyote/1.1
Content-Type: text/html
Content-Length: 8
Date: Wed, 07 Jan 2009 16:20:42 GMT
status=3
[2009-01-07 11:20:42] bacd2d28 RA::Engine - Post-processing content 'status=3
[2009-01-07 11:20:42] bacd2d28 RA_Format_Processor::Process - applet upgrade failed
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent 's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - 90 00
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
In addition – the following is the pki-tps…tps-error.log snippet
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel creation failure
I’m also bringing John Whitelock, another one of our engineers in on discussions. He just joined the pki-users list.
Zach Casper
_____________________________________________ *From:* Jack Magne [mailto:jmagne@redhat.com] *Sent:* Wednesday, January 07, 2009 1:09 PM *To:* Zach Casper *Cc:* pki-users@redhat.com *Subject:* Re: [Pki-users] ESC Format / Enroll Error
Zach:
Sorry for the delay....
The default developer keyset we use for our keys with TPS is the
standard like follows:
tks.defKeySet.auth_key=#40#41...#4f
tks.defKeySet.kek_key=#40#41...#4f
tks.defKeySet.mac_key=#40#41.. #4f
If you look in the CS.cfg file under
/var/lib/pki-tks/conf
We have an entire procedure documented in the CS 7.3 documentation to
perform a key changeover if required.
Feel free to post any further logs you might obtain after further testing.
thanks,
jack
Zach Casper wrote:
Could there be an issue with the default key our card is loaded with
(VISA Key) not being able to create the secure connection? What are
the default key(s) used/needed by Dogtag?
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 5:35 PM
*To:* Zach Casper
*Cc:* pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
I'll have to take a closer look later but there is a quick thing you can
try.
Also, remember depending upon your card, if you make too many failed
attempts at a secure channel, the card can lock itself up.
In /var/lib/pki-tps/conf/CS.cfg you will have a block like this:
channel.defKeyVersion=1
channel. defKeyIndex=1
We have experimented with some other cards where the following works:
channel.defKeyVersion=0
channel.defKeyIndex=0
Zach Casper wrote:
tps-error.log
...
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel
creation failure
tps-debug.log
...
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process -
Authenticate returns: 0
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - path =
/usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='20')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6f 10 84 08 a0 00
00 00 03 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 00 00 a5 04 9f 65
01 ff 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg -
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='13'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%56%F5%29%9D%7B%8F%6F%A7'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6a 86
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - applet
upgrade failed
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=43&msg_type=13&operation=5&result=1&message=19'
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 2:38 PM
*To:* Adewumi, Julius-p99373
*Cc:* Zach Casper; pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
You are having a problem creating a secure channel. Perhaps posting a
snippet of the log might help.
Adewumi, Julius-p99373 wrote:
You might want to play with changing "false" to "true in the CS.cfg for
op.enroll.userKey.update.applet.emptyToken.enable=false or the
op.format... equivalent , etc.
/From: Julius Adewumi/
/@GDC4S.com/
/Ph:480-441-6768/
/Contract Corp:MTSI/
------------------------------------------------------------------------
*From:* pki-users-bounces@redhat.com
[mailto:pki-users-bounces@redhat.com] *On Behalf Of *Zach Casper
*Sent:* Tuesday, December 23, 2008 12:00 PM
*To:* pki-users@redhat.com
*Subject:* RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following:
RA_Format_Processor::Process – applet upgrade failed
Tps-error log show the following:
RA_Processor::SetupSecureChannel – Failed to create a secure channel
0- potentially due to an RA/TKS key mismatch or differing RA/TKS key
versions.
RA_Processor::UpgradeApplet -0 channel create failure
And a series of Bad Response when trying to SelectApplet or GetStatus
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 1:10 PM
*To:* Zach Casper
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
The first step would be to take a look at the tps log or smart card
server.
These can be found at:
/var/lib/pki-tps/logs/tps-debug.log
Search the bottom of the log for error 19 and it should give you an
idea
of what TPS was trying to do at the time.
Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
“Formatting of smart card failed. Error: The Smart Card Server cannot
upgrade the software on your smart card.”
And Diagnostics show this error:
“Attempting to Format Key, ID: ####### - Key Format failure, Error:
19.”
This card comes up as “Formatted” because we’ve manually installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
------------------------------------------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
Jack, Thanks again for the help. Below I have pasted the log you asked for from that same test. [07/Jan/2009:11:20:42][http-13443-Processor25]: Authentication: client certificate found [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: Authentication: mapped certificate to user [07/Jan/2009:11:20:42][http-13443-Processor25]: authenticated uid=TPS-localhost.localdomain-7889,ou=People,dc=localhost.localdomain-pki-tk s [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create() message=[AuditEvent=AUTH_SUCCESS][SubjectID=TPS-localhost.localdomain-7889][ Outcome=Success][AuthMgr=certUserDBAuthMgr] authentication success [07/Jan/2009:11:20:42][http-13443-Processor25]: checkACLS(): ACLEntry expressions= group="Token Key Service Manager Agents" [07/Jan/2009:11:20:42][http-13443-Processor25]: evaluating expressions: group="Token Key Service Manager Agents" [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: UGSubsystem.isMemberOf() using new lookup code [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization search base: cn=Token Key Service Manager Agents,ou=groups,dc=localhost.localdomain-pki-tks [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization search filter: (uniquemember=uid=TPS-localhost.localdomain-7889,ou=People,dc=localhost.loca ldomain-pki-tks) [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization result: true [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: evaluated expression: group="Token Key Service Manager Agents" to be true [07/Jan/2009:11:20:42][http-13443-Processor25]: DirAclAuthz: authorization passed [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create() message=[AuditEvent=AUTHZ_SUCCESS][SubjectID=TPS-localhost.localdomain-7889] [Outcome=Success][aclResource=certServer.tks.sessionkey][Op=read] authorization success [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create() message=[AuditEvent=ROLE_ASSUME][SubjectID=TPS-localhost.localdomain-7889][O utcome=Success][Role=Token Key Service Manager Agents] assume privileged role [07/Jan/2009:11:20:42][http-13443-Processor25]: keySet selected: defKeySet [07/Jan/2009:11:20:42][http-13443-Processor25]: keySet selected: defKeySet [07/Jan/2009:11:20:42][http-13443-Processor25]: processComputeSessionKey: [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet: serversideKeygen requested [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet about to try ComputeSessionKey selectedToken=Internal Key Storage Token keyNickName=#FF#02 [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:Tried ComputeSessionKey, got NULL java.lang.Exception: Can't compute session key! at com.netscape.cms.servlet.tks.TokenServlet.processComputeSessionKey(TokenServ let.java:336) at com.netscape.cms.servlet.tks.TokenServlet.process(TokenServlet.java:945) at com.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:482) at com.netscape.cms.servlet.tks.TokenServlet.service(TokenServlet.java:964) at javax.servlet.http.HttpServlet.service(HttpServlet.java:729) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Application FilterChain.java:269) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterCh ain.java:188) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.ja va:213) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.ja va:172) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127 ) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117 ) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:548) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java :108) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:174) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:875) at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processC onnection(Http11BaseProtocol.java:665) at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.jav a:528) at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWo rkerThread.java:81) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.jav a:689) at java.lang.Thread.run(Thread.java:636) [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet Computing Session Key: java.lang.Exception: Can't compute session key! [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:outputString.encode status=3 [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:outputString.length 8 [07/Jan/2009:11:20:42][http-13443-Processor25]: CMSServlet: curDate=Wed Jan 07 11:20:42 GMT-05:00 2009 id=tksSessionKey time=430 -----Original Message----- From: Jack Magne [mailto:jmagne@redhat.com] Sent: Wednesday, January 07, 2009 4:24 PM To: Zach Casper Cc: pki-users@redhat.com; 'John Whitelock' Subject: Re: [Pki-users] ESC Format / Enroll Error Zach: It looks like with your second test, you have managed to get by the hurdle of the failed "InitializeUpdate" command. This is due to using 0 and 0 for the defKeyVersion and defKeyIndex. Now it looks like the TKS system is not acting as expected. It would be great to have a look at the TKS debug log found in /var/lib/pki-tks/logs I suspect we are having an issue with computing the session key in the TKS. thanks, jack Zach Casper wrote:
Thanks Jack.
It appears we are using the same keys so on to troubleshooting our error logs. Below are our current logs file contents.
When we use the default values:
channel.defKeyVersion=1
channel. defKeyIndex=1
Ther error we get is:
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123'
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Attributes mail,cn,uid
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed cn=Test User1
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 3
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed uid=testuser1
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 4
[2009-01-07 11:05:07] ba6ec600 RA_Format_Processor::Process - Authenticate returns: 0
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2009-01-07 11:05:07] ba6ec600 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='20')
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg -
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='13'
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%09%CD%60%A7%11%EC%23%A 5'
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 6a 86
[2009-01-07 11:05:08] ba6ec600 RA_Format_Processor::Process - applet upgrade failed
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 90 00
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
When we switch the values to be:
channel.defKeyVersion=0
channel. defKeyIndex=0
The error now looks like this:
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123'
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Attributes mail,cn,uid
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed cn=Test User1
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 3
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed uid=testuser1
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 4
[2009-01-07 11:20:41] bacd2d28 RA_Format_Processor::Process - Authenticate returns: 0
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2009-01-07 11:20:41] bacd2d28 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='20')
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg -
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='13'
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%00%00%08%95%74%0B%AC%37%C9%DE%8 0'
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='30')
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 71 61 57 01 0e 0d 90 bd
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - ff 02 00 21 2e 6b ec 9e 33 2b
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - a5 26 d0 02 e6 64 c9 3c 90 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg -
[2009-01-07 11:20:41] bacd2d28 HttpConnection::getResponse - Send request to host localhost.localdomain:13443 servlet /tks/agent/tks/computeSessionKey
[2009-01-07 11:20:42] bacd2d28 RA::Engine - Pre-processing content 'HTTP/1.1 200 OK
Server: Apache-Coyote/1.1
Content-Type: text/html
Content-Length: 8
Date: Wed, 07 Jan 2009 16:20:42 GMT
status=3
[2009-01-07 11:20:42] bacd2d28 RA::Engine - Post-processing content 'status=3
[2009-01-07 11:20:42] bacd2d28 RA_Format_Processor::Process - applet upgrade failed
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - 90 00
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
In addition - the following is the pki-tps.tps-error.log snippet
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel creation failure
I'm also bringing John Whitelock, another one of our engineers in on discussions. He just joined the pki-users list.
Zach Casper
_____________________________________________ *From:* Jack Magne [mailto:jmagne@redhat.com] *Sent:* Wednesday, January 07, 2009 1:09 PM *To:* Zach Casper *Cc:* pki-users@redhat.com *Subject:* Re: [Pki-users] ESC Format / Enroll Error
Zach:
Sorry for the delay....
The default developer keyset we use for our keys with TPS is the
standard like follows:
tks.defKeySet.auth_key=#40#41...#4f
tks.defKeySet.kek_key=#40#41...#4f
tks.defKeySet.mac_key=#40#41.. #4f
If you look in the CS.cfg file under
/var/lib/pki-tks/conf
We have an entire procedure documented in the CS 7.3 documentation to
perform a key changeover if required.
Feel free to post any further logs you might obtain after further testing.
thanks,
jack
Zach Casper wrote:
Could there be an issue with the default key our card is loaded with
(VISA Key) not being able to create the secure connection? What are
the default key(s) used/needed by Dogtag?
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 5:35 PM
*To:* Zach Casper
*Cc:* pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
I'll have to take a closer look later but there is a quick thing you can
try.
Also, remember depending upon your card, if you make too many failed
attempts at a secure channel, the card can lock itself up.
In /var/lib/pki-tps/conf/CS.cfg you will have a block like this:
channel.defKeyVersion=1
channel. defKeyIndex=1
We have experimented with some other cards where the following works:
channel.defKeyVersion=0
channel.defKeyIndex=0
Zach Casper wrote:
tps-error.log
...
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel
creation failure
tps-debug.log
...
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process -
Authenticate returns: 0
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - path =
/usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='20')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6f 10 84 08 a0 00
00 00 03 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 00 00 a5 04 9f 65
01 ff 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg -
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='13'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%56%F5%29%9D%7B%8F%6F%A 7'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6a 86
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - applet
upgrade failed
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=43&msg_type=13&operation=5&result=1&message=19'
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 2:38 PM
*To:* Adewumi, Julius-p99373
*Cc:* Zach Casper; pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
You are having a problem creating a secure channel. Perhaps posting a
snippet of the log might help.
Adewumi, Julius-p99373 wrote:
You might want to play with changing "false" to "true in the CS.cfg for
op.enroll.userKey.update.applet.emptyToken.enable=false or the
op.format... equivalent , etc.
/From: Julius Adewumi/
/@GDC4S.com/
/Ph:480-441-6768/
/Contract Corp:MTSI/
------------------------------------------------------------------------
*From:* pki-users-bounces@redhat.com
[mailto:pki-users-bounces@redhat.com] *On Behalf Of *Zach Casper
*Sent:* Tuesday, December 23, 2008 12:00 PM
*To:* pki-users@redhat.com
*Subject:* RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following:
RA_Format_Processor::Process - applet upgrade failed
Tps-error log show the following:
RA_Processor::SetupSecureChannel - Failed to create a secure channel
0- potentially due to an RA/TKS key mismatch or differing RA/TKS key
versions.
RA_Processor::UpgradeApplet -0 channel create failure
And a series of Bad Response when trying to SelectApplet or
GetStatus
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 1:10 PM
*To:* Zach Casper
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
The first step would be to take a look at the tps log or smart card
server.
These can be found at:
/var/lib/pki-tps/logs/tps-debug.log
Search the bottom of the log for error 19 and it should give you an
idea
of what TPS was trying to do at the time.
Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
"Formatting of smart card failed. Error: The Smart Card Server cannot
upgrade the software on your smart card."
And Diagnostics show this error:
"Attempting to Format Key, ID: ####### - Key Format failure,
Error:
19."
This card comes up as "Formatted" because we've manually installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
------------------------------------------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
Thanks: I will take a look in an effort to figure out what we have. John Whitelock wrote:
Jack,
Thanks again for the help. Below I have pasted the log you asked for from that same test.
[07/Jan/2009:11:20:42][http-13443-Processor25]: Authentication: client certificate found [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: Authentication: mapped certificate to user [07/Jan/2009:11:20:42][http-13443-Processor25]: authenticated uid=TPS-localhost.localdomain-7889,ou=People,dc=localhost.localdomain-pki-tk s [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create() message=[AuditEvent=AUTH_SUCCESS][SubjectID=TPS-localhost.localdomain-7889][ Outcome=Success][AuthMgr=certUserDBAuthMgr] authentication success
[07/Jan/2009:11:20:42][http-13443-Processor25]: checkACLS(): ACLEntry expressions= group="Token Key Service Manager Agents" [07/Jan/2009:11:20:42][http-13443-Processor25]: evaluating expressions: group="Token Key Service Manager Agents" [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: UGSubsystem.isMemberOf() using new lookup code [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization search base: cn=Token Key Service Manager Agents,ou=groups,dc=localhost.localdomain-pki-tks [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization search filter: (uniquemember=uid=TPS-localhost.localdomain-7889,ou=People,dc=localhost.loca ldomain-pki-tks) [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization result: true [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: evaluated expression: group="Token Key Service Manager Agents" to be true [07/Jan/2009:11:20:42][http-13443-Processor25]: DirAclAuthz: authorization passed [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create() message=[AuditEvent=AUTHZ_SUCCESS][SubjectID=TPS-localhost.localdomain-7889] [Outcome=Success][aclResource=certServer.tks.sessionkey][Op=read] authorization success
[07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create() message=[AuditEvent=ROLE_ASSUME][SubjectID=TPS-localhost.localdomain-7889][O utcome=Success][Role=Token Key Service Manager Agents] assume privileged role
[07/Jan/2009:11:20:42][http-13443-Processor25]: keySet selected: defKeySet [07/Jan/2009:11:20:42][http-13443-Processor25]: keySet selected: defKeySet [07/Jan/2009:11:20:42][http-13443-Processor25]: processComputeSessionKey: [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet: serversideKeygen requested [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet about to try ComputeSessionKey selectedToken=Internal Key Storage Token keyNickName=#FF#02 [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:Tried ComputeSessionKey, got NULL java.lang.Exception: Can't compute session key! at com.netscape.cms.servlet.tks.TokenServlet.processComputeSessionKey(TokenServ let.java:336) at com.netscape.cms.servlet.tks.TokenServlet.process(TokenServlet.java:945) at com.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:482) at com.netscape.cms.servlet.tks.TokenServlet.service(TokenServlet.java:964) at javax.servlet.http.HttpServlet.service(HttpServlet.java:729) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Application FilterChain.java:269) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterCh ain.java:188) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.ja va:213) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.ja va:172) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127 ) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117 ) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:548) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java :108) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:174) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:875) at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processC onnection(Http11BaseProtocol.java:665) at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.jav a:528) at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWo rkerThread.java:81) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.jav a:689) at java.lang.Thread.run(Thread.java:636) [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet Computing Session Key: java.lang.Exception: Can't compute session key! [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:outputString.encode status=3 [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:outputString.length 8 [07/Jan/2009:11:20:42][http-13443-Processor25]: CMSServlet: curDate=Wed Jan 07 11:20:42 GMT-05:00 2009 id=tksSessionKey time=430
-----Original Message----- From: Jack Magne [mailto:jmagne@redhat.com] Sent: Wednesday, January 07, 2009 4:24 PM To: Zach Casper Cc: pki-users@redhat.com; 'John Whitelock' Subject: Re: [Pki-users] ESC Format / Enroll Error
Zach:
It looks like with your second test, you have managed to get by the hurdle of the failed "InitializeUpdate" command. This is due to using 0 and 0 for the defKeyVersion and defKeyIndex.
Now it looks like the TKS system is not acting as expected.
It would be great to have a look at the TKS debug log found in /var/lib/pki-tks/logs
I suspect we are having an issue with computing the session key in the TKS.
thanks, jack
Zach Casper wrote:
Thanks Jack.
It appears we are using the same keys so on to troubleshooting our error logs. Below are our current logs file contents.
When we use the default values:
channel.defKeyVersion=1
channel. defKeyIndex=1
Ther error we get is:
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123'
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Attributes mail,cn,uid
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed cn=Test User1
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 3
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed uid=testuser1
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 4
[2009-01-07 11:05:07] ba6ec600 RA_Format_Processor::Process - Authenticate returns: 0
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2009-01-07 11:05:07] ba6ec600 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='20')
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg -
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='13'
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%09%CD%60%A7%11%EC%23%A 5'
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 6a 86
[2009-01-07 11:05:08] ba6ec600 RA_Format_Processor::Process - applet upgrade failed
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 90 00
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
When we switch the values to be:
channel.defKeyVersion=0
channel. defKeyIndex=0
The error now looks like this:
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123'
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Attributes mail,cn,uid
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed cn=Test User1
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 3
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed uid=testuser1
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 4
[2009-01-07 11:20:41] bacd2d28 RA_Format_Processor::Process - Authenticate returns: 0
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2009-01-07 11:20:41] bacd2d28 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='20')
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg -
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='13'
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%00%00%08%95%74%0B%AC%37%C9%DE%8 0'
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='30')
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 71 61 57 01 0e 0d 90 bd
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - ff 02 00 21 2e 6b ec 9e 33 2b
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - a5 26 d0 02 e6 64 c9 3c 90 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg -
[2009-01-07 11:20:41] bacd2d28 HttpConnection::getResponse - Send request to host localhost.localdomain:13443 servlet /tks/agent/tks/computeSessionKey
[2009-01-07 11:20:42] bacd2d28 RA::Engine - Pre-processing content 'HTTP/1.1 200 OK
Server: Apache-Coyote/1.1
Content-Type: text/html
Content-Length: 8
Date: Wed, 07 Jan 2009 16:20:42 GMT
status=3
[2009-01-07 11:20:42] bacd2d28 RA::Engine - Post-processing content 'status=3
[2009-01-07 11:20:42] bacd2d28 RA_Format_Processor::Process - applet upgrade failed
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - 90 00
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
In addition - the following is the pki-tps.tps-error.log snippet
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel creation failure
I'm also bringing John Whitelock, another one of our engineers in on discussions. He just joined the pki-users list.
Zach Casper
_____________________________________________ *From:* Jack Magne [mailto:jmagne@redhat.com] *Sent:* Wednesday, January 07, 2009 1:09 PM *To:* Zach Casper *Cc:* pki-users@redhat.com *Subject:* Re: [Pki-users] ESC Format / Enroll Error
Zach:
Sorry for the delay....
The default developer keyset we use for our keys with TPS is the
standard like follows:
tks.defKeySet.auth_key=#40#41...#4f
tks.defKeySet.kek_key=#40#41...#4f
tks.defKeySet.mac_key=#40#41.. #4f
If you look in the CS.cfg file under
/var/lib/pki-tks/conf
We have an entire procedure documented in the CS 7.3 documentation to
perform a key changeover if required.
Feel free to post any further logs you might obtain after further testing.
thanks,
jack
Zach Casper wrote:
Could there be an issue with the default key our card is loaded with
(VISA Key) not being able to create the secure connection? What are
the default key(s) used/needed by Dogtag?
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 5:35 PM
*To:* Zach Casper
*Cc:* pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
I'll have to take a closer look later but there is a quick thing you can
try.
Also, remember depending upon your card, if you make too many failed
attempts at a secure channel, the card can lock itself up.
In /var/lib/pki-tps/conf/CS.cfg you will have a block like this:
channel.defKeyVersion=1
channel. defKeyIndex=1
We have experimented with some other cards where the following works:
channel.defKeyVersion=0
channel.defKeyIndex=0
Zach Casper wrote:
tps-error.log
...
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel
creation failure
tps-debug.log
...
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process -
Authenticate returns: 0
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - path =
/usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='20')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6f 10 84 08 a0 00
00 00 03 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 00 00 a5 04 9f 65
01 ff 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg -
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='13'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%56%F5%29%9D%7B%8F%6F%A 7'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6a 86
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - applet
upgrade failed
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=43&msg_type=13&operation=5&result=1&message=19'
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 2:38 PM
*To:* Adewumi, Julius-p99373
*Cc:* Zach Casper; pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
You are having a problem creating a secure channel. Perhaps posting a
snippet of the log might help.
Adewumi, Julius-p99373 wrote:
You might want to play with changing "false" to "true in the
CS.cfg for
op.enroll.userKey.update.applet.emptyToken.enable=false or the
op.format... equivalent , etc.
/From: Julius Adewumi/
/@GDC4S.com/
/Ph:480-441-6768/
/Contract Corp:MTSI/
*From:* pki-users-bounces@redhat.com
[mailto:pki-users-bounces@redhat.com] *On Behalf Of *Zach Casper
*Sent:* Tuesday, December 23, 2008 12:00 PM
*To:* pki-users@redhat.com
*Subject:* RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following:
RA_Format_Processor::Process - applet upgrade failed
Tps-error log show the following:
RA_Processor::SetupSecureChannel - Failed to create a secure channel
0- potentially due to an RA/TKS key mismatch or differing RA/TKS key
versions.
RA_Processor::UpgradeApplet -0 channel create failure
And a series of Bad Response when trying to SelectApplet or
GetStatus
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 1:10 PM
*To:* Zach Casper
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
The first step would be to take a look at the tps log or smart card
server.
These can be found at:
/var/lib/pki-tps/logs/tps-debug.log
Search the bottom of the log for error 19 and it should give you an
idea
of what TPS was trying to do at the time.
Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
"Formatting of smart card failed. Error: The Smart Card Server
cannot
upgrade the software on your smart card."
And Diagnostics show this error:
"Attempting to Format Key, ID: ####### - Key Format failure,
Error:
19."
This card comes up as "Formatted" because we've manually
installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
John,Zach: After looking into this, it appears that for the case of using the developer key set, there is some code in our tks, specifically the "symkey" rpm, that appears to be hard coded for Axalto tokens. Working on narrowing it down... John Whitelock wrote:
Jack,
Thanks again for the help. Below I have pasted the log you asked for from that same test.
[07/Jan/2009:11:20:42][http-13443-Processor25]: Authentication: client certificate found [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: Authentication: mapped certificate to user [07/Jan/2009:11:20:42][http-13443-Processor25]: authenticated uid=TPS-localhost.localdomain-7889,ou=People,dc=localhost.localdomain-pki-tk s [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create() message=[AuditEvent=AUTH_SUCCESS][SubjectID=TPS-localhost.localdomain-7889][ Outcome=Success][AuthMgr=certUserDBAuthMgr] authentication success
[07/Jan/2009:11:20:42][http-13443-Processor25]: checkACLS(): ACLEntry expressions= group="Token Key Service Manager Agents" [07/Jan/2009:11:20:42][http-13443-Processor25]: evaluating expressions: group="Token Key Service Manager Agents" [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: UGSubsystem.isMemberOf() using new lookup code [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization search base: cn=Token Key Service Manager Agents,ou=groups,dc=localhost.localdomain-pki-tks [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization search filter: (uniquemember=uid=TPS-localhost.localdomain-7889,ou=People,dc=localhost.loca ldomain-pki-tks) [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization result: true [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: evaluated expression: group="Token Key Service Manager Agents" to be true [07/Jan/2009:11:20:42][http-13443-Processor25]: DirAclAuthz: authorization passed [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create() message=[AuditEvent=AUTHZ_SUCCESS][SubjectID=TPS-localhost.localdomain-7889] [Outcome=Success][aclResource=certServer.tks.sessionkey][Op=read] authorization success
[07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create() message=[AuditEvent=ROLE_ASSUME][SubjectID=TPS-localhost.localdomain-7889][O utcome=Success][Role=Token Key Service Manager Agents] assume privileged role
[07/Jan/2009:11:20:42][http-13443-Processor25]: keySet selected: defKeySet [07/Jan/2009:11:20:42][http-13443-Processor25]: keySet selected: defKeySet [07/Jan/2009:11:20:42][http-13443-Processor25]: processComputeSessionKey: [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet: serversideKeygen requested [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet about to try ComputeSessionKey selectedToken=Internal Key Storage Token keyNickName=#FF#02 [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:Tried ComputeSessionKey, got NULL java.lang.Exception: Can't compute session key! at com.netscape.cms.servlet.tks.TokenServlet.processComputeSessionKey(TokenServ let.java:336) at com.netscape.cms.servlet.tks.TokenServlet.process(TokenServlet.java:945) at com.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:482) at com.netscape.cms.servlet.tks.TokenServlet.service(TokenServlet.java:964) at javax.servlet.http.HttpServlet.service(HttpServlet.java:729) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Application FilterChain.java:269) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterCh ain.java:188) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.ja va:213) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.ja va:172) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127 ) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117 ) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:548) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java :108) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:174) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:875) at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processC onnection(Http11BaseProtocol.java:665) at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.jav a:528) at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWo rkerThread.java:81) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.jav a:689) at java.lang.Thread.run(Thread.java:636) [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet Computing Session Key: java.lang.Exception: Can't compute session key! [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:outputString.encode status=3 [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:outputString.length 8 [07/Jan/2009:11:20:42][http-13443-Processor25]: CMSServlet: curDate=Wed Jan 07 11:20:42 GMT-05:00 2009 id=tksSessionKey time=430
-----Original Message----- From: Jack Magne [mailto:jmagne@redhat.com] Sent: Wednesday, January 07, 2009 4:24 PM To: Zach Casper Cc: pki-users@redhat.com; 'John Whitelock' Subject: Re: [Pki-users] ESC Format / Enroll Error
Zach:
It looks like with your second test, you have managed to get by the hurdle of the failed "InitializeUpdate" command. This is due to using 0 and 0 for the defKeyVersion and defKeyIndex.
Now it looks like the TKS system is not acting as expected.
It would be great to have a look at the TKS debug log found in /var/lib/pki-tks/logs
I suspect we are having an issue with computing the session key in the TKS.
thanks, jack
Zach Casper wrote:
Thanks Jack.
It appears we are using the same keys so on to troubleshooting our error logs. Below are our current logs file contents.
When we use the default values:
channel.defKeyVersion=1
channel. defKeyIndex=1
Ther error we get is:
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123'
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Attributes mail,cn,uid
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed cn=Test User1
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 3
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed uid=testuser1
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 4
[2009-01-07 11:05:07] ba6ec600 RA_Format_Processor::Process - Authenticate returns: 0
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2009-01-07 11:05:07] ba6ec600 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='20')
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg -
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='13'
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%09%CD%60%A7%11%EC%23%A 5'
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 6a 86
[2009-01-07 11:05:08] ba6ec600 RA_Format_Processor::Process - applet upgrade failed
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 90 00
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
When we switch the values to be:
channel.defKeyVersion=0
channel. defKeyIndex=0
The error now looks like this:
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123'
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Attributes mail,cn,uid
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed cn=Test User1
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 3
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed uid=testuser1
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 4
[2009-01-07 11:20:41] bacd2d28 RA_Format_Processor::Process - Authenticate returns: 0
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent 's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2009-01-07 11:20:41] bacd2d28 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='20')
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg -
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='13'
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%00%00%08%95%74%0B%AC%37%C9%DE%8 0'
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='30')
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 71 61 57 01 0e 0d 90 bd
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - ff 02 00 21 2e 6b ec 9e 33 2b
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - a5 26 d0 02 e6 64 c9 3c 90 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg -
[2009-01-07 11:20:41] bacd2d28 HttpConnection::getResponse - Send request to host localhost.localdomain:13443 servlet /tks/agent/tks/computeSessionKey
[2009-01-07 11:20:42] bacd2d28 RA::Engine - Pre-processing content 'HTTP/1.1 200 OK
Server: Apache-Coyote/1.1
Content-Type: text/html
Content-Length: 8
Date: Wed, 07 Jan 2009 16:20:42 GMT
status=3
[2009-01-07 11:20:42] bacd2d28 RA::Engine - Post-processing content 'status=3
[2009-01-07 11:20:42] bacd2d28 RA_Format_Processor::Process - applet upgrade failed
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - 90 00
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
In addition - the following is the pki-tps.tps-error.log snippet
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel creation failure
I'm also bringing John Whitelock, another one of our engineers in on discussions. He just joined the pki-users list.
Zach Casper
_____________________________________________ *From:* Jack Magne [mailto:jmagne@redhat.com] *Sent:* Wednesday, January 07, 2009 1:09 PM *To:* Zach Casper *Cc:* pki-users@redhat.com *Subject:* Re: [Pki-users] ESC Format / Enroll Error
Zach:
Sorry for the delay....
The default developer keyset we use for our keys with TPS is the
standard like follows:
tks.defKeySet.auth_key=#40#41...#4f
tks.defKeySet.kek_key=#40#41...#4f
tks.defKeySet.mac_key=#40#41.. #4f
If you look in the CS.cfg file under
/var/lib/pki-tks/conf
We have an entire procedure documented in the CS 7.3 documentation to
perform a key changeover if required.
Feel free to post any further logs you might obtain after further testing.
thanks,
jack
Zach Casper wrote:
Could there be an issue with the default key our card is loaded with
(VISA Key) not being able to create the secure connection? What are
the default key(s) used/needed by Dogtag?
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 5:35 PM
*To:* Zach Casper
*Cc:* pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
I'll have to take a closer look later but there is a quick thing you can
try.
Also, remember depending upon your card, if you make too many failed
attempts at a secure channel, the card can lock itself up.
In /var/lib/pki-tps/conf/CS.cfg you will have a block like this:
channel.defKeyVersion=1
channel. defKeyIndex=1
We have experimented with some other cards where the following works:
channel.defKeyVersion=0
channel.defKeyIndex=0
Zach Casper wrote:
tps-error.log
...
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel
creation failure
tps-debug.log
...
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process -
Authenticate returns: 0
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - path =
/usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='20')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6f 10 84 08 a0 00
00 00 03 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 00 00 a5 04 9f 65
01 ff 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg -
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='13'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%56%F5%29%9D%7B%8F%6F%A 7'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6a 86
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - applet
upgrade failed
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=43&msg_type=13&operation=5&result=1&message=19'
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 2:38 PM
*To:* Adewumi, Julius-p99373
*Cc:* Zach Casper; pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
You are having a problem creating a secure channel. Perhaps posting a
snippet of the log might help.
Adewumi, Julius-p99373 wrote:
You might want to play with changing "false" to "true in the
CS.cfg for
op.enroll.userKey.update.applet.emptyToken.enable=false or the
op.format... equivalent , etc.
/From: Julius Adewumi/
/@GDC4S.com/
/Ph:480-441-6768/
/Contract Corp:MTSI/
*From:* pki-users-bounces@redhat.com
[mailto:pki-users-bounces@redhat.com] *On Behalf Of *Zach Casper
*Sent:* Tuesday, December 23, 2008 12:00 PM
*To:* pki-users@redhat.com
*Subject:* RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following:
RA_Format_Processor::Process - applet upgrade failed
Tps-error log show the following:
RA_Processor::SetupSecureChannel - Failed to create a secure channel
0- potentially due to an RA/TKS key mismatch or differing RA/TKS key
versions.
RA_Processor::UpgradeApplet -0 channel create failure
And a series of Bad Response when trying to SelectApplet or
GetStatus
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 1:10 PM
*To:* Zach Casper
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
The first step would be to take a look at the tps log or smart card
server.
These can be found at:
/var/lib/pki-tps/logs/tps-debug.log
Search the bottom of the log for error 19 and it should give you an
idea
of what TPS was trying to do at the time.
Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
"Formatting of smart card failed. Error: The Smart Card Server
cannot
upgrade the software on your smart card."
And Diagnostics show this error:
"Attempting to Format Key, ID: ####### - Key Format failure,
Error:
19."
This card comes up as "Formatted" because we've manually
installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
Thank you for the help Jack. Please let us know if there is anything we can do to help you. John -----Original Message----- From: Jack Magne [mailto:jmagne@redhat.com] Sent: Friday, January 09, 2009 1:53 PM To: John Whitelock Cc: pki-users@redhat.com; 'Zach Casper' Subject: Re: [Pki-users] ESC Format / Enroll Error John,Zach: After looking into this, it appears that for the case of using the developer key set, there is some code in our tks, specifically the "symkey" rpm, that appears to be hard coded for Axalto tokens. Working on narrowing it down... John Whitelock wrote:
Jack,
Thanks again for the help. Below I have pasted the log you asked for from that same test.
[07/Jan/2009:11:20:42][http-13443-Processor25]: Authentication: client certificate found [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: Authentication: mapped certificate to user [07/Jan/2009:11:20:42][http-13443-Processor25]: authenticated
uid=TPS-localhost.localdomain-7889,ou=People,dc=localhost.localdomain-pki-tk
s [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create()
message=[AuditEvent=AUTH_SUCCESS][SubjectID=TPS-localhost.localdomain-7889][
Outcome=Success][AuthMgr=certUserDBAuthMgr] authentication success
[07/Jan/2009:11:20:42][http-13443-Processor25]: checkACLS(): ACLEntry expressions= group="Token Key Service Manager Agents" [07/Jan/2009:11:20:42][http-13443-Processor25]: evaluating expressions: group="Token Key Service Manager Agents" [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: UGSubsystem.isMemberOf() using new lookup code [07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization search base: cn=Token Key Service Manager Agents,ou=groups,dc=localhost.localdomain-pki-tks [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization search filter:
(uniquemember=uid=TPS-localhost.localdomain-7889,ou=People,dc=localhost.loca
ldomain-pki-tks) [07/Jan/2009:11:20:42][http-13443-Processor25]: authorization result: true [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: evaluated expression: group="Token Key Service Manager Agents" to be true [07/Jan/2009:11:20:42][http-13443-Processor25]: DirAclAuthz: authorization passed [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create()
message=[AuditEvent=AUTHZ_SUCCESS][SubjectID=TPS-localhost.localdomain-7889]
[Outcome=Success][aclResource=certServer.tks.sessionkey][Op=read] authorization success
[07/Jan/2009:11:20:42][http-13443-Processor25]: getConn: mNumConns now 2 [07/Jan/2009:11:20:42][http-13443-Processor25]: returnConn: mNumConns now 3 [07/Jan/2009:11:20:42][http-13443-Processor25]: SignedAuditEventFactory: create()
message=[AuditEvent=ROLE_ASSUME][SubjectID=TPS-localhost.localdomain-7889][O
utcome=Success][Role=Token Key Service Manager Agents] assume privileged role
[07/Jan/2009:11:20:42][http-13443-Processor25]: keySet selected: defKeySet [07/Jan/2009:11:20:42][http-13443-Processor25]: keySet selected: defKeySet [07/Jan/2009:11:20:42][http-13443-Processor25]: processComputeSessionKey: [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet: serversideKeygen requested [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet about to try ComputeSessionKey selectedToken=Internal Key Storage Token keyNickName=#FF#02 [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:Tried ComputeSessionKey, got NULL java.lang.Exception: Can't compute session key! at
com.netscape.cms.servlet.tks.TokenServlet.processComputeSessionKey(TokenServ
let.java:336) at com.netscape.cms.servlet.tks.TokenServlet.process(TokenServlet.java:945) at com.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:482) at com.netscape.cms.servlet.tks.TokenServlet.service(TokenServlet.java:964) at javax.servlet.http.HttpServlet.service(HttpServlet.java:729) at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Application
FilterChain.java:269) at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterCh
ain.java:188) at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.ja
va:213) at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.ja
va:172) at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127
) at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117
) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:548) at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java
:108) at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:174)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:875) at
org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processC
onnection(Http11BaseProtocol.java:665) at
org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.jav
a:528) at
org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWo
rkerThread.java:81) at
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.jav
a:689) at java.lang.Thread.run(Thread.java:636) [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet Computing Session Key: java.lang.Exception: Can't compute session key! [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:outputString.encode status=3 [07/Jan/2009:11:20:42][http-13443-Processor25]: TokenServlet:outputString.length 8 [07/Jan/2009:11:20:42][http-13443-Processor25]: CMSServlet: curDate=Wed Jan 07 11:20:42 GMT-05:00 2009 id=tksSessionKey time=430
-----Original Message----- From: Jack Magne [mailto:jmagne@redhat.com] Sent: Wednesday, January 07, 2009 4:24 PM To: Zach Casper Cc: pki-users@redhat.com; 'John Whitelock' Subject: Re: [Pki-users] ESC Format / Enroll Error
Zach:
It looks like with your second test, you have managed to get by the hurdle of the failed "InitializeUpdate" command. This is due to using 0 and 0 for the defKeyVersion and defKeyIndex.
Now it looks like the TKS system is not acting as expected.
It would be great to have a look at the TKS debug log found in /var/lib/pki-tks/logs
I suspect we are having an issue with computing the session key in the TKS.
thanks, jack
Zach Casper wrote:
Thanks Jack.
It appears we are using the same keys so on to troubleshooting our error logs. Below are our current logs file contents.
When we use the default values:
channel.defKeyVersion=1
channel. defKeyIndex=1
Ther error we get is:
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123'
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Attributes mail,cn,uid
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed cn=Test User1
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 3
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Exposed uid=testuser1
[2009-01-07 11:05:07] ba6ec600 LDAP_Authentication::Authenticate - Size 4
[2009-01-07 11:05:07] ba6ec600 RA_Format_Processor::Process - Authenticate returns: 0
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent
's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2009-01-07 11:05:07] ba6ec600 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='20')
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00
[2009-01-07 11:05:07] ba6ec600 AP_Session::ReadMsg -
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - pdu_len='13'
[2009-01-07 11:05:07] ba6ec600 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%09%CD%60%A7%11%EC%23%A
5'
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 6a 86
[2009-01-07 11:05:08] ba6ec600 RA_Format_Processor::Process - applet upgrade failed
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:05:08] ba6ec600 AP_Session::ReadMsg - 90 00
[2009-01-07 11:05:08] ba6ec600 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
When we switch the values to be:
channel.defKeyVersion=0
channel. defKeyIndex=0
The error now looks like this:
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - User bind required 'uid=testuser1,ou=People,dc=localdomain' 'envieta123'
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Attributes mail,cn,uid
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed cn=Test User1
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 3
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Exposed uid=testuser1
[2009-01-07 11:20:41] bacd2d28 LDAP_Authentication::Authenticate - Size 4
[2009-01-07 11:20:41] bacd2d28 RA_Format_Processor::Process - Authenticate returns: 0
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent
's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2009-01-07 11:20:41] bacd2d28 RA_Processor::UpgradeApplet - path = /usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='20')
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 6f 10 84 08 a0 00 00 00 03 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 a5 04 9f 65 01 ff 90 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg -
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - pdu_len='13'
[2009-01-07 11:20:41] bacd2d28 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%00%00%08%95%74%0B%AC%37%C9%DE%8
0'
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='30')
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - 00 00 71 61 57 01 0e 0d 90 bd
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - ff 02 00 21 2e 6b ec 9e 33 2b
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg - a5 26 d0 02 e6 64 c9 3c 90 00
[2009-01-07 11:20:41] bacd2d28 AP_Session::ReadMsg -
[2009-01-07 11:20:41] bacd2d28 HttpConnection::getResponse - Send request to host localhost.localdomain:13443 servlet /tks/agent/tks/computeSessionKey
[2009-01-07 11:20:42] bacd2d28 RA::Engine - Pre-processing content 'HTTP/1.1 200 OK
Server: Apache-Coyote/1.1
Content-Type: text/html
Content-Length: 8
Date: Wed, 07 Jan 2009 16:20:42 GMT
status=3
[2009-01-07 11:20:42] bacd2d28 RA::Engine - Post-processing content 'status=3
[2009-01-07 11:20:42] bacd2d28 RA_Format_Processor::Process - applet upgrade failed
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - pdu_len='12'
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - decoded pdu = (length='2')
[2009-01-07 11:20:42] bacd2d28 AP_Session::ReadMsg - 90 00
[2009-01-07 11:20:42] bacd2d28 AP_Session::WriteMsg - Sent 's=43&msg_type=13&operation=5&result=1&message=19'
In addition - the following is the pki-tps.tps-error.log snippet
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel creation failure [2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel - Failed to create a secure channel - potentially due to an RA/TKS key mismatch or differing RA/TKS key versions. [2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel creation failure
I'm also bringing John Whitelock, another one of our engineers in on discussions. He just joined the pki-users list.
Zach Casper
_____________________________________________ *From:* Jack Magne [mailto:jmagne@redhat.com] *Sent:* Wednesday, January 07, 2009 1:09 PM *To:* Zach Casper *Cc:* pki-users@redhat.com *Subject:* Re: [Pki-users] ESC Format / Enroll Error
Zach:
Sorry for the delay....
The default developer keyset we use for our keys with TPS is the
standard like follows:
tks.defKeySet.auth_key=#40#41...#4f
tks.defKeySet.kek_key=#40#41...#4f
tks.defKeySet.mac_key=#40#41.. #4f
If you look in the CS.cfg file under
/var/lib/pki-tks/conf
We have an entire procedure documented in the CS 7.3 documentation to
perform a key changeover if required.
Feel free to post any further logs you might obtain after further
testing.
thanks,
jack
Zach Casper wrote:
Could there be an issue with the default key our card is loaded with
(VISA Key) not being able to create the secure connection? What are
the default key(s) used/needed by Dogtag?
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 5:35 PM
*To:* Zach Casper
*Cc:* pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
I'll have to take a closer look later but there is a quick thing you can
try.
Also, remember depending upon your card, if you make too many failed
attempts at a secure channel, the card can lock itself up.
In /var/lib/pki-tps/conf/CS.cfg you will have a block like this:
channel.defKeyVersion=1
channel. defKeyIndex=1
We have experimented with some other cards where the following works:
channel.defKeyVersion=0
channel.defKeyIndex=0
Zach Casper wrote:
tps-error.log
...
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:09:39] ba5de4e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:10:20] ba5cb398 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:10:20] ba5cb398 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:11:14] b8e04520 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:11:14] b8e04520 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:39:38] ba5c00e0 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:44:27] ba5b14c8 RA_Processor::UpgradeApplet - channel
creation failure
[2008-12-23 12:45:54] ba5f2590 RA_Processor::SetupSecureChannel -
Failed to create a secure channel - potentially due to an RA/TKS key
mismatch or differing RA/TKS key versions.
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - channel
creation failure
tps-debug.log
...
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process -
Authenticate returns: 0
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=67&msg_type=14¤t_state=10&next_task_name=PROGRESS_APPLET_UPGRADE'
[2008-12-23 12:45:54] ba5f2590 RA_Processor::UpgradeApplet - path =
/usr/share/pki/tps/applets/1.3.44724DDE.ijc
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%A0%00%00%00%03%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='20')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6f 10 84 08 a0 00
00 00 03 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 00 00 a5 04 9f 65
01 ff 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg -
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='13'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=71&msg_type=9&pdu_size=13&pdu_data=%80%50%01%01%08%56%F5%29%9D%7B%8F%6F%A
7'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 6a 86
[2008-12-23 12:45:54] ba5f2590 RA_Format_Processor::Process - applet
upgrade failed
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - pdu_len='12'
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=68&msg_type=9&pdu_size=12&pdu_data=%00%A4%04%00%07%62%76%01%FF%00%00%00'
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - decoded pdu =
(length='2')
[2008-12-23 12:45:54] ba5f2590 AP_Session::ReadMsg - 90 00
[2008-12-23 12:45:54] ba5f2590 AP_Session::WriteMsg - Sent
's=43&msg_type=13&operation=5&result=1&message=19'
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 2:38 PM
*To:* Adewumi, Julius-p99373
*Cc:* Zach Casper; pki-users@redhat.com
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
You are having a problem creating a secure channel. Perhaps posting a
snippet of the log might help.
Adewumi, Julius-p99373 wrote:
You might want to play with changing "false" to "true in the
CS.cfg for
op.enroll.userKey.update.applet.emptyToken.enable=false or the
op.format... equivalent , etc.
/From: Julius Adewumi/
/@GDC4S.com/
/Ph:480-441-6768/
/Contract Corp:MTSI/
*From:* pki-users-bounces@redhat.com
[mailto:pki-users-bounces@redhat.com] *On Behalf Of *Zach Casper
*Sent:* Tuesday, December 23, 2008 12:00 PM
*To:* pki-users@redhat.com
*Subject:* RE: [Pki-users] ESC Format / Enroll Error
Tps-debug log shows the following:
RA_Format_Processor::Process - applet upgrade failed
Tps-error log show the following:
RA_Processor::SetupSecureChannel - Failed to create a secure channel
0- potentially due to an RA/TKS key mismatch or differing RA/TKS key
versions.
RA_Processor::UpgradeApplet -0 channel create failure
And a series of Bad Response when trying to SelectApplet or
GetStatus
zach
_____________________________________________
*From:* Jack Magne [mailto:jmagne@redhat.com]
*Sent:* Tuesday, December 23, 2008 1:10 PM
*To:* Zach Casper
*Subject:* Re: [Pki-users] ESC Format / Enroll Error
The first step would be to take a look at the tps log or smart card
server.
These can be found at:
/var/lib/pki-tps/logs/tps-debug.log
Search the bottom of the log for error 19 and it should give you an
idea
of what TPS was trying to do at the time.
Zach Casper wrote:
We have an Infineon Smart Card and currently we are unable to
Format/Enroll due to the following ESC Error
"Formatting of smart card failed. Error: The Smart Card Server
cannot
upgrade the software on your smart card."
And Diagnostics show this error:
"Attempting to Format Key, ID: ####### - Key Format failure,
Error:
19."
This card comes up as "Formatted" because we've manually
installed a
version of the Dogtag applet prior to using ESC & Dogtag.
Any advice on how we can troubleshoot?
--
Zach Casper
Envieta LLC
----------------------------------------
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
_______________________________________________
Pki-users mailing list
Pki-users@redhat.com
participants (4)
-
Adewumi, Julius-p99373 -
Jack Magne -
John Whitelock -
Zach Casper