Project

General

Profile

Tigase Log

Behnam Hatami
Added over 3 years ago

I have some question about tigase log.

in my log I encounter a lot of warnings and I want to know how to avoid them.

STARTTLS:

2015-10-03 14:57:42.956 [in_123-c2s]       ClientConnectionManager.processCommand()  WARNING: Cant find sevice for STARTTLS command: {0}

Inifinite loop:

2015-10-03 15:01:41.707 [in_100-c2s]       TLSIO.writeBuff()                  WARNING:  Infinite loop detected in writeBuff(buff) TLS code, tlsWrapper.getStatus(): NEED_READ

I use Oracle Java 8 and I think due to previous questions, this should not happen.

Received roster request but user session is not authorized yet:

2015-10-03 14:57:50.828 [jabber:iq:roster Queue Worker 31]  JabberIqRoster.process()  WARNING: Received roster request but user session is not authorized yet: from=c2s@xxx6/00.000.000.000_5222_93.110.120.190_47262, to=sess-man@xxx6, DATA=<iq from="0aw1wnfsflk3@yyy.xxx.com/21ee67e17c902639" xmlns="jabber:client" type="get" id="F1TeF-129"><query ver="" xmlns="jabber:iq:roster"/></iq>, SIZE=151, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=get

As permission of packet says, I think user is authorized and there should not be any problem.

Packet with TO attribute set to NULL:

2015-10-03 15:13:52.543 [in_154-message-router]  MessageRouter.processPacket()  WARNING: Packet with TO attribute set to NULL: from=c2s@xxxxx6/00.000.000.000_5222_5.190.64.209_58504, to=null, DATA=<stream:features type="error"><sm xmlns="urn:xmpp:sm:3"/><auth xmlns="http://jabber.org/features/iq-auth"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms><csi xmlns="urn:xmpp:csi:0"/><ver xmlns="urn:xmpp:features:rosterver"/><register xmlns="http://yyyyyyy.xxxxx/features/iq-register"/><error type="wait" code="404"><recipient-unavailable xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></stream:features>, SIZE=460, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=error
2015-10-03 17:08:49.904 [in_1-message-router]  MessageRouter.processPacket()  WARNING:  Packet with TO attribute set to NULL: from=null, to=null, DATA=<proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls" type="error"><error type="wait" code="404"><recipient-unavailable xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></proceed>, SIZE=178, XMLNS=urn:ietf:params:xml:ns:xmpp-tls, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=error

NullPointer exception in Presence:

2015-10-03 15:17:48.584 [presence Queue Worker 13]  WorkerThread.run()        SEVERE:   tigase.server.xmppsession.SessionManager$ProcessorWorkerThread,(presence Queue Worker 13) Exception during packet processing: from=sess-man@xxxxx6, to=sess-man@xxxxx6, DATA=<presence from="naux3az6woe7@yyyyyyy.xxxxx" to="g48vcphzjqww@yyyyyyy.xxxxx" xmlns="jabber:client" type="unsubscribe" id="a27S39g0NMf670m0xAiDxiJO1LZ5P9"/>, SIZE=160, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=unsubscribe
java.lang.NullPointerException
    at tigase.xmpp.impl.Presence.sendPresence(Presence.java:721)
    at tigase.xmpp.impl.Presence.broadcastProbe(Presence.java:253)
    at tigase.xmpp.impl.Presence.processInUnsubscribe(Presence.java:1541)
    at tigase.xmpp.impl.Presence.process(Presence.java:564)
    at tigase.server.xmppsession.SessionManager$ProcessorWorkerThread.process(SessionManager.java:2522)
    at tigase.util.WorkerThread.run(WorkerThread.java:128)

ConcurrentModificationException:

2015-10-03 15:43:42.439 [amp Queue Worker 20]  WorkerThread.run()             SEVERE:   tigase.server.xmppsession.SessionManager$ProcessorWorkerThread,(amp Queue Worker 20) Exception during packet processing: from=c2s@xxxxx6/00.000.000.000_5222_93.119.49.248_10395, to=sess-man@xxxxx6, DATA=<presence from="apvuiwp010h7@yyyyyyy.xxxxx/38e2435ecf085727" xmlns="jabber:client" id="g4iAI-5"><c hash="sha-1" node="http://xxxxx/" ver="none" xmlns="http://jabber.org/protocol/caps"/></presence>, SIZE=202, XMLNS=jabber:client, PRIORITY=PRESENCE, PERMISSION=AUTH, TYPE=null
java.util.ConcurrentModificationException
    at java.util.ArrayDeque$DeqIterator.next(ArrayDeque.java:643)
    at tigase.xmpp.impl.BlockingCommand.filter(BlockingCommand.java:156)
    at tigase.server.xmppsession.SessionManager.addOutPackets(SessionManager.java:977)
    at tigase.server.xmppsession.SessionManager$ProcessorWorkerThread.process(SessionManager.java:2527)
    at tigase.util.WorkerThread.run(WorkerThread.java:128)

NotAuthorizedException

tlsWrapper.2015-10-09 00:39:40.135 [jabber:iq:last Queue Worker 30]  SessionManager$ProcessorWorkerThread.process()  WARNING: Exception during packet processing: from=c2s@yyyyy6/00.000.000.000_5222_31.7.109.227_52573, to=sess-man@yyyyy6, DATA=<presence id="K1wb9-16" xmlns="jabber:client" from="rvs2bakndr0q@xxxxxxx.yyyyy/1ea3b6e1f606e7c2" type="unavailable"/>, SIZE=120, XMLNS=jabber:client, PRIORITY=PRESENCE, PERMISSION=AUTH, TYPE=unavailable
tigase.xmpp.NotAuthorizedException: Session has not been yet authorised.
        at tigase.xmpp.XMPPResourceConnection.getBareJID(XMPPResourceConnection.java:516)
        at tigase.xmpp.impl.LastActivity.process(LastActivity.java:168)
        at tigase.server.xmppsession.SessionManager$ProcessorWorkerThread.process(SessionManager.java:2522)
        at tigase.util.WorkerThread.run(WorkerThread.java:128)

INFO: Message without TO attribute set, don't know what to do wih this

I send unavailable to server, then shut-down the connection from client. in server side I got this info:

2015-10-06 12:43:06.246 [in_263-sess-man]  SessionManager.getXMPPResourceConnection()  INFO: Message without TO attribute set, don't know what to do wih this: from=c2s@xxxxx6/00.000.000.000_5222_10.142.247.131_55678, to=sess-man@xxxxx6, DATA=<presence xmlns="jabber:client" type="unavailable" id="YI017-3"/>, SIZE=65, XMLNS=jabber:client, PRIORITY=PRESENCE, PERMISSION=NONE, TYPE=unavailable

Is there any thing that I should worry about?

Impossible happened, please report to developer packet:

I write a push component. it provides a list of available backends to clients that it supports by overriding getDiscoItems. But Server get a lot of impossible for this discovery packet. Is there any reason that I encounter this problem almost for this packet?

2015-10-06 13:10:53.703 [in_167-sess-man]  SessionManager.processPacket()     INFO:     Impossible happened, please report to developer packet: from=c2s@xxxxx6/00.000.000.000_5222_2.181.117.222_10399, to=sess-man@xxxxx6, DATA=<iq type="error" from="tfl7cuf25vsk@yyyyyyy.xxxxx/62c9c3cffd7464f9" to="yyyyyyy.xxxxx" id="d8pZ6-10" xmlns="jabber:client"><query node="http://xxxxx/extensions/presence#push" xmlns="http://jabber.org/protocol/disco#items"><item node="http://xxxxx/extensions/presence#push" name="Google Cloud Messaging push notifications" jid="push@yyyyyyy.xxxxx"/></query><error type="wait" code="404"><recipient-unavailable xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>, SIZE=482, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=error, connection: XMPPResourceConnection=[user_jid=sess-man@xxxxx6, packets=250563, connectioId=null, domain=xxxxx6, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false].

there are some other cases here:

2015-10-06 13:10:52.190 [in_806-sess-man]  SessionManager.processPacket()     INFO:     Impossible happened, please report to developer packet: from=c2s@xxxxx6/00.000.000.000_5222_5.120.139.209_34694, to=sess-man@xxxxx6, DATA=<iq type="error" from="9x5b054swa4i@yyyyyyy.xxxxx/d07e18dda32e0d1b" to="yyyyyyy.xxxxx" id="s7QVi-29" xmlns="jabber:client"><error type="wait" code="404"><recipient-unavailable xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>, SIZE=240, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=error, connection: XMPPResourceConnection=[user_jid=sess-man@xxxxx6, packets
=250558, connectioId=null, domain=xxxxx6, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false].

Replies (6)

Added by Behnam Hatami over 3 years ago

Is there any one that can help me to figure out these problems?

Added by Daniel Wisnewski IoT 1 Cloud over 3 years ago

Do all of these errors show when you first start? any specific activity that causes them?

Which version of Tigase are you running and what environment?

Added by Behnam Hatami over 3 years ago

I use latest version of tigase 7.1-snapshot.

STARTTLS and Infinite loop starts after tigase server start up. [I think these exception occur when users try to reconnect to server after server restart]

I don't think there is any specific activity that cause these problems.

other exceptions occur after some time and repeats many times.

Added by Wojciech Kapcia TigaseTeam over 3 years ago

Behnam Hatami wrote:

STARTTLS:

Most likely client disconnected during establishing TLS.

Inifinite loop:

This may be a bit misleading and may happen while sending really big chunks of data over socket connection.

Received roster request but user session is not authorized yet:

As permission of packet says, I think user is authorized and there should not be any problem.

It may happen, that the client disconnected during processing of the packet hence the packet was marked as authorised but later on user session was checked again and it was after the logout.

Packet with TO attribute set to NULL:

Those are again error results due to abrupt disconnection.

NullPointer exception in Presence:

Fixed;

ConcurrentModificationException:

Do you have any custom filtering plugins?

NotAuthorizedException

Again - session was probably closed before packet was processed.

INFO: Message without TO attribute set, don't know what to do wih this

I send unavailable to server, then shut-down the connection from client. in server side I got this info:

[...]

Is there any thing that I should worry about?

Same as above - connection was closed before packet was processed.

Impossible happened, please report to developer packet:

I write a push component. it provides a list of available backends to clients that it supports by overriding getDiscoItems. But Server get a lot of impossible for this discovery packet. Is there any reason that I encounter this problem almost for this packet?

[...]

there are some other cases here:

It would be more helpful if, instead of single line you could also provide a stanza that triggered the issue...

Added by Behnam Hatami over 3 years ago

Hi thanks for your reply, very useful for me.

I get these errors from monitor command getError action, and it gives me just the problem not the cause.

for ConcurrentModificationException: I figure out the problem and I have a patch for it.

I attached it and I want my modification to merge with master.

Added by Wojciech Kapcia TigaseTeam about 3 years ago

Thank you for the patch, I've included it in the release branch which will be merged into master promptly.

PS. Instead of sending complete java files you can submit diff patches which should be easier to apply.

    (1-6/6)