Sip Message Inspection in SailFin
Tuesday Sep 29, 2009
SipMessageInspection(SMI) feature is intended as a way of troubleshooting Sip traffic through SailFin. SMI in SailFin is implemented as logging of requests and responses in the server log. Together with the contextual log information in the server logs, Sip messages helps in tracing and debugging. SMI was first introduced in SailFin 1.0, but it had few limitations such as outgoing requests and responses are not accounted for.
SMI is enhanced in SailFin 2.0 to overcome the short comings in 1.0 and in addition, ability to add user defined message adapters is provided to customize the information logged as part of SMI.
SailFin's sip stack is based on layered architecture and by default SMI logs messages at network layer and application dispatcher/servlet dispatcher, reasoning behind these two are that they are important interception points both from the application and infrastructure developer point of views. Logging at network layer will take care of incoming and outgoing messages from the container and logging at servlet dispatcher takes care of incoming and outgoing messages from or to the applications, which includes the messages generated in the container and stayed back in the container, for example application composition. Users could configure the log message adapters at each layer.
SMI can be configured with the help of properties under sip-service element in the domain.xml and they can be set either using admin GUI or asadmin command line.
By default an adapter is configured at GrizzlyNetworkManager layer and one for servlet invocation on application dispatcher. Users could configure their adapters using on of the following three properties: smiServletAdapter, smiLayerAdapter, smiNetworkManagerAdapter and their values should be in the following format:
User defined adapters should implement org.jvnet.glassfish.comms.admin.reporter.SMILogMessageAdapter interface.
For the default adapters, it is possible to control the amount of records logged by setting smi log level ( e.g. server-config.log-service.module-log-levels.property.smi=FINE ).
When smi log level is
FINE: messages are logged at SERVLET interception in the Application Dispatcher layer
FINER: SERVLET interception and NetworkManager from/to cluster (i.e excluding Loadbalancer network hops)
FINEST:SERVLET interception and NetworkManager including Loadbalancer network hops
If the intent is to log messages only at NetworkManager thus bypassing messages at servlet invocation, there is a work around to achieve the same. There is a NullAdapter implementation in SailFin, which can be set as an adapter implementation for smiServletAdapter property.
Access logging, where SIP messages are logged into a different file is implemented on top of SMI.
Cut and paster from the server logs to when a simple invite UAS application is run:
[#|2009-09-27T23:21:03.509+0530|FINE|sun-glassfish-comms-server2.0|javax.enterprise.system.container.sip.smi|_ThreadID=16;_ThreadName=SipContainer-serversWorkerThread-5060-9;ClassName=org.jvnet.glassfish.comms.admin.reporter.SMIBaseReporter;MethodName=log;_RequestID=fc6596b6-87ec-4304-b423-76425085c98c;|SMI -->IN Request INVITE At: inviteuas/TestSipServlet -->
INVITE sip:sailfin-AT-inviteuas-DOT-com;transport=UDP SIP/2.0
Content-Length: 127
Max-Forwards: 70
From: "sipp"
Cseq: 1 INVITE
Contact:
Subject: inviteuas Test
To: "sailfin"
Content-Type: application/sdp
Test-Type: uas
Call-Id: 1-10460-AT-127.0.0-DOT-1
Via: SIP/2.0/UDP 127.0.0-DOT-1:5090;branch=z9hG4bK-10460-1-0
v=0
o=user1 53655765 2353687637 IN IP4 127.0.0-DOT-1
s=-
c=IN IP4 127.0.0-DOT-1
t=0 0
m=audio 6000 RTP/AVP 0
a=rtpmap:0 PCMU/8000|#]
[#|2009-09-27T23:21:03.533+0530|FINE|sun-glassfish-comms-server2.0|javax.enterprise.system.container.sip.smi|_ThreadID=16;_ThreadName=SipContainer-serversWorkerThread-5060-9;ClassName=org.jvnet.glassfish.comms.admin.reporter.SMIBaseReporter;MethodName=log;_RequestID=fc6596b6-87ec-4304-b423-76425085c98c;|SMI <--OUT Response 200 (INVITE) At: inviteuas/TestSipServlet -->
SIP/2.0 200 OK
From: "sipp"
Cseq: 1 INVITE
Contact:
To: "sailfin"
Server: Glassfish_SIP_2.0.0
Call-Id: 1-10460-AT-127.0.0-DOT-1
Via: SIP/2.0/UDP 127.0.0-DOT-1:5090;branch=z9hG4bK-10460-1-0
|#]
[#|2009-09-27T23:21:03.578+0530|FINE|sun-glassfish-comms-server2.0|javax.enterprise.system.container.sip.smi|_ThreadID=17;_ThreadName=SipContainer-serversWorkerThread-5060-7;ClassName=org.jvnet.glassfish.comms.admin.reporter.SMIBaseReporter;MethodName=log;_RequestID=6dd574b5-0f5a-4857-8e85-0a805d6e02e8;|SMI -->IN Request ACK At: inviteuas/TestSipServlet -->
ACK sip:sailfin-AT-inviteuas-DOT-com;transport=UDP;fid=server_1 SIP/2.0
Content-Length: 0
Max-Forwards: 69
From: "sipp"
Cseq: 1 ACK
Contact: sip:sipp-AT-127.0.0-DOT-1:5090
Subject: inviteuas Test
To: "sailfin"
Call-Id: 1-10460-AT-127.0.0-DOT-1
Via: SIP/2.0/UDP 127.0.0-DOT-1:5090;branch=z9hG4bK-10460-1-5
|#]#|2009-09-27T23:21:04.073+0530|FINE|sun-glassfish-comms-server2.0|javax.enterprise.system.container.sip.smi|_ThreadID=18;_ThreadName=SipContainer-serversWorkerThread-5060-6;ClassName=org.jvnet.glassfish.comms.admin.reporter.SMIBaseReporter;MethodName=log;_RequestID=c88e7c7c-18a1-4632-9994-1e12d6a52d8c;|SMI -->IN Request BYE At: inviteuas/TestSipServlet -->
BYE sip:sailfin-AT-inviteuas-DOT-com;transport=UDP;fid=server_1 SIP/2.0
Content-Length: 0
Max-Forwards: 69
From: "sipp"
Cseq: 2 BYE
Contact: sip:sipp-AT-127.0.0.1:5090
Subject: inviteuas Test
To: "sailfin"
Call-Id: 1-10460-AT-127.0.0.1
Via: SIP/2.0/UDP 127.0.0.1:5090;branch=z9hG4bK-10460-1-7
|#]
[#|2009-09-27T23:21:04.087+0530|FINE|sun-glassfish-comms-server2.0|javax.enterprise.system.container.sip.smi|_ThreadID=18;_ThreadName=SipContainer-serversWorkerThread-5060-6;ClassName=org.jvnet.glassfish.comms.admin.reporter.SMIBaseReporter;MethodName=log;_RequestID=c88e7c7c-18a1-4632-9994-1e12d6a52d8c;|SMI <--OUT Response 200 (BYE) At: inviteuas/TestSipServlet -->
SIP/2.0 200 OK
From: "sipp"
Cseq: 2 BYE
To: "sailfin"
Server: Glassfish_SIP_2.0.0
Call-Id: 1-10460-AT-127.0.0.1
Via: SIP/2.0/UDP 127.0.0.1:5090;branch=z9hG4bK-10460-1-7
|#]










