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/201108241238/aspcud-trendy-1.5/3e4f8550-0b33-11df-942d-00163e1d94dc.cudf.dudf-real.log.runsolver ./aspcud-trendy-1.5 /home/misc2010/data/2011/dudf-real//3e4f8550-0b33-11df-942d-00163e1d94dc.cudf /home/misc2010/tmp/201108241238/aspcud-trendy-1.5/3e4f8550-0b33-11df-942d-00163e1d94dc.cudf.dudf-real.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.25 1.12 1.03 5/36 20481
/proc/meminfo: memFree=444068/1048576 swapFree=0/0
[pid=20478] ppid=20477 vsize=2584 CPUtime=0
/proc/20478/stat : 20478 (aspcud-trendy-1) S 20477 20478 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 4596237 2646016 279 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/20478/statm: 646 279 234 194 0 33 0
[pid=20479] ppid=20478 vsize=2584 CPUtime=0
/proc/20479/stat : 20479 (aspcud-trendy-1) S 20478 20478 1511 34817 1511 4202560 118 0 0 0 0 0 0 0 18 0 1 0 4596237 2646016 133 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0
/proc/20479/statm: 646 133 87 194 0 33 0
[pid=20480] ppid=20479 vsize=2584 CPUtime=0
/proc/20480/stat : 20480 (aspcud-trendy-1) R 20479 20478 1511 34817 1511 4202560 127 0 0 0 0 0 0 0 25 0 1 0 4596237 2646016 150 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/20480/statm: 646 150 104 194 0 33 0
[pid=20481] ppid=20480 vsize=2584 CPUtime=0
/proc/20481/stat : 20481 (aspcud-trendy-1) R 20480 20478 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 4596237 2646016 46 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/20481/statm: 646 46 0 194 0 33 0

[startup+0.135452 s]
/proc/loadavg: 1.25 1.12 1.03 5/36 20481
/proc/meminfo: memFree=444068/1048576 swapFree=0/0
[pid=20478] ppid=20477 vsize=2592 CPUtime=0.01
/proc/20478/stat : 20478 (aspcud-trendy-1) S 20477 20478 1511 34817 1511 4202496 616 2232 0 0 0 0 0 1 25 0 1 0 4596237 2654208 298 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20478/statm: 648 298 251 194 0 35 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2592

[startup+0.205469 s]
/proc/loadavg: 1.25 1.12 1.03 5/36 20481
/proc/meminfo: memFree=444068/1048576 swapFree=0/0
[pid=20478] ppid=20477 vsize=2592 CPUtime=0.01
/proc/20478/stat : 20478 (aspcud-trendy-1) S 20477 20478 1511 34817 1511 4202496 616 2232 0 0 0 0 0 1 25 0 1 0 4596237 2654208 298 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20478/statm: 648 298 251 194 0 35 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2592

[startup+0.305485 s]
/proc/loadavg: 1.25 1.12 1.03 5/36 20481
/proc/meminfo: memFree=444068/1048576 swapFree=0/0
[pid=20478] ppid=20477 vsize=2592 CPUtime=0.01
/proc/20478/stat : 20478 (aspcud-trendy-1) S 20477 20478 1511 34817 1511 4202496 616 2232 0 0 0 0 0 1 25 0 1 0 4596237 2654208 298 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20478/statm: 648 298 251 194 0 35 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2592

[startup+0.705548 s]
/proc/loadavg: 1.25 1.12 1.03 5/36 20481
/proc/meminfo: memFree=444068/1048576 swapFree=0/0
[pid=20478] ppid=20477 vsize=2592 CPUtime=0.01
/proc/20478/stat : 20478 (aspcud-trendy-1) S 20477 20478 1511 34817 1511 4202496 616 2232 0 0 0 0 0 1 25 0 1 0 4596237 2654208 298 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20478/statm: 648 298 251 194 0 35 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2592

[startup+1.50569 s]
/proc/loadavg: 1.23 1.11 1.03 2/37 20492
/proc/meminfo: memFree=422968/1048576 swapFree=0/0
[pid=20478] ppid=20477 vsize=2592 CPUtime=0.01
/proc/20478/stat : 20478 (aspcud-trendy-1) S 20477 20478 1511 34817 1511 4202496 616 2232 0 0 0 0 0 1 25 0 1 0 4596237 2654208 298 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20478/statm: 648 298 251 194 0 35 0
[pid=20490] ppid=20478 vsize=1924 CPUtime=0
/proc/20490/stat : 20490 (clasp) S 20478 20478 1511 34817 1511 4202496 291 0 0 0 0 0 0 0 25 0 1 0 4596238 1970176 159 1283457024 134512640 136285277 4293720240 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/20490/statm: 481 159 144 433 0 46 0
[pid=20491] ppid=20478 vsize=2588 CPUtime=0
/proc/20491/stat : 20491 (gringo) S 20478 20478 1511 34817 1511 4202496 404 0 0 0 0 0 0 0 25 0 1 0 4596238 2650112 272 1283457024 134512640 136933539 4290080192 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/20491/statm: 647 272 242 592 0 52 0
[pid=20492] ppid=20478 vsize=27108 CPUtime=1.49
/proc/20492/stat : 20492 (cudf2lp) R 20478 20478 1511 34817 1511 4202496 8095 0 0 0 145 4 0 0 25 0 1 0 4596238 27758592 6497 1283457024 134512640 135786343 4288726160 18446744073709551615 134614162 0 0 6 0 0 0 0 17 0 0 0 0
/proc/20492/statm: 6777 6497 126 311 0 6464 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 34212

[startup+3.10598 s]
/proc/loadavg: 1.23 1.11 1.03 3/37 20492
/proc/meminfo: memFree=394944/1048576 swapFree=0/0
[pid=20478] ppid=20477 vsize=2592 CPUtime=2.26
/proc/20478/stat : 20478 (aspcud-trendy-1) S 20477 20478 1511 34817 1511 4202496 617 17482 0 0 0 0 213 13 18 0 1 0 4596237 2654208 298 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20478/statm: 648 298 251 194 0 35 0
[pid=20490] ppid=20478 vsize=18576 CPUtime=0.07
/proc/20490/stat : 20490 (clasp) R 20478 20478 1511 34817 1511 4202496 5064 0 0 0 7 0 0 0 18 0 1 0 4596238 19021824 4274 1283457024 134512640 136285277 4293720240 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/20490/statm: 4644 4274 177 433 0 4209 0
[pid=20491] ppid=20478 vsize=30824 CPUtime=0.76
/proc/20491/stat : 20491 (gringo) R 20478 20478 1511 34817 1511 4202496 8403 0 0 0 72 4 0 0 18 0 1 0 4596238 31563776 6322 1283457024 134512640 136933539 4290080192 18446744073709551615 136204839 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20491/statm: 7706 6322 253 592 0 7111 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 51992

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

[startup+3.206 s]
/proc/loadavg: 1.23 1.11 1.03 3/37 20492
/proc/meminfo: memFree=394944/1048576 swapFree=0/0
[pid=20478] ppid=20477 vsize=2592 CPUtime=2.26
/proc/20478/stat : 20478 (aspcud-trendy-1) S 20477 20478 1511 34817 1511 4202496 617 17482 0 0 0 0 213 13 18 0 1 0 4596237 2654208 298 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20478/statm: 648 298 251 194 0 35 0
[pid=20490] ppid=20478 vsize=20932 CPUtime=0.09
/proc/20490/stat : 20490 (clasp) R 20478 20478 1511 34817 1511 4202496 5623 0 0 0 9 0 0 0 18 0 1 0 4596238 21434368 4833 1283457024 134512640 136285277 4293720240 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/20490/statm: 5233 4833 177 433 0 4798 0
[pid=20491] ppid=20478 vsize=32784 CPUtime=0.84
/proc/20491/stat : 20491 (gringo) R 20478 20478 1511 34817 1511 4202496 8869 0 0 0 80 4 0 0 18 0 1 0 4596238 33570816 6788 1283457024 134512640 136933539 4290080192 18446744073709551615 135650632 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/20491/statm: 8196 6788 253 592 0 7601 0
Current children cumulated CPU time (s) 3.19
Current children cumulated vsize (KiB) 56308

[startup+4.00622 s]
/proc/loadavg: 1.23 1.11 1.03 2/36 20492
/proc/meminfo: memFree=404012/1048576 swapFree=0/0
[pid=20478] ppid=20477 vsize=2592 CPUtime=3.18
/proc/20478/stat : 20478 (aspcud-trendy-1) S 20477 20478 1511 34817 1511 4202496 617 27117 0 0 0 0 301 17 15 0 1 0 4596237 2654208 298 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20478/statm: 648 298 251 194 0 35 0
[pid=20490] ppid=20478 vsize=29456 CPUtime=0.81
/proc/20490/stat : 20490 (clasp) R 20478 20478 1511 34817 1511 4202496 8651 0 0 0 80 1 0 0 18 0 1 0 4596238 30162944 7105 1283457024 134512640 136285277 4293720240 18446744073709551615 134893169 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/20490/statm: 7364 7105 234 433 0 6929 0
Current children cumulated CPU time (s) 3.99
Current children cumulated vsize (KiB) 32048

[startup+4.20628 s]
/proc/loadavg: 1.23 1.11 1.03 2/36 20492
/proc/meminfo: memFree=404012/1048576 swapFree=0/0
[pid=20478] ppid=20477 vsize=2592 CPUtime=3.18
/proc/20478/stat : 20478 (aspcud-trendy-1) S 20477 20478 1511 34817 1511 4202496 617 27117 0 0 0 0 301 17 15 0 1 0 4596237 2654208 298 1283457024 134512640 135304128 4292792288 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/20478/statm: 648 298 251 194 0 35 0
[pid=20490] ppid=20478 vsize=29456 CPUtime=1.01
/proc/20490/stat : 20490 (clasp) R 20478 20478 1511 34817 1511 4202496 8651 0 0 0 100 1 0 0 19 0 1 0 4596238 30162944 7105 1283457024 134512640 136285277 4293720240 18446744073709551615 134893162 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/20490/statm: 7364 7105 234 433 0 6929 0
Current children cumulated CPU time (s) 4.19
Current children cumulated vsize (KiB) 32048

Child status: 0
Real time (s): 4.281
CPU time (s): 4.28027
CPU user time (s): 4.07225
CPU system time (s): 0.208013
CPU usage (%): 99.9829
Max. virtual memory (cumulated for all children) (KiB): 68312

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.07225
system time used= 0.208013
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 39924
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= 1150
involuntary context switches= 844

runsolver used 0 second user time and 0 second system time

The end