def test_log_to_file(self):
"""
Test
"""
log_file = "/tmp/pythonsol_unittest.log"
# Clean
if FileUtility.is_file_exist(log_file):
os.remove(log_file)
# Init
SolBase.logging_init(log_level="INFO",
log_to_file=log_file,
log_to_console=True,
log_to_syslog=False,
log_callback=self._on_log,
force_reset=True)
SolBase.set_compo_name("COMPO_XXX")
# Emit a log
logger.info("TEST LOG 888")
# Emit a log (str)
logger.info(u"BUF \u001B\u0BD9\U0001A10D\u1501\xc3 FUB")
# Check the file
buf = FileUtility.file_to_textbuffer(log_file, "utf-8")
self.assertIsNotNone(buf)
self.assertGreaterEqual(buf.find("TEST LOG 888"), 0)
self.assertGreaterEqual(buf.find("BUF "), 0)
self.assertGreaterEqual(buf.find(" FUB"), 0)
self.assertGreaterEqual(
buf.find(u"BUF \u001B\u0BD9\U0001A10D\u1501\xc3 FUB"), 0)
# Simulate a log rotate : kick the file and touch it
os.remove(log_file)
FileUtility.append_text_to_file(log_file,
"TOTO\n",
"utf-8",
overwrite=False)
# Re-emit
logger.info("TEST LOG 999")
buf = FileUtility.file_to_textbuffer(log_file, "utf-8")
self.assertIsNotNone(buf)
self.assertGreaterEqual(buf.find("TOTO"), 0)
self.assertGreaterEqual(buf.find("TEST LOG 999"), 0)
def test_log_to_file_time_file_seconds(self):
"""
Test
"""
log_file = "/tmp/pythonsol_unittest.log"
# Clean
if FileUtility.is_file_exist(log_file):
os.remove(log_file)
for f in glob.glob("/tmp/pythonsol_unittest.log.*"):
os.remove(f)
# Init
SolBase.logging_init(log_level="INFO",
log_to_file=log_file,
log_to_console=True,
log_to_syslog=False,
log_callback=self._on_log,
force_reset=True,
log_to_file_mode="time_file_seconds")
SolBase.set_compo_name("COMPO_XXX")
# Emit a log
logger.info("TEST LOG 888")
# Emit a log (str)
logger.info(u"BUF \u001B\u0BD9\U0001A10D\u1501\xc3 FUB")
# Check the file
buf = FileUtility.file_to_textbuffer(log_file, "utf-8")
self.assertIsNotNone(buf)
self.assertGreaterEqual(buf.find("TEST LOG 888"), 0)
self.assertGreaterEqual(buf.find("BUF "), 0)
self.assertGreaterEqual(buf.find(" FUB"), 0)
self.assertGreaterEqual(
buf.find(u"BUF \u001B\u0BD9\U0001A10D\u1501\xc3 FUB"), 0)
# Wait 5 sec
for i in range(0, 10):
SolBase.sleep(1100)
logger.info("Log i=%s", i)
# Emit a log
logger.info("TEST LOG 999")
# We should have "pythonsol_unittest.log.*" but no more than 7
f_count = 0
for f in glob.glob("/tmp/pythonsol_unittest.log.*"):
logger.info("Found %s", f)
f_count += 1
self.assertGreater(f_count, 0)
self.assertLessEqual(f_count, 7)
# Reset
SolBase.logging_init("INFO", True)
def test_log_to_file_with_filter_greenlet(self):
"""
Test
"""
log_file = "/tmp/pythonsol_unittest.log"
# Clean
if FileUtility.is_file_exist(log_file):
os.remove(log_file)
# Init
SolBase.logging_init(log_level="INFO",
log_to_file=log_file,
log_to_console=True,
log_to_syslog=False,
log_callback=self._on_log,
force_reset=True)
SolBase.set_compo_name("COMPO_XXX")
# Go
g1 = gevent.spawn(self._run_filter, "ip001")
g2 = gevent.spawn(self._run_filter, "ip002")
gevent.joinall([g1, g2])
# Re-read and check
buf = FileUtility.file_to_textbuffer(log_file, "utf-8")
self.assertGreaterEqual(buf.find("TEST LOG ip_addr=ip001"), 0)
self.assertGreaterEqual(buf.find("TEST LOG ip_addr=ip002"), 0)
# Via regex
for r, b in [
["TEST LOG ip_addr=ip001 | k_ip:ip001 z_value:ip001", True],
["TEST LOG ip_addr=ip002 | k_ip:ip002 z_value:ip002", True],
["TEST LOG ip_addr=ip001 | k_ip:ip002", False],
["TEST LOG ip_addr=ip002 | k_ip:ip001", False],
]:
idx = buf.find(r)
if b:
self.assertLess(0, idx, r)
else:
self.assertGreaterEqual(0, idx, r)
def _file_to_list(cls, file_name, sep="\n"):
"""
Load a file to a list, \n delimited
:param file_name: File name
:type file_name: str
:param sep: separator
:type sep: str
:return list
:rtype list
"""
ret = None
# noinspection PyBroadException,PyPep8
try:
if FileUtility.is_file_exist(file_name):
ret = FileUtility.file_to_textbuffer(file_name, "ascii")
except:
ret = None
finally:
if ret and len(ret) > 0:
return ret.split(sep)
else:
return list()
def test_start_status_reload_stop_logfile(self):
"""
Test
"""
try:
# Start
self._reset_std_capture()
main_helper_file = self.current_dir + "CustomDaemon.py"
main_helper_file = abspath(main_helper_file)
self.assertTrue(FileUtility.is_file_exist(main_helper_file))
# Params
ar = list()
ar.append(sys.executable)
ar.append(main_helper_file)
ar.append("-pidfile={0}".format(self.daemon_pid_file))
ar.append("-stderr={0}".format(self.daemon_std_err))
ar.append("-stdout=/dev/null")
ar.append("-logfile={0}".format(self.daemon_std_out))
ar.append("start")
# =========================
# START
# =========================
# Launch
logger.info("Start : %s", " ".join(ar))
p = subprocess.Popen(args=ar)
logger.info("Started")
SolBase.sleep(0)
self._wait_process(p)
# Try wait for stdout
ms_start = SolBase.mscurrent()
while SolBase.msdiff(ms_start) < self.stdout_timeout_ms:
if "n".join(self._get_std_out()).find(
" INFO | CustomDaemon@_on_start") >= 0:
break
else:
SolBase.sleep(10)
# Get std (caution, we are async since forked)
logger.info("stdOut ### START")
for s in self._get_std_out():
logger.info("stdOut => %s", s)
logger.info("stdOut ### END")
logger.info("stdErr ### START")
for s in self._get_std_err():
logger.info("stdErr => %s", s)
logger.info("stdErr ### END")
# Check
self.assertTrue(len(self._get_std_err()) == 0)
self.assertTrue(len(self._get_std_out()) > 0)
self.assertTrue("n".join(self._get_std_out()).find(" ERROR ") < 0)
self.assertTrue("n".join(self._get_std_out()).find(
" INFO | CustomDaemon@_on_start") >= 0)
self.assertTrue("n".join(self._get_std_out()).find(" WARN ") < 0)
# =========================
# STATUS
# =========================
for _ in range(0, 10):
# Args
ar = list()
ar.append(sys.executable)
ar.append(main_helper_file)
ar.append("-pidfile={0}".format(self.daemon_pid_file))
ar.append("status")
# Launch
p = subprocess.Popen(args=ar)
self._wait_process(p)
# =========================
# RELOAD
# =========================
for _ in range(0, 10):
# Args
ar = list()
ar.append(sys.executable)
ar.append(main_helper_file)
ar.append("-pidfile={0}".format(self.daemon_pid_file))
ar.append("reload")
# Launch
p = subprocess.Popen(args=ar)
self._wait_process(p)
# =========================
# STOP
# =========================
# Args
ar = list()
ar.append(sys.executable)
ar.append(main_helper_file)
ar.append("-pidfile={0}".format(self.daemon_pid_file))
ar.append("stop")
# Launch
p = subprocess.Popen(args=ar)
self._wait_process(p)
# =========================
# OVER, CHECK LOGS
# =========================
# Try wait for stdout
ms_start = SolBase.mscurrent()
while SolBase.msdiff(ms_start) < self.stdout_timeout_ms:
if "n".join(self._get_std_out()).find(" INFO | CustomDaemon@_on_stop") >= 0 \
and "n".join(self._get_std_out()).find(" INFO | CustomDaemon@_on_status") >= 0:
break
else:
SolBase.sleep(10)
# Get std (caution, we are async since forked)
logger.info("stdOut ### START")
for s in self._get_std_out():
logger.info("stdOut => %s", s)
logger.info("stdOut ### END")
logger.info("stdErr ### START")
for s in self._get_std_err():
logger.info("stdErr => %s", s)
logger.info("stdErr ### END")
# Check
self.assertTrue(len(self._get_std_err()) == 0)
self.assertTrue(len(self._get_std_out()) > 0)
self.assertTrue("n".join(self._get_std_out()).find(" ERROR ") < 0)
self.assertTrue("n".join(self._get_std_out()).find(
" INFO | CustomDaemon@_on_start") >= 0)
self.assertTrue("n".join(self._get_std_out()).find(
" INFO | CustomDaemon@_on_stop") >= 0)
self.assertTrue("n".join(self._get_std_out()).find(
" INFO | CustomDaemon@_on_status") >= 0)
self.assertTrue("n".join(self._get_std_out()).find(" WARN ") < 0)
# =========================
# OVER, CHECK ACTION FILE
# =========================
buf = FileUtility.file_to_textbuffer(
CustomDaemon.DAEMON_LAST_ACTION_FILE, "ascii")
self.assertTrue(buf.find("is_running=False") >= 0)
self.assertTrue(buf.find("start_count=1") >= 0)
self.assertTrue(buf.find("stop_count=1") >= 0)
self.assertTrue(buf.find("status_count=10") >= 0)
self.assertTrue(buf.find("reload_count=10") >= 0)
self.assertTrue(buf.find("last_action=stop") >= 0)
finally:
logger.debug("Exiting test, idx=%s", self.run_idx)