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/201103031013/apt-pbo-trendy-1.0.8/140.cudf.caixa.log.runsolver ./apt-pbo-trendy-1.0.8 /home/misc2010/data/misc4/caixa//140.cudf /home/misc2010/tmp/201103031013/apt-pbo-trendy-1.0.8/140.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.81 1.70 1.39 4/34 22161
/proc/meminfo: memFree=322192/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=5464 CPUtime=0.04
/proc/22161/stat : 22161 (apt-pbo) R 22159 22159 29493 34817 29493 4202496 1041 0 0 0 4 0 0 0 25 0 1 0 75833409 5595136 981 1283457024 134512640 135745756 4290524464 18446744073709551615 135277883 0 0 128 0 0 0 0 17 0 0 0 0
/proc/22161/statm: 1366 981 414 302 0 620 0

[startup+0.206551 s]
/proc/loadavg: 1.81 1.70 1.39 4/34 22161
/proc/meminfo: memFree=322192/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=8236 CPUtime=0.04
/proc/22161/stat : 22161 (apt-pbo) S 22159 22159 29493 34817 29493 4202496 1582 411 0 0 4 0 0 0 25 0 1 0 75833409 8433664 1401 1283457024 134512640 135745756 4290524464 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22161/statm: 2059 1401 648 302 0 792 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9912

[startup+0.306579 s]
/proc/loadavg: 1.81 1.70 1.39 4/34 22161
/proc/meminfo: memFree=322192/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=8236 CPUtime=0.04
/proc/22161/stat : 22161 (apt-pbo) S 22159 22159 29493 34817 29493 4202496 1582 411 0 0 4 0 0 0 25 0 1 0 75833409 8433664 1401 1283457024 134512640 135745756 4290524464 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22161/statm: 2059 1401 648 302 0 792 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9912

[startup+0.406782 s]
/proc/loadavg: 1.81 1.70 1.39 4/34 22161
/proc/meminfo: memFree=322192/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=8236 CPUtime=0.04
/proc/22161/stat : 22161 (apt-pbo) S 22159 22159 29493 34817 29493 4202496 1582 411 0 0 4 0 0 0 25 0 1 0 75833409 8433664 1401 1283457024 134512640 135745756 4290524464 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22161/statm: 2059 1401 648 302 0 792 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9912

[startup+0.70669 s]
/proc/loadavg: 1.81 1.70 1.39 4/34 22161
/proc/meminfo: memFree=322192/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=8236 CPUtime=0.04
/proc/22161/stat : 22161 (apt-pbo) S 22159 22159 29493 34817 29493 4202496 1582 411 0 0 4 0 0 0 25 0 1 0 75833409 8433664 1401 1283457024 134512640 135745756 4290524464 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22161/statm: 2059 1401 648 302 0 792 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9912

[startup+1.50692 s]
/proc/loadavg: 1.81 1.70 1.39 2/36 22165
/proc/meminfo: memFree=291912/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=8236 CPUtime=0.04
/proc/22161/stat : 22161 (apt-pbo) S 22159 22159 29493 34817 29493 4202496 1582 411 0 0 4 0 0 0 25 0 1 0 75833409 8433664 1401 1283457024 134512640 135745756 4290524464 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22161/statm: 2059 1401 648 302 0 792 0
[pid=22165] ppid=22161 vsize=37272 CPUtime=1.46
/proc/22165/stat : 22165 (cudftodeb.nativ) R 22161 22159 29493 34817 29493 4202496 8981 0 0 0 144 2 0 0 25 0 1 0 75833415 38166528 8901 1283457024 134512640 135029684 4293488720 18446744073709551615 135011900 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/22165/statm: 9318 8901 246 127 0 8699 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 47184

[startup+3.10737 s]
/proc/loadavg: 1.81 1.70 1.39 2/36 22165
/proc/meminfo: memFree=274180/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=8236 CPUtime=0.04
/proc/22161/stat : 22161 (apt-pbo) S 22159 22159 29493 34817 29493 4202496 1582 411 0 0 4 0 0 0 25 0 1 0 75833409 8433664 1401 1283457024 134512640 135745756 4290524464 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22161/statm: 2059 1401 648 302 0 792 0
[pid=22165] ppid=22161 vsize=66000 CPUtime=3.06
/proc/22165/stat : 22165 (cudftodeb.nativ) R 22161 22159 29493 34817 29493 4202496 16121 0 0 0 280 26 0 0 25 0 1 0 75833415 67584000 16041 1283457024 134512640 135029684 4293488720 18446744073709551615 134967018 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/22165/statm: 16500 16041 258 127 0 15881 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 75912

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

[startup+3.30743 s]
/proc/loadavg: 1.81 1.70 1.39 2/36 22165
/proc/meminfo: memFree=274180/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=8236 CPUtime=0.04
/proc/22161/stat : 22161 (apt-pbo) S 22159 22159 29493 34817 29493 4202496 1582 411 0 0 4 0 0 0 25 0 1 0 75833409 8433664 1401 1283457024 134512640 135745756 4290524464 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22161/statm: 2059 1401 648 302 0 792 0
[pid=22165] ppid=22161 vsize=69024 CPUtime=3.25
/proc/22165/stat : 22165 (cudftodeb.nativ) R 22161 22159 29493 34817 29493 4202496 16871 0 0 0 298 27 0 0 25 0 1 0 75833415 70680576 16791 1283457024 134512640 135029684 4293488720 18446744073709551615 134882792 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/22165/statm: 17256 16791 258 127 0 16637 0
Current children cumulated CPU time (s) 3.29
Current children cumulated vsize (KiB) 78936

[startup+4.10466 s]
/proc/loadavg: 1.75 1.69 1.39 2/36 22165
/proc/meminfo: memFree=248760/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=8236 CPUtime=0.04
/proc/22161/stat : 22161 (apt-pbo) S 22159 22159 29493 34817 29493 4202496 1582 411 0 0 4 0 0 0 25 0 1 0 75833409 8433664 1401 1283457024 134512640 135745756 4290524464 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22161/statm: 2059 1401 648 302 0 792 0
[pid=22165] ppid=22161 vsize=52392 CPUtime=3.97
/proc/22165/stat : 22165 (cudftodeb.nativ) D 22161 22159 29493 34817 29493 4202496 16879 0 0 0 357 40 0 0 25 0 1 0 75833415 53649408 12670 1283457024 134512640 135029684 4293488720 18446744073709551615 4294960130 0 0 0 1024 18446744071564252162 0 0 17 0 0 0 0
/proc/22165/statm: 13098 12670 258 127 0 12479 0
Current children cumulated CPU time (s) 4.01
Current children cumulated vsize (KiB) 62304

[startup+4.91157 s]
/proc/loadavg: 1.75 1.69 1.39 2/36 22165
/proc/meminfo: memFree=260168/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=8236 CPUtime=4.55
/proc/22161/stat : 22161 (apt-pbo) S 22159 22159 29493 34817 29493 4202496 1755 17791 0 0 5 0 396 54 18 0 1 0 75833409 8433664 1427 1283457024 134512640 135745756 4290524464 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/22161/statm: 2059 1427 653 302 0 792 0
Current children cumulated CPU time (s) 4.55
Current children cumulated vsize (KiB) 9912

[startup+5.30469 s]
/proc/loadavg: 1.75 1.69 1.39 2/36 22165
/proc/meminfo: memFree=260168/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=8236 CPUtime=4.55
/proc/22161/stat : 22161 (apt-pbo) S 22159 22159 29493 34817 29493 4202496 1755 17791 0 0 5 0 396 54 18 0 1 0 75833409 8433664 1427 1283457024 134512640 135745756 4290524464 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/22161/statm: 2059 1427 653 302 0 792 0
Current children cumulated CPU time (s) 4.55
Current children cumulated vsize (KiB) 9912

[startup+5.40496 s]
/proc/loadavg: 1.75 1.69 1.39 2/36 22165
/proc/meminfo: memFree=260168/1048576 swapFree=0/0
[pid=22159] ppid=22158 vsize=1676 CPUtime=0
/proc/22159/stat : 22159 (sh) S 22158 22159 29493 34817 29493 4202496 221 176 0 0 0 0 0 0 25 0 1 0 75833409 1716224 129 1283457024 134512640 134593992 4292700176 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22159/statm: 419 129 112 20 0 46 0
[pid=22161] ppid=22159 vsize=57192 CPUtime=4.78
/proc/22161/stat : 22161 (apt-pbo) D 22159 22159 29493 34817 29493 4202496 1886 21035 1 1 5 0 417 56 16 0 1 0 75833409 58564608 1457 1283457024 134512640 135745756 4290524464 18446744073709551615 4294960130 0 0 128 0 18446744071696460772 0 0 17 0 0 0 0
/proc/22161/statm: 14298 1457 680 302 0 823 0
Current children cumulated CPU time (s) 4.78
Current children cumulated vsize (KiB) 58868

Child status: 100
Real time (s): 5.4113
CPU time (s): 4.7923
CPU user time (s): 4.22826
CPU system time (s): 0.564035
CPU usage (%): 88.561
Max. virtual memory (cumulated for all children) (KiB): 78936

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.22826
system time used= 0.564035
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 23517
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= 47
involuntary context switches= 83

runsolver used 0 second user time and 0 second system time

The end