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/aspuncud-paranoid-1.3/e381ba7e-a192-11e0-8647-00163e1e087d.cudf.dudf-real.log.runsolver ./aspuncud-paranoid-1.3 /home/misc2010/data/2011/dudf-real//e381ba7e-a192-11e0-8647-00163e1e087d.cudf /home/misc2010/tmp/201108251442/aspuncud-paranoid-1.3/e381ba7e-a192-11e0-8647-00163e1e087d.cudf.dudf-real.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.29 1.41 1.35 3/34 30088 /proc/meminfo: memFree=287432/1048576 swapFree=0/0 [pid=30087] ppid=30086 vsize=2584 CPUtime=0 /proc/30087/stat : 30087 (aspuncud-parano) R 30086 30087 4778 34817 4778 4202496 366 0 0 0 0 0 0 0 25 0 1 0 11258780 2646016 279 1283457024 134512640 135304128 4291182144 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0 /proc/30087/statm: 646 279 234 194 0 33 0 [pid=30088] ppid=30087 vsize=2584 CPUtime=0 /proc/30088/stat : 30088 (aspuncud-parano) R 30087 30087 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11258780 2646016 45 1283457024 134512640 135304128 4291182144 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0 /proc/30088/statm: 646 45 0 194 0 33 0 [startup+0.113595 s] /proc/loadavg: 1.29 1.41 1.35 3/34 30088 /proc/meminfo: memFree=287432/1048576 swapFree=0/0 [pid=30087] ppid=30086 vsize=2588 CPUtime=0 /proc/30087/stat : 30087 (aspuncud-parano) S 30086 30087 4778 34817 4778 4202496 656 2940 0 0 0 0 0 0 25 0 1 0 11258780 2650112 297 1283457024 134512640 135304128 4291182144 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30087/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2588 [startup+0.203615 s] /proc/loadavg: 1.29 1.41 1.35 3/34 30088 /proc/meminfo: memFree=287432/1048576 swapFree=0/0 [pid=30087] ppid=30086 vsize=2588 CPUtime=0 /proc/30087/stat : 30087 (aspuncud-parano) S 30086 30087 4778 34817 4778 4202496 656 2940 0 0 0 0 0 0 25 0 1 0 11258780 2650112 297 1283457024 134512640 135304128 4291182144 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30087/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2588 [startup+0.313644 s] /proc/loadavg: 1.29 1.41 1.35 3/34 30088 /proc/meminfo: memFree=287432/1048576 swapFree=0/0 [pid=30087] ppid=30086 vsize=2588 CPUtime=0 /proc/30087/stat : 30087 (aspuncud-parano) S 30086 30087 4778 34817 4778 4202496 656 2940 0 0 0 0 0 0 25 0 1 0 11258780 2650112 297 1283457024 134512640 135304128 4291182144 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30087/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2588 [startup+0.713733 s] /proc/loadavg: 1.29 1.41 1.35 3/34 30088 /proc/meminfo: memFree=287432/1048576 swapFree=0/0 [pid=30087] ppid=30086 vsize=2588 CPUtime=0 /proc/30087/stat : 30087 (aspuncud-parano) S 30086 30087 4778 34817 4778 4202496 656 2940 0 0 0 0 0 0 25 0 1 0 11258780 2650112 297 1283457024 134512640 135304128 4291182144 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30087/statm: 647 297 251 194 0 34 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2588 [startup+1.51392 s] /proc/loadavg: 1.29 1.41 1.35 2/37 30104 /proc/meminfo: memFree=265812/1048576 swapFree=0/0 [pid=30087] ppid=30086 vsize=2588 CPUtime=0 /proc/30087/stat : 30087 (aspuncud-parano) S 30086 30087 4778 34817 4778 4202496 656 2940 0 0 0 0 0 0 25 0 1 0 11258780 2650112 297 1283457024 134512640 135304128 4291182144 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30087/statm: 647 297 251 194 0 34 0 [pid=30102] ppid=30087 vsize=3444 CPUtime=0 /proc/30102/stat : 30102 (unclasp) S 30087 30087 4778 34817 4778 4202496 407 0 0 0 0 0 0 0 25 0 1 0 11258782 3526656 272 1283457024 134512640 135121179 4294017408 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/30102/statm: 861 272 240 149 0 52 0 [pid=30103] ppid=30087 vsize=2688 CPUtime=0 /proc/30103/stat : 30103 (gringo) S 30087 30087 4778 34817 4778 4202496 408 0 0 0 0 0 0 0 25 0 1 0 11258782 2752512 280 1283457024 134512640 137056543 4292398976 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/30103/statm: 672 280 252 622 0 47 0 [pid=30104] ppid=30087 vsize=35360 CPUtime=1.5 /proc/30104/stat : 30104 (cudf2lp) R 30087 30087 4778 34817 4778 4202496 11326 0 0 0 146 4 0 0 25 0 1 0 11258782 36208640 8633 1283457024 134512640 135786343 4290885264 18446744073709551615 135191469 0 0 6 0 0 0 0 17 0 0 0 0 /proc/30104/statm: 8840 8633 133 311 0 8527 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 44080 Solver just ended. Dumping a history of the last processes samples [startup+1.604 s] /proc/loadavg: 1.29 1.41 1.35 2/37 30104 /proc/meminfo: memFree=265812/1048576 swapFree=0/0 [pid=30087] ppid=30086 vsize=2588 CPUtime=0 /proc/30087/stat : 30087 (aspuncud-parano) S 30086 30087 4778 34817 4778 4202496 656 2940 0 0 0 0 0 0 25 0 1 0 11258780 2650112 297 1283457024 134512640 135304128 4291182144 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30087/statm: 647 297 251 194 0 34 0 [pid=30102] ppid=30087 vsize=4380 CPUtime=0 /proc/30102/stat : 30102 (unclasp) S 30087 30087 4778 34817 4778 4202496 685 0 0 0 0 0 0 0 18 0 1 0 11258782 4485120 550 1283457024 134512640 135121179 4294017408 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/30102/statm: 1095 550 275 149 0 286 0 [pid=30103] ppid=30087 vsize=4232 CPUtime=0.05 /proc/30103/stat : 30103 (gringo) R 30087 30087 4778 34817 4778 4202496 811 0 0 0 5 0 0 0 18 0 1 0 11258782 4333568 585 1283457024 134512640 137056543 4292398976 18446744073709551615 136301796 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30103/statm: 1058 585 253 622 0 433 0 [pid=30104] ppid=30087 vsize=35364 CPUtime=1.54 /proc/30104/stat : 30104 (cudf2lp) R 30087 30087 4778 34817 4778 4202496 11331 0 0 0 150 4 0 0 25 0 1 0 11258782 36212736 8638 1283457024 134512640 135786343 4290885264 18446744073709551615 135258574 0 0 6 0 0 0 0 17 0 0 0 0 /proc/30104/statm: 8841 8638 137 311 0 8528 0 Current children cumulated CPU time (s) 1.59 Current children cumulated vsize (KiB) 46564 [startup+1.80404 s] /proc/loadavg: 1.29 1.41 1.35 2/37 30104 /proc/meminfo: memFree=265812/1048576 swapFree=0/0 [pid=30087] ppid=30086 vsize=2588 CPUtime=1.66 /proc/30087/stat : 30087 (aspuncud-parano) S 30086 30087 4778 34817 4778 4202496 656 14275 0 0 0 0 162 4 18 0 1 0 11258780 2650112 297 1283457024 134512640 135304128 4291182144 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/30087/statm: 647 297 251 194 0 34 0 [pid=30102] ppid=30087 vsize=6400 CPUtime=0 /proc/30102/stat : 30102 (unclasp) R 30087 30087 4778 34817 4778 4202496 1160 0 0 0 0 0 0 0 18 0 1 0 11258782 6553600 1025 1283457024 134512640 135121179 4294017408 18446744073709551615 4294960130 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30102/statm: 1600 1025 277 149 0 791 0 [pid=30103] ppid=30087 vsize=6688 CPUtime=0.12 /proc/30103/stat : 30103 (gringo) R 30087 30087 4778 34817 4778 4202496 1555 0 0 0 12 0 0 0 18 0 1 0 11258782 6848512 1151 1283457024 134512640 137056543 4292398976 18446744073709551615 134805928 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30103/statm: 1672 1151 268 622 0 1047 0 Current children cumulated CPU time (s) 1.78 Current children cumulated vsize (KiB) 15676 [startup+1.90407 s] /proc/loadavg: 1.29 1.41 1.35 2/37 30104 /proc/meminfo: memFree=265812/1048576 swapFree=0/0 [pid=30087] ppid=30086 vsize=2588 CPUtime=1.66 /proc/30087/stat : 30087 (aspuncud-parano) R 30086 30087 4778 34817 4778 4202496 656 14275 0 0 0 0 162 4 19 0 1 0 11258780 2650112 297 1283457024 134512640 135304128 4291182144 18446744073709551615 4294960130 0 65536 4 1132560123 0 0 0 17 0 0 0 0 /proc/30087/statm: 647 297 251 194 0 34 0 [pid=30102] ppid=30087 vsize=9012 CPUtime=0.04 /proc/30102/stat : 30102 (unclasp) R 30087 30087 4778 34817 4778 4202496 1842 0 0 0 4 0 0 0 18 0 1 0 11258782 9228288 1666 1283457024 134512640 135121179 4294017408 18446744073709551615 134988523 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/30102/statm: 2253 1666 289 149 0 1444 0 [pid=30103] ppid=30087 vsize=0 CPUtime=0.18 /proc/30103/stat : 30103 (gringo) Z 30087 30087 4778 34817 4778 4202508 2349 0 0 0 18 0 0 0 18 0 1 0 11258782 0 0 1283457024 0 0 0 0 0 0 0 6 16384 18446744071564254338 0 0 17 0 0 0 0 /proc/30103/statm: 0 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.88 Current children cumulated vsize (KiB) 11600 Child status: 0 Real time (s): 1.99966 CPU time (s): 1.98812 CPU user time (s): 1.93212 CPU system time (s): 0.056003 CPU usage (%): 99.4229 Max. virtual memory (cumulated for all children) (KiB): 50080 getrusage(RUSAGE_CHILDREN,...) data: user time used= 1.93212 system time used= 0.056003 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 22555 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= 368 involuntary context switches= 291 runsolver used 0 second user time and 0.012 second system time The end