TryAbort selectively proposing only aborted txns

I have a cluster of two groups, each of which has three nodes.
When I was performing read and write operations at the same time, a problem that could not be inquired suddenly occurred. I went to check the log and found that the leader of group 1 kept prompting to terminate the transaction. At the same time another group(group 2) can provide services. When you query predicates that are in the group 2, the result is returned correctly.

What’s wrong with that? I need help badly!

dgraph version:1.0.14

The log on the leader of the group 1:

W0829 13:05:58.095411  123223 node.go:87] A tick missed to fire. Node blocks too long!
W0829 13:05:58.155451  123223 node.go:87] A tick missed to fire. Node blocks too long!
W0829 13:05:58.175423  123223 node.go:87] A tick missed to fire. Node blocks too long!
W0829 13:05:58.195483  123223 node.go:87] A tick missed to fire. Node blocks too long!
W0829 13:05:58.215440  123223 node.go:87] A tick missed to fire. Node blocks too long!
W0829 13:05:58.235441  123223 node.go:87] A tick missed to fire. Node blocks too long!
W0829 13:05:58.255440  123223 node.go:87] A tick missed to fire. Node blocks too long!
W0829 13:05:58.433941  123223 draft.go:764] Raft.Ready took too long to process: 170ms. Most likely due to slow disk: 0s. Num entries: 0. MustSync: false
I0829 13:08:09.455606  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:08:09.458027  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:08:09.458097  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:08:09.458322  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:08:39.455521  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:08:39.457891  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:08:39.457924  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:08:39.458003  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:09:09.455522  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:09:09.457686  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:09:09.457709  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:09:09.457769  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:09:40.394748  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:09:40.396934  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:09:40.396967  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:09:40.397013  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:10:09.455562  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:10:09.457359  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:10:09.457385  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:10:09.457438  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:10:39.455511  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:10:39.457836  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:10:39.457883  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:10:39.457973  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:11:09.455533  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:11:09.457877  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:11:09.457911  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:11:09.458000  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:11:39.455550  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:11:39.457524  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:11:39.457603  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:11:39.457700  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:12:10.437805  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:12:10.440039  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:12:10.440080  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:12:10.440199  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:12:39.455672  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:12:39.490693  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:12:39.490760  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:12:39.490866  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:13:09.455486  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:13:09.457546  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:13:09.457582  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:13:09.457638  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:13:39.455473  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:13:39.457659  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:13:39.457690  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:13:39.457747  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:14:09.455470  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:14:09.457800  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:14:09.457833  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:14:09.457899  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:14:40.430894  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:14:40.433232  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:14:40.433254  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:14:40.433313  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:15:09.455517  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:15:09.458029  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:15:09.458059  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:15:09.458128  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:15:39.455543  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:15:39.458194  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:15:39.458228  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:15:39.458328  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >

[hadoop@BXPL-BD-60-17 ~]$
[hadoop@BXPL-BD-60-17 ~]$ tail -f /usr/local/graphbase/dgraph/alph
a_1.log
I0829 13:15:39.458228  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:15:39.458328  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:16:09.455536  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:16:09.458064  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:16:09.458091  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:16:09.458181  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:16:39.455580  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:16:39.457926  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:16:39.457955  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:16:39.458023  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:17:10.331771  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:17:10.334214  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:17:10.334292  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:17:10.334398  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:17:39.455535  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:17:39.457780  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:17:39.457812  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:17:39.457883  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >
I0829 13:18:09.455508  123223 draft.go:931] Found 1 old transactions. Acting to abort them.
I0829 13:18:09.457562  123223 draft.go:891] TryAbort 1 txns with start ts. Error: <nil>
I0829 13:18:09.457598  123223 draft.go:898] TryAbort returned with
delta: txns:<start_ts:1080528 >
I0829 13:18:09.457697  123223 draft.go:915] TryAbort selectively proposing only aborted txns: txns:<start_ts:1080528 >

Can you please upgrade to v1.0.16? Or, check the release notes for v1.0.15 and v1.0.16? There were a bunch of fixes around this area.

Also pushed another fix to release/v1.0 branch. We should do a release tomorrow. You can compile from source and try this branch too.

Happy to provide you binaries, email me on aman[AT]dgraph.io.

Yes, I have tried to upgrade the version of Dgraph to 1.0.16, and then starts the service with a new version based on the original data, but the current situation is that the group with the problem cannot even elect a leader.image

@CalicoBox please try the v1.0.17 release binaries, which addresses this issue by reducing the rate of sent proposals in the system.

I upgraded dgraph to 1.0.17, but the situation is no different from that of 1.0.16. Group1 still failed to elect a leader

same error in 20.07

Seeing the same behavior in 2.0.0-rc1 as well as 20.07 when performing bulk upsert operations.

@Valdanito @n3integration Are you seeing this error repeatedly where Dgraph seems simply stuck doing these? Or, does this show up only once in a while?

Open transactions that haven’t had any activity for 5 minutes trigger these “Found N old transactions. Acting to abort them.” logs where Dgraph will abort these txns in the background. So, these logs are expected to happen if you have txns that were opened but not committed.

In my case this only appears occasionally.