Busy:Processing after subsequent extruder motor activation

Pierre

Hey guys, got a weird thing that started happening with printer. Everything was working fine the day before until i rebooted my pc sooooo nothing changed as far as i'm concerned.

Problem:

After all homing and preheating procedures, I can click on manual extrution for 1, 10, 50mm. I notice that the extruder motor rotates and then there is a pause, then it rotates again and then just stops. When this happens, all other commands get delayed (ie i click home, or jog and the printer takes 2-30s before executing the move). Further attempts to manually jog causes message "Busy:Processing".

What I already tried and same behavior occured:

Reduce BAUD rate to lower values

Increase extruder motors driver current

Decreased receive cache size to 63 in RH

Enabled send OK and WAIT in RH firmware configurator

Re-installed and regenerated RH firmware and Host

Changed USB ports

Changed computers

Changed Arduino DUE board for a new one

Grabbed a cup of coffee hoping for magic :)

Machine specs:

Custom built running on Arduino DUE with RADDS shield

Firmware: Repetier Firmware generated using Repetier-Firmware configuration tool for version 1.0.2

Host: Repetier Host 2.0.5

OS: Win 10 x64

Baud rate: 115200 ANSI

The night before I successfully ran 3D printing jobs and manually extruded without problems. If I do NOT activate extrude motors and simply do a dry run, everything works fine.

Any idea what may be causing this?
I've attached my config.json file and RH host logs in the file named configfiles.zip

Thanks ahead for your help.

Repetier

Ok, points 1,2,3,4,6,7,8,9 are useless to the problem. If you see busy:processing the connection is working well, only that the firmware has informed host that it is busy doing something, so please do not send anything else and do not time out.

The question here is which command does cause the busy state and why. So in host log window enable command, ack etc and run commands one by one. Wait until it is executed, not only queued. Then you see the commands send an can exactly say when it happens. One possible thing could be a integer overflow causing very long delays. In radds the delay can be 4 minutes I think it was if a timer was missed. The problem can happen on deltas as there are submoves with reduced precision, especially if extruder has a high steps per mm setting or segments per second is low. But I do not have these infos, so if you post I could say more. Attaching files does not work in this forum.

Pierre

@Repetier
Thanks for the feedback. Please see annotated logs bellow, I'll try to make a video.

// Machine homed using G28

13:06:35.424 : wait

13:06:35.846 : N14 G2838

13:06:35.846 : ok 14

13:06:37.846 : busy:processing

13:06:39.840 : busy:processing

13:06:41.612 : X:0.00 Y:0.00 Z:241.600 E:0.0000

13:06:41.612 : wait

// Machine can still jog manually (commands ommitted)

13:07:15.644 : wait

13:07:16.644 : wait

//activating cooling fan and setting extruder temp (using diamond hotend)

13:07:17.535 : N15 M104 T0 S180*28

13:07:17.535 : ok 15

13:07:17.535 : TargetExtr0:180

13:07:18.535 : wait

13:07:18.778 : N16 M106 P0 S25518

13:07:18.778 : ok 16

13:07:18.778 : Fanspeed:255

13:07:19.778 : wait

//Cooling fan and Heater temperature successfully stabilized

//Manually reset extruder position and extrude 10mm (E1 currently selected, but problem exhists with all extruders)

13:10:09.955 : wait

13:10:10.955 : wait

13:10:11.955 : wait

13:10:12.330 : N17 G92 E0*113

13:10:12.330 : ok 17

13:10:12.330 : N18 G1 E10 F12032

13:10:12.330 : ok 18

13:10:13.330 : wait

// Machine can still jog manually (commands ommitted)

//Manually reset extruder position and extrude 10mm a second time

13:11:15.403 : wait

13:11:15.756 : N19 G92 E0*127

13:11:15.756 : ok 19

13:11:16.756 : wait

13:11:34.778 : wait

13:11:35.247 : N20 G1 E10126

13:11:35.247 : ok 20

// Machine can still jog manually (commands ommitted)

//Manually reset extruder position and extrude 10mm a third time. At this point I can hear/see extruder partially extruding and pausing, then extruding again until 10mm of filament is extruded.

//NOTE: NO busy:processing signal is sent by firmware during this period, only WAIT signal.

13:11:44.262 : wait

13:11:45.250 : wait

13:11:45.797 : N21 G92 E0*116

13:11:45.797 : ok 21

13:11:51.797 : wait

13:11:52.797 : wait

13:11:53.188 : N22 G1 E10124

13:11:53.188 : ok 22

13:11:54.187 : wait

// Machine CANNOT jog manually (commands ommitted). Any commands past this point is shown in RH logs bellow. The firmware does NOT generate busy:processing signal, but instead the machine does NOT respond to any other commands.

13:12:03.196 : wait

13:12:04.196 : wait

13:12:05.040 : N23 G92 E0*118

13:12:05.040 : ok 23

13:12:06.040 : wait

13:12:07.040 : wait

13:12:08.040 : wait

13:12:08.196 : N24 G1 E10122

13:12:08.196 : ok 24

13:12:09.196 : wait

13:12:10.196 : wait

13:12:11.196 : wait

13:12:12.196 : wait

13:12:13.196 : wait

13:12:14.196 : wait

13:12:15.196 : wait

13:12:16.196 : wait

13:12:16.290 : N25 G92 E0*112

13:12:16.290 : ok 25

13:12:17.290 : wait

13:12:18.284 : wait

13:12:19.287 : wait

13:12:19.787 : N26 G1 E10120

13:12:19.787 : ok 26

13:12:20.787 : wait

13:12:21.787 : wait

13:12:22.787 : wait

13:12:23.787 : wait

13:12:24.787 : wait

13:12:25.787 : wait

13:12:26.724 : N27 G92 E0*114

13:12:26.724 : ok 27

13:12:27.724 : wait

13:12:28.717 : wait

13:12:29.724 : wait

13:12:30.724 : wait

13:12:31.724 : wait

13:12:32.724 : wait

13:12:33.724 : wait

13:12:33.990 : N28 G1 E10118

13:12:33.990 : ok 28

13:12:34.990 : wait

13:12:35.990 : wait

13:12:36.990 : wait

13:12:37.990 : wait

13:12:38.990 : wait

13:12:39.990 : wait

13:12:40.990 : wait

13:12:41.990 : wait

13:12:42.990 : wait

13:12:43.989 : wait

13:12:44.989 : wait

13:12:46.005 : wait

13:12:46.036 : N29 G92 E0*124

13:12:46.036 : ok 29

13:12:47.036 : wait

13:12:48.036 : wait

13:12:49.039 : wait

13:12:50.040 : wait

13:12:51.040 : wait

13:12:51.165 : N30 G1 E10*127

13:12:51.165 : ok 30

13:12:52.165 : wait

13:12:53.165 : wait

13:12:54.165 : wait

13:12:55.165 : wait

13:12:56.165 : wait

13:12:57.165 : wait

13:12:58.165 : wait

13:12:59.163 : wait

13:13:00.171 : wait

13:13:01.171 : wait

13:13:02.168 : wait

13:13:03.168 : wait

13:13:04.168 : wait

13:13:05.184 : wait

13:13:06.184 : wait

13:13:07.184 : wait

13:13:08.184 : wait

13:13:09.184 : wait

13:13:10.184 : wait

13:13:11.184 : wait

13:13:12.184 : wait

13:13:13.184 : wait

13:13:14.184 : wait

13:13:15.184 : wait

13:13:16.184 : wait

13:13:17.184 : wait

13:13:18.184 : wait

13:13:19.198 : wait

13:13:20.198 : wait

13:13:21.200 : wait

13:13:22.190 : wait

13:13:23.190 : wait

13:13:24.190 : wait

13:13:25.189 : wait

13:13:26.189 : wait

13:13:27.204 : wait

// Continuing to send additional commands will then cause busy:processing signal as expected if I start to frantically send too many commands.

Question is: why does firmware send OK or WAIT signal after G1 E.. command even though it has not physically executed those commands? It's as if a temperature related algorithm is locking up and not triggering Busy:processing signal until more commands are sent. I'll try to make a video since this is a bit hard to explain.

Pierre

Added video here:
https://www.youtube.com/watch?v=AszB6nnVheM

Pierre

still investigating.

Repetier

Ok, I see this is a hard one. All correct commands and firmware responsive but doing not what is expected.

"ok" is send when command is received, not executed. This reduces latency and increases througput. "wait" appears if buffer is empty for at least 1 second to indicate firmware it could do something.

When you start connection, what does it report as free memory. Should be at least 900 byte. If stack overflows such strange things can happen, otherwise I do not expect such unlogical behaviour. Looking back I see you have RADDS so ram should not really be an issue. The extruder could maybe be explained with overheating stepper driver for overcurrent/bad cooling. Especially a short pause indicates a pause to cool down and after that it continues and then it gets too hot for any more moves. Just a possible explaination for this, but it would not effect firmware starting to block busy at some point as far as I can say.

When moves do not take place any more you can still send M114/M199 to see if commands get executed as these send back some data. M114 is interesting as it shows current position so you see if the moves were executed (even if they do not move). That would mean something prevents physical moves - drivers not working, no main power, ...

Pierre

@Repetier Sorry to have wasted your time. I figured out the problem, it was a hardware problem that somehow affected the software...I found that while calibrating my stepper motor driver current setting, if the potentiometer is set bellow 30% of travel range, this issue happens even though all motors seem to operate correctly. I am still not sure how low current delivery causes issue with the rest of the firmware (maybe I'm using cheap knockoff DRV8825 ?) anyway thanks.

Repetier

Ok, would also not have guessed on a too low setting. Normally you get troubles for too high. Too low only causes not moving, but it did at least at the start. Glad you solved it.