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/201108300820/aspcud-1.5/19890cfe-db9f-11df-9e6c-00163e3d3b7c.cudf.dudf-real.log.runsolver ./aspcud-1.5 /home/misc2010/data/2011/dudf-real//19890cfe-db9f-11df-9e6c-00163e3d3b7c.cudf /home/misc2010/tmp/201108300820/aspcud-1.5/19890cfe-db9f-11df-9e6c-00163e3d3b7c.cudf.dudf-real.result +sum(installedsize) 

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.04 1.02 1.00 3/39 3415
/proc/meminfo: memFree=915976/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=0
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 1521 0 0 0 0 0 0 25 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=2592 CPUtime=0
/proc/3413/stat : 3413 (aspcud-1.5) R 3405 3405 2160 34817 2160 4202560 110 0 0 0 0 0 0 0 25 0 1 0 51511842 2654208 131 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 0 6 1132494585 0 0 0 17 0 0 0 0
/proc/3413/statm: 648 131 83 194 0 35 0
[pid=3414] ppid=3405 vsize=2592 CPUtime=0
/proc/3414/stat : 3414 (aspcud-1.5) R 3405 3405 2160 34817 2160 4202560 110 0 0 0 0 0 0 0 25 0 1 0 51511842 2654208 131 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 0 6 1132494585 0 0 0 17 0 0 0 0
/proc/3414/statm: 648 131 83 194 0 35 0
[pid=3415] ppid=3405 vsize=2592 CPUtime=0
/proc/3415/stat : 3415 (aspcud-1.5) D 3405 3405 2160 34817 2160 4202560 109 0 0 0 0 0 0 0 25 0 1 0 51511842 2654208 130 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 0 6 1132494585 18446744071564252162 0 0 17 0 0 0 0
/proc/3415/statm: 648 130 82 194 0 35 0

[startup+0.171084 s]
/proc/loadavg: 1.04 1.02 1.00 3/39 3415
/proc/meminfo: memFree=915976/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=0
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 1521 0 0 0 0 0 0 25 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=1920 CPUtime=0
/proc/3413/stat : 3413 (clasp) D 3405 3405 2160 34817 2160 4202496 161 0 10 0 0 0 0 0 24 0 1 0 51511842 1966080 40 1283457024 134512640 136285277 4293242960 18446744073709551615 135219216 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/3413/statm: 480 40 31 433 0 45 0
[pid=3414] ppid=3405 vsize=2576 CPUtime=0
/proc/3414/stat : 3414 (gringo) D 3405 3405 2160 34817 2160 4202496 160 0 9 0 0 0 0 0 24 0 1 0 51511842 2637824 38 1283457024 134512640 136933539 4290496768 18446744073709551615 135997923 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/3414/statm: 644 38 29 592 0 49 0
[pid=3415] ppid=3405 vsize=1432 CPUtime=0
/proc/3415/stat : 3415 (cudf2lp) D 3405 3405 2160 34817 2160 4202496 162 0 9 0 0 0 0 0 24 0 1 0 51511842 1466368 40 1283457024 134512640 135786343 4291974288 18446744073709551615 134792368 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/3415/statm: 358 40 30 311 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 8520

[startup+0.207105 s]
/proc/loadavg: 1.04 1.02 1.00 3/39 3415
/proc/meminfo: memFree=915976/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=0
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 1521 0 0 0 0 0 0 25 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=1920 CPUtime=0
/proc/3413/stat : 3413 (clasp) D 3405 3405 2160 34817 2160 4202496 161 0 11 0 0 0 0 0 24 0 1 0 51511842 1966080 41 1283457024 134512640 136285277 4293242960 18446744073709551615 135139632 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/3413/statm: 480 41 32 433 0 45 0
[pid=3414] ppid=3405 vsize=2576 CPUtime=0
/proc/3414/stat : 3414 (gringo) D 3405 3405 2160 34817 2160 4202496 165 0 10 0 0 0 0 0 24 0 1 0 51511842 2637824 44 1283457024 134512640 136933539 4290496768 18446744073709551615 135891216 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/3414/statm: 644 44 34 592 0 49 0
[pid=3415] ppid=3405 vsize=1432 CPUtime=0
/proc/3415/stat : 3415 (cudf2lp) D 3405 3405 2160 34817 2160 4202496 162 0 9 0 0 0 0 0 24 0 1 0 51511842 1466368 40 1283457024 134512640 135786343 4291974288 18446744073709551615 134792368 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/3415/statm: 358 40 30 311 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 8520

[startup+0.319132 s]
/proc/loadavg: 1.04 1.02 1.00 3/39 3415
/proc/meminfo: memFree=915976/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=0
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 1521 0 0 0 0 0 0 25 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=1924 CPUtime=0
/proc/3413/stat : 3413 (clasp) S 3405 3405 2160 34817 2160 4202496 272 0 19 0 0 0 0 0 23 0 1 0 51511842 1970176 159 1283457024 134512640 136285277 4293242960 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/3413/statm: 481 159 144 433 0 46 0
[pid=3414] ppid=3405 vsize=2576 CPUtime=0
/proc/3414/stat : 3414 (gringo) D 3405 3405 2160 34817 2160 4202496 240 0 19 0 0 0 0 0 22 0 1 0 51511842 2637824 127 1283457024 134512640 136933539 4290496768 18446744073709551615 134629104 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/3414/statm: 644 127 115 592 0 49 0
[pid=3415] ppid=3405 vsize=1440 CPUtime=0
/proc/3415/stat : 3415 (cudf2lp) D 3405 3405 2160 34817 2160 4202496 258 0 15 0 0 0 0 0 22 0 1 0 51511842 1474560 141 1283457024 134512640 135786343 4291974288 18446744073709551615 135258478 0 0 6 0 18446744071564252162 0 0 17 0 0 0 0
/proc/3415/statm: 360 141 112 311 0 47 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 8532

[startup+0.707146 s]
/proc/loadavg: 1.04 1.02 1.00 3/39 3415
/proc/meminfo: memFree=915976/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=0
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 1521 0 0 0 0 0 0 25 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=1924 CPUtime=0
/proc/3413/stat : 3413 (clasp) S 3405 3405 2160 34817 2160 4202496 272 0 19 0 0 0 0 0 23 0 1 0 51511842 1970176 159 1283457024 134512640 136285277 4293242960 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/3413/statm: 481 159 144 433 0 46 0
[pid=3414] ppid=3405 vsize=2588 CPUtime=0
/proc/3414/stat : 3414 (gringo) S 3405 3405 2160 34817 2160 4202496 380 0 24 0 0 0 0 0 21 0 1 0 51511842 2650112 272 1283457024 134512640 136933539 4290496768 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/3414/statm: 647 272 242 592 0 52 0
[pid=3415] ppid=3405 vsize=9008 CPUtime=0.21
/proc/3415/stat : 3415 (cudf2lp) R 3405 3405 2160 34817 2160 4202496 2334 0 15 0 21 0 0 0 22 0 1 0 51511842 9224192 1906 1283457024 134512640 135786343 4291974288 18446744073709551615 134761412 0 0 6 0 0 0 0 17 0 0 0 0
/proc/3415/statm: 2252 1906 128 311 0 1939 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 16112

[startup+1.50973 s]
/proc/loadavg: 1.04 1.02 1.00 2/40 3416
/proc/meminfo: memFree=890172/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=0
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 1521 0 0 0 0 0 0 25 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=1924 CPUtime=0
/proc/3413/stat : 3413 (clasp) S 3405 3405 2160 34817 2160 4202496 272 0 19 0 0 0 0 0 23 0 1 0 51511842 1970176 159 1283457024 134512640 136285277 4293242960 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/3413/statm: 481 159 144 433 0 46 0
[pid=3414] ppid=3405 vsize=2588 CPUtime=0
/proc/3414/stat : 3414 (gringo) S 3405 3405 2160 34817 2160 4202496 380 0 24 0 0 0 0 0 21 0 1 0 51511842 2650112 272 1283457024 134512640 136933539 4290496768 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/3414/statm: 647 272 242 592 0 52 0
[pid=3415] ppid=3405 vsize=27944 CPUtime=0.85
/proc/3415/stat : 3415 (cudf2lp) R 3405 3405 2160 34817 2160 4202496 7592 0 15 0 84 1 0 0 25 0 1 0 51511842 28614656 6057 1283457024 134512640 135786343 4291974288 18446744073709551615 134579366 0 0 6 0 0 0 0 17 0 0 0 0
/proc/3415/statm: 6986 6057 135 311 0 6673 0
Current children cumulated CPU time (s) 0.85
Current children cumulated vsize (KiB) 35048

[startup+3.1101 s]
/proc/loadavg: 1.04 1.02 1.00 3/40 3416
/proc/meminfo: memFree=855716/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=0
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 1521 0 0 0 0 0 0 25 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=22624 CPUtime=0.14
/proc/3413/stat : 3413 (clasp) S 3405 3405 2160 34817 2160 4202496 6397 0 22 0 12 2 0 0 18 0 1 0 51511842 23166976 5223 1283457024 134512640 136285277 4293242960 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/3413/statm: 5656 5223 177 433 0 5221 0
[pid=3414] ppid=3405 vsize=30956 CPUtime=1.07
/proc/3414/stat : 3414 (gringo) S 3405 3405 2160 34817 2160 4202496 9591 0 24 0 104 3 0 0 18 0 1 0 51511842 31698944 6479 1283457024 134512640 136933539 4290496768 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/3414/statm: 7739 6479 242 592 0 7144 0
[pid=3415] ppid=3405 vsize=27592 CPUtime=1.23
/proc/3415/stat : 3415 (cudf2lp) R 3405 3405 2160 34817 2160 4202496 8925 0 15 0 121 2 0 0 25 0 1 0 51511842 28254208 6667 1283457024 134512640 135786343 4291974288 18446744073709551615 135219696 0 0 6 0 0 0 0 17 0 0 0 0
/proc/3415/statm: 6898 6667 139 311 0 6585 0
Current children cumulated CPU time (s) 2.44
Current children cumulated vsize (KiB) 83764
heavy processes:

[startup+6.31095 s]
/proc/loadavg: 1.12 1.04 1.01 2/39 3416
/proc/meminfo: memFree=727764/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=1.39
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 10449 0 15 0 0 135 4 18 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=82760 CPUtime=0.7
/proc/3413/stat : 3413 (clasp) R 3405 3405 2160 34817 2160 4202496 23675 0 22 0 66 4 0 0 18 0 1 0 51511842 84746240 20052 1283457024 134512640 136285277 4293242960 18446744073709551615 134782266 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3413/statm: 20690 20052 177 433 0 20255 0
[pid=3414] ppid=3405 vsize=145112 CPUtime=3.54
/proc/3414/stat : 3414 (gringo) R 3405 3405 2160 34817 2160 4202496 42865 0 24 0 336 18 0 0 22 0 1 0 51511842 148594688 27869 1283457024 134512640 136933539 4290496768 18446744073709551615 135633710 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/3414/statm: 36278 27869 253 592 0 35683 0
Current children cumulated CPU time (s) 5.63
Current children cumulated vsize (KiB) 230464

[startup+12.7125 s]
/proc/loadavg: 1.11 1.04 1.01 2/38 3416
/proc/meminfo: memFree=780860/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=5.55
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 58957 0 39 0 0 530 25 18 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=133808 CPUtime=6.48
/proc/3413/stat : 3413 (clasp) R 3405 3405 2160 34817 2160 4202496 39873 0 22 0 635 13 0 0 25 0 1 0 51511842 137019392 33214 1283457024 134512640 136285277 4293242960 18446744073709551615 134955202 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3413/statm: 33452 33214 234 433 0 33017 0
Current children cumulated CPU time (s) 12.03
Current children cumulated vsize (KiB) 136400

[startup+25.5049 s]
/proc/loadavg: 1.08 1.04 1.00 2/38 3416
/proc/meminfo: memFree=703856/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=5.55
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 58957 0 39 0 0 530 25 18 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=195324 CPUtime=19.27
/proc/3413/stat : 3413 (clasp) R 3405 3405 2160 34817 2160 4202496 55245 0 22 0 1908 19 0 0 25 0 1 0 51511842 200011776 48585 1283457024 134512640 136285277 4293242960 18446744073709551615 134951781 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3413/statm: 48831 48585 234 433 0 48396 0
Current children cumulated CPU time (s) 24.82
Current children cumulated vsize (KiB) 197916

[startup+51.1109 s]
/proc/loadavg: 1.06 1.03 1.00 2/38 3416
/proc/meminfo: memFree=406132/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=5.55
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 58957 0 39 0 0 530 25 18 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=505708 CPUtime=44.86
/proc/3413/stat : 3413 (clasp) R 3405 3405 2160 34817 2160 4202496 132816 0 22 0 4444 42 0 0 25 0 1 0 51511842 517844992 126156 1283457024 134512640 136285277 4293242960 18446744073709551615 134966715 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3413/statm: 126427 126156 234 433 0 125992 0
Current children cumulated CPU time (s) 50.41
Current children cumulated vsize (KiB) 508300

[startup+102.302 s]
/proc/loadavg: 1.02 1.02 1.00 2/40 3418
/proc/meminfo: memFree=186504/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=5.55
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 58957 0 39 0 0 530 25 18 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=711636 CPUtime=96.01
/proc/3413/stat : 3413 (clasp) R 3405 3405 2160 34817 2160 4202496 184274 0 22 0 9539 62 0 0 25 0 1 0 51511842 728715264 177614 1283457024 134512640 136285277 4293242960 18446744073709551615 134642064 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3413/statm: 177909 177614 234 433 0 177474 0
Current children cumulated CPU time (s) 101.56
Current children cumulated vsize (KiB) 714228

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

[startup+127.909 s]
/proc/loadavg: 1.01 1.02 1.00 3/40 3421
/proc/meminfo: memFree=166540/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=5.55
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 58957 0 39 0 0 530 25 18 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=731624 CPUtime=121.58
/proc/3413/stat : 3413 (clasp) R 3405 3405 2160 34817 2160 4202496 189270 0 22 0 12095 63 0 0 25 0 1 0 51511842 749182976 182610 1283457024 134512640 136285277 4293242960 18446744073709551615 134960075 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3413/statm: 182906 182610 234 433 0 182471 0
Current children cumulated CPU time (s) 127.13
Current children cumulated vsize (KiB) 734216

[startup+134.311 s]
/proc/loadavg: 1.01 1.02 1.00 2/40 3422
/proc/meminfo: memFree=122892/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=5.55
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 58957 0 39 0 0 530 25 18 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=779320 CPUtime=127.97
/proc/3413/stat : 3413 (clasp) R 3405 3405 2160 34817 2160 4202496 201202 0 22 0 12731 66 0 0 25 0 1 0 51511842 798023680 194542 1283457024 134512640 136285277 4293242960 18446744073709551615 134965025 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3413/statm: 194830 194542 234 433 0 194395 0
Current children cumulated CPU time (s) 133.52
Current children cumulated vsize (KiB) 781912

[startup+140.712 s]
/proc/loadavg: 1.01 1.02 1.00 2/40 3422
/proc/meminfo: memFree=4316/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=5.55
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 58957 0 39 0 0 530 25 18 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=894432 CPUtime=134.37
/proc/3413/stat : 3413 (clasp) R 3405 3405 2160 34817 2160 4202496 229986 0 22 0 13360 77 0 0 25 0 1 0 51511842 915898368 223326 1283457024 134512640 136285277 4293242960 18446744073709551615 134963461 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3413/statm: 223608 223326 234 433 0 223173 0
Current children cumulated CPU time (s) 139.92
Current children cumulated vsize (KiB) 897024

[startup+143.913 s]
/proc/loadavg: 1.01 1.02 1.00 2/40 3423
/proc/meminfo: memFree=4336/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=5.55
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 58957 0 39 0 0 530 25 18 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=944872 CPUtime=137.56
/proc/3413/stat : 3413 (clasp) R 3405 3405 2160 34817 2160 4202496 242528 0 22 0 13671 85 0 0 25 0 1 0 51511842 967548928 235868 1283457024 134512640 136285277 4293242960 18446744073709551615 134951781 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3413/statm: 236218 235868 234 433 0 235783 0
Current children cumulated CPU time (s) 143.11
Current children cumulated vsize (KiB) 947464

[startup+145.514 s]
/proc/loadavg: 1.09 1.04 1.01 2/40 3423
/proc/meminfo: memFree=4340/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=5.55
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 580 58957 0 39 0 0 530 25 18 0 1 0 51511841 2654208 298 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 298 251 194 0 35 0
[pid=3413] ppid=3405 vsize=971840 CPUtime=139.16
/proc/3413/stat : 3413 (clasp) R 3405 3405 2160 34817 2160 4202496 249028 0 22 0 13829 87 0 0 25 0 1 0 51511842 995164160 242368 1283457024 134512640 136285277 4293242960 18446744073709551615 134951781 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3413/statm: 242960 242368 234 433 0 242525 0
Current children cumulated CPU time (s) 144.71
Current children cumulated vsize (KiB) 974432

[startup+146.884 s]
/proc/loadavg: 1.09 1.04 1.01 1/39 3423
/proc/meminfo: memFree=983256/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=145.58
/proc/3405/stat : 3405 (aspcud-1.5) D 3404 3405 2160 34817 2160 4202496 600 310597 9 61 0 0 14421 137 18 0 1 0 51511841 2654208 76 1283457024 134512640 135304128 4286859824 18446744073709551615 4160347152 0 65536 4 1132560123 18446744071564332000 0 0 17 0 0 0 0
/proc/3405/statm: 648 76 29 194 0 35 0
Current children cumulated CPU time (s) 145.58
Current children cumulated vsize (KiB) 2592

[startup+147.004 s]
/proc/loadavg: 1.09 1.04 1.01 1/39 3423
/proc/meminfo: memFree=983256/1048576 swapFree=0/0
[pid=3405] ppid=3404 vsize=2592 CPUtime=145.58
/proc/3405/stat : 3405 (aspcud-1.5) S 3404 3405 2160 34817 2160 4202496 736 310597 17 61 0 0 14421 137 18 0 1 0 51511841 2654208 203 1283457024 134512640 135304128 4286859824 18446744073709551615 4294960130 0 65536 16902 1132543225 18446744071564329979 0 0 17 0 0 0 0
/proc/3405/statm: 648 203 156 194 0 35 0
Current children cumulated CPU time (s) 145.58
Current children cumulated vsize (KiB) 2592

Child status: 0
Real time (s): 147.095
CPU time (s): 145.597
CPU user time (s): 144.217
CPU system time (s): 1.38009
CPU usage (%): 98.9819
Max. virtual memory (cumulated for all children) (KiB): 983936

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 144.217
system time used= 1.38009
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 313962
page faults= 89
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 7035
involuntary context switches= 7830

runsolver used 0.004 second user time and 0.108006 second system time

The end