Scripting / Logging Gripe Summary

I finally got a series of Korn shell scripts ported over to PowerShell. I did this for my team as part of getting them to adopt PowerShell as the "official" scripting language. :-) Here's what I found to be less than optimal:

1. There is no way to capture debug, verbose or warning output to a log file. This is a significant limitation IMO. When these scripts run there is *NOBODY* at the console to look at the output. These scripts are scheduled to execute in the wee hours of the morning. We want to capture *everything* to a log file for later analysis, traceability and debugging. Copy-Item -verbose shows you each file it copies which is handy when a wildcarded source is specified. Unfortunately I had to write my own CopyFile function that does its own resolve-path to write info on every file that is copied to the log file because I couldn't capture the "verbose" output to the log file.

2. Having to decorate every interesting, non-captured line like so:

BuildCustomCeImage.exe 2>&1 >> $LogFile
gci $OutputDir 2>&1 >> $LogFile
set-location $InstallDir 2>&1 >> $LogFile

really clutters up the script. Please consider providing a way to capture all output (similar to Korn shell's exec 2>&1 $LogFile) e.g.:

$script:HostOutputFile = $LogFile
or
$host.UI.RedirectOutput $LogFile -All # error, warning, debug - everything

The redirection somehow needs to be scoped to the current script that is executing. It isn't uncommon for us to invoke a script from the top level script where the child script wants to log to its own log file. And when the top level script exits, you would want all host output to automatically switch back to the host/console.

3. Dealing with paths that have square braces in them really bites. We tend to write re-usable, generic function libraries so we don't know a priori whether to a path parameter should be passed to a cmdlet's -path or -literalpath parameter. Furthermore, that path may need to be escaped or unescaped depending on whether or not a -path parameter accepts wildcard input or not. Consider the following:

$BaseDir = "C:\Project"
.... Some where in a different script file
$Path = "$BaseDir\``[somedir``]"
$files = get-childitem "$Path\*.txt" # works because the original $Path var escaped the []
.... Yet somewhere different
copy-item foo.txt $Path # Hmm that won't work because it copies to literal `[somedir`].

To make this work I need a function to unescape the []. Of course this makes it hard to write a reusable function that uses copy-item. The best I can do is hope the caller passes in the correctly unescaped path.

4. When outputting formatted objets to a file, PowerShell generates the appropriate CRLF sequences. However if you want to output strings to your log file like so:

"`n`nSending summary log:" >> $LogFile

The `n doesn't get translated to CRLF in the resulting file. This results in bad formatting in notepad - rather than line breaks you see little square boxes. Perhaps `n shouldn't get converted to CRLF but that means I have to do this:

$NL = [Environment]::NewLine
"$NL${NL}Sending summary log:" >> $LogFile

If that is the best we can do, perhaps $NL should be predefined by PowerShell?

5. Copy-item -force is broken. Please fix it. The other reason I had to create a CopyFile function is to fix the issue with -force. Executing copy-item -force when the destination file is readonly, will make the file writable but for whatever reason - fails to complete the copy. It is embarrasing when I can't demonstrate a simple equivalent for UNIX's cp -f src dst in PowerShell.

Deep cleansing breath, hold it, exhale. OK I *think* I've gotten this out of my system for a while.

--
Keith

"Keith Hill [MVP]" <r_keith_hill@no.spam.thank.u.hotmail.com> wrote in
message news:%23RYpTFOlHHA.1624@TK2MSFTNGP06.phx.gbl...
I finally got a series of Korn shell scripts ported over to PowerShell. I
did this for my team as part of getting them to adopt PowerShell as the
"official" scripting language. :-) Here's what I found to be less than
optimal:

<snip>

2. Having to decorate every interesting, non-captured line like so:

BuildCustomCeImage.exe 2>&1 >> $LogFile
gci $OutputDir 2>&1 >> $LogFile
set-location $InstallDir 2>&1 >> $LogFile


==> in CMD scripts I do it this way:

(
echo/test
dir/s
type thefile.txt
) 2>&1 >> LogFile.log

Seems to me that something along those lines should work in PS.

/Al

"Al Dunbar" <AlanDrub@hotmail.com.nospaam> wrote in message
news:%23svy6gZlHHA.3512@TK2MSFTNGP06.phx.gbl...
> ==> in CMD scripts I do it this way:
>
> (
> echo/test
> dir/s
> type thefile.txt
> ) 2>&1 >> LogFile.log
>
> Seems to me that something along those lines should work in PS.

You can do this in PowerShell:

& {
dir c:\
gps
dir c:\asdfa
write-warning "This is a warning"
copy-item $Home\foo.ps1 c:\temp -verbose
} 2>&1 > foo.log

And that is a fine solution for small scripts like the above. I'm not so
sure I would want to use this approach in a script that is several hundred
lines long. There is also a problem in this scenario where objects getting
formatted differently when the output is redirected to a file within the
script. For example the process objects show up like so in foo.log:

Id : 1276
Handles : 121
CPU :
Name : audiodg


Id : 556
Handles : 753
CPU :
Name : csrss
....

instead of how they normally appear when gps output is directed to the host
(console):

Handles NPM(K) PM(K) WS(K) VM(M) CPU(s) Id ProcessName
------- ------ ----- ----- ----- ------ -- -----------
121 4 11692 9556 46 1276 audiodg
753 6 1672 3564 89 556 csrss
....

--
Keith

Keith,

Have you tried Start-Transcript for logging? It works fine for some of my
relatively small scripts, but I am not sure what caveats it has.

--
Thanks,
Roman Kuzmin

"Roman Kuzmin" <z@z.z> wrote in message
news:OCwKVzalHHA.1624@TK2MSFTNGP06.phx.gbl...
> Keith,
>
> Have you tried Start-Transcript for logging? It works fine for some of my
> relatively small scripts, but I am not sure what caveats it has.

The problem with that approach is that if the user is using this method to
log their PowerShell session (which I do), then you have to call
Stop-Transcript first before you start logging the transcript for the
script. That wouldn't be too bad if there was a guaranteed way to resume
transcribing when the script is done. So the user's shell level transcript
gets resumed.

--
Keith

Keith,

> 2. Having to decorate every interesting, non-captured line like so:
> *
> BuildCustomCeImage.exe 2>&1 >> $LogFile
> gci $OutputDir 2>&1 >> $LogFile
> set-location $InstallDir 2>&1 >> $LogFile

You could always run the scripts from a scheduling package that captures all
the stdout/stderr output and saves it automatically. I use Argent Job
Scheduler for that - for cmd files, vbscript, exe's, powershell, whatever. It
doesn't care what it's actually running, just does the scheduling, checks the
return code and captures all output. I'm sure other "enterprise" schedulers
offer similar facilities.

Neil Pike. Protech Computing Ltd

"Neil Pike" <neilpike@compuserve.com> wrote in message
news:VA.000064d7.05fe421d@compuserve.com...
> Keith,
>
>> 2. Having to decorate every interesting, non-captured line like so:
>>
>> BuildCustomCeImage.exe 2>&1 >> $LogFile
>> gci $OutputDir 2>&1 >> $LogFile
>> set-location $InstallDir 2>&1 >> $LogFile
>
> You could always run the scripts from a scheduling package that captures
> all
> the stdout/stderr output and saves it automatically. I use Argent Job
> Scheduler for that - for cmd files, vbscript, exe's, powershell, whatever.
> It
> doesn't care what it's actually running, just does the scheduling, checks
> the
> return code and captures all output. I'm sure other "enterprise"
> schedulers
> offer similar facilities.
>

Interesting. We've just relied on the Windows task scheduler since these
scripts run on a very minimal test image i.e. we don't install anything that
doesn't need to be on the image.

--
Keith

What I have done with transcription is use the -path parameter to direct scripts to their own "logging" folder so if I
was writing a file copy script:

$logfile = "C:\logs\copyFileScript\{0:yyyyMMddHHmm}" -f (get-date)
# Adding the processID of the powershell session @ the end of the timestamp is a good idea as well
Start-Transcript -path $logfile
Copy-Item [...] -verbose
....
Stop-Transcript

hth,
Clint

"Keith Hill" <r_keith_hill@mailhot.nospamIdotcom> wrote in message
news:9C45795A-7F5C-4D8F-A772-E4AF24CB69F6@microsoft.com...
> "Roman Kuzmin" <z@z.z> wrote in message news:OCwKVzalHHA.1624@TK2MSFTNGP06.phx.gbl...
>> Keith,
>>
>> Have you tried Start-Transcript for logging? It works fine for some of my relatively small scripts, but I am not sure
>> what caveats it has.
>
> The problem with that approach is that if the user is using this method to log their PowerShell session (which I do),
> then you have to call Stop-Transcript first before you start logging the transcript for the script. That wouldn't be
> too bad if there was a guaranteed way to resume transcribing when the script is done. So the user's shell level
> transcript gets resumed.
>
> --
> Keith

"Clint Bergman" <clint@psd267.wednet.edu> wrote in message
news:uG7gw0mlHHA.3760@TK2MSFTNGP05.phx.gbl...
> What I have done with transcription is use the -path parameter to direct
> scripts to their own "logging" folder so if I was writing a file copy
> script:
>
> $logfile = "C:\logs\copyFileScript\{0:yyyyMMddHHmm}" -f (get-date)
> # Adding the processID of the powershell session @ the end of the
> timestamp is a good idea as well
> Start-Transcript -path $logfile
> Copy-Item [...] -verbose
> ...
> Stop-Transcript

That's a pretty good approach however you need to make sure that in the
event of an error you invoke Stop-Transcript via a trap handler.
Unfortunately there is no way to catch Ctrl+C. Still if the script only
ever runs via a scheduled job it's no big deal if stop transcript isn't
called because the shell exits when done. However have you perused these
transcript files? Have you noticed any formatting funnies with directory
listing or process dumps?

--
Keith

I haven't unfortunately, and I took another job after putting those scripts in place. From what I remember though the
lines were what I expected. This particular implementation was a file deletion script that cleaned out files older than
6 days, and we didn't have much cause to go over the log files much. I don't have any more than that, sorry.

~Clint

"Keith Hill [MVP]" <r_keith_hill@no.spam.thank.u.hotmail.com> wrote in message
news:%23VK5F9mlHHA.5084@TK2MSFTNGP03.phx.gbl...
> "Clint Bergman" <clint@psd267.wednet.edu> wrote in message news:uG7gw0mlHHA.3760@TK2MSFTNGP05.phx.gbl...
>> What I have done with transcription is use the -path parameter to direct scripts to their own "logging" folder so if
>> I was writing a file copy script:
>>
>> $logfile = "C:\logs\copyFileScript\{0:yyyyMMddHHmm}" -f (get-date)
>> # Adding the processID of the powershell session @ the end of the timestamp is a good idea as well
>> Start-Transcript -path $logfile
>> Copy-Item [...] -verbose
>> ...
>> Stop-Transcript
>
> That's a pretty good approach however you need to make sure that in the event of an error you invoke Stop-Transcript
> via a trap handler. Unfortunately there is no way to catch Ctrl+C. Still if the script only ever runs via a scheduled
> job it's no big deal if stop transcript isn't called because the shell exits when done. However have you perused
> these transcript files? Have you noticed any formatting funnies with directory listing or process dumps?
>
> --
> Keith
>