[NETCONF-348] "Please try again" should not result in http code 500 Created: 06/Feb/17  Updated: 15/Mar/19  Resolved: 09/Mar/17

Status: Resolved
Project: netconf
Component/s: netconf
Affects Version/s: None
Fix Version/s: None

Type: Bug
Reporter: Vratko Polak Assignee: Matúš Kubica
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All


External issue ID: 7741

 Description   

Recent (February 2nd) result of Netconf cluster job had a failed test case [0] but the karaf.log [1] message suggests client should retry later. The proper status code for this situation is 503. Netconf code should communicate that to the Restconf code.

Segment from karaf.log suggests that perhaps there is an underlying issue of new Master not being elected, but currently it is not clear whether the Master would get elected later:

2017-02-02 13:16:21,748 | WARN | ult-dispatcher-3 | ReliableDeliverySupervisor | 201 - com.typesafe.akka.slf4j - 2.4.16 | Association with remote system [akka.tcp://opendaylight-cluster-data@10.29.12.204:2550] has failed, address is now gated for [5000] ms. Reason: [Association failed with [akka.tcp://opendaylight-cluster-data@10.29.12.204:2550]] Caused by: [Connection refused: /10.29.12.204:2550]
2017-02-02 13:16:23,473 | WARN | lt-dispatcher-19 | BrokerFacade | 290 - org.opendaylight.netconf.sal-rest-connector - 1.5.0.SNAPSHOT | Exception by reading CONFIGURATION via Restconf: /(urn:opendaylight:test:netconf:crud?revision=2014-10-18)cont
NetconfDocumentedException{message=RemoteDevice

{netconf-test-device}:Master is down. Please try again., errorType=APPLICATION, errorTag=OPERATION_FAILED, errorSeverity=WARNING, errorInfo={}}
at org.opendaylight.netconf.topology.singleton.impl.tx.NetconfProxyDOMTransaction$1.onComplete(NetconfProxyDOMTransaction.java:70)[320:org.opendaylight.netconf.topology-singleton:1.2.0.SNAPSHOT]
at akka.dispatch.OnComplete.internal(Future.scala:258)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.OnComplete.internal(Future.scala:256)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.japi$CallbackBridge.apply(Future.scala:186)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.japi$CallbackBridge.apply(Future.scala:183)[200:com.typesafe.akka.actor:2.4.16]
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:32)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at akka.dispatch.BatchingExecutor$AbstractBatch.processBatch(BatchingExecutor.scala:55)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply$mcV$sp(BatchingExecutor.scala:91)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply(BatchingExecutor.scala:91)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply(BatchingExecutor.scala:91)[200:com.typesafe.akka.actor:2.4.16]
at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:72)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at akka.dispatch.BatchingExecutor$BlockableBatch.run(BatchingExecutor.scala:90)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:39)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:415)[200:com.typesafe.akka.actor:2.4.16]
at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
2017-02-02 13:16:23,476 | ERROR | lt-dispatcher-19 | ExecutionList | 84 - com.google.guava - 18.0.0 | RuntimeException while executing runnable com.google.common.util.concurrent.Futures$6@5738a853 with executor INSTANCE
org.opendaylight.netconf.sal.restconf.impl.RestconfDocumentedException: errors: [RestconfError [error-type: application, error-tag: operation-failed, error-message: Problem to get data from transaction., error-info: NetconfDocumentedException{message=RemoteDevice{netconf-test-device}

:Master is down. Please try again., errorType=APPLICATION, errorTag=OPERATION_FAILED, errorSeverity=WARNING, errorInfo={}}
at org.opendaylight.netconf.topology.singleton.impl.tx.NetconfProxyDOMTransaction$1.onComplete(NetconfProxyDOMTransaction.java:70)
at akka.dispatch.OnComplete.internal(Future.scala:258)
at akka.dispatch.OnComplete.internal(Future.scala:256)
at akka.dispatch.japi$CallbackBridge.apply(Future.scala:186)
at akka.dispatch.japi$CallbackBridge.apply(Future.scala:183)
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:32)
at akka.dispatch.BatchingExecutor$AbstractBatch.processBatch(BatchingExecutor.scala:55)
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply$mcV$sp(BatchingExecutor.scala:91)
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply(BatchingExecutor.scala:91)
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply(BatchingExecutor.scala:91)
at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:72)
at akka.dispatch.BatchingExecutor$BlockableBatch.run(BatchingExecutor.scala:90)
at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:39)
at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:415)
at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
]]
at org.opendaylight.netconf.sal.restconf.impl.BrokerFacade.handlingCallback(BrokerFacade.java:1259)[290:org.opendaylight.netconf.sal-rest-connector:1.5.0.SNAPSHOT]
at org.opendaylight.netconf.sal.restconf.impl.BrokerFacade$2.onFailure(BrokerFacade.java:537)[290:org.opendaylight.netconf.sal-rest-connector:1.5.0.SNAPSHOT]
at com.google.common.util.concurrent.Futures$6.run(Futures.java:1310)[84:com.google.guava:18.0.0]
at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:457)[84:com.google.guava:18.0.0]
at com.google.common.util.concurrent.ExecutionList.executeListener(ExecutionList.java:156)[84:com.google.guava:18.0.0]
at com.google.common.util.concurrent.ExecutionList.execute(ExecutionList.java:145)[84:com.google.guava:18.0.0]
at com.google.common.util.concurrent.AbstractFuture.setException(AbstractFuture.java:202)[84:com.google.guava:18.0.0]
at com.google.common.util.concurrent.SettableFuture.setException(SettableFuture.java:68)[84:com.google.guava:18.0.0]
at org.opendaylight.netconf.topology.singleton.impl.tx.NetconfReadOnlyTransaction$2.onComplete(NetconfReadOnlyTransaction.java:87)[320:org.opendaylight.netconf.topology-singleton:1.2.0.SNAPSHOT]
at org.opendaylight.netconf.topology.singleton.impl.tx.NetconfReadOnlyTransaction$2.onComplete(NetconfReadOnlyTransaction.java:68)[320:org.opendaylight.netconf.topology-singleton:1.2.0.SNAPSHOT]
at akka.dispatch.OnComplete.internal(Future.scala:258)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.OnComplete.internal(Future.scala:256)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.japi$CallbackBridge.apply(Future.scala:186)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.japi$CallbackBridge.apply(Future.scala:183)[200:com.typesafe.akka.actor:2.4.16]
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:32)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at akka.dispatch.BatchingExecutor$AbstractBatch.processBatch(BatchingExecutor.scala:55)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply$mcV$sp(BatchingExecutor.scala:91)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply(BatchingExecutor.scala:91)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply(BatchingExecutor.scala:91)[200:com.typesafe.akka.actor:2.4.16]
at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:72)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at akka.dispatch.BatchingExecutor$BlockableBatch.run(BatchingExecutor.scala:90)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:39)[200:com.typesafe.akka.actor:2.4.16]
at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:415)[200:com.typesafe.akka.actor:2.4.16]
at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)[196:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
Caused by: NetconfDocumentedException{message=RemoteDevice

{netconf-test-device}

:Master is down. Please try again., errorType=APPLICATION, errorTag=OPERATION_FAILED, errorSeverity=WARNING, errorInfo={}}
at org.opendaylight.netconf.topology.singleton.impl.tx.NetconfProxyDOMTransaction$1.onComplete(NetconfProxyDOMTransaction.java:70)[320:org.opendaylight.netconf.topology-singleton:1.2.0.SNAPSHOT]
... 17 more
2017-02-02 13:16:25,632 | INFO | ult-dispatcher-3 | kka://opendaylight-cluster-data) | 201 - com.typesafe.akka.slf4j - 2.4.16 | Cluster Node [akka.tcp://opendaylight-cluster-data@10.29.12.137:2550] - Leader can currently not perform its duties, reachability status: [akka.tcp://opendaylight-cluster-data@10.29.12.137:2550 -> akka.tcp://opendaylight-cluster-data@10.29.12.204:2550: Unreachable [Unreachable] (3), akka.tcp://opendaylight-cluster-data@10.29.13.95:2550 -> akka.tcp://opendaylight-cluster-data@10.29.12.204:2550: Unreachable [Unreachable] (1)], member status: [akka.tcp://opendaylight-cluster-data@10.29.12.137:2550 Up seen=true, akka.tcp://opendaylight-cluster-data@10.29.12.204:2550 Up seen=false, akka.tcp://opendaylight-cluster-data@10.29.13.95:2550 Up seen=true]

[0] https://logs.opendaylight.org/releng/jenkins092/netconf-csit-3node-clustering-only-carbon/435/archives/log.html.gz#s1-s6-t12-k2-k1-k3-k7-k1
[1] https://logs.opendaylight.org/releng/jenkins092/netconf-csit-3node-clustering-only-carbon/435/archives/odl3_karaf.log.gz



 Comments   
Comment by Vratko Polak [ 06/Feb/17 ]

The message returned by Restconf, as it contains different keywords to search for:

<errors xmlns="urn:ietf:params:xml:ns:yang:ietf-restconf"><error><error-type>application</error-type><error-tag>operation-failed</error-tag><error-message>Problem while PUT operations</error-message></error></errors>

Comment by Vratko Polak [ 09/Feb/17 ]

> perhaps there is an underlying issue of new Master not being elected

This Bug is not concerned abut this symptom. Master being down is a bad thing, but it is reported as NETCONF-344.

Comment by Vratko Polak [ 09/Feb/17 ]

This bug is about "Please try again" (caused by whatever reason) turning into status 500 instead of 503.

Comment by Matúš Kubica [ 28/Feb/17 ]

https://git.opendaylight.org/gerrit/#/c/51684/

Generated at Wed Feb 07 20:14:47 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.