Strange backend message lastPgEvent (v2.0.3.6-2.0.3.6_canary_2018-04-23)

Hi,

If I run the Version v2.0.3.6-2.0.3.6_canary_2018-04-23 I face same strange problems with the backend message lastPgEvent. It shows strange values for file processing and progress?

Here are two events:

lastPgEvent : {
"BackupID":"7",
"TaskID":2,
"BackendAction":"List",
"BackendPath":null,
"BackendFileSize":-1,
"BackendFileProgress":0,
"BackendSpeed":-1,
"BackendIsBlocking":false,
"CurrentFilename":"E:\\!duplicati test\\Long-Subfolder-1\\even-longer-foldername\\final-folder-name-very-long-too\\testdumpfile1",
"CurrentFilesize":519045120,
"CurrentFileoffset":137,
"Phase":"Backup_ProcessingFiles",
"OverallProgress":0,
"ProcessedFileCount":0,
"ProcessedFileSize":0,
"TotalFileCount":5,
"TotalFileSize":231,
"StillCounting":false
}

and

lastPgEvent : {
"BackupID":"7",
"TaskID":2,
"BackendAction":"List",
"BackendPath":null,
"BackendFileSize":-1,
"BackendFileProgress":0,
"BackendSpeed":-1,
"BackendIsBlocking":false,
"CurrentFilename":"E:\\!duplicati test\\Long-Subfolder-1\\even-longer-foldername\\final-folder-name-very-long-too\\testdumpfile2",
"CurrentFilesize":137,
"CurrentFileoffset":137,
"Phase":"Backup_ProcessingFiles",
"OverallProgress":0,
"ProcessedFileCount":0,
"ProcessedFileSize":0,
"TotalFileCount":5,
"TotalFileSize":231,
"StillCounting":false
}

FileSize of testdumpfile1 is correct (519.045.120 Byte) but the “CurrentFileoffset” of 137 never changes during backup. The second testdumpfile2 is significantly(!) bigger than indicated “CurrentFilesize” of 137 and with that file it was the same that the “CurrentFileoffset” of 137 never changed.

If I switch back to Version v2.0.3.5-2.0.3.5_canary_2018-04-13 everything is fine again. With both versions I can run a backups and a restore.

Can someone confirm this behavior or is there something wrong with my build?

I can’t confirm the behavior but I can confirm that 2.0.3.6 is known to have some issues so I’d strongly recommend you stay with 2.0.3.5 for the moment.

I’m going to tag @kenkendk on this as I think he’s close to being ready to put out a new canary version but I don’t know whether or not he’s address this particular issue in what’s been fixed so far.

(Oh, and I edited your post to make the JSON more readable by starting the block with triple-tics and the word “json” (so: ```json) and ending it with just triple-tics. The line formatting I did manually.)

Yes, it looks like a reporting issue with the canary.

The new code is running on multiple files in parallel, so maybe that is causing problems.

I found the problem. The progress was also reporting on metadata, which caused problems because the metadata path is the same as the source data path. This explains the small number (137) being reported.

I have fixed it by ignoring metadata, as it tends to be very small.

1 Like

Thanks a lot for looking at it and fixing it!

I believe this fix has rolled with 2.0.3.7 canary, so if you happen to update to it please let us know whether or not it fixes the odd lastPgEvent messages you were getting. :slight_smile:

1 Like

Yes lastPgEvent is now back on track! Problem solved.

BUT: master progress bar at the top of the index.html is no longer updated, no speed indication nor number of remaining files. Try to figure it out myself, but if someone can step in :blush: I would be happy.

Seems to be a “cosmetic error” because backing up and restoring files work great so far!