Cleanup serial handling and logs

GMagician commented 5 years ago

Should address #84 and #85

probonopd commented 5 years ago

Hmm, https://transfer.sh/ is having issues at the moment, so the build artifacts of PRs don't get uploaded at the moment. Can you enable https://github.com/probonopd/uploadtool in your repo by setting GITHUB_TOKEN on https://travis-ci.com/GMagician/WirelessPrinting/settings as described in https://github.com/probonopd/uploadtool?

GMagician commented 5 years ago

that should be done

probonopd commented 5 years ago

This does not seem to work at all for me; getting

Trying 192.168.0.27...
Connected to 192.168.0.27.
Escape character is '^]'.
<#TIMEOUT#
<#TIMEOUT#
<#TIMEOUT#
<#TIMEOUT#
<#TIMEOUT#
<#TIMEOUT#

right from the beginning.

probonopd commented 5 years ago

log.txt.zip

Here is a full log from 1.x for comparison. Things to note:

Every line coming from the printer is displayed, prefixed by < Regardless of whether they could be interpreted or not
Every line sent to the printer is displayed, prefixed by >
The temperatures which the printer sends during heating were parsed (but wrong; hence the generated json was wrong too)
We did not send anything to the printer before the printer responded with "ok"
There were no timeouts

GMagician commented 5 years ago

I'm talking about what prusa does when it is heating. When prusa MK2 is heating respond with T:nn E:n B:nn (without ok and without busy) in same situation marlin respond with usual M105 (T:nn/nn B:nn/nn) message (without ok but with busy)

That's why previous json was in errorr. With this PR we fix it

probonopd commented 5 years ago

For the "still alive" timer it should not matter whether we can parse a response from the printer or not. For the question whether we can send the next line to the printer all that matters if we got ok from the printer.

probonopd commented 5 years ago

Still getting

Trying 192.168.0.27...
Connected to 192.168.0.27.
Escape character is '^]'.
#TIMEOUT#
#TIMEOUT#
#TIMEOUT#
#TIMEOUT#
#TIMEOUT#

right from the beginning in c970472. Before it even attempts the baudrate detection.

GMagician commented 5 years ago

yes...that's is baud detection that never receive ok and never go on....I'll try a different approach

GMagician commented 5 years ago

try nr #1

probonopd commented 5 years ago

This fixes baudrate detection:

Trying 192.168.0.27...
Connected to 192.168.0.27.
Escape character is '^]'.
Connecting at 500000
>���115
Connecting at 250000
>���115
Connecting at 115200
>���115
<FIRMWARE_NAME:Marlin V1.0.2; Sprinter/grbl mashup for gen6 FIRMWARE_URL:https://github.com/prusa3d/Prusa-i3-Plus/ PROTOCOL_VERSION:1.0 MACHINE_TYPE:Prusa i3 MK2 EXTRUDER_COUNT:1 UUID:00000000-0000-0000-0000-000000000000
 #wait more#
<FIRMWARE_NAME:Marlin V1.0.2; Sprinter/grbl mashup for gen6 FIRMWARE_URL:https://github.com/prusa3d/Prusa-i3-Plus/ PROTOCOL_VERSION:1.0 MACHINE_TYPE:Prusa i3 MK2 EXTRUDER_COUNT:1 UUID:00000000-0000-0000-0000-000000000000
ok
 ##
Connected
>M117 192.168.0.27 SD
<ok
 ##
>M300 S500 P50
<ok
 ##
>M105
<ok T:29.0 /0.0 B:28.6 /0.0 T0:29.0 /0.0 @:0 B@:0
 ##
>M105
<ok T:29.0 /0.0 B:28.6 /0.0 T0:29.0 /0.0 @:0 B@:0
 ##

Now trying to print something.

probonopd commented 5 years ago

It is now not sending stuff to the printer before we get an OK, but the /api/printer does not get updated with the temperature values during heating. During the whole heating phase it shows:

{
  "state": {
    "text": "Printing",
    "flags": {
      "operational": true,
      "paused": false,
      "printing": true,
      "pausing": false,
      "cancelling": false,
      "sdReady": false,
      "error": false,
      "ready": true,
      "closedOrError": false
    }
  },
  "temperature": {
    "tool0": {
      "actual": 29.0,
      "target": 0.0,
      "offset": 0
    },
    "bed": {
      "actual": 28.6,
      "target": 0.0,
      "offset": 0
    }
  },
  "sd": {
    "ready": false
  }
}

Still getting #TIMEOUT# when the printer starts its autocalibration.

But printing works. Log attached.

log.txt.zip

probonopd commented 5 years ago

Why are there many lines like

T:158.23 E:0 B:39.0
T:160.15 E:0 B:39.2
T:162.44 E:0 B:39.4
T:164.49 E:0 B:39.7
T:166.51 E:0 B:40.0

without being prefixed by <? Everything coming from the printer should be printed to telnet, prefixed by a < as the first thing (before we even try to interpret it). This would make it much easier to read the logs and know what the printer is actually sending.

GMagician commented 5 years ago

without being prefixed by <? Everything coming from the printer should be printed to telnet, prefixed by a < as the first thing (before we even try to interpret it).

that is what it should do...

GMagician commented 5 years ago

I think your firmware works a quite differently by marlin.. have you ever seen a T:xxx/ yy message?

probonopd commented 5 years ago

Instead of

Add missing \n when message not complete

why not start processing a line only after \n has been received? In the 1.x branch I did:

https://github.com/probonopd/WirelessPrinting/blob/a1dbae89cd9782f1dd7dced60d97f24e029a350d/ESP8266WirelessPrintAsync/ESP8266WirelessPrintAsync.ino#L188-L192

So, after we have sent something to the printer, we wait until we get ok back. In the meantime, we wait until we see \n and only if we see it, we print the complete line and then try to parse the line.

This has proven to be very robust for me.

have you ever seen a T:xxx/ yy message?

See the log from the 1.x branch which I had posted in https://github.com/probonopd/WirelessPrinting/pull/87#issuecomment-468908626.

Lots of them during heating. And every line was correctly prefixed by <.

< T:102.42 E:0 B:32.9
68573, free heap RAM: 30328

< T:105.02 E:0 B:33.0
69575, free heap RAM: 30328

< T:107.56 E:0 B:33.3
70577, free heap RAM: 30328

< T:110.03 E:0 B:33.7
71580, free heap RAM: 30328

< T:112.57 E:0 B:33.7
72582, free heap RAM: 30328

GMagician commented 5 years ago

why not start processing a line only after \n has been received? In the 1.x branch I did:

Because this way I stop everything... I want to process telnet and send more than one command when serial buffer let me do this (like repetier already does)

GMagician commented 5 years ago

Now I think you only have some timeouts during print..right?

probonopd commented 5 years ago

send more than one command when serial buffer let me do this (like repetier already does)

Isn't this adding risk of bugs? What is the advantage of sending more than one line at a time?

probonopd commented 5 years ago

Trying 192.168.0.27...
Connected to 192.168.0.27.
Escape character is '^]'.
Connecting at 500000
>115
Connecting at 250000
>115
Connecting at 115200
>115
< #wait more#
<ok #acknowledged#
Connected
>M117 192.168.0.27 SD
<ok #acknowledged#
>M300 S500 P50
<ok #acknowledged#
>M105
<ok T:28.5 /0.0 B:28.2 /0.0 T0:28.5 /0.0 @:0 B@:0 #acknowledged#
>M105
<ok T:28.5 /0.0 B:28.2 /0.0 T0:28.5 /0.0 @:0 B@:0 #acknowledged#
>M105
<ok T:28.5 /0.0 B:28.2 /0.0 T0:28.5 /0.0 @:0 B@:0 #acknowledged#
>M105
<ok T:28.5 /0.0 B:28.2 /0.0 T0:28.5 /0.0 @:0 B@:0 #acknowledged#
>M105
<ok T:28.5 /0.0 B:28.2 /0.0 T0:28.5 /0.0 @:0 B@:0 #acknowledged#
>M105
<ok T:28.5 /0.0 B:28.2 /0.0 T0:28.5 /0.0 @:0 B@:0 #acknowledged#
>M105
<ok T:28.5 /0.0 B:28.2 /0.0 T0:28.5 /0.0 @:0 B@:0 #acknowledged#
>M105
<ok T:28.5 /0.0 B:28.2 /0.0 T0:28.5 /0.0 @:0 B@:0 #acknowledged#
>M105
<ok T:28.5 /0.0 B:28.2 /0.0 T0:28.5 /0.0 @:0 B@:0 #acknowledged#
>M117 Receiving...
<ok #acknowledged#
>M117 Received
<ok #acknowledged#
>M300 S500 P50
<ok #acknowledged#
>M117 Printing...
<ok #acknowledged#
>M300 S500 P50
<ok #acknowledged#
>M105
<ok T:28.5 /0.0 B:28.2 /0.0 T0:28.5 /0.0 @:0 B@:0 #acknowledged#
>M201 X9000 Y9000 Z500 E10000 
<ok #acknowledged#
>M203 X500 Y500 Z12 E120 
<ok #acknowledged#
>M204 P2000 R1500 T2000 
<ok #acknowledged#
>M205 X10.00 Y10.00 Z0.20 E2.50 
<ok #acknowledged#
>M205 S0 T0 
<ok #acknowledged#
>M107
<ok #acknowledged#
>M115 U3.1.0 
<ok #acknowledged#
>M83  
<ok #acknowledged#
>M204 S2000 T1500 
<ok #acknowledged#
>M104 S215 
<ok #acknowledged#
>M140 S60 
<ok #acknowledged#
>M190 S60 
<T:28.50 E:0 B:28.6 #autotemp#
<T:28.50 E:0 B:28.6 #autotemp#
<T:29.00 E:0 B:28.6 #autotemp#
(...)

/api/printer is showing the correct values during heating :+1:

When heating done and bed calibration starts:

<T:212.50 E:0 B:59.7 #autotemp#
<T:212.50 E:0 B:59.7 #autotemp#
<T:212.97 E:0 B:60.0 #autotemp#
<ok #acknowledged#
>M109 S215 
<T:213.5 E:0 W:? #autotemp#
<T:214.6 E:0 W:2 #autotemp#
<T:215.8 E:0 W:1 #autotemp#
<T:216.7 E:0 W:0 #autotemp#
<ok #acknowledged#
>G28 W 
#TIMEOUT#
#TIMEOUT#
#TIMEOUT#
#TIMEOUT#
#TIMEOUT#
<ok #acknowledged#
>G80 
#TIMEOUT#
#TIMEOUT#
#TIMEOUT#

But the print starts.

log.txt.zip

probonopd commented 5 years ago

What do these

#TIMEOUT#
#TIMEOUT#
#TIMEOUT#
#TIMEOUT#
#TIMEOUT#

messages actually mean, other than the fact that the printer sent nothing in the last 2.5 seconds?

probonopd commented 5 years ago

So this solves #72, #84 (with the addition of #tags#), and #85 for me. :+1: Ready for merge?

GMagician commented 5 years ago

messages actually mean, other than the fact that the printer sent nothing in the last 2.5 seconds?

yes.. prusa is not answering....Marlin say busy. Marli is more friendly from this point of view...

Not merge now..

GMagician commented 5 years ago

1) I'm wondering... #acknowledge# is too much for me what do you think? 2) on wait more it should print last received line but it doesnt...I need to fix

probonopd commented 5 years ago

Let's not make this too Marlin specific.

probonopd commented 5 years ago

yes.. prusa is not answering....Marlin say busy. Marli is more friendly from this point of view...

If #TIMEOUT# does not do anything then why do we need it at all?

probonopd commented 5 years ago

I'm wondering... #acknowledged# is too much for me what do you think?

It depends on what you mean by #acknowledged#. The fact that we have recognized that we got ok back? Then let's call it #ok#, maybe.

GMagician commented 5 years ago

Then let's call it #ok#, maybe.

it's an ok message got...but you get ok in frame and #ok# at end... why simply not say anything but the response

probonopd commented 5 years ago

why simply not say anything but the response

Saying the response on telnet means "we have received some random output from the printer". It does not necessarily mean that we have understood the printer having said "ok". So I am for #ok#.

GMagician commented 5 years ago

  server.on("/api/version", HTTP_GET, [](AsyncWebServerRequest * request) {
    // http://docs.octoprint.org/en/master/api/version.html
    request->send(200, "application/json", "{\r\n"
                                           "  \"api\": \"" API_VERSION "\",\r\n"
                                           "  \"server\": \"" VERSION "\"\r\n"
                                           "}");  });

does it still should report VERSION or SKETCH_VERSION?

probonopd commented 5 years ago

Also, I would put all #tags# on separate lines, below the line starting with > to make clear that this is not part of what the printer has sent.

probonopd commented 5 years ago

does it still should report VERSION or SKETCH_VERSION?

It reports

{
  "api": "0.1",
  "server": "1.3.10"
}

GMagician commented 5 years ago

I used # just to say that... if you dont enclose your response between something known you dont know if trailing spaces or not

probonopd commented 5 years ago

OK, I see

GMagician commented 5 years ago

Not sure if substring(oldLineStartPos, newLineStartPos) or substring(oldLineStartPos, newLineStartPos-1), please send another log when installed

probonopd commented 5 years ago

Are you still doing all this without access to a real printer? Amazing!

GMagician commented 5 years ago

Are you still doing all this without access to a real printer? Amazing!

sigh yes...my usb plug doesn't arrive. I think it as been lost between path

probonopd commented 5 years ago

Not good:

>M107
<#ok#
>M115 U3.1.0 
<#ok#
>M83  
<#ok#
>M204 S2000 T1500 
<#ok#
>M104 S215 
<#ok#
>M140 S60 
<#ok#
>M190 S60 
<#autotemp#
<#autotemp#
<#autotemp#
<#autotemp#
<#autotemp#

probonopd commented 5 years ago

usb plug

You mean a SD shield for the WeMos D1 Mini? This system is not using USB at all... besides the USB integrated into the WeMos D1 Mini for initially flashing the sketch.

GMagician commented 5 years ago

I use mega that needs 5V signals but mini has 3.3. I ordered a usb to usb micro converter to let me able to connect both without soldering

probonopd commented 5 years ago

Not exactly sure what you are trying to do but my printers deliver 5V as the input to the D1 Mini. The D1 Mini contains a voltage regulator that converts it down to the 3.3V needed by the ESP8266.

GMagician commented 5 years ago

I want to connect mini to mega usb. Mega has a Type C connector (I think it's its name) and mini has a micro usb connector. I have a standard cable to connect PC to mega but PC has standard usb, so I need a converter to micro usb

GMagician commented 5 years ago

Please another log after installation...

probonopd commented 5 years ago

Looking good to me now :+1: log.txt.zip

GMagician commented 5 years ago

what is needed for G80? it seems a long operation... with no feedback...

GMagician commented 5 years ago

<T:212.6 E:0 W:?#autotemp#

that's wrong...it should not be recognized as autotemp....what is W:?

probonopd commented 5 years ago

Bed calibration

https://youtu.be/JqH41K2vq0g?t=927 at 15:27

probonopd commented 5 years ago

what is W:?

Good question. Searching... (but again, we should not care too much about particular firmware specialties)

GMagician commented 5 years ago

Bed calibration

ok I know...but no busy nor other message during it...

GMagician commented 5 years ago

I think you can merge it

probonopd commented 5 years ago

No clue what W: means.

probonopd / WirelessPrinting

Cleanup serial handling and logs #87