During an update we checkpoint after each operation that we perform on disk. This is needed in order to continue an update after an update failure/reboot/etc. An update payload can have a few thousand operations (I've seen 7000) (each operation is basically says write this data into this place on disk.) But 100K seems a bit excessive. Adding senj@ to see if this high number is WAI or not?!
We maybe able to reduce that by reducing the number of checkpoints though.

For each operation we have to write 6 prefs to save the progress, see DeltaPerformer::CheckpointUpdateProgress().
If there are 7k operations, that's 42k times, there're also other usage of prefs but I think those should be less than 1k total, this is still way less than 100k.

We probably don't have to save the progress that aggressively, right now we do it after each operation complete, and the current size limit for each replace operation is 2MB (soft_chunk_size), if we increase this, we should have fewer operations, less checkpoints and slightly smaller payload.
However the downside is that during applying an operation, UE can not respond to any DBus request, we will also send status update less frequently.
Also we don't split/merge any diff operations right now, so this limit applies to replace and copy operations only, which is relatively fast compared to diff operations, and we already have very large diff operations that's significantly larger than this limit (Chrome).

I propose:
1. Increase soft_chunk_size to 4MB or 8MB.
2. Merge small diff operations.
3. Splitting large diff operations without hurting payload size requires significant change to diff generation process, we can do this later.

We also have the write cache which writes in 1MB blocks. But for the sake of checkpointing, we flush the cache even if only a small portion of it is full.
I think it would be more reasonable and effective to figure out a way to:
- Make sure the write cache is almost full before flushing it.
- Write checkpoints after a flush. This forces more that one operation be retried after a reboot/restart in the middle of the update, but I think the cost associated with it is not much.

This will reduce the number of writes to like: 2GB/1M * 6 == 12000 instead of 100K.

Of course these are in addition to the solutions Sen suggested.

But we have to flush if we seek, and for diff operations, having multiple extents are quite common. So if we do that we have to skip checkpoint if flush is triggered by seeking.

i only had a snippet of a strace log from the operation and it had ~40k ops, so i guessed that had i retained the full log, it'd be like twice as many.  i can re-run the full thing to get the actual number of creat syscalls, but ...

imo, even 10k ops is way more than is reasonable.  i understand we want to checkpoint things, but it looks like the granularity here is excessive beyond and normal needs we have for processing an update.  excess i/o in the stateful partition directly impacts the rest of the system and how responsive it is during an update.

i'm guessing part of the checkpointing idea is that, during a long operation (like slow network or disk?), we make sure we can resume at a reasonable point and not get wedged forever.  can we factor in timing in some way with the checkpoints ?  if we're downloading & processing things quickly, then there's no need to checkpoint hundreds of times a second right ?  if we could process things that fast in the first place, seems reasonable to assume that we could resume them as quickly as well ?  so we shouldn't need to checkpoint more than once every second or so ?

i'm not familiar with the UE internals to say how feasible this is though, so just food for thought.

Yeah good idea, I think we can keep track of the time of last checkpoint and skip if less than certain amount of time has passed.
What value do you guys think is appropriate? 10s? 30s?

we can start conservative and go with 1s or 5s since it's a big deviation from what we've done in the past

Yeah, that's a good idea. I never looked at it that way. With enough bandwidth the whole update takes no more than 3 minutes I think. With lower bandwidth larger checkpoint time frames might be inefficient. I think 10s should be reasonable. wdyt?

I replicated this on samus and saw 70789 creat calls updating between 10323.58.0 and 10895.78.0.

For you if wanted to work on this :)

Thanks, I'll give it a go!

Seems like the culprit might be writes to update-duration-uptime, which accounts for ~65000 calls to creat on my samus build.

I experimented a bit - limiting checkpoints to once every 10 seconds reduced the number of creat calls by about 5000, which isn't a huge impact.

That said, we write to update-duration-uptime every time we receive any amount of data over the network (see PayloadState::DownloadProgress). It seems to me like the main purpose of calling into download progress is to keep track of our throughput while connected to a given URL so we can give up and try a new one if we stop making forward progress. Uptime looks like it's purely used in metrics collection (I only found one reader - PayloadState::CollectAndReportSuccessfulUpdateMetrics), and it looks like it's just tacked onto DownloadProgress for the sake of convenience. Assuming most updates take about 3 minutes, we're persisting this metric once every ~3 ms, which seems like way more resolution than we need here.

I tried limiting writes to update-duration-uptime to at most once per second, and this combined with the less frequent checkpointing reduced the number of calls to creat to 194 in total.

Does anyone with more knowledge of UE see any issues with limiting the frequency of update-duration-uptime writes? I think we might also be able to forgo the checkpoint optimization, since it's not as large a contributor as we thought. Thoughts?

The following revision refers to this bug:
  https://chromium.googlesource.com/aosp/platform/system/update_engine/+/0e452c92bf5fd1a8737170cfd333e50db8cd7f1d

commit 0e452c92bf5fd1a8737170cfd333e50db8cd7f1d
Author: Colin Howes <chowes@google.com>
Date: Wed Nov 07 04:19:28 2018

update_engine: Reduce prefs writes during update

Currently we checkpoint after every operation during an update in order
to allow us to resume if an update is interrupted for some reason. In
addition, we write the current uptime duration every time we receive
data over the network in order to collect total uptime metrics when an
update finishes, even if it was interrupted by a restart. In practice,
this results in a massive number of writes to prefs files during an
update (~70000 calls to creat on the samus build I tested).

This change introduces rate limiting to both of these mechanisms, such
that checkpoints and changes in uptime are persisted at most once per
second. This reduces the number of calls to creat to around 650.

BUG= chromium:898648 
TEST=Perform an update while running strace:
strace -p <pidof update_engine> -f -e '!read,write,sendto,recvfrom'

Change-Id: Icadc8de4efdebf480ef37c6ef69603e250212102
Reviewed-on: https://chromium-review.googlesource.com/1316467
Commit-Ready: ChromeOS CL Exonerator Bot <chromiumos-cl-exonerator@appspot.gserviceaccount.com>
Tested-by: Amin Hassani <ahassani@chromium.org>
Reviewed-by: Amin Hassani <ahassani@chromium.org>

[modify] https://crrev.com/0e452c92bf5fd1a8737170cfd333e50db8cd7f1d/payload_consumer/delta_performer.cc
[modify] https://crrev.com/0e452c92bf5fd1a8737170cfd333e50db8cd7f1d/payload_consumer/delta_performer.h
[modify] https://crrev.com/0e452c92bf5fd1a8737170cfd333e50db8cd7f1d/payload_state.cc

Thanks @chowes