Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Weird tty behavior under frequent connect-disconnect screnario #467

Open
tsipa opened this issue Jul 4, 2020 · 7 comments
Open

Weird tty behavior under frequent connect-disconnect screnario #467

tsipa opened this issue Jul 4, 2020 · 7 comments
Labels
bug Something isn't working

Comments

@tsipa
Copy link

tsipa commented Jul 4, 2020 •
edited

Please answer the following questions.

What version of the firmware are you using?
0469e7b of Devt, spi_daisy_4axis_xyz
fc6926d of master with spi_daisy_4axis_xyz

Is the problem repeatable?
Yes

Under what conditions does the bug occur?

raspberry pi, 4.19.66-v7+, esp32 with:
Bus 001 Device 005: ID 10c4:ea60 Cygnal Integrated Products, Inc. CP2102/CP2109 UART Bridge Controller [CP210x family]

I've tried to reproduce it without using cncjs, with screen /dev/ttyUSB0, and failed to get clear repro. I've tried to spawn multiple FDs to TTY, but problem is something else. With CNCJS it's relatively easy to reproduce and makes it completely unusable.

open browser 1, do "connect" against /dev/ttyUSB0
open browser 2, do "connect" against /dev/ttyUSB0
open browser 1, do "disconnect" against /dev/ttyUSB0
open browser 2, do "connect" against /dev/ttyUSB0
open browser 1, do "connect" against /dev/ttyUSB0

After few times doing that you'll get noop /dev/ttyUSB0 which will not recover until you hit reset button on ESP32.
You can attach to this /dev/ttyUSB0 but it won't respond on any commands. When hit reset it will spew normal boot message.
No echo '[ESP444]RESTART' > /dev/ttyUSB0 will work, only physical reset.
@tsipa tsipa added the bug Something isn't working label Jul 4, 2020
@tsipa
Copy link
Author

tsipa commented Jul 4, 2020

It doesn't seems like it's a problem with uart driver or board itself, at least with
esptool.py --chip esp32 --port /dev/ttyUSB0 --baud 921600 --before default_reset --after hard_reset write_flash -z --flash_mode dio --flash_freq 80m --flash_size detect 0xe000 /root/zalupa/boot_app0.bin 0x1000 /root/zalupa/bootloader_qio_80m.bin 0x10000 /root/zalupa/Grbl_Esp32.ino.bin 0x8000 ~/zalupa/Grbl_Esp32.ino.partitions.bin
i can reset board

@MitchBradley
Copy link
Collaborator

Try logging all of the CNCjs messages using -vvv on the CNCjs server command line.

@tsipa
Copy link
Author

tsipa commented Jul 4, 2020

Works:

2020-07-04T16:34:15.996Z - silly controller:Grbl < [GC:G0 G54 G17 G21 G90 G94 M5 M9 T0 F0 S0.000]
2020-07-04T16:34:15.998Z - silly controller:Grbl < ok
2020-07-04T16:34:15.998Z - silly controller:Grbl < <Idle|MPos:0.000,0.000,0.000|FS:0,0|Pn:P|WCO:0.000,0.000,0.000>
2020-07-04T16:34:16.245Z - silly controller:Grbl < <Idle|MPos:0.000,0.000,0.000|FS:0,0|Pn:P|Ov:100,100,100>
2020-07-04T16:34:16.495Z - silly controller:Grbl < <Idle|MPos:0.000,0.000,0.000|FS:0,0|Pn:P>
2020-07-04T16:34:16.496Z - silly controller:Grbl < [GC:G0 G54 G17 G21 G90 G94 M5 M9 T0 F0 S0.000]
2020-07-04T16:34:16.498Z - silly controller:Grbl < ok
2020-07-04T16:34:16.765Z - silly controller:Grbl < <Idle|MPos:0.000,0.000,0.000|FS:0,0|Pn:P>
2020-07-04T16:34:17.015Z - silly controller:Grbl < <Idle|MPos:0.000,0.000,0.000|FS:0,0|Pn:P>
2020-07-04T16:34:17.017Z - silly controller:Grbl < [GC:G0 G54 G17 G21 G90 G94 M5 M9 T0 F0 S0.000]
2020-07-04T16:34:17.019Z - silly controller:Grbl < ok
2020-07-04T16:34:17.273Z - silly controller:Grbl < <Idle|MPos:0.000,0.000,0.000|FS:0,0|Pn:P>
2020-07-04T16:34:17.526Z - silly controller:Grbl < [GC:G0 G54 G17 G21 G90 G94 M5 M9 T0 F0 S0.000]
2020-07-04T16:34:17.528Z - silly controller:Grbl < ok
2020-07-04T16:34:17.528Z - silly controller:Grbl < <Idle|MPos:0.000,0.000,0.000|FS:0,0|Pn:P>
2020-07-04T16:34:17.781Z - silly controller:Grbl < <Idle|MPos:0.000,0.000,0.000|FS:0,0|Pn:P>
2020-07-04T16:34:18.033Z - silly controller:Grbl < <Idle|MPos:0.000,0.000,0.000|FS:0,0|Pn:P>
2020-07-04T16:34:18.035Z - silly controller:Grbl < [GC:G0 G54 G17 G21 G90 G94 M5 M9 T0 F0 S0.000]
2020-07-04T16:34:18.036Z - silly controller:Grbl < ok
2020-07-04T16:34:18.295Z - silly controller:Grbl < <Idle|MPos:0.000,0.000,0.000|FS:0,0|Pn:P>
2020-07-04T16:34:18.547Z - silly controller:Grbl < <Idle|MPos:0.000,0.000,0.000|FS:0,0|Pn:P|WCO:0.000,0.000,0.000>
2020-07-04T16:34:18.549Z - silly controller:Grbl < [GC:G0 G54 G17 G21 G90 G94 M5 M9 T0 F0 S0.000]
2020-07-04T16:34:18.551Z - silly controller:Grbl < ok
2020-07-04T16:34:18.712Z - debug service:cncengine socket.close("/dev/ttyUSB0"): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18339:25)

One more connect-disconnect, still works:

2020-07-04T16:34:19.063Z - debug service:cncengine socket.list(): id=d8IvgPu2GTW1Hgo1AAAB     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18241:25)
2020-07-04T16:34:19.079Z - debug service:cncengine socket.list(): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18241:25)
2020-07-04T16:34:19.095Z - debug service:cncengine socket.list(): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18241:25)
2020-07-04T16:34:20.317Z - debug service:cncengine socket.open("/dev/ttyUSB0", {"controllerType":"Grbl","baudrate":115200,"rtscts":false}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18269:25)
2020-07-04T16:34:20.323Z - debug controller:Grbl Add socket connection: id=uJ-p7hg2nL1vE3ikAAAC     at GrblController.addConnection (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:9277:26)
2020-07-04T16:34:20.345Z - debug controller:Grbl Connected to serial port "/dev/ttyUSB0"     at SerialPort.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:9211:28)
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:22.270Z - silly controller:Grbl > $$
2020-07-04T16:34:22.275Z - silly controller:Grbl < $0=3
2020-07-04T16:34:22.279Z - silly controller:Grbl < $1=250
2020-07-04T16:34:22.284Z - silly controller:Grbl < $2=0
2020-07-04T16:34:22.288Z - silly controller:Grbl < $3=0
2020-07-04T16:34:22.290Z - silly controller:Grbl < $4=0
2020-07-04T16:34:22.293Z - silly controller:Grbl < $5=1
2020-07-04T16:34:22.296Z - silly controller:Grbl < $6=0
2020-07-04T16:34:22.299Z - silly controller:Grbl < $10=1
2020-07-04T16:34:22.302Z - silly controller:Grbl < $11=0.010
2020-07-04T16:34:22.304Z - silly controller:Grbl < $12=0.002
2020-07-04T16:34:22.307Z - silly controller:Grbl < $13=0
2020-07-04T16:34:22.310Z - silly controller:Grbl < $20=0
2020-07-04T16:34:22.312Z - silly controller:Grbl < $21=0
2020-07-04T16:34:22.333Z - silly controller:Grbl < $22=0
2020-07-04T16:34:22.336Z - silly controller:Grbl < $23=3
2020-07-04T16:34:22.339Z - silly controller:Grbl < $24=200.000
2020-07-04T16:34:22.341Z - silly controller:Grbl < $25=2000.000
2020-07-04T16:34:22.344Z - silly controller:Grbl < $26=250.000
2020-07-04T16:34:22.347Z - silly controller:Grbl < $27=1.000
2020-07-04T16:34:22.349Z - silly controller:Grbl < $30=1.000
2020-07-04T16:34:22.352Z - silly controller:Grbl < $31=0.000
2020-07-04T16:34:22.355Z - silly controller:Grbl < $32=0
2020-07-04T16:34:22.358Z - silly controller:Grbl < $N1=
2020-07-04T16:34:22.361Z - silly controller:Grbl < $N0=
2020-07-04T16:34:22.363Z - silly controller:Grbl < $100=800.000
2020-07-04T16:34:22.366Z - silly controller:Grbl < $101=800.000
2020-07-04T16:34:22.369Z - silly controller:Grbl < $102=800.000
2020-07-04T16:34:22.372Z - silly controller:Grbl < $110=1000.000
2020-07-04T16:34:22.375Z - silly controller:Grbl < $111=1000.000
2020-07-04T16:34:22.378Z - silly controller:Grbl < $112=500.000
2020-07-04T16:34:22.380Z - silly controller:Grbl < $120=50.000
2020-07-04T16:34:22.381Z - silly controller:Grbl < $121=50.000
2020-07-04T16:34:22.383Z - silly controller:Grbl < $122=50.000
2020-07-04T16:34:22.385Z - silly controller:Grbl < $130=300.000
2020-07-04T16:34:22.386Z - silly controller:Grbl < $131=300.000
2020-07-04T16:34:22.388Z - silly controller:Grbl < $132=300.000
2020-07-04T16:34:22.390Z - silly controller:Grbl < ok
2020-07-04T16:34:23.781Z - debug service:cncengine socket.close("/dev/ttyUSB0"): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18339:25)

Few more times, works:

2020-07-04T16:34:23.795Z - debug service:cncengine socket.list(): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18241:25)
2020-07-04T16:34:23.855Z - debug service:cncengine socket.list(): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18241:25)
2020-07-04T16:34:25.072Z - debug service:cncengine socket.open("/dev/ttyUSB0", {"controllerType":"Grbl","baudrate":115200,"rtscts":false}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18269:25)
2020-07-04T16:34:25.076Z - debug controller:Grbl Add socket connection: id=uJ-p7hg2nL1vE3ikAAAC     at GrblController.addConnection (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:9277:26)
2020-07-04T16:34:25.092Z - debug controller:Grbl Connected to serial port "/dev/ttyUSB0"     at SerialPort.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:9211:28)
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:26.463Z - silly controller:Grbl > $$
2020-07-04T16:34:26.471Z - silly controller:Grbl < $0=3
2020-07-04T16:34:26.475Z - silly controller:Grbl < $1=250
2020-07-04T16:34:26.480Z - silly controller:Grbl < $2=0
2020-07-04T16:34:26.483Z - silly controller:Grbl < $3=0
2020-07-04T16:34:26.486Z - silly controller:Grbl < $4=0
2020-07-04T16:34:26.488Z - silly controller:Grbl < $5=1
2020-07-04T16:34:26.491Z - silly controller:Grbl < $6=0
2020-07-04T16:34:26.493Z - silly controller:Grbl < $10=1
2020-07-04T16:34:26.496Z - silly controller:Grbl < $11=0.010
2020-07-04T16:34:26.499Z - silly controller:Grbl < $12=0.002
2020-07-04T16:34:26.509Z - silly controller:Grbl < $13=0
2020-07-04T16:34:26.511Z - silly controller:Grbl < $20=0
2020-07-04T16:34:26.514Z - silly controller:Grbl < $21=0
2020-07-04T16:34:26.522Z - silly controller:Grbl < $22=0
2020-07-04T16:34:26.525Z - silly controller:Grbl < $23=3
2020-07-04T16:34:26.527Z - silly controller:Grbl < $24=200.000
2020-07-04T16:34:26.530Z - silly controller:Grbl < $25=2000.000
2020-07-04T16:34:26.532Z - silly controller:Grbl < $26=250.000
2020-07-04T16:34:26.535Z - silly controller:Grbl < $27=1.000
2020-07-04T16:34:26.537Z - silly controller:Grbl < $30=1.000
2020-07-04T16:34:26.540Z - silly controller:Grbl < $31=0.000
2020-07-04T16:34:26.542Z - silly controller:Grbl < $32=0
2020-07-04T16:34:26.545Z - silly controller:Grbl < $N1=
2020-07-04T16:34:26.547Z - silly controller:Grbl < $N0=
2020-07-04T16:34:26.550Z - silly controller:Grbl < $100=800.000
2020-07-04T16:34:26.552Z - silly controller:Grbl < $101=800.000
2020-07-04T16:34:26.554Z - silly controller:Grbl < $102=800.000
2020-07-04T16:34:26.557Z - silly controller:Grbl < $110=1000.000
2020-07-04T16:34:26.559Z - silly controller:Grbl < $111=1000.000
2020-07-04T16:34:26.561Z - silly controller:Grbl < $112=500.000
2020-07-04T16:34:26.564Z - silly controller:Grbl < $120=50.000
2020-07-04T16:34:26.566Z - silly controller:Grbl < $121=50.000
2020-07-04T16:34:26.568Z - silly controller:Grbl < $122=50.000
2020-07-04T16:34:26.571Z - silly controller:Grbl < $130=300.000
2020-07-04T16:34:26.573Z - silly controller:Grbl < $131=300.000
2020-07-04T16:34:26.575Z - silly controller:Grbl < $132=300.000
2020-07-04T16:34:26.578Z - silly controller:Grbl < ok
2020-07-04T16:34:27.740Z - debug service:cncengine socket.close("/dev/ttyUSB0"): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18339:25)
2020-07-04T16:34:27.751Z - debug service:cncengine socket.list(): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18241:25)
2020-07-04T16:34:27.813Z - debug service:cncengine socket.list(): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18241:25)
2020-07-04T16:34:28.732Z - debug service:cncengine socket.open("/dev/ttyUSB0", {"controllerType":"Grbl","baudrate":115200,"rtscts":false}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18269:25)
2020-07-04T16:34:28.738Z - debug controller:Grbl Add socket connection: id=uJ-p7hg2nL1vE3ikAAAC     at GrblController.addConnection (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:9277:26)
2020-07-04T16:34:28.758Z - debug controller:Grbl Connected to serial port "/dev/ttyUSB0"     at SerialPort.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:9211:28)
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:29.860Z - silly controller:Grbl > $$
2020-07-04T16:34:29.865Z - silly controller:Grbl < $0=3
2020-07-04T16:34:29.868Z - silly controller:Grbl < $1=250
2020-07-04T16:34:29.872Z - silly controller:Grbl < $2=0
2020-07-04T16:34:29.876Z - silly controller:Grbl < $3=0
2020-07-04T16:34:29.878Z - silly controller:Grbl < $4=0
2020-07-04T16:34:29.880Z - silly controller:Grbl < $5=1
2020-07-04T16:34:29.882Z - silly controller:Grbl < $6=0
2020-07-04T16:34:29.884Z - silly controller:Grbl < $10=1
2020-07-04T16:34:29.886Z - silly controller:Grbl < $11=0.010
2020-07-04T16:34:29.889Z - silly controller:Grbl < $12=0.002
2020-07-04T16:34:29.891Z - silly controller:Grbl < $13=0
2020-07-04T16:34:29.897Z - silly controller:Grbl < $20=0
2020-07-04T16:34:29.899Z - silly controller:Grbl < $21=0
2020-07-04T16:34:29.901Z - silly controller:Grbl < $22=0
2020-07-04T16:34:29.903Z - silly controller:Grbl < $23=3
2020-07-04T16:34:29.906Z - silly controller:Grbl < $24=200.000
2020-07-04T16:34:29.908Z - silly controller:Grbl < $25=2000.000
2020-07-04T16:34:29.910Z - silly controller:Grbl < $26=250.000
2020-07-04T16:34:29.912Z - silly controller:Grbl < $27=1.000
2020-07-04T16:34:29.914Z - silly controller:Grbl < $30=1.000
2020-07-04T16:34:29.916Z - silly controller:Grbl < $31=0.000
2020-07-04T16:34:29.919Z - silly controller:Grbl < $32=0
2020-07-04T16:34:29.921Z - silly controller:Grbl < $N1=
2020-07-04T16:34:29.923Z - silly controller:Grbl < $N0=
2020-07-04T16:34:29.926Z - silly controller:Grbl < $100=800.000
2020-07-04T16:34:29.928Z - silly controller:Grbl < $101=800.000
2020-07-04T16:34:29.931Z - silly controller:Grbl < $102=800.000
2020-07-04T16:34:29.933Z - silly controller:Grbl < $110=1000.000
2020-07-04T16:34:29.936Z - silly controller:Grbl < $111=1000.000
2020-07-04T16:34:29.938Z - silly controller:Grbl < $112=500.000
2020-07-04T16:34:29.941Z - silly controller:Grbl < $120=50.000
2020-07-04T16:34:29.943Z - silly controller:Grbl < $121=50.000
2020-07-04T16:34:29.946Z - silly controller:Grbl < $122=50.000
2020-07-04T16:34:29.949Z - silly controller:Grbl < $130=300.000
2020-07-04T16:34:29.957Z - silly controller:Grbl < $131=300.000
2020-07-04T16:34:29.959Z - silly controller:Grbl < $132=300.000
2020-07-04T16:34:29.960Z - silly controller:Grbl < ok
2020-07-04T16:34:30.520Z - debug service:cncengine socket.close("/dev/ttyUSB0"): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18339:25)
2020-07-04T16:34:30.850Z - debug service:cncengine socket.list(): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18241:25)
2020-07-04T16:34:30.883Z - debug service:cncengine socket.list(): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18241:25)
2020-07-04T16:34:32.097Z - debug service:cncengine socket.open("/dev/ttyUSB0", {"controllerType":"Grbl","baudrate":115200,"rtscts":false}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18269:25)
2020-07-04T16:34:32.099Z - debug controller:Grbl Add socket connection: id=uJ-p7hg2nL1vE3ikAAAC     at GrblController.addConnection (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:9277:26)
2020-07-04T16:34:32.115Z - debug controller:Grbl Connected to serial port "/dev/ttyUSB0"     at SerialPort.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:9211:28)
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:33.052Z - silly controller:Grbl > $$
2020-07-04T16:34:33.058Z - silly controller:Grbl < $0=3
2020-07-04T16:34:33.061Z - silly controller:Grbl < $1=250
2020-07-04T16:34:33.065Z - silly controller:Grbl < $2=0
2020-07-04T16:34:33.068Z - silly controller:Grbl < $3=0
2020-07-04T16:34:33.070Z - silly controller:Grbl < $4=0
2020-07-04T16:34:33.072Z - silly controller:Grbl < $5=1
2020-07-04T16:34:33.075Z - silly controller:Grbl < $6=0
2020-07-04T16:34:33.077Z - silly controller:Grbl < $10=1
2020-07-04T16:34:33.079Z - silly controller:Grbl < $11=0.010
2020-07-04T16:34:33.082Z - silly controller:Grbl < $12=0.002
2020-07-04T16:34:33.084Z - silly controller:Grbl < $13=0
2020-07-04T16:34:33.090Z - silly controller:Grbl < $20=0
2020-07-04T16:34:33.093Z - silly controller:Grbl < $21=0
2020-07-04T16:34:33.095Z - silly controller:Grbl < $22=0
2020-07-04T16:34:33.098Z - silly controller:Grbl < $23=3
2020-07-04T16:34:33.100Z - silly controller:Grbl < $24=200.000
2020-07-04T16:34:33.103Z - silly controller:Grbl < $25=2000.000
2020-07-04T16:34:33.105Z - silly controller:Grbl < $26=250.000
2020-07-04T16:34:33.107Z - silly controller:Grbl < $27=1.000
2020-07-04T16:34:33.109Z - silly controller:Grbl < $30=1.000
2020-07-04T16:34:33.112Z - silly controller:Grbl < $31=0.000
2020-07-04T16:34:33.114Z - silly controller:Grbl < $32=0
2020-07-04T16:34:33.117Z - silly controller:Grbl < $N1=
2020-07-04T16:34:33.119Z - silly controller:Grbl < $N0=
2020-07-04T16:34:33.121Z - silly controller:Grbl < $100=800.000
2020-07-04T16:34:33.124Z - silly controller:Grbl < $101=800.000
2020-07-04T16:34:33.126Z - silly controller:Grbl < $102=800.000
2020-07-04T16:34:33.128Z - silly controller:Grbl < $110=1000.000
2020-07-04T16:34:33.131Z - silly controller:Grbl < $111=1000.000
2020-07-04T16:34:33.133Z - silly controller:Grbl < $112=500.000
2020-07-04T16:34:33.136Z - silly controller:Grbl < $120=50.000
2020-07-04T16:34:33.138Z - silly controller:Grbl < $121=50.000
2020-07-04T16:34:33.141Z - silly controller:Grbl < $122=50.000
2020-07-04T16:34:33.143Z - silly controller:Grbl < $130=300.000
2020-07-04T16:34:33.167Z - silly controller:Grbl < $131=300.000
2020-07-04T16:34:33.169Z - silly controller:Grbl < $132=300.000
2020-07-04T16:34:33.170Z - silly controller:Grbl < ok
2020-07-04T16:34:33.938Z - debug service:cncengine socket.close("/dev/ttyUSB0"): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18339:25)

And now it's dead:

2020-07-04T16:34:33.949Z - debug service:cncengine socket.list(): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18241:25)
2020-07-04T16:34:34.006Z - debug service:cncengine socket.list(): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18241:25)
2020-07-04T16:34:34.715Z - debug service:cncengine socket.open("/dev/ttyUSB0", {"controllerType":"Grbl","baudrate":115200,"rtscts":false}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18269:25)
2020-07-04T16:34:34.720Z - debug controller:Grbl Add socket connection: id=uJ-p7hg2nL1vE3ikAAAC     at GrblController.addConnection (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:9277:26)
2020-07-04T16:34:34.740Z - debug controller:Grbl Connected to serial port "/dev/ttyUSB0"     at SerialPort.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:9211:28)
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:35.997Z - silly controller:Grbl > $$
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:38.137Z - silly controller:Grbl > $$
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:39.361Z - silly controller:Grbl > $$
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:40.193Z - silly controller:Grbl > $$
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:41.500Z - silly controller:Grbl > $?
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:42.764Z - silly controller:Grbl > $+
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:44.804Z - silly controller:Grbl > $L
", {"__sender__":"bb3c6791-7509-4c0d-aabb-e08bb3d15a75"}): id=uJ-p7hg2nL1vE3ikAAAC     at Socket.<anonymous> (/usr/lib/node_modules/cncjs/dist/cncjs/server/index.js:18379:25)
2020-07-04T16:34:47.609Z - silly controller:Grbl > $r

I got repro without multiple browser magic, simply connect-disconnect from a single browser window.

I did strace on cncjs process and it's clearly do write("$$") to /dev/ttyUSB0 FD.

@MitchBradley
Copy link
Collaborator

I have to leave soon for a Fourth of July celebration so I will not be able to work with you in detail for several hours. Since you seem to have a lot of debugging skills, I will give you some avenues to explore.

  1. Others have reported issues with CH34x serial chips; the problems went away with a CP2102-equipped ESP32. I have had problems with CH340 myself - it would make a Mac computer crash under certain conditions. I think that Mac problem was a bug in the driver. I just mention that as support for my general distrust of CH34x.

One way to investigate this further would be to do some kernel-level debugging of the CH341 driver. I see that you can talk to the driver with esptool, but it is still possible that the driver is getting hung in some way that affects only the way that CNCjs uses it.

  1. Another source of problems in CNCjs-land has been the nodejs serialport module. You might get more clues by adding debugging information in that module. You could debug either in the Javascript portion of the module in node_modules/@serialport/bindings/lib/*.js or in the system-dependent binary code that is compiled from node_modules/@serialport/bindings/src/serialport_unix.cpp . I don't have time right now to give complete instructions, but perhaps you already know how to rebuild node modules or can figure it out from the internet.

  2. Another approach would be to create a nodejs test program that uses the serialport module in a similar way to cncjs, opening, sending $$, closing, repeat.

  3. Finally, you could try with a different GRBL controller if you have one. If that fails, it points toward CNCjs and its serialport infrastructure as the cause of the problem. If it succeeds, it doesn't tell us much because CH34x chips are unusual in GRBL systems, so the problem could still be anywhere.

Sorry, have to go now.

@tsipa
Copy link
Author

tsipa commented Jul 4, 2020 •
edited

Ugh, i really apologize, i had another device connected with CH34x uart and confused it with esp32. The problem happen on CP210x. I updated original post with right description.

@MitchBradley
Copy link
Collaborator

One final thought - the other problem report from CH340 ESP32 was consistent with the hypothesis that opening and closing the serial port could be causing glitches on the ESP32 enable line, thus partially resetting the ESP32 and getting it into a strange state. That hypothesis is consistent with your results. In particular, the fact that esptool can recover it is explained by the fact the esptool explicitly does a full hardware reset in order to put the ESP32 into bootloader mode. That reset involves controlling some lines via modem control signals that go through a cross-coupled latch on the ESP32 dev board.

@MitchBradley
Copy link
Collaborator

The debugging ideas around nodejs serialport still apply, even with CP2102. Happy debugging. Really must leave now.,

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@tsipa @MitchBradley