Get-VBRTaskSessions changes session info?

[Backerupper]

I am seeing something very odd that is not making sense to me.

Gather a (or some) backup sessions (in this case, successful backup sessions within the last 2 hours)
Output the session info
Notice Total (GB) equals 140 (as it should/confirmed)

Then gather tasksessions for that session
Output same exact session info
Notice Total (GB) is now 240 (double what it should be)

If you change one line and omit the Get-VBRTaskSession command everything outputs as expected (with $taskList now holding sessions and not tasksessions...).
$task = $session | Get-VBRTaskSession
to
$task = $session# | Get-VBRTaskSession


Is there any reason why running Get-VBRTaskSession would change the value?
Note - there is a handful of values that will double under session.progress not just this one

Code: Select all

$HourstoCheck = 2

# Gather all sessions
$allSessions = Get-VBRBackupSession
# Gather just successful backup sessions within $HourstoCheck
$successSessions = $allSessions | ?{$_.CreationTime -ge (Get-Date).AddHours(-$HourstoCheck) -and $_.JobType -eq "Backup" -and $_.Result -eq "Success"}

# Output Session Info
$successSessions | Select @{Name="Job Name"; Expression = {$_.Name}},
  @{Name="Start Time"; Expression = {$_.CreationTime}},
  @{Name="Stop Time"; Expression = {$_.EndTime}},
  @{Name="Total (GB)"; Expression = {[Math]::Round($_.Progress.ProcessedSize/1GB,2)}},
  Result, ID

# Gather all Backup Tasks from Sessions created within time frame
$taskList = @()
Foreach ($session in $successSessions) {
  $task = $session | Get-VBRTaskSession
  $taskList += $task
}

# Output Session Info
$successSessions | Select @{Name="Job Name"; Expression = {$_.Name}},
  @{Name="Start Time"; Expression = {$_.CreationTime}},
  @{Name="Stop Time"; Expression = {$_.EndTime}},
  @{Name="Total (GB)"; Expression = {[Math]::Round($_.Progress.ProcessedSize/1GB,2)}},
  Result, ID

Output

Code: Select all

Job Name   : Temp Backup Job (Reverse Incremental)
Start Time : 10/15/2016 2:31:08 AM
Stop Time  : 10/15/2016 2:36:01 AM
Total (GB) : 140
Result     : Success
Id         : 22d09531-431c-43f1-a916-2cefa0354a6a

Job Name   : Temp Backup Job (Reverse Incremental)
Start Time : 10/15/2016 2:31:08 AM
Stop Time  : 10/15/2016 2:36:01 AM
Total (GB) : 280
Result     : Success
Id         : 22d09531-431c-43f1-a916-2cefa0354a6a

[Backerupper]

Any thoughts on this?

[veremin]

Even though the described behaviour looks like a complete mystery, we've been able to confirm it. Cannot say anything about the root cause at the moment. Thanks.

[Backerupper]

Is it safe to assume that this is found a bit late and won't be fixed in 9.5?

[veremin]

Most likely, it won't. We are yet to find the root cause. Investigation process goes slower then usual, as all our resources are concentrated on 9.5 release. Thanks.

[Backerupper]

Here's another example with a different trigger

This time it is tape backup sessions and the data double occurs after running GetDetails()

Yes, I realize that this may not be the supported way to get tape sessions. The problem is that Get-VBRSession returns very little helpful information.
I just found it odd that this is having the same behavior as the code above.

Code: Select all

$HourstoCheck = 16

$tapeJob = Get-VBRTapeJob -Name "CentOS Backup to Tape Job"
$tpSessions = [veeam.backup.core.cbackupsession]::GetByJob($tapeJob.id)

# Gather sessions within $HourstoCheck
$sessions = $tpSessions | ?{$_.CreationTime -ge (Get-Date).AddHours(-$HourstoCheck)}

# Output Session Info
$sessions | Select @{Name="Job Name"; Expression = {$_.Name}},
  @{Name="Start Time"; Expression = {$_.CreationTime}},
  @{Name="Stop Time"; Expression = {$_.EndTime}},
  @{Name="Total (GB)"; Expression = {[Math]::Round($_.Progress.ProcessedSize/1GB,2)}},
  Result, ID

Foreach ($session in $sessions) {
  $session.GetDetails() | Out-Null
}

# Output Session Info
$sessions | Select @{Name="Job Name"; Expression = {$_.Name}},
  @{Name="Start Time"; Expression = {$_.CreationTime}},
  @{Name="Stop Time"; Expression = {$_.EndTime}},
  @{Name="Total (GB)"; Expression = {[Math]::Round($_.Progress.ProcessedSize/1GB,2)}},
  Result, ID

Code: Select all

Job Name   : CentOS Backup to Tape Job
Start Time : 10/28/2016 6:00:09 AM
Stop Time  : 10/28/2016 6:13:41 AM
Total (GB) : 19
Result     : Success
Id         : e0cf3fa8-1091-486d-9cdb-aca99cbe276a

Job Name   : CentOS Backup to Tape Job
Start Time : 10/28/2016 6:00:09 AM
Stop Time  : 10/28/2016 6:13:41 AM
Total (GB) : 38
Result     : Success
Id         : e0cf3fa8-1091-486d-9cdb-aca99cbe276a

[veremin]

Correct, the issue doesn't seem to be specific to particular job type. The processed data gets doubled, whenever you execute some inner method of job session object.

The causing factor is still unclear for us. Most likely, we will get back to this topic, once 9.5 is released.

Thanks.

[Backerupper]

Any update on this?
I'm seeing it is still an issue with 9.5 Update 2

[veremin]

While we're investigating the said behaviour, you can workaround the issue by re-assigning $sessions variable after calling internal method. Thanks.