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/install/rand118.cudf.log.runsolver /home/competition/aspuncud-full-1.7/aspuncud-full /home/competition/data/install/rand118.cudf /tmp/misc2012/2012-09-02-22:42/full/aspuncud-full-1.7/trendy-size/install/rand118.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.03 1.01 1.00 2/59 2145
/proc/meminfo: memFree=701964/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=3152 CPUtime=0
/proc/2145/stat : 2145 (runsolver) R 2144 1733 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 119664330 3227648 32 18446744073709551615 134512640 134586868 4287349680 4287347728 4151444528 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/2145/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.204636 s]
/proc/loadavg: 1.03 1.01 1.00 2/59 2145
/proc/meminfo: memFree=701964/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=0.04
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 694 2797 2 7 0 1 2 1 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073600 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9212

[startup+0.300331 s]
/proc/loadavg: 1.03 1.01 1.00 2/59 2145
/proc/meminfo: memFree=701964/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=0.04
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 694 2797 2 7 0 1 2 1 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073600 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9212

[startup+0.400327 s]
/proc/loadavg: 1.03 1.01 1.00 2/59 2145
/proc/meminfo: memFree=701964/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=0.04
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 694 2797 2 7 0 1 2 1 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073600 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9212

[startup+0.700256 s]
/proc/loadavg: 1.03 1.01 1.00 2/59 2145
/proc/meminfo: memFree=701964/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=0.04
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 694 2797 2 7 0 1 2 1 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073600 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9212

[startup+1.50032 s]
/proc/loadavg: 1.03 1.01 1.00 2/61 2158
/proc/meminfo: memFree=666732/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=0.04
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 694 2797 2 7 0 1 2 1 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073600 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2158] ppid=2145 vsize=30672 CPUtime=1.37
/proc/2158/stat : 2158 (cudf2lp) R 2145 2145 1733 0 -1 4202496 9078 0 1 0 132 5 0 0 20 0 1 0 119664339 31408128 7346 18446744073709551615 4194304 5690517 140735744820544 140735744817032 4340504 0 0 16781316 0 0 0 0 17 0 0 0 1 0 0
/proc/2158/statm: 7668 7346 160 366 0 7299 0
Current children cumulated CPU time (s) 1.41
Current children cumulated vsize (KiB) 39884

[startup+3.10032 s]
/proc/loadavg: 1.03 1.01 1.00 2/61 2158
/proc/meminfo: memFree=635236/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=0.04
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 694 2797 2 7 0 1 2 1 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073600 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2158] ppid=2145 vsize=93028 CPUtime=2.96
/proc/2158/stat : 2158 (cudf2lp) R 2145 2145 1733 0 -1 4202496 26392 0 1 0 283 13 0 0 20 0 1 0 119664339 95260672 19666 18446744073709551615 4194304 5690517 140735744820544 140735744817128 4951870 0 0 16781316 0 0 0 0 17 0 0 0 1 0 0
/proc/2158/statm: 23257 19666 160 366 0 22888 0
Current children cumulated CPU time (s) 3
Current children cumulated vsize (KiB) 102240

[startup+6.30032 s]
/proc/loadavg: 1.03 1.01 1.00 2/61 2159
/proc/meminfo: memFree=647760/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=5.37
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 722 42116 2 8 0 1 505 31 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073600 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2159] ppid=2145 vsize=24196 CPUtime=0.8
/proc/2159/stat : 2159 (gringo) R 2145 2145 1733 0 -1 4202496 6168 0 0 0 76 4 0 0 20 0 1 0 119664878 24776704 5057 18446744073709551615 4194304 6531320 140734979431872 140734979427688 4417340 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/2159/statm: 6049 5057 259 571 0 5470 0
Current children cumulated CPU time (s) 6.17
Current children cumulated vsize (KiB) 33408

[startup+12.7003 s]
/proc/loadavg: 1.03 1.01 1.00 2/61 2159
/proc/meminfo: memFree=379920/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=5.37
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 722 42116 2 8 0 1 505 31 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073600 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2159] ppid=2145 vsize=363580 CPUtime=7.14
/proc/2159/stat : 2159 (gringo) R 2145 2145 1733 0 -1 4202496 87194 0 0 0 667 47 0 0 20 0 1 0 119664878 372305920 70719 18446744073709551615 4194304 6531320 140734979431872 140734979428296 4595913 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/2159/statm: 90895 70719 282 571 0 90316 0
Current children cumulated CPU time (s) 12.51
Current children cumulated vsize (KiB) 372792

[startup+25.5034 s]
/proc/loadavg: 1.02 1.01 1.00 2/62 2161
/proc/meminfo: memFree=439944/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=16.93
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 763 224070 2 8 0 1 1569 123 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073008 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2160] ppid=2145 vsize=231108 CPUtime=8.13
/proc/2160/stat : 2160 (unclasp) R 2145 2145 1733 0 -1 4202496 69958 0 1 0 793 20 0 0 20 0 1 0 119666054 236654592 57322 18446744073709551615 4194304 6012874 140736095977520 140736095976840 4548507 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/2160/statm: 57777 57322 230 444 0 57325 0
[pid=2161] ppid=2145 vsize=22464 CPUtime=0.01
/proc/2161/stat : 2161 (parse.py) S 2145 2145 1733 0 -1 4202496 1406 0 13 0 0 1 0 0 20 0 1 0 119666054 23003136 1228 18446744073709551615 4194304 6642060 140733946191936 140733946190216 140667612337952 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/2161/statm: 5616 1228 508 598 0 702 0
Current children cumulated CPU time (s) 25.07
Current children cumulated vsize (KiB) 262784

[startup+51.1003 s]
/proc/loadavg: 1.01 1.01 1.00 2/62 2161
/proc/meminfo: memFree=439944/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=16.93
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 763 224070 2 8 0 1 1569 123 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073008 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2160] ppid=2145 vsize=231108 CPUtime=33.52
/proc/2160/stat : 2160 (unclasp) R 2145 2145 1733 0 -1 4202496 69958 0 1 0 3332 20 0 0 20 0 1 0 119666054 236654592 57322 18446744073709551615 4194304 6012874 140736095977520 140736095976840 4274948 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/2160/statm: 57777 57322 230 444 0 57325 0
[pid=2161] ppid=2145 vsize=22464 CPUtime=0.01
/proc/2161/stat : 2161 (parse.py) S 2145 2145 1733 0 -1 4202496 1406 0 13 0 0 1 0 0 20 0 1 0 119666054 23003136 1228 18446744073709551615 4194304 6642060 140733946191936 140733946190216 140667612337952 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/2161/statm: 5616 1228 508 598 0 702 0
Current children cumulated CPU time (s) 50.46
Current children cumulated vsize (KiB) 262784

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

[startup+51.3003 s]
/proc/loadavg: 1.01 1.01 1.00 2/62 2161
/proc/meminfo: memFree=439944/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=16.93
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 763 224070 2 8 0 1 1569 123 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073008 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2160] ppid=2145 vsize=231108 CPUtime=33.72
/proc/2160/stat : 2160 (unclasp) R 2145 2145 1733 0 -1 4202496 69958 0 1 0 3352 20 0 0 20 0 1 0 119666054 236654592 57322 18446744073709551615 4194304 6012874 140736095977520 140736095976840 4548913 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/2160/statm: 57777 57322 230 444 0 57325 0
[pid=2161] ppid=2145 vsize=22464 CPUtime=0.01
/proc/2161/stat : 2161 (parse.py) S 2145 2145 1733 0 -1 4202496 1406 0 13 0 0 1 0 0 20 0 1 0 119666054 23003136 1228 18446744073709551615 4194304 6642060 140733946191936 140733946190216 140667612337952 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/2161/statm: 5616 1228 508 598 0 702 0
Current children cumulated CPU time (s) 50.66
Current children cumulated vsize (KiB) 262784

[startup+57.7003 s]
/proc/loadavg: 1.01 1.01 1.00 2/62 2161
/proc/meminfo: memFree=439820/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=16.93
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 763 224070 2 8 0 1 1569 123 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073008 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2160] ppid=2145 vsize=231108 CPUtime=40.07
/proc/2160/stat : 2160 (unclasp) R 2145 2145 1733 0 -1 4202496 69979 0 1 0 3986 21 0 0 20 0 1 0 119666054 236654592 57343 18446744073709551615 4194304 6012874 140736095977520 140736095976840 4549324 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/2160/statm: 57777 57343 230 444 0 57325 0
[pid=2161] ppid=2145 vsize=22464 CPUtime=0.01
/proc/2161/stat : 2161 (parse.py) S 2145 2145 1733 0 -1 4202496 1406 0 13 0 0 1 0 0 20 0 1 0 119666054 23003136 1228 18446744073709551615 4194304 6642060 140733946191936 140733946190216 140667612337952 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/2161/statm: 5616 1228 508 598 0 702 0
Current children cumulated CPU time (s) 57.01
Current children cumulated vsize (KiB) 262784

[startup+64.1003 s]
/proc/loadavg: 1.01 1.01 1.00 2/62 2161
/proc/meminfo: memFree=439820/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=16.93
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 763 224070 2 8 0 1 1569 123 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073008 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2160] ppid=2145 vsize=231108 CPUtime=46.43
/proc/2160/stat : 2160 (unclasp) R 2145 2145 1733 0 -1 4202496 69980 0 1 0 4621 22 0 0 20 0 1 0 119666054 236654592 57344 18446744073709551615 4194304 6012874 140736095977520 140736095976584 4532853 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/2160/statm: 57777 57344 230 444 0 57325 0
[pid=2161] ppid=2145 vsize=22464 CPUtime=0.01
/proc/2161/stat : 2161 (parse.py) S 2145 2145 1733 0 -1 4202496 1406 0 13 0 0 1 0 0 20 0 1 0 119666054 23003136 1228 18446744073709551615 4194304 6642060 140733946191936 140733946190216 140667612337952 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/2161/statm: 5616 1228 508 598 0 702 0
Current children cumulated CPU time (s) 63.37
Current children cumulated vsize (KiB) 262784

[startup+65.7003 s]
/proc/loadavg: 1.01 1.01 1.00 2/62 2161
/proc/meminfo: memFree=439820/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=16.93
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 763 224070 2 8 0 1 1569 123 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073008 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2160] ppid=2145 vsize=231108 CPUtime=48.01
/proc/2160/stat : 2160 (unclasp) R 2145 2145 1733 0 -1 4202496 69980 0 1 0 4779 22 0 0 20 0 1 0 119666054 236654592 57344 18446744073709551615 4194304 6012874 140736095977520 140736095976840 4498884 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/2160/statm: 57777 57344 230 444 0 57325 0
[pid=2161] ppid=2145 vsize=22464 CPUtime=0.01
/proc/2161/stat : 2161 (parse.py) S 2145 2145 1733 0 -1 4202496 1406 0 13 0 0 1 0 0 20 0 1 0 119666054 23003136 1228 18446744073709551615 4194304 6642060 140733946191936 140733946190216 140667612337952 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/2161/statm: 5616 1228 508 598 0 702 0
Current children cumulated CPU time (s) 64.95
Current children cumulated vsize (KiB) 262784

[startup+67.306 s]
/proc/loadavg: 1.01 1.01 1.00 2/62 2161
/proc/meminfo: memFree=439820/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=16.93
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 763 224070 2 8 0 1 1569 123 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073008 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2160] ppid=2145 vsize=231108 CPUtime=49.6
/proc/2160/stat : 2160 (unclasp) R 2145 2145 1733 0 -1 4202496 69980 0 1 0 4938 22 0 0 20 0 1 0 119666054 236654592 57344 18446744073709551615 4194304 6012874 140736095977520 140736095976840 4548507 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/2160/statm: 57777 57344 230 444 0 57325 0
[pid=2161] ppid=2145 vsize=22464 CPUtime=0.01
/proc/2161/stat : 2161 (parse.py) S 2145 2145 1733 0 -1 4202496 1406 0 13 0 0 1 0 0 20 0 1 0 119666054 23003136 1228 18446744073709551615 4194304 6642060 140733946191936 140733946190216 140667612337952 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/2161/statm: 5616 1228 508 598 0 702 0
Current children cumulated CPU time (s) 66.54
Current children cumulated vsize (KiB) 262784

[startup+67.7003 s]
/proc/loadavg: 1.01 1.01 1.00 2/62 2161
/proc/meminfo: memFree=439820/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=16.93
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 763 224070 2 8 0 1 1569 123 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073008 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2160] ppid=2145 vsize=231108 CPUtime=49.99
/proc/2160/stat : 2160 (unclasp) R 2145 2145 1733 0 -1 4202496 69980 0 1 0 4977 22 0 0 20 0 1 0 119666054 236654592 57344 18446744073709551615 4194304 6012874 140736095977520 140736095976840 4548507 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/2160/statm: 57777 57344 230 444 0 57325 0
[pid=2161] ppid=2145 vsize=22464 CPUtime=0.01
/proc/2161/stat : 2161 (parse.py) S 2145 2145 1733 0 -1 4202496 1406 0 13 0 0 1 0 0 20 0 1 0 119666054 23003136 1228 18446744073709551615 4194304 6642060 140733946191936 140733946190216 140667612337952 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/2161/statm: 5616 1228 508 598 0 702 0
Current children cumulated CPU time (s) 66.93
Current children cumulated vsize (KiB) 262784

[startup+68.1003 s]
/proc/loadavg: 1.01 1.01 1.00 2/62 2161
/proc/meminfo: memFree=439820/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=16.93
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 763 224070 2 8 0 1 1569 123 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052073008 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
[pid=2160] ppid=2145 vsize=231108 CPUtime=50.39
/proc/2160/stat : 2160 (unclasp) R 2145 2145 1733 0 -1 4202496 69980 0 1 0 5017 22 0 0 20 0 1 0 119666054 236654592 57344 18446744073709551615 4194304 6012874 140736095977520 140736095976840 4311312 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/2160/statm: 57777 57344 230 444 0 57325 0
[pid=2161] ppid=2145 vsize=22464 CPUtime=0.01
/proc/2161/stat : 2161 (parse.py) S 2145 2145 1733 0 -1 4202496 1406 0 13 0 0 1 0 0 20 0 1 0 119666054 23003136 1228 18446744073709551615 4194304 6642060 140733946191936 140733946190136 140667612337952 0 0 16777220 20994 0 0 0 17 0 0 0 11 0 0
/proc/2161/statm: 5616 1228 508 598 0 702 0
Current children cumulated CPU time (s) 67.33
Current children cumulated vsize (KiB) 262784

[startup+68.2004 s]
/proc/loadavg: 1.01 1.01 1.00 2/62 2161
/proc/meminfo: memFree=439820/1022884 swapFree=0/0
[pid=2145] ppid=2144 vsize=9212 CPUtime=67.44
/proc/2145/stat : 2145 (aspuncud-full) S 2144 2145 1733 0 -1 4202496 796 295481 2 22 0 1 6590 153 20 0 1 0 119664330 9433088 364 18446744073709551615 4194304 5129932 140735052074944 140735052072496 140592881812574 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/2145/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 67.44
Current children cumulated vsize (KiB) 9212

Child status: 0
Real time (s): 68.2173
CPU time (s): 67.4602
CPU user time (s): 65.9001
CPU system time (s): 1.5601
CPU usage (%): 98.8902
Max. virtual memory (cumulated for all children) (KiB): 808672

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 65.9001
system time used= 1.5601
maximum resident set size= 661900
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 296510
page faults= 25
swaps= 0
block input operations= 70576
block output operations= 82760
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 180
involuntary context switches= 7859

runsolver used 0.16001 second user time and 0.232014 second system time

The end