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/p2cudf-paranoid-1.9/randa45895.cudf.difficult.log.runsolver ./p2cudf-paranoid-1.9 /home/misc2010/data/2010/difficult//randa45895.cudf /home/misc2010/tmp/201012061533/p2cudf-paranoid-1.9/randa45895.cudf.difficult.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.43 1.40 1.28 3/45 30711
/proc/meminfo: memFree=642044/1048576 swapFree=2078744/2097144
[pid=30711] ppid=30710 vsize=952 CPUtime=0
/proc/30711/stat : 30711 (p2cudf-paranoid) R 30710 30711 2059 34821 2220 4194304 103 0 0 0 0 0 0 0 25 0 1 0 876585739 974848 29 1283457024 134512640 135304128 4291598064 18446744073709551615 4159712484 0 0 0 0 0 0 0 17 0 0 0 0
/proc/30711/statm: 238 29 22 194 0 10 0

[startup+0.150592 s]
/proc/loadavg: 1.43 1.40 1.28 3/45 30711
/proc/meminfo: memFree=642044/1048576 swapFree=2078744/2097144
[pid=30711] ppid=30710 vsize=2572 CPUtime=0
/proc/30711/stat : 30711 (p2cudf-paranoid) S 30710 30711 2059 34821 2220 4202496 379 0 0 0 0 0 0 0 25 0 1 0 876585739 2633728 274 1283457024 134512640 135304128 4291598064 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30711/statm: 643 274 233 194 0 29 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2572

[startup+0.210606 s]
/proc/loadavg: 1.43 1.40 1.28 3/45 30711
/proc/meminfo: memFree=642044/1048576 swapFree=2078744/2097144
[pid=30711] ppid=30710 vsize=2572 CPUtime=0
/proc/30711/stat : 30711 (p2cudf-paranoid) S 30710 30711 2059 34821 2220 4202496 379 0 0 0 0 0 0 0 25 0 1 0 876585739 2633728 274 1283457024 134512640 135304128 4291598064 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30711/statm: 643 274 233 194 0 29 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2572

[startup+0.310613 s]
/proc/loadavg: 1.43 1.40 1.28 3/45 30711
/proc/meminfo: memFree=642044/1048576 swapFree=2078744/2097144
[pid=30711] ppid=30710 vsize=2572 CPUtime=0
/proc/30711/stat : 30711 (p2cudf-paranoid) S 30710 30711 2059 34821 2220 4202496 379 0 0 0 0 0 0 0 25 0 1 0 876585739 2633728 274 1283457024 134512640 135304128 4291598064 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30711/statm: 643 274 233 194 0 29 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2572

[startup+0.712738 s]
/proc/loadavg: 1.43 1.40 1.28 3/45 30711
/proc/meminfo: memFree=642044/1048576 swapFree=2078744/2097144
[pid=30711] ppid=30710 vsize=2572 CPUtime=0
/proc/30711/stat : 30711 (p2cudf-paranoid) S 30710 30711 2059 34821 2220 4202496 379 0 0 0 0 0 0 0 25 0 1 0 876585739 2633728 274 1283457024 134512640 135304128 4291598064 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30711/statm: 643 274 233 194 0 29 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2572

[startup+1.51286 s]
/proc/loadavg: 1.47 1.41 1.28 5/57 30734
/proc/meminfo: memFree=600332/1048576 swapFree=2078744/2097144
[pid=30711] ppid=30710 vsize=2572 CPUtime=0
/proc/30711/stat : 30711 (p2cudf-paranoid) S 30710 30711 2059 34821 2220 4202496 379 0 0 0 0 0 0 0 25 0 1 0 876585739 2633728 274 1283457024 134512640 135304128 4291598064 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30711/statm: 643 274 233 194 0 29 0
[pid=30713] ppid=30711 vsize=2576 CPUtime=0.02
/proc/30713/stat : 30713 (p2cudf) S 30711 30711 2059 34821 2220 4202496 393 2999 0 1 0 0 2 0 25 0 1 0 876585740 2637824 282 1283457024 134512640 135304128 4288314320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30713/statm: 644 282 241 194 0 30 0
[pid=30725] ppid=30713 vsize=871484 CPUtime=1.46
/proc/30725/stat : 30725 (java) S 30713 30711 2059 34821 2220 4202496 17060 0 1 0 139 7 0 0 25 0 10 0 876585743 892399616 14891 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30725/statm: 217871 14891 1741 10 0 214961 0
[pid=30725/tid=30726] ppid=30713 vsize=871484 CPUtime=0.68
/proc/30725/task/30726/stat : 30726 (java) R 30713 30711 2059 34821 2220 4202560 9668 0 1 0 64 4 0 0 25 0 10 0 876585744 892399616 14891 1283457024 134512640 134550932 4289084208 18446744073709551615 4095776548 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=30725/tid=30727] ppid=30713 vsize=871484 CPUtime=0
/proc/30725/task/30727/stat : 30727 (java) S 30713 30711 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 876585745 892399616 14891 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30728] ppid=30713 vsize=871484 CPUtime=0
/proc/30725/task/30728/stat : 30728 (java) S 30713 30711 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 876585746 892399616 14891 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30729] ppid=30713 vsize=871484 CPUtime=0
/proc/30725/task/30729/stat : 30729 (java) S 30713 30711 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 876585746 892399616 14891 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30730] ppid=30713 vsize=871484 CPUtime=0
/proc/30725/task/30730/stat : 30730 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 876585748 892399616 14891 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30731] ppid=30713 vsize=871484 CPUtime=0.24
/proc/30725/task/30731/stat : 30731 (java) R 30713 30711 2059 34821 2220 4202560 2616 0 0 0 24 0 0 0 25 0 10 0 876585748 892399616 14891 1283457024 134512640 134550932 4289084208 18446744073709551615 4152539074 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=30725/tid=30732] ppid=30713 vsize=871484 CPUtime=0.5
/proc/30725/task/30732/stat : 30732 (java) R 30713 30711 2059 34821 2220 4202560 3663 0 0 0 49 1 0 0 20 0 10 0 876585748 892399616 14891 1283457024 134512640 134550932 4289084208 18446744073709551615 4148964865 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=30725/tid=30733] ppid=30713 vsize=871484 CPUtime=0
/proc/30725/task/30733/stat : 30733 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 876585748 892399616 14891 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30734] ppid=30713 vsize=871484 CPUtime=0
/proc/30725/task/30734/stat : 30734 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 876585748 892399616 14891 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.48
Current children cumulated vsize (KiB) 876632

[startup+3.1049 s]
/proc/loadavg: 1.47 1.41 1.28 1/57 30734
/proc/meminfo: memFree=461276/1048576 swapFree=2078744/2097144
[pid=30711] ppid=30710 vsize=2572 CPUtime=0
/proc/30711/stat : 30711 (p2cudf-paranoid) S 30710 30711 2059 34821 2220 4202496 379 0 0 0 0 0 0 0 25 0 1 0 876585739 2633728 274 1283457024 134512640 135304128 4291598064 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30711/statm: 643 274 233 194 0 29 0
[pid=30713] ppid=30711 vsize=2576 CPUtime=0.02
/proc/30713/stat : 30713 (p2cudf) S 30711 30711 2059 34821 2220 4202496 393 2999 0 1 0 0 2 0 25 0 1 0 876585740 2637824 282 1283457024 134512640 135304128 4288314320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30713/statm: 644 282 241 194 0 30 0
[pid=30725] ppid=30713 vsize=873508 CPUtime=3.02
/proc/30725/stat : 30725 (java) S 30713 30711 2059 34821 2220 4202496 57832 0 1 0 275 27 0 0 25 0 10 0 876585743 894472192 55269 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30725/statm: 218377 55269 1762 10 0 215467 0
[pid=30725/tid=30726] ppid=30713 vsize=873508 CPUtime=1.64
/proc/30725/task/30726/stat : 30726 (java) R 30713 30711 2059 34821 2220 4202560 49606 0 1 0 142 22 0 0 25 0 10 0 876585744 894472192 55269 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=30725/tid=30727] ppid=30713 vsize=873508 CPUtime=0
/proc/30725/task/30727/stat : 30727 (java) S 30713 30711 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 16 0 10 0 876585745 894472192 55269 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30728] ppid=30713 vsize=873508 CPUtime=0
/proc/30725/task/30728/stat : 30728 (java) S 30713 30711 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 876585746 894472192 55269 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30729] ppid=30713 vsize=873508 CPUtime=0
/proc/30725/task/30729/stat : 30729 (java) S 30713 30711 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 876585746 894472192 55269 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30730] ppid=30713 vsize=873508 CPUtime=0
/proc/30725/task/30730/stat : 30730 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 876585748 894472192 55269 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30731] ppid=30713 vsize=873508 CPUtime=0.24
/proc/30725/task/30731/stat : 30731 (java) S 30713 30711 2059 34821 2220 4202560 2616 0 0 0 24 0 0 0 25 0 10 0 876585748 894472192 55269 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30732] ppid=30713 vsize=873508 CPUtime=1.1
/proc/30725/task/30732/stat : 30732 (java) R 30713 30711 2059 34821 2220 4202560 4497 0 0 0 108 2 0 0 16 0 10 0 876585748 894472192 55269 1283457024 134512640 134550932 4289084208 18446744073709551615 4152539035 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=30725/tid=30733] ppid=30713 vsize=873508 CPUtime=0
/proc/30725/task/30733/stat : 30733 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 876585748 894472192 55269 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30734] ppid=30713 vsize=873508 CPUtime=0
/proc/30725/task/30734/stat : 30734 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 876585748 894472192 55269 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.04
Current children cumulated vsize (KiB) 878656

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

[startup+3.20492 s]
/proc/loadavg: 1.47 1.41 1.28 1/57 30734
/proc/meminfo: memFree=461276/1048576 swapFree=2078744/2097144
[pid=30711] ppid=30710 vsize=2572 CPUtime=0
/proc/30711/stat : 30711 (p2cudf-paranoid) S 30710 30711 2059 34821 2220 4202496 379 0 0 0 0 0 0 0 25 0 1 0 876585739 2633728 274 1283457024 134512640 135304128 4291598064 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30711/statm: 643 274 233 194 0 29 0
[pid=30713] ppid=30711 vsize=2576 CPUtime=0.02
/proc/30713/stat : 30713 (p2cudf) S 30711 30711 2059 34821 2220 4202496 393 2999 0 1 0 0 2 0 25 0 1 0 876585740 2637824 282 1283457024 134512640 135304128 4288314320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30713/statm: 644 282 241 194 0 30 0
[pid=30725] ppid=30713 vsize=875352 CPUtime=3.12
/proc/30725/stat : 30725 (java) S 30713 30711 2059 34821 2220 4202496 58678 0 1 0 285 27 0 0 25 0 10 0 876585743 896360448 55737 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30725/statm: 218838 55737 1762 10 0 215928 0
[pid=30725/tid=30726] ppid=30713 vsize=875352 CPUtime=1.64
/proc/30725/task/30726/stat : 30726 (java) R 30713 30711 2059 34821 2220 4202560 49606 0 1 0 142 22 0 0 25 0 10 0 876585744 896360448 55737 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=30725/tid=30727] ppid=30713 vsize=875352 CPUtime=0
/proc/30725/task/30727/stat : 30727 (java) S 30713 30711 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 16 0 10 0 876585745 896360448 55737 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30728] ppid=30713 vsize=875352 CPUtime=0
/proc/30725/task/30728/stat : 30728 (java) S 30713 30711 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 876585746 896360448 55737 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30729] ppid=30713 vsize=875352 CPUtime=0
/proc/30725/task/30729/stat : 30729 (java) S 30713 30711 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 876585746 896360448 55737 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30730] ppid=30713 vsize=875352 CPUtime=0
/proc/30725/task/30730/stat : 30730 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 876585748 896360448 55737 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30731] ppid=30713 vsize=875352 CPUtime=0.24
/proc/30725/task/30731/stat : 30731 (java) S 30713 30711 2059 34821 2220 4202560 2616 0 0 0 24 0 0 0 25 0 10 0 876585748 896360448 55737 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30732] ppid=30713 vsize=875352 CPUtime=1.2
/proc/30725/task/30732/stat : 30732 (java) R 30713 30711 2059 34821 2220 4202560 5343 0 0 0 118 2 0 0 16 0 10 0 876585748 896360448 55737 1283457024 134512640 134550932 4289084208 18446744073709551615 4150070190 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=30725/tid=30733] ppid=30713 vsize=875352 CPUtime=0
/proc/30725/task/30733/stat : 30733 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 876585748 896360448 55737 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30734] ppid=30713 vsize=875352 CPUtime=0
/proc/30725/task/30734/stat : 30734 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 876585748 896360448 55737 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.14
Current children cumulated vsize (KiB) 880500

[startup+4.00509 s]
/proc/loadavg: 1.47 1.41 1.28 3/57 30734
/proc/meminfo: memFree=412280/1048576 swapFree=2078744/2097144
[pid=30711] ppid=30710 vsize=2572 CPUtime=0
/proc/30711/stat : 30711 (p2cudf-paranoid) S 30710 30711 2059 34821 2220 4202496 379 0 0 0 0 0 0 0 25 0 1 0 876585739 2633728 274 1283457024 134512640 135304128 4291598064 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30711/statm: 643 274 233 194 0 29 0
[pid=30713] ppid=30711 vsize=2576 CPUtime=0.02
/proc/30713/stat : 30713 (p2cudf) S 30711 30711 2059 34821 2220 4202496 393 2999 0 1 0 0 2 0 25 0 1 0 876585740 2637824 282 1283457024 134512640 135304128 4288314320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30713/statm: 644 282 241 194 0 30 0
[pid=30725] ppid=30713 vsize=871372 CPUtime=3.92
/proc/30725/stat : 30725 (java) S 30713 30711 2059 34821 2220 4202496 73578 0 1 0 357 35 0 0 25 0 10 0 876585743 892284928 69341 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30725/statm: 217843 69341 1766 10 0 214933 0
[pid=30725/tid=30726] ppid=30713 vsize=871372 CPUtime=1.83
/proc/30725/task/30726/stat : 30726 (java) R 30713 30711 2059 34821 2220 4202560 50390 0 1 0 160 23 0 0 25 0 10 0 876585744 892284928 69341 1283457024 134512640 134550932 4289084208 18446744073709551615 4096099998 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=30725/tid=30727] ppid=30713 vsize=871372 CPUtime=0.31
/proc/30725/task/30727/stat : 30727 (java) S 30713 30711 2059 34821 2220 4202560 13601 0 0 0 24 7 0 0 16 0 10 0 876585745 892284928 69341 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30728] ppid=30713 vsize=871372 CPUtime=0
/proc/30725/task/30728/stat : 30728 (java) S 30713 30711 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 18 0 10 0 876585746 892284928 69341 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30729] ppid=30713 vsize=871372 CPUtime=0
/proc/30725/task/30729/stat : 30729 (java) S 30713 30711 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 10 0 876585746 892284928 69341 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30730] ppid=30713 vsize=871372 CPUtime=0
/proc/30725/task/30730/stat : 30730 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 876585748 892284928 69341 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30731] ppid=30713 vsize=871372 CPUtime=0.24
/proc/30725/task/30731/stat : 30731 (java) S 30713 30711 2059 34821 2220 4202560 2616 0 0 0 24 0 0 0 25 0 10 0 876585748 892284928 69341 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30732] ppid=30713 vsize=871372 CPUtime=1.48
/proc/30725/task/30732/stat : 30732 (java) S 30713 30711 2059 34821 2220 4202560 5861 0 0 0 146 2 0 0 15 0 10 0 876585748 892284928 69341 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30733] ppid=30713 vsize=871372 CPUtime=0
/proc/30725/task/30733/stat : 30733 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 876585748 892284928 69341 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30734] ppid=30713 vsize=871372 CPUtime=0
/proc/30725/task/30734/stat : 30734 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 876585748 892284928 69341 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.94
Current children cumulated vsize (KiB) 876520

[startup+4.40486 s]
/proc/loadavg: 1.47 1.41 1.28 1/58 30735
/proc/meminfo: memFree=357588/1048576 swapFree=2078744/2097144
[pid=30711] ppid=30710 vsize=2572 CPUtime=0
/proc/30711/stat : 30711 (p2cudf-paranoid) S 30710 30711 2059 34821 2220 4202496 379 0 0 0 0 0 0 0 25 0 1 0 876585739 2633728 274 1283457024 134512640 135304128 4291598064 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30711/statm: 643 274 233 194 0 29 0
[pid=30713] ppid=30711 vsize=2576 CPUtime=0.02
/proc/30713/stat : 30713 (p2cudf) S 30711 30711 2059 34821 2220 4202496 393 2999 0 1 0 0 2 0 25 0 1 0 876585740 2637824 282 1283457024 134512640 135304128 4288314320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30713/statm: 644 282 241 194 0 30 0
[pid=30725] ppid=30713 vsize=871696 CPUtime=4
/proc/30725/stat : 30725 (java) S 30713 30711 2059 34821 2220 4202496 73626 0 1 0 365 35 0 0 25 0 11 0 876585743 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30725/statm: 217924 69389 1766 10 0 215014 0
[pid=30725/tid=30726] ppid=30713 vsize=871696 CPUtime=1.91
/proc/30725/task/30726/stat : 30726 (java) S 30713 30711 2059 34821 2220 4202560 50434 0 1 0 168 23 0 0 25 0 11 0 876585744 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30727] ppid=30713 vsize=871696 CPUtime=0.31
/proc/30725/task/30727/stat : 30727 (java) S 30713 30711 2059 34821 2220 4202560 13601 0 0 0 24 7 0 0 16 0 11 0 876585745 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30728] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30728/stat : 30728 (java) S 30713 30711 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 18 0 11 0 876585746 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30729] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30729/stat : 30729 (java) S 30713 30711 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 11 0 876585746 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30730] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30730/stat : 30730 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 876585748 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30731] ppid=30713 vsize=871696 CPUtime=0.24
/proc/30725/task/30731/stat : 30731 (java) S 30713 30711 2059 34821 2220 4202560 2616 0 0 0 24 0 0 0 25 0 11 0 876585748 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30732] ppid=30713 vsize=871696 CPUtime=1.48
/proc/30725/task/30732/stat : 30732 (java) S 30713 30711 2059 34821 2220 4202560 5861 0 0 0 146 2 0 0 15 0 11 0 876585748 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30733] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30733/stat : 30733 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 876585748 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30734] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30734/stat : 30734 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 876585748 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30735] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30735/stat : 30735 (java) S 30713 30711 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 11 0 876586149 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.02
Current children cumulated vsize (KiB) 876844

[startup+4.60485 s]
/proc/loadavg: 1.47 1.41 1.28 1/58 30735
/proc/meminfo: memFree=357588/1048576 swapFree=2078744/2097144
[pid=30711] ppid=30710 vsize=2572 CPUtime=0
/proc/30711/stat : 30711 (p2cudf-paranoid) S 30710 30711 2059 34821 2220 4202496 379 0 0 0 0 0 0 0 25 0 1 0 876585739 2633728 274 1283457024 134512640 135304128 4291598064 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30711/statm: 643 274 233 194 0 29 0
[pid=30713] ppid=30711 vsize=2576 CPUtime=0.02
/proc/30713/stat : 30713 (p2cudf) S 30711 30711 2059 34821 2220 4202496 393 2999 0 1 0 0 2 0 25 0 1 0 876585740 2637824 282 1283457024 134512640 135304128 4288314320 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30713/statm: 644 282 241 194 0 30 0
[pid=30725] ppid=30713 vsize=871696 CPUtime=4
/proc/30725/stat : 30725 (java) S 30713 30711 2059 34821 2220 4202496 73626 0 1 0 365 35 0 0 25 0 11 0 876585743 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/30725/statm: 217924 69389 1766 10 0 215014 0
[pid=30725/tid=30726] ppid=30713 vsize=871696 CPUtime=1.91
/proc/30725/task/30726/stat : 30726 (java) S 30713 30711 2059 34821 2220 4202560 50434 0 1 0 168 23 0 0 25 0 11 0 876585744 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30727] ppid=30713 vsize=871696 CPUtime=0.31
/proc/30725/task/30727/stat : 30727 (java) S 30713 30711 2059 34821 2220 4202560 13601 0 0 0 24 7 0 0 16 0 11 0 876585745 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30728] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30728/stat : 30728 (java) S 30713 30711 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 18 0 11 0 876585746 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30729] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30729/stat : 30729 (java) S 30713 30711 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 11 0 876585746 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30730] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30730/stat : 30730 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 876585748 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30731] ppid=30713 vsize=871696 CPUtime=0.24
/proc/30725/task/30731/stat : 30731 (java) S 30713 30711 2059 34821 2220 4202560 2616 0 0 0 24 0 0 0 25 0 11 0 876585748 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30732] ppid=30713 vsize=871696 CPUtime=1.48
/proc/30725/task/30732/stat : 30732 (java) S 30713 30711 2059 34821 2220 4202560 5861 0 0 0 146 2 0 0 15 0 11 0 876585748 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30733] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30733/stat : 30733 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 876585748 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30734] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30734/stat : 30734 (java) S 30713 30711 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 876585748 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=30725/tid=30735] ppid=30713 vsize=871696 CPUtime=0
/proc/30725/task/30735/stat : 30735 (java) D 30713 30711 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 20 0 11 0 876586149 892616704 69389 1283457024 134512640 134550932 4289084208 18446744073709551615 4294960130 0 4 0 16800975 18446744071564252162 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.02
Current children cumulated vsize (KiB) 876844

Child status: 0
Real time (s): 4.66881
CPU time (s): 4.04425
CPU user time (s): 3.67223
CPU system time (s): 0.372023
CPU usage (%): 86.6227
Max. virtual memory (cumulated for all children) (KiB): 880560

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.67223
system time used= 0.372023
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 77422
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= 434
involuntary context switches= 458

runsolver used 0 second user time and 0 second system time

The end