def testCookieErrorToLog(self):
from zope.testing.loggingsupport import InstalledHandler
cookies = {
'HTTP_COOKIE':
'foo=bar; path=/; spam="eggs"; ldap/OU="Williams"'
}
handler = InstalledHandler('eventlog')
try:
req = self._createRequest(extra_env=cookies)
finally:
handler.uninstall()
self.assertEqual(len(handler.records), 1)
self.assertEqual(handler.records[0].getMessage(),
'Illegal key value: ldap/OU')
self.assertFalse(req.cookies.has_key('foo'))
self.assertFalse(req.has_key('foo'))
self.assertFalse(req.cookies.has_key('spam'))
self.assertFalse(req.has_key('spam'))
self.assertFalse(req.cookies.has_key('ldap/OU'))
self.assertFalse(req.has_key('ldap/OU'))
# Reserved key
self.assertFalse(req.cookies.has_key('path'))
def testCookieErrorToLog(self):
from zope.testing.loggingsupport import InstalledHandler
cookies = {
'HTTP_COOKIE':
'foo=bar; path=/; spam="eggs"; ldap/OU="Williams"'
}
handler = InstalledHandler('eventlog')
try:
req = self._createRequest(extra_env=cookies)
finally:
handler.uninstall()
self.assertEqual(len(handler.records), 1)
message = handler.records[0].getMessage()
self.assertTrue(message.startswith('Illegal key'))
self.assertIn('ldap/OU', message)
self.assertNotIn('foo', req.cookies)
self.assertNotIn('foo', req)
self.assertNotIn('spam', req.cookies)
self.assertNotIn('spam', req)
self.assertNotIn('ldap/OU', req.cookies)
self.assertNotIn('ldap/OU', req)
# Reserved key
self.assertNotIn('path', req.cookies)
class Futures(RemoteLibrary):
def start_futures_logging(self):
self._v_record = InstalledHandler('experimental.futures',
level=logging.DEBUG)
def get_futures_log(self):
return unicode(self._v_record)
def stop_futures_logging(self):
self._v_record.uninstall()
def test_search_for_factory_updates_search_set(self):
from zope.testing.loggingsupport import InstalledHandler
with warnings.catch_warnings(record=True):
INT.register_legacy_search_module(__name__)
# The cache is initialized lazily
assert_that(__name__, is_in(INT.LEGACY_FACTORY_SEARCH_MODULES))
assert_that(INT.find_factory_for_class_name('testfunctions'),
is_(none()))
# And we have been examined and removed
assert_that(__name__,
is_not(is_in(INT.LEGACY_FACTORY_SEARCH_MODULES)))
assert_that(INT.LEGACY_FACTORY_SEARCH_MODULES, is_(set()))
# Now we're going to fiddle with our public classes and try again.
# This will force re-registration to occur. Note we do this before
# we make ourself public, so that we can assert it's lazy
INT.register_legacy_search_module(__name__)
TestFunctions.__external_can_create__ = True
handler = InstalledHandler(INT.__name__)
try:
assert_that(INT.find_factory_for_class_name('testfunctions'),
equal_to(TestFunctions))
# Now lets register ourself again, to trigger the logged warnings.
assert_that(__name__,
is_not(is_in(INT.LEGACY_FACTORY_SEARCH_MODULES)))
assert_that(INT.LEGACY_FACTORY_SEARCH_MODULES, is_(set()))
# Now we're going to fiddle with our public classes and try again.
# This will force re-registration to occur. Note we do this before
# we make ourself public, so that we can assert it's lazy
INT.register_legacy_search_module(__name__)
assert_that(INT.find_factory_for_class_name('testfunctions'),
equal_to(TestFunctions))
# case doesn't matter
assert_that(INT.find_factory_for_class_name('TeStfUnctIons'),
equal_to(TestFunctions))
assert_that(
str(handler),
contains_string(
"Found duplicate registration for legacy search path.")
)
assert_that(INT.legacy_factories.count_legacy_classes_found(),
greater_than_or_equal_to)
finally:
del TestFunctions.__external_can_create__
handler.uninstall()
class Futures(RemoteLibrary):
def start_futures_logging(self):
self._v_record = InstalledHandler('experimental.futures',
level=logging.DEBUG)
def get_futures_log(self):
return unicode(self._v_record)
def stop_futures_logging(self):
self._v_record.uninstall()
def test_log_info(self):
from zope.server import zlogintegration
from zope.testing.loggingsupport import InstalledHandler
handler = InstalledHandler('zope.server')
try:
zlogintegration.log_info(None, "Some Info")
finally:
handler.uninstall()
self.assertEqual(1, len(handler.records))
self.assertEqual("Some Info", str(handler.records[0].getMessage()))
def test_log_info(self):
from zope.server import zlogintegration
from zope.testing.loggingsupport import InstalledHandler
handler = InstalledHandler('zope.server')
try:
zlogintegration.log_info(None, "Some Info")
finally:
handler.uninstall()
self.assertEqual(1, len(handler.records))
self.assertEqual("Some Info", str(handler.records[0].getMessage()))
def test_jsonifier(self):
from zope.testing.loggingsupport import InstalledHandler
handler = InstalledHandler('newt.db.jsonpickle')
from ..jsonpickle import Jsonifier
jsonifier = Jsonifier()
p, tid = self.conn._storage.load(z64)
class_name, ghost_pickle, state = jsonifier('0', p)
self.assertEqual('persistent.mapping.PersistentMapping', class_name)
self.assertEqual('{"data": {}}', state)
self.assertTrue(
p.startswith(ghost_pickle) and ghost_pickle[-1:] == b'.'
and b'persistent.mapping' in ghost_pickle)
# custon skip_class
jsonifier2 = Jsonifier(skip_class=lambda c: 1)
self.assertEqual((None, None, None), jsonifier2('0', p))
# empty records are skipped:
self.assertEqual((None, None, None), jsonifier('0', ''))
# BTrees are skipped by default
from BTrees.OOBTree import BTree
self.root.x = BTree()
self.conn.transaction_manager.commit()
p, tid = self.conn._storage.load(self.root.x._p_oid)
self.assertEqual((None, None, None), jsonifier('0', p))
# errors are logged, and return Nones:
self.assertEqual(handler.records, [])
self.assertEqual((None, None, None), jsonifier('foo', b'badness'))
self.assertEqual(
[r.getMessage().replace("b'", "'") for r in handler.records],
["Failed pickle load, oid: 'foo', pickle starts: 'badness'"])
handler.uninstall()
def testBrokenMailerErrorsAreEaten(self):
from zope.testing.loggingsupport import InstalledHandler
from zope.sendmail.delivery import DirectMailDelivery
mailer = BrokenMailerStub()
delivery = DirectMailDelivery(mailer)
fromaddr = 'Jim <*****@*****.**'
toaddrs = ('Guido <*****@*****.**>',
'Steve <steve@examplecom>')
opt_headers = ('From: Jim <*****@*****.**>\n'
'To: some-zope-coders:;\n'
'Date: Mon, 19 May 2003 10:17:36 -0400\n'
'Message-Id: <*****@*****.**>\n')
message = ('Subject: example\n'
'\n'
'This is just an example\n')
msgid = delivery.send(fromaddr, toaddrs, opt_headers + message)
log_handler = InstalledHandler('MailDataManager')
try:
transaction.commit()
finally:
# Clean up after ourselves
log_handler.uninstall()
transaction.abort()
class TestLongRequestLogger(unittest.TestCase):
def setUp(self):
from Products.LongRequestLogger.patch import do_patch
from Products.LongRequestLogger.dumper import logger_name
from zope.testing.loggingsupport import InstalledHandler
self.setTestEnvironment()
do_patch()
self.loghandler = InstalledHandler(logger_name)
self.requests = []
def tearDown(self):
from Products.LongRequestLogger.patch import do_unpatch
do_unpatch()
self.restoreTestEnvironment()
self.loghandler.uninstall()
for request in self.requests:
request.response.stdout.close()
request.clear()
def setTestEnvironment(self):
self.old_env = {}
for var, value in config_env_variables.items():
self.old_env[var] = os.environ.pop(var, None)
if value:
os.environ[var] = value
def restoreTestEnvironment(self):
for var, value in self.old_env.items():
os.environ.pop(var, None)
if value is not None:
os.environ[var] = value
def makeRequest(self, path='/', **kw):
# create fake request and response for convenience
from ZPublisher.HTTPRequest import HTTPRequest
from ZPublisher.HTTPResponse import HTTPResponse
stdin = StringIO()
stdout = StringIO()
# minimal environment needed
env = dict(SERVER_NAME='localhost',
SERVER_PORT='80',
REQUEST_METHOD='GET',
SCRIPT_NAME=path)
response = HTTPResponse(stdout=stdout)
request = HTTPRequest(stdin, env, response)
self.requests.append(request)
return request
def testDumperFormat(self):
from Products.LongRequestLogger.dumper import Dumper
dumper = Dumper()
check_dump(dumper.format_thread())
def testDumperRequestExtraction(self):
# The dumper extract requests by looking for the frame that contains
# call_object and then looking for the 'request' variable inside it
from ZPublisher.Publish import call_object
from Products.LongRequestLogger.dumper import Dumper
def callable():
dumper = Dumper()
frame = sys._current_frames()[dumper.thread_id]
return dumper.extract_request(frame)
request = self.makeRequest('/foo')
retrieved_request = call_object(callable, (), request)
self.assertTrue(request is retrieved_request)
def testRequestFormating(self):
from Products.LongRequestLogger.dumper import Dumper
dumper = Dumper()
request = self.makeRequest('/foo/bar')
check_request_formating(dumper.format_request(request))
def testDumperLog(self):
from Products.LongRequestLogger.dumper import Dumper
dumper = Dumper()
# check the dumper will log what we expect when called
dumper()
check_log(str(self.loghandler))
def testMonitorStopBeforeTimeout(self):
from Products.LongRequestLogger.monitor import Monitor
m = Monitor()
# sleep just a little to let the other thread start
s = Sleeper(0.01)
s.sleep()
self.assertTrue(m.isAlive())
m.stop()
self.assertFalse(m.isAlive())
# unless this test is so slow that there were 2 seconds interval
# between starting the monitor and stopping it, there should be no
# logged messages
self.assertFalse(self.loghandler.records)
def testMonitorStopAfterTimeout(self):
from Products.LongRequestLogger.monitor import Monitor
m = Monitor()
s = Sleeper(m.dumper.timeout + 0.5)
# sleep a little more than the timeout to be on the safe side
s.sleep()
m.stop()
check_monitor_log(str(self.loghandler))
def testMonitorStopAfterTimeoutAndTwoIntervals(self):
from Products.LongRequestLogger.monitor import Monitor
m = Monitor()
s = Sleeper(m.dumper.timeout + 2 * m.dumper.interval + 0.5)
# sleep a little more than timeout + intervals to be on the safe
# side
s.sleep()
m.stop()
check_monitor_2_intervals_log(str(self.loghandler))
def testMonitorConfigurationDisabled(self):
from Products.LongRequestLogger.monitor import Monitor
from Products.LongRequestLogger.dumper import DEFAULT_TIMEOUT
from Products.LongRequestLogger.dumper import DEFAULT_INTERVAL
os.environ['longrequestlogger_file'] = ''
m = Monitor()
s = Sleeper(DEFAULT_TIMEOUT + 2 * DEFAULT_INTERVAL + 0.5)
# sleep a little more than timeout + intervals
s.sleep()
# the thread shouldn't run disabled
self.assertFalse(m.isAlive())
# stopping shouldn't break nonetheless
m.stop()
self.assertFalse(m.isAlive())
# and there should be no records
self.assertFalse(self.loghandler.records)
def testMonitorWithEnvironmentConfiguration(self):
from Products.LongRequestLogger.monitor import Monitor
os.environ['longrequestlogger_timeout'] = '3.5'
os.environ['longrequestlogger_interval'] = '2'
m = Monitor()
s = Sleeper(m.dumper.timeout + m.dumper.interval + 0.5)
# sleep a little more than the timeout to be on the safe side
s.sleep()
m.stop()
check_monitor_environment_log(str(self.loghandler))
def testIsPatched(self):
import ZPublisher.Publish
import Products.LongRequestLogger
self.assertEquals(ZPublisher.Publish.publish_module_standard,
Products.LongRequestLogger.patch.wrapper)
def testPublish(self):
from ZPublisher.Publish import publish_module_standard
# Before publishing, there should be no slow query records.
self.assertFalse(self.loghandler.records)
# Request taking (timeout + interval + margin) 3.5 seconds...
request = self.makeRequest('/', interval=3.5)
request['interval'] = 3.5
publish_module_standard('Products.LongRequestLogger.tests.common',
request=request,
response=request.response,
debug=True)
# ...should generate query log records like these
check_publishing_1_interval_log(str(self.loghandler))
class TestLongRequestLogger(unittest.TestCase):
def setUp(self):
from Products.LongRequestLogger import do_patch, monitor, dumper
from zope.testing.loggingsupport import InstalledHandler
dumper.config = dict(logfile=os.devnull)
log = dumper.getLogger()
self.monitor = monitor.Monitor(log, **dumper.get_configuration())
do_patch(self.monitor)
self.loghandler = InstalledHandler(log.name)
self.requests = []
def tearDown(self):
from Products.LongRequestLogger import do_unpatch
do_unpatch()
self.monitor.stop()
self.loghandler.uninstall()
for request in self.requests:
request.response.stdout.close()
request.clear()
def makeRequest(self, path='/', **kw):
# create fake request and response for convenience
from ZPublisher.HTTPRequest import HTTPRequest
from ZPublisher.HTTPResponse import HTTPResponse
stdin = StringIO()
stdout = StringIO()
# minimal environment needed
env = dict(SERVER_NAME='localhost',
SERVER_PORT='80',
REQUEST_METHOD='GET',
SCRIPT_NAME=path)
response = HTTPResponse(stdout=stdout)
request = HTTPRequest(stdin, env, response)
self.requests.append(request)
return request
def testDumperFormat(self):
from Products.LongRequestLogger.dumper import Dumper
dumper = Dumper()
check_dump(dumper.format_thread())
def testDumperRequestExtraction(self):
# The dumper extract requests by looking for the frame that contains
# call_object and then looking for the 'request' variable inside it
from ZPublisher.Publish import call_object
from Products.LongRequestLogger.dumper import Dumper
def callable():
dumper = Dumper()
frame = sys._current_frames()[dumper.thread_id]
return dumper.extract_request(frame)
request = self.makeRequest('/foo')
retrieved_request = call_object(callable, (), request)
self.assertTrue(request is retrieved_request)
def testRequestFormating(self):
from Products.LongRequestLogger.dumper import Dumper
dumper = Dumper()
request = self.makeRequest('/foo/bar')
check_request_formating(dumper.format_request(request))
def testPublish(self):
from ZPublisher.Publish import publish_module_standard
# Before publishing, there should be no slow query records.
self.assertFalse(self.loghandler.records)
# Request taking (timeout + interval + margin) 3.5 seconds...
request = self.makeRequest('/', interval=3.5)
request['interval'] = 3.5
publish_module_standard('Products.LongRequestLogger.tests.common',
request=request,
response=request.response,
debug=True)
# ...should generate query log records like these
check_publishing_1_interval_log(str(self.loghandler))
class FunctionalTestAweber(FunctionalTestCase):
"""Functional test of Aweber."""
def setUp(self):
"""Prepare testing environment."""
self.portal = self.layer['portal']
self.registry = getUtility(IRegistry)
self.settings = self.registry.forInterface(IAweberSettings)
self.settings.app_id = u'appid'
self.settings.authorization_code = u'authorizationcode'
self.settings.consumer_key = u'consumerkey'
self.settings.consumer_secret = u'consumersecret'
self.settings.access_token = u'accesstoken'
self.settings.access_secret = u'accesssecret'
transaction.commit()
self.browser = Browser(self.portal)
self.login_as_admin()
# install a testing log handler
self.logger = InstalledHandler('niteoweb.aweber')
def tearDown(self):
"""Clean up after yourself."""
# logout
self.browser.open(self.portal.absolute_url() + '/logout')
# reset our mocked logger
self.logger.uninstall()
self.logger.clear()
def test_controlpanel_view(self):
"""Test for control panel view."""
self.browser.open(self.portal.absolute_url() + "/@@aweber-settings")
self.assertEqual(
self.browser.url,
'http://nohost/plone/@@aweber-settings',
)
self.assertIn(
'<h1 class="documentFirstHeading">Aweber settings</h1>',
self.browser.contents,
)
def test_save(self):
"""Test save button."""
self.browser.open(self.portal.absolute_url() + "/@@aweber-settings")
self.browser.getControl(name='form.widgets.app_id').value = \
u'temp_app_id'
self.browser.getControl(name="form.buttons.save").click()
# test if value is saved
self.assertEqual(
self.settings.app_id,
u'temp_app_id'
)
def test_cancel(self):
"""Test cancel button."""
self.browser.open(self.portal.absolute_url() + "/@@aweber-settings")
self.browser.getControl(name='form.widgets.app_id').value = \
u'temp_app_id'
self.browser.getControl(name="form.buttons.cancel").click()
# test if value is unchanged
self.assertEqual(
self.settings.app_id,
u'appid'
)
def test_get_auth(self):
"""Test get authorization code button."""
self.browser.open(self.portal.absolute_url() + "/@@aweber-settings")
self.browser.getControl(name="form.buttons.get_auth").click()
url = "https://auth.aweber.com/1.0/oauth/authorize_app/{0}".format(
self.browser.getControl(name="form.widgets.app_id").value
)
message = "Visit '{0}' and copy authorization code " \
"to Authorization Code field".format(url)
self.assertIn(message, self.browser.contents)
@patch("niteoweb.aweber.controlpanel.parse_auth_code")
@patch("niteoweb.aweber.controlpanel.set_list_names")
def test_parse_auth(self, set_list_names, parse_auth_code):
"""Test get authorization code button."""
self.browser.open(self.portal.absolute_url() + "/@@aweber-settings")
self.browser.getControl(name="form.buttons.parse_auth").click()
assert set_list_names.called
assert parse_auth_code.called
@patch("niteoweb.aweber.controlpanel.set_list_names")
def test_update_lists(self, set_list_names):
"""Test update lists button."""
self.browser.open(self.portal.absolute_url() + "/@@aweber-settings")
self.browser.getControl(name="form.buttons.update_lists").click()
assert set_list_names.called
@patch("niteoweb.aweber.aweberapi.subscribe_to_aweber_mailinglist")
def test_subscribe_user(self, subscribe):
"""Test subscribe user button."""
self.browser.open(self.portal.absolute_url() + "/@@aweber-settings")
self.browser.getControl(name="form.buttons.subscribe_user").click()
assert subscribe.called
class TestLongRequestLogger(unittest.TestCase):
def setUp(self):
from Products.LongRequestLogger import do_patch, monitor, dumper
from zope.testing.loggingsupport import InstalledHandler
dumper.config = dict(logfile=os.devnull)
log = dumper.getLogger()
self.monitor = monitor.Monitor(log, **dumper.get_configuration())
do_patch(self.monitor)
self.loghandler = InstalledHandler(log.name)
self.requests = []
def tearDown(self):
from Products.LongRequestLogger import do_unpatch
do_unpatch()
self.monitor.stop()
self.loghandler.uninstall()
for request in self.requests:
request.response.stdout.close()
request.clear()
def makeRequest(self, path='/', **kw):
# create fake request and response for convenience
from ZPublisher.HTTPRequest import HTTPRequest
from ZPublisher.HTTPResponse import HTTPResponse
stdin = StringIO()
stdout = StringIO()
# minimal environment needed
env = dict(SERVER_NAME='localhost',
SERVER_PORT='80',
REQUEST_METHOD='GET',
SCRIPT_NAME=path)
response = HTTPResponse(stdout=stdout)
request = HTTPRequest(stdin, env, response)
self.requests.append(request)
return request
def testDumperFormat(self):
from Products.LongRequestLogger.dumper import Dumper
dumper = Dumper()
check_dump(dumper.format_thread())
def testDumperRequestExtraction(self):
# The dumper extract requests by looking for the frame that contains
# call_object and then looking for the 'request' variable inside it
from ZPublisher.Publish import call_object
from Products.LongRequestLogger.dumper import Dumper
def callable():
dumper = Dumper()
frame = sys._current_frames()[dumper.thread_id]
return dumper.extract_request(frame)
request = self.makeRequest('/foo')
retrieved_request = call_object(callable, (), request)
self.assertTrue(request is retrieved_request)
def testRequestFormating(self):
from Products.LongRequestLogger.dumper import Dumper
dumper = Dumper()
request = self.makeRequest('/foo/bar')
check_request_formating(dumper.format_request(request))
def testPublish(self):
from .common import Sleeper
from ZPublisher.Publish import publish_module_standard
# Before publishing, there should be no slow query records.
self.assertFalse(self.loghandler.records)
request = self.makeRequest('/')
# 1. All information is dumped on initial timeout.
# 2. 1 second later, a single line is logged
# because there's no new information.
# 3. Only the traceback changes and it is logged
# without request information.
# 4. The request changes with same traceback:
# only the request is logged.
# 5. The request changes with different traceback: full dump.
request['sleeper'] = Sleeper(3.5, 2, 1, 4.5)
publish_module_standard(Sleeper.__module__,
request=request,
response=request.response,
debug=True)
# ...should generate query log records like these
check_publishing_1_interval_log(str(self.loghandler))
