search

moleculerjs / moleculer

:rocket: Progressive microservices framework for Node.js
https://moleculer.services/
MIT License
6.17k stars 587 forks source link

Improved retry policy #95

Closed icebob closed 6 years ago

icebob commented 7 years ago

Make a better action call retry settings & logic, with exponencial backoff. Options In broker settings:

retryPolicy: {
        retries: 5,
        delay: 200,
        maxDelay: 1000,
        factor: 2,
        check: err => !!err.retryable
}

In the next version the MoleculerError error class has a retryable property. If it's true, the ServiceBroker retry to call the action by retry policy settings. There is a MoleculerRetryableError error class where this property is true defaultly.

The current retryCount option will be removed.

TomKaltz commented 6 years ago

I couldn't get retry to work. I throw MoleculerRetryableError in my service and the caller does not retry.

icebob commented 6 years ago

Did you set requestRetry in broker options or retryCount in calling options?

TomKaltz commented 6 years ago

After some more testing I realized there is some nuance. I will post the scenarios and results later.

On Tue, May 15, 2018 at 04:58 Icebob notifications@github.com wrote:

Did you set requestRetry in broker options or retryCount in calling options?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/moleculerjs/moleculer/issues/95#issuecomment-389112081, or mute the thread https://github.com/notifications/unsubscribe-auth/AC0_IbXlNDNmKFgADOWiUJ0qc5TLyxyYks5tyqapgaJpZM4PROdI .

-- Thomas Kaltz III Sent from Gmail Mobile

TomKaltz commented 6 years ago

These 2 brokers are run in different processes. The call seems to be retried only twice even though I set call retryCount to 5. Same results when broker option requestRetry set to 5 as well.

broker.createService({
  name: "vidispine",
  actions: {
    getApprovalRequestedSavedSearch(){
        return new Promise((resolve, reject)=>{
          setTimeout(()=>{
            let er = new MoleculerRetryableError("AXIOS ERROR TRY AGAIN",500,'PLEASE RETRY')
            er.retryable = true
            reject(er)
          },2000)
        })
    },
  },
})
broker.createService({
  name: "testservice",
  async started() {
    broker.waitForServices(['vidispine'],3000).then(()=>{
      broker.call('vidispine.getApprovalRequestedSavedSearch',null,{retryCount:5})
        .then(broker.logger.info)
        .catch(((e)=>{
          broker.logger.error({
            error: e.name,
            retryCount: e.ctx.retryCount,
          })
        }))
    })
  }
})

This is the log for the calling broker...

[2018-05-15T19:33:04.903Z] INFO  tk-macbook-pro.local-70032/BROKER: Moleculer v0.12.4 is starting...
[2018-05-15T19:33:04.906Z] INFO  tk-macbook-pro.local-70032/BROKER: Node ID: tk-macbook-pro.local-70032
[2018-05-15T19:33:04.906Z] INFO  tk-macbook-pro.local-70032/BROKER: Namespace: <not defined>
[2018-05-15T19:33:04.907Z] INFO  tk-macbook-pro.local-70032/REGISTRY: Strategy: RoundRobinStrategy
[2018-05-15T19:33:04.909Z] INFO  tk-macbook-pro.local-70032/BROKER: Transporter: NatsTransporter
[2018-05-15T19:33:04.912Z] INFO  tk-macbook-pro.local-70032/REGISTRY: '$node' service is registered.
[2018-05-15T19:33:04.912Z] DEBUG tk-macbook-pro.local-70032/BROKER: Broadcast '$services.changed' local event.
[2018-05-15T19:33:04.914Z] INFO  tk-macbook-pro.local-70032/REGISTRY: 'testservice' service is registered.
[2018-05-15T19:33:04.915Z] DEBUG tk-macbook-pro.local-70032/BROKER: Broadcast '$services.changed' local event.
[2018-05-15T19:33:04.916Z] INFO  tk-macbook-pro.local-70032/TRANSIT: Connecting to the transporter...
[2018-05-15T19:33:04.928Z] INFO  tk-macbook-pro.local-70032/BROKER: Waiting for service(s) 'vidispine'...
[2018-05-15T19:33:04.928Z] DEBUG tk-macbook-pro.local-70032/BROKER: 0 of 1 services are available. Waiting further...
[2018-05-15T19:33:04.933Z] INFO  tk-macbook-pro.local-70032/TRANSPORTER: NATS client is connected.
[2018-05-15T19:33:04.934Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Send DISCOVER packet to 'all nodes'
[2018-05-15T19:33:04.937Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Incoming INFO packet from 'tk-macbook-pro.local-69846'
[2018-05-15T19:33:04.938Z] DEBUG tk-macbook-pro.local-70032/BROKER: Broadcast '$node.connected' local event.
[2018-05-15T19:33:04.938Z] INFO  tk-macbook-pro.local-70032/REGISTRY: Node 'tk-macbook-pro.local-69846' connected.
[2018-05-15T19:33:05.437Z] DEBUG tk-macbook-pro.local-70032/BROKER: Broadcast '$transporter.connected' local event.
[2018-05-15T19:33:05.438Z] INFO  tk-macbook-pro.local-70032/BROKER: Waiting for service(s) 'vidispine'...
[2018-05-15T19:33:05.439Z] INFO  tk-macbook-pro.local-70032/BROKER: Service(s) 'vidispine' are available.
[2018-05-15T19:33:05.440Z] DEBUG tk-macbook-pro.local-70032/BROKER: Call 'vidispine.getApprovalRequestedSavedSearch' action on 'tk-macbook-pro.local-69846' node.
[2018-05-15T19:33:05.440Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Send 'vidispine.getApprovalRequestedSavedSearch' request to 'tk-macbook-pro.local-69846' node.
[2018-05-15T19:33:05.440Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Send REQ packet to 'tk-macbook-pro.local-69846'
[2018-05-15T19:33:05.441Z] INFO  tk-macbook-pro.local-70032/BROKER: ServiceBroker with 2 service(s) is started successfully.
[2018-05-15T19:33:05.442Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Send INFO packet to 'all nodes'
[2018-05-15T19:33:05.932Z] INFO  tk-macbook-pro.local-70032/BROKER: Service(s) 'vidispine' are available.
[2018-05-15T19:33:05.932Z] DEBUG tk-macbook-pro.local-70032/BROKER: Call 'vidispine.getApprovalRequestedSavedSearch' action on 'tk-macbook-pro.local-69846' node.
[2018-05-15T19:33:05.933Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Send 'vidispine.getApprovalRequestedSavedSearch' request to 'tk-macbook-pro.local-69846' node.
[2018-05-15T19:33:05.933Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Send REQ packet to 'tk-macbook-pro.local-69846'
[2018-05-15T19:33:07.445Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Incoming RES packet from 'tk-macbook-pro.local-69846'
[2018-05-15T19:33:07.446Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Response 'vidispine.getApprovalRequestedSavedSearch' received from 'tk-macbook-pro.local-69846'.
[2018-05-15T19:33:07.449Z] ERROR tk-macbook-pro.local-70032/BROKER: { error: 'MoleculerRetryableError', retryCount: 5 }
[2018-05-15T19:33:07.943Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Incoming RES packet from 'tk-macbook-pro.local-69846'
[2018-05-15T19:33:07.944Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Response 'vidispine.getApprovalRequestedSavedSearch' received from 'tk-macbook-pro.local-69846'.
[2018-05-15T19:33:07.944Z] ERROR tk-macbook-pro.local-70032/BROKER: { error: 'MoleculerRetryableError', retryCount: 5 }
[2018-05-15T19:33:08.357Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Incoming HEARTBEAT packet from 'tk-macbook-pro.local-69846'
[2018-05-15T19:33:10.649Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Send HEARTBEAT packet to 'all nodes'
[2018-05-15T19:33:13.360Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Incoming HEARTBEAT packet from 'tk-macbook-pro.local-69846'
^C[2018-05-15T19:33:14.698Z] DEBUG tk-macbook-pro.local-70032/BROKER: Broadcast '$transporter.disconnected' local event.
[2018-05-15T19:33:14.698Z] DEBUG tk-macbook-pro.local-70032/TRANSIT: Send DISCONNECT packet to 'all nodes'
icebob commented 6 years ago

Thanks, I will check it.

icebob commented 6 years ago

Hmm, it's an ugly bug, because the retryable prop of Error is not transferred to the caller broker.

icebob commented 6 years ago

Fixed. Will be released in the next 0.12.5 version.