timeout error not happening in node v6 #48

vigneshnrfs · 2016-08-30T12:16:01Z

I tried installing the latest version of seneca on node v6.

I am using seneca-amqp-transport. When I try calling a pattern that does not even exist, the seneca instance does not even throw a timeout error.

However, it works as expected in seneca v2.0.1.

Explicitly setting the timeout as below does not help either.

var seneca = Seneca({
  tag: 'some-name',
  timeout: 500,
  log: 'silent',
  debug: {
    undead: false,
    short_logs: false,
  },
  strict: {
    result: true,
    add: false,
    find: true,
    maxloop: 11
  }
})

nfantone · 2016-08-30T13:42:47Z

Interesting. TBH, I haven't tried Seneca 3.0.0, yet - though, all unit tests run fine on it.

I'll give it a spin and get back to you.

nfantone · 2016-08-30T14:39:26Z

@vigneshnrfs Tried it with both node 5.12.0 and 6.5.0 + seneca 3.0.0 and all my desktop tests ran fine.

$ ~/seneca-amqp-transport on git:develop ✖︎ [15:29:12]
→ node -v
v6.5.0

$ ~/seneca-amqp-transport on git:develop ✖︎ [15:29:19]
→ npm -v
3.10.6

$ ~/seneca-amqp-transport on git:develop ✖︎ [15:29:23]
→ AMQP_URL=amqp://guest@guest:my.rabbitmq.server:5672 node examples/client.js
{"kind":"notice","notice":"hello","level":"info","seneca":"arpyjxxb899k/1472567371003/1009/3.0.0/-","when":1472567371038}


# Error stacktrace was shortened for legibility
{"notice":"seneca: Action role:create failed: [TIMEOUT]."

Could you try reproducing what I just did here? Just run the examples/client.js script without any listener. Don't forget to set AMQP_URL to some valid AMQP broker instance.

vigneshnrfs · 2016-08-31T07:11:19Z

Hi.. tried the same as above. But the result is the same.

FDLMC945:amqp-test vignesh$ node -v
v6.5.0
FDLMC945:amqp-test vignesh$ npm -v
3.10.3
FDLMC945:amqp-test vignesh$ npm ls
seneca-amqp-transport@1.0.2-dev /Users/vignesh/Documents/amqp-test
├─┬ amqplib@0.4.2
// ...

FDLMC945:amqp-test vignesh$ AMQP_URL=amqp://guest:guest@localhost:5672 examples/client.js 
{"kind":"notice","notice":"hello","level":"info","seneca":"l33f7ne3ckam/1472627245919/37716/3.0.0/-","when":1472627245971}
Run…
Run…
Run…
Run…
Run…
Run…
Run…
Run…
^C
FDLMC945:amqp-test vignesh$

The 'Run...' message is emitted everytime setInterval function executes.

I ran the same with just seneca 2.1.0 and it works as expected.

FDLMC945:amqp-test vignesh$ cat package.json 
{
  "name": "seneca-amqp-transport",
  "version": "1.0.2-dev",
  "codename": "Transcendent threepwood",
  "description": "AMQP transport plugin for seneca.js",
  "main": "index.js",
  "files": [
    "index.js",
    "lib/*",
    "defaults.json"
  ],
  "scripts": {
    "test": "gulp test",
    "validate": "gulp validate"
  },
  "repository": {
    "type": "git",
    "url": "git@github.com:disintegrator/seneca-amqp-transport.git"
  },
  "keywords": [
    "seneca",
    "plugin",
    "amqp",
    "transport",
    "rabbitmq",
    "zmq",
    "activemq",
    "microservice",
    "rpc"
  ],
  "author": "Nicolás Fantone <nfantone@gmail.com> (https://github.com/nfantone)",
  "contributors": [
    "George Haidar <ghaidar0@gmail.com>",
    "Chris Spiliotopoulos <chrysanthos.spiliotopoulos@gmail.com> (https://github.com/chefArchitect)"
  ],
  "license": "MIT",
  "bugs": {
    "url": "https://github.com/seneca-contrib/seneca-amqp-transport/issues"
  },
  "homepage": "https://github.com/seneca-contrib/seneca-amqp-transport",
  "dependencies": {
    "amqplib": "^0.4.2",
    "amqpuri": "^1.0.2",
    "bluebird": "^3.4.2",
    "jsonic": "^0.2.2",
    "lodash": "^4.15.0",
    "seneca": "^2.0.0",
    "shortid": "^2.2.6"
  },
  "devDependencies": {
    "chai": "^3.5.0",
    "chai3-json-schema": "^1.2.1",
    "dirty-chai": "^1.2.2",
    "eslint": "^3.3.1",
    "eslint-config-seneca": "^3.0.0",
    "eslint-config-xo-space": "^0.14.0",
    "eslint-plugin-hapi": "^4.0.0",
    "eslint-plugin-standard": "^2.0.0",
    "gulp": "^3.9.1",
    "gulp-eslint": "^3.0.1",
    "gulp-if": "^2.0.1",
    "gulp-istanbul": "^1.1.0",
    "gulp-load-plugins": "^1.2.4",
    "gulp-mocha": "^3.0.1",
    "gulp-release": "^1.1.0",
    "pre-commit": "^1.1.3",
    "sinon": "^1.17.5",
    "sinon-bluebird": "^3.0.2",
    "sinon-chai": "^2.8.0"
  },
  "pre-commit": [
    "validate"
  ]
}
FDLMC945:amqp-test vignesh$ npm ls
seneca-amqp-transport@1.0.2-dev /Users/vignesh/Documents/amqp-test
├─┬ amqplib@0.4.2
// ...

FDLMC945:amqp-test vignesh$ AMQP_URL=amqp://guest:guest@localhost:5672 examples/client.js 
2016-08-31T07:14:27.569Z e96kosu4m6ig/1472627667540/37816/- INFO    hello   Seneca/2.1.0/e96kosu4m6ig/1472627667540/37816/- 
2016-08-31T07:14:29.653Z e96kosu4m6ig/1472627667540/37816/- INFO    client  {type:amqp,pin:role:create,url:amqp://guest:guest@localhost:5672}   
Run…
Run…
Run…
Run…
Run…
Run…
2016-08-31T07:14:42.781Z e96kosu4m6ig/1472627667540/37816/- ERROR   act client$         OUT     role:create 11117   {max:100,min:25,role:create}    ENTRY   (gabjm10a5lau)  -   seneca: Action role:create failed: [TIMEOUT:gplzaoameb2n/kgdx8q2ymfwr:11111<1472627682773-1472627671660:undefined]. act_execute {id:gplzaoameb2n/kgdx8q2ymfwr,gate:false,ungate:false,desc:null,time:{start:147262

nfantone · 2016-08-31T10:46:38Z

@vigneshnrfs I believe I know what's going on. On Seneca 3.0.0 the default timeout has doubled.
Take a look at this commit.

So, could you try waiting longer on your first run? It should take half the time for a TIMEOUT error to arise in Seneca 2.1.0.

vigneshnrfs · 2016-08-31T10:56:25Z

I've waited for about 2 minutes and no error is thrown.

I'm wondering does is it specific to amqp-transport or an issue in the seneca core module itself.

nfantone · 2016-08-31T11:04:18Z

I've waited for about 2 minutes and no error is thrown.

I know this is going to sound rather insulting, but I gotta ask: are you completely positive? Because, in your example I can read 8 "Run..." prints on the 3.0.1 run, which would total a waiting time of 16s - given that the interval for setInterval is 2000. So that would not timeout in Seneca 3.0.0, but would in Seneca 2.1.0. It explains your whole situation.

I'm wondering does is it specific to amqp-transport or an issue in the seneca core module itself.

The transport does not manage actions specifically. And is not responsible for triggering timeouts at that level. It does, however, handle timeouts when reaching the broker or on idle connections.

vigneshnrfs · 2016-08-31T11:08:49Z

I am absolutely positive. I ran the scripts just before replying to you.

FDLMC945:amqp-test vignesh$ AMQP_URL=amqp://guest:guest@localhost:5672 examples/client.js 
{"kind":"notice","notice":"hello","level":"info","seneca":"50s7ncz4syex/1472640786756/39850/3.0.0/-","when":1472640786785}
Run…
Run…
Run…
Run…
Run…
Run…
Run…
Run…
// A whole lotta "Run..."

^C
FDLMC945:amqp-test vignesh$

nfantone · 2016-08-31T11:23:38Z

Ok, I re-cloned the repo, started from scratch and now I'm getting the same behaviour you're describing. I wonder what was different on my first attempt. I'll open an issue on senecajs/seneca. Let's see what they can tell us about this.

Thanks for letting me know.

nfantone · 2016-08-31T11:32:54Z

@vigneshnrfs Feel free to follow this up on senecajs/seneca#517

vigneshnrfs · 2016-08-31T13:18:36Z

@nfantone Thanks a lot.

mcdonnelldean · 2016-09-12T15:16:01Z

Folks, just a heads up, still digging here. The only changes I can see where doubling time-out and updating the Gate Executor. Still not sure the root cause, as soon as I find it I'll let ye know.

nfantone · 2016-09-22T11:53:52Z

@mcdonnelldean Could you find a possible suspect on this?

@vigneshnrfs Any chance you figured this out?

vigneshnrfs · 2016-09-23T05:10:40Z

Haven't really looked into it. For the moment, using v2.

nfantone · 2016-09-27T20:26:07Z

@vigneshnrfs I'm testing with latest 3.2.1. Seems like the issue was resolved. I'll get back to you with a report very soon.

nfantone · 2016-09-27T21:15:29Z

@vigneshnrfs Ok, sadly this is still going on in latest release. Already reached out to @mcdonnelldean for input.

mcdonnelldean · 2016-09-27T21:19:24Z

The only thing that has changed that could be responsible is the gate executor. No other part of transport got any significant updates. @rjrodger any thoughts on this.

Amqp is broken on 3

On 27 Sep 2016 10:15 p.m., Nicolás Fantone notifications@github.com wrote:

@vigneshnrfshttps://github.com/vigneshnrfs Ok, sadly this is still going on in latest release. Already reached out to @mcdonnelldeanhttps://github.com/mcdonnelldean for input.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHubhttps://github.com//issues/48#issuecomment-250001188, or mute the threadhttps://github.com/notifications/unsubscribe-auth/ADdT6XU0AL_2RAHmk2Qe4l5j4pRqntHoks5quYdxgaJpZM4Jwdam.

mcdonnelldean · 2016-10-11T15:36:44Z

@nfantone We are going to put some time on this issue in the next couple of days, we have someone working with seneca who should be able to drill in to this and figure out just what happened.

paolochiodi · 2016-10-12T10:46:01Z

@nfantone @vigneshnrfs I'm able to confirm this is a bug on the seneca side that causes the timeout to not work for most actions (not only related to amqp or even transports).

The bug actually resides in seneca gate-executor, you can follow the resolution here senecajs/gate-executor#16

nfantone · 2016-10-12T12:08:39Z

@paolochiodi Replied to you in senecajs/gate-executor#16. I'm going to leave this issue open for people coming to the transport to be aware of the bug until it's fixed.

nfantone · 2016-10-25T22:21:50Z

Fixed in seneca@3.2.2 🎉

nfantone added bug question and removed bug labels Aug 30, 2016

nfantone mentioned this issue Aug 31, 2016

Global timeout not firing on 3.2.1 senecajs/seneca#517

Closed

nfantone added the bug label Aug 31, 2016

nfantone self-assigned this Sep 27, 2016

paolochiodi mentioned this issue Oct 12, 2016

timeout bug senecajs/gate-executor#16

Closed

nfantone removed their assignment Oct 12, 2016

nfantone closed this as completed Oct 25, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

timeout error not happening in node v6 #48

timeout error not happening in node v6 #48

vigneshnrfs commented Aug 30, 2016 •

edited by nfantone

nfantone commented Aug 30, 2016 •

edited

nfantone commented Aug 30, 2016

vigneshnrfs commented Aug 31, 2016 •

edited by nfantone

nfantone commented Aug 31, 2016 •

edited

vigneshnrfs commented Aug 31, 2016

nfantone commented Aug 31, 2016

vigneshnrfs commented Aug 31, 2016 •

edited by nfantone

nfantone commented Aug 31, 2016

nfantone commented Aug 31, 2016

vigneshnrfs commented Aug 31, 2016

mcdonnelldean commented Sep 12, 2016

nfantone commented Sep 22, 2016 •

edited

vigneshnrfs commented Sep 23, 2016

nfantone commented Sep 27, 2016

nfantone commented Sep 27, 2016

mcdonnelldean commented Sep 27, 2016

mcdonnelldean commented Oct 11, 2016

paolochiodi commented Oct 12, 2016 •

edited

nfantone commented Oct 12, 2016 •

edited

nfantone commented Oct 25, 2016

timeout error not happening in node v6 #48

timeout error not happening in node v6 #48

Comments

vigneshnrfs commented Aug 30, 2016 • edited by nfantone

nfantone commented Aug 30, 2016 • edited

nfantone commented Aug 30, 2016

vigneshnrfs commented Aug 31, 2016 • edited by nfantone

nfantone commented Aug 31, 2016 • edited

vigneshnrfs commented Aug 31, 2016

nfantone commented Aug 31, 2016

vigneshnrfs commented Aug 31, 2016 • edited by nfantone

nfantone commented Aug 31, 2016

nfantone commented Aug 31, 2016

vigneshnrfs commented Aug 31, 2016

mcdonnelldean commented Sep 12, 2016

nfantone commented Sep 22, 2016 • edited

vigneshnrfs commented Sep 23, 2016

nfantone commented Sep 27, 2016

nfantone commented Sep 27, 2016

mcdonnelldean commented Sep 27, 2016

mcdonnelldean commented Oct 11, 2016

paolochiodi commented Oct 12, 2016 • edited

nfantone commented Oct 12, 2016 • edited

nfantone commented Oct 25, 2016

vigneshnrfs commented Aug 30, 2016 •

edited by nfantone

nfantone commented Aug 30, 2016 •

edited

vigneshnrfs commented Aug 31, 2016 •

edited by nfantone

nfantone commented Aug 31, 2016 •

edited

vigneshnrfs commented Aug 31, 2016 •

edited by nfantone

nfantone commented Sep 22, 2016 •

edited

paolochiodi commented Oct 12, 2016 •

edited

nfantone commented Oct 12, 2016 •

edited