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/trendy-size/upgrade/difficult/rand484.cudf.log.runsolver /home/competition/aspuncud-full-1.7/aspuncud-full /home/competition/data/upgrade/difficult/rand484.cudf /tmp/misc2012/2012-09-02-22:42/full/aspuncud-full-1.7/trendy-size/upgrade/difficult/rand484.cudf.result -count(removed),-sum(solution,installedsize),-notuptodate(solution),-unsat_recommends(solution),-count(new) 

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.02 1.05 1.00 2/59 18183
/proc/meminfo: memFree=703096/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=3152 CPUtime=0
/proc/18183/stat : 18183 (runsolver) R 18182 1750 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 119730573 3227648 32 18446744073709551615 134512640 134586868 4289963024 4289961072 4151583792 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/18183/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.181617 s]
/proc/loadavg: 1.02 1.05 1.00 2/59 18183
/proc/meminfo: memFree=703096/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=0.03
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 692 2801 2 7 0 0 3 0 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403824 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+0.200335 s]
/proc/loadavg: 1.02 1.05 1.00 2/59 18183
/proc/meminfo: memFree=703096/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=0.03
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 692 2801 2 7 0 0 3 0 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403824 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+0.300319 s]
/proc/loadavg: 1.02 1.05 1.00 2/59 18183
/proc/meminfo: memFree=703096/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=0.03
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 692 2801 2 7 0 0 3 0 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403824 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+0.700235 s]
/proc/loadavg: 1.02 1.05 1.00 2/59 18183
/proc/meminfo: memFree=703096/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=0.03
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 692 2801 2 7 0 0 3 0 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403824 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+1.50033 s]
/proc/loadavg: 1.02 1.05 1.00 2/61 18196
/proc/meminfo: memFree=669352/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=0.03
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 692 2801 2 7 0 0 3 0 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403824 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18196] ppid=18183 vsize=30540 CPUtime=1.32
/proc/18196/stat : 18196 (cudf2lp) R 18183 18183 1750 0 -1 4202496 9053 0 1 0 128 4 0 0 20 0 1 0 119730584 31272960 7320 18446744073709551615 4194304 5690517 140735192840416 140735192838056 4357488 0 0 16781316 0 0 0 0 17 0 0 0 4 0 0
/proc/18196/statm: 7635 7320 160 366 0 7266 0
Current children cumulated CPU time (s) 1.35
Current children cumulated vsize (KiB) 39752

[startup+3.10033 s]
/proc/loadavg: 1.02 1.05 1.00 2/61 18196
/proc/meminfo: memFree=638104/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=0.03
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 692 2801 2 7 0 0 3 0 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403824 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18196] ppid=18183 vsize=93028 CPUtime=2.88
/proc/18196/stat : 18196 (cudf2lp) R 18183 18183 1750 0 -1 4202496 26393 0 1 0 272 16 0 0 20 0 1 0 119730584 95260672 19666 18446744073709551615 4194304 5690517 140735192840416 140735192837000 4951778 0 0 16781316 0 0 0 0 17 0 0 0 7 0 0
/proc/18196/statm: 23257 19666 160 366 0 22888 0
Current children cumulated CPU time (s) 2.91
Current children cumulated vsize (KiB) 102240

[startup+6.30033 s]
/proc/loadavg: 1.02 1.05 1.00 2/61 18197
/proc/meminfo: memFree=651248/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=5.23
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 719 42122 2 8 0 0 493 30 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403824 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18197] ppid=18183 vsize=27044 CPUtime=0.82
/proc/18197/stat : 18197 (gringo) R 18183 18183 1750 0 -1 4202496 6961 0 1 0 78 4 0 0 20 0 1 0 119731116 27693056 5851 18446744073709551615 4194304 6531320 140734425417872 140734425413416 5563180 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/18197/statm: 6761 5851 259 571 0 6182 0
Current children cumulated CPU time (s) 6.05
Current children cumulated vsize (KiB) 36256

[startup+12.7003 s]
/proc/loadavg: 1.02 1.05 1.00 2/61 18197
/proc/meminfo: memFree=365924/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=5.23
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 719 42122 2 8 0 0 493 30 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403824 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18197] ppid=18183 vsize=412348 CPUtime=7.16
/proc/18197/stat : 18197 (gringo) R 18183 18183 1750 0 -1 4202496 98751 0 1 0 674 42 0 0 20 0 1 0 119731116 422244352 82277 18446744073709551615 4194304 6531320 140734425417872 140734425414312 4598302 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/18197/statm: 103087 82277 282 571 0 102508 0
Current children cumulated CPU time (s) 12.39
Current children cumulated vsize (KiB) 421560

[startup+25.5004 s]
/proc/loadavg: 1.01 1.04 1.00 2/62 18199
/proc/meminfo: memFree=430892/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=18.4
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 758 221563 2 9 0 0 1708 132 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403232 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18198] ppid=18183 vsize=229788 CPUtime=6.53
/proc/18198/stat : 18198 (unclasp) R 18183 18183 1750 0 -1 4202496 69612 0 1 0 625 28 0 0 20 0 1 0 119732458 235302912 56995 18446744073709551615 4194304 6012874 140736821960944 140736821960264 4548507 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/18198/statm: 57447 56995 226 444 0 56995 0
[pid=18199] ppid=18183 vsize=22320 CPUtime=0.01
/proc/18199/stat : 18199 (parse.py) S 18183 18183 1750 0 -1 4202496 1370 0 13 0 1 0 0 0 20 0 1 0 119732458 22855680 1192 18446744073709551615 4194304 6642060 140735694562144 140735694560024 140337949570848 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/18199/statm: 5580 1192 508 598 0 666 0
Current children cumulated CPU time (s) 24.94
Current children cumulated vsize (KiB) 261320

[startup+51.1004 s]
/proc/loadavg: 1.01 1.04 1.00 2/62 18199
/proc/meminfo: memFree=430892/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=18.4
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 758 221563 2 9 0 0 1708 132 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403232 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18198] ppid=18183 vsize=229788 CPUtime=31.86
/proc/18198/stat : 18198 (unclasp) R 18183 18183 1750 0 -1 4202496 69612 0 1 0 3156 30 0 0 20 0 1 0 119732458 235302912 56995 18446744073709551615 4194304 6012874 140736821960944 140736821960264 4548572 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/18198/statm: 57447 56995 226 444 0 56995 0
[pid=18199] ppid=18183 vsize=22464 CPUtime=0.02
/proc/18199/stat : 18199 (parse.py) S 18183 18183 1750 0 -1 4202496 1407 0 13 0 2 0 0 0 20 0 1 0 119732458 23003136 1229 18446744073709551615 4194304 6642060 140735694562144 140735694560424 140337949570848 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/18199/statm: 5616 1229 508 598 0 702 0
Current children cumulated CPU time (s) 50.28
Current children cumulated vsize (KiB) 261464

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

[startup+51.2005 s]
/proc/loadavg: 1.01 1.04 1.00 2/62 18199
/proc/meminfo: memFree=430892/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=18.4
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 758 221563 2 9 0 0 1708 132 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403232 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18198] ppid=18183 vsize=229788 CPUtime=31.96
/proc/18198/stat : 18198 (unclasp) R 18183 18183 1750 0 -1 4202496 69612 0 1 0 3166 30 0 0 20 0 1 0 119732458 235302912 56995 18446744073709551615 4194304 6012874 140736821960944 140736821960264 4506567 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/18198/statm: 57447 56995 226 444 0 56995 0
[pid=18199] ppid=18183 vsize=22464 CPUtime=0.02
/proc/18199/stat : 18199 (parse.py) S 18183 18183 1750 0 -1 4202496 1407 0 13 0 2 0 0 0 20 0 1 0 119732458 23003136 1229 18446744073709551615 4194304 6642060 140735694562144 140735694560424 140337949570848 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/18199/statm: 5616 1229 508 598 0 702 0
Current children cumulated CPU time (s) 50.38
Current children cumulated vsize (KiB) 261464

[startup+64.0003 s]
/proc/loadavg: 1.00 1.04 1.00 2/62 18199
/proc/meminfo: memFree=430892/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=18.4
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 758 221563 2 9 0 0 1708 132 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403232 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18198] ppid=18183 vsize=229788 CPUtime=44.64
/proc/18198/stat : 18198 (unclasp) R 18183 18183 1750 0 -1 4202496 69635 0 1 0 4433 31 0 0 20 0 1 0 119732458 235302912 57018 18446744073709551615 4194304 6012874 140736821960944 140736821960264 4548913 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/18198/statm: 57447 57018 226 444 0 56995 0
[pid=18199] ppid=18183 vsize=22464 CPUtime=0.02
/proc/18199/stat : 18199 (parse.py) S 18183 18183 1750 0 -1 4202496 1407 0 13 0 2 0 0 0 20 0 1 0 119732458 23003136 1229 18446744073709551615 4194304 6642060 140735694562144 140735694560424 140337949570848 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/18199/statm: 5616 1229 508 598 0 702 0
Current children cumulated CPU time (s) 63.06
Current children cumulated vsize (KiB) 261464

[startup+67.2033 s]
/proc/loadavg: 1.00 1.04 1.00 2/62 18199
/proc/meminfo: memFree=430768/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=18.4
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 758 221563 2 9 0 0 1708 132 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403232 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18198] ppid=18183 vsize=229788 CPUtime=47.82
/proc/18198/stat : 18198 (unclasp) R 18183 18183 1750 0 -1 4202496 69635 0 1 0 4751 31 0 0 20 0 1 0 119732458 235302912 57018 18446744073709551615 4194304 6012874 140736821960944 140736821960264 4855815 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/18198/statm: 57447 57018 226 444 0 56995 0
[pid=18199] ppid=18183 vsize=22464 CPUtime=0.02
/proc/18199/stat : 18199 (parse.py) S 18183 18183 1750 0 -1 4202496 1407 0 13 0 2 0 0 0 20 0 1 0 119732458 23003136 1229 18446744073709551615 4194304 6642060 140735694562144 140735694560424 140337949570848 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/18199/statm: 5616 1229 508 598 0 702 0
Current children cumulated CPU time (s) 66.24
Current children cumulated vsize (KiB) 261464

[startup+68.8003 s]
/proc/loadavg: 1.00 1.04 1.00 2/62 18199
/proc/meminfo: memFree=430768/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=18.4
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 758 221563 2 9 0 0 1708 132 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403232 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18198] ppid=18183 vsize=229788 CPUtime=49.41
/proc/18198/stat : 18198 (unclasp) R 18183 18183 1750 0 -1 4202496 69635 0 1 0 4909 32 0 0 20 0 1 0 119732458 235302912 57018 18446744073709551615 4194304 6012874 140736821960944 140736821960264 4548913 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/18198/statm: 57447 57018 226 444 0 56995 0
[pid=18199] ppid=18183 vsize=22464 CPUtime=0.02
/proc/18199/stat : 18199 (parse.py) S 18183 18183 1750 0 -1 4202496 1407 0 13 0 2 0 0 0 20 0 1 0 119732458 23003136 1229 18446744073709551615 4194304 6642060 140735694562144 140735694560424 140337949570848 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/18199/statm: 5616 1229 508 598 0 702 0
Current children cumulated CPU time (s) 67.83
Current children cumulated vsize (KiB) 261464

[startup+69.6003 s]
/proc/loadavg: 1.00 1.04 1.00 2/62 18199
/proc/meminfo: memFree=430768/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=18.4
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 758 221563 2 9 0 0 1708 132 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403232 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18198] ppid=18183 vsize=229788 CPUtime=50.21
/proc/18198/stat : 18198 (unclasp) R 18183 18183 1750 0 -1 4202496 69635 0 1 0 4989 32 0 0 20 0 1 0 119732458 235302912 57018 18446744073709551615 4194304 6012874 140736821960944 140736821960264 4548507 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/18198/statm: 57447 57018 226 444 0 56995 0
[pid=18199] ppid=18183 vsize=22464 CPUtime=0.02
/proc/18199/stat : 18199 (parse.py) S 18183 18183 1750 0 -1 4202496 1407 0 13 0 2 0 0 0 20 0 1 0 119732458 23003136 1229 18446744073709551615 4194304 6642060 140735694562144 140735694560424 140337949570848 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/18199/statm: 5616 1229 508 598 0 702 0
Current children cumulated CPU time (s) 68.63
Current children cumulated vsize (KiB) 261464

[startup+70.0003 s]
/proc/loadavg: 1.00 1.04 1.00 2/62 18199
/proc/meminfo: memFree=430768/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=18.4
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 758 221563 2 9 0 0 1708 132 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403232 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18198] ppid=18183 vsize=229788 CPUtime=50.61
/proc/18198/stat : 18198 (unclasp) R 18183 18183 1750 0 -1 4202496 69635 0 1 0 5029 32 0 0 20 0 1 0 119732458 235302912 57018 18446744073709551615 4194304 6012874 140736821960944 140736821960264 4548180 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/18198/statm: 57447 57018 226 444 0 56995 0
[pid=18199] ppid=18183 vsize=22464 CPUtime=0.02
/proc/18199/stat : 18199 (parse.py) S 18183 18183 1750 0 -1 4202496 1407 0 13 0 2 0 0 0 20 0 1 0 119732458 23003136 1229 18446744073709551615 4194304 6642060 140735694562144 140735694560424 140337949570848 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/18199/statm: 5616 1229 508 598 0 702 0
Current children cumulated CPU time (s) 69.03
Current children cumulated vsize (KiB) 261464

[startup+70.2013 s]
/proc/loadavg: 1.00 1.04 1.00 2/62 18199
/proc/meminfo: memFree=430768/1022884 swapFree=0/0
[pid=18183] ppid=18182 vsize=9212 CPUtime=18.4
/proc/18183/stat : 18183 (aspuncud-full) S 18182 18183 1750 0 -1 4202496 758 221563 2 9 0 0 1708 132 20 0 1 0 119730573 9433088 364 18446744073709551615 4194304 5129932 140735709405168 140735709403232 140405243917406 0 65536 16781316 1115778811 0 0 0 17 0 0 0 3 0 0
/proc/18183/statm: 2303 364 303 229 0 63 0
[pid=18198] ppid=18183 vsize=229788 CPUtime=50.8
/proc/18198/stat : 18198 (unclasp) R 18183 18183 1750 0 -1 4202496 69643 0 1 0 5045 35 0 0 20 0 1 0 119732458 235302912 32450 18446744073709551615 4194304 6012874 140736821960944 140736821960344 5474154 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/18198/statm: 57447 32450 234 444 0 56995 0
[pid=18199] ppid=18183 vsize=22464 CPUtime=0.02
/proc/18199/stat : 18199 (parse.py) S 18183 18183 1750 0 -1 4202496 1407 0 13 0 2 0 0 0 20 0 1 0 119732458 23003136 1229 18446744073709551615 4194304 6642060 140735694562144 140735694560344 140337949570848 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/18199/statm: 5616 1229 508 598 0 702 0
Current children cumulated CPU time (s) 69.22
Current children cumulated vsize (KiB) 261464

Child status: 0
Real time (s): 70.2649
CPU time (s): 69.3083
CPU user time (s): 67.5722
CPU system time (s): 1.73611
CPU usage (%): 98.6387
Max. virtual memory (cumulated for all children) (KiB): 784048

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 67.5722
system time used= 1.73611
maximum resident set size= 651852
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 293655
page faults= 26
swaps= 0
block input operations= 70776
block output operations= 82248
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 195
involuntary context switches= 8087

runsolver used 0.148009 second user time and 0.336021 second system time

The end