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/201108241238/aspcud-trendy-1.5/rand399.cudf.s-e-l.log.runsolver ./aspcud-trendy-1.5 /home/misc2010/data/2011/incremental/s-e-l/rand399.cudf /home/misc2010/tmp/201108241238/aspcud-trendy-1.5/rand399.cudf.s-e-l.result 

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.00 1.02 1.00 5/37 10022
/proc/meminfo: memFree=672028/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2592 CPUtime=0
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 374 0 0 0 0 0 0 0 18 0 1 0 2384751 2654208 280 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/10019/statm: 648 280 234 194 0 35 0
[pid=10020] ppid=10019 vsize=2592 CPUtime=0
/proc/10020/stat : 10020 (aspcud-trendy-1) S 10019 10019 1511 34817 1511 4202560 118 0 0 0 0 0 0 0 18 0 1 0 2384751 2654208 134 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0
/proc/10020/statm: 648 134 87 194 0 35 0
[pid=10021] ppid=10020 vsize=2592 CPUtime=0
/proc/10021/stat : 10021 (aspcud-trendy-1) R 10020 10019 1511 34817 1511 4202560 126 0 0 0 0 0 0 0 25 0 1 0 2384751 2654208 151 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/10021/statm: 648 151 104 194 0 35 0
[pid=10022] ppid=10021 vsize=2592 CPUtime=0
/proc/10022/stat : 10022 (aspcud-trendy-1) R 10021 10019 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 2384751 2654208 47 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/10022/statm: 648 47 0 194 0 35 0

[startup+0.134154 s]
/proc/loadavg: 1.00 1.02 1.00 5/37 10022
/proc/meminfo: memFree=672028/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=0
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 624 2229 0 0 0 0 0 0 25 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2600

[startup+0.204181 s]
/proc/loadavg: 1.00 1.02 1.00 5/37 10022
/proc/meminfo: memFree=672028/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=0
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 624 2229 0 0 0 0 0 0 25 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2600

[startup+0.304198 s]
/proc/loadavg: 1.00 1.02 1.00 5/37 10022
/proc/meminfo: memFree=672028/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=0
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 624 2229 0 0 0 0 0 0 25 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2600

[startup+0.704314 s]
/proc/loadavg: 1.00 1.02 1.00 5/37 10022
/proc/meminfo: memFree=672028/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=0
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 624 2229 0 0 0 0 0 0 25 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2600

[startup+1.50447 s]
/proc/loadavg: 1.00 1.02 1.00 2/38 10033
/proc/meminfo: memFree=641876/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=0
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 624 2229 0 0 0 0 0 0 25 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=6236 CPUtime=0.01
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 1481 0 0 0 0 1 0 0 18 0 1 0 2384752 6385664 1266 1283457024 134512640 136285277 4290881024 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 1559 1266 177 433 0 1124 0
[pid=10032] ppid=10019 vsize=9012 CPUtime=0.2
/proc/10032/stat : 10032 (gringo) R 10019 10019 1511 34817 1511 4202496 2390 0 0 0 20 0 0 0 18 0 1 0 2384752 9228288 1578 1283457024 134512640 136933539 4287251200 18446744073709551615 134579791 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10032/statm: 2253 1578 242 592 0 1658 0
[pid=10033] ppid=10019 vsize=30572 CPUtime=1.26
/proc/10033/stat : 10033 (cudf2lp) R 10019 10019 1511 34817 1511 4202496 10056 0 0 0 120 6 0 0 25 0 1 0 2384753 31305728 7426 1283457024 134512640 135786343 4293322992 18446744073709551615 135258574 0 0 6 0 0 0 0 17 0 0 0 0
/proc/10033/statm: 7643 7426 137 311 0 7330 0
Current children cumulated CPU time (s) 1.47
Current children cumulated vsize (KiB) 48420

[startup+3.10488 s]
/proc/loadavg: 1.00 1.02 1.00 3/37 10033
/proc/meminfo: memFree=633956/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=35788 CPUtime=0.56
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 10385 0 0 0 50 6 0 0 18 0 1 0 2384752 36646912 8643 1283457024 134512640 136285277 4290881024 18446744073709551615 134902130 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 8947 8643 217 433 0 8512 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 38388

[startup+6.30586 s]
/proc/loadavg: 1.00 1.02 1.00 2/36 10033
/proc/meminfo: memFree=632872/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=57024 CPUtime=3.76
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 15869 0 0 0 368 8 0 0 25 0 1 0 2384752 58392576 14008 1283457024 134512640 136285277 4290881024 18446744073709551615 134930780 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 14256 14008 234 433 0 13821 0
Current children cumulated CPU time (s) 6.28
Current children cumulated vsize (KiB) 59624

[startup+12.7073 s]
/proc/loadavg: 1.00 1.02 1.00 2/36 10033
/proc/meminfo: memFree=612040/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=61964 CPUtime=10.16
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 17108 0 0 0 1008 8 0 0 25 0 1 0 2384752 63451136 15247 1283457024 134512640 136285277 4290881024 18446744073709551615 134966723 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 15491 15247 234 433 0 15056 0
Current children cumulated CPU time (s) 12.68
Current children cumulated vsize (KiB) 64564

[startup+25.5101 s]
/proc/loadavg: 1.00 1.01 1.00 2/36 10033
/proc/meminfo: memFree=589968/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=84028 CPUtime=22.94
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 22632 0 0 0 2284 10 0 0 25 0 1 0 2384752 86044672 20771 1283457024 134512640 136285277 4290881024 18446744073709551615 134966723 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 21007 20771 234 433 0 20572 0
Current children cumulated CPU time (s) 25.46
Current children cumulated vsize (KiB) 86628

[startup+51.1158 s]
/proc/loadavg: 1.00 1.01 1.00 2/35 10033
/proc/meminfo: memFree=450104/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=223916 CPUtime=48.54
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 57540 0 0 0 4827 27 0 0 25 0 1 0 2384752 229289984 55679 1283457024 134512640 136285277 4290881024 18446744073709551615 134985101 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 55979 55679 234 433 0 55544 0
Current children cumulated CPU time (s) 51.06
Current children cumulated vsize (KiB) 226516

[startup+102.31 s]
/proc/loadavg: 1.00 1.01 1.00 2/35 10033
/proc/meminfo: memFree=427040/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=246780 CPUtime=99.68
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 63286 0 0 0 9938 30 0 0 25 0 1 0 2384752 252702720 61425 1283457024 134512640 136285277 4290881024 18446744073709551615 134623633 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 61695 61425 234 433 0 61260 0
Current children cumulated CPU time (s) 102.2
Current children cumulated vsize (KiB) 249380

[startup+162.308 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 10033
/proc/meminfo: memFree=313952/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=363572 CPUtime=159.62
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 92397 0 0 0 15920 42 0 0 25 0 1 0 2384752 372297728 90536 1283457024 134512640 136285277 4290881024 18446744073709551615 134959509 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 90893 90536 234 433 0 90458 0
Current children cumulated CPU time (s) 162.14
Current children cumulated vsize (KiB) 366172

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

[startup+166.409 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 10033
/proc/meminfo: memFree=293492/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=381260 CPUtime=163.72
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 96845 0 0 0 16328 44 0 0 25 0 1 0 2384752 390410240 94984 1283457024 134512640 136285277 4290881024 18446744073709551615 134733778 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 95315 94984 234 433 0 94880 0
Current children cumulated CPU time (s) 166.24
Current children cumulated vsize (KiB) 383860

[startup+169.61 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 10033
/proc/meminfo: memFree=285680/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=387992 CPUtime=166.92
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 98536 0 0 0 16647 45 0 0 25 0 1 0 2384752 397303808 96675 1283457024 134512640 136285277 4290881024 18446744073709551615 134945930 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 96998 96675 234 433 0 96563 0
Current children cumulated CPU time (s) 169.44
Current children cumulated vsize (KiB) 390592

[startup+172.811 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 10033
/proc/meminfo: memFree=285680/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=387992 CPUtime=170.12
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 98536 0 0 0 16967 45 0 0 25 0 1 0 2384752 397303808 96675 1283457024 134512640 136285277 4290881024 18446744073709551615 134930675 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 96998 96675 234 433 0 96563 0
Current children cumulated CPU time (s) 172.64
Current children cumulated vsize (KiB) 390592

[startup+173.611 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 10033
/proc/meminfo: memFree=285680/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=387992 CPUtime=170.92
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 98536 0 0 0 17047 45 0 0 25 0 1 0 2384752 397303808 96675 1283457024 134512640 136285277 4290881024 18446744073709551615 134959509 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 96998 96675 234 433 0 96563 0
Current children cumulated CPU time (s) 173.44
Current children cumulated vsize (KiB) 390592

[startup+174.411 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 10033
/proc/meminfo: memFree=285680/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=387992 CPUtime=171.72
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 98536 0 0 0 17127 45 0 0 25 0 1 0 2384752 397303808 96675 1283457024 134512640 136285277 4290881024 18446744073709551615 134966723 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 96998 96675 234 433 0 96563 0
Current children cumulated CPU time (s) 174.24
Current children cumulated vsize (KiB) 390592

[startup+174.611 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 10033
/proc/meminfo: memFree=285680/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=221228 CPUtime=171.92
/proc/10031/stat : 10031 (clasp) R 10019 10019 1511 34817 1511 4202496 98543 0 0 0 17145 47 0 0 25 0 1 0 2384752 226537472 55073 1283457024 134512640 136285277 4290881024 18446744073709551615 135631763 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/10031/statm: 55307 55073 241 433 0 54872 0
Current children cumulated CPU time (s) 174.44
Current children cumulated vsize (KiB) 223828

[startup+174.706 s]
/proc/loadavg: 1.00 1.00 1.00 2/35 10033
/proc/meminfo: memFree=285680/1048576 swapFree=0/0
[pid=10019] ppid=10018 vsize=2600 CPUtime=2.52
/proc/10019/stat : 10019 (aspcud-trendy-1) S 10018 10019 1511 34817 1511 4202496 625 25344 0 0 0 0 241 11 18 0 1 0 2384751 2662400 299 1283457024 134512640 135304128 4292405184 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10019/statm: 650 299 251 194 0 37 0
[pid=10031] ppid=10019 vsize=2148 CPUtime=171.97
/proc/10031/stat : 10031 (clasp) D 10019 10019 1511 34817 1511 4202496 98543 0 1 0 17145 52 0 0 25 0 1 0 2384752 2199552 341 1283457024 134512640 136285277 4290881024 18446744073709551615 135940400 0 0 6 18944 18446744071564332000 0 0 17 0 0 0 0
/proc/10031/statm: 537 341 242 433 0 102 0
Current children cumulated CPU time (s) 174.49
Current children cumulated vsize (KiB) 4748

Child status: 0
Real time (s): 174.726
CPU time (s): 174.511
CPU user time (s): 173.875
CPU system time (s): 0.636039
CPU usage (%): 99.8769
Max. virtual memory (cumulated for all children) (KiB): 390592

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 173.875
system time used= 0.636039
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 128169
page faults= 2
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1241
involuntary context switches= 2934

runsolver used 0 second user time and 0.012 second system time

The end