This is another attempt to share what I’ve researched in my personal time with other Engineers simply because  I have benefited  a lot  from reading  other people’s blogs also.  My  hope is that this post is useful to someone out there.

Not too long ago, I wrote a post about  the boot process of Cisco jabber for windows which can be found    here.  In continuation of this entry, I thought I’d add share some more  information on how to read the logs that are generated  when  two people who are  on  Cisco Jabbber clients start chatting or sharing screenshots with each other.

Knowing what to expect in these logs could prove very important if a client complains to you that when he sends chat message to someone the message is never delivered.  Anyway, before I start talking too much, lets begin.

Lets starting of by talking about the trace file  that should be  used when looking into the chat messages or picture exchange between tw0 people on jabber clients.   In this regard, the best trace to collect is the XCP Connnecton Manager traces.  It is also advisable to set the trace level to detailed before attempting to collect the trace file. So the question is,  ‘why the XCP Connection manager trace’ ? Well the XCP Connection Manager  helps jabber clients to connect to the IM and Presence Server. It is sort of like an intermediary.

Now that we have that under our belt, the nex thing to know is how to differnciate one chat message for another in a massive pile of traces.

There are several things unique to every chat conversation:

1)   The sender and the receiver’s jabber ID  (JID)

2)  Every message has a Unique ID which is used to identify a message as it is transported across multiple  IM and presence servers en-route to it’s destination or jabber user.

When reading jabber traces, the same rule that applies to phones and call-manager applies here too:  and that is, you will mostly only find the logs for a given jabber client on the server that it is registered to.  This is true for the XCP Connection Manager traces.  What I’m trying to say here is that sometimes you have to collect logs from multiple IM and presence servers but most of the interesting logs will piled up in one server.

Now that we understand that, let talk briefly about the message flow.

For every chat message/ conversation there are several  messages that are exchanged  in the following order.

1) One of the very first messages is the   “IN FROM CLIENT” message. This is the trace line that tells us that someone has sent a message via the XCP Connection Manager  to the IM and presence server using a jabber client.

2)   “OUT TO SERVER” message. This means that the message has now been transferred to the IM and Presence server’s internal processes so that  a destination for the message can be calculatated or derived. It is at this stage that components like the XCP Router kicks in.

3) ” IN FROM SERVER” message. This is the message that  instructs an IM and presence node to deliver a message to a particular XMPP client. i.e jabber.  Please note that if jabber clients are chatting with each other but they are not registered to the same IM and Presence node, you will never see an  “OUT TO SERVER” and an ” IN FROM SERVER” message together on any single node for one conversation going in one direction (i.e from sender to receiver).

4)   Then there is the  “OUT TO CLIENT ” message. This is one of the final messages you will see in the logs when a message is about to be  delivered to  a recipient jabber client.

Ok now that we’ve discussed this matter at length, let take a look at some logs.

In the logs below, user2@voiceinitiate.com sends a message to  User1@voiceinitiate.comand a message ID of 52a46470:00000990:0000010c‘ is assigned to the message

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

[IN FROM CLIENT state:6]: <message id=’uid:52a46470:00000990:0000010c‘ to=’user1@voiceinitiate.com’ type=’chat’><body>hello this is maxwell. i am having a cup of tea so feel free to play your xbox at work</body><thread>connect23313xmlns=’http://jabber.org/protocol/xhtml-im’&gt;hello this is maxwel. i am having a cup of tea so feel free to play your xbox at work

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

The Jabber session manager  (cm-1_jsm-1) that is running on server “subcup.voiceinitiate.com”,  informs us that this  message is being sent out to the server’s internal processes for analysis and message delivery

::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

cm-1_jsmcp-1.subcup-voiceinitiate-com [OUT TO SERVER(3)]: from=‘user2@voiceinitiate.com/jabber_22990‘ id=’uid:52a46470:00000990:0000010c‘ to=’user1@voiceinitiate

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

In the  output below, the  Jabber session manager  (cm-1_jsm-1) that is running on server “pubcup.voiceinitiate.com”,  informs us that it has received a request to deliver   message to user1@voiceinitiate.com to user2@voiceinitiate.com

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

cm-1_jsmcp-1.pubcup-voiceinitiate-com [IN FROM SERVER]: from=’user2@voiceinitiate.com/jabber_22990′ id=’uid:52a46470:00000990:0000010c’ to=’user1@voiceinitiate.com’ type=‘chat’ xml:lang=’en’><body>hello this is maxwell. i am having a cup of tea so feel free to play your xbox at work</body>connect23313xmlns=’http://jabber.org/protocol/xhtml-im’&gt;hello this is maxwel. i am having a cup of tea so feel free to play your xbox at work

 :::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

In the logs below, we see that the  message is delivered to the recipient jabber client.

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

cm-1_jsmcp-1_xmppd-1 [OUT TO CLIENT]: <message from=’user2@voiceinitiate.com/jabber_22990′ id=’uid:52a46470:00000990:0000010c’ to=’user1@voiceinitiate.com‘ type=‘chat‘ xml:lang=’en’>hello this is maxwell. i am having a cup of tea so feel free to play your xbox at workconnect23313xmlns=’http://jabber.org/protocol/xhtml-im’&gt;hello this is maxwel. i am having a cup of tea so feel free to play your xbox at work

:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

Ok so now that we know how text/ chat messages flow within the server(s), how about when we send a screen-shot to someone via jabber? Well  the snapshot below shows me sending a picture from one jabber client to another . I will not show you the full message follow because we already have a general idea of what to expect. However, what  I will show here is the actual traces that showed what was happening in the background as the picture  was being sent.

Let me first of show you the  actual screen-shot  that I took while the picture was being transferred between jabber clients. Pay special attention to the name of the file and see if you can see  that same file name in the the logs below.

jabber

cm-1_jsmcp-1_xmppd-1 [OUT TO CLIENT]: <iq from=’user1@voiceinitiate.com/wbxconnect’ id=’uid:52a45b16:00004d03:000001a7‘ to=‘user2@voiceinitiate.com/jabber_22990′ type=’set’ xml:lang=’en’>Successfully sent file ‘user1@voiceinitiate.com_20131208_150328.png(13613 bytes)’.</x></jingle></iq>

 :::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

The logs above withe XCP Connections Manager logs. Now the presence Engine logs are even more interesting. Check out the logs below that even tells you were the file was saved on the computer hard-drive.

 :::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

system.pe.jabber 1308670 INFO ClientEmComponent::onPacket() – PACKET RECEIVED::  <message from=’user1@voiceinitiate.com/wbxconnect’ to=’user2@voiceinitiate.com‘ type=’chat’ xml:lang=’en’> xmlns=’http://webex.com/connect/imcmd’/>Subject&lt;body xmlns=’http://www.w3.org/1999/xhtml’>&lt;img alt=’Screen capture‘ contenteditable=’false’ id=‘user1@voiceinitiate.com_20131208_150328.png’ name=‘connect_screen_capture‘ src=’file:///C:/Documents%20and%20Settings/user1/My%20Documents/MyJabberFiles/user1@voiceinitiate.com/user1@voiceinitiate.com_20131208_150328.png‘/></body></html></message>

Anyway, I hope that what has been shared here today will come in handy to someone down the line.

All the best

Maxwell