runsolver Copyright (C) 2010 Olivier ROUSSEL This is runsolver version 3.2.9a (svn: 651) This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for more details. command line: runsolver -s SIGUSR1 -M 1124 -C 150 -d 10 -w /tmp/misc2012/2012-09-02-17:21/basic/p2cudf-basic-1.15/embedded/install/rand943.cudf.log.runsolver /home/competition/p2cudf-basic-1.15/p2cudf-basic-1.15 /home/competition/data/install/rand943.cudf /tmp/misc2012/2012-09-02-17:21/basic/p2cudf-basic-1.15/embedded/install/rand943.cudf.result -sum(solution,installedsize),-count(removed) Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 150 seconds Enforcing CPUTime limit (hard limit, will send SIGXCPU): 180 seconds Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB [startup+0 s] /proc/loadavg: 1.11 1.04 0.94 2/59 6497 /proc/meminfo: memFree=591268/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=3152 CPUtime=0 /proc/6497/stat : 6497 (runsolver) R 6496 1750 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 115977310 3227648 32 18446744073709551615 134512640 134586868 4293426928 4293424976 4151968816 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.165719 s] /proc/loadavg: 1.11 1.04 0.94 2/59 6497 /proc/meminfo: memFree=591268/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 9168 [startup+0.200328 s] /proc/loadavg: 1.11 1.04 0.94 2/59 6497 /proc/meminfo: memFree=591268/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 9168 [startup+0.300322 s] /proc/loadavg: 1.11 1.04 0.94 2/59 6497 /proc/meminfo: memFree=591268/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 9168 [startup+0.700243 s] /proc/loadavg: 1.11 1.04 0.94 2/59 6497 /proc/meminfo: memFree=591268/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 9168 [startup+1.50078 s] /proc/loadavg: 1.11 1.04 0.94 4/70 6509 /proc/meminfo: memFree=541696/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 [pid=6500] ppid=6497 vsize=1045656 CPUtime=1.47 /proc/6500/stat : 6500 (java) S 6497 6497 1750 0 -1 4202496 33625 0 0 0 132 15 0 0 20 0 10 0 115977311 1070751744 29924 18446744073709551615 4194304 4228012 140737446272496 140737446263520 139711607017077 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/6500/statm: 261414 29924 2346 9 0 248764 0 [pid=6500/tid=6501] ppid=6497 vsize=1045656 CPUtime=0.69 /proc/6500/task/6501/stat : 6501 (java) R 6497 6497 1750 0 -1 4202560 14392 0 0 0 62 7 0 0 20 0 10 0 115977312 1070751744 29924 18446744073709551615 4194304 4228012 140737446272496 139711613543072 139711511459792 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0 [pid=6500/tid=6502] ppid=6497 vsize=1045656 CPUtime=0 /proc/6500/task/6502/stat : 6502 (java) S 6497 6497 1750 0 -1 4202560 3 0 0 0 0 0 0 0 20 0 10 0 115977314 1070751744 29924 18446744073709551615 4194304 4228012 140737446272496 139711506189440 139711607031371 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6503] ppid=6497 vsize=1045656 CPUtime=0 /proc/6500/task/6503/stat : 6503 (java) S 6497 6497 1750 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115977315 1070751744 29924 18446744073709551615 4194304 4228012 140737446272496 139711505135632 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6504] ppid=6497 vsize=1045656 CPUtime=0 /proc/6500/task/6504/stat : 6504 (java) S 6497 6497 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 115977315 1070751744 29924 18446744073709551615 4194304 4228012 140737446272496 139711504082848 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6505] ppid=6497 vsize=1045656 CPUtime=0 /proc/6500/task/6505/stat : 6505 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115977319 1070751744 29924 18446744073709551615 4194304 4228012 140737446272496 139711503031280 139711607039008 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6506] ppid=6497 vsize=1045656 CPUtime=0.37 /proc/6500/task/6506/stat : 6506 (java) R 6497 6497 1750 0 -1 4202560 9782 0 0 0 34 3 0 0 20 0 10 0 115977319 1070751744 29924 18446744073709551615 4194304 4228012 140737446272496 139711501963912 139711599594911 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6507] ppid=6497 vsize=1045656 CPUtime=0.38 /proc/6500/task/6507/stat : 6507 (java) R 6497 6497 1750 0 -1 4202560 8159 0 0 0 34 4 0 0 20 0 10 0 115977319 1070751744 29924 18446744073709551615 4194304 4228012 140737446272496 139711500913816 139711592862104 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6508] ppid=6497 vsize=1045656 CPUtime=0 /proc/6500/task/6508/stat : 6508 (java) S 6497 6497 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115977319 1070751744 29924 18446744073709551615 4194304 4228012 140737446272496 139711499873488 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6509] ppid=6497 vsize=1045656 CPUtime=0 /proc/6500/task/6509/stat : 6509 (java) S 6497 6497 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115977319 1070751744 29924 18446744073709551615 4194304 4228012 140737446272496 139711498820992 139711607031371 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.47 Current children cumulated vsize (KiB) 1054824 [startup+3.10082 s] /proc/loadavg: 1.11 1.04 0.94 4/70 6509 /proc/meminfo: memFree=443116/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 [pid=6500] ppid=6497 vsize=1045368 CPUtime=3.03 /proc/6500/stat : 6500 (java) S 6497 6497 1750 0 -1 4202496 76096 0 0 0 273 30 0 0 20 0 10 0 115977311 1070456832 71406 18446744073709551615 4194304 4228012 140737446272496 140737446263520 139711607017077 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/6500/statm: 261342 71406 2366 9 0 248692 0 [pid=6500/tid=6501] ppid=6497 vsize=1045368 CPUtime=1.52 /proc/6500/task/6501/stat : 6501 (java) R 6497 6497 1750 0 -1 4202560 47426 0 0 0 134 18 0 0 20 0 10 0 115977312 1070456832 71406 18446744073709551615 4194304 4228012 140737446272496 139711613543104 139711511354806 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0 [pid=6500/tid=6502] ppid=6497 vsize=1045368 CPUtime=0.17 /proc/6500/task/6502/stat : 6502 (java) S 6497 6497 1750 0 -1 4202560 7949 0 0 0 14 3 0 0 20 0 10 0 115977314 1070456832 71406 18446744073709551615 4194304 4228012 140737446272496 139711506189440 139711607031371 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6503] ppid=6497 vsize=1045368 CPUtime=0 /proc/6500/task/6503/stat : 6503 (java) S 6497 6497 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 115977315 1070456832 71406 18446744073709551615 4194304 4228012 140737446272496 139711505135632 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6504] ppid=6497 vsize=1045368 CPUtime=0 /proc/6500/task/6504/stat : 6504 (java) S 6497 6497 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 115977315 1070456832 71406 18446744073709551615 4194304 4228012 140737446272496 139711504082848 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6505] ppid=6497 vsize=1045368 CPUtime=0 /proc/6500/task/6505/stat : 6505 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115977319 1070456832 71406 18446744073709551615 4194304 4228012 140737446272496 139711503031280 139711607039008 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6506] ppid=6497 vsize=1045368 CPUtime=0.64 /proc/6500/task/6506/stat : 6506 (java) S 6497 6497 1750 0 -1 4202560 10585 0 0 0 60 4 0 0 20 0 10 0 115977319 1070456832 71406 18446744073709551615 4194304 4228012 140737446272496 139711501978640 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6507] ppid=6497 vsize=1045368 CPUtime=0.68 /proc/6500/task/6507/stat : 6507 (java) S 6497 6497 1750 0 -1 4202560 8843 0 0 0 64 4 0 0 20 0 10 0 115977319 1070456832 71406 18446744073709551615 4194304 4228012 140737446272496 139711500925968 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6508] ppid=6497 vsize=1045368 CPUtime=0 /proc/6500/task/6508/stat : 6508 (java) S 6497 6497 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115977319 1070456832 71406 18446744073709551615 4194304 4228012 140737446272496 139711499873488 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6509] ppid=6497 vsize=1045368 CPUtime=0 /proc/6500/task/6509/stat : 6509 (java) S 6497 6497 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115977319 1070456832 71406 18446744073709551615 4194304 4228012 140737446272496 139711498820992 139711607031371 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.03 Current children cumulated vsize (KiB) 1054536 [startup+6.30079 s] /proc/loadavg: 1.10 1.03 0.94 2/70 6509 /proc/meminfo: memFree=151468/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 [pid=6500] ppid=6497 vsize=1045368 CPUtime=5.83 /proc/6500/stat : 6500 (java) S 6497 6497 1750 0 -1 4202496 121422 0 0 0 539 44 0 0 20 0 10 0 115977311 1070456832 115154 18446744073709551615 4194304 4228012 140737446272496 140737446263520 139711607017077 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/6500/statm: 261342 115154 2368 9 0 248692 0 [pid=6500/tid=6501] ppid=6497 vsize=1045368 CPUtime=3.19 /proc/6500/task/6501/stat : 6501 (java) R 6497 6497 1750 0 -1 4202560 47428 0 0 0 299 20 0 0 20 0 10 0 115977312 1070456832 115154 18446744073709551615 4194304 4228012 140737446272496 139711613543104 139711511407124 0 4 0 16800975 0 0 0 -1 0 0 0 38 0 0 [pid=6500/tid=6502] ppid=6497 vsize=1045368 CPUtime=1.22 /proc/6500/task/6502/stat : 6502 (java) S 6497 6497 1750 0 -1 4202560 53236 0 0 0 108 14 0 0 20 0 10 0 115977314 1070456832 115154 18446744073709551615 4194304 4228012 140737446272496 139711506189440 139711607031371 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6503] ppid=6497 vsize=1045368 CPUtime=0 /proc/6500/task/6503/stat : 6503 (java) S 6497 6497 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 115977315 1070456832 115154 18446744073709551615 4194304 4228012 140737446272496 139711505135632 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6504] ppid=6497 vsize=1045368 CPUtime=0 /proc/6500/task/6504/stat : 6504 (java) S 6497 6497 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 115977315 1070456832 115154 18446744073709551615 4194304 4228012 140737446272496 139711504082848 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6505] ppid=6497 vsize=1045368 CPUtime=0 /proc/6500/task/6505/stat : 6505 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115977319 1070456832 115154 18446744073709551615 4194304 4228012 140737446272496 139711503031280 139711607039008 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6506] ppid=6497 vsize=1045368 CPUtime=0.68 /proc/6500/task/6506/stat : 6506 (java) S 6497 6497 1750 0 -1 4202560 10621 0 0 0 64 4 0 0 20 0 10 0 115977319 1070456832 115154 18446744073709551615 4194304 4228012 140737446272496 139711501978640 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6507] ppid=6497 vsize=1045368 CPUtime=0.71 /proc/6500/task/6507/stat : 6507 (java) S 6497 6497 1750 0 -1 4202560 8843 0 0 0 67 4 0 0 20 0 10 0 115977319 1070456832 115154 18446744073709551615 4194304 4228012 140737446272496 139711500925968 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6508] ppid=6497 vsize=1045368 CPUtime=0 /proc/6500/task/6508/stat : 6508 (java) S 6497 6497 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115977319 1070456832 115154 18446744073709551615 4194304 4228012 140737446272496 139711499873488 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6509] ppid=6497 vsize=1045368 CPUtime=0 /proc/6500/task/6509/stat : 6509 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115977319 1070456832 115154 18446744073709551615 4194304 4228012 140737446272496 139711498820992 139711607031371 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 5.83 Current children cumulated vsize (KiB) 1054536 [startup+12.7008 s] /proc/loadavg: 1.25 1.07 0.95 4/71 6510 /proc/meminfo: memFree=9940/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 [pid=6500] ppid=6497 vsize=1046396 CPUtime=12.05 /proc/6500/stat : 6500 (java) S 6497 6497 1750 0 -1 4202496 152896 0 0 0 1146 59 0 0 20 0 11 0 115977311 1071509504 146628 18446744073709551615 4194304 4228012 140737446272496 140737446263520 139711607017077 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/6500/statm: 261599 146628 2379 9 0 248949 0 [pid=6500/tid=6501] ppid=6497 vsize=1046396 CPUtime=6.11 /proc/6500/task/6501/stat : 6501 (java) R 6497 6497 1750 0 -1 4202560 47799 0 0 0 588 23 0 0 20 0 11 0 115977312 1071509504 146628 18446744073709551615 4194304 4228012 140737446272496 139711613550584 139711511798176 0 4 0 16800975 0 0 0 -1 0 0 0 40 0 0 [pid=6500/tid=6502] ppid=6497 vsize=1046396 CPUtime=2.09 /proc/6500/task/6502/stat : 6502 (java) S 6497 6497 1750 0 -1 4202560 83884 0 0 0 183 26 0 0 20 0 11 0 115977314 1071509504 146628 18446744073709551615 4194304 4228012 140737446272496 139711506189440 139711607031371 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6503] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6503/stat : 6503 (java) S 6497 6497 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 115977315 1071509504 146628 18446744073709551615 4194304 4228012 140737446272496 139711505135632 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6504] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6504/stat : 6504 (java) S 6497 6497 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115977315 1071509504 146628 18446744073709551615 4194304 4228012 140737446272496 139711504082848 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6505] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6505/stat : 6505 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115977319 1071509504 146628 18446744073709551615 4194304 4228012 140737446272496 139711503031280 139711607039008 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6506] ppid=6497 vsize=1046396 CPUtime=1.92 /proc/6500/task/6506/stat : 6506 (java) S 6497 6497 1750 0 -1 4202560 10747 0 0 0 188 4 0 0 20 0 11 0 115977319 1071509504 146628 18446744073709551615 4194304 4228012 140737446272496 139711501978640 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6507] ppid=6497 vsize=1046396 CPUtime=1.9 /proc/6500/task/6507/stat : 6507 (java) S 6497 6497 1750 0 -1 4202560 9166 0 0 0 186 4 0 0 20 0 11 0 115977319 1071509504 146628 18446744073709551615 4194304 4228012 140737446272496 139711500925968 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6508] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6508/stat : 6508 (java) S 6497 6497 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115977319 1071509504 146628 18446744073709551615 4194304 4228012 140737446272496 139711499873488 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6509] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6509/stat : 6509 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115977319 1071509504 146628 18446744073709551615 4194304 4228012 140737446272496 139711498820992 139711607031371 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6510] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6510/stat : 6510 (java) S 6497 6497 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 115978484 1071509504 146628 18446744073709551615 4194304 4228012 140737446272496 139711497623392 139711607031371 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 12.05 Current children cumulated vsize (KiB) 1055564 Solver just ended. Dumping a history of the last processes samples [startup+12.8011 s] /proc/loadavg: 1.25 1.07 0.95 4/71 6510 /proc/meminfo: memFree=9940/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 [pid=6500] ppid=6497 vsize=1046396 CPUtime=12.15 /proc/6500/stat : 6500 (java) S 6497 6497 1750 0 -1 4202496 152902 0 0 0 1156 59 0 0 20 0 11 0 115977311 1071509504 146634 18446744073709551615 4194304 4228012 140737446272496 140737446263520 139711607017077 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/6500/statm: 261599 146634 2379 9 0 248949 0 [pid=6500/tid=6501] ppid=6497 vsize=1046396 CPUtime=6.15 /proc/6500/task/6501/stat : 6501 (java) R 6497 6497 1750 0 -1 4202560 47805 0 0 0 592 23 0 0 20 0 11 0 115977312 1071509504 146634 18446744073709551615 4194304 4228012 140737446272496 139711613542304 139711512266985 0 4 0 16800975 0 0 0 -1 0 0 0 40 0 0 [pid=6500/tid=6502] ppid=6497 vsize=1046396 CPUtime=2.09 /proc/6500/task/6502/stat : 6502 (java) S 6497 6497 1750 0 -1 4202560 83884 0 0 0 183 26 0 0 20 0 11 0 115977314 1071509504 146634 18446744073709551615 4194304 4228012 140737446272496 139711506189440 139711607031371 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6503] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6503/stat : 6503 (java) S 6497 6497 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 115977315 1071509504 146634 18446744073709551615 4194304 4228012 140737446272496 139711505135632 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6504] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6504/stat : 6504 (java) S 6497 6497 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115977315 1071509504 146634 18446744073709551615 4194304 4228012 140737446272496 139711504082848 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6505] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6505/stat : 6505 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115977319 1071509504 146634 18446744073709551615 4194304 4228012 140737446272496 139711503031280 139711607039008 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6506] ppid=6497 vsize=1046396 CPUtime=1.94 /proc/6500/task/6506/stat : 6506 (java) R 6497 6497 1750 0 -1 4202560 10747 0 0 0 190 4 0 0 20 0 11 0 115977319 1071509504 146634 18446744073709551615 4194304 4228012 140737446272496 139711501978384 139711589862640 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6507] ppid=6497 vsize=1046396 CPUtime=1.93 /proc/6500/task/6507/stat : 6507 (java) R 6497 6497 1750 0 -1 4202560 9166 0 0 0 189 4 0 0 20 0 11 0 115977319 1071509504 146634 18446744073709551615 4194304 4228012 140737446272496 139711500925712 139711591320227 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6508] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6508/stat : 6508 (java) S 6497 6497 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115977319 1071509504 146634 18446744073709551615 4194304 4228012 140737446272496 139711499873488 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6509] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6509/stat : 6509 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115977319 1071509504 146634 18446744073709551615 4194304 4228012 140737446272496 139711498820992 139711607031371 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6510] ppid=6497 vsize=1046396 CPUtime=0 /proc/6500/task/6510/stat : 6510 (java) S 6497 6497 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 115978484 1071509504 146634 18446744073709551615 4194304 4228012 140737446272496 139711497623392 139711607031371 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 12.15 Current children cumulated vsize (KiB) 1055564 [startup+13.6009 s] /proc/loadavg: 1.25 1.07 0.95 2/71 6510 /proc/meminfo: memFree=9816/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 [pid=6500] ppid=6497 vsize=1047424 CPUtime=12.76 /proc/6500/stat : 6500 (java) S 6497 6497 1750 0 -1 4202496 152941 0 0 0 1217 59 0 0 20 0 11 0 115977311 1072562176 146671 18446744073709551615 4194304 4228012 140737446272496 140737446263520 139711607017077 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/6500/statm: 261856 146671 2381 9 0 249206 0 [pid=6500/tid=6501] ppid=6497 vsize=1047424 CPUtime=6.52 /proc/6500/task/6501/stat : 6501 (java) S 6497 6497 1750 0 -1 4202560 47815 0 0 0 629 23 0 0 20 0 11 0 115977312 1072562176 146671 18446744073709551615 4194304 4228012 140737446272496 139711613551536 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 40 0 0 [pid=6500/tid=6502] ppid=6497 vsize=1047424 CPUtime=2.09 /proc/6500/task/6502/stat : 6502 (java) S 6497 6497 1750 0 -1 4202560 83884 0 0 0 183 26 0 0 20 0 11 0 115977314 1072562176 146671 18446744073709551615 4194304 4228012 140737446272496 139711506189440 139711607031371 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6503] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6503/stat : 6503 (java) S 6497 6497 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 115977315 1072562176 146671 18446744073709551615 4194304 4228012 140737446272496 139711505135632 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6504] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6504/stat : 6504 (java) S 6497 6497 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115977315 1072562176 146671 18446744073709551615 4194304 4228012 140737446272496 139711504082848 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6505] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6505/stat : 6505 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115977319 1072562176 146671 18446744073709551615 4194304 4228012 140737446272496 139711503031280 139711607039008 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6506] ppid=6497 vsize=1047424 CPUtime=2.06 /proc/6500/task/6506/stat : 6506 (java) S 6497 6497 1750 0 -1 4202560 10754 0 0 0 202 4 0 0 20 0 11 0 115977319 1072562176 146671 18446744073709551615 4194304 4228012 140737446272496 139711501978640 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6507] ppid=6497 vsize=1047424 CPUtime=2.04 /proc/6500/task/6507/stat : 6507 (java) S 6497 6497 1750 0 -1 4202560 9182 0 0 0 200 4 0 0 20 0 11 0 115977319 1072562176 146671 18446744073709551615 4194304 4228012 140737446272496 139711500925968 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6508] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6508/stat : 6508 (java) S 6497 6497 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115977319 1072562176 146671 18446744073709551615 4194304 4228012 140737446272496 139711499873488 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6509] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6509/stat : 6509 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115977319 1072562176 146671 18446744073709551615 4194304 4228012 140737446272496 139711498820992 139711607031371 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 12.76 Current children cumulated vsize (KiB) 1056592 [startup+14.0008 s] /proc/loadavg: 1.25 1.07 0.95 2/71 6510 /proc/meminfo: memFree=9816/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 [pid=6500] ppid=6497 vsize=1047424 CPUtime=12.84 /proc/6500/stat : 6500 (java) S 6497 6497 1750 0 -1 4202496 152944 0 0 0 1224 60 0 0 20 0 11 0 115977311 1072562176 146674 18446744073709551615 4194304 4228012 140737446272496 140737446263520 139711607017077 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/6500/statm: 261856 146674 2381 9 0 249206 0 [pid=6500/tid=6501] ppid=6497 vsize=1047424 CPUtime=6.52 /proc/6500/task/6501/stat : 6501 (java) S 6497 6497 1750 0 -1 4202560 47815 0 0 0 629 23 0 0 20 0 11 0 115977312 1072562176 146674 18446744073709551615 4194304 4228012 140737446272496 139711613551536 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 40 0 0 [pid=6500/tid=6502] ppid=6497 vsize=1047424 CPUtime=2.09 /proc/6500/task/6502/stat : 6502 (java) S 6497 6497 1750 0 -1 4202560 83884 0 0 0 183 26 0 0 20 0 11 0 115977314 1072562176 146674 18446744073709551615 4194304 4228012 140737446272496 139711506189440 139711607031371 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6503] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6503/stat : 6503 (java) S 6497 6497 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 115977315 1072562176 146674 18446744073709551615 4194304 4228012 140737446272496 139711505135632 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6504] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6504/stat : 6504 (java) S 6497 6497 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115977315 1072562176 146674 18446744073709551615 4194304 4228012 140737446272496 139711504082848 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6505] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6505/stat : 6505 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115977319 1072562176 146674 18446744073709551615 4194304 4228012 140737446272496 139711503031280 139711607039008 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6506] ppid=6497 vsize=1047424 CPUtime=2.06 /proc/6500/task/6506/stat : 6506 (java) S 6497 6497 1750 0 -1 4202560 10754 0 0 0 202 4 0 0 20 0 11 0 115977319 1072562176 146674 18446744073709551615 4194304 4228012 140737446272496 139711501978640 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6507] ppid=6497 vsize=1047424 CPUtime=2.07 /proc/6500/task/6507/stat : 6507 (java) S 6497 6497 1750 0 -1 4202560 9183 0 0 0 203 4 0 0 20 0 11 0 115977319 1072562176 146674 18446744073709551615 4194304 4228012 140737446272496 139711500925968 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6508] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6508/stat : 6508 (java) S 6497 6497 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115977319 1072562176 146674 18446744073709551615 4194304 4228012 140737446272496 139711499873488 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6509] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6509/stat : 6509 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115977319 1072562176 146674 18446744073709551615 4194304 4228012 140737446272496 139711498820992 139711607031371 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 12.84 Current children cumulated vsize (KiB) 1056592 [startup+14.1008 s] /proc/loadavg: 1.25 1.07 0.95 2/71 6510 /proc/meminfo: memFree=9816/1022884 swapFree=0/0 [pid=6497] ppid=6496 vsize=9168 CPUtime=0 /proc/6497/stat : 6497 (p2cudf-basic-1.) S 6496 6497 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 115977310 9388032 330 18446744073709551615 4194304 5129932 140735004199984 140735004198128 140732395283550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0 /proc/6497/statm: 2292 330 280 229 0 52 0 [pid=6500] ppid=6497 vsize=1047424 CPUtime=12.94 /proc/6500/stat : 6500 (java) S 6497 6497 1750 0 -1 4202496 152945 0 0 0 1233 61 0 0 20 0 11 0 115977311 1072562176 146675 18446744073709551615 4194304 4228012 140737446272496 140737446263520 139711607017077 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0 /proc/6500/statm: 261856 146675 2381 9 0 249206 0 [pid=6500/tid=6501] ppid=6497 vsize=1047424 CPUtime=6.52 /proc/6500/task/6501/stat : 6501 (java) S 6497 6497 1750 0 -1 4202560 47815 0 0 0 629 23 0 0 20 0 11 0 115977312 1072562176 146675 18446744073709551615 4194304 4228012 140737446272496 139711613551536 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 40 0 0 [pid=6500/tid=6502] ppid=6497 vsize=1047424 CPUtime=2.09 /proc/6500/task/6502/stat : 6502 (java) S 6497 6497 1750 0 -1 4202560 83884 0 0 0 183 26 0 0 20 0 11 0 115977314 1072562176 146675 18446744073709551615 4194304 4228012 140737446272496 139711506189440 139711607031371 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6503] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6503/stat : 6503 (java) S 6497 6497 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 115977315 1072562176 146675 18446744073709551615 4194304 4228012 140737446272496 139711505135632 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6504] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6504/stat : 6504 (java) S 6497 6497 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115977315 1072562176 146675 18446744073709551615 4194304 4228012 140737446272496 139711504082848 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6505] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6505/stat : 6505 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115977319 1072562176 146675 18446744073709551615 4194304 4228012 140737446272496 139711503031280 139711607039008 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6506] ppid=6497 vsize=1047424 CPUtime=2.08 /proc/6500/task/6506/stat : 6506 (java) S 6497 6497 1750 0 -1 4202560 10754 0 0 0 204 4 0 0 20 0 11 0 115977319 1072562176 146675 18446744073709551615 4194304 4228012 140737446272496 139711501978640 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6507] ppid=6497 vsize=1047424 CPUtime=2.08 /proc/6500/task/6507/stat : 6507 (java) S 6497 6497 1750 0 -1 4202560 9183 0 0 0 204 4 0 0 20 0 11 0 115977319 1072562176 146675 18446744073709551615 4194304 4228012 140737446272496 139711500925968 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6508] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6508/stat : 6508 (java) S 6497 6497 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115977319 1072562176 146675 18446744073709551615 4194304 4228012 140737446272496 139711499873488 139711607030484 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 [pid=6500/tid=6509] ppid=6497 vsize=1047424 CPUtime=0 /proc/6500/task/6509/stat : 6509 (java) S 6497 6497 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115977319 1072562176 146675 18446744073709551615 4194304 4228012 140737446272496 139711498820992 139711607031371 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0 Current children cumulated CPU time (s) 12.94 Current children cumulated vsize (KiB) 1056592 Child status: 0 Real time (s): 14.1998 CPU time (s): 13.0528 CPU user time (s): 12.3768 CPU system time (s): 0.676042 CPU usage (%): 91.9227 Max. virtual memory (cumulated for all children) (KiB): 1057864 getrusage(RUSAGE_CHILDREN,...) data: user time used= 12.3768 system time used= 0.676042 maximum resident set size= 586748 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 153717 page faults= 1 swaps= 0 block input operations= 68512 block output operations= 224 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 1150 involuntary context switches= 3451 runsolver used 0.032002 second user time and 0.128008 second system time The end