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/201108311143/aspcud-1.5/e381ba7e-a192-11e0-8647-00163e1e087d.cudf.dudf-real.log.runsolver ./aspcud-1.5 /home/misc2010/data/2011/dudf-real//e381ba7e-a192-11e0-8647-00163e1e087d.cudf /home/misc2010/tmp/201108311143/aspcud-1.5/e381ba7e-a192-11e0-8647-00163e1e087d.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.00 1.00 1.00 5/38 3136
/proc/meminfo: memFree=417416/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=0
/proc/3126/stat : 3126 (aspcud-1.5) R 3125 3126 19908 34817 19908 4202496 554 1520 0 0 0 0 0 0 25 0 1 0 68537466 2658304 297 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65538 4 1132560123 0 0 0 17 0 0 0 0
/proc/3126/statm: 649 297 250 194 0 36 0
[pid=3134] ppid=3126 vsize=2596 CPUtime=0
/proc/3134/stat : 3134 (aspcud-1.5) R 3126 3126 19908 34817 19908 4202560 110 0 0 0 0 0 0 0 25 0 1 0 68537467 2658304 131 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 0 6 1132494585 0 0 0 17 0 0 0 0
/proc/3134/statm: 649 131 83 194 0 36 0
[pid=3135] ppid=3126 vsize=2596 CPUtime=0
/proc/3135/stat : 3135 (aspcud-1.5) S 3126 3126 19908 34817 19908 4202560 110 0 0 0 0 0 0 0 25 0 1 0 68537467 2658304 131 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 0 6 1132494585 18446744071564457842 0 0 17 0 0 0 0
/proc/3135/statm: 649 131 83 194 0 36 0
[pid=3136] ppid=3126 vsize=2596 CPUtime=0
/proc/3136/stat : 3136 (aspcud-1.5) R 3126 3126 19908 34817 19908 4202560 0 0 0 0 0 0 0 0 25 0 1 0 68537467 2658304 47 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65538 4 1132560123 0 0 0 17 0 0 0 0
/proc/3136/statm: 649 47 0 194 0 36 0

[startup+0.206157 s]
/proc/loadavg: 1.00 1.00 1.00 5/38 3136
/proc/meminfo: memFree=417416/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=0
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 1520 0 0 0 0 0 0 25 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=1928 CPUtime=0
/proc/3134/stat : 3134 (clasp) S 3126 3126 19908 34817 19908 4202496 292 0 0 0 0 0 0 0 25 0 1 0 68537467 1974272 160 1283457024 134512640 136285277 4290786816 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/3134/statm: 482 160 144 433 0 47 0
[pid=3135] ppid=3126 vsize=2584 CPUtime=0
/proc/3135/stat : 3135 (gringo) S 3126 3126 19908 34817 19908 4202496 403 0 0 0 0 0 0 0 25 0 1 0 68537467 2646016 271 1283457024 134512640 136933539 4291071680 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/3135/statm: 646 271 242 592 0 51 0
[pid=3136] ppid=3126 vsize=5868 CPUtime=0.15
/proc/3136/stat : 3136 (cudf2lp) R 3126 3126 19908 34817 19908 4202496 1509 0 0 0 15 0 0 0 25 0 1 0 68537467 6008832 1243 1283457024 134512640 135786343 4292616256 18446744073709551615 134566144 0 0 6 0 0 0 0 17 0 0 0 0
/proc/3136/statm: 1467 1243 128 311 0 1154 0
Current children cumulated CPU time (s) 0.15
Current children cumulated vsize (KiB) 12976

[startup+0.306164 s]
/proc/loadavg: 1.00 1.00 1.00 5/38 3136
/proc/meminfo: memFree=417416/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=0
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 1520 0 0 0 0 0 0 25 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=1928 CPUtime=0
/proc/3134/stat : 3134 (clasp) S 3126 3126 19908 34817 19908 4202496 292 0 0 0 0 0 0 0 25 0 1 0 68537467 1974272 160 1283457024 134512640 136285277 4290786816 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/3134/statm: 482 160 144 433 0 47 0
[pid=3135] ppid=3126 vsize=2584 CPUtime=0
/proc/3135/stat : 3135 (gringo) S 3126 3126 19908 34817 19908 4202496 403 0 0 0 0 0 0 0 25 0 1 0 68537467 2646016 271 1283457024 134512640 136933539 4291071680 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/3135/statm: 646 271 242 592 0 51 0
[pid=3136] ppid=3126 vsize=8952 CPUtime=0.24
/proc/3136/stat : 3136 (cudf2lp) R 3126 3126 19908 34817 19908 4202496 2341 0 0 0 24 0 0 0 25 0 1 0 68537467 9166848 1898 1283457024 134512640 135786343 4292616256 18446744073709551615 134849790 0 0 6 0 0 0 0 17 0 0 0 0
/proc/3136/statm: 2238 1898 128 311 0 1925 0
Current children cumulated CPU time (s) 0.24
Current children cumulated vsize (KiB) 16060

[startup+0.40617 s]
/proc/loadavg: 1.00 1.00 1.00 5/38 3136
/proc/meminfo: memFree=417416/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=0
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 1520 0 0 0 0 0 0 25 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=1928 CPUtime=0
/proc/3134/stat : 3134 (clasp) S 3126 3126 19908 34817 19908 4202496 292 0 0 0 0 0 0 0 25 0 1 0 68537467 1974272 160 1283457024 134512640 136285277 4290786816 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/3134/statm: 482 160 144 433 0 47 0
[pid=3135] ppid=3126 vsize=2584 CPUtime=0
/proc/3135/stat : 3135 (gringo) S 3126 3126 19908 34817 19908 4202496 403 0 0 0 0 0 0 0 25 0 1 0 68537467 2646016 271 1283457024 134512640 136933539 4291071680 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/3135/statm: 646 271 242 592 0 51 0
[pid=3136] ppid=3126 vsize=9944 CPUtime=0.32
/proc/3136/stat : 3136 (cudf2lp) R 3126 3126 19908 34817 19908 4202496 2666 0 0 0 32 0 0 0 25 0 1 0 68537467 10182656 2223 1283457024 134512640 135786343 4292616256 18446744073709551615 134566203 0 0 6 0 0 0 0 17 0 0 0 0
/proc/3136/statm: 2486 2223 128 311 0 2173 0
Current children cumulated CPU time (s) 0.32
Current children cumulated vsize (KiB) 17052

[startup+0.706199 s]
/proc/loadavg: 1.00 1.00 1.00 5/38 3136
/proc/meminfo: memFree=417416/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=0
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 1520 0 0 0 0 0 0 25 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=1928 CPUtime=0
/proc/3134/stat : 3134 (clasp) S 3126 3126 19908 34817 19908 4202496 292 0 0 0 0 0 0 0 25 0 1 0 68537467 1974272 160 1283457024 134512640 136285277 4290786816 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/3134/statm: 482 160 144 433 0 47 0
[pid=3135] ppid=3126 vsize=2584 CPUtime=0
/proc/3135/stat : 3135 (gringo) S 3126 3126 19908 34817 19908 4202496 403 0 0 0 0 0 0 0 25 0 1 0 68537467 2646016 271 1283457024 134512640 136933539 4291071680 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/3135/statm: 646 271 242 592 0 51 0
[pid=3136] ppid=3126 vsize=15312 CPUtime=0.58
/proc/3136/stat : 3136 (cudf2lp) R 3126 3126 19908 34817 19908 4202496 4264 0 0 0 56 2 0 0 25 0 1 0 68537467 15679488 3468 1283457024 134512640 135786343 4292616256 18446744073709551615 135199389 0 0 6 0 0 0 0 17 0 0 0 0
/proc/3136/statm: 3828 3468 128 311 0 3515 0
Current children cumulated CPU time (s) 0.58
Current children cumulated vsize (KiB) 22420

[startup+1.51511 s]
/proc/loadavg: 1.00 1.00 1.00 2/39 3137
/proc/meminfo: memFree=378008/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=0
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 1520 0 0 0 0 0 0 25 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=1928 CPUtime=0
/proc/3134/stat : 3134 (clasp) S 3126 3126 19908 34817 19908 4202496 292 0 0 0 0 0 0 0 25 0 1 0 68537467 1974272 160 1283457024 134512640 136285277 4290786816 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/3134/statm: 482 160 144 433 0 47 0
[pid=3135] ppid=3126 vsize=2584 CPUtime=0
/proc/3135/stat : 3135 (gringo) S 3126 3126 19908 34817 19908 4202496 403 0 0 0 0 0 0 0 25 0 1 0 68537467 2646016 271 1283457024 134512640 136933539 4291071680 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/3135/statm: 646 271 242 592 0 51 0
[pid=3136] ppid=3126 vsize=38888 CPUtime=1.3
/proc/3136/stat : 3136 (cudf2lp) R 3126 3126 19908 34817 19908 4202496 10811 0 0 0 127 3 0 0 25 0 1 0 68537467 39821312 9213 1283457024 134512640 135786343 4292616256 18446744073709551615 135208284 0 0 6 0 0 0 0 17 0 0 0 0
/proc/3136/statm: 9722 9213 135 311 0 9409 0
Current children cumulated CPU time (s) 1.3
Current children cumulated vsize (KiB) 45996

[startup+3.11542 s]
/proc/loadavg: 1.00 1.00 1.00 3/38 3137
/proc/meminfo: memFree=395976/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=1.65
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 14834 0 0 0 0 158 7 17 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=7392 CPUtime=1.26
/proc/3134/stat : 3134 (clasp) R 3126 3126 19908 34817 19908 4202496 1756 0 0 0 126 0 0 0 19 0 1 0 68537467 7569408 1621 1283457024 134512640 136285277 4290786816 18446744073709551615 134966715 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3134/statm: 1848 1621 234 433 0 1413 0
Current children cumulated CPU time (s) 2.91
Current children cumulated vsize (KiB) 9988

[startup+6.3062 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 3137
/proc/meminfo: memFree=393008/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=1.65
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 14834 0 0 0 0 158 7 17 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=7656 CPUtime=4.44
/proc/3134/stat : 3134 (clasp) R 3126 3126 19908 34817 19908 4202496 1864 0 0 0 444 0 0 0 25 0 1 0 68537467 7839744 1709 1283457024 134512640 136285277 4290786816 18446744073709551615 134955707 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3134/statm: 1914 1709 234 433 0 1479 0
Current children cumulated CPU time (s) 6.09
Current children cumulated vsize (KiB) 10252

[startup+12.7075 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 3138
/proc/meminfo: memFree=392520/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=1.65
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 14834 0 0 0 0 158 7 17 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=9232 CPUtime=10.84
/proc/3134/stat : 3134 (clasp) R 3126 3126 19908 34817 19908 4202496 2312 0 0 0 1084 0 0 0 25 0 1 0 68537467 9453568 2100 1283457024 134512640 136285277 4290786816 18446744073709551615 134960063 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3134/statm: 2308 2100 234 433 0 1873 0
Current children cumulated CPU time (s) 12.49
Current children cumulated vsize (KiB) 11828

[startup+25.5111 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 3139
/proc/meminfo: memFree=390908/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=1.65
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 14834 0 0 0 0 158 7 17 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=9760 CPUtime=23.64
/proc/3134/stat : 3134 (clasp) R 3126 3126 19908 34817 19908 4202496 2599 0 0 0 2363 1 0 0 25 0 1 0 68537467 9994240 2234 1283457024 134512640 136285277 4290786816 18446744073709551615 134960063 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3134/statm: 2440 2234 234 433 0 2005 0
Current children cumulated CPU time (s) 25.29
Current children cumulated vsize (KiB) 12356

[startup+51.1064 s]
/proc/loadavg: 1.00 1.00 1.00 2/36 3139
/proc/meminfo: memFree=390552/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=1.65
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 14834 0 0 0 0 158 7 17 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=10368 CPUtime=49.21
/proc/3134/stat : 3134 (clasp) R 3126 3126 19908 34817 19908 4202496 2759 0 0 0 4920 1 0 0 25 0 1 0 68537467 10616832 2386 1283457024 134512640 136285277 4290786816 18446744073709551615 134966723 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3134/statm: 2592 2386 234 433 0 2157 0
Current children cumulated CPU time (s) 50.86
Current children cumulated vsize (KiB) 12964

[startup+102.307 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 3139
/proc/meminfo: memFree=389692/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=1.65
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 14834 0 0 0 0 158 7 17 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=10636 CPUtime=100.36
/proc/3134/stat : 3134 (clasp) R 3126 3126 19908 34817 19908 4202496 3195 0 0 0 10035 1 0 0 25 0 1 0 68537467 10891264 2453 1283457024 134512640 136285277 4290786816 18446744073709551615 134615133 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3134/statm: 2659 2453 234 433 0 2224 0
Current children cumulated CPU time (s) 102.01
Current children cumulated vsize (KiB) 13232

[startup+162.31 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 3139
/proc/meminfo: memFree=388700/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=1.65
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 14834 0 0 0 0 158 7 17 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=11516 CPUtime=160.33
/proc/3134/stat : 3134 (clasp) R 3126 3126 19908 34817 19908 4202496 4369 0 0 0 16032 1 0 0 25 0 1 0 68537467 11792384 2671 1283457024 134512640 136285277 4290786816 18446744073709551615 134734768 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3134/statm: 2879 2671 234 433 0 2444 0
Current children cumulated CPU time (s) 161.98
Current children cumulated vsize (KiB) 14112

[startup+222.312 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 3139
/proc/meminfo: memFree=388452/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=1.65
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 14834 0 0 0 0 158 7 17 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=11944 CPUtime=220.3
/proc/3134/stat : 3134 (clasp) R 3126 3126 19908 34817 19908 4202496 4943 0 0 0 22029 1 0 0 25 0 1 0 68537467 12230656 2778 1283457024 134512640 136285277 4290786816 18446744073709551615 134959509 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3134/statm: 2986 2778 234 433 0 2551 0
Current children cumulated CPU time (s) 221.95
Current children cumulated vsize (KiB) 14540

[startup+282.305 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 3139
/proc/meminfo: memFree=388328/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=1.65
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 14834 0 0 0 0 158 7 17 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=12292 CPUtime=280.23
/proc/3134/stat : 3134 (clasp) R 3126 3126 19908 34817 19908 4202496 5466 0 0 0 28022 1 0 0 25 0 1 0 68537467 12587008 2862 1283457024 134512640 136285277 4290786816 18446744073709551615 134669900 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3134/statm: 3073 2862 234 433 0 2638 0
Current children cumulated CPU time (s) 281.88
Current children cumulated vsize (KiB) 14888



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+290.506 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 3139
/proc/meminfo: memFree=388328/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=1.65
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 14834 0 0 0 0 158 7 17 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=12276 CPUtime=288.42
/proc/3134/stat : 3134 (clasp) R 3126 3126 19908 34817 19908 4202496 5530 0 0 0 28841 1 0 0 25 0 1 0 68537467 12570624 2861 1283457024 134512640 136285277 4290786816 18446744073709551615 134959509 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3134/statm: 3069 2861 234 433 0 2634 0
Current children cumulated CPU time (s) 290.07
Current children cumulated vsize (KiB) 14872

Sending User defined signal 1 to process tree (bottom up)
Sleeping 10 seconds

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

[startup+290.506 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 3139
/proc/meminfo: memFree=388328/1048576 swapFree=0/0
[pid=3126] ppid=3125 vsize=2596 CPUtime=1.65
/proc/3126/stat : 3126 (aspcud-1.5) S 3125 3126 19908 34817 19908 4202496 581 14834 0 0 0 0 158 7 17 0 1 0 68537466 2658304 298 1283457024 134512640 135304128 4294654368 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3126/statm: 649 298 251 194 0 36 0
[pid=3134] ppid=3126 vsize=12276 CPUtime=288.42
/proc/3134/stat : 3134 (clasp) R 3126 3126 19908 34817 19908 4202496 5530 0 0 0 28841 1 0 0 25 0 1 0 68537467 12570624 2861 1283457024 134512640 136285277 4290786816 18446744073709551615 134959509 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/3134/statm: 3069 2861 234 433 0 2634 0
Current children cumulated CPU time (s) 290.07
Current children cumulated vsize (KiB) 14872

Child status: 0
Real time (s): 290.529
CPU time (s): 290.098
CPU user time (s): 290.006
CPU system time (s): 0.092005
CPU usage (%): 99.8517
Max. virtual memory (cumulated for all children) (KiB): 46648

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 290.006
system time used= 0.092005
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 24517
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= 195
involuntary context switches= 3657

runsolver used 0 second user time and 0.008 second system time

The end