# Copyright (c) 2010 Flowerfire, Inc. All Rights Reserved. deepmail_pop_imap_smtp = { plugin_version = "1.2" # 2008-05-21 - 1.0 - KBB - Initial creation - first pass, POP3 only. # 2008-05-27 - 1.1 - KBB - Added IMAP support. # 2008-06-03 - 1.2 - KBB - Added SMTP support. # 2010-11-02 - 1.2.1 - MSG - Edited info lines. info.1.manufacturer = "DeepMail" info.1.device = "IMAP/POP3/SMTP Server" info.1.version = "" # The name of this format log.format.format_label = "DeepMail IMAP/POP3/SMTP Server Log Format" log.miscellaneous.log_data_type = "mail_server" log.miscellaneous.log_format_type = "mail_server" # The format of dates and times in this log log.format.date_format = "auto" log.format.time_format = "auto" # The log is in this format if any of the first ten lines match this regular expression # POP3: 2008/04/11 15:49:02 [6734/2964283424] [sendmsg=+OK deeppop3d 3.33 Service is ready <62.1207896542@mail>] # IMAP: 2008/03/30 07:59:24 [31489/2988318752] LOGOUT IP=[166.166.166.166] UserID=[severian] Domain=[urth.net@urth.net] # SMTP: 2008/04/11 23:09:42 [6890/3038150688] from=silk@viron.com, size=2222, nrcpts=1, to=marble@whorl.com log.format.autodetect_regular_expression = '[0-9]{4}/[0-9]{2}/[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2} \\[[0-9]*/[0-9]*\\] (\\[sendmsg=\\+OK deeppop3d |(LOGIN|LOGOUT) IP=\\[[0-9.]+\\] UserID=\\[|from=[^@]+@[^,]+, size=[0-9]+, nrcpts=[0-9]+, to=[^@]+@)' log.format.autodetect_lines = 1000 # All log field parsing will be done using the parsing filters log.format.parse_only_with_filters = "true" # Log fields log.fields = { date = "" time = "" #connection_id = "" #message_id = "" protocol = "" operation = "" server_response = "" status = "" cmd = "" user = "" domain = "" host_ip = "" mailbox.case_sensitive = "true" error_message = "" connections = "" from = "" to = "" subject = "" queuefile = "" mailer = "" #messages_listed = "" messages_retrieved = "" messages_deleted = "" octets_retrieved = "" size = "" messages_seen = "" messages_unseen = "" connection_duration = "" errors = "" nrcpts = "" } # log.fields # Log Parsing Filters log.parsing_filters.parse = ` v.line = current_log_line(); v.key = ''; v.message = ''; # Parse common elements #2008/04/11 15:49:02 [6734/3084460064] [readcmd=DELE 1] if (matches_regular_expression(v.line, '^([0-9]{4}/[0-9]{2}/[0-9]{2}) ([0-9]{2}:[0-9]{2}:[0-9]{2}) \\\\[([0-9]+/[0-9]+)] (.*)$')) then ( v.key = $3; v.message = $4; set_collected_field(v.key, 'date', $1); set_collected_field(v.key, 'time', $2); #set_collected_field(v.key, 'connection_id', v.key); ); # Parse POP command lines #2008/04/11 15:49:02 [6734/2964283424] [AuthCmd : pass][user=severian cmd=pass ********] #2008/04/11 15:49:02 [6734/2964283424] [AuthCmd : user][cmd=user severian@urth.net] #2008/04/11 15:49:02 [6734/2964283424] [Cmd : list][user=severian cmd=list] #2008/04/11 15:49:02 [6734/2964283424] [Cmd : retr][user=severian cmd=retr 1] #2008/04/11 15:49:02 [6734/2964283424] [Cmd : stat][user=severian cmd=stat] #2008/04/11 15:49:02 [6734/2998333472] [AuthCmd : Invalid Command][user= cmd=capa] #2008/04/11 15:49:02 [6734/2998333472] [AuthCmd : pass][user=triskele cmd=pass ********] #2008/04/11 15:49:02 [6734/2998333472] [AuthCmd : user][cmd=user triskele] #2008/04/11 15:49:02 [6734/3084460064] [Cmd : dele][user=dorcas cmd=dele 1] #2008/04/11 15:49:03 [6734/2964283424] [readcmd=QUIT] if (matches_regular_expression(v.message, '\\\\[readcmd=([^]]+)\\\\]')) then ( set_collected_field(v.key, 'cmd', lowercase($1)); # The only one that will be captured this way is quit set_collected_field(v.key, 'protocol', 'POP3'); # Only the POP log has cmds in it ); else if (matches_regular_expression(v.message, '\\\\[(AuthCmd|Cmd) : ([^]]+)\\\\]\\\\[(.*[^=]+=[^ ]+)( ([^=]+))?\\\\]')) then ( # Possible command/parameter patterns: # cmd=apop parameter user password # cmd=user parameter # cmd=user parameter user # user= cmd=auth parameter # user= cmd=capa parameter # user=username cmd=capa parameter # user=username cmd=dele parameter number # user=username cmd=list parameter # user=username cmd=list parameter number # user=username cmd=pass parameter ******** # user=username cmd=retr parameter number # user=username cmd=stat parameter # user=username cmd=top parameter number number # user=username cmd=uidl parameter # user=username cmd=uidl parameter number v.cmd = $2; #v.parameter = $5; #set_collected_field(v.key, 'operation', $1); collect_listed_fields(v.key, $3, ' ', '=', ''); # It's simpler to ignore all but dele and detr, but then we don't have cmd when checking server response. ###2008/04/11 15:49:24 [6734/3046404128] [Cmd : dele][user=severian cmd=dele 1] ###2008/04/11 15:49:25 [6734/3070439456] [Cmd : retr][user=triskele cmd=retr 1] ##else if (matches_regular_expression(v.message, '\\\\[Cmd : (dele|retr)\\\\]\\\\[user=([^ ]+) cmd=')) then ( ## v.cmd = $1; ## set_collected_field(v.key, 'cmd', $1); ## set_collected_field(v.key, 'user', $2); set_collected_field(v.key, 'protocol', 'POP3'); # Only the POP log has cmds in it # The number is actually the message number, not the total, so count them. if (v.cmd eq 'retr') then ( #set_collected_field(v.key, 'messages_retrieved', v.parameter); set_collected_field(v.key, 'messages_retrieved', 1); ); else if (v.cmd eq 'dele') then ( #set_collected_field(v.key, 'messages_deleted', v.parameter); set_collected_field(v.key, 'messages_deleted', 1); ); ); # command #2008/04/11 15:49:02 [6734/2964283424] Login user=severian host=172.66.66.66, # of Msg=3 #2008/04/11 15:49:03 [6734/2964283424] Logout user=severian host=172.66.66.66, # of Msg=3, # of Delete=3 else if (matches_regular_expression(v.message, '(Login|Logout) user=([^, ]+),? host=([0-9.]+),')) then ( v.ekey = v.key . " " . $2; set_collected_field(v.key, 'operation', $1); set_collected_field(v.key, 'user', $2); set_collected_field(v.key, 'host_ip', $3); # Save time in order to calculate the duration if ($1 eq 'Login') then ( set_collected_field(v.ekey, 'login_time', get_collected_field(v.key, 'date_time')); ); # Calculate the duration else ( int login_time_epoc = date_time_to_epoc(get_collected_field(v.ekey, 'login_time')); if (login_time_epoc > 0) then ( int logout_time_epoc = date_time_to_epoc(get_collected_field(v.key, 'date_time')); set_collected_field(v.key, 'connection_duration', 0.0 + (logout_time_epoc - login_time_epoc)); ); set_collected_field(v.key, 'connections', 1); # These carry over, so don't count anything more than once. set_collected_field(v.key, 'messages_deleted', 0); set_collected_field(v.key, 'messages_retrieved', 0); set_collected_field(v.key, 'octets_retrieved', 0); set_collected_field(v.key, 'server_response', ''); set_collected_field(v.key, 'protocol', 'POP3'); accept_collected_entry(v.key, false); ); ); #2008/04/11 15:49:02 [6734/2998333472] There is no such ID(badger@urth.net record else if (matches_regular_expression(v.message, '(There is no such ID\\\\(([^@]+)@([^ ]+) record)')) then ( set_collected_field('', 'date', get_collected_field(v.key, 'date')); set_collected_field('', 'time', get_collected_field(v.key, 'time')); set_collected_field('', 'host_ip', get_collected_field(v.key, 'host_ip')); set_collected_field('', 'protocol', 'POP3'); set_collected_field('', 'errors', 1); set_collected_field('', 'error_message', $1 . $3); set_collected_field('', 'user', $4); set_collected_field('', 'domain', $5); accept_collected_entry('', false); ); #2008/04/11 15:49:02 [6734/3084460064] [INFO][CClient::DeleteMsg()][deleted msg count=1 size=3116 in user=severian domain=urth.net else if (matches_regular_expression(v.message, '\\\\[INFO\\\\]\\\\[[^]]+\\\\]\\\\[[^]]*domain=([^ ]+)')) then ( set_collected_field(v.key, 'domain', $1); set_collected_field(v.key, 'protocol', 'POP3'); ); #2008/04/11 15:49:02 [6734/3084460064] [sendmsg=+OK Message deleted] #2008/04/11 15:49:02 [6734/3084460064] [sendmsg=+OK Bye...] #2008/04/11 15:49:02 [6734/2998333472] [sendmsg=-ERR Bad login] #2008/04/11 15:49:02 [6734/2998333472] [sendmsg=-ERR Unknown AUTHORIZATION state command] #2008/04/11 15:49:02 [6734/2998333472] [sendmsg=+OK User name accepted, password please] else if (matches_regular_expression(v.message, '\\\\[sendmsg=([+-]([^ ]+) [^]]+)\\\\]')) then ( v.response = $1; set_collected_field(v.key, 'status', $2); #2008/04/11 17:59:34 [6734/3010351136] [sendmsg=+OK Mailbox open, 404 message(s)] if (matches_regular_expression(v.response, '(\\\\+OK Mailbox open), ([0-9]+) message\\\\(s\\\\)')) then ( set_collected_field(v.key, 'server_response', $1 . " [omitted] messages(s)"); ); #2008/04/11 15:49:02 [6734/2964283424] [sendmsg=+OK deeppop3d 3.33 Service is ready <62.1207896542@mail>] else if (matches_regular_expression(v.response, '(\\\\+OK deeppop3d [^ ]+ Service is ready) <([^>]+)>')) then ( set_collected_field(v.key, 'server_response', $1 . " <[omitted]>"); #set_collected_field(v.key, 'message_id', $2); ); #2008/04/11 15:49:02 [6734/2964283424] [sendmsg=+OK 4493 octets] else if (matches_regular_expression(v.response, '\\\\+OK ([0-9]+) octets')) then ( set_collected_field(v.key, 'server_response', '+OK [omitted] octets'); set_collected_field(v.key, 'octets_retrieved', $1); ); #2008/04/11 15:49:02 [6734/2964283424] [sendmsg=+OK 3 39472] else if (matches_regular_expression(v.response, '\\\\+OK [0-9]+ [0-9]+')) then ( set_collected_field(v.key, 'server_response', '+OK [omitted]'); ); else ( set_collected_field(v.key, 'server_response', v.response); ); # Carry over, but don't count anything more than once. v.cmd = get_collected_field(v.key, 'cmd'); if (v.cmd ne 'dele') then ( set_collected_field(v.key, 'messages_deleted', 0); ); if (v.cmd ne 'retr') then ( set_collected_field(v.key, 'messages_retrieved', 0); set_collected_field(v.key, 'octets_retrieved', 0); ); set_collected_field(v.key, 'protocol', 'POP3'); accept_collected_entry(v.key, true); set_collected_field(v.key, 'server_response', ''); ); # sendmsg # Parse IMAP lines #2008/03/30 18:03:17 [31489/2980306976] [badger] setUserInfo error, [There is no such ID(badger@urth.net record] else if (matches_regular_expression(v.message, '(\\\\[[^]]+\\\\] setUserInfo error, \\\\[There is no such ID\\\\(([^@]+)@([^ ]+) record\\\\])')) then ( set_collected_field('', 'date', get_collected_field(v.key, 'date')); set_collected_field('', 'time', get_collected_field(v.key, 'time')); set_collected_field('', 'host_ip', get_collected_field(v.key, 'host_ip')); set_collected_field('', 'protocol', 'IMAP'); set_collected_field('', 'errors', 1); set_collected_field('', 'error_message', $1); set_collected_field('', 'user', $2); set_collected_field('', 'domain', $3); accept_collected_entry('', false); ); #2008/03/30 07:59:21 [31489/2988318752] [severian] setUserInfo error, [db_open() : No such file or directory in /usr/local/DEEPSoft/MailSuite/local/domain/urth.net@urth.net.dbf] else if (matches_regular_expression(v.message, '(\\\\([[^]]+)\\\\] setUserInfo error, .*')) then ( set_collected_field('', 'date', get_collected_field(v.key, 'date')); set_collected_field('', 'time', get_collected_field(v.key, 'time')); set_collected_field('', 'host_ip', get_collected_field(v.key, 'host_ip')); set_collected_field('', 'protocol', 'IMAP'); set_collected_field('', 'errors', 1); set_collected_field('', 'error_message', $1); set_collected_field('', 'user', $2); accept_collected_entry('', false); ); #2008/03/30 19:02:35 [31489/2964283424] [dorcas] In CMailboxManager::LoadUIDV, db_open() : No such file or directory in /usr/local/DEEPSoft/MailSuite/user/urth.net/p3/h5/dorcas/hello_goodbye.dbf else if (matches_regular_expression(v.message, '\\\\[([^]]+)\\\\] (.* No such file or directory .*)')) then ( set_collected_field('', 'date', get_collected_field(v.key, 'date')); set_collected_field('', 'time', get_collected_field(v.key, 'time')); set_collected_field('', 'host_ip', get_collected_field(v.key, 'host_ip')); set_collected_field('', 'errors', 1); set_collected_field('', 'protocol', 'IMAP'); set_collected_field('', 'user', $1); set_collected_field('', 'error_message', $2); accept_collected_entry('', false); ); #2008/03/30 07:59:48 [31489/2986315808] [dorcas] Mailbox INBOX is selected. You have 24 mails. (seen 0, unseen 24) else if (matches_regular_expression(v.message, '\\\\[([^]]+)\\\\] Mailbox (.*) is selected. You have [0-9]+ mails\\\\. \\\\(seen ([0-9]+), unseen ([0-9]+)\\\\)')) then ( set_collected_field(v.key, 'protocol', 'IMAP'); set_collected_field(v.key, 'user', $1); v.mbox = $2; v.seen = $3; v.unseen = $4; v.mboxes = get_collected_field(v.key, 'mailbox'); if (v.mboxes ne '(empty)' and !(matches_regular_expression(v.mboxes, '(^| )' . v.mbox . '( |,|$)'))) then ( set_collected_field(v.key, 'mailbox', v.mboxes . ', ' . v.mbox); set_collected_field(v.key, 'messages_seen', v.seen + get_collected_field(v.key, 'messages_seen')); set_collected_field(v.key, 'messages_unseen', v.unseen + get_collected_field(v.key, 'messages_unseen')); ); else ( set_collected_field(v.key, 'mailbox', v.mbox); # Don't add these again if the mailbox is the same. set_collected_field(v.key, 'messages_seen', v.seen); set_collected_field(v.key, 'messages_unseen', v.unseen); ); ); #2008/03/30 20:56:08 [31489/3082457120] [dorcas] EXPUNGEd 1 mails else if (matches_regular_expression(v.message, '\\\\[([^]]+)\\\\] EXPUNGEd ([0-9]+) mails')) then ( set_collected_field(v.key, 'user', $1); set_collected_field(v.key, 'messages_deleted', $2); ); # It appears that this happens instead of a LOGOUT, not after the LOGOUT, # maybe if the user disconnects without logging out?? #2008/03/30 12:51:35 [31489/3046404128] Disconnect [Connection closed in ReadFromBuffer()] else if (v.message eq 'Disconnect [Connection closed in ReadFromBuffer()]') then ( int login_time_epoc = date_time_to_epoc(get_collected_field(v.key, 'login_time')); if (login_time_epoc > 0) then ( int logout_time_epoc = date_time_to_epoc(get_collected_field(v.key, 'date_time')); set_collected_field(v.key, 'connection_duration', 0.0 + (logout_time_epoc - login_time_epoc)); ); set_collected_field(v.key, 'connections', 1); set_collected_field(v.key, 'operation', 'Disconnect'); accept_collected_entry(v.key, false); ); #2008/03/30 07:59:24 [31489/2988318752] LOGOUT IP=[166.166.166.166] UserID=[severian] Domain=[urth.net@urth.net] else if (matches_regular_expression(v.message, 'L(OGOUT|OGIN) IP=\\\\[([0-9.]+)\\\\] UserID=\\\\[([^]]+)\\\\] Domain=\\\\[([^]]+)\\\\]')) then ( v.op = "L" . lowercase($1); # Make consistent with POP v.ekey = v.key . " " . $2; set_collected_field(v.key, 'protocol', 'IMAP'); set_collected_field(v.key, 'operation', v.op); set_collected_field(v.key, 'host_ip', $2); set_collected_field(v.key, 'user', $3); set_collected_field(v.key, 'domain', $4); # Save time in order to calculate the duration if (v.op eq 'Login') then ( set_collected_field(v.ekey, 'login_time', get_collected_field(v.key, 'date_time')); # Save this one for Disconnect where user isn't available set_collected_field(v.key, 'login_time', get_collected_field(v.key, 'date_time')); accept_collected_entry(v.key, true); ); # Calculate the duration else ( int login_time_epoc = date_time_to_epoc(get_collected_field(v.ekey, 'login_time')); if (login_time_epoc > 0) then ( int logout_time_epoc = date_time_to_epoc(get_collected_field(v.key, 'date_time')); set_collected_field(v.key, 'connection_duration', 0.0 + (logout_time_epoc - login_time_epoc)); ); set_collected_field(v.key, 'connections', 1); accept_collected_entry(v.key, false); ); ); # Parse SMTP lines # Example 1 #2008/04/11 23:09:42 [6890/3038150688] from=badger@urth.net, size=2222, nrcpts=1, to=silk@viron.com #2008/04/11 23:09:42 [6890/3038150688] Not Filtered : IP=[166.166.166.166], from=[badger@urth.net], to=[silk@viron.com], subject=[we have a cas1no that suits you] #2008/04/11 23:09:42 [6890/3038150688] from=badger@urth.net, to=silk@viron.com, stat=Queued, queuefile=/usr/local/DEEPSoft/MailSuite/local/smtp/queue/qprime/local/q05/1207922982411276303815068822145 #2008/04/11 23:09:42 [6890/3038150688] Closed, IP=[166.166.166.166] # Example 2 #2008/04/11 19:06:23 [11211/3080364064] Filtering in LocalQDelivery[/usr/local/DEEPSoft/MailSuite/local/smtp/queue/qprime/local/q09/1207908382188228307620662420719]... #2008/04/11 19:06:23 [11211/3080364064] Not Filtered : IP=[166.166.166.166], from=[mint@viron.com], to=[silk@here.whorl.com], subject=[Because of your increasing size...] #2008/04/11 19:06:23 [11211/3080364064] silk's quota is using 1/204800 KB #2008/04/11 19:06:23 [11211/3080364064] Forwarding to silk@sky.whorl.com by silk@here.whorl.com's extended forwarding process #2008/04/11 19:06:23 [11211/3080364064] from=silk-forward-daemon@here.whorl.com, to=silk@sky.whorl.com, stat=Queued, queuefile=/usr/local/DEEPSoft/MailSuite/local/smtp/queue/qprime/remote/q03/120790838316126230803640643 #2008/04/11 19:06:23 [11211/3080364064] from=mint@viron.com, to=silk@here.whorl.com, stat=Sent(Forwarded), mailer=localqueue else if (matches_regular_expression(v.message, ' : (IP=\\\\[.*)\\\\]$')) then ( v.message = $2; v.message = replace_all(v.message, '=[', '='); v.message = replace_all(v.message, '],', ','); # The one at the end with no comma is stripped above collect_listed_fields(v.key, v.message, ', ', '=', 'IP=host_ip'); set_collected_field(v.key, 'protocol', 'SMTP'); ); else if (matches_regular_expression(v.message, '(from=.*)')) then ( collect_listed_fields(v.key, v.message, ', ', '=', 'stat=server_response'); if (contains(v.message, 'stat=')) then ( v.stat = get_collected_field(v.key, 'server_response'); #Sent[250 Message received: 20080411140035207.SOL.22459@urth.net] #Returned[550 Unknown user badger@urth.net] #Sent[250 Ok: queued as A978E71] if (matches_regular_expression(v.stat, '^([^[]+)\\\\[([0-9]+) ')) then ( set_collected_field(v.key, 'status', $1 . " (" . $2 . ")"); ); #user unknown #Queued #Blocked else ( set_collected_field(v.key, 'status', v.stat); ); set_collected_field(v.key, 'protocol', 'SMTP'); accept_collected_entry(v.key, true); # Clear these so they are not counted more than once set_collected_field(v.key, 'nrcpts', 0); set_collected_field(v.key, 'size', 0); ); ); #Connect Timeout mail.urth.com:25, Operation now in progress #Fail to connect to mail.urth.com : Connection refused #Fail to open queue file : /usr/local/DEEPSoft/MailSuite/local/smtp/queue/qprime/remote/q01/120790918492619130823670081.dat #In EmailParse(), Special Character violation[] #In MAIL(), Invalid MAIL FROM: #In MAIL(), badger@urth.net ... User Unknown #In RCPT(), +._-9badger@urth.net ... User Unknown #Loop Detected in proxy mx(Remote Host => mail[155.155.155.155]:25) #MX Server(urth.net:25) error code : 421 #No MAIL_FROM Info. in /usr/local/DEEPSoft/MailSuite/local/smtp/queue/qprime/remote/q01/120791522853925430843699521.dat #No MSG file in /usr/local/DEEPSoft/MailSuite/local/smtp/queue/remote/q01/120671085860864930763581761.eml #QLock() : Fail to lock, Resource temporarily unavailable in /usr/local/DEEPSoft/MailSuite/local/smtp/queue/qprime/remote/q00/1207911339845058308236700810 #Sending return mail is done(to=severian-forward-daemon@urth.com, subject=Returned Mail: Sending Fail) #There is no active MX server for urth.com #There is no such ID[+._-9badger@urth.net] #TimeOut in ReadFromBuffer() # Use '' as key so that flow of regular collection is not interrupted. else if (matches_regular_expression(v.message, '([tT]ime[oO]ut|[fF]ail|[vV]iolation|[iI]nvalid| \.\.\. User Unknown|Loop Detected|[eE]rror|No MAIL_FROM|No MSG|There is no)')) then ( set_collected_field('', 'date', get_collected_field(v.key, 'date')); set_collected_field('', 'time', get_collected_field(v.key, 'time')); set_collected_field('', 'host_ip', get_collected_field(v.key, 'host_ip')); set_collected_field('', 'protocol', get_collected_field(v.key, 'protocol')); set_collected_field('', 'error_message', v.message); set_collected_field('', 'errors', 1); accept_collected_entry('', false); ); #else ( # debug # echo(v.message); #); ` # Database fields database.fields = { date_time = "" hour_of_day = "" day_of_week = "" #connection_id = "" #message_id = "" cmd = "" user = "" domain = "" host_ip = "" mailbox = "" error_message = "" protocol = "" operation = "" server_response = "" status = "" cmd = "" user = "" from = "" to = "" subject = "" queuefile = "" mailer = "" } # database.fields # Log Filters log.filters = { mark_entry = { label = '$lang_admin.log_filters.mark_entry_label' comment = '$lang_admin.log_filters.mark_entry_comment' value = 'events = 1;' } # mark_entry } # log.filters # Database numerical fields database.numerical_fields = { connections = { default = true } # connections connection_duration = { type = "int" integer_bits = 64 display_format_type = "duration_compact" } # connection_duration octets_retrieved = { type = "int" integer_bits = 64 display_format_type = "bandwidth" } # octets_retrieved size = { type = "int" integer_bits = 64 display_format_type = "bandwidth" } # size #messages_listed = "" messages_retrieved = "" messages_deleted = "" messages_seen = "" messages_unseen = "" errors = "" nrcpts = "" events = { default = true requires_log_field = false entries_field = true } # events } # database.numerical_fields create_profile_wizard_options = { # How the reports should be grouped in the report menu report_groups = { date_time_group = "" } # report_groups } # create_profile_wizard_options } # deepmail_pop_imap_smtp