Stephan3 / dwc2-for-klipper

A translator between DWC2 and Klipper
GNU General Public License v3.0
160 stars 38 forks source link

can't send G commands after FIRMWARE_RESTART #14

Closed rafaljot closed 5 years ago

rafaljot commented 5 years ago

after FIRMWARE_RESTART I can't send G commands to printer from dwc2 web interface. I see nothing special in log, LCD works,

I tried to debug and I think the problem is with

self.reactor.register_callback(self.gcode_reactor_callback)

because this callback never triggers after FIRMWARE_RESTART

Do you have the same issue ?

Stephan3 commented 5 years ago

just tested it her on my local machine and it works. So dont know what to say. Is your firmware_restart successfull in that case? The reactor callback works in any situation.

rafaljot commented 5 years ago

I put logging before this line and inside callback. And yes, the rest of Klipper seems to be all right after restart. So I will continue the investigation.

rafaljot commented 5 years ago

I think the problem in reactor.py here:

class ReactorCallback:
def __init__(self, reactor, callback, waketime):
        self.reactor = reactor
        self.timer = reactor.register_timer(self.invoke, waketime)
        self.callback = callback
    def invoke(self, eventtime):
        self.reactor.unregister_timer(self.timer)
        self.callback(eventtime)
        return self.reactor.NEVER

self.callback = callback is after register_timer. In fast multicores it can fire invoke before setting callback

Stephan3 commented 5 years ago

Hmm i tried that meanwhile on my i7 6700. There it works. You can try to debug to put inside the callback

logging.error(“this is callback”)

So you can know that it was called. As I am not able to reproduce this, it’s hard to help here

rafaljot commented 5 years ago

I did it. It is not called after restart any more.

I have two environments

  1. PyCharm on Ubuntu (vmWare) + trigorilla board
  2. BananaPi Zero (4cores) + EinsyRambo
rafaljot commented 5 years ago

unfortunately in step-by-step debuggingi it works.

Stephan3 commented 5 years ago

hm hm dafuq why does it work for me :/ Just tried a arch vm and Debian9 live in vm. Both did with Arduino Mega and smoothie.

That’s what’s here.

Do you get a reply (with logging)in reactor.py when this error occurred? May be I have an idea

rafaljot commented 5 years ago

I added some extra loggins and traps: web_dwc2_and_reactor.zip

First restart: INFO:root:DWC2:31850.92 - 127.0.0.1 - GET - /rr_gcode?gcode=RESTART ERROR:root:#1 rr_gcode ERROR:root:#5 ReactorCallback ERROR:root:#7 register_timer ERROR:root:#6 _check_timers ERROR:root:#6 ReactorCallback:invoke ERROR:root:#8 unregister_timer ERROR:root:#3 gcode_reactor_callback ERROR:root:#4 gcode_reactor_callback

Second Restart: INFO:root:DWC2:31939.93 - 127.0.0.1 - GET - /rr_gcode?gcode=RESTART ERROR:root:#1 rr_gcode ERROR:root:#5 ReactorCallback ERROR:root:#7 register_timer INFO:root:Stats 10148.8: gcodein=0 mcu: mcu_awake=0.006 mcu_task_avg=0.000078 mcu_task_stddev=0.000069 bytes_write=1828 bytes_read=8984 bytes_retransmit=0 bytes_invalid=4 send_seq=200 receive_seq=200 retransmit_seq=0 srtt=0.003 rttvar=0.001 rto=0.025 ready_bytes=0 stalled_bytes=0 freq=16003009 print_time=1.632 buffer_time=0.000 print_stall=0 extruder: target=0 temp=1208.0 pwm=0.000

rafaljot commented 5 years ago

It looks like I have two instances of Reactor and two web_dwc2 after RESTART So rr_gcode registers callbacks into old one

Stephan3 commented 5 years ago

Okay looks promising. can you try to add theese:

        self.printer = config.get_printer()
        self.reactor = self.printer.get_reactor(

in line 81 in function handle ready for me? Then try to break it

rafaljot commented 5 years ago

nothing new. How to reproduce issue:

  1. send command m117 #1 ;you will see #1 on LCD - if you have LCD
  2. send RESTART ; #1 changes for "Ready"
  3. send command m117 #2 ;you will see #2 on LCD - if you have LCD
  4. send RESTART ; #2 changes for "Ready" etc.

step 1 and 2 always works.

3,4. etc sometime works sometimes not.
For sure I see two reactor.self ids in the same time

you can examine it by adding:

import threading logging.error('#threading.active_count:'+ str(threading.active_count()))

it increases by 1 with each RESTART

rafaljot commented 5 years ago

I changed

tornado.ioloop.IOLoop.instance().start()

to:

self.ioloop = tornado.ioloop.IOLoop.current()
self.ioloop.start()

and added:

self.ioloop.stop()

before:

self.http_server.stop()

It works :)

Stephan3 commented 5 years ago

As i adopted this, i am going to close this. Thanks