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/201108251442/packup2mp4pa-0.6/rand992.cudf.dudf-random.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/dudf-random//rand992.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/rand992.cudf.dudf-random.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.52 1.44 1.29 4/35 24209 /proc/meminfo: memFree=320320/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=3712 CPUtime=0 /proc/24209/stat : 24209 (packup) R 24208 24208 4778 34817 4778 4202496 405 0 0 0 0 0 0 0 25 0 1 0 11181631 3801088 334 1283457024 134512640 134752139 4290493872 18446744073709551615 4157805283 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/24209/statm: 928 334 286 59 0 92 0 [startup+0.203664 s] /proc/loadavg: 1.52 1.44 1.29 4/35 24209 /proc/meminfo: memFree=320320/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=10088 CPUtime=0.2 /proc/24209/stat : 24209 (packup) R 24208 24208 4778 34817 4778 4202496 2018 0 0 0 16 4 0 0 25 0 1 0 11181631 10330112 1947 1283457024 134512640 134752139 4290493872 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/24209/statm: 2522 1947 286 59 0 1686 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 12660 [startup+0.313675 s] /proc/loadavg: 1.52 1.44 1.29 4/35 24209 /proc/meminfo: memFree=320320/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=13108 CPUtime=0.32 /proc/24209/stat : 24209 (packup) R 24208 24208 4778 34817 4778 4202496 2778 0 0 0 28 4 0 0 25 0 1 0 11181631 13422592 2707 1283457024 134512640 134752139 4290493872 18446744073709551615 134539913 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/24209/statm: 3277 2707 286 59 0 2441 0 Current children cumulated CPU time (s) 0.32 Current children cumulated vsize (KiB) 15680 [startup+0.403688 s] /proc/loadavg: 1.52 1.44 1.29 4/35 24209 /proc/meminfo: memFree=320320/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=15616 CPUtime=0.4 /proc/24209/stat : 24209 (packup) R 24208 24208 4778 34817 4778 4202496 3379 0 0 0 36 4 0 0 25 0 1 0 11181631 15990784 3308 1283457024 134512640 134752139 4290493872 18446744073709551615 134682008 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/24209/statm: 3904 3308 286 59 0 3068 0 Current children cumulated CPU time (s) 0.4 Current children cumulated vsize (KiB) 18188 [startup+0.713788 s] /proc/loadavg: 1.52 1.44 1.29 4/35 24209 /proc/meminfo: memFree=320320/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=22808 CPUtime=0.71 /proc/24209/stat : 24209 (packup) R 24208 24208 4778 34817 4778 4202496 5188 0 0 0 66 5 0 0 25 0 1 0 11181631 23355392 5117 1283457024 134512640 134752139 4290493872 18446744073709551615 134681812 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/24209/statm: 5702 5117 286 59 0 4866 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 25380 [startup+1.5139 s] /proc/loadavg: 1.48 1.43 1.29 2/36 24210 /proc/meminfo: memFree=290672/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=47324 CPUtime=1.51 /proc/24209/stat : 24209 (packup) R 24208 24208 4778 34817 4778 4202496 11414 0 0 0 144 7 0 0 25 0 1 0 11181631 48459776 11294 1283457024 134512640 134752139 4290493872 18446744073709551615 4157830583 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/24209/statm: 11831 11294 316 59 0 10995 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 49896 [startup+3.10425 s] /proc/loadavg: 1.48 1.43 1.29 2/38 24212 /proc/meminfo: memFree=261376/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=51176 CPUtime=1.85 /proc/24209/stat : 24209 (packup) S 24208 24208 4778 34817 4778 4202496 12378 0 0 0 161 24 0 0 25 0 1 0 11181631 52404224 12052 1283457024 134512640 134752139 4290493872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/24209/statm: 12794 12052 324 59 0 11958 0 [pid=24211] ppid=24209 vsize=1668 CPUtime=0 /proc/24211/stat : 24211 (sh) S 24209 24208 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 25 0 1 0 11181816 1708032 123 1283457024 134512640 134593992 4293994928 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/24211/statm: 417 123 108 20 0 44 0 [pid=24212] ppid=24211 vsize=28824 CPUtime=1.23 /proc/24212/stat : 24212 (minisatp_32) R 24211 24208 4778 34817 4778 4202496 6691 0 0 0 116 7 0 0 25 0 1 0 11181818 29515776 6001 1283457024 134512640 135413687 4289146160 18446744073709551615 134988446 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/24212/statm: 7206 6001 85 220 0 6984 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 84240 [startup+6.30519 s] /proc/loadavg: 1.48 1.43 1.29 2/38 24214 /proc/meminfo: memFree=268700/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=51180 CPUtime=5.51 /proc/24209/stat : 24209 (packup) S 24208 24208 4778 34817 4778 4202496 12452 25944 0 0 174 41 314 22 18 0 1 0 11181631 52408320 12061 1283457024 134512640 134752139 4290493872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/24209/statm: 12795 12061 332 59 0 11959 0 [pid=24213] ppid=24209 vsize=1668 CPUtime=0 /proc/24213/stat : 24213 (sh) S 24209 24208 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 11182185 1708032 123 1283457024 134512640 134593992 4288986352 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/24213/statm: 417 123 108 20 0 44 0 [pid=24214] ppid=24213 vsize=21600 CPUtime=0.75 /proc/24214/stat : 24214 (minisatp_32) R 24213 24208 4778 34817 4778 4202496 4608 0 0 0 72 3 0 0 22 0 1 0 11182185 22118400 4077 1283457024 134512640 135413687 4291514224 18446744073709551615 134960792 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/24214/statm: 5400 4077 77 220 0 5178 0 Current children cumulated CPU time (s) 6.26 Current children cumulated vsize (KiB) 77020 [startup+12.7068 s] /proc/loadavg: 1.40 1.41 1.28 2/38 24214 /proc/meminfo: memFree=147180/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=51180 CPUtime=5.51 /proc/24209/stat : 24209 (packup) S 24208 24208 4778 34817 4778 4202496 12452 25944 0 0 174 41 314 22 18 0 1 0 11181631 52408320 12061 1283457024 134512640 134752139 4290493872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/24209/statm: 12795 12061 332 59 0 11959 0 [pid=24213] ppid=24209 vsize=1668 CPUtime=0 /proc/24213/stat : 24213 (sh) S 24209 24208 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 11182185 1708032 123 1283457024 134512640 134593992 4288986352 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/24213/statm: 417 123 108 20 0 44 0 [pid=24214] ppid=24213 vsize=140096 CPUtime=7.16 /proc/24214/stat : 24214 (minisatp_32) R 24213 24208 4778 34817 4778 4202496 49203 0 0 0 688 28 0 0 25 0 1 0 11182185 143458304 31643 1283457024 134512640 135413687 4291514224 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/24214/statm: 35024 31643 107 220 0 34802 0 Current children cumulated CPU time (s) 12.67 Current children cumulated vsize (KiB) 195516 Solver just ended. Dumping a history of the last processes samples [startup+12.9069 s] /proc/loadavg: 1.40 1.41 1.28 2/38 24214 /proc/meminfo: memFree=147180/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=51180 CPUtime=5.51 /proc/24209/stat : 24209 (packup) S 24208 24208 4778 34817 4778 4202496 12452 25944 0 0 174 41 314 22 18 0 1 0 11181631 52408320 12061 1283457024 134512640 134752139 4290493872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/24209/statm: 12795 12061 332 59 0 11959 0 [pid=24213] ppid=24209 vsize=1668 CPUtime=0 /proc/24213/stat : 24213 (sh) S 24209 24208 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 11182185 1708032 123 1283457024 134512640 134593992 4288986352 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/24213/statm: 417 123 108 20 0 44 0 [pid=24214] ppid=24213 vsize=140096 CPUtime=7.35 /proc/24214/stat : 24214 (minisatp_32) R 24213 24208 4778 34817 4778 4202496 49678 0 0 0 706 29 0 0 25 0 1 0 11182185 143458304 31862 1283457024 134512640 135413687 4291514224 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/24214/statm: 35024 31862 107 220 0 34802 0 Current children cumulated CPU time (s) 12.86 Current children cumulated vsize (KiB) 195516 [startup+13.3069 s] /proc/loadavg: 1.40 1.41 1.28 2/38 24214 /proc/meminfo: memFree=142468/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=51180 CPUtime=5.51 /proc/24209/stat : 24209 (packup) S 24208 24208 4778 34817 4778 4202496 12452 25944 0 0 174 41 314 22 18 0 1 0 11181631 52408320 12061 1283457024 134512640 134752139 4290493872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/24209/statm: 12795 12061 332 59 0 11959 0 [pid=24213] ppid=24209 vsize=1668 CPUtime=0 /proc/24213/stat : 24213 (sh) S 24209 24208 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 11182185 1708032 123 1283457024 134512640 134593992 4288986352 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/24213/statm: 417 123 108 20 0 44 0 [pid=24214] ppid=24213 vsize=140096 CPUtime=7.75 /proc/24214/stat : 24214 (minisatp_32) R 24213 24208 4778 34817 4778 4202496 49913 0 0 0 746 29 0 0 25 0 1 0 11182185 143458304 32088 1283457024 134512640 135413687 4291514224 18446744073709551615 134649456 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/24214/statm: 35024 32088 107 220 0 34802 0 Current children cumulated CPU time (s) 13.26 Current children cumulated vsize (KiB) 195516 [startup+13.507 s] /proc/loadavg: 1.40 1.41 1.28 2/38 24214 /proc/meminfo: memFree=142468/1048576 swapFree=0/0 [pid=24208] ppid=24207 vsize=2572 CPUtime=0 /proc/24208/stat : 24208 (packup2mp4pa-0.) S 24207 24208 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11181631 2633728 274 1283457024 134512640 135304128 4294793728 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/24208/statm: 643 274 233 194 0 30 0 [pid=24209] ppid=24208 vsize=50408 CPUtime=13.48 /proc/24209/stat : 24209 (packup) R 24208 24208 4778 34817 4778 4202496 21543 76016 0 0 180 45 1070 53 18 0 1 0 11181631 51617792 11881 1283457024 134512640 134752139 4290493872 18446744073709551615 4157798638 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/24209/statm: 12602 11881 345 59 0 11766 0 Current children cumulated CPU time (s) 13.48 Current children cumulated vsize (KiB) 52980 Child status: 0 Real time (s): 13.5611 CPU time (s): 13.5568 CPU user time (s): 12.5528 CPU system time (s): 1.00406 CPU usage (%): 99.9684 Max. virtual memory (cumulated for all children) (KiB): 208260 getrusage(RUSAGE_CHILDREN,...) data: user time used= 12.5528 system time used= 1.00406 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 99937 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= 11 involuntary context switches= 214 runsolver used 0 second user time and 0 second system time The end