Java Code Examples for java.util.logging.LogRecord#setMillis()

/**
 * Append a log event at the appropriate JUL level, depending on the log4j level.
 */
@Override
protected void append(LoggingEvent loggingEvent)
{
    java.util.logging.Logger logger = java.util.logging.Logger.getLogger(loggingEvent.getLoggerName());
    if (logger == null) {
        LogLog.warn(format("Cannot obtain JUL %s. Verify that this appender is used while an appropriate LogManager is active.", loggingEvent.getLoggerName()));
        return;
    }

    Level level = loggingEvent.getLevel();
    java.util.logging.Level julLevel = convertLog4jLevel(level);

    LogRecord record = new LogRecord(julLevel, loggingEvent.getRenderedMessage());
    record.setMillis(loggingEvent.getTimeStamp());
    LocationInfo location = loggingEvent.getLocationInformation();
    if (location != null) {
        record.setSourceClassName(location.getClassName());
        record.setSourceMethodName(location.getMethodName());
    }

    logger.log(record);
}
 

@Test
public void format() {
    final LogRecord record = new LogRecord(Level.FINE, "test message");
    record.setLoggerName("logger");
    record.setLevel(Level.FINER);
    record.setMillis(123456789);
    record.setSourceClassName("my.class.Name");
    record.setSourceMethodName("aMethod");

    // default
    assertEquals(
            "Jan 02, 1970 my.class.Name aMethod\nFINER: test message\n",
            new LocalFileHandler.PatternFormatter("%1$tb %1$td, %1$tY %1$tl:%1$tM:%1$tS %1$Tp %2$s%n%4$s: %5$s%6$s%n", Locale.ENGLISH)
                    .format(record).replace("\r", "").replaceFirst("1970.*my"/*skip time*/, "1970 my"));

    // simple
    assertEquals(
            "test message\n",
            new LocalFileHandler.PatternFormatter("%5$s%n", Locale.ENGLISH).format(record).replace("\r", ""));

    final String custom = new LocalFileHandler.PatternFormatter("%1$tY-%1$tM-%1$td %1$tT [%4$5s][%7$s] %5$s%6$s%n", Locale.ENGLISH)
            .format(record).replace("\r", "");
    assertTrue(custom
            .matches("1970\\-17\\-02 \\p{Digit}+\\:17\\:36 \\[FINER\\]\\[my\\.class\\.Name\\] test message\\\n"));
}
 

/** See {@link #tagValueAt_usageExplained()} */
@Test public void annotationValueAt_usageExplained() {
  TraceContext context = TraceContext.newBuilder().traceId(1L).spanId(2L).build();

  MutableSpan span = new MutableSpan();
  span.annotate(1L, "1");
  span.annotate(2L, "2");
  span.annotate(2L, "2-1");
  span.annotate(3L, "3");

  // Some may want to export data to their logging system under a trace ID/Timestamp
  // While the syntax here isn't precise, it is similar to what one can do with a firehose
  // handler which receives (context, span) inputs.
  Logger logger = Logger.getLogger(getClass().getName());
  for (int i = 0; i < span.annotationCount(); i++) {
    LogRecord record = new LogRecord(Level.FINE, span.annotationValueAt(i));
    record.setParameters(
        new Object[] {context.traceIdString(), context.spanIdString()});
    record.setMillis(span.annotationTimestampAt(i) / 1000L);
    logger.log(record);
  }
}
 

@Test
public void testFormat() {

	LogRecord record = new LogRecord( Level.FINER, "This is an error log message." );
	record.setLoggerName( "my.logger.name" );
	record.setSourceClassName( "my.package.Class" );
	record.setSourceMethodName( "myMethod" );
	record.setMillis( new Date().getTime());

	String s = new RoboconfLogFormatter().format( record );
	Assert.assertEquals( 2, s.split( "\n" ).length );
	Assert.assertTrue( s.contains( "\n" + record.getMessage()));
	Assert.assertTrue( s.startsWith( "[" ));

	String fullName = record.getSourceClassName() + "#" + record.getSourceMethodName() + "\n";
	Assert.assertTrue( s.contains( fullName ));
}
 

private LogRecord eventToRecord(LoggingEvent event, Level julLevel) {
    String format = event.getMessage();
    Object[] arguments = event.getArgumentArray();
    FormattingTuple ft = MessageFormatter.arrayFormat(format, arguments);
    if (ft.getThrowable() != null && event.getThrowable() != null) {
        throw new IllegalArgumentException("both last element in argument array and last argument are of type Throwable");
    }

    Throwable t = event.getThrowable();
    if (ft.getThrowable() != null) {
        t = ft.getThrowable();
        throw new IllegalStateException("fix above code");
    }

    LogRecord record = new LogRecord(julLevel, ft.getMessage());
    record.setLoggerName(event.getLoggerName());
    record.setMillis(event.getTimeStamp());
    record.setSourceClassName(EventConstants.NA_SUBST);
    record.setSourceMethodName(EventConstants.NA_SUBST);

    record.setThrown(t);
    return record;
}
 

@SuppressWarnings("deprecation")  // setMillis is deprecated in JDK 9
protected Object writeReplace() {
	LogRecord serialized = new LogRecord(getLevel(), getMessage());
	serialized.setLoggerName(getLoggerName());
	serialized.setResourceBundle(getResourceBundle());
	serialized.setResourceBundleName(getResourceBundleName());
	serialized.setSourceClassName(getSourceClassName());
	serialized.setSourceMethodName(getSourceMethodName());
	serialized.setSequenceNumber(getSequenceNumber());
	serialized.setParameters(getParameters());
	serialized.setThreadID(getThreadID());
	serialized.setMillis(getMillis());
	serialized.setThrown(getThrown());
	return serialized;
}
 

private static LogRecord logRecord(
    Level level, String message, String loggerName, int tid, long millis) {
  LogRecord result = new LogRecord(level, message);
  result.setLoggerName(loggerName);
  result.setMillis(millis);
  result.setThreadID(tid);
  return result;
}
 

@Test
public void testWithArgumentsAndMetadata() {
  LogData data =
      FakeLogData.withPrintfStyle("Foo='%s'", "bar")
          .setTimestampNanos(123456789000L)
          .addMetadata(COUNT_KEY, 23)
          .addMetadata(ID_KEY, "test ID");

  LogRecord record = SimpleLogRecord.create(data);

  assertThat(record.getLevel()).isEqualTo(Level.INFO);
  assertThat(record.getMessage()).isEqualTo("Foo='bar' [CONTEXT count=23 id=\"test ID\" ]");
  assertThat(record.getParameters()).isNull();
  // Just do this once for sanity checking - it's only for debugging.
  record.setMillis(123456789);
  assertThat(record.toString())
      .isEqualTo(
          "SimpleLogRecord {\n"
              + "  message: Foo='bar' [CONTEXT count=23 id=\"test ID\" ]\n"
              + "  arguments: <none>\n"
              + "  original message: Foo='%s'\n"
              + "  original arguments:\n"
              + "    bar\n"
              + "  metadata:\n"
              + "    count: 23\n"
              + "    id: test ID\n"
              + "  level: INFO\n"
              + "  timestamp (nanos): 123456789000\n"
              + "  class: com.google.FakeClass\n"
              + "  method: fakeMethod\n"
              + "  line number: 123\n"
              + "}");
}
 

private static LogRecord createLogRecord(
    Level level, ZonedDateTime dateTime, RuntimeException thrown) {
  LogRecord record = new LogRecord(level, "some message");
  record.setMillis(dateTime.toInstant().toEpochMilli());
  record.setSourceClassName("SomeSourceClass");
  record.setSourceMethodName("aSourceMethod");
  record.setThreadID(543);
  if (thrown != null) {
    record.setThrown(thrown);
  }
  return record;
}
 

/**
 * Creates and returns a LogRecord with a given message and throwable.
 *
 * @param message The message to place in the {@link LogRecord}
 * @param throwable The throwable to place in the {@link LogRecord}
 * @param params A list of parameters to place in the {@link LogRecord}
 * @return A {@link LogRecord} with the given message and throwable.
 */
private LogRecord createLogRecord(String message, Throwable throwable, Object... params) {
  LogRecord logRecord = new LogRecord(Level.INFO, message);
  logRecord.setLoggerName("LoggerName");
  logRecord.setMillis(1L);
  logRecord.setThreadID(2);
  logRecord.setThrown(throwable);
  logRecord.setParameters(params);
  return logRecord;
}
 

@Subscribe
public void buildStarted(BuildEvent.Started started) {
  LogRecord record = new LogRecord(LEVEL, "Build started");
  record.setMillis(started.getTimestampMillis());
  LOG.log(record);
}
 

private void logViaDelegate(Level level, String msg) {
  LogRecord logRecord = new LogRecord(level, msg);
  logRecord.setMillis(System.currentTimeMillis());
  delegate.publish(logRecord);
}
 

public void endElement(String uri, String localName, String qName) throws SAXException {
    if (current != null) {
        String v = chars.toString();
        values.put(current, v);
        if (current == Elem.PARAM) {
            if (params == null) {
                params = new ArrayList<String>();
            }
            params.add(v);
            if (params.size() > 1500) {
                LOG.severe("Too long params when reading a record. Deleting few. Msg: " + Elem.MESSAGE.parse(values)); // NOI18N
                for (String p : params) {
                    LOG.fine(p);
                }
                params.clear();
            }
        }
    }
    current = null;
    chars = new StringBuilder();
    
    if (currentEx != null && currentEx.values != null) {
        if ("frame".equals(qName)) { // NOI18N
            String line = Elem.LINE.parse(values);
            StackTraceElement elem = new StackTraceElement(
                    Elem.CLASS.parse(values),
                    Elem.METHOD.parse(values),
                    Elem.FILE.parse(values),
                    line == null ? -1 : Integer.parseInt(line)
                    );
            currentEx.trace.add(elem);
            values.remove(Elem.CLASS);
            values.remove(Elem.METHOD);
            values.remove(Elem.LINE);
        }
        if ("exception".equals(qName)) {
            currentEx.message = values.get(Elem.MESSAGE);
            String more = values.get(Elem.MORE);
            if (more != null) currentEx.more = Integer.parseInt(more);
            if (exceptions == null){
                exceptions = new ArrayDeque<FakeException>();
            }
            exceptions.add(currentEx);
            values = currentEx.values;
            currentEx = null;
        }
        return;
    }
    
    if ("record".equals(qName)) { // NOI18N
        String millis = Elem.MILLIS.parse(values);
        String seq = Elem.SEQUENCE.parse(values);
        String lev = Elem.LEVEL.parse(values);
        String thread = Elem.THREAD.parse(values);
        String msg = Elem.MESSAGE.parse(values);
        String key = Elem.KEY.parse(values);
        String catalog = Elem.CATALOG.parse(values);
        
        if (lev != null) {
            LogRecord r = new LogRecord(parseLevel(lev), key != null && catalog != null ? key : msg);
            try {
                r.setThreadID(parseInt(thread));
            } catch (NumberFormatException ex) {
                LOG.log(Level.WARNING, ex.getMessage(), ex);
            }
            r.setSequenceNumber(parseLong(seq));
            r.setMillis(parseLong(millis));
            r.setResourceBundleName(key);
            if (catalog != null && key != null) {
                r.setResourceBundleName(catalog);
                if (!"<null>".equals(catalog)) { // NOI18N
                    try {
                        ResourceBundle b = NbBundle.getBundle(catalog);
                        b.getObject(key);
                        // ok, the key is there
                        r.setResourceBundle(b);
                    } catch (MissingResourceException e) {
                        LOG.log(Level.CONFIG, "Cannot find resource bundle {0} for key {1}", new Object[] { catalog, key });
                        r.setResourceBundle(new FakeBundle(key, msg));
                    }
                } else {
                    LOG.log(Level.CONFIG, "Cannot find resource bundle <null> for key {1}", key);
                }
            }
            if (params != null) {
                r.setParameters(params.toArray());
            }
            if (exceptions != null) {
                r.setThrown(createThrown(null));
                // exceptions = null;  should be empty after poll
            }

            callback.publish(r);
        }

        currentEx = null;
        params = null;
        values.clear();
    }
    
}
 

@Subscribe
public void buildFinished(BuildEvent.Finished finished) {
  LogRecord record = new LogRecord(LEVEL, "Build finished");
  record.setMillis(finished.getTimestampMillis());
  LOG.log(record);
}
 

public static void main(String[] args) throws Exception {

        Locale.setDefault(Locale.ENGLISH);
        LogRecord record = new LogRecord(Level.INFO, "Java Version: {0}");
        record.setLoggerName("test");
        record.setParameters(new Object[] {System.getProperty("java.version")});
        int nanos = getNanoAdjustment(record);
        long millis = record.getMillis();
        // make sure we don't have leading zeros when printing below
        // the second precision
        if (millis % MILLIS_IN_SECOND < 100) millis = millis + 100;
        // make sure we have some nanos
        if (nanos % NANOS_IN_MICRO == 0) nanos = nanos + 999;
        record.setMillis(millis);
        setNanoAdjustment(record, nanos);
        final Instant instant = record.getInstant();
        if (nanos < 0) {
            throw new RuntimeException("Unexpected negative nano adjustment: "
                    + getNanoAdjustment(record));
        }
        if (nanos >= NANOS_IN_MILLI) {
            throw new RuntimeException("Nano adjustment exceeds 1ms: "
                    + getNanoAdjustment(record));
        }
        if (millis != record.getMillis()) {
            throw new RuntimeException("Unexpected millis: " + millis + " != "
                    + record.getMillis());
        }
        if (millis != record.getInstant().toEpochMilli()) {
            throw new RuntimeException("Unexpected millis: "
                    + record.getInstant().toEpochMilli());
        }
        ZonedDateTime zdt = ZonedDateTime.ofInstant(instant, ZoneId.systemDefault());
        int zdtNanos = zdt.getNano();
        long expectedNanos = (millis % MILLIS_IN_SECOND) * NANOS_IN_MILLI + nanos;
        assertEquals(expectedNanos, instant.getNano(), "Instant.getNano()");
        assertEquals(expectedNanos, zdtNanos, "ZonedDateTime.getNano()");
        String match = "."+expectedNanos+" ";

        System.out.println("Testing with default format...");

        SimpleFormatter formatter = new SimpleFormatter();
        String str = formatter.format(record);
        if (str.contains(match)) {
            throw new RuntimeException("SimpleFormatter.format()"
                    + " string contains unexpected nanos: "
                    + "\n\tdid not expect match for: '" + match + "'"
                    + "\n\tin: " + str);
        }

        System.out.println("Nanos omitted as expected: no '"+match+"' in "+str);


        System.out.println("Changing format to print nanos...");
        System.setProperty("java.util.logging.SimpleFormatter.format",
                "%1$tb %1$td, %1$tY %1$tl:%1$tM:%1$tS.%1$tN %1$Tp %2$s%n%4$s: %5$s%6$s%n");

        SimpleFormatter formatter2 = new SimpleFormatter();
        str = formatter2.format(record);
        if (!str.contains(match)) {
            throw new RuntimeException("SimpleFormatter.format()"
                    + " string does not contain expected nanos: "
                    + "\n\texpected match for: '" + match + "'"
                    + "\n\tin: " + str);
        }
        System.out.println("Found expected match for '"+match+"' in "+str);


        System.out.println("Changing format to omit nanos...");
        System.setProperty("java.util.logging.SimpleFormatter.format",
                "%1$tb %1$td, %1$tY %1$tl:%1$tM:%1$tS %1$Tp %2$s%n%4$s: %5$s%6$s%n");

        SimpleFormatter formatter3 = new SimpleFormatter();
        str = formatter3.format(record);
        String notMatch = match;
        if (str.contains(notMatch)) {
            throw new RuntimeException("SimpleFormatter.format()"
                    + " string contains unexpected nanos: "
                    + "\n\tdid not expect match for: '" + notMatch + "'"
                    + "\n\tin: " + str);
        }
        System.out.println("Nanos omitted as expected: no '"+notMatch+"' in "+str);

    }
 

public static void test(Properties props) {
    Configuration conf = Configuration.apply(props);

    LogRecord record = new LogRecord(Level.INFO, "Test Name: {0}");
    record.setLoggerName("test");
    record.setParameters(new Object[] {conf.testName()});
    int nanos = record.getInstant().getNano() % NANOS_IN_MILLI;
    long millis = record.getMillis();
    // make sure we don't have leading zeros when printing below
    // the second precision
    if (millis % MILLIS_IN_SECOND < 100) millis = millis + 100;
    // make sure we some nanos - and make sure we don't have
    // trailing zeros
    if (nanos % 10 == 0) nanos = nanos + 7;

    record.setMillis(millis);
    setNanoAdjustment(record, nanos);
    final Instant instant = record.getInstant();
    if (nanos < 0) {
        throw new RuntimeException("Unexpected negative nano adjustment: "
                + getNanoAdjustment(record));
    }
    if (nanos >= NANOS_IN_MILLI) {
        throw new RuntimeException("Nano adjustment exceeds 1ms: "
                + getNanoAdjustment(record));
    }
    if (millis != record.getMillis()) {
        throw new RuntimeException("Unexpected millis: " + millis + " != "
                + record.getMillis());
    }
    if (millis != record.getInstant().toEpochMilli()) {
        throw new RuntimeException("Unexpected millis: "
                + record.getInstant().toEpochMilli());
    }
    long expectedNanos = (millis % MILLIS_IN_SECOND) * NANOS_IN_MILLI + nanos;
    assertEquals(expectedNanos, instant.getNano(), "Instant.getNano()");

    XMLFormatter formatter = new XMLFormatter();
    testMatching(formatter, record, instant, expectedNanos, conf.useInstant(formatter));

    XMLFormatter custom = new CustomXMLFormatter();
    testMatching(custom, record, instant, expectedNanos, conf.useInstant(custom));
}
 

public void endElement(String uri, String localName, String qName) throws SAXException {
    if (current != null) {
        String v = chars.toString();
        values.put(current, v);
        if (current == Elem.PARAM) {
            if (params == null) {
                params = new ArrayList<String>();
            }
            params.add(v);
            if (params.size() > 1500) {
                LOG.severe("Too long params when reading a record. Deleting few. Msg: " + Elem.MESSAGE.parse(values)); // NOI18N
                for (String p : params) {
                    LOG.fine(p);
                }
                params.clear();
            }
        }
    }
    current = null;
    chars = new StringBuilder();
    
    if (currentEx != null && currentEx.values != null) {
        if ("frame".equals(qName)) { // NOI18N
            String line = Elem.LINE.parse(values);
            StackTraceElement elem = new StackTraceElement(
                    Elem.CLASS.parse(values),
                    Elem.METHOD.parse(values),
                    Elem.FILE.parse(values),
                    line == null ? -1 : Integer.parseInt(line)
                    );
            currentEx.trace.add(elem);
            values.remove(Elem.CLASS);
            values.remove(Elem.METHOD);
            values.remove(Elem.LINE);
        }
        if ("exception".equals(qName)) {
            currentEx.message = values.get(Elem.MESSAGE);
            String more = values.get(Elem.MORE);
            if (more != null) currentEx.more = Integer.parseInt(more);
            if (exceptions == null){
                exceptions = new ArrayDeque<FakeException>();
            }
            exceptions.add(currentEx);
            values = currentEx.values;
            currentEx = null;
        }
        return;
    }
    
    if ("record".equals(qName)) { // NOI18N
        String millis = Elem.MILLIS.parse(values);
        String seq = Elem.SEQUENCE.parse(values);
        String lev = Elem.LEVEL.parse(values);
        String thread = Elem.THREAD.parse(values);
        String msg = Elem.MESSAGE.parse(values);
        String key = Elem.KEY.parse(values);
        String catalog = Elem.CATALOG.parse(values);
        
        if (lev != null) {
            LogRecord r = new LogRecord(parseLevel(lev), key != null && catalog != null ? key : msg);
            try {
                r.setThreadID(parseInt(thread));
            } catch (NumberFormatException ex) {
                LOG.log(Level.WARNING, ex.getMessage(), ex);
            }
            r.setSequenceNumber(parseLong(seq));
            r.setMillis(parseLong(millis));
            r.setResourceBundleName(key);
            if (catalog != null && key != null) {
                r.setResourceBundleName(catalog);
                if (!"<null>".equals(catalog)) { // NOI18N
                    try {
                        ResourceBundle b = NbBundle.getBundle(catalog);
                        b.getObject(key);
                        // ok, the key is there
                        r.setResourceBundle(b);
                    } catch (MissingResourceException e) {
                        LOG.log(Level.CONFIG, "Cannot find resource bundle {0} for key {1}", new Object[] { catalog, key });
                        r.setResourceBundle(new FakeBundle(key, msg));
                    }
                } else {
                    LOG.log(Level.CONFIG, "Cannot find resource bundle <null> for key {1}", key);
                }
            }
            if (params != null) {
                r.setParameters(params.toArray());
            }
            if (exceptions != null) {
                r.setThrown(createThrown(null));
                // exceptions = null;  should be empty after poll
            }

            callback.publish(r);
        }

        currentEx = null;
        params = null;
        values.clear();
    }
    
}
 

/** Calls all delegates. */
public Throwable annotate(
    Throwable t, int severity, String message, final String localizedMessage, Throwable stackTrace,
    java.util.Date date
) {
    if (delegates.isEmpty()) {
        LogRecord rec = new LogRecord(convertSeverity(severity, true, Level.ALL), message);
        if (stackTrace != null) {
            rec.setThrown(stackTrace);
        }
        if (date != null) {
            rec.setMillis(date.getTime());
        }
        if (localizedMessage != null) {
            ResourceBundle rb = new ResourceBundle() {
                public Object handleGetObject(String key) {
                    if ("msg".equals(key)) { // NOI18N
                        return localizedMessage;
                    } else {
                        return null;
                    }
                }
                
                public Enumeration<String> getKeys() {
                    return Enumerations.singleton("msg"); // NOI18N
                }
            };
            rec.setResourceBundle(rb);
            rec.setMessage("msg"); // NOI18N
        }
        
        AnnException ann = AnnException.findOrCreate(t, true);
        if (ann != null) {  //#148778 - Although ann should not be null, it was reported it can happen.
            ann.addRecord(rec);
        }
        
        return t;
    }
    
    for (ErrorManager em : delegates) {
        em.annotate(t, severity, message, localizedMessage, stackTrace, date);
    }

    return t;
}
 

@Subscribe
public void ruleResumed(BuildRuleEvent.Resumed resumed) {
  LogRecord record = new LogRecord(LEVEL, resumed.toString());
  record.setMillis(resumed.getTimestampMillis());
  LOG.log(record);
}
 

@Subscribe
public void ruleFinished(BuildRuleEvent.Finished finished) {
  LogRecord record = new LogRecord(LEVEL, finished.toLogMessage());
  record.setMillis(finished.getTimestampMillis());
  LOG.log(record);
}