Error While intergrating Cube.js with Nodejs Express

[ddkhoa]

Hello,

I've just started learning CubeJS. I followed this article to intergrate CubeJS to NodeJS Express : https://statsbot.co/blog/node-express-analytics-dashboard-with-cubejs/. In the end, when I run the server, there is an infinity loop with theses messages :

GET /cubejs-api/v1/load?query=%7B%22measures%22%3A%5B%22Tweets.count%22%5D%2C%22dimensions%22%3A%5B%22Tweets.location%22%5D%2C%22filters%22%3A%5B%7B%22dimension%22%3A%22Tweets.location%22%2C%22operator%22%3A%22notEquals%22%2C%22values%22%3A%5B%22%22%5D%7D%5D%2C%22limit%22%3A5%7D 200 5017.397 ms - 25
Load Request: {"query":"{"measures":["Tweets.count"],"dimensions":["Tweets.location"],"filters":[{"dimension":"Tweets.location","operator":"notEquals","values":[""]}],"limit":5}","authInfo":{"iat":1560350861,"exp":1560437261}}
Query started: {"query":"SELECT user.location tweets.location, count() tweets.count FROM tweets AS tweets WHERE (user.location <> ?) GROUP BY 1 ORDER BY 2 DESC LIMIT 5","params":[""]}
Missing cache for: {"cacheKey":["SELECT\n user.location tweets.location, count() tweets.count\n FROM\n tweets AS tweets\n WHERE (user.location <> ?) GROUP BY 1 ORDER BY 2 DESC LIMIT 5",[""],[]]}
Missing cache for: {"cacheKey":["select count(*) from tweets AS tweets",[]]}

My .env :
CUBEJS_DB_HOST=localhost
CUBEJS_DB_NAME=twitter
CUBEJS_DB_TYPE=mongobi
CUBEJS_DB_PORT=3307
CUBEJS_API_SECRET=79dff8180bf3f64b916cd110d26729f458b36cbdc69f2ed73d03356a62c63766bc34d605beaa13c7d587dd0b6153504ac378c9893bf6cfafa0f1bdb55e0c4c6b

In index.hbs in views folder, I also modified the cubejs token and apiUrl parameter.

It didn't work, I tried downloading the project from Github but I ran into the same problem.
But, when I create a serverless application using cubejs CLI it worked.

Can someone help me ?
Thank you

[paveltiunov]

Hey @ddkhoa! Thanks for posting this! Could you please run dev server using npm run dev and try to issue some queries using playground or see your database schema?
Also what do you see in your mongod and mongosqld logs?

[ddkhoa]

Hi,
I run the dev server, here is what I saw in log files.

MongoDB Log
2019-06-12T22:18:04.539+0200 I NETWORK [listener] connection accepted from 127.0.0.1:50817 #6 (4 connections now open)
2019-06-12T22:18:05.729+0200 I NETWORK [conn6] received client metadata from 127.0.0.1:50817 conn6: { driver: { name: "mongo-go-driver", version: "local build" }, os: { type: "windows", architecture: "amd64" }, platform: "go1.11.9", application: { name: "mongosqld" } }
2019-06-12T22:18:06.732+0200 I NETWORK [listener] connection accepted from 127.0.0.1:50819 #7 (5 connections now open)
2019-06-12T22:18:06.732+0200 I NETWORK [conn7] received client metadata from 127.0.0.1:50819 conn7: { driver: { name: "mongo-go-driver", version: "local build" }, os: { type: "windows", architecture: "amd64" }, platform: "go1.11.9", application: { name: "mongosqld" } }
2019-06-12T22:18:07.344+0200 I NETWORK [conn7] end connection 127.0.0.1:50819 (4 connections now open)
2019-06-12T22:18:07.344+0200 I NETWORK [conn6] end connection 127.0.0.1:50817 (3 connections now open)
2019-06-12T22:18:08.499+0200 I NETWORK [listener] connection accepted from 127.0.0.1:50822 #8 (4 connections now open)
2019-06-12T22:18:08.499+0200 I NETWORK [conn8] received client metadata from 127.0.0.1:50822 conn8: { driver: { name: "mongo-go-driver", version: "local build" }, os: { type: "windows", architecture: "amd64" }, platform: "go1.11.9", application: { name: "mongosqld" } }
2019-06-12T22:18:09.524+0200 I NETWORK [listener] connection accepted from 127.0.0.1:50824 #9 (5 connections now open)
2019-06-12T22:18:09.524+0200 I NETWORK [conn9] received client metadata from 127.0.0.1:50824 conn9: { driver: { name: "mongo-go-driver", version: "local build" }, os: { type: "windows", architecture: "amd64" }, platform: "go1.11.9", application: { name: "mongosqld" } }
2019-06-12T22:18:09.627+0200 I NETWORK [conn9] end connection 127.0.0.1:50824 (4 connections now open)
2019-06-12T22:18:09.627+0200 I NETWORK [conn5] end connection 127.0.0.1:49796 (3 connections now open)

Mongosqld log
2019-06-12T22:18:03.440+0200 I NETWORK [conn1] connection accepted from 127.0.0.1:50814 #1 (1 connection now open)
2019-06-12T22:18:07.493+0200 I NETWORK [conn1] end connection 127.0.0.1:50814 (0 connections now open)
2019-06-12T22:18:08.500+0200 I NETWORK [conn2] connection accepted from 127.0.0.1:50820 #2 (1 connection now open)
2019-06-12T22:18:18.161+0200 I NETWORK [conn3] connection accepted from 127.0.0.1:50828 #3 (2 connections now open)
2019-06-12T22:18:20.291+0200 I NETWORK [conn3] end connection 127.0.0.1:50828 (1 connection now open)
2019-06-12T22:18:20.292+0200 I NETWORK [conn4] connection accepted from 127.0.0.1:50838 #4 (2 connections now open)
2019-06-12T22:18:22.299+0200 I NETWORK [conn5] connection accepted from 127.0.0.1:50839 #5 (3 connections now open)

And when I run the nodeJS server (npm start), nothing appears in these 2 log files.

[paveltiunov]

@ddkhoa Does playground work for you? If not could you please share all cube.js dev server logs from the launch point in time?

[ddkhoa]

@paveltiunov So let me resume the situation

_ The NodeJS server (launch by command "npm start") didn't work, in server log there's an endless loop. In Mongod and Mongosqld logs, there's nothing. (So there is a problem with the connection to Mongosqld from Nodejs server ?).

_ The playgound (the serverless application created by cubeJS cli, launch by "npm run dev") work, I posted the content of Mongod log and Mongosqld log in the comment above. Here is the log of server.

Compiling schema: {"version":"default_schema_version_1fabc283064e32e3b80721011ed35e85"}
Load Request: {"query":"{"measures":["Tweets.count"],"timeDimensions":[],"filters":[]}","authInfo":{"iat":1560411137,"exp":1560497537}}
Query started: {"query":"SELECT count(tweets.id) tweets.count FROM twitter.tweets AS tweets LIMIT 10000","params":[]}
Missing cache for: {"cacheKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]]}
Missing cache for: {"cacheKey":["select count() from twitter.tweets AS tweets",[]]}
Added to queue: {"priority":10,"queueSize":1,"queryKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]]}
Added to queue: {"priority":0,"queueSize":2,"queryKey":["select count() from twitter.tweets AS tweets",[]]}
Performing query: {"queueSize":2,"queryKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]]}
Performing query: {"queueSize":2,"queryKey":["select count() from twitter.tweets AS tweets",[]]}
Continue wait: {"duration":5002,"query":"SELECT count(tweets.id) tweets.count FROM twitter.tweets AS tweets LIMIT 10000","params":[]}
Continue wait: {"query":"{"measures":["Tweets.count"],"timeDimensions":[],"filters":[]}","authInfo":{"iat":1560411137,"exp":1560497537}}
Load Request: {"query":"{"measures":["Tweets.count"],"timeDimensions":[],"filters":[]}","authInfo":{"iat":1560411137,"exp":1560497537}}
Query started: {"query":"SELECT count(tweets.id) tweets.count FROM twitter.tweets AS tweets LIMIT 10000","params":[]}
Missing cache for: {"cacheKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]]}
Missing cache for: {"cacheKey":["select count() from twitter.tweets AS tweets",[]]}
Performing query completed: {"queueSize":2,"duration":6721,"queryKey":["select count() from twitter.tweets AS tweets",[]]}
Renewed: {"cacheKey":["select count() from twitter.tweets AS tweets",[]]}
Missing cache for: {"cacheKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]]}
Performing query completed: {"queueSize":2,"duration":6738,"queryKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]]}
Renewed: {"cacheKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]]}
Renewed: {"cacheKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]]}
Query completed: {"duration":1721,"query":"SELECT count(tweets.id) tweets.count FROM twitter.tweets AS tweets LIMIT 10000","params":[]}
Load Request Success: {"query":"{"measures":["Tweets.count"],"timeDimensions":[],"filters":[]}","authInfo":{"iat":1560411137,"exp":1560497537}}
Load Request: {"query":"{"measures":["Tweets.count"],"timeDimensions":[],"filters":[]}","authInfo":{"iat":1560411137,"exp":1560497537}}
Query started: {"query":"SELECT count(tweets.id) tweets.count FROM twitter.tweets AS tweets LIMIT 10000","params":[]}
Found cache entry: {"cacheKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]],"time":1560411149394,"renewedAgo":27,"renewalKey":"SQL_QUERY_RESULT_STANDALONE_bf6b0308450446218e700e5b3ab25d8b"}
Using cache for: {"cacheKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]]}
Found cache entry: {"cacheKey":["select count() from twitter.tweets AS tweets",[]],"time":1560411149378,"renewedAgo":44,"renewalKey":"SQL_QUERY_RESULT_STANDALONE_b60b32074a42cee14c9d3b51f45a334a","newRenewalKey":"SQL_QUERY_RESULT_STANDALONE_b60b32074a42cee14c9d3b51f45a334a","renewalThreshold":120}
Using cache for: {"cacheKey":["select count() from twitter.tweets AS tweets",[]]}
Found cache entry: {"cacheKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]],"time":1560411149394,"renewedAgo":29,"renewalKey":"SQL_QUERY_RESULT_STANDALONE_bf6b0308450446218e700e5b3ab25d8b","newRenewalKey":"SQL_QUERY_RESULT_STANDALONE_bf6b0308450446218e700e5b3ab25d8b","renewalThreshold":21600}
Using cache for: {"cacheKey":["SELECT\n count(tweets.id) tweets.count\n FROM\n twitter.tweets AS tweets\n LIMIT 10000",[],[]]}
Query completed: {"duration":4,"query":"SELECT count(tweets.id) tweets.count FROM twitter.tweets AS tweets LIMIT 10000","params":[]}
Load Request Success: {"query":"{"measures":["Tweets.count"],"timeDimensions":[],"filters":[]}","authInfo":{"iat":1560411137,"exp":1560497537}}

[ddkhoa]

@paveltiunov I solved the problem, turns out it's an error of npm when I installed the dependencies. I need to run : "npm audit fix". For information, my node version is 8.9.0 and my npm version is 6.3.0. I closed the thread. Thank you

[paveltiunov]

@ddkhoa Great to hear that you were able to resolve this! But still issue seems pretty weird to me. Could you please provide some more additional context for it? Do you mean you ran dev server from serverless application which worked and express application just didn't? And what's fixed your express application is just npm audit fix command?

[ddkhoa]

Yes, exactly. When I ran the express application, there was a message showing the temporary token. I searched for the string "temporary cube.js token" in express project, I didn't receive any result. I did the same thing inside the serverless project and I found one result in DevServer.js file in node_modules/@cubejs_backend/server-core/core. So I concluded that there were some missing files I ran the command "npm audit fix". That's all. I tried to reproduce the error by deleting node_modules folder and rerun the npm install command but I can't, sorry.