Moddable-OpenSource / moddable

Tools for developers to create truly open IoT products using standard JavaScript on low cost microcontrollers.
http://www.moddable.com
1.34k stars 237 forks source link

address already in use #1063

Closed bartbutenaers closed 1 year ago

bartbutenaers commented 1 year ago

Build environment: Linux on Raspberry Target device: WT32-ETH01

Description

@ralphwetzel was investigating another issue for me, i.e. that I get all the time this error:

Error: listen EADDRINUSE: address already in use :::5002

When a new xsbug-log instance is spawned, the previous running instance should be terminated first. Ralph found out that this termination is currently not done by the xsbug-log script.

I had a second issue, which I think is quite related to this. I started accidentally an instance of xsbug (via Ralph's sidebar in Node-RED). Then I realized that I should have started in fact xsbug-log, since I am working on a headless Pi. But both xsbug and xsbug-log are listening to the same port (i.e. 5004 in Node-RED). So I "think" that xsbug should also terminate running xsbug-log instances before starting, and the other way around. But I am not an expert in this, so don't know if that makes sense at all in other use cases...

Steps to Reproduce

  1. Start xsbug-log so it starts listening.
  2. Start xsbug-log again
  3. Now you should see the above error, because the previous instance of xsbug-log is still running
phoddie commented 1 year ago

When a new xsbug-log instance is spawned, the previous running instance should be terminated first

I'm not sure about that. The usual workflow when using xsbug-log is to launch it in a console, leave it running while in use, and press ^C to exit when done.

What you are doing is like launching xsbug twice. The second instance will fail to bind to the port used by the first.

Perhaps there's a misunderstanding about workflow here. Why do you have two instances running?

bartbutenaers commented 1 year ago

Hi @phoddie,

Yes you are absolutely correct that I don't want two instances running.

This is how I use it in Node-RED via Ralph's sidebar:

  1. At some moment I start xsbug (or xsbug-log), so it starts listening to port 5004.
  2. Then doing some other stuff, so my log in the xterm of the sidebar will now show other info. Or I continue in another browser session, with an empty xterm terminal prompt in the sidebar. So in both cases I don't see the "listening" anymore in the log. Which means I have no visual indication at all anymore about what is all running in the background.
  3. Some time later I start the xsbug target again (or I click "reconnect to xsbug") via the sidebar, because I don't see any info anymore showing up in my sidebar xterm. However I don't realize at this moment that the problem is not xsbug listening anymore, but instead it is my wt32-eth01 that is not serial connected anymore. Yep that wt32-eth01 requires quite some manual work with power on/off an (dis)connecting the programming pin over and over again...
  4. Due to my faulthy action, I suddenly I get that error because the previous xsbug instance is still listening to that port. But it makes no sense at all to me at this point, because it looked to me that we were not listening...

I have no visual indication in my flow editor that xsbug (or xsbug-log) is listening. And due to all manual interactions required on my wt32-eth01, it is all very confusing what I am doing wrong. Therefore Ralph suggested to open this issue, to automatically stop the previous instance when a new instance is started.

Hope that makes sense?

BTW keep in mind that this might be logical behaviour for you guys, but it took me quite some time to figure out how this all these tools need to work together behind the scenes. It would REALLY help a lot if this error isn't raised, but it is just terminated a new session started. Such features would really lower the threshold to get started with this...

Thanks for your understanding!!!

phoddie commented 1 year ago

@bartbutenaers - thank you for the background.

If you were running from the command line console, there would be no problem. The flow would work as I describe.

The problem is happening inside the MCU plug-in. While I don't understand the details of that yet, my instinct is to solve the problem there.

It would REALLY help a lot if this error isn't raised, but it is just terminated a new session started.

I understand that this is an issue for you and I'm happy to help find a solution. However, I don't think launching one debugger instance should always kill any other active debugger instance. That will be nice for you, but an unpleasant surprise for someone else.

For me, the main question is why there is an unused instance of xsbug-log still running in the plug-in.

And due to all manual interactions required on my wt32-eth01..

Yes, your favorite board is a bit of a pain to program. Both @andycarle and I have endured that.

ralphwetzel commented 1 year ago

Perhaps the results of two small test sequences might be supportive here:

First test is run on a Mac from the command line with a hardware device connected; no action by the plugin:

% mcconfig -d -x -m -p esp32 => opens xsbug % mcconfig -d -x -m -p esp32 => uses existing xsbug instance % mcconfig -d -x -m -p esp32 -l => kills xsbug, runs xsbug-log % mcconfig -d -x -m -p esp32 => opens xsbug % mcconfig -d -x -m -p esp32 -l => kills xsbug, runs xsbug-log % mcconfig -d -x -m -p esp32 -l => runs xsbug-log

All is fine!

Second: The same sequence run on Ubuntu Linux from the command line with a hardware device connected; no action by the plugin:

% mcconfig -d -x -m -p esp32 => opens xsbug % mcconfig -d -x -m -p esp32 => uses existing xsbug instance % mcconfig -d -x -m -p esp32 -l => doesn't kill xsbug, errors when trying to run xsbug-log

Error: listen EADDRINUSE: address already in use :::5002

(closing xsbug manually here) % mcconfig -d -x -m -p esp32 -l => runs xsbug-log % mcconfig -d -x -m -p esp32 -l => runs xsbug-log % mcconfig -d -x -m -p esp32 => opens xsbug

My summary: The behavior on Linux is different as on Mac: Running mcconfig [...] -l doesn't kill xsbug, keeping the port occupied, xsbug-log trips over the occupied port & errors.

phoddie commented 1 year ago

Thanks, @ralphwetzel.

I think perhaps our search for solutions is too focused on killing. I don't think it is a good practice to have the make system terminating processes. We've seen where that can leave to undesirable results. Instead of killing, I explored peaceful co-existence.

The reason that there is conflict between xsbug and xsbug-log is that they both want to use the same resource, port 5002. While 5002 is the default port for the xsbug protocol, the protocol can run over any port. Fortuitously, both xsbug and xsbug-log already allow the default port to be overridden by the XSBUG_PORT environment variable.

I modified mcconfig and mcrun to launch xsbug-log with an XSBUG_PORT of 50002, leaving xsbug with the default of 5002. With that change, the two peacefully co-exist allowing the make file sections to kill xsbug to be removed.

The changes are committed. They work nicely from the command line. I'm unsure, but perhaps the MCU plug-in will need an update as a result of these changes.

ralphwetzel commented 1 year ago

I'm unsure, but perhaps the MCU plug-in will need an updated as a result of these changes.

It wouldn't be necessary - but I'm going to follow on that path & put xsbug-log @ 50004, whereas xsbug stays @ 5004. That should allow a nice co-existence of both tools.

ralphwetzel commented 1 year ago

Fortuitously, both xsbug and xsbug-log already allow the default port to be overridden by the XSBUG_PORT environment variable.

Sorry - but it looks like we're all following the wrong path here ... and sorry a second time that - most probably - I pushed us in this wrong direction.

If this is still true - and I am pretty sure it is - we didn't implement XSBUG_PORT (long time ago) to move the listening port of xsbug. It's purpose is to tell serial2xsbug (!!) where to look for xsbug!

Thus xsbug always listens on 5002. -x: localhost:5004 forces serial2xsbug yet to connect to :5004 ... where the plugin listens & forwards the messages to xsbug.

That said, if we now use XSBUG_PORT to define an alternative listening port for xsbug-log, we'll change both ends of the connection - eliminating the functionality to move the plugin in between.

There might even be a design glitch in xsbug-log ... as it considers XSBUG_PORT !

So what's my proposal:

Change this https://github.com/Moddable-OpenSource/moddable/blob/0025289c9fac79bc3721291753d1af314862b20d/tools/xsbug-log/xsbug-log.js#L73

to

const portIn = 50002;

Revert ed12dfc03c7af25bd158a7227d840880f624021e ... as it is wrong (and sorry once again that I proposed this change!). EDIT: Reverting this might not be necessary when line 73 was changed - as it then hasn't any effect on xsbug-log anymore.

EDIT / Additional comment: 33dcf7313a7bf0576c083495feac81bee6c43610 is still correct and necessary ... as it forwards the alternative listening port of xsbug-log to serial2xsbug.

phoddie commented 1 year ago

xsbug does not always listen on port 5002. The code you show is xsbug initializing the default port. It has long been possible to change that in xsbug preferences, for example.

image
ralphwetzel commented 1 year ago

You're right - but this wasn't the issue I tried to highlight.

phoddie commented 1 year ago

I think it would be helpful if you could describe the problem independent of proposed solutions.

tve commented 1 year ago

If I may chime in... If I understand correctly:

To me the crux of the issue is: is the build process being told "I absolutely want debugger X" or is it being told "the default debugger is X". If it's the former, the build process should kill any inappropriate debugger or pick an alternate port dynamically to use with debugger X. If it's the latter, the build process should not do anything if a debugger is already listening on the right port regardless of which debugger it is.

In either case, IMHO, it should be possible to tell the build process "serial2xsbug should connect to port N" and "do not kill or launch any debugger".

In terms of "describe the problem" maybe it is that there is confusion/disagreement about what the build process is being told and thus should do?

ralphwetzel commented 1 year ago

My pleasure:

You introduced XSBUG_PORT as a mean to define the port serial2xsbug uses to connect to xsbug. XSBUG_PORT yet did not influence the listening port definition of xsbug. When xsbug-log was created, it was designed to consider XSBUG_PORT as its listening port definition. This is different to xsbug. Due to this change in logic, defining XSBUG_PORT now changes the listening port of xsbug-log & the search port of serial2xsbug in synch. The functionality you designed thus is no more given.

Speaking of proposals: I've once learned to appreciate those. They have a great benefit - it's up to the recipient to adopt them or ignore them. And in this special case: It addresses the topic perfectly...

bartbutenaers commented 1 year ago

Hi guys,

Really sorry that I have to keep waisting your precious time on this feature, but I can't get it running. Although I probably will have done something wrong myself, because I need to do it all hurry hurry in a short amount of free time. So please take that into account in your anaysis!!

I have updated my SDK using the Linux Update procedure, so hopefully that is done correctly. But I have the impression now that I cannot listen at all using xsbug-log anymore. Whatever I do (reboot my Raspberry, ...) it keeps showing me that the address is already in use:

image

It seems to me that only Node-RED is listening to one of the ports mentioned above, i.e. port 5004:

image

I assume that is the Proxy subprocess spawned by Ralph's node-red-mcu-plugin sidebar?

But then I would have expected to see that as a node-red subprocess also in htop, but there I see it as a separte process:

image

Does this ring a bell to anybody? Please don't hesitate to let me execute extra commands to provide you with extra information for troubleshooting...

Thanks!!!

bartbutenaers commented 1 year ago

BTW I have quickly drawn the setup, in an attempt to be able to follow the technical details of this discussion a bit better. Probably the drawing is not correct, but feel free to update it (by unzipping attempt1.zip and open it on excalidraw):

image

ralphwetzel commented 1 year ago

image

Diagram Data

bartbutenaers commented 1 year ago

Hmm, seems I am going to end up in the Guinness Book Of Records for the most issues registered in the wrong repo. Seems this is one for node-red-mcu-plugin instead of here. Sorry about that, but when I start registering an issue, I have no clue at all to which of the 3 repo's the root cause is related...

Did a bit of debugging, but now I am running out of creativity:

  1. When Node-RED has been started, none of the ports are being used (5002, 5004, 50002).

  2. Then I start xsbug-log via the sidebar:

    image

  3. The first thing that happens now in the sidebar server-side is creating a new Proxy instance.

  4. Then mcconfig is being launched with target xsbug on port 5004:

    image

  5. And immediately afterwards the proxy server starts listening to port 5004:

    image

So I end up with two services that want to listen on the same port...

Hopefully you can fix this based on this extra information.

bartbutenaers commented 1 year ago

Should this code snippet become something like this:

image

Because then I get this:

image

Will need to do some extra tests, but just sharing some thoughts meanwhile...

ralphwetzel commented 1 year ago

@bartbutenaers

Seems this is one for node-red-mcu-plugin instead of here.

I don't think so. The plugin acts as instructed...

While I tried to explain ( two times) what's happening here and here, I'm on stand by to implement a solution if there is one...

phoddie commented 1 year ago

Thank you to everyone -- @bartbutenaers, @tve, and @ralphwetzel -- for your ideas and feedback.

The swirl of different issues made it difficult for me to understand the root problem. I needed to step back from this topic to get some perspective.

The XSBUG_HOST and XSBUG_PORT environment variables are to override how runtimes connect to the debugger (xsbug), which defaults to localhost:5002. The runtimes here are the simulator and serial2xsbug, which is the bridge to the microcontroller runtime. It was indeed a mistake for xsbug-log to use XSBUG_PORT as an input as it is not a runtime.

I've committed several changes to try to help move this forward:

These changes should help. Still, there is likely more work to be done to arrive at an optimal workflow. There are, however, many different scenarios to consider, which requires care in designing solutions.

bartbutenaers commented 1 year ago

Hi @phoddie,

Thanks for taking a look at this!!
And yes from time to time it helps to take a step back, and view the problem from a distance...

I will wait until the sidebar from @ralphwetzel supports this way of working. It makes no sense that I start now using workarounds, since Ralph's sidebar is the perfect tool for this job in my Node-RED editor. Will get back here with feedback afterwards...

ralphwetzel commented 1 year ago

@bartbutenaers I've adapted the plugin to deal with these latest changes. Not tested too intensively - but so far it seems run smoothly. A new release (v1.3.0) has been published to npm & is installable via the Manage Palette option in the NR menu.

phoddie commented 1 year ago

Great news. Thank you. I'm going to close this issue.