pjsip_scheduler.c: Add ability to trace scheduled tasks.

When a scheduled task is created you can pass in the
AST_SIP_SCHED_TASK_TRACK flag.  This new flag causes scheduling events to
be logged.

Change-Id: I91967eb3d5a220915ce86881a28af772f9a7f56b

diff --git a/include/asterisk/res_pjsip.h b/include/asterisk/res_pjsip.h
index d9e43c1bae8a55e375bf0dbcdd936153301b0512..92813d079d0410a8061a68839a9e3f2ac303b4e6 100644 (file)
--- a/include/asterisk/res_pjsip.h
+++ b/include/asterisk/res_pjsip.h
@@ -1649,16 +1649,23 @@ enum ast_sip_scheduler_task_flags {
         */
        AST_SIP_SCHED_TASK_DATA_FREE = ( 1 << 3 ),
 
-       /*! \brief AST_SIP_SCHED_TASK_PERIODIC
-        * The task is scheduled at multiples of interval
+       /*!
+        * \brief The task is scheduled at multiples of interval
         * \see Interval
         */
        AST_SIP_SCHED_TASK_PERIODIC = (0 << 4),
-       /*! \brief AST_SIP_SCHED_TASK_DELAY
-        * The next invocation of the task is at last finish + interval
+       /*!
+        * \brief The next invocation of the task is at last finish + interval
         * \see Interval
         */
        AST_SIP_SCHED_TASK_DELAY = (1 << 4),
+       /*!
+        * \brief The scheduled task's events are tracked in the debug log.
+        * \details
+        * Schedule events such as scheduling, running, rescheduling, canceling,
+        * and destroying are logged about the task.
+        */
+       AST_SIP_SCHED_TASK_TRACK = (1 << 5),
 };
 
 /*!

diff --git a/res/res_pjsip/pjsip_scheduler.c b/res/res_pjsip/pjsip_scheduler.c
index 88773c3c2eac1d403151747834e46abcbe5d0a87..20241d17a52cf7588f6e4263eed2b112771e304b 100644 (file)
--- a/res/res_pjsip/pjsip_scheduler.c
+++ b/res/res_pjsip/pjsip_scheduler.c
@@ -88,6 +88,9 @@ static int run_task(void *data)
                return -1;
        }
 
+       if (schtd->flags & AST_SIP_SCHED_TASK_TRACK) {
+               ast_log(LOG_DEBUG, "Sched %p: Running %s\n", schtd, schtd->name);
+       }
        ao2_lock(schtd);
        schtd->last_start = ast_tvnow();
        schtd->is_running = 1;
@@ -139,6 +142,10 @@ static int run_task(void *data)
        }
 
        ao2_unlock(schtd);
+       if (schtd->flags & AST_SIP_SCHED_TASK_TRACK) {
+               ast_log(LOG_DEBUG, "Sched %p: Rescheduled %s for %d ms\n", schtd, schtd->name,
+                       delay);
+       }
 
        return 0;
 }
@@ -161,6 +168,9 @@ static int push_to_serializer(const void *data)
                return 0;
        }
 
+       if (schtd->flags & AST_SIP_SCHED_TASK_TRACK) {
+               ast_log(LOG_DEBUG, "Sched %p: Ready to run %s\n", schtd, schtd->name);
+       }
        ao2_t_ref(schtd, +1, "Give ref to run_task()");
        if (ast_sip_push_task(schtd->serializer, run_task, schtd)) {
                /*
@@ -183,6 +193,10 @@ int ast_sip_sched_task_cancel(struct ast_sip_sched_task *schtd)
        int res;
        int sched_id;
 
+       if (schtd->flags & AST_SIP_SCHED_TASK_TRACK) {
+               ast_log(LOG_DEBUG, "Sched %p: Canceling %s\n", schtd, schtd->name);
+       }
+
        /*
         * Prevent any tasks in the serializer queue from
         * running and restarting the scheduled item on us
@@ -349,6 +363,9 @@ static void schtd_dtor(void *data)
 {
        struct ast_sip_sched_task *schtd = data;
 
+       if (schtd->flags & AST_SIP_SCHED_TASK_TRACK) {
+               ast_log(LOG_DEBUG, "Sched %p: Destructor %s\n", schtd, schtd->name);
+       }
        if (schtd->flags & AST_SIP_SCHED_TASK_DATA_AO2) {
                /* release our own ref, then release the callers if asked to do so */
                ao2_ref(schtd->task_data, (schtd->flags & AST_SIP_SCHED_TASK_DATA_FREE) ? -2 : -1);
@@ -389,6 +406,10 @@ struct ast_sip_sched_task *ast_sip_schedule_task(struct ast_taskprocessor *seria
                task_id = ast_atomic_fetchadd_int(&task_count, 1);
                sprintf(schtd->name, "task_%08x", task_id);
        }
+       if (schtd->flags & AST_SIP_SCHED_TASK_TRACK) {
+               ast_log(LOG_DEBUG, "Sched %p: Scheduling %s for %d ms\n", schtd, schtd->name,
+                       interval);
+       }
        schtd->when_queued = ast_tvnow();
        if (!(schtd->flags & AST_SIP_SCHED_TASK_DELAY)) {
                schtd->next_periodic = ast_tvadd(schtd->when_queued,