[GH-ISSUE #652] GUI does not report "running" if log level is not verbose enough (NOTE or 'higher') #519

Closed
opened 2026-05-05 06:34:57 -06:00 by gitea-mirror · 11 comments
Owner

Originally created by @plessbd on GitHub (May 4, 2020).
Original GitHub issue: https://github.com/debauchee/barrier/issues/652

Operating Systems

Server: macOS Catalina 10.15.4

Client: macOS Catalina 10.15.4

Barrier Version

2.3.3-snapshot-b6a1b574 (with applied #648)

Steps to reproduce bug

  1. Open Barrier App
  2. Click Start
  3. Window text in bottom left says 'Barrier is starting.' Button changes to stop
  4. Everything works but never gets to a 'Started' state.

If the log level is ERROR or WARNING the GUI does not correctly get 'RUNNING' state

https://github.com/debauchee/barrier/blob/master/src/gui/src/MainWindow.cpp#L379-L399

Server
Good:

[2020-05-05T09:38:07] INFO: starting server
[2020-05-05T09:38:07] INFO: config file: /private/var/folders/gx/6jwb8yzj4fd29jcf_syprmf80000gn/T/Barrier.bDKxjV
[2020-05-05T09:38:07] INFO: log level: NOTE
[2020-05-05T09:38:08] NOTE: started server (IPv4/IPv6), waiting for clients
2020-05-05 09:38:08.043 barriers[35630:8402363] starting cocoa loop

Bad:

[2020-05-05T09:38:59] INFO: starting server
[2020-05-05T09:38:59] INFO: config file: /private/var/folders/gx/6jwb8yzj4fd29jcf_syprmf80000gn/T/Barrier.ZpuYup
[2020-05-05T09:38:59] INFO: log level: WARNING
2020-05-05 09:39:00.000 barriers[35872:8403666] starting cocoa loop

Client:
Good:

[2020-05-05T09:38:59] INFO: starting server
[2020-05-05T09:38:59] INFO: config file: /private/var/folders/gx/6jwb8yzj4fd29jcf_syprmf80000gn/T/Barrier.ZpuYup
[2020-05-05T09:38:59] INFO: log level: WARNING
2020-05-05 09:39:00.000 barriers[35872:8403666] starting cocoa loop

Bad:

[2020-05-05T09:38:59] INFO: starting server
[2020-05-05T09:38:59] INFO: config file: /private/var/folders/gx/6jwb8yzj4fd29jcf_syprmf80000gn/T/Barrier.ZpuYup
[2020-05-05T09:38:59] INFO: log level: WARNING
2020-05-05 09:39:00.000 barriers[35872:8403666] starting cocoa loop
Originally created by @plessbd on GitHub (May 4, 2020). Original GitHub issue: https://github.com/debauchee/barrier/issues/652 ### Operating Systems ### Server: macOS Catalina 10.15.4 Client: macOS Catalina 10.15.4 ### Barrier Version ### 2.3.3-snapshot-b6a1b574 (with applied #648) ### Steps to reproduce bug ### 1. Open Barrier App 2. Click Start 3. Window text in bottom left says 'Barrier is starting.' Button changes to stop 4. Everything works but never gets to a 'Started' state. If the log level is ERROR or WARNING the GUI does not correctly get 'RUNNING' state https://github.com/debauchee/barrier/blob/master/src/gui/src/MainWindow.cpp#L379-L399 Server Good: ``` [2020-05-05T09:38:07] INFO: starting server [2020-05-05T09:38:07] INFO: config file: /private/var/folders/gx/6jwb8yzj4fd29jcf_syprmf80000gn/T/Barrier.bDKxjV [2020-05-05T09:38:07] INFO: log level: NOTE [2020-05-05T09:38:08] NOTE: started server (IPv4/IPv6), waiting for clients 2020-05-05 09:38:08.043 barriers[35630:8402363] starting cocoa loop ``` Bad: ``` [2020-05-05T09:38:59] INFO: starting server [2020-05-05T09:38:59] INFO: config file: /private/var/folders/gx/6jwb8yzj4fd29jcf_syprmf80000gn/T/Barrier.ZpuYup [2020-05-05T09:38:59] INFO: log level: WARNING 2020-05-05 09:39:00.000 barriers[35872:8403666] starting cocoa loop ``` Client: Good: ``` [2020-05-05T09:38:59] INFO: starting server [2020-05-05T09:38:59] INFO: config file: /private/var/folders/gx/6jwb8yzj4fd29jcf_syprmf80000gn/T/Barrier.ZpuYup [2020-05-05T09:38:59] INFO: log level: WARNING 2020-05-05 09:39:00.000 barriers[35872:8403666] starting cocoa loop ``` Bad: ``` [2020-05-05T09:38:59] INFO: starting server [2020-05-05T09:38:59] INFO: config file: /private/var/folders/gx/6jwb8yzj4fd29jcf_syprmf80000gn/T/Barrier.ZpuYup [2020-05-05T09:38:59] INFO: log level: WARNING 2020-05-05 09:39:00.000 barriers[35872:8403666] starting cocoa loop ```
gitea-mirror 2026-05-05 06:34:57 -06:00
Author
Owner

@simons-public commented on GitHub (May 4, 2020):

@plessbd Can you try this updated build? Earlier in #648 I had forgotten to manually specify barrierc and barriers in the macdeployqt arguments with -executable=. Since they're not listed in CFBundleExecutable in the plist they weren't getting picked up.

It might not be related, but it could be causing issues if the gui and command line binaries are linked to different libraries. I didn't experience the same issue, but I'm still running on Mojave since I need 32bit.

<!-- gh-comment-id:623582844 --> @simons-public commented on GitHub (May 4, 2020): @plessbd Can you try [this updated build](https://github.com/simons-public/barrier/releases/tag/use-macdeployqt)? Earlier in #648 I had forgotten to manually specify `barrierc` and `barriers` in the `macdeployqt` arguments with `-executable=`. Since they're not listed in CFBundleExecutable in the plist they weren't getting picked up. It might not be related, but it could be causing issues if the gui and command line binaries are linked to different libraries. I didn't experience the same issue, but I'm still running on Mojave since I need 32bit.
Author
Owner

@plessbd commented on GitHub (May 4, 2020):

That did not seem to change anything except I had to reallow the application in accessibility.

Feel free to let me know if there is something else I can try. I am comfortable editing source and all.

<!-- gh-comment-id:623620506 --> @plessbd commented on GitHub (May 4, 2020): That did not seem to change anything except I had to reallow the application in accessibility. Feel free to let me know if there is something else I can try. I am comfortable editing source and all.
Author
Owner

@simons-public commented on GitHub (May 4, 2020):

If you know the last commit that didn't have that issue you could do a git bisect and figure out which change broke it. You might have to git cherry-pick the commits from #648 to get it to build though, I don't know how long the build_installer.sh script has been not working for.

I'll look through the repo and see how the barrier GUI process communicates with the server and see if there's any troubleshooting info that can be gleaned from that. I'm curious as to how its communicating status.

Also if you could post a dtruss output for the main barrier process to a gist that could help narrow it down. Running sudo dtruss -n barrier should pick it up. That'll show all the system calls that the main process is making.

<!-- gh-comment-id:623764197 --> @simons-public commented on GitHub (May 4, 2020): If you know the last commit that didn't have that issue you could do a `git bisect` and figure out which change broke it. You might have to `git cherry-pick` the commits from #648 to get it to build though, I don't know how long the `build_installer.sh` script has been not working for. I'll look through the repo and see how the barrier GUI process communicates with the server and see if there's any troubleshooting info that can be gleaned from that. I'm curious as to how its communicating status. Also if you could post a `dtruss` output for the main barrier process to a gist that could help narrow it down. Running `sudo dtruss -n barrier` should pick it up. That'll show all the system calls that the main process is making.
Author
Owner

@simons-public commented on GitHub (May 5, 2020):

I think I see the issue in your log:
[2020-05-04T11:26:50] WARNING: cannot listen for clients: cannot bind address: Address already in use

It looks like there might another process tying up the socket. It's keeping the barriers process from outputting server status: active to stdout, which is how the barrier GUI checks that the server is running.

If you kill any old barrier/barriers/barrierc processes or reboot it might fix the problem. Or it might be a new daemon in Catalina that uses the same ports as barrier's IPC (24801) since there's another issue with the same symptoms. I figure it's just the IPC port since client/server connectivity happens on 24800 and you said the service is working otherwise.

<!-- gh-comment-id:623782479 --> @simons-public commented on GitHub (May 5, 2020): I think I see the issue in your log: `[2020-05-04T11:26:50] WARNING: cannot listen for clients: cannot bind address: Address already in use` It looks like there might another process tying up the socket. It's keeping the `barriers` process from outputting `server status: active` to stdout, [which is how the barrier GUI checks that the server is running](https://github.com/debauchee/barrier/blob/master/src/gui/src/MainWindow.cpp#L379-L399). If you kill any old `barrier/barriers/barrierc` processes or reboot it might fix the problem. Or it might be a new daemon in Catalina that uses the same ports as [barrier's IPC (24801)](https://github.com/debauchee/barrier/blob/b6a1b5742006157c3fe746288961a9d2827a3f26/src/lib/ipc/Ipc.h#L22) since there's another [issue with the same symptoms](#516). I figure it's just the IPC port since client/server connectivity happens on 24800 and you said the service is working otherwise.
Author
Owner

@plessbd commented on GitHub (May 5, 2020):

found the issue
https://github.com/debauchee/barrier/blob/master/src/gui/src/MainWindow.cpp#L379-L399

Which seems you added to the other issue already.

So this only happens when log level is not error or warning, otherwise it doesnt say that it has started.

<!-- gh-comment-id:624035905 --> @plessbd commented on GitHub (May 5, 2020): found the issue https://github.com/debauchee/barrier/blob/master/src/gui/src/MainWindow.cpp#L379-L399 Which seems you added to the other issue already. So this only happens when log level is not error or warning, otherwise it doesnt say that it has started.
Author
Owner

@simons-public commented on GitHub (May 5, 2020):

Are you still getting the warning about binding the address from your original edit on the issue though? If it’s another ‘barriers’ process running in the background #654 is just going to mask the real issue. The GUI still won’t be connected to the ‘barriers’ process it is running, so the stop command won’t actually stop the process that is handling inbound port 24800 connections. What should change is the server should exit with a failure and an error message if it can’t bind to the port that way you get an indication of the underlying issue.

<!-- gh-comment-id:624206362 --> @simons-public commented on GitHub (May 5, 2020): Are you still getting the warning about binding the address from your original edit on the issue though? If it’s another ‘barriers’ process running in the background #654 is just going to mask the real issue. The GUI still won’t be connected to the ‘barriers’ process it is running, so the stop command won’t actually stop the process that is handling inbound port 24800 connections. What should change is the server should exit with a failure and an error message if it can’t bind to the port that way you get an indication of the underlying issue.
Author
Owner

@plessbd commented on GitHub (May 5, 2020):

I believe that was a different issue as I somehow got into a state where I did have multiple barrier-servers running, not sure how that happened.

But testing on a rebooted system did not show those errors anymore.

<!-- gh-comment-id:624208382 --> @plessbd commented on GitHub (May 5, 2020): I believe that was a different issue as I somehow got into a state where I did have multiple barrier-servers running, not sure how that happened. But testing on a rebooted system did not show those errors anymore.
Author
Owner

@simons-public commented on GitHub (May 5, 2020):

The multiple servers issue can still happen with #654 in place though since the server can still show ‘starting cocoa loop’ even if it can’t bind to the port (as shown in your original log post before the edit). It makes connectivity issues harder to troubleshoot for users. Until the GUI uses barrier IPC to communicate status it’s better to have the ‘barriers’ process exit on failing to bind. I can make a pull request that does that later today.

I just checked I can very consistently reproduce the described behavior by starting another barriers instance from the command line and clicking Start on the GUI. Then after stopping and killing any extra barriers instances, clicking on the Start button shows "Barrier is running."

Barrier appears to be working because there is another instance of the server running, but the GUI is not talking to that other instance, so it never triggers the "Barrier is running." message despite not throwing any errors. Clicking Stop in this instance also won't stop the other instance from running.

I think elevating the cannot listen for clients: log to from WARNING to ERROR is actually the best option here. That lets users know that the barriers process being controlled by the GUI is not going to work if it can't bind the socket, and that the port is already in use by another process that needs to be stopped.

<!-- gh-comment-id:624232321 --> @simons-public commented on GitHub (May 5, 2020): The multiple servers issue can still happen with #654 in place though since the server can still show ‘starting cocoa loop’ even if it can’t bind to the port (as shown in your original log post before the edit). It makes connectivity issues harder to troubleshoot for users. <s>Until the GUI uses barrier IPC to communicate status it’s better to have the ‘barriers’ process exit on failing to bind. I can make a pull request that does that later today.</s> I just checked I can very consistently reproduce the described behavior by starting another `barriers` instance from the command line and clicking Start on the GUI. Then after stopping and killing any extra `barriers` instances, clicking on the Start button shows "Barrier is running." Barrier appears to be working because there is another instance of the server running, but the GUI is not talking to that other instance, so it never triggers the "Barrier is running." message despite not throwing any errors. Clicking Stop in this instance also won't stop the other instance from running. I think elevating the `cannot listen for clients:` log to from WARNING to ERROR is actually the best option here. That lets users know that the `barriers` process being controlled by the GUI is [not going to work if it can't bind the socket](https://github.com/debauchee/barrier/blob/b6a1b5742006157c3fe746288961a9d2827a3f26/src/lib/barrier/ServerApp.cpp#L562-L567), and that the port is already in use by another process that needs to be stopped.
Author
Owner

@simons-public commented on GitHub (May 12, 2020):

@plessbd Sorry I totally missed the point you were getting at that ERROR or WARNING levels don't print INFO messages.

I think checking for starting cocoa loop in #654 doesn't give the right status since it still shows that in the logs even if it can't bind to the port, but I changed the log level for the messages that the GUI checks for in #664 if you wouldn't mind trying it.

<!-- gh-comment-id:627095548 --> @simons-public commented on GitHub (May 12, 2020): @plessbd Sorry I _totally_ missed the point you were getting at that ERROR or WARNING levels don't print INFO messages. I think checking for `starting cocoa loop` in #654 doesn't give the right status since it still shows that in the logs [even if it can't bind to the port](https://gist.github.com/simons-public/a1e83a573795f4d57caad983d7dfd4a1), but I changed the log level for the messages that the [GUI checks for](https://github.com/debauchee/barrier/blob/master/src/gui/src/MainWindow.cpp#L379-L399) in #664 if you wouldn't mind trying it.
Author
Owner

@plessbd commented on GitHub (May 12, 2020):

@simons-public it works, but has made me realize the loglevel is "ignored" for the first 3 messages
https://github.com/debauchee/barrier/blob/master/src/gui/src/MainWindow.cpp#L539-L548
and by ignored, I mean output prefixed with INFO

I guess we could say "There are three hard things in Computer Science: cache invalidation, naming things, what level to log message, and off-by-one errors"

<!-- gh-comment-id:627314173 --> @plessbd commented on GitHub (May 12, 2020): @simons-public it works, but has made me realize the loglevel is "ignored" for the first 3 messages https://github.com/debauchee/barrier/blob/master/src/gui/src/MainWindow.cpp#L539-L548 and by ignored, I mean output prefixed with INFO I guess we could say "There are three hard things in Computer Science: cache invalidation, naming things, what level to log message, and off-by-one errors"
Author
Owner

@simons-public commented on GitHub (May 12, 2020):

@plessbd The first 3 INFOs are printed, but you are still right that the INFO level messages do drop off before the "started server (%s), waiting for clients" gets parsed for updating the client status.

I like your addition to that quote, I'm totally saving that for later.

<!-- gh-comment-id:627443328 --> @simons-public commented on GitHub (May 12, 2020): @plessbd The first 3 INFOs are printed, but you are still right that the INFO level messages do drop off before the "started server (%s), waiting for clients" gets parsed for updating the client status. I like your addition to that quote, I'm totally saving that for later.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference: github-starred/barrier#519
No description provided.