View
#!/usr/bin/python3.6
# -*- python -*-

import sys
sys.dont_write_bytecode = True

sys.path.insert(0, '/usr/local/etc/python')

import os
import ljz
from ljz import sendemail, randphrase, randwords, reformatbody, quotebody, yow, randphrase, randtext,       \
                randgarbage, randnonsense, utag, getutag, getaddrutag, putaddrutag, addrhasutag, fixtagpat, \
                iptocountry, domtocountry, randomsenders, ncsub, b36, random_b36, hostpats, zonepats,       \
                addrpats, ourhostpats, ourzonepats, ouraddrpats, inpatlist, addrparse, parseaddress,        \
                baseaddr, getaddrinfo, getbaseaddrs, getaddrs, dehtml, msgdecode, timescount, emailtotext,  \
                hostcheck, urlutil, sendimages, savemessage, b36uuid, shortimgname, milters, randitem,      \
                getimageinfo, genemail, hcap, decodeurl, literalquery, ppsql, imseen, imseeninit, itemseen, \
                fromtocount, randnm, isip4, _readcache, _controller, _pycheck, _loadavg, _cpu,              \
                makemessage, _connectionID

import ljz.l
import ljz.o
import ljz.u

from ljz.t import *
from ljz.u import *

fullprog = sys.argv[0]
prog     = os.path.basename(fullprog)

out = ljz.o.sysout
err = ljz.o.syserr

import re
import pwd
import imp
import spf
import time
import glob
import copy
import json
import queue
import fcntl
import errno
import types
import ctypes
import random
import getopt
import signal
import psutil
import pprint
import syslog
import difflib
import hashlib
import traceback
import itertools
import threading

import email
import email.utils
import email.header
import email.parser

from socket import AF_INET, AF_INET6

##import numpy

import Milter
import ljz.milter

##recippat    = re.compile(r'^.*?from\s+\S+\s+\(\s*(\S+)\s+\[(\S+?)\].*$', re.M)
recippat    = re.compile(r'^.*?for\s+<(\S+)>.*$', re.M)
commentpat  = re.compile(r'#.*$')
localpat    = re.compile(r'^(127\.0\.0\.|::1).*$')
imagepat    = re.compile(r'\.(jpe?g|png|gif|tiff?)$', re.I)
ctypepat    = re.compile(r'^(\s*Content-Type:.*?)application/octet-stream(.*?name=)"(\S+?)"(.*)$', re.I)
hsplitpat   = re.compile(r'\s*,\s*', re.M)
specialpat  = re.compile(r'\bgoogle\.com$', re.I)
prog        = os.path.basename(sys.argv[0])
##topdir      = os.path.join('/etc', prog)
postconf    = '/usr/sbin/postconf'
topdir      = '/etc/milter'
rundir      = '/var/run/{}'.format(prog)
vpath       = os.path.join(topdir, '.verbose')
mvpath      = os.path.join(topdir, '.moreverbose')
filterdir   = 'filter.d'
filterpat   = '*.f.py'
filterpath  = os.path.join(topdir, filterdir)
filterglob  = os.path.join(filterpath, filterpat)
filterfile  = '.pmfilter'
filterinc   = '/usr/local/etc/pminclude'
filepp      = '/usr/bin/filepp'
runppypath  = '/etc/postfix/.milter-ppy'
port        = 20002
sockfile    = '/var/spool/postfix/var/run/milter.sock'
sockunix    = 'unix:{}'.format(sockfile)
sockinet    = 'inet:{}'.format(port)
vmutop      = '/var/vmusers'
modname     = '_pmf_'
mailsender  = '/root/bin/m'
lockfile    = '/tmp/.pm.l'
killlock    = '/tmp/.pmk.l'
cwindow     = 60.0
cminimum    = 3
validfuncs  = set(['enabled', 'conn', 'hello', 'envfrom', 'envrcpt', 'data', 'header', 'eoh', 'body', 'eom', 'close'])
_addrmaps   = {}

LOCK_EX     = fcntl.LOCK_EX
LOCK_SH     = fcntl.LOCK_SH
LOCK_NB     = fcntl.LOCK_NB
LOCK_UN     = fcntl.LOCK_UN

_syslog_id  = 'postfix/{}'.format(prog)
###ljz.syslog_init(_syslog_id)

skipfiltlog = oset(['header'])

connect_map = {}

def is_verbose():
##    with Protection('is_verbose'):
    with Protection('is_verbose'):
        if os.path.exists(vpath):
            return True
    return False

def is_more_verbose():
##    with Protection('is_more_verbose'):
    with Protection('is_more_verbose'):
        if os.path.exists(mvpath):
            return True
    return False

def run_pm_filters():
    m = milters()
    return (not m or m[0] == 'pm')

_ourlogger = ljz.o._getxlogger('logger',
                               stream=ljz.o._getlogpath(prog),
                               sid=(_syslog_id, ljz.o.xlogger.loglevel.INFO, syslog.LOG_MAIL, ''),
                               create=True)

def _our_stream_log(*args, **kwargs):
    _id = kwargs.get('_id', None)
    if not args:
        args = ('',)
    for a in args:
        _ourlogger.info(a, output=(ljz.o._xlogoutput.STREAM,), _id=_id)

def _our_sys_log(*args, **kwargs):
    _id = kwargs.get('_id', None)
    if not args:
        args = ('',)
    for a in args:
        if not a:
            a= ''
        _ourlogger.info(a, output=(ljz.o._xlogoutput.SYSLOG,), _id=False)
slog = _our_sys_log

##_locker = ljz.l.HippoFileLock
##_locker = ljz.l.HippoOsloLock
_locker = ljz.l.HippoQueueLock

##_loggerflags = ''
_loggerflags = ''

def _getsock():
    rc, out, err = ljz.invoke([postconf, '-p', 'smtpd_milters' ])
    if rc != 0:
        return sockinet
    elif 'unix:' in out:
##        os.chmod(sockfile, 0o777)
        return sockunix
    else:
        return sockinet

def _showheader(name, value, maybe_shorten=True, prefix=None):
    if maybe_shorten:
        for p in _showheader.pats:
            if p.search(name):
                return '{}: [...]'.format(name)
    offset = ' ' * (len(name) + 2)
    if prefix:
        offset = '{}{}'.format(prefix, offset)
    result = ''
    first  = True
    for vline in value.split('\n'):
        vline = vline.strip()
        if not vline:
            continue
        if first:
            result = vline
            first  = False
            continue
        result = '{}\n{}{}'.format(result, offset, vline)
    return '{}: {}'.format(name, result)
_showheader.pats = (
    re.compile(r'^x-(ms|microsoft)-', re.I),
    re.compile(r'^X-Forefront'),
    re.compile(r'^X-Gm'),
    re.compile(r'^(X-Google-)?DKIM-Signature'),
    re.compile(r'^[a-z][a-z-]+')
)
    
def _fixparms(parms):
    parms = [utf8decode(x) for x in parms]
    for i,s in enumerate(parms):
        if type(s) in (list, tuple):
            parms[i] = ';'.join([utf8decode(x) for x in filter(lambda y: y, s)])
    return [x for x in filter(lambda y: y, parms)]

def isrunning():
    mypid      = os.getpid()
    fullinterp = sys.executable
    interp     = os.path.basename(fullinterp)
    for p in psutil.process_iter():
        pd     = p.as_dict(attrs=['pid', 'name', 'cmdline'])
        runpid = pd.get('pid', None)
        if not runpid:
            continue
        name    = pd.get('name', None)
        cmdline = pd.get('cmdline', [])
        nprog   = (prog == name)
        fprog   = (fullprog in cmdline)
        if runpid == mypid or ((not nprog) and not fprog):
            continue
        if nprog or (fprog and name == interp and cmdline[0] == fullinterp and cmdline[1] == fullprog):
            return (True, runpid, name, cmdline, interp, fullinterp)
    return (False, None, None, None, None, None)

def dokill():
    with ljz.l._hippolock():
        running, runpid, name, cmdline, interp, fullinterp = isrunning()
        if not running:
            return True
        nprog   = (prog == name)
        fprog   = (fullprog in cmdline)
        killpid = -1
        if nprog or (fprog and name == interp and cmdline[0] == fullinterp and cmdline[1] == fullprog):
            killpid = runpid
        if killpid < 1:
            return False
        try:
            os.kill(killpid, 0)
            n = 8
            while n > 0:
                n -= 1
                try:
                    os.kill(killpid, signal.SIGKILL)
                except:
                    pass
                time.sleep(0.25)
                os.kill(killpid, 0)
            msg = '!!! unable to kill {}'.format(prog)
            _our_sys_log('', msg)
            _our_stream_log(r'\n\n{}\n'.format(msg))
            return False
        except:
            pass
        msg = '!!! killed {}'.format(prog)
        _our_sys_log('', msg)
        _our_stream_log(r'\n\n{}\n'.format(msg))
        return True

def main():

    try:
        opts, args = getopt.getopt(sys.argv[1:], 'kKw:W:', ['kill', 'wait'])
    except getopt.GetoptError as e:
        print('{}'.format(e))
        return 1

    waitfor = -1
    for o, a in opts:
        if o in ('-k', '-K', '--kill'):
            dokill()
            return 0
        if o in ('-w', '-W', '--wait'):
            try:
                waitfor = int(a)
            except:
                assert False, 'invalid option: {}'.format(o)
        else:
            assert False, 'invalid option: {}'.format(o)

    with ljz.l._hippolock():
        msgtext = 'already running'
        if waitfor > 0:
            start = time.time()
            while time.time() - start < waitfor:
                running, runpid, name, cmdline, interp, fullinterp = isrunning()
                if running:
                    time.sleep(0.25)
            msgtext = 'still running after {} sec'.format(waitfor)
        running, runpid, name, cmdline, interp, fullinterp = isrunning()
        if running:
            msg = '!!! {} {}: {}'.format(prog, milterClass.__name__, msgtext)
            _our_sys_log('', msg)
            _our_stream_log(r'\n\n{}\n'.format(msg))
            print(msg)
            return 1

    mprefix = '=== {} {}'.format(prog, milterClass.__name__)
    loadavg = _loadavg(fmt=True)
    startupmsg = '{}: startup{}'.format(mprefix, loadavg)
    _our_sys_log('', startupmsg, '')
    _our_stream_log(r'\n\n====={}\n'.format(startupmsg))
    imseeninit()
    rc = 0
    try:
        rc = HippoMilter.startup()
    finally:
        shutdownmsg = '{}: shutdown{}'.format(mprefix, loadavg)
        _our_sys_log('', shutdownmsg, '')
        _our_stream_log(r'\n\n====={}\n'.format(shutdownmsg))
    return 0

# Decorators    

class prefilter(object):
    init = None
    filterlock = None
    funclock = None
    def __init__(self, *args, **kwargs):
        if args and len(args) > 0:
            self.init = args[0]
        self.filterlock = kwargs.get('filterlock', None)
        self.funclock = kwargs.get('funclock', None)
    def __call__(self, f):
        def func(*args):
            args = [utf8decode(x) for x in args]
            s = args[0]
            a = args[1:]
            try:
                rc = None
                if self.init is not None:
                    try:
                        data = self.init(*args)
                    except Exception as e:
##                        slog('!!! prefilter exception: {}: {} {}'.format(e, f.__name__, args))
                        s.sys_log('!!! prefilter exception: {}: {} {}'.format(e, f.__name__, args))
                        strace()
                        data = None
                    if data is not None:
##hippo
##                        a = [data] + list(a)
                        a = list(data)
                if self.filterlock is None or self.filterlock is False:
                    rc = s.filter(f.__name__, *a)
                    if not s._isactive():
                        rc = None
                else:
                    if self.filterlock is True:
                        try:
                            suff = 'pre-{}'.format(s.hlsuffix)
                        except:
                            suff = 'pre'
                    elif not self.filterlock:
                        suff = 'pre'
                    else:
                        suff = 'pre-{}'.format(self.filterlock)
                    with _locker(f.__name__, suffix=suff, verbose=s.lockverbose):
                        rc = s.filter(f.__name__, *a)
                        if not s._isactive():
                            rc = None
                if self.funclock is None or self.funclock is False:
                    if rc is None:
                        return f(*args)
                else:
                    if self.funclock is True:
                        try:
                            suff = 'func-{}'.format(s.hlsuffix)
                        except:
                            suff = 'func'
                    elif not self.funclock:
                        suff = 'func'
                    else:
                        suff = 'func-{}'.format(self.funclock)
                    with _locker(f.__name__, suffix=suff, verbose=s.lockverbose):
                        if rc is None:
                            return f(*args)
                # Log the function call if the main function
                # is not going to be invoked.
                if a:
                    argstr = ' - {}'.format(a)
                else:
                    argstr = ''
                loadavg = _loadavg()
                if loadavg:
                    loadavg = ' - {}'.format(loadavg)
                s.verbose_log('{:<9}{}{}'.format(f.__name__.upper(), loadavg, argstr))
                return rc
            except:
                strace(logger=ljz.o.xputs, _id=s._id)
                raise
        return func

class postfilter(object):
    init = None
    filterlock = None
    funclock = None
    def __init__(self, *args, **kwargs):
        if args and len(args) > 0:
            self.init = args[0]
        self.filterlock = kwargs.get('filterlock', None)
        self.funclock = kwargs.get('funclock', None)
    def __call__(self, f):
        def func(*args):
            args = [utf8decode(x) for x in args]
            s = args[0]
            a = args[1:]
            try:
                if self.funclock is None or self.funclock is False:
                    rc = f(*args)
                else:
                    if self.funclock is True:
                        try:
                            suff = 'func-{}'.format(s.hlsuffix)
                        except:
                            suff = 'func'
                    elif not self.funclock:
                        suff = 'func'
                    else:
                        suff = 'func-{}'.format(self.funclock)
                    with _locker(f.__name__, suffix=suff, verbose=s.lockverbose):
                        rc = f(*args)
                if self.init is not None:
                    try:
                        data = self.init(*args)
                    except Exception as e:
##                        slog('!!! postfilter exception: {}: {} {}'.format(e, f.__name__, args))
                        s.sys_log('!!! postfilter exception: {}: {} {}'.format(e, f.__name__, args))
                        strace()
                        data = None
                    if data is not None:
##hippo
##                        a = [data] + list(a)
                        a = list(data)
                newrc = None
                if self.filterlock is None or self.filterlock is False:
                    newrc = s.filter(f.__name__, *a)
                    if not s._isactive():
                        newrc = None
                else:
                    if self.filterlock is True:
                        try:
                            suff = 'post-{}'.format(s.hlsuffix)
                        except:
                            suff = 'post'
                    elif not self.filterlock:
                        suff = 'post'
                    else:
                        suff = 'post-{}'.format(self.filterlock)
                    with _locker(f.__name__, suffix=suff, verbose=s.lockverbose):
                        newrc = s.filter(f.__name__, *a)
                        if not s._isactive():
                            newrc = None
                if newrc is None:
                    return rc
                else:
                    return newrc
            except:
                strace(logger=ljz.o.xputs, _id=s._id)
                raise
        return func

# End of decorators

filterinfo = {}

sock = _getsock()
class MilterPy(Milter.Base):

    @classmethod
    def startup(cls):
        timeout = 600
        Milter.factory = cls
        flags  = 0
        flags += Milter.CHGFROM
        flags += Milter.DELRCPT
        flags += Milter.ADDRCPT
        flags += Milter.ADDRCPT_PAR
        flags += Milter.CHGHDRS
        flags += Milter.ADDHDRS
        flags += Milter.MODBODY
        flags += Milter.CHGBODY
        Milter.set_flags(flags)
##        Milter.set_exception_policy(Milter.CONTINUE)
        ct = ljz.ControllerThread()
        ct.daemon = True
        ct.start()
##        Milter.setdbg(6) # max debug level=6
        rc = Milter.runmilter(prog, sock, timeout, rmsock=True)
        return rc
    
    def __init__(self):
        self._id = Milter.uniqueID()
        self._resultCode = {}
        for r in ( 'Accept', 'Reject', 'Discard', 'Continue', 'Tempfail', 'Noreply', 'Skip' ):
            value = getattr(Milter, r.upper(), None)
            if value is not None:
                self._resultCode[value] = r

    def _rc(self, value):
        if type(value) in (list, tuple):
            if len(value) < 1:
                return None
            else:
                return value[0]

    def _result(self, value):
        if type(value) in (list, tuple):
            result = self._result(self._rc(value))
            if len(value) > 1:
                result = '{}: {} - {} {}'.format(result, *ljz.ecode(*value[1:]))
            return result
        elif value is None:
            return 'Continue'
        else:
            return self._resultCode.get(value, 'result:{}'.format(value))

    def connID(self):
        return self._id

    def init(self):
        pass

    def Accept(self):
        return Milter.ACCEPT
    
    def Reject(self):
        return Milter.REJECT
    
    def Discard(self):
        return Milter.DISCARD
    
    def Continue(self):
        return Milter.CONTINUE
    
    def TempFail(self):
        return Milter.TEMPFAIL
    
    def NoReply(self):
        return Milter.NOREPLY
    
    def Skip(self):
        return Milter.SKIP
    
    def CustomReply(self, *args):
        if len(args) < 1:
            return Milter.REJECT
        else:
            return tuple([ Milter.REJECT ] + list(args))

class MilterPpy(ljz.milter.Milter):

    @classmethod
    def startup(cls):
        s = cls.__new__(cls, logger=None, verbose=True)
        return s.run(port, threaded=False)

milterClass = None

if os.path.exists(runppypath):
    milterClass = MilterPpy
else:
    milterClass = MilterPy

class HippoMilter(milterClass):

    # Call this as early as possible.
    def _init(self):
        self.id          = _connectionID(incr=True)
        self.topdir      = topdir
        self.vmutop      = vmutop
        self.rcpt        = odict()
        self.chgrcpt     = odict()
        self.newrcpt     = odict()
        self.IP          = None
        self.IPname      = None
        self.port        = None
        self.helo        = None
        self.authuser    = None
        self.origfrom    = None
        self.mailfrom    = None
        self.receiver    = None
        self.fromparms   = []
        self.senders     = oset([])
        self.hrcpt       = odict()
        self.rdominfo    = {}
        self.headers     = odict()
        self.chgheaders  = oset([])
        self.bodytext    = ''
        self.newbody     = None
        self.boundary    = None
        self.newfrom     = None
        self.fset        = oset([])
        self.dirset      = oset([])
        self.dirchain    = []
        self.filterseen  = oset([])
        self.flags       = {}
        self.block       = False
        self.logmsg      = []
        self.hlsuffix    = None
        self.lockverbose = False
        self.isours      = False
        self._id         = b36(self.id, 6)
        self.logger = ljz.o._getxlogger(self._id,
                                        stream=ljz.o._getlogpath(prog),
                                        sid=(_syslog_id, ljz.o.xlogger.loglevel.INFO, syslog.LOG_MAIL, ''),
                                        create=True)

    # Now just use this to call _init(), and then
    # move on to conn().
    def connect(self, IPname, family, hostaddr):
        try:
            self._init()
            return self.conn(IPname, family, hostaddr)
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise

    @postfilter(filterlock=True)
    def conn(self, IPname, family, hostaddr):
        global connect_map
        IPname   = utf8decode(IPname)
        family   = utf8decode(family)
        hostaddr = tuple([utf8decode(x) for x in hostaddr])
        special  = False
        testip   = None
        try:
            self.hlsuffix = hostaddr[0]
            if specialpat.search(IPname):
                testip = '.'.join(self.hlsuffix.split('.')[0:2])
                self.hlsuffix = 'net-{}'.format(testip)
                special = True
        except:
            self.hlsuffix = IPname
        self.IPname = IPname
        logmsgs = []
        logmsgs.append('')
        logmsgs.append('CONNECT   - {} {}'.format(IPname, hostaddr))
        loadavg = _loadavg()
        if loadavg:
            logmsgs.append('          - {}'.format(loadavg))
        try:
            self.IP = hostaddr[0]
        except Exception as e:
            logmsgs.append('CONNECT   - !!! unable to determine IP address: {}'.format(e))
####            self.stream_vlog('CONNECT - !!! unable to determine IP address: {}'.format(e))
            self.stream_vlog(*logmsgs)
            return self.Reject()
        if localpat.search(self.IP):
            return self.Accept()
        try:
            self.port = hostaddr[1]
        except Exception as e:
            self.verbose_log('unable to determine port: {}'.format(e))
            logmsgs.append('CONNECT   - !!! unable to determine port: {}'.format(e))
##            self.stream_vlog('CONNECT   - !!! unable to determine port: {}'.format(e))
            self.stream_vlog(*logmsgs)
            return self.Reject()
        self.stream_vlog(*logmsgs)
        with ljz.l._hippolock():
            if not special:
                testip = self.IP
            now    = time.time()
            cutoff = now - cwindow
            count  = 0
            if testip in connect_map:
                entries = connect_map[testip]
                count   = len(entries)
                while len(entries) > 0 and entries[0] < cutoff:
                    entries = entries[1:]
                connect_map[testip] = entries
            else:
                connect_map[testip] = []
            connect_map[testip].append(now)
            count += 1
            self.verbose_log('ATTEMPTS  - {}: {} during {:.3f}s'.format(testip, count, now - connect_map[testip][0]))
            if count > cminimum:
                doit = True
                addrpat_list = addrpats()
                if addrpat_list is not None:
                    for pat in addrpat_list:
                        if pat.search(self.IP):
                            doit = False
                            break
                if doit:
                    self.sys_log('=== will block: [[ {} ]]'.format(testip))
                    self.block = True
##        if not is_verbose():
##            self.sys_log('=== from {}[{}]:{}'.format(self.IP, self.IPname, self.port))
        if family == AF_INET6:
            self.flow  = hostaddr[2]
            self.scope = hostaddr[3]
        else:
            self.flow  = None
            self.scope = None
        self.helo = None
        self.receiver = self.getsymval('j')
        return self.Continue()

    @postfilter(filterlock='')
    def hello(self, heloname):
        try:
            loadavg = _loadavg()
            if loadavg:
                loadavg = '{} - '.format(loadavg)
            self.helo = utf8decode(heloname)
            self.verbose_log('HELO      - {}{}'.format(loadavg, self.helo))
            return self.Continue()
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise

    @postfilter(filterlock='')
    def envfrom(self, mailfrom, *strs):
        try:
            mailfrom = utf8decode(mailfrom)
            strs = _fixparms(strs)
            self.fromparms = strs  # ESMTP parms
            self.authuser  = self.getsymval('{auth_authen}') # authenticated user
            self.origfrom  = mailfrom
            try:
                n, u, d = addrparse(mailfrom)
                if u is None or d is None:
                    self.mailfrom = mailfrom
                else:
                    self.mailfrom = '{}@{}'.format(u, d)
                self.senders.add(baseaddr(self.mailfrom))
            except:
                self.mailfrom = mailfrom
            try:
                self.isours = inpatlist(self.mailfrom, ourzonepats())
            except Exception as e:
                self.stream_vlog('!!! inpatlist failed: {}'.format(e))
            ustr = ' <<{}>>'.format(self.authuser) if self.authuser else ''
            loadavg = _loadavg()
            if loadavg:
                loadavg = '{} - '.format(loadavg)
            self.verbose_log('MAIL FROM - {}{} {}{}'.format(loadavg, self.mailfrom, self.fromparms, ustr))
            return self.Continue()
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise

    def _envrcpt_filter(s, *a):
        with _locker(funcname(), suffix=s.hlsuffix):
            s.makedinfo(*a)
        return a
    @postfilter(_envrcpt_filter, filterlock='', funclock=True)
    def envrcpt(self, to, *strs):
        try:
            to   = utf8decode(to)
            strs = _fixparms(strs)
            loadavg = _loadavg()
            if loadavg:
                loadavg = '{} - '.format(loadavg)
            self.verbose_log('RCPT TO   - {}{} {}'.format(loadavg, to, strs))
            rto = baseaddr(to)
            fromtocount(self.mailfrom, rto, update=True)
            self.rcpt[rto] = list(strs)
            return self.Continue()
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise

    @postfilter()
    def data(self):
        try:
            self.block = False
            loadavg = _loadavg()
            if loadavg:
                loadavg = '      - {}'.format(loadavg)
            self.verbose_log('DATA{}'.format(loadavg))
            return self.Continue()
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise
                                    
    @postfilter()
    def header(self, name, hval):
        try:
            name = utf8decode(name)
            hval = utf8decode(hval)
            self.verbose_log('HEADER    - {}'.format(_showheader(name, hval, prefix='            ')))
            self.block = False
            nlc = name.lower()
            if nlc == 'received':
                m = recippat.search(hval)
                if m:
                    receivedfor = baseaddr(m.group(1))
                    if receivedfor not in self.rcpt:
                       self.rcpt[receivedfor] = []
            self.storeheader(name, hval)
            return self.Continue()
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise

    @postfilter(filterlock='', funclock=True)
    def eoh(self):
        try:
            self.block = False
            loadavg = _loadavg()
            if loadavg:
                loadavg = '       - {}'.format(loadavg)
            self.verbose_log('EOH{}'.format(loadavg))
            return self.Continue()
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise

    @postfilter(filterlock='')
    def body(self, chunk):
        try:
            self.block = False
            self.bodytext += utf8decode(chunk)
            lc = len(self.bodytext)
            pl = '' if lc == 1 else 's'
            loadavg = _loadavg()
            if loadavg:
                loadavg = '{} - '.format(loadavg)
            self.verbose_log('BODY      - {}{} byte{}'.format(loadavg, lc, pl))
            return self.Continue()
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise

    @prefilter(filterlock='', funclock=True)
    def eom(self):
        try:
            self.block = False
            loadavg = _loadavg()
            if loadavg:
                loadavg = '       - {}'.format(loadavg)
            self.verbose_log('EOM{}'.format(loadavg))
            with Protection('eom reconstruct', log=self.verbose_log):
                self.reconstruct()
            return self.Accept()
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise

    def unknown(self, cmd):
        try:
            loadavg = _loadavg()
            if loadavg:
                loadavg = '{} -'.format(loadavg)
            self.verbose_log('UNKNOWN   - {}{}'.format(loadavg, cmd))
            return self.Continue()
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise

    def abort(self):
        try:
            loadavg = _loadavg()
            if loadavg:
                loadavg = '     - {}'.format(loadavg)
            self.stream_vlog('ABORT{}'.format(loadavg))
            return self.Continue()
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise

    @prefilter(filterlock='')
    def close(self, data=None):
        try:
            if data:
                data = ' - {}'.format(data)
            else:
                data = ''
            self.stream_vlog('CLOSE{}{}'.format(data, _loadavg(fmt='     - ')))
            return self.Continue()
        except:
            strace(logger=ljz.o.xputs, _id=self._id)
            raise

    ## === support functions ===

    def _string_log(self, *args, **kwargs):
        _id = kwargs.get('_id', None)
        _pp = kwargs.get('_pp', False)
        if not args:
            args = ('',)
        buff = io.StringIO()
        for a in args:
            self.logger.format(a, outbuff=buff, _pp=_pp, _id=_id)
        result = buff.getvalue()
        buff.close()
        return result

    def stream_log(self, *args, **kwargs):
        _id = kwargs.get('_id', None)
        _pp = kwargs.get('_pp', False)
        if not args:
            args = ('',)
        for a in args:
            self.logger.info(a, output=(ljz.o._xlogoutput.STREAM,), _pp=_pp, _id=_id)

    def stdout_log(self, *args, **kwargs):
        _id = kwargs.get('_id', None)
        _pp = kwargs.get('_pp', False)
        if not args:
            args = ('',)
        for a in args:
            self.logger.info(a, output=(ljz.o._xlogoutput.STDOUT,), _pp=_pp, _id=_id)
        
    def stdout_stream_log(self, *args, **kwargs):
        _id = kwargs.get('_id', None)
        _pp = kwargs.get('_pp', False)
        if not args:
            args = ('',)
        for a in args:
            self.logger.info(a, output=(ljz.o._xlogoutput.STDOUT, ljz.o._xlogoutput.STREAM), _pp=_pp, _id=_id)
        
    def stdout_stream_flog(self, *args, **kwargs):
        if not args:
            args = ('',)
        self.stdout_stream_log(*args, **kwargs)
        
    def sys_slog(self, *args, **kwargs):
        if not args:
            args = ('',)
        for a in args:
            self.logger.info(a, output=(ljz.o._xlogoutput.SYSLOG,), _id=False)

    def sys_formatted_slog(self, *args, **kwargs):
        _id = kwargs.get('_id', None)
        _pp = kwargs.get('_pp', False)
        if not args:
            args = ('',)
        for a in args:
            self.logger.info(a, output=(ljz.o._xlogoutput.SYSLOG,), _pp=_pp, _id=_id)

    def sys_stream_slog(self, *args, **kwargs):
        _id = kwargs.get('_id', None)
        _pp = kwargs.get('_pp', False)
        if not args:
            args = ('',)
        self.stream_log(*args, _pp=_pp, _id=_id)
        self.sys_slog(*args, _pp=_pp, _id=_id)
        
    def sys_log(self, *args, **kwargs):
        _id = kwargs.get('_id', None)
        _pp = kwargs.get('_pp', False)
        if not args:
            args = ('',)
        self.sys_slog(*args, _pp=_pp, _id=_id)
        self.stdout_log(*args, _pp=_pp, _id=_id)

    def verbose_log(self, *args, **kwargs):
        _id = kwargs.get('_id', None)
        _pp = kwargs.get('_pp', False)
        if not args:
            args = ('',)
        if is_verbose():
            self.sys_log(*args, _pp=_pp, _id=_id)
        else:
            self.stdout_log(*args, _pp=_pp, _id=_id)

    def vverbose_log(self, *args, **kwargs):
        _id = kwargs.get('_id', None)
        _pp = kwargs.get('_pp', False)
        if not args:
            args = ('',)
        if is_verbose():
            self.sys_log(*args, _pp=_pp, _id=_id)
        else:
            self.stdout_log(*args, _pp=_pp, _id=_id)

    def stream_vlog(self, *args, **kwargs):
        _id = kwargs.get('_id', None)
        _pp = kwargs.get('_pp', False)
        if not args:
            args = ('',)
        self.stream_log(*args, _pp=_pp, _id=_id)
        self.verbose_log(*args, _pp=_pp, _id=_id)

    def stream_vvlog(self, *args, **kwargs):
        _id = kwargs.get('_id', None)
        _pp = kwargs.get('_pp', False)
        if not args:
            args = ('',)
        self.stream_log(*args, _pp=_pp, _id=_id)
        self.vverbose_log(*args, _pp=_pp, _id=_id)

    def safeprogress(self):
        try:
            self.progress()
        except:
            pass

    def fixparms(self, parms):
        parms = [utf8decode(x) for x in parms]
        for i,s in enumerate(parms):
            if type(s) in (list, tuple):
                parms[i] = ';'.join([utf8decode(x) for x in filter(lambda y: y, s)])
        return [x for x in filter(lambda y: y, parms)]
    
    def replacehdr(self, hdr, new, same=False):
        if hdr and new:
            hl = hdr.lower()
            self.chgheaders.add(hl)
            if same:
                name = hdr
            else:
                name = hdr.capitalize()
            newh = [ name ]
            if new:
                snew = str(new)
                if hl in ('from', 'reply-to', 'to', 'cc', 'bcc'):
                    newh.extend([x for x in getbaseaddrs(snew)])
                else:
                    newh.append(snew)
            self.headers[hl] = newh

    def removehdr(self, hdr, same=False):
        return self.replacehdr(hdr, None, same)

    def changehdrs(self, old, new, *hdrs):
        for h in hdrs:
            hl = h.lower()
            if hl in self.headers:
                self.chgheaders.add(hl)
                items = self.headers[hl]
                if len(items) < 2:
                    continue
                newvs = [ items[0] ]
                for v in items[1:]:
                    newv = v
                    if not new:
                        if old and v == old:
                            newv = None
                    elif not old:
                        newv = copy.copy(str(new))
                    else:
                        newv = v.replace(str(old), str(new))
                    if newv:
                        newvs.append(newv)
                self.headers[hl] = newvs
        
    def hdraddr(self, key, format=True, brackets=False, tolower=True):
        key = utf8decode(key)
        if not key in self.headers:
            return None
        item  = self.headers[key]
        litem = len(item) if item else 0
        if litem < 1:
            return None
        elif litem < 2:
            item = item[0]
        else:
            item = item[1]
        if format:
            return baseaddr(item, brackets, tolower)
        else:
            return item

    def _fixbody(self, rbody):
        if not rbody:
            return rbody
        newbody = ''
        changed = False
        for line in rbody.rstrip().split('\n'):
            line = line.rstrip()
            m = ctypepat.search(line)
            if not m:
                newbody = '{}{}\n'.format(newbody, line)
                continue
            ctype = m.group(1)
            item0 = m.group(2)
            fname = m.group(3)
            item1 = m.group(4)
            m = imagepat.search(fname.lower())
            if not m:
                newbody = '{}{}\n'.format(newbody, line)
                continue
            itype = m.group(1)
            if itype == 'jpg':
                itype = 'jpeg'
            elif itype == 'tif':
                itype = 'tiff'
            newbody = '{}{}image/{}{}"{}"{}\n'.format(newbody, ctype, itype, item0, fname, item1)
##            xlog(r'=== application/octet-stream => image/{}'.format(itype))
            self.stream_log(r'=== application/octet-stream => image/{}'.format(itype))
            changed = True
        if changed:
            rbody = newbody
        return rbody

    def reconstruct(self):
        if self.newfrom is not None and len(self.newfrom) > 1:
            f = self.newfrom[0]
            p = self.newfrom[1]
            if not p:
                esmtpargs = None
            elif '__iter__' in set(dir(p)):
                esmtpargs = ' '.join(p)
            else:
                esmtpargs = str(p)
            self.chgfrom(f, esmtpargs)
        recipients = oset([x for x in self.rcpt])
        newrecips  = oset([])
        if self.chgrcpt is not None:
            for oldr,r in self.chgrcpt.items():
                newr = r[0]
                newl = r[1]
                self.delrcpt(oldr)
                recipients.discard(oldr)
                if newr:
                    self.addrcpt(newr, *newl)
                    recipients.add(newr)
                    newrecips.add(newr)
        toheaders = self.headers.get('to', [])
        if toheaders:
            toheaders = [baseaddr(x) for x in toheaders[1:]]
        toheaders = oset(toheaders)
        addtoheaders = oset([])
        if self.newrcpt is not None:
            for r,v in self.newrcpt.items():
                if r not in newrecips:
                    self.addrcpt(r, *v)
                    newrecips.add(r)
                if r not in toheaders:
                    addtoheaders.add(r)
                recipients.add(r)
        for hl, items in self.headers.items():
            if hl not in self.chgheaders:
                continue
            if len(items) < 2:
                continue
            k  = items[0]
            vs = items[1:]
            n  = len(vs)
            # get rid of old headers
            if hl == 'to':
                toheaders.discard(baseaddr(k))
            for i in range(n, 0, -1):
                self.chgheader(k, i - 1, '')
            # add replacement headers
            for v in vs:
                if not v or not v.strip():
                    continue
                self.addheader(k, v)
        if addtoheaders:
            for ath in addtoheaders:
                if ath:
                    self.addheader('To', ath)
        elif recipients and not toheaders:
            self.addheader('To', random.choice(recipients))
        if self.newbody is None:
            body = self.bodytext
        else:
            body = self.newbody
        if self.flags.get('_no_multipart_related_', False):
            body = body.replace('content-id:', 'x-xontent-xid:').replace('multipart/related', 'multipart/mixed')
        if body != self.bodytext:
            self.replacebody(body)
        self.verbose_log('=== reconstructed')
                        
    def messagetext(self):
        fullmsg = ''
        for hl, items in self.headers.items():
            if type(items) in (list, tuple, oset, sset) and len(items) > 1:
                k  = items[0]
                vs = items[1:]
                for v in vs:
                    if v is None:
                        continue
                    fullmsg += '{}: {}\n'.format(k, v)
        if len(fullmsg) > 0:
            fullmsg += '\n'
        if self.newbody is None:
            fullmsg += self.bodytext
        else:
            fullmsg += self.newbody
        return fullmsg

    def components(self):
        _, mbody, links, addrs, images = emailtotext(self.messagetext())
        if mbody is None:
            mbody, links, addrs = msgdecode(self.bodytext if self.newbody is None else self.newbody, ctype=contenttype)
            images = {}
        return (mbody, links, addrs, images)

    def makedinfo(self, *args):
        if len(args) < 1:
            return None
        to = args[0]
        try:
            u, d = parseaddress(to.lower())
        except Exception as e:
            return None
        domf  = os.path.join(vmutop, d, filterfile)
        userf = os.path.join(vmutop, d, u, filterfile)
        if d in self.rdominfo:
            dinfo = self.rdominfo[d]
        else:
            dinfo = []
        if domf not in dinfo:
            dinfo.append(domf)
        if userf not in dinfo:
            dinfo.append(userf)
        self.rdominfo[d] = dinfo
        return d

    def storeheader(self, name, hval):
        lname = name.lower()
        h = self.headers.get(lname, [ name ])
        if hval:
            h.append(hval)
        else:
            h.append(None)
        self.headers[lname] = h
        
    def changefrom(self, newmf):
        # must run at eoh or later
        mf = copy.copy(self.mailfrom)
        self.mailfrom = newmf
        self.newfrom  = [ '<{}>'.format(self.mailfrom), self.fromparms ]
        self.changehdrs(mf, newmf, 'from', 'reply-to', 'received')
        
    def changeto(self, mt, newmt):
        # must run at eoh or later
        if not mt:
            return
        if newmt is None:
            newmt = ''
        for r,ri in self.rcpt.items():
            rlist = []
            changed = False
            rcpt = ncsub(r, mt, newmt)
            if rcpt != r:
                changed = True
            for i in ri:
                newitem = ncsub(i, mt, newmt)
                if newitem != i:
                    changed = True
                rlist.append(newitem)
            if not changed:
                continue
            self.chgrcpt[r] = [rcpt, rlist]
        self.changehdrs(mt, newmt, 'To', 'Cc', 'Bcc', 'Received')

    def addto(self, toaddr, *args):
        if toaddr:
            self.newrcpt[baseaddr(toaddr)] = list(*args)
            
    def removeto(self, rcpt):
        # must run at eoh or later
        if not rcpt:
            return
        rcpt = baseaddr(rcpt)
        if rcpt not in self.rcpt:
            return
        self.chgrcpt[rcpt] = [ None, [] ]
        self.changehdrs(rcpt, None, 'To', 'Cc', 'Bcc', 'Received')
    delto = removeto
    deleteto = removeto

    def gettext(self, *files):
        if self.dirset is None or len(self.dirset) < 1 or files is None or len(files) < 1:
            return None
        for d in self.dirset:
            for ff in files:
                f = os.path.join(d, ff)
##                with Protection('gettext handle file'):
                with Protection('gettext handle file'):
                    with ljz.u._open(f, 'rb') as fh:
                        result = fh.read()
                        if result:
                            text = utf8decode(result).strip()
                            if text:
                                # Return the readable text from the first non-empty file found.
                                return text + '\n'
        return None
    
    def textmatch(self, text, *files):
        text = utf8decode(text)
        if self.dirset is None or len(self.dirset) < 1 or text is None or files is None or len(files) < 1:
            return False
        seen = oset([])
        for d in self.dirset:
            d = utf8decode(d)
            for ff in files:
                ff = utf8decode(ff)
                f = os.path.join(d, ff)
                try:
                    pats = makematchpats(f, multiline=True)
                except Exception as e:
                    continue
                for p in pats:
                    patpat = p.pattern
                    if patpat in seen:
                        continue
                    seen.add(patpat)
                    if p.search(text):
                        self.verbose_log('=== text match: {}'.format(shortname(f)))
                        return True
        return False

    def addrmap(self, addrinfo, *files):
        global _addrmaps
        if '_addrmap_quiet_' in self.flags:
            quiet = True
            del self.flags['_addrmap_quiet_']
        else:
            quiet = False
        if self.dirset is None or len(self.dirset) < 1 or addrinfo is None or files is None or len(files) < 1:
            return False
        if type(addrinfo) not in (list, tuple, set, oset, sset):
            addrinfo = [addrinfo]
        seen = oset([])
        for addr in addrinfo:
            addr = utf8decode(addr)
            for d in self.dirset:
                for ff in files:
                    ff    = utf8decode(ff)
                    f     = os.path.join(d, ff)
                    ts    = None
                    inode = None
                    try:
                        rpf   = os.path.realpath(f)
                        ts    = os.path.getmtime(rpf)
                        inode = '{:016x}'.format(ctypes.c_ulong(os.stat(rpf).st_ino).value)
                    except:
                        continue
                    finfo = _addrmaps.get(inode, None)
                    doit  = True
                    if finfo:
                        fts, pats, matches = finfo
                        if fts and (fts == ts):
                            doit = False
                    if doit:
                        try:
                            pats, matches    = makeaddrmatchpats(f)
                            _addrmaps[inode] = [ ts, pats, matches ]
                            if finfo is not None:
                                self.stdout_stream_log('=== reloaded addrmap {}'.format(f))
                        except Exception as e:
##                            xmlog('!!! failed to load addrmap {}: {}'.format(f, e))
                            self.stdout_stream_log('!!! failed to load addrmap {}: {}'.format(f, e))
                            continue
                    for p in pats:
                        patpat = p.pattern
                        if patpat in seen:
                            continue
                        seen.add(patpat)
                        if p.search(addr):
                            if p in matches:
                                m = matches[p]
                            else:
                                m = []
                            if not quiet:
##                                vlog('=== addr match: {}: {} {}'.format(shortname(f), addr, m))
                                self.verbose_log('=== addr match: {}: {} {}'.format(shortname(f), addr, m))
                            return (True, m)
        return (False, [])

    def addrmatch(self, addrinfo, *files):
        result, matches = self.addrmap(addrinfo, *files)
        return result
    
    def cmap(self):
        return connect_map
    
    def __filter(self, which, *args):
        if '_stop_' in self.flags:
            return None
        if args is None:
            data = None
            args = []
        elif len(args) < 1:
            data = None
        else:
            data = args[0]
        if data is None and self.rcpt is not None:
            newfset = oset([])
            for r,v in self.rcpt.items():
##                with Protection('__filter parse address', log=ljz.o.xlog):
                with Protection('__filter parse address', log=ljz.o.xlog):
                    d = parseaddress(r.lower())[1]
                    if d in self.rdominfo:
                        newfset.update(self.rdominfo[d])
            self.fset = oset(list(newfset) + list(self.fset))
        elif self.rdominfo is not None and data in self.rdominfo:
            self.fset = oset(self.rdominfo[data] + list(self.fset))
        self.fset.update(sorted(glob.glob(filterglob)))
        self.dirset = oset([ self.topdir ] + [ os.path.dirname(x) for x in self.fset ])
        flist = list(self.fset)
        while len(flist) > 0:
            self.dirchain = [ self.topdir ] + [ os.path.dirname(x) for x in flist ]
            f = flist[0]
            flist = flist[1:]
            with ljz.l._hippolock():
                result = self.pmfilter(which, f, *args)
            if type(result) in (tuple, list, oset, sset):
                # Result is a vector.
                nresult = len(result)
                if nresult < 1:
                    # Empty list or empty tuple: continue processing
                    # more filters.
                    pass
                elif nresult < 2:
                    # Only one item: if it's not None return it;
                    # otherwise, keep processing more filters.
                    if result[0] is not None:
                        return result[0]
                elif result[0] is None:
                    # At least two items. First item is None: continue
                    # processing more filters.
                    pass
                elif result[1] is True:
                    # At least two items. First item is not None and
                    # second item is explicitly True. Return the first
                    # item and stop processing any more filters.
                    self.flags['_stop_'] = True
##                    slog('=== filter processing stopped by [{}]'.format(name))
                    self.sys_stream_slog('=== filter processing stopped by [{}]'.format(name))
                    return result[0]
                else:
                    # At least two items. First item is not None and
                    # second item is not an explicit True. Return the
                    # first item and set the reply string to the result of
                    # properly reformatting the second through nth items.
                    reply = ljz.ecode(*(result[1:]))
                    self.setreply(*reply)
                    return result[0]
            elif result is not None:
                return result
        return None

    def _runpm(self):
        return run_pm_filters()

    def _isactive(self):
        return self._runpm()
    
    def filter(self, which, *args):
        rc = self.__filter(which, *args)
        if rc == self.Discard():
            try:
                r = list(self.rcpt)[0].lower()
                try:
                    recipient = '@'.join(parseaddress(r))
                except:
                    recipient = r
            except:
                recipient = 'UNKNOWN@RECIPIENT.TLD'
            msg = '=== discarding: from=<{}> to=<{}>'.format(self.mailfrom, recipient)
            self.sys_slog(msg)
        return rc
    
    def loadfilter(self, path, context):
        global filterinfo
        goodtext  = 'loadfilter success'
        errortext = 'loadfilter failure'
        try:
            spath = os.path.realpath(os.path.expanduser(path))
        except Exception as e:
            self.stdout_log('!!! loadfilter: invalid filter file: {} - {}'.format(e, path))
            return None
        try:
            ts = os.path.getmtime(spath)
        except:
##            with Protection('loadfilter cleanup'):
            with Protection('loadfilter cleanup'):
                del filterinfo[spath]
            return None
        prefix = ''
        suffix = 'file'
        def _getcode(p):
            try:
                with ljz.u._open(p, 'rb') as f:
                    source = f.read()
            except Exception as e:
                self.stream_vlog(ljz.o._msgbanner(errortext,
                                                  '!!! unable to open filter file: {} - {}'.format(shortname(p), e),
                                                  char='#'))
                return (False, None)
            try:
                codeobj = compile(source, p, 'exec')
                return (True, codeobj)
            except Exception as e:
                self.stream_vlog(ljz.o._msgbanner(errortext,
                                                  '!!! uncompilable filter file: {} - {}'.format(shortname(p), e),
                                                  char='#'))
##hippo
                _, codeobj = filterinfo.get(spath, [None, None])
                if codeobj:
                    filterinfo[spath] = (ts, codeobj)
                prefix = 're'
                suffix = 'code'
                return (False, codeobj)
##                return None
##hippo end
        newcode = False
        if spath in filterinfo:
            fts, codeobj = filterinfo[spath]
            if fts != ts:
                isnew, codeobj = _getcode(spath)
                if not codeobj:
                    return None
                newcode = isnew
        else:
            isnew, codeobj = _getcode(spath)
            if not codeobj:
                return None
            newcode = isnew
        isvalid  = False
        codetype = type(codeobj)
        for co in codeobj.co_consts:
            if type(co) is codetype and co.co_name in validfuncs:
                isvalid = True
                break
        codefile = os.path.basename(codeobj.co_filename)
        if not isvalid:
            self.stream_vlog(ljz.o._msgbanner(errortext,
                                              '!!! loadfilter: not a filter file: {}'.format(codefile),
                                              char='#'))
##            with Protection('loadfilter cleanup'):
            with Protection('loadfilter cleanup'):
                del filterinfo[spath]
            return None
        if newcode:
            self.stream_vlog(ljz.o._msgbanner(goodtext,
                                              '{}loading filter {}: {}'.format(prefix, suffix, codefile),
                                              char='='))
            filterinfo[spath] = (ts, codeobj)
        try:
            ctx = context.copy()
            exec(codeobj, ctx)
            return ctx
        except:
            return None

    def pmfilter(self, which, filterfile, *args):

        if which is None or filterfile is None or (not os.path.exists(filterfile)):
            return (None, None)

        if args is None:
            args = []
            
        g = copy.copy(globals())
        g['_xxlog'] = self.stdout_stream_log
        g['_xolog'] = self.stdout_log
        g['_xrlog'] = self.sys_log
        g['_xslog'] = self.sys_stream_slog
        g['_vvlog'] = self.stream_vvlog
        ctx = self.loadfilter(filterfile, g)
        if ctx is None:
            return (None, None)
        elif which in ctx:
            func = ctx[which]
        else:
            return (None, None)

        tested = False
        if 'enabled' in ctx:
            # We're only here if an enabled() guard exists.
            # If not, we just proceed.
            enabled = ctx['enabled']
            try:
                e = enabled(self, which, *args)
                # explicit False: do not run filter
                # anything True:  run filter
                # implicit False: run filter if no authuser
                if e is False:
                    self.stream_vvlog('=== not enabled: [{}] {}'.format(which, shortname(filterfile)))
                    return (None, None)
                elif e:
                    tested = True
            except:
                # We are only here if the existing enabled() guard
                # threw an exception. Treat this as if the enabled
                # function doesn't even exist, so 'tested' remains
                # False.
                pass

        if not tested:
            if self.authuser is not None:
                # If there is no enabled() guard and if there is
                # an authorized user, don't run the filter.
                self.stream_vvlog('=== auth user [{}]: skipped: [{}] {}'.format(self.authuser, which, shortname(filterfile)))
                return (None, None)

        try:
            result = func(self, *args)
            if which not in skipfiltlog:
                rcresult = self._result(result)
                self.verbose_log('=== [{}] {} => {}'.format(which, shortname(filterfile), rcresult))
                rc = self._rc(result)
                if rc not in (None, self.Continue()):
                    self.stream_log('=== [{}] => {}'.format(which, rcresult))
            return result
        except Exception as e:
            self.sys_log('!!! pmfilter exception: {}: {} {}'.format(e, shortname(filterfile), args))
            strace()
            return (None, None)

def shortname(file):
    if file is None:
        return None
    t, b = os.path.split(file)
    if len(t) < 0:
        return b
    else:
        return os.path.join(os.path.basename(t), b)

def makematchpats(fname, multiline=False):
    pats = []
    if multiline:
        reflags = (re.I | re.S)
    else:
        reflags = re.I
##    with Protection('makematchpats'):
    with Protection('makematchpats'):
        with ljz.u._open(fname, 'rb') as f:
            for line in f:
                line = commentpat.sub('', utf8decode(line)).rstrip()
                if len(line) < 1:
                    continue
                items = line.split()
                if len(items) < 1:
                    continue
                pat = items[0]
                try:
                    cpat = re.compile(pat, reflags)
                    pats.append(cpat)
                except Exception as e:
                    ljz.o.sslog('!!! exception {}, fname: {}, invalid pattern: {}'.format(e, fname, pat))
    return pats
    
def makeaddrmatchpats(fname):
    pats = []
    matches = {}
##    with Protection('makeaddrmatchpats'):
    with Protection('makeaddrmatchpats'):
        with ljz.u._open(fname, 'rb') as f:
            for line in f:
                line = commentpat.sub('', utf8decode(line)).rstrip()
                if len(line) < 1:
                    continue
                items = line.split()
                if len(items) < 1:
                    continue
                item = items[0]
                pat = '^{}$'.format(item.replace(r'.', r'\.')
                                        .replace('?', '.?')
                                        .replace(r'*', r'.*?')
                                        .replace(r'=', r'([a-z0-9-]+\.)*?'))
##                                        .replace(r'@=', r'@(\S+?\.)*?'))
                try:
                    cpat = re.compile(pat, re.I)
                    pats.append(cpat)
                    if len(items) > 1:
                        matches[cpat] = items[1:]
                    else:
                        matches[cpat] = []
                except Exception as e:
                    ljz.o.sslog('!!! exception {}, fname: {}, invalid pattern: {}'.format(e, fname, pat))
    return (pats, matches)
            
if __name__ == '__main__':
    try:
        sys.exit(main())
    except Exception as e:
        _our_sys_log('!!! exception: {}'.format(e,))
        strace(logger=_our_sys_log)
        sys.exit(-1)