[COMMON] media: mfc: print information if open failed
authorJeonghee Kim <jhhhh.kim@samsung.com>
Mon, 20 Aug 2018 07:20:48 +0000 (16:20 +0900)
committerhskang <hs1218.kang@samsung.com>
Sun, 9 Sep 2018 21:39:16 +0000 (06:39 +0900)
Change-Id: Ia287436790c71a6081cf7e26b12ec959c87f2094
Signed-off-by: Jeonghee Kim <jhhhh.kim@samsung.com>
drivers/media/platform/exynos/mfc/mfc.c
drivers/media/platform/exynos/mfc/mfc_data_struct.h
drivers/media/platform/exynos/mfc/mfc_debug.h
drivers/media/platform/exynos/mfc/mfc_dec_v4l2.c
drivers/media/platform/exynos/mfc/mfc_dec_vb2.c
drivers/media/platform/exynos/mfc/mfc_enc_v4l2.c
drivers/media/platform/exynos/mfc/mfc_enc_vb2.c
drivers/media/platform/exynos/mfc/mfc_hwlock.c
drivers/media/platform/exynos/mfc/mfc_watchdog.c

index da60d601602acdc679e943bff8e5a66d544a2b23..2ee1250fc0524e36618e7f2b49f57bb43c14bc20 100644 (file)
@@ -59,7 +59,7 @@
 #define MFC_ENC_OTF_DRM_NAME           "s5p-mfc-enc-otf-secure"
 
 struct _mfc_trace g_mfc_trace[MFC_TRACE_COUNT_MAX];
-struct _mfc_trace g_mfc_trace_hwlock[MFC_TRACE_COUNT_MAX];
+struct _mfc_trace g_mfc_trace_longterm[MFC_TRACE_COUNT_MAX];
 struct mfc_dev *g_mfc_dev;
 
 #ifdef CONFIG_EXYNOS_CONTENT_PATH_PROTECTION
@@ -372,7 +372,6 @@ static int __mfc_init_instance(struct mfc_dev *dev, struct mfc_ctx *ctx)
        if (dbg_enable)
                mfc_alloc_dbg_info_buffer(dev);
 
-       MFC_TRACE_DEV_HWLOCK("**open\n");
        ret = mfc_get_hwlock_dev(dev);
        if (ret < 0) {
                mfc_err_dev("Failed to get hwlock\n");
@@ -519,6 +518,8 @@ static int mfc_open(struct file *file)
                ctx->num++;
                if (ctx->num >= MFC_NUM_CONTEXTS) {
                        mfc_err_dev("Too many open contexts\n");
+                       mfc_err_dev("Print information to check if there was an error or not\n");
+                       call_dop(dev, dump_info_context, dev);
                        ret = -EBUSY;
                        goto err_ctx_num;
                }
@@ -558,6 +559,8 @@ static int mfc_open(struct file *file)
                                        dev->num_drm_inst, dev->num_inst);
                } else {
                        mfc_err_ctx("Too many instance are opened for DRM\n");
+                       mfc_err_dev("Print information to check if there was an error or not\n");
+                       call_dop(dev, dump_info_context, dev);
                        ret = -EINVAL;
                        goto err_drm_start;
                }
@@ -593,6 +596,8 @@ static int mfc_open(struct file *file)
        trace_mfc_node_open(ctx->num, dev->num_inst, ctx->type, ctx->is_drm);
        mfc_info_ctx("MFC open completed [%d:%d] dev = 0x%p, ctx = 0x%p, version = %d\n",
                        dev->num_drm_inst, dev->num_inst, dev, ctx, MFC_DRIVER_INFO);
+       MFC_TRACE_CTX_LT("[INFO] %s %s opened (ctx:%d, total:%d)\n", ctx->is_drm ? "DRM" : "Normal",
+                       mfc_is_decoder_node(node) ? "DEC" : "ENC", ctx->num, dev->num_inst);
        mutex_unlock(&dev->mfc_mutex);
        return ret;
 
@@ -632,6 +637,8 @@ err_no_device:
 
 static int __mfc_wait_close_inst(struct mfc_dev *dev, struct mfc_ctx *ctx)
 {
+       int ret;
+
        if (atomic_read(&dev->watchdog_run)) {
                mfc_err_ctx("watchdog already running!\n");
                return 0;
@@ -648,20 +655,25 @@ static int __mfc_wait_close_inst(struct mfc_dev *dev, struct mfc_ctx *ctx)
 
        /* To issue the command 'CLOSE_INSTANCE' */
        if (mfc_just_run(dev, ctx->num)) {
-               mfc_err_ctx("Failed to run MFC\n");
+               mfc_err_ctx("failed to run MFC, state: %d\n", ctx->state);
+               MFC_TRACE_CTX_LT("[ERR][Release] failed to run MFC, state: %d\n", ctx->state);
                return -EIO;
        }
 
        /* Wait until instance is returned or timeout occured */
-       if (mfc_wait_for_done_ctx(ctx,
-                               MFC_REG_R2H_CMD_CLOSE_INSTANCE_RET) == 1) {
-               mfc_err_ctx("Waiting for CLOSE_INSTANCE timed out\n");
+       ret = mfc_wait_for_done_ctx(ctx, MFC_REG_R2H_CMD_CLOSE_INSTANCE_RET);
+       if (ret == 1) {
+               mfc_err_ctx("failed to wait CLOSE_INSTANCE(timeout)\n");
+
                if (mfc_wait_for_done_ctx(ctx,
                                        MFC_REG_R2H_CMD_CLOSE_INSTANCE_RET)) {
-                       mfc_err_ctx("waiting once more but timed out\n");
+                       mfc_err_ctx("waited once more but failed to wait CLOSE_INSTANCE\n");
                        dev->logging_data->cause |= (1 << MFC_CAUSE_FAIL_CLOSE_INST);
                        call_dop(dev, dump_and_stop_always, dev);
                }
+       } else if (ret == -1) {
+               mfc_err_ctx("failed to wait CLOSE_INSTANCE(err)\n");
+               call_dop(dev, dump_and_stop_debug_mode, dev);
        }
 
        ctx->inst_no = MFC_NO_INSTANCE_SET;
@@ -681,6 +693,8 @@ static int mfc_release(struct file *file)
        mfc_info_ctx("MFC driver release is called [%d:%d], is_drm(%d)\n",
                        dev->num_drm_inst, dev->num_inst, ctx->is_drm);
 
+       MFC_TRACE_CTX_LT("[INFO] release is called (ctx:%d, total:%d)\n", ctx->num, dev->num_inst);
+
        mfc_clear_bit(ctx->num, &dev->work_bits);
 
        /* If a H/W operation is in progress, wait for it complete */
@@ -690,10 +704,11 @@ static int mfc_release(struct file *file)
                        mfc_cleanup_work_bit_and_try_run(ctx);
                }
        }
-       MFC_TRACE_CTX_HWLOCK("**release\n");
+
        ret = mfc_get_hwlock_ctx(ctx);
        if (ret < 0) {
                mfc_err_dev("Failed to get hwlock\n");
+               MFC_TRACE_CTX_LT("[ERR][Release] failed to get hwlock (shutdown: %d)\n", dev->shutdown);
                mutex_unlock(&dev->mfc_mutex);
                return -EBUSY;
        }
@@ -786,6 +801,8 @@ static int mfc_release(struct file *file)
 
        trace_mfc_node_close(ctx->num, dev->num_inst, ctx->type, ctx->is_drm);
 
+       MFC_TRACE_CTX_LT("[INFO] Release finished (ctx:%d, total:%d)\n", ctx->num, dev->num_inst);
+
        dev->ctx[ctx->num] = 0;
        kfree(ctx);
 
@@ -1290,9 +1307,9 @@ static int mfc_probe(struct platform_device *pdev)
        __mfc_parse_dt(dev->device->of_node, dev);
 
        atomic_set(&dev->trace_ref, 0);
-       atomic_set(&dev->trace_ref_hwlock, 0);
+       atomic_set(&dev->trace_ref_longterm, 0);
        dev->mfc_trace = g_mfc_trace;
-       dev->mfc_trace_hwlock = g_mfc_trace_hwlock;
+       dev->mfc_trace_longterm = g_mfc_trace_longterm;
 
        dma_set_mask(&pdev->dev, DMA_BIT_MASK(36));
 
@@ -1524,7 +1541,6 @@ static void mfc_shutdown(struct platform_device *pdev)
        int ret;
 
        mfc_info_dev("MFC shutdown is called\n");
-       MFC_TRACE_DEV_HWLOCK("**shutdown \n");
 
        if (!mfc_pm_get_pwr_ref_cnt(dev)) {
                dev->shutdown = 1;
@@ -1560,7 +1576,6 @@ static int mfc_suspend(struct device *device)
        if (dev->num_inst == 0)
                return 0;
 
-       MFC_TRACE_DEV_HWLOCK("**sleep\n");
        ret = mfc_get_hwlock_dev(dev);
        if (ret < 0) {
                mfc_err_dev("Failed to get hwlock\n");
@@ -1589,7 +1604,6 @@ static int mfc_resume(struct device *device)
        if (dev->num_inst == 0)
                return 0;
 
-       MFC_TRACE_DEV_HWLOCK("**wakeup\n");
        ret = mfc_get_hwlock_dev(dev);
        if (ret < 0) {
                mfc_err_dev("Failed to get hwlock\n");
index 2309c2fa5ae2a48a393e01e117a48a3e0d0fd581..282997639e2dc133d96496638db14b68ddd35cb6 100644 (file)
@@ -717,6 +717,7 @@ struct mfc_dump_ops {
        void (*dump_regs)(struct mfc_dev *dev);
        void (*dump_info)(struct mfc_dev *dev);
        void (*dump_info_without_regs)(struct mfc_dev *dev);
+       void (*dump_info_context)(struct mfc_dev *dev);
        void (*dump_and_stop_always)(struct mfc_dev *dev);
        void (*dump_and_stop_debug_mode)(struct mfc_dev *dev);
 };
@@ -810,8 +811,9 @@ struct mfc_dev {
 
        atomic_t trace_ref;
        struct _mfc_trace *mfc_trace;
-       atomic_t trace_ref_hwlock;
-       struct _mfc_trace *mfc_trace_hwlock;
+       atomic_t trace_ref_longterm;
+
+       struct _mfc_trace *mfc_trace_longterm;
        bool continue_clock_on;
 
        bool shutdown;
index 179da9807fdd4719f0b47b828a6eb6d0c867df16..22eda0a3bfbf6abaa7c9b0d8f578894eba0dfc9d 100644 (file)
@@ -101,24 +101,24 @@ struct _mfc_trace {
 
 
 /* If there is no ctx structure */
-#define MFC_TRACE_DEV_HWLOCK(fmt, args...)                                                     \
+#define MFC_TRACE_DEV_LT(fmt, args...)                                                 \
        do {                                                                                    \
                int cpu = raw_smp_processor_id();                                               \
                int cnt;                                                                        \
-               cnt = atomic_inc_return(&dev->trace_ref_hwlock) & (MFC_TRACE_COUNT_MAX - 1);    \
-               dev->mfc_trace_hwlock[cnt].time = cpu_clock(cpu);                               \
-               snprintf(dev->mfc_trace_hwlock[cnt].str, MFC_TRACE_STR_LEN,                     \
+               cnt = atomic_inc_return(&dev->trace_ref_longterm) & (MFC_TRACE_COUNT_MAX - 1);  \
+               dev->mfc_trace_longterm[cnt].time = cpu_clock(cpu);                             \
+               snprintf(dev->mfc_trace_longterm[cnt].str, MFC_TRACE_STR_LEN,                   \
                                fmt, ##args);                                                   \
        } while (0)
 
 /* If there is ctx structure */
-#define MFC_TRACE_CTX_HWLOCK(fmt, args...)                                                     \
+#define MFC_TRACE_CTX_LT(fmt, args...)                                                 \
        do {                                                                                    \
                int cpu = raw_smp_processor_id();                                               \
                int cnt;                                                                        \
-               cnt = atomic_inc_return(&dev->trace_ref_hwlock) & (MFC_TRACE_COUNT_MAX - 1);    \
-               dev->mfc_trace_hwlock[cnt].time = cpu_clock(cpu);                               \
-               snprintf(dev->mfc_trace_hwlock[cnt].str, MFC_TRACE_STR_LEN,                     \
+               cnt = atomic_inc_return(&dev->trace_ref_longterm) & (MFC_TRACE_COUNT_MAX - 1);  \
+               dev->mfc_trace_longterm[cnt].time = cpu_clock(cpu);                             \
+               snprintf(dev->mfc_trace_longterm[cnt].str, MFC_TRACE_STR_LEN,                   \
                                "[c:%d] " fmt, ctx->num, ##args);                               \
        } while (0)
 
index 6faebaf069647c631231594963879b7489723829..2d045d42afa99aa26423e59709114526d4cefeac 100644 (file)
@@ -501,7 +501,6 @@ static int mfc_dec_s_fmt_vid_out_mplane(struct file *file, void *priv,
        mfc_debug(2, "[STREAM] sizeimage: %d\n", pix_fmt_mp->plane_fmt[0].sizeimage);
        pix_fmt_mp->plane_fmt[0].bytesperline = 0;
 
-       MFC_TRACE_CTX_HWLOCK("**DEC s_fmt\n");
        ret = mfc_get_hwlock_ctx(ctx);
        if (ret < 0) {
                mfc_err_ctx("Failed to get hwlock\n");
index 5f217adab6a87037f78081b1f30532166bcb97e0..bf83abfbbfa0f09815862f5a0c1ee32a526aec99 100644 (file)
@@ -383,7 +383,6 @@ static void mfc_dec_stop_streaming(struct vb2_queue *q)
                                test_bit(ctx->num, &dev->hwlock.bits), q->type);
        MFC_TRACE_CTX("** DEC streamoff(type:%d)\n", q->type);
 
-       MFC_TRACE_CTX_HWLOCK("**DEC streamoff(type:%d)\n", q->type);
        /* If a H/W operation is in progress, wait for it complete */
        ret = mfc_get_hwlock_ctx(ctx);
        if (ret < 0) {
index f991a802f3b80c055c2b24f088a4f0b568a0e65f..91d1107f8df552250cc448fe62b2aba4c98e1e8d 100644 (file)
@@ -445,8 +445,6 @@ static int mfc_enc_s_fmt_vid_cap_mplane(struct file *file, void *priv,
                return -ENOMEM;
        }
 
-       MFC_TRACE_CTX_HWLOCK("**ENC s_fmt\n");
-
        ret = mfc_get_hwlock_ctx(ctx);
        if (ret < 0) {
                mfc_err_dev("Failed to get hwlock\n");
index 97a8a361f354149272b607e69e26a3824c1ffd75..346113a32f9cfd292b11befad6b450f4bd174b9f 100644 (file)
@@ -350,7 +350,7 @@ static void mfc_enc_stop_streaming(struct vb2_queue *q)
                }
                aborted = 1;
        }
-       MFC_TRACE_CTX_HWLOCK("**ENC streamoff(type:%d)\n", q->type);
+
        ret = mfc_get_hwlock_ctx(ctx);
        if (ret < 0) {
                mfc_err_ctx("Failed to get hwlock\n");
index f46b09ce7e4c22e9367323b4b664b4a76389e75c..6e7ebd5a0d5764009037b03be41ab8b0321d8b04 100644 (file)
@@ -133,11 +133,6 @@ int mfc_get_hwlock_dev(struct mfc_dev *dev)
                        ((dev->hwlock.transfer_owner == 1) && (dev->hwlock.dev == 1)),
                        msecs_to_jiffies(MFC_HWLOCK_TIMEOUT));
 
-               MFC_TRACE_DEV_HWLOCK("get_hwlock_dev: before waiting\n");
-               MFC_TRACE_DEV_HWLOCK(">>dev:0x%lx, bits:0x%lx, owned:%d, wl:%d, trans:%d\n",
-                               dev->hwlock.dev, dev->hwlock.bits, dev->hwlock.owned_by_irq,
-                               dev->hwlock.wl_count, dev->hwlock.transfer_owner);
-
                dev->hwlock.transfer_owner = 0;
                __mfc_remove_listable_wq_dev(dev);
                if (ret == 0) {
@@ -155,11 +150,6 @@ int mfc_get_hwlock_dev(struct mfc_dev *dev)
                dev->hwlock.dev = 1;
                dev->hwlock.owned_by_irq = 0;
 
-               MFC_TRACE_DEV_HWLOCK("get_hwlock_dev: no waiting\n");
-               MFC_TRACE_DEV_HWLOCK(">>dev:0x%lx, bits:0x%lx, owned:%d, wl:%d, trans:%d\n",
-                               dev->hwlock.dev, dev->hwlock.bits, dev->hwlock.owned_by_irq,
-                               dev->hwlock.wl_count, dev->hwlock.transfer_owner);
-
                __mfc_print_hwlock(dev);
                spin_unlock_irqrestore(&dev->hwlock.lock, flags);
                mutex_unlock(&dev->hwlock_wq.wait_mutex);
@@ -179,7 +169,6 @@ int mfc_get_hwlock_dev(struct mfc_dev *dev)
  */
 int mfc_get_hwlock_ctx(struct mfc_ctx *curr_ctx)
 {
-       struct mfc_ctx *ctx = curr_ctx;
        struct mfc_dev *dev = curr_ctx->dev;
        int ret = 0;
        unsigned long flags;
@@ -202,22 +191,12 @@ int mfc_get_hwlock_ctx(struct mfc_ctx *curr_ctx)
 
                spin_unlock_irqrestore(&dev->hwlock.lock, flags);
 
-               MFC_TRACE_CTX_HWLOCK("get_hwlock_ctx: before waiting\n");
-               MFC_TRACE_CTX_HWLOCK(">>dev:0x%lx, bits:0x%lx, owned:%d, wl:%d, trans:%d\n",
-                               dev->hwlock.dev, dev->hwlock.bits, dev->hwlock.owned_by_irq,
-                               dev->hwlock.wl_count, dev->hwlock.transfer_owner);
-
                mfc_debug(2, "Waiting for hwlock to be released\n");
 
                ret = wait_event_timeout(curr_ctx->hwlock_wq.wait_queue,
                        ((dev->hwlock.transfer_owner == 1) && (test_bit(curr_ctx->num, &dev->hwlock.bits))),
                        msecs_to_jiffies(MFC_HWLOCK_TIMEOUT));
 
-               MFC_TRACE_CTX_HWLOCK("get_hwlock_ctx: after waiting, ret:%d\n", ret);
-               MFC_TRACE_CTX_HWLOCK(">>dev:0x%lx, bits:0x%lx, owned:%d, wl:%d, trans:%d\n",
-                               dev->hwlock.dev, dev->hwlock.bits, dev->hwlock.owned_by_irq,
-                               dev->hwlock.wl_count, dev->hwlock.transfer_owner);
-
                dev->hwlock.transfer_owner = 0;
                __mfc_remove_listable_wq_ctx(curr_ctx);
                if (ret == 0) {
@@ -236,11 +215,6 @@ int mfc_get_hwlock_ctx(struct mfc_ctx *curr_ctx)
                set_bit(curr_ctx->num, &dev->hwlock.bits);
                dev->hwlock.owned_by_irq = 0;
 
-               MFC_TRACE_CTX_HWLOCK("get_hwlock_ctx: no waiting\n");
-               MFC_TRACE_CTX_HWLOCK(">>dev:0x%lx, bits:0x%lx, owned:%d, wl:%d, trans:%d\n",
-                               dev->hwlock.dev, dev->hwlock.bits, dev->hwlock.owned_by_irq,
-                               dev->hwlock.wl_count, dev->hwlock.transfer_owner);
-
                __mfc_print_hwlock(dev);
                spin_unlock_irqrestore(&dev->hwlock.lock, flags);
                mutex_unlock(&curr_ctx->hwlock_wq.wait_mutex);
@@ -290,11 +264,6 @@ void mfc_release_hwlock_dev(struct mfc_dev *dev)
 
                dev->hwlock.transfer_owner = 1;
 
-               MFC_TRACE_DEV_HWLOCK("release_hwlock_dev: wakeup\n");
-               MFC_TRACE_DEV_HWLOCK(">>dev:0x%lx, bits:0x%lx, owned:%d, wl:%d, trans:%d\n",
-                               dev->hwlock.dev, dev->hwlock.bits, dev->hwlock.owned_by_irq,
-                               dev->hwlock.wl_count, dev->hwlock.transfer_owner);
-
                wake_up(&listable_wq->wait_queue);
        }
 
@@ -312,7 +281,6 @@ void mfc_release_hwlock_dev(struct mfc_dev *dev)
 static void __mfc_release_hwlock_ctx_protected(struct mfc_ctx *curr_ctx)
 {
        struct mfc_dev *dev = curr_ctx->dev;
-       struct mfc_ctx *ctx = curr_ctx;
        struct mfc_listable_wq *listable_wq;
 
        __mfc_print_hwlock(dev);
@@ -339,11 +307,6 @@ static void __mfc_release_hwlock_ctx_protected(struct mfc_ctx *curr_ctx)
 
                dev->hwlock.transfer_owner = 1;
 
-               MFC_TRACE_CTX_HWLOCK("release_hwlock_ctx: wakeup\n");
-               MFC_TRACE_CTX_HWLOCK(">>dev:0x%lx, bits:0x%lx, owned:%d, wl:%d, trans:%d\n",
-                               dev->hwlock.dev, dev->hwlock.bits, dev->hwlock.owned_by_irq,
-                               dev->hwlock.wl_count, dev->hwlock.transfer_owner);
-
                wake_up(&listable_wq->wait_queue);
        }
 
index 96bc08af3d92fd2be020741931a631b63a2365a1..66b59109a2bc9b0391d9291d5023ef7f313eafa5 100644 (file)
@@ -216,6 +216,20 @@ static void __mfc_dump_trace(struct mfc_dev *dev)
        }
 }
 
+static void __mfc_dump_trace_longterm(struct mfc_dev *dev)
+{
+       int i, cnt, trace_cnt;
+
+       pr_err("-----------dumping MFC trace long-term info-----------\n");
+
+       trace_cnt = atomic_read(&dev->trace_ref_longterm);
+       for (i = MFC_TRACE_COUNT_PRINT - 1; i >= 0; i--) {
+               cnt = ((trace_cnt + MFC_TRACE_COUNT_MAX) - i) % MFC_TRACE_COUNT_MAX;
+               pr_err("MFC trace longterm[%d]: time=%llu, str=%s", cnt,
+                               dev->mfc_trace_longterm[cnt].time, dev->mfc_trace_longterm[cnt].str);
+       }
+}
+
 void __mfc_dump_buffer_info(struct mfc_dev *dev)
 {
        struct mfc_ctx *ctx;
@@ -337,6 +351,12 @@ static void __mfc_dump_struct(struct mfc_dev *dev)
        }
 }
 
+static void __mfc_dump_info_context(struct mfc_dev *dev)
+{
+       __mfc_dump_state(dev);
+       __mfc_dump_trace_longterm(dev);
+}
+
 static void __mfc_dump_info_without_regs(struct mfc_dev *dev)
 {
        __mfc_dump_state(dev);
@@ -418,6 +438,7 @@ struct mfc_dump_ops mfc_dump_ops = {
        .dump_regs                      = __mfc_dump_regs,
        .dump_info                      = __mfc_dump_info,
        .dump_info_without_regs         = __mfc_dump_info_without_regs,
+       .dump_info_context              = __mfc_dump_info_context,
        .dump_and_stop_always           = __mfc_dump_info_and_stop_hw,
        .dump_and_stop_debug_mode       = __mfc_dump_info_and_stop_hw_debug,
 };