Tempature code sent then drops out with control preheat

2018-05-28 19:20:05,117 - Changing monitoring state from "Offline" to "Detecting serial port"
2018-05-28 19:20:05,138 - Serial port list: ['/dev/ttyUSB0']
2018-05-28 19:20:05,139 - Connecting to: /dev/ttyUSB0
2018-05-28 19:20:05,154 - Changing monitoring state from "Detecting serial port" to "Opening serial port"
2018-05-28 19:20:05,157 - Connected to: Serial<id=0x723f6710, open=True>(port='/dev/ttyUSB0', baudrate=250000, bytesize=8, parity='N', stopbits=1, timeout=10.0, xonxoff=False, rtscts=False, dsrdtr=False), starting monitor
2018-05-28 19:20:05,158 - Changing monitoring state from "Opening serial port" to "Connecting"
2018-05-28 19:20:05,176 - Send: N0 M110 N0*125
2018-05-28 19:20:06,692 - Recv: start
2018-05-28 19:20:06,694 - Recv: echo:Marlin 1.1.8
2018-05-28 19:20:06,696 - Send: N0 M110 N0*125
2018-05-28 19:20:06,696 - Recv: 
2018-05-28 19:20:06,698 - Recv: echo: Last Updated: 2017-12-25 12:00 | Author: (Bob Kuhn, Anet config)
2018-05-28 19:20:06,699 - Recv: echo:Compiled: May 16 2018
2018-05-28 19:20:06,700 - Recv: echo: Free Memory: 12218  PlannerBufferBytes: 1232
2018-05-28 19:20:06,712 - Recv: echo:V47 stored settings retrieved (614 bytes; crc 19974)
2018-05-28 19:20:06,714 - Recv: echo:  G21    ; Units in mm
2018-05-28 19:20:06,715 - Recv: echo:  M149 C ; Units in Celsius
2018-05-28 19:20:06,716 - Recv: 
2018-05-28 19:20:06,717 - Recv: echo:Filament settings: Disabled
2018-05-28 19:20:06,718 - Recv: echo:  M200 D1.75
2018-05-28 19:20:06,719 - Recv: echo:  M200 D0
2018-05-28 19:20:06,720 - Recv: echo:Steps per unit:
2018-05-28 19:20:06,721 - Recv: echo:  M92 X100.00 Y100.00 Z400.00 E100.00
2018-05-28 19:20:06,722 - Recv: echo:Maximum feedrates (units/s):
2018-05-28 19:20:06,723 - Recv: echo:  M203 X400.00 Y400.00 Z8.00 E50.00
2018-05-28 19:20:06,724 - Recv: echo:Maximum Acceleration (units/s2):
2018-05-28 19:20:06,725 - Recv: echo:  M201 X2000 Y2000 Z100 E10000
2018-05-28 19:20:06,726 - Recv: echo:Acceleration (units/s2): P<print_accel> R<retract_accel> T<travel_accel>
2018-05-28 19:20:06,728 - Recv: echo:  M204 P400.00 R1000.00 T1000.00
2018-05-28 19:20:06,732 - Recv: echo:Advanced: S<min_feedrate> T<min_travel_feedrate> B<min_segment_time_us> X<max_xy_jerk> Z<max_z_jerk> E<max_e_jerk>
2018-05-28 19:20:06,735 - Recv: echo:  M205 S0.00 T0.00 B20000 X10.00 Y10.00 Z0.30 E5.00
2018-05-28 19:20:06,736 - Recv: echo:Home offset:
2018-05-28 19:20:06,737 - Recv: echo:  M206 X0.00 Y0.00 Z0.00
2018-05-28 19:20:06,739 - Recv: echo:Material heatup parameters:
2018-05-28 19:20:06,740 - Recv: echo:  M145 S0 H190 B60 F0
2018-05-28 19:20:06,741 - Recv: echo:  M145 S1 H240 B90 F0
2018-05-28 19:20:06,742 - Recv: echo:PID settings:
2018-05-28 19:20:06,744 - Recv: echo:  M301 P21.00 I1.25 D86.00
2018-05-28 19:20:09,242 - Recv: ok
2018-05-28 19:20:09,269 - Changing monitoring state from "Connecting" to "Operational"
2018-05-28 19:20:09,302 - Send: N0 M110 N0*125
2018-05-28 19:20:09,426 - Recv: ok
2018-05-28 19:20:09,428 - Send: N1 M115*39
2018-05-28 19:20:09,516 - Recv: FIRMWARE_NAME:Marlin 1.1.8 (Github) SOURCE_CODE_URL:https://github.com/MarlinFirmware/Marlin PROTOCOL_VERSION:1.0 MACHINE_TYPE:3D Printer EXTRUDER_COUNT:1 UUID:cede2a2f-41a2-4748-9b12-c55c62f367ff
2018-05-28 19:20:09,527 - Recv: Cap:SERIAL_XON_XOFF:0
2018-05-28 19:20:09,537 - Recv: Cap:EEPROM:1
2018-05-28 19:20:09,538 - Recv: Cap:VOLUMETRIC:1
2018-05-28 19:20:09,544 - Recv: Cap:AUTOREPORT_TEMP:1
2018-05-28 19:20:09,555 - Recv: Cap:PROGRESS:0
2018-05-28 19:20:09,561 - Recv: Cap:PRINT_JOB:1
2018-05-28 19:20:09,563 - Recv: Cap:AUTOLEVEL:0
2018-05-28 19:20:09,564 - Recv: Cap:Z_PROBE:0
2018-05-28 19:20:09,568 - Recv: Cap:LEVELING_DATA:0
2018-05-28 19:20:09,574 - Recv: Cap:BUILD_PERCENT:0
2018-05-28 19:20:09,576 - Recv: Cap:SOFTWARE_POWER:0
2018-05-28 19:20:09,580 - Recv: Cap:TOGGLE_LIGHTS:0
2018-05-28 19:20:09,582 - Recv: Cap:CASE_LIGHT_BRIGHTNESS:0
2018-05-28 19:20:09,583 - Recv: Cap:EMERGENCY_PARSER:0
2018-05-28 19:20:09,584 - Recv: ok
2018-05-28 19:20:09,585 - Send: M21
2018-05-28 19:20:13,862 - Recv: echo:SD init fail
2018-05-28 19:20:13,943 - Recv: ok
2018-05-28 19:20:13,945 - Send: G21
2018-05-28 19:20:17,994 - Recv: echo:SD init fail
2018-05-28 19:20:17,998 - Recv: ok
2018-05-28 19:20:18,004 - Send: G28
2018-05-28 19:20:31,889 - Recv: X:-33.00 Y:-10.00 Z:0.00 E:0.00 Count X:-3300 Y:-1000 Z:0
2018-05-28 19:20:32,258 - Recv: ok
2018-05-28 19:20:32,498 - Send: M84
2018-05-28 19:20:32,696 - Recv: ok
2018-05-28 19:20:32,698 - Send: M155 S2
2018-05-28 19:20:32,818 - Recv: ok
2018-05-28 19:20:32,820 - Send: M105
2018-05-28 19:20:32,826 - Recv: ok T:55.15 /0.00 B:45.66 /0.00 @:0 B@:0
2018-05-28 19:20:34,706 - Recv:  T:54.11 /0.00 B:45.50 /0.00 @:0 B@:0
2018-05-28 19:20:36,720 - Recv:  T:54.12 /0.00 B:45.50 /0.00 @:0 B@:0
2018-05-28 19:20:38,731 - Recv:  T:54.46 /0.00 B:45.50 /0.00 @:0 B@:0
2018-05-28 19:20:40,724 - Recv:  T:55.04 /0.00 B:45.41 /0.00 @:0 B@:0
2018-05-28 19:20:42,704 - Recv:  T:55.10 /0.00 B:45.25 /0.00 @:0 B@:0
2018-05-28 19:20:44,704 - Recv:  T:55.49 /0.00 B:45.25 /0.00 @:0 B@:0
2018-05-28 19:20:46,703 - Recv:  T:55.33 /0.00 B:45.25 /0.00 @:0 B@:0
2018-05-28 19:20:48,703 - Recv:  T:55.61 /0.00 B:45.13 /0.00 @:0 B@:0
2018-05-28 19:20:50,704 - Recv:  T:56.37 /0.00 B:45.00 /0.00 @:0 B@:0
2018-05-28 19:20:52,704 - Recv:  T:56.27 /0.00 B:45.00 /0.00 @:0 B@:0
2018-05-28 19:20:54,704 - Recv:  T:56.80 /0.00 B:45.00 /0.00 @:0 B@:0
2018-05-28 19:20:56,703 - Recv:  T:57.06 /0.00 B:44.98 /0.00 @:0 B@:0
2018-05-28 19:20:58,703 - Recv:  T:56.86 /0.00 B:44.75 /0.00 @:0 B@:0
2018-05-28 19:21:00,704 - Recv:  T:56.67 /0.00 B:44.75 /0.00 @:0 B@:0
2018-05-28 19:21:02,703 - Recv:  T:56.40 /0.00 B:44.75 /0.00 @:0 B@:0
2018-05-28 19:21:04,704 - Recv:  T:56.27 /0.00 B:44.73 /0.00 @:0 B@:0
2018-05-28 19:21:06,706 - Recv:  T:56.27 /0.00 B:44.52 /0.00 @:0 B@:0
2018-05-28 19:21:08,706 - Recv:  T:56.00 /0.00 B:44.50 /0.00 @:0 B@:0
2018-05-28 19:21:10,707 - Recv:  T:55.69 /0.00 B:44.50 /0.00 @:0 B@:0
2018-05-28 19:21:12,708 - Recv:  T:55.71 /0.00 B:44.50 /0.00 @:0 B@:0
2018-05-28 19:21:14,707 - Recv:  T:55.07 /0.00 B:44.36 /0.00 @:0 B@:0
2018-05-28 19:21:16,708 - Recv:  T:53.64 /0.00 B:44.25 /0.00 @:0 B@:0
2018-05-28 19:21:18,708 - Recv:  T:52.33 /0.00 B:44.25 /0.00 @:0 B@:0
2018-05-28 19:21:20,708 - Recv:  T:51.14 /0.00 B:44.25 /0.00 @:0 B@:0
2018-05-28 19:21:22,709 - Recv:  T:49.75 /0.00 B:44.23 /0.00 @:0 B@:0
2018-05-28 19:21:24,709 - Recv:  T:48.50 /0.00 B:44.03 /0.00 @:0 B@:0
2018-05-28 19:21:26,709 - Recv:  T:47.25 /0.00 B:44.00 /0.00 @:0 B@:0
2018-05-28 19:21:28,709 - Recv:  T:46.00 /0.00 B:44.00 /0.00 @:0 B@:0
2018-05-28 19:21:30,709 - Recv:  T:45.02 /0.00 B:44.00 /0.00 @:0 B@:0
2018-05-28 19:21:32,709 - Recv:  T:44.97 /0.00 B:43.86 /0.00 @:0 B@:0
2018-05-28 19:21:34,709 - Recv:  T:44.47 /0.00 B:43.77 /0.00 @:0 B@:0
2018-05-28 19:21:36,709 - Recv:  T:44.00 /0.00 B:43.75 /0.00 @:0 B@:0
2018-05-28 19:21:36,838 - Send: G91
2018-05-28 19:21:36,853 - Recv: ok
2018-05-28 19:21:36,856 - Send: G1 Z10 F200
2018-05-28 19:21:36,864 - Recv: ok
2018-05-28 19:21:36,866 - Send: G90
2018-05-28 19:21:36,871 - Recv: ok
2018-05-28 19:21:37,071 - Send: G91
2018-05-28 19:21:37,081 - Recv: ok
2018-05-28 19:21:37,083 - Send: G1 Z10 F200
2018-05-28 19:21:37,091 - Recv: ok
2018-05-28 19:21:37,093 - Send: G90
2018-05-28 19:21:37,098 - Recv: ok
2018-05-28 19:21:37,464 - Send: G91
2018-05-28 19:21:37,474 - Recv: ok
2018-05-28 19:21:37,476 - Send: G1 Z10 F200
2018-05-28 19:21:37,483 - Recv: ok
2018-05-28 19:21:37,486 - Send: G90
2018-05-28 19:21:37,491 - Recv: ok
2018-05-28 19:21:37,670 - Send: G91
2018-05-28 19:21:37,681 - Recv: ok
2018-05-28 19:21:37,683 - Send: G1 Z10 F200
2018-05-28 19:21:37,690 - Recv: ok
2018-05-28 19:21:37,692 - Send: G90
2018-05-28 19:21:37,697 - Recv: ok
2018-05-28 19:21:38,710 - Recv:  T:43.41 /0.00 B:43.70 /0.00 @:0 B@:0
2018-05-28 19:21:40,710 - Recv:  T:42.83 /0.00 B:43.70 /0.00 @:0 B@:0
2018-05-28 19:21:41,910 - Send: G91
2018-05-28 19:21:41,932 - Recv: ok
2018-05-28 19:21:41,935 - Send: G1 Z10 F200
2018-05-28 19:21:41,942 - Recv: ok
2018-05-28 19:21:41,945 - Send: G90
2018-05-28 19:21:41,950 - Recv: ok
2018-05-28 19:21:42,205 - Send: G91
2018-05-28 19:21:42,214 - Recv: ok
2018-05-28 19:21:42,217 - Send: G1 Z10 F200
2018-05-28 19:21:42,244 - Recv: ok
2018-05-28 19:21:42,247 - Send: G90
2018-05-28 19:21:42,252 - Recv: ok
2018-05-28 19:21:42,624 - Send: G91
2018-05-28 19:21:42,633 - Recv: ok
2018-05-28 19:21:42,636 - Send: G1 Z10 F200
2018-05-28 19:21:42,643 - Recv: ok
2018-05-28 19:21:42,646 - Send: G90
2018-05-28 19:21:42,651 - Recv: ok
2018-05-28 19:21:42,710 - Recv:  T:42.56 /0.00 B:43.61 /0.00 @:0 B@:0
2018-05-28 19:21:42,854 - Send: G91
2018-05-28 19:21:42,869 - Recv: ok
2018-05-28 19:21:42,871 - Send: G1 Z10 F200
2018-05-28 19:21:42,879 - Recv: ok
2018-05-28 19:21:42,881 - Send: G90
2018-05-28 19:21:42,886 - Recv: ok
2018-05-28 19:21:43,089 - Send: G91
2018-05-28 19:21:43,099 - Recv: ok
2018-05-28 19:21:43,102 - Send: G1 Z10 F200
2018-05-28 19:21:43,109 - Recv: ok
2018-05-28 19:21:43,112 - Send: G90
2018-05-28 19:21:43,117 - Recv: ok
2018-05-28 19:21:43,327 - Send: G91
2018-05-28 19:21:43,339 - Recv: ok
2018-05-28 19:21:43,345 - Send: G1 Z10 F200
2018-05-28 19:21:43,352 - Recv: ok
2018-05-28 19:21:43,354 - Send: G90
2018-05-28 19:21:43,360 - Recv: ok
2018-05-28 19:21:43,642 - Send: G91
2018-05-28 19:21:43,653 - Recv: ok
2018-05-28 19:21:43,656 - Send: G1 Z10 F200
2018-05-28 19:21:43,662 - Recv: ok
2018-05-28 19:21:43,665 - Send: G90
2018-05-28 19:21:43,670 - Recv: ok
2018-05-28 19:21:44,194 - Send: G91
2018-05-28 19:21:44,205 - Recv: ok
2018-05-28 19:21:44,207 - Send: G1 Z10 F200
2018-05-28 19:21:44,215 - Recv: ok
2018-05-28 19:21:44,218 - Send: G90
2018-05-28 19:21:44,242 - Recv: ok
2018-05-28 19:21:44,657 - Send: G91
2018-05-28 19:21:44,662 - Recv: ok
2018-05-28 19:21:44,665 - Send: G1 Z10 F200
2018-05-28 19:21:44,673 - Recv: ok
2018-05-28 19:21:44,676 - Send: G90
2018-05-28 19:21:44,681 - Recv: ok
2018-05-28 19:21:44,710 - Recv:  T:42.59 /0.00 B:43.52 /0.00 @:0 B@:0
2018-05-28 19:21:44,955 - Send: G91
2018-05-28 19:21:44,973 - Recv: ok
2018-05-28 19:21:44,975 - Send: G1 Z10 F200
2018-05-28 19:21:44,983 - Recv: ok
2018-05-28 19:21:44,985 - Send: G90
2018-05-28 19:21:44,990 - Recv: ok
2018-05-28 19:21:45,311 - Send: G91
2018-05-28 19:21:45,324 - Recv: ok
2018-05-28 19:21:45,327 - Send: G1 Z10 F200
2018-05-28 19:21:45,334 - Recv: ok
2018-05-28 19:21:45,337 - Send: G90
2018-05-28 19:21:45,342 - Recv: ok
2018-05-28 19:21:45,919 - Send: G91
2018-05-28 19:21:45,933 - Recv: ok
2018-05-28 19:21:45,936 - Send: G1 Z10 F200
2018-05-28 19:21:45,943 - Recv: ok
2018-05-28 19:21:45,946 - Send: G90
2018-05-28 19:21:45,951 - Recv: ok
2018-05-28 19:21:46,710 - Recv:  T:42.38 /0.00 B:43.52 /0.00 @:0 B@:0
2018-05-28 19:21:46,967 - Send: G91
2018-05-28 19:21:46,981 - Recv: ok
2018-05-28 19:21:46,987 - Send: G1 Z10 F200
2018-05-28 19:21:46,994 - Recv: ok
2018-05-28 19:21:46,997 - Send: G90
2018-05-28 19:21:47,002 - Recv: ok
2018-05-28 19:21:47,332 - Send: G91
2018-05-28 19:21:47,340 - Recv: ok
2018-05-28 19:21:47,343 - Send: G1 Z10 F200
2018-05-28 19:21:47,352 - Recv: ok
2018-05-28 19:21:47,355 - Send: G90
2018-05-28 19:21:47,360 - Recv: ok
2018-05-28 19:21:47,579 - Send: G91
2018-05-28 19:21:47,592 - Recv: ok
2018-05-28 19:21:47,597 - Send: G1 Z10 F200
2018-05-28 19:21:48,710 - Recv:  T:41.86 /0.00 B:43.52 /0.00 @:0 B@:0
2018-05-28 19:21:48,882 - Recv: ok
2018-05-28 19:21:48,884 - Send: G90
2018-05-28 19:21:48,889 - Recv: ok
2018-05-28 19:21:48,891 - Send: G91
2018-05-28 19:21:48,897 - Recv: ok
2018-05-28 19:21:48,899 - Send: G1 Z10 F200
2018-05-28 19:21:50,710 - Recv:  T:41.44 /0.00 B:43.45 /0.00 @:0 B@:0
2018-05-28 19:21:51,884 - Recv: ok
2018-05-28 19:21:51,892 - Send: G90
2018-05-28 19:21:51,898 - Recv: ok
2018-05-28 19:21:51,901 - Send: G91
2018-05-28 19:21:51,905 - Recv: ok
2018-05-28 19:21:51,908 - Send: G1 Z10 F200
2018-05-28 19:21:52,709 - Recv:  T:40.77 /0.00 B:43.36 /0.00 @:0 B@:0
2018-05-28 19:21:54,711 - Recv:  T:40.17 /0.00 B:43.28 /0.00 @:0 B@:0
2018-05-28 19:21:54,885 - Recv: ok
2018-05-28 19:21:54,887 - Send: G90
2018-05-28 19:21:54,892 - Recv: ok
2018-05-28 19:21:54,894 - Send: G91
2018-05-28 19:21:54,898 - Recv: ok
2018-05-28 19:21:54,901 - Send: G1 Z10 F200
2018-05-28 19:21:56,710 - Recv:  T:39.57 /0.00 B:43.23 /0.00 @:0 B@:0
2018-05-28 19:21:57,887 - Recv: ok
2018-05-28 19:21:57,895 - Send: G90
2018-05-28 19:21:57,900 - Recv: ok
2018-05-28 19:21:57,903 - Send: G91
2018-05-28 19:21:57,908 - Recv: ok
2018-05-28 19:21:57,910 - Send: G1 Z10 F200
2018-05-28 19:21:58,711 - Recv:  T:38.92 /0.00 B:43.22 /0.00 @:0 B@:0
2018-05-28 19:22:00,710 - Recv:  T:38.28 /0.00 B:43.17 /0.00 @:0 B@:0
2018-05-28 19:22:00,889 - Recv: ok
2018-05-28 19:22:00,892 - Send: G90
2018-05-28 19:22:00,896 - Recv: ok
2018-05-28 19:22:00,899 - Send: G91
2018-05-28 19:22:00,904 - Recv: ok
2018-05-28 19:22:00,906 - Send: G1 Z10 F200
2018-05-28 19:22:02,710 - Recv:  T:37.95 /0.00 B:43.11 /0.00 @:0 B@:0
2018-05-28 19:22:03,891 - Recv: ok
2018-05-28 19:22:03,899 - Send: G90
2018-05-28 19:22:03,904 - Recv: ok
2018-05-28 19:22:03,907 - Send: G91
2018-05-28 19:22:03,912 - Recv: ok
2018-05-28 19:22:03,914 - Send: G1 Z10 F200
2018-05-28 19:22:04,710 - Recv:  T:37.50 /0.00 B:43.05 /0.00 @:0 B@:0
2018-05-28 19:22:06,710 - Recv:  T:37.22 /0.00 B:43.00 /0.00 @:0 B@:0
2018-05-28 19:22:06,891 - Recv: ok
2018-05-28 19:22:06,894 - Send: G90
2018-05-28 19:22:06,899 - Recv: ok
2018-05-28 19:22:06,901 - Send: G91
2018-05-28 19:22:06,906 - Recv: ok
2018-05-28 19:22:06,909 - Send: G1 Z10 F200
2018-05-28 19:22:06,915 - Recv: ok
2018-05-28 19:22:06,918 - Send: G90
2018-05-28 19:22:06,923 - Recv: ok
2018-05-28 19:22:06,925 - Send: G91
2018-05-28 19:22:06,930 - Recv: ok
2018-05-28 19:22:06,932 - Send: G1 Z10 F200
2018-05-28 19:22:06,938 - Recv: ok
2018-05-28 19:22:06,941 - Send: G90
2018-05-28 19:22:06,946 - Recv: ok
2018-05-28 19:22:06,948 - Send: G91
2018-05-28 19:22:06,953 - Recv: ok
2018-05-28 19:22:06,956 - Send: G1 Z10 F200
2018-05-28 19:22:06,961 - Recv: ok
2018-05-28 19:22:06,963 - Send: G90
2018-05-28 19:22:06,969 - Recv: ok
2018-05-28 19:22:06,971 - Send: G91
2018-05-28 19:22:06,976 - Recv: ok
2018-05-28 19:22:06,979 - Send: G1 Z10 F200
2018-05-28 19:22:06,984 - Recv: ok
2018-05-28 19:22:06,987 - Send: G90
2018-05-28 19:22:06,991 - Recv: ok
2018-05-28 19:22:06,994 - Send: G91
2018-05-28 19:22:06,999 - Recv: ok
2018-05-28 19:22:07,001 - Send: G1 Z10 F200
2018-05-28 19:22:07,007 - Recv: ok
2018-05-28 19:22:07,009 - Send: G90
2018-05-28 19:22:07,014 - Recv: ok
2018-05-28 19:22:07,017 - Send: G91
2018-05-28 19:22:07,022 - Recv: ok
2018-05-28 19:22:07,024 - Send: G1 Z-10 F200
2018-05-28 19:22:07,032 - Recv: ok
2018-05-28 19:22:07,035 - Send: G90
2018-05-28 19:22:07,040 - Recv: ok
2018-05-28 19:22:07,042 - Send: G91
2018-05-28 19:22:07,047 - Recv: ok
2018-05-28 19:22:07,050 - Send: G1 Z-10 F200
2018-05-28 19:22:08,708 - Recv:  T:36.90 /0.00 B:42.92 /0.00 @:0 B@:0
2018-05-28 19:22:09,895 - Recv: ok
2018-05-28 19:22:09,903 - Send: G90
2018-05-28 19:22:09,908 - Recv: ok
2018-05-28 19:22:09,911 - Send: G91
2018-05-28 19:22:09,916 - Recv: ok
2018-05-28 19:22:09,919 - Send: G1 Z-10 F200
2018-05-28 19:22:10,708 - Recv:  T:36.57 /0.00 B:42.91 /0.00 @:0 B@:0
2018-05-28 19:22:12,708 - Recv:  T:36.23 /0.00 B:42.80 /0.00 @:0 B@:0
2018-05-28 19:22:12,895 - Recv: ok
2018-05-28 19:22:12,898 - Send: G90
2018-05-28 19:22:12,902 - Recv: ok
2018-05-28 19:22:12,905 - Send: G91
2018-05-28 19:22:12,910 - Recv: ok
2018-05-28 19:22:12,913 - Send: G1 Z-10 F200
2018-05-28 19:22:14,707 - Recv:  T:36.10 /0.00 B:42.78 /0.00 @:0 B@:0
2018-05-28 19:22:15,896 - Recv: ok
2018-05-28 19:22:15,904 - Send: G90
2018-05-28 19:22:15,910 - Recv: ok
2018-05-28 19:22:15,912 - Send: G91
2018-05-28 19:22:15,917 - Recv: ok
2018-05-28 19:22:15,920 - Send: G1 Z-10 F200
2018-05-28 19:22:16,707 - Recv:  T:35.93 /0.00 B:42.78 /0.00 @:0 B@:0
2018-05-28 19:22:18,706 - Recv:  T:35.60 /0.00 B:42.72 /0.00 @:0 B@:0
2018-05-28 19:22:18,897 - Recv: ok
2018-05-28 19:22:18,900 - Send: G90
2018-05-28 19:22:18,905 - Recv: ok
2018-05-28 19:22:18,907 - Send: G91
2018-05-28 19:22:18,912 - Recv: ok
2018-05-28 19:22:18,915 - Send: G1 Z-10 F200
2018-05-28 19:22:20,706 - Recv:  T:35.39 /0.00 B:42.63 /0.00 @:0 B@:0
2018-05-28 19:22:21,899 - Recv: ok
2018-05-28 19:22:21,902 - Send: G90
2018-05-28 19:22:21,910 - Recv: ok
2018-05-28 19:22:21,913 - Send: G91
2018-05-28 19:22:21,917 - Recv: ok
2018-05-28 19:22:21,920 - Send: G1 Z-10 F200
2018-05-28 19:22:22,705 - Recv:  T:35.15 /0.00 B:42.56 /0.00 @:0 B@:0
2018-05-28 19:22:24,705 - Recv:  T:35.04 /0.00 B:42.61 /0.00 @:0 B@:0
2018-05-28 19:22:24,900 - Recv: ok
2018-05-28 19:22:24,903 - Send: G90
2018-05-28 19:22:24,908 - Recv: ok
2018-05-28 19:22:24,910 - Send: G91
2018-05-28 19:22:24,915 - Recv: ok
2018-05-28 19:22:24,918 - Send: G1 Z-10 F200
2018-05-28 19:22:26,705 - Recv:  T:34.83 /0.00 B:42.53 /0.00 @:0 B@:0
2018-05-28 19:22:27,902 - Recv: ok
2018-05-28 19:22:27,908 - Send: G90
2018-05-28 19:22:27,913 - Recv: ok
2018-05-28 19:22:27,916 - Send: G91
2018-05-28 19:22:27,920 - Recv: ok
2018-05-28 19:22:27,923 - Send: G1 Z-10 F200
2018-05-28 19:22:28,704 - Recv:  T:34.81 /0.00 B:42.44 /0.00 @:0 B@:0
2018-05-28 19:22:30,704 - Recv:  T:34.63 /0.00 B:42.44 /0.00 @:0 B@:0
2018-05-28 19:22:30,903 - Recv: ok
2018-05-28 19:22:30,906 - Send: G90
2018-05-28 19:22:30,911 - Recv: ok
2018-05-28 19:22:30,913 - Send: G91
2018-05-28 19:22:30,918 - Recv: ok
2018-05-28 19:22:30,921 - Send: G1 Z-10 F200
2018-05-28 19:22:32,703 - Recv:  T:34.48 /0.00 B:42.47 /0.00 @:0 B@:0
2018-05-28 19:22:33,905 - Recv: ok
2018-05-28 19:22:33,914 - Send: G90
2018-05-28 19:22:33,918 - Recv: ok
2018-05-28 19:22:33,921 - Send: G91
2018-05-28 19:22:33,926 - Recv: ok
2018-05-28 19:22:33,929 - Send: G1 Z-10 F200
2018-05-28 19:22:34,704 - Recv:  T:34.44 /0.00 B:42.34 /0.00 @:0 B@:0
2018-05-28 19:22:36,702 - Recv:  T:34.29 /0.00 B:42.27 /0.00 @:0 B@:0
2018-05-28 19:22:36,906 - Recv: ok
2018-05-28 19:22:36,909 - Send: G90
2018-05-28 19:22:36,914 - Recv: ok
2018-05-28 19:22:36,916 - Send: G91
2018-05-28 19:22:36,921 - Recv: ok
2018-05-28 19:22:36,924 - Send: G1 Z-10 F200

Hope this helps in some sort of way.

@wildvortex Is this serial.log a capture of some activity that failed (like you posted in your original post)?

To me it just looks like a fresh connect to the printer and someone / something is moving the Z axis up and down.

In ~/.octoprint/logs (or OctoPrint Settings, Logging) there are probably multiple versions of serial.log some of which will also have a ."date string" on the end. If you just restarted OctoPrint after a failure, then the serial.log file that includes the failure will be the one with the latest ."date string" on the end.

Since the serial.log and the octoprint.log (and any other log files) are time stamped, making a note of the time when a failure occurs or when you interact with your printer or your software can help you find the correct log file (or segment of the correct log file) to post.

I understand this is all new to you and you are frustrated but as @OutsourcedGuru put it, you need to help us so we can help you.

As an additional observation: That log looks like the printer was at some temperature (~55°C) but with target set to 0 and hence the hotend slowly cooling. This could be due to you setting a target temperature outside of this OctoPrint connection (e.g. through an earlier connection or through the printer controller itself). If through the printer itself, keep in mind that most printers or rather their controllers reset when you connect to them via serial (OctoPrint or any other kind of host program), and that reset also clears the target temperatures.

The issue is that when I tell Octoprint to print a second or third print it will set the bed Temp but hotend temp stays at 0. If I manually try to set the temperature after that the target temp will momentarily show 180 then drop back to 0. Also at that point if I send M109 S190 it will not show the command in the terminal log. The only way to stop this from happening is a total reset. I am shut down for the night. I'll capture the log in the morning. I will get it to act up.
On another note, once a print was done I tried sending a M106 S51 command and also nothing was happening. All of this is happening after 1 print

yes, there was a lot of up and down as I was working on the machine yesterday. I sent that log as I also had the issue then. will try to start up and make it produce the problem and then capture just that tomorrow.

1 Like

That sounds like the communication is getting stuck someway after completion of a print. So best try a small print, capture a serial.log of that and share that here. We need to see what exactly is happening throughout the whole communication lifecycle.

You could test if you can reproduce with the attached gcode file, it's what I use a lot during development for quick "print start"/"print done" tests. The only thing it does is put some messages on the printer's controller and home the print head.

only_home.gcode (44 Bytes)

Or use this one, that does a blocking heatup of the hotend to 100°C and then shuts off the heater again.

heatup_test.gcode (71 Bytes)

If you use those, make sure though that you really see the same broken behaviour with them - the issue might as well be caused by something in your sliced GCODE files, and in that case it's not guaranteed you can replicate it with those two very small test files.

serial.log (35.5 KB)
history of this log, I ran your homing G code then your hotend heat Gcode. Directly after that I ran your hotend Gcode and still no sign. Finally I tried to run a File I had created and that is when I saw the Bed heat set and not the hotend. Once this happens the only way to get the printer to work correctly is to reset Octoprint. Again, as long as I set the preheat prior to starting a print there is no problem.

I have noticed too at times that if I cancel a print it take a very long time to cancel it sometimes prompting me to reset as well.

Hope this is informative enough.

First of all, that looks like completely expected behaviour and I'm going to tell you why:

Based on the log, that is because you set the bed heat using M190, which is a blocking heatup, meaning the printer won't return control to the host until the heatup is completed:

2018-05-30 12:34:09,217 - Changing monitoring state from "Operational" to "Printing"
2018-05-30 12:34:09,233 - Send: N0 M110 N0*125
2018-05-30 12:34:09,239 - Recv: ok
2018-05-30 12:34:09,241 - Send: N1 M190 S50*92
2018-05-30 12:34:09,248 - Recv:  T:80.51 /0.00 B:23.50 /50.00 @:0 B@:0 W:?
2018-05-30 12:34:10,249 - Recv:  T:80.27 /0.00 B:23.50 /50.00 @:0 B@:0 W:?
2018-05-30 12:34:10,793 - Recv:  T:80.26 /0.00 B:23.50 /50.00 @:0 B@:0
2018-05-30 12:34:11,248 - Recv:  T:80.13 /0.00 B:23.50 /50.00 @:0 B@:0 W:?
[...]
2018-05-30 12:34:25,248 - Recv:  T:77.33 /0.00 B:26.28 /50.00 @:0 B@:127 W:?
2018-05-30 12:34:26,147 - Changing monitoring state from "Printing" to "Cancelling"
2018-05-30 12:34:26,248 - Recv:  T:77.18 /0.00 B:26.50 /50.00 @:0 B@:127 W:?
[...]
2018-05-30 12:34:55,248 - Recv:  T:72.11 /0.00 B:34.83 /50.00 @:0 B@:127 W:?
2018-05-30 12:34:56,248 - Recv:  T:71.97 /0.00 B:34.91 /50.00 @:0 B@:127 W:?
2018-05-30 12:34:56,792 - Recv:  T:71.94 /0.00 B:35.17 /50.00 @:0 B@:127
2018-05-30 12:34:57,247 - Recv:  T:71.83 /0.00 B:35.17 /50.00 @:0 B@:127 W:?

Note how your bed had only reached 35°C when you aborted.

So OctoPrint will not send any commands following that blocking heatup command until your printer signals that it is done (since doing so could cause issues with the printer ignoring the commands or even locking up). No green light from the printer, no commands sent to the printer.

You then cancelled during the blocking heatup. Same issue. Control is only returned to OctoPrint once the blocking heatup is done, so it can't run the cancel script and hence not finish the cancel routine until your bed is at temperature. See also

To fix this you probably want to adjust your start GCODE in your slicer. Instead of setting and awaiting the bed temperature with M190 and then the hotend temperature with M109 like this:

M190 S60
M109 S210

set the bed temperature with M140, then set and wait for the hotend with M109, then finally wait for the bed with M190 like this:

M140 S60
M109 S210
M190 S60

That way both heaters can heat up simultanously and you reduce the wait times significantly (and hence also the "can't cancel because waiting" time frame).

As a side note, when your printer is in some blocking routine and you are in a hurry, simple disconnecting and reconnecting will usually suffice (since a serial connect causes most printer controllers to reset, effectively cancelling any blocking commands), you don't need to restart the OctoPrint server.

1 Like

I use Cura and have looked at my start Gcode and none of that code it there. Where else may I find it sending this code? I also took a look in Octoprint Gcode scripts and there is nothing in there for before the job begins

Unless one of your installed plugins is adding it (unlikely) it must be in either Cura's or OctoPrint's defined start GCODE. Check the GCODE file. If it's not in there, it's coming from OctoPrint (scripts or some plugin). If it is in there it's coming from your slicer.

One thing I thought of is that if I send that gcode to the printer just after startup both the hotend and bed will start to heat at the same time. If I resend that same gcode after then I get the result shown.

Ok, was just looking at a piece of Gcode and see what you are saying there. Talked to a friend who also uses Cura and he says it just can't be changed.

It is a defined start code with Cura...bummer! The world around to this is to set tempature in the tempature GUI prior to starting the print. I forget sometimes and get the problem we have been talking about. So, how do I mark this as solved?

Look at "Preferences" -> "Configure" -> "Printers" -> "Machine Settings". Here's mine for my CR-10S

Maybe not changed easily, but Cura's Extensions -> Post Processing -> Modify G-Code -> Add a script -> Search and Replace menu area allows you to post-process what's been sliced.

I really have no idea if this would work since I haven't tested it and the Internet doesn't have any great examples for Cura's regex yet.

Search:                  M190 S([0-9]*)\nM109 S([0-9]*)\n
Replace:                 M140 S$1\nM109 S$2\nM190 S$1\n
Use Regular Expressions: [x]

The machine settings that @Norman mentioned should work, plus this:

1 Like

Nope, no M190 there. That's the first place I looked. Seems to be a part of Marlin sourcecode

when looking at the code in comparison to my start code in cura it runs the following lines:This is a typical gcode header:
;FLAVOR:Marlin
;TIME:8225
;Filament used: 8.51902m
;Layer height: 0.2
;Generated with Cura_SteamEngine 3.3.1
M190 S50
M104 S200
M109 S200
M82 ;absolute extrusion mode
the remainder below is my machine start G-code has. so the M190 is run before that.
G21 ;metric values
G90 ;absolute positioning
M82 ;set extruder to absolute mode
M107 ;start with the fan off
G28 X0 Y0 ;move X/Y to min endstops
G28 Z0 ;move Z to min endstops
G1 Z25.0 F9000 ;move the platform down 15mm
G92 E0 ;zero the extruded length
G1 F200 E20 ;extrude 20mm of feed stock
G92 E0 ;zero the extruded length again
G1 F9000
M117 Printing...PI3_calibration_cylinder.gcode (955.3 KB)

I do see what you are saying now. Went to that posting. Added the lines to my startup G-code. I will see what happens when I get home and will update you all

Thanks Gina that works perfect.