Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

"expected a protocol start message" error #40

Closed
GoogleCodeExporter opened this issue Mar 24, 2015 · 6 comments
Closed

"expected a protocol start message" error #40

GoogleCodeExporter opened this issue Mar 24, 2015 · 6 comments
Labels
auto-migrated Priority-Medium Type-Defect

Comments

@GoogleCodeExporter
Copy link 

hi,

Steps to reproduce the problem :

1. go to https://www.e-contract.be/eid-applet-test/identify.jsp
2. Click "yes" into the Privacy alert
3. i get an "General Error"

At this moment, it happens only on a particular computer(configuration),
under Firefox and Google Chrome but not with IE8.
Windows WP Pro.
eidApplet versions : 1.0.0.GA & 1.0.1-SNAPSHOT

Enabling logging on the server side, i get this log details:

DEBUG 2010-04-09 13:03:46,515
be.fedict.eid.applet.service.AppletServiceServlet - doPost
DEBUG 2010-04-09 13:03:46,515
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - current
protocol state: null
DEBUG 2010-04-09 13:03:46,515
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - protocol
state transition: INIT
DEBUG 2010-04-09 13:03:46,515
be.fedict.eid.applet.service.impl.handler.HelloMessageHandler - hello
message received
DEBUG 2010-04-09 13:03:46,515
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - current
protocol state: INIT
DEBUG 2010-04-09 13:03:46,515
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - protocol
state transition: IDENTIFY
DEBUG 2010-04-09 13:03:46,515
be.fedict.eid.applet.service.impl.CleanSessionProtocolStateListener -
cleaning up the identity session attributes...
DEBUG 2010-04-09 13:03:51,140
be.fedict.eid.applet.service.AppletServiceServlet - doPost
DEBUG 2010-04-09 13:03:51,156
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - current
protocol state: null
09-avr.-2010 13:03:51 org.apache.catalina.core.StandardWrapperValve invoke
GRAVE: "Servlet.service()" pour la servlet AppletServiceServlet a généré
une exception
java.lang.RuntimeException: expected a protocol start message
    at
be.fedict.eid.applet.shared.protocol.ProtocolStateMachine.checkRequestMessage(Pr
otocolStateMachine.java:107)
    at
be.fedict.eid.applet.service.AppletServiceServlet.doPost(AppletServiceServlet.ja
va:221)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)


But when it works well, I get :


DEBUG 2010-04-09 13:04:28,639
be.fedict.eid.applet.service.AppletServiceServlet - doPost
DEBUG 2010-04-09 13:04:28,639
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - current
protocol state: null
DEBUG 2010-04-09 13:04:28,639
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - protocol
state transition: INIT
DEBUG 2010-04-09 13:04:28,639
be.fedict.eid.applet.service.impl.handler.HelloMessageHandler - hello
message received
DEBUG 2010-04-09 13:04:28,639
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - current
protocol state: INIT
DEBUG 2010-04-09 13:04:28,639
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - protocol
state transition: IDENTIFY
DEBUG 2010-04-09 13:04:28,639
be.fedict.eid.applet.service.impl.CleanSessionProtocolStateListener -
cleaning up the identity session attributes...
DEBUG 2010-04-09 13:04:33,467
be.fedict.eid.applet.service.AppletServiceServlet - doPost
DEBUG 2010-04-09 13:04:33,483
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - current
protocol state: IDENTIFY


Looking at the source code, I suspected the http session to be cleaned or
lost so i added some debug to collect information about session :

DEBUG 2010-04-09 13:14:26,171
be.fedict.eid.applet.service.AppletServiceServlet - doPost
DEBUG 2010-04-09 13:14:26,171
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - current
protocol state: null, session:AEFB833F1D07C865E716CA56FCD76B33,
creationTime:1270811666171, lastAccessTime:1270811666171
DEBUG 2010-04-09 13:14:26,171
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - protocol
state transition: INIT, session:AEFB833F1D07C865E716CA56FCD76B33,
creationTime:1270811666171, lastAccessTime:1270811666171
DEBUG 2010-04-09 13:14:26,171
be.fedict.eid.applet.service.impl.handler.HelloMessageHandler - hello
message received
DEBUG 2010-04-09 13:14:26,171
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - current
protocol state: INIT, session:AEFB833F1D07C865E716CA56FCD76B33,
creationTime:1270811666171, lastAccessTime:1270811666171
DEBUG 2010-04-09 13:14:26,171
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - protocol
state transition: IDENTIFY, session:AEFB833F1D07C865E716CA56FCD76B33,
creationTime:1270811666171, lastAccessTime:1270811666171
DEBUG 2010-04-09 13:14:26,171
be.fedict.eid.applet.service.impl.CleanSessionProtocolStateListener -
cleaning up the identity session attributes...
DEBUG 2010-04-09 13:14:36,420
be.fedict.eid.applet.service.AppletServiceServlet - doPost
DEBUG 2010-04-09 13:14:36,436
be.fedict.eid.applet.service.impl.HttpServletProtocolContext - current
protocol state: null, session:EBE58099FF8D7FEF50D214AD07F7E6FD,
creationTime:1270811676436, lastAccessTime:1270811676436
09-avr.-2010 13:14:36 org.apache.catalina.core.StandardWrapperValve invoke
GRAVE: "Servlet.service()" pour la servlet AppletServiceServlet a généré
une exception
java.lang.RuntimeException: expected a protocol start message
    at
be.fedict.eid.applet.shared.protocol.ProtocolStateMachine.checkRequestMessage(Pr
otocolStateMachine.java:107)

As you can see, a new session has been created after the IDENTIFY message.
Why the applet starts a new session????

thanks a lot,

Sébastien

Original issue reported on code.google.com by sebastie...@gmail.com on 9 Apr 2010 at 12:36
@GoogleCodeExporter
Copy link
Author 

Are you sure that there exists an HTTP session cookie right before the eID 
Applet runs?

Original comment by frank.co...@gmail.com on 19 Apr 2010 at 10:07

@GoogleCodeExporter
Copy link
Author 

Here is a execution sample:

1) Right before the eID Applet runs, firefox shows session cookie with the 
session id
: 1E7D19D5057C1A353E8936DB3718A8FA

2) when I run the applet, i get that log on the server side :
---------------
DEBUG 16:05:08,485 be.fedict.eid.applet.service.AppletServiceServlet - doPost
DEBUG 16:05:08,485 be.fedict.eid.applet.service.impl.HttpServletProtocolContext 
-
current protocol state: null s, session:1B0FB2036FE29CB50F9C22B64E5CB70E,
creationTime:1271772308485, lastAccessTime:1271772308485
DEBUG 16:05:08,485 be.fedict.eid.applet.service.impl.HttpServletProtocolContext 
-
protocol state transition: INIT, session:1B0FB2036FE29CB50F9C22B64E5CB70E,
creationTime:1271772308485, lastAccessTime:1271772308485
DEBUG 16:05:08,485 
be.fedict.eid.applet.service.impl.handler.HelloMessageHandler -
hello message received
DEBUG 16:05:08,501 be.fedict.eid.applet.service.impl.HttpServletProtocolContext 
-
current protocol state: INIT s, session:1B0FB2036FE29CB50F9C22B64E5CB70E,
creationTime:1271772308485, lastAccessTime:1271772308485
DEBUG 16:05:08,501 be.fedict.eid.applet.service.impl.HttpServletProtocolContext 
-
protocol state transition: IDENTIFY, session:1B0FB2036FE29CB50F9C22B64E5CB70E,
creationTime:1271772308485, lastAccessTime:1271772308485
DEBUG 16:05:08,501
be.fedict.eid.applet.service.impl.CleanSessionProtocolStateListener - cleaning 
up the
identity session attributes...
--------------------

So the session ID has changed but firefox still display the old session id in 
http
session cookie...


3) Next, if click "yes" on the privacy popup, the server log is : 
--------------------
DEBUG 16:05:28,625 be.fedict.eid.applet.service.AppletServiceServlet - doPost
DEBUG 16:05:28,625 be.fedict.eid.applet.service.impl.HttpServletProtocolContext 
-
current protocol state: null s, session:40CE272FF239AA0D7CD982927E9DE5A8,
creationTime:1271772328625, lastAccessTime:1271772328625
16:05:28 org.apache.catalina.core.StandardWrapperValve invoke
GRAVE: "Servlet.service()" pour la servlet AppletServiceServlet a généré une 
exception
java.lang.RuntimeException: expected a protocol start message
--------------------

A new session ID is created again. Firefox still display the initial session id.


I'm not sure if the http session cookie displayed in firefox is properly 
refreshed
but it seems that a new session id is created each time the applet communicates 
with
the server.


Here is the applet log (note that the server asks for a new session cookie): 

--------------------
Niveau de traçage fixé à 5 : tous ... terminés.
basic: Starting applet teardown
basic: Finished applet teardown
basic: Récepteur de progression ajouté :
sun.plugin.util.GrayBoxPainter$GrayBoxProgressListener@15718f2
basic: Applet chargé.
basic: Applet resized and added to parent container
basic: PERF: AppletExecutionRunnable - applet.init() BEGIN ; jvmLaunch dt 
128350 us,
pluginInit dt 24251225 us, TotalTime: 24379575 us
basic: Applet initialized
basic: Récepteur de progression supprimé :
sun.plugin.util.GrayBoxPainter$GrayBoxProgressListener@15718f2
basic: Applet made visible
basic: Starting applet
basic: Applet started
basic: Told clients applet is started
network: Connexion de https://10.32.128.216:8443/mywebapp/applet-service avec
proxy=DIRECT
network: Connexion de http://10.32.128.216:8443/ avec proxy=DIRECT
network: Serveur https://10.32.128.216:8443/mywebapp/applet-service demandant de
définir un cookie avec "JSESSIONID=1B0FB2036FE29CB50F9C22B64E5CB70E; 
Path=/mywebapp;
Secure"
network: Connexion de https://10.32.128.216:8443/mywebapp/applet-service avec
proxy=DIRECT
network: Connexion de http://10.32.128.216:8443/ avec proxy=DIRECT 
--------------------


thx

Original comment by sebastie...@gmail.com on 20 Apr 2010 at 2:39

@GoogleCodeExporter
Copy link
Author 

Normally the Java plugin runtime received the session cookie from the web 
browser and uses this session cookie when the eID Applet communicates with the 
server. Apparently you're mixing http with https, which probably causes some 
session cookie issues (Secure session cookie).

Original comment by frank.co...@gmail.com on 21 Jun 2010 at 3:33

  • Changed state: WontFix

@GoogleCodeExporter
Copy link
Author 

Hi,

This is not related to a http/https mixing.

Since the revision 322 
"eid-applet-core/src/main/java/be/fedict/eid/applet/Controller.java" the applet 
displays the message "Error: No session cookie detected!" before the error 
occurs and I was able to reproduce the issue by disabling cookies in Firefox 
3.6.6.

If cookies are necessary to allow the use of the eID applet I suggest to return 
an error code directly like "SESSION_COOKIE_ERROR" instead of starting to 
exchange data with the server and then return a generic error. Thus, we can 
display a user friendly message asking to enable cookies to use the eID applet.

Original comment by sebastie...@gmail.com on 14 Jul 2010 at 3:49

@GoogleCodeExporter
Copy link
Author 

The problem with turning the session cookie detection into an error code is 
that we cannot differentiate between a server setting the session cookie to 
HttpOnly, or a web browser having disabled the usage of session cookie. So for 
the moment we can only give some warning in the detail messages.

Original comment by frank.co...@gmail.com on 19 Jul 2010 at 12:39

@GoogleCodeExporter
Copy link
Author 

Hello, and thanks for providing this open source.

Same error here however: expected a protocol start message

Only in Firefox, not in iE.

Is there a fix yet for this?

Original comment by polarpu...@hotmail.com on 14 Oct 2010 at 3:53

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
auto-migrated Priority-Medium Type-Defect
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@GoogleCodeExporter