Hi, all.
I have inserted @pause command into the G-code to change filament during print. The print pauses at the correct time/point. Changing filament takes up to 2 minutes. Sometimes printer correctly waits those 2 minutes and resumes printing only after "resume" button is pushed in OctoPrint interface. But almost every other time printer resumes to print about 40 seconds after the pause started WITHOUT "resume" button to be pushed (even without pushed accidentally).
To solve the problem i have repeated the prints several times but could not notice any conditions associated with normal or premature resuming.
Here are scripts and log-files:
after print job is paused script
{% if pause_position.x is not none %}
G91 ; set relative
M83 ; extruder relative
G1 Z+5 E-5 F4500 ; retract 5 mm and move 5 mm up
G90 ; set absolute
M82 ; extruder absolute
G1 X10 Y-10 ; go to safe rest position to change filament
M300 S300 P2000 ; make beep for 2 sec
; M117 change filament
{% endif %}
before print job is resumed script:
{% if pause_position.x is not none %}
M83 ; relative extruder
; prime nozzle
G1 E-5 F4500
G1 E5 F4500
G1 E5 F4500
G4 S2
M82 ; absolute E
G90 ; absolute XYZ
G92 E{{ pause_position.e }} ; set E to where it was before pause
; move back to pre-pause position XYZ
G1 X{{pause_position.x }} Y{{pause_position.y }} Z{{pause_position.z }} F4500
; reset to feedrate before pause if available
{% if pause_position.f is not none %}G1 F{{ pause_position.f }}{% endif %}{% endif %}
octoprint.log
2018-12-04 19:08:10,957 - octoprint.plugins.enclosure - INFO - DS18B20 result: 32.0
2018-12-04 19:08:10,960 - octoprint.plugins.enclosure - INFO - Sensor Enclosure_temperature Temperature: 32.0 humidity 0.0
2018-12-04 19:08:14,204 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Pausing"
2018-12-04 19:08:15,035 - octoprint.util.comm - INFO - Changing monitoring state from "Pausing" to "Paused"
2018-12-04 19:08:21,917 - octoprint.plugins.enclosure - INFO - DS18B20 result: 32.062
2018-12-04 19:08:21,921 - octoprint.plugins.enclosure - INFO - Sensor Enclosure_temperature Temperature: 32.1 humidity 0.0
2018-12-04 19:08:30,501 - octoprint.plugins.navbartemp - INFO - Checking SoC internal temperature
2018-12-04 19:08:32,876 - octoprint.plugins.enclosure - INFO - DS18B20 result: 34.687
2018-12-04 19:08:32,881 - octoprint.plugins.enclosure - INFO - Sensor Enclosure_temperature Temperature: 34.7 humidity 0.0
2018-12-04 19:08:32,883 - octoprint.plugins.enclosure - INFO - Turning gpio to control temperature on.
2018-12-04 19:08:32,888 - octoprint.plugins.enclosure - INFO - Writing on gpio: 13 value True
2018-12-04 19:08:43,836 - octoprint.plugins.enclosure - INFO - DS18B20 result: 32.625
2018-12-04 19:08:43,840 - octoprint.plugins.enclosure - INFO - Sensor Enclosure_temperature Temperature: 32.6 humidity 0.0
2018-12-04 19:08:54,796 - octoprint.plugins.enclosure - INFO - DS18B20 result: 31.875
2018-12-04 19:08:54,801 - octoprint.plugins.enclosure - INFO - Sensor Enclosure_temperature Temperature: 31.9 humidity 0.0
2018-12-04 19:08:54,804 - octoprint.util.comm - INFO - Changing monitoring state from "Paused" to "Resuming"
2018-12-04 19:08:54,834 - octoprint.plugins.enclosure - INFO - Turning gpio to control temperature off.
2018-12-04 19:08:54,839 - octoprint.plugins.enclosure - INFO - Writing on gpio: 13 value False
2018-12-04 19:08:57,237 - octoprint.util.comm - INFO - Changing monitoring state from "Resuming" to "Printing"
2018-12-04 19:09:00,556 - octoprint.plugins.navbartemp - INFO - Checking SoC internal temperature
2018-12-04 19:09:05,915 - octoprint.plugins.enclosure - INFO - DS18B20 result: 31.25
serial.log
2018-12-04 19:08:53,173 - Recv: T:194.82 /195 B:52.99 /53 B@:0 @:132
2018-12-04 19:08:54,052 - Recv: wait
2018-12-04 19:08:54,259 - Recv: T:194.82 /195 B:52.93 /53 B@:47 @:118
2018-12-04 19:08:54,804 - Changing monitoring state from "Paused" to "Resuming"
2018-12-04 19:08:54,846 - Send: N27360 M83*24
2018-12-04 19:08:54,868 - Recv: ok 27360
2018-12-04 19:08:54,875 - Send: N27361 G1 E-5 F4500*51
2018-12-04 19:08:54,904 - Recv: ok 27361
2018-12-04 19:08:54,911 - Send: N27362 G1 E5 F4500*29
2018-12-04 19:08:54,935 - Recv: ok 27362
2018-12-04 19:08:54,941 - Send: N27363 G1 E5 F4500*28
2018-12-04 19:08:54,963 - Recv: ok 27363
2018-12-04 19:08:54,970 - Send: N27364 G4 S2*104
2018-12-04 19:08:54,978 - Recv: ok 27364
2018-12-04 19:08:55,363 - Recv: T:194.82 /195 B:52.87 /53 B@:44 @:126
2018-12-04 19:08:56,449 - Recv: T:194.71 /195 B:53.11 /53 B@:0 @:133
2018-12-04 19:08:56,976 - Send: N27365 M82*28
2018-12-04 19:08:56,980 - Recv: busy:processing
2018-12-04 19:08:57,153 - Recv: ok 27365
2018-12-04 19:08:57,160 - Send: N27366 G90*22
2018-12-04 19:08:57,168 - Recv: ok 27366
2018-12-04 19:08:57,174 - Send: N27367 G92 E0.0*94
2018-12-04 19:08:57,184 - Recv: ok 27367
2018-12-04 19:08:57,190 - Send: N27368 G1 X133.99 Y126.94 Z3.8 F4500*16
2018-12-04 19:08:57,207 - Recv: ok 27368
2018-12-04 19:08:57,213 - Send: N27369 G1 F360.0*108
2018-12-04 19:08:57,232 - Recv: ok 27369
2018-12-04 19:08:57,236 - Changing monitoring state from "Resuming" to "Printing"
2018-12-04 19:08:57,250 - Send: N27370 M106 S255*100
2018-12-04 19:08:57,271 - Recv: ok 27370
2018-12-04 19:08:57,277 - Recv: Fanspeed:255
My OctoPrint ver. 1.3.9, printer firmware Repetier 1.0.3, no Klipper
I could not even understand who triggers premature event, OctoPrint or firmware.
Thank you for help.