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/e0bd67a6-56d0-11df-b11f-00163e7a6f5e.cudf.dudf-real.log.runsolver ./aspcud-trendy-1.5 /home/misc2010/data/2011/dudf-real//e0bd67a6-56d0-11df-b11f-00163e7a6f5e.cudf /home/misc2010/tmp/201108241238/aspcud-trendy-1.5/e0bd67a6-56d0-11df-b11f-00163e7a6f5e.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.20 1.18 1.12 5/36 633
/proc/meminfo: memFree=302520/1048576 swapFree=0/0
[pid=630] ppid=629 vsize=2592 CPUtime=0
/proc/630/stat : 630 (aspcud-trendy-1) S 629 630 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 5136036 2654208 280 1283457024 134512640 135304128 4290241904 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/630/statm: 648 280 234 194 0 35 0
[pid=631] ppid=630 vsize=2592 CPUtime=0
/proc/631/stat : 631 (aspcud-trendy-1) S 630 630 1511 34817 1511 4202560 118 0 0 0 0 0 0 0 18 0 1 0 5136037 2654208 134 1283457024 134512640 135304128 4290241904 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0
/proc/631/statm: 648 134 87 194 0 35 0
[pid=632] ppid=631 vsize=2592 CPUtime=0
/proc/632/stat : 632 (aspcud-trendy-1) R 631 630 1511 34817 1511 4202560 127 0 0 0 0 0 0 0 25 0 1 0 5136037 2654208 151 1283457024 134512640 135304128 4290241904 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/632/statm: 648 151 104 194 0 35 0
[pid=633] ppid=632 vsize=2592 CPUtime=0
/proc/633/stat : 633 (aspcud-trendy-1) R 632 630 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 5136037 2654208 47 1283457024 134512640 135304128 4290241904 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/633/statm: 648 47 0 194 0 35 0

[startup+0.145539 s]
/proc/loadavg: 1.20 1.18 1.12 5/36 633
/proc/meminfo: memFree=302520/1048576 swapFree=0/0
[pid=630] ppid=629 vsize=2600 CPUtime=0.01
/proc/630/stat : 630 (aspcud-trendy-1) S 629 630 1511 34817 1511 4202496 624 2224 0 0 0 0 1 0 25 0 1 0 5136036 2662400 299 1283457024 134512640 135304128 4290241904 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/630/statm: 650 299 251 194 0 37 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2600

[startup+0.205545 s]
/proc/loadavg: 1.20 1.18 1.12 5/36 633
/proc/meminfo: memFree=302520/1048576 swapFree=0/0
[pid=630] ppid=629 vsize=2600 CPUtime=0.01
/proc/630/stat : 630 (aspcud-trendy-1) S 629 630 1511 34817 1511 4202496 624 2224 0 0 0 0 1 0 25 0 1 0 5136036 2662400 299 1283457024 134512640 135304128 4290241904 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/630/statm: 650 299 251 194 0 37 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2600

[startup+0.305562 s]
/proc/loadavg: 1.20 1.18 1.12 5/36 633
/proc/meminfo: memFree=302520/1048576 swapFree=0/0
[pid=630] ppid=629 vsize=2600 CPUtime=0.01
/proc/630/stat : 630 (aspcud-trendy-1) S 629 630 1511 34817 1511 4202496 624 2224 0 0 0 0 1 0 25 0 1 0 5136036 2662400 299 1283457024 134512640 135304128 4290241904 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/630/statm: 650 299 251 194 0 37 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2600

[startup+0.705646 s]
/proc/loadavg: 1.20 1.18 1.12 5/36 633
/proc/meminfo: memFree=302520/1048576 swapFree=0/0
[pid=630] ppid=629 vsize=2600 CPUtime=0.01
/proc/630/stat : 630 (aspcud-trendy-1) S 629 630 1511 34817 1511 4202496 624 2224 0 0 0 0 1 0 25 0 1 0 5136036 2662400 299 1283457024 134512640 135304128 4290241904 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/630/statm: 650 299 251 194 0 37 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2600

[startup+1.50586 s]
/proc/loadavg: 1.20 1.18 1.12 3/36 644
/proc/meminfo: memFree=294076/1048576 swapFree=0/0
[pid=630] ppid=629 vsize=2600 CPUtime=1.25
/proc/630/stat : 630 (aspcud-trendy-1) S 629 630 1511 34817 1511 4202496 625 13417 0 0 0 0 120 5 17 0 1 0 5136036 2662400 299 1283457024 134512640 135304128 4290241904 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/630/statm: 650 299 251 194 0 37 0
[pid=642] ppid=630 vsize=13356 CPUtime=0.24
/proc/642/stat : 642 (clasp) R 630 630 1511 34817 1511 4202496 3686 0 0 0 19 5 0 0 18 0 1 0 5136038 13676544 3099 1283457024 134512640 136285277 4286945856 18446744073709551615 134669396 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/642/statm: 3339 3099 233 433 0 2904 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 15956

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

[startup+1.50586 s]
/proc/loadavg: 1.20 1.18 1.12 3/36 644
/proc/meminfo: memFree=294076/1048576 swapFree=0/0
[pid=630] ppid=629 vsize=2600 CPUtime=1.25
/proc/630/stat : 630 (aspcud-trendy-1) S 629 630 1511 34817 1511 4202496 625 13417 0 0 0 0 120 5 17 0 1 0 5136036 2662400 299 1283457024 134512640 135304128 4290241904 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/630/statm: 650 299 251 194 0 37 0
[pid=642] ppid=630 vsize=13356 CPUtime=0.24
/proc/642/stat : 642 (clasp) R 630 630 1511 34817 1511 4202496 3686 0 0 0 19 5 0 0 18 0 1 0 5136038 13676544 3099 1283457024 134512640 136285277 4286945856 18446744073709551615 134669396 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/642/statm: 3339 3099 233 433 0 2904 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 15956

Child status: 0
Real time (s): 1.53636
CPU time (s): 1.54009
CPU user time (s): 1.42009
CPU system time (s): 0.120007
CPU usage (%): 100.243
Max. virtual memory (cumulated for all children) (KiB): 28204

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 1.42009
system time used= 0.120007
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 21477
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= 468
involuntary context switches= 339

runsolver used 0 second user time and 0 second system time

The end