SignServer / Discussion / Help: "Token has been removed" err...

Hi all.
I've a problem using SignServer with a Safenet LunaSA.
After some time the server runs unused (one hour or so) the server stop working and I get a 'Token has been removed" error.

Follows the stacktrace:

java.security.ProviderException: Token has been removed
    at sun.security.pkcs11.Session.id(Session.java:73)
    at sun.security.pkcs11.SessionManager.ensureValid(SessionManager.java:134)
    at sun.security.pkcs11.SessionManager.getOpSession(SessionManager.java:117)
    at sun.security.pkcs11.Token.getOpSession(Token.java:247)
    at sun.security.pkcs11.P11Signature.initialize(P11Signature.java:283)
    at sun.security.pkcs11.P11Signature.engineInitSign(P11Signature.java:375)
    at java.security.Signature$Delegate.engineInitSign(Signature.java:1095)
    at java.security.Signature.initSign(Signature.java:480)
    at org.ejbca.core.model.ca.catoken.BaseCAToken.testKey(BaseCAToken.java:100)
    at org.ejbca.core.model.ca.catoken.BaseCAToken.getCATokenStatus(BaseCAToken.java:425)
    at org.signserver.server.cryptotokens.CryptoTokenBase.getCryptoTokenStatus(CryptoTokenBase.java:105)
    at org.signserver.server.signers.BaseSigner.getStatus(BaseSigner.java:48)
    at org.signserver.ejb.WorkerSessionBean.process(WorkerSessionBean.java:192)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
    at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
    at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:79)
    at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:191)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77)
    at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:110)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:240)
    at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:210)
    at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:84)
    at $Proxy104.process(Unknown Source)
    at org.signserver.web.GenericProcessServlet.processRequest(GenericProcessServlet.java:350)
    at org.signserver.web.GenericProcessServlet.doPost(GenericProcessServlet.java:254)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
    at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:182)
    at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
    at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:437)
    at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:366)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
    at java.lang.Thread.run(Thread.java:662)

Thanks a lot,
Massimiliano

Massimiliano Ziccardi - 2012-01-23

Here are the server data:

SignServer V. 3.2.1
JVM : Sun Java 1.6.0.30
OS : Windows 2008 R2

Regards,
Massimiliano

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Anonymous - 2012-01-23

If this happens all the time this could be due to a network issue.
There may be a parameter fot setting time-to-live or refresh.

Does activate also fail?

Anders
tech support

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Massimiliano Ziccardi - 2012-01-23

Yes, activate also fail. As soon as I have that error, I have to restart the whole application.

About the time-to-live/refresh: do you mean some LunaSA driver parameter? Or a SignServer setting?

I already activated the TCPKeepAlive in the LunaSA driver configuration, but with no luck.

Thanks,
Massimiliano

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Anonymous - 2012-01-23

Is this really the complete stack-trace? I.e. there's nothing available from lower layers?
I'm not a LunaSA expert, but surely there must be some log-files also for LunaSA that could give a hint.

Anders
tech support

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Massimiliano Ziccardi - 2012-01-23

Yes, that's the complete Stacktrace: Signserver uses the SunPKCS#11 provider to connect to the Luna.

Thanks,
Massimiliano

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Anonymous - 2012-01-23

I looked at the source code of SunPKCS#11 and it seems that it doesn't do anything but testing if the token is available so the (non-informative) stack-trace is unfortunately ok…

Workariund:
http://mail.openjdk.java.net/pipermail/security-dev/2010-April/001817.html

There seems to be a LunaSA debug mode as well:
http://c3.safenet-inc.com/downloads/3/D/3D587845-18A0-49FA-A8F1-991FE2E42404/CRN_Luna_SA_4-2.pdf

Anders
tech support

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Tomas Gustavsson - 2012-01-23

Yes most certainly the network connect was broken and then a restart of JBoss is needed.

Normally you can "ping" the HSM by doing a HeealthCheck regularly to keep the connection open.
I never had to do that with Luna SA though, so it's probably some switch or firewall that kills your connection after some time.

/Tomas

PrimeKey Solutions offers commercial EJBCA and SignServer support subscriptions and training courses. Please see www.primekey.se or contact info@primekey.se for more information.
http://www.primekey.se/Services/Support/
http://www.primekey.se/Services/Training/

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Massimiliano Ziccardi - 2012-01-23

There's no firewall between signserver and the HSM….
I'm trying to schedule a 'signserver.cmd testkey' command every 5 minutes to see what happens….

I 'm even enabling cklog for the LunaSA appliance…
I'll let you know.

Thanks,
Massimiliano

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Tomas Gustavsson - 2012-06-07

hi Massimiliano,

I guess your problem was solved? Was there anything special to it?

Cheers,
Tomas

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Massimiliano Ziccardi - 2012-06-07

Sorry Tomas,
I completely forgot to write here how I solved the issue….

I wrote the safenet support complaining that my Java application was getting that error, and they suggested me to add the following rows in the crystoki.ini file

TCPKeepAlive=1 ClientKeepAlive=20

That solved the issue…. Probably there was a firewall that was dropping the connection and the "keep alive" setting solved the issue.

Thanks,
Massimiliano
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Tomas Gustavsson - 2012-06-07

Thanks, very helpful info!

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Tomas Gustavsson - 2012-06-07

Our Chrystoki.conf looks like:
Chrystoki2 = {
   LibUNIX64=/usr/lib/libCryptoki2_64.so;
}

Luna = {
DefaultTimeOut=500000;
PEDTimeout1=100000;
PEDTimeout2=100000;
}

CardReader = {
RemoteCommand=1;
}

LunaSA Client = {
   ClientPrivKeyFile = /…./cert/client/…Key.pem;
   ClientCertFile = /…./cert/client/….pem;
   ServerPort00 = 1792;
   ServerName00 = IP_Address;
NetClient=1;
ServerCAFile=…/cert/server/CAFile.pem;
SSLConfigFile=/usr/lunasa/bin/openssl.cnf;
ReceiveTimeout=20000;
}

Is this the file? In that case where should the lines be added?

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Hi Tomas.

I've not been clear, you are right.

On windows the file il a bit different, however the settings should be inside the LunaSA Client section.

Follows my config file.

[Chrystoki2]
LibNT=C:\Program Files\LunaSA\cryptoki.dll
[Luna]
DefaultTimeOut=500000
PEDTimeout1=100000
PEDTimeout2=100000
[CardReader]
RemoteCommand=1
[LunaSA Client]
NetClient=1
ServerCAFile=C:\Program Files (x86)\LunaSA\cert\server\CAFile.pem
ClientCertFile=C:\Program Files (x86)\LunaSA\cert\client\xxxx.pem
ClientPrivKeyFile=C:\Program Files (x86)\LunaSA\cert\client\xxxxKey.pem
SSLConfigFile=C:\Program Files (x86)\LunaSA\openssl.cnf
ReceiveTimeout=20000
ServerName00=xxx.yyy.zzz.www
ServerPort00=1792
TCPKeepAlive=1
ClientKeepAlive=20
ServerName01=xxx.yyy.zzz.www
ServerPort01=1792

Anonymous - 2012-06-07

Hi Massimiliano,

Did it occurred to you suddenly or you had problems before? What was the time slice for what the service worked properly?
Do you have other slots/partitions configured on this Luna SA? Did you have any problem with other services connected to these other slots?

I am asking this, because we have just obtained the same beautiful _Token has been removed error_ message problem:D and we want to figure out what the problem exactly is?

Thank you!
Csabi

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Massimiliano Ziccardi - 2012-06-07

Hi Csabi.

Follows the requested details.

Did it occurred to you suddenly or you had problems before?

We bought a couple of HSM dedicated to the Timestamping Service. The problem started immediately (after some minute).

What was the time slice for what the service worked properly?

I don't remember, sorry (it was 6 months ago).

Do you have other slots/partitions configured on this Luna SA?

Both HSM has only one slot/partition. Both SignServer machine can access both HSMs.

Did you have any problem with other services connected to these other slots?

As I told you these HSMs are dedicated to the Timestamping.

In other applications, with other LunaSA with many slots, we got the same problem.
With an older version (firmware/hardware) of the LunaSA, the setting I proposed here didn't work.

The HSM version for wich the setting worked is :

lunash:>hsm sh Appliance Details: ================== Software Version: 4.1.0-9 Firmware: 4.6.1 Hardware Model: Luna K5

The version that didn't work is:

lunash:>hsm sh Appliance Details: ================== Software Version: 4.3.0-5 Firmware: 4.5.3 Hardware Model: Luna K3

Regards,
Massimiliano
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

"Token has been removed" err...

Forums

Help

"Token has been removed" err... document.SUBSCRIPTION_OPTIONS = { "thing": "topic", "subscribed": false, "url": "subscribe", "icon": { "css": "fa fa-envelope-o" } };

/Tomas

"Token has been removed" err...