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/201109011757/aspcud-1.5/rand440.cudf.dudf-random.log.runsolver ./aspcud-1.5 /home/misc2010/data/2011/dudf-random//rand440.cudf /home/misc2010/tmp/201109011757/aspcud-1.5/rand440.cudf.dudf-random.result -sum(pin-priority-1),-sum(pin-priority-500),-sum(pin-priority-700),-notuptodate,-removed,-changed 

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.07 0.98 5/40 25861
/proc/meminfo: memFree=466020/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2588 CPUtime=0
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 374 0 0 0 0 0 0 0 21 0 1 0 72026766 2650112 280 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/25859/statm: 647 280 234 194 0 34 0
[pid=25860] ppid=25859 vsize=2588 CPUtime=0
/proc/25860/stat : 25860 (aspcud-1.5) R 25859 25859 22717 34817 22717 4202560 110 0 0 0 0 0 0 0 25 0 1 0 72026766 2650112 133 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/25860/statm: 647 133 86 194 0 34 0
[pid=25861] ppid=25860 vsize=2588 CPUtime=0
/proc/25861/stat : 25861 (aspcud-1.5) R 25860 25859 22717 34817 22717 4202560 0 0 0 0 0 0 0 0 25 0 1 0 72026766 2650112 47 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/25861/statm: 647 47 0 194 0 34 0

[startup+0.143586 s]
/proc/loadavg: 1.20 1.07 0.98 5/40 25861
/proc/meminfo: memFree=466020/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=0
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 1521 0 0 0 0 0 0 25 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.207538 s]
/proc/loadavg: 1.20 1.07 0.98 5/40 25861
/proc/meminfo: memFree=466020/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=0
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 1521 0 0 0 0 0 0 25 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.307539 s]
/proc/loadavg: 1.20 1.07 0.98 5/40 25861
/proc/meminfo: memFree=466020/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=0
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 1521 0 0 0 0 0 0 25 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.707598 s]
/proc/loadavg: 1.20 1.07 0.98 5/40 25861
/proc/meminfo: memFree=466020/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=0
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 1521 0 0 0 0 0 0 25 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+1.50761 s]
/proc/loadavg: 1.20 1.07 0.98 2/42 25870
/proc/meminfo: memFree=434432/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=0
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 1521 0 0 0 0 0 0 25 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=1924 CPUtime=0
/proc/25868/stat : 25868 (clasp) S 25859 25859 22717 34817 22717 4202496 291 0 0 0 0 0 0 0 25 0 1 0 72026767 1970176 159 1283457024 134512640 136285277 4293580976 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/25868/statm: 481 159 144 433 0 46 0
[pid=25869] ppid=25859 vsize=2588 CPUtime=0
/proc/25869/stat : 25869 (gringo) S 25859 25859 22717 34817 22717 4202496 404 0 0 0 0 0 0 0 25 0 1 0 72026767 2650112 272 1283457024 134512640 136933539 4287353648 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/25869/statm: 647 272 242 592 0 52 0
[pid=25870] ppid=25859 vsize=29448 CPUtime=1.3
/proc/25870/stat : 25870 (cudf2lp) R 25859 25859 22717 34817 22717 4202496 8143 0 0 0 124 6 0 0 25 0 1 0 72026767 30154752 6642 1283457024 134512640 135786343 4293581024 18446744073709551615 134536268 0 0 6 0 0 0 0 17 0 0 0 0
/proc/25870/statm: 7362 6642 128 311 0 7049 0
Current children cumulated CPU time (s) 1.3
Current children cumulated vsize (KiB) 36556

[startup+3.11319 s]
/proc/loadavg: 1.20 1.07 0.98 2/42 25870
/proc/meminfo: memFree=395180/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=0
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 1521 0 0 0 0 0 0 25 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=11492 CPUtime=0.04
/proc/25868/stat : 25868 (clasp) S 25859 25859 22717 34817 22717 4202496 3064 0 0 0 3 1 0 0 18 0 1 0 72026767 11767808 2546 1283457024 134512640 136285277 4293580976 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/25868/statm: 2873 2546 177 433 0 2438 0
[pid=25869] ppid=25859 vsize=16124 CPUtime=0.46
/proc/25869/stat : 25869 (gringo) S 25859 25859 22717 34817 22717 4202496 4623 0 0 0 44 2 0 0 18 0 1 0 72026767 16510976 3058 1283457024 134512640 136933539 4287353648 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/25869/statm: 4031 3058 242 592 0 3436 0
[pid=25870] ppid=25859 vsize=46076 CPUtime=2.3
/proc/25870/stat : 25870 (cudf2lp) R 25859 25859 22717 34817 22717 4202496 14083 0 0 0 220 10 0 0 25 0 1 0 72026767 47181824 11312 1283457024 134512640 135786343 4293581024 18446744073709551615 134524693 0 0 6 0 0 0 0 17 0 0 0 0
/proc/25870/statm: 11519 11312 139 311 0 11206 0
Current children cumulated CPU time (s) 2.8
Current children cumulated vsize (KiB) 76288

[startup+6.31361 s]
/proc/loadavg: 1.18 1.06 0.98 2/40 25870
/proc/meminfo: memFree=403396/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=44856 CPUtime=2.35
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 12915 0 0 0 232 3 0 0 21 0 1 0 72026767 45932544 10983 1283457024 134512640 136285277 4293580976 18446744073709551615 134931449 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 11214 10983 234 433 0 10779 0
Current children cumulated CPU time (s) 6
Current children cumulated vsize (KiB) 47452

[startup+12.7059 s]
/proc/loadavg: 1.17 1.06 0.98 2/40 25871
/proc/meminfo: memFree=276048/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=172624 CPUtime=8.75
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 44870 0 0 0 858 17 0 0 25 0 1 0 72026767 176766976 42938 1283457024 134512640 136285277 4293580976 18446744073709551615 134639645 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 43156 42938 234 433 0 42721 0
Current children cumulated CPU time (s) 12.4
Current children cumulated vsize (KiB) 175220

[startup+25.5096 s]
/proc/loadavg: 1.13 1.06 0.98 2/40 25872
/proc/meminfo: memFree=185528/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=254228 CPUtime=21.54
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 65256 0 0 0 2132 22 0 0 25 0 1 0 72026767 260329472 63324 1283457024 134512640 136285277 4293580976 18446744073709551615 134650622 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 63557 63324 234 433 0 63122 0
Current children cumulated CPU time (s) 25.19
Current children cumulated vsize (KiB) 256824

[startup+51.1055 s]
/proc/loadavg: 1.08 1.05 0.98 2/39 25873
/proc/meminfo: memFree=5596/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=453900 CPUtime=47.12
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 115153 0 0 0 4675 37 0 0 25 0 1 0 72026767 464793600 113220 1283457024 134512640 136285277 4293580976 18446744073709551615 134733720 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 113475 113220 234 433 0 113040 0
Current children cumulated CPU time (s) 50.77
Current children cumulated vsize (KiB) 456496

[startup+102.312 s]
/proc/loadavg: 1.04 1.04 0.98 2/38 25873
/proc/meminfo: memFree=5892/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=490244 CPUtime=98.32
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 127647 0 0 0 9787 45 0 0 25 0 1 0 72026767 502009856 122316 1283457024 134512640 136285277 4293580976 18446744073709551615 134639197 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 122561 122316 234 433 0 122126 0
Current children cumulated CPU time (s) 101.97
Current children cumulated vsize (KiB) 492840

[startup+162.306 s]
/proc/loadavg: 1.01 1.03 0.98 2/38 25873
/proc/meminfo: memFree=5460/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=593524 CPUtime=158.25
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 153447 0 0 0 15772 53 0 0 25 0 1 0 72026767 607768576 148116 1283457024 134512640 136285277 4293580976 18446744073709551615 134734261 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 148381 148116 234 433 0 147946 0
Current children cumulated CPU time (s) 161.9
Current children cumulated vsize (KiB) 596120

[startup+222.309 s]
/proc/loadavg: 1.00 1.02 0.98 2/38 25873
/proc/meminfo: memFree=5832/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=592664 CPUtime=218.21
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 153447 0 0 0 21766 55 0 0 25 0 1 0 72026767 606887936 147923 1283457024 134512640 136285277 4293580976 18446744073709551615 134930797 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 148166 147923 234 433 0 147731 0
Current children cumulated CPU time (s) 221.86
Current children cumulated vsize (KiB) 595260

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

[startup+255.906 s]
/proc/loadavg: 1.00 1.02 0.98 2/38 25873
/proc/meminfo: memFree=5832/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=592664 CPUtime=251.78
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 153447 0 0 0 25123 55 0 0 25 0 1 0 72026767 606887936 147923 1283457024 134512640 136285277 4293580976 18446744073709551615 134735627 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 148166 147923 234 433 0 147731 0
Current children cumulated CPU time (s) 255.43
Current children cumulated vsize (KiB) 595260

[startup+268.709 s]
/proc/loadavg: 1.00 1.02 0.98 2/38 25873
/proc/meminfo: memFree=5832/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=592664 CPUtime=264.58
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 153447 0 0 0 26403 55 0 0 25 0 1 0 72026767 606887936 147923 1283457024 134512640 136285277 4293580976 18446744073709551615 134733771 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 148166 147923 234 433 0 147731 0
Current children cumulated CPU time (s) 268.23
Current children cumulated vsize (KiB) 595260

[startup+275.11 s]
/proc/loadavg: 1.00 1.02 0.98 2/38 25873
/proc/meminfo: memFree=5832/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=592664 CPUtime=270.97
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 153447 0 0 0 27042 55 0 0 25 0 1 0 72026767 606887936 147923 1283457024 134512640 136285277 4293580976 18446744073709551615 134686305 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 148166 147923 234 433 0 147731 0
Current children cumulated CPU time (s) 274.62
Current children cumulated vsize (KiB) 595260

[startup+278.311 s]
/proc/loadavg: 1.00 1.02 0.98 2/38 25873
/proc/meminfo: memFree=5832/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=592664 CPUtime=274.17
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 153447 0 0 0 27362 55 0 0 25 0 1 0 72026767 606887936 147923 1283457024 134512640 136285277 4293580976 18446744073709551615 134723304 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 148166 147923 234 433 0 147731 0
Current children cumulated CPU time (s) 277.82
Current children cumulated vsize (KiB) 595260

[startup+279.911 s]
/proc/loadavg: 1.00 1.02 0.98 2/38 25873
/proc/meminfo: memFree=5832/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=592664 CPUtime=275.77
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 153447 0 0 0 27522 55 0 0 25 0 1 0 72026767 606887936 147923 1283457024 134512640 136285277 4293580976 18446744073709551615 134959806 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 148166 147923 234 433 0 147731 0
Current children cumulated CPU time (s) 279.42
Current children cumulated vsize (KiB) 595260

[startup+280.708 s]
/proc/loadavg: 1.00 1.02 0.98 2/38 25873
/proc/meminfo: memFree=5832/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=592664 CPUtime=276.57
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 153447 0 0 0 27602 55 0 0 25 0 1 0 72026767 606887936 147923 1283457024 134512640 136285277 4293580976 18446744073709551615 134649408 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 148166 147923 234 433 0 147731 0
Current children cumulated CPU time (s) 280.22
Current children cumulated vsize (KiB) 595260

[startup+281.508 s]
/proc/loadavg: 1.00 1.02 0.98 2/38 25873
/proc/meminfo: memFree=5832/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=592664 CPUtime=277.37
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 153447 0 0 0 27682 55 0 0 25 0 1 0 72026767 606887936 147923 1283457024 134512640 136285277 4293580976 18446744073709551615 134642093 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 148166 147923 234 433 0 147731 0
Current children cumulated CPU time (s) 281.02
Current children cumulated vsize (KiB) 595260

[startup+281.908 s]
/proc/loadavg: 1.00 1.02 0.98 2/38 25873
/proc/meminfo: memFree=5832/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=447000 CPUtime=277.77
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 153455 0 0 0 27717 60 0 0 25 0 1 0 72026767 457728000 103356 1283457024 134512640 136285277 4293580976 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 111750 103356 242 433 0 111315 0
Current children cumulated CPU time (s) 281.42
Current children cumulated vsize (KiB) 449596

[startup+282.009 s]
/proc/loadavg: 1.00 1.02 0.98 2/38 25873
/proc/meminfo: memFree=5832/1048576 swapFree=0/0
[pid=25859] ppid=25858 vsize=2596 CPUtime=3.65
/proc/25859/stat : 25859 (aspcud-1.5) S 25858 25859 22717 34817 22717 4202496 581 29284 0 0 0 0 348 17 18 0 1 0 72026766 2658304 299 1283457024 134512640 135304128 4287091280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25859/statm: 649 299 251 194 0 36 0
[pid=25868] ppid=25859 vsize=26252 CPUtime=277.87
/proc/25868/stat : 25868 (clasp) R 25859 25859 22717 34817 22717 4202496 153455 0 0 0 27717 70 0 0 25 0 1 0 72026767 26882048 3295 1283457024 134512640 136285277 4293580976 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25868/statm: 6563 3295 242 433 0 6128 0
Current children cumulated CPU time (s) 281.52
Current children cumulated vsize (KiB) 28848

Child status: 0
Real time (s): 282.031
CPU time (s): 281.562
CPU user time (s): 280.662
CPU system time (s): 0.900056
CPU usage (%): 99.8335
Max. virtual memory (cumulated for all children) (KiB): 596120

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 280.662
system time used= 0.900056
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 186948
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= 1665
involuntary context switches= 4815

runsolver used 0 second user time and 0.012 second system time

The end