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/201012091704/cudf2pbo4user-1.0/randa223c3.cudf.impossible.log.runsolver ./cudf2pbo4user-1.0 /home/misc2010/data/2010/impossible//randa223c3.cudf /home/misc2010/tmp/201012091704/cudf2pbo4user-1.0/randa223c3.cudf.impossible.result -changed,-notuptodate,-removed,-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.10 1.05 1.00 3/39 7876
/proc/meminfo: memFree=411844/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=0
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 384 0 0 0 0 0 0 0 18 0 1 0 901797571 2633728 281 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 281 240 194 0 29 0
[pid=7876] ppid=7875 vsize=2572 CPUtime=0
/proc/7876/stat : 7876 (cudf2pbo4user-1) D 7875 7875 25521 34816 2180 4202560 80 0 0 0 0 0 0 0 18 0 1 0 901797571 2633728 104 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 0 0 0 18446744071564252162 0 0 17 0 0 0 0
/proc/7876/statm: 643 104 62 194 0 29 0

[startup+0.170952 s]
/proc/loadavg: 1.10 1.05 1.00 3/39 7876
/proc/meminfo: memFree=411844/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=0
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 384 0 0 0 0 0 0 0 18 0 1 0 901797571 2633728 281 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 281 240 194 0 29 0
[pid=7876] ppid=7875 vsize=8440 CPUtime=0.15
/proc/7876/stat : 7876 (cudf_msu32) R 7875 7875 25521 34816 2180 4202496 1928 0 0 0 14 1 0 0 25 0 1 0 901797571 8642560 1820 1283457024 134512640 136125367 4292767824 18446744073709551615 134717747 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/7876/statm: 2110 1820 146 394 0 1714 0
Current children cumulated CPU time (s) 0.15
Current children cumulated vsize (KiB) 11012

[startup+0.210962 s]
/proc/loadavg: 1.10 1.05 1.00 3/39 7876
/proc/meminfo: memFree=411844/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=0
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 384 0 0 0 0 0 0 0 18 0 1 0 901797571 2633728 281 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 281 240 194 0 29 0
[pid=7876] ppid=7875 vsize=9892 CPUtime=0.19
/proc/7876/stat : 7876 (cudf_msu32) R 7875 7875 25521 34816 2180 4202496 2279 0 0 0 17 2 0 0 25 0 1 0 901797571 10129408 2171 1283457024 134512640 136125367 4292767824 18446744073709551615 134719238 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/7876/statm: 2473 2171 146 394 0 2077 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 12464

[startup+0.31099 s]
/proc/loadavg: 1.10 1.05 1.00 3/39 7876
/proc/meminfo: memFree=411844/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=0
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 384 0 0 0 0 0 0 0 18 0 1 0 901797571 2633728 281 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 281 240 194 0 29 0
[pid=7876] ppid=7875 vsize=13348 CPUtime=0.29
/proc/7876/stat : 7876 (cudf_msu32) R 7875 7875 25521 34816 2180 4202496 3161 0 0 0 26 3 0 0 25 0 1 0 901797571 13668352 3053 1283457024 134512640 136125367 4292767824 18446744073709551615 134718296 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/7876/statm: 3337 3053 147 394 0 2941 0
Current children cumulated CPU time (s) 0.29
Current children cumulated vsize (KiB) 15920

[startup+0.711059 s]
/proc/loadavg: 1.10 1.05 1.00 3/39 7876
/proc/meminfo: memFree=411844/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=0
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 384 0 0 0 0 0 0 0 18 0 1 0 901797571 2633728 281 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 281 240 194 0 29 0
[pid=7876] ppid=7875 vsize=25424 CPUtime=0.69
/proc/7876/stat : 7876 (cudf_msu32) R 7875 7875 25521 34816 2180 4202496 6176 0 0 0 63 6 0 0 25 0 1 0 901797571 26034176 6068 1283457024 134512640 136125367 4292767824 18446744073709551615 135549817 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/7876/statm: 6356 6068 147 394 0 5960 0
Current children cumulated CPU time (s) 0.69
Current children cumulated vsize (KiB) 27996

[startup+1.51121 s]
/proc/loadavg: 1.10 1.05 1.00 2/40 7877
/proc/meminfo: memFree=377600/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=0
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 384 0 0 0 0 0 0 0 18 0 1 0 901797571 2633728 281 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 281 240 194 0 29 0
[pid=7876] ppid=7875 vsize=46088 CPUtime=1.49
/proc/7876/stat : 7876 (cudf_msu32) R 7875 7875 25521 34816 2180 4202496 11392 0 0 0 142 7 0 0 25 0 1 0 901797571 47194112 11235 1283457024 134512640 136125367 4292767824 18446744073709551615 135594622 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/7876/statm: 11522 11235 157 394 0 11126 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 48660

[startup+3.10214 s]
/proc/loadavg: 1.10 1.05 1.00 2/40 7877
/proc/meminfo: memFree=348956/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=2.45
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 402 15783 0 0 0 0 206 39 20 0 1 0 901797571 2633728 282 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 282 241 194 0 29 0
Current children cumulated CPU time (s) 2.45
Current children cumulated vsize (KiB) 2572
heavy processes:

[startup+6.30296 s]
/proc/loadavg: 1.17 1.07 1.01 2/40 7878
/proc/meminfo: memFree=386776/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=2.45
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 402 15783 0 0 0 0 206 39 20 0 1 0 901797571 2633728 282 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 282 241 194 0 29 0
[pid=7878] ppid=7875 vsize=23604 CPUtime=3.78
/proc/7878/stat : 7878 (bmo-pblex32) R 7875 7875 25521 34816 2180 4202496 6259 0 0 0 302 76 0 0 25 0 1 0 901797818 24170496 5551 1283457024 134512640 135887319 4288890048 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/7878/statm: 5901 5551 138 336 0 5563 0
Current children cumulated CPU time (s) 6.23
Current children cumulated vsize (KiB) 26176

[startup+12.7048 s]
/proc/loadavg: 1.16 1.06 1.00 2/40 7878
/proc/meminfo: memFree=371028/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=2.45
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 402 15783 0 0 0 0 206 39 20 0 1 0 901797571 2633728 282 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 282 241 194 0 29 0
[pid=7878] ppid=7875 vsize=40364 CPUtime=10.18
/proc/7878/stat : 7878 (bmo-pblex32) R 7875 7875 25521 34816 2180 4202496 12570 0 0 0 851 167 0 0 25 0 1 0 901797818 41332736 9762 1283457024 134512640 135887319 4288890048 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/7878/statm: 10091 9762 144 336 0 9753 0
Current children cumulated CPU time (s) 12.63
Current children cumulated vsize (KiB) 42936

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

[startup+12.8048 s]
/proc/loadavg: 1.16 1.06 1.00 2/40 7878
/proc/meminfo: memFree=371028/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=2.45
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 402 15783 0 0 0 0 206 39 20 0 1 0 901797571 2633728 282 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 282 241 194 0 29 0
[pid=7878] ppid=7875 vsize=40364 CPUtime=10.28
/proc/7878/stat : 7878 (bmo-pblex32) R 7875 7875 25521 34816 2180 4202496 12573 0 0 0 859 169 0 0 25 0 1 0 901797818 41332736 9765 1283457024 134512640 135887319 4288890048 18446744073709551615 134598400 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/7878/statm: 10091 9765 144 336 0 9753 0
Current children cumulated CPU time (s) 12.73
Current children cumulated vsize (KiB) 42936

[startup+13.6052 s]
/proc/loadavg: 1.14 1.06 1.00 2/40 7878
/proc/meminfo: memFree=369540/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=2.45
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 402 15783 0 0 0 0 206 39 20 0 1 0 901797571 2633728 282 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 282 241 194 0 29 0
[pid=7878] ppid=7875 vsize=48076 CPUtime=11.07
/proc/7878/stat : 7878 (bmo-pblex32) R 7875 7875 25521 34816 2180 4202496 15471 0 0 0 929 178 0 0 25 0 1 0 901797818 49229824 11700 1283457024 134512640 135887319 4288890048 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/7878/statm: 12019 11700 144 336 0 11681 0
Current children cumulated CPU time (s) 13.52
Current children cumulated vsize (KiB) 50648

[startup+14.0054 s]
/proc/loadavg: 1.14 1.06 1.00 2/40 7878
/proc/meminfo: memFree=369540/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=2.45
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 402 15783 0 0 0 0 206 39 20 0 1 0 901797571 2633728 282 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 282 241 194 0 29 0
[pid=7878] ppid=7875 vsize=48340 CPUtime=11.47
/proc/7878/stat : 7878 (bmo-pblex32) R 7875 7875 25521 34816 2180 4202496 15522 0 0 0 967 180 0 0 25 0 1 0 901797818 49500160 11751 1283457024 134512640 135887319 4288890048 18446744073709551615 135381649 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/7878/statm: 12085 11751 144 336 0 11747 0
Current children cumulated CPU time (s) 13.92
Current children cumulated vsize (KiB) 50912

[startup+14.4056 s]
/proc/loadavg: 1.14 1.06 1.00 2/40 7878
/proc/meminfo: memFree=361480/1048576 swapFree=2095372/2097144
[pid=7875] ppid=7874 vsize=2572 CPUtime=14.26
/proc/7875/stat : 7875 (cudf2pbo4user-1) S 7874 7875 25521 34816 2180 4202496 435 31715 0 0 0 0 1204 222 21 0 1 0 901797571 2633728 282 1283457024 134512640 135304128 4291126848 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/7875/statm: 643 282 241 194 0 29 0
Current children cumulated CPU time (s) 14.26
Current children cumulated vsize (KiB) 2572

Child status: 0
Real time (s): 14.4089
CPU time (s): 14.3369
CPU user time (s): 12.1088
CPU system time (s): 2.22814
CPU usage (%): 99.5001
Max. virtual memory (cumulated for all children) (KiB): 64992

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 12.1088
system time used= 2.22814
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 33771
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= 22
involuntary context switches= 3276

runsolver used 0 second user time and 0 second system time

The end