DSF 1.3.1 (unstable) released

gruen

nothing works, power cycle doesn't help:

Duet Control Server v1.3.1
Written by Christian Hammacher for Duet3D
Licensed under the terms of the GNU Public License Version 3

[info] Settings loaded
[info] Environment initialized
[warn] Bad data checksum (expected 0xa23d, got 0x5ef8)
[warn] Bad data checksum (expected 0xa23d, got 0x5ef8)
[warn] Bad data checksum (expected 0xa23d, got 0x5ef8)
[warn] Restarting transfer because the number of maximum retries has been exceeded
[error] Duet is not available

gtj0

@gruen I have to ask... was it working before and with which version?

Can you paste the contents of /opt/dsf/conf/config.json.
Can you change the "LogLevel" entry to "debug" and restart the DCS and paste the output.

gruen

@gtj0

here is the config.json

{
  "LogLevel": "info",
  "SocketDirectory": "/var/run/dsf",
  "SocketFile": "dcs.sock",
  "Backlog": 4,
  "SocketPollInterval": 2000,
  "BaseDirectory": "/opt/dsf/sd",
  "HostUpdateInterval": 4000,
  "MaxMessageAge": 60,
  "SpiDevice": "/dev/spidev0.0",
  "SpiFrequency": 8000000,
  "SpiTransferTimeout": 500,
  "MaxSpiRetries": 3,
  "SpiPollDelay": 25,
  "SpiPollDelaySimulating": 5,
  "GpioChipDevice": "/dev/gpiochip0",
  "TransferReadyPin": 25,
  "BufferedPrintCodes": 32,
  "BufferedMacroCodes": 16,
  "MaxBufferSpacePerChannel": 1536,
  "ModelUpdateInterval": 250,
  "MaxMachineModelLockTime": -1,
  "FileInfoReadBufferSize": 8192,
  "FileInfoReadLimitHeader": 12288,
  "FileInfoReadLimitFooter": 262144,
  "MaxLayerHeight": 0.9,
     
}

removed: "LayerHeightFilters"

-- Logs begin at Sat 2020-04-04 22:30:02 CEST, end at Sat 2020-04-04 22:30:59 CEST. --
Apr 04 22:30:05 Duet6 systemd[1]: Started Duet Control Server.
Apr 04 22:30:09 Duet6 DuetControlServer[335]: Duet Control Server v1.3.1
Apr 04 22:30:09 Duet6 DuetControlServer[335]: Written by Christian Hammacher for Duet3D
Apr 04 22:30:09 Duet6 DuetControlServer[335]: Licensed under the terms of the GNU Public License Version 3
Apr 04 22:30:12 Duet6 DuetControlServer[335]: [info] Settings loaded
Apr 04 22:30:12 Duet6 DuetControlServer[335]: [info] Environment initialized
Apr 04 22:30:12 Duet6 DuetControlServer[335]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:12 Duet6 DuetControlServer[335]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:12 Duet6 DuetControlServer[335]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:12 Duet6 DuetControlServer[335]: [warn] Restarting transfer because the number of maximum retries has been exceeded
Apr 04 22:30:12 Duet6 DuetControlServer[335]: [error] Duet is not available
Apr 04 22:30:12 Duet6 systemd[1]: duetcontrolserver.service: Succeeded.
Apr 04 22:30:17 Duet6 systemd[1]: duetcontrolserver.service: Service RestartSec=5s expired, scheduling restart.
Apr 04 22:30:17 Duet6 systemd[1]: duetcontrolserver.service: Scheduled restart job, restart counter is at 1.
Apr 04 22:30:17 Duet6 systemd[1]: Stopped Duet Control Server.
Apr 04 22:30:17 Duet6 systemd[1]: Started Duet Control Server.
Apr 04 22:30:18 Duet6 DuetControlServer[737]: Duet Control Server v1.3.1
Apr 04 22:30:18 Duet6 DuetControlServer[737]: Written by Christian Hammacher for Duet3D
Apr 04 22:30:18 Duet6 DuetControlServer[737]: Licensed under the terms of the GNU Public License Version 3
Apr 04 22:30:19 Duet6 DuetControlServer[737]: [info] Settings loaded
Apr 04 22:30:19 Duet6 DuetControlServer[737]: [info] Environment initialized
Apr 04 22:30:19 Duet6 DuetControlServer[737]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:19 Duet6 DuetControlServer[737]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:19 Duet6 DuetControlServer[737]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:19 Duet6 DuetControlServer[737]: [warn] Restarting transfer because the number of maximum retries has been exceeded
Apr 04 22:30:19 Duet6 DuetControlServer[737]: [error] Duet is not available
Apr 04 22:30:19 Duet6 systemd[1]: duetcontrolserver.service: Succeeded.
Apr 04 22:30:25 Duet6 systemd[1]: duetcontrolserver.service: Service RestartSec=5s expired, scheduling restart.
Apr 04 22:30:25 Duet6 systemd[1]: duetcontrolserver.service: Scheduled restart job, restart counter is at 2.
Apr 04 22:30:25 Duet6 systemd[1]: Stopped Duet Control Server.
Apr 04 22:30:25 Duet6 systemd[1]: Started Duet Control Server.
Apr 04 22:30:25 Duet6 DuetControlServer[1054]: Duet Control Server v1.3.1
Apr 04 22:30:25 Duet6 DuetControlServer[1054]: Written by Christian Hammacher for Duet3D
Apr 04 22:30:25 Duet6 DuetControlServer[1054]: Licensed under the terms of the GNU Public License Version 3
Apr 04 22:30:26 Duet6 DuetControlServer[1054]: [info] Settings loaded
Apr 04 22:30:27 Duet6 DuetControlServer[1054]: [info] Environment initialized
Apr 04 22:30:27 Duet6 DuetControlServer[1054]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:27 Duet6 DuetControlServer[1054]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:27 Duet6 DuetControlServer[1054]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:27 Duet6 DuetControlServer[1054]: [warn] Restarting transfer because the number of maximum retries has been exceeded
Apr 04 22:30:27 Duet6 DuetControlServer[1054]: [error] Duet is not available
Apr 04 22:30:27 Duet6 systemd[1]: duetcontrolserver.service: Succeeded.
Apr 04 22:30:32 Duet6 systemd[1]: duetcontrolserver.service: Service RestartSec=5s expired, scheduling restart.
Apr 04 22:30:32 Duet6 systemd[1]: duetcontrolserver.service: Scheduled restart job, restart counter is at 3.
Apr 04 22:30:32 Duet6 systemd[1]: Stopped Duet Control Server.
Apr 04 22:30:32 Duet6 systemd[1]: Started Duet Control Server.
Apr 04 22:30:32 Duet6 DuetControlServer[1227]: Duet Control Server v1.3.1
Apr 04 22:30:32 Duet6 DuetControlServer[1227]: Written by Christian Hammacher for Duet3D
Apr 04 22:30:32 Duet6 DuetControlServer[1227]: Licensed under the terms of the GNU Public License Version 3
Apr 04 22:30:34 Duet6 DuetControlServer[1227]: [info] Settings loaded
Apr 04 22:30:34 Duet6 DuetControlServer[1227]: [info] Environment initialized
Apr 04 22:30:34 Duet6 DuetControlServer[1227]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:34 Duet6 DuetControlServer[1227]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:34 Duet6 DuetControlServer[1227]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:34 Duet6 DuetControlServer[1227]: [warn] Restarting transfer because the number of maximum retries has been exceeded
Apr 04 22:30:34 Duet6 DuetControlServer[1227]: [error] Duet is not available
Apr 04 22:30:34 Duet6 systemd[1]: duetcontrolserver.service: Succeeded.
Apr 04 22:30:52 Duet6 systemd[1]: duetcontrolserver.service: Service RestartSec=5s expired, scheduling restart.
Apr 04 22:30:52 Duet6 systemd[1]: duetcontrolserver.service: Scheduled restart job, restart counter is at 4.
Apr 04 22:30:52 Duet6 systemd[1]: Stopped Duet Control Server.
Apr 04 22:30:52 Duet6 systemd[1]: Started Duet Control Server.
Apr 04 22:30:53 Duet6 DuetControlServer[1241]: Duet Control Server v1.3.1
Apr 04 22:30:53 Duet6 DuetControlServer[1241]: Written by Christian Hammacher for Duet3D
Apr 04 22:30:53 Duet6 DuetControlServer[1241]: Licensed under the terms of the GNU Public License Version 3
Apr 04 22:30:54 Duet6 DuetControlServer[1241]: [info] Settings loaded
Apr 04 22:30:55 Duet6 DuetControlServer[1241]: [info] Environment initialized
Apr 04 22:30:55 Duet6 DuetControlServer[1241]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:55 Duet6 DuetControlServer[1241]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:55 Duet6 DuetControlServer[1241]: [warn] Bad data checksum (expected 0x31c7, got 0xe55f)
Apr 04 22:30:55 Duet6 DuetControlServer[1241]: [warn] Restarting transfer because the number of maximum retries has been exceeded
Apr 04 22:30:55 Duet6 DuetControlServer[1241]: [error] Duet is not available
Apr 04 22:30:55 Duet6 systemd[1]: duetcontrolserver.service: Succeeded.

gruen

RC5 works for me, how can I downgrade?

wilriker

@gruen Have your tried reflashing the Duet? I've seen this before sometimes and strangely (coincidentally?) it only went away after flashing the firmware again.

tobias_munich

@chrishamm @dc42 thank you guys,

after updating via apt upgrade the system is running again.
a new test print is running.

Update: After 1h of printing DCS lost the connection again

gtj0

The default SpiFrequency in /opt/dsf/conf/config.json changed from 2000000 (2MHz) to 8000000 (8MHz) with the recent release. Try changing it back to 2000000 and see what happens. Experiment to see what the fastest speed you can reliably run at.

chrishamm

@tobias_munich Sorry to hear you are having problems. Can you check for error messages when DCS disconnected? Can you share the output of M122?

@gruen Please do what @gtj0 said.

gtj0

@chrishamm Do you want me to open github issues for the print time and model issues I mentioned above?

mikedahlgren

@chrishamm Shared elsewhere but here is the results of "sudo journalctl -u duetcontrolserver -en 100 --no-pager"

Apr 06 18:02:00 duet3 DuetControlServer[13291]: Duet Control Server v1.3.1
Apr 06 18:02:00 duet3 DuetControlServer[13291]: Written by Christian Hammacher for Duet3D
Apr 06 18:02:00 duet3 DuetControlServer[13291]: Licensed under the terms of the GNU Public License Version 3
Apr 06 18:02:01 duet3 DuetControlServer[13291]: [info] Settings loaded
Apr 06 18:02:01 duet3 DuetControlServer[13291]: [info] Environment initialized
Apr 06 18:02:01 duet3 DuetControlServer[13291]: [warn] RepRapFirmware got a bad header checksum
Apr 06 18:02:01 duet3 DuetControlServer[13291]: [info] Connection to Duet established
Apr 06 18:02:01 duet3 DuetControlServer[13291]: [info] IPC socket created at /var/run/dsf/dcs.sock
Apr 06 18:02:01 duet3 DuetControlServer[13291]: [info] Aux: Running code from firmware 'M20 S2 P0:/macros' on channel Aux
Apr 06 18:02:02 duet3 DuetControlServer[13291]: [fatal] Abnormal program termination
Apr 06 18:02:02 duet3 DuetControlServer[13291]: [fatal] Update task faulted
Apr 06 18:02:02 duet3 DuetControlServer[13291]: System.ArgumentException: Requested value 'fault' was not found.
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at System.Enum.TryParseByName(RuntimeType enumType, String originalValueString, ReadOnlySpan1 value, Boolean ignoreCase, Boolean throwOnFailure, UInt64& result) Apr 06 18:02:02 duet3 DuetControlServer[13291]: at System.Enum.TryParseInt32Enum(RuntimeType enumType, String originalValueString, ReadOnlySpan1 value, Int32 minInclusive, Int32 maxInclusive, Boolean ignoreCase, Boolean throwOnFailure, TypeCode type, Int32& result)
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at System.Enum.TryParse(Type enumType, String value, Boolean ignoreCase, Boolean throwOnFailure, Object& result)
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at System.Enum.Parse(Type enumType, String value, Boolean ignoreCase)
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at DuetAPI.Utility.JsonLowerCaseStringEnumConverter.JsonLowerCaseStringEnumConverterInner1.Read(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options) in /home/christian/duet/DuetSoftwareFramework/src/DuetAPI/Utility/JsonLowerCaseStringEnumConverter.cs:line 62 Apr 06 18:02:02 duet3 DuetControlServer[13291]: at System.Text.Json.JsonPropertyInfoNullable2.OnRead(ReadStack& state, Utf8JsonReader& reader)
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at System.Text.Json.JsonPropertyInfo.Read(JsonTokenType tokenType, ReadStack& state, Utf8JsonReader& reader)
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at System.Text.Json.JsonSerializer.ReadCore(JsonSerializerOptions options, Utf8JsonReader& reader, ReadStack& readStack)
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at System.Text.Json.JsonSerializer.ReadCore(Type returnType, JsonSerializerOptions options, Utf8JsonReader& reader)
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at System.Text.Json.JsonSerializer.Deserialize(String json, Type returnType, JsonSerializerOptions options)
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at DuetAPI.Machine.ModelObject.UpdateFromJson(JsonElement jsonElement, Boolean ignoreSbcProperties) in /home/christian/duet/DuetSoftwareFramework/src/DuetAPI/Machine/Base/ModelObject.cs:line 282
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at DuetAPI.Machine.ModelCollectionHelper.UpdateFromJson(IList list, Type itemType, JsonElement jsonElement, Boolean ignoreSbcProperties) in /home/christian/duet/DuetSoftwareFramework/src/DuetAPI/Machine/Base/ModelCollection.cs:line 227
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at DuetAPI.Machine.ModelObject.UpdateFromJson(JsonElement jsonElement, Boolean ignoreSbcProperties) in /home/christian/duet/DuetSoftwareFramework/src/DuetAPI/Machine/Base/ModelObject.cs:line 264
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at DuetAPI.Machine.ModelObject.UpdateFromJson(JsonElement jsonElement, Boolean ignoreSbcProperties) in /home/christian/duet/DuetSoftwareFramework/src/DuetAPI/Machine/Base/ModelObject.cs:line 248
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at DuetAPI.Machine.MachineModel.UpdateFromFirmwareModel(String key, JsonElement jsonElement) in /home/christian/duet/DuetSoftwareFramework/src/DuetAPI/Machine/MachineModel.cs:line 134
Apr 06 18:02:02 duet3 DuetControlServer[13291]: at DuetControlServer.Model.Updater.Run() in /home/christian/duet/DuetSoftwareFramework/src/DuetControlServer/Model/Updater.cs:line 140
Apr 06 18:02:02 duet3 DuetControlServer[13291]: [fatal] Update task faulted

chrishamm

@mikedahlgren Thanks, I've got a fix ready and will release it later this week. Until then the only way to get DCS back working is to reset the Duet 3 using the push button and to wait a moment.

@gtj0 You're right about the printing time and Simplify3D, I'm looking into it. As for the diffs it's all looking good and appears like what DWC would expect, but it's odd that you are seeing the tool temperatures being transmitted over and over again even though nothing has changed. I just tried to reproduce it and I could do this, so I'll fix it as well. Thanks for letting me know!

PS: It's actually Simplify3D that tried to be smart, they're now printing hour instead of hours so my regex doesn't work any more. I'll update it.

mikedahlgren

@chrishamm Thanks you!

gtj0

@chrishamm Can you also comment on the other model oddities like the "fans" object showing in an update but with all empty values. It's kinda confusing because some of the things the RRF model considers "live" show up on every update but others which are also "live" don't.

chrishamm

@gtj0 The whole purpose of the patch-mode subscription is to reflect changes. So it is intended to transmit empty objects if none of the properties of a list item have changed, else you would not be able to tell when the size of a list has changed (e.g. because you decided to delete a tool or something else). Well, in your case you shouldn't be seeing any empty or null items either and it's related to the bug I'm about to fix, so don't worry about it.

PS: Here the new regex for S3D that should work, feel free to give it a try:

Build time: ((?<h>\d+) hour(s)?\s*)?((?<m>\d+) minute(s)?\s*)?((?<s>(\d+) second(s)?))?

gtj0

@chrishamm Cool! I'll give the regex a try.

gtj0

@gtj0 said in DSF 1.3.1 (unstable) released:

@chrishamm Cool! I'll give the regex a try.

AHHHHH. The fact that all those <> etc characters need to be escaped in config.json is really annoying. I'll wait for you to update the default file in the repo.

gtj0

(Possibly) New issue with messages.
If I execute G32 directly, I get the Leadscrew adjustments made: 0.005 0.040 -0.000, points used 3, (mean, deviation) before (0.014, 0.017) after (0.000, 0.000) message back. If I execute G32 from a macro, I don't.

For the good case, I see 2 messages in the DCS log...

DuetControlServer[4316]: [debug] Completed G30 P2 X230 Y-222 Z-99999 S3 ; probe near a leadscrew and calibrate 3 motors => Leadscrew adjustments made: 0.005 0.040 -0.000, points used 3, (mean, deviation) before (0.014, 0.017) after (0.000, 0.000)
DuetControlServer[4316]: Leadscrew adjustments made: 0.005 0.040 -0.000, points used 3, (mean, deviation) before (0.014, 0.017) after (0.000, 0.000)

When run from a macro I only see...

DuetControlServer[4316]: [debug] Completed G30 P2 X230 Y-222 Z-99999 S3 ; probe near a leadscrew and calibrate 3 motors => Leadscrew adjustments made: 0.005 0.040 -0.000, points used 3, (mean, deviation) before (0.014, 0.017) after (0.000, 0.000)

gtj0

@dc42 @chrishamm Not sure of this is a DSF or RRF issue but the model reported by the DSF always has the extrusion factor at "1" and M221 doesn't seem to affect it. Not sure if the M221 isn't working or if the value reported in the model is incorrect.

dc42

@gtj0 said in DSF 1.3.1 (unstable) released:

@dc42 @chrishamm Not sure of this is a DSF or RRF issue but the model reported by the DSF always has the extrusion factor at "1" and M221 doesn't seem to affect it. Not sure if the M221 isn't working or if the value reported in the model is incorrect.

It works for me, in standalone mode (read command/response pairs from bottom to top as usual):

07/04/2020, 07:59:43 	m563 p0
Tool 0 - drives: 0; heaters (active/standby temps): 1 (0.0/0.0); xmap: X; ymap: Y; fans: 0; status: selected
07/04/2020, 07:59:22 	m409 k"move.extruders[].factor"
{"key":"move.extruders[].factor","flags":"","result":[1.2,1.0]}
07/04/2020, 07:59:17 	m221
Extrusion factor(s) for current tool: 120.0%
07/04/2020, 07:59:14 	m221 s120
07/04/2020, 07:59:07 	t0
07/04/2020, 07:58:59 	m221 s120
Error: M221: No tool selected
07/04/2020, 07:58:42 	m409 k"move.extruders[].factor"
{"key":"move.extruders[].factor","flags":"","result":[1.0,1.0]}

gtj0

@dc42 Yeah you're right. I keep forgetting I can do M409 to get the values from RRF.

@chrishamm It does appear to be a DSF model update issue. M409 reports the correct value but the DSF model does not.