source: CMDIValidator/trunk/cmdi-validator-tool/src/main/java/eu/clarin/cmdi/validator/tool/CMDIValidatorTool.java @ 5391

Last change on this file since 5391 was 5391, checked in by Oliver Schonefeld, 10 years ago
  • add command line option to enable full debugging (level trace)
  • Property svn:eol-style set to native
File size: 27.3 KB
Line 
1/**
2 * This software is copyright (c) 2014 by
3 *  - Institut fuer Deutsche Sprache (http://www.ids-mannheim.de)
4 * This is free software. You can redistribute it
5 * and/or modify it under the terms described in
6 * the GNU General Public License v3 of which you
7 * should have received a copy. Otherwise you can download
8 * it from
9 *
10 *   http://www.gnu.org/licenses/gpl-3.0.txt
11 *
12 * @copyright Institut fuer Deutsche Sprache (http://www.ids-mannheim.de)
13 *
14 * @license http://www.gnu.org/licenses/gpl-3.0.txt
15 *  GNU General Public License v3
16 */
17package eu.clarin.cmdi.validator.tool;
18
19import humanize.Humanize;
20
21import java.io.File;
22import java.io.PrintWriter;
23import java.util.Locale;
24import java.util.concurrent.TimeUnit;
25
26import net.java.truevfs.access.TFile;
27import net.java.truevfs.access.TVFS;
28import net.java.truevfs.kernel.spec.FsSyncException;
29
30import org.apache.commons.cli.CommandLine;
31import org.apache.commons.cli.CommandLineParser;
32import org.apache.commons.cli.GnuParser;
33import org.apache.commons.cli.HelpFormatter;
34import org.apache.commons.cli.OptionBuilder;
35import org.apache.commons.cli.OptionGroup;
36import org.apache.commons.cli.Options;
37import org.apache.commons.cli.ParseException;
38import org.slf4j.Logger;
39import org.slf4j.LoggerFactory;
40
41import eu.clarin.cmdi.validator.ThreadedCMDIValidatorProcessor;
42import eu.clarin.cmdi.validator.CMDIValidator;
43import eu.clarin.cmdi.validator.CMDIValidatorConfig;
44import eu.clarin.cmdi.validator.CMDIValidatorException;
45import eu.clarin.cmdi.validator.CMDIValidatorInitException;
46import eu.clarin.cmdi.validator.CMDIValidatorHandlerAdapter;
47import eu.clarin.cmdi.validator.CMDIValidatorResult;
48import eu.clarin.cmdi.validator.CMDIValidatorResult.Message;
49import eu.clarin.cmdi.validator.CMDIValidatorResult.Severity;
50import eu.clarin.cmdi.validator.extensions.CheckHandlesExtension;
51import eu.clarin.cmdi.validator.utils.HandleResolver;
52
53
54public class CMDIValidatorTool {
55    private static final String PRG_NAME                 = "cmdi-validator";
56    private static final long DEFAULT_PROGRESS_INTERVAL  = 15000;
57    private static final Locale LOCALE                   = Locale.ENGLISH;
58    private static final char OPT_DEBUG                  = 'd';
59    private static final char OPT_DEBUG_TRACE            = 'D';
60    private static final char OPT_QUIET                  = 'q';
61    private static final char OPT_VERBOSE                = 'v';
62    private static final char OPT_THREAD_COUNT           = 't';
63    private static final char OPT_NO_THREADS             = 'T';
64    private static final char OPT_NO_ESTIMATE            = 'E';
65    private static final char OPT_SCHEMA_CACHE_DIR       = 'c';
66    private static final char OPT_NO_SCHEMATRON          = 'S';
67    private static final char OPT_SCHEMATRON_FILE        = 's';
68    private static final char OPT_CHECK_PIDS             = 'p';
69    private static final char OPT_CHECK_AND_RESOLVE_PIDS = 'P';
70    private static final Logger logger =
71            LoggerFactory.getLogger(CMDIValidatorTool.class);
72    private static final org.apache.log4j.ConsoleAppender appender;
73
74
75    public static void main(String[] args) {
76        /*
77         * application defaults
78         */
79        int debugging             = 0;
80        boolean quiet             = false;
81        boolean verbose           = false;
82        int threadCount           = Runtime.getRuntime().availableProcessors();
83        boolean estimate          = true;
84        long progressInterval     = DEFAULT_PROGRESS_INTERVAL;
85        File schemaCacheDir       = null;
86        boolean disableSchematron = false;
87        File schematronFile       = null;
88        boolean checkPids         = false;
89        boolean checkAndResolvePids   = false;
90
91        /*
92         * setup command line parser
93         */
94        final Options options = createCommandLineOptions();
95        try {
96            final CommandLineParser parser = new GnuParser();
97            final CommandLine line = parser.parse(options, args);
98            // check incompatible combinations
99            if (line.hasOption(OPT_THREAD_COUNT) && line.hasOption(OPT_NO_THREADS)) {
100                throw new ParseException("The -t and -T options are mutually exclusive");
101            }
102            if (line.hasOption(OPT_DEBUG) && line.hasOption(OPT_QUIET)) {
103                throw new ParseException("The -d and -q switches are mutually exclusive");
104            }
105            if (line.hasOption(OPT_VERBOSE) && line.hasOption(OPT_QUIET)) {
106                throw new ParseException("The -v and -q switches are mutually exclusive");
107            }
108            if (line.hasOption(OPT_NO_SCHEMATRON) && line.hasOption(OPT_SCHEMATRON_FILE)) {
109                throw new ParseException("The -s and -S options are mutually exclusive");
110            }
111            if (line.hasOption(OPT_CHECK_PIDS) && line.hasOption(OPT_CHECK_AND_RESOLVE_PIDS)) {
112                throw new ParseException("The -p and -P options are mutually exclusive");
113            }
114
115            // extract options
116            if (line.hasOption(OPT_DEBUG)) {
117                debugging = 1;
118            }
119            if (line.hasOption(OPT_DEBUG_TRACE)) {
120                debugging = 2;
121            }
122            if (line.hasOption(OPT_QUIET)) {
123                quiet = true;
124            }
125            if (line.hasOption(OPT_VERBOSE)) {
126                verbose = true;
127            }
128            if (quiet) {
129                progressInterval = -1;
130            }
131            if (line.hasOption(OPT_THREAD_COUNT)) {
132                try {
133                    threadCount = Integer.parseInt(
134                            line.getOptionValue(OPT_THREAD_COUNT));
135                    if (threadCount < 1) {
136                        throw new ParseException(
137                                "thread count must be larger then 0");
138                    }
139                } catch (NumberFormatException e) {
140                    throw new ParseException("invalid number");
141                }
142            }
143            if (line.hasOption(OPT_NO_THREADS)) {
144                threadCount = 1;
145            }
146            if (line.hasOption(OPT_NO_ESTIMATE) || (progressInterval < 0)) {
147                estimate = false;
148            }
149            if (line.hasOption(OPT_SCHEMA_CACHE_DIR)) {
150                String dir = line.getOptionValue(OPT_SCHEMA_CACHE_DIR);
151                if ((dir == null) || dir.isEmpty()) {
152                    throw new ParseException("invalid argument for -" +
153                            OPT_SCHEMA_CACHE_DIR);
154                }
155                schemaCacheDir = new File(dir);
156            }
157            if (line.hasOption(OPT_NO_SCHEMATRON)) {
158                disableSchematron = true;
159            }
160            if (line.hasOption(OPT_SCHEMATRON_FILE)) {
161                String name = line.getOptionValue(OPT_SCHEMATRON_FILE);
162                if ((name == null) || name.isEmpty()) {
163                    throw new ParseException("invalid argument for -" +
164                            OPT_SCHEMATRON_FILE);
165                }
166                schematronFile = new File(name);
167            }
168            if (line.hasOption(OPT_CHECK_PIDS)) {
169                checkPids = true;
170            }
171            if (line.hasOption(OPT_CHECK_AND_RESOLVE_PIDS)) {
172                checkAndResolvePids = true;
173            }
174
175            final String[] remaining = line.getArgs();
176            if ((remaining == null) || (remaining.length == 0)) {
177                throw new ParseException("require <DIRECTORY> or <FILE> as " +
178                        "additional command line parameter");
179            }
180
181            final org.apache.log4j.Logger log =
182                    org.apache.log4j.Logger.getLogger(
183                            CMDIValidator.class.getPackage().getName());
184            if (debugging > 0) {
185                appender.setLayout(
186                        new org.apache.log4j.PatternLayout("[%p] %t: %m%n"));
187                if (debugging > 1) {
188                    log.setLevel(org.apache.log4j.Level.TRACE);
189                } else {
190                    log.setLevel(org.apache.log4j.Level.DEBUG);
191                }
192            } else {
193                if (quiet) {
194                    log.setLevel(org.apache.log4j.Level.ERROR);
195                } else {
196                    log.setLevel(org.apache.log4j.Level.INFO);
197                }
198            }
199
200            TFile archive = null;
201            try {
202                if (schemaCacheDir != null) {
203                    logger.info("using schema cache directory: {}", schemaCacheDir);
204                }
205                if (schematronFile != null) {
206                    logger.info("using Schematron schema from file: {}", schematronFile);
207                }
208
209                /*
210                 * process archive
211                 */
212                archive = new TFile(remaining[0]);
213                if (archive.exists()) {
214                    if (archive.isArchive()) {
215                        logger.info("reading archive '{}'", archive);
216                    } else {
217                        logger.info("reading directory '{}'", archive);
218                    }
219
220                    int totalFileCount = -1;
221                    if (estimate && logger.isInfoEnabled()) {
222                        logger.debug("counting files ...");
223                        totalFileCount = countFiles(archive);
224                    }
225
226                    if (threadCount > 1) {
227                      logger.debug("using {} threads", threadCount);
228                    }
229
230
231                    final ValidationHandler handler = new ValidationHandler(verbose);
232
233                    final CMDIValidatorConfig.Builder builder =
234                            new CMDIValidatorConfig.Builder(archive, handler);
235                    if (schemaCacheDir != null) {
236                        builder.schemaCacheDirectory(schemaCacheDir);
237                    }
238                    if (schematronFile != null) {
239                        builder.schematronSchemaFile(schematronFile);
240                    }
241                    if (disableSchematron) {
242                        builder.disableSchematron();
243                    }
244
245                    CheckHandlesExtension checkHandleExtension = null;
246                    if (checkPids || checkAndResolvePids) {
247                        if (checkAndResolvePids) {
248                            logger.info("enabling PID validation (syntax and resolving)");
249                        } else {
250                            logger.info("enabling PID validation (syntax only)");
251                        }
252                        checkHandleExtension =
253                                new CheckHandlesExtension(checkAndResolvePids);
254                        builder.extension(checkHandleExtension);
255                    }
256
257                    final ThreadedCMDIValidatorProcessor processor =
258                            new ThreadedCMDIValidatorProcessor(threadCount);
259                    processor.start();
260                    try {
261                        final CMDIValidator validator =
262                                new CMDIValidator(builder.build());
263                        processor.process(validator);
264
265                        /*
266                         * Wait until validation is done and report about
267                         * progress every now and then ...
268                         */
269                        for (;;) {
270                            try {
271                                if (handler.await(progressInterval)) {
272                                    break;
273                                }
274                            } catch (InterruptedException e) {
275                                /* IGNORE */
276                            }
277                            if ((progressInterval > 0) && logger.isInfoEnabled()) {
278                                final long now = System.currentTimeMillis();
279                                int fps    = -1;
280                                long bps   = -1;
281                                int count  = 0;
282                                long delta = -1;
283                                synchronized (handler) {
284                                    delta = (now - handler.getTimeStarted()) / 1000;
285                                    if (delta > 0) {
286                                        fps = (int) (handler.getTotalFileCount() / delta);
287                                        bps = (handler.getTotalBytes() / delta);
288                                    }
289                                    count = handler.getTotalFileCount();
290                                } // synchronized (result)
291                                if (totalFileCount > 0) {
292                                    float complete = (count / (float)  totalFileCount) * 100f;
293                                    logger.info("processed {} files ({}%) in {} ({} files/second, {}/second) ...",
294                                            count,
295                                            String.format(LOCALE, "%.2f", complete),
296                                            Humanize.duration(delta, LOCALE),
297                                            ((fps != -1) ? fps : "N/A"),
298                                            ((bps != -1) ? Humanize.binaryPrefix(bps, LOCALE) : "N/A MB"));
299                                } else {
300                                    logger.info("processed {} files in {} ({} files/second, {}/second) ...",
301                                            count,
302                                            Humanize.duration(delta, LOCALE),
303                                            ((fps != -1) ? fps : "N/A"),
304                                            ((bps != -1) ? Humanize.binaryPrefix(bps, LOCALE) : "N/A MB"));
305                                }
306                                if (logger.isDebugEnabled()) {
307                                    if ((checkHandleExtension != null) &&
308                                            checkHandleExtension.isResolvingHandles()) {
309                                        final HandleResolver.Statistics stats =
310                                                checkHandleExtension.getStatistics();
311                                        logger.debug("[handle resolver stats] total requests: {}, running requests: {}, cache hits: {}, cache misses: {}, current cache size: {}",
312                                                stats.getTotalRequestsCount(),
313                                                stats.getCurrentRequestsCount(),
314                                                stats.getCacheHitCount(),
315                                                stats.getCacheMissCount(),
316                                                stats.getCurrentCacheSize());
317                                    }
318                                }
319                            }
320                        } // for (;;)
321                    } finally {
322                        processor.shutdown();
323                    }
324
325                    int fps = -1;
326                    long bps = -1;
327                    if (handler.getTimeElapsed() > 0) {
328                        fps = (int) (handler.getTotalFileCount() / handler.getTimeElapsed());
329                        bps = handler.getTotalBytes() / handler.getTimeElapsed();
330                    }
331
332                    logger.info("time elapsed: {}, validation result: {}% failure rate (files: {} total, {} passed, {} failed; {} total, {} files/second, {}/second)",
333                            Humanize.duration(handler.getTimeElapsed(), LOCALE),
334                            String.format(LOCALE, "%.2f", handler.getFailureRate() * 100f),
335                            handler.getTotalFileCount(),
336                            handler.getValidFileCount(),
337                            handler.getInvalidFileCount(),
338                            Humanize.binaryPrefix(handler.getTotalBytes(), LOCALE),
339                            ((fps != -1) ? fps : "N/A"),
340                            ((bps != -1) ? Humanize.binaryPrefix(bps, LOCALE) : "N/A MB"));
341                    logger.debug("... done");
342                } else {
343                    logger.error("not found: {}", archive);
344                }
345            } finally {
346                if (archive != null) {
347                    try {
348                        TVFS.umount(archive);
349                    } catch (FsSyncException e) {
350                        logger.error("error unmounting archive", e);
351                    }
352                }
353            }
354        } catch (CMDIValidatorException e) {
355            logger.error("error initalizing job: {}", e.getMessage());
356            if (debugging > 0) {
357                logger.error(e.getMessage(), e);
358            }
359            System.exit(1);
360        } catch (CMDIValidatorInitException e) {
361            logger.error("error initializing validator: {}", e.getMessage());
362            if (debugging > 0) {
363                logger.error(e.getMessage(), e);
364            }
365            System.exit(2);
366        } catch (ParseException e) {
367            PrintWriter writer = new PrintWriter(System.err);
368            if (e.getMessage() != null) {
369                writer.print("ERROR: ");
370                writer.println(e.getMessage());
371            }
372            HelpFormatter formatter = new HelpFormatter();
373            formatter.printHelp(writer, HelpFormatter.DEFAULT_WIDTH, PRG_NAME,
374                    null, options, HelpFormatter.DEFAULT_LEFT_PAD,
375                    HelpFormatter.DEFAULT_DESC_PAD, null, true);
376            writer.flush();
377            writer.close();
378            System.exit(64); /* EX_USAGE */
379        }
380    }
381
382
383    @SuppressWarnings("static-access")
384    private static Options createCommandLineOptions() {
385        final Options options = new Options();
386        OptionGroup g1 = new OptionGroup();
387        g1.addOption(OptionBuilder
388                .withDescription("enable debugging output")
389                .withLongOpt("debug")
390                .create(OPT_DEBUG));
391        g1.addOption(OptionBuilder
392                .withDescription("enable full debugging output")
393                .withLongOpt("trace")
394                .create(OPT_DEBUG_TRACE));
395        g1.addOption(OptionBuilder
396                .withDescription("be quiet")
397                .withLongOpt("quiet")
398                .create(OPT_QUIET));
399        options.addOptionGroup(g1);
400        options.addOption(OptionBuilder
401                .withDescription("be verbose")
402                .withLongOpt("verbose")
403                .create(OPT_VERBOSE));
404        OptionGroup g2 = new OptionGroup();
405        g2.addOption(OptionBuilder
406                .withDescription("number of validator threads")
407                .hasArg()
408                .withArgName("COUNT")
409                .withLongOpt("threads")
410                .create(OPT_THREAD_COUNT));
411        g2.addOption(OptionBuilder
412                .withDescription("disable threading")
413                .withLongOpt("no-threads")
414                .create(OPT_NO_THREADS));
415        options.addOptionGroup(g2);
416        options.addOption(OptionBuilder
417            .withDescription("disable gathering of total file count for progress reporting")
418            .withLongOpt("no-estimate")
419            .create(OPT_NO_ESTIMATE));
420        options.addOption(OptionBuilder
421                .withDescription("schema caching directory")
422                .hasArg()
423                .withArgName("DIRECTORY")
424                .withLongOpt("schema-cache-dir")
425                .create(OPT_SCHEMA_CACHE_DIR));
426        OptionGroup g3 = new OptionGroup();
427        g3.addOption(OptionBuilder
428                .withDescription("disable Schematron validator")
429                .withLongOpt("no-schematron")
430                .create(OPT_NO_SCHEMATRON));
431        g3.addOption(OptionBuilder
432                .withDescription("load Schematron schema from file")
433                .hasArg()
434                .withArgName("FILE")
435                .withLongOpt("schematron-file")
436                .create(OPT_SCHEMATRON_FILE));
437        options.addOptionGroup(g3);
438        OptionGroup g4 = new OptionGroup();
439        g4.addOption(OptionBuilder
440                .withDescription("check persistent identifiers syntax")
441                .withLongOpt("check-pids")
442                .create(OPT_CHECK_PIDS));
443        g4.addOption(OptionBuilder
444                .withDescription("check persistent identifiers syntax and if they resolve properly")
445                .withLongOpt("check-and-resolve-pids")
446                .create(OPT_CHECK_AND_RESOLVE_PIDS));
447        options.addOptionGroup(g4);
448        return options;
449    }
450
451
452    private static final int countFiles(TFile directory) {
453        int count = 0;
454        final TFile[] entries = directory.listFiles();
455        if ((entries != null) && (entries.length > 0)) {
456            for (TFile entry : entries) {
457                if (entry.isDirectory()) {
458                    count += countFiles(entry);
459                } else {
460                    count++;
461                }
462            }
463        }
464        return count;
465    }
466
467
468    private static class ValidationHandler extends CMDIValidatorHandlerAdapter {
469        private final boolean verbose;
470        private long started     = System.currentTimeMillis();
471        private long finished    = -1;
472        private int filesTotal   = 0;
473        private int filesInvalid = 0;
474        private long totalBytes  = 0;
475        private boolean isCompleted = false;
476        private final Object waiter = new Object();
477
478
479        private ValidationHandler(boolean verbose) {
480            this.verbose = verbose;
481        }
482
483
484        public long getTimeStarted() {
485            return started;
486        }
487
488
489        public long getTimeElapsed() {
490            long duration = (finished != -1)
491                    ? (finished - started)
492                    : (System.currentTimeMillis() - started);
493            return TimeUnit.MILLISECONDS.toSeconds(duration);
494        }
495
496
497        public int getTotalFileCount() {
498            return filesTotal;
499        }
500
501
502        public int getValidFileCount() {
503            return filesTotal - filesInvalid;
504        }
505
506        public int getInvalidFileCount() {
507            return filesInvalid;
508        }
509
510
511        public float getFailureRate() {
512            return (filesTotal > 0)
513                    ? ((float) filesInvalid / (float) filesTotal)
514                    : 0.0f;
515        }
516
517
518        public long getTotalBytes() {
519            return totalBytes;
520        }
521
522
523        public boolean await(long timeout) throws InterruptedException {
524            synchronized (waiter) {
525                if (isCompleted) {
526                    return true;
527                }
528                if (timeout > 0) {
529                    waiter.wait(timeout);
530                } else {
531                    waiter.wait();
532                }
533                return isCompleted;
534            }
535        }
536
537
538        @Override
539        public void onJobStarted() throws CMDIValidatorException {
540            logger.debug("validation process started");
541        }
542
543
544        @Override
545        public void onJobFinished(final CMDIValidator.Result result)
546                throws CMDIValidatorException {
547            finished = System.currentTimeMillis();
548            switch (result) {
549            case OK:
550                logger.debug("validation process finished successfully");
551                break;
552            case ABORTED:
553                logger.info("processing was aborted");
554                break;
555            case ERROR:
556                logger.debug("validation process yielded an error");
557                break;
558            default:
559                logger.debug("unknown result: " + result);
560            } // switch
561
562            synchronized (waiter) {
563                isCompleted = true;
564                waiter.notifyAll();
565            } // synchronized (waiter)
566        }
567
568
569        @Override
570        public void onValidationSuccess(final CMDIValidatorResult result)
571                throws CMDIValidatorException {
572            final File file = result.getFile();
573            synchronized (this) {
574                filesTotal++;
575                if (file != null) {
576                    totalBytes += file.length();
577                }
578            } // synchronized (this) {
579
580            if (result.isHighestSeverity(Severity.WARNING)) {
581                if (verbose) {
582                    logger.warn("file '{}' is valid (with warnings):", file);
583                    for (Message msg : result.getMessages()) {
584                        if ((msg.getLineNumber() != -1) &&
585                                (msg.getColumnNumber() != -1)) {
586                            logger.warn(" ({}) {} [line={}, column={}]",
587                                    msg.getSeverity().getShortcut(),
588                                    msg.getMessage(),
589                                    msg.getLineNumber(),
590                                    msg.getColumnNumber());
591                        } else {
592                            logger.warn(" ({}) {}",
593                                    msg.getSeverity().getShortcut(),
594                                    msg.getMessage());
595                        }
596                    }
597                } else {
598                    Message msg = result.getFirstMessage(Severity.WARNING);
599                    int count   = result.getMessageCount(Severity.WARNING);
600                    if (count > 1) {
601                        logger.warn("file '{}' is valid (with warnings): {} ({} more warnings)",
602                                file, msg.getMessage(), (count - 1));
603                    } else {
604                        logger.warn("file '{}' is valid (with warnings): {}",
605                                file, msg.getMessage());
606                    }
607                }
608            } else {
609                logger.debug("file '{}' is valid", file);
610            }
611        }
612
613
614        @Override
615        public void onValidationFailure(final CMDIValidatorResult result) {
616            final File file = result.getFile();
617            synchronized (this) {
618                filesTotal++;
619                filesInvalid++;
620                if (file != null) {
621                    totalBytes += file.length();
622                }
623            } // synchronized (this)
624
625            if (verbose) {
626            logger.error("file '{}' is invalid:", file);
627                for (Message msg : result.getMessages()) {
628                    if ((msg.getLineNumber() != -1) &&
629                            (msg.getColumnNumber() != -1)) {
630                        logger.error(" ({}) {} [line={}, column={}]",
631                                msg.getSeverity().getShortcut(),
632                                msg.getMessage(),
633                                msg.getLineNumber(),
634                                msg.getColumnNumber());
635                    } else {
636                        logger.error(" ({}) {}",
637                                msg.getSeverity().getShortcut(),
638                                msg.getMessage());
639                    }
640                }
641            } else {
642                Message msg = result.getFirstMessage(Severity.ERROR);
643                int count   = result.getMessageCount(Severity.ERROR);
644                if (count > 1) {
645                    logger.error("file '{}' is invalid: {} ({} more errors)",
646                            file, msg.getMessage(), (count - 1));
647                } else {
648                    logger.error("file '{}' is invalid: {}",
649                            file, msg.getMessage());
650                }
651            }
652        }
653    } // class JobHandler
654
655
656    static {
657        appender = new org.apache.log4j.ConsoleAppender(
658                new org.apache.log4j.PatternLayout("%m%n"),
659                org.apache.log4j.ConsoleAppender.SYSTEM_OUT);
660        org.apache.log4j.BasicConfigurator.configure(appender);
661        org.apache.log4j.Logger logger =
662                org.apache.log4j.Logger.getRootLogger();
663        logger.setLevel(org.apache.log4j.Level.WARN);
664    }
665
666} // class CMDIValidatorTool
Note: See TracBrowser for help on using the repository browser.