ftmod_misdn: Improve debug log messages.

Signed-off-by: Stefan Knoblich <stkn@openisdn.net>

diff --git a/libs/freetdm/src/ftmod/ftmod_misdn/ftmod_misdn.c b/libs/freetdm/src/ftmod/ftmod_misdn/ftmod_misdn.c
index a023d83aec9ad9add0a5d2a0663bb05bc332c9cd..40c329be13f91826e7ce998e9ff0d89a4172701a 100644 (file)
--- a/libs/freetdm/src/ftmod/ftmod_misdn/ftmod_misdn.c
+++ b/libs/freetdm/src/ftmod/ftmod_misdn/ftmod_misdn.c
@@ -458,8 +458,9 @@ static ftdm_status_t misdn_activate_channel(ftdm_channel_t *chan, int activate)
                                return FTDM_FAIL;
                        }
 //#ifdef MISDN_DEBUG_EVENTS
-                       ftdm_log_chan(chan, FTDM_LOG_DEBUG, "mISDN got event '%s (%#x)' while waiting for %s confirmation\n",
-                               misdn_event2str(hh->prim), hh->prim, (activate) ? "activation" : "deactivation");
+                       ftdm_log_chan(chan, FTDM_LOG_DEBUG, "mISDN got event '%s (%#x)', id %#x, while waiting for %s confirmation on %c-channel\n",
+                               misdn_event2str(hh->prim), hh->prim, hh->id, (activate) ? "activation" : "deactivation",
+                               ftdm_channel_get_type(chan) == FTDM_CHAN_TYPE_B ? 'B' : 'D');
 //#endif
                        switch (hh->prim) {
                        case PH_ACTIVATE_IND:   /* success (or not): save last response, */
@@ -478,13 +479,11 @@ static ftdm_status_t misdn_activate_channel(ftdm_channel_t *chan, int activate)
                                        misdn_event2str(hh->prim), (activate) ? "activation" : "deactivation", hh->id);
                                break;
                        case MPH_INFORMATION_IND:
-                               ftdm_log_chan(chan, FTDM_LOG_DEBUG, "mISDN ignoring event '%s (%#x)' while waiting for %s confirmation\n",
-                                       misdn_event2str(hh->prim), hh->prim, (activate) ? "activation" : "deactivation");
                                misdn_handle_mph_information_ind(chan, hh, MISDN_MSG_DATA(buf), retval - MISDN_HEADER_LEN);
                                break;
                        default:                /* other messages, ignore */
-                               ftdm_log_chan(chan, FTDM_LOG_DEBUG, "mISDN ignoring event '%s (%#x)' while waiting for %s confirmation\n",
-                                       misdn_event2str(hh->prim), hh->prim, (activate) ? "activation" : "deactivation");
+                               ftdm_log_chan(chan, FTDM_LOG_DEBUG, "mISDN ignoring event '%s (%#x)', id %#x, while waiting for %s confirmation\n",
+                                       misdn_event2str(hh->prim), hh->prim, hh->id, (activate) ? "activation" : "deactivation");
                                break;
                        }
                }
@@ -911,6 +910,9 @@ static FIO_CLOSE_FUNCTION(misdn_close)
 
        assert(chan_priv);
 
+       ftdm_log_chan(ftdmchan, FTDM_LOG_NOTICE, "mISDN trying to close %c-channel\n",
+               ftdm_channel_get_type(ftdmchan) == FTDM_CHAN_TYPE_B ? 'B' : 'D');
+
        /* deactivate b-channels on close */
        if (ftdm_channel_get_type(ftdmchan) == FTDM_CHAN_TYPE_B) {
                /*
@@ -926,11 +928,13 @@ static FIO_CLOSE_FUNCTION(misdn_close)
                 */
                ret = misdn_activate_channel(ftdmchan, 0);
                if (ret != FTDM_SUCCESS) {
-                       ftdm_log_chan_msg(ftdmchan, FTDM_LOG_ERROR, "Failed to deactivate channel\n");
+                       ftdm_log_chan(ftdmchan, FTDM_LOG_ERROR, "Failed to deactivate %c-channel\n",
+                               ftdm_channel_get_type(ftdmchan) == FTDM_CHAN_TYPE_B ? 'B' : 'D');
                        return FTDM_FAIL;
                }
 
-               ftdm_log_chan_msg(ftdmchan, FTDM_LOG_INFO, "mISDN channel deactivated\n");
+               ftdm_log_chan(ftdmchan, FTDM_LOG_INFO, "mISDN %c-channel deactivated\n",
+                       ftdm_channel_get_type(ftdmchan) == FTDM_CHAN_TYPE_B ? 'B' : 'D');
                chan_priv->state = MISDN_CHAN_STATE_CLOSED;
        }
 
@@ -989,8 +993,8 @@ static FIO_COMMAND_FUNCTION(misdn_command)
 
        case FTDM_COMMAND_GET_INTERVAL:
                FTDM_COMMAND_OBJ_INT = ftdm_channel_get_io_interval(ftdmchan);
-               ftdm_log(FTDM_LOG_NOTICE, "Interval %d ms [%d:%d]\n",
-                       ftdm_channel_get_io_interval(ftdmchan), ftdm_channel_get_span_id(ftdmchan), ftdm_channel_get_id(ftdmchan));
+               ftdm_log_chan(ftdmchan, FTDM_LOG_NOTICE, "Interval %d ms\n",
+                       ftdm_channel_get_io_interval(ftdmchan));
                break;
 
        default:
@@ -1169,6 +1173,7 @@ static FIO_READ_FUNCTION(misdn_read)
        int retval;
 
        if (priv->state == MISDN_CHAN_STATE_CLOSED) {
+               ftdm_log_chan_msg(ftdmchan, FTDM_LOG_DEBUG, "mISDN ignoring read on closed channel\n");
                /* ignore */
                *datalen = 0;
                return FTDM_SUCCESS;
@@ -1200,7 +1205,7 @@ static FIO_READ_FUNCTION(misdn_read)
                        if (*datalen > 0) {
                                char hbuf[MAX_DATA_MEM] = { 0 };
                                print_hex_bytes(data, *datalen, hbuf, sizeof(hbuf));
-                               ftdm_log(FTDM_LOG_DEBUG, "mISDN read data: %s\n", hbuf);
+                               ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "mISDN read data: %s\n", hbuf);
                        }
 #endif
                        return FTDM_SUCCESS;
@@ -1210,6 +1215,10 @@ static FIO_READ_FUNCTION(misdn_read)
                        misdn_handle_incoming(ftdmchan, rbuf, retval);
                }
        }
+#ifdef MISDN_DEBUG_IO
+       ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "mISDN nothing received on %c-channel\n",
+               ftdm_channel_get_type(ftdmchan) == FTDM_CHAN_TYPE_B ? 'B' : 'D');
+#endif
        return FTDM_SUCCESS;
 }
 
@@ -1250,21 +1259,16 @@ static FIO_WRITE_FUNCTION(misdn_write)
        size += MISDN_HEADER_LEN;
 
 #ifdef MISDN_DEBUG_IO
-       ftdm_log(FTDM_LOG_DEBUG, "mISDN writing %d bytes to channel %d:%d socket %d\n",
-               size, ftdm_channel_get_span_id(ftdmchan), ftdm_channel_get_id(ftdmchan), ftdmchan->sockfd);
+       ftdm_log_chan(ftdmchan, FTDM_LOG_DEBUG, "mISDN writing %d bytes to channel socket %d [dev.ch: %d.%d]\n",
+               size, ftdmchan->sockfd, priv->addr.dev, priv->addr.channel);
 #endif
        if ((retval = sendto(ftdmchan->sockfd, wbuf, size, 0, NULL, 0)) != size) {
-               ftdm_log(FTDM_LOG_ERROR, "mISDN channel %d:%d socket write error: %s\n",
-                       ftdm_channel_get_span_id(ftdmchan), ftdm_channel_get_id(ftdmchan),
+               ftdm_log_chan(ftdmchan, FTDM_LOG_ERROR, "mISDN channel socket write error: %s\n",
                        strerror(errno));
                return FTDM_FAIL;
        }
        *datalen = retval;
 
-//     if (priv->debugfd >= 0) {
-//             write(priv->debugfd, wbuf + MISDN_HEADER_LEN, size  - MISDN_HEADER_LEN);
-//     }
-
        priv->tx_cnt++;
        return FTDM_SUCCESS;
 }