2.1.0.2 Beta as Windows 10 Windows service, backing up C: drive to a portable USB drive.
It had been getting a little flaky in the GUI. I forget details. It might have gone disconnected.
The refresh request was not completing, as seen in developer tools and below in Wireshark:
GET /api/v1/auth/refresh HTTP/1.1
Host: localhost:8200
Connection: keep-alive
Cache-Control: max-age=0
sec-ch-ua: "Microsoft Edge";v="131", "Chromium";v="131", "Not_A Brand";v="24"
sec-ch-ua-mobile: ?0
sec-ch-ua-platform: "Windows"
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36 Edg/131.0.0.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7
Sec-Fetch-Site: cross-site
Sec-Fetch-Mode: navigate
Sec-Fetch-User: ?1
Sec-Fetch-Dest: document
Accept-Encoding: gzip, deflate, br, zstd
Accept-Language: en-US,en;q=0.9
Cookie: default-theme=ngax
HTTP/1.1 405 Method Not Allowed
Content-Length: 0
Date: Wed, 11 Dec 2024 14:19:35 GMT
Server: Kestrel
Allow: POST
At some point, I managed to get in, thinking it had finished (I noticed lack of activity). No log.
Turns out that Server had crashed and been restarted by WindowsService. Event log saw it.
Fault bucket 1878496532562272393, type 4
Event Name: APPCRASH
Response: Not available
Cab Id: 0
Problem signature:
P1: Duplicati.Server.exe
P2: 2.1.0.2
P3: 66470000
P4: coreclr.dll
P5: 8.0.624.26715
P6: 66479681
P7: c0000005
P8: 00000000003bb01e
P9:
P10:
Attached files:
\\?\C:\ProgramData\Microsoft\Windows\WER\Temp\WERD625.tmp.mdmp
\\?\C:\ProgramData\Microsoft\Windows\WER\Temp\WER40D7.tmp.WERInternalMetadata.xml
\\?\C:\ProgramData\Microsoft\Windows\WER\Temp\WER5F8B.tmp.xml
\\?\C:\ProgramData\Microsoft\Windows\WER\Temp\WER5FE7.tmp.csv
\\?\C:\ProgramData\Microsoft\Windows\WER\Temp\WER6036.tmp.txt
These files may be available here:
\\?\C:\ProgramData\Microsoft\Windows\WER\ReportArchive\AppCrash_Duplicati.Server_fbe73f31456f99d997385f068b31e15ed8eac33_77701b1f_eaf5e1ad-58a2-4f13-9bec-537b44a9ec98
Analysis symbol:
Rechecking for solution: 0
Report Id: 57c101b6-c025-443d-ba0f-962f719f11b6
Report Status: 268435456
Hashed bucket: 15043ce29c5751ed4a11c2a4c72d6089
Cab Guid: 0
After this was Server restart. 31 seconds before it was:
Category: Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware
EventId: 1
SpanId: 61b97df4e7040d16
TraceId: 6eed8aa74b790a9432299df183ff28eb
ParentId: 0000000000000000
ConnectionId: 0HN8OLGDGO15L
RequestId: 0HN8OLGDGO15L:0000001B
RequestPath: /api/v1/auth/refresh
An unhandled exception has occurred while executing the request.
Exception:
Duplicati.WebserverCore.Exceptions.UnauthorizedException: Authorization failed due to missing cookie.
at Duplicati.WebserverCore.Endpoints.V1.Auth.<>c.<<Map>b__3_0>d.MoveNext()
--- End of stack trace from previous location ---
at Microsoft.AspNetCore.Http.RequestDelegateFactory.<TaskOfTToValueTaskOfObject>g__ExecuteAwaited|92_0[T](Task`1 task)
at Duplicati.WebserverCore.Middlewares.HostnameFilter.InvokeAsync(EndpointFilterInvocationContext context, EndpointFilterDelegate next)
at Duplicati.WebserverCore.Middlewares.LanguageFilter.InvokeAsync(EndpointFilterInvocationContext context, EndpointFilterDelegate next)
at Microsoft.AspNetCore.Http.RequestDelegateFactory.<ExecuteValueTaskOfObject>g__ExecuteAwaited|129_0(ValueTask`1 valueTask, HttpContext httpContext, JsonTypeInfo`1 jsonTypeInfo)
at Duplicati.WebserverCore.Middlewares.WebsocketExtensions.<>c__DisplayClass0_0.<<UseNotifications>b__0>d.MoveNext()
--- End of stack trace from previous location ---
at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddlewareImpl.<Invoke>g__Awaited|10_0(ExceptionHandlerMiddlewareImpl middleware, HttpContext context, Task task)
and before that a lot of “Failed to refresh token” (which I’m used to seeing when on a terminal).
There were some of these. System during backup did see some busy CPU and disk moments:
Category: Microsoft.AspNetCore.Server.Kestrel
EventId: 22
As of "12/11/2024 23:05:09 +00:00", the heartbeat has been running for "00:00:32.6966726" which is longer than "00:00:01". This could be caused by thread pool starvation.
No *crashlog.txt (if its name is similar to the old one), no output to the log file defined in the job.
About → Show log → Stored has nothing. I’m not sure what other clues may be available now.
Last file on the destination was a dindex, which event log and DB agree to. DB state Uploaded.
This was not an initial backup, so probably on a restart it will do a synthetic file list and continue, however I thought I’d report the problem in case there’s any more information to glean from this.