[deliverable/lttng-analyses.git] / tests / test_irq.py

#!/usr/bin/env python3

from TraceTest import AnalyzesTest
import sys


class IrqTest(AnalyzesTest):
    def __init__(self, delete_trace=True, verbose=False):
        super().__init__(delete_trace=delete_trace,
                         verbose=verbose)
        self.test_list = [('irqstats', self.run_irqstats),
                          ('irqlog', self.run_irqlog)]

    def write_trace(self):
        self.t.write_softirq_raise(1000 , 1, 1)
        self.t.write_softirq_raise(1001 , 3, 1)
        self.t.write_softirq_raise(1002 , 1, 9)
        self.t.write_softirq_exit(1003 , 0, 4)
        self.t.write_softirq_raise(1004 , 3, 9)
        self.t.write_softirq_raise(1005 , 3, 7)
        self.t.write_softirq_entry(1006 , 3, 1)
        self.t.write_softirq_entry(1007 , 1, 1)
        self.t.write_softirq_exit(1008 , 1, 1)
        self.t.write_softirq_exit(1009 , 3, 1)
        self.t.write_softirq_entry(1010 , 1, 9)
        self.t.write_softirq_entry(1011 , 3, 7)
        self.t.write_softirq_exit(1012 , 1, 9)
        self.t.write_softirq_exit(1013 , 3, 7)
        self.t.write_softirq_entry(1014 , 3, 9)
        self.t.write_softirq_exit(1015 , 3, 9)
        self.t.write_irq_handler_entry(1016 , 0, 41, "ahci")
        self.t.write_softirq_raise(1017 , 0, 4)
        self.t.write_irq_handler_exit(1018 , 0, 41, 1)
        self.t.write_softirq_entry(1019 , 0, 4)
        self.t.write_softirq_exit(1020 , 0, 4)
        self.t.write_irq_handler_entry(1021 , 0, 41, "ahci")
        self.t.write_softirq_raise(1022 , 0, 4)
        self.t.write_irq_handler_exit(1023 , 0, 41, 1)
        self.t.write_softirq_entry(1024 , 0, 4)
        self.t.write_softirq_exit(1025 , 0, 4)
        self.t.write_irq_handler_entry(1026 , 0, 41, "ahci")
        self.t.write_softirq_raise(1027 , 0, 4)
        self.t.write_irq_handler_exit(1028 , 0, 41, 1)
        self.t.write_softirq_entry(1029 , 0, 4)
        self.t.write_softirq_exit(1030 , 0, 4)
        self.t.write_irq_handler_entry(1031 , 0, 41, "ahci")
        self.t.write_softirq_raise(1032 , 0, 4)
        self.t.write_irq_handler_exit(1033 , 0, 41, 1)
        self.t.write_softirq_entry(1034 , 0, 4)
        self.t.write_softirq_exit(1035 , 0, 4)
        self.t.write_irq_handler_entry(1036 , 0, 41, "ahci")
        self.t.write_softirq_raise(1037 , 0, 4)
        self.t.write_irq_handler_exit(1038 , 0, 41, 1)
        self.t.write_softirq_entry(1039 , 0, 4)
        self.t.write_softirq_exit(1040 , 0, 4)
        self.t.write_irq_handler_entry(1041 , 0, 41, "ahci")
        self.t.write_softirq_raise(1042 , 0, 4)
        self.t.write_irq_handler_exit(1043 , 0, 41, 1)
        self.t.write_softirq_entry(1044 , 0, 4)
        self.t.write_softirq_exit(1045 , 0, 4)
        self.t.flush()

    def run_irqstats(self):
        expected = """Timerange: [1969-12-31 19:00:01.000000000, 1969-12-31 19:00:01.045000000]
Hard IRQ                                             Duration (us)
                       count          min          avg          max        stdev       
----------------------------------------------------------------------------------|
41: <ahci>                 6     2000.000     2000.000     2000.000        0.000  |

Soft IRQ                                             Duration (us)                                        Raise latency (us)
                       count          min          avg          max        stdev  |  count          min          avg          max        stdev       
----------------------------------------------------------------------------------|------------------------------------------------------------
1:  <TIMER_SOFTIRQ>        2     1000.000     2000.000     3000.000     1414.214  |      2     5000.000     6000.000     7000.000     1414.214
4:  <BLOCK_SOFTIRQ>        6     1000.000     1000.000     1000.000        0.000  |      6     2000.000     2000.000     2000.000        0.000
7:  <SCHED_SOFTIRQ>        1     2000.000     2000.000     2000.000            ?  |      1     6000.000     6000.000     6000.000            ?
9:  <RCU_SOFTIRQ>          2     1000.000     1500.000     2000.000      707.107  |      2     8000.000     9000.000    10000.000     1414.214"""

        return self.compare_output('%slttng-irqstats %s "%s"' % (
                       self.cmd_root, self.common_options, self.t.get_trace_root()),
                       expected)

    def run_irqlog(self):
        expected = """Timerange: [1969-12-31 19:00:01.000000000, 1969-12-31 19:00:01.045000000]
Begin                End                   Duration (us)  CPU  Type         #  Name                  
[19:00:01.007000000, 19:00:01.008000000]        1000.000    1  SoftIRQ      1  TIMER_SOFTIRQ (raised at 19:00:01.000000000)
[19:00:01.006000000, 19:00:01.009000000]        3000.000    3  SoftIRQ      1  TIMER_SOFTIRQ (raised at 19:00:01.001000000)
[19:00:01.010000000, 19:00:01.012000000]        2000.000    1  SoftIRQ      9  RCU_SOFTIRQ (raised at 19:00:01.002000000)
[19:00:01.011000000, 19:00:01.013000000]        2000.000    3  SoftIRQ      7  SCHED_SOFTIRQ (raised at 19:00:01.005000000)
[19:00:01.014000000, 19:00:01.015000000]        1000.000    3  SoftIRQ      9  RCU_SOFTIRQ (raised at 19:00:01.004000000)
[19:00:01.016000000, 19:00:01.018000000]        2000.000    0  IRQ         41  ahci                  
[19:00:01.019000000, 19:00:01.020000000]        1000.000    0  SoftIRQ      4  BLOCK_SOFTIRQ (raised at 19:00:01.017000000)
[19:00:01.021000000, 19:00:01.023000000]        2000.000    0  IRQ         41  ahci                  
[19:00:01.024000000, 19:00:01.025000000]        1000.000    0  SoftIRQ      4  BLOCK_SOFTIRQ (raised at 19:00:01.022000000)
[19:00:01.026000000, 19:00:01.028000000]        2000.000    0  IRQ         41  ahci                  
[19:00:01.029000000, 19:00:01.030000000]        1000.000    0  SoftIRQ      4  BLOCK_SOFTIRQ (raised at 19:00:01.027000000)
[19:00:01.031000000, 19:00:01.033000000]        2000.000    0  IRQ         41  ahci                  
[19:00:01.034000000, 19:00:01.035000000]        1000.000    0  SoftIRQ      4  BLOCK_SOFTIRQ (raised at 19:00:01.032000000)
[19:00:01.036000000, 19:00:01.038000000]        2000.000    0  IRQ         41  ahci                  
[19:00:01.039000000, 19:00:01.040000000]        1000.000    0  SoftIRQ      4  BLOCK_SOFTIRQ (raised at 19:00:01.037000000)
[19:00:01.041000000, 19:00:01.043000000]        2000.000    0  IRQ         41  ahci                  
[19:00:01.044000000, 19:00:01.045000000]        1000.000    0  SoftIRQ      4  BLOCK_SOFTIRQ (raised at 19:00:01.042000000)"""

        return self.compare_output('%slttng-irqlog %s "%s"' % (
                       self.cmd_root, self.common_options, self.t.get_trace_root()),
                       expected)


def test_answer():
    t = IrqTest(verbose=True)
    ok = t.run()
    assert(ok)
Commit	Line	Data
89086b3e JD	1	#!/usr/bin/env python3
	2
	3	from TraceTest import AnalyzesTest
	4	import sys
	5
	6
	7	class IrqTest(AnalyzesTest):
	8	def __init__(self, delete_trace=True, verbose=False):
	9	super().__init__(delete_trace=delete_trace,
	10	verbose=verbose)
	11	self.test_list = [('irqstats', self.run_irqstats),
	12	('irqlog', self.run_irqlog)]
	13
	14	def write_trace(self):
	15	self.t.write_softirq_raise(1000 , 1, 1)
	16	self.t.write_softirq_raise(1001 , 3, 1)
	17	self.t.write_softirq_raise(1002 , 1, 9)
	18	self.t.write_softirq_exit(1003 , 0, 4)
	19	self.t.write_softirq_raise(1004 , 3, 9)
	20	self.t.write_softirq_raise(1005 , 3, 7)
	21	self.t.write_softirq_entry(1006 , 3, 1)
	22	self.t.write_softirq_entry(1007 , 1, 1)
	23	self.t.write_softirq_exit(1008 , 1, 1)
	24	self.t.write_softirq_exit(1009 , 3, 1)
	25	self.t.write_softirq_entry(1010 , 1, 9)
	26	self.t.write_softirq_entry(1011 , 3, 7)
	27	self.t.write_softirq_exit(1012 , 1, 9)
	28	self.t.write_softirq_exit(1013 , 3, 7)
	29	self.t.write_softirq_entry(1014 , 3, 9)
	30	self.t.write_softirq_exit(1015 , 3, 9)
	31	self.t.write_irq_handler_entry(1016 , 0, 41, "ahci")
	32	self.t.write_softirq_raise(1017 , 0, 4)
	33	self.t.write_irq_handler_exit(1018 , 0, 41, 1)
	34	self.t.write_softirq_entry(1019 , 0, 4)
	35	self.t.write_softirq_exit(1020 , 0, 4)
	36	self.t.write_irq_handler_entry(1021 , 0, 41, "ahci")
	37	self.t.write_softirq_raise(1022 , 0, 4)
	38	self.t.write_irq_handler_exit(1023 , 0, 41, 1)
	39	self.t.write_softirq_entry(1024 , 0, 4)
	40	self.t.write_softirq_exit(1025 , 0, 4)
	41	self.t.write_irq_handler_entry(1026 , 0, 41, "ahci")
	42	self.t.write_softirq_raise(1027 , 0, 4)
	43	self.t.write_irq_handler_exit(1028 , 0, 41, 1)
	44	self.t.write_softirq_entry(1029 , 0, 4)
	45	self.t.write_softirq_exit(1030 , 0, 4)
	46	self.t.write_irq_handler_entry(1031 , 0, 41, "ahci")
	47	self.t.write_softirq_raise(1032 , 0, 4)
	48	self.t.write_irq_handler_exit(1033 , 0, 41, 1)
	49	self.t.write_softirq_entry(1034 , 0, 4)
	50	self.t.write_softirq_exit(1035 , 0, 4)
	51	self.t.write_irq_handler_entry(1036 , 0, 41, "ahci")
	52	self.t.write_softirq_raise(1037 , 0, 4)
	53	self.t.write_irq_handler_exit(1038 , 0, 41, 1)
	54	self.t.write_softirq_entry(1039 , 0, 4)
	55	self.t.write_softirq_exit(1040 , 0, 4)
	56	self.t.write_irq_handler_entry(1041 , 0, 41, "ahci")
	57	self.t.write_softirq_raise(1042 , 0, 4)
	58	self.t.write_irq_handler_exit(1043 , 0, 41, 1)
	59	self.t.write_softirq_entry(1044 , 0, 4)
	60	self.t.write_softirq_exit(1045 , 0, 4)
	61	self.t.flush()
	62
	63	def run_irqstats(self):
	64	expected = """Timerange: [1969-12-31 19:00:01.000000000, 1969-12-31 19:00:01.045000000]
65	Hard IRQ Duration (us)
66	count min avg max stdev
67	----------------------------------------------------------------------------------\|
68	41: <ahci> 6 2000.000 2000.000 2000.000 0.000 \|
69
70	Soft IRQ Duration (us) Raise latency (us)
71	count min avg max stdev \| count min avg max stdev
72	----------------------------------------------------------------------------------\|------------------------------------------------------------
73	1: <TIMER_SOFTIRQ> 2 1000.000 2000.000 3000.000 1414.214 \| 2 5000.000 6000.000 7000.000 1414.214
74	4: <BLOCK_SOFTIRQ> 6 1000.000 1000.000 1000.000 0.000 \| 6 2000.000 2000.000 2000.000 0.000
75	7: <SCHED_SOFTIRQ> 1 2000.000 2000.000 2000.000 ? \| 1 6000.000 6000.000 6000.000 ?
76	9: <RCU_SOFTIRQ> 2 1000.000 1500.000 2000.000 707.107 \| 2 8000.000 9000.000 10000.000 1414.214"""
77
78	return self.compare_output('%slttng-irqstats %s "%s"' % (
79	self.cmd_root, self.common_options, self.t.get_trace_root()),
80	expected)
81
82	def run_irqlog(self):
83	expected = """Timerange: [1969-12-31 19:00:01.000000000, 1969-12-31 19:00:01.045000000]
84	Begin End Duration (us) CPU Type # Name
85	[19:00:01.007000000, 19:00:01.008000000] 1000.000 1 SoftIRQ 1 TIMER_SOFTIRQ (raised at 19:00:01.000000000)
86	[19:00:01.006000000, 19:00:01.009000000] 3000.000 3 SoftIRQ 1 TIMER_SOFTIRQ (raised at 19:00:01.001000000)
87	[19:00:01.010000000, 19:00:01.012000000] 2000.000 1 SoftIRQ 9 RCU_SOFTIRQ (raised at 19:00:01.002000000)
88	[19:00:01.011000000, 19:00:01.013000000] 2000.000 3 SoftIRQ 7 SCHED_SOFTIRQ (raised at 19:00:01.005000000)
89	[19:00:01.014000000, 19:00:01.015000000] 1000.000 3 SoftIRQ 9 RCU_SOFTIRQ (raised at 19:00:01.004000000)
90	[19:00:01.016000000, 19:00:01.018000000] 2000.000 0 IRQ 41 ahci
91	[19:00:01.019000000, 19:00:01.020000000] 1000.000 0 SoftIRQ 4 BLOCK_SOFTIRQ (raised at 19:00:01.017000000)
92	[19:00:01.021000000, 19:00:01.023000000] 2000.000 0 IRQ 41 ahci
93	[19:00:01.024000000, 19:00:01.025000000] 1000.000 0 SoftIRQ 4 BLOCK_SOFTIRQ (raised at 19:00:01.022000000)
94	[19:00:01.026000000, 19:00:01.028000000] 2000.000 0 IRQ 41 ahci
95	[19:00:01.029000000, 19:00:01.030000000] 1000.000 0 SoftIRQ 4 BLOCK_SOFTIRQ (raised at 19:00:01.027000000)
96	[19:00:01.031000000, 19:00:01.033000000] 2000.000 0 IRQ 41 ahci
97	[19:00:01.034000000, 19:00:01.035000000] 1000.000 0 SoftIRQ 4 BLOCK_SOFTIRQ (raised at 19:00:01.032000000)
98	[19:00:01.036000000, 19:00:01.038000000] 2000.000 0 IRQ 41 ahci
99	[19:00:01.039000000, 19:00:01.040000000] 1000.000 0 SoftIRQ 4 BLOCK_SOFTIRQ (raised at 19:00:01.037000000)
100	[19:00:01.041000000, 19:00:01.043000000] 2000.000 0 IRQ 41 ahci
101	[19:00:01.044000000, 19:00:01.045000000] 1000.000 0 SoftIRQ 4 BLOCK_SOFTIRQ (raised at 19:00:01.042000000)"""
102
103	return self.compare_output('%slttng-irqlog %s "%s"' % (
104	self.cmd_root, self.common_options, self.t.get_trace_root()),
105	expected)
106
107
108	def test_answer():
109	t = IrqTest(verbose=True)
110	ok = t.run()
111	assert(ok)