Attachment 128606 Details for Bug 99130 – ftrace call graph log for i915_gem_wait_ioctl

ftrace call graph log for i915_gem_wait_ioctl

ioctl_graph_bad.log (text/x-c), 11.79 KB, created by Dorota Czaplejewicz on 2016-12-21 14:50:00 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Dorota Czaplejewicz

Created: 2016-12-21 14:50:00 UTC

Size: 11.79 KB

patch

obsolete

>CPU 0 is empty
>CPU 1 is empty
>CPU 4 is empty
>CPU 5 is empty
>CPU 7 is empty
>cpus=8
>        gem_wait-21904 [003]  7660.658879: funcgraph_entry:                   |  sys_ioctl() {
>        gem_wait-21904 [003]  7660.658879: funcgraph_entry:                   |    __fdget() {
>        gem_wait-21904 [003]  7660.658879: funcgraph_entry:        0.066 us   |      __fget_light();
>        gem_wait-21904 [003]  7660.658880: funcgraph_exit:         0.254 us   |    }
>        gem_wait-21904 [003]  7660.658880: funcgraph_entry:                   |    do_vfs_ioctl() {
>        gem_wait-21904 [003]  7660.658880: funcgraph_entry:                   |      drm_ioctl() {
>        gem_wait-21904 [003]  7660.658880: funcgraph_entry:                   |        drm_printk() {
>        gem_wait-21904 [003]  7660.658880: funcgraph_entry:                   |          printk() {
>        gem_wait-21904 [003]  7660.658880: funcgraph_entry:                   |            vprintk_default() {
>        gem_wait-21904 [003]  7660.658880: funcgraph_entry:                   |              vprintk_emit() {
>        gem_wait-21904 [003]  7660.658880: funcgraph_entry:        0.061 us   |                __cpuidle_text_end();
>        gem_wait-21904 [003]  7660.658881: funcgraph_entry:        0.611 us   |                sprint_symbol_no_offset();
>        gem_wait-21904 [003]  7660.658882: funcgraph_entry:        0.136 us   |                log_store();
>        gem_wait-21904 [003]  7660.658883: funcgraph_entry:        0.048 us   |                _raw_spin_unlock();
>        gem_wait-21904 [003]  7660.658883: funcgraph_entry:        0.179 us   |                console_trylock();
>        gem_wait-21904 [003]  7660.658883: funcgraph_entry:      ! 645.154 us |                console_unlock();
>        gem_wait-21904 [003]  7660.659529: funcgraph_exit:       ! 648.403 us |              }
>        gem_wait-21904 [003]  7660.659529: funcgraph_exit:       ! 648.641 us |            }
>        gem_wait-21904 [003]  7660.659529: funcgraph_exit:       ! 648.865 us |          }
>        gem_wait-21904 [003]  7660.659529: funcgraph_exit:       ! 649.108 us |        }
>        gem_wait-21904 [003]  7660.659529: funcgraph_entry:        0.063 us   |        drm_ioctl_permit();
>        gem_wait-21904 [003]  7660.659530: funcgraph_entry:                   |        __might_fault() {
>        gem_wait-21904 [003]  7660.659530: funcgraph_entry:                   |          __might_sleep() {
>        gem_wait-21904 [003]  7660.659530: funcgraph_entry:        0.024 us   |            ___might_sleep();
>        gem_wait-21904 [003]  7660.659530: funcgraph_exit:         0.238 us   |          }
>        gem_wait-21904 [003]  7660.659530: funcgraph_exit:         0.482 us   |        }
>        gem_wait-21904 [003]  7660.659530: funcgraph_entry:                   |        i915_gem_wait_ioctl() {
>        gem_wait-21904 [003]  7660.659531: funcgraph_entry:        0.026 us   |          __rcu_read_lock();
>        gem_wait-21904 [003]  7660.659531: funcgraph_entry:        0.026 us   |          __rcu_read_unlock();
>        gem_wait-21904 [003]  7660.659531: funcgraph_entry:        0.104 us   |          ktime_get();
>        gem_wait-21904 [003]  7660.659531: funcgraph_entry:                   |          i915_gem_object_wait() {
>        gem_wait-21904 [003]  7660.659531: funcgraph_entry:                   |            __might_sleep() {
>        gem_wait-21904 [003]  7660.659532: funcgraph_entry:        0.029 us   |              ___might_sleep();
>        gem_wait-21904 [003]  7660.659532: funcgraph_exit:         0.247 us   |            }
>        gem_wait-21904 [003]  7660.659532: funcgraph_entry:                   |            reservation_object_get_fences_rcu() {
>        gem_wait-21904 [003]  7660.659532: funcgraph_entry:        0.021 us   |              __rcu_read_lock();
>        gem_wait-21904 [003]  7660.659532: funcgraph_entry:                   |              krealloc() {
>        gem_wait-21904 [003]  7660.659533: funcgraph_entry:        3.126 us   |                __kmalloc_track_caller();
>        gem_wait-21904 [003]  7660.659536: funcgraph_entry:        0.066 us   |                kfree();
>        gem_wait-21904 [003]  7660.659536: funcgraph_exit:         3.610 us   |              }
>        gem_wait-21904 [003]  7660.659536: funcgraph_entry:        0.020 us   |              __rcu_read_unlock();
>        gem_wait-21904 [003]  7660.659537: funcgraph_exit:         4.562 us   |            }
>        gem_wait-21904 [003]  7660.659537: funcgraph_entry:                   |            i915_gem_object_wait_fence() {
>        gem_wait-21904 [003]  7660.659537: funcgraph_entry:                   |              __cpuidle_text_end() {
>        gem_wait-21904 [003]  7660.659537: funcgraph_entry:        0.021 us   |                preempt_count_add();
>        gem_wait-21904 [003]  7660.659537: funcgraph_entry:        0.027 us   |                do_raw_spin_lock();
>        gem_wait-21904 [003]  7660.659538: funcgraph_exit:         0.479 us   |              }
>        gem_wait-21904 [003]  7660.659538: funcgraph_entry:                   |              _raw_spin_unlock() {
>        gem_wait-21904 [003]  7660.659538: funcgraph_entry:        0.026 us   |                do_raw_spin_unlock();
>        gem_wait-21904 [003]  7660.659538: funcgraph_entry:        0.026 us   |                preempt_count_sub();
>        gem_wait-21904 [003]  7660.659538: funcgraph_exit:         0.461 us   |              }
>        gem_wait-21904 [003]  7660.659538: funcgraph_exit:         1.466 us   |            }
>        gem_wait-21904 [003]  7660.659538: funcgraph_entry:                   |            i915_gem_object_wait_fence() {
>        gem_wait-21904 [003]  7660.659539: funcgraph_entry:                   |              __cpuidle_text_end() {
>        gem_wait-21904 [003]  7660.659539: funcgraph_entry:        0.021 us   |                preempt_count_add();
>        gem_wait-21904 [003]  7660.659539: funcgraph_entry:        0.028 us   |                do_raw_spin_lock();
>        gem_wait-21904 [003]  7660.659539: funcgraph_exit:         0.444 us   |              }
>        gem_wait-21904 [003]  7660.659539: funcgraph_entry:                   |              _raw_spin_unlock() {
>        gem_wait-21904 [003]  7660.659539: funcgraph_entry:        0.027 us   |                do_raw_spin_unlock();
>        gem_wait-21904 [003]  7660.659539: funcgraph_entry:        0.020 us   |                preempt_count_sub();
>        gem_wait-21904 [003]  7660.659540: funcgraph_exit:         0.444 us   |              }
>        gem_wait-21904 [003]  7660.659540: funcgraph_exit:         1.301 us   |            }
>        gem_wait-21904 [003]  7660.659540: funcgraph_entry:                   |            i915_gem_object_wait_fence() {
>        gem_wait-21904 [003]  7660.659540: funcgraph_entry:                   |              __cpuidle_text_end() {
>        gem_wait-21904 [003]  7660.659540: funcgraph_entry:        0.027 us   |                preempt_count_add();
>        gem_wait-21904 [003]  7660.659540: funcgraph_entry:        0.029 us   |                do_raw_spin_lock();
>        gem_wait-21904 [003]  7660.659541: funcgraph_exit:         0.447 us   |              }
>        gem_wait-21904 [003]  7660.659541: funcgraph_entry:                   |              _raw_spin_unlock() {
>        gem_wait-21904 [003]  7660.659541: funcgraph_entry:                   |                do_raw_spin_unlock() {
>        gem_wait-21904 [003]  7660.659541: funcgraph_entry:        3.778 us   |                smp_irq_work_interrupt();
>        gem_wait-21904 [003]  7660.659546: funcgraph_exit:         0.034 us   |                }
>        gem_wait-21904 [003]  7660.659546: funcgraph_entry:        0.021 us   |                preempt_count_sub();
>        gem_wait-21904 [003]  7660.659550: funcgraph_exit:         8.963 us   |              }
>        gem_wait-21904 [003]  7660.659550: funcgraph_exit:         9.837 us   |            }
>        gem_wait-21904 [003]  7660.659550: funcgraph_entry:                   |            kfree() {
>        gem_wait-21904 [003]  7660.659550: funcgraph_entry:        0.020 us   |              kmemleak_free();
>        gem_wait-21904 [003]  7660.659550: funcgraph_entry:                   |              _raw_spin_lock_irqsave() {
>        gem_wait-21904 [003]  7660.659550: funcgraph_entry:        0.038 us   |                preempt_count_add();
>        gem_wait-21904 [003]  7660.659551: funcgraph_entry:        0.032 us   |                do_raw_spin_lock();
>        gem_wait-21904 [003]  7660.659551: funcgraph_exit:         0.565 us   |              }
>        gem_wait-21904 [003]  7660.659551: funcgraph_entry:                   |              _raw_spin_unlock_irqrestore() {
>        gem_wait-21904 [003]  7660.659551: funcgraph_entry:        0.027 us   |                do_raw_spin_unlock();
>        gem_wait-21904 [003]  7660.659552: funcgraph_entry:        0.025 us   |                preempt_count_sub();
>        gem_wait-21904 [003]  7660.659552: funcgraph_exit:         0.481 us   |              }
>        gem_wait-21904 [003]  7660.659552: funcgraph_entry:                   |              __slab_free() {
>        gem_wait-21904 [003]  7660.659552: funcgraph_entry:        1.858 us   |                free_debug_processing();
>        gem_wait-21904 [003]  7660.659554: funcgraph_entry:        0.029 us   |                preempt_count_add();
>        gem_wait-21904 [003]  7660.659554: funcgraph_entry:        0.028 us   |                preempt_count_sub();
>        gem_wait-21904 [003]  7660.659555: funcgraph_exit:         2.564 us   |              }
>        gem_wait-21904 [003]  7660.659555: funcgraph_exit:         4.571 us   |            }
>        gem_wait-21904 [003]  7660.659555: funcgraph_exit:       + 23.282 us  |          }
>        gem_wait-21904 [003]  7660.659555: funcgraph_entry:        0.035 us   |          ns_to_timespec();
>        gem_wait-21904 [003]  7660.659555: funcgraph_entry:        0.025 us   |          ns_to_timespec();
>        gem_wait-21904 [003]  7660.659555: funcgraph_entry:                   |          printk() {
>        gem_wait-21904 [003]  7660.659555: funcgraph_entry:                   |            vprintk_default() {
>        gem_wait-21904 [003]  7660.659556: funcgraph_entry:                   |              vprintk_emit() {
>        gem_wait-21904 [003]  7660.659556: funcgraph_entry:        0.056 us   |                __cpuidle_text_end();
>        gem_wait-21904 [003]  7660.659557: funcgraph_entry:        0.139 us   |                log_store();
>        gem_wait-21904 [003]  7660.659557: funcgraph_entry:        0.066 us   |                _raw_spin_unlock();
>        gem_wait-21904 [003]  7660.659557: funcgraph_entry:        0.202 us   |                console_trylock();
>        gem_wait-21904 [003]  7660.659558: funcgraph_entry:      ! 633.916 us |                console_unlock();
>        gem_wait-21904 [003]  7660.660192: funcgraph_exit:       ! 636.287 us |              }
>        gem_wait-21904 [003]  7660.660192: funcgraph_exit:       ! 636.515 us |            }
>        gem_wait-21904 [003]  7660.660192: funcgraph_exit:       ! 636.805 us |          }
>        gem_wait-21904 [003]  7660.660192: funcgraph_exit:       ! 661.850 us |        }
>        gem_wait-21904 [003]  7660.660192: funcgraph_entry:                   |        __might_fault() {
>        gem_wait-21904 [003]  7660.660193: funcgraph_entry:                   |          __might_sleep() {
>        gem_wait-21904 [003]  7660.660193: funcgraph_entry:        0.029 us   |            ___might_sleep();
>        gem_wait-21904 [003]  7660.660193: funcgraph_exit:         0.224 us   |          }
>        gem_wait-21904 [003]  7660.660193: funcgraph_exit:         0.481 us   |        }
>        gem_wait-21904 [003]  7660.660193: funcgraph_exit:       # 1313.307 us |      }
>        gem_wait-21904 [003]  7660.660193: funcgraph_exit:       # 1313.576 us |    }
>        gem_wait-21904 [003]  7660.660193: funcgraph_exit:       # 1314.252 us |  }
>

Actions: View

Attachments on bug 99130: 128524 | 128525 | 128544 | 128545 | 128546 | 128547 | 128548 | 128606

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.