Breaking correctly some SIP logs

[opsi]

Hi All, here is what my logs look likes :

17:31:52.872 CALL(IP)  (00:62582:01) Fax Mode is Bypass, Modem Mode is Bypass
17:31:52.872 CALL(IP)  (00:62582:01) RFC2833 DTMF Relay in use, Dynamic Payload
                        Type is 101
17:31:52.872 CALL(IP)  (00:62582:01) Initial MID is disabled
17:31:52.882 CALL(IP)  (00:62582:01) SENT Outseize ACK (toPvid: x66) to L3P
17:31:52.882 CALL(SIP) (00:62582:01) RCVD Outseize Ack from VPPL
17:31:52.882 CALL(SIP) (00:62582:01) SENT Connect to L4
17:31:52.882 CALL(SIP) (00:62582:01) Start 868 Seconds Session End Timer
17:31:52.882 CALL(SIP) (00:62582:01) RCVD Cut Thru from VPPL
17:31:52.882 CALL(SIP) (00:62582:01) RCVD Connect from VPPL
17:31:52.882 CALL(L4)  (00:62582:01) RCVD Connect  from SIP
17:31:52.882 CALL(L4)  (00:62582:01) SENT CPE of ANSWER  to GCL
17:31:52.882 CALL(L4)  (00:62582:01) SENT connect_1way: r_ts=0x24f l_ts=0x489 t
                       o TSI
17:31:52.882 CALL(L4)  (00:62582:00) SENT connect_1way: r_ts=0x489 l_ts=0x24f t
                       o TSI
17:31:52.882 CALL(GCL) (00:62582:01) RCVD CPE of ANSWER  from L4
17:31:52.882 CALL(GCL) (00:62582:01) SENT Call Answered to GCL
17:31:52.882 CALL(GCL) (00:62582:00) SENT CPE of ANSWER  to L4
17:31:52.882 CALL(L4)  (00:62582:00) RCVD CPE of ANSWER from GCL
17:31:52.882 CALL(L4)  (00:62582:00) SENT Connect to ISDN
17:31:52.882 CALL(ISD) (00:62582:00) RCVD Connect from L4
17:31:52.882 CALL(ISD) (00:62582:00) SENT Connect to Network
17:31:52.962 CALL(SIP) (00:00000:00) SENT OPTIONS to 10.247.9.200:5060 Cseq:257
                       375
17:31:52.962 CALL(SIP) (00:00000:00)      with R-URI: 10.247.9.200:5060 UDP
17:31:52.962 CALL(SIP) (00:00000:00) 
                        <--- [10.247.9.200, 5060 <- 10.247.9.150, 5060]
                       OPTIONS sip:10.247.9.200:5060;ttl=0 SIP/2.0\r\n 
                       Via: SIP/2.0/UDP 10.247.9.150:5060;rport;branch=z9hG4bK-
                       79cd-1294306312-4999-65\r\n 
                       Call-ID: 73f1-1e61-98201021544-Phy_SGKCHIM1-0-10.247.9.1
                       50\r\n 
                       CSeq: 257375 OPTIONS\r\n 
                       Max-Forwards: 70\r\n 
                       To: <sip:10.247.9.200:5060;ttl=0>\r\n 
                       From: <sip:10.247.9.150>;tag=95ffcd055e0f78f7d5d397020e8
                       9288d9c72166f\r\n 

So it can be just one line per event or more.

I have create a new source type as following:

adminops@ocsinventory:/opt/splunk/bin$ sudo ./splunk cmd btool props list sip
[sip]
BREAK_ONLY_BEFORE = CALL
BREAK_ONLY_BEFORE_DATE = false
CHARSET = UTF-8
DATETIME_CONFIG = /etc/datetime.xml
LEARN_SOURCETYPE = false
MAX_DAYS_AGO = 2000
MAX_DAYS_HENCE = 2
MAX_DIFF_SECS_AGO = 3600
MAX_DIFF_SECS_HENCE = 604800
MAX_EVENTS = 256
MAX_TIMESTAMP_LOOKAHEAD = 128
MUST_BREAK_AFTER = 
MUST_NOT_BREAK_AFTER = 
MUST_NOT_BREAK_BEFORE = 
SEGMENTATION = indexing
SEGMENTATION-all = full
SEGMENTATION-inner = inner
SEGMENTATION-outer = outer
SEGMENTATION-raw = none
SEGMENTATION-standard = standard
SHOULD_LINEMERGE = True
TRANSFORMS = 
TRUNCATE = 10000
maxDist = 100

But unfortunnately, it doesn't break the events correctly... If you have any idea what i should change, it would help a lot 🙂

Pierre

[opsi]

Thanks for the answer. Actually it is what i did at the first time, but i think, i have an issue due to the fact that i'm reading the log file from a NFS Share on an another server. I saw an post on that previously.

Thanks, Pierre

[southeringtonp · Accepted solution]

So you want to start a new event with each line that starts with a timestamp, right?

Is BREAK_ONLY_BEFORE_DATE set to False for a reason? Seems like that would be the opposite of what you'd want.

Part of the problem may be that there are no datestamps, only timestamps. You can use TIME_FORMAT to tell it explicitly what to look for.

Try:

[sip]
SHOULD_LINEMERGE = True
BREAK_ONLY_BEFORE_DATE = true
MAX_TIMESTAMP_LOOKAHEAD = 14
TIME_FORMAT = %H:%M:%S.%Q

Turning MAX_TIMESTAMP_LOOKAHEAD down will help avoid incorrectly splitting on timestamps in the data column.

Turning linemerge off and using LINE_BREAKER instead is another good option.