System start date #877

jflefebvre06 · 2019-05-28T10:17:15Z

Hello,

Could you please add system start date ?

dbwiddis · 2019-05-28T13:40:43Z

It's possible to add that, but I have a long list of other things I'd like to do first. Can you contribute a PR?

tbradellis · 2019-06-04T00:58:22Z

I'd like to contribute here. Quick question for clarification...Is this system start date in reference to the date the system last started?
For example, mac returns
sysctl kern.boottime
kern.boottime: { sec = 1559582130, usec = 247918 } Mon Jun 3 10:15:30 2019

And, if that's the right Date Time being referenced here....return ms, ns, or seconds and let the caller determine what to do?

spyhunter99 · 2019-06-04T01:14:55Z

just get the up time and subtract. Note on that windows 10 and other os's with a hybrid sleep/shutdown, the dates might not be what you expect

jflefebvre06 · 2019-06-04T10:52:06Z

Hello,

Please find my contribution

public final class SystemUtil {

private static final Pattern MAC_UNIX_PATTERN = Pattern.compile("((\\d+) days,)? (\\d+):(\\d+)");
private static final Object LOCK_GETSYSTEMUPTIME = new Object();
private static final List<String[]> LINUX_COMMANDS = Arrays.asList(new String[] { "who", "-b" }, new String[] { "last reboot | less" }, new String[] { "uptime", "-s" });

private static String systemUptime;

private SystemUtil() {
        super();
    }

public static String getSystemUptime() throws IOException {

        synchronized (LOCK_GETSYSTEMUPTIME) {

            if (systemUptime == null) {

                if (SystemUtils.IS_OS_WINDOWS) {
                    systemUptime = SystemUtil.getSystemUptimeWindows();
                } else if (SystemUtils.IS_OS_UNIX) {
                    systemUptime = SystemUtil.getSystemUptimeUnix();
                } else if (SystemUtils.IS_OS_MAC) {
                    systemUptime = SystemUtil.getSystemUptimeCommonUnixAndMac();
                }

                systemUptime = StringUtils.trimToNull(systemUptime);
            }
        }

        Validate.notBlank(systemUptime, "A ce stade systemUptime ne peut pas être null");

        return systemUptime;
    }

private static String getSystemUptimeWindows() throws IOException {
        return SystemUtil.executeCommands("wmic", "OS", "Get", "LastBootUpTime");
    }

    private static String getSystemUptimeUnix() throws IOException {
String res = null;

        for (final String[] commands : LINUX_COMMANDS) {
            try {
                res = SystemUtil.executeCommands(commands);

                if (StringUtils.isNotBlank(res)) {
                    break;
                }
            } catch (final IOException ioException) {
                // Not available command
            }

        }

        if (StringUtils.isBlank(res)) {
            res = SystemUtil.getSystemUptimeCommonUnixAndMac();
        }

        return res;
    }

    private static String getSystemUptimeCommonUnixAndMac() throws IOException {

        String res = null;

        final Calendar calendar = Calendar.getInstance();

        final String result = SystemUtil.executeCommands("uptime");

        // Sample linux  'uptime' command :
        // 10:37:04 up 17:51, load average: 0.23, 0.88, 0.89
        // 10:38:42 up 17:53, load average: 0.70, 0.81, 0.86
        // 10:28:21 up 189 days, 19:00, 1 user, load average: 0.07, 0.13, 0.16
        // 08:11:22 up 146 days, 34 min, 3 users, load average: 0.28, 0.45, 0.38

        if (StringUtils.isNotBlank(result)) {

            final Matcher matcher = MAC_UNIX_PATTERN.matcher(result);
            if (matcher.find()) {
                final int days = NumberUtils.toInt(matcher.group(2));
                final int hours = NumberUtils.toInt(matcher.group(3));
                final int minutes = NumberUtils.toInt(matcher.group(4));

                calendar.set(Calendar.SECOND, 0);
                calendar.set(Calendar.MILLISECOND, 0);
                calendar.add(Calendar.DAY_OF_MONTH, -1 * days);
                calendar.add(Calendar.HOUR_OF_DAY, -1 * hours);
                calendar.add(Calendar.MINUTE, -1 * minutes);

                res = String.valueOf(calendar.getTimeInMillis());
            }
        }
        return res;
    }

    private static String executeCommands(final String... commands) throws IOException {

        Validate.notEmpty(commands, "commands cannot be empty");

        final Process uptimeProc;

        if (commands.length == 1) {
            uptimeProc = Runtime.getRuntime().exec(commands[0]);
        } else {
            uptimeProc = Runtime.getRuntime().exec(commands);
        }

        try {
            final int exitCode = uptimeProc.waitFor();
            if (exitCode != 0) {
                throw new IOException("Command exited with " + exitCode);
            }
        } catch (final InterruptedException interruptedException) {
            throw new IOException(interruptedException);
        }

        String result = null;

        try (InputStream inputStream = uptimeProc.getInputStream();
                Reader inputStreamReader = new InputStreamReader(inputStream, Charset.defaultCharset());
                BufferedReader bufferedReader = new BufferedReader(inputStreamReader);) {

            String lastLine = null;
            String line;
            while ((line = bufferedReader.readLine()) != null) {

                if (StringUtils.isNotBlank(line)) {
                    lastLine = line.trim();
                }
            }

            if (lastLine != null) {
                result = lastLine;
            }
        }

        return StringUtils.trimToNull(result);

    }

}

It is strange but on unix system, not seems to always return the same date. Not tested on mac.

dbwiddis · 2019-06-04T13:58:48Z

@tbradellis Since this is a new functionality, we get to describe what it is! Putting it the same units as the existing "up time" seems reasonable to me.

@spyhunter99 "Use getSystemUpTime() and subtract from now" is probably a great default to use in the absence of a direct native call. However, given that most OS's have the value available, let's leave this option to the users and try to get it directly.

@jflefebvre06 thanks for the code! There are a few changes you need to make. It would be great if you can put together a PR and submit the code there. You want to:

Create a new method in the CentralProcessor interface
Implement the OS-specific code in the respective <os>CentralProcessor classes.
- For Mac and FreeBSD, the boot time is already calculated internally in the classes as a constant BOOTTIME. Just return that value.
- For other OS's we should create a BOOTTIME constant and populate it the first time using calculations, then return the value.
- For Linux, the btime field in /proc/stat gives boot time.
- For Solaris, there is a kstat unix:0:system_misc:boot_time
- For Windows, rather than command line wmic use the WmiUtil class to execute the query. Use Win32_OperatingSystem rather than OS. I'm on the fence about whether the WMI overhead query is preferable to the default here. Edit: Don't use WMI. Scroll down for an event log solution; probably want "now minus uptime" as a final default if that fails.

tbradellis · 2019-06-04T19:32:18Z

I see! Thanks @dbwiddis. Looks like @jflefebvre06 has put some effort in here so I'll look for something else to work on unless @jflefebvre06 decides otherwise.

dbwiddis · 2019-06-09T00:03:21Z

Hey @jflefebvre06 are you planning on submitting a PR or can @tbradellis take over? :)

dbwiddis · 2019-06-09T00:10:47Z

Based on this StackOverflow post, using WMI boot time is a bad idea. Subtracting up time from current time seems the best option -- that's what we do in WindowsOperatingSystem to calculate the start time of processes, and we could, in fact, find the start time of process 0 this way (but it's probably overkill code-wise vs. subtracting from start time plainly!). Another option is to read the event log (see #631 for a request for code to do that!), with information in the above linked post.

dbwiddis · 2019-06-09T22:09:39Z

Here's the code to read the boot up time from the event log. Reading the log iterating backwards takes 238ms vs. reading it forwards at 410ms... still kinda long.

        long now = System.nanoTime();
        EventLogIterator iter = new EventLogIterator(null, "System", WinNT.EVENTLOG_BACKWARDS_READ);
        long bootTime = 0;
        while (iter.hasNext()) {
            EventLogRecord record = iter.next();
            if (record.getRecord().EventID.getLow().intValue() == 6005) {
                bootTime = record.getRecord().TimeGenerated.longValue();
                break;
            }
        }
        System.out.format("Boot time = %d, elapsed nanos = %d%n", bootTime, System.nanoTime() - now);

Boot time = 1558693023, elapsed nanos = 237697900

Another note: the EventLogRecord does have a getEventId() method on it, but it returns the "Instance ID" which doesn't strip the leading "01" bits defining this as an info record, so we need to directly manipulate the EventID structure element to compare only the rightmost 16 bits.

dbwiddis · 2019-06-09T23:38:41Z

Here's some runtime comparisons of the options:

    enum BootUpProperty {
        LASTBOOTUPTIME;
    }

    private static final WmiQuery<BootUpProperty> BOOTUP_QUERY = new WmiQuery<>(null, BootUpProperty.class);

    public static void main(String[] args) {
        long now = System.nanoTime();
        EventLogIterator iter = new EventLogIterator(null, "System", WinNT.EVENTLOG_BACKWARDS_READ);
        long bootTime = 0;
        while (iter.hasNext()) {
            EventLogRecord record = iter.next();
            if (record.getRecord().EventID.getLow().intValue() == 6005) {
                bootTime = record.getRecord().TimeGenerated.longValue();
                break;
            }
        }
        System.out.format("Boot time = %d, elapsed nanos = %d%n", bootTime, System.nanoTime() - now);

        now = System.nanoTime();
        String foo = ExecutingCommand.getAnswerAt("wmic OS Get LastBootUpTime", 2);
        System.out.format("Boot time = %s, elapsed nanos = %d%n", foo, System.nanoTime() - now);

        BOOTUP_QUERY.setWmiClassName("Win32_OperatingSystem");
        WmiQueryHandler handler = WmiQueryHandler.createInstance();
        now = System.nanoTime();
        WmiResult<BootUpProperty> wmiResult = handler.queryWMI(BOOTUP_QUERY);
        System.out.format("Boot time = %s, elapsed nanos = %d%n", wmiResult.getValue(BootUpProperty.LASTBOOTUPTIME, 0),
                System.nanoTime() - now);

        WindowsCentralProcessor wcp = new WindowsCentralProcessor();
        now = System.nanoTime();
        System.out.format("Boot time = %d, elapsed nanos = %d%n",
                System.currentTimeMillis() - wcp.getSystemUptime() * 1000L,
                System.nanoTime() - now);
    }

Boot time = 1558693023, elapsed nanos = 229412300
Boot time = 20190524222529.667000-420 , elapsed nanos = 202901400
Boot time = 20190524222529.667000-420, elapsed nanos = 84453900
Boot time = 1558758099164, elapsed nanos = 120300

I kind of like the last one, with simple subtraction, but unfortunately it appears that it loses a lot of time with sleep/hibernate cycles. It's at least close to the WMI time. The Event Log time is probably the most accurate, though, if we can afford the longer (229 ms) read time.

dbwiddis · 2019-06-10T07:41:58Z

More fun. Event ID 12 is actually the OS start up time, but doesn't always occur if Windows "Fast Startup" is enabled.

So the strategy should be to check for event id's 6005 or 12. When iterating backwards, find the first 6005; if a 12 exists before the next 6005, use it; otherwise use the first 6005.

dbwiddis · 2019-06-10T17:30:01Z

Here's my recommended code for Windows. Runs in about 200ms.

    public static void main(String[] args) {
        boolean found = false;
        long now = System.nanoTime();
        EventLogIterator iter = new EventLogIterator(null, "System", WinNT.EVENTLOG_BACKWARDS_READ);
        long bootTime = 0;
        while (iter.hasNext()) {
            EventLogRecord record = iter.next();
            if (record.getRecord().EventID.getLow().intValue() == 6005) {
                if (found) {
                    // Didn't find EventID 12, return first 6005
                    break;
                }
                // First 6005; tentatively assign and look for EventID 12
                bootTime = record.getRecord().TimeGenerated.longValue();
                found = true;
            } else if (found && record.getRecord().EventID.getLow().intValue() == 12) {
                // First 12 after 6005, this is boot time
                bootTime = record.getRecord().TimeGenerated.longValue();
                break;
            }
        }
        System.out.format("Boot time = %d, elapsed nanos = %d%n", bootTime, System.nanoTime() - now);
    }

dbwiddis · 2019-07-10T17:10:17Z

@tbradellis This looks like no one else is going to do it, do you want to tackle it?

shannondavid · 2019-07-18T18:55:13Z

@dbwiddis, I submitted a pull request (#910). Please let me know if there is anything I should change.

jflefebvre06 · 2019-10-10T12:14:33Z

Hello

On windows it does not work.

final Date systemBootDate = new Date(TimeUnit.SECONDS.toMillis(systemInfo.getOperatingSystem().getSystemBootTime()));

systemBootDate value is 'Wed Oct 09 15:54:18 CEST 2019'
but I start my desktop today (Thu Oct 10) at 7:30 am

My computer is a Windows 7 French.

dbwiddis · 2019-10-10T13:56:27Z

Was it a full system boot or a reboot/wake from sleep?

OSHI reads the event log. What system events happened at 07:30?

jflefebvre06 · 2019-10-10T14:40:52Z

Sorry not 07:30 but 07:54, I m wake up not early today :)

Nom du journal :System
Source : Microsoft-Windows-Kernel-General
Date : 10/10/2019 07:54:41
ID de l’événement :12
Catégorie de la tâche :Aucun
Niveau : Information
Mots clés :
Utilisateur : Système
Ordinateur : ITEM-66489.XXX
Description :
Le système d’exploitation a démarré à l’heure système ‎2019‎-‎10‎-‎10T05:54:41.125599400Z.
XML de l’événement :

<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
  <System>
    <Provider Name="Microsoft-Windows-Kernel-General" Guid="{A68CA8B7-004F-D7B6-A698-07E2DE0F1F5D}" />
    <EventID>12</EventID>
    <Version>0</Version>
    <Level>4</Level>
    <Task>0</Task>
    <Opcode>0</Opcode>
    <Keywords>0x8000000000000000</Keywords>
    <TimeCreated SystemTime="2019-10-10T05:54:41.687200300Z" />
    <EventRecordID>1424860</EventRecordID>
    <Correlation />
    <Execution ProcessID="4" ThreadID="8" />
    <Channel>System</Channel>
    <Computer>ITEM-66489.XXX</Computer>
    <Security UserID="S-1-5-18" />
  </System>
  <EventData>
    <Data Name="MajorVersion">6</Data>
    <Data Name="MinorVersion">1</Data>
    <Data Name="BuildVersion">7601</Data>
    <Data Name="QfeVersion">24441</Data>
    <Data Name="ServiceVersion">1</Data>
    <Data Name="BootMode">0</Data>
    <Data Name="StartTime">2019-10-10T05:54:41.125599400Z</Data>
  </EventData>
</Event>

dbwiddis · 2019-10-10T16:16:47Z

07:54:41 for a boot time (event 12) should be what OSHI captures. And given that your Date conversion is an xx:54:xx value I'm suspicious about time zone conversions -- but also am wondering why OSHI would have an :18 vs. the :41.

Looking at the code I can't see a problem with the assignment of boot time from the event log record, but it's possible that it's using the fallback calculation of "now minus uptime". Looking carefully at the logic it seems to require we find an event 6005 before (chronologically "after") the event 12, per my comment above:

More fun. Event ID 12 is actually the OS start up time, but doesn't always occur if Windows "Fast Startup" is enabled.

So the strategy should be to check for event id's 6005 or 12. When iterating backwards, find the first 6005; if a 12 exists before the next 6005, use it; otherwise use the first 6005.

It seems the case isn't handled where we have a 12 but no 6005. So that's one bug.

The other bug may be in the calculation of UpTime... has your system been hibernating for about 7 hours? If so this is probably not the issue...

jflefebvre06 · 2019-10-10T16:29:51Z

hello @dbwiddis
No my system not have hibernated, hybernation is not activated on my desktop

jflefebvre06 · 2019-10-10T16:38:32Z

I have reboot my workstation at 17:18

Nom du journal :System
Source : Microsoft-Windows-Kernel-General
Date : 10/10/2019 17:18:01
ID de l’événement :12
Catégorie de la tâche :Aucun
Niveau : Information
Mots clés :
Utilisateur : Système
Ordinateur : ITEM-66489.dhcp.nice.fr.sopra
Description :
Le système d’exploitation a démarré à l’heure système ‎2019‎-‎10‎-‎10T15:18:01.125599400Z.
XML de l’événement :

<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
  <System>
    <Provider Name="Microsoft-Windows-Kernel-General" Guid="{A68CA8B7-004F-D7B6-A698-07E2DE0F1F5D}" />
    <EventID>12</EventID>
    <Version>0</Version>
    <Level>4</Level>
    <Task>0</Task>
    <Opcode>0</Opcode>
    <Keywords>0x8000000000000000</Keywords>
    <TimeCreated SystemTime="2019-10-10T15:18:01.718400400Z" />
    <EventRecordID>1425242</EventRecordID>
    <Correlation />
    <Execution ProcessID="4" ThreadID="8" />
    <Channel>System</Channel>
    <Computer>ITEM-66489.dhcp.nice.fr.sopra</Computer>
    <Security UserID="S-1-5-18" />
  </System>
  <EventData>
    <Data Name="MajorVersion">6</Data>
    <Data Name="MinorVersion">1</Data>
    <Data Name="BuildVersion">7601</Data>
    <Data Name="QfeVersion">24441</Data>
    <Data Name="ServiceVersion">1</Data>
    <Data Name="BootMode">0</Data>
    <Data Name="StartTime">2019-10-10T15:18:01.125599400Z</Data>
  </EventData>
</Event>

And now oshi give System boot time 1570686885

System boot time : [1570686885]
System boot date : [Thu Oct 10 07:54:45 CEST 2019]

jflefebvre06 · 2019-10-11T03:19:16Z

Launch just after wy worksation boot :

System boot time : [1570720685]
System boot date : [Thu Oct 10 17:18:05 CEST 2019]
Current time : [1570763794980]
Current date : [Fri Oct 11 05:16:34 CEST 2019]

dbwiddis · 2019-10-11T03:20:21Z

OK, I did some testing on my own machine and have similar symptoms, identified by the bug I already identified.

Looking carefully at the logic it seems to require we find an event 6005 before (chronologically "after") the event 12, per my comment above

You'll notice after your reboot (17:18) that OSHI identified the previous boot (7:54:45). (And in the one you just posted after this morning's new boot it got yesterday's 17:18 boot.) . The bug is that it's lagging a reboot behind in some cases. It appears in the event log that even though the "Event Log Service Startup" event (6005) occurs after the boot, these particular events are not necessarily reported in chronological order. In my event log, the Boot event (12) occurs first but is logged later.

So the fix is to change the logic from identifying a 6005 "first" and then a 12... it needs to be robust to different ordering.

dbwiddis · 2019-10-11T05:20:20Z

Bug should be fixed in #1013, now in snapshot. (Re-)Closing this issue, re-open if you still have problems.

jflefebvre06 · 2019-10-11T05:32:45Z

Please find my test case below, not very fast but works fine

@EnabledOnOs(OS.WINDOWS)
    @Test
    public void getSystemBootTimeTestWindows() {

        final EventLogIterator iter = new EventLogIterator(null, "System", WinNT.EVENTLOG_BACKWARDS_READ);

        final Optional<Long> time = StreamSupport.stream(Spliterators.spliteratorUnknownSize(iter, 0), true).filter(r -> r.getRecord().EventID.getLow().intValue() == 12)
                .map(r -> r.getRecord().TimeGenerated.longValue()).max(Comparator.naturalOrder());

        MatcherAssert.assertThat("Time found", time.isPresent());
        MatcherAssert.assertThat("Is valid systemBootTime", SystemUtil.getSystemBootTime(), Matchers.equalTo(time.get()));
    }

dbwiddis · 2019-10-11T05:38:53Z

Not fast because you read the entire event log to collect all the event 12s. :) Try enabling fast startup on Win10 and see if your test case still works...

jflefebvre06 · 2019-10-11T05:39:36Z

Yes I Know

dbwiddis added good first issue Good issues for new contributors to work on new feature Something OSHI doesn't do now but could do labels May 28, 2019

dbwiddis mentioned this issue Jul 17, 2019

DetectVM - Wrong comparison of result #908

Closed

dbwiddis closed this as completed in d551002 Jul 25, 2019

dbwiddis reopened this Oct 10, 2019

dbwiddis added bug? Might be a bug but need more information and removed good first issue Good issues for new contributors to work on labels Oct 10, 2019

dbwiddis removed the bug? Might be a bug but need more information label Oct 11, 2019

dbwiddis added the confirmed bug Confirmed bugs. Highest priority to fix. label Oct 11, 2019

dbwiddis mentioned this issue Oct 11, 2019

Fix boot time calculation #1013

Merged

dbwiddis removed the confirmed bug Confirmed bugs. Highest priority to fix. label Oct 11, 2019

dbwiddis closed this as completed Oct 11, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

System start date #877

System start date #877

jflefebvre06 commented May 28, 2019

dbwiddis commented May 28, 2019

tbradellis commented Jun 4, 2019

spyhunter99 commented Jun 4, 2019

jflefebvre06 commented Jun 4, 2019

dbwiddis commented Jun 4, 2019 •

edited

tbradellis commented Jun 4, 2019

dbwiddis commented Jun 9, 2019

dbwiddis commented Jun 9, 2019

dbwiddis commented Jun 9, 2019 •

edited

dbwiddis commented Jun 9, 2019 •

edited

dbwiddis commented Jun 10, 2019

dbwiddis commented Jun 10, 2019

dbwiddis commented Jul 10, 2019

shannondavid commented Jul 18, 2019

jflefebvre06 commented Oct 10, 2019

dbwiddis commented Oct 10, 2019

jflefebvre06 commented Oct 10, 2019

dbwiddis commented Oct 10, 2019

jflefebvre06 commented Oct 10, 2019

jflefebvre06 commented Oct 10, 2019

jflefebvre06 commented Oct 11, 2019

dbwiddis commented Oct 11, 2019 •

edited

dbwiddis commented Oct 11, 2019

jflefebvre06 commented Oct 11, 2019

dbwiddis commented Oct 11, 2019

jflefebvre06 commented Oct 11, 2019

System start date #877

System start date #877

Comments

jflefebvre06 commented May 28, 2019

dbwiddis commented May 28, 2019

tbradellis commented Jun 4, 2019

spyhunter99 commented Jun 4, 2019

jflefebvre06 commented Jun 4, 2019

dbwiddis commented Jun 4, 2019 • edited

tbradellis commented Jun 4, 2019

dbwiddis commented Jun 9, 2019

dbwiddis commented Jun 9, 2019

dbwiddis commented Jun 9, 2019 • edited

dbwiddis commented Jun 9, 2019 • edited

dbwiddis commented Jun 10, 2019

dbwiddis commented Jun 10, 2019

dbwiddis commented Jul 10, 2019

shannondavid commented Jul 18, 2019

jflefebvre06 commented Oct 10, 2019

dbwiddis commented Oct 10, 2019

jflefebvre06 commented Oct 10, 2019

dbwiddis commented Oct 10, 2019

jflefebvre06 commented Oct 10, 2019

jflefebvre06 commented Oct 10, 2019

jflefebvre06 commented Oct 11, 2019

dbwiddis commented Oct 11, 2019 • edited

dbwiddis commented Oct 11, 2019

jflefebvre06 commented Oct 11, 2019

dbwiddis commented Oct 11, 2019

jflefebvre06 commented Oct 11, 2019

dbwiddis commented Jun 4, 2019 •

edited

dbwiddis commented Jun 9, 2019 •

edited

dbwiddis commented Jun 9, 2019 •

edited

dbwiddis commented Oct 11, 2019 •

edited