[Info-vax] HIBertanting DECthreads process accrues CPU time.

San rsandeep80 at gmail.com
Fri Feb 11 00:12:05 EST 2011


On Feb 10, 10:47 pm, VAXman-  @SendSpamHere.ORG wrote:
> In article <00AAAC90.D13DD... at SendSpamHere.ORG>, VAXman-  @SendSpamHere.ORG writes:
> >I have a process with three threads.  These three threads are created
> >and then, sit on $HIBER until awakened when there is work to do.
>
> >Occasionally, I will see this process (when started) accruing CPU time
> >when there is nothing in terms of work for it to do.  I've put various
> >markers in the code and *these* threads are not active.  I've used SDA
> >and I've viewed the TEBs.  Stack highwater is well below each thread's
> >stack limit.
> >...
> >Does anybody have a clue as to what DECthreads is doing here?
>
> >I am convinced there something horked in the thread scheduler.  Sadly,
> >I cannot use pthread_getcputime_np() on the several internal (negative
> >sequence number threads) which DECthreads has created to see which of
> >them is actually accruing this time.  I do know that it's not MY three
> >threads chewing up this time.
>
> Here's some more info from SDA.  Note threads -2 and -4 are "running"
> and are clocking up all the CPU time.  No idea why.  All of the other
> threads (and I took the time to name my threads) are going nothing at
> all.
>
> SDA> PTHREAD THREAD -af
>
> main thread 1 (blocked, kernel) "MY THREAD 1" (0x000000007B744D90), created by
>     pthread
>   Waiting in $HIBER
>   No stack trace available
>   Scheduling: home RAD 0, current RAD 0, SCHED_OTHER policy at priority 11
>     q_num: 0, average cpu time: 0.03, average sched interval: 60.25, last run
> --------------------------------^^^^
>     stamp: 354414.460, last ready stamp: 354414.460, last adj stamp:
>     354414.460, cpu time: 0.062594320
>   PKTA 0x00000000, VP critical history 0x00000000; next block sequence num
>     10720, reference count is 2, static_ctx: (sp: 0x78EF3590, fp_control:
>     0x0000000000000000, persona: 0000000000000001, asten: 0000000000000001);
>     Last dispatched from T2, to T-2; governed by global lock
>    ASTs are enabled
>   10720 kernel blocking calls, 16 pagefaults: 0x0000000000118000,
>     0x0000000000112000, 0x000000000010A000, >0x0000000000056000,
>     0x00000000000CC000, 0x000000000011C000
>   Alloc flags: teb-not-stack, def-stack, foreign-stack, separate-tsd, tis-tsd;
>     Self flags: no-resched; Debug flags: activated
>   Thread specific data: 0=0x000000007B7453E4
>   Stack: SP 0x0000000078EF3590, base is 0x0000000078EF8000 (size: 955219968
>     bytes), guard area at 0x0000000040000000 (size: 0 bytes)
>   General cancelability enabled, asynch cancelability disabled
>   The thread's start function and argument are 0x001813A0 (0x0000000078EF3B80)
>   The thread's latest errno is 0
>
> thread 2 (blocked, kernel) "MY THREAD 2" (0x000000000025B280), created by
>     pthread
>   Waiting in $HIBER
>   No stack trace available
>   Scheduling: home RAD 0, current RAD 0, SCHED_OTHER policy at priority 8
>     q_num: 31, average cpu time: 0.00, average sched interval: 67.52, last run
> ---------------------------------^^^^
>     stamp: 354417.460, last ready stamp: 354417.460, last adj stamp:
>     354417.460, cpu time: 0.060174894
>   PKTA 0x00000000, VP critical history 0x00000000; next block sequence num
>     10716, reference count is 1, static_ctx: (sp: 0x00259810, fp_control:
>     0x0000000000000000, persona: 0000000000000001, asten: 0000000000000001);
>     Last dispatched from T-4, to T-4; governed by global lock
>    ASTs are enabled
>   10716 kernel blocking calls
>   Self flags: no-resched; Sched flags: detached, report-preemption
>   Thread specific data: 0=0x000000000025B8D4
>   Stack: SP 0x0000000000259810, base is 0x000000000025A000 (size: 32768 bytes),
>     yellow zone at 0x0000000000252000 (size: 8192 bytes), guard area at
>     0x0000000000250000 (size: 8192 bytes)
>   Detached
>   General cancelability enabled, asynch cancelability disabled
>   The thread's start function and argument are 0x00180AE0 (0x0000000000000000)
>   The thread's handle was stored at 0x000E01E0.
>   The thread's latest errno is 0
>
> thread 3 (blocked, kernel) "MY THREAD 3" (0x000000000027D280), created by
>     pthread
>   Waiting in $HIBER
>   No stack trace available
>   Scheduling: home RAD 0, current RAD 0, SCHED_OTHER policy at priority 8
>     q_num: 31, average cpu time: 0.00, average sched interval: 73.23, last run
> ---------------------------------^^^^
>     stamp: 354420.460, last ready stamp: 354420.460, last adj stamp:
>     354420.460, cpu time: 0.073178289
>   PKTA 0x00000000, VP critical history 0x00000000; next block sequence num
>     10718, reference count is 1, static_ctx: (sp: 0x0027B810, fp_control:
>     0x0000000000000000, persona: 0000000000000001, asten: 0000000000000001);
>     Last dispatched from T-4, to T-4; governed by global lock
>    ASTs are enabled
>   10718 kernel blocking calls
>   Self flags: no-resched; Sched flags: detached, report-preemption
>   Thread specific data: 0=0x000000000027D8D4
>   Stack: SP 0x000000000027B810, base is 0x000000000027C000 (size: 32768 bytes),
>     yellow zone at 0x0000000000274000 (size: 8192 bytes), guard area at
>     0x0000000000272000 (size: 8192 bytes)
>   Detached
>   General cancelability enabled, asynch cancelability disabled
>   The thread's start function and argument are 0x00180B30 (0x0000000000000000)
>   The thread's handle was stored at 0x000E00F0.
>   The thread's latest errno is 0
>
> manager thread -1 (blocked) "manager thread" (0x00000000001D9280), created by
>     pthread
>   Blocked on indeterminate object
>   No stack trace available
>   Scheduling: home RAD 0, current RAD 0, SCHED_FIFO policy at priority 34
>     q_num: 32, average cpu time: 0.00, average sched interval: 42603.66, last
>     run stamp: 354415.460, last ready stamp: 351448.460, cpu time: 0.138105628
>   PKTA 0x00000000, VP critical history 0x00000001; next block sequence num
>     10790, reference count is 2, static_ctx: (sp: 0x001D7830, fp_control:
>     0x0000000000000000, persona: 0000000000000001, asten: 0000000000000001);
>     Last dispatched from T-2, to T3; governed by global lock
>    ASTs are enabled
>   Object flags: daemon; Self flags: no-resched, no-async-sigs; Sched flags:
>     run-til-block, prio-preempt, fixed-prio, report-preemption
>   Thread specific data: 0=0x00000000001D98D4
>   Stack: SP 0x00000000001D7830, base is 0x00000000001D8000 (size: 49152 bytes),
>     yellow zone at 0x00000000001CC000 (size: 8192 bytes), guard area at
>     0x00000000001CA000 (size: 8192 bytes)
>   General cancelability enabled, asynch cancelability disabled
>   The thread's start function and argument are 0x7B76A670 (0x0000000000000000)
>   The thread's handle was stored at 0x7B758110.
>   The thread's latest errno is 0
>
> ----------------vvvvvvv---------------------------------------------------- --
> null thread -2 (running) "null thread for VP 2" (0x00000000001FD280), created
> ----------------^^^^^^^---------------------------------------------------- --
>     by pthread
>   Scheduling: home RAD 0, current RAD 0, null thread policy at priority -1
>     q_num: -1, average cpu time: 99.97, average sched interval: 11985.29, last
> ---------------------------------^^^^^
>     run stamp: 354416.460, last ready stamp: 353968.460, cpu time >=
>     5.000713713, V2, on kid 0x0000000021800645.
>   PKTA 0x7FFEFF98, VP critical set, history 0x00000001; reference count is 2,
>     static_ctx: (sp: 0x00000000, fp_control: 0x0000000000000000, persona:
>     0000000000000001, asten: 0000000000000001); Last dispatched from T1, to
>     T-1; governed by VP 2
>    ASTs are enabled
>   Object flags: daemon; Self flags: no-async-sigs; Sched flags: run-til-block,
>     fixed-prio
>   Thread specific data: 0=0x00000000001FD8D4
>   Stack: SP unavailable, base is 0x00000000001FC000 (size: 49152 bytes), yellow
>     zone at 0x00000000001F0000 (size: 8192 bytes), guard area at
>     0x00000000001EE000 (size: 8192 bytes)
>   General cancelability enabled, asynch cancelability disabled
>   The thread's start function and argument are 0x7B76A6A0 (0x00000000001FD980)
>   The thread's handle was stored at 0x78EF7AA0.
>   The thread's latest errno is 0
>
> exit handler thread -3 (blocked) "exit-handling thread" (0x0000000000221280),
>     created by pthread
>   Blocked on indeterminate object
>   No stack trace available
>   Scheduling: home RAD 0, current RAD 0, SCHED_FIFO policy at priority 32
>     q_num: 32, average cpu time: 0.00, average sched interval: 0.01, last run
>     stamp: 343704.450, last ready stamp: 343704.450, cpu time: 0.000054426
>   PKTA 0x00000000, VP critical history 0x00000000; next block sequence num 1,
>     reference count is 2, static_ctx: (sp: 0x0021F850, fp_control:
>     0x0000000000000000, persona: 0000000000000001, asten: 0000000000000001);
>     Last dispatched from T1, to T1; governed by global lock
>    ASTs are enabled
>   Object flags: daemon; Self flags: no-resched; Sched flags: run-til-block,
>     prio-preempt, fixed-prio, report-preemption
>   Thread specific data: 0=0x00000000002218D4
>   Stack: SP 0x000000000021F850, base is 0x0000000000220000 (size: 49152 bytes),
>     yellow zone at 0x0000000000214000 (size: 8192 bytes), guard area at
>     0x0000000000212000 (size: 8192 bytes)
>   General cancelability enabled, asynch cancelability disabled
>   The thread's start function and argument are 0x7B76B868 (0x0000000000000000)
>   The thread's handle was stored at 0x7B758188.
>   The thread's latest errno is 0
>
> ----------------vvvvvvv---------------------------------------------------- --
> null thread -4 (running) "null thread for VP 3" (0x000000000026D280), created
> ----------------^^^^^^^---------------------------------------------------- --
>     by pthread
>   Scheduling: home RAD 0, current RAD 0, null thread policy at priority -1
>     q_num: -1, average cpu time: 99.97, average sched interval: 47546.57, last
> ---------------------------------^^^^^
>     run stamp: 354418.460, last ready stamp: 353249.460, cpu time >=
>     0.432673002, V3, on kid 0x0000000021800A45.
>   PKTA 0x40029F98, VP critical set, history 0x00000001; reference count is 2,
>     static_ctx: (sp: 0x00000000, fp_control: 0x0000000000000000, persona:
>     0000000000000001, asten: 0000000000000001); Last dispatched from T3, to T3;
>     governed by VP 3
>    ASTs are enabled
>   Object flags:
> ...
>
> read more »

When a threaded application is idle, it schedules null thread. So if
you see that
the null thread is "running" it means the application is now idle.
However, the
null thread internally calls $HIBER, and the applciation will now be
in HIB state.

So from pthreads library perspective null thread will always be
"running", however,
from the kernel perspective it would be HIBernating. To view the state
of the
process, you could issue a:

$ SHOW SYSTEM /MULTI /FULL

This command will show what state each kernel thread is in. If it is
HIB, then the
process is not accumulating CPU time.

-Sandeep



More information about the Info-vax mailing list