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/aspuncud-user-1.0/29180036-5408-11df-9f57-00163e7a6f5e.cudf.dudf-real.log.runsolver ./aspuncud-user-1.0 /home/misc2010/data/2011/dudf-real//29180036-5408-11df-9f57-00163e7a6f5e.cudf /home/misc2010/tmp/201108300820/aspuncud-user-1.0/29180036-5408-11df-9f57-00163e7a6f5e.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.05 1.02 1.00 5/39 5576
/proc/meminfo: memFree=906448/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2584 CPUtime=0
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 373 0 0 0 0 0 0 0 18 0 1 0 52707165 2646016 279 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/5573/statm: 646 279 234 194 0 33 0
[pid=5574] ppid=5573 vsize=2584 CPUtime=0
/proc/5574/stat : 5574 (aspuncud-user-1) S 5573 5573 2160 34817 2160 4202560 118 0 0 0 0 0 0 0 18 0 1 0 52707166 2646016 133 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0
/proc/5574/statm: 646 133 87 194 0 33 0
[pid=5575] ppid=5574 vsize=2584 CPUtime=0
/proc/5575/stat : 5575 (aspuncud-user-1) R 5574 5573 2160 34817 2160 4202560 126 0 0 0 0 0 0 0 25 0 1 0 52707166 2646016 150 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/5575/statm: 646 150 104 194 0 33 0
[pid=5576] ppid=5575 vsize=2584 CPUtime=0
/proc/5576/stat : 5576 (aspuncud-user-1) R 5575 5573 2160 34817 2160 4202560 0 0 0 0 0 0 0 0 25 0 1 0 52707166 2646016 46 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/5576/statm: 646 46 0 194 0 33 0

[startup+0.204794 s]
/proc/loadavg: 1.05 1.02 1.00 5/39 5576
/proc/meminfo: memFree=906448/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=0
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 1519 0 0 0 0 0 0 25 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2588

[startup+0.30482 s]
/proc/loadavg: 1.05 1.02 1.00 5/39 5576
/proc/meminfo: memFree=906448/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=0
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 1519 0 0 0 0 0 0 25 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2588

[startup+0.404835 s]
/proc/loadavg: 1.05 1.02 1.00 5/39 5576
/proc/meminfo: memFree=906448/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=0
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 1519 0 0 0 0 0 0 25 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2588

[startup+0.704886 s]
/proc/loadavg: 1.05 1.02 1.00 5/39 5576
/proc/meminfo: memFree=906448/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=0
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 1519 0 0 0 0 0 0 25 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2588

[startup+1.50507 s]
/proc/loadavg: 1.05 1.02 1.00 3/40 5584
/proc/meminfo: memFree=873452/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=0
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 1519 0 0 0 0 0 0 25 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=12480 CPUtime=0.02
/proc/5582/stat : 5582 (unclasp) S 5573 5573 2160 34817 2160 4202496 3025 0 0 0 2 0 0 0 18 0 1 0 52707167 12779520 2503 1283457024 134512640 135121179 4288357408 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/5582/statm: 3120 2503 275 149 0 2311 0
[pid=5583] ppid=5573 vsize=16192 CPUtime=0.46
/proc/5583/stat : 5583 (gringo) R 5573 5573 2160 34817 2160 4202496 4500 0 0 0 43 3 0 0 18 0 1 0 52707167 16580608 3036 1283457024 134512640 137056543 4290614752 18446744073709551615 134756995 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5583/statm: 4048 3036 253 622 0 3423 0
[pid=5584] ppid=5573 vsize=23472 CPUtime=1
/proc/5584/stat : 5584 (cudf2lp) R 5573 5573 2160 34817 2160 4202496 7074 0 0 0 100 0 0 0 25 0 1 0 52707167 24035328 5665 1283457024 134512640 135786343 4287052512 18446744073709551615 135258574 0 0 6 0 0 0 0 17 0 0 0 0
/proc/5584/statm: 5868 5665 139 311 0 5555 0
Current children cumulated CPU time (s) 1.48
Current children cumulated vsize (KiB) 54732

[startup+3.10557 s]
/proc/loadavg: 1.12 1.03 1.01 3/40 5584
/proc/meminfo: memFree=840220/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=1.19
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 8596 0 0 0 0 117 2 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=36292 CPUtime=0.25
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 9580 0 0 0 22 3 0 0 18 0 1 0 52707167 37163008 8380 1283457024 134512640 135121179 4288357408 18446744073709551615 4294960130 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 9073 8380 277 149 0 8264 0
[pid=5583] ppid=5573 vsize=58072 CPUtime=1.65
/proc/5583/stat : 5583 (gringo) R 5573 5573 2160 34817 2160 4202496 16912 0 0 0 155 10 0 0 18 0 1 0 52707167 59465728 12623 1283457024 134512640 137056543 4290614752 18446744073709551615 134802006 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5583/statm: 14518 12623 268 622 0 13893 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 96952

[startup+6.30695 s]
/proc/loadavg: 1.12 1.03 1.01 2/38 5584
/proc/meminfo: memFree=858480/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=53148 CPUtime=3.12
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 47661 0 0 0 292 20 0 0 23 0 1 0 52707167 54423552 12088 1283457024 134512640 135121179 4288357408 18446744073709551615 134713296 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 13287 12088 319 149 0 12478 0
Current children cumulated CPU time (s) 6.28
Current children cumulated vsize (KiB) 55736

[startup+12.7097 s]
/proc/loadavg: 1.10 1.03 1.01 2/38 5584
/proc/meminfo: memFree=857744/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=55704 CPUtime=9.52
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 127411 0 0 0 905 47 0 0 25 0 1 0 52707167 57040896 12673 1283457024 134512640 135121179 4288357408 18446744073709551615 4157418262 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 13926 12673 319 149 0 13117 0
Current children cumulated CPU time (s) 12.68
Current children cumulated vsize (KiB) 58292

[startup+25.5044 s]
/proc/loadavg: 1.09 1.03 1.01 2/38 5584
/proc/meminfo: memFree=858612/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=53152 CPUtime=22.3
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 276786 0 0 0 2090 140 0 0 25 0 1 0 52707167 54427648 12099 1283457024 134512640 135121179 4288357408 18446744073709551615 134869258 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 13288 12099 319 149 0 12479 0
Current children cumulated CPU time (s) 25.46
Current children cumulated vsize (KiB) 55740

[startup+51.1139 s]
/proc/loadavg: 1.06 1.03 1.00 2/38 5584
/proc/meminfo: memFree=857620/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=54132 CPUtime=47.89
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 569376 0 0 0 4501 288 0 0 25 0 1 0 52707167 55431168 12341 1283457024 134512640 135121179 4288357408 18446744073709551615 134734450 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 13533 12341 321 149 0 12724 0
Current children cumulated CPU time (s) 51.05
Current children cumulated vsize (KiB) 56720

[startup+102.311 s]
/proc/loadavg: 1.02 1.02 1.00 2/38 5584
/proc/meminfo: memFree=856380/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=53604 CPUtime=99.05
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 1138394 0 0 0 9374 531 0 0 25 0 1 0 52707167 54890496 12256 1283457024 134512640 135121179 4288357408 18446744073709551615 134734403 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 13401 12256 323 149 0 12592 0
Current children cumulated CPU time (s) 102.21
Current children cumulated vsize (KiB) 56192

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

[startup+102.511 s]
/proc/loadavg: 1.02 1.02 1.00 2/38 5584
/proc/meminfo: memFree=857744/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=54864 CPUtime=99.25
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 1140761 0 0 0 9392 533 0 0 25 0 1 0 52707167 56180736 12571 1283457024 134512640 135121179 4288357408 18446744073709551615 134981886 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 13716 12571 323 149 0 12907 0
Current children cumulated CPU time (s) 102.41
Current children cumulated vsize (KiB) 57452

[startup+128.111 s]
/proc/loadavg: 1.01 1.02 1.00 2/38 5584
/proc/meminfo: memFree=843608/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=67988 CPUtime=124.84
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 1398276 0 0 0 11840 644 0 0 25 0 1 0 52707167 69619712 15689 1283457024 134512640 135121179 4288357408 18446744073709551615 134990541 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 16997 15689 323 149 0 16188 0
Current children cumulated CPU time (s) 128
Current children cumulated vsize (KiB) 70576

[startup+140.915 s]
/proc/loadavg: 1.01 1.02 1.00 2/38 5584
/proc/meminfo: memFree=827488/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=83176 CPUtime=137.63
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 1505923 0 0 0 13061 702 0 0 25 0 1 0 52707167 85172224 19804 1283457024 134512640 135121179 4288357408 18446744073709551615 134980996 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 20794 19804 323 149 0 19985 0
Current children cumulated CPU time (s) 140.79
Current children cumulated vsize (KiB) 85764

[startup+147.308 s]
/proc/loadavg: 1.01 1.02 1.00 2/38 5584
/proc/meminfo: memFree=822652/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=88620 CPUtime=144
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 1560876 0 0 0 13671 729 0 0 25 0 1 0 52707167 90746880 21189 1283457024 134512640 135121179 4288357408 18446744073709551615 134713296 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 22155 21189 323 149 0 21346 0
Current children cumulated CPU time (s) 147.16
Current children cumulated vsize (KiB) 91208

[startup+148.909 s]
/proc/loadavg: 1.01 1.02 1.00 2/38 5584
/proc/meminfo: memFree=820668/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=91156 CPUtime=145.6
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 1574326 0 0 0 13821 739 0 0 25 0 1 0 52707167 93343744 21833 1283457024 134512640 135121179 4288357408 18446744073709551615 134734477 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 22789 21833 323 149 0 21980 0
Current children cumulated CPU time (s) 148.76
Current children cumulated vsize (KiB) 93744

[startup+150.51 s]
/proc/loadavg: 1.01 1.02 1.00 2/38 5584
/proc/meminfo: memFree=819552/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=90068 CPUtime=147.2
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 1591099 0 0 0 13973 747 0 0 25 0 1 0 52707167 92229632 21556 1283457024 134512640 135121179 4288357408 18446744073709551615 134878470 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 22517 21556 323 149 0 21708 0
Current children cumulated CPU time (s) 150.36
Current children cumulated vsize (KiB) 92656

[startup+151.31 s]
/proc/loadavg: 1.01 1.02 1.00 2/38 5584
/proc/meminfo: memFree=818808/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=91048 CPUtime=148.01
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 1596404 0 0 0 14053 748 0 0 25 0 1 0 52707167 93233152 21809 1283457024 134512640 135121179 4288357408 18446744073709551615 134891771 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 22762 21809 323 149 0 21953 0
Current children cumulated CPU time (s) 151.17
Current children cumulated vsize (KiB) 93636

[startup+151.71 s]
/proc/loadavg: 1.01 1.02 1.00 2/38 5584
/proc/meminfo: memFree=818808/1048576 swapFree=0/0
[pid=5573] ppid=5572 vsize=2588 CPUtime=3.16
/proc/5573/stat : 5573 (aspuncud-user-1) S 5572 5573 2160 34817 2160 4202496 572 27217 0 0 0 0 302 14 18 0 1 0 52707165 2650112 297 1283457024 134512640 135304128 4293310528 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5573/statm: 647 297 251 194 0 34 0
[pid=5582] ppid=5573 vsize=88984 CPUtime=148.41
/proc/5582/stat : 5582 (unclasp) R 5573 5573 2160 34817 2160 4202496 1598413 0 0 0 14092 749 0 0 25 0 1 0 52707167 91119616 21471 1283457024 134512640 135121179 4288357408 18446744073709551615 4157384876 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5582/statm: 22246 21471 336 149 0 21437 0
Current children cumulated CPU time (s) 151.57
Current children cumulated vsize (KiB) 91572

Child status: 0
Real time (s): 151.804
CPU time (s): 151.665
CPU user time (s): 143.997
CPU system time (s): 7.66848
CPU usage (%): 99.9088
Max. virtual memory (cumulated for all children) (KiB): 108384

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 143.997
system time used= 7.66848
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 1630177
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= 3340
involuntary context switches= 4338

runsolver used 0 second user time and 0.008 second system time

The end