MTA Relay transaction tracking search

[melonman]

Hi

I am creating a search for sendmail log on multiple mail servers to obtain time taken to relay between MTA and each process happened on each Mail server.

I have already configured distributed search on each mail server(mail1,mail2,mail3) and each splunk sees /var/log/maillog.

To be specific, I want to get time taken between each log entry of the following, and show the result in bar or column graph with each process' elapsed time stacked so you can know how long it takes to get mail1 to mail3(spool), total time and time taken in each mail server.

Could anyone help me create a search string to get the result?

<mail1>
Dec 16 17:14:08 mail1 sm-mta[22714]: oBG8E7wE022714: from=<testuser1@mydomain.poc>, size=475, class=0, nrcpts=1, msgid=<282997A8AE804969B7AEDEF9E8C357F6@ChangeMe>, proto=SMTP, daemon=MTA, relay=[192.168.30.110]
Dec 16 17:14:09 mail1 sm-mta[22716]: oBG8E7wE022714: to=<testuser2@mydomain.poc>, delay=00:00:01, xdelay=00:00:01, mailer=smtp, pri=120475, relay=[192.168.30.112] [192.168.30.112], dsn=2.0.0, stat=Sent (oBG8E8u5017130 Message accepted for delivery)

<mail2>
Dec 16 17:14:09 mail2 sm-mta[17130]: oBG8E8u5017130: from=<testuser1@mydomain.poc>, size=658, class=0, nrcpts=1, msgid=<282997A8AE804969B7AEDEF9E8C357F6@ChangeMe>, proto=ESMTP, daemon=MTA, relay=[192.168.30.111]
Dec 16 17:14:11 mail2 sm-mta[17132]: STARTTLS=client, relay=[192.168.30.113], version=TLSv1/SSLv3, verify=FAIL, cipher=DHE-RSA-AES256-SHA, bits=256/256
Dec 16 17:14:11 mail2 sm-mta[17132]: oBG8E8u5017130: to=<testuser2@mydomain.poc>, delay=00:00:02, xdelay=00:00:02, mailer=smtp, pri=120658, relay=[192.168.30.113] [192.168.30.113], dsn=2.0.0, stat=Sent (oBG8EALJ002849 Message accepted for delivery)

<mail3>
Dec 16 17:14:11 mail3 sm-mta[2849]: STARTTLS=server, relay=[192.168.30.112], version=TLSv1/SSLv3, verify=NO, cipher=DHE-RSA-AES256-SHA, bits=256/256
Dec 16 17:14:11 mail3 sm-mta[2849]: oBG8EALJ002849: from=<testuser1@mydomain.poc>, size=851, class=0, nrcpts=1, msgid=<282997A8AE804969B7AEDEF9E8C357F6@ChangeMe>, proto=ESMTP, daemon=MTA, relay=[192.168.30.112]
Dec 16 17:14:11 mail3 lmtpd: session=1 msgid=<282997A8AE804969B7AEDEF9E8C357F6@ChangeMe> recipient=<testuser2@mydomain.poc> mailbox=!users/testuser2/INBOX size=1458 uid=9 stat=Delivered
Dec 16 17:14:11 mail3 sm-mta[2851]: oBG8EALJ002849: to=<testuser2@mydomain.poc>, delay=00:00:00, xdelay=00:00:00, mailer=mstore, pri=120851, relay=localhost [127.0.0.1], dsn=2.0.0, stat=Sent

-- additional information

I created search just to get the delay with in the mail server.

# splunk search 'sourcetype="sendmail" testuser* | transaction queueid | table host, from, to, delay, msgid, queueid' -auth admin:changeme

host          from                    to              delay                       msgid                        queueid
----- ---------------------- ----------------------  -------- --------------------------------------------- --------------
mail3 testuser1@mydomain.poc testuser2@mydomain.poc  00:00:00 282997A8AE804969B7AEDEF9E8C357F6@ChangeMe     oBG8EALJ002849
mail2 testuser1@mydomain.poc testuser2@mydomain.poc  00:00:02 282997A8AE804969B7AEDEF9E8C357F6@ChangeMe     oBG8E8u5017130
mail1 testuser1@mydomain.poc testuser2@mydomain.poc  00:00:01 282997A8AE804969B7AEDEF9E8C357F6@ChangeMe     oBG8E7wE022714
mail3 testuser1@mydomain.poc testuser2@mydomain.poc  00:00:01 FA1F6FD73ED347CB8F3B5451C59750CA@ChangeMe     oBG8Ard9002705
mail2 testuser1@mydomain.poc testuser2@mydomain.poc  00:00:02 FA1F6FD73ED347CB8F3B5451C59750CA@ChangeMe     oBG8Aq5h016984
mail1 testuser1@mydomain.poc testuser2@mydomain.poc  00:00:01 FA1F6FD73ED347CB8F3B5451C59750CA@ChangeMe     oBG8Aok0022150
...

But, I would like to get the result in the format similar to the following. I think I still have to do transaction search for msgid. * OK with different format if the result have those information.

 msgid  from  to     total  host   ArrivedAt  StayedFor SentAt  
------- ----- ----- ------- ------ ---------- --------- --------
abcdef  user1 user2 6 sec   mail1  HH:MM:SS   2 sec     HH:MM:SS
                            mail2  HH:MM:SS   3 sec     HH:MM:SS
                            mail3  HH:MM:SS   1 sec     HH:MM:SS

What would be an easy way to get the result...?

Thanks!

[melonman · Accepted solution]

With splunk team, I could get the following result, but I am still looking for the search to get the result based on actual time stamp like above.

# splunk search 'sourcetype="sendmail" | convert dur2sec(delay) dur2sec(xdelay) | transaction queueid | search msgid=*ChangeMe from=testuser1* to=testuser2* | where delay>=0 | stats last(_time) as time1 first(_time) as time2 list(delay) as delay(sec) values(host) list(stat) by from,to,msgid | convert ctime(time1) ctime(time2)'

         from                    to                             msgid                          time1               time2        delay(sec) values(host) list(stat)
---------------------- ---------------------- ----------------------------------------- ------------------- ------------------- ---------- ------------ ----------
testuser1@mydomain.poc testuser2@mydomain.poc 012B28991FA3471F9929FEA3977B7C8A@ChangeMe 12/20/2010 16:31:00 12/20/2010 16:31:08          5 mail1        Sent
                                                                                                                                         7 mail2        Sent
                                                                                                                                         5 mail3        Sent
testuser1@mydomain.poc testuser2@mydomain.poc 1EE3A51D02FD4EF58488BEA27F452324@ChangeMe 12/20/2010 16:39:11 12/20/2010 16:39:13          0 mail1        Sent
                                                                                                                                         1 mail2        Sent
                                                                                                                                         1 mail3        Sent
testuser1@mydomain.poc testuser2@mydomain.poc 24FC6F57221C4FFA9BC1B5E5E0676519@ChangeMe 12/16/2010 14:06:18 12/16/2010 14:06:18          0 mail1        Sent
testuser1@mydomain.poc testuser2@mydomain.poc 282997A8AE804969B7AEDEF9E8C357F6@ChangeMe 12/16/2010 17:14:08 12/16/2010 17:14:11          0 mail1        Sent
                                                                                                                                         2 mail2        Sent
                                                                                                                                         1 mail3        Sent
testuser1@mydomain.poc testuser2@mydomain.poc 2FB15937BFF349B8BEA52BC33776C122@ChangeMe 12/20/2010 16:29:13 12/20/2010 16:29:16          0 mail1        Sent
                                                                                                                                         2 mail2        Sent
                                                                                                                                         2 mail3        Sent
testuser1@mydomain.poc testuser2@mydomain.poc 99A437DA859C4EA4B58702961591692C@ChangeMe 12/16/2010 14:27:31 12/16/2010 14:27:33          0 mail1        Sent
                                                                                                                                         1 mail2        Sent
                                                                                                                                         2 mail3        Sent
testuser1@mydomain.poc testuser2@mydomain.poc 9E3FCD84A0524ACFB0F7AF4FD2FA7B68@ChangeMe 12/16/2010 15:02:35 12/16/2010 15:02:37          1 mail1        Sent
                                                                                                                                         1 mail2        Sent
                                                                                                                                         1 mail3        Sent
testuser1@mydomain.poc testuser2@mydomain.poc FA1F6FD73ED347CB8F3B5451C59750CA@ChangeMe 12/16/2010 17:10:52 12/16/2010 17:10:55          1 mail1        Sent
                                                                                                                                         2 mail2        Sent
                                                                                                                                         1 mail3        Sent