FilterBox/Write-SRxFilterBranch.debug.ps1
|
<# .SYNOPSIS INSTRUMENTED (debug) build of the Filter Box branch worker. Identical logic to Write-SRxFilterBranch.ps1 but with heavy FILE LOGGING so the first CSOM branch write is easy to diagnose after the fact (hidden child process). .WHERE IS THE LOG Two correlated files next to -ResultPath (in %TEMP%, srx-filter-*.json): <ResultPath>.log step-by-step debug log (this script) <ResultPath>.transcript full transcript (PnP verbose etc.) A mirror log also lands in %TEMP%\SRxFilterLogs\ in case ResultPath is bad. .HOW TO USE Temporarily point the launcher at THIS file. In SRxFilterBox.psm1, inside Start-SRxFilterBranchOperation, change: $worker = Join-Path $SourcePath 'Write-SRxFilterBranch.ps1' to: $worker = Join-Path $SourcePath 'Write-SRxFilterBranch.debug.ps1' Reproduce one Save, then open the newest *.log in %TEMP%\SRxFilterLogs\. The failing line includes ScriptStackTrace + PositionMessage. TIP (watch live): temporarily drop -HideWindow in Start-Process, or tail: Get-Content "$env:TEMP\SRxFilterLogs\*.log" -Wait -Tail 60 #> [CmdletBinding()] param( [Parameter(Mandatory)] [string]$RootPath, [Parameter(Mandatory)] [string]$PackPath, [Parameter(Mandatory)] [string]$ResultPath, [Parameter(Mandatory=$false)] [switch]$Force, [Parameter(Mandatory=$false)] [ValidateSet('JSON','XML')] [string]$Format = 'JSON' ) $ErrorActionPreference = 'Stop' # ============================================================ LOGGING (first!) $script:DbgLogPaths = @() try { $mirrorDir = Join-Path $env:TEMP 'SRxFilterLogs' if (-not (Test-Path $mirrorDir)) { New-Item -ItemType Directory -Path $mirrorDir -Force | Out-Null } $stamp = (Get-Date).ToString('yyyyMMdd-HHmmss-fff') $script:DbgLogPaths += (Join-Path $mirrorDir ("filter-$stamp-pid$PID.log")) } catch { } try { if ($ResultPath) { $script:DbgLogPaths += ($ResultPath + '.log') } } catch { } function Write-Dbg { param([string]$Message, [string]$Level = 'INFO') $line = "{0} [{1}] (pid {2}) {3}" -f ((Get-Date).ToString('o')), $Level, $PID, $Message foreach ($p in $script:DbgLogPaths) { try { Add-Content -LiteralPath $p -Value $line -Encoding UTF8 } catch { } } try { Write-Host $line } catch { } } function Write-DbgException { param($ErrorRecord, [string]$Where = '') try { $ex = $ErrorRecord.Exception Write-Dbg "==================== EXCEPTION $Where ====================" 'ERROR' Write-Dbg ("Type : " + $ex.GetType().FullName) 'ERROR' Write-Dbg ("Message : " + $ex.Message) 'ERROR' Write-Dbg ("CategoryInfo : " + $ErrorRecord.CategoryInfo) 'ERROR' Write-Dbg ("FullyQualifiedId: " + $ErrorRecord.FullyQualifiedErrorId) 'ERROR' if ($ErrorRecord.InvocationInfo) { Write-Dbg ("PositionMessage : " + $ErrorRecord.InvocationInfo.PositionMessage) 'ERROR' Write-Dbg ("ScriptName:Line : {0}:{1}" -f $ErrorRecord.InvocationInfo.ScriptName, $ErrorRecord.InvocationInfo.ScriptLineNumber) 'ERROR' } Write-Dbg ("ScriptStackTrace:`n" + $ErrorRecord.ScriptStackTrace) 'ERROR' Write-Dbg (".NET StackTrace :`n" + $ex.StackTrace) 'ERROR' $inner = $ex.InnerException; $depth = 0 while ($inner -and $depth -lt 6) { Write-Dbg ("--- Inner[$depth] : " + $inner.GetType().FullName) 'ERROR' Write-Dbg (" Message : " + $inner.Message) 'ERROR' Write-Dbg (" StackTrace :`n" + $inner.StackTrace) 'ERROR' $inner = $inner.InnerException; $depth++ } Write-Dbg "=========================================================" 'ERROR' } catch { try { Write-Dbg ("Write-DbgException failed: " + $_.Exception.Message) 'ERROR' } catch {} } } try { if ($ResultPath) { $script:TranscriptPath = $ResultPath + '.transcript'; Start-Transcript -LiteralPath $script:TranscriptPath -Force | Out-Null } } catch { Write-Dbg ("Start-Transcript failed (non-fatal): " + $_.Exception.Message) 'WARN' } Write-Dbg "########## FILTER WORKER START ##########" Write-Dbg ("PSVersion : " + $PSVersionTable.PSVersion.ToString() + " Edition: " + $PSVersionTable.PSEdition) Write-Dbg ("RootPath : " + $RootPath) Write-Dbg ("PackPath : " + $PackPath + " exists=" + (Test-Path $PackPath)) Write-Dbg ("ResultPath : " + $ResultPath) Write-Dbg ("Force : " + [bool]$Force) # ------------------------------------------------------------ result plumbing function Write-SRxFilterResult { param([bool]$Success, [bool]$Conflict, $Data, [string]$ErrorText) $payload = [pscustomobject]@{ Success = $Success; Conflict = $Conflict; Data = $Data; Error = $ErrorText Pid = $PID; Ended = (Get-Date).ToString('o'); LogPath = ($script:DbgLogPaths -join ';') } $json = $payload | ConvertTo-Json -Depth 25 -Compress try { $dir = Split-Path -Parent $ResultPath if ($dir -and -not (Test-Path $dir)) { New-Item -ItemType Directory -Path $dir -Force | Out-Null } Set-Content -LiteralPath $ResultPath -Value $json -Encoding UTF8 Write-Dbg ("Result written: Success=$Success Conflict=$Conflict Error='$ErrorText'") } catch { Write-Dbg ("Failed to write result file: " + $_.Exception.Message) 'ERROR' } Write-Host ("__JSON__" + $json) } function ConvertFrom-SRxJsonFile { param([string]$Path) if (-not (Test-Path $Path)) { throw "Input file not found: $Path" } $raw = Get-Content -LiteralPath $Path -Raw -Encoding UTF8 if ([string]::IsNullOrWhiteSpace($raw)) { throw "Input file empty: $Path" } return ($raw | ConvertFrom-Json) } function ConvertTo-SRxNodesStack { param($Branch) $stack = [System.Collections.Stack]::new() foreach ($d in $Branch) { $attrs = @{} if ($d.Attributes) { foreach ($p in $d.Attributes.PSObject.Properties) { $attrs[$p.Name] = [string]$p.Value } } if ($d.NodeName) { $attrs['ts_NodeName'] = [string]$d.NodeName } if ($d.KeyAttribute) { $attrs['ts_KeyAttribute'] = [string]$d.KeyAttribute } if ($d.KeyAttributeValue) { $attrs['ts_KeyAttributeValue'] = [string]$d.KeyAttributeValue } if ($d.ProvisioningActivity){ $attrs['ts_ProvisioningActivity']= [string]$d.ProvisioningActivity } if ($d.CustomizationTarget) { $attrs['ts_CustomizationTarget'] = $true } if ($d.Deprecated) { $attrs['ts_Deprecated'] = $true } $termNode = [pscustomobject]@{ Name = [string]$d.Name; Attributes = $attrs; Scope = [int]$d.Scope xPath = [string]$d.XPath; Operation = [string]$d.Operation; optype = [int]$d.Optype } $stack.Push($termNode) } return ,$stack } try { # ============================================================ STAGE 1: bootstrap Write-Dbg "STAGE 1: bootstrap begin" Set-Location -Path $RootPath $externalScript = Join-Path $RootPath 'loadmodule.ps1' Write-Dbg ("loadmodule : " + $externalScript + " exists=" + (Test-Path $externalScript)) if (-not (Test-Path $externalScript)) { throw "loadmodule.ps1 not found at '$externalScript'." } . $externalScript Write-Dbg ("after dot-source: `$LoadModule is " + $(if ($null -eq $LoadModule) {'NULL'} else {$LoadModule.GetType().Name})) if ($null -ne $LoadModule) { $LoadModule.Invoke("SRxCore") | Out-Null } Write-Dbg "STAGE 1a: Initialize-SRxEnv -LoadModule2" Initialize-SRxEnv -LoadModule2 $LoadModule -RootPath $RootPath | Out-Null Connect-SRxSPOService if ($null -eq $global:SRxEnv) { if (Get-Command Start-SRxShell -ErrorAction SilentlyContinue) { Write-Dbg "STAGE 1b: Start-SRxShell -isJob"; Start-SRxShell -RootPath $RootPath -isJob | Out-Null } elseif (Get-Command Initialize-SRxEnv -ErrorAction SilentlyContinue) { Write-Dbg "STAGE 1b: Initialize-SRxEnv -RootPath"; Initialize-SRxEnv -RootPath $RootPath | Out-Null } else { throw "SRx environment could not be initialised from '$RootPath'." } } if ($null -eq $global:SRxEnv -or $null -eq $global:SRxEnv.Tenancy) { throw "global:SRxEnv or .Tenancy is null after bootstrap." } Write-Dbg ("STAGE 1 done. Tenancy.AdminUrl = '" + $global:SRxEnv.Tenancy.AdminUrl + "'") try { Import-Module (Join-Path $PSScriptRoot 'SRxFilterBox.psm1') -DisableNameChecking -Force -ErrorAction SilentlyContinue } catch { Write-Dbg ("SRxFilterBox import warn: " + $_.Exception.Message) 'WARN' } try { Import-Module (Join-Path $PSScriptRoot 'SRxCustomizationJson.psm1') -DisableNameChecking -Force -ErrorAction SilentlyContinue } catch { Write-Dbg ("SRxCustomizationJson import warn: " + $_.Exception.Message) 'WARN' } $jsonWriterPath = Join-Path $PSScriptRoot 'Write-SRxJsonCustomization.ps1' Write-Dbg ("Write-SRxJsonCustomization.ps1 path: $jsonWriterPath exists=" + (Test-Path $jsonWriterPath)) try { . $jsonWriterPath; Write-Dbg ("Write-SRxJsonCustomization loaded: " + [bool](Get-Command Write-SRxJsonCustomization -Errn SilentlyContinue)) } catch { Write-Dbg ("dot-source FAILED: " + $_.Exception.Message) 'ERROR' } Write-Dbg ("Sync-SRxLocalFilterBranch available: " + [bool](Get-Command Sync-SRxLocalFilterBranch -ErrorAction SilentlyContinue)) Write-Dbg ("Get-SRxCustomizationWriter available: " + [bool](Get-Command Get-SRxCustomizationWriter -ErrorAction SilentlyContinue)) # ============================================================ STAGE 2: read pack Write-Dbg "STAGE 2: read pack" $pack = ConvertFrom-SRxJsonFile -Path $PackPath $operation = [string]$pack.Operation $scope = [int]$pack.Scope Write-Dbg (" Operation=$operation Scope=$scope Optype=$($pack.Optype)") Write-Dbg (" Environment='$($pack.Environment)' Design='$($pack.Design)' TermID='$($pack.TermID)'") Write-Dbg (" BaselineModified='$($pack.BaselineModified)'") $bcount = 0; if ($pack.Branch) { $bcount = @($pack.Branch).Count } Write-Dbg (" Branch descriptors: $bcount") $i = 0 foreach ($d in @($pack.Branch)) { $i++ $ac = 0; if ($d.Attributes) { $ac = @($d.Attributes.PSObject.Properties).Count } Write-Dbg (" [$i] Name='$($d.Name)' NodeName='$($d.NodeName)' Key='$($d.KeyAttribute)'='$($d.KeyAttributeValue)' attrs=$ac Deprecated=$($d.Deprecated) Include=$($d.CustomizationTarget)") } # ============================================================ STAGE 3: concurrency (Iteration 2) Write-Dbg "STAGE 3: concurrency check skipped (Iteration 1 / -Force=$([bool]$Force))" # ============================================================ STAGE 4: WRITE BRANCH Write-Dbg "STAGE 4: build writer + nodesStack" <# if (-not (Get-Command Get-SRxCustomizationWriter -ErrorAction SilentlyContinue)) { throw "Get-SRxCustomizationWriter not available (SRxCore not loaded)." } $writer = Get-SRxCustomizationWriter Write-Dbg (" writer type: " + $(if ($null -eq $writer) {'NULL'} else {$writer.GetType().Name})) $nodesStack = ConvertTo-SRxNodesStack -Branch $pack.Branch Write-Dbg (" nodesStack count: " + $nodesStack.Count + " (Peek leaf Name='" + $(if ($nodesStack.Count){$nodesStack.Peek().Name}else{''}) + "')") $writerPack = [pscustomobject]@{ nodesStack = $nodesStack ts_Environment = [string]$pack.Environment ts_Design = [string]$pack.Design ts_TermID = [string]$pack.TermID } Write-Dbg "STAGE 4a: writer.Start(writerPack) <-- CSOM branch walk" $writer.Start($writerPack) Write-Dbg "STAGE 4 done: branch written to termstore" #> # decide effective format (JSON only for term-hosted layers 1..3; scope 0 -> XML) $effFormat = $Format if ([int]$pack.Scope -le 0) { $effFormat = 'XML' } if (-not (Get-Command Get-SRxCustomizationWriter -ErrorAction SilentlyContinue)) { throw "Get-SRxCustomizationWriter not available (SRxCore not loaded)." } if ($effFormat -eq 'JSON') { if (-not (Get-Command New-SRxJsonContainerTerm -ErrorAction SilentlyContinue)) { throw "New-SRxJsonContainerTerm not available (SRxCustomizationJson not loaded)." } if (-not (Get-Command Write-SRxJsonCustomization -ErrorAction SilentlyContinue)) { throw "Write-SRxJsonCustomization not available (dot-source it in STAGE 1)." } # build the container descriptor (Name = C_<hash>, Attributes = ts_* incl. compressed json) $container = New-SRxJsonContainerTerm -Pack $pack -Operation $operation # app-only connection (same pattern CustomizationWriter uses) $conn = Get-SRxConnection -siteUrl $global:SRxEnv.Tenancy.AdminUrl $props = @{} foreach ($k in $container.Attributes.Keys) { $props[[string]$k] = [string]$container.Attributes[$k] } $jw = Write-SRxJsonCustomization -Connection $conn ` -Scope ([int]$pack.Scope) ` -Optype ([int]$pack.Optype) ` -Environment ([string]$pack.Environment) ` -Design ([string]$pack.Design) ` -TermID ([string]$pack.TermID) ` -ContainerName ([string]$container.Name) ` -Operation ([string]$operation) ` -Props $props if (-not $jw.Success) { throw "Direct JSON write failed: $($jw.Error)" } } else { $writer = Get-SRxCustomizationWriter # legacy XML-mirror branch (unchanged) - keep your existing else{} body $nodesStack = ConvertTo-SRxNodesStack -Branch $pack.Branch $writerPack = [pscustomobject]@{ nodesStack = ,$nodesStack ts_Environment = [string]$pack.Environment ts_Design = [string]$pack.Design ts_TermID = [string]$pack.TermID } $writer.Start($writerPack) } Write-Dbg "STAGE 4 done: branch written to termstore" # ============================================================ STAGE 5: LOCAL SYNC Write-Dbg "STAGE 5: local sync (termSet.xml + JSON)" $syncData = $null; $syncWarning = $null try { if (Get-Command Sync-SRxLocalFilterBranch -ErrorAction SilentlyContinue) { if ($effFormat -eq 'JSON') { $sync = Sync-SRxLocalJsonCustomization -Pack $pack -Operation $operation } else { $sync = Sync-SRxLocalFilterBranch -Pack $pack } if ($sync.Success) { $syncData = $sync; Write-Dbg " local sync OK" } else { $syncWarning = "Local sync failed: $($sync.Error)"; Write-Dbg (" " + $syncWarning) 'WARN' } } else { $syncWarning = "Sync-SRxLocalFilterBranch not available; local cache not updated."; Write-Dbg (" " + $syncWarning) 'WARN' } } catch { $syncWarning = "Local sync threw: $($_.Exception.Message)"; Write-DbgException -ErrorRecord $_ -Where "(local sync)" } # ============================================================ STAGE 6: result $data = [pscustomobject]@{ Operation = $operation Scope = $scope FilterNodes = if ($syncData) { $syncData.FilterNodes } else { $null } OuterXml = if ($syncData) { $syncData.OuterXml } else { $null } SyncWarning = $syncWarning } Write-SRxFilterResult -Success $true -Conflict $false -Data $data -ErrorText $null Write-Dbg "########## FILTER WORKER SUCCESS ##########" try { Stop-Transcript | Out-Null } catch {} exit 0 } catch { Write-DbgException -ErrorRecord $_ -Where "(main try)" $msg = $_.Exception.Message if ($_.Exception.InnerException) { $msg += " | inner: " + $_.Exception.InnerException.Message } $msg2 = $msg + " [log: " + ($script:DbgLogPaths | Select-Object -First 1) + "]" Write-SRxFilterResult -Success $false -Conflict $false -Data $null -ErrorText $msg2 Write-Dbg "########## FILTER WORKER FAILED ##########" try { Stop-Transcript | Out-Null } catch {} exit 1 } |