The Syslog protocol is a very popular way of sending log information over TCP/IP to event log collectors (The introduction to Syslog in the RFC is well worth a read).Sendmail can do logging to a syslog server straight of the bat but in the Windows world it unfortunately doesn’t get much of a run. Exchange does make its tracking logs available via WMI as well as the raw tab separated text file but doesn’t give you any way of sending them to another server. To get my Exchange server producing syslog messages for the tracking log data I thought I’d write a small c# console application that would retrieve the tracking log data for the last 5 minutes then create and send syslog messages for each message in the log. Then all I need to do is create a scheduled task on the Exchange boxes to run the app every five minutes.
Digging a bit deeper.
When you dig a bit deeper into the message tracking logs on Exchange you’ll find there are a lot of events that are logged and only some of them are of day to day use. The way I approached the application is that I decided I wanted to log 3 different types of syslog events the first was a Mail.Notice priority syslog message for normal email traffic on the server. I also run the IMF on my exchange boxes so I wanted to send a different Syslog message for any messages that where blocked by the IMF on my server so I decided to use the Mail.Warning priority for any IMF messages. The last event I wanted to know about was any NDR’s that where sent so I used the Mail.Error priority syslog for these. There where a couple of approaches I could have taken to extract these messages from the log files the first would have been just to open the file and parse it out. The second was to query every event for the last five minutes via WMI and then filter out the ones I didn’t want. The third method was to query the logs for each of the different event numbers and use the filtered result set that WMI returns. I went for the third method which means that the code ends up doing three separate queries to get all the different categories of the events I wanted to report on. This didn’t seem to come at two much of a performance penalty and made the code a little more logical to understand. I may switch to another method once I got some more testing done. (I guess a fourth method would have been to use the Microsoft log parser util)
The Code itself
The code itself consists of two functions the first function goes out and grabs all the tracking log events for the last five minutes based on two input parameters which are the eventids and servername and then builds a syslog message for each log entry and then stores the message text in an arraylist which is returned to the calling stub. The main stub then goes though the arraylist and calls the sendsyslog function which takes the syslog message text, the priority of the Syslog message you want to send and the ipaddress of the syslog server you want to send to. The Syslog sending code itself is pretty simple the following links where helping in putting something basic together http://blogs.msdn.com/2004/11/05/252920.aspx and http://www.eggheadcafe.com/articles/20050212.asp . I should make one note about the WMI code when you have a message that is sent to multiple recipients WMI returns this to you as one entry. I guess it all depends on the way you look at it but a message sent to two recipients to me is two messages. So what I’ve done with the code is I create a separate syslog event for every recipient of a message. An alternative to this would be to create one syslog message and then stack the to field this reduces the number of syslog messages but makes it harder to process.
The code is designed to run with two command line parameters the first is the name of the Exchange server you want to extract the data from and the second is the IPaddress of the syslog server you want the syslogs sent to.
Making it real-time
Having this run in real-time vs on a scheduled basis is certainly a more desirable way to go. There is an Event that gets fired "OnMsgTrackLog" which looks like it could be used to hook in and do this with but its undocumented territory so I’ve had to leave untill I have more time.
I’ve put a downloadable copy of the code here the code itself looks like
using System;
using System.Collections;
using System.Net.Sockets;
using System.Text;
using System.Net;
using System.Management;
namespace ExchangeTrackinglogSender
{
class SendLog
{
static void Main(string[] args)
{
try
{
SendLog sl = new SendLog();
string snServername = args[0];
string snSyslogIPName = args[1];
ArrayList alEmailalist = sl.getRecentLogs(5,snServername,1020,1028);
IEnumerator raEnumerator = alEmailalist.GetEnumerator();
while ( raEnumerator.MoveNext() )
{
sl.sendsyslog(raEnumerator.Current.ToString(),snSyslogIPName,21);
}
ArrayList alIMFalist = sl.getRecentLogs(5,snServername,1039,1039);
IEnumerator raEnumerator1 = alIMFalist.GetEnumerator();
while ( raEnumerator1.MoveNext() )
{
sl.sendsyslog(raEnumerator1.Current.ToString(),snSyslogIPName,20);}
ArrayList alNDRalist = sl.getRecentLogs(5,snServername,1026,1030);
IEnumerator raEnumerator2 = alNDRalist.GetEnumerator();
while ( raEnumerator2.MoveNext() )
{
sl.sendsyslog(raEnumerator2.Current.ToString(),snSyslogIPName,19);}
}
catch(IndexOutOfRangeException e){
Console.WriteLine("Usage exsyslog.exe ");
}
catch(Exception e)
{
System.IO.StreamWriter elErrorlog = new System.IO.StreamWriter("c:\\Syslogsendererror.log",true);
elErrorlog.WriteLine(System.DateTime.Now + " " + e.InnerException + " " + " Exception Description:" + e.ToString());
elErrorlog.Close();
}
}
void sendsyslog(string mtMessagetxt,string iaIpaddress, int spPriority){
UdpClient ucUdpclient = new UdpClient(iaIpaddress, 514);
byte[] rawMsg;
string strParams = System.String.Format("<{0}>{1}",spPriority, mtMessagetxt);
rawMsg = System.Text.Encoding.ASCII.GetBytes(string.Concat(strParams));
ucUdpclient.Send(rawMsg, rawMsg.Length);
ucUdpclient.Close();
ucUdpclient=null;
}
ArrayList getRecentLogs(int tiTimeinterval,string snServername, int idTid1, int idTid2){
ArrayList alRecpalist = new ArrayList();
ConnectionOptions coObjconn = new ConnectionOptions();
coObjconn.Impersonation = ImpersonationLevel.Impersonate;
coObjconn.EnablePrivileges = true;
string qtQuerytime = ManagementDateTimeConverter.ToDmtfDateTime(DateTime.Now.ToUniversalTime().AddMinutes(-tiTimeinterval));
ManagementScope msExmangescope = new ManagementScope(@"\\" + snServername + @"\root\MicrosoftExchangeV2",coObjconn);
ObjectQuery qoObjquery = new ObjectQuery("Select * FROM Exchange_MessageTrackingEntry where entrytype = '" + idTid1 + "' and OriginationTime >= '" + qtQuerytime + "' or entrytype = '" + idTid2 + "' and OriginationTime > '" + qtQuerytime + "'");
System.Management.ManagementObjectSearcher osObjsearch = new System.Management.ManagementObjectSearcher(msExmangescope,qoObjquery);
System.Management.ManagementObjectCollection qcQueryCollection1 = osObjsearch.Get();
foreach( System.Management.ManagementObject reTrackinglogEntry in qcQueryCollection1 )
{
string[] raReciparray = (string[])reTrackinglogEntry["RecipientAddress"];
UInt32[] raRecipStatusarray = (UInt32[])reTrackinglogEntry["RecipientStatus"];
for(int i=0;i<=raReciparray.GetUpperBound(0);i++)
{
string msMsgtext;
msMsgtext = "date=" + ManagementDateTimeConverter.ToDateTime(reTrackinglogEntry["OriginationTime"].ToString()).ToString("yyyy-MM-dd") + ",";
msMsgtext = msMsgtext + "time=" + ManagementDateTimeConverter.ToDateTime(reTrackinglogEntry["OriginationTime"].ToString()).ToString("HH:mm:ss") + ",";
msMsgtext = msMsgtext + "servername=" + snServername + ",eventid=" + reTrackinglogEntry["EntryType"].ToString() + ",";
msMsgtext = msMsgtext + "msgid=" + "\"" + reTrackinglogEntry["MessageID"].ToString() + "\",RecipientType=" + raRecipStatusarray[i] + ",";
msMsgtext = msMsgtext + "nrcpts=" + reTrackinglogEntry["RecipientCount"] + ",";
if(reTrackinglogEntry["subject"] != null) {msMsgtext = msMsgtext + "subject=\"" + reTrackinglogEntry["subject"].ToString().Replace("\"","") + "\",";}
msMsgtext = msMsgtext + "from=" + reTrackinglogEntry["SenderAddress"].ToString() + ",to=" + raReciparray[i] + ",size=" + reTrackinglogEntry["size"].ToString();
alRecpalist.Add(msMsgtext);
}
}
return alRecpalist;
}
}
}
Digging a bit deeper.
When you dig a bit deeper into the message tracking logs on Exchange you’ll find there are a lot of events that are logged and only some of them are of day to day use. The way I approached the application is that I decided I wanted to log 3 different types of syslog events the first was a Mail.Notice priority syslog message for normal email traffic on the server. I also run the IMF on my exchange boxes so I wanted to send a different Syslog message for any messages that where blocked by the IMF on my server so I decided to use the Mail.Warning priority for any IMF messages. The last event I wanted to know about was any NDR’s that where sent so I used the Mail.Error priority syslog for these. There where a couple of approaches I could have taken to extract these messages from the log files the first would have been just to open the file and parse it out. The second was to query every event for the last five minutes via WMI and then filter out the ones I didn’t want. The third method was to query the logs for each of the different event numbers and use the filtered result set that WMI returns. I went for the third method which means that the code ends up doing three separate queries to get all the different categories of the events I wanted to report on. This didn’t seem to come at two much of a performance penalty and made the code a little more logical to understand. I may switch to another method once I got some more testing done. (I guess a fourth method would have been to use the Microsoft log parser util)
The Code itself
The code itself consists of two functions the first function goes out and grabs all the tracking log events for the last five minutes based on two input parameters which are the eventids and servername and then builds a syslog message for each log entry and then stores the message text in an arraylist which is returned to the calling stub. The main stub then goes though the arraylist and calls the sendsyslog function which takes the syslog message text, the priority of the Syslog message you want to send and the ipaddress of the syslog server you want to send to. The Syslog sending code itself is pretty simple the following links where helping in putting something basic together http://blogs.msdn.com/2004/11/05/252920.aspx and http://www.eggheadcafe.com/articles/20050212.asp . I should make one note about the WMI code when you have a message that is sent to multiple recipients WMI returns this to you as one entry. I guess it all depends on the way you look at it but a message sent to two recipients to me is two messages. So what I’ve done with the code is I create a separate syslog event for every recipient of a message. An alternative to this would be to create one syslog message and then stack the to field this reduces the number of syslog messages but makes it harder to process.
The code is designed to run with two command line parameters the first is the name of the Exchange server you want to extract the data from and the second is the IPaddress of the syslog server you want the syslogs sent to.
Making it real-time
Having this run in real-time vs on a scheduled basis is certainly a more desirable way to go. There is an Event that gets fired "OnMsgTrackLog" which looks like it could be used to hook in and do this with but its undocumented territory so I’ve had to leave untill I have more time.
I’ve put a downloadable copy of the code here the code itself looks like
using System;
using System.Collections;
using System.Net.Sockets;
using System.Text;
using System.Net;
using System.Management;
namespace ExchangeTrackinglogSender
{
class SendLog
{
static void Main(string[] args)
{
try
{
SendLog sl = new SendLog();
string snServername = args[0];
string snSyslogIPName = args[1];
ArrayList alEmailalist = sl.getRecentLogs(5,snServername,1020,1028);
IEnumerator raEnumerator = alEmailalist.GetEnumerator();
while ( raEnumerator.MoveNext() )
{
sl.sendsyslog(raEnumerator.Current.ToString(),snSyslogIPName,21);
}
ArrayList alIMFalist = sl.getRecentLogs(5,snServername,1039,1039);
IEnumerator raEnumerator1 = alIMFalist.GetEnumerator();
while ( raEnumerator1.MoveNext() )
{
sl.sendsyslog(raEnumerator1.Current.ToString(),snSyslogIPName,20);}
ArrayList alNDRalist = sl.getRecentLogs(5,snServername,1026,1030);
IEnumerator raEnumerator2 = alNDRalist.GetEnumerator();
while ( raEnumerator2.MoveNext() )
{
sl.sendsyslog(raEnumerator2.Current.ToString(),snSyslogIPName,19);}
}
catch(IndexOutOfRangeException e){
Console.WriteLine("Usage exsyslog.exe
}
catch(Exception e)
{
System.IO.StreamWriter elErrorlog = new System.IO.StreamWriter("c:\\Syslogsendererror.log",true);
elErrorlog.WriteLine(System.DateTime.Now + " " + e.InnerException + " " + " Exception Description:" + e.ToString());
elErrorlog.Close();
}
}
void sendsyslog(string mtMessagetxt,string iaIpaddress, int spPriority){
UdpClient ucUdpclient = new UdpClient(iaIpaddress, 514);
byte[] rawMsg;
string strParams = System.String.Format("<{0}>{1}",spPriority, mtMessagetxt);
rawMsg = System.Text.Encoding.ASCII.GetBytes(string.Concat(strParams));
ucUdpclient.Send(rawMsg, rawMsg.Length);
ucUdpclient.Close();
ucUdpclient=null;
}
ArrayList getRecentLogs(int tiTimeinterval,string snServername, int idTid1, int idTid2){
ArrayList alRecpalist = new ArrayList();
ConnectionOptions coObjconn = new ConnectionOptions();
coObjconn.Impersonation = ImpersonationLevel.Impersonate;
coObjconn.EnablePrivileges = true;
string qtQuerytime = ManagementDateTimeConverter.ToDmtfDateTime(DateTime.Now.ToUniversalTime().AddMinutes(-tiTimeinterval));
ManagementScope msExmangescope = new ManagementScope(@"\\" + snServername + @"\root\MicrosoftExchangeV2",coObjconn);
ObjectQuery qoObjquery = new ObjectQuery("Select * FROM Exchange_MessageTrackingEntry where entrytype = '" + idTid1 + "' and OriginationTime >= '" + qtQuerytime + "' or entrytype = '" + idTid2 + "' and OriginationTime > '" + qtQuerytime + "'");
System.Management.ManagementObjectSearcher osObjsearch = new System.Management.ManagementObjectSearcher(msExmangescope,qoObjquery);
System.Management.ManagementObjectCollection qcQueryCollection1 = osObjsearch.Get();
foreach( System.Management.ManagementObject reTrackinglogEntry in qcQueryCollection1 )
{
string[] raReciparray = (string[])reTrackinglogEntry["RecipientAddress"];
UInt32[] raRecipStatusarray = (UInt32[])reTrackinglogEntry["RecipientStatus"];
for(int i=0;i<=raReciparray.GetUpperBound(0);i++)
{
string msMsgtext;
msMsgtext = "date=" + ManagementDateTimeConverter.ToDateTime(reTrackinglogEntry["OriginationTime"].ToString()).ToString("yyyy-MM-dd") + ",";
msMsgtext = msMsgtext + "time=" + ManagementDateTimeConverter.ToDateTime(reTrackinglogEntry["OriginationTime"].ToString()).ToString("HH:mm:ss") + ",";
msMsgtext = msMsgtext + "servername=" + snServername + ",eventid=" + reTrackinglogEntry["EntryType"].ToString() + ",";
msMsgtext = msMsgtext + "msgid=" + "\"" + reTrackinglogEntry["MessageID"].ToString() + "\",RecipientType=" + raRecipStatusarray[i] + ",";
msMsgtext = msMsgtext + "nrcpts=" + reTrackinglogEntry["RecipientCount"] + ",";
if(reTrackinglogEntry["subject"] != null) {msMsgtext = msMsgtext + "subject=\"" + reTrackinglogEntry["subject"].ToString().Replace("\"","") + "\",";}
msMsgtext = msMsgtext + "from=" + reTrackinglogEntry["SenderAddress"].ToString() + ",to=" + raReciparray[i] + ",size=" + reTrackinglogEntry["size"].ToString();
alRecpalist.Add(msMsgtext);
}
}
return alRecpalist;
}
}
}