[LITMUS^RT] Base_task when executed does not give the correct debug output as rtspin does

[Susan S]

Hi,

Thank you for the quick reply.

The issue is in my base_task I used a program to utilize 100% CPU by
writing the prime number calculation.By using the "top" command I have
verified that the program runs in all cores and all CPUs are 100% utilized.

The issue is in the st-trace-schedule output.It shows only one cpu as
used.Please do let me know where I have gone wrong.I am running this on
Xeon D-1548 processor which has 16 logical cpus.

I have attached the base_task program,with the debug file output and
st-trace output also along with this mail.

Regards,
Susan Rose.



On Thu, Mar 8, 2018 at 2:19 PM, Björn Brandenburg <bbb at mpi-sws.org> wrote:

>
> > On 8. Mar 2018, at 09:31, Susan S <susanrosethomas2001 at gmail.com> wrote:
> >
> > I am new to litmus-rt. I am trying to study the flow of the GSN-EDF , so
> analyzed the rtspin output using the debug file by using command "cat
> /dev/litmus/log > debug.txt &".
> >
> > This debug.txt of rtspin gives the correct flow of gsnedf scheduler.But
> when i wrote a job in base_task and executed the output debug file doesnot
> contain the contents as for rtspin.
> >
> > I want to know if only rtspin can be used for testing the scheduler
> functions or is there any other method by which I can test my application
> program with the litmus-rt schedulers.
>
> Any task that uses the LITMUS^RT API should work fine. There is nothing
> special about rtspin.
>
> >
> > Since there is limited help from my institute please do guide me how to
> test a simple program and verify its output for different schedulers.
>
> Happy to help, but without knowing your code and how exactly you launched
> the processes and any output there’s not much that we can say. If you can
> share additional details, we can take a look.
>
> - Björn
>
>
> _______________________________________________
> litmus-dev mailing list
> litmus-dev at lists.litmus-rt.org
> https://lists.litmus-rt.org/listinfo/litmus-dev
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.litmus-rt.org/pipermail/litmus-dev/attachments/20180312/f7bbaa5d/attachment-0001.html>
-------------- next part --------------
20 P0: (base_task/5873:0) alloc_ctrl_page ctrl_page = ffff8804325ba000
21 P0: (base_task/5873:0) litmus/ctrl: mapping ffff8804325ba000 (pfn:4325ba) to 0x7f6ef1caf000 (prot:8000000000000027)
22 P0: (base_task/5873:0) litmus_ctrl_mmap flags=0x10162073 prot=0x8000000000000027
23 P0: Setting up rt task parameters for process 5873.
24 P0: gsn edf: task new 5873
25 P0: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=220529983633 to ready queue at 220529984342
26 P0: (base_task/5873:1) linking to local CPU 0 to avoid IPI
27 P0: (base_task/5873:1) ignoring an enqueue, not a wake up.
28 P0: (base_task/5873:1) charged 2180 exec time (total:2180, rem:9997820)
29 P0: (base_task/5873:1) blocks:0 out_of_time:0 np:0 sleep:0 preempt:0 state:0 sig:0
30 P0: (base_task/5873:1) job completion indicated at 220529995673
31 P0: (base_task/5873:1) charged 3376 exec time (total:5556, rem:9994444)
32 P0: (base_task/5873:1) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
33 P0: (base_task/5873:1) job_completion(forced=0).
34 P0: (base_task/5873:2) add_release(), rel=220629983633
35 P0: (base_task/5873:2) scheduled_on = NO_CPU
36 P0: (base_task/5873:2) linking to local CPU 0 to avoid IPI
37 P0: (swapper/0/0:0) will be preempted by base_task/5873
38 P0: (base_task/5873:2) scheduled_on = P0
39 P0: (base_task/5873:0) fork: real-time status denied
40 P0: (base_task/5873:0) fork: real-time status denied
41 P0: (base_task/5873:0) fork: real-time status denied
42 P0: (base_task/5873:0) fork: real-time status denied
43 P0: (base_task/5873:0) fork: real-time status denied
44 P0: (base_task/5873:0) fork: real-time status denied
45 P0: (base_task/5873:0) fork: real-time status denied
46 P0: (base_task/5873:0) fork: real-time status denied
47 P0: (base_task/5873:0) fork: real-time status denied
48 P0: (base_task/5873:0) fork: real-time status denied
49 P0: (base_task/5873:0) fork: real-time status denied
50 P0: (base_task/5873:0) fork: real-time status denied
51 P0: (base_task/5873:0) fork: real-time status denied
52 P0: (base_task/5873:0) fork: real-time status denied
53 P0: (base_task/5873:0) fork: real-time status denied
54 P0: (base_task/5873:0) fork: real-time status denied
55 P0: (base_task/5873:2) block at 220630944907
56 P0: (base_task/5873:2) charged 849644 exec time (total:849644, rem:9150356)
57 P0: (base_task/5873:2) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
58 P0: (base_task/5873:2) scheduled_on = NO_CPU
59 P1: (base_task/5873:2) try_to_wake_up() state:1
60 P1: (base_task/5873:2) wake_up at 228651394253
61 P1: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=228651396326 to ready queue at 228651396992
62 P1: (base_task/5873:3) linking to local CPU 1 to avoid IPI
63 P1: (base_task/5873:3) try_to_wake_up() done state:0
64 P1: (base_task/5874:0) will be preempted by base_task/5873
65 P1: (base_task/5873:3) scheduled_on = P1
66 P1: (base_task/5873:3) migrate from 0
67 P1: (base_task/5873:3) stack_in_use=-1
68 P1: (base_task/5873:3) block at 228651424842
69 P1: (base_task/5873:3) charged 14807 exec time (total:14807, rem:9985193)
70 P1: (base_task/5873:3) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
71 P1: (base_task/5873:3) scheduled_on = NO_CPU
72 P10: (base_task/5873:3) try_to_wake_up() state:1
73 P10: (base_task/5873:3) wake_up at 228658232150
74 P10: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=228651396326 to ready queue at 228658234343
75 P10: check_for_preemptions: attempting to link task 5873 to 15
76 P10: P1 is closest available CPU to P1
77 P10: (base_task/5873:3) try_to_wake_up() done state:0
78 P1: (swapper/1/0:0) will be preempted by base_task/5873
79 P1: (base_task/5873:3) scheduled_on = P1
80 P1: (base_task/5873:3) block at 228658268494
81 P1: (base_task/5873:3) charged 36416 exec time (total:51223, rem:9948777)
82 P1: (base_task/5873:3) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
83 P1: (base_task/5873:3) scheduled_on = NO_CPU
84 P8: (base_task/5873:3) try_to_wake_up() state:1
85 P8: (base_task/5873:3) wake_up at 228704815847
86 P8: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=228651396326 to ready queue at 228704817645
87 P8: check_for_preemptions: attempting to link task 5873 to 1
88 P8: P1 is closest available CPU to P1
89 P8: (base_task/5873:3) try_to_wake_up() done state:0
90 P1: (swapper/1/0:0) will be preempted by base_task/5873
91 P1: (base_task/5873:3) scheduled_on = P1
92 P1: (base_task/5873:3) block at 228704844245
93 P1: (base_task/5873:3) charged 28338 exec time (total:79561, rem:9920439)
94 P1: (base_task/5873:3) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
95 P1: (base_task/5873:3) scheduled_on = NO_CPU
96 P4: (base_task/5873:3) try_to_wake_up() state:1
97 P4: (base_task/5873:3) wake_up at 228720273481
98 P4: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=228651396326 to ready queue at 228720275036
99 P4: (base_task/5873:3) linking to local CPU 4 to avoid IPI
100 P4: (base_task/5873:3) try_to_wake_up() done state:0
101 P4: (base_task/5882:0) will be preempted by base_task/5873
102 P4: (base_task/5873:3) scheduled_on = P4
103 P4: (base_task/5873:3) migrate from 1
104 P4: (base_task/5873:3) stack_in_use=-1
105 P4: (base_task/5873:3) block at 228720306299
106 P4: (base_task/5873:3) charged 20972 exec time (total:100533, rem:9899467)
107 P4: (base_task/5873:3) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
108 P4: (base_task/5873:3) scheduled_on = NO_CPU
109 P5: (base_task/5873:3) try_to_wake_up() state:1
110 P5: (base_task/5873:3) wake_up at 228728985956
111 P5: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=228651396326 to ready queue at 228728987327
112 P5: (base_task/5873:3) linking to local CPU 5 to avoid IPI
113 P5: (base_task/5873:3) try_to_wake_up() done state:0
114 P5: (base_task/5887:0) will be preempted by base_task/5873
115 P5: (base_task/5873:3) scheduled_on = P5
116 P5: (base_task/5873:3) migrate from 4
117 P5: (base_task/5873:3) stack_in_use=-1
118 P5: (base_task/5873:3) charged 6838 exec time (total:107371, rem:9892629)
119 P5: (base_task/5873:3) job completion indicated at 228729125839
120 P5: (base_task/5873:3) charged 124958 exec time (total:232329, rem:9767671)
121 P5: (base_task/5873:3) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
122 P5: (base_task/5873:3) job_completion(forced=0).
123 P5: (base_task/5873:4) add_release(), rel=228751396326
124 P5: (base_task/5873:4) scheduled_on = NO_CPU
125 P5: (base_task/5873:4) linking to local CPU 5 to avoid IPI
126 P5: (swapper/5/0:0) will be preempted by base_task/5873
127 P5: (base_task/5873:4) scheduled_on = P5
128 P5: (base_task/5873:0) fork: real-time status denied
129 P5: (base_task/5873:0) fork: real-time status denied
130 P5: (base_task/5873:0) fork: real-time status denied
131 P5: (base_task/5873:0) fork: real-time status denied
132 P5: (base_task/5873:0) fork: real-time status denied
133 P5: (base_task/5873:0) fork: real-time status denied
134 P5: (base_task/5873:0) fork: real-time status denied
135 P5: (base_task/5873:0) fork: real-time status denied
136 P5: (base_task/5873:0) fork: real-time status denied
137 P5: (base_task/5873:0) fork: real-time status denied
138 P5: (base_task/5873:0) fork: real-time status denied
139 P5: (base_task/5873:0) fork: real-time status denied
140 P5: (base_task/5873:0) fork: real-time status denied
141 P5: (base_task/5873:4) charged 571630 exec time (total:571630, rem:9428370)
142 P5: (base_task/5873:0) fork: real-time status denied
143 P5: (base_task/5873:0) fork: real-time status denied
144 P5: (base_task/5873:0) fork: real-time status denied
145 P5: (base_task/5873:4) block at 228752152414
146 P5: (base_task/5873:4) charged 149470 exec time (total:721100, rem:9278900)
147 P5: (base_task/5873:4) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
148 P5: (base_task/5873:4) scheduled_on = NO_CPU
149 P5: (base_task/5873:4) try_to_wake_up() state:1
150 P5: (base_task/5873:4) wake_up at 236809459363
151 P5: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=236809460339 to ready queue at 236809460768
152 P5: (base_task/5873:5) linking to local CPU 5 to avoid IPI
153 P5: (base_task/5873:5) try_to_wake_up() done state:0
154 P5: (base_task/5892:0) will be preempted by base_task/5873
155 P5: (base_task/5873:5) scheduled_on = P5
156 P5: (base_task/5873:5) job completion indicated at 236809568820
157 P5: (base_task/5873:5) charged 110895 exec time (total:110895, rem:9889105)
158 P5: (base_task/5873:5) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
159 P5: (base_task/5873:5) job_completion(forced=0).
160 P5: (base_task/5873:6) add_release(), rel=236909460339
161 P5: (base_task/5873:6) scheduled_on = NO_CPU
162 P5: (base_task/5873:6) linking to local CPU 5 to avoid IPI
163 P5: (swapper/5/0:0) will be preempted by base_task/5873
164 P5: (base_task/5873:6) scheduled_on = P5
165 P5: (base_task/5873:0) fork: real-time status denied
166 P5: (base_task/5873:0) fork: real-time status denied
167 P5: (base_task/5873:0) fork: real-time status denied
168 P5: (base_task/5873:0) fork: real-time status denied
169 P5: (base_task/5873:0) fork: real-time status denied
170 P5: (base_task/5873:0) fork: real-time status denied
171 P5: (base_task/5873:0) fork: real-time status denied
172 P5: (base_task/5873:0) fork: real-time status denied
173 P5: (base_task/5873:0) fork: real-time status denied
174 P5: (base_task/5873:6) charged 452961 exec time (total:452961, rem:9547039)
175 P5: (base_task/5873:0) fork: real-time status denied
176 P5: (base_task/5873:0) fork: real-time status denied
177 P5: (base_task/5873:0) fork: real-time status denied
178 P5: (base_task/5873:0) fork: real-time status denied
179 P5: (base_task/5873:0) fork: real-time status denied
180 P5: (base_task/5873:0) fork: real-time status denied
181 P5: (base_task/5873:0) fork: real-time status denied
182 P5: (base_task/5873:6) block at 236910365766
183 P5: (base_task/5873:6) charged 362666 exec time (total:815627, rem:9184373)
184 P5: (base_task/5873:6) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
185 P5: (base_task/5873:6) scheduled_on = NO_CPU
186 P6: (base_task/5873:6) try_to_wake_up() state:1
187 P6: (base_task/5873:6) wake_up at 244908789208
188 P6: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=244908790744 to ready queue at 244908791361
189 P6: (base_task/5873:7) linking to local CPU 6 to avoid IPI
190 P6: (base_task/5873:7) try_to_wake_up() done state:0
191 P6: (base_task/5908:0) will be preempted by base_task/5873
192 P6: (base_task/5873:7) scheduled_on = P6
193 P6: (base_task/5873:7) migrate from 5
194 P6: (base_task/5873:7) stack_in_use=-1
195 P6: (base_task/5873:7) block at 244908819576
196 P6: (base_task/5873:7) charged 14480 exec time (total:14480, rem:9985520)
197 P6: (base_task/5873:7) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
198 P6: (base_task/5873:7) scheduled_on = NO_CPU
199 P15: (base_task/5873:7) try_to_wake_up() state:1
200 P15: (base_task/5873:7) wake_up at 244920187367
201 P15: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=244908790744 to ready queue at 244920188950
202 P15: check_for_preemptions: attempting to link task 5873 to 14
203 P15: P6 is closest available CPU to P6
204 P15: (base_task/5873:7) try_to_wake_up() done state:0
205 P6: (swapper/6/0:0) will be preempted by base_task/5873
206 P6: (base_task/5873:7) scheduled_on = P6
207 P6: (base_task/5873:7) block at 244920209877
208 P6: (base_task/5873:7) charged 22551 exec time (total:37031, rem:9962969)
209 P6: (base_task/5873:7) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
210 P6: (base_task/5873:7) scheduled_on = NO_CPU
211 P1: (base_task/5873:7) try_to_wake_up() state:1
212 P1: (base_task/5873:7) wake_up at 245187852138
213 P1: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=245187853306 to ready queue at 245187853814
214 P1: (base_task/5873:8) linking to local CPU 1 to avoid IPI
215 P1: (base_task/5873:8) try_to_wake_up() done state:0
216 P1: (base_task/5910:0) will be preempted by base_task/5873
217 P1: (base_task/5873:8) scheduled_on = P1
218 P1: (base_task/5873:8) migrate from 6
219 P1: (base_task/5873:8) stack_in_use=-1
220 P1: (base_task/5873:8) job completion indicated at 245187917256
221 P1: (base_task/5873:8) charged 56455 exec time (total:56455, rem:9943545)
222 P1: (base_task/5873:8) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
223 P1: (base_task/5873:8) job_completion(forced=0).
224 P1: (base_task/5873:9) add_release(), rel=245287853306
225 P1: (base_task/5873:9) scheduled_on = NO_CPU
226 P1: (base_task/5873:9) linking to local CPU 1 to avoid IPI
227 P1: (swapper/1/0:0) will be preempted by base_task/5873
228 P1: (base_task/5873:9) scheduled_on = P1
229 P1: (base_task/5873:0) fork: real-time status denied
230 P1: (base_task/5873:9) charged 52139 exec time (total:52139, rem:9947861)
231 P1: (base_task/5873:0) fork: real-time status denied
232 P1: (base_task/5873:0) fork: real-time status denied
233 P1: (base_task/5873:0) fork: real-time status denied
234 P1: (base_task/5873:0) fork: real-time status denied
235 P1: (base_task/5873:0) fork: real-time status denied
236 P1: (base_task/5873:0) fork: real-time status denied
237 P1: (base_task/5873:0) fork: real-time status denied
238 P1: (base_task/5873:0) fork: real-time status denied
239 P1: (base_task/5873:0) fork: real-time status denied
240 P1: (base_task/5873:0) fork: real-time status denied
241 P1: (base_task/5873:0) fork: real-time status denied
242 P1: (base_task/5873:0) fork: real-time status denied
243 P1: (base_task/5873:0) fork: real-time status denied
244 P1: (base_task/5873:0) fork: real-time status denied
245 P1: (base_task/5873:0) fork: real-time status denied
246 P1: (base_task/5873:9) block at 245288665939
247 P1: (base_task/5873:9) charged 662979 exec time (total:715118, rem:9284882)
248 P1: (base_task/5873:9) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
249 P1: (base_task/5873:9) scheduled_on = NO_CPU
250 P10: (base_task/5873:9) try_to_wake_up() state:1
251 P10: (base_task/5873:9) wake_up at 253325527639
252 P10: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=253325529371 to ready queue at 253325530315
253 P10: check_for_preemptions: attempting to link task 5873 to 14
254 P10: P1 is closest available CPU to P1
255 P10: (base_task/5873:10) try_to_wake_up() done state:0
256 P1: (base_task/5932:0) will be preempted by base_task/5873
257 P1: (base_task/5873:10) scheduled_on = P1
258 P1: (base_task/5873:10) block at 253325578408
259 P1: (base_task/5873:10) charged 50912 exec time (total:50912, rem:9949088)
260 P1: (base_task/5873:10) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
261 P1: (base_task/5873:10) scheduled_on = NO_CPU
262 P11: (base_task/5873:10) try_to_wake_up() state:1
263 P11: (base_task/5873:10) wake_up at 253340874661
264 P11: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=253325529371 to ready queue at 253340876914
265 P11: check_for_preemptions: attempting to link task 5873 to 14
266 P11: P1 is closest available CPU to P1
267 P11: (base_task/5873:10) try_to_wake_up() done state:0
268 P1: (swapper/1/0:0) will be preempted by base_task/5873
269 P1: (base_task/5873:10) scheduled_on = P1
270 P1: (base_task/5873:10) block at 253340903397
271 P1: (base_task/5873:10) charged 28851 exec time (total:79763, rem:9920237)
272 P1: (base_task/5873:10) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
273 P1: (base_task/5873:10) scheduled_on = NO_CPU
274 P13: (base_task/5873:10) try_to_wake_up() state:1
275 P13: (base_task/5873:10) wake_up at 253668553794
276 P13: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=253668554908 to ready queue at 253668555594
277 P13: check_for_preemptions: attempting to link task 5873 to 13
278 P13: P1 is closest available CPU to P1
279 P13: (base_task/5873:11) try_to_wake_up() done state:0
280 P1: (swapper/1/0:0) will be preempted by base_task/5873
281 P1: (base_task/5873:11) scheduled_on = P1
282 P1: (base_task/5873:11) block at 253668618844
283 P1: (base_task/5873:11) charged 65071 exec time (total:65071, rem:9934929)
284 P1: (base_task/5873:11) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
285 P1: (base_task/5873:11) scheduled_on = NO_CPU
286 P12: (base_task/5873:11) try_to_wake_up() state:1
287 P12: (base_task/5873:11) wake_up at 253784775341
288 P12: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=253784776496 to ready queue at 253784776879
289 P12: check_for_preemptions: attempting to link task 5873 to 10
290 P12: P1 is closest available CPU to P1
291 P12: (base_task/5873:12) try_to_wake_up() done state:0
292 P1: (swapper/1/0:0) will be preempted by base_task/5873
293 P1: (base_task/5873:12) scheduled_on = P1
294 P1: (base_task/5873:12) job completion indicated at 253784845287
295 P1: (base_task/5873:12) charged 71927 exec time (total:71927, rem:9928073)
296 P1: (base_task/5873:12) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
297 P1: (base_task/5873:12) job_completion(forced=0).
298 P1: (base_task/5873:13) add_release(), rel=253884776496
299 P1: (base_task/5873:13) scheduled_on = NO_CPU
300 P1: (base_task/5873:13) linking to local CPU 1 to avoid IPI
301 P1: (swapper/1/0:0) will be preempted by base_task/5873
302 P1: (base_task/5873:13) scheduled_on = P1
303 P1: (base_task/5873:0) fork: real-time status denied
304 P1: (base_task/5873:13) charged 120572 exec time (total:120572, rem:9879428)
305 P1: (base_task/5873:0) fork: real-time status denied
306 P1: (base_task/5873:0) fork: real-time status denied
307 P1: (base_task/5873:0) fork: real-time status denied
308 P1: (base_task/5873:0) fork: real-time status denied
309 P1: (base_task/5873:0) fork: real-time status denied
310 P1: (base_task/5873:0) fork: real-time status denied
311 P1: (base_task/5873:0) fork: real-time status denied
312 P1: (base_task/5873:0) fork: real-time status denied
313 P1: (base_task/5873:0) fork: real-time status denied
314 P1: (base_task/5873:0) fork: real-time status denied
315 P1: (base_task/5873:0) fork: real-time status denied
316 P1: (base_task/5873:0) fork: real-time status denied
317 P1: (base_task/5873:0) fork: real-time status denied
318 P1: (base_task/5873:0) fork: real-time status denied
319 P1: (base_task/5873:0) fork: real-time status denied
320 P1: (base_task/5873:13) block at 253885717699
321 P1: (base_task/5873:13) charged 711223 exec time (total:831795, rem:9168205)
322 P1: (base_task/5873:13) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
323 P1: (base_task/5873:13) scheduled_on = NO_CPU
324 P8: (base_task/5873:13) try_to_wake_up() state:1
325 P8: (base_task/5873:13) wake_up at 255719406026
326 P8: rt: adding base_task/5873 (10000000, 100000000, 100000000) rel=255719407862 to ready queue at 255719408918
327 P8: check_for_preemptions: attempting to link task 5873 to 6
328 P8: P1 is closest available CPU to P1
329 P8: (base_task/5873:14) try_to_wake_up() done state:0
330 P1: (base_task/5951:0) will be preempted by base_task/5873
331 P1: (base_task/5873:14) scheduled_on = P1
332 P1: (base_task/5873:14) exiting, demoted to SCHED_FIFO
333 P1: (base_task/5873:14) RIP
334 P1: (base_task/5873:14) ignoring a dequeue, not going to sleep.
335 P1: (base_task/5873:14) Deallocating real-time task data
336 P1: (base_task/5873:0) litmus_ctrl_vm_close flags=0x10160073 prot=0x25
337 P1: (base_task/5873:0) litmus/ctrl: 00007f6ef1caf000:00007f6ef1cb0000 vma:ffff880432688450 vma->vm_private_data:          (null) closed.
338 P3: (base_task/5873:0) freeing ctrl_page ffff8804325ba000
339 P11: (base_task/6029:0) alloc_ctrl_page ctrl_page = ffff88043c0c0000
340 P11: (base_task/6029:0) litmus/ctrl: mapping ffff88043c0c0000 (pfn:43c0c0) to 0x7f87ab062000 (prot:8000000000000027)
341 P11: (base_task/6029:0) litmus_ctrl_mmap flags=0x10162073 prot=0x8000000000000027
342 P11: Setting up rt task parameters for process 6029.
343 P11: gsn edf: task new 6029
344 P11: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=439792858997 to ready queue at 439792859379
345 P11: check_for_preemptions: attempting to link task 6029 to 14
346 P11: P11 is closest available CPU to P11
347 P11: (base_task/6029:1) ignoring an enqueue, not a wake up.
348 P11: (base_task/6029:1) charged 2432 exec time (total:2432, rem:9997568)
349 P11: (base_task/6029:1) blocks:0 out_of_time:0 np:0 sleep:0 preempt:0 state:0 sig:0
350 P11: (base_task/6029:1) job completion indicated at 439792875208
351 P11: (base_task/6029:1) charged 5703 exec time (total:8135, rem:9991865)
352 P11: (base_task/6029:1) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
353 P11: (base_task/6029:1) job_completion(forced=0).
354 P11: (base_task/6029:2) add_release(), rel=439892858997
355 P11: (base_task/6029:2) scheduled_on = NO_CPU
356 P11: check_for_preemptions: attempting to link task 6029 to 2
357 P11: P11 is closest available CPU to P11
358 P11: (swapper/11/0:0) will be preempted by base_task/6029
359 P11: (base_task/6029:2) scheduled_on = P11
360 P11: (base_task/6029:0) fork: real-time status denied
361 P11: (base_task/6029:2) charged 43128 exec time (total:43128, rem:9956872)
362 P11: (base_task/6029:0) fork: real-time status denied
363 P11: (base_task/6029:0) fork: real-time status denied
364 P11: (base_task/6029:0) fork: real-time status denied
365 P11: (base_task/6029:0) fork: real-time status denied
366 P11: (base_task/6029:0) fork: real-time status denied
367 P11: (base_task/6029:0) fork: real-time status denied
368 P11: (base_task/6029:0) fork: real-time status denied
369 P11: (base_task/6029:0) fork: real-time status denied
370 P11: (base_task/6029:0) fork: real-time status denied
371 P11: (base_task/6029:0) fork: real-time status denied
372 P11: (base_task/6029:0) fork: real-time status denied
373 P11: (base_task/6029:0) fork: real-time status denied
374 P11: (base_task/6029:0) fork: real-time status denied
375 P11: (base_task/6029:0) fork: real-time status denied
376 P11: (base_task/6029:0) fork: real-time status denied
377 P11: (base_task/6029:2) block at 439893794607
378 P11: (base_task/6029:2) charged 787555 exec time (total:830683, rem:9169317)
379 P11: (base_task/6029:2) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
380 P11: (base_task/6029:2) scheduled_on = NO_CPU
381 P12: (base_task/6029:2) try_to_wake_up() state:1
382 P12: (base_task/6029:2) wake_up at 447921980631
383 P12: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=447921981824 to ready queue at 447921982192
384 P12: check_for_preemptions: attempting to link task 6029 to 2
385 P12: P11 is closest available CPU to P11
386 P12: (base_task/6029:3) try_to_wake_up() done state:0
387 P11: (Xorg/4989:0) will be preempted by base_task/6029
388 P11: (base_task/6029:3) scheduled_on = P11
389 P11: (base_task/6029:3) charged 25034 exec time (total:25034, rem:9974966)
390 P11: (base_task/6029:3) block at 447922057911
391 P11: (base_task/6029:3) charged 52292 exec time (total:77326, rem:9922674)
392 P11: (base_task/6029:3) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
393 P11: (base_task/6029:3) scheduled_on = NO_CPU
394 P11: (base_task/6029:3) try_to_wake_up() state:1
395 P11: (base_task/6029:3) wake_up at 447993446175
396 P11: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=447921981824 to ready queue at 447993447799
397 P11: check_for_preemptions: attempting to link task 6029 to 3
398 P11: P11 is closest available CPU to P11
399 P11: (base_task/6029:3) try_to_wake_up() done state:0
400 P11: (base_task/6034:0) will be preempted by base_task/6029
401 P11: (base_task/6029:3) scheduled_on = P11
402 P11: (base_task/6029:3) block at 447993522051
403 P11: (base_task/6029:3) charged 76005 exec time (total:153331, rem:9846669)
404 P11: (base_task/6029:3) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
405 P11: (base_task/6029:3) scheduled_on = NO_CPU
406 P0: (base_task/6029:3) try_to_wake_up() state:1
407 P0: (base_task/6029:3) wake_up at 448309563793
408 P0: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=448309564967 to ready queue at 448309565563
409 P0: (base_task/6029:4) linking to local CPU 0 to avoid IPI
410 P0: (base_task/6029:4) try_to_wake_up() done state:0
411 P0: (base_task/6043:0) will be preempted by base_task/6029
412 P0: (base_task/6029:4) scheduled_on = P0
413 P0: (base_task/6029:4) migrate from 11
414 P0: (base_task/6029:4) stack_in_use=-1
415 P0: (base_task/6029:4) job completion indicated at 448309686827
416 P0: (base_task/6029:4) charged 114224 exec time (total:114224, rem:9885776)
417 P0: (base_task/6029:4) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
418 P0: (base_task/6029:4) job_completion(forced=0).
419 P0: (base_task/6029:5) add_release(), rel=448409564967
420 P0: (base_task/6029:5) scheduled_on = NO_CPU
421 P0: (base_task/6029:5) linking to local CPU 0 to avoid IPI
422 P0: (swapper/0/0:0) will be preempted by base_task/6029
423 P0: (base_task/6029:5) scheduled_on = P0
424 P0: (base_task/6029:0) fork: real-time status denied
425 P0: (base_task/6029:0) fork: real-time status denied
426 P0: (base_task/6029:0) fork: real-time status denied
427 P0: (base_task/6029:0) fork: real-time status denied
428 P0: (base_task/6029:0) fork: real-time status denied
429 P0: (base_task/6029:5) charged 381249 exec time (total:381249, rem:9618751)
430 P0: (base_task/6029:0) fork: real-time status denied
431 P0: (base_task/6029:0) fork: real-time status denied
432 P0: (base_task/6029:0) fork: real-time status denied
433 P0: (base_task/6029:0) fork: real-time status denied
434 P0: (base_task/6029:0) fork: real-time status denied
435 P0: (base_task/6029:0) fork: real-time status denied
436 P0: (base_task/6029:0) fork: real-time status denied
437 P0: (base_task/6029:0) fork: real-time status denied
438 P0: (base_task/6029:0) fork: real-time status denied
439 P0: (base_task/6029:0) fork: real-time status denied
440 P0: (base_task/6029:0) fork: real-time status denied
441 P0: (base_task/6029:5) block at 448410587868
442 P0: (base_task/6029:5) charged 578130 exec time (total:959379, rem:9040621)
443 P0: (base_task/6029:5) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
444 P0: (base_task/6029:5) scheduled_on = NO_CPU
445 P1: (base_task/6029:5) try_to_wake_up() state:1
446 P1: (base_task/6029:5) wake_up at 456294121567
447 P1: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=456294123189 to ready queue at 456294123864
448 P1: (base_task/6029:6) linking to local CPU 1 to avoid IPI
449 P1: (base_task/6029:6) try_to_wake_up() done state:0
450 P1: (base_task/6049:0) will be preempted by base_task/6029
451 P1: (base_task/6029:6) scheduled_on = P1
452 P1: (base_task/6029:6) migrate from 0
453 P1: (base_task/6029:6) stack_in_use=-1
454 P1: (base_task/6029:6) block at 456294161860
455 P1: (base_task/6029:6) charged 24566 exec time (total:24566, rem:9975434)
456 P1: (base_task/6029:6) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
457 P1: (base_task/6029:6) scheduled_on = NO_CPU
458 P2: (base_task/6029:6) try_to_wake_up() state:1
459 P2: (base_task/6029:6) wake_up at 456425058690
460 P2: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=456425059912 to ready queue at 456425060468
461 P2: (base_task/6029:7) linking to local CPU 2 to avoid IPI
462 P2: (base_task/6029:7) try_to_wake_up() done state:0
463 P2: (base_task/6050:0) will be preempted by base_task/6029
464 P2: (base_task/6029:7) scheduled_on = P2
465 P2: (base_task/6029:7) migrate from 1
466 P2: (base_task/6029:7) stack_in_use=-1
467 P2: (base_task/6029:7) block at 456425088192
468 P2: (base_task/6029:7) charged 18739 exec time (total:18739, rem:9981261)
469 P2: (base_task/6029:7) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
470 P2: (base_task/6029:7) scheduled_on = NO_CPU
471 P11: (base_task/6029:7) try_to_wake_up() state:1
472 P11: (base_task/6029:7) wake_up at 456434319949
473 P11: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=456425059912 to ready queue at 456434321462
474 P11: check_for_preemptions: attempting to link task 6029 to 7
475 P11: P2 is closest available CPU to P2
476 P11: (base_task/6029:7) try_to_wake_up() done state:0
477 P2: (swapper/2/0:0) will be preempted by base_task/6029
478 P2: (base_task/6029:7) scheduled_on = P2
479 P2: (base_task/6029:7) block at 456434373809
480 P2: (base_task/6029:7) charged 53840 exec time (total:72579, rem:9927421)
481 P2: (base_task/6029:7) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
482 P2: (base_task/6029:7) scheduled_on = NO_CPU
483 P4: (base_task/6029:7) try_to_wake_up() state:1
484 P4: (base_task/6029:7) wake_up at 456446980412
485 P4: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=456425059912 to ready queue at 456446981713
486 P4: (base_task/6029:7) linking to local CPU 4 to avoid IPI
487 P4: (base_task/6029:7) try_to_wake_up() done state:0
488 P4: (base_task/6052:0) will be preempted by base_task/6029
489 P4: (base_task/6029:7) scheduled_on = P4
490 P4: (base_task/6029:7) migrate from 2
491 P4: (base_task/6029:7) stack_in_use=-1
492 P4: (base_task/6029:7) charged 11212 exec time (total:83791, rem:9916209)
493 P4: (base_task/6029:7) block at 456447032710
494 P4: (base_task/6029:7) charged 30603 exec time (total:114394, rem:9885606)
495 P4: (base_task/6029:7) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
496 P4: (base_task/6029:7) scheduled_on = NO_CPU
497 P8: (base_task/6029:7) try_to_wake_up() state:1
498 P8: (base_task/6029:7) wake_up at 456477147372
499 P8: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=456425059912 to ready queue at 456477148901
500 P8: check_for_preemptions: attempting to link task 6029 to 1
501 P8: P4 is closest available CPU to P4
502 P8: (base_task/6029:7) try_to_wake_up() done state:0
503 P4: (swapper/4/0:0) will be preempted by base_task/6029
504 P4: (base_task/6029:7) scheduled_on = P4
505 P4: (base_task/6029:7) block at 456477179281
506 P4: (base_task/6029:7) charged 32033 exec time (total:146427, rem:9853573)
507 P4: (base_task/6029:7) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
508 P4: (base_task/6029:7) scheduled_on = NO_CPU
509 P3: (base_task/6029:7) try_to_wake_up() state:1
510 P3: (base_task/6029:7) wake_up at 456622793552
511 P3: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=456622794727 to ready queue at 456622795274
512 P3: (base_task/6029:8) linking to local CPU 3 to avoid IPI
513 P3: (base_task/6029:8) try_to_wake_up() done state:0
514 P3: (base_task/6057:0) will be preempted by base_task/6029
515 P3: (base_task/6029:8) scheduled_on = P3
516 P3: (base_task/6029:8) migrate from 4
517 P3: (base_task/6029:8) stack_in_use=-1
518 P3: (base_task/6029:8) job completion indicated at 456622876307
519 P3: (base_task/6029:8) charged 74313 exec time (total:74313, rem:9925687)
520 P3: (base_task/6029:8) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
521 P3: (base_task/6029:8) job_completion(forced=0).
522 P3: (base_task/6029:9) add_release(), rel=456722794727
523 P3: (base_task/6029:9) scheduled_on = NO_CPU
524 P3: (base_task/6029:9) linking to local CPU 3 to avoid IPI
525 P3: (swapper/3/0:0) will be preempted by base_task/6029
526 P3: (base_task/6029:9) scheduled_on = P3
527 P3: (base_task/6029:0) fork: real-time status denied
528 P3: (base_task/6029:0) fork: real-time status denied
529 P3: (base_task/6029:9) charged 94570 exec time (total:94570, rem:9905430)
530 P3: (base_task/6029:0) fork: real-time status denied
531 P3: (base_task/6029:0) fork: real-time status denied
532 P3: (base_task/6029:0) fork: real-time status denied
533 P3: (base_task/6029:0) fork: real-time status denied
534 P3: (base_task/6029:0) fork: real-time status denied
535 P3: (base_task/6029:0) fork: real-time status denied
536 P3: (base_task/6029:0) fork: real-time status denied
537 P3: (base_task/6029:0) fork: real-time status denied
538 P3: (base_task/6029:0) fork: real-time status denied
539 P3: (base_task/6029:0) fork: real-time status denied
540 P3: (base_task/6029:0) fork: real-time status denied
541 P3: (base_task/6029:0) fork: real-time status denied
542 P3: (base_task/6029:0) fork: real-time status denied
543 P3: (base_task/6029:0) fork: real-time status denied
544 P3: (base_task/6029:9) block at 456723597404
545 P3: (base_task/6029:9) charged 594470 exec time (total:689040, rem:9310960)
546 P3: (base_task/6029:9) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
547 P3: (base_task/6029:9) scheduled_on = NO_CPU
548 P12: (base_task/6029:9) try_to_wake_up() state:1
549 P12: (base_task/6029:9) wake_up at 464778497137
550 P12: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=464778498276 to ready queue at 464778506776
551 P12: check_for_preemptions: attempting to link task 6029 to 9
552 P12: P3 is closest available CPU to P3
553 P12: (base_task/6029:10) try_to_wake_up() done state:0
554 P3: (swapper/3/0:0) will be preempted by base_task/6029
555 P3: (base_task/6029:10) scheduled_on = P3
556 P3: (base_task/6029:10) block at 464778559137
557 P3: (base_task/6029:10) charged 61745 exec time (total:61745, rem:9938255)
558 P3: (base_task/6029:10) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
559 P3: (base_task/6029:10) scheduled_on = NO_CPU
560 P6: (base_task/6029:10) try_to_wake_up() state:1
561 P6: (base_task/6029:10) wake_up at 465076002388
562 P6: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=465076004100 to ready queue at 465076004744
563 P6: (base_task/6029:11) linking to local CPU 6 to avoid IPI
564 P6: (base_task/6029:11) try_to_wake_up() done state:0
565 P6: (base_task/6069:0) will be preempted by base_task/6029
566 P6: (base_task/6029:11) scheduled_on = P6
567 P6: (base_task/6029:11) migrate from 3
568 P6: (base_task/6029:11) stack_in_use=-1
569 P6: (base_task/6029:11) block at 465076045969
570 P6: (base_task/6029:11) charged 29416 exec time (total:29416, rem:9970584)
571 P6: (base_task/6029:11) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
572 P6: (base_task/6029:11) scheduled_on = NO_CPU
573 P8: (base_task/6029:11) try_to_wake_up() state:1
574 P8: (base_task/6029:11) wake_up at 465140741630
575 P8: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=465076004100 to ready queue at 465140743393
576 P8: check_for_preemptions: attempting to link task 6029 to 2
577 P8: P6 is closest available CPU to P6
578 P8: (base_task/6029:11) try_to_wake_up() done state:0
579 P6: (swapper/6/0:0) will be preempted by base_task/6029
580 P6: (base_task/6029:11) scheduled_on = P6
581 P6: (base_task/6029:11) job completion indicated at 465140813591
582 P6: (base_task/6029:11) charged 74023 exec time (total:103439, rem:9896561)
583 P6: (base_task/6029:11) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
584 P6: (base_task/6029:11) job_completion(forced=0).
585 P6: (base_task/6029:12) add_release(), rel=465176004100
586 P6: (base_task/6029:12) scheduled_on = NO_CPU
587 P6: (base_task/6029:12) linking to local CPU 6 to avoid IPI
588 P6: (swapper/6/0:0) will be preempted by base_task/6029
589 P6: (base_task/6029:12) scheduled_on = P6
590 P6: (base_task/6029:0) fork: real-time status denied
591 P6: (base_task/6029:0) fork: real-time status denied
592 P6: (base_task/6029:0) fork: real-time status denied
593 P6: (base_task/6029:0) fork: real-time status denied
594 P6: (base_task/6029:0) fork: real-time status denied
595 P6: (base_task/6029:0) fork: real-time status denied
596 P6: (base_task/6029:0) fork: real-time status denied
597 P6: (base_task/6029:0) fork: real-time status denied
598 P6: (base_task/6029:0) fork: real-time status denied
599 P6: (base_task/6029:0) fork: real-time status denied
600 P6: (base_task/6029:0) fork: real-time status denied
601 P6: (base_task/6029:0) fork: real-time status denied
602 P6: (base_task/6029:0) fork: real-time status denied
603 P6: (base_task/6029:0) fork: real-time status denied
604 P6: (base_task/6029:0) fork: real-time status denied
605 P6: (base_task/6029:0) fork: real-time status denied
606 P6: (base_task/6029:12) charged 955599 exec time (total:955599, rem:9044401)
607 P6: (base_task/6029:12) block at 465177016623
608 P6: (base_task/6029:12) charged 13849 exec time (total:969448, rem:9030552)
609 P6: (base_task/6029:12) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
610 P6: (base_task/6029:12) scheduled_on = NO_CPU
611 P6: (base_task/6029:12) try_to_wake_up() state:1
612 P6: (base_task/6029:12) wake_up at 473181132565
613 P6: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=473181133673 to ready queue at 473181134128
614 P6: (base_task/6029:13) linking to local CPU 6 to avoid IPI
615 P6: (base_task/6029:13) try_to_wake_up() done state:0
616 P6: (base_task/6081:0) will be preempted by base_task/6029
617 P6: (base_task/6029:13) scheduled_on = P6
618 P6: (base_task/6029:13) block at 473181173659
619 P6: (base_task/6029:13) charged 41144 exec time (total:41144, rem:9958856)
620 P6: (base_task/6029:13) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
621 P6: (base_task/6029:13) scheduled_on = NO_CPU
622 P4: (base_task/6029:13) try_to_wake_up() state:1
623 P4: (base_task/6029:13) wake_up at 473190399018
624 P4: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=473181133673 to ready queue at 473190400954
625 P4: (base_task/6029:13) linking to local CPU 4 to avoid IPI
626 P4: (base_task/6029:13) try_to_wake_up() done state:0
627 P4: (base_task/6084:0) will be preempted by base_task/6029
628 P4: (base_task/6029:13) scheduled_on = P4
629 P4: (base_task/6029:13) migrate from 6
630 P4: (base_task/6029:13) stack_in_use=-1
631 P4: (base_task/6029:13) block at 473190447612
632 P4: (base_task/6029:13) charged 34302 exec time (total:75446, rem:9924554)
633 P4: (base_task/6029:13) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
634 P4: (base_task/6029:13) scheduled_on = NO_CPU
635 P0: (base_task/6029:13) try_to_wake_up() state:1
636 P0: (base_task/6029:13) wake_up at 473356657323
637 P0: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=473356658477 to ready queue at 473356659067
638 P0: (base_task/6029:14) linking to local CPU 0 to avoid IPI
639 P0: (base_task/6029:14) try_to_wake_up() done state:0
640 P0: (base_task/6087:0) will be preempted by base_task/6029
641 P0: (base_task/6029:14) scheduled_on = P0
642 P0: (base_task/6029:14) migrate from 4
643 P0: (base_task/6029:14) stack_in_use=-1
644 P0: (base_task/6029:14) job completion indicated at 473356753064
645 P0: (base_task/6029:14) charged 86666 exec time (total:86666, rem:9913334)
646 P0: (base_task/6029:14) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
647 P0: (base_task/6029:14) job_completion(forced=0).
648 P0: (base_task/6029:15) add_release(), rel=473456658477
649 P0: (base_task/6029:15) scheduled_on = NO_CPU
650 P0: (base_task/6029:15) linking to local CPU 0 to avoid IPI
651 P0: (swapper/0/0:0) will be preempted by base_task/6029
652 P0: (base_task/6029:15) scheduled_on = P0
653 P0: (base_task/6029:0) fork: real-time status denied
654 P0: (base_task/6029:0) fork: real-time status denied
655 P0: (base_task/6029:0) fork: real-time status denied
656 P0: (base_task/6029:15) charged 233952 exec time (total:233952, rem:9766048)
657 P0: (base_task/6029:0) fork: real-time status denied
658 P0: (base_task/6029:0) fork: real-time status denied
659 P0: (base_task/6029:0) fork: real-time status denied
660 P0: (base_task/6029:0) fork: real-time status denied
661 P0: (base_task/6029:0) fork: real-time status denied
662 P0: (base_task/6029:0) fork: real-time status denied
663 P0: (base_task/6029:0) fork: real-time status denied
664 P0: (base_task/6029:0) fork: real-time status denied
665 P0: (base_task/6029:0) fork: real-time status denied
666 P0: (base_task/6029:0) fork: real-time status denied
667 P0: (base_task/6029:0) fork: real-time status denied
668 P0: (base_task/6029:0) fork: real-time status denied
669 P0: (base_task/6029:0) fork: real-time status denied
670 P0: (base_task/6029:15) block at 473457595216
671 P0: (base_task/6029:15) charged 584693 exec time (total:818645, rem:9181355)
672 P0: (base_task/6029:15) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
673 P0: (base_task/6029:15) scheduled_on = NO_CPU
674 P1: (base_task/6029:15) try_to_wake_up() state:1
675 P1: (base_task/6029:15) wake_up at 481303848874
676 P1: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=481303850484 to ready queue at 481303851051
677 P1: (base_task/6029:16) linking to local CPU 1 to avoid IPI
678 P1: (base_task/6029:16) try_to_wake_up() done state:0
679 P1: (base_task/6097:0) will be preempted by base_task/6029
680 P1: (base_task/6029:16) scheduled_on = P1
681 P1: (base_task/6029:16) migrate from 0
682 P1: (base_task/6029:16) stack_in_use=-1
683 P1: (base_task/6029:16) block at 481303888519
684 P1: (base_task/6029:16) charged 24649 exec time (total:24649, rem:9975351)
685 P1: (base_task/6029:16) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
686 P1: (base_task/6029:16) scheduled_on = NO_CPU
687 P2: (base_task/6029:16) try_to_wake_up() state:1
688 P2: (base_task/6029:16) wake_up at 481456298218
689 P2: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=481456299926 to ready queue at 481456300532
690 P2: (base_task/6029:17) linking to local CPU 2 to avoid IPI
691 P2: (base_task/6029:17) try_to_wake_up() done state:0
692 P2: (base_task/6098:0) will be preempted by base_task/6029
693 P2: (base_task/6029:17) scheduled_on = P2
694 P2: (base_task/6029:17) migrate from 1
695 P2: (base_task/6029:17) stack_in_use=-1
696 P2: (base_task/6029:17) block at 481456368819
697 P2: (base_task/6029:17) charged 46334 exec time (total:46334, rem:9953666)
698 P2: (base_task/6029:17) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
699 P2: (base_task/6029:17) scheduled_on = NO_CPU
700 P3: (base_task/6029:17) try_to_wake_up() state:1
701 P3: (base_task/6029:17) wake_up at 481474921179
702 P3: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=481456299926 to ready queue at 481474923180
703 P3: (base_task/6029:17) linking to local CPU 3 to avoid IPI
704 P3: (base_task/6029:17) try_to_wake_up() done state:0
705 P3: (base_task/6099:0) will be preempted by base_task/6029
706 P3: (base_task/6029:17) scheduled_on = P3
707 P3: (base_task/6029:17) migrate from 2
708 P3: (base_task/6029:17) stack_in_use=-1
709 P3: (base_task/6029:17) block at 481474969910
710 P3: (base_task/6029:17) charged 32629 exec time (total:78963, rem:9921037)
711 P3: (base_task/6029:17) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
712 P3: (base_task/6029:17) scheduled_on = NO_CPU
713 P13: (base_task/6029:17) try_to_wake_up() state:1
714 P13: (base_task/6029:17) wake_up at 481487734629
715 P13: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=481456299926 to ready queue at 481487736107
716 P13: check_for_preemptions: attempting to link task 6029 to 6
717 P13: P3 is closest available CPU to P3
718 P13: (base_task/6029:17) try_to_wake_up() done state:0
719 P3: (swapper/3/0:0) will be preempted by base_task/6029
720 P3: (base_task/6029:17) scheduled_on = P3
721 P3: (base_task/6029:17) block at 481487782772
722 P3: (base_task/6029:17) charged 48152 exec time (total:127115, rem:9872885)
723 P3: (base_task/6029:17) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
724 P3: (base_task/6029:17) scheduled_on = NO_CPU
725 P6: (base_task/6029:17) try_to_wake_up() state:1
726 P6: (base_task/6029:17) wake_up at 481495348504
727 P6: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=481456299926 to ready queue at 481495349769
728 P6: (base_task/6029:17) linking to local CPU 6 to avoid IPI
729 P6: (base_task/6029:17) try_to_wake_up() done state:0
730 P6: (base_task/6102:0) will be preempted by base_task/6029
731 P6: (base_task/6029:17) scheduled_on = P6
732 P6: (base_task/6029:17) migrate from 3
733 P6: (base_task/6029:17) stack_in_use=-1
734 P6: (base_task/6029:17) block at 481495378678
735 P6: (base_task/6029:17) charged 20611 exec time (total:147726, rem:9852274)
736 P6: (base_task/6029:17) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
737 P6: (base_task/6029:17) scheduled_on = NO_CPU
738 P8: (base_task/6029:17) try_to_wake_up() state:1
739 P8: (base_task/6029:17) wake_up at 481513720920
740 P8: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=481456299926 to ready queue at 481513722500
741 P8: check_for_preemptions: attempting to link task 6029 to 8
742 P8: P6 is closest available CPU to P6
743 P8: (base_task/6029:17) try_to_wake_up() done state:0
744 P6: (swapper/6/0:0) will be preempted by base_task/6029
745 P6: (base_task/6029:17) scheduled_on = P6
746 P6: (base_task/6029:17) block at 481513789457
747 P6: (base_task/6029:17) charged 68598 exec time (total:216324, rem:9783676)
748 P6: (base_task/6029:17) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
749 P6: (base_task/6029:17) scheduled_on = NO_CPU
750 P12: (base_task/6029:17) try_to_wake_up() state:1
751 P12: (base_task/6029:17) wake_up at 481566809617
752 P12: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=481566810880 to ready queue at 481566811359
753 P12: check_for_preemptions: attempting to link task 6029 to 3
754 P12: P6 is closest available CPU to P6
755 P12: (base_task/6029:18) try_to_wake_up() done state:0
756 P6: (swapper/6/0:0) will be preempted by base_task/6029
757 P6: (base_task/6029:18) scheduled_on = P6
758 P6: (base_task/6029:18) job completion indicated at 481566925905
759 P6: (base_task/6029:18) charged 118226 exec time (total:118226, rem:9881774)
760 P6: (base_task/6029:18) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
761 P6: (base_task/6029:18) job_completion(forced=0).
762 P6: (base_task/6029:19) add_release(), rel=481666810880
763 P6: (base_task/6029:19) scheduled_on = NO_CPU
764 P6: (base_task/6029:19) linking to local CPU 6 to avoid IPI
765 P6: (swapper/6/0:0) will be preempted by base_task/6029
766 P6: (base_task/6029:19) scheduled_on = P6
767 P6: (base_task/6029:0) fork: real-time status denied
768 P6: (base_task/6029:19) charged 88170 exec time (total:88170, rem:9911830)
769 P6: (base_task/6029:0) fork: real-time status denied
770 P6: (base_task/6029:0) fork: real-time status denied
771 P6: (base_task/6029:0) fork: real-time status denied
772 P6: (base_task/6029:0) fork: real-time status denied
773 P6: (base_task/6029:0) fork: real-time status denied
774 P6: (base_task/6029:0) fork: real-time status denied
775 P6: (base_task/6029:0) fork: real-time status denied
776 P6: (base_task/6029:0) fork: real-time status denied
777 P6: (base_task/6029:0) fork: real-time status denied
778 P6: (base_task/6029:0) fork: real-time status denied
779 P6: (base_task/6029:0) fork: real-time status denied
780 P6: (base_task/6029:0) fork: real-time status denied
781 P6: (base_task/6029:0) fork: real-time status denied
782 P6: (base_task/6029:0) fork: real-time status denied
783 P6: (base_task/6029:0) fork: real-time status denied
784 P6: (base_task/6029:19) block at 481667627554
785 P6: (base_task/6029:19) charged 624576 exec time (total:712746, rem:9287254)
786 P6: (base_task/6029:19) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
787 P6: (base_task/6029:19) scheduled_on = NO_CPU
788 P7: (base_task/6029:19) try_to_wake_up() state:1
789 P7: (base_task/6029:19) wake_up at 489671253261
790 P7: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=489671255041 to ready queue at 489671255628
791 P7: (base_task/6029:20) linking to local CPU 7 to avoid IPI
792 P7: (base_task/6029:20) try_to_wake_up() done state:0
793 P7: (base_task/6114:0) will be preempted by base_task/6029
794 P7: (base_task/6029:20) scheduled_on = P7
795 P7: (base_task/6029:20) migrate from 6
796 P7: (base_task/6029:20) stack_in_use=-1
797 P7: (base_task/6029:20) block at 489671293287
798 P7: (base_task/6029:20) charged 23623 exec time (total:23623, rem:9976377)
799 P7: (base_task/6029:20) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
800 P7: (base_task/6029:20) scheduled_on = NO_CPU
801 P8: (base_task/6029:20) try_to_wake_up() state:1
802 P8: (base_task/6029:20) wake_up at 489785518400
803 P8: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=489785519635 to ready queue at 489785520142
804 P8: check_for_preemptions: attempting to link task 6029 to 4
805 P8: P7 is closest available CPU to P7
806 P8: (base_task/6029:21) try_to_wake_up() done state:0
807 P7: (swapper/7/0:0) will be preempted by base_task/6029
808 P7: (base_task/6029:21) scheduled_on = P7
809 P7: (base_task/6029:21) block at 489785598876
810 P7: (base_task/6029:21) charged 80558 exec time (total:80558, rem:9919442)
811 P7: (base_task/6029:21) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
812 P7: (base_task/6029:21) scheduled_on = NO_CPU
813 P2: (base_task/6029:21) try_to_wake_up() state:1
814 P2: (base_task/6029:21) wake_up at 489942844879
815 P2: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=489942846138 to ready queue at 489942846647
816 P2: (base_task/6029:22) linking to local CPU 2 to avoid IPI
817 P2: (base_task/6029:22) try_to_wake_up() done state:0
818 P2: (base_task/6124:0) will be preempted by base_task/6029
819 P2: (base_task/6029:22) scheduled_on = P2
820 P2: (base_task/6029:22) migrate from 7
821 P2: (base_task/6029:22) stack_in_use=-1
822 P2: (base_task/6029:22) job completion indicated at 489942920317
823 P2: (base_task/6029:22) charged 65935 exec time (total:65935, rem:9934065)
824 P2: (base_task/6029:22) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
825 P2: (base_task/6029:22) job_completion(forced=0).
826 P2: (base_task/6029:23) add_release(), rel=490042846138
827 P2: (base_task/6029:23) scheduled_on = NO_CPU
828 P2: (base_task/6029:23) linking to local CPU 2 to avoid IPI
829 P2: (swapper/2/0:0) will be preempted by base_task/6029
830 P2: (base_task/6029:23) scheduled_on = P2
831 P2: (base_task/6029:0) fork: real-time status denied
832 P2: (base_task/6029:23) charged 50076 exec time (total:50076, rem:9949924)
833 P2: (base_task/6029:0) fork: real-time status denied
834 P2: (base_task/6029:0) fork: real-time status denied
835 P2: (base_task/6029:0) fork: real-time status denied
836 P2: (base_task/6029:0) fork: real-time status denied
837 P2: (base_task/6029:0) fork: real-time status denied
838 P2: (base_task/6029:0) fork: real-time status denied
839 P2: (base_task/6029:0) fork: real-time status denied
840 P2: (base_task/6029:0) fork: real-time status denied
841 P2: (base_task/6029:0) fork: real-time status denied
842 P2: (base_task/6029:0) fork: real-time status denied
843 P2: (base_task/6029:0) fork: real-time status denied
844 P2: (base_task/6029:0) fork: real-time status denied
845 P2: (base_task/6029:0) fork: real-time status denied
846 P2: (base_task/6029:0) fork: real-time status denied
847 P2: (base_task/6029:0) fork: real-time status denied
848 P2: (base_task/6029:23) block at 490043638018
849 P2: (base_task/6029:23) charged 635452 exec time (total:685528, rem:9314472)
850 P2: (base_task/6029:23) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
851 P2: (base_task/6029:23) scheduled_on = NO_CPU
852 P3: (base_task/6029:23) try_to_wake_up() state:1
853 P3: (base_task/6029:23) wake_up at 498032526667
854 P3: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=498032528389 to ready queue at 498032529046
855 P3: (base_task/6029:24) linking to local CPU 3 to avoid IPI
856 P3: (base_task/6029:24) try_to_wake_up() done state:0
857 P3: (base_task/6130:0) will be preempted by base_task/6029
858 P3: (base_task/6029:24) scheduled_on = P3
859 P3: (base_task/6029:24) migrate from 2
860 P3: (base_task/6029:24) stack_in_use=-1
861 P3: (base_task/6029:24) block at 498032570271
862 P3: (base_task/6029:24) charged 27167 exec time (total:27167, rem:9972833)
863 P3: (base_task/6029:24) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
864 P3: (base_task/6029:24) scheduled_on = NO_CPU
865 P12: (base_task/6029:24) try_to_wake_up() state:1
866 P12: (base_task/6029:24) wake_up at 498085493329
867 P12: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=498032528389 to ready queue at 498085495466
868 P12: check_for_preemptions: attempting to link task 6029 to 0
869 P12: P3 is closest available CPU to P3
870 P12: (base_task/6029:24) try_to_wake_up() done state:0
871 P3: (base_task/6138:0) will be preempted by base_task/6029
872 P3: (base_task/6029:24) scheduled_on = P3
873 P3: (base_task/6029:24) block at 498085536164
874 P3: (base_task/6029:24) charged 42806 exec time (total:69973, rem:9930027)
875 P3: (base_task/6029:24) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
876 P3: (base_task/6029:24) scheduled_on = NO_CPU
877 P5: (base_task/6029:24) try_to_wake_up() state:1
878 P5: (base_task/6029:24) wake_up at 498122734582
879 P5: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=498032528389 to ready queue at 498122736248
880 P5: (base_task/6029:24) linking to local CPU 5 to avoid IPI
881 P5: (base_task/6029:24) try_to_wake_up() done state:0
882 P5: (base_task/6132:0) will be preempted by base_task/6029
883 P5: (base_task/6029:24) scheduled_on = P5
884 P5: (base_task/6029:24) migrate from 3
885 P5: (base_task/6029:24) stack_in_use=-1
886 P5: (base_task/6029:24) block at 498122797337
887 P5: (base_task/6029:24) charged 48339 exec time (total:118312, rem:9881688)
888 P5: (base_task/6029:24) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
889 P5: (base_task/6029:24) scheduled_on = NO_CPU
890 P8: (base_task/6029:24) try_to_wake_up() state:1
891 P8: (base_task/6029:24) wake_up at 498172226126
892 P8: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=498172227731 to ready queue at 498172228237
893 P8: check_for_preemptions: attempting to link task 6029 to 3
894 P8: P5 is closest available CPU to P5
895 P8: (base_task/6029:25) try_to_wake_up() done state:0
896 P5: (swapper/5/0:0) will be preempted by base_task/6029
897 P5: (base_task/6029:25) scheduled_on = P5
898 P5: (base_task/6029:25) block at 498172282057
899 P5: (base_task/6029:25) charged 55634 exec time (total:55634, rem:9944366)
900 P5: (base_task/6029:25) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
901 P5: (base_task/6029:25) scheduled_on = NO_CPU
902 P10: (base_task/6029:25) try_to_wake_up() state:1
903 P10: (base_task/6029:25) wake_up at 498297435454
904 P10: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=498297436639 to ready queue at 498297437154
905 P10: check_for_preemptions: attempting to link task 6029 to 3
906 P10: P5 is closest available CPU to P5
907 P10: (base_task/6029:26) try_to_wake_up() done state:0
908 P5: (swapper/5/0:0) will be preempted by base_task/6029
909 P5: (base_task/6029:26) scheduled_on = P5
910 P5: (base_task/6029:26) block at 498297496700
911 P5: (base_task/6029:26) charged 61307 exec time (total:61307, rem:9938693)
912 P5: (base_task/6029:26) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
913 P5: (base_task/6029:26) scheduled_on = NO_CPU
914 P3: (base_task/6029:26) try_to_wake_up() state:1
915 P3: (base_task/6029:26) wake_up at 498375668848
916 P3: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=498297436639 to ready queue at 498375670668
917 P3: (base_task/6029:26) linking to local CPU 3 to avoid IPI
918 P3: (base_task/6029:26) try_to_wake_up() done state:0
919 P3: (base_task/6138:0) will be preempted by base_task/6029
920 P3: (base_task/6029:26) scheduled_on = P3
921 P3: (base_task/6029:26) migrate from 5
922 P3: (base_task/6029:26) stack_in_use=-1
923 P3: (base_task/6029:26) block at 498375727297
924 P3: (base_task/6029:26) charged 48171 exec time (total:109478, rem:9890522)
925 P3: (base_task/6029:26) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
926 P3: (base_task/6029:26) scheduled_on = NO_CPU
927 P1: (base_task/6029:26) try_to_wake_up() state:1
928 P1: (base_task/6029:26) wake_up at 498458675916
929 P1: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=498458677113 to ready queue at 498458677664
930 P1: (base_task/6029:27) linking to local CPU 1 to avoid IPI
931 P1: (base_task/6029:27) try_to_wake_up() done state:0
932 P1: (base_task/6144:0) will be preempted by base_task/6029
933 P1: (base_task/6029:27) scheduled_on = P1
934 P1: (base_task/6029:27) migrate from 3
935 P1: (base_task/6029:27) stack_in_use=-1
936 P1: (base_task/6029:27) job completion indicated at 498458726316
937 P1: (base_task/6029:27) charged 41254 exec time (total:41254, rem:9958746)
938 P1: (base_task/6029:27) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
939 P1: (base_task/6029:27) job_completion(forced=0).
940 P1: (base_task/6029:28) add_release(), rel=498558677113
941 P1: (base_task/6029:28) scheduled_on = NO_CPU
942 P1: (base_task/6029:28) linking to local CPU 1 to avoid IPI
943 P1: (swapper/1/0:0) will be preempted by base_task/6029
944 P1: (base_task/6029:28) scheduled_on = P1
945 P1: (base_task/6029:0) fork: real-time status denied
946 P1: (base_task/6029:0) fork: real-time status denied
947 P1: (base_task/6029:0) fork: real-time status denied
948 P1: (base_task/6029:0) fork: real-time status denied
949 P1: (base_task/6029:28) charged 261576 exec time (total:261576, rem:9738424)
950 P1: (base_task/6029:0) fork: real-time status denied
951 P1: (base_task/6029:0) fork: real-time status denied
952 P1: (base_task/6029:0) fork: real-time status denied
953 P1: (base_task/6029:0) fork: real-time status denied
954 P1: (base_task/6029:0) fork: real-time status denied
955 P1: (base_task/6029:0) fork: real-time status denied
956 P1: (base_task/6029:0) fork: real-time status denied
957 P1: (base_task/6029:0) fork: real-time status denied
958 P1: (base_task/6029:0) fork: real-time status denied
959 P1: (base_task/6029:0) fork: real-time status denied
960 P1: (base_task/6029:0) fork: real-time status denied
961 P1: (base_task/6029:0) fork: real-time status denied
962 P1: (base_task/6029:28) block at 498559535992
963 P1: (base_task/6029:28) charged 532968 exec time (total:794544, rem:9205456)
964 P1: (base_task/6029:28) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
965 P1: (base_task/6029:28) scheduled_on = NO_CPU
966 P2: (base_task/6029:28) try_to_wake_up() state:1
967 P2: (base_task/6029:28) wake_up at 506583829913
968 P2: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=506583831535 to ready queue at 506583832573
969 P2: (base_task/6029:29) linking to local CPU 2 to avoid IPI
970 P2: (base_task/6029:29) try_to_wake_up() done state:0
971 P2: (base_task/6147:0) will be preempted by base_task/6029
972 P2: (base_task/6029:29) scheduled_on = P2
973 P2: (base_task/6029:29) migrate from 1
974 P2: (base_task/6029:29) stack_in_use=-1
975 P2: (base_task/6029:29) block at 506583868224
976 P2: (base_task/6029:29) charged 22827 exec time (total:22827, rem:9977173)
977 P2: (base_task/6029:29) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
978 P2: (base_task/6029:29) scheduled_on = NO_CPU
979 P11: (base_task/6029:29) try_to_wake_up() state:1
980 P11: (base_task/6029:29) wake_up at 506672292402
981 P11: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=506583831535 to ready queue at 506672294094
982 P11: check_for_preemptions: attempting to link task 6029 to 5
983 P11: P2 is closest available CPU to P2
984 P11: (base_task/6029:29) try_to_wake_up() done state:0
985 P2: (swapper/2/0:0) will be preempted by base_task/6029
986 P2: (base_task/6029:29) scheduled_on = P2
987 P2: (base_task/6029:29) block at 506672348201
988 P2: (base_task/6029:29) charged 55595 exec time (total:78422, rem:9921578)
989 P2: (base_task/6029:29) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
990 P2: (base_task/6029:29) scheduled_on = NO_CPU
991 P4: (base_task/6029:29) try_to_wake_up() state:1
992 P4: (base_task/6029:29) wake_up at 506676867208
993 P4: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=506583831535 to ready queue at 506676868487
994 P4: (base_task/6029:29) linking to local CPU 4 to avoid IPI
995 P4: (base_task/6029:29) try_to_wake_up() done state:0
996 P4: (base_task/6149:0) will be preempted by base_task/6029
997 P4: (base_task/6029:29) scheduled_on = P4
998 P4: (base_task/6029:29) migrate from 2
999 P4: (base_task/6029:29) stack_in_use=-1
1000 P4: (base_task/6029:29) block at 506676931071
1001 P4: (base_task/6029:29) charged 54486 exec time (total:132908, rem:9867092)
1002 P4: (base_task/6029:29) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1003 P4: (base_task/6029:29) scheduled_on = NO_CPU
1004 P7: (base_task/6029:29) try_to_wake_up() state:1
1005 P7: (base_task/6029:29) wake_up at 506782065396
1006 P7: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=506782066561 to ready queue at 506782067090
1007 P7: (base_task/6029:30) linking to local CPU 7 to avoid IPI
1008 P7: (base_task/6029:30) try_to_wake_up() done state:0
1009 P7: (base_task/6157:0) will be preempted by base_task/6029
1010 P7: (base_task/6029:30) scheduled_on = P7
1011 P7: (base_task/6029:30) migrate from 4
1012 P7: (base_task/6029:30) stack_in_use=-1
1013 P7: (base_task/6029:30) block at 506782118513
1014 P7: (base_task/6029:30) charged 42314 exec time (total:42314, rem:9957686)
1015 P7: (base_task/6029:30) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1016 P7: (base_task/6029:30) scheduled_on = NO_CPU
1017 P6: (base_task/6029:30) try_to_wake_up() state:1
1018 P6: (base_task/6029:30) wake_up at 506801576724
1019 P6: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=506782066561 to ready queue at 506801578351
1020 P6: (base_task/6029:30) linking to local CPU 6 to avoid IPI
1021 P6: (base_task/6029:30) try_to_wake_up() done state:0
1022 P6: (base_task/6162:0) will be preempted by base_task/6029
1023 P6: (base_task/6029:30) scheduled_on = P6
1024 P6: (base_task/6029:30) migrate from 7
1025 P6: (base_task/6029:30) stack_in_use=-1
1026 P6: (base_task/6029:30) job completion indicated at 506801635195
1027 P6: (base_task/6029:30) charged 43524 exec time (total:85838, rem:9914162)
1028 P6: (base_task/6029:30) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
1029 P6: (base_task/6029:30) job_completion(forced=0).
1030 P6: (base_task/6029:31) add_release(), rel=506882066561
1031 P6: (base_task/6029:31) scheduled_on = NO_CPU
1032 P6: (base_task/6029:31) linking to local CPU 6 to avoid IPI
1033 P6: (swapper/6/0:0) will be preempted by base_task/6029
1034 P6: (base_task/6029:31) scheduled_on = P6
1035 P6: (base_task/6029:0) fork: real-time status denied
1036 P6: (base_task/6029:0) fork: real-time status denied
1037 P6: (base_task/6029:0) fork: real-time status denied
1038 P6: (base_task/6029:0) fork: real-time status denied
1039 P6: (base_task/6029:0) fork: real-time status denied
1040 P6: (base_task/6029:0) fork: real-time status denied
1041 P6: (base_task/6029:0) fork: real-time status denied
1042 P6: (base_task/6029:0) fork: real-time status denied
1043 P6: (base_task/6029:0) fork: real-time status denied
1044 P6: (base_task/6029:0) fork: real-time status denied
1045 P6: (base_task/6029:0) fork: real-time status denied
1046 P6: (base_task/6029:0) fork: real-time status denied
1047 P6: (base_task/6029:0) fork: real-time status denied
1048 P6: (base_task/6029:0) fork: real-time status denied
1049 P6: (base_task/6029:0) fork: real-time status denied
1050 P6: (base_task/6029:0) fork: real-time status denied
1051 P6: (base_task/6029:31) block at 506882826961
1052 P6: (base_task/6029:31) charged 706278 exec time (total:706278, rem:9293722)
1053 P6: (base_task/6029:31) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1054 P6: (base_task/6029:31) scheduled_on = NO_CPU
1055 P15: (base_task/6029:31) try_to_wake_up() state:1
1056 P15: (base_task/6029:31) wake_up at 514885033269
1057 P15: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=514885034415 to ready queue at 514885034893
1058 P15: check_for_preemptions: attempting to link task 6029 to 9
1059 P15: P6 is closest available CPU to P6
1060 P15: (base_task/6029:32) try_to_wake_up() done state:0
1061 P6: (Xorg/4989:0) will be preempted by base_task/6029
1062 P6: (base_task/6029:32) scheduled_on = P6
1063 P6: (base_task/6029:32) block at 514885074296
1064 P6: (base_task/6029:32) charged 40929 exec time (total:40929, rem:9959071)
1065 P6: (base_task/6029:32) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1066 P6: (base_task/6029:32) scheduled_on = NO_CPU
1067 P0: (base_task/6029:32) try_to_wake_up() state:1
1068 P0: (base_task/6029:32) wake_up at 515584062545
1069 P0: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=515584063687 to ready queue at 515584064148
1070 P0: (base_task/6029:33) linking to local CPU 0 to avoid IPI
1071 P0: (base_task/6029:33) try_to_wake_up() done state:0
1072 P0: (base_task/6165:0) will be preempted by base_task/6029
1073 P0: (base_task/6029:33) scheduled_on = P0
1074 P0: (base_task/6029:33) migrate from 6
1075 P0: (base_task/6029:33) stack_in_use=-1
1076 P0: (base_task/6029:33) job completion indicated at 515584187800
1077 P0: (base_task/6029:33) charged 115552 exec time (total:115552, rem:9884448)
1078 P0: (base_task/6029:33) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
1079 P0: (base_task/6029:33) job_completion(forced=0).
1080 P0: (base_task/6029:34) add_release(), rel=515684063687
1081 P0: (base_task/6029:34) scheduled_on = NO_CPU
1082 P0: (base_task/6029:34) linking to local CPU 0 to avoid IPI
1083 P0: (swapper/0/0:0) will be preempted by base_task/6029
1084 P0: (base_task/6029:34) scheduled_on = P0
1085 P0: (base_task/6029:0) fork: real-time status denied
1086 P0: (base_task/6029:0) fork: real-time status denied
1087 P0: (base_task/6029:0) fork: real-time status denied
1088 P0: (base_task/6029:0) fork: real-time status denied
1089 P0: (base_task/6029:0) fork: real-time status denied
1090 P0: (base_task/6029:0) fork: real-time status denied
1091 P0: (base_task/6029:0) fork: real-time status denied
1092 P0: (base_task/6029:0) fork: real-time status denied
1093 P0: (base_task/6029:0) fork: real-time status denied
1094 P0: (base_task/6029:0) fork: real-time status denied
1095 P0: (base_task/6029:0) fork: real-time status denied
1096 P0: (base_task/6029:0) fork: real-time status denied
1097 P0: (base_task/6029:0) fork: real-time status denied
1098 P0: (base_task/6029:0) fork: real-time status denied
1099 P0: (base_task/6029:0) fork: real-time status denied
1100 P0: (base_task/6029:0) fork: real-time status denied
1101 P0: (base_task/6029:34) block at 515684768268
1102 P0: (base_task/6029:34) charged 694787 exec time (total:694787, rem:9305213)
1103 P0: (base_task/6029:34) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1104 P0: (base_task/6029:34) scheduled_on = NO_CPU
1105 P0: (base_task/6029:34) try_to_wake_up() state:1
1106 P0: (base_task/6029:34) wake_up at 518463667707
1107 P0: rt: adding base_task/6029 (10000000, 100000000, 100000000) rel=518463669545 to ready queue at 518463670289
1108 P0: (base_task/6029:35) linking to local CPU 0 to avoid IPI
1109 P0: (base_task/6029:35) try_to_wake_up() done state:0
1110 P0: (kworker/u32:0/5988:0) will be preempted by base_task/6029
1111 P0: (base_task/6029:35) scheduled_on = P0
1112 P0: (base_task/6029:35) exiting, demoted to SCHED_FIFO
1113 P0: (base_task/6029:35) RIP
1114 P0: (base_task/6029:35) ignoring a dequeue, not going to sleep.
1115 P0: (base_task/6029:35) Deallocating real-time task data
1116 P0: (base_task/6029:0) litmus_ctrl_vm_close flags=0x10160073 prot=0x25
1117 P0: (base_task/6029:0) litmus/ctrl: 00007f87ab062000:00007f87ab063000 vma:ffff880408a7a000 vma->vm_private_data:          (null) closed.
1118 P2: (base_task/6029:0) freeing ctrl_page ffff88043c0c0000
1119 P14: 
6Enabling feather-trace event 501.
1120 P14: 
6Enabling feather-trace event 502.
1121 P14: 
6Enabling feather-trace event 503.
1122 P14: 
6Enabling feather-trace event 504.
1123 P14: 
6Enabling feather-trace event 505.
1124 P14: 
6Enabling feather-trace event 506.
1125 P14: 
6Enabling feather-trace event 507.
1126 P14: 
6Enabling feather-trace event 508.
1127 P14: 
6Enabling feather-trace event 509.
1128 P14: 
6Enabling feather-trace event 510.
1129 P14: 
6Enabling feather-trace event 511.
1130 P1: 
6Enabling feather-trace event 501.
1131 P1: 
6Enabling feather-trace event 502.
1132 P1: 
6Enabling feather-trace event 503.
1133 P1: 
6Enabling feather-trace event 504.
1134 P1: 
6Enabling feather-trace event 505.
1135 P1: 
6Enabling feather-trace event 506.
1136 P1: 
6Enabling feather-trace event 507.
1137 P1: 
6Enabling feather-trace event 508.
1138 P1: 
6Enabling feather-trace event 509.
1139 P1: 
6Enabling feather-trace event 510.
1140 P1: 
6Enabling feather-trace event 511.
1141 P9: 
6Enabling feather-trace event 501.
1142 P9: 
6Enabling feather-trace event 502.
1143 P9: 
6Enabling feather-trace event 503.
1144 P9: 
6Enabling feather-trace event 504.
1145 P9: 
6Enabling feather-trace event 505.
1146 P9: 
6Enabling feather-trace event 506.
1147 P9: 
6Enabling feather-trace event 507.
1148 P9: 
6Enabling feather-trace event 508.
1149 P9: 
6Enabling feather-trace event 509.
1150 P9: 
6Enabling feather-trace event 510.
1151 P9: 
6Enabling feather-trace event 511.
1152 P9: 
6Enabling feather-trace event 501.
1153 P9: 
6Enabling feather-trace event 502.
1154 P9: 
6Enabling feather-trace event 503.
1155 P9: 
6Enabling feather-trace event 504.
1156 P9: 
6Enabling feather-trace event 505.
1157 P9: 
6Enabling feather-trace event 506.
1158 P9: 
6Enabling feather-trace event 507.
1159 P9: 
6Enabling feather-trace event 508.
1160 P9: 
6Enabling feather-trace event 509.
1161 P9: 
6Enabling feather-trace event 510.
1162 P9: 
6Enabling feather-trace event 511.
1163 P9: 
6Enabling feather-trace event 501.
1164 P9: 
6Enabling feather-trace event 502.
1165 P9: 
6Enabling feather-trace event 503.
1166 P9: 
6Enabling feather-trace event 504.
1167 P9: 
6Enabling feather-trace event 505.
1168 P9: 
6Enabling feather-trace event 506.
1169 P9: 
6Enabling feather-trace event 507.
1170 P9: 
6Enabling feather-trace event 508.
1171 P9: 
6Enabling feather-trace event 509.
1172 P9: 
6Enabling feather-trace event 510.
1173 P9: 
6Enabling feather-trace event 511.
1174 P9: 
6Enabling feather-trace event 501.
1175 P9: 
6Enabling feather-trace event 502.
1176 P9: 
6Enabling feather-trace event 503.
1177 P9: 
6Enabling feather-trace event 504.
1178 P9: 
6Enabling feather-trace event 505.
1179 P9: 
6Enabling feather-trace event 506.
1180 P9: 
6Enabling feather-trace event 507.
1181 P9: 
6Enabling feather-trace event 508.
1182 P9: 
6Enabling feather-trace event 509.
1183 P9: 
6Enabling feather-trace event 510.
1184 P9: 
6Enabling feather-trace event 511.
1185 P2: 
6Enabling feather-trace event 501.
1186 P2: 
6Enabling feather-trace event 502.
1187 P2: 
6Enabling feather-trace event 503.
1188 P2: 
6Enabling feather-trace event 504.
1189 P2: 
6Enabling feather-trace event 505.
1190 P2: 
6Enabling feather-trace event 506.
1191 P2: 
6Enabling feather-trace event 507.
1192 P2: 
6Enabling feather-trace event 508.
1193 P2: 
6Enabling feather-trace event 509.
1194 P2: 
6Enabling feather-trace event 510.
1195 P2: 
6Enabling feather-trace event 511.
1196 P2: 
6Enabling feather-trace event 501.
1197 P2: 
6Enabling feather-trace event 502.
1198 P2: 
6Enabling feather-trace event 503.
1199 P2: 
6Enabling feather-trace event 504.
1200 P2: 
6Enabling feather-trace event 505.
1201 P2: 
6Enabling feather-trace event 506.
1202 P2: 
6Enabling feather-trace event 507.
1203 P2: 
6Enabling feather-trace event 508.
1204 P2: 
6Enabling feather-trace event 509.
1205 P2: 
6Enabling feather-trace event 510.
1206 P2: 
6Enabling feather-trace event 511.
1207 P2: 
6Enabling feather-trace event 501.
1208 P2: 
6Enabling feather-trace event 502.
1209 P2: 
6Enabling feather-trace event 503.
1210 P2: 
6Enabling feather-trace event 504.
1211 P2: 
6Enabling feather-trace event 505.
1212 P2: 
6Enabling feather-trace event 506.
1213 P2: 
6Enabling feather-trace event 507.
1214 P2: 
6Enabling feather-trace event 508.
1215 P2: 
6Enabling feather-trace event 509.
1216 P2: 
6Enabling feather-trace event 510.
1217 P2: 
6Enabling feather-trace event 511.
1218 P11: 
6Enabling feather-trace event 501.
1219 P11: 
6Enabling feather-trace event 502.
1220 P11: 
6Enabling feather-trace event 503.
1221 P11: 
6Enabling feather-trace event 504.
1222 P11: 
6Enabling feather-trace event 505.
1223 P11: 
6Enabling feather-trace event 506.
1224 P11: 
6Enabling feather-trace event 507.
1225 P11: 
6Enabling feather-trace event 508.
1226 P11: 
6Enabling feather-trace event 509.
1227 P11: 
6Enabling feather-trace event 510.
1228 P11: 
6Enabling feather-trace event 511.
1229 P11: 
6Enabling feather-trace event 501.
1230 P11: 
6Enabling feather-trace event 502.
1231 P11: 
6Enabling feather-trace event 503.
1232 P11: 
6Enabling feather-trace event 504.
1233 P11: 
6Enabling feather-trace event 505.
1234 P11: 
6Enabling feather-trace event 506.
1235 P11: 
6Enabling feather-trace event 507.
1236 P11: 
6Enabling feather-trace event 508.
1237 P11: 
6Enabling feather-trace event 509.
1238 P11: 
6Enabling feather-trace event 510.
1239 P11: 
6Enabling feather-trace event 511.
1240 P4: 
6Enabling feather-trace event 501.
1241 P4: 
6Enabling feather-trace event 502.
1242 P4: 
6Enabling feather-trace event 503.
1243 P4: 
6Enabling feather-trace event 504.
1244 P4: 
6Enabling feather-trace event 505.
1245 P4: 
6Enabling feather-trace event 506.
1246 P4: 
6Enabling feather-trace event 507.
1247 P4: 
6Enabling feather-trace event 508.
1248 P4: 
6Enabling feather-trace event 509.
1249 P4: 
6Enabling feather-trace event 510.
1250 P4: 
6Enabling feather-trace event 511.
1251 P2: 
6Enabling feather-trace event 501.
1252 P2: 
6Enabling feather-trace event 502.
1253 P2: 
6Enabling feather-trace event 503.
1254 P2: 
6Enabling feather-trace event 504.
1255 P2: 
6Enabling feather-trace event 505.
1256 P2: 
6Enabling feather-trace event 506.
1257 P2: 
6Enabling feather-trace event 507.
1258 P2: 
6Enabling feather-trace event 508.
1259 P2: 
6Enabling feather-trace event 509.
1260 P2: 
6Enabling feather-trace event 510.
1261 P2: 
6Enabling feather-trace event 511.
1262 P2: 
6Enabling feather-trace event 501.
1263 P2: 
6Enabling feather-trace event 502.
1264 P2: 
6Enabling feather-trace event 503.
1265 P2: 
6Enabling feather-trace event 504.
1266 P2: 
6Enabling feather-trace event 505.
1267 P2: 
6Enabling feather-trace event 506.
1268 P2: 
6Enabling feather-trace event 507.
1269 P2: 
6Enabling feather-trace event 508.
1270 P2: 
6Enabling feather-trace event 509.
1271 P2: 
6Enabling feather-trace event 510.
1272 P2: 
6Enabling feather-trace event 511.
1273 P2: 
6Enabling feather-trace event 501.
1274 P2: 
6Enabling feather-trace event 502.
1275 P2: 
6Enabling feather-trace event 503.
1276 P2: 
6Enabling feather-trace event 504.
1277 P2: 
6Enabling feather-trace event 505.
1278 P2: 
6Enabling feather-trace event 506.
1279 P2: 
6Enabling feather-trace event 507.
1280 P2: 
6Enabling feather-trace event 508.
1281 P2: 
6Enabling feather-trace event 509.
1282 P2: 
6Enabling feather-trace event 510.
1283 P2: 
6Enabling feather-trace event 511.
1284 P2: 
6Enabling feather-trace event 501.
1285 P2: 
6Enabling feather-trace event 502.
1286 P2: 
6Enabling feather-trace event 503.
1287 P2: 
6Enabling feather-trace event 504.
1288 P2: 
6Enabling feather-trace event 505.
1289 P2: 
6Enabling feather-trace event 506.
1290 P2: 
6Enabling feather-trace event 507.
1291 P2: 
6Enabling feather-trace event 508.
1292 P2: 
6Enabling feather-trace event 509.
1293 P2: 
6Enabling feather-trace event 510.
1294 P2: 
6Enabling feather-trace event 511.
1295 P13: (base_task/6510:0) alloc_ctrl_page ctrl_page = ffff880408a63000
1296 P13: (base_task/6510:0) litmus/ctrl: mapping ffff880408a63000 (pfn:408a63) to 0x7fc81c8e3000 (prot:8000000000000027)
1297 P13: (base_task/6510:0) litmus_ctrl_mmap flags=0x10162073 prot=0x8000000000000027
1298 P13: Setting up rt task parameters for process 6510.
1299 P13: gsn edf: task new 6510
1300 P13: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=735473212872 to ready queue at 735473213187
1301 P13: check_for_preemptions: attempting to link task 6510 to 3
1302 P13: P13 is closest available CPU to P13
1303 P13: (base_task/6510:1) ignoring an enqueue, not a wake up.
1304 P13: (base_task/6510:1) charged 2528 exec time (total:2528, rem:9997472)
1305 P13: (base_task/6510:1) blocks:0 out_of_time:0 np:0 sleep:0 preempt:0 state:0 sig:0
1306 P13: (base_task/6510:1) job completion indicated at 735473227632
1307 P13: (base_task/6510:1) charged 5333 exec time (total:7861, rem:9992139)
1308 P13: (base_task/6510:1) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
1309 P13: (base_task/6510:1) job_completion(forced=0).
1310 P13: (base_task/6510:2) add_release(), rel=735573212872
1311 P13: (base_task/6510:2) scheduled_on = NO_CPU
1312 P13: check_for_preemptions: attempting to link task 6510 to 11
1313 P13: P13 is closest available CPU to P13
1314 P13: (swapper/13/0:0) will be preempted by base_task/6510
1315 P13: (base_task/6510:2) scheduled_on = P13
1316 P13: (base_task/6510:0) fork: real-time status denied
1317 P13: (base_task/6510:0) fork: real-time status denied
1318 P13: (base_task/6510:0) fork: real-time status denied
1319 P13: (base_task/6510:0) fork: real-time status denied
1320 P13: (base_task/6510:0) fork: real-time status denied
1321 P13: (base_task/6510:0) fork: real-time status denied
1322 P13: (base_task/6510:0) fork: real-time status denied
1323 P13: (base_task/6510:0) fork: real-time status denied
1324 P13: (base_task/6510:0) fork: real-time status denied
1325 P13: (base_task/6510:0) fork: real-time status denied
1326 P13: (base_task/6510:0) fork: real-time status denied
1327 P13: (base_task/6510:0) fork: real-time status denied
1328 P13: (base_task/6510:0) fork: real-time status denied
1329 P13: (base_task/6510:0) fork: real-time status denied
1330 P13: (base_task/6510:0) fork: real-time status denied
1331 P13: (base_task/6510:2) charged 725248 exec time (total:725248, rem:9274752)
1332 P13: (base_task/6510:0) fork: real-time status denied
1333 P13: (base_task/6510:2) block at 735574107536
1334 P13: (base_task/6510:2) charged 103958 exec time (total:829206, rem:9170794)
1335 P13: (base_task/6510:2) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1336 P13: (base_task/6510:2) scheduled_on = NO_CPU
1337 P6: (base_task/6510:2) try_to_wake_up() state:1
1338 P6: (base_task/6510:2) wake_up at 743669079717
1339 P6: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=743669080908 to ready queue at 743669081661
1340 P6: (base_task/6510:3) linking to local CPU 6 to avoid IPI
1341 P6: (base_task/6510:3) try_to_wake_up() done state:0
1342 P6: (base_task/6511:0) will be preempted by base_task/6510
1343 P6: (base_task/6510:3) scheduled_on = P6
1344 P6: (base_task/6510:3) migrate from 13
1345 P6: (base_task/6510:3) stack_in_use=-1
1346 P6: (base_task/6510:3) job completion indicated at 743669214204
1347 P6: (base_task/6510:3) charged 124496 exec time (total:124496, rem:9875504)
1348 P6: (base_task/6510:3) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
1349 P6: (base_task/6510:3) job_completion(forced=0).
1350 P6: (base_task/6510:4) add_release(), rel=743769080908
1351 P6: (base_task/6510:4) scheduled_on = NO_CPU
1352 P6: (base_task/6510:4) linking to local CPU 6 to avoid IPI
1353 P6: (swapper/6/0:0) will be preempted by base_task/6510
1354 P6: (base_task/6510:4) scheduled_on = P6
1355 P6: (base_task/6510:0) fork: real-time status denied
1356 P6: (base_task/6510:0) fork: real-time status denied
1357 P6: (base_task/6510:0) fork: real-time status denied
1358 P6: (base_task/6510:0) fork: real-time status denied
1359 P6: (base_task/6510:0) fork: real-time status denied
1360 P6: (base_task/6510:0) fork: real-time status denied
1361 P6: (base_task/6510:0) fork: real-time status denied
1362 P6: (base_task/6510:0) fork: real-time status denied
1363 P6: (base_task/6510:0) fork: real-time status denied
1364 P6: (base_task/6510:0) fork: real-time status denied
1365 P6: (base_task/6510:0) fork: real-time status denied
1366 P6: (base_task/6510:0) fork: real-time status denied
1367 P6: (base_task/6510:0) fork: real-time status denied
1368 P6: (base_task/6510:0) fork: real-time status denied
1369 P6: (base_task/6510:0) fork: real-time status denied
1370 P6: (base_task/6510:0) fork: real-time status denied
1371 P6: (base_task/6510:4) charged 896044 exec time (total:896044, rem:9103956)
1372 P6: (base_task/6510:4) block at 743770042663
1373 P6: (base_task/6510:4) charged 40152 exec time (total:936196, rem:9063804)
1374 P6: (base_task/6510:4) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1375 P6: (base_task/6510:4) scheduled_on = NO_CPU
1376 P7: (base_task/6510:4) try_to_wake_up() state:1
1377 P7: (base_task/6510:4) wake_up at 751818684566
1378 P7: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=751818685730 to ready queue at 751818686703
1379 P7: (base_task/6510:5) linking to local CPU 7 to avoid IPI
1380 P7: (base_task/6510:5) try_to_wake_up() done state:0
1381 P7: (base_task/6529:0) will be preempted by base_task/6510
1382 P7: (base_task/6510:5) scheduled_on = P7
1383 P7: (base_task/6510:5) migrate from 6
1384 P7: (base_task/6510:5) stack_in_use=-1
1385 P7: (base_task/6510:5) block at 751818725713
1386 P7: (base_task/6510:5) charged 30356 exec time (total:30356, rem:9969644)
1387 P7: (base_task/6510:5) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1388 P7: (base_task/6510:5) scheduled_on = NO_CPU
1389 P12: (base_task/6510:5) try_to_wake_up() state:1
1390 P12: (base_task/6510:5) wake_up at 751822149082
1391 P12: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=751818685730 to ready queue at 751822150327
1392 P12: check_for_preemptions: attempting to link task 6510 to 6
1393 P12: P7 is closest available CPU to P7
1394 P12: (base_task/6510:5) try_to_wake_up() done state:0
1395 P7: (swapper/7/0:0) will be preempted by base_task/6510
1396 P7: (base_task/6510:5) scheduled_on = P7
1397 P7: (base_task/6510:5) job completion indicated at 751822211266
1398 P7: (base_task/6510:5) charged 64289 exec time (total:94645, rem:9905355)
1399 P7: (base_task/6510:5) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
1400 P7: (base_task/6510:5) job_completion(forced=0).
1401 P7: (base_task/6510:6) add_release(), rel=751918685730
1402 P7: (base_task/6510:6) scheduled_on = NO_CPU
1403 P7: (base_task/6510:6) linking to local CPU 7 to avoid IPI
1404 P7: (swapper/7/0:0) will be preempted by base_task/6510
1405 P7: (base_task/6510:6) scheduled_on = P7
1406 P7: (base_task/6510:0) fork: real-time status denied
1407 P7: (base_task/6510:0) fork: real-time status denied
1408 P7: (base_task/6510:0) fork: real-time status denied
1409 P7: (base_task/6510:0) fork: real-time status denied
1410 P7: (base_task/6510:6) charged 224644 exec time (total:224644, rem:9775356)
1411 P7: (base_task/6510:0) fork: real-time status denied
1412 P7: (base_task/6510:0) fork: real-time status denied
1413 P7: (base_task/6510:0) fork: real-time status denied
1414 P7: (base_task/6510:0) fork: real-time status denied
1415 P7: (base_task/6510:0) fork: real-time status denied
1416 P7: (base_task/6510:0) fork: real-time status denied
1417 P7: (base_task/6510:0) fork: real-time status denied
1418 P7: (base_task/6510:0) fork: real-time status denied
1419 P7: (base_task/6510:0) fork: real-time status denied
1420 P7: (base_task/6510:0) fork: real-time status denied
1421 P7: (base_task/6510:0) fork: real-time status denied
1422 P7: (base_task/6510:0) fork: real-time status denied
1423 P7: (base_task/6510:6) block at 751919546390
1424 P7: (base_task/6510:6) charged 543475 exec time (total:768119, rem:9231881)
1425 P7: (base_task/6510:6) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1426 P7: (base_task/6510:6) scheduled_on = NO_CPU
1427 P5: (base_task/6510:6) try_to_wake_up() state:1
1428 P5: (base_task/6510:6) wake_up at 759993294134
1429 P5: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=759993295306 to ready queue at 759993296054
1430 P5: (base_task/6510:7) linking to local CPU 5 to avoid IPI
1431 P5: (base_task/6510:7) try_to_wake_up() done state:0
1432 P5: (base_task/6545:0) will be preempted by base_task/6510
1433 P5: (base_task/6510:7) scheduled_on = P5
1434 P5: (base_task/6510:7) migrate from 7
1435 P5: (base_task/6510:7) stack_in_use=-1
1436 P5: (base_task/6510:7) block at 759993333849
1437 P5: (base_task/6510:7) charged 29162 exec time (total:29162, rem:9970838)
1438 P5: (base_task/6510:7) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1439 P5: (base_task/6510:7) scheduled_on = NO_CPU
1440 P0: (base_task/6510:7) try_to_wake_up() state:1
1441 P0: (base_task/6510:7) wake_up at 759995097508
1442 P0: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=759993295306 to ready queue at 759995098685
1443 P0: (base_task/6510:7) linking to local CPU 0 to avoid IPI
1444 P0: (base_task/6510:7) try_to_wake_up() done state:0
1445 P0: (base_task/6554:0) will be preempted by base_task/6510
1446 P0: (base_task/6510:7) scheduled_on = P0
1447 P0: (base_task/6510:7) migrate from 5
1448 P0: (base_task/6510:7) stack_in_use=-1
1449 P0: (base_task/6510:7) block at 759995122009
1450 P0: (base_task/6510:7) charged 14987 exec time (total:44149, rem:9955851)
1451 P0: (base_task/6510:7) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1452 P0: (base_task/6510:7) scheduled_on = NO_CPU
1453 P4: (base_task/6510:7) try_to_wake_up() state:1
1454 P4: (base_task/6510:7) wake_up at 760036590751
1455 P4: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=759993295306 to ready queue at 760036592200
1456 P4: (base_task/6510:7) linking to local CPU 4 to avoid IPI
1457 P4: (base_task/6510:7) try_to_wake_up() done state:0
1458 P4: (base_task/6558:0) will be preempted by base_task/6510
1459 P4: (base_task/6510:7) scheduled_on = P4
1460 P4: (base_task/6510:7) migrate from 0
1461 P4: (base_task/6510:7) stack_in_use=-1
1462 P4: (base_task/6510:7) job completion indicated at 760036629262
1463 P4: (base_task/6510:7) charged 30491 exec time (total:74640, rem:9925360)
1464 P4: (base_task/6510:7) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
1465 P4: (base_task/6510:7) job_completion(forced=0).
1466 P4: (base_task/6510:8) add_release(), rel=760093295306
1467 P4: (base_task/6510:8) scheduled_on = NO_CPU
1468 P4: (base_task/6510:8) linking to local CPU 4 to avoid IPI
1469 P4: (swapper/4/0:0) will be preempted by base_task/6510
1470 P4: (base_task/6510:8) scheduled_on = P4
1471 P4: (base_task/6510:0) fork: real-time status denied
1472 P4: (base_task/6510:0) fork: real-time status denied
1473 P4: (base_task/6510:0) fork: real-time status denied
1474 P4: (base_task/6510:0) fork: real-time status denied
1475 P4: (base_task/6510:0) fork: real-time status denied
1476 P4: (base_task/6510:0) fork: real-time status denied
1477 P4: (base_task/6510:0) fork: real-time status denied
1478 P4: (base_task/6510:0) fork: real-time status denied
1479 P4: (base_task/6510:0) fork: real-time status denied
1480 P4: (base_task/6510:0) fork: real-time status denied
1481 P4: (base_task/6510:0) fork: real-time status denied
1482 P4: (base_task/6510:8) charged 687338 exec time (total:687338, rem:9312662)
1483 P4: (base_task/6510:0) fork: real-time status denied
1484 P4: (base_task/6510:0) fork: real-time status denied
1485 P4: (base_task/6510:0) fork: real-time status denied
1486 P4: (base_task/6510:0) fork: real-time status denied
1487 P4: (base_task/6510:0) fork: real-time status denied
1488 P4: (base_task/6510:8) block at 760094243725
1489 P4: (base_task/6510:8) charged 241096 exec time (total:928434, rem:9071566)
1490 P4: (base_task/6510:8) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1491 P4: (base_task/6510:8) scheduled_on = NO_CPU
1492 P7: (base_task/6510:8) try_to_wake_up() state:1
1493 P7: (base_task/6510:8) wake_up at 768097958339
1494 P7: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=768097959488 to ready queue at 768097960290
1495 P7: (base_task/6510:9) linking to local CPU 7 to avoid IPI
1496 P7: (base_task/6510:9) try_to_wake_up() done state:0
1497 P7: (base_task/6561:0) will be preempted by base_task/6510
1498 P7: (base_task/6510:9) scheduled_on = P7
1499 P7: (base_task/6510:9) migrate from 4
1500 P7: (base_task/6510:9) stack_in_use=-1
1501 P7: (base_task/6510:9) block at 768097982467
1502 P7: (base_task/6510:9) charged 12863 exec time (total:12863, rem:9987137)
1503 P7: (base_task/6510:9) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1504 P7: (base_task/6510:9) scheduled_on = NO_CPU
1505 P7: (base_task/6510:9) try_to_wake_up() state:1
1506 P7: (base_task/6510:9) wake_up at 768148277243
1507 P7: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=768097959488 to ready queue at 768148278985
1508 P7: (base_task/6510:9) linking to local CPU 7 to avoid IPI
1509 P7: (base_task/6510:9) try_to_wake_up() done state:0
1510 P7: (base_task/6562:0) will be preempted by base_task/6510
1511 P7: (base_task/6510:9) scheduled_on = P7
1512 P7: (base_task/6510:9) block at 768148314759
1513 P7: (base_task/6510:9) charged 37850 exec time (total:50713, rem:9949287)
1514 P7: (base_task/6510:9) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1515 P7: (base_task/6510:9) scheduled_on = NO_CPU
1516 P0: (base_task/6510:9) try_to_wake_up() state:1
1517 P0: (base_task/6510:9) wake_up at 768149686739
1518 P0: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=768097959488 to ready queue at 768149688002
1519 P0: (base_task/6510:9) linking to local CPU 0 to avoid IPI
1520 P0: (base_task/6510:9) try_to_wake_up() done state:0
1521 P0: (base_task/6571:0) will be preempted by base_task/6510
1522 P0: (base_task/6510:9) scheduled_on = P0
1523 P0: (base_task/6510:9) migrate from 7
1524 P0: (base_task/6510:9) stack_in_use=-1
1525 P0: (base_task/6510:9) job completion indicated at 768149728618
1526 P0: (base_task/6510:9) charged 34197 exec time (total:84910, rem:9915090)
1527 P0: (base_task/6510:9) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
1528 P0: (base_task/6510:9) job_completion(forced=0).
1529 P0: (base_task/6510:10) add_release(), rel=768197959488
1530 P0: (base_task/6510:10) scheduled_on = NO_CPU
1531 P0: (base_task/6510:10) linking to local CPU 0 to avoid IPI
1532 P0: (swapper/0/0:0) will be preempted by base_task/6510
1533 P0: (base_task/6510:10) scheduled_on = P0
1534 P0: (base_task/6510:0) fork: real-time status denied
1535 P0: (base_task/6510:0) fork: real-time status denied
1536 P0: (base_task/6510:0) fork: real-time status denied
1537 P0: (base_task/6510:0) fork: real-time status denied
1538 P0: (base_task/6510:0) fork: real-time status denied
1539 P0: (base_task/6510:0) fork: real-time status denied
1540 P0: (base_task/6510:0) fork: real-time status denied
1541 P0: (base_task/6510:0) fork: real-time status denied
1542 P0: (base_task/6510:0) fork: real-time status denied
1543 P0: (base_task/6510:0) fork: real-time status denied
1544 P0: (base_task/6510:0) fork: real-time status denied
1545 P0: (base_task/6510:0) fork: real-time status denied
1546 P0: (base_task/6510:0) fork: real-time status denied
1547 P0: (base_task/6510:0) fork: real-time status denied
1548 P0: (base_task/6510:0) fork: real-time status denied
1549 P0: (base_task/6510:0) fork: real-time status denied
1550 P0: (base_task/6510:10) block at 768198961380
1551 P0: (base_task/6510:10) charged 886835 exec time (total:886835, rem:9113165)
1552 P0: (base_task/6510:10) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1553 P0: (base_task/6510:10) scheduled_on = NO_CPU
1554 P1: (base_task/6510:10) try_to_wake_up() state:1
1555 P1: (base_task/6510:10) wake_up at 776352083174
1556 P1: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=776352084287 to ready queue at 776352085089
1557 P1: (base_task/6510:11) linking to local CPU 1 to avoid IPI
1558 P1: (base_task/6510:11) try_to_wake_up() done state:0
1559 P1: (base_task/6577:0) will be preempted by base_task/6510
1560 P1: (base_task/6510:11) scheduled_on = P1
1561 P1: (base_task/6510:11) migrate from 0
1562 P1: (base_task/6510:11) stack_in_use=-1
1563 P1: (base_task/6510:11) job completion indicated at 776352153827
1564 P1: (base_task/6510:11) charged 60536 exec time (total:60536, rem:9939464)
1565 P1: (base_task/6510:11) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
1566 P1: (base_task/6510:11) job_completion(forced=0).
1567 P1: (base_task/6510:12) add_release(), rel=776452084287
1568 P1: (base_task/6510:12) scheduled_on = NO_CPU
1569 P1: (base_task/6510:12) linking to local CPU 1 to avoid IPI
1570 P1: (swapper/1/0:0) will be preempted by base_task/6510
1571 P1: (base_task/6510:12) scheduled_on = P1
1572 P1: (base_task/6510:0) fork: real-time status denied
1573 P1: (base_task/6510:0) fork: real-time status denied
1574 P1: (base_task/6510:0) fork: real-time status denied
1575 P1: (base_task/6510:0) fork: real-time status denied
1576 P1: (base_task/6510:0) fork: real-time status denied
1577 P1: (base_task/6510:0) fork: real-time status denied
1578 P1: (base_task/6510:0) fork: real-time status denied
1579 P1: (base_task/6510:0) fork: real-time status denied
1580 P1: (base_task/6510:0) fork: real-time status denied
1581 P1: (base_task/6510:0) fork: real-time status denied
1582 P1: (base_task/6510:0) fork: real-time status denied
1583 P1: (base_task/6510:0) fork: real-time status denied
1584 P1: (base_task/6510:0) fork: real-time status denied
1585 P1: (base_task/6510:0) fork: real-time status denied
1586 P1: (base_task/6510:0) fork: real-time status denied
1587 P1: (base_task/6510:0) fork: real-time status denied
1588 P1: (base_task/6510:12) block at 776452911571
1589 P1: (base_task/6510:12) charged 806992 exec time (total:806992, rem:9193008)
1590 P1: (base_task/6510:12) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1591 P1: (base_task/6510:12) scheduled_on = NO_CPU
1592 P8: 
6kworker/dying (2115) used greatest stack depth: 11888 bytes left
1593 P10: (base_task/6510:12) try_to_wake_up() state:1
1594 P10: (base_task/6510:12) wake_up at 784491473586
1595 P10: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=784491474656 to ready queue at 784491475408
1596 P10: check_for_preemptions: attempting to link task 6510 to 3
1597 P10: P1 is closest available CPU to P1
1598 P10: (base_task/6510:13) try_to_wake_up() done state:0
1599 P1: (swapper/1/0:0) will be preempted by base_task/6510
1600 P1: (base_task/6510:13) scheduled_on = P1
1601 P1: (base_task/6510:13) block at 784491501041
1602 P1: (base_task/6510:13) charged 27903 exec time (total:27903, rem:9972097)
1603 P1: (base_task/6510:13) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1604 P1: (base_task/6510:13) scheduled_on = NO_CPU
1605 P11: (base_task/6510:13) try_to_wake_up() state:1
1606 P11: (base_task/6510:13) wake_up at 784492975133
1607 P11: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=784491474656 to ready queue at 784492976335
1608 P11: check_for_preemptions: attempting to link task 6510 to 3
1609 P11: P1 is closest available CPU to P1
1610 P11: (base_task/6510:13) try_to_wake_up() done state:0
1611 P1: (swapper/1/0:0) will be preempted by base_task/6510
1612 P1: (base_task/6510:13) scheduled_on = P1
1613 P1: (base_task/6510:13) charged 26928 exec time (total:54831, rem:9945169)
1614 P1: (base_task/6510:13) block at 784493017603
1615 P1: (base_task/6510:13) charged 15755 exec time (total:70586, rem:9929414)
1616 P1: (base_task/6510:13) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1617 P1: (base_task/6510:13) scheduled_on = NO_CPU
1618 P5: (base_task/6510:13) try_to_wake_up() state:1
1619 P5: (base_task/6510:13) wake_up at 784533590814
1620 P5: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=784491474656 to ready queue at 784533592171
1621 P5: (base_task/6510:13) linking to local CPU 5 to avoid IPI
1622 P5: (base_task/6510:13) try_to_wake_up() done state:0
1623 P5: (base_task/6599:0) will be preempted by base_task/6510
1624 P5: (base_task/6510:13) scheduled_on = P5
1625 P5: (base_task/6510:13) migrate from 1
1626 P5: (base_task/6510:13) stack_in_use=-1
1627 P5: (base_task/6510:13) job completion indicated at 784533645999
1628 P5: (base_task/6510:13) charged 47648 exec time (total:118234, rem:9881766)
1629 P5: (base_task/6510:13) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
1630 P5: (base_task/6510:13) job_completion(forced=0).
1631 P5: (base_task/6510:14) add_release(), rel=784591474656
1632 P5: (base_task/6510:14) scheduled_on = NO_CPU
1633 P5: (base_task/6510:14) linking to local CPU 5 to avoid IPI
1634 P5: (swapper/5/0:0) will be preempted by base_task/6510
1635 P5: (base_task/6510:14) scheduled_on = P5
1636 P5: (base_task/6510:0) fork: real-time status denied
1637 P5: (base_task/6510:0) fork: real-time status denied
1638 P5: (base_task/6510:0) fork: real-time status denied
1639 P5: (base_task/6510:0) fork: real-time status denied
1640 P5: (base_task/6510:0) fork: real-time status denied
1641 P5: (base_task/6510:0) fork: real-time status denied
1642 P5: (base_task/6510:14) charged 446178 exec time (total:446178, rem:9553822)
1643 P5: (base_task/6510:0) fork: real-time status denied
1644 P5: (base_task/6510:0) fork: real-time status denied
1645 P5: (base_task/6510:0) fork: real-time status denied
1646 P5: (base_task/6510:0) fork: real-time status denied
1647 P5: (base_task/6510:0) fork: real-time status denied
1648 P5: (base_task/6510:0) fork: real-time status denied
1649 P5: (base_task/6510:0) fork: real-time status denied
1650 P5: (base_task/6510:0) fork: real-time status denied
1651 P5: (base_task/6510:0) fork: real-time status denied
1652 P5: (base_task/6510:0) fork: real-time status denied
1653 P5: (base_task/6510:14) block at 784592511789
1654 P5: (base_task/6510:14) charged 505721 exec time (total:951899, rem:9048101)
1655 P5: (base_task/6510:14) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1656 P5: (base_task/6510:14) scheduled_on = NO_CPU
1657 P14: (base_task/6510:14) try_to_wake_up() state:1
1658 P14: (base_task/6510:14) wake_up at 792613854388
1659 P14: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=792613856493 to ready queue at 792613857633
1660 P14: check_for_preemptions: attempting to link task 6510 to 14
1661 P14: P5 is closest available CPU to P5
1662 P14: (base_task/6510:15) try_to_wake_up() done state:0
1663 P5: (tracker-extract/5305:0) will be preempted by base_task/6510
1664 P5: (base_task/6510:15) scheduled_on = P5
1665 P5: (base_task/6510:15) block at 792613885678
1666 P5: (base_task/6510:15) charged 31589 exec time (total:31589, rem:9968411)
1667 P5: (base_task/6510:15) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1668 P5: (base_task/6510:15) scheduled_on = NO_CPU
1669 P0: (base_task/6510:15) try_to_wake_up() state:1
1670 P0: (base_task/6510:15) wake_up at 792650485260
1671 P0: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=792613856493 to ready queue at 792650486788
1672 P0: (base_task/6510:15) linking to local CPU 0 to avoid IPI
1673 P0: (base_task/6510:15) try_to_wake_up() done state:0
1674 P0: (base_task/6610:0) will be preempted by base_task/6510
1675 P0: (base_task/6510:15) scheduled_on = P0
1676 P0: (base_task/6510:15) migrate from 5
1677 P0: (base_task/6510:15) stack_in_use=-1
1678 P0: (base_task/6510:15) block at 792650575839
1679 P0: (base_task/6510:15) charged 80195 exec time (total:111784, rem:9888216)
1680 P0: (base_task/6510:15) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1681 P0: (base_task/6510:15) scheduled_on = NO_CPU
1682 P3: (base_task/6510:15) try_to_wake_up() state:1
1683 P3: (base_task/6510:15) wake_up at 792685170493
1684 P3: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=792613856493 to ready queue at 792685172071
1685 P3: (base_task/6510:15) linking to local CPU 3 to avoid IPI
1686 P3: (base_task/6510:15) try_to_wake_up() done state:0
1687 P3: (base_task/6623:0) will be preempted by base_task/6510
1688 P3: (base_task/6510:15) scheduled_on = P3
1689 P3: (base_task/6510:15) migrate from 0
1690 P3: (base_task/6510:15) stack_in_use=-1
1691 P3: (base_task/6510:15) job completion indicated at 792685209253
1692 P3: (base_task/6510:15) charged 28681 exec time (total:140465, rem:9859535)
1693 P3: (base_task/6510:15) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
1694 P3: (base_task/6510:15) job_completion(forced=0).
1695 P3: (base_task/6510:16) add_release(), rel=792713856493
1696 P3: (base_task/6510:16) scheduled_on = NO_CPU
1697 P3: (base_task/6510:16) linking to local CPU 3 to avoid IPI
1698 P3: (swapper/3/0:0) will be preempted by base_task/6510
1699 P3: (base_task/6510:16) scheduled_on = P3
1700 P3: (base_task/6510:0) fork: real-time status denied
1701 P3: (base_task/6510:0) fork: real-time status denied
1702 P3: (base_task/6510:0) fork: real-time status denied
1703 P3: (base_task/6510:16) charged 109343 exec time (total:109343, rem:9890657)
1704 P3: (base_task/6510:0) fork: real-time status denied
1705 P3: (base_task/6510:0) fork: real-time status denied
1706 P3: (base_task/6510:0) fork: real-time status denied
1707 P3: (base_task/6510:0) fork: real-time status denied
1708 P3: (base_task/6510:0) fork: real-time status denied
1709 P3: (base_task/6510:0) fork: real-time status denied
1710 P3: (base_task/6510:0) fork: real-time status denied
1711 P3: (base_task/6510:0) fork: real-time status denied
1712 P3: (base_task/6510:0) fork: real-time status denied
1713 P3: (base_task/6510:0) fork: real-time status denied
1714 P3: (base_task/6510:0) fork: real-time status denied
1715 P3: (base_task/6510:0) fork: real-time status denied
1716 P3: (base_task/6510:0) fork: real-time status denied
1717 P3: (base_task/6510:16) block at 792714610618
1718 P3: (base_task/6510:16) charged 608000 exec time (total:717343, rem:9282657)
1719 P3: (base_task/6510:16) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1720 P3: (base_task/6510:16) scheduled_on = NO_CPU
1721 P5: (base_task/6510:16) try_to_wake_up() state:1
1722 P5: (base_task/6510:16) wake_up at 800701994953
1723 P5: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=800701996665 to ready queue at 800701997763
1724 P5: (base_task/6510:17) linking to local CPU 5 to avoid IPI
1725 P5: (base_task/6510:17) try_to_wake_up() done state:0
1726 P5: (base_task/6625:0) will be preempted by base_task/6510
1727 P5: (base_task/6510:17) scheduled_on = P5
1728 P5: (base_task/6510:17) migrate from 3
1729 P5: (base_task/6510:17) stack_in_use=-1
1730 P5: (base_task/6510:17) block at 800702029046
1731 P5: (base_task/6510:17) charged 14641 exec time (total:14641, rem:9985359)
1732 P5: (base_task/6510:17) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1733 P5: (base_task/6510:17) scheduled_on = NO_CPU
1734 P6: (base_task/6510:17) try_to_wake_up() state:1
1735 P6: (base_task/6510:17) wake_up at 800758698910
1736 P6: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=800701996665 to ready queue at 800758700390
1737 P6: (base_task/6510:17) linking to local CPU 6 to avoid IPI
1738 P6: (base_task/6510:17) try_to_wake_up() done state:0
1739 P6: (base_task/6626:0) will be preempted by base_task/6510
1740 P6: (base_task/6510:17) scheduled_on = P6
1741 P6: (base_task/6510:17) migrate from 5
1742 P6: (base_task/6510:17) stack_in_use=-1
1743 P6: (base_task/6510:17) block at 800758726326
1744 P6: (base_task/6510:17) charged 17209 exec time (total:31850, rem:9968150)
1745 P6: (base_task/6510:17) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1746 P6: (base_task/6510:17) scheduled_on = NO_CPU
1747 P0: (base_task/6510:17) try_to_wake_up() state:1
1748 P0: (base_task/6510:17) wake_up at 800807811330
1749 P0: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=800807812661 to ready queue at 800807813537
1750 P0: (base_task/6510:18) linking to local CPU 0 to avoid IPI
1751 P0: (base_task/6510:18) try_to_wake_up() done state:0
1752 P0: (base_task/6629:0) will be preempted by base_task/6510
1753 P0: (base_task/6510:18) scheduled_on = P0
1754 P0: (base_task/6510:18) migrate from 6
1755 P0: (base_task/6510:18) stack_in_use=-1
1756 P0: (base_task/6510:18) block at 800807871371
1757 P0: (base_task/6510:18) charged 49103 exec time (total:49103, rem:9950897)
1758 P0: (base_task/6510:18) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1759 P0: (base_task/6510:18) scheduled_on = NO_CPU
1760 P2: (base_task/6510:18) try_to_wake_up() state:1
1761 P2: (base_task/6510:18) wake_up at 800816939885
1762 P2: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=800807812661 to ready queue at 800816941029
1763 P2: (base_task/6510:18) linking to local CPU 2 to avoid IPI
1764 P2: (base_task/6510:18) try_to_wake_up() done state:0
1765 P2: (base_task/6637:0) will be preempted by base_task/6510
1766 P2: (base_task/6510:18) scheduled_on = P2
1767 P2: (base_task/6510:18) migrate from 0
1768 P2: (base_task/6510:18) stack_in_use=-1
1769 P2: (base_task/6510:18) job completion indicated at 800816977424
1770 P2: (base_task/6510:18) charged 29012 exec time (total:78115, rem:9921885)
1771 P2: (base_task/6510:18) blocks:0 out_of_time:0 np:0 sleep:1 preempt:0 state:0 sig:0
1772 P2: (base_task/6510:18) job_completion(forced=0).
1773 P2: (base_task/6510:19) add_release(), rel=800907812661
1774 P2: (base_task/6510:19) scheduled_on = NO_CPU
1775 P2: (base_task/6510:19) linking to local CPU 2 to avoid IPI
1776 P2: (swapper/2/0:0) will be preempted by base_task/6510
1777 P2: (base_task/6510:19) scheduled_on = P2
1778 P2: (base_task/6510:0) fork: real-time status denied
1779 P2: (base_task/6510:19) charged 113335 exec time (total:113335, rem:9886665)
1780 P2: (base_task/6510:0) fork: real-time status denied
1781 P2: (base_task/6510:0) fork: real-time status denied
1782 P2: (base_task/6510:0) fork: real-time status denied
1783 P2: (base_task/6510:0) fork: real-time status denied
1784 P2: (base_task/6510:0) fork: real-time status denied
1785 P2: (base_task/6510:0) fork: real-time status denied
1786 P2: (base_task/6510:0) fork: real-time status denied
1787 P2: (base_task/6510:0) fork: real-time status denied
1788 P2: (base_task/6510:0) fork: real-time status denied
1789 P2: (base_task/6510:0) fork: real-time status denied
1790 P2: (base_task/6510:0) fork: real-time status denied
1791 P2: (base_task/6510:0) fork: real-time status denied
1792 P2: (base_task/6510:0) fork: real-time status denied
1793 P2: (base_task/6510:0) fork: real-time status denied
1794 P2: (base_task/6510:0) fork: real-time status denied
1795 P2: (base_task/6510:19) block at 800908808198
1796 P2: (base_task/6510:19) charged 801180 exec time (total:914515, rem:9085485)
1797 P2: (base_task/6510:19) blocks:1 out_of_time:0 np:0 sleep:0 preempt:1 state:1 sig:0
1798 P2: (base_task/6510:19) scheduled_on = NO_CPU
1799 P0: (base_task/6510:19) try_to_wake_up() state:1
1800 P0: (base_task/6510:19) wake_up at 802551847243
1801 P0: rt: adding base_task/6510 (10000000, 100000000, 100000000) rel=802551848748 to ready queue at 802551850003
1802 P0: (base_task/6510:20) linking to local CPU 0 to avoid IPI
1803 P0: (base_task/6510:20) try_to_wake_up() done state:0
1804 P0: (kworker/u32:2/6113:0) will be preempted by base_task/6510
1805 P0: (base_task/6510:20) scheduled_on = P0
1806 P0: (base_task/6510:20) migrate from 2
1807 P0: (base_task/6510:20) stack_in_use=-1
1808 P0: (base_task/6510:20) exiting, demoted to SCHED_FIFO
1809 P0: (base_task/6510:20) RIP
1810 P0: (base_task/6510:20) ignoring a dequeue, not going to sleep.
1811 P0: (base_task/6510:20) Deallocating real-time task data
1812 P0: (base_task/6510:0) litmus_ctrl_vm_close flags=0x10160073 prot=0x25
1813 P0: (base_task/6510:0) litmus/ctrl: 00007fc81c8e3000:00007fc81c8e4000 vma:ffff8804436380b8 vma->vm_private_data:          (null) closed.
1814 P11: (base_task/6510:0) freeing ctrl_page ffff880408a63000
1815 P9: 
6Disabling feather-trace event 501.
1816 P9: 
6Disabling feather-trace event 502.
1817 P9: 
6Disabling feather-trace event 503.
1818 P9: 
6Disabling feather-trace event 504.
1819 P9: 
6Disabling feather-trace event 505.
1820 P9: 
6Disabling feather-trace event 506.
1821 P6: 
6Disabling feather-trace event 501.
1822 P14: 
6Disabling feather-trace event 501.
1823 P6: 
6Disabling feather-trace event 502.
1824 P14: 
6Disabling feather-trace event 502.
1825 P9: 
6Disabling feather-trace event 507.
1826 P14: 
6Disabling feather-trace event 503.
1827 P9: 
6Disabling feather-trace event 508.
1828 P0: 
6Disabling feather-trace event 501.
1829 P9: 
6Disabling feather-trace event 509.
1830 P6: 
6Disabling feather-trace event 503.
1831 P13: 
6Disabling feather-trace event 501.
1832 P0: 
6Disabling feather-trace event 502.
1833 P6: 
6Disabling feather-trace event 504.
1834 P7: 
6Disabling feather-trace event 501.
1835 P13: 
6Disabling feather-trace event 502.
1836 P14: 
6Disabling feather-trace event 504.
1837 P0: 
6Disabling feather-trace event 503.
1838 P6: 
6Disabling feather-trace event 505.
1839 P7: 
6Disabling feather-trace event 502.
1840 P12: 
6Disabling feather-trace event 501.
1841 P13: 
6Disabling feather-trace event 503.
1842 P4: 
6Disabling feather-trace event 501.
1843 P14: 
6Disabling feather-trace event 505.
1844 P6: 
6Disabling feather-trace event 506.
1845 P7: 
6Disabling feather-trace event 503.
1846 P12: 
6Disabling feather-trace event 502.
1847 P13: 
6Disabling feather-trace event 504.
1848 P4: 
6Disabling feather-trace event 502.
1849 P14: 
6Disabling feather-trace event 506.
1850 P9: 
6Disabling feather-trace event 510.
1851 P6: 
6Disabling feather-trace event 507.
1852 P10: 
6Disabling feather-trace event 501.
1853 P7: 
6Disabling feather-trace event 504.
1854 P12: 
6Disabling feather-trace event 503.
1855 P13: 
6Disabling feather-trace event 505.
1856 P4: 
6Disabling feather-trace event 503.
1857 P9: 
6Disabling feather-trace event 511.
1858 P6: 
6Disabling feather-trace event 508.
1859 P10: 
6Disabling feather-trace event 502.
1860 P7: 
6Disabling feather-trace event 505.
1861 P12: 
6Disabling feather-trace event 504.
1862 P13: 
6Disabling feather-trace event 506.
1863 P4: 
6Disabling feather-trace event 504.
1864 P0: 
6Disabling feather-trace event 504.
1865 P6: 
6Disabling feather-trace event 509.
1866 P10: 
6Disabling feather-trace event 503.
1867 P7: 
6Disabling feather-trace event 506.
1868 P12: 
6Disabling feather-trace event 505.
1869 P13: 
6Disabling feather-trace event 507.
1870 P0: 
6Disabling feather-trace event 505.
1871 P6: 
6Disabling feather-trace event 510.
1872 P10: 
6Disabling feather-trace event 504.
1873 P7: 
6Disabling feather-trace event 507.
1874 P12: 
6Disabling feather-trace event 506.
1875 P13: 
6Disabling feather-trace event 508.
1876 P14: 
6Disabling feather-trace event 507.
1877 P0: 
6Disabling feather-trace event 506.
1878 P6: 
6Disabling feather-trace event 511.
1879 P10: 
6Disabling feather-trace event 505.
1880 P7: 
6Disabling feather-trace event 508.
1881 P12: 
6Disabling feather-trace event 507.
1882 P14: 
6Disabling feather-trace event 508.
1883 P0: 
6Disabling feather-trace event 507.
1884 P10: 
6Disabling feather-trace event 506.
1885 P7: 
6Disabling feather-trace event 509.
1886 P4: 
6Disabling feather-trace event 505.
1887 P12: 
6Disabling feather-trace event 508.
1888 P14: 
6Disabling feather-trace event 509.
1889 P0: 
6Disabling feather-trace event 508.
1890 P10: 
6Disabling feather-trace event 507.
1891 P7: 
6Disabling feather-trace event 510.
1892 P4: 
6Disabling feather-trace event 506.
1893 P14: 
6Disabling feather-trace event 510.
1894 P0: 
6Disabling feather-trace event 509.
1895 P10: 
6Disabling feather-trace event 508.
1896 P7: 
6Disabling feather-trace event 511.
1897 P4: 
6Disabling feather-trace event 507.
1898 P13: 
6Disabling feather-trace event 509.
1899 P14: 
6Disabling feather-trace event 511.
1900 P0: 
6Disabling feather-trace event 510.
1901 P10: 
6Disabling feather-trace event 509.
1902 P4: 
6Disabling feather-trace event 508.
1903 P0: 
6Disabling feather-trace event 511.
1904 P10: 
6Disabling feather-trace event 510.
1905 P12: 
6Disabling feather-trace event 509.
1906 P4: 
6Disabling feather-trace event 509.
1907 P10: 
6Disabling feather-trace event 511.
1908 P12: 
6Disabling feather-trace event 510.
1909 P13: 
6Disabling feather-trace event 510.
1910 P12: 
6Disabling feather-trace event 511.
1911 P13: 
6Disabling feather-trace event 511.
1912 P4: 
6Disabling feather-trace event 510.
1913 P4: 
6Disabling feather-trace event 511.
1914 P10: 
6Disabling feather-trace event 501.
1915 P10: 
6Disabling feather-trace event 502.
1916 P10: 
6Disabling feather-trace event 503.
1917 P10: 
6Disabling feather-trace event 504.
1918 P10: 
6Disabling feather-trace event 505.
1919 P10: 
6Disabling feather-trace event 506.
1920 P10: 
6Disabling feather-trace event 507.
1921 P10: 
6Disabling feather-trace event 508.
1922 P10: 
6Disabling feather-trace event 509.
1923 P10: 
6Disabling feather-trace event 510.
1924 P10: 
6Disabling feather-trace event 511.
1925 P10: 
6Disabling feather-trace event 501.
1926 P10: 
6Disabling feather-trace event 502.
1927 P10: 
6Disabling feather-trace event 503.
1928 P10: 
6Disabling feather-trace event 504.
1929 P10: 
6Disabling feather-trace event 505.
1930 P10: 
6Disabling feather-trace event 506.
1931 P10: 
6Disabling feather-trace event 507.
1932 P10: 
6Disabling feather-trace event 508.
1933 P10: 
6Disabling feather-trace event 509.
1934 P10: 
6Disabling feather-trace event 510.
1935 P10: 
6Disabling feather-trace event 511.
1936 P10: 
6Disabling feather-trace event 501.
1937 P10: 
6Disabling feather-trace event 502.
1938 P10: 
6Disabling feather-trace event 503.
1939 P10: 
6Disabling feather-trace event 504.
1940 P10: 
6Disabling feather-trace event 505.
1941 P10: 
6Disabling feather-trace event 506.
1942 P10: 
6Disabling feather-trace event 507.
1943 P10: 
6Disabling feather-trace event 508.
1944 P10: 
6Disabling feather-trace event 509.
1945 P10: 
6Disabling feather-trace event 510.
1946 P10: 
6Disabling feather-trace event 511.
1947 P10: 
6Disabling feather-trace event 501.
1948 P10: 
6Disabling feather-trace event 502.
1949 P10: 
6Disabling feather-trace event 503.
1950 P10: 
6Disabling feather-trace event 504.
1951 P10: 
6Disabling feather-trace event 505.
1952 P10: 
6Disabling feather-trace event 506.
1953 P10: 
6Disabling feather-trace event 507.
1954 P10: 
6Disabling feather-trace event 508.
1955 P10: 
6Disabling feather-trace event 509.
1956 P10: 
6Disabling feather-trace event 510.
1957 P10: 
6Disabling feather-trace event 511.
1958 P12: 
6Disabling feather-trace event 501.
1959 P12: 
6Disabling feather-trace event 502.
1960 P12: 
6Disabling feather-trace event 503.
1961 P12: 
6Disabling feather-trace event 504.
1962 P12: 
6Disabling feather-trace event 505.
1963 P12: 
6Disabling feather-trace event 506.
1964 P12: 
6Disabling feather-trace event 507.
1965 P12: 
6Disabling feather-trace event 508.
1966 P12: 
6Disabling feather-trace event 509.
1967 P12: 
6Disabling feather-trace event 510.
1968 P12: 
6Disabling feather-trace event 511.
1969 P10: 
6Disabling feather-trace event 501.
1970 P10: 
6Disabling feather-trace event 502.
1971 P10: 
6Disabling feather-trace event 503.
1972 P10: 
6Disabling feather-trace event 504.
1973 P10: 
6Disabling feather-trace event 505.
1974 P13: 
6Disabling feather-trace event 501.
1975 P10: 
6Disabling feather-trace event 506.
1976 P13: 
6Disabling feather-trace event 502.
1977 P13: 
6Disabling feather-trace event 503.
1978 P10: 
6Disabling feather-trace event 507.
1979 P13: 
6Disabling feather-trace event 504.
1980 P13: 
6Disabling feather-trace event 505.
1981 P10: 
6Disabling feather-trace event 508.
1982 P13: 
6Disabling feather-trace event 506.
1983 P13: 
6Disabling feather-trace event 507.
1984 P10: 
6Disabling feather-trace event 509.
1985 P10: 
6Disabling feather-trace event 510.
1986 P13: 
6Disabling feather-trace event 508.
1987 P10: 
6Disabling feather-trace event 511.
1988 P13: 
6Disabling feather-trace event 509.
1989 P13: 
6Disabling feather-trace event 510.
1990 P13: 
6Disabling feather-trace event 511.
1991 P0: 
1Failed trace writes: 0
1992 P7: 
1Failed trace writes: 0
1993 P14: 
1Failed trace writes: 0
1994 P6: 
1Failed trace writes: 0
1995 P9: 
1Failed trace writes: 0
1996 P4: 
1Failed trace writes: 0
1997 P11: 
1Failed trace writes: 0
1998 P12: 
1Failed trace writes: 0
1999 P5: 
1Failed trace writes: 0
2000 P13: 
1Failed trace writes: 0
2001 P2: 
1Failed trace writes: 0
2002 P10: 
1Failed trace writes: 0
2003 P12: 
1Failed trace writes: 0
2004 P10: 
1Failed trace writes: 0
2005 P0: 
1Failed trace writes: 0
2006 P10: 
1Failed trace writes: 0
2007 P0: usb 1-1.1: new high-speed USB device number 6 using ehci-pci
2008 P0: usb 1-1.1: New USB device found, idVendor=03f0, idProduct=5607
2009 P0: usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
2010 P0: usb 1-1.1: Product: v210w
2011 P0: usb 1-1.1: Manufacturer: HP
2012 P0: usb 1-1.1: SerialNumber: 0411030000003213
2013 P0: usb-storage 1-1.1:1.0: USB Mass Storage device detected
2014 P0: scsi host6: usb-storage 1-1.1:1.0
2015 P0: scsi 6:0:0:0: Direct-Access     hp       v210w            1100 PQ: 0 ANSI: 4
2016 P0: sd 6:0:0:0: Attached scsi generic sg1 type 0
2017 P6: sd 6:0:0:0: [sdb] 15728640 512-byte logical blocks: (8.05 GB/7.50 GiB)
2018 P6: sd 6:0:0:0: [sdb] Write Protect is off
2019 P6: sd 6:0:0:0: [sdb] Mode Sense: 43 00 00 00
2020 P6: sd 6:0:0:0: [sdb] No Caching mode page found
2021 P6: sd 6:0:0:0: [sdb] Assuming drive cache: write through
2022 P6: 
6 sdb: sdb1
2023 P6: sd 6:0:0:0: [sdb] Attached SCSI removable disk
2024 P4: 
4FAT-fs (sdb1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: schedule_host=localhost.localdomain_scheduler=GSN-EDF_trace=.pdf
Type: application/pdf
Size: 15023 bytes
Desc: not available
URL: <http://lists.litmus-rt.org/pipermail/litmus-dev/attachments/20180312/f7bbaa5d/attachment-0001.pdf>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: base_task.c
Type: text/x-csrc
Size: 5177 bytes
Desc: not available
URL: <http://lists.litmus-rt.org/pipermail/litmus-dev/attachments/20180312/f7bbaa5d/attachment-0001.c>