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/201103110955/apt-pbo-paranoid-1.0.8/1075.cudf.caixa.log.runsolver ./apt-pbo-paranoid-1.0.8 /home/misc2010/data/misc4/caixa//1075.cudf /home/misc2010/tmp/201103110955/apt-pbo-paranoid-1.0.8/1075.cudf.caixa.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.00 1.04 1.00 5/36 9383
/proc/meminfo: memFree=547720/1048576 swapFree=0/0
[pid=9383] ppid=9382 vsize=1676 CPUtime=0
/proc/9383/stat : 9383 (sh) R 9382 9383 12462 34817 12462 4194304 182 0 0 0 0 0 0 0 25 0 1 0 143974118 1716224 102 1283457024 134512640 134593992 4293200016 18446744073709551615 4159440797 0 0 0 0 0 0 0 17 0 0 0 0
/proc/9383/statm: 419 102 86 20 0 46 0

[startup+0.192781 s]
/proc/loadavg: 1.00 1.04 1.00 5/36 9383
/proc/meminfo: memFree=547720/1048576 swapFree=0/0
[pid=9383] ppid=9382 vsize=1676 CPUtime=0
/proc/9383/stat : 9383 (sh) S 9382 9383 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 25 0 1 0 143974118 1716224 129 1283457024 134512640 134593992 4293200016 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9383/statm: 419 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+0.204778 s]
/proc/loadavg: 1.00 1.04 1.00 5/36 9383
/proc/meminfo: memFree=547720/1048576 swapFree=0/0
[pid=9383] ppid=9382 vsize=1676 CPUtime=0
/proc/9383/stat : 9383 (sh) S 9382 9383 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 25 0 1 0 143974118 1716224 129 1283457024 134512640 134593992 4293200016 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9383/statm: 419 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+0.309191 s]
/proc/loadavg: 1.00 1.04 1.00 5/36 9383
/proc/meminfo: memFree=547720/1048576 swapFree=0/0
[pid=9383] ppid=9382 vsize=1676 CPUtime=0
/proc/9383/stat : 9383 (sh) S 9382 9383 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 25 0 1 0 143974118 1716224 129 1283457024 134512640 134593992 4293200016 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9383/statm: 419 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+0.709295 s]
/proc/loadavg: 1.00 1.04 1.00 5/36 9383
/proc/meminfo: memFree=547720/1048576 swapFree=0/0
[pid=9383] ppid=9382 vsize=1676 CPUtime=0
/proc/9383/stat : 9383 (sh) S 9382 9383 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 25 0 1 0 143974118 1716224 129 1283457024 134512640 134593992 4293200016 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9383/statm: 419 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+1.50942 s]
/proc/loadavg: 1.00 1.04 1.00 2/39 9389
/proc/meminfo: memFree=513896/1048576 swapFree=0/0
[pid=9383] ppid=9382 vsize=1676 CPUtime=0
/proc/9383/stat : 9383 (sh) S 9382 9383 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 25 0 1 0 143974118 1716224 129 1283457024 134512640 134593992 4293200016 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9383/statm: 419 129 112 20 0 46 0
[pid=9386] ppid=9383 vsize=8224 CPUtime=0.05
/proc/9386/stat : 9386 (apt-pbo) S 9383 9383 12462 34817 12462 4202496 1575 409 0 0 5 0 0 0 25 0 1 0 143974118 8421376 1400 1283457024 134512640 135745756 4290489632 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/9386/statm: 2056 1400 648 302 0 789 0
[pid=9389] ppid=9386 vsize=34752 CPUtime=1.26
/proc/9389/stat : 9389 (cudftodeb.nativ) R 9386 9383 12462 34817 12462 4202496 8320 0 0 0 124 2 0 0 25 0 1 0 143974124 35586048 8241 1283457024 134512640 135029684 4292280112 18446744073709551615 134843204 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/9389/statm: 8688 8241 246 127 0 8069 0
Current children cumulated CPU time (s) 1.31
Current children cumulated vsize (KiB) 44652

[startup+3.10976 s]
/proc/loadavg: 1.00 1.04 1.00 2/39 9389
/proc/meminfo: memFree=491552/1048576 swapFree=0/0
[pid=9383] ppid=9382 vsize=1676 CPUtime=0
/proc/9383/stat : 9383 (sh) S 9382 9383 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 25 0 1 0 143974118 1716224 129 1283457024 134512640 134593992 4293200016 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9383/statm: 419 129 112 20 0 46 0
[pid=9386] ppid=9383 vsize=8224 CPUtime=0.05
/proc/9386/stat : 9386 (apt-pbo) S 9383 9383 12462 34817 12462 4202496 1575 409 0 0 5 0 0 0 25 0 1 0 143974118 8421376 1400 1283457024 134512640 135745756 4290489632 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/9386/statm: 2056 1400 648 302 0 789 0
[pid=9389] ppid=9386 vsize=60960 CPUtime=2.85
/proc/9389/stat : 9389 (cudftodeb.nativ) R 9386 9383 12462 34817 12462 4202496 14870 0 0 0 265 20 0 0 25 0 1 0 143974124 62423040 14791 1283457024 134512640 135029684 4292280112 18446744073709551615 134967018 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/9389/statm: 15240 14791 258 127 0 14621 0
Current children cumulated CPU time (s) 2.9
Current children cumulated vsize (KiB) 70860

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

[startup+3.20978 s]
/proc/loadavg: 1.00 1.04 1.00 2/39 9389
/proc/meminfo: memFree=491552/1048576 swapFree=0/0
[pid=9383] ppid=9382 vsize=1676 CPUtime=0
/proc/9383/stat : 9383 (sh) S 9382 9383 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 25 0 1 0 143974118 1716224 129 1283457024 134512640 134593992 4293200016 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9383/statm: 419 129 112 20 0 46 0
[pid=9386] ppid=9383 vsize=8224 CPUtime=0.05
/proc/9386/stat : 9386 (apt-pbo) S 9383 9383 12462 34817 12462 4202496 1575 409 0 0 5 0 0 0 25 0 1 0 143974118 8421376 1400 1283457024 134512640 135745756 4290489632 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/9386/statm: 2056 1400 648 302 0 789 0
[pid=9389] ppid=9386 vsize=63480 CPUtime=2.95
/proc/9389/stat : 9389 (cudftodeb.nativ) R 9386 9383 12462 34817 12462 4202496 15386 0 0 0 275 20 0 0 25 0 1 0 143974124 65003520 15307 1283457024 134512640 135029684 4292280112 18446744073709551615 134968855 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/9389/statm: 15870 15307 258 127 0 15251 0
Current children cumulated CPU time (s) 3
Current children cumulated vsize (KiB) 73380

[startup+4.8085 s]
/proc/loadavg: 1.00 1.04 1.00 2/41 9391
/proc/meminfo: memFree=472556/1048576 swapFree=0/0
[pid=9383] ppid=9382 vsize=1676 CPUtime=0
/proc/9383/stat : 9383 (sh) S 9382 9383 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 25 0 1 0 143974118 1716224 129 1283457024 134512640 134593992 4293200016 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9383/statm: 419 129 112 20 0 46 0
[pid=9386] ppid=9383 vsize=8224 CPUtime=0.05
/proc/9386/stat : 9386 (apt-pbo) S 9383 9383 12462 34817 12462 4202496 1575 409 0 0 5 0 0 0 25 0 1 0 143974118 8421376 1400 1283457024 134512640 135745756 4290489632 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/9386/statm: 2056 1400 648 302 0 789 0
[pid=9389] ppid=9386 vsize=55024 CPUtime=4.47
/proc/9389/stat : 9389 (cudftodeb.nativ) R 9386 9383 12462 34817 12462 4202496 17253 0 0 0 396 51 0 0 25 0 1 0 143974124 56344576 13295 1283457024 134512640 135029684 4292280112 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/9389/statm: 13756 13295 258 127 0 13137 0
Current children cumulated CPU time (s) 4.52
Current children cumulated vsize (KiB) 64924

[startup+5.20106 s]
/proc/loadavg: 1.00 1.04 1.00 2/41 9391
/proc/meminfo: memFree=472556/1048576 swapFree=0/0
[pid=9383] ppid=9382 vsize=1676 CPUtime=0
/proc/9383/stat : 9383 (sh) S 9382 9383 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 25 0 1 0 143974118 1716224 129 1283457024 134512640 134593992 4293200016 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9383/statm: 419 129 112 20 0 46 0
[pid=9386] ppid=9383 vsize=8224 CPUtime=4.57
/proc/9386/stat : 9386 (apt-pbo) S 9383 9383 12462 34817 12462 4202496 1749 17663 0 0 5 1 399 52 18 0 1 0 143974118 8421376 1426 1283457024 134512640 135745756 4290489632 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/9386/statm: 2056 1426 653 302 0 789 0
Current children cumulated CPU time (s) 4.57
Current children cumulated vsize (KiB) 9900

[startup+5.60515 s]
/proc/loadavg: 1.00 1.04 1.00 1/42 9399
/proc/meminfo: memFree=505584/1048576 swapFree=0/0
[pid=9383] ppid=9382 vsize=1676 CPUtime=0
/proc/9383/stat : 9383 (sh) S 9382 9383 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 25 0 1 0 143974118 1716224 129 1283457024 134512640 134593992 4293200016 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9383/statm: 419 129 112 20 0 46 0
[pid=9386] ppid=9383 vsize=57184 CPUtime=4.82
/proc/9386/stat : 9386 (apt-pbo) D 9383 9383 12462 34817 12462 4202496 1880 20903 1 1 5 1 418 58 16 0 1 0 143974118 58556416 1456 1283457024 134512640 135745756 4290489632 18446744073709551615 4294960130 0 0 128 0 18446744071696460772 0 0 17 0 0 0 0
/proc/9386/statm: 14296 1456 680 302 0 821 0
Current children cumulated CPU time (s) 4.82
Current children cumulated vsize (KiB) 58860

Child status: 100
Real time (s): 5.62745
CPU time (s): 4.8443
CPU user time (s): 4.24027
CPU system time (s): 0.604037
CPU usage (%): 86.0835
Max. virtual memory (cumulated for all children) (KiB): 78420

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.24026
system time used= 0.604037
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 23380
page faults= 2
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 52
involuntary context switches= 168

runsolver used 0 second user time and 0 second system time

The end