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/201012091434/cudf2msu4user-1.0/rand49d73b.cudf.difficult.log.runsolver ./cudf2msu4user-1.0 /home/misc2010/data/2010/difficult//rand49d73b.cudf /home/misc2010/tmp/201012091434/cudf2msu4user-1.0/rand49d73b.cudf.difficult.result -changed,-removed,-unmet_recommends,-new 

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.17 1.10 1.02 5/39 28627
/proc/meminfo: memFree=408468/1048576 swapFree=2095372/2097144
[pid=28626] ppid=28625 vsize=2568 CPUtime=0
/proc/28626/stat : 28626 (cudf2msu4user-1) R 28625 28626 25521 34816 25544 4202496 361 0 0 0 0 0 0 0 25 0 1 0 900118303 2629632 275 1283457024 134512640 135304128 4290391440 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/28626/statm: 642 275 236 194 0 28 0
[pid=28627] ppid=28626 vsize=2568 CPUtime=0
/proc/28627/stat : 28627 (cudf2msu4user-1) R 28626 28626 25521 34816 25544 4202560 0 0 0 0 0 0 0 0 25 0 1 0 900118303 2629632 39 1283457024 134512640 135304128 4290391440 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/28627/statm: 642 39 0 194 0 28 0

[startup+0.14571 s]
/proc/loadavg: 1.17 1.10 1.02 5/39 28627
/proc/meminfo: memFree=408468/1048576 swapFree=2095372/2097144
[pid=28626] ppid=28625 vsize=2568 CPUtime=0
/proc/28626/stat : 28626 (cudf2msu4user-1) S 28625 28626 25521 34816 25544 4202496 379 0 0 0 0 0 0 0 25 0 1 0 900118303 2629632 276 1283457024 134512640 135304128 4290391440 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28626/statm: 642 276 237 194 0 28 0
[pid=28627] ppid=28626 vsize=8104 CPUtime=0.14
/proc/28627/stat : 28627 (cudf_msu32) R 28626 28626 25521 34816 25544 4202496 1776 0 0 0 13 1 0 0 25 0 1 0 900118303 8298496 1715 1283457024 134512640 136120023 4287886160 18446744073709551615 134711990 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/28627/statm: 2026 1715 141 393 0 1631 0
Current children cumulated CPU time (s) 0.14
Current children cumulated vsize (KiB) 10672

[startup+0.20572 s]
/proc/loadavg: 1.17 1.10 1.02 5/39 28627
/proc/meminfo: memFree=408468/1048576 swapFree=2095372/2097144
[pid=28626] ppid=28625 vsize=2568 CPUtime=0
/proc/28626/stat : 28626 (cudf2msu4user-1) S 28625 28626 25521 34816 25544 4202496 379 0 0 0 0 0 0 0 25 0 1 0 900118303 2629632 276 1283457024 134512640 135304128 4290391440 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28626/statm: 642 276 237 194 0 28 0
[pid=28627] ppid=28626 vsize=10236 CPUtime=0.2
/proc/28627/stat : 28627 (cudf_msu32) R 28626 28626 25521 34816 25544 4202496 2328 0 0 0 19 1 0 0 25 0 1 0 900118303 10481664 2267 1283457024 134512640 136120023 4287886160 18446744073709551615 134732295 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/28627/statm: 2559 2267 141 393 0 2164 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 12804

[startup+0.305738 s]
/proc/loadavg: 1.17 1.10 1.02 5/39 28627
/proc/meminfo: memFree=408468/1048576 swapFree=2095372/2097144
[pid=28626] ppid=28625 vsize=2568 CPUtime=0
/proc/28626/stat : 28626 (cudf2msu4user-1) S 28625 28626 25521 34816 25544 4202496 379 0 0 0 0 0 0 0 25 0 1 0 900118303 2629632 276 1283457024 134512640 135304128 4290391440 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28626/statm: 642 276 237 194 0 28 0
[pid=28627] ppid=28626 vsize=13864 CPUtime=0.3
/proc/28627/stat : 28627 (cudf_msu32) R 28626 28626 25521 34816 25544 4202496 3228 0 0 0 29 1 0 0 25 0 1 0 900118303 14196736 3167 1283457024 134512640 136120023 4287886160 18446744073709551615 134711963 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/28627/statm: 3466 3167 142 393 0 3071 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 16432

[startup+0.705849 s]
/proc/loadavg: 1.17 1.10 1.02 5/39 28627
/proc/meminfo: memFree=408468/1048576 swapFree=2095372/2097144
[pid=28626] ppid=28625 vsize=2568 CPUtime=0
/proc/28626/stat : 28626 (cudf2msu4user-1) S 28625 28626 25521 34816 25544 4202496 379 0 0 0 0 0 0 0 25 0 1 0 900118303 2629632 276 1283457024 134512640 135304128 4290391440 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28626/statm: 642 276 237 194 0 28 0
[pid=28627] ppid=28626 vsize=25676 CPUtime=0.7
/proc/28627/stat : 28627 (cudf_msu32) R 28626 28626 25521 34816 25544 4202496 6188 0 0 0 68 2 0 0 25 0 1 0 900118303 26292224 6127 1283457024 134512640 136120023 4287886160 18446744073709551615 134712066 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/28627/statm: 6419 6127 142 393 0 6024 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 28244

[startup+1.50609 s]
/proc/loadavg: 1.17 1.10 1.02 2/40 28628
/proc/meminfo: memFree=353764/1048576 swapFree=2095372/2097144
[pid=28626] ppid=28625 vsize=2568 CPUtime=0
/proc/28626/stat : 28626 (cudf2msu4user-1) S 28625 28626 25521 34816 25544 4202496 379 0 0 0 0 0 0 0 25 0 1 0 900118303 2629632 276 1283457024 134512640 135304128 4290391440 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28626/statm: 642 276 237 194 0 28 0
[pid=28627] ppid=28626 vsize=56600 CPUtime=1.5
/proc/28627/stat : 28627 (cudf_msu32) R 28626 28626 25521 34816 25544 4202496 14043 0 0 0 146 4 0 0 25 0 1 0 900118303 57958400 13871 1283457024 134512640 136120023 4287886160 18446744073709551615 134831643 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/28627/statm: 14150 13871 181 393 0 13755 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 59168

[startup+3.1066 s]
/proc/loadavg: 1.17 1.10 1.02 2/40 28628
/proc/meminfo: memFree=353640/1048576 swapFree=2095372/2097144
[pid=28626] ppid=28625 vsize=2568 CPUtime=0
/proc/28626/stat : 28626 (cudf2msu4user-1) S 28625 28626 25521 34816 25544 4202496 379 0 0 0 0 0 0 0 25 0 1 0 900118303 2629632 276 1283457024 134512640 135304128 4290391440 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28626/statm: 642 276 237 194 0 28 0
[pid=28627] ppid=28626 vsize=56600 CPUtime=3.1
/proc/28627/stat : 28627 (cudf_msu32) R 28626 28626 25521 34816 25544 4202496 14043 0 0 0 306 4 0 0 25 0 1 0 900118303 57958400 13871 1283457024 134512640 136120023 4287886160 18446744073709551615 134831666 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/28627/statm: 14150 13871 181 393 0 13755 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 59168

[startup+6.30744 s]
/proc/loadavg: 1.15 1.09 1.02 2/40 28628
/proc/meminfo: memFree=352152/1048576 swapFree=2095372/2097144
[pid=28626] ppid=28625 vsize=2568 CPUtime=0
/proc/28626/stat : 28626 (cudf2msu4user-1) S 28625 28626 25521 34816 25544 4202496 379 0 0 0 0 0 0 0 25 0 1 0 900118303 2629632 276 1283457024 134512640 135304128 4290391440 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28626/statm: 642 276 237 194 0 28 0
[pid=28627] ppid=28626 vsize=57932 CPUtime=6.3
/proc/28627/stat : 28627 (cudf_msu32) R 28626 28626 25521 34816 25544 4202496 14490 0 0 0 626 4 0 0 25 0 1 0 900118303 59322368 14236 1283457024 134512640 136120023 4287886160 18446744073709551615 134867714 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/28627/statm: 14483 14236 185 393 0 14088 0
Current children cumulated CPU time (s) 6.3
Current children cumulated vsize (KiB) 60500

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

[startup+6.30744 s]
/proc/loadavg: 1.15 1.09 1.02 2/40 28628
/proc/meminfo: memFree=352152/1048576 swapFree=2095372/2097144
[pid=28626] ppid=28625 vsize=2568 CPUtime=0
/proc/28626/stat : 28626 (cudf2msu4user-1) S 28625 28626 25521 34816 25544 4202496 379 0 0 0 0 0 0 0 25 0 1 0 900118303 2629632 276 1283457024 134512640 135304128 4290391440 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28626/statm: 642 276 237 194 0 28 0
[pid=28627] ppid=28626 vsize=57932 CPUtime=6.3
/proc/28627/stat : 28627 (cudf_msu32) R 28626 28626 25521 34816 25544 4202496 14490 0 0 0 626 4 0 0 25 0 1 0 900118303 59322368 14236 1283457024 134512640 136120023 4287886160 18446744073709551615 134867714 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/28627/statm: 14483 14236 185 393 0 14088 0
Current children cumulated CPU time (s) 6.3
Current children cumulated vsize (KiB) 60500

Child status: 0
Real time (s): 6.39654
CPU time (s): 6.3884
CPU user time (s): 6.3404
CPU system time (s): 0.048003
CPU usage (%): 99.8728
Max. virtual memory (cumulated for all children) (KiB): 60500

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.3404
system time used= 0.048003
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 14895
page faults= 0
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 3
involuntary context switches= 122

runsolver used 0 second user time and 0 second system time

The end