You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ozone.apache.org by "Aravindan Vijayan (Jira)" <ji...@apache.org> on 2020/06/30 17:49:00 UTC

[jira] [Comment Edited] (HDDS-3894) Noisy log at OM when the requested sequence is not written into DB

    [ https://issues.apache.org/jira/browse/HDDS-3894?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17148855#comment-17148855 ] 

Aravindan Vijayan edited comment on HDDS-3894 at 6/30/20, 5:48 PM:
-------------------------------------------------------------------

[~rakeshr] Thanks for tracking this issue. Since Recon can recover from this, and the frequency of the getUpdatesSince call should be around ~10mins, we may be ok with just suppressing the logs here. But we should understand why this is happening.

Can you share more details on the setup here? 
* Can we check if Recon was talking to the leader/follower OM? Was there a failover before these logs started appearing?
* What is the load on OzoneManager when this happens? Are we running a stress test on OM RocksDB?


was (Author: avijayan):
[~rakeshr] Thanks for tracking this issue. Since Recon can recover from this, and the frequency of the getUpdatesSince call should be around ~10mins, we may be ok with just suppressing the logs here. But we should understand why this is happening.

Can you share more details on the setup here? 
* Is OM HA enabled? Can we check if Recon was talking to the leader/follower OM?
* What is the load on OzoneManager when this happens? Are we running a stress test on OM RocksDB?

> Noisy log at OM when the requested sequence is not written into DB
> ------------------------------------------------------------------
>
>                 Key: HDDS-3894
>                 URL: https://issues.apache.org/jira/browse/HDDS-3894
>             Project: Hadoop Distributed Data Store
>          Issue Type: Bug
>          Components: Ozone Manager, Ozone Recon
>            Reporter: Rakesh Radhakrishnan
>            Assignee: Rakesh Radhakrishnan
>            Priority: Minor
>
> Too many logs at OM, which is noisy. It looks like Recon is making this call to OM to update the delta info. OM can ignore this exception and reduce the log priority to DEBUG or so.
> *Ozone-om.log*
> {code:java}
> 2020-06-26 10:02:52,963 INFO org.apache.ratis.server.raftlog.segmented.SegmentedRaftLogWorker: 5dca58f5-6231-4858-9589-4e64b1435aa4@group-C5BA1605619E-SegmentedRaftLogWorker: Rolled log segment from /data/3/jun27_new1/hadoop-ozone/om/ratis2/bf265839-605b-3f16-9796-c5ba1605619e/current/log_inprogress_106536 to /data/3/jun27_new1/hadoop-ozone/om/ratis2/bf265839-605b-3f16-9796-c5ba1605619e/current/log_106536-106603
> 2020-06-26 10:02:52,982 INFO org.apache.ratis.server.raftlog.segmented.SegmentedRaftLogWorker: 5dca58f5-6231-4858-9589-4e64b1435aa4@group-C5BA1605619E-SegmentedRaftLogWorker: created new log segment /data/3/jun27_new1/hadoop-ozone/om/ratis2/bf265839-605b-3f16-9796-c5ba1605619e/current/log_inprogress_106604
> 2020-06-26 10:09:54,828 ERROR org.apache.hadoop.hdds.utils.db.RDBStore: Unable to get delta updates since sequenceNumber 11268864
> org.rocksdb.RocksDBException: Requested sequence not yet written in the db
>         at org.rocksdb.RocksDB.getUpdatesSince(Native Method)
>         at org.rocksdb.RocksDB.getUpdatesSince(RocksDB.java:3588)
>         at org.apache.hadoop.hdds.utils.db.RDBStore.getUpdatesSince(RDBStore.java:339)
>         at org.apache.hadoop.ozone.om.OzoneManager.getDBUpdates(OzoneManager.java:3422)
>         at org.apache.hadoop.ozone.protocolPB.OzoneManagerRequestHandler.getOMDBUpdates(OzoneManagerRequestHandler.java:257)
>         at org.apache.hadoop.ozone.protocolPB.OzoneManagerRequestHandler.handleReadRequest(OzoneManagerRequestHandler.java:194)
>         at org.apache.hadoop.ozone.protocolPB.OzoneManagerProtocolServerSideTranslatorPB.submitReadRequestToOM(OzoneManagerProtocolServerSideTranslatorPB.java:171)
>         at org.apache.hadoop.ozone.protocolPB.OzoneManagerProtocolServerSideTranslatorPB.processRequest(OzoneManagerProtocolServerSideTranslatorPB.java:109)
>         at org.apache.hadoop.hdds.server.OzoneProtocolMessageDispatcher.processRequest(OzoneProtocolMessageDispatcher.java:74)
>         at org.apache.hadoop.ozone.protocolPB.OzoneManagerProtocolServerSideTranslatorPB.submitRequest(OzoneManagerProtocolServerSideTranslatorPB.java:99)
>         at org.apache.hadoop.ozone.protocol.proto.OzoneManagerProtocolProtos$OzoneManagerService$2.callBlockingMethod(OzoneManagerProtocolProtos.java)
>         at org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:528)
>         at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:1070)
>         at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:985)
>         at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:913)
>         at java.security.AccessController.doPrivileged(Native Method)
>         at javax.security.auth.Subject.doAs(Subject.java:422)
>         at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1876)
>         at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2882)
> 2020-06-26 10:11:08,442 INFO org.apache.ratis.server.raftlog.segmented.SegmentedRaftLogWorker: 5dca58f5-6231-4858-9589-4e64b1435aa4@group-C5BA1605619E-SegmentedRaftLogWorker: Rolling segment log-106604_106637 to index:106637
> 2020-06-26 10:11:08,443 INFO org.apache.ratis.server.raftlog.segmented.SegmentedRaftLogWorker: 5dca58f5-6231-4858-9589-4e64b1435aa4@group-C5BA1605619E-SegmentedRaftLogWorker: Rolling segment log-106638_106654 to index:106654
> 2020-06-26 10:11:08,444 INFO org.apache.ratis.server.raftlog.segmented.SegmentedRaftLogWorker: 5dca58f5-6231-4858-9589-4e64b1435aa4@group-C5BA1605619E-SegmentedRaftLogWorker: Rolling segment log-106655_106671 to index:106671
> {code}
> *Recon.log*
> {code:java}
> 2020-06-26 10:08:55,883 INFO org.apache.hadoop.ozone.recon.fsck.MissingContainerTask: Missing Container task Thread took 88 milliseconds for processing 0 containers.
> 2020-06-26 10:09:54,824 INFO org.apache.hadoop.ozone.recon.spi.impl.OzoneManagerServiceProviderImpl: Syncing data from Ozone Manager.
> 2020-06-26 10:09:54,824 INFO org.apache.hadoop.ozone.recon.spi.impl.OzoneManagerServiceProviderImpl: Obtaining delta updates from Ozone Manager
> 2020-06-26 10:09:54,828 INFO org.apache.hadoop.ozone.recon.spi.impl.OzoneManagerServiceProviderImpl: Number of updates received from OM : 0
> {code}



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

---------------------------------------------------------------------
To unsubscribe, e-mail: ozone-issues-unsubscribe@hadoop.apache.org
For additional commands, e-mail: ozone-issues-help@hadoop.apache.org