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/201108241238/aspuncud-trendy-1.3/rand450.cudf.s-e-l-s.log.runsolver ./aspuncud-trendy-1.3 /home/misc2010/data/2011/incremental/s-e-l-s/rand450.cudf /home/misc2010/tmp/201108241238/aspuncud-trendy-1.3/rand450.cudf.s-e-l-s.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.00 1.00 4/38 13403 /proc/meminfo: memFree=534060/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2584 CPUtime=0 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 372 0 0 0 0 0 0 0 25 0 1 0 3099463 2646016 279 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/13400/statm: 646 279 234 194 0 33 0 [pid=13401] ppid=13400 vsize=2584 CPUtime=0 /proc/13401/stat : 13401 (aspuncud-trendy) S 13400 13400 1511 34817 1511 4202560 119 0 0 0 0 0 0 0 25 0 1 0 3099463 2646016 133 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0 /proc/13401/statm: 646 133 87 194 0 33 0 [pid=13402] ppid=13401 vsize=2584 CPUtime=0 /proc/13402/stat : 13402 (aspuncud-trendy) R 13401 13400 1511 34817 1511 4202560 127 0 0 0 0 0 0 0 25 0 1 0 3099463 2646016 150 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/13402/statm: 646 150 104 194 0 33 0 [pid=13403] ppid=13402 vsize=2584 CPUtime=0 /proc/13403/stat : 13403 (aspuncud-trendy) R 13402 13400 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 3099463 2646016 46 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/13403/statm: 646 46 0 194 0 33 0 [startup+0.116203 s] /proc/loadavg: 1.00 1.00 1.00 4/38 13403 /proc/meminfo: memFree=534060/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=0 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 2231 0 0 0 0 0 0 25 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2588 [startup+0.206228 s] /proc/loadavg: 1.00 1.00 1.00 4/38 13403 /proc/meminfo: memFree=534060/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=0 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 2231 0 0 0 0 0 0 25 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2588 [startup+0.305984 s] /proc/loadavg: 1.00 1.00 1.00 4/38 13403 /proc/meminfo: memFree=534060/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=0 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 2231 0 0 0 0 0 0 25 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2588 [startup+0.706731 s] /proc/loadavg: 1.00 1.00 1.00 4/38 13403 /proc/meminfo: memFree=534060/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=0 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 2231 0 0 0 0 0 0 25 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2588 [startup+1.50775 s] /proc/loadavg: 1.00 1.00 1.00 2/39 13415 /proc/meminfo: memFree=498436/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=0 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 2231 0 0 0 0 0 0 25 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 [pid=13412] ppid=13400 vsize=3440 CPUtime=0 /proc/13412/stat : 13412 (unclasp) S 13400 13400 1511 34817 1511 4202496 406 0 0 0 0 0 0 0 25 0 1 0 3099464 3522560 271 1283457024 134512640 135121179 4294941280 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/13412/statm: 860 271 240 149 0 51 0 [pid=13413] ppid=13400 vsize=2696 CPUtime=0 /proc/13413/stat : 13413 (gringo) S 13400 13400 1511 34817 1511 4202496 407 0 0 0 0 0 0 0 25 0 1 0 3099464 2760704 281 1283457024 134512640 137056543 4294568336 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/13413/statm: 674 281 252 622 0 49 0 [pid=13414] ppid=13400 vsize=40452 CPUtime=1.37 /proc/13414/stat : 13414 (cudf2lp) R 13400 13400 1511 34817 1511 4202496 11592 0 0 0 129 8 0 0 25 0 1 0 3099464 41422848 8688 1283457024 134512640 135786343 4294158768 18446744073709551615 135199415 0 0 6 0 0 0 0 17 0 0 0 0 /proc/13414/statm: 10113 8688 126 311 0 9800 0 Current children cumulated CPU time (s) 1.37 Current children cumulated vsize (KiB) 49176 [startup+3.10819 s] /proc/loadavg: 1.00 1.00 1.00 2/39 13415 /proc/meminfo: memFree=460292/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=2.17 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 17922 0 0 0 0 204 13 18 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 [pid=13412] ppid=13400 vsize=20772 CPUtime=0.09 /proc/13412/stat : 13412 (unclasp) R 13400 13400 1511 34817 1511 4202496 5375 0 0 0 7 2 0 0 18 0 1 0 3099464 21270528 4582 1283457024 134512640 135121179 4294941280 18446744073709551615 4294960130 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/13412/statm: 5193 4582 277 149 0 4384 0 [pid=13413] ppid=13400 vsize=24040 CPUtime=0.69 /proc/13413/stat : 13413 (gringo) R 13400 13400 1511 34817 1511 4202496 7227 0 0 0 67 2 0 0 18 0 1 0 3099464 24616960 4961 1283457024 134512640 137056543 4294568336 18446744073709551615 136293969 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/13413/statm: 6010 4961 268 622 0 5385 0 Current children cumulated CPU time (s) 2.95 Current children cumulated vsize (KiB) 47400 [startup+6.30903 s] /proc/loadavg: 1.08 1.02 1.01 2/37 13415 /proc/meminfo: memFree=473848/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=3.37 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 31115 0 0 0 0 315 22 15 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 [pid=13412] ppid=13400 vsize=44768 CPUtime=2.78 /proc/13412/stat : 13412 (unclasp) R 13400 13400 1511 34817 1511 4202496 29856 0 0 0 262 16 0 0 22 0 1 0 3099464 45842432 10038 1283457024 134512640 135121179 4294941280 18446744073709551615 134734450 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/13412/statm: 11192 10038 333 149 0 10383 0 Current children cumulated CPU time (s) 6.15 Current children cumulated vsize (KiB) 47356 [startup+12.7114 s] /proc/loadavg: 1.07 1.02 1.00 2/37 13416 /proc/meminfo: memFree=473600/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=3.37 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 31115 0 0 0 0 315 22 15 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 [pid=13412] ppid=13400 vsize=45520 CPUtime=9.18 /proc/13412/stat : 13412 (unclasp) R 13400 13400 1511 34817 1511 4202496 109925 0 0 0 866 52 0 0 25 0 1 0 3099464 46612480 10196 1283457024 134512640 135121179 4294941280 18446744073709551615 134980988 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/13412/statm: 11380 10196 333 149 0 10571 0 Current children cumulated CPU time (s) 12.55 Current children cumulated vsize (KiB) 48108 [startup+25.5053 s] /proc/loadavg: 1.06 1.01 1.00 2/37 13417 /proc/meminfo: memFree=473848/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=3.37 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 31115 0 0 0 0 315 22 15 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 [pid=13412] ppid=13400 vsize=45928 CPUtime=21.96 /proc/13412/stat : 13412 (unclasp) R 13400 13400 1511 34817 1511 4202496 235824 0 0 0 2088 108 0 0 25 0 1 0 3099464 47030272 10324 1283457024 134512640 135121179 4294941280 18446744073709551615 134980996 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/13412/statm: 11482 10324 333 149 0 10673 0 Current children cumulated CPU time (s) 25.33 Current children cumulated vsize (KiB) 48516 Solver just ended. Dumping a history of the last processes samples [startup+25.6053 s] /proc/loadavg: 1.06 1.01 1.00 2/37 13417 /proc/meminfo: memFree=473848/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=3.37 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 31115 0 0 0 0 315 22 15 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 [pid=13412] ppid=13400 vsize=45012 CPUtime=22.06 /proc/13412/stat : 13412 (unclasp) R 13400 13400 1511 34817 1511 4202496 236951 0 0 0 2098 108 0 0 25 0 1 0 3099464 46092288 10095 1283457024 134512640 135121179 4294941280 18446744073709551615 134734450 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/13412/statm: 11253 10095 333 149 0 10444 0 Current children cumulated CPU time (s) 25.43 Current children cumulated vsize (KiB) 47600 [startup+26.4056 s] /proc/loadavg: 1.06 1.01 1.00 2/37 13417 /proc/meminfo: memFree=473600/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=3.37 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 31115 0 0 0 0 315 22 15 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 [pid=13412] ppid=13400 vsize=44988 CPUtime=22.86 /proc/13412/stat : 13412 (unclasp) R 13400 13400 1511 34817 1511 4202496 246291 0 0 0 2174 112 0 0 25 0 1 0 3099464 46067712 10095 1283457024 134512640 135121179 4294941280 18446744073709551615 134713296 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/13412/statm: 11247 10095 333 149 0 10438 0 Current children cumulated CPU time (s) 26.23 Current children cumulated vsize (KiB) 47576 [startup+26.8058 s] /proc/loadavg: 1.06 1.01 1.00 2/37 13417 /proc/meminfo: memFree=473600/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=3.37 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 31115 0 0 0 0 315 22 15 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 [pid=13412] ppid=13400 vsize=44828 CPUtime=23.26 /proc/13412/stat : 13412 (unclasp) R 13400 13400 1511 34817 1511 4202496 251179 0 0 0 2211 115 0 0 25 0 1 0 3099464 45903872 10050 1283457024 134512640 135121179 4294941280 18446744073709551615 134734446 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/13412/statm: 11207 10050 333 149 0 10398 0 Current children cumulated CPU time (s) 26.63 Current children cumulated vsize (KiB) 47416 [startup+27.0058 s] /proc/loadavg: 1.06 1.01 1.00 2/37 13417 /proc/meminfo: memFree=473600/1048576 swapFree=0/0 [pid=13400] ppid=13399 vsize=2588 CPUtime=3.37 /proc/13400/stat : 13400 (aspuncud-trendy) S 13399 13400 1511 34817 1511 4202496 622 31115 0 0 0 0 315 22 15 0 1 0 3099463 2650112 297 1283457024 134512640 135304128 4288396256 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13400/statm: 647 297 251 194 0 34 0 [pid=13412] ppid=13400 vsize=42920 CPUtime=23.46 /proc/13412/stat : 13412 (unclasp) R 13400 13400 1511 34817 1511 4202496 252929 0 0 0 2228 118 0 0 25 0 1 0 3099464 43950080 9689 1283457024 134512640 135121179 4294941280 18446744073709551615 4158236124 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/13412/statm: 10730 9689 342 149 0 9921 0 Current children cumulated CPU time (s) 26.83 Current children cumulated vsize (KiB) 45508 Child status: 0 Real time (s): 27.0465 CPU time (s): 26.8897 CPU user time (s): 25.4616 CPU system time (s): 1.42809 CPU usage (%): 99.4203 Max. virtual memory (cumulated for all children) (KiB): 87704 getrusage(RUSAGE_CHILDREN,...) data: user time used= 25.4616 system time used= 1.42809 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 287198 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= 2025 involuntary context switches= 1782 runsolver used 0 second user time and 0.008 second system time The end