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-pbo-trendy-1.0.6/rand2d2fd0.cudf.difficult.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/2010/difficult//rand2d2fd0.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/rand2d2fd0.cudf.difficult.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: 1.04 0.99 0.99 4/41 13750
/proc/meminfo: memFree=695552/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=3544 CPUtime=0
/proc/13750/stat : 13750 (apt-pbo) R 13748 13748 4159 34819 4229 4202496 504 0 0 0 0 0 0 0 25 0 1 0 879808470 3629056 452 1283457024 134512640 135744540 4292984688 18446744073709551615 4159141376 0 0 128 0 0 0 0 17 0 0 0 0
/proc/13750/statm: 886 452 350 301 0 154 0

[startup+0.166221 s]
/proc/loadavg: 1.04 0.99 0.99 4/41 13750
/proc/meminfo: memFree=695552/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=8352 CPUtime=0.06
/proc/13750/stat : 13750 (apt-pbo) S 13748 13748 4159 34819 4229 4202496 1610 412 0 0 4 2 0 0 25 0 1 0 879808470 8552448 1422 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/13750/statm: 2088 1422 646 301 0 821 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 10028

[startup+0.206238 s]
/proc/loadavg: 1.04 0.99 0.99 4/41 13750
/proc/meminfo: memFree=695552/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=8352 CPUtime=0.06
/proc/13750/stat : 13750 (apt-pbo) S 13748 13748 4159 34819 4229 4202496 1610 412 0 0 4 2 0 0 25 0 1 0 879808470 8552448 1422 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/13750/statm: 2088 1422 646 301 0 821 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 10028

[startup+0.306277 s]
/proc/loadavg: 1.04 0.99 0.99 4/41 13750
/proc/meminfo: memFree=695552/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=8352 CPUtime=0.06
/proc/13750/stat : 13750 (apt-pbo) S 13748 13748 4159 34819 4229 4202496 1610 412 0 0 4 2 0 0 25 0 1 0 879808470 8552448 1422 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/13750/statm: 2088 1422 646 301 0 821 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 10028

[startup+0.706392 s]
/proc/loadavg: 1.04 0.99 0.99 4/41 13750
/proc/meminfo: memFree=695552/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=8352 CPUtime=0.06
/proc/13750/stat : 13750 (apt-pbo) S 13748 13748 4159 34819 4229 4202496 1610 412 0 0 4 2 0 0 25 0 1 0 879808470 8552448 1422 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/13750/statm: 2088 1422 646 301 0 821 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 10028

[startup+1.50655 s]
/proc/loadavg: 1.28 1.04 1.01 2/43 13754
/proc/meminfo: memFree=670576/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=8352 CPUtime=0.06
/proc/13750/stat : 13750 (apt-pbo) S 13748 13748 4159 34819 4229 4202496 1610 412 0 0 4 2 0 0 25 0 1 0 879808470 8552448 1422 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/13750/statm: 2088 1422 646 301 0 821 0
[pid=13754] ppid=13750 vsize=33204 CPUtime=1.44
/proc/13754/stat : 13754 (cudftodeb.nativ) R 13750 13748 4159 34819 4229 4202496 7870 0 0 0 137 7 0 0 25 0 1 0 879808476 34000896 7788 1283457024 134512640 135029684 4288162624 18446744073709551615 134973057 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/13754/statm: 8301 7788 247 127 0 7684 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 43232

[startup+3.10708 s]
/proc/loadavg: 1.28 1.04 1.01 2/43 13754
/proc/meminfo: memFree=648256/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=8352 CPUtime=0.06
/proc/13750/stat : 13750 (apt-pbo) S 13748 13748 4159 34819 4229 4202496 1610 412 0 0 4 2 0 0 25 0 1 0 879808470 8552448 1422 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/13750/statm: 2088 1422 646 301 0 821 0
[pid=13754] ppid=13750 vsize=67232 CPUtime=3.04
/proc/13754/stat : 13754 (cudftodeb.nativ) R 13750 13748 4159 34819 4229 4202496 16381 0 0 0 291 13 0 0 25 0 1 0 879808476 68845568 16299 1283457024 134512640 135029684 4288162624 18446744073709551615 134968855 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/13754/statm: 16808 16299 258 127 0 16191 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 77260

[startup+6.30778 s]
/proc/loadavg: 1.25 1.04 1.01 2/43 13754
/proc/meminfo: memFree=640204/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=8352 CPUtime=0.06
/proc/13750/stat : 13750 (apt-pbo) S 13748 13748 4159 34819 4229 4202496 1610 412 0 0 4 2 0 0 25 0 1 0 879808470 8552448 1422 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/13750/statm: 2088 1422 646 301 0 821 0
[pid=13754] ppid=13750 vsize=47672 CPUtime=6.23
/proc/13754/stat : 13754 (cudftodeb.nativ) R 13750 13748 4159 34819 4229 4202496 20030 0 0 0 527 96 0 0 25 0 1 0 879808476 48816128 11448 1283457024 134512640 135029684 4288162624 18446744073709551615 134870781 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/13754/statm: 11918 11448 258 127 0 11301 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 57700

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

[startup+6.4078 s]
/proc/loadavg: 1.25 1.04 1.01 2/43 13754
/proc/meminfo: memFree=640204/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=8352 CPUtime=0.06
/proc/13750/stat : 13750 (apt-pbo) S 13748 13748 4159 34819 4229 4202496 1610 412 0 0 4 2 0 0 25 0 1 0 879808470 8552448 1422 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/13750/statm: 2088 1422 646 301 0 821 0
[pid=13754] ppid=13750 vsize=48672 CPUtime=6.33
/proc/13754/stat : 13754 (cudftodeb.nativ) R 13750 13748 4159 34819 4229 4202496 20293 0 0 0 532 101 0 0 25 0 1 0 879808476 49840128 11711 1283457024 134512640 135029684 4288162624 18446744073709551615 134884658 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/13754/statm: 12168 11711 258 127 0 11551 0
Current children cumulated CPU time (s) 6.39
Current children cumulated vsize (KiB) 58700

[startup+9.61067 s]
/proc/loadavg: 1.25 1.04 1.01 1/44 13762
/proc/meminfo: memFree=629156/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=29452 CPUtime=7.75
/proc/13750/stat : 13750 (apt-pbo) S 13748 13748 4159 34819 4229 4202496 7094 29145 0 267 20 6 636 113 18 0 1 0 879808470 30158848 6504 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/13750/statm: 7363 6504 5163 301 0 1370 0
Current children cumulated CPU time (s) 7.75
Current children cumulated vsize (KiB) 31128

[startup+11.2109 s]
/proc/loadavg: 1.23 1.03 1.01 3/44 13767
/proc/meminfo: memFree=622832/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=29452 CPUtime=8.03
/proc/13750/stat : 13750 (apt-pbo) S 13748 13748 4159 34819 4229 4202496 7094 29145 0 267 28 26 636 113 18 0 1 0 879808470 30158848 6504 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/13750/statm: 7363 6504 5163 301 0 1370 0
[pid=13764] ppid=13750 vsize=2580 CPUtime=0
/proc/13764/stat : 13764 (apt-get.sh) S 13750 13748 4159 34819 4229 4202496 421 491 0 0 0 0 0 0 18 0 1 0 879809397 2641920 278 1283457024 134512640 135304128 4291263456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13764/statm: 645 278 235 194 0 31 0
[pid=13767] ppid=13764 vsize=25352 CPUtime=1.61
/proc/13767/stat : 13767 (apt-get) R 13764 13748 4159 34819 4229 4202496 5641 0 0 0 137 24 0 0 25 0 1 0 879809398 25960448 5526 1283457024 134512640 134649604 4288063744 18446744073709551615 4156607039 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/13767/statm: 6338 5526 4862 34 0 702 0
Current children cumulated CPU time (s) 9.64
Current children cumulated vsize (KiB) 59060

[startup+11.6109 s]
/proc/loadavg: 1.23 1.03 1.01 3/44 13767
/proc/meminfo: memFree=622832/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=29452 CPUtime=8.07
/proc/13750/stat : 13750 (apt-pbo) S 13748 13748 4159 34819 4229 4202496 7094 29145 0 267 31 27 636 113 18 0 1 0 879808470 30158848 6504 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/13750/statm: 7363 6504 5163 301 0 1370 0
[pid=13764] ppid=13750 vsize=2580 CPUtime=0
/proc/13764/stat : 13764 (apt-get.sh) S 13750 13748 4159 34819 4229 4202496 421 491 0 0 0 0 0 0 18 0 1 0 879809397 2641920 278 1283457024 134512640 135304128 4291263456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/13764/statm: 645 278 235 194 0 31 0
[pid=13767] ppid=13764 vsize=25352 CPUtime=1.97
/proc/13767/stat : 13767 (apt-get) R 13764 13748 4159 34819 4229 4202496 5645 0 0 0 168 29 0 0 25 0 1 0 879809398 25960448 5530 1283457024 134512640 134649604 4288063744 18446744073709551615 4156607037 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/13767/statm: 6338 5530 4862 34 0 702 0
Current children cumulated CPU time (s) 10.04
Current children cumulated vsize (KiB) 59060

[startup+11.8111 s]
/proc/loadavg: 1.23 1.03 1.01 3/44 13767
/proc/meminfo: memFree=622832/1048576 swapFree=2076380/2097144
[pid=13748] ppid=13747 vsize=1676 CPUtime=0
/proc/13748/stat : 13748 (sh) S 13747 13748 4159 34819 4229 4202496 222 174 0 0 0 0 0 0 18 0 1 0 879808470 1716224 129 1283457024 134512640 134594024 4294177136 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13748/statm: 419 129 112 20 0 45 0
[pid=13750] ppid=13748 vsize=31504 CPUtime=10.22
/proc/13750/stat : 13750 (apt-pbo) R 13748 13748 4159 34819 4229 4202496 7691 35716 0 267 31 28 812 151 18 0 1 0 879808470 32260096 7020 1283457024 134512640 135744540 4292984688 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/13750/statm: 7876 7020 5166 301 0 1883 0
Current children cumulated CPU time (s) 10.22
Current children cumulated vsize (KiB) 33180

Child status: 0
Real time (s): 11.8745
CPU time (s): 10.2566
CPU user time (s): 8.45253
CPU system time (s): 1.80411
CPU usage (%): 86.3757
Max. virtual memory (cumulated for all children) (KiB): 91372

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 8.45253
system time used= 1.80411
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 44177
page faults= 267
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 55664
involuntary context switches= 55640

runsolver used 0 second user time and 0 second system time

The end