Howdy, am seeing some strange behaviour with this ...
# lucee
a
Howdy, am seeing some strange behaviour with this code: https://trycf.com/gist/a1bc621e3bf5a7eb3945910e43e8efee/lucee5?theme=monokai [will explain in a thread, pls hold...]
Copy code
timeInMillisecondsAtStartup = CreateObject("java", "lucee.loader.engine.CFMLEngineFactory").getInstance().uptime()
timeInMillisecondsNow = getTickCount()

uptimeInMilliseconds = timeInMillisecondsNow - timeInMillisecondsAtStartup

uptimeInMillisecondsAsDuration = convertMillisecondsToDuration(uptimeInMilliseconds)

writeOutput(uptimeInMillisecondsAsDuration)


function convertMillisecondsToDuration(ms) {
    var s = int(ms / 1000)
    var m = int(s / 60)
    var h = int(m / 60)
    var d = int(h / 24)
    
    return 
        "#numberFormat(d, "00")#"
        & ":#numberFormat(h % 24, "00")#"
		& ":#numberFormat(m % 60, "00")#"
		& ":#numberFormat(s % 60, "00")#"
}
This outputs something like
23:11:57:09
90% of the time it works fine. Periodically, it will return a much lower value, eg
00:00:12:56
Then it will return to emitting the correct value We see this after an application reload (just running
onApplicationStart
directly, not an actual "app restart"). However this could be confirmation bias at work: we have two pieces of code running this, one ad hoc (always correct), one as part of the code that runs from
onApplicationStart
running; if it reports wrong, it's always the latter that does it, but the latter doesn't always do it. If after seeing it wrong on the app-start code, I check the ad-hoc code, it's still reporting wrong. It is not some wayward var scoping issue; the code seems sound to me. We have only one Lucee instance in the container. We see it happening on multiple single-instance-Lucee-containers (ie: it's not just one isolated box doing it). All of these containers are running the same Docker image / codebase. Any ideas what might be going on? Does this ring any bells with anyone? Don't sink any time into investigating, I can do that, I am just checking if anyone already knows "ah yeah that happens cos x" (long odds on that I know). Cheers.
d
Any idea if it's the uptime() or getTickCount() returning unexpected issues? My guess is it's the uptime(). I wonder if it's not really at the server level, but at the app level and triggering the onApplicationStart is causing it to reset the value.
a
I have not dug into it yet. I can't replicate locally, and to put telemetry on prod I'd need to raise a ticket, prioritise it, waste a dev's time etc; and currently it's only "annoying" rather than an actual problem.
d
I'd take a look at the source code and see where uptime() is coming from and trace it from there. I bet the onApplicationStart() is somehow resetting that value.
Are you wanting the server uptime or the application's uptime?
We use this to get the JVM uptime: createObject("java", "java.lang.management.ManagementFactory").getRuntimeMXBean().getUptime()
a
The application server's uptime (as distinct from the metal's uptime which we already have), and the application's own uptime (which we also already have). It's for a status page (always reports correctly) / error email (is the one that reports wrong sometimes)
NB: I link tot he implementation of
uptime
in the the trycf gist, but it's:
Copy code
/*
* <https://github.com/lucee/Lucee/blob/5.3.9.166/core/src/main/java/lucee/runtime/engine/CFMLEngineImpl.java#L410>
* 	this.uptime = System.currentTimeMillis();
*
* <https://github.com/lucee/Lucee/blob/5.3.9.166/core/src/main/java/lucee/runtime/engine/CFMLEngineImpl.java#L1612-L1614>
* 	public long uptime() {
*		return uptime;
*	}
*/
Thanks for the tip re
.getRuntimeMXBean().getUptime()
. This is more what I'd want us to use anyhow (I inherited this code).
d
We've been using getRuntimeMXBean().getUptime() and it has seemed reliable for us across ACF & Lucee
✅ 1