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/201108311143/aspuncud-user-1.0/rand763.cudf.user-upgrades.log.runsolver ./aspuncud-user-1.0 /home/misc2010/data/2011/user-upgrades/rand763.cudf /home/misc2010/tmp/201108311143/aspuncud-user-1.0/rand763.cudf.user-upgrades.result -sum(installedsize) Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 seconds Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB Current StackSize limit: 8192 KiB [startup+0 s] /proc/loadavg: 1.10 1.04 1.01 5/36 28681 /proc/meminfo: memFree=505884/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2588 CPUtime=0 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 373 0 0 0 0 0 0 0 18 0 1 0 65036351 2650112 279 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/28678/statm: 647 279 234 194 0 34 0 [pid=28679] ppid=28678 vsize=2588 CPUtime=0 /proc/28679/stat : 28679 (aspuncud-user-1) S 28678 28678 19908 34817 19908 4202560 119 0 0 0 0 0 0 0 18 0 1 0 65036351 2650112 133 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0 /proc/28679/statm: 647 133 87 194 0 34 0 [pid=28680] ppid=28679 vsize=2588 CPUtime=0 /proc/28680/stat : 28680 (aspuncud-user-1) R 28679 28678 19908 34817 19908 4202560 127 0 0 0 0 0 0 0 25 0 1 0 65036351 2650112 150 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/28680/statm: 647 150 104 194 0 34 0 [pid=28681] ppid=28680 vsize=2588 CPUtime=0 /proc/28681/stat : 28681 (aspuncud-user-1) R 28680 28678 19908 34817 19908 4202560 0 0 0 0 0 0 0 0 25 0 1 0 65036351 2650112 46 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/28681/statm: 647 46 0 194 0 34 0 [startup+0.174864 s] /proc/loadavg: 1.10 1.04 1.01 5/36 28681 /proc/meminfo: memFree=505884/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=0 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 574 1521 0 0 0 0 0 0 25 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+0.204876 s] /proc/loadavg: 1.10 1.04 1.01 5/36 28681 /proc/meminfo: memFree=505884/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=0 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 574 1521 0 0 0 0 0 0 25 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+0.304912 s] /proc/loadavg: 1.10 1.04 1.01 5/36 28681 /proc/meminfo: memFree=505884/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=0 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 574 1521 0 0 0 0 0 0 25 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+0.704999 s] /proc/loadavg: 1.10 1.04 1.01 5/36 28681 /proc/meminfo: memFree=505884/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=0 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 574 1521 0 0 0 0 0 0 25 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+1.50522 s] /proc/loadavg: 1.10 1.04 1.01 2/37 28689 /proc/meminfo: memFree=488884/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=0 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 574 1521 0 0 0 0 0 0 25 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 [pid=28687] ppid=28678 vsize=3448 CPUtime=0 /proc/28687/stat : 28687 (unclasp) S 28678 28678 19908 34817 19908 4202496 407 0 0 0 0 0 0 0 25 0 1 0 65036352 3530752 272 1283457024 134512640 135121179 4288660592 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/28687/statm: 862 272 240 149 0 53 0 [pid=28688] ppid=28678 vsize=2692 CPUtime=0 /proc/28688/stat : 28688 (gringo) S 28678 28678 19908 34817 19908 4202496 408 0 0 0 0 0 0 0 25 0 1 0 65036352 2756608 281 1283457024 134512640 137056543 4294885872 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/28688/statm: 673 281 252 622 0 48 0 [pid=28689] ppid=28678 vsize=28116 CPUtime=1.49 /proc/28689/stat : 28689 (cudf2lp) R 28678 28678 19908 34817 19908 4202496 8042 0 0 0 148 1 0 0 25 0 1 0 65036352 28790784 6303 1283457024 134512640 135786343 4291028656 18446744073709551615 134614188 0 0 6 0 0 0 0 17 0 0 0 0 /proc/28689/statm: 7029 6303 128 311 0 6716 0 Current children cumulated CPU time (s) 1.49 Current children cumulated vsize (KiB) 36848 [startup+3.10564 s] /proc/loadavg: 1.10 1.04 1.01 2/37 28689 /proc/meminfo: memFree=463588/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=2.52 /proc/28678/stat : 28678 (aspuncud-user-1) R 28677 28678 19908 34817 19908 4202496 575 15491 0 0 0 0 244 8 19 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 0 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 [pid=28687] ppid=28678 vsize=7184 CPUtime=0.48 /proc/28687/stat : 28687 (unclasp) R 28678 28678 19908 34817 19908 4202496 1534 0 0 0 47 1 0 0 18 0 1 0 65036352 7356416 1265 1283457024 134512640 135121179 4288660592 18446744073709551615 134990522 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/28687/statm: 1796 1265 323 149 0 987 0 [pid=28688] ppid=28678 vsize=0 CPUtime=0.07 /proc/28688/stat : 28688 (gringo) Z 28678 28678 19908 34817 19908 4202508 1076 0 0 0 6 1 0 0 18 0 1 0 65036352 0 0 1283457024 0 0 0 0 0 0 0 6 16384 18446744071564254338 0 0 17 0 0 0 0 /proc/28688/statm: 0 0 0 0 0 0 0 Current children cumulated CPU time (s) 3.07 Current children cumulated vsize (KiB) 9776 [startup+6.30659 s] /proc/loadavg: 1.10 1.04 1.01 2/35 28689 /proc/meminfo: memFree=488420/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=2.6 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 575 16567 0 0 0 0 250 10 17 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 [pid=28687] ppid=28678 vsize=24664 CPUtime=3.68 /proc/28687/stat : 28687 (unclasp) R 28678 28678 19908 34817 19908 4202496 6168 0 0 0 364 4 0 0 25 0 1 0 65036352 25255936 5600 1283457024 134512640 135121179 4288660592 18446744073709551615 134839113 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/28687/statm: 6166 5600 323 149 0 5357 0 Current children cumulated CPU time (s) 6.28 Current children cumulated vsize (KiB) 27256 [startup+12.709 s] /proc/loadavg: 1.09 1.04 1.01 2/35 28689 /proc/meminfo: memFree=460032/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=2.6 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 575 16567 0 0 0 0 250 10 17 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 [pid=28687] ppid=28678 vsize=52124 CPUtime=10.08 /proc/28687/stat : 28687 (unclasp) R 28678 28678 19908 34817 19908 4202496 13258 0 0 0 1000 8 0 0 25 0 1 0 65036352 53374976 12421 1283457024 134512640 135121179 4288660592 18446744073709551615 134885275 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/28687/statm: 13031 12421 323 149 0 12222 0 Current children cumulated CPU time (s) 12.68 Current children cumulated vsize (KiB) 54716 [startup+25.5037 s] /proc/loadavg: 1.07 1.03 1.01 2/35 28689 /proc/meminfo: memFree=424320/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=2.6 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 575 16567 0 0 0 0 250 10 17 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 [pid=28687] ppid=28678 vsize=85688 CPUtime=22.87 /proc/28687/stat : 28687 (unclasp) R 28678 28678 19908 34817 19908 4202496 22331 0 0 0 2276 11 0 0 25 0 1 0 65036352 87744512 20722 1283457024 134512640 135121179 4288660592 18446744073709551615 134891771 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/28687/statm: 21422 20722 323 149 0 20613 0 Current children cumulated CPU time (s) 25.47 Current children cumulated vsize (KiB) 88280 [startup+51.1125 s] /proc/loadavg: 1.04 1.03 1.00 2/37 28692 /proc/meminfo: memFree=338736/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=2.6 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 575 16567 0 0 0 0 250 10 17 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 [pid=28687] ppid=28678 vsize=171200 CPUtime=48.46 /proc/28687/stat : 28687 (unclasp) R 28678 28678 19908 34817 19908 4202496 47964 0 0 0 4824 22 0 0 25 0 1 0 65036352 175308800 42223 1283457024 134512640 135121179 4288660592 18446744073709551615 134891771 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/28687/statm: 42800 42223 323 149 0 41991 0 Current children cumulated CPU time (s) 51.06 Current children cumulated vsize (KiB) 173792 [startup+102.308 s] /proc/loadavg: 1.02 1.02 1.00 2/37 28697 /proc/meminfo: memFree=206428/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=2.6 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 575 16567 0 0 0 0 250 10 17 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 [pid=28687] ppid=28678 vsize=303132 CPUtime=99.63 /proc/28687/stat : 28687 (unclasp) R 28678 28678 19908 34817 19908 4202496 100969 0 0 0 9925 38 0 0 25 0 1 0 65036352 310407168 74952 1283457024 134512640 135121179 4288660592 18446744073709551615 134873589 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/28687/statm: 75783 74952 323 149 0 74974 0 Current children cumulated CPU time (s) 102.23 Current children cumulated vsize (KiB) 305724 [startup+162.309 s] /proc/loadavg: 1.00 1.02 1.00 2/36 28700 /proc/meminfo: memFree=38176/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=2.6 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 575 16567 0 0 0 0 250 10 17 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 [pid=28687] ppid=28678 vsize=472144 CPUtime=159.59 /proc/28687/stat : 28687 (unclasp) R 28678 28678 19908 34817 19908 4202496 188691 0 0 0 15896 63 0 0 25 0 1 0 65036352 483475456 117227 1283457024 134512640 135121179 4288660592 18446744073709551615 134917895 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/28687/statm: 118036 117227 323 149 0 117227 0 Current children cumulated CPU time (s) 162.19 Current children cumulated vsize (KiB) 474736 [startup+222.308 s] /proc/loadavg: 1.00 1.01 1.00 2/35 28700 /proc/meminfo: memFree=5924/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=2.6 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 575 16567 0 0 0 0 250 10 17 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 [pid=28687] ppid=28678 vsize=605044 CPUtime=219.55 /proc/28687/stat : 28687 (unclasp) R 28678 28678 19908 34817 19908 4202496 279305 0 0 0 21862 93 0 0 25 0 1 0 65036352 619565056 149890 1283457024 134512640 135121179 4288660592 18446744073709551615 134836042 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/28687/statm: 151261 149890 323 149 0 150452 0 Current children cumulated CPU time (s) 222.15 Current children cumulated vsize (KiB) 607636 [startup+282.307 s] /proc/loadavg: 1.00 1.01 1.00 2/35 28700 /proc/meminfo: memFree=5896/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=2.6 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 575 16567 0 0 0 0 250 10 17 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 [pid=28687] ppid=28678 vsize=744220 CPUtime=279.45 /proc/28687/stat : 28687 (unclasp) R 28678 28678 19908 34817 19908 4202496 357823 0 0 0 27822 123 0 0 25 0 1 0 65036352 762081280 184476 1283457024 134512640 135121179 4288660592 18446744073709551615 134734450 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/28687/statm: 186055 184476 323 149 0 185246 0 Current children cumulated CPU time (s) 282.05 Current children cumulated vsize (KiB) 746812 Maximum CPU time exceeded: sending signal-name then SIGKILL [startup+290.31 s] /proc/loadavg: 1.00 1.01 1.00 2/35 28700 /proc/meminfo: memFree=6120/1048576 swapFree=0/0 [pid=28678] ppid=28677 vsize=2592 CPUtime=2.6 /proc/28678/stat : 28678 (aspuncud-user-1) S 28677 28678 19908 34817 19908 4202496 575 16567 0 0 0 0 250 10 17 0 1 0 65036351 2654208 297 1283457024 134512640 135304128 4289977664 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/28678/statm: 648 297 251 194 0 35 0 [pid=28687] ppid=28678 vsize=765596 CPUtime=287.44 /proc/28687/stat : 28687 (unclasp) R 28678 28678 19908 34817 19908 4202496 368358 0 0 0 28615 129 0 0 25 0 1 0 65036352 783970304 189740 1283457024 134512640 135121179 4288660592 18446744073709551615 134873589 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/28687/statm: 191399 189740 323 149 0 190590 0 Current children cumulated CPU time (s) 290.04 Current children cumulated vsize (KiB) 768188 Sending User defined signal 1 to process tree (bottom up) Sleeping 10 seconds Solver just ended. Dumping a history of the last processes samples Child status: 0 Real time (s): 290.41 CPU time (s): 290.094 CPU user time (s): 288.654 CPU system time (s): 1.44009 CPU usage (%): 99.8914 Max. virtual memory (cumulated for all children) (KiB): 768188 getrusage(RUSAGE_CHILDREN,...) data: user time used= 288.654 system time used= 1.44009 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 387892 page faults= 0 swaps= 0 block input operations= 0 block output operations= 0 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 151 involuntary context switches= 3886 runsolver used 0.008 second user time and 0 second system time The end