apache / apache/incubator-pegasus
backup: unexpected cancel operation
- Dominant language
- C++
- Stars
- 2.1k
- Forks
- 328
- PR merge metrics
- No merged PRs in 30d
Description
## Bug Report
Please answer these questions before submitting your issue. Thanks!
### 1. What did you do?
If possible, provide a recipe for reproducing the error.
Normal setup. 2019/7/28.
4-day period of backup, scheduled at 3:00 am.
### 2. What did you expect to see?
The most recent backup was ended at 7/26, which means no backup task should be run before 7/30.
### 3. What did you see instead?
A backup cancel operation heavily blocked the replica-server‘s read/write handling.
The logs:
```
D2019-07-28 00:25:39.307 (1564244739307908603 a21b) replica.replica13.0404000d395dfa0e: replica_backup.cpp:760:set_backup_context_cancel(): 1.110@10.114.11.26:60801: cancel backup progress, backup_request = backup_request(pid=1.110, policy=policy_info(policy_name=daily_bak, backup_provider_type=fds_wq), app_name=feeds_user_history, backup_id=1564081494642)
D2019-07-28 00:25:39.307 (1564244739307919494 a215) replica.replica7.0404000757e03026: replica_backup.cpp:760:set_backup_context_cancel(): 1.32@10.114.11.26:60801: cancel backup progress, backup_request = backup_request(pid=1.32, policy=policy_info(policy_name=daily_bak, backup_provider_type=fds_wq), app_name=feeds_user_history, backup_id=1564081494642)
D2019-07-28 00:25:39.307 (1564244739307930085 a225) replica.replica23.04040017b116af54: replica_backup.cpp:760:set_backup_context_cancel(): 1.72@10.114.11.26:60801: cancel backup progress, backup_request = backup_request(pid=1.72, policy=policy_info(policy_name=daily_bak, backup_provider_type=fds_wq), app_name=feeds_user_history, backup_id=1564081494642)
D2019-07-28 00:25:39.307 (1564244739307941464 a21c) replica.replica14.0404000edf16ed14: replica_backup.cpp:760:set_backup_context_cancel(): 1.111@10.114.11.26:60801: cancel backup progress, backup_request = backup_request(pid=1.111, policy=policy_info(policy_name=daily_bak, backup_provider_type=fds_wq), app_name=feeds_user_history, backup_id=1564081494642)
E2019-07-28 00:25:39.308 (1564244739308003269 a23e) replica.local_app23.0400a1e6f74f8101: replica_stub.cpp:1392:response_client(): 1.111@10.114.11.26:60801: read fail: client = 10.132.17.44:19602, code = RPC_RRDB_RRDB_MULTI_GET, timeout = 110, status = replication::partition_status::PS_INACTIVE, error = ERR_INVALID_STATE
```
The perf-counter `replica*eon.replica_stub*cold.backup.recent.cancel.count` was raised up to 9 at the moment. (0 for normal)
### 4. What version of Pegasus are you using?
1.11.3 (modified version for duplication).
Contributor guide
Research direction
Start by tracing the cancellation path at replica_backup.cpp:760:set_backup_context_cancel() and the read failure at replica_stub.cpp:1392:response_client(), using the supplied logs and backup recent cancel counter as evidence. Investigate why cancellation occurs before the stated next backup date and why it blocks replica read/write handling. Done means the unexpected cancellation and resulting RPC failures are prevented or their cause is clearly resolved.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- cpp
- Domain
- databases, distributed-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 25/100