EFM 1.12 Debug Log

[Neo541]

I just upgraded from 1.11 to 1.12, and had a quick question.

I've noticed in the new version that I am unable to see the text of email messages in the debug log. I used this to add to my banned words filters, and feel lost without it! :)

Am I doing something wrong, or any way to put it back?

If not, I think i'll have to go back to 1.11 :(

[sheila]

You might try this...

Look in your emailfilter_n.py file where "n" is replaced with the filter number.

Find this line:

#debug('parsed message:\\n%s' % str(msg))

It comes in this section:
raw_message = StringIO(sys.stdin.read())

try:
smart_parser_obj = efm_Parser()
msg = smart_parser_obj.parse(raw_message)
#debug('parsed message:\\n%s' % str(msg))
#msg = email.message_from_file(raw_message)
except email.Errors.MessageError:
import rfc822
from cStringIO import StringIO


From the line

#debug('parsed message:\\n%s' % str(msg))

Remove the # character at the front of the line in front of the word "debug", moving the entire line to the left one character, so that it is lined up with the front of the lines above and below it.

This will cause the full raw message to be written out to the debug file. It will also make your debug file grow large much more quickly.

Let me know if this does what you want...

spelling correction...

[sheila]

P.S. Before doing this, I would recommend saving a backup of the emailfilter_n.py file.

You might find it convenient to do this editing through the File Manager in your CNC. The File Manager will automatically offer you the option to save a backup when you go to save the modified file.

[Neo541]

Sheila,

Thanks for the reply!

I tried what was suggested, and I got this error in my error log:

[*** Sun May 30 02:40:33 2004 ***
Traceback (most recent call last):
File "/big/dom/xMYSITE/emailfilter/emailfilter_1.py", line 297, in ?
msg = smart_parser_obj.parse(raw_message)
File "//usr/lib/python2.2/email/Parser.py", line 62, in parse
self._parseheaders(root, fp)
File "/big/dom/xMYSITE/emailfilter/emailfilter_1.py", line 98, in _parseheaders
raise email.Errors.HeaderParseError(
HeaderParseError: Not a header, not a continuation: `` version=2.63'
'

Also, the email did not go through. Any thoughts?

[sheila]

That error was not caused by the change I suggested.

That error would have occured for the particular email that triggered it whether you made the change I suggested or not.

Basically, there are some emails that are so badly formatted (not conforming to Internet email standards) that the email parsing library that EFM uses will throw an error on such emails and not parse them.

We are currently working on a fix for this problem in EFM.

Send yourself a lil ol' test email and see if the change that I suggested does what you requested. Don't send yourself a known spam or virus email for the test, as a possible spam or virus email may trigger the parsing error that you just shared.

Does this make sense?

[sheila]

Question about your debug files:

What permissions are set on them? Depending on when you initially installed EFM vs. when you upgraded, the PHP file that writes out the filters may have not run under Secure Mode (TM) earlier, but may have this time. Thus, the permissions on the debug files may no longer allow EFM to write to them.

Make sure that the debug files have perms 664, if they do not already.

[Neo541]

Makes perfect sense, except the test one I sent created that error.

Also, it set into motion a repeating error, since I had it set to email me with any errors. So, it tried to notify me of an error, that one had an error, so it tried again, and so on.

I replaced that file with my backup and all is normal again.

I'm quite sure that the only change I made was removing the #, but I suppose I could try it again to make sure.

[Neo541]

dbmail_1.debug and dbmail_1.rjct are set at 644.

emailfilter_n.py are all at 775.

filter_data_n.dat are all at 644.

Which should I switch to 664?

[Neo541]

Sorry to keep replying, but I do get something in my debug log. For example:

*** Sun May 30 02:49:39 2004 ***
dumping header data: for MssgID: <20040530064938.10420.qmail@neo.futurequest.net>
Date: "30 May 2004 06:49:38 -0000"
Subject: Reply to post 'EFM 1.12 Debug Log'
from addys: "FutureQuest Community Forums Mailer" <Service@FutureQuest.net>
to addys: me@myemail.com

*** Sun May 30 02:49:39 2004 ***
Passed banned headers check

*** Sun May 30 02:49:39 2004 ***
Extensionlist is []

*** Sun May 30 02:49:39 2004 ***
Checking for banned words.

*** Sun May 30 02:49:39 2004 ***
message main type is text or None

*** Sun May 30 02:49:39 2004 ***
passed banned-word check

*** Sun May 30 02:49:39 2004 ***
system exit--0

Most of that is the same, but the part that has changed is:

message main type is text or None

instead of actually having the message displayed, so I could read the text.

[sheila]

Originally posted by Neo541:
dbmail_1.debug and dbmail_1.rjct are set at 644.

emailfilter_n.py are all at 775.

filter_data_n.dat are all at 644.

Which should I switch to 664?
dbmail_1.debug and dbmail_1.rjct should be 664.

An alternative fix, is to simply delete the debug, rjct and err files and let the script recreate them, as it will recreate them with the correct permissions.

Is anything at all being written to your debug files? If the debugging option is turned on, and you send an email through the filter, then there should be at least some small amount of info written to the debug file. At the very minimum, it indicates that an email was received.

If you are not getting even that, then the file permissions are probably the issue.

[sheila]

Originally posted by Neo541:
Sorry to keep replying, but I do get something in my debug log. For example:



Most of that is the same, but the part that has changed is:
message main type is text or None


instead of actually having the message displayed, so I could read the text.
The section of the code that writes this is here:
for part in msg.walk():
#debug("*&*&*&*&*&*& !! current part:\n %s\n\n" % str(part))
try:
if part.get_main_type() == 'text' or not part.get_main_type():
debug("message main type is text or None")
part_contents = part.get_payload(decode=1) or ''
body_text = strippedstring(part_contents, '<!--', '-->', '')
#debug("comments removed:\n%s" % body_text)
tdpat = re.compile(r'<[\s/]?(td).*?>', re.I+re.S+re.M)
brpat = re.compile(r'<[\s/]?(br).*?>', re.I+re.S+re.M)
body_text = tdpat.sub(' ', body_text)
#debug("td tags removed:\n%s" % body_text)
body_text = brpat.sub(' ', body_text)
#debug("br tags removed:\n%s" % body_text)
body_text = strippedstring(body_text, '<', '>', '')
#debug("all html removed:\n%s" % body_text)
body_text = remove_new_lines(body_text).lower()
#debug("decoded/stripped contents:\n%s\n\n" % body_text)


Notice the "debug" statements, with the # symbol in front. These lines would write something to the debug file if the comment symbol (#) were removed from the front of the line.

If you want to see the full, raw text part, before any decoding or manipulation of HTML tags, etc... is done, then remove the # symbol from the front of this line:

#debug("*&*&*&*&*&*& !! current part:\n %s\n\n" % str(part))

Make sure not to change the indentation of the lines when you remove the symbol. The whole line must move left one character, so that the line begins in the exact same spot when the # character is removed. (Python is sensitive to white space.)

Otherwise if you want to see the decoded/stripped body contents (or in addition to the raw contents) then remove the # character from this line:

#debug("decoded/stripped contents:\n%s\n\n" % body_text)

[Neo541]

Okay, when I made that change, it had an error again:

*** Sun May 30 03:08:38 2004 ***
Traceback (most recent call last):
File "/big/dom/xMYSITE/emailfilter/emailfilter_1.py", line 297, in ?
msg = smart_parser_obj.parse(raw_message)
File "//usr/lib/python2.2/email/Parser.py", line 62, in parse
self._parseheaders(root, fp)
File "/big/dom/xMYSITE/emailfilter/emailfilter_1.py", line 98, in _parseheaders
raise email.Errors.HeaderParseError(
HeaderParseError: Not a header, not a continuation: `` version=2.63''

[sheila]

The email that is causing this error is malformed.

That is what this error says:
raise email.Errors.HeaderParseError(
HeaderParseError: Not a header, not a continuation: `` version=2.63''

Without seeing the actual raw email, I really don't have much else to offer.

[sheila]

OK, thanks to a good night's sleep, some raw emails sent to me privately, and a few tests with my thinking cap on...

I've uncovered a bug in EFM 1.12 that is causing this problem.

I've already made the correction in the development version, but don't know when that will be available.

In the meantime, you can make this correction yourself if you feel confident about editing the EFM emailfilter_n.py files.

Find line 73 which currently looks like this:

if line[0] in ' ':

And edit it to look like this:

if line[0] in ' \t':

All you are doing is replacing the part within the single quotation marks. Instead of having several spaces you will have a single space, a blackslash, and a letter t IN THAT ORDER.

Note: this turns out to be an intermittent bug... The spaces inside the quote marks are actually a single space and a tab character. However, depending on the manipulation of the file, the tab character may get saved at some point as a string of consecutive spaces instead of a tab character. If this happens, the code breaks. The replacement line I have suggested is not susceptible to this problem.

The pertinent code appears in a block that looks like this:
# Header continuation line
if line[0] in ' ':
if not lastheader:
raise email.Errors.HeaderParseError(
'Continuation line seen before first header')
lastvalue.append(line)
continue

This should now allow the messages to parse correctly and you should be able to remove the comment symbol in front of the debug lines without problems.

The emails you sent me were correctly formed. It is simply that there was a bug in the parsing code.

Why this bug was only being triggered when you tried to print the raw email to the debug file, I have no idea. It makes no sense to me, but I'm not going to spend any time on figuring that out, since a fix is available as described above.

I hope this helps you to get the behavior you need out of EFM. Lest you think this was something just for you...not at all. I needed to see this. Was important. ;)

[sheila]

P.S. Just one additional follow-up...
Were you editting the file in a text editor that replaces tabs with spaces?

If so, that is what caused the problem that you were having. In any case, the suggested "fix" will prevent you from having that problem in the future.

[Neo541]

Sheila,

That seems to have worked! :)

I used notepad to make the changes before, i'm not sure if that converts tabs or not.

Thanks for all your help!

[sheila]

Well, I tested with notepad on my computer, and it did not replace the tab with spaces. So I'm at a loss to explain how that happened to your file. But in any case, glad to hear that the issue is now resolved.