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/4065.cudf.caixa.log.runsolver ./apt-pbo-paranoid-1.0.8 /home/misc2010/data/misc4/caixa//4065.cudf /home/misc2010/tmp/201103110955/apt-pbo-paranoid-1.0.8/4065.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.22 1.17 1.09 5/37 21378
/proc/meminfo: memFree=76364/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=4092 CPUtime=0.02
/proc/21378/stat : 21378 (apt-pbo) R 21376 21376 12462 34817 12462 4202496 705 0 0 0 2 0 0 0 25 0 1 0 144471692 4190208 653 1283457024 134512640 135745756 4288299792 18446744073709551615 134832387 0 0 128 0 0 0 0 17 0 0 0 0
/proc/21378/statm: 1023 653 406 302 0 287 0

[startup+0.154346 s]
/proc/loadavg: 1.22 1.17 1.09 5/37 21378
/proc/meminfo: memFree=76364/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=8232 CPUtime=0.05
/proc/21378/stat : 21378 (apt-pbo) S 21376 21376 12462 34817 12462 4202496 1577 409 0 0 4 1 0 0 25 0 1 0 144471692 8429568 1401 1283457024 134512640 135745756 4288299792 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21378/statm: 2058 1401 648 302 0 791 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9904

[startup+0.215936 s]
/proc/loadavg: 1.22 1.17 1.09 5/37 21378
/proc/meminfo: memFree=76364/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=8232 CPUtime=0.05
/proc/21378/stat : 21378 (apt-pbo) S 21376 21376 12462 34817 12462 4202496 1577 409 0 0 4 1 0 0 25 0 1 0 144471692 8429568 1401 1283457024 134512640 135745756 4288299792 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21378/statm: 2058 1401 648 302 0 791 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9904

[startup+0.315972 s]
/proc/loadavg: 1.22 1.17 1.09 5/37 21378
/proc/meminfo: memFree=76364/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=8232 CPUtime=0.05
/proc/21378/stat : 21378 (apt-pbo) S 21376 21376 12462 34817 12462 4202496 1577 409 0 0 4 1 0 0 25 0 1 0 144471692 8429568 1401 1283457024 134512640 135745756 4288299792 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21378/statm: 2058 1401 648 302 0 791 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9904

[startup+0.716069 s]
/proc/loadavg: 1.22 1.17 1.09 5/37 21378
/proc/meminfo: memFree=76364/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=8232 CPUtime=0.05
/proc/21378/stat : 21378 (apt-pbo) S 21376 21376 12462 34817 12462 4202496 1577 409 0 0 4 1 0 0 25 0 1 0 144471692 8429568 1401 1283457024 134512640 135745756 4288299792 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21378/statm: 2058 1401 648 302 0 791 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9904

[startup+1.50632 s]
/proc/loadavg: 1.22 1.17 1.09 2/39 21382
/proc/meminfo: memFree=40312/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=8232 CPUtime=0.05
/proc/21378/stat : 21378 (apt-pbo) S 21376 21376 12462 34817 12462 4202496 1577 409 0 0 4 1 0 0 25 0 1 0 144471692 8429568 1401 1283457024 134512640 135745756 4288299792 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21378/statm: 2058 1401 648 302 0 791 0
[pid=21382] ppid=21378 vsize=37248 CPUtime=1.42
/proc/21382/stat : 21382 (cudftodeb.nativ) R 21378 21376 12462 34817 12462 4202496 8860 0 0 0 135 7 0 0 25 0 1 0 144471698 38141952 8781 1283457024 134512640 135029684 4290784704 18446744073709551615 134974442 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21382/statm: 9312 8781 246 127 0 8693 0
Current children cumulated CPU time (s) 1.47
Current children cumulated vsize (KiB) 47152

[startup+3.10675 s]
/proc/loadavg: 1.22 1.17 1.09 2/39 21382
/proc/meminfo: memFree=14432/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=8232 CPUtime=0.05
/proc/21378/stat : 21378 (apt-pbo) S 21376 21376 12462 34817 12462 4202496 1577 409 0 0 4 1 0 0 25 0 1 0 144471692 8429568 1401 1283457024 134512640 135745756 4288299792 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21378/statm: 2058 1401 648 302 0 791 0
[pid=21382] ppid=21378 vsize=62336 CPUtime=2.99
/proc/21382/stat : 21382 (cudftodeb.nativ) R 21378 21376 12462 34817 12462 4202496 15115 0 0 0 277 22 0 0 25 0 1 0 144471698 63832064 15036 1283457024 134512640 135029684 4290784704 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21382/statm: 15584 15036 258 127 0 14965 0
Current children cumulated CPU time (s) 3.04
Current children cumulated vsize (KiB) 72240

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

[startup+3.20678 s]
/proc/loadavg: 1.22 1.17 1.09 2/39 21382
/proc/meminfo: memFree=14432/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=8232 CPUtime=0.05
/proc/21378/stat : 21378 (apt-pbo) S 21376 21376 12462 34817 12462 4202496 1577 409 0 0 4 1 0 0 25 0 1 0 144471692 8429568 1401 1283457024 134512640 135745756 4288299792 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21378/statm: 2058 1401 648 302 0 791 0
[pid=21382] ppid=21378 vsize=64352 CPUtime=3.09
/proc/21382/stat : 21382 (cudftodeb.nativ) R 21378 21376 12462 34817 12462 4202496 15663 0 0 0 285 24 0 0 25 0 1 0 144471698 65896448 15584 1283457024 134512640 135029684 4290784704 18446744073709551615 134973030 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21382/statm: 16088 15584 258 127 0 15469 0
Current children cumulated CPU time (s) 3.14
Current children cumulated vsize (KiB) 74256

[startup+4.80717 s]
/proc/loadavg: 1.20 1.17 1.09 2/39 21382
/proc/meminfo: memFree=5192/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=8232 CPUtime=0.05
/proc/21378/stat : 21378 (apt-pbo) S 21376 21376 12462 34817 12462 4202496 1577 409 0 0 4 1 0 0 25 0 1 0 144471692 8429568 1401 1283457024 134512640 135745756 4288299792 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21378/statm: 2058 1401 648 302 0 791 0
[pid=21382] ppid=21378 vsize=58300 CPUtime=4.69
/proc/21382/stat : 21382 (cudftodeb.nativ) R 21378 21376 12462 34817 12462 4202496 19166 0 0 0 419 50 0 0 25 0 1 0 144471698 59699200 14086 1283457024 134512640 135029684 4290784704 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21382/statm: 14575 14086 258 127 0 13956 0
Current children cumulated CPU time (s) 4.74
Current children cumulated vsize (KiB) 68204

[startup+5.60703 s]
/proc/loadavg: 1.20 1.17 1.09 4/42 21390
/proc/meminfo: memFree=62808/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=8232 CPUtime=5.28
/proc/21378/stat : 21378 (apt-pbo) S 21376 21376 12462 34817 12462 4202496 1752 20075 0 0 4 1 458 65 18 0 1 0 144471692 8429568 1427 1283457024 134512640 135745756 4288299792 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/21378/statm: 2058 1427 653 302 0 791 0
[pid=21383] ppid=21378 vsize=2568 CPUtime=0.01
/proc/21383/stat : 21383 (apt-get.sh) S 21378 21376 12462 34817 12462 4202496 408 490 0 0 0 0 0 1 18 0 1 0 144472238 2629632 273 1283457024 134512640 135304128 4286687712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21383/statm: 642 273 232 194 0 29 0
[pid=21386] ppid=21383 vsize=3916 CPUtime=0
/proc/21386/stat : 21386 (apt-get) S 21383 21376 12462 34817 12462 4202496 538 815 0 0 0 0 0 0 25 0 1 0 144472238 4009984 419 1283457024 134512640 134650667 4288109440 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/21386/statm: 979 419 375 34 0 70 0
[pid=21388] ppid=21386 vsize=4052 CPUtime=0
/proc/21388/stat : 21388 (file) S 21386 21376 12462 34817 12462 4202496 449 0 0 0 0 0 0 0 25 0 1 0 144472239 4149248 368 1283457024 134512640 134522521 4291124832 18446744073709551615 4294960130 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21388/statm: 1013 368 331 3 0 68 0
[pid=21390] ppid=21386 vsize=4048 CPUtime=0.13
/proc/21390/stat : 21390 (copy) R 21386 21376 12462 34817 12462 4202496 475 0 0 0 10 3 0 0 25 0 1 0 144472239 4145152 394 1283457024 134512640 134523002 4288402368 18446744073709551615 4159529898 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21390/statm: 1012 394 341 3 0 67 0
Current children cumulated CPU time (s) 5.42
Current children cumulated vsize (KiB) 24488

[startup+6.00667 s]
/proc/loadavg: 1.20 1.17 1.09 4/42 21390
/proc/meminfo: memFree=62808/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=8232 CPUtime=5.28
/proc/21378/stat : 21378 (apt-pbo) S 21376 21376 12462 34817 12462 4202496 1752 20075 0 0 4 1 458 65 18 0 1 0 144471692 8429568 1427 1283457024 134512640 135745756 4288299792 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/21378/statm: 2058 1427 653 302 0 791 0
[pid=21383] ppid=21378 vsize=2568 CPUtime=0.01
/proc/21383/stat : 21383 (apt-get.sh) S 21378 21376 12462 34817 12462 4202496 408 490 0 0 0 0 0 1 18 0 1 0 144472238 2629632 273 1283457024 134512640 135304128 4286687712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21383/statm: 642 273 232 194 0 29 0
[pid=21386] ppid=21383 vsize=52748 CPUtime=0.23
/proc/21386/stat : 21386 (apt-get) D 21383 21376 12462 34817 12462 4202496 565 1744 1 0 0 1 18 4 24 0 1 0 144472238 54013952 437 1283457024 134512640 134650667 4288109440 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/21386/statm: 13187 437 388 34 0 70 0
Current children cumulated CPU time (s) 5.52
Current children cumulated vsize (KiB) 65220

[startup+6.1067 s]
/proc/loadavg: 1.20 1.17 1.09 4/42 21390
/proc/meminfo: memFree=62808/1048576 swapFree=0/0
[pid=21376] ppid=21375 vsize=1672 CPUtime=0
/proc/21376/stat : 21376 (sh) S 21375 21376 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144471692 1712128 129 1283457024 134512640 134593992 4286808688 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21376/statm: 418 129 112 20 0 45 0
[pid=21378] ppid=21376 vsize=57192 CPUtime=5.53
/proc/21378/stat : 21378 (apt-pbo) R 21376 21376 12462 34817 12462 4202496 1883 23319 1 1 4 1 477 71 16 0 1 0 144471692 58564608 1457 1283457024 134512640 135745756 4288299792 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/21378/statm: 14298 1457 680 302 0 823 0
Current children cumulated CPU time (s) 5.53
Current children cumulated vsize (KiB) 58864

Child status: 100
Real time (s): 6.12469
CPU time (s): 5.54835
CPU user time (s): 4.8203
CPU system time (s): 0.728045
CPU usage (%): 90.5898
Max. virtual memory (cumulated for all children) (KiB): 88368

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.8203
system time used= 0.728045
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 25800
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= 53
involuntary context switches= 214

runsolver used 0 second user time and 0.004 second system time

The end