search

openstf / stf

Control and manage Android devices from your browser.
https://openstf.io
Other
13.17k stars 2.71k forks source link

systemd service failing for websocket service #1106

Closed shri-0509 closed 4 years ago

shri-0509 commented 4 years ago

What is the issue or idea you have? docker image for websocket microservice failing Does it only happen on a specific device? Please run adb devices -l and paste the corresponding row.

Please provide the steps to reproduce the issue. whenever i try to run websocket system service using docker image, I am getting below error bin/stf websocket

Options: -h, --help Show help. [boolean] -V, --version Show version. [boolean] --connect-push, -c App-side ZeroMQ PULL endpoint to connect to. [array] [required] --connect-sub, -u App-side ZeroMQ PUB endpoint to connect to. [array] [required] --port, -p The port to bind to. [number] [default: 7110] --secret, -s The secret to use for auth JSON Web Tokens. Anyone who knows this token can freely enter the system if they want, so keep it safe. [string] [required] --ssid, -i The name of the session ID cookie. [string] [default: "ssid"] --storage-url, -r URL to the storage unit. [string] [required]

Each option can be be overwritten with an environment variable by converting the option to uppercase, replacing dashes with underscores and prefixing it with STF_WEBSOCKET_ (e.g. STF_WEBSOCKET_STORAGE_URL).

Unexpected token ...

What is the expected behavior? It systemd service should run normally for websocket service Do you see errors or warnings in the stf local output? If so, please paste them or the full log here.

Please run stf doctor and paste the output here.

issue-label-bot[bot] commented 4 years ago

Issue-Label Bot is automatically applying the label bug to this issue, with a confidence of 0.82. Please mark this comment with :thumbsup: or :thumbsdown: to give our bot feedback!

Links: app homepage, dashboard and code for this bot.

shri-0509 commented 4 years ago

I always see that unexpected token ... in journalctl logs only for websocket service. Is anyone facing the same issue? Please do the needful. @thinkhy any thought on this..

shri-0509 commented 4 years ago

this is the docker version I am using .. Client: Docker Engine - Community Version: 19.03.2 API version: 1.40 Go version: go1.12.8 Git commit: 6a30dfc Built: Thu Aug 29 05:26:49 2019 OS/Arch: darwin/amd64 Experimental: false

Server: Docker Engine - Community Engine: Version: 19.03.2 API version: 1.40 (minimum version 1.12) Go version: go1.12.8 Git commit: 6a30dfc Built: Thu Aug 29 05:32:21 2019 OS/Arch: linux/amd64 Experimental: true containerd: Version: v1.2.6 GitCommit: 894b81a4b802e4eb2a91d1ce216b8817763c29fb runc: Version: 1.0.0-rc8 GitCommit: 425e105d5a03fabd737a126ad93d62a9eeede87f docker-init: Version: 0.18.0 GitCommit: fec3683

p00h commented 4 years ago

I can definitely confirm this unexpected behaviour. There is a standalone Raspberry 4 box with latest CentOS for arm arch.

[root@localhost ~]# stf doctor
2019-10-04T07:03:00.207Z INF/cli:doctor 1121 [*] OS Arch: arm
2019-10-04T07:03:00.213Z INF/cli:doctor 1121 [*] OS Platform: linux
2019-10-04T07:03:00.215Z INF/cli:doctor 1121 [*] OS Platform: 4.19.72-v7l.1.el7
2019-10-04T07:03:00.216Z INF/cli:doctor 1121 [*] Using Node 6.17.1
2019-10-04T07:03:00.278Z INF/cli:doctor 1121 [*] Using ZeroMQ 4.1.4
2019-10-04T07:03:00.320Z INF/cli:doctor 1121 [*] Using RethinkDB 2.3.6
2019-10-04T07:03:00.322Z INF/cli:doctor 1121 [*] Using GraphicsMagick 1.3.32
2019-10-04T07:03:00.323Z INF/cli:doctor 1121 [*] Using ProtoBuf 3.10.0
2019-10-04T07:03:00.323Z INF/cli:doctor 1121 [*] Using ADB 1.0.31

Logs while running stf local

2019-10-04T07:00:06.401Z INF/app 982 [*] Using pre-built resources
2019-10-04T07:00:06.449Z INF/app 982 [*] Listening on port 7105
2019-10-04T07:00:06.458Z INF/db 982 [*] Connecting to 127.0.0.1:28015
/usr/lib/node_modules/stf/lib/cli websocket

Options:
  -h, --help          Show help.                                       [boolean]
  -V, --version       Show version.                                    [boolean]
  --connect-push, -c  App-side ZeroMQ PULL endpoint to connect to.
                                                              [array] [required]
  --connect-sub, -u   App-side ZeroMQ PUB endpoint to connect to.
                                                              [array] [required]
  --port, -p          The port to bind to.              [number] [default: 7110]
  --secret, -s        The secret to use for auth JSON Web Tokens. Anyone who
                      knows this token can freely enter the system if they want,
                      so keep it safe.                       [string] [required]
  --ssid, -i          The name of the session ID cookie.
                                                      [string] [default: "ssid"]
  --storage-url, -r   URL to the storage unit.               [string] [required]

Each option can be be overwritten with an environment variable by converting the
option to uppercase, replacing dashes with underscores and prefixing it with
`STF_WEBSOCKET_` (e.g. `STF_WEBSOCKET_STORAGE_URL`).

Unexpected token ...
2019-10-04T07:00:06.706Z FTL/cli:local 938 [*] Child process had an error ExitError: Exit code "1"
    at ChildProcess.<anonymous> (/usr/lib/node_modules/stf/lib/util/procutil.js:49:23)
    at emitTwo (events.js:106:13)
    at ChildProcess.emit (events.js:191:7)
    at Process.ChildProcess._handle.onexit (internal/child_process.js:219:12)
2019-10-04T07:00:06.707Z INF/cli:local 938 [*] Shutting down all child processes
2019-10-04T07:00:06.732Z INF/util:lifecycle 950 [app001] Winding down for graceful exit
2019-10-04T07:00:06.733Z INF/util:lifecycle 951 [dev001] Winding down for graceful exit
2019-10-04T07:00:06.743Z INF/util:lifecycle 957 [proc001] Winding down for graceful exit
2019-10-04T07:00:06.750Z INF/util:lifecycle 963 [proc002] Winding down for graceful exit
2019-10-04T07:00:06.750Z INF/util:lifecycle 964 [reaper001] Winding down for graceful exit
2019-10-04T07:00:06.759Z WRN/db 957 [proc001] Connection closed
2019-10-04T07:00:06.760Z INF/util:lifecycle 975 [*] Winding down for graceful exit
2019-10-04T07:00:06.767Z WRN/db 963 [proc002] Connection closed
2019-10-04T07:00:06.772Z WRN/db 964 [reaper001] Connection closed
2019-10-04T07:00:06.760Z INF/util:lifecycle 982 [*] Winding down for graceful exit
2019-10-04T07:00:06.761Z INF/util:lifecycle 981 [*] Winding down for graceful exit
2019-10-04T07:00:06.784Z INF/auth-mock 981 [*] Waiting for client connections to end
2019-10-04T07:00:06.799Z WRN/db 982 [*] Connection closed
shri-0509 commented 4 years ago

root cause is please use socket.io exact version 2.2.0 in package.json ... it will work fine.. But didn't find time to explore why new version is creating issue...

p00h commented 4 years ago

@shridharkabbur gonna try it right now

p00h commented 4 years ago

Changing socket.io version to 2.2.0 changed nothing. Fresh install with given fix gave the same result as above.

shri-0509 commented 4 years ago

socket.io 2.2.0 version worked for me.. Can you please check in node_modules/socket.io folder which version exists in package.json. please use exact version...

sssz commented 4 years ago

I also meet the same FAIL. I Install the dependence and then use npm install -g stf. running stf local. websocket run error 2019-10-07T07:08:45.656Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli migrate" 2019-10-07T07:08:46.549Z INF/db 30338 [] Connecting to 127.0.0.1:28015 2019-10-07T07:08:46.942Z INF/db:setup 30338 [] Database "stf" already exists 2019-10-07T07:08:46.965Z INF/db:setup 30338 [] Table "users" already exists 2019-10-07T07:08:46.966Z INF/db:setup 30338 [] Table "accessTokens" already exists 2019-10-07T07:08:46.966Z INF/db:setup 30338 [] Table "vncauth" already exists 2019-10-07T07:08:46.966Z INF/db:setup 30338 [] Table "devices" already exists 2019-10-07T07:08:46.966Z INF/db:setup 30338 [] Table "logs" already exists 2019-10-07T07:08:47.059Z INF/db:setup 30338 [] Index "users"."adbKeys" already exists 2019-10-07T07:08:47.060Z INF/db:setup 30338 [] Waiting for index "users"."adbKeys" 2019-10-07T07:08:47.063Z INF/db:setup 30338 [] Index "accessTokens"."email" already exists 2019-10-07T07:08:47.064Z INF/db:setup 30338 [] Index "vncauth"."response" already exists 2019-10-07T07:08:47.064Z INF/db:setup 30338 [] Index "vncauth"."responsePerDevice" already exists 2019-10-07T07:08:47.064Z INF/db:setup 30338 [] Index "devices"."owner" already exists 2019-10-07T07:08:47.064Z INF/db:setup 30338 [] Index "devices"."present" already exists 2019-10-07T07:08:47.064Z INF/db:setup 30338 [] Index "devices"."providerChannel" already exists 2019-10-07T07:08:47.065Z INF/db:setup 30338 [] Waiting for index "accessTokens"."email" 2019-10-07T07:08:47.067Z INF/db:setup 30338 [] Waiting for index "vncauth"."response" 2019-10-07T07:08:47.069Z INF/db:setup 30338 [] Waiting for index "vncauth"."responsePerDevice" 2019-10-07T07:08:47.076Z INF/db:setup 30338 [] Waiting for index "devices"."owner" 2019-10-07T07:08:47.077Z INF/db:setup 30338 [] Waiting for index "devices"."present" 2019-10-07T07:08:47.080Z INF/db:setup 30338 [] Waiting for index "devices"."providerChannel" 2019-10-07T07:08:47.119Z INF/db:setup 30338 [] Index "users"."adbKeys" is ready 2019-10-07T07:08:47.132Z INF/db:setup 30338 [] Index "accessTokens"."email" is ready 2019-10-07T07:08:47.134Z INF/db:setup 30338 [] Index "vncauth"."response" is ready 2019-10-07T07:08:47.134Z INF/db:setup 30338 [] Index "vncauth"."responsePerDevice" is ready 2019-10-07T07:08:47.135Z INF/db:setup 30338 [] Index "devices"."owner" is ready 2019-10-07T07:08:47.135Z INF/db:setup 30338 [] Index "devices"."present" is ready 2019-10-07T07:08:47.140Z INF/db:setup 30338 [] Index "devices"."providerChannel" is ready 2019-10-07T07:08:47.151Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli triproxy app001 --bind-pub tcp://127.0.0.1:7111 --bind-dealer tcp://127.0.0.1:7112 --bind-pull tcp://127.0.0.1:7113" 2019-10-07T07:08:47.160Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli triproxy dev001 --bind-pub tcp://127.0.0.1:7114 --bind-dealer tcp://127.0.0.1:7115 --bind-pull tcp://127.0.0.1:7116" 2019-10-07T07:08:47.172Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli processor proc001 --connect-app-dealer tcp://127.0.0.1:7112 --connect-dev-dealer tcp://127.0.0.1:7115" 2019-10-07T07:08:47.180Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli processor proc002 --connect-app-dealer tcp://127.0.0.1:7112 --connect-dev-dealer tcp://127.0.0.1:7115" 2019-10-07T07:08:47.189Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli reaper reaper001 --connect-push tcp://127.0.0.1:7116 --connect-sub tcp://127.0.0.1:7111" 2019-10-07T07:08:47.206Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli provider --name isg-VirtualBox --min-port 7400 --max-port 7700 --connect-sub tcp://127.0.0.1:7114 --connect-push tcp://127.0.0.1:7116 --group-timeout 900 --public-ip localhost --storage-url http://localhost:7100/ --adb-host 127.0.0.1 --adb-port 5037 --vnc-initial-size 600x800 --mute-master never" 2019-10-07T07:08:47.236Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli auth-mock --port 7120 --secret kute kittykat --app-url http://localhost:7100/" 2019-10-07T07:08:47.276Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli app --port 7105 --secret kute kittykat --auth-url http://localhost:7100/auth/mock/ --websocket-url http://localhost:7110/" 2019-10-07T07:08:47.292Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli api --port 7106 --secret kute kittykat --connect-push tcp://127.0.0.1:7113 --connect-sub tcp://127.0.0.1:7111" 2019-10-07T07:08:47.331Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli websocket --port 7110 --secret kute kittykat --storage-url http://localhost:7100/ --connect-sub tcp://127.0.0.1:7111 --connect-push tcp://127.0.0.1:7113" 2019-10-07T07:08:47.385Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli storage-temp --port 7102" 2019-10-07T07:08:47.416Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli storage-plugin-image --port 7103 --storage-url http://localhost:7100/" 2019-10-07T07:08:47.474Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli storage-plugin-apk --port 7104 --storage-url http://localhost:7100/" 2019-10-07T07:08:47.533Z INF/util:procutil 30332 [] Forking "/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/cli poorxy --port 7100 --app-url http://localhost:7105/ --auth-url http://localhost:7120/ --api-url http://localhost:7106/ --websocket-url http://localhost:7110/ --storage-url http://localhost:7102/ --storage-plugin-image-url http://localhost:7103/ --storage-plugin-apk-url http://localhost:7104/" 2019-10-07T07:08:53.116Z INF/triproxy 30344 [app001] PUB socket bound on tcp://127.0.0.1:7111 2019-10-07T07:08:53.114Z INF/triproxy 30345 [dev001] PUB socket bound on tcp://127.0.0.1:7114 2019-10-07T07:08:53.136Z INF/triproxy 30345 [dev001] DEALER socket bound on tcp://127.0.0.1:7115 2019-10-07T07:08:53.136Z INF/triproxy 30344 [app001] DEALER socket bound on tcp://127.0.0.1:7112 2019-10-07T07:08:53.154Z INF/triproxy 30345 [dev001] PULL socket bound on tcp://127.0.0.1:7116 2019-10-07T07:08:53.154Z INF/triproxy 30344 [app001] PULL socket bound on tcp://127.0.0.1:7113 2019-10-07T07:08:55.121Z INF/db 30346 [] Connecting to 127.0.0.1:28015 2019-10-07T07:08:55.118Z INF/db 30351 [] Connecting to 127.0.0.1:28015 2019-10-07T07:08:55.145Z INF/reaper 30360 [reaper001] Subscribing to permanent channel "ALL" 2019-10-07T07:08:55.233Z INF/reaper 30360 [reaper001] Reaping devices with no heartbeat 2019-10-07T07:08:55.262Z INF/db 30360 [reaper001] Connecting to 127.0.0.1:28015 2019-10-07T07:08:55.351Z INF/reaper 30360 [reaper001] Receiving input from "tcp://127.0.0.1:7111" 2019-10-07T07:08:55.358Z INF/processor 30346 [proc001] App dealer connected to "tcp://127.0.0.1:7112" 2019-10-07T07:08:55.353Z INF/processor 30351 [proc002] App dealer connected to "tcp://127.0.0.1:7112" 2019-10-07T07:08:55.361Z INF/reaper 30360 [reaper001] Sending output to "tcp://127.0.0.1:7116" 2019-10-07T07:08:55.374Z INF/processor 30351 [proc002] Device dealer connected to "tcp://127.0.0.1:7115" 2019-10-07T07:08:55.375Z INF/processor 30346 [proc001] Device dealer connected to "tcp://127.0.0.1:7115" 2019-10-07T07:08:58.363Z INF/poorxy 30418 [] Listening on port 7100 2019-10-07T07:09:00.835Z INF/provider 30369 [] Subscribing to permanent channel "cuBuv7x/SiGXei1rnTgaKQ==" 2019-10-07T07:09:00.856Z INF/provider 30369 [] Sending output to "tcp://127.0.0.1:7116" 2019-10-07T07:09:00.858Z INF/provider 30369 [] Receiving input from "tcp://127.0.0.1:7114" 2019-10-07T07:09:01.087Z INF/provider 30369 [] Tracking devices 2019-10-07T07:09:04.421Z INF/auth-mock 30372 [] Listening on port 7120 2019-10-07T07:09:06.105Z INF/storage:temp 30401 [*] Listening on port 7102 ../../lib/cli websocket

Options: -h, --help Show help. [boolean] -V, --version Show version. [boolean] --connect-push, -c App-side ZeroMQ PULL endpoint to connect to. [array] [required] --connect-sub, -u App-side ZeroMQ PUB endpoint to connect to. [array] [required] --port, -p The port to bind to. [number] [default: 7110] --secret, -s The secret to use for auth JSON Web Tokens. Anyone who knows this token can freely enter the system if they want, so keep it safe. [string] [required] --ssid, -i The name of the session ID cookie. [string] [default: "ssid"] --storage-url, -r URL to the storage unit. [string] [required]

Each option can be be overwritten with an environment variable by converting the option to uppercase, replacing dashes with underscores and prefixing it with STF_WEBSOCKET_ (e.g. STF_WEBSOCKET_STORAGE_URL).

Unexpected token ... 2019-10-07T07:09:07.842Z FTL/cli:local 30332 [] Child process had an error ExitError: Exit code "1" at ChildProcess. (/usr/local/nodejs/node-v8.1.2-linux-x64/lib/node_modules/stf/lib/util/procutil.js:49:23) at emitTwo (events.js:125:13) at ChildProcess.emit (events.js:213:7) at Process.ChildProcess._handle.onexit (internal/child_process.js:197:12) 2019-10-07T07:09:07.842Z INF/cli:local 30332 [] Shutting down all child processes 2019-10-07T07:09:07.855Z INF/util:lifecycle 30344 [app001] Winding down for graceful exit 2019-10-07T07:09:07.868Z INF/util:lifecycle 30345 [dev001] Winding down for graceful exit 2019-10-07T07:09:07.883Z INF/util:lifecycle 30346 [proc001] Winding down for graceful exit 2019-10-07T07:09:07.889Z INF/util:lifecycle 30351 [proc002] Winding down for graceful exit 2019-10-07T07:09:07.901Z INF/util:lifecycle 30360 [reaper001] Winding down for graceful exit 2019-10-07T07:09:07.916Z INF/util:lifecycle 30369 [] Winding down for graceful exit 2019-10-07T07:09:07.932Z WRN/db 30346 [proc001] Connection closed 2019-10-07T07:09:07.936Z INF/util:lifecycle 30372 [] Winding down for graceful exit 2019-10-07T07:09:07.947Z INF/auth-mock 30372 [] Waiting for client connections to end 2019-10-07T07:09:07.936Z WRN/db 30351 [proc002] Connection closed 2019-10-07T07:09:07.937Z WRN/db 30360 [reaper001] Connection closed 2019-10-07T07:09:08.695Z INF/app 30379 [] Using pre-built resources 2019-10-07T07:09:08.732Z INF/app 30379 [] Listening on port 7105 2019-10-07T07:09:08.733Z INF/util:lifecycle 30379 [] Winding down for graceful exit 2019-10-07T07:09:08.735Z INF/db 30379 [*] Connecting to 127.0.0.1:28015

sssz commented 4 years ago

local/index.js run the websocket subprocess by using stf websocket --port 7110 --secret "kute kittykat" --storage-url http://localhost:7100 --connect-sub tcp://127.0.0.1:7111 --connect-push tcp://127.0.0.1:7113. If I input the command. the error is the same. How to fix this? thanks

entomber commented 4 years ago

I had the same issue. It's probably related to the version of Node you're running. I fixed it by using 8.16.1. See #1102

Jeycyp commented 4 years ago

对的，把版本换换成8.16.1是可以的。具体方法如下（要是没有nvm，可以使用这样的办法安装： NVM（Node version manager）顾名思义，就是Node.js的版本管理软件 下载并安装NVM脚本 curl https://raw.githubusercontent.com/creationix/nvm/v0.13.1/install.sh | bash source ~/.bash_profile ） 查看本地 nvm ls 查看所有node版本：nvm ls-remote 安装对应的版本：nvm install 版本(不要加v) 切换node的版本：nvm alias default 版本(不要加v)

shri-0509 commented 4 years ago

In docker file node version is 6.11 and using socket.io exact version 2.2.0 in package.json, issue will not occur..

sssz commented 4 years ago

Thanks, Nodejs 8.16.1 fix this problem perfectly.

koral-- commented 4 years ago

Confirmed solution has been provided so I'm closing this issue.