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/aspcud-paranoid-1.4/1265.cudf.caixa.log.runsolver ./aspcud-paranoid-1.4 /home/misc2010/data/misc4/caixa//1265.cudf /home/misc2010/tmp/201103031013/aspcud-paranoid-1.4/1265.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.93 1.59 1.29 5/38 18607
/proc/meminfo: memFree=449928/1048576 swapFree=0/0
[pid=18604] ppid=18603 vsize=2584 CPUtime=0
/proc/18604/stat : 18604 (aspcud-paranoid) S 18603 18604 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 75808090 2646016 278 1283457024 134512640 135304128 4289203376 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/18604/statm: 646 278 234 194 0 33 0
[pid=18605] ppid=18604 vsize=2584 CPUtime=0
/proc/18605/stat : 18605 (aspcud-paranoid) S 18604 18604 29493 34817 29493 4202560 116 0 0 0 0 0 0 0 18 0 1 0 75808090 2646016 130 1283457024 134512640 135304128 4289203376 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0
/proc/18605/statm: 646 130 85 194 0 33 0
[pid=18606] ppid=18605 vsize=2584 CPUtime=0
/proc/18606/stat : 18606 (aspcud-paranoid) R 18605 18604 29493 34817 29493 4202560 127 0 0 0 0 0 0 0 25 0 1 0 75808090 2646016 149 1283457024 134512640 135304128 4289203376 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/18606/statm: 646 149 104 194 0 33 0
[pid=18607] ppid=18606 vsize=2584 CPUtime=0
/proc/18607/stat : 18607 (aspcud-paranoid) R 18606 18604 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 75808090 2646016 45 1283457024 134512640 135304128 4289203376 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/18607/statm: 646 45 0 194 0 33 0

[startup+0.174036 s]
/proc/loadavg: 1.93 1.59 1.29 5/38 18607
/proc/meminfo: memFree=449928/1048576 swapFree=0/0
[pid=18604] ppid=18603 vsize=2596 CPUtime=0
/proc/18604/stat : 18604 (aspcud-paranoid) S 18603 18604 29493 34817 29493 4202496 655 2947 0 0 0 0 0 0 25 0 1 0 75808090 2658304 298 1283457024 134512640 135304128 4289203376 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/18604/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.204044 s]
/proc/loadavg: 1.93 1.59 1.29 5/38 18607
/proc/meminfo: memFree=449928/1048576 swapFree=0/0
[pid=18604] ppid=18603 vsize=2596 CPUtime=0
/proc/18604/stat : 18604 (aspcud-paranoid) S 18603 18604 29493 34817 29493 4202496 655 2947 0 0 0 0 0 0 25 0 1 0 75808090 2658304 298 1283457024 134512640 135304128 4289203376 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/18604/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.304052 s]
/proc/loadavg: 1.93 1.59 1.29 5/38 18607
/proc/meminfo: memFree=449928/1048576 swapFree=0/0
[pid=18604] ppid=18603 vsize=2596 CPUtime=0
/proc/18604/stat : 18604 (aspcud-paranoid) S 18603 18604 29493 34817 29493 4202496 655 2947 0 0 0 0 0 0 25 0 1 0 75808090 2658304 298 1283457024 134512640 135304128 4289203376 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/18604/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.704096 s]
/proc/loadavg: 1.93 1.59 1.29 5/38 18607
/proc/meminfo: memFree=449928/1048576 swapFree=0/0
[pid=18604] ppid=18603 vsize=2596 CPUtime=0
/proc/18604/stat : 18604 (aspcud-paranoid) S 18603 18604 29493 34817 29493 4202496 655 2947 0 0 0 0 0 0 25 0 1 0 75808090 2658304 298 1283457024 134512640 135304128 4289203376 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/18604/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

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

[startup+0.804109 s]
/proc/loadavg: 1.93 1.59 1.29 5/38 18607
/proc/meminfo: memFree=449928/1048576 swapFree=0/0
[pid=18604] ppid=18603 vsize=2596 CPUtime=0
/proc/18604/stat : 18604 (aspcud-paranoid) S 18603 18604 29493 34817 29493 4202496 655 2947 0 0 0 0 0 0 25 0 1 0 75808090 2658304 298 1283457024 134512640 135304128 4289203376 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/18604/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+1.20417 s]
/proc/loadavg: 1.93 1.59 1.29 2/38 18621
/proc/meminfo: memFree=433076/1048576 swapFree=0/0
[pid=18604] ppid=18603 vsize=2596 CPUtime=0.72
/proc/18604/stat : 18604 (aspcud-paranoid) S 18603 18604 29493 34817 29493 4202496 656 12473 0 0 0 0 65 7 18 0 1 0 75808090 2658304 298 1283457024 134512640 135304128 4289203376 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/18604/statm: 649 298 251 194 0 36 0
[pid=18619] ppid=18604 vsize=10784 CPUtime=0.07
/proc/18619/stat : 18619 (clasp) S 18604 18604 29493 34817 29493 4202496 2733 0 0 0 6 1 0 0 18 0 1 0 75808092 11042816 2397 1283457024 134512640 136241547 4293361760 18446744073709551615 135683070 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/18619/statm: 2696 2397 175 423 0 2271 0
[pid=18620] ppid=18604 vsize=17460 CPUtime=0.39
/proc/18620/stat : 18620 (gringo) R 18604 18604 29493 34817 29493 4202496 4129 0 0 0 37 2 0 0 19 0 1 0 75808092 17879040 3368 1283457024 134512640 136959103 4287892384 18446744073709551615 134695169 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/18620/statm: 4365 3368 257 598 0 3764 0
Current children cumulated CPU time (s) 1.18
Current children cumulated vsize (KiB) 30840

[startup+1.3042 s]
/proc/loadavg: 1.93 1.59 1.29 2/38 18621
/proc/meminfo: memFree=433076/1048576 swapFree=0/0
[pid=18604] ppid=18603 vsize=2600 CPUtime=1.29
/proc/18604/stat : 18604 (aspcud-paranoid) R 18603 18604 29493 34817 29493 4202496 1911 31421 0 0 0 2 113 14 25 0 1 0 75808090 2662400 310 1283457024 134512640 135304128 4289203376 18446744073709551615 134735712 0 0 16902 1132543225 0 0 0 17 0 0 0 0
/proc/18604/statm: 650 310 262 194 0 37 0
Current children cumulated CPU time (s) 1.29
Current children cumulated vsize (KiB) 2600

Child status: 0
Real time (s): 1.30452
CPU time (s): 1.30008
CPU user time (s): 1.13207
CPU system time (s): 0.16801
CPU usage (%): 99.6596
Max. virtual memory (cumulated for all children) (KiB): 30840

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 1.13207
system time used= 0.16801
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 33353
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= 894
involuntary context switches= 893

runsolver used 0.012 second user time and 0 second system time

The end