Idle time and sleep/wake notification

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

Idle time and sleep/wake notification

Eliot Miranda-2
 
Hi All,

    I've just added tallying of idle time in the VM so that the system report can give more meaningful overheads to the GC information it reports.  Currently the VM tallies idle time in the innards of relinquishProcessorForMicroseconds:.  But it also needs to tally idle time across SLEEP/WAKE events.  May I ask experts in the Mac OS, X11 and Windows worlds to have a loop at event processing and either implement tallying idle time here or reporting back on what work is required or (as I fear in the case of X11/Unix) whether it is unsupported.

Here's an example of the nonsense one gets back after waking one's laptop:
Virtual Machine Statistics
--------------------------
uptime 14h 59m 26s (runtime 11h 53m 33s, idletime 3h 5m 53s)
memory 338,690,048 bytes
old 333,689,744 bytes (98.5%)
young 4,111,360 bytes (1.2%)
used 314,964,392 bytes (93%)
free 21,991,672 bytes (6.5%)
GCs 3,430 (15733.6 ms between GCs 12482 ms runtime between GCs)
full 8 totalling 1,331 ms (0% runtime), avg 166.4 ms
marking 536 ms (40.3%) avg 67 ms,
compacting 795 ms (59.7%) avg 99.4 ms
scavenges 3,422 totalling 2,511 ms (0.01% runtime), avg 0.7 ms
tenures 818,889 (avg 239 tenures per scavenge)
Since last view 2,463 (21394 ms between GCs, 17285 ms runtime between GCs)
uptime 52695.2 s, runtime 42574 s, idletime 10121.2 s
full 2 totalling 322 ms (0% runtime), avg 161 ms
scavenge 2,461 totalling 2,029 ms (0% runtime), avg 0.8 ms
tenures 16,733 (avg 6 tenures per scavenge)

whereas while the machine stays awake we get good information:
Virtual Machine Statistics
--------------------------
uptime 1m 58s (runtime 0m 21s, idletime 1m 37s)
memory 281,018,368 bytes
old 276,018,064 bytes (98.2%)
young 4,111,360 bytes (1.5%)
used 251,951,208 bytes (89.7%)
free 26,712,592 bytes (9.5%)
GCs 37 (3203.5 ms between GCs 569.7 ms runtime between GCs)
full 0 totalling 0 ms (0% runtime), avg 0 ms
scavenges 37 totalling 13 ms (0.06% runtime), avg 0.4 ms
tenures 648 (avg 17 tenures per scavenge)
Since last view 30 (3498 ms between GCs, 590 ms runtime between GCs)
uptime 104.9 s, runtime 17.7 s, idletime 87.2 s
full 0
scavenge 30 totalling 11 ms (0.1% runtime), avg 0.4 ms
tenures 0

_,,,^..^,,,_
best, Eliot
Reply | Threaded
Open this post in threaded view
|

Re: Idle time and sleep/wake notification

Eliot Miranda-2
 
Some info from an old colleague on Linux facilities:

You could try the upower lib and daemon < https://upower.freedesktop.org/docs/ >. 

If that's not available or you don't fancy it and you're running systemd you can probably knock something up via the  systemd-suspend.service < https://www.freedesktop.org/software/systemd/man/systemd-suspend.service.html >. A bit Heath-Robinson though...

Or you could configure the acpid < https://linux.die.net/man/8/acpid >to notify you (via a socket or somesuch...).

_,,,^..^,,,_ (phone)

On Mar 20, 2017, at 8:16 AM, Eliot Miranda <[hidden email]> wrote:

Hi All,

    I've just added tallying of idle time in the VM so that the system report can give more meaningful overheads to the GC information it reports.  Currently the VM tallies idle time in the innards of relinquishProcessorForMicroseconds:.  But it also needs to tally idle time across SLEEP/WAKE events.  May I ask experts in the Mac OS, X11 and Windows worlds to have a loop at event processing and either implement tallying idle time here or reporting back on what work is required or (as I fear in the case of X11/Unix) whether it is unsupported.

Here's an example of the nonsense one gets back after waking one's laptop:
Virtual Machine Statistics
--------------------------
uptime 14h 59m 26s (runtime 11h 53m 33s, idletime 3h 5m 53s)
memory 338,690,048 bytes
old 333,689,744 bytes (98.5%)
young 4,111,360 bytes (1.2%)
used 314,964,392 bytes (93%)
free 21,991,672 bytes (6.5%)
GCs 3,430 (15733.6 ms between GCs 12482 ms runtime between GCs)
full 8 totalling 1,331 ms (0% runtime), avg 166.4 ms
marking 536 ms (40.3%) avg 67 ms,
compacting 795 ms (59.7%) avg 99.4 ms
scavenges 3,422 totalling 2,511 ms (0.01% runtime), avg 0.7 ms
tenures 818,889 (avg 239 tenures per scavenge)
Since last view 2,463 (21394 ms between GCs, 17285 ms runtime between GCs)
uptime 52695.2 s, runtime 42574 s, idletime 10121.2 s
full 2 totalling 322 ms (0% runtime), avg 161 ms
scavenge 2,461 totalling 2,029 ms (0% runtime), avg 0.8 ms
tenures 16,733 (avg 6 tenures per scavenge)

whereas while the machine stays awake we get good information:
Virtual Machine Statistics
--------------------------
uptime 1m 58s (runtime 0m 21s, idletime 1m 37s)
memory 281,018,368 bytes
old 276,018,064 bytes (98.2%)
young 4,111,360 bytes (1.5%)
used 251,951,208 bytes (89.7%)
free 26,712,592 bytes (9.5%)
GCs 37 (3203.5 ms between GCs 569.7 ms runtime between GCs)
full 0 totalling 0 ms (0% runtime), avg 0 ms
scavenges 37 totalling 13 ms (0.06% runtime), avg 0.4 ms
tenures 648 (avg 17 tenures per scavenge)
Since last view 30 (3498 ms between GCs, 590 ms runtime between GCs)
uptime 104.9 s, runtime 17.7 s, idletime 87.2 s
full 0
scavenge 30 totalling 11 ms (0.1% runtime), avg 0.4 ms
tenures 0

_,,,^..^,,,_
best, Eliot
Reply | Threaded
Open this post in threaded view
|

Re: Idle time and sleep/wake notification

Ryan Macnak
 
You could measure CPU time instead of wall time: https://github.com/dart-lang/sdk/blob/master/runtime/vm/os_linux.cc#L182

On Mon, Apr 10, 2017 at 8:58 AM, Eliot Miranda <[hidden email]> wrote:
 
Some info from an old colleague on Linux facilities:

You could try the upower lib and daemon < https://upower.freedesktop.org/docs/ >. 

If that's not available or you don't fancy it and you're running systemd you can probably knock something up via the  systemd-suspend.service < https://www.freedesktop.org/software/systemd/man/systemd-suspend.service.html >. A bit Heath-Robinson though...

Or you could configure the acpid < https://linux.die.net/man/8/acpid >to notify you (via a socket or somesuch...).

_,,,^..^,,,_ (phone)

On Mar 20, 2017, at 8:16 AM, Eliot Miranda <[hidden email]> wrote:

Hi All,

    I've just added tallying of idle time in the VM so that the system report can give more meaningful overheads to the GC information it reports.  Currently the VM tallies idle time in the innards of relinquishProcessorForMicroseconds:.  But it also needs to tally idle time across SLEEP/WAKE events.  May I ask experts in the Mac OS, X11 and Windows worlds to have a loop at event processing and either implement tallying idle time here or reporting back on what work is required or (as I fear in the case of X11/Unix) whether it is unsupported.

Here's an example of the nonsense one gets back after waking one's laptop:
Virtual Machine Statistics
--------------------------
uptime 14h 59m 26s (runtime 11h 53m 33s, idletime 3h 5m 53s)
memory 338,690,048 bytes
old 333,689,744 bytes (98.5%)
young 4,111,360 bytes (1.2%)
used 314,964,392 bytes (93%)
free 21,991,672 bytes (6.5%)
GCs 3,430 (15733.6 ms between GCs 12482 ms runtime between GCs)
full 8 totalling 1,331 ms (0% runtime), avg 166.4 ms
marking 536 ms (40.3%) avg 67 ms,
compacting 795 ms (59.7%) avg 99.4 ms
scavenges 3,422 totalling 2,511 ms (0.01% runtime), avg 0.7 ms
tenures 818,889 (avg 239 tenures per scavenge)
Since last view 2,463 (21394 ms between GCs, 17285 ms runtime between GCs)
uptime 52695.2 s, runtime 42574 s, idletime 10121.2 s
full 2 totalling 322 ms (0% runtime), avg 161 ms
scavenge 2,461 totalling 2,029 ms (0% runtime), avg 0.8 ms
tenures 16,733 (avg 6 tenures per scavenge)

whereas while the machine stays awake we get good information:
Virtual Machine Statistics
--------------------------
uptime 1m 58s (runtime 0m 21s, idletime 1m 37s)
memory 281,018,368 bytes
old 276,018,064 bytes (98.2%)
young 4,111,360 bytes (1.5%)
used 251,951,208 bytes (89.7%)
free 26,712,592 bytes (9.5%)
GCs 37 (3203.5 ms between GCs 569.7 ms runtime between GCs)
full 0 totalling 0 ms (0% runtime), avg 0 ms
scavenges 37 totalling 13 ms (0.06% runtime), avg 0.4 ms
tenures 648 (avg 17 tenures per scavenge)
Since last view 30 (3498 ms between GCs, 590 ms runtime between GCs)
uptime 104.9 s, runtime 17.7 s, idletime 87.2 s
full 0
scavenge 30 totalling 11 ms (0.1% runtime), avg 0.4 ms
tenures 0

_,,,^..^,,,_
best, Eliot


Reply | Threaded
Open this post in threaded view
|

Re: Idle time and sleep/wake notification

Eliot Miranda-2
 
Hi Ryan,

On Mon, Apr 10, 2017 at 7:16 PM, Ryan Macnak <[hidden email]> wrote:
 
You could measure CPU time instead of wall time: https://github.com/dart-lang/sdk/blob/master/runtime/vm/os_linux.cc#L182

Yes, a better addition than idle time, I agree.
 
On Mon, Apr 10, 2017 at 8:58 AM, Eliot Miranda <[hidden email]> wrote:
 
Some info from an old colleague on Linux facilities:

You could try the upower lib and daemon < https://upower.freedesktop.org/docs/ >. 

If that's not available or you don't fancy it and you're running systemd you can probably knock something up via the  systemd-suspend.service < https://www.freedesktop.org/software/systemd/man/systemd-suspend.service.html >. A bit Heath-Robinson though...

Or you could configure the acpid < https://linux.die.net/man/8/acpid >to notify you (via a socket or somesuch...).

_,,,^..^,,,_ (phone)

On Mar 20, 2017, at 8:16 AM, Eliot Miranda <[hidden email]> wrote:

Hi All,

    I've just added tallying of idle time in the VM so that the system report can give more meaningful overheads to the GC information it reports.  Currently the VM tallies idle time in the innards of relinquishProcessorForMicroseconds:.  But it also needs to tally idle time across SLEEP/WAKE events.  May I ask experts in the Mac OS, X11 and Windows worlds to have a loop at event processing and either implement tallying idle time here or reporting back on what work is required or (as I fear in the case of X11/Unix) whether it is unsupported.

Here's an example of the nonsense one gets back after waking one's laptop:
Virtual Machine Statistics
--------------------------
uptime 14h 59m 26s (runtime 11h 53m 33s, idletime 3h 5m 53s)
memory 338,690,048 bytes
old 333,689,744 bytes (98.5%)
young 4,111,360 bytes (1.2%)
used 314,964,392 bytes (93%)
free 21,991,672 bytes (6.5%)
GCs 3,430 (15733.6 ms between GCs 12482 ms runtime between GCs)
full 8 totalling 1,331 ms (0% runtime), avg 166.4 ms
marking 536 ms (40.3%) avg 67 ms,
compacting 795 ms (59.7%) avg 99.4 ms
scavenges 3,422 totalling 2,511 ms (0.01% runtime), avg 0.7 ms
tenures 818,889 (avg 239 tenures per scavenge)
Since last view 2,463 (21394 ms between GCs, 17285 ms runtime between GCs)
uptime 52695.2 s, runtime 42574 s, idletime 10121.2 s
full 2 totalling 322 ms (0% runtime), avg 161 ms
scavenge 2,461 totalling 2,029 ms (0% runtime), avg 0.8 ms
tenures 16,733 (avg 6 tenures per scavenge)

whereas while the machine stays awake we get good information:
Virtual Machine Statistics
--------------------------
uptime 1m 58s (runtime 0m 21s, idletime 1m 37s)
memory 281,018,368 bytes
old 276,018,064 bytes (98.2%)
young 4,111,360 bytes (1.5%)
used 251,951,208 bytes (89.7%)
free 26,712,592 bytes (9.5%)
GCs 37 (3203.5 ms between GCs 569.7 ms runtime between GCs)
full 0 totalling 0 ms (0% runtime), avg 0 ms
scavenges 37 totalling 13 ms (0.06% runtime), avg 0.4 ms
tenures 648 (avg 17 tenures per scavenge)
Since last view 30 (3498 ms between GCs, 590 ms runtime between GCs)
uptime 104.9 s, runtime 17.7 s, idletime 87.2 s
full 0
scavenge 30 totalling 11 ms (0.1% runtime), avg 0.4 ms
tenures 0

_,,,^..^,,,_
best, Eliot






--
_,,,^..^,,,_
best, Eliot
Reply | Threaded
Open this post in threaded view
|

Re: Idle time and sleep/wake notification

Ben Coman
 


On Wed, Apr 12, 2017 at 3:13 AM, Eliot Miranda <[hidden email]> wrote:
>  
> Hi Ryan,
>
> On Mon, Apr 10, 2017 at 7:16 PM, Ryan Macnak <[hidden email]> wrote:
>>
>>  
>> You could measure CPU time instead of wall time: https://github.com/dart-lang/sdk/blob/master/runtime/vm/os_linux.cc#L182
>
>
> Yes, a better addition than idle time, I agree.

Another use for CPU-time that I was going to suggest soon, is that Pharo CI often
has intermittent failures of time-sensitive tests.  For example...
    
    MutexTest >> testFailedCriticalSectionShouldUnblockWaitingOne
| lastExecuted |
lastExecuted := false.
self fork: [[mutex critical: [ 5 milliSeconds wait.
self error: 'critical section failed' ]] ifError: []].
self fork: [mutex critical: [ lastExecuted := true ]].
10 milliSeconds wait.
self assert: lastExecuted

My unfounded guess is that on a busy CI server, there are rare cases
where the VM/test-Image is not scheduled for too long, 
and VM-time moves too far in one jump.

Leaving aside whether the above code is a good way to structure tests**,
I was considering whether instead of deriving the VM-clock from wall-time, 
perhaps a command line setting it to derive from CPU-time
would mean any VM pauses due to server load would be transparent to the VM/Image. 

And I was considering tying this into my proposed VM-clock improvements (still in outline stage) 

cheers -ben

** I'm not sure what is a better way.  I managed to rearrange some tests to wait on
a semaphore, but since mutexes still currently block using semaphores, 
there seems to be conflict.   

>  

>>
>> On Mon, Apr 10, 2017 at 8:58 AM, Eliot Miranda <[hidden email]> wrote:
>>>
>>>  
>>> Some info from an old colleague on Linux facilities:
>>>
>>> You could try the upower lib and daemon < https://upower.freedesktop.org/docs/ >.
>>>
>>> If that's not available or you don't fancy it and you're running systemd you can probably knock something up via the  systemd-suspend.service < https://www.freedesktop.org/software/systemd/man/systemd-suspend.service.html >. A bit Heath-Robinson though...
>>>
>>> Or you could configure the acpid < https://linux.die.net/man/8/acpid >to notify you (via a socket or somesuch...).
>>>
>>> _,,,^..^,,,_ (phone)
>>>
>>> On Mar 20, 2017, at 8:16 AM, Eliot Miranda <[hidden email]> wrote:
>>>
>>> Hi All,
>>>
>>>     I've just added tallying of idle time in the VM so that the system report can give more meaningful overheads to the GC information it reports.  Currently the VM tallies idle time in the innards of relinquishProcessorForMicroseconds:.  But it also needs to tally idle time across SLEEP/WAKE events.  May I ask experts in the Mac OS, X11 and Windows worlds to have a loop at event processing and either implement tallying idle time here or reporting back on what work is required or (as I fear in the case of X11/Unix) whether it is unsupported.
>>>
>>> Here's an example of the nonsense one gets back after waking one's laptop:
>>> Virtual Machine Statistics
>>> --------------------------
>>> uptime 14h 59m 26s (runtime 11h 53m 33s, idletime 3h 5m 53s)
>>> memory 338,690,048 bytes
>>> old 333,689,744 bytes (98.5%)
>>> young 4,111,360 bytes (1.2%)
>>> used 314,964,392 bytes (93%)
>>> free 21,991,672 bytes (6.5%)
>>> GCs 3,430 (15733.6 ms between GCs 12482 ms runtime between GCs)
>>> full 8 totalling 1,331 ms (0% runtime), avg 166.4 ms
>>> marking 536 ms (40.3%) avg 67 ms,
>>> compacting 795 ms (59.7%) avg 99.4 ms
>>> scavenges 3,422 totalling 2,511 ms (0.01% runtime), avg 0.7 ms
>>> tenures 818,889 (avg 239 tenures per scavenge)
>>> Since last view 2,463 (21394 ms between GCs, 17285 ms runtime between GCs)
>>> uptime 52695.2 s, runtime 42574 s, idletime 10121.2 s
>>> full 2 totalling 322 ms (0% runtime), avg 161 ms
>>> scavenge 2,461 totalling 2,029 ms (0% runtime), avg 0.8 ms
>>> tenures 16,733 (avg 6 tenures per scavenge)
>>>
>>> whereas while the machine stays awake we get good information:
>>> Virtual Machine Statistics
>>> --------------------------
>>> uptime 1m 58s (runtime 0m 21s, idletime 1m 37s)
>>> memory 281,018,368 bytes
>>> old 276,018,064 bytes (98.2%)
>>> young 4,111,360 bytes (1.5%)
>>> used 251,951,208 bytes (89.7%)
>>> free 26,712,592 bytes (9.5%)
>>> GCs 37 (3203.5 ms between GCs 569.7 ms runtime between GCs)
>>> full 0 totalling 0 ms (0% runtime), avg 0 ms
>>> scavenges 37 totalling 13 ms (0.06% runtime), avg 0.4 ms
>>> tenures 648 (avg 17 tenures per scavenge)
>>> Since last view 30 (3498 ms between GCs, 590 ms runtime between GCs)
>>> uptime 104.9 s, runtime 17.7 s, idletime 87.2 s
>>> full 0
>>> scavenge 30 totalling 11 ms (0.1% runtime), avg 0.4 ms
>>> tenures 0
>>>
>>> _,,,^..^,,,_
>>> best, Eliot
>>>
>>>
>>
>>
>
>
>
> --
> _,,,^..^,,,_
> best, Eliot
>