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/1243.cudf.caixa.log.runsolver ./apt-pbo-paranoid-1.0.8 /home/misc2010/data/misc4/caixa//1243.cudf /home/misc2010/tmp/201103110955/apt-pbo-paranoid-1.0.8/1243.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.04 1.04 1.00 4/39 15929
/proc/meminfo: memFree=537552/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=5196 CPUtime=0.04
/proc/15929/stat : 15929 (apt-pbo) R 15927 15927 12462 34817 12462 4202496 992 0 0 0 4 0 0 0 25 0 1 0 144382474 5320704 932 1283457024 134512640 135745756 4287224320 18446744073709551615 4158777325 0 0 128 0 0 0 0 17 0 0 0 0
/proc/15929/statm: 1299 932 414 302 0 553 0

[startup+0.189621 s]
/proc/loadavg: 1.04 1.04 1.00 4/39 15929
/proc/meminfo: memFree=537552/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=8228 CPUtime=0.05
/proc/15929/stat : 15929 (apt-pbo) S 15927 15927 12462 34817 12462 4202496 1578 409 0 0 4 0 0 1 25 0 1 0 144382474 8425472 1401 1283457024 134512640 135745756 4287224320 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15929/statm: 2057 1401 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+0.20964 s]
/proc/loadavg: 1.04 1.04 1.00 4/39 15929
/proc/meminfo: memFree=537552/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=8228 CPUtime=0.05
/proc/15929/stat : 15929 (apt-pbo) S 15927 15927 12462 34817 12462 4202496 1578 409 0 0 4 0 0 1 25 0 1 0 144382474 8425472 1401 1283457024 134512640 135745756 4287224320 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15929/statm: 2057 1401 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+0.309641 s]
/proc/loadavg: 1.04 1.04 1.00 4/39 15929
/proc/meminfo: memFree=537552/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=8228 CPUtime=0.05
/proc/15929/stat : 15929 (apt-pbo) S 15927 15927 12462 34817 12462 4202496 1578 409 0 0 4 0 0 1 25 0 1 0 144382474 8425472 1401 1283457024 134512640 135745756 4287224320 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15929/statm: 2057 1401 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+0.709749 s]
/proc/loadavg: 1.04 1.04 1.00 4/39 15929
/proc/meminfo: memFree=537552/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=8228 CPUtime=0.05
/proc/15929/stat : 15929 (apt-pbo) S 15927 15927 12462 34817 12462 4202496 1578 409 0 0 4 0 0 1 25 0 1 0 144382474 8425472 1401 1283457024 134512640 135745756 4287224320 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15929/statm: 2057 1401 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+1.50986 s]
/proc/loadavg: 1.04 1.04 1.00 2/41 15933
/proc/meminfo: memFree=502700/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=8228 CPUtime=0.05
/proc/15929/stat : 15929 (apt-pbo) S 15927 15927 12462 34817 12462 4202496 1578 409 0 0 4 0 0 1 25 0 1 0 144382474 8425472 1401 1283457024 134512640 135745756 4287224320 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15929/statm: 2057 1401 648 302 0 790 0
[pid=15933] ppid=15929 vsize=36260 CPUtime=1.42
/proc/15933/stat : 15933 (cudftodeb.nativ) R 15929 15927 12462 34817 12462 4202496 8729 0 0 0 135 7 0 0 25 0 1 0 144382480 37130240 8650 1283457024 134512640 135029684 4293951680 18446744073709551615 134967098 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/15933/statm: 9065 8650 246 127 0 8446 0
Current children cumulated CPU time (s) 1.47
Current children cumulated vsize (KiB) 46160

[startup+3.11499 s]
/proc/loadavg: 1.04 1.04 1.00 2/41 15933
/proc/meminfo: memFree=481980/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=8228 CPUtime=0.05
/proc/15929/stat : 15929 (apt-pbo) S 15927 15927 12462 34817 12462 4202496 1578 409 0 0 4 0 0 1 25 0 1 0 144382474 8425472 1401 1283457024 134512640 135745756 4287224320 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15929/statm: 2057 1401 648 302 0 790 0
[pid=15933] ppid=15929 vsize=63476 CPUtime=2.96
/proc/15933/stat : 15933 (cudftodeb.nativ) R 15929 15927 12462 34817 12462 4202496 15454 0 0 0 274 22 0 0 25 0 1 0 144382480 64999424 15375 1283457024 134512640 135029684 4293951680 18446744073709551615 134888552 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/15933/statm: 15869 15375 258 127 0 15250 0
Current children cumulated CPU time (s) 3.01
Current children cumulated vsize (KiB) 73376

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

[startup+3.21501 s]
/proc/loadavg: 1.04 1.04 1.00 2/41 15933
/proc/meminfo: memFree=481980/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=8228 CPUtime=0.05
/proc/15929/stat : 15929 (apt-pbo) S 15927 15927 12462 34817 12462 4202496 1578 409 0 0 4 0 0 1 25 0 1 0 144382474 8425472 1401 1283457024 134512640 135745756 4287224320 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15929/statm: 2057 1401 648 302 0 790 0
[pid=15933] ppid=15929 vsize=64988 CPUtime=3.06
/proc/15933/stat : 15933 (cudftodeb.nativ) R 15929 15927 12462 34817 12462 4202496 15870 0 0 0 284 22 0 0 25 0 1 0 144382480 66547712 15791 1283457024 134512640 135029684 4293951680 18446744073709551615 134966356 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/15933/statm: 16247 15791 258 127 0 15628 0
Current children cumulated CPU time (s) 3.11
Current children cumulated vsize (KiB) 74888

[startup+4.01519 s]
/proc/loadavg: 1.04 1.04 1.00 2/41 15933
/proc/meminfo: memFree=457428/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=8228 CPUtime=0.05
/proc/15929/stat : 15929 (apt-pbo) S 15927 15927 12462 34817 12462 4202496 1578 409 0 0 4 0 0 1 25 0 1 0 144382474 8425472 1401 1283457024 134512640 135745756 4287224320 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15929/statm: 2057 1401 648 302 0 790 0
[pid=15933] ppid=15929 vsize=51380 CPUtime=3.86
/proc/15933/stat : 15933 (cudftodeb.nativ) R 15929 15927 12462 34817 12462 4202496 15877 0 0 0 356 30 0 0 25 0 1 0 144382480 52613120 12420 1283457024 134512640 135029684 4293951680 18446744073709551615 134969986 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/15933/statm: 12845 12420 258 127 0 12226 0
Current children cumulated CPU time (s) 3.91
Current children cumulated vsize (KiB) 61280

[startup+4.80608 s]
/proc/loadavg: 1.04 1.04 1.00 2/41 15933
/proc/meminfo: memFree=463008/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=8228 CPUtime=4.43
/proc/15929/stat : 15929 (apt-pbo) S 15927 15927 12462 34817 12462 4202496 1752 16662 0 0 4 2 389 48 18 0 1 0 144382474 8425472 1427 1283457024 134512640 135745756 4287224320 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/15929/statm: 2057 1427 653 302 0 790 0
Current children cumulated CPU time (s) 4.43
Current children cumulated vsize (KiB) 9900

[startup+5.20614 s]
/proc/loadavg: 1.04 1.04 1.00 2/41 15933
/proc/meminfo: memFree=463008/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=8228 CPUtime=4.43
/proc/15929/stat : 15929 (apt-pbo) S 15927 15927 12462 34817 12462 4202496 1752 16662 0 0 4 2 389 48 18 0 1 0 144382474 8425472 1427 1283457024 134512640 135745756 4287224320 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/15929/statm: 2057 1427 653 302 0 790 0
Current children cumulated CPU time (s) 4.43
Current children cumulated vsize (KiB) 9900

[startup+5.30613 s]
/proc/loadavg: 1.04 1.04 1.00 2/41 15933
/proc/meminfo: memFree=463008/1048576 swapFree=0/0
[pid=15927] ppid=15926 vsize=1672 CPUtime=0
/proc/15927/stat : 15927 (sh) S 15926 15927 12462 34817 12462 4202496 221 175 0 0 0 0 0 0 25 0 1 0 144382474 1712128 128 1283457024 134512640 134593992 4294912560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15927/statm: 418 128 112 20 0 45 0
[pid=15929] ppid=15927 vsize=8228 CPUtime=4.43
/proc/15929/stat : 15929 (apt-pbo) S 15927 15927 12462 34817 12462 4202496 1752 16662 0 0 4 2 389 48 18 0 1 0 144382474 8425472 1427 1283457024 134512640 135745756 4287224320 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/15929/statm: 2057 1427 653 302 0 790 0
Current children cumulated CPU time (s) 4.43
Current children cumulated vsize (KiB) 9900

Child status: 100
Real time (s): 5.33831
CPU time (s): 4.65229
CPU user time (s): 4.11626
CPU system time (s): 0.536033
CPU usage (%): 87.1491
Max. virtual memory (cumulated for all children) (KiB): 74888

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.11626
system time used= 0.536033
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 22386
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= 50
involuntary context switches= 154

runsolver used 0 second user time and 0 second system time

The end