For information, the progress bar makes it about one third of the way across before it trips
And displays
Daniel
I’ve added some additional diagnostic logging. Please try uploading a file that was failing before and let me know the filename and when you tried.
Is it fortunate or unfortunate that the file loaded properly this morning!?!
Maybe you can spot what improved.
Page is
/library/projects/Europa_Full_Current_Map
File uploaded is
/gls/3/d/EuropaCurrentMapV310.vmod
Daniel
That’s unlucky. I changed no code beyond adding some additional logging.
I need somebody who can reproduce the problem to do so and let me know they have.
I got some free time late this afternoon, but the file failed to upload. I’m getting the same error.
-Joel
This is what I see in the logs from earlier today:
2026-01-22T00:09:24.438747Z INFO request{source=158.62.192.93 method=POST uri=h
ttp://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/M
odule/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: starting add_file
2026-01-22T00:09:24.440159Z INFO request{source=158.62.192.93 method=POST uri=h
ttp://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/M
odule/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: created temp file uploads
/atmp_13510757fb3e5bd6d2069716ab41a2a4b27
2026-01-22T00:09:24.440187Z INFO request{source=158.62.192.93 method=POST uri=h
ttp://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/M
odule/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: 87
2026-01-22T00:09:24.440195Z INFO request{source=158.62.192.93 method=POST uri=h
ttp://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/M
odule/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: 96
2026-01-22T00:09:24.440197Z INFO request{source=158.62.192.93 method=POST uri=h
ttp://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/M
odule/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: 101
2026-01-22T00:14:24.469962Z INFO request{source=158.62.192.93 method=POST uri=http://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/Module/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: finished processing request latency=300033 ms status=408
The third, fourth, and fifth entries give line numbers.
The relevant code is:
pub async fn stream_to_writer<S, W>(
stream: S,
writer: W
) -> Result<(String, u64), io::Error>
where
S: Stream<Item = Result<Bytes, io::Error>> + Send,
W: AsyncWrite
{
info!("{}", line!());
// make hashing reader
let mut hasher = Sha256::new();
let reader = InspectReader::new(
StreamReader::new(stream),
|buf| hasher.update(buf)
);
info!("{}", line!());
// read stream
futures::pin_mut!(reader);
futures::pin_mut!(writer);
info!("{}", line!());
let size = tokio::io::copy(&mut reader, &mut writer).await?;
let sha256 = format!("{:x}", hasher.finalize());
info!("{}", line!());
Ok((sha256, size))
}
What we’re not seeing in the logs is the last info!. The time from the first log message to the second to last is 1.4ms, but almost 6 minutes elapsed between that and the last.
I’ve added more another info! between writing the file and finalizing the hash. Please try again and let me know when you do.
This is likely to require quite a few more tries to solve. Thank you for continuing to help troubleshoot.
Ok, I tried again this morning. It made it about 2/3 before failing.
-Joel
That confirmed for me that your upload doesn’t make it past
let size = tokio::io::copy(&mut reader, &mut writer).await?;
The is the line that reads all the data from the stream (via a hasher) and writes it to disk. I’m going to consult with the tokio discord to see if they can give me any ideas about why that could take so long, but only for some uploads.
I’m not a programmer, so I don’t pretend to read the code, but have been a (rather innocent and naive) project director with a team of programmers who did, so I ask the silly questions that sometimes help…
When it says “await”, might it need more time to write than it took to read?
Maybe not helpful. I thought I’d ask.
Daniel
The await keyword in Rust means that you’re calling an asynchronous function, and you want execution to resume here when it finishes. It’s how you resolve the futures that asynchronous functions return.
Good guess, but it’s not that.
I’ve added yet more logging, so we can see exactly how far the upload gets. Please try again.
Sorry for the delay here. Busy weekend. I tried and got the same 408 error.
Hey Mark, try logging out and logging back in. That seems to fix the 401 error.
-Joel T
You’re going to keep getting the error while I’m adding diagnostic logging. That’s expected.
I tried again 401 error. logged out and in several times.
On this attempt, I saw:
2026-01-26T04:24:37.057946Z INFO request{source=158.62.195.181 method=POST uri=http://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/Module/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: starting add_file
...
2026-01-26T04:24:37.059744Z INFO request{source=158.62.195.181 method=POST uri=http://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/Module/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: 87
2026-01-26T04:24:37.059752Z INFO request{source=158.62.195.181 method=POST uri=http://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/Module/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: 102
...
2026-01-26T04:29:36.847820Z INFO request{source=158.62.195.181 method=POST uri=http://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/Module/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: 102564826
2026-01-26T04:29:36.847825Z INFO request{source=158.62.195.181 method=POST uri=http://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/Module/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: 102564915
2026-01-26T04:29:37.061842Z INFO request{source=158.62.195.181 method=POST uri=http://vassalengine.org/v1/projects/Assault_Sicily_43_-_Gela_Beachhead/packages/Module/1.2.1/AssaultSicily1.2.1.vmod version=HTTP/2.0}: finished processing request latency=300026 ms status=408
The log entries with just a number are indicating how many bytes of the file have been read. The file is 272173883 bytes in total; processing only got through 102564915 bytes before timing out. That’s a bit over a third of the entire file. (There’s one log entry for each read from the stream, thousands in total; I’ve excerpted here the first two and last two to establish a frame of reference.)
The reads are far, far smaller than I was expecting. The first read advanced to offset 87, and the second one only to 107. There are a lot of tiny reads. There are also some which are 8192 bytes, which probably corresponds to having filled an 8KB buffer. Doing a huge number small reads is not what I was expecting to see; that’s going to be slower than a smaller number of large reads. I think the huge number of small reads is why the upload is timing out for you; I don’t know why this is happening for some people and not others.
I’ve made a small change that I’d like to see the effect of. Previously, the hasher wrapped the stream reader, which means that every read from the stream went directly to the hasher. When the reads are small, this means many calls to the hasher for small amounts of data. I’ve moved the hasher to wrap the writer instead. The writer is called only on full buffers, so this should result in fewer calls to the hasher on larger amounts of data.
Please try uploading the file again.
I can’t tell if I’ve fixed the problem unless someone having it tries uploading a file again and lets me know that’s happened.
I tried last night and again this morning. Same error.
-Joel T.