You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@accumulo.apache.org by "Eric Newton (Updated) (JIRA)" <ji...@apache.org> on 2012/02/29 14:23:56 UTC
[jira] [Updated] (ACCUMULO-436) tablet merge stuck
[ https://issues.apache.org/jira/browse/ACCUMULO-436?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Eric Newton updated ACCUMULO-436:
---------------------------------
Description:
After 14 hours of randomwalk, a merge operation appeared to be stuck.
Garbage collector was stuck, some tablets were offline:
||\# Online Tablet Servers|| \# Total Tablet Servers|| Loggers Last GC ||\# Tablets ||\# Unassigned||Tablets||Entries||Ingest||Query||Hold Time||OS Load||
|10 |10 |10 |*Running 2/29/12 12:14 PM* |299 |*4* |277.50M |311 |5.53K |— |0.50|
Garbage collector could not get a consistent !METADATA table scan:
{noformat}
29 13:04:10,808 [util.TabletIterator] INFO : Resetting !METADATA scanner to [24q;5f83b8f927c41c9d%00; : [] 9223372036854775807 false,~ : [] 9223372036854775807 false)
29 13:04:11,071 [util.TabletIterator] INFO : Metadata inconsistency : 1419e44259517c51 != 5f83b8f927c41c9d metadataKey = 24q< ~tab:~pr [] 724883 false
{noformat}
Table (id 24q) had a merge in progress:
{noformat}
./bin/accumulo org.apache.accumulo.server.fate.Admin print
txid: 7bea12fa46c40a72 status: IN_PROGRESS op: BulkImport locked: [] locking: [R:24q] top: BulkImport
txid: 08db6105a25c0788 status: IN_PROGRESS op: CloneTable locked: [] locking: [R:24q] top: CloneTable
txid: 5f798db1cab5fdea status: IN_PROGRESS op: BulkImport locked: [] locking: [R:24q] top: BulkImport
txid: 6aa9a8a9b36a4f4d status: IN_PROGRESS op: TableRangeOp locked: [] locking: [W:24q] top: TableRangeOp
txid: 5c6e82e235ec3855 status: IN_PROGRESS op: TableRangeOp locked: [] locking: [W:24q] top: TableRangeOp
txid: 653a9293ba9f1cdc status: IN_PROGRESS op: RenameTable locked: [] locking: [W:24q] top: RenameTable
txid: 651c62eb37136b6e status: IN_PROGRESS op: TableRangeOp locked: [W:24q] locking: [] top: TableRangeOpWait
{noformat}
Scan of table 24q:
{noformat}
scan -b 24q; -e 24q<
24q;073b220b74a75059 loc:135396fb191d4b6 [] 192.168.117.6:9997
24q;073b220b74a75059 srv:compact [] 3
24q;073b220b74a75059 srv:dir [] /t-00031y0
24q;073b220b74a75059 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
24q;073b220b74a75059 srv:time [] M0
24q;073b220b74a75059 ~tab:~pr [] \x00
24q;1419e44259517c51 loc:235396fb184b5cd [] 192.168.117.12:9997
24q;1419e44259517c51 srv:compact [] 3
24q;1419e44259517c51 srv:dir [] /t-00031y1
24q;1419e44259517c51 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
24q;1419e44259517c51 srv:time [] M0
24q;1419e44259517c51 ~tab:~pr [] \x01073b220b74a75059
24q;51fc3e7faea2b7e9 chopped:chopped [] chopped
24q;51fc3e7faea2b7e9 srv:compact [] 3
24q;51fc3e7faea2b7e9 srv:dir [] /t-00031y2
24q;51fc3e7faea2b7e9 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
24q;51fc3e7faea2b7e9 srv:time [] M0
24q;51fc3e7faea2b7e9 ~tab:~pr [] \x011419e44259517c51
24q;5e65b844f2c7f868 chopped:chopped [] chopped
24q;5e65b844f2c7f868 srv:compact [] 3
24q;5e65b844f2c7f868 srv:dir [] /t-00031e1
24q;5e65b844f2c7f868 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
24q;5e65b844f2c7f868 srv:time [] M0
24q;5e65b844f2c7f868 ~tab:~pr [] \x0151fc3e7faea2b7e9
24q;5f83b8f927c41c9d chopped:chopped [] chopped
24q;5f83b8f927c41c9d srv:compact [] 3
24q;5f83b8f927c41c9d srv:dir [] /t-000329w
24q;5f83b8f927c41c9d srv:lock [] tservers/192.168.117.6:9997/zlock-0000000002$135396fb191c4f3
24q;5f83b8f927c41c9d srv:time [] M0
24q;5f83b8f927c41c9d ~tab:~pr [] \x015e65b844f2c7f868
24q< chopped:chopped [] chopped
24q< srv:compact [] 3
24q< srv:dir [] /default_tablet
24q< srv:lock [] tservers/192.168.117.6:9997/zlock-0000000002$135396fb191c4f3
24q< srv:time [] M0
24q< ~tab:~pr [] \x011419e44259517c51
{noformat}
Master Logs
{noformat}
29 13:11:49,903 [state.MergeStats] INFO : Computing next merge state for 24q;6badf28df1d8ece7;37f3488aa92ac056 which is presently MERGING isDelete : false
29 13:11:49,903 [state.MergeStats] INFO : 4 tablets are unassigned 24q;6badf28df1d8ece7;37f3488aa92ac056
{noformat}
The final consistency check is failing because the merge is partially complete. The final step is not "adampotent" enough: partial execution leaves the Repo in a state in which it cannot continue after restart.
was:
After 14 hours of randomwalk, a merge operation appeared to be stuck.
Garbage collector was stuck, some tablets were offline:
||\# Online Tablet Servers|| \# Total Tablet Servers|| Loggers Last GC ||\# Tablets ||\# Unassigned||Tablets||Entries||Ingest||Query||Hold Time||OS Load||
|10 |10 |10 |*Running 2/29/12 12:14 PM* |299 |*4* |277.50M |311 |5.53K |— |0.50|
Garbage collector could not get a consistent !METADATA table scan:
{noformat}
29 13:04:10,808 [util.TabletIterator] INFO : Resetting !METADATA scanner to [24q;5f83b8f927c41c9d%00; : [] 9223372036854775807 false,~ : [] 9223372036854775807 false)
29 13:04:11,071 [util.TabletIterator] INFO : Metadata inconsistency : 1419e44259517c51 != 5f83b8f927c41c9d metadataKey = 24q< ~tab:~pr [] 724883 false
{noformat}
Table (id 24q) had a merge in progress:
{noformat}
./bin/accumulo org.apache.accumulo.server.fate.Admin print
txid: 7bea12fa46c40a72 status: IN_PROGRESS op: BulkImport locked: [] locking: [R:24q] top: BulkImport
txid: 08db6105a25c0788 status: IN_PROGRESS op: CloneTable locked: [] locking: [R:24q] top: CloneTable
txid: 5f798db1cab5fdea status: IN_PROGRESS op: BulkImport locked: [] locking: [R:24q] top: BulkImport
txid: 6aa9a8a9b36a4f4d status: IN_PROGRESS op: TableRangeOp locked: [] locking: [W:24q] top: TableRangeOp
txid: 5c6e82e235ec3855 status: IN_PROGRESS op: TableRangeOp locked: [] locking: [W:24q] top: TableRangeOp
txid: 653a9293ba9f1cdc status: IN_PROGRESS op: RenameTable locked: [] locking: [W:24q] top: RenameTable
txid: 651c62eb37136b6e status: IN_PROGRESS op: TableRangeOp locked: [W:24q] locking: [] top: TableRangeOpWait
{noformat}
Scan of table 24q:
{noformat}
scan -b 24q; -e 24q<
24q;073b220b74a75059 loc:135396fb191d4b6 [] 192.168.117.6:9997
24q;073b220b74a75059 srv:compact [] 3
24q;073b220b74a75059 srv:dir [] /t-00031y0
24q;073b220b74a75059 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
24q;073b220b74a75059 srv:time [] M0
24q;073b220b74a75059 ~tab:~pr [] \x00
24q;1419e44259517c51 loc:235396fb184b5cd [] 192.168.117.12:9997
24q;1419e44259517c51 srv:compact [] 3
24q;1419e44259517c51 srv:dir [] /t-00031y1
24q;1419e44259517c51 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
24q;1419e44259517c51 srv:time [] M0
24q;1419e44259517c51 ~tab:~pr [] \x01073b220b74a75059
24q;51fc3e7faea2b7e9 chopped:chopped [] chopped
24q;51fc3e7faea2b7e9 srv:compact [] 3
24q;51fc3e7faea2b7e9 srv:dir [] /t-00031y2
24q;51fc3e7faea2b7e9 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
24q;51fc3e7faea2b7e9 srv:time [] M0
24q;51fc3e7faea2b7e9 ~tab:~pr [] \x011419e44259517c51
24q;5e65b844f2c7f868 chopped:chopped [] chopped
24q;5e65b844f2c7f868 srv:compact [] 3
24q;5e65b844f2c7f868 srv:dir [] /t-00031e1
24q;5e65b844f2c7f868 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
24q;5e65b844f2c7f868 srv:time [] M0
24q;5e65b844f2c7f868 ~tab:~pr [] \x0151fc3e7faea2b7e9
24q;5f83b8f927c41c9d chopped:chopped [] chopped
24q;5f83b8f927c41c9d srv:compact [] 3
24q;5f83b8f927c41c9d srv:dir [] /t-000329w
24q;5f83b8f927c41c9d srv:lock [] tservers/192.168.117.6:9997/zlock-0000000002$135396fb191c4f3
24q;5f83b8f927c41c9d srv:time [] M0
24q;5f83b8f927c41c9d ~tab:~pr [] \x015e65b844f2c7f868
24q< chopped:chopped [] chopped
24q< srv:compact [] 3
24q< srv:dir [] /default_tablet
24q< srv:lock [] tservers/192.168.117.6:9997/zlock-0000000002$135396fb191c4f3
24q< srv:time [] M0
24q< ~tab:~pr [] \x011419e44259517c51
{nofromat}
Master Logs
{noformat}
29 13:11:49,903 [state.MergeStats] INFO : Computing next merge state for 24q;6badf28df1d8ece7;37f3488aa92ac056 which is presently MERGING isDelete : false
29 13:11:49,903 [state.MergeStats] INFO : 4 tablets are unassigned 24q;6badf28df1d8ece7;37f3488aa92ac056
{noformat}
The final consistency check is failing because the delete is partially complete. The delete step is not "adampotent" enough: partial execution leaves the Repo in a state in which it cannot continue after restart.
> tablet merge stuck
> ------------------
>
> Key: ACCUMULO-436
> URL: https://issues.apache.org/jira/browse/ACCUMULO-436
> Project: Accumulo
> Issue Type: Bug
> Components: master
> Environment: randomwalk with agitation on 10-node test cluster
> Reporter: Eric Newton
> Assignee: Eric Newton
> Fix For: 1.4.0
>
>
> After 14 hours of randomwalk, a merge operation appeared to be stuck.
> Garbage collector was stuck, some tablets were offline:
> ||\# Online Tablet Servers|| \# Total Tablet Servers|| Loggers Last GC ||\# Tablets ||\# Unassigned||Tablets||Entries||Ingest||Query||Hold Time||OS Load||
> |10 |10 |10 |*Running 2/29/12 12:14 PM* |299 |*4* |277.50M |311 |5.53K |— |0.50|
> Garbage collector could not get a consistent !METADATA table scan:
> {noformat}
> 29 13:04:10,808 [util.TabletIterator] INFO : Resetting !METADATA scanner to [24q;5f83b8f927c41c9d%00; : [] 9223372036854775807 false,~ : [] 9223372036854775807 false)
> 29 13:04:11,071 [util.TabletIterator] INFO : Metadata inconsistency : 1419e44259517c51 != 5f83b8f927c41c9d metadataKey = 24q< ~tab:~pr [] 724883 false
> {noformat}
> Table (id 24q) had a merge in progress:
> {noformat}
> ./bin/accumulo org.apache.accumulo.server.fate.Admin print
> txid: 7bea12fa46c40a72 status: IN_PROGRESS op: BulkImport locked: [] locking: [R:24q] top: BulkImport
> txid: 08db6105a25c0788 status: IN_PROGRESS op: CloneTable locked: [] locking: [R:24q] top: CloneTable
> txid: 5f798db1cab5fdea status: IN_PROGRESS op: BulkImport locked: [] locking: [R:24q] top: BulkImport
> txid: 6aa9a8a9b36a4f4d status: IN_PROGRESS op: TableRangeOp locked: [] locking: [W:24q] top: TableRangeOp
> txid: 5c6e82e235ec3855 status: IN_PROGRESS op: TableRangeOp locked: [] locking: [W:24q] top: TableRangeOp
> txid: 653a9293ba9f1cdc status: IN_PROGRESS op: RenameTable locked: [] locking: [W:24q] top: RenameTable
> txid: 651c62eb37136b6e status: IN_PROGRESS op: TableRangeOp locked: [W:24q] locking: [] top: TableRangeOpWait
> {noformat}
> Scan of table 24q:
> {noformat}
> scan -b 24q; -e 24q<
> 24q;073b220b74a75059 loc:135396fb191d4b6 [] 192.168.117.6:9997
> 24q;073b220b74a75059 srv:compact [] 3
> 24q;073b220b74a75059 srv:dir [] /t-00031y0
> 24q;073b220b74a75059 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
> 24q;073b220b74a75059 srv:time [] M0
> 24q;073b220b74a75059 ~tab:~pr [] \x00
> 24q;1419e44259517c51 loc:235396fb184b5cd [] 192.168.117.12:9997
> 24q;1419e44259517c51 srv:compact [] 3
> 24q;1419e44259517c51 srv:dir [] /t-00031y1
> 24q;1419e44259517c51 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
> 24q;1419e44259517c51 srv:time [] M0
> 24q;1419e44259517c51 ~tab:~pr [] \x01073b220b74a75059
> 24q;51fc3e7faea2b7e9 chopped:chopped [] chopped
> 24q;51fc3e7faea2b7e9 srv:compact [] 3
> 24q;51fc3e7faea2b7e9 srv:dir [] /t-00031y2
> 24q;51fc3e7faea2b7e9 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
> 24q;51fc3e7faea2b7e9 srv:time [] M0
> 24q;51fc3e7faea2b7e9 ~tab:~pr [] \x011419e44259517c51
> 24q;5e65b844f2c7f868 chopped:chopped [] chopped
> 24q;5e65b844f2c7f868 srv:compact [] 3
> 24q;5e65b844f2c7f868 srv:dir [] /t-00031e1
> 24q;5e65b844f2c7f868 srv:lock [] tservers/192.168.117.7:9997/zlock-0000000002$3353986642ea7f3
> 24q;5e65b844f2c7f868 srv:time [] M0
> 24q;5e65b844f2c7f868 ~tab:~pr [] \x0151fc3e7faea2b7e9
> 24q;5f83b8f927c41c9d chopped:chopped [] chopped
> 24q;5f83b8f927c41c9d srv:compact [] 3
> 24q;5f83b8f927c41c9d srv:dir [] /t-000329w
> 24q;5f83b8f927c41c9d srv:lock [] tservers/192.168.117.6:9997/zlock-0000000002$135396fb191c4f3
> 24q;5f83b8f927c41c9d srv:time [] M0
> 24q;5f83b8f927c41c9d ~tab:~pr [] \x015e65b844f2c7f868
> 24q< chopped:chopped [] chopped
> 24q< srv:compact [] 3
> 24q< srv:dir [] /default_tablet
> 24q< srv:lock [] tservers/192.168.117.6:9997/zlock-0000000002$135396fb191c4f3
> 24q< srv:time [] M0
> 24q< ~tab:~pr [] \x011419e44259517c51
> {noformat}
> Master Logs
> {noformat}
> 29 13:11:49,903 [state.MergeStats] INFO : Computing next merge state for 24q;6badf28df1d8ece7;37f3488aa92ac056 which is presently MERGING isDelete : false
> 29 13:11:49,903 [state.MergeStats] INFO : 4 tablets are unassigned 24q;6badf28df1d8ece7;37f3488aa92ac056
> {noformat}
> The final consistency check is failing because the merge is partially complete. The final step is not "adampotent" enough: partial execution leaves the Repo in a state in which it cannot continue after restart.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira