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/ca8f656c-db9e-11df-b9cf-00163e3d3b7c.cudf.dudf-real.log.runsolver ./aspcud-1.5 /home/misc2010/data/2011/dudf-real//ca8f656c-db9e-11df-b9cf-00163e3d3b7c.cudf /home/misc2010/tmp/201108300820/aspcud-1.5/ca8f656c-db9e-11df-b9cf-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.07 1.05 1.01 4/36 15349
/proc/meminfo: memFree=932848/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2588 CPUtime=0
/proc/15348/stat : 15348 (aspcud-1.5) R 15347 15348 2160 34817 2160 4202496 366 0 0 0 0 0 0 0 25 0 1 0 57901216 2650112 279 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/15348/statm: 647 279 234 194 0 34 0
[pid=15349] ppid=15348 vsize=2588 CPUtime=0
/proc/15349/stat : 15349 (aspcud-1.5) R 15348 15348 2160 34817 2160 4202560 0 0 0 0 0 0 0 0 25 0 1 0 57901216 2650112 45 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/15349/statm: 647 45 0 194 0 34 0

[startup+0.127105 s]
/proc/loadavg: 1.07 1.05 1.01 4/36 15349
/proc/meminfo: memFree=932848/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=0
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 1522 0 0 0 0 0 0 25 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.207114 s]
/proc/loadavg: 1.07 1.05 1.01 4/36 15349
/proc/meminfo: memFree=932848/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=0
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 1522 0 0 0 0 0 0 25 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.307114 s]
/proc/loadavg: 1.07 1.05 1.01 4/36 15349
/proc/meminfo: memFree=932848/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=0
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 1522 0 0 0 0 0 0 25 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.707197 s]
/proc/loadavg: 1.07 1.05 1.01 4/36 15349
/proc/meminfo: memFree=932848/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=0
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 1522 0 0 0 0 0 0 25 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+1.51047 s]
/proc/loadavg: 1.07 1.05 1.01 2/39 15359
/proc/meminfo: memFree=902116/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=0
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 1522 0 0 0 0 0 0 25 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=1924 CPUtime=0
/proc/15357/stat : 15357 (clasp) S 15348 15348 2160 34817 2160 4202496 273 0 18 0 0 0 0 0 22 0 1 0 57901217 1970176 159 1283457024 134512640 136285277 4288499120 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/15357/statm: 481 159 144 433 0 46 0
[pid=15358] ppid=15348 vsize=2580 CPUtime=0
/proc/15358/stat : 15358 (gringo) S 15348 15348 2160 34817 2160 4202496 380 0 23 0 0 0 0 0 22 0 1 0 57901217 2641920 271 1283457024 134512640 136933539 4290986528 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/15358/statm: 645 271 242 592 0 50 0
[pid=15359] ppid=15348 vsize=27588 CPUtime=1.01
/proc/15359/stat : 15359 (cudf2lp) R 15348 15348 2160 34817 2160 4202496 8921 0 15 0 95 6 0 0 25 0 1 0 57901217 28250112 6663 1283457024 134512640 135786343 4291819584 18446744073709551615 134543201 0 0 6 0 0 0 0 17 0 0 0 0
/proc/15359/statm: 6897 6663 136 311 0 6584 0
Current children cumulated CPU time (s) 1.01
Current children cumulated vsize (KiB) 34688

[startup+3.10465 s]
/proc/loadavg: 1.07 1.05 1.01 4/39 15359
/proc/meminfo: memFree=865740/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=0
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 1522 0 0 0 0 0 0 25 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=23416 CPUtime=0.06
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4202496 6629 0 21 0 6 0 0 0 18 0 1 0 57901217 23977984 5454 1283457024 134512640 136285277 4288499120 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 5854 5454 177 433 0 5419 0
[pid=15358] ppid=15348 vsize=31592 CPUtime=1.18
/proc/15358/stat : 15358 (gringo) R 15348 15348 2160 34817 2160 4202496 9880 0 23 0 110 8 0 0 18 0 1 0 57901217 32350208 6767 1283457024 134512640 136933539 4290986528 18446744073709551615 135765486 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/15358/statm: 7898 6767 242 592 0 7303 0
[pid=15359] ppid=15348 vsize=27592 CPUtime=1.28
/proc/15359/stat : 15359 (cudf2lp) R 15348 15348 2160 34817 2160 4202496 8925 0 15 0 122 6 0 0 25 0 1 0 57901217 28254208 6667 1283457024 134512640 135786343 4291819584 18446744073709551615 135258574 0 0 6 0 0 0 0 17 0 0 0 0
/proc/15359/statm: 6898 6667 139 311 0 6585 0
Current children cumulated CPU time (s) 2.52
Current children cumulated vsize (KiB) 85196

[startup+6.30544 s]
/proc/loadavg: 1.14 1.07 1.01 2/38 15360
/proc/meminfo: memFree=743244/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=1.41
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 10450 0 15 0 0 133 8 18 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=83292 CPUtime=0.64
/proc/15357/stat : 15357 (clasp) S 15348 15348 2160 34817 2160 4202496 23828 0 21 0 61 3 0 0 18 0 1 0 57901217 85291008 20204 1283457024 134512640 136285277 4288499120 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/15357/statm: 20823 20204 177 433 0 20388 0
[pid=15358] ppid=15348 vsize=156084 CPUtime=3.69
/proc/15358/stat : 15358 (gringo) R 15348 15348 2160 34817 2160 4202496 45443 0 23 0 344 25 0 0 21 0 1 0 57901217 159830016 30059 1283457024 134512640 136933539 4290986528 18446744073709551615 134734605 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/15358/statm: 39021 30059 253 592 0 38426 0
Current children cumulated CPU time (s) 5.74
Current children cumulated vsize (KiB) 241972

[startup+12.7071 s]
/proc/loadavg: 1.13 1.06 1.01 2/37 15360
/proc/meminfo: memFree=795968/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=5.62
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 58958 0 38 0 0 523 39 18 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=132336 CPUtime=6.53
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4202496 39516 0 21 0 644 9 0 0 25 0 1 0 57901217 135512064 32856 1283457024 134512640 136285277 4288499120 18446744073709551615 134650356 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 33084 32856 234 433 0 32649 0
Current children cumulated CPU time (s) 12.15
Current children cumulated vsize (KiB) 134932

[startup+25.5098 s]
/proc/loadavg: 1.10 1.06 1.01 2/37 15362
/proc/meminfo: memFree=720328/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=5.62
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 58958 0 38 0 0 523 39 18 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=195328 CPUtime=19.31
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4202496 55247 0 21 0 1917 14 0 0 25 0 1 0 57901217 200015872 48586 1283457024 134512640 136285277 4288499120 18446744073709551615 134723339 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 48832 48586 234 433 0 48397 0
Current children cumulated CPU time (s) 24.93
Current children cumulated vsize (KiB) 197924

[startup+51.115 s]
/proc/loadavg: 1.07 1.05 1.01 2/37 15364
/proc/meminfo: memFree=441204/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=5.62
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 58958 0 38 0 0 523 39 18 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=482588 CPUtime=44.88
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4202496 127080 0 21 0 4452 36 0 0 25 0 1 0 57901217 494170112 120419 1283457024 134512640 136285277 4288499120 18446744073709551615 134649439 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 120647 120419 234 433 0 120212 0
Current children cumulated CPU time (s) 50.5
Current children cumulated vsize (KiB) 485184

[startup+102.309 s]
/proc/loadavg: 1.03 1.04 1.00 2/36 15367
/proc/meminfo: memFree=203140/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=5.62
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 58958 0 38 0 0 523 39 18 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=711640 CPUtime=95.97
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4202496 184276 0 21 0 9551 46 0 0 25 0 1 0 57901217 728719360 177615 1283457024 134512640 136285277 4288499120 18446744073709551615 134955207 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 177910 177615 234 433 0 177475 0
Current children cumulated CPU time (s) 101.59
Current children cumulated vsize (KiB) 714236

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

[startup+102.409 s]
/proc/loadavg: 1.03 1.04 1.00 2/36 15367
/proc/meminfo: memFree=203140/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=5.62
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 58958 0 38 0 0 523 39 18 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=711640 CPUtime=96.07
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4202496 184276 0 21 0 9561 46 0 0 25 0 1 0 57901217 728719360 177615 1283457024 134512640 136285277 4288499120 18446744073709551615 134735638 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 177910 177615 234 433 0 177475 0
Current children cumulated CPU time (s) 101.69
Current children cumulated vsize (KiB) 714236

[startup+128.008 s]
/proc/loadavg: 1.02 1.04 1.00 2/36 15367
/proc/meminfo: memFree=183176/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=5.62
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 58958 0 38 0 0 523 39 18 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=731628 CPUtime=121.58
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4202496 189272 0 21 0 12110 48 0 0 25 0 1 0 57901217 749187072 182611 1283457024 134512640 136285277 4288499120 18446744073709551615 134723339 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 182907 182611 234 433 0 182472 0
Current children cumulated CPU time (s) 127.2
Current children cumulated vsize (KiB) 734224

[startup+140.812 s]
/proc/loadavg: 1.01 1.04 1.00 2/36 15367
/proc/meminfo: memFree=80380/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=5.62
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 58958 0 38 0 0 523 39 18 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=834268 CPUtime=134.38
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4202496 214936 0 21 0 13382 56 0 0 25 0 1 0 57901217 854290432 208275 1283457024 134512640 136285277 4288499120 18446744073709551615 134959509 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 208567 208275 234 433 0 208132 0
Current children cumulated CPU time (s) 140
Current children cumulated vsize (KiB) 836864

[startup+147.213 s]
/proc/loadavg: 1.01 1.04 1.00 2/35 15367
/proc/meminfo: memFree=4132/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=5.62
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 58958 0 38 0 0 523 39 18 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=934128 CPUtime=140.76
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4202496 239896 0 21 0 14003 73 0 0 25 0 1 0 57901217 956547072 233235 1283457024 134512640 136285277 4288499120 18446744073709551615 134965224 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 233532 233235 234 433 0 233097 0
Current children cumulated CPU time (s) 146.38
Current children cumulated vsize (KiB) 936724

[startup+148.814 s]
/proc/loadavg: 1.01 1.04 1.00 2/35 15367
/proc/meminfo: memFree=4132/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=5.62
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 58958 0 38 0 0 523 39 18 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=960352 CPUtime=142.35
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4202496 246260 0 21 0 14158 77 0 0 25 0 1 0 57901217 983400448 239599 1283457024 134512640 136285277 4288499120 18446744073709551615 134639147 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 240088 239599 234 433 0 239653 0
Current children cumulated CPU time (s) 147.97
Current children cumulated vsize (KiB) 962948

[startup+149.614 s]
/proc/loadavg: 1.09 1.05 1.01 2/35 15367
/proc/meminfo: memFree=4344/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=5.62
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 58958 0 38 0 0 523 39 18 0 1 0 57901216 2658304 298 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 298 251 194 0 36 0
[pid=15357] ppid=15348 vsize=973684 CPUtime=143.15
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4202496 249473 0 21 0 14235 80 0 0 25 0 1 0 57901217 997052416 242812 1283457024 134512640 136285277 4288499120 18446744073709551615 134639147 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 243421 242812 234 433 0 242986 0
Current children cumulated CPU time (s) 148.77
Current children cumulated vsize (KiB) 976280

[startup+150.414 s]
/proc/loadavg: 1.09 1.05 1.01 2/35 15367
/proc/meminfo: memFree=4344/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=5.62
/proc/15348/stat : 15348 (aspcud-1.5) S 15347 15348 2160 34817 2160 4202496 581 58958 0 38 0 0 523 39 18 0 1 0 57901216 2658304 89 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/15348/statm: 649 89 42 194 0 36 0
[pid=15357] ppid=15348 vsize=986096 CPUtime=143.95
/proc/15357/stat : 15357 (clasp) R 15348 15348 2160 34817 2160 4204544 252432 0 21 0 14311 84 0 0 25 0 1 0 57901217 1009762304 245574 1283457024 134512640 136285277 4288499120 18446744073709551615 135658630 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/15357/statm: 246524 245574 37 433 0 246089 0
Current children cumulated CPU time (s) 149.57
Current children cumulated vsize (KiB) 988692

[startup+151.205 s]
/proc/loadavg: 1.09 1.05 1.01 1/36 15369
/proc/meminfo: memFree=985412/1048576 swapFree=0/0
[pid=15348] ppid=15347 vsize=2596 CPUtime=149.73
/proc/15348/stat : 15348 (aspcud-1.5) D 15347 15348 2160 34817 2160 4202496 741 311721 17 65 0 0 14837 136 18 0 1 0 57901216 2658304 203 1283457024 134512640 135304128 4287343264 18446744073709551615 4294960130 0 0 16902 1132543225 18446744071564252162 0 0 17 0 0 0 0
/proc/15348/statm: 649 203 156 194 0 36 0
Current children cumulated CPU time (s) 149.73
Current children cumulated vsize (KiB) 2596

Child status: 0
Real time (s): 151.281
CPU time (s): 149.741
CPU user time (s): 148.377
CPU system time (s): 1.36408
CPU usage (%): 98.982
Max. virtual memory (cumulated for all children) (KiB): 988692

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 148.377
system time used= 1.36408
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 314889
page faults= 88
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 7036
involuntary context switches= 7876

runsolver used 0 second user time and 0.060003 second system time

The end