runsolver Copyright (C) 2010 Olivier ROUSSEL

This is runsolver version 3.2.9a (svn: 651)

This program is distributed in the hope that it will be useful,
but WITHOUT ANY WARRANTY; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
GNU General Public License for more details.

command line: /home/misc2010/bin/runsolver -s SIGUSR1 -M 1124 -C 290 -d 10 -w /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/rand165.sarge-etch.cudf.sarge-etch.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/icse/sarge-etch/rand165.sarge-etch.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/rand165.sarge-etch.cudf.sarge-etch.result 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 seconds
Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB
Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB
Current StackSize limit: 8192 KiB


[startup+0 s]
/proc/loadavg: 0.99 0.98 0.99 2/40 8843
/proc/meminfo: memFree=784988/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=3028 CPUtime=0
/proc/8843/stat : 8843 (runsolver) D 8842 8843 4159 34819 4229 4202560 73 0 0 0 0 0 0 0 24 0 1 0 878791242 3100672 94 1283457024 134512640 134586868 4291032448 18446744073709551615 4294960130 0 0 0 24578 18446744071564332000 0 0 17 0 0 0 0
/proc/8843/statm: 757 94 62 19 0 55 0

[startup+0.121027 s]
/proc/loadavg: 0.99 0.98 0.99 2/40 8843
/proc/meminfo: memFree=784988/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=2588 CPUtime=0
/proc/8843/stat : 8843 (apt-get-trendy-) S 8842 8843 4159 34819 4229 4202496 518 1357 0 0 0 0 0 0 25 0 1 0 878791242 2650112 281 1283457024 134512640 135304128 4292167536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8843/statm: 647 281 237 194 0 33 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2588

[startup+0.204996 s]
/proc/loadavg: 0.99 0.98 0.99 2/40 8843
/proc/meminfo: memFree=784988/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=2588 CPUtime=0.01
/proc/8843/stat : 8843 (apt-get-trendy-) S 8842 8843 4159 34819 4229 4202496 567 1854 0 3 0 0 0 1 24 0 1 0 878791242 2650112 284 1283457024 134512640 135304128 4292167536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8843/statm: 647 284 240 194 0 33 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2588

[startup+0.311121 s]
/proc/loadavg: 0.99 0.98 0.99 2/40 8843
/proc/meminfo: memFree=784988/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=2588 CPUtime=0.01
/proc/8843/stat : 8843 (apt-get-trendy-) S 8842 8843 4159 34819 4229 4202496 567 1854 0 3 0 0 0 1 24 0 1 0 878791242 2650112 284 1283457024 134512640 135304128 4292167536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8843/statm: 647 284 240 194 0 33 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2588

[startup+0.71119 s]
/proc/loadavg: 0.99 0.98 0.99 2/40 8843
/proc/meminfo: memFree=784988/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=2588 CPUtime=0.01
/proc/8843/stat : 8843 (apt-get-trendy-) S 8842 8843 4159 34819 4229 4202496 567 1854 0 3 0 0 0 1 24 0 1 0 878791242 2650112 284 1283457024 134512640 135304128 4292167536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8843/statm: 647 284 240 194 0 33 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2588

[startup+1.51137 s]
/proc/loadavg: 0.99 0.98 0.99 2/42 8854
/proc/meminfo: memFree=749928/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=2588 CPUtime=0.01
/proc/8843/stat : 8843 (apt-get-trendy-) S 8842 8843 4159 34819 4229 4202496 567 1854 0 3 0 0 0 1 24 0 1 0 878791242 2650112 284 1283457024 134512640 135304128 4292167536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8843/statm: 647 284 240 194 0 33 0
[pid=8854] ppid=8843 vsize=29216 CPUtime=1.3
/proc/8854/stat : 8854 (cudftodeb.nativ) R 8843 8843 4159 34819 4229 4202496 6902 0 8 0 128 2 0 0 25 0 1 0 878791258 29917184 6837 1283457024 134512640 135004320 4287978448 18446744073709551615 134995972 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/8854/statm: 7304 6837 225 121 0 6696 0
Current children cumulated CPU time (s) 1.31
Current children cumulated vsize (KiB) 31804

[startup+3.11173 s]
/proc/loadavg: 0.99 0.98 0.99 2/42 8854
/proc/meminfo: memFree=725500/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=2588 CPUtime=0.01
/proc/8843/stat : 8843 (apt-get-trendy-) S 8842 8843 4159 34819 4229 4202496 567 1854 0 3 0 0 0 1 24 0 1 0 878791242 2650112 284 1283457024 134512640 135304128 4292167536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8843/statm: 647 284 240 194 0 33 0
[pid=8854] ppid=8843 vsize=30240 CPUtime=2.88
/proc/8854/stat : 8854 (cudftodeb.nativ) R 8843 8843 4159 34819 4229 4202496 12423 0 8 0 283 5 0 0 25 0 1 0 878791258 30965760 7112 1283457024 134512640 135004320 4287978448 18446744073709551615 4158711382 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/8854/statm: 7560 7112 237 121 0 6952 0
Current children cumulated CPU time (s) 2.89
Current children cumulated vsize (KiB) 32828

Solver just ended. Dumping a history of the last processes samples

[startup+3.21175 s]
/proc/loadavg: 0.99 0.98 0.99 2/42 8854
/proc/meminfo: memFree=725500/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=2588 CPUtime=0.01
/proc/8843/stat : 8843 (apt-get-trendy-) S 8842 8843 4159 34819 4229 4202496 567 1854 0 3 0 0 0 1 24 0 1 0 878791242 2650112 284 1283457024 134512640 135304128 4292167536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8843/statm: 647 284 240 194 0 33 0
[pid=8854] ppid=8843 vsize=30240 CPUtime=2.98
/proc/8854/stat : 8854 (cudftodeb.nativ) R 8843 8843 4159 34819 4229 4202496 12423 0 8 0 293 5 0 0 25 0 1 0 878791258 30965760 7112 1283457024 134512640 135004320 4287978448 18446744073709551615 134863655 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/8854/statm: 7560 7112 237 121 0 6952 0
Current children cumulated CPU time (s) 2.99
Current children cumulated vsize (KiB) 32828

[startup+4.81442 s]
/proc/loadavg: 0.99 0.98 0.99 2/42 8864
/proc/meminfo: memFree=746748/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=2596 CPUtime=3.3
/proc/8843/stat : 8843 (apt-get-trendy-) S 8842 8843 4159 34819 4229 4202496 707 17567 0 14 0 0 320 10 18 0 1 0 878791242 2658304 295 1283457024 134512640 135304128 4292167536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8843/statm: 649 295 249 194 0 35 0
[pid=8864] ppid=8843 vsize=101452 CPUtime=0.43
/proc/8864/stat : 8864 (apt-get) R 8843 8843 4159 34819 4229 4202496 3168 0 161 0 40 3 0 0 21 0 1 0 878791677 103886848 3252 1283457024 134512640 134619611 4292648208 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/8864/statm: 25363 3252 3199 27 0 57 0
Current children cumulated CPU time (s) 3.73
Current children cumulated vsize (KiB) 104048

[startup+5.61037 s]
/proc/loadavg: 0.99 0.98 0.99 2/42 8864
/proc/meminfo: memFree=723060/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=2596 CPUtime=3.3
/proc/8843/stat : 8843 (apt-get-trendy-) S 8842 8843 4159 34819 4229 4202496 707 17567 0 14 0 0 320 10 18 0 1 0 878791242 2658304 295 1283457024 134512640 135304128 4292167536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8843/statm: 649 295 249 194 0 35 0
[pid=8864] ppid=8843 vsize=17052 CPUtime=0.61
/proc/8864/stat : 8864 (apt-get) R 8843 8843 4159 34819 4229 4202496 6474 0 167 0 58 3 0 0 18 0 1 0 878791677 17461248 3600 1283457024 134512640 134619611 4292648208 18446744073709551615 4159947028 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/8864/statm: 4263 3600 3191 27 0 404 0
Current children cumulated CPU time (s) 3.91
Current children cumulated vsize (KiB) 19648

[startup+5.81041 s]
/proc/loadavg: 0.99 0.98 0.99 2/42 8864
/proc/meminfo: memFree=723060/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=2596 CPUtime=3.3
/proc/8843/stat : 8843 (apt-get-trendy-) S 8842 8843 4159 34819 4229 4202496 707 17567 0 14 0 0 320 10 18 0 1 0 878791242 2658304 295 1283457024 134512640 135304128 4292167536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8843/statm: 649 295 249 194 0 35 0
[pid=8864] ppid=8843 vsize=17232 CPUtime=0.81
/proc/8864/stat : 8864 (apt-get) R 8843 8843 4159 34819 4229 4202496 6512 0 167 0 78 3 0 0 18 0 1 0 878791677 17645568 3638 1283457024 134512640 134619611 4292648208 18446744073709551615 4159844800 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/8864/statm: 4308 3638 3195 27 0 449 0
Current children cumulated CPU time (s) 4.11
Current children cumulated vsize (KiB) 19828

[startup+5.91043 s]
/proc/loadavg: 0.99 0.98 0.99 2/42 8864
/proc/meminfo: memFree=723060/1048576 swapFree=2080288/2097144
[pid=8843] ppid=8842 vsize=2596 CPUtime=3.3
/proc/8843/stat : 8843 (apt-get-trendy-) S 8842 8843 4159 34819 4229 4202496 707 17567 0 14 0 0 320 10 18 0 1 0 878791242 2658304 295 1283457024 134512640 135304128 4292167536 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/8843/statm: 649 295 249 194 0 35 0
[pid=8864] ppid=8843 vsize=17232 CPUtime=0.91
/proc/8864/stat : 8864 (apt-get) R 8843 8843 4159 34819 4229 4202496 6512 0 167 0 88 3 0 0 18 0 1 0 878791677 17645568 3638 1283457024 134512640 134619611 4292648208 18446744073709551615 4159962240 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/8864/statm: 4308 3638 3195 27 0 449 0
Current children cumulated CPU time (s) 4.21
Current children cumulated vsize (KiB) 19828

Child status: 100
Real time (s): 5.94904
CPU time (s): 4.25627
CPU user time (s): 4.11626
CPU system time (s): 0.140008
CPU usage (%): 71.5454
Max. virtual memory (cumulated for all children) (KiB): 104048

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.11626
system time used= 0.140008
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 24806
page faults= 181
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 218
involuntary context switches= 80

runsolver used 0 second user time and 0 second system time

The end