static void do_rotate(cdr_fd_t *fd)
{
switch_time_exp_t tm;
char date[80] = "";
switch_size_t retsize;
char *p;
close(fd->fd);
fd->fd = -1;
if (globals.rotate) {
switch_time_exp_lt(&tm, switch_micro_time_now());
switch_strftime_nocheck(date, &retsize, sizeof(date), "%Y-%m-%d-%H-%M-%S", &tm);
p = switch_mprintf("%s.%s", fd->path, date);
assert(p);
switch_file_rename(fd->path, p, globals.pool);
free(p);
}
do_reopen(fd);
if (fd->fd < 0) {
switch_event_t *event;
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_CRIT, "Error opening %s\n", fd->path);
if (switch_event_create(&event, SWITCH_EVENT_TRAP) == SWITCH_STATUS_SUCCESS) {
switch_event_add_header(event, SWITCH_STACK_BOTTOM, "Critical-Error", "Error opening cdr file %s\n", fd->path);
switch_event_fire(&event);
}
} else {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_NOTICE, "%s CDR logfile %s\n", globals.rotate ? "Rotated" : "Re-opened", fd->path);
}
}
/* rotate the log file */
static switch_status_t mod_logfile_rotate(logfile_profile_t *profile)
{
unsigned int i = 0;
char *filename = NULL;
switch_status_t stat = 0;
int64_t offset = 0;
switch_memory_pool_t *pool = NULL;
switch_time_exp_t tm;
char date[80] = "";
switch_size_t retsize;
switch_status_t status = SWITCH_STATUS_SUCCESS;
switch_mutex_lock(globals.mutex);
switch_time_exp_lt(&tm, switch_micro_time_now());
switch_strftime_nocheck(date, &retsize, sizeof(date), "%Y-%m-%d-%H-%M-%S", &tm);
profile->log_size = 0;
stat = switch_file_seek(profile->log_afd, SWITCH_SEEK_SET, &offset);
if (stat != SWITCH_STATUS_SUCCESS) {
status = SWITCH_STATUS_FALSE;
goto end;
}
switch_core_new_memory_pool(&pool);
filename = switch_core_alloc(pool, strlen(profile->logfile) + WARM_FUZZY_OFFSET);
for (i = 1; i < MAX_ROT; i++) {
sprintf((char *) filename, "%s.%s.%i", profile->logfile, date, i);
if (switch_file_exists(filename, pool) == SWITCH_STATUS_SUCCESS) {
continue;
}
switch_file_close(profile->log_afd);
switch_file_rename(profile->logfile, filename, pool);
if ((status = mod_logfile_openlogfile(profile, SWITCH_FALSE)) != SWITCH_STATUS_SUCCESS) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_CRIT, "Error Rotating Log!\n");
goto end;
}
break;
}
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_NOTICE, "New log started.\n");
end:
if (pool) {
switch_core_destroy_memory_pool(&pool);
}
switch_mutex_unlock(globals.mutex);
return status;
}
SWITCH_DECLARE(void) switch_console_printf(switch_text_channel_t channel, const char *file, const char *func, int line, const char *fmt, ...)
{
char *data = NULL;
int ret = 0;
va_list ap;
FILE *handle = switch_core_data_channel(channel);
const char *filep = switch_cut_path(file);
char date[80] = "";
switch_size_t retsize;
switch_time_exp_t tm;
switch_event_t *event;
va_start(ap, fmt);
ret = switch_vasprintf(&data, fmt, ap);
va_end(ap);
if (ret == -1) {
fprintf(stderr, "Memory Error\n");
goto done;
}
if (channel == SWITCH_CHANNEL_ID_LOG_CLEAN) {
fprintf(handle, "%s", data);
goto done;
}
switch_time_exp_lt(&tm, switch_micro_time_now());
switch_strftime_nocheck(date, &retsize, sizeof(date), "%Y-%m-%d %T", &tm);
if (channel == SWITCH_CHANNEL_ID_LOG) {
fprintf(handle, "[%d] %s %s:%d %s() %s", (int) getpid(), date, filep, line, func, data);
goto done;
}
if (channel == SWITCH_CHANNEL_ID_EVENT &&
switch_event_running() == SWITCH_STATUS_SUCCESS && switch_event_create(&event, SWITCH_EVENT_LOG) == SWITCH_STATUS_SUCCESS) {
switch_event_add_header_string(event, SWITCH_STACK_BOTTOM, "Log-Data", data);
switch_event_add_header_string(event, SWITCH_STACK_BOTTOM, "Log-File", filep);
switch_event_add_header_string(event, SWITCH_STACK_BOTTOM, "Log-Function", func);
switch_event_add_header(event, SWITCH_STACK_BOTTOM, "Log-Line", "%d", line);
switch_event_fire(&event);
}
done:
if (data) {
free(data);
}
fflush(handle);
}
SWITCH_DECLARE(switch_status_t) switch_strftime_tz(const char *tz, const char *format, char *date, size_t len, switch_time_t thetime)
{
time_t timep;
const char *tz_name = tz;
const char *tzdef;
switch_size_t retsize;
struct tm tm = { 0 };
switch_time_exp_t stm;
if (!thetime) {
thetime = switch_micro_time_now();
}
timep = (thetime) / (int64_t) (1000000);
if (!zstr(tz_name)) {
tzdef = switch_lookup_timezone(tz_name);
} else {
/* We set the default timezone to GMT. */
tz_name = "GMT";
tzdef = "GMT";
}
if (tzdef) { /* The lookup of the zone may fail. */
tztime(&timep, tzdef, &tm);
tm2switchtime(&tm, &stm);
switch_strftime_nocheck(date, &retsize, len, zstr(format) ? "%Y-%m-%d %T" : format, &stm);
if (!zstr_buf(date)) {
return SWITCH_STATUS_SUCCESS;
}
}
return SWITCH_STATUS_FALSE;
}
/* rotate the log file */
static switch_status_t mod_logfile_rotate(logfile_profile_t *profile)
{
unsigned int i = 0;
char *filename = NULL;
switch_status_t stat = 0;
int64_t offset = 0;
switch_memory_pool_t *pool = NULL;
switch_time_exp_t tm;
char date[80] = "";
switch_size_t retsize;
switch_status_t status = SWITCH_STATUS_SUCCESS;
switch_mutex_lock(globals.mutex);
switch_time_exp_lt(&tm, switch_micro_time_now());
switch_strftime_nocheck(date, &retsize, sizeof(date), "%Y-%m-%d-%H-%M-%S", &tm);
profile->log_size = 0;
stat = switch_file_seek(profile->log_afd, SWITCH_SEEK_SET, &offset);
if (stat != SWITCH_STATUS_SUCCESS) {
status = SWITCH_STATUS_FALSE;
goto end;
}
switch_core_new_memory_pool(&pool);
filename = switch_core_alloc(pool, strlen(profile->logfile) + WARM_FUZZY_OFFSET);
if (profile->max_rot) {
char *from_filename = NULL;
char *to_filename = NULL;
from_filename = switch_core_alloc(pool, strlen(profile->logfile) + WARM_FUZZY_OFFSET);
to_filename = switch_core_alloc(pool, strlen(profile->logfile) + WARM_FUZZY_OFFSET);
for (i=profile->suffix; i>1; i--) {
sprintf((char *) to_filename, "%s.%i", profile->logfile, i);
sprintf((char *) from_filename, "%s.%i", profile->logfile, i-1);
if (switch_file_exists(to_filename, pool) == SWITCH_STATUS_SUCCESS) {
if ((status = switch_file_remove(to_filename, pool)) != SWITCH_STATUS_SUCCESS) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_CRIT, "Error removing log %s\n",to_filename);
goto end;
}
}
if ((status = switch_file_rename(from_filename, to_filename, pool)) != SWITCH_STATUS_SUCCESS) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_CRIT, "Error renaming log from %s to %s [%s]\n",
from_filename, to_filename, strerror(errno));
goto end;
}
}
sprintf((char *) to_filename, "%s.%i", profile->logfile, i);
if (switch_file_exists(to_filename, pool) == SWITCH_STATUS_SUCCESS) {
if ((status = switch_file_remove(to_filename, pool)) != SWITCH_STATUS_SUCCESS) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_CRIT, "Error removing log %s [%s]\n", to_filename, strerror(errno));
goto end;
}
}
switch_file_close(profile->log_afd);
if ((status = switch_file_rename(profile->logfile, to_filename, pool)) != SWITCH_STATUS_SUCCESS) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_CRIT, "Error renaming log from %s to %s [%s]\n", profile->logfile, to_filename, strerror(errno));
goto end;
}
if ((status = mod_logfile_openlogfile(profile, SWITCH_FALSE)) != SWITCH_STATUS_SUCCESS) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_CRIT, "Error reopening log %s\n", profile->logfile);
}
if (profile->suffix < profile->max_rot) {
profile->suffix++;
}
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_NOTICE, "New log started.\n");
goto end;
}
/* XXX This have no real value EXCEPT making sure if we rotate within the same second, the end index will increase */
for (i = 1; i < MAX_ROT; i++) {
sprintf((char *) filename, "%s.%s.%i", profile->logfile, date, i);
if (switch_file_exists(filename, pool) == SWITCH_STATUS_SUCCESS) {
continue;
}
switch_file_close(profile->log_afd);
switch_file_rename(profile->logfile, filename, pool);
if ((status = mod_logfile_openlogfile(profile, SWITCH_FALSE)) != SWITCH_STATUS_SUCCESS) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_CRIT, "Error Rotating Log!\n");
goto end;
}
break;
}
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_NOTICE, "New log started.\n");
end:
if (pool) {
switch_core_destroy_memory_pool(&pool);
}
switch_mutex_unlock(globals.mutex);
return status;
}
/* This is where we actually charge the guy
This can be called anytime a call is in progress or at the end of a call before the session is destroyed */
static switch_status_t do_billing(switch_core_session_t *session)
{
/* FS vars we will use */
switch_channel_t *channel;
switch_caller_profile_t *profile;
/* Local vars */
nibble_data_t *nibble_data;
switch_time_t ts = switch_micro_time_now();
double billamount;
char date[80] = "";
char *uuid;
switch_size_t retsize;
switch_time_exp_t tm;
const char *billrate;
const char *billincrement;
const char *billaccount;
double nobal_amt = globals.nobal_amt;
double lowbal_amt = globals.lowbal_amt;
double balance;
if (!session) {
/* Why are we here? */
return SWITCH_STATUS_SUCCESS;
}
uuid = switch_core_session_get_uuid(session);
/* Get channel var */
if (!(channel = switch_core_session_get_channel(session))) {
return SWITCH_STATUS_SUCCESS;
}
/* Variables kept in FS but relevant only to this module */
billrate = switch_channel_get_variable(channel, "nibble_rate");
billincrement = switch_channel_get_variable(channel, "nibble_increment");
billaccount = switch_channel_get_variable(channel, "nibble_account");
if (!zstr(switch_channel_get_variable(channel, "nobal_amt"))) {
nobal_amt = atof(switch_channel_get_variable(channel, "nobal_amt"));
}
if (!zstr(switch_channel_get_variable(channel, "lowbal_amt"))) {
lowbal_amt = atof(switch_channel_get_variable(channel, "lowbal_amt"));
}
/* Return if there's no billing information on this session */
if (!billrate || !billaccount) {
return SWITCH_STATUS_SUCCESS;
}
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Attempting to bill at $%s per minute to account %s\n", billrate,
billaccount);
/* Get caller profile info from channel */
profile = switch_channel_get_caller_profile(channel);
if (!profile || !profile->times) {
/* No caller profile (why would this happen?) */
return SWITCH_STATUS_SUCCESS;
}
if (profile->times->answered < 1) {
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Not billing %s - call is not in answered state\n", billaccount);
/* See if this person has enough money left to continue the call */
balance = get_balance(billaccount, channel);
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Comparing %f to hangup balance of %f\n", balance, nobal_amt);
if (balance <= nobal_amt) {
/* Not enough money - reroute call to nobal location */
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Balance of %f fell below allowed amount of %f! (Account %s)\n",
balance, nobal_amt, billaccount);
transfer_call(session, globals.nobal_action);
}
return SWITCH_STATUS_SUCCESS;
}
/* Lock this session's data for this module while we tinker with it */
if (globals.mutex) {
switch_mutex_lock(globals.mutex);
}
/* Get our nibble data var. This will be NULL if it's our first call here for this session */
nibble_data = (nibble_data_t *) switch_channel_get_private(channel, "_nibble_data_");
/* Are we in paused mode? If so, we don't do anything here - go back! */
if (nibble_data && (nibble_data->pausets > 0)) {
if (globals.mutex) {
switch_mutex_unlock(globals.mutex);
}
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Received heartbeat, but we're paused - ignoring\n");
return SWITCH_STATUS_SUCCESS;
}
/* Have we done any billing on this channel yet? If no, set up vars for doing so */
if (!nibble_data) {
nibble_data = switch_core_session_alloc(session, sizeof(*nibble_data));
memset(nibble_data, 0, sizeof(*nibble_data));
/* Setup new billing data (based on call answer time, in case this module started late with active calls) */
nibble_data->lastts = profile->times->answered; /* Set the initial answer time to match when the call was really answered */
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_INFO, "Beginning new billing on %s\n", uuid);
}
switch_time_exp_lt(&tm, nibble_data->lastts);
switch_strftime_nocheck(date, &retsize, sizeof(date), "%Y-%m-%d %T", &tm);
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%d seconds passed since last bill time of %s\n",
(int) ((ts - nibble_data->lastts) / 1000000), date);
if ((ts - nibble_data->lastts) >= 0) {
/* If billincrement is set we bill by it and not by time elapsed */
if (!(switch_strlen_zero(billincrement))) {
switch_time_t chargedunits = (ts - nibble_data->lastts) / 1000000 <= atol(billincrement) ? atol(billincrement) * 1000000 : (switch_time_t)(ceil((ts - nibble_data->lastts) / (atol(billincrement) * 1000000.0))) * atol(billincrement) * 1000000;
billamount = (atof(billrate) / 1000000 / 60) * chargedunits - nibble_data->bill_adjustments;
/* Account for the prepaid amount */
nibble_data->lastts += chargedunits;
} else {
/* Convert billrate into microseconds and multiply by # of microseconds that have passed since last *successful* bill */
billamount = (atof(billrate) / 1000000 / 60) * ((ts - nibble_data->lastts)) - nibble_data->bill_adjustments;
/* Update the last time we billed */
nibble_data->lastts = ts;
}
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Billing $%f to %s (Call: %s / %f so far)\n", billamount, billaccount,
uuid, nibble_data->total);
/* DO ODBC BILLING HERE and reset counters if it's successful! */
if (bill_event(billamount, billaccount, channel) == SWITCH_STATUS_SUCCESS) {
/* Increment total cost */
nibble_data->total += billamount;
/* Reset manual billing adjustments from pausing */
nibble_data->bill_adjustments = 0;
/* Update channel variable with current billing */
switch_channel_set_variable_printf(channel, "nibble_total_billed", "%f", nibble_data->total);
} else {
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_CRIT, "Failed to log to database!\n");
}
} else {
if (switch_strlen_zero(billincrement))
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_WARNING, "Just tried to bill %s negative minutes! That should be impossible.\n", uuid);
}
/* Save this location */
if (channel) {
switch_channel_set_private(channel, "_nibble_data_", nibble_data);
/* don't verify balance and transfer to nobal if we're done with call */
if (switch_channel_get_state(channel) != CS_REPORTING && switch_channel_get_state(channel) != CS_HANGUP) {
balance = get_balance(billaccount, channel);
/* See if we've achieved low balance */
if (!nibble_data->lowbal_action_executed && balance <= lowbal_amt) {
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Balance of %f fell below low balance amount of %f! (Account %s)\n",
balance, lowbal_amt, billaccount);
if (exec_app(session, globals.lowbal_action) != SWITCH_STATUS_SUCCESS)
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_ERROR, "Low balance action didn't execute\n");
else
nibble_data->lowbal_action_executed = 1;
}
/* See if this person has enough money left to continue the call */
if (balance <= nobal_amt) {
/* Not enough money - reroute call to nobal location */
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_CRIT, "Balance of %f fell below allowed amount of %f! (Account %s)\n",
balance, nobal_amt, billaccount);
/* IMPORTANT: Billing must be paused before the transfer occurs! This prevents infinite loops, since the transfer will result */
/* in nibblebill checking the call again in the routing process for an allowed balance! */
/* If you intend to give the user the option to re-up their balance, you must clear & resume billing once the balance is updated! */
nibblebill_pause(session);
transfer_call(session, globals.nobal_action);
}
}
}
/* Done changing - release lock */
if (globals.mutex) {
switch_mutex_unlock(globals.mutex);
}
/* Go check if this call is allowed to continue */
return SWITCH_STATUS_SUCCESS;
}
static switch_status_t set_json_cdr_log_dirs()
{
switch_time_exp_t tm;
char *path = NULL;
char date[80] = "";
switch_size_t retsize;
switch_status_t status = SWITCH_STATUS_SUCCESS, dir_status;
int err_dir_index;
switch_time_exp_lt(&tm, switch_micro_time_now());
switch_strftime_nocheck(date, &retsize, sizeof(date), "%Y-%m-%d-%H-%M-%S", &tm);
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_NOTICE, "Rotating log file paths\n");
if (!zstr(globals.base_log_dir)) {
if (globals.rotate) {
if ((path = switch_mprintf("%s%s%s", globals.base_log_dir, SWITCH_PATH_SEPARATOR, date))) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_NOTICE, "Rotating log file path to %s\n", path);
dir_status = SWITCH_STATUS_SUCCESS;
if (switch_directory_exists(path, globals.pool) != SWITCH_STATUS_SUCCESS) {
dir_status = switch_dir_make(path, SWITCH_FPROT_OS_DEFAULT, globals.pool);
}
if (dir_status == SWITCH_STATUS_SUCCESS) {
switch_thread_rwlock_wrlock(globals.log_path_lock);
switch_safe_free(globals.log_dir);
globals.log_dir = path;
switch_thread_rwlock_unlock(globals.log_path_lock);
} else {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create new mod_json_cdr log_dir path\n");
switch_safe_free(path);
status = SWITCH_STATUS_FALSE;
}
} else {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to generate new mod_json_cdr log_dir path\n");
status = SWITCH_STATUS_FALSE;
}
} else {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_NOTICE, "Setting log file path to %s\n", globals.base_log_dir);
if ((path = switch_safe_strdup(globals.base_log_dir))) {
switch_thread_rwlock_wrlock(globals.log_path_lock);
switch_safe_free(globals.log_dir);
switch_dir_make_recursive(path, SWITCH_DEFAULT_DIR_PERMS, globals.pool);
globals.log_dir = path;
switch_thread_rwlock_unlock(globals.log_path_lock);
} else {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to set log_dir path\n");
status = SWITCH_STATUS_FALSE;
}
}
}
for (err_dir_index = 0; err_dir_index < globals.err_dir_count; err_dir_index++) {
if (globals.rotate) {
if ((path = switch_mprintf("%s%s%s", globals.base_err_log_dir[err_dir_index], SWITCH_PATH_SEPARATOR, date))) {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_NOTICE, "Rotating err log file path to %s\n", path);
dir_status = SWITCH_STATUS_SUCCESS;
if (switch_directory_exists(path, globals.pool) != SWITCH_STATUS_SUCCESS) {
dir_status = switch_dir_make(path, SWITCH_FPROT_OS_DEFAULT, globals.pool);
}
if (dir_status == SWITCH_STATUS_SUCCESS) {
switch_thread_rwlock_wrlock(globals.log_path_lock);
switch_safe_free(globals.err_log_dir[err_dir_index]);
globals.err_log_dir[err_dir_index] = path;
switch_thread_rwlock_unlock(globals.log_path_lock);
} else {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to create new mod_json_cdr err_log_dir path\n");
switch_safe_free(path);
status = SWITCH_STATUS_FALSE;
}
} else {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to generate new mod_json_cdr err_log_dir path\n");
status = SWITCH_STATUS_FALSE;
}
} else {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_NOTICE, "Setting err log file path to %s\n", globals.base_err_log_dir[err_dir_index]);
if ((path = switch_safe_strdup(globals.base_err_log_dir[err_dir_index]))) {
switch_thread_rwlock_wrlock(globals.log_path_lock);
switch_safe_free(globals.err_log_dir[err_dir_index]);
switch_dir_make_recursive(path, SWITCH_DEFAULT_DIR_PERMS, globals.pool);
globals.err_log_dir[err_dir_index] = path;
switch_thread_rwlock_unlock(globals.log_path_lock);
} else {
switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_ERROR, "Failed to set err_log_dir path\n");
status = SWITCH_STATUS_FALSE;
}
}
}
return status;
}