[Pki-users] ESC Format / Enroll Error

Zach Casper zach.casper at envieta.com
Wed Jan 7 19:14:16 UTC 2009 

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&current_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&current_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 at redhat.com] 
Sent: Wednesday, January 07, 2009 1:09 PM
To: Zach Casper
Cc: pki-users at 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 at redhat.com]
> *Sent:* Tuesday, December 23, 2008 5:35 PM
> *To:* Zach Casper
> *Cc:* pki-users at 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&current_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 at redhat.com]
>
> > *Sent:* Tuesday, December 23, 2008 2:38 PM
>
> > *To:* Adewumi, Julius-p99373
>
> > *Cc:* Zach Casper; pki-users at 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 at redhat.com
>
> >
>
> > > [mailto:pki-users-bounces at redhat.com] *On Behalf Of *Zach Casper
>
> >
>
> > > *Sent:* Tuesday, December 23, 2008 12:00 PM
>
> >
>
> > > *To:* pki-users at 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 at 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 at redhat.com
>
> >
>
> > >
>
> >
>
> > > > https://www.redhat.com/mailman/listinfo/pki-users
>
> >
>
> > >
>
> >
>
> > > >
>
> >
>
> > >
>
> >
>
> > > 
> ------------------------------------------------------------------------
>
> >
>
> > >
>
> >
>
> > > _______________________________________________
>
> >
>
> > > Pki-users mailing list
>
> >
>
> > > Pki-users at redhat.com
>
> >
>
> > > https://www.redhat.com/mailman/listinfo/pki-users
>
> >
>
> > >
>
> >
>
> > ------------------------------------------------------------------------
>
> >
>
> > _______________________________________________
>
> > Pki-users mailing list
>
> > Pki-users at redhat.com
>
> > https://www.redhat.com/mailman/listinfo/pki-users
>
> >
>


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/pki-users/attachments/20090107/c5d2fb98/attachment.htm>

More information about the Pki-users mailing list