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/7bf50d1c-9b1b-11df-8b50-00163e46d37a.cudf.dudf-real.log.runsolver ./aspcud-1.5 /home/misc2010/data/2011/dudf-real//7bf50d1c-9b1b-11df-8b50-00163e46d37a.cudf /home/misc2010/tmp/201108311143/aspcud-1.5/7bf50d1c-9b1b-11df-8b50-00163e46d37a.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.12 1.04 1.01 3/38 30408
/proc/meminfo: memFree=764148/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=0.01
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 1519 0 0 0 1 0 0 25 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=2596 CPUtime=0
/proc/30406/stat : 30406 (aspcud-1.5) R 30398 30398 19908 34817 19908 4202560 110 0 0 0 0 0 0 0 25 0 1 0 65971223 2658304 131 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 0 6 1132494585 0 0 0 17 0 0 0 0
/proc/30406/statm: 649 131 83 194 0 36 0
[pid=30407] ppid=30398 vsize=2596 CPUtime=0
/proc/30407/stat : 30407 (aspcud-1.5) R 30398 30398 19908 34817 19908 4202560 110 0 0 0 0 0 0 0 25 0 1 0 65971223 2658304 131 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 0 6 1132494585 0 0 0 17 0 0 0 0
/proc/30407/statm: 649 131 83 194 0 36 0
[pid=30408] ppid=30398 vsize=1444 CPUtime=0
/proc/30408/stat : 30408 (cudf2lp) D 30398 30398 19908 34817 19908 4202496 258 0 0 0 0 0 0 0 25 0 1 0 65971223 1478656 126 1283457024 134512640 135786343 4289205504 18446744073709551615 135258478 0 0 6 0 18446744071564252162 0 0 17 0 0 0 0
/proc/30408/statm: 361 126 112 311 0 48 0

[startup+0.139507 s]
/proc/loadavg: 1.12 1.04 1.01 3/38 30408
/proc/meminfo: memFree=764148/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=0.01
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 1519 0 0 0 1 0 0 25 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=1932 CPUtime=0
/proc/30406/stat : 30406 (clasp) S 30398 30398 19908 34817 19908 4202496 292 0 0 0 0 0 0 0 25 0 1 0 65971223 1978368 160 1283457024 134512640 136285277 4288426944 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/30406/statm: 483 160 144 433 0 48 0
[pid=30407] ppid=30398 vsize=2584 CPUtime=0
/proc/30407/stat : 30407 (gringo) S 30398 30398 19908 34817 19908 4202496 404 0 0 0 0 0 0 0 25 0 1 0 65971223 2646016 272 1283457024 134512640 136933539 4288152560 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/30407/statm: 646 272 242 592 0 51 0
[pid=30408] ppid=30398 vsize=5476 CPUtime=0.1
/proc/30408/stat : 30408 (cudf2lp) R 30398 30398 19908 34817 19908 4202496 1359 0 0 0 8 2 0 0 25 0 1 0 65971223 5607424 1093 1283457024 134512640 135786343 4289205504 18446744073709551615 135052128 0 0 6 0 0 0 0 17 0 0 0 0
/proc/30408/statm: 1369 1093 128 311 0 1056 0
Current children cumulated CPU time (s) 0.11
Current children cumulated vsize (KiB) 12588

[startup+0.210852 s]
/proc/loadavg: 1.12 1.04 1.01 3/38 30408
/proc/meminfo: memFree=764148/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=0.01
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 1519 0 0 0 1 0 0 25 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=1932 CPUtime=0
/proc/30406/stat : 30406 (clasp) S 30398 30398 19908 34817 19908 4202496 292 0 0 0 0 0 0 0 25 0 1 0 65971223 1978368 160 1283457024 134512640 136285277 4288426944 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/30406/statm: 483 160 144 433 0 48 0
[pid=30407] ppid=30398 vsize=2584 CPUtime=0
/proc/30407/stat : 30407 (gringo) S 30398 30398 19908 34817 19908 4202496 404 0 0 0 0 0 0 0 25 0 1 0 65971223 2646016 272 1283457024 134512640 136933539 4288152560 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/30407/statm: 646 272 242 592 0 51 0
[pid=30408] ppid=30398 vsize=6184 CPUtime=0.15
/proc/30408/stat : 30408 (cudf2lp) R 30398 30398 19908 34817 19908 4202496 1580 0 0 0 12 3 0 0 25 0 1 0 65971223 6332416 1314 1283457024 134512640 135786343 4289205504 18446744073709551615 134701290 0 0 6 0 0 0 0 17 0 0 0 0
/proc/30408/statm: 1546 1314 128 311 0 1233 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 13296

[startup+0.303489 s]
/proc/loadavg: 1.12 1.04 1.01 3/38 30408
/proc/meminfo: memFree=764148/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=0.01
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 1519 0 0 0 1 0 0 25 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=1932 CPUtime=0
/proc/30406/stat : 30406 (clasp) S 30398 30398 19908 34817 19908 4202496 292 0 0 0 0 0 0 0 25 0 1 0 65971223 1978368 160 1283457024 134512640 136285277 4288426944 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/30406/statm: 483 160 144 433 0 48 0
[pid=30407] ppid=30398 vsize=2584 CPUtime=0
/proc/30407/stat : 30407 (gringo) S 30398 30398 19908 34817 19908 4202496 404 0 0 0 0 0 0 0 25 0 1 0 65971223 2646016 272 1283457024 134512640 136933539 4288152560 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/30407/statm: 646 272 242 592 0 51 0
[pid=30408] ppid=30398 vsize=8868 CPUtime=0.23
/proc/30408/stat : 30408 (cudf2lp) R 30398 30398 19908 34817 19908 4202496 2334 0 0 0 20 3 0 0 25 0 1 0 65971223 9080832 1891 1283457024 134512640 135786343 4289205504 18446744073709551615 134924518 0 0 6 0 0 0 0 17 0 0 0 0
/proc/30408/statm: 2217 1891 128 311 0 1904 0
Current children cumulated CPU time (s) 0.24
Current children cumulated vsize (KiB) 15980

[startup+0.707518 s]
/proc/loadavg: 1.12 1.04 1.01 3/38 30408
/proc/meminfo: memFree=764148/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=0.01
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 1519 0 0 0 1 0 0 25 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=1932 CPUtime=0
/proc/30406/stat : 30406 (clasp) S 30398 30398 19908 34817 19908 4202496 292 0 0 0 0 0 0 0 25 0 1 0 65971223 1978368 160 1283457024 134512640 136285277 4288426944 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/30406/statm: 483 160 144 433 0 48 0
[pid=30407] ppid=30398 vsize=2584 CPUtime=0
/proc/30407/stat : 30407 (gringo) S 30398 30398 19908 34817 19908 4202496 404 0 0 0 0 0 0 0 25 0 1 0 65971223 2646016 272 1283457024 134512640 136933539 4288152560 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/30407/statm: 646 272 242 592 0 51 0
[pid=30408] ppid=30398 vsize=15496 CPUtime=0.58
/proc/30408/stat : 30408 (cudf2lp) R 30398 30398 19908 34817 19908 4202496 4362 0 0 0 55 3 0 0 25 0 1 0 65971223 15867904 3517 1283457024 134512640 135786343 4289205504 18446744073709551615 135208297 0 0 6 0 0 0 0 17 0 0 0 0
/proc/30408/statm: 3874 3517 128 311 0 3561 0
Current children cumulated CPU time (s) 0.59
Current children cumulated vsize (KiB) 22608

[startup+1.51288 s]
/proc/loadavg: 1.12 1.04 1.01 2/39 30409
/proc/meminfo: memFree=724908/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=0.01
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 1519 0 0 0 1 0 0 25 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=1932 CPUtime=0
/proc/30406/stat : 30406 (clasp) S 30398 30398 19908 34817 19908 4202496 292 0 0 0 0 0 0 0 25 0 1 0 65971223 1978368 160 1283457024 134512640 136285277 4288426944 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/30406/statm: 483 160 144 433 0 48 0
[pid=30407] ppid=30398 vsize=2584 CPUtime=0
/proc/30407/stat : 30407 (gringo) S 30398 30398 19908 34817 19908 4202496 404 0 0 0 0 0 0 0 25 0 1 0 65971223 2646016 272 1283457024 134512640 136933539 4288152560 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/30407/statm: 646 272 242 592 0 51 0
[pid=30408] ppid=30398 vsize=35600 CPUtime=1.35
/proc/30408/stat : 30408 (cudf2lp) R 30398 30398 19908 34817 19908 4202496 11250 0 0 0 129 6 0 0 25 0 1 0 65971223 36454400 8685 1283457024 134512640 135786343 4289205504 18446744073709551615 135191439 0 0 6 0 0 0 0 17 0 0 0 0
/proc/30408/statm: 8900 8685 135 311 0 8587 0
Current children cumulated CPU time (s) 1.36
Current children cumulated vsize (KiB) 42712

[startup+3.11354 s]
/proc/loadavg: 1.12 1.04 1.01 2/37 30409
/proc/meminfo: memFree=733916/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=1.94
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 17198 0 0 0 1 182 11 17 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=12992 CPUtime=1.01
/proc/30406/stat : 30406 (clasp) R 30398 30398 19908 34817 19908 4202496 3648 0 0 0 99 2 0 0 19 0 1 0 65971223 13303808 3009 1283457024 134512640 136285277 4288426944 18446744073709551615 134959776 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/30406/statm: 3248 3009 234 433 0 2813 0
Current children cumulated CPU time (s) 2.95
Current children cumulated vsize (KiB) 15588

[startup+6.30431 s]
/proc/loadavg: 1.11 1.04 1.01 2/37 30409
/proc/meminfo: memFree=722880/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=1.94
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 17198 0 0 0 1 182 11 17 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=25160 CPUtime=4.19
/proc/30406/stat : 30406 (clasp) R 30398 30398 19908 34817 19908 4202496 6707 0 0 0 417 2 0 0 25 0 1 0 65971223 25763840 6068 1283457024 134512640 136285277 4288426944 18446744073709551615 134650374 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/30406/statm: 6290 6068 234 433 0 5855 0
Current children cumulated CPU time (s) 6.13
Current children cumulated vsize (KiB) 27756

[startup+12.7058 s]
/proc/loadavg: 1.10 1.04 1.01 2/37 30410
/proc/meminfo: memFree=712968/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=1.94
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 17198 0 0 0 1 182 11 17 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=34528 CPUtime=10.59
/proc/30406/stat : 30406 (clasp) R 30398 30398 19908 34817 19908 4202496 9010 0 0 0 1055 4 0 0 25 0 1 0 65971223 35356672 8371 1283457024 134512640 136285277 4288426944 18446744073709551615 134639124 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/30406/statm: 8632 8371 234 433 0 8197 0
Current children cumulated CPU time (s) 12.53
Current children cumulated vsize (KiB) 37124

[startup+25.5084 s]
/proc/loadavg: 1.08 1.03 1.01 2/36 30410
/proc/meminfo: memFree=708272/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=1.94
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 17198 0 0 0 1 182 11 17 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=39816 CPUtime=23.38
/proc/30406/stat : 30406 (clasp) R 30398 30398 19908 34817 19908 4202496 10214 0 0 0 2334 4 0 0 25 0 1 0 65971223 40771584 9575 1283457024 134512640 136285277 4288426944 18446744073709551615 134733720 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/30406/statm: 9954 9575 234 433 0 9519 0
Current children cumulated CPU time (s) 25.32
Current children cumulated vsize (KiB) 42412

[startup+51.1133 s]
/proc/loadavg: 1.05 1.03 1.00 2/36 30410
/proc/meminfo: memFree=708148/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=1.94
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 17198 0 0 0 1 182 11 17 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=39816 CPUtime=48.97
/proc/30406/stat : 30406 (clasp) R 30398 30398 19908 34817 19908 4202496 10243 0 0 0 4891 6 0 0 25 0 1 0 65971223 40771584 9604 1283457024 134512640 136285277 4288426944 18446744073709551615 134669840 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/30406/statm: 9954 9604 234 433 0 9519 0
Current children cumulated CPU time (s) 50.91
Current children cumulated vsize (KiB) 42412

[startup+102.314 s]
/proc/loadavg: 1.02 1.02 1.00 2/35 30410
/proc/meminfo: memFree=699104/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=1.94
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 17198 0 0 0 1 182 11 17 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=48872 CPUtime=100.13
/proc/30406/stat : 30406 (clasp) R 30398 30398 19908 34817 19908 4202496 12668 0 0 0 10005 8 0 0 25 0 1 0 65971223 50044928 11820 1283457024 134512640 136285277 4288426944 18446744073709551615 134966767 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/30406/statm: 12218 11820 234 433 0 11783 0
Current children cumulated CPU time (s) 102.07
Current children cumulated vsize (KiB) 51468

[startup+162.307 s]
/proc/loadavg: 1.01 1.02 1.00 2/35 30410
/proc/meminfo: memFree=686952/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=1.94
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 17198 0 0 0 1 182 11 17 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=60952 CPUtime=160.07
/proc/30406/stat : 30406 (clasp) R 30398 30398 19908 34817 19908 4202496 15695 0 0 0 15995 12 0 0 25 0 1 0 65971223 62414848 14847 1283457024 134512640 136285277 4288426944 18446744073709551615 134964956 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/30406/statm: 15238 14847 234 433 0 14803 0
Current children cumulated CPU time (s) 162.01
Current children cumulated vsize (KiB) 63548

[startup+222.31 s]
/proc/loadavg: 1.00 1.01 1.00 2/35 30410
/proc/meminfo: memFree=686952/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=1.94
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 17198 0 0 0 1 182 11 17 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=60952 CPUtime=220.02
/proc/30406/stat : 30406 (clasp) R 30398 30398 19908 34817 19908 4202496 15695 0 0 0 21990 12 0 0 25 0 1 0 65971223 62414848 14847 1283457024 134512640 136285277 4288426944 18446744073709551615 134966793 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/30406/statm: 15238 14847 234 433 0 14803 0
Current children cumulated CPU time (s) 221.96
Current children cumulated vsize (KiB) 63548

[startup+282.314 s]
/proc/loadavg: 1.00 1.01 1.00 2/35 30410
/proc/meminfo: memFree=686952/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=1.94
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 17198 0 0 0 1 182 11 17 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=60952 CPUtime=279.97
/proc/30406/stat : 30406 (clasp) R 30398 30398 19908 34817 19908 4202496 15695 0 0 0 27985 12 0 0 25 0 1 0 65971223 62414848 14847 1283457024 134512640 136285277 4288426944 18446744073709551615 134963435 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/30406/statm: 15238 14847 234 433 0 14803 0
Current children cumulated CPU time (s) 281.91
Current children cumulated vsize (KiB) 63548



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+290.415 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 30410
/proc/meminfo: memFree=686952/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=1.94
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 17198 0 0 0 1 182 11 17 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=60952 CPUtime=288.07
/proc/30406/stat : 30406 (clasp) R 30398 30398 19908 34817 19908 4202496 15695 0 0 0 28795 12 0 0 25 0 1 0 65971223 62414848 14847 1283457024 134512640 136285277 4288426944 18446744073709551615 134670227 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/30406/statm: 15238 14847 234 433 0 14803 0
Current children cumulated CPU time (s) 290.01
Current children cumulated vsize (KiB) 63548

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.415 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 30410
/proc/meminfo: memFree=686952/1048576 swapFree=0/0
[pid=30398] ppid=30397 vsize=2596 CPUtime=1.94
/proc/30398/stat : 30398 (aspcud-1.5) S 30397 30398 19908 34817 19908 4202496 581 17198 0 0 0 1 182 11 17 0 1 0 65971222 2658304 298 1283457024 134512640 135304128 4287228560 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/30398/statm: 649 298 251 194 0 36 0
[pid=30406] ppid=30398 vsize=60952 CPUtime=288.07
/proc/30406/stat : 30406 (clasp) R 30398 30398 19908 34817 19908 4202496 15695 0 0 0 28795 12 0 0 25 0 1 0 65971223 62414848 14847 1283457024 134512640 136285277 4288426944 18446744073709551615 134670227 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/30406/statm: 15238 14847 234 433 0 14803 0
Current children cumulated CPU time (s) 290.01
Current children cumulated vsize (KiB) 63548

Child status: 0
Real time (s): 290.445
CPU time (s): 290.05
CPU user time (s): 289.794
CPU system time (s): 0.256016
CPU usage (%): 99.8642
Max. virtual memory (cumulated for all children) (KiB): 63548

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 289.794
system time used= 0.256016
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 37154
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= 548
involuntary context switches= 3922

runsolver used 0 second user time and 0 second system time

The end