KitchenVerifyPesterNoTestsRun.log

D, [2017-03-22T06:04:10.979811 #16824] DEBUG -- acme-win-webdefault-nano: Berksfile found at D:/Github/TDDwithChefDSCPester/cookbooks/acme_win_web/Berksfile, loading Berkshelf
D, [2017-03-22T06:04:12.430329 #16824] DEBUG -- acme-win-webdefault-nano: Berkshelf 5.6.4 library loaded
D, [2017-03-22T06:04:12.431462 #16824] DEBUG -- acme-win-webdefault-nano: winrm requested, loading winrm gem (["~> 2.0"])
D, [2017-03-22T06:04:12.727548 #16824] DEBUG -- acme-win-webdefault-nano: winrm is loaded.
D, [2017-03-22T06:04:12.728548 #16824] DEBUG -- acme-win-webdefault-nano: winrm-fs requested, loading winrm-fs gem (["~> 1.0"])
D, [2017-03-22T06:04:12.885544 #16824] DEBUG -- acme-win-webdefault-nano: winrm-fs is loaded.
I, [2017-03-22T06:04:12.888568 #16824]  INFO -- acme-win-webdefault-nano: -----> Verifying <acme-win-webdefault-nano>...
I, [2017-03-22T06:04:12.892050 #16824]  INFO -- acme-win-webdefault-nano: Preparing files for transfer
D, [2017-03-22T06:04:12.893021 #16824] DEBUG -- acme-win-webdefault-nano: Creating local sandbox in C:/Users/rschi/AppData/Local/Temp/acme-win-webdefault-nano-sandbox-20170322-16824-ucewty
I, [2017-03-22T06:04:12.894044 #16824]  INFO -- acme-win-webdefault-nano: Preparing to copy supporting powershell modules.
I, [2017-03-22T06:04:12.906522 #16824]  INFO -- acme-win-webdefault-nano: Preparing to copy files from D:/Github/TDDwithChefDSCPester/cookbooks/acme_win_web/test/integration/acme_win_web.default to the SUT.
I, [2017-03-22T06:04:12.913035 #16824]  INFO -- acme-win-webdefault-nano: Transferring files to <acme-win-webdefault-nano>
D, [2017-03-22T06:04:13.591042 #16824] DEBUG -- acme-win-webdefault-nano: creating hash for directory $env:TEMP\verifier
D, [2017-03-22T06:04:13.593533 #16824] DEBUG -- acme-win-webdefault-nano: Populating files
D, [2017-03-22T06:04:13.596522 #16824] DEBUG -- acme-win-webdefault-nano: +++ Adding NamedPipes/NamedPipes.psm1
D, [2017-03-22T06:04:13.598540 #16824] DEBUG -- acme-win-webdefault-nano: +++ Adding PesterUtil/PesterUtil.psm1
D, [2017-03-22T06:04:13.600022 #16824] DEBUG -- acme-win-webdefault-nano: +++ Adding ScheduledTaskRunner/ScheduledTaskRunner.psm1
D, [2017-03-22T06:04:13.601542 #16824] DEBUG -- acme-win-webdefault-nano: === All files added.
D, [2017-03-22T06:04:13.605022 #16824] DEBUG -- acme-win-webdefault-nano: Running check_files.ps1
D, [2017-03-22T06:04:13.608025 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] opening remote shell on http://192.168.2.90:5985/wsman
D, [2017-03-22T06:04:13.866520 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Waiting for output...
D, [2017-03-22T06:04:14.726417 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Processing output
D, [2017-03-22T06:04:14.727918 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] polling for pipeline state. message: #<WinRM::PSRP::Message:0x567cc00 @data="\xEF\xBB\xBF<Obj RefId=\"0\"><MS><Version N=\"protocolversion\">2.3</Version><Version N=\"PSVersion\">2.0</Version><Version N=\"SerializationVersion\">1.1.0.1</Version></MS></Obj>", @destination=1, @type=65538, @pipeline_id="00000000-0000-0000-0000-000000000000", @runspace_pool_id="00000000-0000-0000-0000-000000000000">
D, [2017-03-22T06:04:14.728418 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Waiting for output...
D, [2017-03-22T06:04:14.833917 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Processing output
D, [2017-03-22T06:04:14.835422 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] polling for pipeline state. message: #<WinRM::PSRP::Message:0x55fa4a8 @data="\xEF\xBB\xBF<Obj RefId=\"0\"><MS><Obj N=\"ApplicationPrivateData\" RefId=\"1\"><TN RefId=\"0\"><T>System.Management.Automation.PSPrimitiveDictionary</T><T>System.Collections.Hashtable</T><T>System.Object</T></TN><DCT><En><S N=\"Key\">PSVersionTable</S><Obj N=\"Value\" RefId=\"2\"><TNRef RefId=\"0\" /><DCT><En><S N=\"Key\">PSEdition</S><S N=\"Value\">Core</S></En><En><S N=\"Key\">PSVersion</S><Version N=\"Value\">5.1.14368.1000</Version></En><En><S N=\"Key\">SerializationVersion</S><Version N=\"Value\">1.1.0.1</Version></En><En><S N=\"Key\">WSManStackVersion</S><Version N=\"Value\">3.0</Version></En><En><S N=\"Key\">PSRemotingProtocolVersion</S><Version N=\"Value\">2.3</Version></En><En><S N=\"Key\">PSCompatibleVersions</S><Obj N=\"Value\" RefId=\"3\"><TN RefId=\"1\"><T>System.Version[]</T><T>System.Array</T><T>System.Object</T></TN><LST><Version>1.0</Version><Version>2.0</Version><Version>3.0</Version><Version>4.0</Version><Version>5.0</Version><Version>5.1.14368.1000</Version></LST></Obj></En><En><S N=\"Key\">CLRVersion</S><Nil N=\"Value\" /></En><En><S N=\"Key\">BuildVersion</S><Version N=\"Value\">10.0.14368.1000</Version></En></DCT></Obj></En><En><S N=\"Key\">DebugStop</S><B N=\"Value\">false</B></En><En><S N=\"Key\">UnhandledBreakpointMode</S><I32 N=\"Value\">1</I32></En><En><S N=\"Key\">DebugBreakpointCount</S><I32 N=\"Value\">0</I32></En><En><S N=\"Key\">BreakAll</S><B N=\"Value\">false</B></En><En><S N=\"Key\">DebugMode</S><I32 N=\"Value\">1</I32></En></DCT></Obj></MS></Obj>", @destination=1, @type=135177, @pipeline_id="00000000-0000-0000-0000-000000000000", @runspace_pool_id="00000000-0000-0000-0000-000000000000">
D, [2017-03-22T06:04:14.835938 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Waiting for output...
D, [2017-03-22T06:04:14.854917 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Processing output
D, [2017-03-22T06:04:14.856417 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] polling for pipeline state. message: #<WinRM::PSRP::Message:0x5548c38 @data="\xEF\xBB\xBF<Obj RefId=\"0\"><MS><I32 N=\"RunspaceState\">2</I32></MS></Obj>", @destination=1, @type=135173, @pipeline_id="00000000-0000-0000-0000-000000000000", @runspace_pool_id="00000000-0000-0000-0000-000000000000">
D, [2017-03-22T06:04:14.862418 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] remote shell created with shell_id: 2DA5E41F-9CAE-4D3A-BE7A-A89190BF20A7
D, [2017-03-22T06:04:14.916636 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Command created for $hash_file = @{
  "deec30762f4c7639a4f2dcb36f57d24c" = @{
    "target" = "$env:TEMP\winrm-upload\tmpzip-deec30762f4c7639a4f2dcb36f57d24c.zip";
    "src_basename" = "modules";
    "dst" = "$env:TEMP\verifier\modules"
  }
}

Function Cleanup($disposable) {
  if (($disposable -ne $null) -and ($disposable.GetType().GetMethod("Dispose") -ne $null)) {
    $disposable.Dispose()
  }
}

Function Check-Files($h) {
  return $h.GetEnumerator() | ForEach-Object {
    $dst = Unresolve-Path $_.Value.target
    $dst_changed = $false
    if(Test-Path $dst -PathType Container) {
      $dst_changed = $true
      $dst = Join-Path $dst $_.Value.src_basename
    }
    New-Object psobject -Property @{
      chk_exists = ($exists = Test-Path $dst -PathType Leaf)
      src_md5 = ($sMd5 = $_.Key)
      dst_md5 = ($dMd5 = if ($exists) { Get-MD5Sum $dst } else { $null })
      chk_dirty = ($dirty = if ($sMd5 -ne $dMd5) { $true } else { $false })
      verifies = if ($dirty -eq $false) { $true } else { $false }
      target_is_folder = $dst_changed
    }
  } | Select-Object -Property chk_exists,src_md5,dst_md5,chk_dirty,verifies,target_is_folder
}

Function Get-MD5Sum($src) {
  Try {
    $c = [System.Security.Cryptography.MD5]::Create()
    $bytes = $c.ComputeHash(($in = (Get-Item $src).OpenRead()))
    return ([System.BitConverter]::ToString($bytes)).Replace("-", "").ToLower()
  } 
  Finally {
    Cleanup $c
    Cleanup $in
  }
}

Function Unresolve-Path($path) {
  if ($path -eq $null) {
    return $null
  }
  else {
    return $ExecutionContext.SessionState.Path.GetUnresolvedProviderPathFromPSPath($path)
  }
}

Check-Files $hash_file | ConvertTo-Csv -NoTypeInformation

if (!$?) { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } } with id: 81EFCF21-D73E-45D6-82EF-C44253B7A32A
D, [2017-03-22T06:04:14.924117 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] creating command_id: 81EFCF21-D73E-45D6-82EF-C44253B7A32A on shell_id 2DA5E41F-9CAE-4D3A-BE7A-A89190BF20A7
D, [2017-03-22T06:04:14.924616 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Waiting for output...
D, [2017-03-22T06:04:15.524615 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Processing output
D, [2017-03-22T06:04:15.542114 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] cleaning up command_id: 81EFCF21-D73E-45D6-82EF-C44253B7A32A on shell_id 2DA5E41F-9CAE-4D3A-BE7A-A89190BF20A7
D, [2017-03-22T06:04:15.561635 #16824] DEBUG -- acme-win-webdefault-nano: Parsing CSV Response
D, [2017-03-22T06:04:15.562615 #16824] DEBUG -- acme-win-webdefault-nano: "chk_exists","src_md5","dst_md5","chk_dirty","verifies","target_is_folder"
"True","deec30762f4c7639a4f2dcb36f57d24c","deec30762f4c7639a4f2dcb36f57d24c","False","True","False"

D, [2017-03-22T06:04:15.563116 #16824] DEBUG -- acme-win-webdefault-nano: File $env:TEMP\verifier\modules is up to date, skipping
D, [2017-03-22T06:04:15.563616 #16824] DEBUG -- acme-win-webdefault-nano: Running extract_files.ps1
D, [2017-03-22T06:04:15.591117 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Command created for trap {
  $e = $_.Exception
  $e.InvocationInfo.ScriptName
  do {
    $e.Message
    $e = $e.InnerException
  } while ($e)
  break
}

function folder($path){
  $path | ? {-not (test-path $_)} | % {$null = mkdir $_}
}

Function Decode-Files($hash) {
  foreach ($key in $hash.keys) {
    $value = $hash[$key]
    $tzip, $dst = $Value["tmpzip"], $Value["dst"]
    if ($tzip) {Unzip-File $tzip $dst}
    New-Object psobject -Property @{dst=$dst;src_md5=$key;tmpzip=$tzip}
  }
}

Function Unzip-File($src, $dst) {
  $unpack = $src -replace '\.zip'
  $dst_parent = Split-Path -Path $dst -Parent
  if(!(Test-Path $dst_parent)) { $dst = $dst_parent }
  folder $unpack, $dst
  try {
    try{
      [IO.Compression.ZipFile]::ExtractToDirectory($src, $unpack)
    }
    catch {
      Add-Type -AssemblyName System.IO.Compression.FileSystem -ErrorAction Stop
      [IO.Compression.ZipFile]::ExtractToDirectory($src, $unpack)
    }
  }
  catch {
    Try {
      $s = New-Object -ComObject Shell.Application
      ($s.NameSpace($unpack)).CopyHere(($s.NameSpace($src)).Items(), 0x610)
    }
    Finally {
      [void][Runtime.Interopservices.Marshal]::ReleaseComObject($s)
    }
  }
  dir $unpack | cp -dest "$dst/" -force -recurse
  rm $unpack -recurse -force
}

$hash_file = @{
  "deec30762f4c7639a4f2dcb36f57d24c" = @{
    "dst" = "$env:TEMP\verifier\modules";
    "tmpzip" = "$env:TEMP\winrm-upload\tmpzip-deec30762f4c7639a4f2dcb36f57d24c.zip"
  }
}
Decode-Files $hash_file | ConvertTo-Csv -NoTypeInformation

if (!$?) { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } } with id: 9FBEBDCF-E703-4850-B669-9BCC690C45B5
D, [2017-03-22T06:04:15.597125 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] creating command_id: 9FBEBDCF-E703-4850-B669-9BCC690C45B5 on shell_id 2DA5E41F-9CAE-4D3A-BE7A-A89190BF20A7
D, [2017-03-22T06:04:15.597619 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Waiting for output...
D, [2017-03-22T06:04:15.919131 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] Processing output
D, [2017-03-22T06:04:15.931143 #16824] DEBUG -- acme-win-webdefault-nano: [WinRM] cleaning up command_id: 9FBEBDCF-E703-4850-B669-9BCC690C45B5 on shell_id 2DA5E41F-9CAE-4D3A-BE7A-A89190BF20A7
D, [2017-03-22T06:04:15.952148 #16824] DEBUG -- acme-win-webdefault-nano: Parsing CSV Response
D, [2017-03-22T06:04:15.953118 #16824] DEBUG -- acme-win-webdefault-nano: "tmpzip","src_md5","dst"
"C:\Users\ADMINI~1\AppData\Local\Temp\winrm-upload\tmpzip-deec30762f4c7639a4f2dcb36f57d24c.zip","deec30762f4c7639a4f2dcb36f57d24c","C:\Users\ADMINI~1\AppData\Local\Temp\verifier\modules"

D, [2017-03-22T06:04:15.957128 #16824] DEBUG -- acme-win-webdefault-nano: Cleaned up src_zip C:/Users/rschi/AppData/Local/Temp/tmpzip-20170322-16824-1or2k8e.zip
D, [2017-03-22T06:04:15.958135 #16824] DEBUG -- acme-win-webdefault-nano: Uploaded 1 items dirty_check: (0m1.97s) stream_files: (0m0.00s) extract: (0m0.39s) 
D, [2017-03-22T06:04:15.958627 #16824] DEBUG -- acme-win-webdefault-nano: Transfer complete
D, [2017-03-22T06:04:15.961130 #16824] DEBUG -- acme-win-webdefault-nano: Cleaning up local sandbox in C:/Users/rschi/AppData/Local/Temp/acme-win-webdefault-nano-sandbox-20170322-16824-ucewty
I, [2017-03-22T06:04:15.971113 #16824]  INFO -- acme-win-webdefault-nano: Finished verifying <acme-win-webdefault-nano> (0m3.08s).