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: runsolver -s SIGUSR1 -M 1124 -C 300 -d 10 -w /tmp/misc2012/2012-09-02-22:42/full/aspuncud-full-1.7/slowlink/upgrade/difficult/rand208.cudf.log.runsolver /home/competition/aspuncud-full-1.7/aspuncud-full /home/competition/data/upgrade/difficult/rand208.cudf /tmp/misc2012/2012-09-02-22:42/full/aspuncud-full-1.7/slowlink/upgrade/difficult/rand208.cudf.result -sum(changed,installedsize),-count(removed),-notuptodate(solution),-count(changed) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 300 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 330 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

[startup+0 s]
/proc/loadavg: 1.00 1.00 1.00 2/64 21422
/proc/meminfo: memFree=450752/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=3152 CPUtime=0
/proc/21422/stat : 21422 (runsolver) R 21421 1745 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 120648524 3227648 33 18446744073709551615 134512640 134586868 4293922736 4293920784 4152169520 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 788 33 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.197866 s]
/proc/loadavg: 1.00 1.00 1.00 2/64 21422
/proc/meminfo: memFree=450752/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=0.02
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 700 2812 0 0 0 0 2 0 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880869296 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.200344 s]
/proc/loadavg: 1.00 1.00 1.00 2/64 21422
/proc/meminfo: memFree=450752/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=0.02
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 700 2812 0 0 0 0 2 0 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880869296 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.30031 s]
/proc/loadavg: 1.00 1.00 1.00 2/64 21422
/proc/meminfo: memFree=450752/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=0.02
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 700 2812 0 0 0 0 2 0 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880869296 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.700236 s]
/proc/loadavg: 1.00 1.00 1.00 2/64 21422
/proc/meminfo: memFree=450752/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=0.02
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 700 2812 0 0 0 0 2 0 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880869296 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+1.50032 s]
/proc/loadavg: 1.00 1.00 1.00 2/66 21435
/proc/meminfo: memFree=416008/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=0.02
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 700 2812 0 0 0 0 2 0 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880869296 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21435] ppid=21422 vsize=53244 CPUtime=1.44
/proc/21435/stat : 21435 (cudf2lp) R 21422 21422 1745 0 -1 4202496 12532 0 0 0 138 6 0 0 20 0 1 0 120648526 54521856 10797 18446744073709551615 4194304 5690517 140736125705408 140736125701608 4963881 0 0 16781316 0 0 0 0 17 0 0 0 1 0 0
/proc/21435/statm: 13311 10797 160 366 0 12942 0
Current children cumulated CPU time (s) 1.46
Current children cumulated vsize (KiB) 62456

[startup+3.10034 s]
/proc/loadavg: 1.00 1.00 1.00 2/66 21435
/proc/meminfo: memFree=384512/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=0.02
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 700 2812 0 0 0 0 2 0 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880869296 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21435] ppid=21422 vsize=93028 CPUtime=3.03
/proc/21435/stat : 21435 (cudf2lp) R 21422 21422 1745 0 -1 4202496 26478 0 0 0 289 14 0 0 20 0 1 0 120648526 95260672 19749 18446744073709551615 4194304 5690517 140736125705408 140736125703048 4348966 0 0 16781316 0 0 0 0 17 0 0 0 2 0 0
/proc/21435/statm: 23257 19749 160 366 0 22888 0
Current children cumulated CPU time (s) 3.05
Current children cumulated vsize (KiB) 102240

[startup+6.30034 s]
/proc/loadavg: 1.00 1.00 1.00 2/66 21436
/proc/meminfo: memFree=395424/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=5.06
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 728 42136 0 0 0 0 478 28 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880869296 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21436] ppid=21422 vsize=32704 CPUtime=1.16
/proc/21436/stat : 21436 (gringo) R 21422 21422 1745 0 -1 4202496 9257 0 0 0 110 6 0 0 20 0 1 0 120649037 33488896 7148 18446744073709551615 4194304 6531320 140733600625376 140733600621192 5632288 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/21436/statm: 8176 7148 259 571 0 7597 0
Current children cumulated CPU time (s) 6.22
Current children cumulated vsize (KiB) 41916

[startup+12.7003 s]
/proc/loadavg: 1.00 1.00 1.00 2/66 21436
/proc/meminfo: memFree=22680/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=5.06
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 728 42136 0 0 0 0 478 28 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880869296 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21436] ppid=21422 vsize=465476 CPUtime=7.43
/proc/21436/stat : 21436 (gringo) R 21422 21422 1745 0 -1 4202496 110366 0 0 0 689 54 0 0 20 0 1 0 120649037 476647424 101086 18446744073709551615 4194304 6531320 140733600625376 140733600622504 5502310 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/21436/statm: 116369 101086 284 571 0 115790 0
Current children cumulated CPU time (s) 12.49
Current children cumulated vsize (KiB) 474688

[startup+25.5004 s]
/proc/loadavg: 1.00 1.00 1.00 2/67 21438
/proc/meminfo: memFree=275384/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=138768 CPUtime=12.04
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 40364 0 0 0 1190 14 0 0 20 0 1 0 120649854 142098432 34196 18446744073709551615 4194304 6012874 140736021877152 140736021876472 4548180 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/21437/statm: 34692 34196 226 444 0 34240 0
[pid=21438] ppid=21422 vsize=22044 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1323 0 0 0 0 2 0 0 20 0 1 0 120649854 22573056 1132 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5511 1132 508 598 0 597 0
Current children cumulated CPU time (s) 25.15
Current children cumulated vsize (KiB) 170024

[startup+51.1004 s]
/proc/loadavg: 1.08 1.02 1.01 2/67 21438
/proc/meminfo: memFree=274764/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=138768 CPUtime=37.37
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 40552 0 1 0 3723 14 0 0 20 0 1 0 120649854 142098432 34385 18446744073709551615 4194304 6012874 140736021877152 140736021876472 4548913 0 0 16781316 16386 0 0 0 17 0 0 0 4 0 0
/proc/21437/statm: 34692 34385 227 444 0 34240 0
[pid=21438] ppid=21422 vsize=22044 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1323 0 0 0 0 2 0 0 20 0 1 0 120649854 22573056 1132 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5511 1132 508 598 0 597 0
Current children cumulated CPU time (s) 50.48
Current children cumulated vsize (KiB) 170024

[startup+102.3 s]
/proc/loadavg: 1.03 1.01 1.00 2/67 21438
/proc/meminfo: memFree=253064/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=162252 CPUtime=88.14
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 45942 0 3 0 8797 17 0 0 20 0 1 0 120649854 166146048 39777 18446744073709551615 4194304 6012874 140736021877152 140736021875560 4498631 0 0 16781316 16386 0 0 0 17 0 0 0 6 0 0
/proc/21437/statm: 40563 39777 231 444 0 40111 0
[pid=21438] ppid=21422 vsize=22044 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1323 0 0 0 0 2 0 0 20 0 1 0 120649854 22573056 1132 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5511 1132 508 598 0 597 0
Current children cumulated CPU time (s) 101.25
Current children cumulated vsize (KiB) 193508

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

[startup+102.404 s]
/proc/loadavg: 1.03 1.01 1.00 2/67 21438
/proc/meminfo: memFree=253064/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=162488 CPUtime=88.23
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 45972 0 3 0 8806 17 0 0 20 0 1 0 120649854 166387712 39807 18446744073709551615 4194304 6012874 140736021877152 140736021875768 4498711 0 0 16781316 16386 0 0 0 17 0 0 0 6 0 0
/proc/21437/statm: 40622 39807 231 444 0 40170 0
[pid=21438] ppid=21422 vsize=22044 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1323 0 0 0 0 2 0 0 20 0 1 0 120649854 22573056 1132 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5511 1132 508 598 0 597 0
Current children cumulated CPU time (s) 101.34
Current children cumulated vsize (KiB) 193744

[startup+128 s]
/proc/loadavg: 1.02 1.01 1.00 2/67 21438
/proc/meminfo: memFree=232108/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=185508 CPUtime=113.63
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 51235 0 3 0 11343 20 0 0 20 0 1 0 120649854 189960192 45070 18446744073709551615 4194304 6012874 140736021877152 140736021875560 4548077 0 0 16781316 16386 0 0 0 17 0 0 0 6 0 0
/proc/21437/statm: 46377 45070 231 444 0 45925 0
[pid=21438] ppid=21422 vsize=22044 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1323 0 0 0 0 2 0 0 20 0 1 0 120649854 22573056 1132 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5511 1132 508 598 0 597 0
Current children cumulated CPU time (s) 126.74
Current children cumulated vsize (KiB) 216764

[startup+134.4 s]
/proc/loadavg: 1.02 1.01 1.00 2/67 21438
/proc/meminfo: memFree=227024/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=190752 CPUtime=119.98
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 52447 0 3 0 11977 21 0 0 20 0 1 0 120649854 195330048 46282 18446744073709551615 4194304 6012874 140736021877152 140736021875560 4548913 0 0 16781316 16386 0 0 0 17 0 0 0 6 0 0
/proc/21437/statm: 47688 46282 231 444 0 47236 0
[pid=21438] ppid=21422 vsize=22044 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1323 0 0 0 0 2 0 0 20 0 1 0 120649854 22573056 1132 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5511 1132 508 598 0 597 0
Current children cumulated CPU time (s) 133.09
Current children cumulated vsize (KiB) 222008

[startup+140.8 s]
/proc/loadavg: 1.02 1.01 1.00 2/67 21438
/proc/meminfo: memFree=222436/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=195880 CPUtime=126.33
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 53607 0 3 0 12612 21 0 0 20 0 1 0 120649854 200581120 47442 18446744073709551615 4194304 6012874 140736021877152 140736021875560 4498884 0 0 16781316 16386 0 0 0 17 0 0 0 6 0 0
/proc/21437/statm: 48970 47442 231 444 0 48518 0
[pid=21438] ppid=21422 vsize=22044 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1323 0 0 0 0 2 0 0 20 0 1 0 120649854 22573056 1132 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5511 1132 508 598 0 597 0
Current children cumulated CPU time (s) 139.44
Current children cumulated vsize (KiB) 227136

[startup+142.4 s]
/proc/loadavg: 1.02 1.01 1.00 2/67 21446
/proc/meminfo: memFree=218096/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=196560 CPUtime=127.88
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 53769 0 3 0 12767 21 0 0 20 0 1 0 120649854 201277440 47604 18446744073709551615 4194304 6012874 140736021877152 140736021875560 4548913 0 0 16781316 16386 0 0 0 17 0 0 0 6 0 0
/proc/21437/statm: 49140 47604 231 444 0 48688 0
[pid=21438] ppid=21422 vsize=22044 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1323 0 0 0 0 2 0 0 20 0 1 0 120649854 22573056 1132 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5511 1132 508 598 0 597 0
Current children cumulated CPU time (s) 140.99
Current children cumulated vsize (KiB) 227816

[startup+143.2 s]
/proc/loadavg: 1.02 1.01 1.00 2/67 21446
/proc/meminfo: memFree=218096/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=196768 CPUtime=128.68
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 53835 0 3 0 12847 21 0 0 20 0 1 0 120649854 201490432 47670 18446744073709551615 4194304 6012874 140736021877152 140736021876472 4497053 0 0 16781316 16386 0 0 0 17 0 0 0 6 0 0
/proc/21437/statm: 49192 47670 231 444 0 48740 0
[pid=21438] ppid=21422 vsize=22044 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1323 0 0 0 0 2 0 0 20 0 1 0 120649854 22573056 1132 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5511 1132 508 598 0 597 0
Current children cumulated CPU time (s) 141.79
Current children cumulated vsize (KiB) 228024

[startup+143.6 s]
/proc/loadavg: 1.02 1.01 1.00 2/67 21446
/proc/meminfo: memFree=218096/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=196904 CPUtime=129.07
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 53867 0 3 0 12886 21 0 0 20 0 1 0 120649854 201629696 47702 18446744073709551615 4194304 6012874 140736021877152 140736021876024 5306932 0 0 16781316 16386 0 0 0 17 0 0 0 6 0 0
/proc/21437/statm: 49226 47702 231 444 0 48774 0
[pid=21438] ppid=21422 vsize=22196 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1335 0 0 0 0 2 0 0 20 0 1 0 120649854 22728704 1144 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5549 1144 508 598 0 635 0
Current children cumulated CPU time (s) 142.18
Current children cumulated vsize (KiB) 228312

[startup+144 s]
/proc/loadavg: 1.02 1.01 1.00 2/67 21446
/proc/meminfo: memFree=218096/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=196904 CPUtime=129.47
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 53867 0 3 0 12926 21 0 0 20 0 1 0 120649854 201629696 47702 18446744073709551615 4194304 6012874 140736021877152 140736021876472 4300210 0 0 16781316 16386 0 0 0 17 0 0 0 6 0 0
/proc/21437/statm: 49226 47702 231 444 0 48774 0
[pid=21438] ppid=21422 vsize=22196 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1346 0 0 0 0 2 0 0 20 0 1 0 120649854 22728704 1155 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5549 1155 508 598 0 635 0
Current children cumulated CPU time (s) 142.58
Current children cumulated vsize (KiB) 228312

[startup+144.1 s]
/proc/loadavg: 1.02 1.01 1.00 2/67 21446
/proc/meminfo: memFree=217972/1022884 swapFree=0/0
[pid=21422] ppid=21421 vsize=9212 CPUtime=13.09
/proc/21422/stat : 21422 (aspuncud-full) S 21421 21422 1745 0 -1 4202496 768 152506 0 0 0 0 1212 97 20 0 1 0 120648524 9433088 364 18446744073709551615 4194304 5129932 140736880870640 140736880868704 139665826194526 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/21422/statm: 2303 364 303 229 0 63 0
[pid=21437] ppid=21422 vsize=196904 CPUtime=129.57
/proc/21437/stat : 21437 (unclasp) R 21422 21422 1745 0 -1 4202496 53867 0 3 0 12936 21 0 0 20 0 1 0 120649854 201629696 47702 18446744073709551615 4194304 6012874 140736021877152 140736021876216 4494997 0 0 16781316 16386 0 0 0 17 0 0 0 6 0 0
/proc/21437/statm: 49226 47702 231 444 0 48774 0
[pid=21438] ppid=21422 vsize=22196 CPUtime=0.02
/proc/21438/stat : 21438 (parse.py) S 21422 21422 1745 0 -1 4202496 1346 0 0 0 0 2 0 0 20 0 1 0 120649854 22728704 1155 18446744073709551615 4194304 6642060 140736811643712 140736811641912 140003593369376 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/21438/statm: 5549 1155 508 598 0 635 0
Current children cumulated CPU time (s) 142.68
Current children cumulated vsize (KiB) 228312

Child status: 0
Real time (s): 144.2
CPU time (s): 142.805
CPU user time (s): 141.533
CPU system time (s): 1.27208
CPU usage (%): 99.0328
Max. virtual memory (cumulated for all children) (KiB): 474688

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 141.533
system time used= 1.27208
maximum resident set size= 404344
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 208781
page faults= 3
swaps= 0
block input operations= 68776
block output operations= 51168
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 110
involuntary context switches= 16467

runsolver used 0.272017 second user time and 0.616038 second system time

The end