step-daemon icon indicating copy to clipboard operation
step-daemon copied to clipboard

Published 20 hours ago • verified publisher icon colinrgodsey

ValueError: I/O operation on closed file

Open chandan0815 opened this issue 2 years ago • 3 comments

Hi @colinrgodsey, I am unable to successfully connect to StepD via Octopi.

The following error is from octoprint.log:

2023-01-09 16:29:21,563 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial connection" 2023-01-09 16:29:21,581 - octoprint.plugins.stepd - INFO - Starting service: ['/home/pi/.octoprint/data/stepd/stepd', '-device', '/dev/ttyUSB0', '-baud', '250000', '-config', 'config.json'] 2023-01-09 16:29:21,608 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial connection" to "Connecting" 2023-01-09 16:29:21,615 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2023-01-09 16:29:27,632 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2023-01-09 16:29:27,636 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational" 2023-01-09 16:29:27,715 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0 2023-01-09 16:29:36,615 - octoprint.plugins.stepd - INFO - GO: panic: Failed to load device settings 2023-01-09 16:29:36,615 - octoprint.plugins.stepd - INFO - GO: 2023-01-09 16:29:36,619 - octoprint.plugins.stepd - INFO - GO: goroutine 22 [running]: 2023-01-09 16:29:36,619 - octoprint.plugins.stepd - INFO - GO: github.com/colinrgodsey/step-daemon/lib/pipeline.ConfigHandler.func1(0x207d780, 0x207d700, 0x207d800, 0x207d840) 2023-01-09 16:29:36,620 - octoprint.plugins.stepd - INFO - GO: /home/pi/.octoprint/data/stepd/repo/lib/pipeline/config_handler.go:178 +0x358 2023-01-09 16:29:36,620 - octoprint.plugins.stepd - INFO - GO: created by main.handler 2023-01-09 16:29:37,446 - octoprint.plugins.stepd - INFO - ERR: /home/pi/.octoprint/data/stepd/repo/cmd/stepd/main.go:41 +0x78 2023-01-09 16:29:37,452 - octoprint.plugins.stepd - INFO - service terminated 2023-01-09 16:29:37,456 - octoprint.util.comm - ERROR - Unexpected error while reading from serial port Traceback (most recent call last): File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/util/comm.py", line 3997, in _readline ret = self._serial.readline() File "/home/pi/oprint/lib/python3.7/site-packages/octoprint_stepd/StepdService.py", line 40, in readline data = self.process.stdout.readline() ValueError: I/O operation on closed file 2023-01-09 16:29:37,459 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Offline after error"

Here is the content from the Octopi Terminal log

Changing monitoring state from "Offline" to "Opening serial connection" Connecting to Step Daemon Changing monitoring state from "Opening serial connection" to "Connecting" Connected to: <octoprint_stepd.StepdService.StepdService object at 0xb0798bb0>, starting monitor Recv: warn:failed to load ./bedlevel.json: open ./bedlevel.json: no such file or directory Recv: info:config processed Recv: T:19.16 /0.00 B:18.91 /0.00 @:0 B@:0 Send: N0 M110 N0125 Recv: T:19.12 /0.00 B:18.89 /0. T:19.16 /0.00 B:18.88 /0.00 @:0 B@:0 Recv: T:19.13 /0.00 B:18.89 /0.00 @:0 B@:0 Recv: T:19.16 /0.00 B:18.90 /0.00 @:0 B@:0 Recv: no page_ready seen, sending anyways Recv: info:gathering device settings Recv: info:stepd initialized Recv: pages_ready Recv: ok N0 Send: N0 M110 N0125 Changing monitoring state from "Connecting" to "Operational" Recv: echo:; Linear Units: Recv: echo: G21 ; (mm) Recv: echo:; Temperature Units: Recv: echo: M149 C ; Units in Celsius Recv: echo:; Filament settings (Disabled): Recv: echo: M200 S0 D1.75 Recv: echo:; Steps per unit: Recv: echo: M92 X80.00 Y80.00 Z400.00 E93.00 Recv: info:max vel (step limit) is [2304 2304 460.8 1981.9354838709678] Recv: echo:; Max feedrates (units/s): Recv: echo: M203 X500.00 Y500.00 Z5.00 E25.00 Recv: echo:; Max Acceleration (units/s2): Recv: ok N0 Recv: echo: M201 X500.00 Y500.00 Z100.00 E5000.00 Recv: echo:; Acceleration (units/s2) (P R T): Recv: echo: M204 P500.00 R500.00 T500.00 Send: N0 M110 N0125 Recv: echo:; Advanced (B<min_segment_time_us> S<min_feedrate> T<min_travel_feedrate> J<junc_dev>): Recv: echo: M205 B20000.00 S0.00 T0.00 J0.08 Recv: echo:; Home offset: Recv: echo: M206 X0.00 Y0.00 Z0.00 Recv: echo:; Material heatup parameters: Recv: echo: M145 S0 H220.00 B45.00 F0 Recv: echo: M145 S1 H240.00 B60.00 F0 Recv: echo:; Hotend PID: Recv: echo: M301 P21.73 I1.54 D76.55 Recv: ok N0 Send: N1 M11539 Recv: ok N1 Send: N2 M2118 Recv: ok N2 Recv: T:19.15 /0.00 B:18.90 /0.00 @:0 B@:0 Recv: T:19.14 /0.00 B:18.90 /0.00 @:0 B@:0 Recv: T:19.12 /0.00 B:18.87 /0.00 @:0 B@:0 Send: N3 M10536 Recv: ok N3 Recv: T:19.16 /0.00 B:18.87 /0.00 @:0 B@:0 Recv: T:19.13 /0.00 B:18.89 /0.00 @:0 B@:0 Unexpected error while reading serial port, please consult octoprint.log for details: ValueError: 'I/O operation on closed file' @ comm.py:_readline:3997 Changing monitoring state from "Operational" to "Offline after error" Connection closed, closing down monitor

Hardware

Ender 3 Board: 4.2.2 GD32F303 with Marlin Release 2.0.x (and also tried with 2.1.x) with Baudrate 250000 Connected via Octoprint over a Raspberry Pi 4B

chandan0815 avatar Jan 09 '23 16:01 chandan0815

Same issue here with the latest Bugfix version. Disabling Step Daemon plugin instantly stops this disconnection.

Arakon avatar Jan 15 '23 18:01 Arakon

Any update on this? I also can't connect after installing Step Daemon plugin

jaum20 avatar Aug 03 '23 15:08 jaum20

Same issue here, the serial error only happens with stepd enabled. Serial log:

2023-12-07 00:56:58,265 - Changing monitoring state from "Offline" to "Opening serial connection" 2023-12-07 00:56:58,278 - Connecting to Step Daemon 2023-12-07 00:56:58,442 - Changing monitoring state from "Opening serial connection" to "Connecting" 2023-12-07 00:56:58,454 - Connected to: <octoprint_stepd.StepdService.StepdService object at 0x6764b8f8>, starting monitor 2023-12-07 00:56:58,471 - Send: N0 M110 N0*125 2023-12-07 00:56:58,471 - Recv: warn:failed to load ./bedlevel.json: open ./bedlevel.json: no such file or directory 2023-12-07 00:56:58,476 - Recv: start 2023-12-07 00:56:58,482 - Recv: Marlin 2.1.1.1 2023-12-07 00:56:58,489 - Send: N0 M110 N0*125 2023-12-07 00:56:58,509 - Recv: info:config processed 2023-12-07 00:56:59,881 - Recv: echo: Last Updated: 2023-07-20 | Author: (Bstart 2023-12-07 00:56:59,885 - Recv: External Reset 2023-12-07 00:56:59,902 - Recv: Marlin 2.1.1.1 2023-12-07 00:56:59,917 - Recv: echo: Last Updated: 2023-07-20 | Author: (Bob Kuhn, Anet config) 2023-12-07 00:56:59,942 - Recv: echo: Compiled: Dec 6 2023 2023-12-07 00:56:59,967 - Recv: echo: Free Memory: 8001 PlannerBufferBytes: 736 2023-12-07 00:57:00,006 - Recv: //action:notification Anet A8 bereit 2023-12-07 00:57:00,050 - Recv: echo:V86 stored settings retrieved (629 bytes; crc 33410) 2023-12-07 00:57:00,055 - Recv: //action:notification Stored settings retrieved 2023-12-07 00:57:02,121 - Recv: //action:prompt_end 2023-12-07 00:57:02,138 - Recv: info:gathering device settings 2023-12-07 00:57:02,144 - Recv: info:stepd initialized 2023-12-07 00:57:02,151 - Recv: pages_ready 2023-12-07 00:57:02,157 - Recv: ok N0 2023-12-07 00:57:02,165 - Send: N0 M110 N0*125 2023-12-07 00:57:02,174 - Changing monitoring state from "Connecting" to "Operational" 2023-12-07 00:57:02,281 - Recv: ok N0 2023-12-07 00:57:02,288 - Send: N0 M110 N0*125 2023-12-07 00:57:02,293 - Recv: ok N0 2023-12-07 00:57:02,304 - Recv: ok N0 2023-12-07 00:57:02,305 - Send: N1 M115*39 2023-12-07 00:57:02,315 - Recv: ok N1 2023-12-07 00:57:02,322 - Send: N2 M21*18 2023-12-07 00:57:02,332 - Recv: ok N2 2023-12-07 00:57:07,170 - Send: N3 M105*36 2023-12-07 00:57:07,178 - Recv: ok N3 2023-12-07 00:57:07,535 - Recv: echo:No SD card 2023-12-07 00:57:07,541 - Recv: echo:Unknown command: "M503" 2023-12-07 00:57:08,538 - Recv: wait 2023-12-07 00:57:09,536 - Recv: wait 2023-12-07 00:57:10,537 - Recv: wait 2023-12-07 00:57:11,536 - Recv: wait 2023-12-07 00:57:12,171 - Send: N4 M105*35 2023-12-07 00:57:12,178 - Recv: ok N4 2023-12-07 00:57:12,537 - Recv: wait 2023-12-07 00:57:13,689 - Unexpected error while reading serial port, please consult octoprint.log for details: ValueError: 'I/O operation on closed file' @ comm.py:_readline:4081 2023-12-07 00:57:13,692 - Changing monitoring state from "Operational" to "Offline after error" 2023-12-07 00:57:13,709 - Connection closed, closing down monitor

syslog:

[Dec  7 00:19:06 anet octoprint[5239]: 2023-12-07 00:19:06,915 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial connection"#033[0m
Dec  7 00:19:07 anet octoprint[5239]: 2023-12-07 00:19:06,998 - octoprint.plugins.stepd - INFO - Starting service: ['/home/frank/.octoprint/data/stepd/stepd', '-device', '/dev/ttyUSB0', '-baud', '250000', '-config', 'config.json']#033[0m
Dec  7 00:19:07 anet octoprint[5239]: 2023-12-07 00:19:07,091 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial connection" to "Connecting"#033[0m
Dec  7 00:19:07 anet octoprint[5239]: 2023-12-07 00:19:07,107 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0#033[0m
Dec  7 00:19:07 anet octoprint[5239]: 2023-12-07 00:19:07,161 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0#033[0m
Dec  7 00:19:07 anet octoprint[5239]: 2023-12-07 00:19:07,169 - octoprint.server - INFO - Autorefresh of serial port list stopped#033[0m
Dec  7 00:19:08 anet octoprint[5239]: 2023-12-07 00:19:08,671 - octoprint.plugins.action_command_notification - INFO - Got a notification: Anet A8 bereit#033[0m
Dec  7 00:19:08 anet octoprint[5239]: 2023-12-07 00:19:08,710 - octoprint.plugins.action_command_notification - INFO - Got a notification: Stored settings retrieved#033[0m
Dec  7 00:19:10 anet octoprint[5239]: 2023-12-07 00:19:10,807 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0#033[0m
Dec  7 00:19:10 anet octoprint[5239]: 2023-12-07 00:19:10,814 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"#033[0m
Dec  7 00:19:10 anet octoprint[5239]: 2023-12-07 00:19:10,841 - octoprint.plugins.firmwareupdater - INFO - Got CONNECTED event#033[0m
Dec  7 00:19:10 anet octoprint[5239]: 2023-12-07 00:19:10,875 - octoprint.plugins.firmwareupdater - INFO - Run postflash flag is not set#033[0m
Dec  7 00:19:10 anet octoprint[5239]: 2023-12-07 00:19:10,933 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0#033[0m
Dec  7 00:19:22 anet octoprint[5239]: 2023-12-07 00:19:22,077 - octoprint.plugins.stepd - INFO - GO: panic: Failed to load device settings#033[0m
Dec  7 00:19:22 anet octoprint[5239]: 2023-12-07 00:19:22,078 - octoprint.plugins.stepd - INFO - GO: #033[0m
Dec  7 00:19:22 anet octoprint[5239]: 2023-12-07 00:19:22,084 - octoprint.plugins.stepd - INFO - ERR: goroutine 21 [running]:#033[0m
Dec  7 00:19:26 anet octoprint[5239]: 2023-12-07 00:19:22,384 - octoprint.plugins.stepd - INFO - ERR: github.com/colinrgodsey/step-daemon/lib/pipeline.ConfigHandler.func1(0x91d880, 0x91d800, 0x91d900, 0x91d940)#033[0m
Dec  7 00:19:27 anet octoprint[5239]: 2023-12-07 00:19:22,388 - octoprint.plugins.stepd - INFO - ERR: /home/frank/.octoprint/data/stepd/repo/lib/pipeline/config_handler.go:178 +0x368#033[0m
Dec  7 00:19:27 anet octoprint[5239]: 2023-12-07 00:19:25,820 - octoprint.plugins.stepd - INFO - ERR: created by main.handler#033[0m
Dec  7 00:19:27 anet octoprint[5239]: #033[31m2023-12-07 00:19:26,255 - octoprint.util.comm - ERROR - Unexpected error while writing to serial port#033[0m
Dec  7 00:19:27 anet octoprint[5239]: Traceback (most recent call last):
Dec  7 00:19:27 anet octoprint[5239]:   File "/home/frank/oprint/lib/python3.9/site-packages/octoprint/util/comm.py", line 4957, in _do_send_without_checksum
Dec  7 00:19:27 anet octoprint[5239]:     result = self._serial.write(to_send)
Dec  7 00:19:27 anet octoprint[5239]:   File "/home/frank/oprint/lib/python3.9/site-packages/octoprint_stepd/StepdService.py", line 47, in write
Dec  7 00:19:27 anet octoprint[5239]:     self.process.stdin.flush()
Dec  7 00:19:27 anet octoprint[5239]: BrokenPipeError: [Errno 32] Broken pipe
Dec  7 00:19:27 anet octoprint[5239]: 2023-12-07 00:19:26,995 - octoprint.plugins.stepd - INFO - ERR: /home/frank/.octoprint/data/stepd/repo/cmd/stepd/main.go:41 +0x78#033[0m
Dec  7 00:19:27 anet octoprint[5239]: 2023-12-07 00:19:27,107 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Offline after error"#033[0m
Dec  7 00:19:27 anet octoprint[5239]: 2023-12-07 00:19:27,132 - octoprint.plugins.stepd - INFO - service terminated#033[0m
Dec  7 00:19:27 anet octoprint[5239]: 2023-12-07 00:19:27,135 - octoprint.server - INFO - Starting autorefresh of serial port list#033[0m
Dec  7 00:19:27 anet octoprint[5239]: 2023-12-07 00:19:27,169 - octoprint.plugins.action_command_notification - INFO - Notifications cleared#033[0m
Dec  7 00:31:01 anet octoprint[5239]: 2023-12-07 00:31:01,603 - octoprint.server.heartbeat - INFO - Server heartbeat <3#033[0m
Dec  7 00:31:14 anet octoprint[5239]: 2023-12-07 00:31:14,501 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.178.28#033[0m
Dec  7 00:46:01 anet octoprint[5239]: 2023-12-07 00:46:01,658 - octoprint.server.heartbeat - INFO - Server heartbeat <3#033[0m](

FrankBoesing avatar Dec 07 '23 00:12 FrankBoesing