Spurious ames: breach peer [~ship-name]

[nisfeb]

Describe the bug
A few weeks ago I booted a ship on the wrong machine and it started from an old pier. I stopped it quickly (less than a minute). There were never 2 instances of this ship running and I didn't notice any communication issues. Then, several weeks later, I booted a different ship and during boot I saw ames: breach pier [~ship-name]. I'm still able to use everything as normal. My messages come in and go out without issue.

I also ran the below on both the ship that was incorrectly booted and the ship that manifested the ames log. Both ships gave the same result for both commands:

> .^((unit rift) j+/=ryft=/~ship-name)
[~ 0]
> .^((unit life) j+/=lyfe=/~ship-name)
[~ 1] 

To Reproduce
Steps to (maybe?) reproduce the behaviour:

1. Boot ship on old pier
2. Stop ship and boot again on up-to-date pier
3. Boot another ship and see ames: breach pier [~ship-name] for the ship from steps 1 and 2.

Expected behaviour
No ames: breach pier [~ship-name] in logs.

System (please supply the following information, if relevant):

• OS: Ubuntu 22.04
• Urbit: 1.13
• 0v1r.0fp5a.98elp.votc5.3ne9d.aei0r.0k1pm.dr69j.iukr2.067p8.2ucn6

[zalberico]

Running an old pier will cause issues with your ship on the network - if it was only for a short time I think that means those issues will be less obvious, but still present (you likely won't be able to talk to some handful of ships the old pier reached out to).

[joemfb]

I solicited this issue from @nisfeb. Running an old pier will certainly cause problems in most scenarios, but it's impossible for me to imagine how that could synthesize a breach notification. This points at least some flakiness in %ames/%jael interaction, possibly something much worse.

[permezel]

Just booted mine today and got a breach peer. There is only one version of my planet, to the best of my knowledge. I have had it hosted on a Vultr VPS for many months, but the script to kick it off keeps getting killed, and I never check back, and so I am currently trying to get back up-to-date.

What does "breach peer" mean?

urbit 1.22
boot: home is /home/urbit/urbit/passur-mosfur
loom: mapped 2048MB
lite: arvo formula 2a2274c9
lite: core 4bb376f0
lite: final state 4bb376f0
loom: mapped 2048MB
boot: protected loom
live: loaded: MB/641.581.056
boot: installed 652 jets
---------------- playback starting ----------------
pier: replaying events 7738842-7738932
pier: (7738932): play: done
---------------- playback complete ----------------
                     vere: checking version compatibility
ames: live on 37691
conn: listening on /home/urbit/urbit/passur-mosfur/.urb/conn.sock
eyre: canceling [i=//http-server/0v1h.2vvi7/12/3 t=~]
eyre: canceling [i=//http-server/0v1h.2vvi7/22/6 t=~]
http: web interface live on http://localhost:8080
http: loopback live on http://localhost:12321
pier (7738943): live
ames: czar nem.urbit.org: ip .66.228.53.179
ames: czar zod.urbit.org: ip .35.247.119.159
ames: czar ber.urbit.org: ip .35.226.110.63
ames: czar dys.urbit.org: ip .157.90.16.237
ames: czar dev.urbit.org: ip .35.227.173.38
ames: czar bus.urbit.org: ip .35.247.126.229
ames: czar ten.urbit.org: ip .104.196.239.18
ames: czar feb.urbit.org: ip .34.82.25.47
ames: czar wet.urbit.org: ip .34.121.77.1
ames: czar lur.urbit.org: ip .35.233.250.88
ames: czar tyr.urbit.org: ip .208.87.131.244
ames: breach peer [~passur-mosfur ~fabbel]
versioned nack for [entity=~hiddev-dannut name=%vanes-5343] in %graph-pull-hook
watch-ack
/gx/~hiddev-dannut/graph-store/~2023.3.10..00.41.11..102a/graph/~hiddev-dannut/vanes-5343/noun
/lib/graph/hoon:<[14 3].[20 5]>
/lib/graph/hoon:<[88 3].[89 41]>
/lib/graph/hoon:<[87 3].[89 41]>
/lib/graph/hoon:<[86 3].[89 41]>
/app/graph-push-hook/hoon:<[254 5].[254 29]>
...

[Fang-]

@permezel A "breach peer" notification by itself isn't harmful or indicative of a problem. breach peer [~x ~y] simply says that you (~x) noticed that someone you talked to at some point (~y) breached their ship. It is not something that is usually cause for concern. The issue here is about a case where that gets printed more often than it should.

[yosoyubik]

I don't think there's an issue with the log shared by @permezel (unless of course that a breach never happened, but looking at the network explorer, ~fabbel breached about a month ago).

@nisfeb's case is interesting because there was never a breach, I presume. The print happens in %ames after receiving a gift from %jael. %jael gets all azimuth events from /app/azimuth. A spurious breach notification could happen if we are notified of a peer's rift, after we had its %keys—the first time, so rift 0—so /app/azimuth will send us %rift and %keys events in the wrong order... But looking at the code path in %jael, this will not happen for rift 0 because the comparison is +gth and both the rift we get as an event and the (bunted) from the peer are 0.

/app/azimuth actually gives us the diffs as keys first and then rift—we flop the diffs before we return them. But that seems ok if those peers were actually breaching (increasing the rift) in the past, I think, so the print in this case makes sense.

As a note, both %rift and %keys diffs have a boot=? flag because if we load azimuth state from a snapshot we might be skipping some intermediate rift/life and going straight to whatever is in the snapshot (this was addressed here)

I still can't see how this can happen for rift=0 but I'm trying to see If I can reproduce this.