Project

General

Profile

Actions

Bug #50422

open

Error: finished tid 1 when last_acked_tid was 2

Added by Sage Weil about 3 years ago. Updated almost 3 years ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
Tiering
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(RADOS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

2021-04-19T01:44:37.828 INFO:tasks.rados.rados.0.smithi093.stdout:2838:  writing smithi09337594-433 from 736437 to 1471575 tid 1
2021-04-19T01:44:37.831 INFO:tasks.rados.rados.0.smithi093.stdout:2838:  writing smithi09337594-433 from 2176090 to 2336437 tid 2
2021-04-19T01:44:37.832 INFO:tasks.rados.rados.0.smithi093.stdout:2839: delete oid 351 current snap is 188
2021-04-19T01:44:37.848 INFO:tasks.rados.rados.0.smithi093.stdout:2839: done (3 left)
2021-04-19T01:44:37.849 INFO:tasks.rados.rados.0.smithi093.stdout:2840: write oid 343 current snap is 188
2021-04-19T01:44:37.849 INFO:tasks.rados.rados.0.smithi093.stdout:2840:  seq_num 1093 ranges {770051=485636,1776701=511047}
2021-04-19T01:44:37.855 INFO:tasks.rados.rados.0.smithi093.stdout:2840:  writing smithi09337594-343 from 770051 to 1255687 tid 1
2021-04-19T01:44:37.862 INFO:tasks.rados.rados.0.smithi093.stdout:2840:  writing smithi09337594-343 from 1776701 to 2287748 tid 2
2021-04-19T01:44:37.862 INFO:tasks.rados.rados.0.smithi093.stdout:2836:  expect (ObjNum 946 snap 133 seq_num 946)
2021-04-19T01:44:38.433 INFO:tasks.rados.rados.0.smithi093.stdout:2836: done (3 left)
2021-04-19T01:44:38.433 INFO:tasks.rados.rados.0.smithi093.stdout:2841: read oid 104 snap -1
2021-04-19T01:44:38.433 INFO:tasks.rados.rados.0.smithi093.stdout:2841:  expect (ObjNum 1085 snap 182 seq_num 1085)
2021-04-19T01:44:38.434 INFO:tasks.rados.rados.0.smithi093.stdout:2842: copy_from oid 321 from oid 165 current snap is 188
2021-04-19T01:44:38.434 INFO:tasks.rados.rados.0.smithi093.stdout:2840:  finishing write tid 1 to smithi09337594-343
2021-04-19T01:44:38.434 INFO:tasks.rados.rados.0.smithi093.stdout:2838:  finishing write tid 2 to smithi09337594-433
2021-04-19T01:44:38.434 INFO:tasks.rados.rados.0.smithi093.stdout:2838:  finishing write tid 1 to smithi09337594-433

/a/sage-2021-04-18_22:27:23-rados-wip-sage-testing-2021-04-18-1607-distro-basic-smithi/6056848
description: rados/thrash/{0-size-min-size-overrides/3-size-2-min-size 1-pg-log-overrides/short_pg_log
2-recovery-overrides/{more-partial-recovery} backoff/peering_and_degraded ceph clusters/{fixed-2
openstack} crc-failures/default d-balancer/crush-compat mon_election/classic msgr-failures/fastclose
msgr/async-v2only objectstore/bluestore-bitmap rados supported-random-distro$/{centos_8}
thrashers/morepggrow thrashosds-health workloads/cache-snaps}
Actions #1

Updated by Neha Ojha almost 3 years ago

  • Category set to Tiering
  • Priority changed from High to Normal

Looks like a cache tiering+short pg log bug

2021-04-19T01:44:38.434 INFO:tasks.rados.rados.0.smithi093.stdout:2842: copy_from oid 321 from oid 165 current snap is 188
2021-04-19T01:44:38.434 INFO:tasks.rados.rados.0.smithi093.stdout:2840:  finishing write tid 1 to smithi09337594-343
2021-04-19T01:44:38.434 INFO:tasks.rados.rados.0.smithi093.stdout:2838:  finishing write tid 2 to smithi09337594-433
2021-04-19T01:44:38.434 INFO:tasks.rados.rados.0.smithi093.stdout:2838:  finishing write tid 1 to smithi09337594-433
2021-04-19T01:44:38.435 INFO:tasks.rados.rados.0.smithi093.stderr:Error: finished tid 1 when last_acked_tid was 2
2021-04-19T01:44:38.436 INFO:tasks.rados.rados.0.smithi093.stderr:/home/jenkins-build/build/workspace/ceph-dev-new-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos8/DIST/centos8/MACHINE_SIZE/gigantic/release/17.0.0-3350-g8c873b45/rpm/el8/BUILD/ceph-17.0.0-3350-g8c873b45/src/test/osd/RadosModel.h: In function 'virtual void WriteOp::_finish(TestOp::CallbackInfo*)' thread 7f050effd700 time 2021-04-19T01:44:38.078536+0000
2021-04-19T01:44:38.436 INFO:tasks.rados.rados.0.smithi093.stderr:/home/jenkins-build/build/workspace/ceph-dev-new-build/ARCH/x86_64/AVAILABLE_ARCH/x86_64/AVAILABLE_DIST/centos8/DIST/centos8/MACHINE_SIZE/gigantic/release/17.0.0-3350-g8c873b45/rpm/el8/BUILD/ceph-17.0.0-3350-g8c873b45/src/test/osd/RadosModel.h: 1051: ceph_abort_msg("abort() called")
2021-04-19T01:44:38.436 INFO:tasks.rados.rados.0.smithi093.stderr: ceph version 17.0.0-3350-g8c873b45 (8c873b451da32374d057795324dfbb6da04bff3e) quincy (dev)
2021-04-19T01:44:38.436 INFO:tasks.rados.rados.0.smithi093.stderr: 1: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0xe5) [0x7f05229c9c46]
2021-04-19T01:44:38.437 INFO:tasks.rados.rados.0.smithi093.stderr: 2: (WriteOp::_finish(TestOp::CallbackInfo*)+0x666) [0x55b037241546]
2021-04-19T01:44:38.437 INFO:tasks.rados.rados.0.smithi093.stderr: 3: (write_callback(void*, void*)+0x1d) [0x55b03726177d]
2021-04-19T01:44:38.437 INFO:tasks.rados.rados.0.smithi093.stderr: 4: /lib64/librados.so.2(+0xa56e6) [0x7f0523d956e6]
2021-04-19T01:44:38.437 INFO:tasks.rados.rados.0.smithi093.stderr: 5: /lib64/librados.so.2(+0xc0a95) [0x7f0523db0a95]
2021-04-19T01:44:38.437 INFO:tasks.rados.rados.0.smithi093.stderr: 6: /lib64/librados.so.2(+0xc2d88) [0x7f0523db2d88]
2021-04-19T01:44:38.438 INFO:tasks.rados.rados.0.smithi093.stderr: 7: /lib64/librados.so.2(+0xc815a) [0x7f0523db815a]
2021-04-19T01:44:38.438 INFO:tasks.rados.rados.0.smithi093.stderr: 8: /lib64/libstdc++.so.6(+0xc2ba3) [0x7f052124dba3]
2021-04-19T01:44:38.438 INFO:tasks.rados.rados.0.smithi093.stderr: 9: /lib64/libpthread.so.0(+0x814a) [0x7f0521e0a14a]
2021-04-19T01:44:38.438 INFO:tasks.rados.rados.0.smithi093.stderr: 10: clone()
Actions

Also available in: Atom PDF