Projects tigase _server server-core Issues #1257
MessageRouter.processPacketMR() : I expect command (Iq) packet here (#1257)
wojciech.kapcia@tigase.net opened 3 years ago
[2021-06-18 05:19:28:500] [WARNING ] [   in_5-message-router ] MessageRouter.processPacketMR()  : I expect command (Iq) packet here, instead I got: from=s2s@ip-172-31-0-99.us-west-2.compute.internal, to=null, DATA=<presence xml:lang="en" to="message-router@sure.im/hit-man" from="hit-man@xmpp.jp/converse.js-103059742" xmlns="jabber:client"><x xmlns="http://jabber.org/protocol/muc"><history/></x><x xmlns="vcard-temp:x:update"/></presence>, SIZE=226, XMLNS=jabber:client, PRIORITY=PRESENCE, PERMISSION=REMOTE, TYPE=null, STABLE_ID=null
wojciech.kapcia@tigase.net commented 3 years ago
[2021-06-18 03:11:11:214] [FINEST  ] [   in_5-message-router ] XMPPDomBuilderHandler.endElement(): Adding new request: <presence xml:lang="en" to="message-router@sure.im/hit-man" from="hit-man@xmpp.jp/converse.js-103059742"><x xmlns="http://jabber.org/protocol/muc"><history/></x><x xmlns="vcard-temp:x:update"/></presence>
[2021-06-18 03:11:11:214] [FINEST  ] [   in_5-message-router ] XMPPIOService.moveParsedPacketsToReceived(): Read packet: <presence xml:lang="en" to="message-router@sure.im/hit-man" from="hit-man@xmpp.jp/converse.js-103059742" xmlns="jabber:client"><x xmlns="http://jabber.org/protocol/muc"><history/></x><x xmlns="vcard-temp:x:update"/></presence> [CID: sure.im@xmpp.jp, IN: 1, OUT: 1, authenticated: true, remote-session-id: 96e3123d-d069-4be6-bc7c-fb65b6bca5cc, jid: null, S2SIOService, UniqueId: 172.18.0.2_5269_172.31.4.176_49502, type: <- incoming (accept), TLS: SocketIO, ID: sure.im@xmpp.jp/a0b85b6b-bb3d-44b5-8bbb-1dba49e363e2, connected Socket[addr=/172.31.4.176,port=49502,localport=5269]]
[2021-06-18 03:11:11:215] [FINEST  ] [   in_5-message-router ] S2SConnectionManager.processSocketData(): Processing socket data: from=s2s@ip-172-31-0-99.us-west-2.compute.internal, to=null, DATA=<presence xml:lang="en" to="message-router@sure.im/hit-man" from="hit-man@xmpp.jp/converse.js-103059742" xmlns="jabber:client"><x xmlns="http://jabber.org/protocol/muc"><history/></x><x xmlns="vcard-temp:x:update"/></presence>, SIZE=226, XMLNS=jabber:client, PRIORITY=PRESENCE, PERMISSION=REMOTE, TYPE=null, STABLE_ID=null [CID: sure.im@xmpp.jp, IN: 1, OUT: 1, authenticated: true, remote-session-id: 96e3123d-d069-4be6-bc7c-fb65b6bca5cc, jid: null, S2SIOService, UniqueId: 172.18.0.2_5269_172.31.4.176_49502, type: <- incoming (accept), TLS: SocketIO, ID: sure.im@xmpp.jp/a0b85b6b-bb3d-44b5-8bbb-1dba49e363e2, connected Socket[addr=/172.31.4.176,port=49502,localport=5269]]
[2021-06-18 03:11:11:215] [FINE    ] [   in_5-message-router ] AuthenticatorSelectorManager.isAllowed(): Connection already authenticated, skipping processor: tigase.server.xmppserver.proc.SaslExternal@7746330a, methodsAvailable: [tigase.server.xmppserver.proc.SaslExternal@7746330a, tigase.server.xmppserver.proc.Dialback@252459b2], checking packet: from=s2s@ip-172-31-0-99.us-west-2.compute.internal, to=null, DATA=<presence xml:lang="en" to="message-router@sure.im/hit-man" from="hit-man@xmpp.jp/converse.js-103059742" xmlns="jabber:client"><x xmlns="http://jabber.org/protocol/muc"><history/></x><x xmlns="vcard-temp:x:update"/></presence>, SIZE=226, XMLNS=jabber:client, PRIORITY=PRESENCE, PERMISSION=REMOTE, TYPE=null, STABLE_ID=null [CID: sure.im@xmpp.jp, IN: 1, OUT: 1, authenticated: true, remote-session-id: 96e3123d-d069-4be6-bc7c-fb65b6bca5cc, jid: null, S2SIOService, UniqueId: 172.18.0.2_5269_172.31.4.176_49502, type: <- incoming (accept), TLS: SocketIO, ID: sure.im@xmpp.jp/a0b85b6b-bb3d-44b5-8bbb-1dba49e363e2, connected Socket[addr=/172.31.4.176,port=49502,localport=5269]]
[2021-06-18 03:11:11:215] [FINE    ] [   in_5-message-router ] AuthenticatorSelectorManager.isAllowed(): Connection already authenticated, skipping processor: tigase.server.xmppserver.proc.Dialback@252459b2, methodsAvailable: [tigase.server.xmppserver.proc.SaslExternal@7746330a, tigase.server.xmppserver.proc.Dialback@252459b2], checking packet: from=s2s@ip-172-31-0-99.us-west-2.compute.internal, to=null, DATA=<presence xml:lang="en" to="message-router@sure.im/hit-man" from="hit-man@xmpp.jp/converse.js-103059742" xmlns="jabber:client"><x xmlns="http://jabber.org/protocol/muc"><history/></x><x xmlns="vcard-temp:x:update"/></presence>, SIZE=226, XMLNS=jabber:client, PRIORITY=PRESENCE, PERMISSION=REMOTE, TYPE=null, STABLE_ID=null [CID: sure.im@xmpp.jp, IN: 1, OUT: 1, authenticated: true, remote-session-id: 96e3123d-d069-4be6-bc7c-fb65b6bca5cc, jid: null, S2SIOService, UniqueId: 172.18.0.2_5269_172.31.4.176_49502, type: <- incoming (accept), TLS: SocketIO, ID: sure.im@xmpp.jp/a0b85b6b-bb3d-44b5-8bbb-1dba49e363e2, connected Socket[addr=/172.31.4.176,port=49502,localport=5269]]
[2021-06-18 03:11:11:215] [FINEST  ] [   in_5-message-router ] S2SConnectionManager.processSocketData(): Adding packet out: from=s2s@ip-172-31-0-99.us-west-2.compute.internal, to=null, DATA=<presence xml:lang="en" to="message-router@sure.im/hit-man" from="hit-man@xmpp.jp/converse.js-103059742" xmlns="jabber:client"><x xmlns="http://jabber.org/protocol/muc"><history/></x><x xmlns="vcard-temp:x:update"/></presence>, SIZE=226, XMLNS=jabber:client, PRIORITY=PRESENCE, PERMISSION=REMOTE, TYPE=null, STABLE_ID=null [CID: sure.im@xmpp.jp, IN: 1, OUT: 1, authenticated: true, remote-session-id: 96e3123d-d069-4be6-bc7c-fb65b6bca5cc, jid: null, S2SIOService, UniqueId: 172.18.0.2_5269_172.31.4.176_49502, type: <- incoming (accept), TLS: SocketIO, ID: sure.im@xmpp.jp/a0b85b6b-bb3d-44b5-8bbb-1dba49e363e2, connected Socket[addr=/172.31.4.176,port=49502,localport=5269]]
[2021-06-18 03:11:11:215] [FINEST  ] [   in_5-message-router ] MessageRouter.processPacket()    : Processing packet: from=s2s@ip-172-31-0-99.us-west-2.compute.internal, to=null, DATA=<presence xml:lang="en" to="message-router@sure.im/hit-man" from="hit-man@xmpp.jp/converse.js-103059742" xmlns="jabber:client"><x xmlns="http://jabber.org/protocol/muc"><history/></x><x xmlns="vcard-temp:x:update"/></presence>, SIZE=226, XMLNS=jabber:client, PRIORITY=PRESENCE, PERMISSION=REMOTE, TYPE=null, STABLE_ID=null
[2021-06-18 03:11:11:215] [FINEST  ] [   in_5-message-router ] MessageRouter.getLocalComponent(): Called for : message-router@sure.im/hit-man
[2021-06-18 03:11:11:215] [FINEST  ] [   in_5-message-router ] MessageRouter.getLocalComponent(): No componentID matches (fast lookup against exact address): message-router@sure.im/hit-man, for map: [upload@ip-172-31-0-99.us-west-2.compute.internal, cl-comp@ip-172-31-0-99.us-west-2.compute.internal, ext-disco@ip-172-31-0-99.us-west-2.compute.internal, message-router@ip-172-31-0-99.us-west-2.compute.internal, muc@ip-172-31-0-99.us-west-2.compute.internal, mix@ip-172-31-0-99.us-west-2.compute.internal, message-archive@ip-172-31-0-99.us-west-2.compute.internal, cluster-contr@ip-172-31-0-99.us-west-2.compute.internal, ext@ip-172-31-0-99.us-west-2.compute.internal, http@ip-172-31-0-99.us-west-2.compute.internal, amp@ip-172-31-0-99.us-west-2.compute.internal, bosh@ip-172-31-0-99.us-west-2.compute.internal, c2s@ip-172-31-0-99.us-west-2.compute.internal, sess-man@ip-172-31-0-99.us-west-2.compute.internal, eventbus@ip-172-31-0-99.us-west-2.compute.internal, vhost-man@ip-172-31-0-99.us-west-2.compute.internal, pubsub@ip-172-31-0-99.us-west-2.compute.internal, monitor@ip-172-31-0-99.us-west-2.compute.internal, push@ip-172-31-0-99.us-west-2.compute.internal, stats@ip-172-31-0-99.us-west-2.compute.internal, ws2s@ip-172-31-0-99.us-west-2.compute.internal, s2s@ip-172-31-0-99.us-west-2.compute.internal]; trying VHost lookup
[2021-06-18 03:11:11:216] [FINEST  ] [   in_5-message-router ] MessageRouter.getLocalComponent(): Called for : message-router@sure.im/hit-man
[2021-06-18 03:11:11:216] [FINEST  ] [   in_5-message-router ] MessageRouter.getLocalComponent(): No componentID matches (fast lookup against exact address): message-router@sure.im/hit-man, for map: [upload@ip-172-31-0-99.us-west-2.compute.internal, cl-comp@ip-172-31-0-99.us-west-2.compute.internal, ext-disco@ip-172-31-0-99.us-west-2.compute.internal, message-router@ip-172-31-0-99.us-west-2.compute.internal, muc@ip-172-31-0-99.us-west-2.compute.internal, mix@ip-172-31-0-99.us-west-2.compute.internal, message-archive@ip-172-31-0-99.us-west-2.compute.internal, cluster-contr@ip-172-31-0-99.us-west-2.compute.internal, ext@ip-172-31-0-99.us-west-2.compute.internal, http@ip-172-31-0-99.us-west-2.compute.internal, amp@ip-172-31-0-99.us-west-2.compute.internal, bosh@ip-172-31-0-99.us-west-2.compute.internal, c2s@ip-172-31-0-99.us-west-2.compute.internal, sess-man@ip-172-31-0-99.us-west-2.compute.internal, eventbus@ip-172-31-0-99.us-west-2.compute.internal, vhost-man@ip-172-31-0-99.us-west-2.compute.internal, pubsub@ip-172-31-0-99.us-west-2.compute.internal, monitor@ip-172-31-0-99.us-west-2.compute.internal, push@ip-172-31-0-99.us-west-2.compute.internal, stats@ip-172-31-0-99.us-west-2.compute.internal, ws2s@ip-172-31-0-99.us-west-2.compute.internal, s2s@ip-172-31-0-99.us-west-2.compute.internal]; trying VHost lookup
[2021-06-18 03:11:11:216] [FINEST  ] [   in_5-message-router ] MessageRouter.processPacket()    : 1. Packet will be processed by: message-router@ip-172-31-0-99.us-west-2.compute.internal, from=s2s@ip-172-31-0-99.us-west-2.compute.internal, to=null, DATA=<presence xml:lang="en" to="message-router@sure.im/hit-man" from="hit-man@xmpp.jp/converse.js-103059742" xmlns="jabber:client"><x xmlns="http://jabber.org/protocol/muc"><history/></x><x xmlns="vcard-temp:x:update"/></presence>, SIZE=226, XMLNS=jabber:client, PRIORITY=PRESENCE, PERMISSION=REMOTE, TYPE=null, STABLE_ID=null
[2021-06-18 03:11:11:222] [WARNING ] [   in_5-message-router ] MessageRouter.processPacketMR()  : I expect command (Iq) packet here, instead I got: from=s2s@ip-172-31-0-99.us-west-2.compute.internal, to=null, DATA=<presence xml:lang="en" to="message-router@sure.im/hit-man" from="hit-man@xmpp.jp/converse.js-103059742" xmlns="jabber:client"><x xmlns="http://jabber.org/protocol/muc"><history/></x><x xmlns="vcard-temp:x:update"/></presence>, SIZE=226, XMLNS=jabber:client, PRIORITY=PRESENCE, PERMISSION=REMOTE, TYPE=null, STABLE_ID=null
wojciech.kapcia@tigase.net commented 3 years ago

Added error response for such packets and changed logging level as this is not really something that warrants WARNING.

issue 1 of 1
Type
Bug
Priority
Minor
Assignee
Version
tigase-server-8.2.0
Spent time
1h 15m
Issue Votes (0)
Watchers (0)
Reference
tigase/_server/server-core#1257
Please wait...
Page is in error, reload to recover