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/201109011757/aspuncud-user-1.0/rand83.cudf.dudf-random.log.runsolver ./aspuncud-user-1.0 /home/misc2010/data/2011/dudf-random//rand83.cudf /home/misc2010/tmp/201109011757/aspuncud-user-1.0/rand83.cudf.dudf-random.result -sum(pin-priority-1),-sum(pin-priority-500),-sum(pin-priority-700),-notuptodate,-removed,-changed 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.02 1.06 1.02 5/34 30104 /proc/meminfo: memFree=581060/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2584 CPUtime=0 /proc/30103/stat : 30103 (aspuncud-user-1) R 30102 30103 22717 34817 22717 4202496 366 0 0 0 0 0 0 0 25 0 1 0 72718649 2646016 279 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0 /proc/30103/statm: 646 279 234 194 0 33 0 [pid=30104] ppid=30103 vsize=2584 CPUtime=0 /proc/30104/stat : 30104 (aspuncud-user-1) R 30103 30103 22717 34817 22717 4202560 0 0 0 0 0 0 0 0 25 0 1 0 72718649 2646016 45 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0 /proc/30104/statm: 646 45 0 194 0 33 0 [startup+0.114298 s] /proc/loadavg: 1.02 1.06 1.02 5/34 30104 /proc/meminfo: memFree=581060/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=0.01 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 576 1518 0 0 0 0 0 1 25 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2588 [startup+0.214314 s] /proc/loadavg: 1.02 1.06 1.02 5/34 30104 /proc/meminfo: memFree=581060/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=0.01 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 576 1518 0 0 0 0 0 1 25 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2588 [startup+0.314344 s] /proc/loadavg: 1.02 1.06 1.02 5/34 30104 /proc/meminfo: memFree=581060/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=0.01 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 576 1518 0 0 0 0 0 1 25 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2588 [startup+0.714428 s] /proc/loadavg: 1.02 1.06 1.02 5/34 30104 /proc/meminfo: memFree=581060/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=0.01 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 576 1518 0 0 0 0 0 1 25 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2588 [startup+1.51461 s] /proc/loadavg: 1.02 1.06 1.02 2/37 30114 /proc/meminfo: memFree=554852/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=0.01 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 576 1518 0 0 0 0 0 1 25 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=3448 CPUtime=0 /proc/30112/stat : 30112 (unclasp) S 30103 30103 22717 34817 22717 4202496 407 0 0 0 0 0 0 0 25 0 1 0 72718650 3530752 272 1283457024 134512640 135121179 4286698128 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/30112/statm: 862 272 240 149 0 53 0 [pid=30113] ppid=30103 vsize=2692 CPUtime=0 /proc/30113/stat : 30113 (gringo) S 30103 30103 22717 34817 22717 4202496 408 0 0 0 0 0 0 0 25 0 1 0 72718650 2756608 281 1283457024 134512640 137056543 4287486688 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/30113/statm: 673 281 252 622 0 48 0 [pid=30114] ppid=30103 vsize=29444 CPUtime=1.5 /proc/30114/stat : 30114 (cudf2lp) R 30103 30103 22717 34817 22717 4202496 8211 0 0 0 146 4 0 0 25 0 1 0 72718650 30150656 6715 1283457024 134512640 135786343 4291223184 18446744073709551615 134566203 0 0 6 0 0 0 0 17 0 0 0 0 /proc/30114/statm: 7361 6715 128 311 0 7048 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 38172 [startup+3.1154 s] /proc/loadavg: 1.02 1.06 1.02 2/37 30114 /proc/meminfo: memFree=530796/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=0.01 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 576 1518 0 0 0 0 0 1 25 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=13008 CPUtime=0.03 /proc/30112/stat : 30112 (unclasp) S 30103 30103 22717 34817 22717 4202496 3182 0 0 0 2 1 0 0 18 0 1 0 72718650 13320192 2661 1283457024 134512640 135121179 4286698128 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/30112/statm: 3252 2661 275 149 0 2443 0 [pid=30113] ppid=30103 vsize=15960 CPUtime=0.51 /proc/30113/stat : 30113 (gringo) S 30103 30103 22717 34817 22717 4202496 4542 0 0 0 49 2 0 0 18 0 1 0 72718650 16343040 2982 1283457024 134512640 137056543 4287486688 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/30113/statm: 3990 2982 253 622 0 3365 0 [pid=30114] ppid=30103 vsize=25476 CPUtime=2.53 /proc/30114/stat : 30114 (cudf2lp) R 30103 30103 22717 34817 22717 4202496 14077 0 0 0 248 5 0 0 25 0 1 0 72718650 26087424 4145 1283457024 134512640 135786343 4291223184 18446744073709551615 135407694 0 0 6 0 0 0 0 17 0 0 0 0 /proc/30114/statm: 6369 4145 139 311 0 6056 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 57032 [startup+6.30728 s] /proc/loadavg: 1.02 1.06 1.02 2/35 30114 /proc/meminfo: memFree=552900/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=3.49 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 577 24587 0 0 0 0 339 10 15 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=31692 CPUtime=2.8 /proc/30112/stat : 30112 (unclasp) R 30103 30103 22717 34817 22717 4202496 28324 0 0 0 270 10 0 0 23 0 1 0 72718650 32452608 7109 1283457024 134512640 135121179 4286698128 18446744073709551615 134734450 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30112/statm: 7923 7109 328 149 0 7114 0 Current children cumulated CPU time (s) 6.29 Current children cumulated vsize (KiB) 34280 [startup+12.7104 s] /proc/loadavg: 1.02 1.06 1.02 2/35 30114 /proc/meminfo: memFree=552908/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=3.49 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 577 24587 0 0 0 0 339 10 15 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=32360 CPUtime=9.19 /proc/30112/stat : 30112 (unclasp) R 30103 30103 22717 34817 22717 4202496 82314 0 0 0 874 45 0 0 25 0 1 0 72718650 33136640 7158 1283457024 134512640 135121179 4286698128 18446744073709551615 134990503 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30112/statm: 8090 7158 328 149 0 7281 0 Current children cumulated CPU time (s) 12.68 Current children cumulated vsize (KiB) 34948 [startup+25.5151 s] /proc/loadavg: 1.01 1.06 1.02 2/35 30114 /proc/meminfo: memFree=552908/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=3.49 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 577 24587 0 0 0 0 339 10 15 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=31692 CPUtime=21.98 /proc/30112/stat : 30112 (unclasp) R 30103 30103 22717 34817 22717 4202496 192652 0 0 0 2104 94 0 0 25 0 1 0 72718650 32452608 7109 1283457024 134512640 135121179 4286698128 18446744073709551615 134713296 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30112/statm: 7923 7109 328 149 0 7114 0 Current children cumulated CPU time (s) 25.47 Current children cumulated vsize (KiB) 34280 Solver just ended. Dumping a history of the last processes samples [startup+25.6151 s] /proc/loadavg: 1.01 1.06 1.02 2/35 30114 /proc/meminfo: memFree=552908/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=3.49 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 577 24587 0 0 0 0 339 10 15 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=31692 CPUtime=22.09 /proc/30112/stat : 30112 (unclasp) R 30103 30103 22717 34817 22717 4202496 193487 0 0 0 2113 96 0 0 25 0 1 0 72718650 32452608 7109 1283457024 134512640 135121179 4286698128 18446744073709551615 134713296 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30112/statm: 7923 7109 328 149 0 7114 0 Current children cumulated CPU time (s) 25.58 Current children cumulated vsize (KiB) 34280 [startup+38.4113 s] /proc/loadavg: 1.01 1.05 1.02 2/35 30114 /proc/meminfo: memFree=552784/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=3.49 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 577 24587 0 0 0 0 339 10 15 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=31692 CPUtime=34.86 /proc/30112/stat : 30112 (unclasp) R 30103 30103 22717 34817 22717 4202496 304375 0 0 0 3324 162 0 0 25 0 1 0 72718650 32452608 7109 1283457024 134512640 135121179 4286698128 18446744073709551615 134734310 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30112/statm: 7923 7109 328 149 0 7114 0 Current children cumulated CPU time (s) 38.35 Current children cumulated vsize (KiB) 34280 [startup+44.8136 s] /proc/loadavg: 1.01 1.05 1.02 2/35 30114 /proc/meminfo: memFree=552412/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=3.49 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 577 24587 0 0 0 0 339 10 15 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=32800 CPUtime=41.27 /proc/30112/stat : 30112 (unclasp) R 30103 30103 22717 34817 22717 4202496 310799 0 0 0 3961 166 0 0 25 0 1 0 72718650 33587200 7354 1283457024 134512640 135121179 4286698128 18446744073709551615 134713260 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30112/statm: 8200 7354 328 149 0 7391 0 Current children cumulated CPU time (s) 44.76 Current children cumulated vsize (KiB) 35388 [startup+46.404 s] /proc/loadavg: 1.01 1.05 1.02 2/35 30114 /proc/meminfo: memFree=552412/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=3.49 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 577 24587 0 0 0 0 339 10 15 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=32800 CPUtime=42.85 /proc/30112/stat : 30112 (unclasp) R 30103 30103 22717 34817 22717 4202496 310799 0 0 0 4119 166 0 0 25 0 1 0 72718650 33587200 7354 1283457024 134512640 135121179 4286698128 18446744073709551615 134980996 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30112/statm: 8200 7354 328 149 0 7391 0 Current children cumulated CPU time (s) 46.34 Current children cumulated vsize (KiB) 35388 [startup+48.0047 s] /proc/loadavg: 1.01 1.05 1.02 2/35 30114 /proc/meminfo: memFree=552288/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=3.49 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 577 24587 0 0 0 0 339 10 15 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=32800 CPUtime=44.45 /proc/30112/stat : 30112 (unclasp) R 30103 30103 22717 34817 22717 4202496 310799 0 0 0 4279 166 0 0 25 0 1 0 72718650 33587200 7354 1283457024 134512640 135121179 4286698128 18446744073709551615 134713296 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30112/statm: 8200 7354 328 149 0 7391 0 Current children cumulated CPU time (s) 47.94 Current children cumulated vsize (KiB) 35388 [startup+48.8051 s] /proc/loadavg: 1.01 1.05 1.02 2/35 30114 /proc/meminfo: memFree=552288/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=3.49 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 577 24587 0 0 0 0 339 10 15 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=32800 CPUtime=45.25 /proc/30112/stat : 30112 (unclasp) R 30103 30103 22717 34817 22717 4202496 310799 0 0 0 4359 166 0 0 25 0 1 0 72718650 33587200 7354 1283457024 134512640 135121179 4286698128 18446744073709551615 134734450 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30112/statm: 8200 7354 328 149 0 7391 0 Current children cumulated CPU time (s) 48.74 Current children cumulated vsize (KiB) 35388 [startup+49.2054 s] /proc/loadavg: 1.01 1.05 1.02 2/35 30114 /proc/meminfo: memFree=552288/1048576 swapFree=0/0 [pid=30103] ppid=30102 vsize=2588 CPUtime=3.49 /proc/30103/stat : 30103 (aspuncud-user-1) S 30102 30103 22717 34817 22717 4202496 577 24587 0 0 0 0 339 10 15 0 1 0 72718649 2650112 297 1283457024 134512640 135304128 4286908928 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30103/statm: 647 297 251 194 0 34 0 [pid=30112] ppid=30103 vsize=0 CPUtime=45.66 /proc/30112/stat : 30112 (unclasp) R 30103 30103 22717 34817 22717 4202500 310814 0 0 0 4399 167 0 0 25 0 1 0 72718650 0 0 1283457024 0 0 0 0 0 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30112/statm: 0 0 0 0 0 0 0 Current children cumulated CPU time (s) 49.15 Current children cumulated vsize (KiB) 2588 Child status: 0 Real time (s): 49.22 CPU time (s): 49.1711 CPU user time (s): 47.383 CPU system time (s): 1.78811 CPU usage (%): 99.9006 Max. virtual memory (cumulated for all children) (KiB): 77240 getrusage(RUSAGE_CHILDREN,...) data: user time used= 47.383 system time used= 1.78811 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 338482 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= 1476 involuntary context switches= 1683 runsolver used 0 second user time and 0 second system time The end