Duet 3 mini 5+ random "pause" while printing

chrishamm

@krohm-koala Thanks, can you provide your G-code/STL as well? I'll try to reproduce it on my setup then. Your latest diagnostics report shows a very high time for the slowest loop, which should not be there, and a couple of underruns.

Is there any chance you have high CPU/IO load on the SBC or persistent logging with log level debug for DuetControlServer?

Krohm Koala

@chrishamm Sure, here's both
STL : porte cure dents.stl
GCODE : https://drive.google.com/file/d/15_oE3-WkcI9CXi_3WlEfSSdbUpI9Or7g/view?usp=sharing

I don't think i can have high load on sbc as it's just running duet, but if there's a way to check, i'll do it.
For persistent logging, how do you check it ?

chrishamm

@krohm-koala Thanks, I'll give it a try tomorrow. You can run this in a Linux console or via SSH to check the configured log level, it should be set to info:

cat /opt/dsf/conf/config.json | grep LogLevel

I'll let you know if I manage to reproduce your problem.

Krohm Koala

@chrishamm Here's what it gives me


{
  "PluginSupport": true,
  "RootPluginSupport": false,
  "PluginsFilename": "/opt/dsf/conf/plugins.txt",
  "LogLevel": "info",
  "SocketDirectory": "/var/run/dsf",
  "SocketFile": "dcs.sock",
  "Backlog": 4,
  "SocketPollInterval": 2000,
  "BaseDirectory": "/opt/dsf/sd",
  "PluginDirectory": "/opt/dsf/plugins",
  "NoTerminateOnReset": false,
  "HostUpdateInterval": 4000,
  "MaxMessageAge": 60,
  "SpiDevice": "/dev/spidev0.0",
  "SpiBufferSize": 8192,
  "SpiTransferMode": 0,
  "SpiFrequency": 8000000,
  "SpiConnectTimeout": 500,
  "SpiTransferTimeout": 500,
  "SpiConnectionTimeout": 4000,
  "MaxSpiRetries": 3,
  "GpioChipDevice": "/dev/gpiochip0",
  "TransferReadyPin": 25,
  "BufferedPrintCodes": 32,
  "BufferedMacroCodes": 16,
  "MaxBufferSpacePerChannel": 1536,
  "MaxCodeBufferSize": 256,
  "MaxMessageLength": 4096,
  "FirmwareComments": [
    "printing object",
    "MESH",
    "process",
    "stop printing object",
    "layer",
    "LAYER",
    "BEGIN_LAYER_OBJECT z=",
    "HEIGHT",
    "PRINTING",
    "REMAINING_TIME"
  ],
  "ModelUpdateInterval": 250,
  "MaxMachineModelLockTime": -1,
  "FileBufferSize": 8192,
  "FileInfoReadLimitHeader": 12288,
  "FileInfoReadLimitFooter": 262144,
  "MaxLayerHeight": 0.9,
  "LayerHeightFilters": [
    {
      "Pattern": "^\\s*layer_height\\D+(?<mm>(\\d+\\.?\\d*))",
      "Options": 17
    },
    {
      "Pattern": "Layer height\\D+(?<mm>(\\d+\\.?\\d*))",
      "Options": 17
    },
    {
      "Pattern": "layerHeight\\D+(?<mm>(\\d+\\.?\\d*))",
      "Options": 17
    },
    {
      "Pattern": "layer_thickness_mm\\D+(?<mm>(\\d+\\.?\\d*))",
      "Options": 17
    },
    {
      "Pattern": "layerThickness\\D+(?<mm>(\\d+\\.?\\d*))",
      "Options": 17
    },
    {
      "Pattern": "sliceHeight\\D+(?<mm>(\\d+\\.?\\d*))",
      "Options": 17
    }
  ],
  "FilamentFilters": [
    {
      "Pattern": "filament used\\D+(((?<mm>\\d+\\.?\\d*)\\s*mm)(\\D+)?)+",
      "Options": 17
    },
    {
      "Pattern": "filament used\\D+(((?<m>\\d+\\.?\\d*)m([^m]|$))(\\D+)?)+",
      "Options": 17
    },
    {
      "Pattern": "filament length\\D+(((?<mm>\\d+\\.?\\d*)\\s*mm)(\\D+)?)+",
      "Options": 17
    },
    {
      "Pattern": "filament used \\[mm\\]\\D+((?<mm>\\d+\\.?\\d*)(\\D+)?)+",
      "Options": 17
    },
    {
      "Pattern": "material\\#(?<index>\\d+)\\D+(?<mm>\\d+\\.?\\d*)",
      "Options": 17
    },
    {
      "Pattern": "Ext\\s*\\#\\d+\\D+(?<mm>\\d+\\.?\\d*)",
      "Options": 17
    },
    {
      "Pattern": "Filament used per extruder:\\r\\n;\\s*(?<name>.+)\\s+=\\s*(?<mm>[0-9.]+)",
      "Options": 17
    },
    {
      "Pattern": "filament used extruder (?<index>\\d+) \\(mm\\) = (?<mm>\\d+\\.?\\d*)",
      "Options": 17
    }
  ],
  "GeneratedByFilters": [
    {
      "Pattern": "generated by\\s+(.+)",
      "Options": 17
    },
    {
      "Pattern": "Sliced by\\s+(.+)",
      "Options": 17
    },
    {
      "Pattern": "(KISSlicer.*)",
      "Options": 17
    },
    {
      "Pattern": "Sliced at:\\s*(.+)",
      "Options": 17
    },
    {
      "Pattern": "Generated with\\s*(.+)",
      "Options": 17
    }
  ],
  "PrintTimeFilters": [
    {
      "Pattern": "estimated printing time .*= ((?<h>(\\d+))h\\s*)?((?<m>(\\d+))m\\s*)?((?<s>(\\d+))s)?",
      "Options": 17
    },
    {
      "Pattern": "TIME:(?<s>(\\d+\\.?\\d*))",
      "Options": 17
    },
    {
      "Pattern": "Build Time:\\s+((?<h>(\\d+\\.?\\d*)) hour(s)?\\s*)?((?<m>(\\d+\\.?\\d*)) minute(s)?\\s*)?((?<s>(\\d+\\.?\\d*)) second(s)?)?",
      "Options": 17
    },
    {
      "Pattern": "print time:\\s+(?<s>(\\d+\\.?\\d*))(s)?",
      "Options": 17
    },
    {
      "Pattern": "Total estimated \\(pre-cool\\) minutes: ((?<m>\\d+\\.?\\d*))",
      "Options": 17
    },
    {
      "Pattern": "total print time \\(s\\) = (?<s>(\\d+\\.?\\d*))",
      "Options": 17
    }
  ],
  "SimulatedTimeFilters": [
    {
      "Pattern": "Simulated print time\\D+(?<s>(\\d+\\.?\\d*))",
      "Options": 17
    }
  ]

chrishamm

@krohm-koala Thanks. I suspect there is something wrong with your SD card, please exchange it and check if the problem persists. In the past damaged SD cards could lead to the same symptoms you are seeing.

I've been printing your G-code and I haven't been able to spot any sudden pauses yet:

=== MainDDARing ===
Scheduled moves 24765, completed 24725, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 1], CDDA state 3

If you get a new one, please consider an A1- or A2-rated microSD card for the Pi - they're generally faster and have more IOPS than the standard cards.

Krohm Koala

@chrishamm Thank's i'll consider that, it would be weird if the SD card is already damaged as it's the original SD card from the duet 3 mini (2/3 months old and not that much use), i'll check if i find good sd card

jay_s_uk

@chrishamm I am also seeing random pauses on 3.4b5 in SBC mode with a mini5+.
Lots of random blobs all over prints.
Wasn't an issue with 3.4b4.
Anything I can provide?

Krohm Koala

@jay_s_uk Thanks, i hope both of us can have everything to help resolve that problem
@chrishamm so i've just change the SD card for an A2 U3 V30, i still have the problem with that SD, i've clone the other SD, maybe the problem ? i think i'll try a clean install if i manage to backup all the config files of the SBC, i haven't found where they are

chrishamm

@krohm-koala That's pretty strange, I haven't been able to reproduce it on my machines yet with your G-code file:

Apparently the print settings don't match my machine but there are no blobs or indications for random pauses visible AFAICS. I'll be happy to address this problem as soon as I figure out what exactly is going on.

Krohm Koala

@chrishamm Clean install done, with the good sd card, problem still here, so i give you my config files, maybe it could be usefull @jay_s_uk can you upload yours too so we can compare if there's "weird" similarities that can cause the bug ?
https://drive.google.com/file/d/1AaEKxDz_qTaEhUuqW9kx5FhKrRhhtVNA/view?usp=sharing

Krohm Koala

@chrishamm this is a weird problem, i have a small print that i've done recently where there's 3 circular tower of small diameter and with this the problem is quite frequent. at least, we have eliminate the fact that it can be a sd problem. If you need me to run some other tests, don't hesitate

dc42

@krohm-koala we have just released software 3.4.0beta6. I know that @chrishamm has improved the SBC to Duet interface in this release, so I suggest you upgrade to see if the problem has been resolved.

Krohm Koala

@dc42 thanks, upgrade is done, i launch a print right now

Krohm Koala

@dc42 Problem still here

chrishamm

@krohm-koala Sorry to hear that, I hope I'll manage to reproduce the culprit next week. @jay_s_uk may provide some further debug details, too, so I can eventually figure out what's going on.

Krohm Koala

@chrishamm since i've upgrade to 3.4.0b6 i can't upload with prusa slicer, it looks like it have upload on the slicer but print doesn't start and i can't find it on the duet

chrishamm

@krohm-koala I'm happy to report we found the reason for this problem and it will be fixed in the next version. To work-around this problem for now, you can set the HostUpdateInterval to -1 in /opt/dsf/conf/config.json but be aware that this will prevent the network and storage devices in the object model from being updated.

PS: It turns out PrusaSlicer sends G-code requests as application/x-www-form-urlencoded whereas it should be text/plain. I've got a work-around ready for this, too.

Krohm Koala

@chrishamm Thanks a lot, it's smooth now what's the work-around for prusa slicer please ? if it's an easy one