在登录MM短彩信服务器时,返回鉴权失败的异常过程分析。
一次正常的XMPP Login流程分析:
10-30 18:37:10.821 20962 20989 I libjingle: [405dfb60] CMyLogin::login begin
10-30 18:37:10.821 20962 20989 I libjingle: [405dfb60] CMyLogin::login end
10-30 18:37:10.821 20962 22807 I libjingle: [518d3b10] PreRun tid:1368210192
10-30 18:37:10.821 20962 22807 I libjingle: [518d3b10] MSG_LOGIN
10-30 18:37:10.821 20962 22807 I libjingle: [518d3b10] PhysicalSocket::Create
10-30 18:37:10.821 20962 22807 I libjingle: [518d3b10] void CMyXmppPump::OnStateChange(buzz::XmppEngine::State):
10-30 18:37:10.821 20962 22807 W libjingle: [518d3b10] Notify State Change 1
10-30 18:37:10.821 20962 22807 I libjingle: [518d3b10] PhysicalSocket::Connect
10-30 18:37:10.821 20962 22807 I libjingle: [518d3b10] SOCK[122] Connect(10.42.205.178:5222) Ret: -1 Error: 115
10-30 18:37:10.821 20962 22807 E libjingle: [518d3b10] cricket_socket_ Connect Error Socket Blocking : [0x00000073] Operation now in progress
10-30 18:37:10.831 20962 22807 I libjingle: [518d3b10] OpenSSLAdapter::OnConnectEvent
10-30 18:37:10.831 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - No error
10-30 18:37:10.831 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_STREAMSTART_SENT
10-30 18:37:10.831 20962 22807 I libjingle: [518d3b10] SEND >>>>>>>>>>>>>>>>>>>>>>>>> : Mon Oct 30 18:37:10 2017
10-30 18:37:10.831 20962 22807 I libjingle: [518d3b10] <stream:stream to="mds.zte.com" xml:lang="*" version="1.0" xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client">
10-30 18:37:10.831 20962 22807 I libjingle: [518d3b10] SOCK[122] Send(131) Ret: 131 Error: 115
10-30 18:37:10.831 20962 22807 I libjingle: [518d3b10] void CMyXmppPump::OnStateChange(buzz::XmppEngine::State):
10-30 18:37:10.831 20962 22807 W libjingle: [518d3b10] Notify State Change 2
10-30 18:37:10.831 20962 20962 D baidu_location_service: baidu location service start1 ...20962
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] RECV <<<<<<<<<<<<<<<<<<<<<<<<< : Mon Oct 30 18:37:10 2017
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <?xml version='1.0' encoding='UTF-8'?>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="mds.zte.com" id="26qsdm09uo" xml:lang="und" version="1.0">
10-30 18:37:10.841 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_STREAMSTART_SENT
10-30 18:37:10.841 20962 22807 E libjingle: [518d3b10] xmpp socket read error bytes -1 socket blocking : [0x0000000b] Try again
10-30 18:37:10.841 20962 22807 E libjingle: [518d3b10] Xmpp Client Socket Read Bytes0
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] RECV <<<<<<<<<<<<<<<<<<<<<<<<< : Mon Oct 30 18:37:10 2017
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <stream:features>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl">
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <mechanism>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] PLAIN
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] </mechanism>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <mechanism>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] SCRAM-SHA-1
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] </mechanism>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <mechanism>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] CRAM-MD5
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] </mechanism>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <mechanism>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] DIGEST-MD5
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] </mechanism>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <mechanism>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] JIVE-SHAREDSECRET
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] </mechanism>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] </mechanisms>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <compression xmlns="http://jabber.org/features/compress">
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <method>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] zlib
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] </method>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] </compression>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <register xmlns="http://jabber.org/features/iq-register"/>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] </stream:features>
10-30 18:37:10.841 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_STARTED_XMPP
10-30 18:37:10.841 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_AUTH_INIT
10-30 18:37:10.841 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_SASL_RUNNING
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] SEND >>>>>>>>>>>>>>>>>>>>>>>>> : Mon Oct 30 18:37:10 2017
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10]
10-30 18:37:10.841 20962 22807 I libjingle:
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] ## TEXT REMOVED ##
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] </auth>
10-30 18:37:10.841 20962 22807 I libjingle: [518d3b10] SOCK[122] Send(132) Ret: 132 Error: 11
10-30 18:37:10.841 20962 22807 E libjingle: [518d3b10] xmpp socket read error bytes -1 socket blocking : [0x0000000b] Try again
10-30 18:37:10.841 20962 22807 E libjingle: [518d3b10] Xmpp Client Socket Read Bytes0
10-30 18:37:10.851 20962 22807 I libjingle: [518d3b10] RECV <<<<<<<<<<<<<<<<<<<<<<<<< : Mon Oct 30 18:37:10 2017
10-30 18:37:10.851 20962 22807 I libjingle: [518d3b10] <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/>
10-30 18:37:10.851 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_SASL_RUNNING
10-30 18:37:10.851 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - No error
10-30 18:37:10.851 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_STREAMSTART_SENT
10-30 18:37:10.851 20962 22807 I libjingle: [518d3b10] SEND >>>>>>>>>>>>>>>>>>>>>>>>> : Mon Oct 30 18:37:10 2017
10-30 18:37:10.851 20962 22807 I libjingle: [518d3b10] <stream:stream to="mds.zte.com" xml:lang="*" version="1.0" xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client">
10-30 18:37:10.851 20962 22807 I libjingle: [518d3b10] SOCK[122] Send(131) Ret: 131 Error: 11
10-30 18:37:10.851 20962 22807 E libjingle: [518d3b10] xmpp socket read error bytes -1 socket blocking : [0x0000000b] Try again
10-30 18:37:10.851 20962 22807 E libjingle: [518d3b10] Xmpp Client Socket Read Bytes0
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] RECV <<<<<<<<<<<<<<<<<<<<<<<<< : Mon Oct 30 18:37:10 2017
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <?xml version='1.0' encoding='UTF-8'?>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="mds.zte.com" id="26qsdm09uo" xml:lang="und" version="1.0">
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <stream:features>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <compression xmlns="http://jabber.org/features/compress">
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <method>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] zlib
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] </method>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] </compression>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <session xmlns="urn:ietf:params:xml:ns:xmpp-session">
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <optional/>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] </session>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <sm xmlns='urn:xmpp:sm:2'/>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <sm xmlns='urn:xmpp:sm:3'/>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] </stream:features>
10-30 18:37:10.861 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_STREAMSTART_SENT
10-30 18:37:10.861 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_STARTED_XMPP
10-30 18:37:10.861 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_BIND_INIT
10-30 18:37:10.861 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_BIND_REQUESTED
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] SEND >>>>>>>>>>>>>>>>>>>>>>>>> : Mon Oct 30 18:37:10 2017
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10]
10-30 18:37:10.861 20962 22807 I libjingle:
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <iq type="set" id="0">
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] <resource>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] MM_Beta
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] </resource>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] </bind>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] </iq>
10-30 18:37:10.861 20962 22807 I libjingle: [518d3b10] SOCK[122] Send(109) Ret: 109 Error: 11
10-30 18:37:10.861 20962 22807 E libjingle: [518d3b10] xmpp socket read error bytes -1 socket blocking : [0x0000000b] Try again
10-30 18:37:10.861 20962 22807 E libjingle: [518d3b10] Xmpp Client Socket Read Bytes0
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] RECV <<<<<<<<<<<<<<<<<<<<<<<<< : Mon Oct 30 18:37:10 2017
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] <iq type="result" id="0" to="mds.zte.com/26qsdm09uo">
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] <jid>
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] 19608080004@mds.zte.com/MM_Beta
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] </jid>
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] </bind>
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] </iq>
10-30 18:37:10.891 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_BIND_REQUESTED
10-30 18:37:10.891 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_SESSION_REQUESTED
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] SEND >>>>>>>>>>>>>>>>>>>>>>>>> : Mon Oct 30 18:37:10 2017
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] <iq type="set" id="1">
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] <session xmlns="urn:ietf:params:xml:ns:xmpp-session"/>
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] </iq>
10-30 18:37:10.891 20962 22807 I libjingle: [518d3b10] SOCK[122] Send(81) Ret: 81 Error: 11
10-30 18:37:10.891 20962 22807 E libjingle: [518d3b10] xmpp socket read error bytes -1 socket blocking : [0x0000000b] Try again
10-30 18:37:10.891 20962 22807 E libjingle: [518d3b10] Xmpp Client Socket Read Bytes0
10-30 18:37:11.071 20962 22807 I libjingle: [518d3b10] RECV <<<<<<<<<<<<<<<<<<<<<<<<< : Mon Oct 30 18:37:11 2017
10-30 18:37:11.071 20962 22807 I libjingle: [518d3b10] <iq type="result" id="1" to="19608080004@mds.zte.com/MM_Beta"/>
10-30 18:37:11.071 20962 22807 V libjingle: [518d3b10] XmppLoginTask::Advance - LOGINSTATE_SESSION_REQUESTED
10-30 18:37:11.071 20962 22807 I libjingle: [518d3b10] void CMyXmppPump::OnStateChange(buzz::XmppEngine::State):
10-30 18:37:11.071 20962 22807 W libjingle: [518d3b10] Notify State Change 3
10-30 18:37:11.071 20962 22807 I libjingle: jingle_callback_event_func 1
简化一下就是:
Auth成功之后,发送jid到服务端进行认证。认证成功之后可以发送短彩信。
异常的流程分析
异常的日志分析:
之前的内容都一样
......
10-30 09:58:08.669 1404 1629 I libjingle: [518eeff8] <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">
10-30 09:58:08.669 1404 1629 I libjingle: [518eeff8] ## TEXT REMOVED ##
10-30 09:58:08.669 1404 1629 I libjingle: [518eeff8] </auth>
10-30 09:58:08.679 1404 1629 I libjingle: [518eeff8] SOCK[126] Send(100) Ret: 100 Error: 11
10-30 09:58:08.679 1404 1629 E libjingle: [518eeff8] xmpp socket read error bytes -1 socket blocking : [0x0000000b] Try again
10-30 09:58:08.679 1404 1629 E libjingle: [518eeff8] Xmpp Client Socket Read Bytes0
10-30 09:58:08.709 1404 1629 I libjingle: [518eeff8] RECV <<<<<<<<<<<<<<<<<<<<<<<<< : Mon Oct 30 09:58:08 2017
10-30 09:58:08.709 1404 1629 I libjingle: [518eeff8] <failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl">
10-30 09:58:08.709 1404 1629 I libjingle: [518eeff8] <not-authorized/>
10-30 09:58:08.709 1404 1629 I libjingle: [518eeff8] </failure>
从以上内容可以看出,在进行Auth认证时,返回了failure;通过抓包分析比较
Success
Failure
以上比较可知,在Auth认证时,CDATA: 携带的账户/密码信息不一致导致失败
问题解决
经过上面分析,发现Auth认证失败,是用户名、密码不匹配导致。
通过排查发现,是密码在用MD5算法加密时,经过了2层加密,终端和服务器的不一致导致匹配失败。修改终端的MD5加密算法即可认证Auth成功。