How do I add timestamps to individual lines of PowerShell & output?

Question

How, if at all, is it possible to add timestamps to each line of an output generated by the & PowerShell operator?

Example:

PS H:\> $result = & ping 192.168.1.1
PS H:\> echo $result

Pinging 192.168.1.1 with 32 bytes of data:
Reply from 192.168.1.1: bytes=32 time=104ms TTL=250
Reply from 192.168.1.1: bytes=32 time=106ms TTL=250
Reply from 192.168.1.1: bytes=32 time=102ms TTL=250
Reply from 192.168.1.1: bytes=32 time=102ms TTL=250
Ping statistics for 192.168.1.1:
Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
Minimum = 102ms, Maximum = 106ms, Average = 103ms

Desired result:

PS H:\> echo $result

2014-12-08T14:45:48.8898125+00:00:Pinging 192.168.1.1 with 32 bytes of data:
2014-12-08T14:45:48.8932661+00:00:Reply from 192.168.1.1: bytes=32 time=104ms TTL=250
2014-12-08T14:45:48.9233451+00:00:Reply from 192.168.1.1: bytes=32 time=106ms TTL=250
2014-12-08T14:45:48.9765438+00:00:Reply from 192.168.1.1: bytes=32 time=102ms TTL=250
2014-12-08T14:45:49.0233105+00:00:Reply from 192.168.1.1: bytes=32 time=102ms TTL=250
2014-12-08T14:45:49.0233201+00:00:
2014-12-08T14:45:49.0238753+00:00:Ping statistics for 192.168.1.1:
2014-12-08T14:45:49.0239210+00:00:    Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
2014-12-08T14:45:49.0233318+00:00:Approximate round trip times in milli-seconds:
2014-12-08T14:45:49.0237209+00:00:    Minimum = 102ms, Maximum = 106ms, Average = 103ms

I know how to split / join a PowerShell array, but this can only happen AFTER the & operator completes. I am looking for more realtime-like solution, where timestamps are added to the output while the & operator is running.

By the way, the timestamp itself is $($(Get-Date -Format o) + ":")

Solution 1

You could use a filter:

filter timestamp {"$(Get-Date -Format o): $_"}
$result = & ping 192.168.1.1 | timestamp

Sample output from $result:

2014-12-08T11:42:59.2827202-05:00: 
2014-12-08T11:42:59.2857205-05:00: Pinging 192.168.1.1 with 32 bytes of data:
2014-12-08T11:43:03.1241043-05:00: Request timed out.
2014-12-08T11:43:08.1236042-05:00: Request timed out.
2014-12-08T11:43:13.1241042-05:00: Request timed out.
2014-12-08T11:43:18.1246042-05:00: Request timed out.
2014-12-08T11:43:18.1246042-05:00: 
2014-12-08T11:43:18.1246042-05:00: Ping statistics for 192.168.1.1:
2014-12-08T11:43:18.1246042-05:00:     Packets: Sent = 4, Received = 0, Lost = 4 (100% loss),

Solution 2

For anyone that is looking for more information on filter, here is the documentation. It was surprising difficult to find since searching any combination of the word "filter" and "powershell" will give a million examples and no documentation. Also help filter in powershell provides no obvious help either.

The answer provided by mjolinor is the best way to do something like this, but I wanted to expand on it.

filter timestamp {"$(Get-Date): $_"}

Is a shortcut for calling this

function timestamp { Process{"$(Get-Date): $_"} }

Both of these create named functions that accept input from the pipeline. Run help pipline in powershell to learn more. The pipeline will operate on a single object at a time, and that object can be referred to with the automatic variable $_. So each function will iterate over every item in the pipeline that was piped to it using the | pipe character.

This behaves differently than a normal function in that it's working on the objects as they arrive, instead of all at once. For example running

function timestamp {
        "$(Get-Date): $input"
}
$result = & ping 127.0.0.1
$result | timestamp

Would dump the entire $result object on a single line and result in a response that looks like this

03/14/2018 15:23:16:  Pinging 127.0.0.1 with 32 bytes of data: Reply from 127.0.0.1: b
ytes=32 time<1ms TTL=128 Reply from 127.0.0.1: bytes=32 time<1ms TTL=128 Reply from 12
7.0.0.1: bytes=32 time<1ms TTL=128 Reply from 127.0.0.1: bytes=32 time<1ms TTL=128  Pi
ng statistics for 127.0.0.1:     Packets: Sent = 4, Received = 4, Lost = 0 (0% loss), 
Approximate round trip times in milli-seconds:     Minimum = 0ms, Maximum = 0ms, Avera
ge = 0ms

Since the function is operating on the object as a whole you would have to iterate over each line. Changing it to this

function timestampfunction {
    foreach ($i in $input){
        "$(Get-Date): $i"
    }
}

Would give you the nicely formatted

03/14/2018 15:23:16: 
03/14/2018 15:23:16: Pinging 127.0.0.1 with 32 bytes of data:
03/14/2018 15:23:16: Reply from 127.0.0.1: bytes=32 time<1ms TTL=128
03/14/2018 15:23:16: Reply from 127.0.0.1: bytes=32 time<1ms TTL=128
03/14/2018 15:23:16: Reply from 127.0.0.1: bytes=32 time<1ms TTL=128
03/14/2018 15:23:16: Reply from 127.0.0.1: bytes=32 time<1ms TTL=128
03/14/2018 15:23:16: 
03/14/2018 15:23:16: Ping statistics for 127.0.0.1:
03/14/2018 15:23:16:     Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
03/14/2018 15:23:16: Approximate round trip times in milli-seconds:
03/14/2018 15:23:16:     Minimum = 0ms, Maximum = 0ms, Average = 0ms

Here is a nicely written article on the differences between these approaches.

Solution 3

You can just use ForEach-Object cmdlet for it (used % alias in below example)

ping 192.168.1.1 | %{ "{0:HH:mm:ss:fff}: {1}" -f (Get-Date), $_ }

result:

23:41:51:301:
23:41:51:302: Pinging 192.168.1.1 with 32 bytes of data:
23:41:55:255: Request timed out.
23:42:00:266: Request timed out.
23:42:05:254: Request timed out.
23:42:10:253: Request timed out.
23:42:10:261:
23:42:10:263: Ping statistics for 192.168.1.1:
23:42:10:265:     Packets: Sent = 4, Received = 0, Lost = 4 (100% loss),

Or use format like in mjolinor answer:

ping 192.168.1.1 | %{ "{0:o}: {1}" -f (Get-Date), $_ }

result:

2019-04-23T23:45:40.5816185+02:00:
2019-04-23T23:45:40.5845856+02:00: Pinging 192.168.1.1 with 32 bytes of data:
2019-04-23T23:45:44.2560567+02:00: Request timed out.
2019-04-23T23:45:49.2549104+02:00: Request timed out.
2019-04-23T23:45:54.2547535+02:00: Request timed out.
2019-04-23T23:45:59.2547932+02:00: Request timed out.
2019-04-23T23:45:59.2577788+02:00:
2019-04-23T23:45:59.2607707+02:00: Ping statistics for 192.168.1.1:
2019-04-23T23:45:59.2627647+02:00:     Packets: Sent = 4, Received = 0, Lost = 4 (100% loss),

Solution 4

You could use the Start-Transcript cmdlet in combination with a custom prompt in your profile:

# Configure PS prompt to show date and time
function prompt
{ 
    $promptStringStart = "PS:" + (Get-Date -format MM/dd/yy` hh:mm:ss)
    $promptStringEnd += ">"
    Write-Host $promptStringStart -NoNewline -ForegroundColor Yellow
    Write-Host $promptStringEnd -NoNewline -ForegroundColor Yellow
    return " "
}

This works great on my Windows 7 workstation. However, on some newer Server 2012 R2 installations Start-Transcript seems to be slightly broken. This fixes part of it: https://support.microsoft.com/en-us/help/3014136/powershell-transcript-file-doesn-t-contain-the-correct-information-in-windows-server-2012-r2

... but it does not fix the issue with the custom prompt, still.

For example, I see this on the console:

PS:02/14/17 08:28:20> hostname
server463

And this is what's written to the log:

PS:02/14/17 08:28:20
>

PS>hostname
server463

View more solutions

Comments

[Piotr L]

My question was about how to add timestamps to the output in the first place, not how to filter them in (or out) subsequently.

[mjolinor]

That's what the filter is doing. A PowerShell filter is a script block that accepts input from the pipeline, and runs once for each object that it gets from the pipeline. It's functionally the same as a function with only a Process block. That filter will add the timestamp to each line output from your executable.

[Piotr L]

Ahh, indeed, it DOES work exactly as you described. Thanks a million - problem solved!

[Piotr L]

Thank you, this is quite an interesting approach and I'm sure it is useful in certain scenarios. I am sticking with the timestamp filter approach though as per mjolinor's answer above. Suits my needs better.

[Piotr L]

This is likely the shortest possible code to get things working, well done. I am sticking with mjolinor's solution though as it suits me better (larger code base, multiple scripts etc so code re-usability is important to me)