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/rand951a14.cudf.easy.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/2010/easy//rand951a14.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/rand951a14.cudf.easy.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.02 1.00 0.99 3/46 381
/proc/meminfo: memFree=783396/1048576 swapFree=2077628/2097144
[pid=376] ppid=375 vsize=1676 CPUtime=0
/proc/376/stat : 376 (sh) S 375 376 4159 34819 4229 4202496 224 175 0 0 0 0 0 0 25 0 1 0 884544878 1716224 129 1283457024 134512640 134594024 4287152832 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/376/statm: 419 129 112 20 0 45 0
[pid=378] ppid=376 vsize=8348 CPUtime=0.04
/proc/378/stat : 378 (apt-pbo) S 376 376 4159 34819 4229 4202496 1608 412 0 0 4 0 0 0 25 0 1 0 884544878 8548352 1421 1283457024 134512640 135744540 4290968976 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/378/statm: 2087 1421 646 301 0 820 0
[pid=381] ppid=378 vsize=3328 CPUtime=0.01
/proc/381/stat : 381 (cudftodeb.nativ) R 378 376 4159 34819 4229 4202496 472 0 0 0 1 0 0 0 25 0 1 0 884544884 3407872 391 1283457024 134512640 135029684 4290454896 18446744073709551615 134554912 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/381/statm: 832 391 246 127 0 215 0

[startup+0.229613 s]
/proc/loadavg: 1.02 1.00 0.99 3/46 381
/proc/meminfo: memFree=783396/1048576 swapFree=2077628/2097144
[pid=376] ppid=375 vsize=1676 CPUtime=0
/proc/376/stat : 376 (sh) S 375 376 4159 34819 4229 4202496 224 175 0 0 0 0 0 0 25 0 1 0 884544878 1716224 129 1283457024 134512640 134594024 4287152832 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/376/statm: 419 129 112 20 0 45 0
[pid=378] ppid=376 vsize=8348 CPUtime=0.04
/proc/378/stat : 378 (apt-pbo) S 376 376 4159 34819 4229 4202496 1608 412 0 0 4 0 0 0 25 0 1 0 884544878 8548352 1421 1283457024 134512640 135744540 4290968976 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/378/statm: 2087 1421 646 301 0 820 0
[pid=381] ppid=378 vsize=6856 CPUtime=0.17
/proc/381/stat : 381 (cudftodeb.nativ) R 378 376 4159 34819 4229 4202496 1383 0 0 0 16 1 0 0 25 0 1 0 884544884 7020544 1302 1283457024 134512640 135029684 4290454896 18446744073709551615 134529104 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/381/statm: 1714 1302 247 127 0 1097 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 16880

[startup+0.309628 s]
/proc/loadavg: 1.02 1.00 0.99 3/46 381
/proc/meminfo: memFree=783396/1048576 swapFree=2077628/2097144
[pid=376] ppid=375 vsize=1676 CPUtime=0
/proc/376/stat : 376 (sh) S 375 376 4159 34819 4229 4202496 224 175 0 0 0 0 0 0 25 0 1 0 884544878 1716224 129 1283457024 134512640 134594024 4287152832 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/376/statm: 419 129 112 20 0 45 0
[pid=378] ppid=376 vsize=8348 CPUtime=0.04
/proc/378/stat : 378 (apt-pbo) S 376 376 4159 34819 4229 4202496 1608 412 0 0 4 0 0 0 25 0 1 0 884544878 8548352 1421 1283457024 134512640 135744540 4290968976 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/378/statm: 2087 1421 646 301 0 820 0
[pid=381] ppid=378 vsize=8508 CPUtime=0.25
/proc/381/stat : 381 (cudftodeb.nativ) R 378 376 4159 34819 4229 4202496 1784 0 0 0 24 1 0 0 25 0 1 0 884544884 8712192 1703 1283457024 134512640 135029684 4290454896 18446744073709551615 134555980 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/381/statm: 2127 1703 247 127 0 1510 0
Current children cumulated CPU time (s) 0.29
Current children cumulated vsize (KiB) 18532

[startup+0.409651 s]
/proc/loadavg: 1.02 1.00 0.99 3/46 381
/proc/meminfo: memFree=783396/1048576 swapFree=2077628/2097144
[pid=376] ppid=375 vsize=1676 CPUtime=0
/proc/376/stat : 376 (sh) S 375 376 4159 34819 4229 4202496 224 175 0 0 0 0 0 0 25 0 1 0 884544878 1716224 129 1283457024 134512640 134594024 4287152832 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/376/statm: 419 129 112 20 0 45 0
[pid=378] ppid=376 vsize=8348 CPUtime=0.04
/proc/378/stat : 378 (apt-pbo) S 376 376 4159 34819 4229 4202496 1608 412 0 0 4 0 0 0 25 0 1 0 884544878 8548352 1421 1283457024 134512640 135744540 4290968976 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/378/statm: 2087 1421 646 301 0 820 0
[pid=381] ppid=378 vsize=10524 CPUtime=0.35
/proc/381/stat : 381 (cudftodeb.nativ) R 378 376 4159 34819 4229 4202496 2320 0 0 0 34 1 0 0 25 0 1 0 884544884 10776576 2239 1283457024 134512640 135029684 4290454896 18446744073709551615 134969984 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/381/statm: 2631 2239 247 127 0 2014 0
Current children cumulated CPU time (s) 0.39
Current children cumulated vsize (KiB) 20548

[startup+0.709711 s]
/proc/loadavg: 1.02 1.00 0.99 3/46 381
/proc/meminfo: memFree=783396/1048576 swapFree=2077628/2097144
[pid=376] ppid=375 vsize=1676 CPUtime=0
/proc/376/stat : 376 (sh) S 375 376 4159 34819 4229 4202496 224 175 0 0 0 0 0 0 25 0 1 0 884544878 1716224 129 1283457024 134512640 134594024 4287152832 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/376/statm: 419 129 112 20 0 45 0
[pid=378] ppid=376 vsize=8348 CPUtime=0.04
/proc/378/stat : 378 (apt-pbo) S 376 376 4159 34819 4229 4202496 1608 412 0 0 4 0 0 0 25 0 1 0 884544878 8548352 1421 1283457024 134512640 135744540 4290968976 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/378/statm: 2087 1421 646 301 0 820 0
[pid=381] ppid=378 vsize=17076 CPUtime=0.65
/proc/381/stat : 381 (cudftodeb.nativ) R 378 376 4159 34819 4229 4202496 3860 0 0 0 63 2 0 0 25 0 1 0 884544884 17485824 3779 1283457024 134512640 135029684 4290454896 18446744073709551615 134976140 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/381/statm: 4269 3779 247 127 0 3652 0
Current children cumulated CPU time (s) 0.69
Current children cumulated vsize (KiB) 27100

[startup+1.50989 s]
/proc/loadavg: 1.02 1.00 0.99 2/47 382
/proc/meminfo: memFree=758976/1048576 swapFree=2077628/2097144
[pid=376] ppid=375 vsize=1676 CPUtime=0
/proc/376/stat : 376 (sh) S 375 376 4159 34819 4229 4202496 224 175 0 0 0 0 0 0 25 0 1 0 884544878 1716224 129 1283457024 134512640 134594024 4287152832 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/376/statm: 419 129 112 20 0 45 0
[pid=378] ppid=376 vsize=8348 CPUtime=0.04
/proc/378/stat : 378 (apt-pbo) S 376 376 4159 34819 4229 4202496 1608 412 0 0 4 0 0 0 25 0 1 0 884544878 8548352 1421 1283457024 134512640 135744540 4290968976 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/378/statm: 2087 1421 646 301 0 820 0
[pid=381] ppid=378 vsize=33708 CPUtime=1.45
/proc/381/stat : 381 (cudftodeb.nativ) R 378 376 4159 34819 4229 4202496 8020 0 0 0 141 4 0 0 25 0 1 0 884544884 34516992 7939 1283457024 134512640 135029684 4290454896 18446744073709551615 134984811 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/381/statm: 8427 7939 247 127 0 7810 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 43732

[startup+3.11021 s]
/proc/loadavg: 1.02 1.00 0.99 2/47 382
/proc/meminfo: memFree=735912/1048576 swapFree=2077628/2097144
[pid=376] ppid=375 vsize=1676 CPUtime=0
/proc/376/stat : 376 (sh) S 375 376 4159 34819 4229 4202496 224 175 0 0 0 0 0 0 25 0 1 0 884544878 1716224 129 1283457024 134512640 134594024 4287152832 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/376/statm: 419 129 112 20 0 45 0
[pid=378] ppid=376 vsize=8348 CPUtime=0.04
/proc/378/stat : 378 (apt-pbo) S 376 376 4159 34819 4229 4202496 1608 412 0 0 4 0 0 0 25 0 1 0 884544878 8548352 1421 1283457024 134512640 135744540 4290968976 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/378/statm: 2087 1421 646 301 0 820 0
[pid=381] ppid=378 vsize=55380 CPUtime=3.05
/proc/381/stat : 381 (cudftodeb.nativ) R 378 376 4159 34819 4229 4202496 13501 0 0 0 258 47 0 0 25 0 1 0 884544884 56709120 13420 1283457024 134512640 135029684 4290454896 18446744073709551615 134887043 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/381/statm: 13845 13420 258 127 0 13228 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 65404

[startup+6.30703 s]
/proc/loadavg: 1.02 1.00 0.99 1/48 390
/proc/meminfo: memFree=742944/1048576 swapFree=2077628/2097144
[pid=376] ppid=375 vsize=1676 CPUtime=0
/proc/376/stat : 376 (sh) S 375 376 4159 34819 4229 4202496 224 175 0 0 0 0 0 0 25 0 1 0 884544878 1716224 129 1283457024 134512640 134594024 4287152832 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/376/statm: 419 129 112 20 0 45 0
[pid=378] ppid=376 vsize=23284 CPUtime=4.87
/proc/378/stat : 378 (apt-pbo) S 376 376 4159 34819 4229 4202496 5891 21197 0 177 16 5 382 84 18 0 1 0 884544878 23842816 5031 1283457024 134512640 135744540 4290968976 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/378/statm: 5821 5031 3682 301 0 1401 0
Current children cumulated CPU time (s) 4.87
Current children cumulated vsize (KiB) 24960
heavy processes:

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

[startup+6.50706 s]
/proc/loadavg: 1.02 1.00 0.99 2/48 395
/proc/meminfo: memFree=738480/1048576 swapFree=2077628/2097144
[pid=376] ppid=375 vsize=1676 CPUtime=0
/proc/376/stat : 376 (sh) S 375 376 4159 34819 4229 4202496 224 175 0 0 0 0 0 0 25 0 1 0 884544878 1716224 129 1283457024 134512640 134594024 4287152832 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/376/statm: 419 129 112 20 0 45 0
[pid=378] ppid=376 vsize=23284 CPUtime=4.9
/proc/378/stat : 378 (apt-pbo) S 376 376 4159 34819 4229 4202496 5891 21197 0 177 19 5 382 84 18 0 1 0 884544878 23842816 5031 1283457024 134512640 135744540 4290968976 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/378/statm: 5821 5031 3682 301 0 1401 0
[pid=392] ppid=378 vsize=2580 CPUtime=0.01
/proc/392/stat : 392 (apt-get.sh) S 378 376 4159 34819 4229 4202496 488 486 0 0 1 0 0 0 20 0 1 0 884545466 2641920 277 1283457024 134512640 135304128 4289409792 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/392/statm: 645 277 235 194 0 31 0
[pid=395] ppid=392 vsize=18512 CPUtime=0.56
/proc/395/stat : 395 (apt-get) R 392 376 4159 34819 4229 4202496 4045 0 0 0 46 10 0 0 25 0 1 0 884545466 18956288 3933 1283457024 134512640 134649604 4293631792 18446744073709551615 4156606346 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/395/statm: 4628 3933 3380 34 0 565 0
Current children cumulated CPU time (s) 5.47
Current children cumulated vsize (KiB) 46052

[startup+6.90713 s]
/proc/loadavg: 1.02 1.00 0.99 2/48 395
/proc/meminfo: memFree=737984/1048576 swapFree=2077628/2097144
[pid=376] ppid=375 vsize=1676 CPUtime=0
/proc/376/stat : 376 (sh) S 375 376 4159 34819 4229 4202496 224 175 0 0 0 0 0 0 25 0 1 0 884544878 1716224 129 1283457024 134512640 134594024 4287152832 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/376/statm: 419 129 112 20 0 45 0
[pid=378] ppid=376 vsize=23284 CPUtime=4.96
/proc/378/stat : 378 (apt-pbo) S 376 376 4159 34819 4229 4202496 5891 21197 0 177 22 8 382 84 18 0 1 0 884544878 23842816 5031 1283457024 134512640 135744540 4290968976 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/378/statm: 5821 5031 3682 301 0 1401 0
[pid=392] ppid=378 vsize=2580 CPUtime=0.01
/proc/392/stat : 392 (apt-get.sh) S 378 376 4159 34819 4229 4202496 488 486 0 0 1 0 0 0 20 0 1 0 884545466 2641920 277 1283457024 134512640 135304128 4289409792 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/392/statm: 645 277 235 194 0 31 0
[pid=395] ppid=392 vsize=18512 CPUtime=0.88
/proc/395/stat : 395 (apt-get) R 392 376 4159 34819 4229 4202496 4058 0 0 0 70 18 0 0 25 0 1 0 884545466 18956288 3946 1283457024 134512640 134649604 4293631792 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/395/statm: 4628 3946 3380 34 0 565 0
Current children cumulated CPU time (s) 5.85
Current children cumulated vsize (KiB) 46052

[startup+7.00717 s]
/proc/loadavg: 1.02 1.00 0.99 2/48 395
/proc/meminfo: memFree=737984/1048576 swapFree=2077628/2097144
[pid=376] ppid=375 vsize=1676 CPUtime=0
/proc/376/stat : 376 (sh) S 375 376 4159 34819 4229 4202496 224 175 0 0 0 0 0 0 25 0 1 0 884544878 1716224 129 1283457024 134512640 134594024 4287152832 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/376/statm: 419 129 112 20 0 45 0
[pid=378] ppid=376 vsize=23284 CPUtime=4.96
/proc/378/stat : 378 (apt-pbo) S 376 376 4159 34819 4229 4202496 5891 21197 0 177 22 8 382 84 18 0 1 0 884544878 23842816 5031 1283457024 134512640 135744540 4290968976 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/378/statm: 5821 5031 3682 301 0 1401 0
[pid=392] ppid=378 vsize=2580 CPUtime=0.01
/proc/392/stat : 392 (apt-get.sh) S 378 376 4159 34819 4229 4202496 488 486 0 0 1 0 0 0 20 0 1 0 884545466 2641920 277 1283457024 134512640 135304128 4289409792 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/392/statm: 645 277 235 194 0 31 0
[pid=395] ppid=392 vsize=18512 CPUtime=0.98
/proc/395/stat : 395 (apt-get) R 392 376 4159 34819 4229 4202496 4060 0 0 0 74 24 0 0 25 0 1 0 884545466 18956288 3948 1283457024 134512640 134649604 4293631792 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/395/statm: 4628 3948 3381 34 0 565 0
Current children cumulated CPU time (s) 5.95
Current children cumulated vsize (KiB) 46052

Child status: 0
Real time (s): 7.06471
CPU time (s): 6.00437
CPU user time (s): 4.8243
CPU system time (s): 1.18007
CPU usage (%): 84.9911
Max. virtual memory (cumulated for all children) (KiB): 65404

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.8243
system time used= 1.18007
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 33196
page faults= 177
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 27314
involuntary context switches= 27291

runsolver used 0 second user time and 0 second system time

The end