nastel / tnt4j Goto Github PK

In method tryObtain, if not throttling based on bytes, or if not exceeding byte rate, it falls to call to mpsLimiter.tryAcquire, but does not save return of this call, so tryObtain will always return true. Below is a snippit from method tryObtain(int msgs, int bytes, long timeout, TimeUnit unit) (comments mine):

if (bytes > 0) {
    // throttling based on bytes, so see if would be blocked
    permit = bpsLimiter.tryAcquire(bytes, timeout, unit);
}
if (msgs > 0 && !permit) {
    // throttling based on messages, and would be throttled based on bytes,
    // check if would be throttled based on messages, setting permit to true if not being
    // throttled based on messages
    permit = permit || mpsLimiter.tryAcquire(msgs, timeout, unit);
} else if (msgs > 0) {
    // If we reach here, either not throttling based on bytes, or have
    // not exceeded byte rate, but throttling based on messages.
    // *** We are not saving return of tryAcquire, so whether or not
    //     we would have been throttled, it returns default value of
    //     permit (true).  Think it should be:  permit = mpsLimiter.tryAcquire(msgs);
    mpsLimiter.tryAcquire(msgs);
}

obtain(int msgs, int bytes) has a similar issue, in that if not throttling based on bytes or not exceeding bytes rate, then it does not count the delay time for messages (in fact, it's calling tryAcquire instead of acquire, so it does not throttle at all). try/finally in obtain should simply be:

if (!isEnabled() || (msgs == 0 && bytes == 0)) {
    return 0;
}
delayTimeSec = (bytes > 0 ? bpsLimiter.acquire(bytes) : 0);
delayTimeSec += (msgs > 0 ? mpsLimiter.acquire(msgs) : 0);

Finally, the logic between tryObtain and obtain seems inconsistent when throttling based on both messages and bytes. tryObtain returns flag indicating there would be no delay if not exceeding either limit, but obtain returns sum of both delays, indicating that there is a delay if exceeding either. Seems like following snippit in tryObtain:
permit || mpsLimiter.tryAcquire
should be:
permit && mpsLimiter.tryAcquire
or simply just drop the permit || all together.

java.lang.NullPointerException
at com.nastel.jkool.tnt4j.utils.Utils.getMethodNameFromStack(Utils.java:535)
at com.nastel.jkool.tnt4j.core.Operation.getResolvedName(Operation.java:155)
at com.nastel.jkool.tnt4j.format.JSONFormatter.format(JSONFormatter.java:181)
at com.nastel.jkool.tnt4j.format.JSONFormatter.format(JSONFormatter.java:107)
at com.nastel.jkool.tnt4j.sink.FileSink.write(FileSink.java:126)
at com.nastel.jkool.tnt4j.sink.FileEventSink._log(FileEventSink.java:97)
at com.nastel.jkool.tnt4j.sink.AbstractEventSink.log(AbstractEventSink.java:414)
at com.jkool.jesl.tnt4j.sink.JKCloudEventSink._log(JKCloudEventSink.java:231)
at com.nastel.jkool.tnt4j.sink.AbstractEventSink.log(AbstractEventSink.java:414)
at com.nastel.jkool.tnt4j.tracker.TrackerImpl.reportEvent(TrackerImpl.java:190)
at com.nastel.jkool.tnt4j.tracker.TrackerImpl.tnt(TrackerImpl.java:443)
at com.nastel.jkool.tnt4j.TrackingLogger.tnt(TrackingLogger.java:838)
at com.jkool.tnt4j.streams.fields.ActivityInfo.recordActivity(ActivityInfo.java:512)
at com.jkool.tnt4j.streams.inputs.TNTInputStream.processActivityItem(TNTInputStream.java:857)
at com.jkool.tnt4j.streams.inputs.TNTInputStream.run(TNTInputStream.java:777)
at java.lang.Thread.run(Thread.java:745)

It seems that the usec portion of time stamp is being printed twice, for example:

2020-01-13 10:40:15.018593593 EST

notice the usecs 593 is printed a second time

Noticed with toString() method. Using toString("yyyy-MM-dd HH:mm:ss.SSSSSS XXX") works fine.

When logging UsecTimestamps, the values are formatted as longs instead of date strings. For example, calling:

logger.info("{0}", UsecTimestamp.now());

the value is formatted as a long (e.g. 1583166154000000) instead of a date/time string (e.g. 2020-03-02 11:22:34.000000)

Note that UsecTimestamp extends java.lang.Number. May a clue as to why. This was not the behavior in release 2.11.

In tnt4j.properties, have the ability to have multiple, possibly disjoint source specifications in a single stanza so that all the sources share the same config. Otherwise, have to copy the stanza multiple times, once for each source.

Another possible solution would be to have something like a source template, which would define template configurations, then the individual source stanzas would just reference the template.

Provider a way to obtain all active loggers within JVM. This would allow develoeprs to see all allocated loggers, get their statistics, access other loggers without knowing instances explicitly.

Have the following Eclipse warning:

The field FileDumpSink.formatter is hiding a field from type FileSink in: /tnt4j/src/main/java/com/jkoolcloud/tnt4j/dump/FileDumpSink.java line 36

I would think that child class wants to use member defined in parent class.

To see these types of warnings, need to set the following Eclipse preference to not ignore it (I set it to Warning):

Java=>Compiler=>Errors/Warnings: Name shadowing and conflicts=>Field declaration hides another field or variable

Probably a good idea if everyone set this to Warning, since in most cases this is unintended behavior.

TrackingActivity spanning multiple threads (start/stop in different) threads reports wrong JVM metrics. thread specific CPU timing maybe negative or completely off since metrics are computed based on CPU timing from differrent threads.

If java Applcation with "tnt4j.properties" like below values
"event.sink.factory: com.nastel.jkool.tnt4j.sink.BufferedEventSinkFactory" -- (It is a default value in JESL package), data may not be inserted into the target due to closing connection before handling data process.

TNT4J initialization fails, with:

Caused by: java.lang.NullPointerException
at com.nastel.jkool.tnt4j.utils.TimeService.(TimeService.java:58)

which is caused by system property " tnt4j.time.server" not being set.

logger.debug("test {0}", arg) JSONFormatter does not resolve msg arguments. The message output does not resolve {0} with arg.

Add support for NTP time synchronization when logging events. This would be useful when log entries must be sequenced and correlated in time across multiple servers.

Describe the bug
When UsecTimestamp is converted to timestamp string and UTC timezone is used, timestamp is invalid.
The timezone part is 00:00, but it should have + or - sign according to specification.

To Reproduce
Run this code:
UsecTimestamp ts = new UsecTimestamp(1652777518123L, 456);
System.out.println(ts.toString("yyyy-MM-dd HH:mm:ss.SSSSSS XXX", TimeZone.getTimeZone("UTC"), Locale.US));
Prints:
2022-05-17 08:51:58.123456 00:00

Expected behavior
Should print:
2022-05-17 08:51:58.123456 +00:00

When using BufferedSink, it appears that the log call is being processed by a thread other then the calling thread, which leads to a chance that the object involved in the log call is being concurrently accessed by multiple threads. If the object's toString method involves iterating through a Collection, then it's possible for a ConcurrentModificationException.

Seems like the correct solution is for the string to be generated in the log call itself, so that it's done in the thread making the log call (or course after checking all necessary log levels and tokens), and it would be the string representation of the object that is being "buffered" for later writing to sink.

We're seeing errors loading tnt4j.properties in java applications, complaining that it can't be found as a resource.

ERROR - Unable to load configuration: source=com.nastel.jkool.db.ui.DBConnectionDialog, file=tnt4j.properties | ERROR | 2018-04-18 10:34:00.577000 EDT | RUNTIME=37704@xman2#SERVER=xman2#NETADDR=192.168.181.77#DATACENTER=UNKNOWN#GEOADDR=0,0
java.io.FileNotFoundException: Resource '/tnt4j.properties' not found

Seems to be related to latest change to TrackerConfigStore.java, b75f769. in particular:

-		String tnt4jResource = "/" + TNT4J_PROPERTIES;
-		InputStream ins = getClass().getClassLoader().getResourceAsStream(tnt4jResource);

to

+		String tnt4jResource = TNT4J_PROPERTIES;
+		InputStream ins = Utils.getResourceAsStream(TrackerConfigStore.class, tnt4jResource);

without the leading "/", it does not find the file.

Had to work around it by defining tnt4j.config system property.

Currently, tracking event timestamps are reported in microsecond resolution, using UsecTimestamp class to maintain them. However, for Properties, it uses java.util.Date objects to hold timestamp, which is only in millisecond resolution.

Property class should use UsecTimestamp instead of java.util.Date. If property is created with a java.util.Date object, it should convert it to a UsecTimestamp.

NullPointerException when tnt4j,properties is missing or not found. Exception thrown below:

Exception in thread "main" java.lang.NullPointerException
        at com.nastel.jkool.tnt4j.config.TrackerConfigStore.loadProperties(TrackerConfigStore.java:200)
        at com.nastel.jkool.tnt4j.config.TrackerConfigStore.loadConfigProps(TrackerConfigStore.java:180)
        at com.nastel.jkool.tnt4j.config.TrackerConfigStore.<init>(TrackerConfigStore.java:166)
        at com.nastel.jkool.tnt4j.config.TrackerConfigStore.<init>(TrackerConfigStore.java:151)
        at com.nastel.jkool.tnt4j.config.TrackerConfigStore.<init>(TrackerConfigStore.java:127)
        at com.nastel.jkool.tnt4j.config.ConfigFactoryStoreImpl.getConfig(ConfigFactoryStoreImpl.java:51)
        at com.nastel.jkool.tnt4j.examples.TNT4JTest.main(TNT4JTest.java:76)

Would be useful to have a function, similar to tryAcquire, that would return the delay that would be used if actually applying limiting.

Essentially, this would be the current obtain method, but without the actual internal sleep calls.