logging issue (gibberish or Null characters?!?!)

by Lahru at 2012-09-21 14:24:56

First the code:

$ErrorActionPreference="SilentlyContinue"
Stop-Transcript | out-null
$ErrorActionPreference = "Continue"

$path1 = "\Server1\Fax\Fax-lines\MyTestFolder"
$path2 = "\Server2\import\Fax-lines\MyTestFolder"
$path3 = "\Server3\backup\Fax-lines\MyTestFolder"
$path4 = "\my.domain.123.com\netlogon\Fax-Import-Monitor\MyTestFolder"

if(Test-Path -Path $path1* -include *.pdf, *.tif)
{
New-Item -Path $path4 -name SUCCESS.txt -Value "Success!" –itemtype file -force
}else{}

Add-Content -Path $path1\copy.log -value "BEGIN ACTION"
Copy-Item -path $path1* -include .pdf,.tif -destination $path2 -verbose -passthru | format-table -property LastWriteTime,Name -autosize | out-file -FilePath $path1\copy.log -append
Move-Item -path $path1*.pdf -destination $path3 -verbose -passthru | format-table -property LastWriteTime,Name -autosize | out-file -FilePath $path1\copy.log -append
Move-Item -path $path1*.tif -destination $path3 -verbose -passthru | format-table -property LastWriteTime,Name -autosize | out-file -FilePath $path1\copy.log -append
Add-Content -Path $path1\copy.log -value "STOP ACTION"
Copy-Item $path1\copy.log $path3\copy.log


Whats going on here? Well … files come into a folder and those files are copied/moved to a destination and a backup folder.
If the copy/move was successful it writes a Success.txt file to a Monitoring directory.
All of that works well.

The problem is that I’m trying to log these actions into a copy.log file and when I open the log file it looks a mess.
If opened in windows Notepad its all a runon scentence & there is a space between every character
If opened in Notepad++ there is a (NULL) between every character.
If I try to copy/paste it into here … it looks completely different.

There also seems to be a bug where sometimes I’ll end up with Machine Code instead of english which is absolutely baffling.

How can I modify this so that my logging is actually understandable and doesn’t look like crud ?
by DonJ at 2012-09-21 18:05:25
So, a couple of things.

First, verbose output isn’t passed along the pipeline, meaning it will never reach Format-Table or your log file. The only thing that will reach Format-Table in each case is whatever’s passed out via -passthru - meaning, the files that are copied or moved. I’m assuming you expected that to be the case.

Second, I’m not quite sure that this is the best way to go about this. For example, I see you’re using Stop-Transcript… have you considered just using Start-Transcript at the top of your script, and Stop-Transcript at the end? You could then dispense with the Format-Table and Out-File commands, and just (essentially) grab everything directly to the transcript. Did you try that and find it wasn’t what you wanted?

If you take out the Out-File commands, does the on-screen output look like what you’re after? It just isn’t going into the file correctly?

Sorry for all the questions, it’s just that I can’t actually test your script on my own system, so I’m not entirely sure what we’re dealing with. Consider ZIPping your copy.log file and attaching it, rather than pasting it into the message.
by Lahru at 2012-09-24 07:57:05
The code isn’t completely orginal. I began with Start-Transcript however it isnt’ giving me the logging info I want or the formatting is wierd so, that first stop-transcript might need to be removed.
If I use *-Transcript its not showing any indication of No Files copied and I have non admin users that will be reading this log.

I need the best way to log & indicate files copied/moved, preferrably which ones. and also if nothing was copied/moved.

Attached copy.log file in a zip

What shoudl be happening:
Script checks for PDF and/or TIF files
If YES = Copy -> destination and MOVE -> Backup & then log actions in the Copy.log file for both.
- Also Write a NEW "Success.txt" file to a monitoring folder.
If NO = Log that (0) Files Copied into the Copy.log file
Copy the Copy.log file to the Monitoring folder at the end of all operations.
by DonJ at 2012-09-24 08:17:43
I’m going to hazard a guess that "No files copied" was being written using Write-Host, which the transcript won’t capture. I didn’t see that in your code, but if you output the message with Write-Output instead, the transcript will capture it. That might be the shortest way to get what you need.

In general, Write-Host is bad.

I’d suggest getting rid of the Format-Table statements. Those are a big "gotcha" in PowerShell, because of the way they work. Instead, consider using Select-Object, which will let you indicate the properties you want, but which won’t preformat the output. Go back to using a transcript, but use Write-Output to output any messages. That should get those messages into the transcript for you. Alternately, you could continue using Out-File and Add-Content - I suspect they’ll work better for you once you aren’t using Formatting cmdlets.
by lido at 2012-09-24 17:30:50
Hi, Lahru. If you wanted to keep the existing code in place you could simply add a -Encoding parameter to the Out-File cmdlets with a value of ascii. The gibberish/spacing issues you’re seeing in your copy.log text file could be a result of a character encoding mismatch. By default the add-content cmdlet encodes its output as ascii while the out-file cmdlet does so in unicode. Try this and see if it meets your needs. Note, I also removed the -verbose params.

if(Test-Path -Path $path1* -include *.pdf, *.tif)
{
New-Item -Path $path4 -name SUCCESS.txt -Value "Success!" –itemtype file -force
}
Add-Content -Path $path1\copy.log -value "BEGIN ACTION"
Copy-Item -path $path1* -include .pdf,.tif -destination $path2 -passthru | format-table -property LastWriteTime,Name -autosize | out-file $path1\copy.log -Append -Encoding ascii
Move-Item -path $path1*.pdf -destination $path3 -passthru | format-table -property LastWriteTime,Name -autosize | out-file $path1\copy.log -Append -Encoding ascii
Move-Item -path $path1*.tif -destination $path3 -passthru | format-table -property LastWriteTime,Name -autosize | Out-File $path1\copy.log -Append -Encoding ascii
Add-Content -Path $path1\copy.log -value "STOP ACTION"
Copy-Item $path1\copy.log $path3\copy.log
by Lahru at 2012-10-01 09:39:58
So far the suggestion and coding presented by LIDO is closest to what I want. (The -encoding ASCII switch seems to have resolved the gibberish)
The main reason for not using transcript is that it’s too much information. This is why I introduced the format-table cmdlet(s) so that what is written in the log file is the name of the file and the time/date-stamp of when it was last modified.

I say the closest because I want the script to actually write to the log file indicating, "0 Files Copied" & the time, when such occurs.
As it stands if nothing copies the script writes consecutive lines of:
[quote]"BEGIN ACTION"
"STOP ACTION"[/quote]
The idea is for a non-administrative user to be able to read this log file and I would prefer it to read thusly:
[quote]"*BEGIN ACTION"
10/01/2012 8:30 am - 0 Files Copied
"STOP ACTION"[/quote]

How should I proceed to include this last bit?
by poshoholic at 2012-10-02 07:16:45
You could use the Tee-Object cmdlet with the -Variable parameter in your pipeline before Format-Table. That would allow you to track which items are copied or moved. Something like this:
if(Test-Path -Path $path1* -include *.pdf, *.tif)
{
New-Item -Path $path4 -name SUCCESS.txt -Value "Success!" –itemtype file -force
}
Add-Content -Path $path1\copy.log -value "BEGIN ACTION"
[PSObject]$itemsProcessed = @()
$itemCount = 0
Copy-Item -path $path1* -include .pdf,.tif -destination $path2 -passthru | Tee-Object -Variable itemsProcessed | format-table -property LastWriteTime,Name -autosize | out-file $path1\copy.log -Append -Encoding ascii
$itemCount += $itemsProcessed.Count
$itemsProcessed = @()
Move-Item -path $path1*.pdf -destination $path3 -passthru | Tee-Object -Variable itemsProcessed | format-table -property LastWriteTime,Name -autosize | out-file $path1\copy.log -Append -Encoding ascii
$itemCount += $itemsProcessed.Count
$itemsProcessed = @()
Move-Item -path $path1*.tif -destination $path3 -passthru | Tee-Object -Variable itemsProcessed | format-table -property LastWriteTime,Name -autosize | Out-File $path1\copy.log -Append -Encoding ascii
$itemCount += $itemsProcessed.Count
$itemsProcessed = @()
"$(Get-Date -Format 'MM/dd/yyyy hh:mm tt') - $itemCount File$(if ($itemCount -ne 1) {'s'}) Copied" | Out-File $path1\copy.log -Append -Encoding ascii
Add-Content -Path $path1\copy.log -value "STOP ACTION"
Copy-Item $path1\copy.log $path3\copy.log
by Lahru at 2012-10-09 07:21:41
Thank you everyone for your solutions & suggestions, here is the final code I decided to go with.
Kirk what you suggest looks interesting but also perhaps a bit too complex for my purpose; I haven’t tried it, but I had the following in place before I saw your post & it seems to fulfill my needs.

$ErrorActionPreference="SilentlyContinue"
Stop-Transcript | out-null
$ErrorActionPreference = "Continue"

$Source = "\path\to\SOURCE\directory"
$Destination = "\path\to\DESTINATION\directory"
$Bkp = "\path\to\BACKUP\directory"
$Monitor = "\path\to\MONITOR\directory"
$Time = GET-DATE

if(Test-Path -Path $Source* -include *.pdf, *.tif)
{
New-Item -Path $Monitor -name SUCCESS.txt -Value "Success @ $time!" –itemtype file -force
Add-Content -Path $Source\copy.log -value "BEGIN ACTION @ $time"
Copy-Item -path $Source* -include .pdf,.tif -destination $Destination -passthru | format-table -property LastWriteTime,Name -autosize | out-file $Source\copy.log -Append -Encoding ascii
Move-Item -path $Source*.pdf -destination $Bkp
Move-Item -path $Source*.tif -destination $Bkp
Add-Content -Path $Source\copy.log -value "STOP ACTION @ $time"
Add-Content -Path $Source\copy.log -value "================================================"
Copy-Item $Source\copy.log $Bkp\copy.log
}
ELSE
{
Add-Content -Path $Source\copy.log -value "*BEGIN ACTION @ $time"
Add-Content -Path $Source\copy.log -value "0 Files Copied"
Add-Content -Path $Source\copy.log -value "STOP ACTION @ $time"
Add-Content -Path $Source\copy.log -value "================================================"
}