test_log.c revision 8a4b0b791bf38ef8389a6501a586d8ab554e3711
10139N/A/**
10139N/A * The contents of this file are subject to the terms of the Common Development and
10139N/A * Distribution License (the License). You may not use this file except in compliance with the
10139N/A * License.
10139N/A *
10139N/A * You can obtain a copy of the License at legal/CDDLv1.0.txt. See the License for the
10139N/A * specific language governing permission and limitations under the License.
10139N/A *
10139N/A * When distributing Covered Software, include this CDDL Header Notice in each file and include
10139N/A * the License file at legal/CDDLv1.0.txt. If applicable, add the following below the CDDL
10139N/A * Header, with the fields enclosed by brackets [] replaced by your own identifying
10139N/A * information: "Portions copyright [year] [name of copyright owner]".
11129N/A *
10139N/A * Copyright 2015 ForgeRock AS.
10139N/A */
10139N/A
10139N/A#include <stdio.h>
11129N/A#include <string.h>
10139N/A#include <stdlib.h>
10139N/A#include <setjmp.h>
11129N/A
11129N/A#include "platform.h"
11129N/A#include "am.h"
11129N/A#include "log.h"
10139N/A#include "cmocka.h"
10139N/A
10139N/Avoid am_worker_pool_init_reset();
10139N/Avoid am_net_init_ssl_reset();
10139N/A
10139N/A/**
10139N/A * This is the simplest of tests to check we can log things without crashing.
10139N/A *
10139N/A * In fact, because of the way logging works (differently) in test mode than it does in "agent mode"
10139N/A * all we're really doing here is to test that logging in test mode isn't broken. This may or may not
10139N/A * bear any relation to whether logging works for the rest of the time.
10139N/A */
10139N/Avoid test_logging_in_unit_test_mode(void** state) {
10139N/A
10139N/A static const char* text1 = "Now is the winter of our discontent,";
10139N/A static const char* text2 = "Made glorious summer by this son of York";
10139N/A
10139N/A AM_LOG_INFO(0, "instance id is zero and no args");
10139N/A AM_LOG_INFO(0, "instance id is zero and incorrect args", text1);
10139N/A AM_LOG_INFO(0, "instance id is zero and more incorrect args", text1, text2);
10139N/A
10139N/A /* we're testing this will not crash */
11129N/A AM_LOG_INFO(0, NULL, text1, text2);
11129N/A
10139N/A /* this will not appear, since the instance is greater than zero, but it should not crash either */
10139N/A AM_LOG_ERROR(10, "%s %s", text1, text2);
10139N/A
10139N/A AM_LOG_INFO(0, "%s %s", text1, text2);
10139N/A AM_LOG_WARNING(0, "%s %s", text1, text2);
10139N/A AM_LOG_ERROR(0, "%s %s", text1, text2);
10139N/A AM_LOG_DEBUG(0, "%s %s", text1, text2);
10139N/A AM_LOG_AUDIT(0, "%s %s", text1, text2);
10139N/A
10139N/A AM_LOG_ALWAYS(0, "%s %s", text1, text2);
10139N/A AM_LOG_ALWAYS(0, "Now %s the %s of our %s, %s summ%s of York",
10139N/A "is",
10139N/A "winter",
10139N/A "discontent",
10139N/A "Made glorious",
10139N/A "er by this son");
10139N/A
10139N/A /* attempt to overflow the buffer, although this will be ultimately unsuccessful because the
10139N/A * logging works differently in unit test mode than it does in "real life" mode.
10139N/A */
10139N/A AM_LOG_ALWAYS(0, "\n"
10139N/A "1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890\n"
10139N/A "1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890\n"
10139N/A "1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890\n"
10139N/A "1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890\n"
10139N/A "1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890\n"
10139N/A "1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890\n"
10139N/A "1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890\n"
10139N/A "1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890\n"
10139N/A "1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890\n"
10139N/A "1234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890\n"
10139N/A "ABCDEFGHIJABCDEFGHIJABCDEFGHIJABCDEFGHIJABCDEFGHIJABCDEFGHIJABCDEFGHIJABCDEFGHIJABCDEFGHIJABCDEFGHIJABCDEFGHIJABCDEFGHIJABCDEFGHIJ");
10139N/A}
10139N/A
10139N/A/*************************************************************************************/
10139N/A
10139N/Achar log_file_name[20];
10139N/Achar audit_file_name[20];
10139N/A
10139N/A#define ONE_K 1024
10139N/A#define ONE_MB 1024 * 1024
10139N/A#define TEN_MB ONE_MB * 10
10139N/A
10139N/A/**
10139N/A * Set up everything (shared memory, etc.) so we can log, just as we would if we were
10139N/A * really running (as opposed to running in test harness mode).
10139N/A */
10139N/Avoid logging_setup(int logging_level) {
10139N/A
10139N/A // destroy the cache, if it exists
10139N/A am_cache_destroy();
10139N/A
10139N/A assert_int_equal(am_init(AM_DEFAULT_AGENT_ID), AM_SUCCESS);
10139N/A
10139N/A sprintf(log_file_name, "log%d", rand() % 1000000);
10139N/A
10139N/A // Note that we need a valid audit file name, even though we never audit
10139N/A sprintf(audit_file_name, "aud%d", rand() % 1000000);
10139N/A
10139N/A am_log_register_instance(getpid(),
10139N/A log_file_name, logging_level, TEN_MB,
10139N/A audit_file_name, AM_LOG_LEVEL_AUDIT, ONE_MB);
10139N/A am_init_worker(AM_DEFAULT_AGENT_ID);
10139N/A}
10139N/A
10139N/A/**
10139N/A * Tear down everything after doing some logging.
11129N/A */
11129N/Avoid logging_teardown() {
11129N/A am_log_shutdown(AM_DEFAULT_AGENT_ID);
11129N/A am_shutdown_worker();
11051N/A am_cache_destroy();
11051N/A am_worker_pool_init_reset();
11036N/A am_net_init_ssl_reset();
11036N/A unlink(log_file_name);
11036N/A unlink(audit_file_name);
10981N/A}
10477N/A
10477N/A/**
10477N/A * Validate that the specified file contains the specified string. Very limited. The
10285N/A * string searched for must occur entirely on a line and not span lines (if it does, it
10477N/A * won't be matched).
10207N/A *
10139N/A * @param log_file_name The log file name
10139N/A * @param text The text string to search for
10139N/A * @return 1 if present, 0 if not present
10139N/A */
10139N/Aint validate_contains(const char* file_name, const char* text) {
10139N/A FILE* fp;
10139N/A int result = 0;
10139N/A char line[10 * ONE_K];
10139N/A
10139N/A if ((fp = fopen(file_name, "r")) != NULL) {
10139N/A while (fgets(line, sizeof(line), fp) != NULL && result == 0) {
10139N/A result = strstr(line, text) != NULL;
10139N/A }
10139N/A fclose(fp);
10139N/A } else {
10139N/A fprintf(stderr, "Warning, failed to open log file %s\n", file_name);
10139N/A }
10139N/A return result;
10139N/A}
10139N/A
10139N/A/*************************************************************************************/
10139N/A
10139N/A/**
10139N/A * Ensure that an impractically high log level we DO actually log text via AM_LOG_DEBUG.
10139N/A */
10139N/Avoid test_log_debug_at_debug_level(void** state) {
10139N/A int result;
10139N/A const char* message = "Message written at DEBUG level.";
10139N/A
10139N/A srand(time(NULL));
10139N/A logging_setup(AM_LOG_LEVEL_AUDIT_DENY);
10139N/A AM_LOG_DEBUG(getpid(), message);
10139N/A sleep(5);
10139N/A result = validate_contains(log_file_name, message);
10139N/A logging_teardown();
10139N/A assert_int_equal(result, 1);
10139N/A}
10139N/A
10139N/A/**
10139N/A * Ensure that at warning log level we do NOT log something via AM_LOG_DEBUG.
10139N/A */
10139N/Avoid test_log_debug_not_at_warning_level(void** state) {
10139N/A int result;
10139N/A const char* message = "Message written at DEBUG level.";
10139N/A
10139N/A logging_setup(AM_LOG_LEVEL_WARNING);
10139N/A AM_LOG_DEBUG(getpid(), message);
10139N/A sleep(5);
10139N/A result = validate_contains(log_file_name, message);
10139N/A logging_teardown();
10139N/A assert_int_equal(result, 0);
10139N/A}
10139N/A
10139N/A/**
10139N/A * Ensure that at warning log level we DO log something via AM_LOG_WARNING.
10139N/A */
10139N/Avoid test_log_warning_at_warning_level(void** state) {
10139N/A int result;
10139N/A const char* message = "Message written at WARNING level.";
10139N/A
10139N/A logging_setup(AM_LOG_LEVEL_WARNING);
10139N/A AM_LOG_WARNING(getpid(), message);
10139N/A sleep(5);
10139N/A result = validate_contains(log_file_name, message);
10139N/A logging_teardown();
10139N/A assert_int_equal(result, 1);
10139N/A}
10139N/A
10139N/A