[mod_spandsp] Use single log for fax negotiation and page reports.

This commit is contained in:
Chris Rienzo 2019-10-22 16:41:45 -04:00 committed by Andrey Volk
parent 64dff4fd98
commit 5913781687
1 changed files with 108 additions and 59 deletions

View File

@ -307,6 +307,7 @@ static int phase_b_handler(void *user_data, int result)
char *fax_document_total_pages = NULL; char *fax_document_total_pages = NULL;
pvt_t *pvt; pvt_t *pvt;
switch_event_t *event; switch_event_t *event;
const char *total_pages_str = "";
pvt = (pvt_t *) user_data; pvt = (pvt_t *) user_data;
switch_assert(pvt); switch_assert(pvt);
@ -343,20 +344,30 @@ static int phase_b_handler(void *user_data, int result)
switch_channel_set_variable(channel, "fax_remote_model", switch_str_nil(t30_get_rx_model(pvt->t30))); switch_channel_set_variable(channel, "fax_remote_model", switch_str_nil(t30_get_rx_model(pvt->t30)));
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "=== Negotiation Result =======================================================\n");
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Remote station id: %s\n", far_ident);
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Local station id: %s\n", local_ident);
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Transfer Rate: %i\n", t30_stats.bit_rate);
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "ECM status %s\n", (t30_stats.error_correcting_mode) ? "on" : "off");
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38 status %s\n", get_t38_status(pvt->t38_mode));
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "remote country: %s\n", switch_str_nil(t30_get_rx_country(pvt->t30)));
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "remote vendor: %s\n", switch_str_nil(t30_get_rx_vendor(pvt->t30)));
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "remote model: %s\n", switch_str_nil(t30_get_rx_model(pvt->t30)));
if (pvt->app_mode == FUNCTION_TX) { if (pvt->app_mode == FUNCTION_TX) {
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Total fax pages: %s\n", fax_document_total_pages); total_pages_str = switch_core_session_sprintf(session, "Total fax pages: %s\n", fax_document_total_pages);
} }
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_INFO,
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "==============================================================================\n"); "=== Negotiation Result =======================================================\n"
"Remote station id: %s\n"
"Local station id: %s\n"
"Transfer Rate: %i\n"
"ECM status %s\n"
"T38 status %s\n"
"remote country: %s\n"
"remote vendor: %s\n"
"remote model: %s\n"
"%s"
"==============================================================================\n",
far_ident,
local_ident,
t30_stats.bit_rate,
(t30_stats.error_correcting_mode) ? "on" : "off",
get_t38_status(pvt->t38_mode),
switch_str_nil(t30_get_rx_country(pvt->t30)),
switch_str_nil(t30_get_rx_vendor(pvt->t30)),
switch_str_nil(t30_get_rx_model(pvt->t30)),
total_pages_str);
switch_channel_execute_on(channel, "execute_on_fax_phase_b"); switch_channel_execute_on(channel, "execute_on_fax_phase_b");
@ -396,6 +407,7 @@ static int phase_d_handler(void *user_data, int msg)
char *fax_longest_bad_row_run = NULL; char *fax_longest_bad_row_run = NULL;
char *fax_document_transferred_pages = NULL; char *fax_document_transferred_pages = NULL;
char *fax_document_total_pages = NULL; char *fax_document_total_pages = NULL;
const char *total_pages_str = "";
switch_core_session_t *session; switch_core_session_t *session;
switch_channel_t *channel; switch_channel_t *channel;
pvt_t *pvt; pvt_t *pvt;
@ -468,19 +480,31 @@ static int phase_d_handler(void *user_data, int msg)
} }
} }
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "==== Page %s===========================================================\n", pvt->app_mode == FUNCTION_TX ? "Sent ====": "Received ");
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Page no = %d\n", (pvt->app_mode == FUNCTION_TX) ? t30_stats.pages_tx : t30_stats.pages_rx);
if (pvt->app_mode == FUNCTION_TX) { if (pvt->app_mode == FUNCTION_TX) {
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Total fax pages: %s\n", fax_document_total_pages); total_pages_str = switch_core_session_sprintf(session, "Total fax pages: %s\n", fax_document_total_pages);
} }
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Image type = %s (%s in the file)\n", t4_image_type_to_str(t30_stats.type), t4_image_type_to_str(t30_stats.image_type)); switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_INFO,
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Image size = %d x %d pixels (%d x %d pixels in the file)\n", t30_stats.width, t30_stats.length, t30_stats.image_width, t30_stats.image_length); "==== Page %s===========================================================\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Image resolution = %d/m x %d/m (%d/m x %d/m in the file)\n", t30_stats.x_resolution, t30_stats.y_resolution, t30_stats.image_x_resolution, t30_stats.image_y_resolution); "Page no = %d\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Compression = %s (%d)\n", t4_compression_to_str(t30_stats.compression), t30_stats.compression); "%s"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Compressed image size = %d bytes\n", t30_stats.image_size); "Image type = %s (%s in the file)\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Bad rows = %d\n", t30_stats.bad_rows); "Image size = %d x %d pixels (%d x %d pixels in the file)\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Longest bad row run = %d\n", t30_stats.longest_bad_row_run); "Image resolution = %d/m x %d/m (%d/m x %d/m in the file)\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "==============================================================================\n"); "Compression = %s (%d)\n"
"Compressed image size = %d bytes\n"
"Bad rows = %d\n"
"Longest bad row run = %d\n"
"==============================================================================\n",
pvt->app_mode == FUNCTION_TX ? "Sent ====": "Received ",
(pvt->app_mode == FUNCTION_TX) ? t30_stats.pages_tx : t30_stats.pages_rx,
total_pages_str,
t4_image_type_to_str(t30_stats.type), t4_image_type_to_str(t30_stats.image_type),
t30_stats.width, t30_stats.length, t30_stats.image_width, t30_stats.image_length,
t30_stats.x_resolution, t30_stats.y_resolution, t30_stats.image_x_resolution, t30_stats.image_y_resolution,
t4_compression_to_str(t30_stats.compression), t30_stats.compression,
t30_stats.image_size,
t30_stats.bad_rows,
t30_stats.longest_bad_row_run);
switch_channel_execute_on(channel, "execute_on_fax_phase_d"); switch_channel_execute_on(channel, "execute_on_fax_phase_d");
@ -528,6 +552,7 @@ static void phase_e_handler(void *user_data, int result)
switch_event_t *event; switch_event_t *event;
const char *var; const char *var;
char *expanded; char *expanded;
const char *fax_result_str = "";
pvt = (pvt_t *) user_data; pvt = (pvt_t *) user_data;
switch_assert(pvt); switch_assert(pvt);
@ -542,38 +567,49 @@ static void phase_e_handler(void *user_data, int result)
local_ident = switch_str_nil(t30_get_tx_ident(pvt->t30)); local_ident = switch_str_nil(t30_get_tx_ident(pvt->t30));
far_ident = switch_str_nil(t30_get_rx_ident(pvt->t30)); far_ident = switch_str_nil(t30_get_rx_ident(pvt->t30));
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "==============================================================================\n");
if (result == T30_ERR_OK) { if (result == T30_ERR_OK) {
if (pvt->app_mode == FUNCTION_TX) { if (pvt->app_mode == FUNCTION_TX) {
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Fax successfully sent.\n"); fax_result_str = switch_core_session_sprintf(session, "Fax successfully sent.\n");
} else if (pvt->app_mode == FUNCTION_RX) { } else if (pvt->app_mode == FUNCTION_RX) {
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Fax successfully received.\n"); fax_result_str = switch_core_session_sprintf(session, "Fax successfully received.\n");
} else { } else {
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Fax successfully managed. How ?\n"); fax_result_str = switch_core_session_sprintf(session, "Fax successfully managed. How ?\n");
} }
switch_channel_set_variable(channel, "fax_success", "1"); switch_channel_set_variable(channel, "fax_success", "1");
} else { } else {
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Fax processing not successful - result (%d) %s.\n", result, fax_result_str = switch_core_session_sprintf(session, "Fax processing not successful - result (%d) %s.\n", result,
t30_completion_code_to_str(result)); t30_completion_code_to_str(result));
switch_channel_set_variable(channel, "fax_success", "0"); switch_channel_set_variable(channel, "fax_success", "0");
} }
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Remote station id: %s\n", far_ident); switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_INFO,
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Local station id: %s\n", local_ident); "==============================================================================\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Pages transferred: %i\n", "%s"
pvt->app_mode == FUNCTION_TX ? t.pages_tx : t.pages_rx); "Remote station id: %s\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Total fax pages: %i\n", t.pages_in_file); "Local station id: %s\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Image resolution: %ix%i\n", t.x_resolution, t.y_resolution); "Pages transferred: %i\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "Transfer Rate: %i\n", t.bit_rate); "Total fax pages: %i\n"
"Image resolution: %ix%i\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "ECM status %s\n", (t.error_correcting_mode) ? "on" : "off"); "Transfer Rate: %i\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38 status %s\n", get_t38_status(pvt->t38_mode)); "ECM status %s\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "remote country: %s\n", switch_str_nil(t30_get_rx_country(pvt->t30))); "T38 status %s\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "remote vendor: %s\n", switch_str_nil(t30_get_rx_vendor(pvt->t30))); "remote country: %s\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "remote model: %s\n", switch_str_nil(t30_get_rx_model(pvt->t30))); "remote vendor: %s\n"
"remote model: %s\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "==============================================================================\n"); "==============================================================================\n",
fax_result_str,
far_ident,
local_ident,
pvt->app_mode == FUNCTION_TX ? t.pages_tx : t.pages_rx,
t.pages_in_file,
t.x_resolution, t.y_resolution,
t.bit_rate,
(t.error_correcting_mode) ? "on" : "off",
get_t38_status(pvt->t38_mode),
switch_str_nil(t30_get_rx_country(pvt->t30)),
switch_str_nil(t30_get_rx_vendor(pvt->t30)),
switch_str_nil(t30_get_rx_model(pvt->t30)));
/* /*
Set our channel variables, variables are also used in event Set our channel variables, variables are also used in event
@ -1092,20 +1128,33 @@ static t38_mode_t negotiate_t38(pvt_t *pvt)
pvt->t38_mode = T38_MODE_NEGOTIATED; pvt->t38_mode = T38_MODE_NEGOTIATED;
switch_channel_set_app_flag_key("T38", channel, CF_APP_T38_NEGOTIATED); switch_channel_set_app_flag_key("T38", channel, CF_APP_T38_NEGOTIATED);
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38 SDP Origin = %s\n", t38_options->sdp_o_line); switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_INFO,
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38FaxVersion = %d\n", t38_options->T38FaxVersion); "T38 SDP Origin = %s\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38MaxBitRate = %d\n", t38_options->T38MaxBitRate); "T38FaxVersion = %d\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38FaxFillBitRemoval = %d\n", t38_options->T38FaxFillBitRemoval); "T38MaxBitRate = %d\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38FaxTranscodingMMR = %d\n", t38_options->T38FaxTranscodingMMR); "T38FaxFillBitRemoval = %d\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38FaxTranscodingJBIG = %d\n", t38_options->T38FaxTranscodingJBIG); "T38FaxTranscodingMMR = %d\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38FaxRateManagement = '%s'\n", t38_options->T38FaxRateManagement); "T38FaxTranscodingJBIG = %d\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38FaxMaxBuffer = %d\n", t38_options->T38FaxMaxBuffer); "T38FaxRateManagement = '%s'\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38FaxMaxDatagram = %d\n", t38_options->T38FaxMaxDatagram); "T38FaxMaxBuffer = %d\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38FaxUdpEC = '%s'\n", t38_options->T38FaxUdpEC); "T38FaxMaxDatagram = %d\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "T38VendorInfo = '%s'\n", switch_str_nil(t38_options->T38VendorInfo)); "T38FaxUdpEC = '%s'\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "ip = '%s'\n", "T38VendorInfo = '%s'\n"
t38_options->remote_ip ? t38_options->remote_ip : "Not specified"); "ip = '%s'\n"
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "port = %d\n", t38_options->remote_port); "port = %d\n",
t38_options->sdp_o_line,
t38_options->T38FaxVersion,
t38_options->T38MaxBitRate,
t38_options->T38FaxFillBitRemoval,
t38_options->T38FaxTranscodingMMR,
t38_options->T38FaxTranscodingJBIG,
t38_options->T38FaxRateManagement,
t38_options->T38FaxMaxBuffer,
t38_options->T38FaxMaxDatagram,
t38_options->T38FaxUdpEC,
switch_str_nil(t38_options->T38VendorInfo),
t38_options->remote_ip ? t38_options->remote_ip : "Not specified",
t38_options->remote_port);
/* Time to practice our negotiating skills, by editing the t38_options */ /* Time to practice our negotiating skills, by editing the t38_options */
@ -2141,7 +2190,7 @@ switch_bool_t t38_gateway_start(switch_core_session_t *session, const char *app,
switch_channel_set_variable(peer ? channel : other_channel, "t38_gateway_format", "audio"); switch_channel_set_variable(peer ? channel : other_channel, "t38_gateway_format", "audio");
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_DEBUG, "%s starting gateway mode to %s\n", switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(session), SWITCH_LOG_INFO, "%s starting gateway mode to %s\n",
switch_channel_get_name(peer ? channel : other_channel), switch_channel_get_name(peer ? channel : other_channel),
switch_channel_get_name(peer ? other_channel : channel)); switch_channel_get_name(peer ? other_channel : channel));
@ -2274,7 +2323,7 @@ static switch_bool_t tone_detect_callback(switch_media_bug_t *bug, void *user_da
if (cont->hits) { if (cont->hits) {
switch_event_t *event; switch_event_t *event;
switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(switch_core_media_bug_get_session(bug)), SWITCH_LOG_DEBUG, switch_log_printf(SWITCH_CHANNEL_SESSION_LOG(switch_core_media_bug_get_session(bug)), SWITCH_LOG_INFO,
"Fax Tone Detected. [%s][%s]\n", cont->app, switch_str_nil(cont->data)); "Fax Tone Detected. [%s][%s]\n", cont->app, switch_str_nil(cont->data));
if (cont->callback) { if (cont->callback) {