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/201103031013/p2cudf-paranoid-1.12/3e4f8550-0b33-11df-942d-00163e1d94dc.cudf.debian.log.runsolver ./p2cudf-paranoid-1.12 /home/misc2010/data/misc4/debian//3e4f8550-0b33-11df-942d-00163e1d94dc.cudf /home/misc2010/tmp/201103031013/p2cudf-paranoid-1.12/3e4f8550-0b33-11df-942d-00163e1d94dc.cudf.debian.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.04 1.00 5/37 18820
/proc/meminfo: memFree=620532/1048576 swapFree=0/0
[pid=18819] ppid=18818 vsize=2568 CPUtime=0
/proc/18819/stat : 18819 (p2cudf-paranoid) R 18818 18819 29493 34817 29493 4202496 357 0 0 0 0 0 0 0 25 0 1 0 74914366 2629632 271 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/18819/statm: 642 271 230 194 0 29 0
[pid=18820] ppid=18819 vsize=2568 CPUtime=0
/proc/18820/stat : 18820 (p2cudf-paranoid) R 18819 18819 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 74914367 2629632 41 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/18820/statm: 642 41 0 194 0 29 0

[startup+0.205677 s]
/proc/loadavg: 1.00 1.04 1.00 5/37 18820
/proc/meminfo: memFree=620532/1048576 swapFree=0/0
[pid=18819] ppid=18818 vsize=2568 CPUtime=0
/proc/18819/stat : 18819 (p2cudf-paranoid) S 18818 18819 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 74914366 2629632 271 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18819/statm: 642 271 230 194 0 29 0
[pid=18820] ppid=18819 vsize=2580 CPUtime=0.04
/proc/18820/stat : 18820 (p2cudf) S 18819 18819 29493 34817 29493 4202496 395 3009 0 1 0 0 2 2 25 0 1 0 74914367 2641920 281 1283457024 134512640 135304128 4287242912 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18820/statm: 645 281 239 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5148

[startup+0.305687 s]
/proc/loadavg: 1.00 1.04 1.00 5/37 18820
/proc/meminfo: memFree=620532/1048576 swapFree=0/0
[pid=18819] ppid=18818 vsize=2568 CPUtime=0
/proc/18819/stat : 18819 (p2cudf-paranoid) S 18818 18819 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 74914366 2629632 271 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18819/statm: 642 271 230 194 0 29 0
[pid=18820] ppid=18819 vsize=2580 CPUtime=0.04
/proc/18820/stat : 18820 (p2cudf) S 18819 18819 29493 34817 29493 4202496 395 3009 0 1 0 0 2 2 25 0 1 0 74914367 2641920 281 1283457024 134512640 135304128 4287242912 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18820/statm: 645 281 239 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5148

[startup+0.40571 s]
/proc/loadavg: 1.00 1.04 1.00 5/37 18820
/proc/meminfo: memFree=620532/1048576 swapFree=0/0
[pid=18819] ppid=18818 vsize=2568 CPUtime=0
/proc/18819/stat : 18819 (p2cudf-paranoid) S 18818 18819 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 74914366 2629632 271 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18819/statm: 642 271 230 194 0 29 0
[pid=18820] ppid=18819 vsize=2580 CPUtime=0.04
/proc/18820/stat : 18820 (p2cudf) S 18819 18819 29493 34817 29493 4202496 395 3009 0 1 0 0 2 2 25 0 1 0 74914367 2641920 281 1283457024 134512640 135304128 4287242912 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18820/statm: 645 281 239 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5148

[startup+0.705791 s]
/proc/loadavg: 1.00 1.04 1.00 5/37 18820
/proc/meminfo: memFree=620532/1048576 swapFree=0/0
[pid=18819] ppid=18818 vsize=2568 CPUtime=0
/proc/18819/stat : 18819 (p2cudf-paranoid) S 18818 18819 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 74914366 2629632 271 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18819/statm: 642 271 230 194 0 29 0
[pid=18820] ppid=18819 vsize=2580 CPUtime=0.04
/proc/18820/stat : 18820 (p2cudf) S 18819 18819 29493 34817 29493 4202496 395 3009 0 1 0 0 2 2 25 0 1 0 74914367 2641920 281 1283457024 134512640 135304128 4287242912 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18820/statm: 645 281 239 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5148

[startup+1.5059 s]
/proc/loadavg: 1.00 1.04 1.00 3/48 18842
/proc/meminfo: memFree=561340/1048576 swapFree=0/0
[pid=18819] ppid=18818 vsize=2568 CPUtime=0
/proc/18819/stat : 18819 (p2cudf-paranoid) S 18818 18819 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 74914366 2629632 271 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18819/statm: 642 271 230 194 0 29 0
[pid=18820] ppid=18819 vsize=2580 CPUtime=0.04
/proc/18820/stat : 18820 (p2cudf) S 18819 18819 29493 34817 29493 4202496 395 3009 0 1 0 0 2 2 25 0 1 0 74914367 2641920 281 1283457024 134512640 135304128 4287242912 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18820/statm: 645 281 239 194 0 32 0
[pid=18833] ppid=18820 vsize=885780 CPUtime=1.46
/proc/18833/stat : 18833 (java) S 18820 18819 29493 34817 29493 4202496 22280 0 1 0 143 3 0 0 25 0 10 0 74914370 907038720 18883 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18833/statm: 221445 18883 1721 10 0 218536 0
[pid=18833/tid=18834] ppid=18820 vsize=885780 CPUtime=0.8
/proc/18833/task/18834/stat : 18834 (java) R 18820 18819 29493 34817 29493 4202560 10628 0 1 0 78 2 0 0 25 0 10 0 74914371 907038720 18883 1283457024 134512640 134550932 4292728432 18446744073709551615 4095477098 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18833/tid=18835] ppid=18820 vsize=885780 CPUtime=0
/proc/18833/task/18835/stat : 18835 (java) S 18820 18819 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 18 0 10 0 74914372 907038720 18883 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18836] ppid=18820 vsize=885780 CPUtime=0
/proc/18833/task/18836/stat : 18836 (java) S 18820 18819 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 74914373 907038720 18883 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18837] ppid=18820 vsize=885780 CPUtime=0
/proc/18833/task/18837/stat : 18837 (java) S 18820 18819 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 74914373 907038720 18883 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18838] ppid=18820 vsize=885780 CPUtime=0
/proc/18833/task/18838/stat : 18838 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74914375 907038720 18883 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18839] ppid=18820 vsize=885780 CPUtime=0.43
/proc/18833/task/18839/stat : 18839 (java) R 18820 18819 29493 34817 29493 4202560 8468 0 0 0 43 0 0 0 25 0 10 0 74914375 907038720 18883 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18833/tid=18840] ppid=18820 vsize=885780 CPUtime=0.22
/proc/18833/task/18840/stat : 18840 (java) R 18820 18819 29493 34817 29493 4202560 2103 0 0 0 22 0 0 0 18 0 10 0 74914375 907038720 18883 1283457024 134512640 134550932 4292728432 18446744073709551615 4150110586 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18833/tid=18841] ppid=18820 vsize=885780 CPUtime=0
/proc/18833/task/18841/stat : 18841 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74914375 907038720 18883 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18842] ppid=18820 vsize=885780 CPUtime=0
/proc/18833/task/18842/stat : 18842 (java) S 18820 18819 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 74914375 907038720 18883 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 890928

[startup+3.10629 s]
/proc/loadavg: 1.00 1.04 1.00 3/48 18842
/proc/meminfo: memFree=449244/1048576 swapFree=0/0
[pid=18819] ppid=18818 vsize=2568 CPUtime=0
/proc/18819/stat : 18819 (p2cudf-paranoid) S 18818 18819 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 74914366 2629632 271 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18819/statm: 642 271 230 194 0 29 0
[pid=18820] ppid=18819 vsize=2580 CPUtime=0.04
/proc/18820/stat : 18820 (p2cudf) S 18819 18819 29493 34817 29493 4202496 395 3009 0 1 0 0 2 2 25 0 1 0 74914367 2641920 281 1283457024 134512640 135304128 4287242912 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18820/statm: 645 281 239 194 0 32 0
[pid=18833] ppid=18820 vsize=882140 CPUtime=3.06
/proc/18833/stat : 18833 (java) S 18820 18819 29493 34817 29493 4202496 74679 0 1 0 284 22 0 0 25 0 10 0 74914370 903311360 70676 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18833/statm: 220535 70676 1743 10 0 217626 0
[pid=18833/tid=18834] ppid=18820 vsize=882140 CPUtime=1.77
/proc/18833/task/18834/stat : 18834 (java) R 18820 18819 29493 34817 29493 4202560 50067 0 1 0 159 18 0 0 25 0 10 0 74914371 903311360 70676 1283457024 134512640 134550932 4292728432 18446744073709551615 4096015906 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18833/tid=18835] ppid=18820 vsize=882140 CPUtime=0.27
/proc/18833/task/18835/stat : 18835 (java) S 18820 18819 29493 34817 29493 4202560 12773 0 0 0 25 2 0 0 16 0 10 0 74914372 903311360 70676 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18836] ppid=18820 vsize=882140 CPUtime=0
/proc/18833/task/18836/stat : 18836 (java) S 18820 18819 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 10 0 74914373 903311360 70676 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18837] ppid=18820 vsize=882140 CPUtime=0
/proc/18833/task/18837/stat : 18837 (java) S 18820 18819 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 74914373 903311360 70676 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18838] ppid=18820 vsize=882140 CPUtime=0
/proc/18833/task/18838/stat : 18838 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74914375 903311360 70676 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18839] ppid=18820 vsize=882140 CPUtime=0.59
/proc/18833/task/18839/stat : 18839 (java) S 18820 18819 29493 34817 29493 4202560 8535 0 0 0 58 1 0 0 17 0 10 0 74914375 903311360 70676 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18840] ppid=18820 vsize=882140 CPUtime=0.41
/proc/18833/task/18840/stat : 18840 (java) S 18820 18819 29493 34817 29493 4202560 2228 0 0 0 41 0 0 0 15 0 10 0 74914375 903311360 70676 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18841] ppid=18820 vsize=882140 CPUtime=0
/proc/18833/task/18841/stat : 18841 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74914375 903311360 70676 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18842] ppid=18820 vsize=882140 CPUtime=0
/proc/18833/task/18842/stat : 18842 (java) S 18820 18819 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 74914375 903311360 70676 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 887288

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

[startup+3.30633 s]
/proc/loadavg: 1.00 1.04 1.00 3/48 18842
/proc/meminfo: memFree=449244/1048576 swapFree=0/0
[pid=18819] ppid=18818 vsize=2568 CPUtime=0
/proc/18819/stat : 18819 (p2cudf-paranoid) S 18818 18819 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 74914366 2629632 271 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18819/statm: 642 271 230 194 0 29 0
[pid=18820] ppid=18819 vsize=2580 CPUtime=0.04
/proc/18820/stat : 18820 (p2cudf) S 18819 18819 29493 34817 29493 4202496 395 3009 0 1 0 0 2 2 25 0 1 0 74914367 2641920 281 1283457024 134512640 135304128 4287242912 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18820/statm: 645 281 239 194 0 32 0
[pid=18833] ppid=18820 vsize=882140 CPUtime=3.26
/proc/18833/stat : 18833 (java) S 18820 18819 29493 34817 29493 4202496 74693 0 1 0 304 22 0 0 25 0 10 0 74914370 903311360 70690 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18833/statm: 220535 70690 1743 10 0 217626 0
[pid=18833/tid=18834] ppid=18820 vsize=882140 CPUtime=1.86
/proc/18833/task/18834/stat : 18834 (java) R 18820 18819 29493 34817 29493 4202560 50069 0 1 0 168 18 0 0 25 0 10 0 74914371 903311360 70690 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18833/tid=18835] ppid=18820 vsize=882140 CPUtime=0.27
/proc/18833/task/18835/stat : 18835 (java) S 18820 18819 29493 34817 29493 4202560 12773 0 0 0 25 2 0 0 16 0 10 0 74914372 903311360 70690 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18836] ppid=18820 vsize=882140 CPUtime=0
/proc/18833/task/18836/stat : 18836 (java) S 18820 18819 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 10 0 74914373 903311360 70690 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18837] ppid=18820 vsize=882140 CPUtime=0
/proc/18833/task/18837/stat : 18837 (java) S 18820 18819 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 74914373 903311360 70690 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18838] ppid=18820 vsize=882140 CPUtime=0
/proc/18833/task/18838/stat : 18838 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74914375 903311360 70690 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18839] ppid=18820 vsize=882140 CPUtime=0.7
/proc/18833/task/18839/stat : 18839 (java) R 18820 18819 29493 34817 29493 4202560 8547 0 0 0 69 1 0 0 16 0 10 0 74914375 903311360 70690 1283457024 134512640 134550932 4292728432 18446744073709551615 4152853141 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18833/tid=18840] ppid=18820 vsize=882140 CPUtime=0.41
/proc/18833/task/18840/stat : 18840 (java) S 18820 18819 29493 34817 29493 4202560 2228 0 0 0 41 0 0 0 15 0 10 0 74914375 903311360 70690 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18841] ppid=18820 vsize=882140 CPUtime=0
/proc/18833/task/18841/stat : 18841 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 74914375 903311360 70690 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18842] ppid=18820 vsize=882140 CPUtime=0
/proc/18833/task/18842/stat : 18842 (java) S 18820 18819 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 74914375 903311360 70690 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.3
Current children cumulated vsize (KiB) 887288

[startup+4.10591 s]
/proc/loadavg: 1.08 1.06 1.01 2/48 18842
/proc/meminfo: memFree=343224/1048576 swapFree=0/0
[pid=18819] ppid=18818 vsize=2568 CPUtime=0
/proc/18819/stat : 18819 (p2cudf-paranoid) S 18818 18819 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 74914366 2629632 271 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18819/statm: 642 271 230 194 0 29 0
[pid=18820] ppid=18819 vsize=2580 CPUtime=0.04
/proc/18820/stat : 18820 (p2cudf) S 18819 18819 29493 34817 29493 4202496 395 3009 0 1 0 0 2 2 25 0 1 0 74914367 2641920 281 1283457024 134512640 135304128 4287242912 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18820/statm: 645 281 239 194 0 32 0
[pid=18833] ppid=18820 vsize=882788 CPUtime=4.01
/proc/18833/stat : 18833 (java) S 18820 18819 29493 34817 29493 4202496 74966 0 1 0 376 25 0 0 25 0 12 0 74914370 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18833/statm: 220697 70963 1771 10 0 217788 0
[pid=18833/tid=18834] ppid=18820 vsize=882788 CPUtime=2.15
/proc/18833/task/18834/stat : 18834 (java) S 18820 18819 29493 34817 29493 4202560 50261 0 1 0 194 21 0 0 25 0 12 0 74914371 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18835] ppid=18820 vsize=882788 CPUtime=0.27
/proc/18833/task/18835/stat : 18835 (java) S 18820 18819 29493 34817 29493 4202560 12773 0 0 0 25 2 0 0 16 0 12 0 74914372 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18836] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18836/stat : 18836 (java) S 18820 18819 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 12 0 74914373 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18837] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18837/stat : 18837 (java) S 18820 18819 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 12 0 74914373 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18838] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18838/stat : 18838 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 12 0 74914375 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18839] ppid=18820 vsize=882788 CPUtime=1.15
/proc/18833/task/18839/stat : 18839 (java) S 18820 18819 29493 34817 29493 4202560 8620 0 0 0 114 1 0 0 16 0 12 0 74914375 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18840] ppid=18820 vsize=882788 CPUtime=0.41
/proc/18833/task/18840/stat : 18840 (java) S 18820 18819 29493 34817 29493 4202560 2228 0 0 0 41 0 0 0 15 0 12 0 74914375 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18841] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18841/stat : 18841 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 12 0 74914375 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18842] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18842/stat : 18842 (java) S 18820 18819 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 12 0 74914375 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.05
Current children cumulated vsize (KiB) 887936

[startup+4.5059 s]
/proc/loadavg: 1.08 1.06 1.01 1/50 18844
/proc/meminfo: memFree=342712/1048576 swapFree=0/0
[pid=18819] ppid=18818 vsize=2568 CPUtime=0
/proc/18819/stat : 18819 (p2cudf-paranoid) S 18818 18819 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 74914366 2629632 271 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18819/statm: 642 271 230 194 0 29 0
[pid=18820] ppid=18819 vsize=2580 CPUtime=0.04
/proc/18820/stat : 18820 (p2cudf) S 18819 18819 29493 34817 29493 4202496 395 3009 0 1 0 0 2 2 25 0 1 0 74914367 2641920 281 1283457024 134512640 135304128 4287242912 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18820/statm: 645 281 239 194 0 32 0
[pid=18833] ppid=18820 vsize=882788 CPUtime=4.01
/proc/18833/stat : 18833 (java) S 18820 18819 29493 34817 29493 4202496 74966 0 1 0 376 25 0 0 25 0 12 0 74914370 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18833/statm: 220697 70963 1771 10 0 217788 0
[pid=18833/tid=18834] ppid=18820 vsize=882788 CPUtime=2.15
/proc/18833/task/18834/stat : 18834 (java) S 18820 18819 29493 34817 29493 4202560 50261 0 1 0 194 21 0 0 25 0 12 0 74914371 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18835] ppid=18820 vsize=882788 CPUtime=0.27
/proc/18833/task/18835/stat : 18835 (java) S 18820 18819 29493 34817 29493 4202560 12773 0 0 0 25 2 0 0 16 0 12 0 74914372 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18836] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18836/stat : 18836 (java) S 18820 18819 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 12 0 74914373 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18837] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18837/stat : 18837 (java) S 18820 18819 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 12 0 74914373 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18838] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18838/stat : 18838 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 12 0 74914375 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18839] ppid=18820 vsize=882788 CPUtime=1.15
/proc/18833/task/18839/stat : 18839 (java) S 18820 18819 29493 34817 29493 4202560 8620 0 0 0 114 1 0 0 16 0 12 0 74914375 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18840] ppid=18820 vsize=882788 CPUtime=0.41
/proc/18833/task/18840/stat : 18840 (java) S 18820 18819 29493 34817 29493 4202560 2228 0 0 0 41 0 0 0 15 0 12 0 74914375 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18841] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18841/stat : 18841 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 12 0 74914375 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18842] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18842/stat : 18842 (java) S 18820 18819 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 12 0 74914375 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18843] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18843/stat : 18843 (java) S 18820 18819 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 24 0 12 0 74914728 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18844] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18844/stat : 18844 (java) S 18820 18819 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 12 0 74914773 903974912 70963 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.05
Current children cumulated vsize (KiB) 887936

[startup+4.60589 s]
/proc/loadavg: 1.08 1.06 1.01 1/50 18844
/proc/meminfo: memFree=342712/1048576 swapFree=0/0
[pid=18819] ppid=18818 vsize=2568 CPUtime=0
/proc/18819/stat : 18819 (p2cudf-paranoid) S 18818 18819 29493 34817 29493 4202496 375 0 0 0 0 0 0 0 25 0 1 0 74914366 2629632 271 1283457024 134512640 135304128 4291593904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18819/statm: 642 271 230 194 0 29 0
[pid=18820] ppid=18819 vsize=2580 CPUtime=0.04
/proc/18820/stat : 18820 (p2cudf) S 18819 18819 29493 34817 29493 4202496 395 3009 0 1 0 0 2 2 25 0 1 0 74914367 2641920 281 1283457024 134512640 135304128 4287242912 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18820/statm: 645 281 239 194 0 32 0
[pid=18833] ppid=18820 vsize=882788 CPUtime=4.03
/proc/18833/stat : 18833 (java) S 18820 18819 29493 34817 29493 4202496 74972 0 1 0 378 25 0 0 25 0 11 0 74914370 903974912 70969 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18833/statm: 220697 70969 1773 10 0 217788 0
[pid=18833/tid=18834] ppid=18820 vsize=882788 CPUtime=2.15
/proc/18833/task/18834/stat : 18834 (java) S 18820 18819 29493 34817 29493 4202560 50261 0 1 0 194 21 0 0 20 0 11 0 74914371 903974912 70969 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18835] ppid=18820 vsize=882788 CPUtime=0.27
/proc/18833/task/18835/stat : 18835 (java) S 18820 18819 29493 34817 29493 4202560 12773 0 0 0 25 2 0 0 16 0 11 0 74914372 903974912 70969 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 0 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18836] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18836/stat : 18836 (java) S 18820 18819 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 11 0 74914373 903974912 70969 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18837] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18837/stat : 18837 (java) S 18820 18819 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 74914373 903974912 70969 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18838] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18838/stat : 18838 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 74914375 903974912 70969 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18839] ppid=18820 vsize=882788 CPUtime=1.17
/proc/18833/task/18839/stat : 18839 (java) S 18820 18819 29493 34817 29493 4202560 8624 0 0 0 116 1 0 0 15 0 11 0 74914375 903974912 70969 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18840] ppid=18820 vsize=882788 CPUtime=0.41
/proc/18833/task/18840/stat : 18840 (java) S 18820 18819 29493 34817 29493 4202560 2228 0 0 0 41 0 0 0 15 0 11 0 74914375 903974912 70969 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18841] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18841/stat : 18841 (java) S 18820 18819 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 74914375 903974912 70969 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18842] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18842/stat : 18842 (java) S 18820 18819 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 11 0 74914375 903974912 70969 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
[pid=18833/tid=18843] ppid=18820 vsize=882788 CPUtime=0
/proc/18833/task/18843/stat : 18843 (java) S 18820 18819 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 24 0 11 0 74914728 903974912 70969 1283457024 134512640 134550932 4292728432 18446744073709551615 4294960130 0 4 0 16800975 18446612132910121920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.07
Current children cumulated vsize (KiB) 887936

Child status: 0
Real time (s): 4.64639
CPU time (s): 4.10826
CPU user time (s): 3.80024
CPU system time (s): 0.308019
CPU usage (%): 88.4182
Max. virtual memory (cumulated for all children) (KiB): 891464

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.80024
system time used= 0.308019
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 78775
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= 522
involuntary context switches= 496

runsolver used 0 second user time and 0 second system time

The end