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/201012061533/gj-paranoid-solver-0.1/rand550.sarge-etch.cudf.sarge-etch.log.runsolver ./gj-paranoid-solver-0.1 /home/misc2010/data/icse/sarge-etch/rand550.sarge-etch.cudf /home/misc2010/tmp/201012061533/gj-paranoid-solver-0.1/rand550.sarge-etch.cudf.sarge-etch.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.10 1.08 1.10 5/46 17148
/proc/meminfo: memFree=811880/1048576 swapFree=2078744/2097144
[pid=17147] ppid=17146 vsize=2572 CPUtime=0
/proc/17147/stat : 17147 (gj-paranoid-sol) S 17146 17147 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 23 0 1 0 875811254 2633728 272 1283457024 134512640 135304128 4286609936 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/17147/statm: 643 272 232 194 0 29 0
[pid=17148] ppid=17147 vsize=300 CPUtime=0
/proc/17148/stat : 17148 (java) R 17147 17147 2059 34821 2220 4194304 99 0 0 0 0 0 0 0 25 0 1 0 875811254 307200 39 1283457024 134512640 134550932 4294607312 18446744073709551615 4159688036 0 0 0 0 0 0 0 17 0 0 0 0
/proc/17148/statm: 75 39 29 10 0 8 0

[startup+0.122642 s]
/proc/loadavg: 1.10 1.08 1.10 5/46 17148
/proc/meminfo: memFree=811880/1048576 swapFree=2078744/2097144
[pid=17147] ppid=17146 vsize=2572 CPUtime=0
/proc/17147/stat : 17147 (gj-paranoid-sol) S 17146 17147 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 23 0 1 0 875811254 2633728 272 1283457024 134512640 135304128 4286609936 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/17147/statm: 643 272 232 194 0 29 0
[pid=17148] ppid=17147 vsize=409672 CPUtime=0.12
/proc/17148/stat : 17148 (java) S 17147 17147 2059 34821 2220 4202496 3581 0 1 0 12 0 0 0 25 0 9 0 875811254 419504128 3046 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/17148/statm: 102418 3046 1732 10 0 96598 0
Current children cumulated CPU time (s) 0.12
Current children cumulated vsize (KiB) 412244

[startup+0.212656 s]
/proc/loadavg: 1.10 1.08 1.10 5/46 17148
/proc/meminfo: memFree=811880/1048576 swapFree=2078744/2097144
[pid=17147] ppid=17146 vsize=2572 CPUtime=0
/proc/17147/stat : 17147 (gj-paranoid-sol) S 17146 17147 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 23 0 1 0 875811254 2633728 272 1283457024 134512640 135304128 4286609936 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/17147/statm: 643 272 232 194 0 29 0
[pid=17148] ppid=17147 vsize=409672 CPUtime=0.22
/proc/17148/stat : 17148 (java) S 17147 17147 2059 34821 2220 4202496 3832 0 1 0 20 2 0 0 25 0 9 0 875811254 419504128 3297 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/17148/statm: 102418 3297 1732 10 0 96598 0
Current children cumulated CPU time (s) 0.22
Current children cumulated vsize (KiB) 412244

[startup+0.302677 s]
/proc/loadavg: 1.10 1.08 1.10 5/46 17148
/proc/meminfo: memFree=811880/1048576 swapFree=2078744/2097144
[pid=17147] ppid=17146 vsize=2572 CPUtime=0
/proc/17147/stat : 17147 (gj-paranoid-sol) S 17146 17147 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 23 0 1 0 875811254 2633728 272 1283457024 134512640 135304128 4286609936 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/17147/statm: 643 272 232 194 0 29 0
[pid=17148] ppid=17147 vsize=410104 CPUtime=0.3
/proc/17148/stat : 17148 (java) S 17147 17147 2059 34821 2220 4202496 4325 0 1 0 27 3 0 0 25 0 9 0 875811254 419946496 3790 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/17148/statm: 102526 3790 1874 10 0 96706 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 412676

[startup+0.70275 s]
/proc/loadavg: 1.10 1.08 1.10 5/46 17148
/proc/meminfo: memFree=811880/1048576 swapFree=2078744/2097144
[pid=17147] ppid=17146 vsize=2572 CPUtime=0
/proc/17147/stat : 17147 (gj-paranoid-sol) S 17146 17147 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 23 0 1 0 875811254 2633728 272 1283457024 134512640 135304128 4286609936 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/17147/statm: 643 272 232 194 0 29 0
[pid=17148] ppid=17147 vsize=410712 CPUtime=0.7
/proc/17148/stat : 17148 (java) S 17147 17147 2059 34821 2220 4202496 12832 0 1 0 63 7 0 0 25 0 9 0 875811254 420569088 12118 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/17148/statm: 102678 12118 2878 10 0 96858 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 413284

[startup+1.51287 s]
/proc/loadavg: 1.10 1.08 1.10 2/55 17157
/proc/meminfo: memFree=751880/1048576 swapFree=2078744/2097144
[pid=17147] ppid=17146 vsize=2572 CPUtime=0
/proc/17147/stat : 17147 (gj-paranoid-sol) S 17146 17147 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 23 0 1 0 875811254 2633728 272 1283457024 134512640 135304128 4286609936 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/17147/statm: 643 272 232 194 0 29 0
[pid=17148] ppid=17147 vsize=410844 CPUtime=1.52
/proc/17148/stat : 17148 (java) S 17147 17147 2059 34821 2220 4202496 28008 0 1 0 140 12 0 0 25 0 9 0 875811254 420704256 27294 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/17148/statm: 102711 27294 2879 10 0 96891 0
[pid=17148/tid=17150] ppid=17147 vsize=410844 CPUtime=0.69
/proc/17148/task/17150/stat : 17150 (java) R 17147 17147 2059 34821 2220 4202560 6657 0 1 0 68 1 0 0 25 0 9 0 875811255 420704256 27294 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=17148/tid=17151] ppid=17147 vsize=410844 CPUtime=0.78
/proc/17148/task/17151/stat : 17151 (java) R 17147 17147 2059 34821 2220 4202560 19960 0 0 0 70 8 0 0 20 0 9 0 875811256 420704256 27294 1283457024 134512640 134550932 4291028384 18446744073709551615 4151054840 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=17148/tid=17152] ppid=17147 vsize=410844 CPUtime=0
/proc/17148/task/17152/stat : 17152 (java) S 17147 17147 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 20 0 9 0 875811256 420704256 27294 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17153] ppid=17147 vsize=410844 CPUtime=0
/proc/17148/task/17153/stat : 17153 (java) S 17147 17147 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 22 0 9 0 875811256 420704256 27294 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17154] ppid=17147 vsize=410844 CPUtime=0
/proc/17148/task/17154/stat : 17154 (java) S 17147 17147 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 9 0 875811257 420704256 27294 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17155] ppid=17147 vsize=410844 CPUtime=0.02
/proc/17148/task/17155/stat : 17155 (java) S 17147 17147 2059 34821 2220 4202560 459 0 0 0 1 1 0 0 16 0 9 0 875811257 420704256 27294 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17156] ppid=17147 vsize=410844 CPUtime=0
/proc/17148/task/17156/stat : 17156 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 9 0 875811257 420704256 27294 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17157] ppid=17147 vsize=410844 CPUtime=0
/proc/17148/task/17157/stat : 17157 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 9 0 875811257 420704256 27294 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.52
Current children cumulated vsize (KiB) 413416

[startup+3.11306 s]
/proc/loadavg: 1.10 1.08 1.10 2/56 17158
/proc/meminfo: memFree=687268/1048576 swapFree=2078744/2097144
[pid=17147] ppid=17146 vsize=2572 CPUtime=0
/proc/17147/stat : 17147 (gj-paranoid-sol) S 17146 17147 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 23 0 1 0 875811254 2633728 272 1283457024 134512640 135304128 4286609936 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/17147/statm: 643 272 232 194 0 29 0
[pid=17148] ppid=17147 vsize=411168 CPUtime=3.11
/proc/17148/stat : 17148 (java) S 17147 17147 2059 34821 2220 4202496 34618 0 1 0 296 15 0 0 25 0 10 0 875811254 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/17148/statm: 102792 33888 2885 10 0 96972 0
[pid=17148/tid=17150] ppid=17147 vsize=411168 CPUtime=2
/proc/17148/task/17150/stat : 17150 (java) R 17147 17147 2059 34821 2220 4202560 9500 0 1 0 198 2 0 0 25 0 10 0 875811255 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4114606598 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=17148/tid=17151] ppid=17147 vsize=411168 CPUtime=1.02
/proc/17148/task/17151/stat : 17151 (java) S 17147 17147 2059 34821 2220 4202560 23655 0 0 0 91 11 0 0 18 0 10 0 875811256 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17152] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17152/stat : 17152 (java) S 17147 17147 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 875811256 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17153] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17153/stat : 17153 (java) S 17147 17147 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 22 0 10 0 875811256 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17154] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17154/stat : 17154 (java) S 17147 17147 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17155] ppid=17147 vsize=411168 CPUtime=0.07
/proc/17148/task/17155/stat : 17155 (java) S 17147 17147 2059 34821 2220 4202560 526 0 0 0 6 1 0 0 15 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17156] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17156/stat : 17156 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17157] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17157/stat : 17157 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17158] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17158/stat : 17158 (java) S 17147 17147 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875811457 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.11
Current children cumulated vsize (KiB) 413740

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

[startup+3.21309 s]
/proc/loadavg: 1.10 1.08 1.10 2/56 17158
/proc/meminfo: memFree=687268/1048576 swapFree=2078744/2097144
[pid=17147] ppid=17146 vsize=2572 CPUtime=0
/proc/17147/stat : 17147 (gj-paranoid-sol) S 17146 17147 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 23 0 1 0 875811254 2633728 272 1283457024 134512640 135304128 4286609936 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/17147/statm: 643 272 232 194 0 29 0
[pid=17148] ppid=17147 vsize=411168 CPUtime=3.21
/proc/17148/stat : 17148 (java) S 17147 17147 2059 34821 2220 4202496 34618 0 1 0 306 15 0 0 25 0 10 0 875811254 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/17148/statm: 102792 33888 2885 10 0 96972 0
[pid=17148/tid=17150] ppid=17147 vsize=411168 CPUtime=2.1
/proc/17148/task/17150/stat : 17150 (java) R 17147 17147 2059 34821 2220 4202560 9500 0 1 0 208 2 0 0 25 0 10 0 875811255 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4115296041 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=17148/tid=17151] ppid=17147 vsize=411168 CPUtime=1.02
/proc/17148/task/17151/stat : 17151 (java) S 17147 17147 2059 34821 2220 4202560 23655 0 0 0 91 11 0 0 18 0 10 0 875811256 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17152] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17152/stat : 17152 (java) S 17147 17147 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 875811256 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17153] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17153/stat : 17153 (java) S 17147 17147 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 22 0 10 0 875811256 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17154] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17154/stat : 17154 (java) S 17147 17147 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17155] ppid=17147 vsize=411168 CPUtime=0.07
/proc/17148/task/17155/stat : 17155 (java) S 17147 17147 2059 34821 2220 4202560 526 0 0 0 6 1 0 0 15 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17156] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17156/stat : 17156 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17157] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17157/stat : 17157 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17158] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17158/stat : 17158 (java) S 17147 17147 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875811457 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.21
Current children cumulated vsize (KiB) 413740

[startup+3.61322 s]
/proc/loadavg: 1.10 1.08 1.10 2/56 17158
/proc/meminfo: memFree=687144/1048576 swapFree=2078744/2097144
[pid=17147] ppid=17146 vsize=2572 CPUtime=0
/proc/17147/stat : 17147 (gj-paranoid-sol) S 17146 17147 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 23 0 1 0 875811254 2633728 272 1283457024 134512640 135304128 4286609936 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/17147/statm: 643 272 232 194 0 29 0
[pid=17148] ppid=17147 vsize=411168 CPUtime=3.61
/proc/17148/stat : 17148 (java) S 17147 17147 2059 34821 2220 4202496 34618 0 1 0 346 15 0 0 25 0 10 0 875811254 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/17148/statm: 102792 33888 2885 10 0 96972 0
[pid=17148/tid=17150] ppid=17147 vsize=411168 CPUtime=2.5
/proc/17148/task/17150/stat : 17150 (java) R 17147 17147 2059 34821 2220 4202560 9500 0 1 0 248 2 0 0 25 0 10 0 875811255 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4115301156 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=17148/tid=17151] ppid=17147 vsize=411168 CPUtime=1.02
/proc/17148/task/17151/stat : 17151 (java) S 17147 17147 2059 34821 2220 4202560 23655 0 0 0 91 11 0 0 18 0 10 0 875811256 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17152] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17152/stat : 17152 (java) S 17147 17147 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 875811256 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17153] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17153/stat : 17153 (java) S 17147 17147 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 22 0 10 0 875811256 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17154] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17154/stat : 17154 (java) S 17147 17147 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17155] ppid=17147 vsize=411168 CPUtime=0.07
/proc/17148/task/17155/stat : 17155 (java) S 17147 17147 2059 34821 2220 4202560 526 0 0 0 6 1 0 0 15 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17156] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17156/stat : 17156 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17157] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17157/stat : 17157 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875811257 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17158] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17158/stat : 17158 (java) S 17147 17147 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875811457 421036032 33888 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.61
Current children cumulated vsize (KiB) 413740

[startup+4.01341 s]
/proc/loadavg: 1.10 1.08 1.10 2/56 17158
/proc/meminfo: memFree=687144/1048576 swapFree=2078744/2097144
[pid=17147] ppid=17146 vsize=2572 CPUtime=0
/proc/17147/stat : 17147 (gj-paranoid-sol) S 17146 17147 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 23 0 1 0 875811254 2633728 272 1283457024 134512640 135304128 4286609936 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/17147/statm: 643 272 232 194 0 29 0
[pid=17148] ppid=17147 vsize=411168 CPUtime=4.01
/proc/17148/stat : 17148 (java) S 17147 17147 2059 34821 2220 4202496 34658 0 1 0 385 16 0 0 25 0 10 0 875811254 421036032 33922 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/17148/statm: 102792 33922 2883 10 0 96972 0
[pid=17148/tid=17150] ppid=17147 vsize=411168 CPUtime=2.72
/proc/17148/task/17150/stat : 17150 (java) R 17147 17147 2059 34821 2220 4202560 9501 0 1 0 270 2 0 0 25 0 10 0 875811255 421036032 33922 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=17148/tid=17151] ppid=17147 vsize=411168 CPUtime=1.19
/proc/17148/task/17151/stat : 17151 (java) R 17147 17147 2059 34821 2220 4202560 23692 0 0 0 108 11 0 0 18 0 10 0 875811256 421036032 33922 1283457024 134512640 134550932 4291028384 18446744073709551615 4149551903 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=17148/tid=17152] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17152/stat : 17152 (java) S 17147 17147 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 875811256 421036032 33922 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17153] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17153/stat : 17153 (java) S 17147 17147 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 22 0 10 0 875811256 421036032 33922 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17154] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17154/stat : 17154 (java) S 17147 17147 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875811257 421036032 33922 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17155] ppid=17147 vsize=411168 CPUtime=0.07
/proc/17148/task/17155/stat : 17155 (java) S 17147 17147 2059 34821 2220 4202560 528 0 0 0 6 1 0 0 16 0 10 0 875811257 421036032 33922 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17156] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17156/stat : 17156 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 10 0 875811257 421036032 33922 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17157] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17157/stat : 17157 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875811257 421036032 33922 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17158] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17158/stat : 17158 (java) S 17147 17147 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875811457 421036032 33922 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.01
Current children cumulated vsize (KiB) 413740

[startup+4.11346 s]
/proc/loadavg: 1.10 1.08 1.10 2/56 17158
/proc/meminfo: memFree=687144/1048576 swapFree=2078744/2097144
[pid=17147] ppid=17146 vsize=2572 CPUtime=0
/proc/17147/stat : 17147 (gj-paranoid-sol) S 17146 17147 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 23 0 1 0 875811254 2633728 272 1283457024 134512640 135304128 4286609936 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/17147/statm: 643 272 232 194 0 29 0
[pid=17148] ppid=17147 vsize=411168 CPUtime=4.11
/proc/17148/stat : 17148 (java) S 17147 17147 2059 34821 2220 4202496 35850 0 1 0 394 17 0 0 25 0 10 0 875811254 421036032 35114 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/17148/statm: 102792 35114 2883 10 0 96972 0
[pid=17148/tid=17150] ppid=17147 vsize=411168 CPUtime=2.73
/proc/17148/task/17150/stat : 17150 (java) R 17147 17147 2059 34821 2220 4202560 9501 0 1 0 271 2 0 0 25 0 10 0 875811255 421036032 35114 1283457024 134512640 134550932 4291028384 18446744073709551615 4115303119 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=17148/tid=17151] ppid=17147 vsize=411168 CPUtime=1.28
/proc/17148/task/17151/stat : 17151 (java) S 17147 17147 2059 34821 2220 4202560 24884 0 0 0 116 12 0 0 18 0 10 0 875811256 421036032 35114 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 0 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17152] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17152/stat : 17152 (java) S 17147 17147 2059 34821 2220 4202560 18 0 0 0 0 0 0 0 18 0 10 0 875811256 421036032 35114 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17153] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17153/stat : 17153 (java) S 17147 17147 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875811256 421036032 35114 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17154] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17154/stat : 17154 (java) S 17147 17147 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875811257 421036032 35114 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17155] ppid=17147 vsize=411168 CPUtime=0.07
/proc/17148/task/17155/stat : 17155 (java) S 17147 17147 2059 34821 2220 4202560 528 0 0 0 6 1 0 0 16 0 10 0 875811257 421036032 35114 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17156] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17156/stat : 17156 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 10 0 875811257 421036032 35114 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17157] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17157/stat : 17157 (java) S 17147 17147 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 15 0 10 0 875811257 421036032 35114 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
[pid=17148/tid=17158] ppid=17147 vsize=411168 CPUtime=0
/proc/17148/task/17158/stat : 17158 (java) S 17147 17147 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 25 0 10 0 875811457 421036032 35114 1283457024 134512640 134550932 4291028384 18446744073709551615 4294960130 0 4 0 16800975 18446612133395920000 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.11
Current children cumulated vsize (KiB) 413740

Child status: 0
Real time (s): 4.15416
CPU time (s): 4.14426
CPU user time (s): 3.96825
CPU system time (s): 0.176011
CPU usage (%): 99.7617
Max. virtual memory (cumulated for all children) (KiB): 413740

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.96825
system time used= 0.176011
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 36248
page faults= 1
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 695
involuntary context switches= 719

runsolver used 0 second user time and 0 second system time

The end