mina-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Kaja Hovi (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (DIRMINA-842) Crash on Android
Date Thu, 07 Jul 2011 10:18:16 GMT

    [ https://issues.apache.org/jira/browse/DIRMINA-842?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13061185#comment-13061185
] 

Kaja Hovi commented on DIRMINA-842:
-----------------------------------

07-07 09:03:17.988: DEBUG/L4J(363): 9622 [NioProcessor-2] DEBUG org.apache.vysper.xmpp.protocol.SessionStateHolder
 - session state changed to = INITIATED
07-07 09:03:18.008: INFO/L4J(363): 9639 [NioProcessor-2] INFO org.apache.vysper.mina.XmppIoHandlerAdapter
 - new session from localhost/127.0.0.1:36058 has been opened
07-07 09:03:18.018: DEBUG/L4J(363): 9645 [NioProcessor-2] DEBUG org.apache.mina.filter.codec.ProtocolCodecFilter
 - Processing a MESSAGE_RECEIVED for session 1
07-07 09:03:18.128: DEBUG/L4J(363): 9764 [NioProcessor-2] DEBUG org.apache.vysper.xml.decoder.XMPPContentHandler
 - Decoder writing stanza: <stream:stream xmlns:stream="http://etherx.jabber.org/streams"
to="hovi.mk.zcu.cz" xml:lang="en" version="1.0"></stream:stream>
07-07 09:03:18.128: DEBUG/L4J(363): 9767 [NioProcessor-2] DEBUG stanza.client  - < <stream:stream
xmlns:stream="http://etherx.jabber.org/streams" to="hovi.mk.zcu.cz" xml:lang="en" version="1.0">
07-07 09:03:18.178: DEBUG/L4J(363): 9813 [pool-3-thread-1] DEBUG org.apache.vysper.xmpp.protocol.SessionStateHolder
 - session state changed to = STARTED
07-07 09:03:18.238: DEBUG/L4J(363): 9871 [NioProcessor-2] DEBUG org.apache.mina.filter.codec.ProtocolCodecFilter
 - Processing a MESSAGE_RECEIVED for session 1
07-07 09:03:18.259: DEBUG/L4J(363): 9896 [NioProcessor-2] DEBUG org.apache.vysper.xml.decoder.XMPPContentHandler
 - Decoder writing stanza: <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"></starttls>
07-07 09:03:18.268: DEBUG/L4J(363): 9900 [NioProcessor-2] DEBUG stanza.client  - < <starttls
xmlns="urn:ietf:params:xml:ns:xmpp-tls"></starttls>
07-07 09:03:18.298: DEBUG/L4J(363): 9928 [NioProcessor-2] DEBUG stanza.server  - > <stream:stream
xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" from="hovi.mk.zcu.cz"
version="1.0" id="e5a7b21bfa76489da1cdaea46d9ba96e"><stream:features xmlns:stream="http://etherx.jabber.org/streams"><starttls
xmlns="urn:ietf:params:xml:ns:xmpp-tls"><required></required></starttls></stream:features>
07-07 09:03:18.298: DEBUG/L4J(363): 9931 [pool-3-thread-2] DEBUG org.apache.vysper.xmpp.protocol.SessionStateHolder
 - session state changed to = ENCRYPTION_STARTED
07-07 09:03:18.328: DEBUG/L4J(363): 9958 [pool-3-thread-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Adding the SSL Filter sslFilter to the chain
07-07 09:03:18.337: DEBUG/L4J(363): 9972 [pool-3-thread-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](no sslEngine) Initializing the SSL Handler
07-07 09:03:18.388: DEBUG/L4J(363): 10021 [pool-3-thread-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](no sslEngine) SSL Handler Initialization done.
07-07 09:03:18.388: DEBUG/L4J(363): 10024 [pool-3-thread-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](ssl...) : Starting the first handshake
07-07 09:03:18.397: DEBUG/L4J(363): 10029 [pool-3-thread-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](ssl...) processing the NEED_UNWRAP state
07-07 09:03:18.448: DEBUG/L4J(363): 10085 [pool-3-thread-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](ssl...): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=59 cap=128:
3C 70 72 6F 63 65 65 64 20 78 6D 6C 6E 73 3D 22...]
07-07 09:03:18.498: DEBUG/L4J(363): 10132 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](ssl...): Message received : HeapBuffer[pos=0 lim=124 cap=1024: 80 7A
01 03 01 00 51 00 00 00 20 00 00 39 00 00...]
07-07 09:03:18.498: DEBUG/L4J(363): 10135 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](ssl...) Processing the received message
07-07 09:03:18.517: DEBUG/L4J(363): 10153 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](ssl...) processing the NEED_UNWRAP state
07-07 09:03:18.538: DEBUG/L4J(363): 10175 [pool-3-thread-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](ssl...): Writing Message : MessageWriteRequest, parent : WR WrapperWriteRequest:
[ prolog=false, open=true, close=true, content=true, stanza=[proceed]
07-07 09:03:19.188: DEBUG/L4J(363): 10819 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](ssl...) processing the NEED_TASK state
07-07 09:03:19.288: DEBUG/L4J(363): 10921 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](ssl...) processing the NEED_WRAP state
07-07 09:03:19.308: DEBUG/L4J(363): 10938 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](ssl...): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=758 cap=1152:
16 03 01 02 F1 02 00 00 46 03 01 4E 15 76 57 B5...]
07-07 09:03:19.308: DEBUG/L4J(363): 10941 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](ssl...) processing the NEED_UNWRAP state
07-07 09:03:19.328: DEBUG/L4J(363): 10959 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](ssl...): Processing the SSL Data 
07-07 09:03:19.428: DEBUG/L4J(363): 11063 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](ssl...): Message received : HeapBuffer[pos=0 lim=126 cap=1024: 16 03
01 00 46 10 00 00 42 00 40 36 CE CA 07 F6...]
07-07 09:03:19.428: DEBUG/L4J(363): 11067 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](ssl...) Processing the received message
07-07 09:03:19.448: DEBUG/L4J(363): 11074 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](ssl...) processing the NEED_UNWRAP state
07-07 09:03:19.638: DEBUG/L4J(363): 11274 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](ssl...) processing the NEED_WRAP state
07-07 09:03:19.668: DEBUG/L4J(363): 11305 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](ssl...): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=6 cap=9:
14 03 01 00 01 01]
07-07 09:03:19.678: DEBUG/L4J(363): 11308 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](ssl...) processing the NEED_WRAP state
07-07 09:03:19.688: DEBUG/L4J(363): 11324 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](ssl...): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=45 cap=72:
16 03 01 00 28 5A 40 52 41 F6 D2 BF B5 82 24 01...]
07-07 09:03:19.688: DEBUG/L4J(363): 11326 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](ssl...) processing the FINISHED state
07-07 09:03:19.700: DEBUG/L4J(363): 11332 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](SSL) is now secured
07-07 09:03:19.700: DEBUG/L4J(363): 11335 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](SSL) processing the FINISHED state
07-07 09:03:19.708: DEBUG/L4J(363): 11338 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](SSL) is now secured
07-07 09:03:19.708: DEBUG/L4J(363): 11342 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](SSL): Processing the SSL Data 
07-07 09:03:19.718: DEBUG/L4J(363): 11351 [NioProcessor-2] DEBUG org.apache.mina.filter.codec.ProtocolCodecFilter
 - Processing a MESSAGE_RECEIVED for session 1
07-07 09:03:19.718: DEBUG/L4J(363): 11354 [NioProcessor-2] DEBUG org.apache.vysper.xmpp.protocol.SessionStateHolder
 - session state changed to = ENCRYPTED
07-07 09:03:19.858: DEBUG/L4J(363): 11492 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](SSL): Message received : HeapBuffer[pos=0 lim=266 cap=512: 17 03 01 00
18 58 65 14 F5 51 86 B3 91 CD 4D C2...]
07-07 09:03:19.878: DEBUG/L4J(363): 11514 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](SSL) Processing the received message
07-07 09:03:19.908: DEBUG/L4J(363): 11544 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](SSL): Processing the SSL Data 
07-07 09:03:19.908: DEBUG/L4J(363): 11546 [NioProcessor-2] DEBUG org.apache.mina.filter.codec.ProtocolCodecFilter
 - Processing a MESSAGE_RECEIVED for session 1
07-07 09:03:19.967: DEBUG/L4J(363): 11601 [NioProcessor-2] DEBUG org.apache.vysper.xml.decoder.XMPPContentHandler
 - Decoder writing stanza: <stream:stream xmlns:stream="http://etherx.jabber.org/streams"
to="hovi.mk.zcu.cz" xml:lang="en" version="1.0"></stream:stream>
07-07 09:03:19.967: DEBUG/L4J(363): 11605 [NioProcessor-2] DEBUG stanza.client  - < <stream:stream
xmlns:stream="http://etherx.jabber.org/streams" to="hovi.mk.zcu.cz" xml:lang="en" version="1.0">
07-07 09:03:20.008: DEBUG/L4J(363): 11646 [pool-3-thread-3] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](SSL): Writing Message : WriteRequest: HeapBuffer[pos=0 lim=374 cap=512:
3C 3F 78 6D 6C 20 76 65 72 73 69 6F 6E 3D 22 31...]
07-07 09:03:20.068: DEBUG/L4J(363): 11707 [pool-3-thread-3] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](SSL): Writing Message : MessageWriteRequest, parent : WR WrapperWriteRequest:
[ prolog=true, open=true, close=false, content=true, stanza=[stream.features.mechanisms[PLAIN]]
07-07 09:03:20.088: DEBUG/L4J(363): 11726 [NioProcessor-2] DEBUG stanza.server  - > <stream:stream
xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" from="hovi.mk.zcu.cz"
version="1.0" id="e5a7b21bfa76489da1cdaea46d9ba96e"><stream:features xmlns:stream="http://etherx.jabber.org/streams"><mechanisms
xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms></stream:features>
07-07 09:03:20.207: DEBUG/L4J(363): 11841 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](SSL): Message received : HeapBuffer[pos=0 lim=154 cap=512: 17 03 01 00
18 DC FC 3B 15 7C 4D 8E 23 F8 DE 75...]
07-07 09:03:20.228: DEBUG/L4J(363): 11861 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler
 - Session Server[1](SSL) Processing the received message
07-07 09:03:20.258: DEBUG/L4J(363): 11892 [NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter
 - Session Server[1](SSL): Processing the SSL Data 
07-07 09:03:20.258: DEBUG/L4J(363): 11894 [NioProcessor-2] DEBUG org.apache.mina.filter.codec.ProtocolCodecFilter
 - Processing a MESSAGE_RECEIVED for session 1
07-07 09:03:20.298: DEBUG/L4J(363): 11931 [NioProcessor-2] DEBUG org.apache.vysper.xml.decoder.XMPPContentHandler
 - Decoder writing stanza: <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">AGhvdmkAcGFzc3dvcmQx</auth>
07-07 09:03:20.298: DEBUG/L4J(363): 11934 [NioProcessor-2] DEBUG stanza.client  - < <auth
xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">AGhvdmkAcGFzc3dvcmQx</auth>
07-07 09:03:21.458: DEBUG/L4J(363): 13093 [NioProcessor-2] DEBUG stanza.server  - > <proceed
xmlns="urn:ietf:params:xml:ns:xmpp-tls"></proceed>

> Crash on Android
> ----------------
>
>                 Key: DIRMINA-842
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-842
>             Project: MINA
>          Issue Type: Bug
>         Environment: android 2.2 (emulator)
>            Reporter: Kaja Hovi
>            Assignee: Niklas Gustavsson
>              Labels: android, ssl
>
> I tried to run VYSPER on android, with just one fix - getting "bks" keystore instead
of "jks" (or just KeyStore ks = KeyStore.getInstance(KeyStore.getDefaultType()); to make it
work on both platforms) , I used portecle to convert VYSPER default jks certificate into bks
format.
> When I run server on android and try to autenticate, I get following exception:
> 06-30 21:36:40.109: ERROR/L4J(342): 1178740 [NioProcessor-2] ERROR org.apache.mina.filter.ssl.SslHandler
 - Invalid Handshaking StateNOT_HANDSHAKING while processing the Handshake for session 3
> 06-30 21:36:40.109: WARN/L4J(342): 1178743 [NioProcessor-2] WARN org.apache.vysper.mina.XmppIoHandlerAdapter
 - error caught on transportation layer: {}
> 06-30 21:36:40.116: WARN/System.err(342): java.lang.IllegalStateException: Invalid Handshaking
StateNOT_HANDSHAKING while processing the Handshake for session 3
> 06-30 21:36:40.116: WARN/System.err(342):     at org.apache.mina.filter.ssl.SslHandler.handshake(SslHandler.java:593)
> 06-30 21:36:40.126: WARN/System.err(342):     at org.apache.mina.filter.ssl.SslHandler.writeNetBuffer(SslHandler.java:632)
> 06-30 21:36:40.137: WARN/System.err(342):     at org.apache.mina.filter.ssl.SslHandler.handshake(SslHandler.java:586)
> 06-30 21:36:40.137: WARN/System.err(342):     at org.apache.mina.filter.ssl.SslHandler.messageReceived(SslHandler.java:349)
> 06-30 21:36:40.137: WARN/System.err(342):     at org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:476)
> 06-30 21:36:40.137: WARN/System.err(342):     at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
> 06-30 21:36:40.155: WARN/System.err(342):     at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
> 06-30 21:36:40.155: WARN/System.err(342):     at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
> 06-30 21:36:40.155: WARN/System.err(342):     at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119)
> 06-30 21:36:40.166: WARN/System.err(342):     at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
> 06-30 21:36:40.166: WARN/System.err(342):     at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426)
> 06-30 21:36:40.166: WARN/System.err(342):     at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:693)
> 06-30 21:36:40.176: WARN/System.err(342):     at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:646)
> 06-30 21:36:40.193: WARN/System.err(342):     at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:635)
> 06-30 21:36:40.196: WARN/System.err(342):     at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$400(AbstractPollingIoProcessor.java:67)
> 06-30 21:36:40.196: WARN/System.err(342):     at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1079)
> 06-30 21:36:40.196: WARN/System.err(342):     at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
> 06-30 21:36:40.206: WARN/System.err(342):     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1068)
> 06-30 21:36:40.215: WARN/System.err(342):     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:561)
> 06-30 21:36:40.215: WARN/System.err(342):     at java.lang.Thread.run(Thread.java:1096)
> Any ideas what might cause this and how to fix it?
> Same project works fine in JRE (with both bks and jks).
> I found similar issue here (mina+android):
> http://androiddiscuss.com/1-android-discuss/1022.html
> I hope I am posting in correct place, since it is also about project VYSPER and it seems
possibly like android sdk bug, sorry if not.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

Mime
View raw message