Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG, NEED VERIFICATION] $worker->getWorker()->error((string)$e); cause a force kill and lost error msg #691

Closed
dhopkalo opened this issue May 26, 2021 · 7 comments · Fixed by #700
Assignees
Labels
B-bug Bug: bug, exception F-need-verification
Milestone

Comments

@dhopkalo
Copy link
Contributor

dhopkalo commented May 26, 2021

When I created my own worker process and use the code example for the push error to the rr server for workers

    } catch (\Throwable $e) {
        $worker->getWorker()->error((string)$e);
    }

I don't see my original error only the next errors:

2021-05-26T16:35:46.711+0300    DEBUG   server          server/plugin.go:225    worker destructed       {"pid": 24906}
2021-05-26T16:35:46.725+0300    ERROR   server          server/plugin.go:238    worker_watcher_wait: signal: killed; process_wait: signal: killed
github.com/spiral/roadrunner/v2/plugins/server.(*Plugin).collectEvents
        github.com/spiral/roadrunner/[email protected]/plugins/server/plugin.go:238
github.com/spiral/roadrunner/v2/pkg/events.(*HandlerImpl).Push
        github.com/spiral/roadrunner/[email protected]/pkg/events/general.go:37
github.com/spiral/roadrunner/v2/pkg/worker_watcher.(*workerWatcher).wait
        github.com/spiral/roadrunner/[email protected]/pkg/worker_watcher/worker_watcher.go:235
github.com/spiral/roadrunner/v2/pkg/worker_watcher.(*workerWatcher).addToWatch.func1
        github.com/spiral/roadrunner/[email protected]/pkg/worker_watcher/worker_watcher.go:260
2021-05-26T16:35:47.278+0300    DEBUG   server          server/plugin.go:223    worker constructed      {"pid": 24965}

I expected to see my (string)$e in the rr logs

Instead, i see that worker process was force killed

I create a simple fix for my issue: #690

@dhopkalo dhopkalo added B-bug Bug: bug, exception F-need-verification labels May 26, 2021
@dhopkalo dhopkalo changed the title [BUG] [BUG] $worker->getWorker()->error((string)$e); cause a force kill process and lost passed error massage May 26, 2021
@dhopkalo dhopkalo changed the title [BUG] $worker->getWorker()->error((string)$e); cause a force kill process and lost passed error massage [BUG] $worker->getWorker()->error((string)$e); cause a force kill and lost error msg May 26, 2021
@rustatian
Copy link
Member

rustatian commented May 27, 2021

Hey @drefixs. Thanks for the report.

  1. Could you please send the whole .rr.yaml you used and the PHP (your) worker sample to reproduce your problem?
  2. Your OS version.

@rustatian rustatian changed the title [BUG] $worker->getWorker()->error((string)$e); cause a force kill and lost error msg [BUG, NEED VERIFICATION] $worker->getWorker()->error((string)$e); cause a force kill and lost error msg May 27, 2021
@dhopkalo
Copy link
Contributor Author

Hi @48d90782 thanks for the quick responce:

server:
   command: "php bin/console baldinof:roadrunner:worker"

http:
  address: 0.0.0.0:80
  middleware: [ "static", "gzip" ]
  pool:
    num_workers: 4
  uploads:
    forbid: [ ".php", ".exe", ".bat" ]
  static:
    dir: "web"
    forbid: [ ".php", ".htaccess" ]

logs:
  mode: production
  encoding: console
  channels:
    http:
      mode: production
      level: debug
      encoding: console
      output: stdout
      err_output: stderr

rpc:
  listen: tcp://127.0.0.1:6001

Also I noticed that if you change http.pool.debug=true it starts to work normally without force killing the process with log

  1. OSX(Darwin)(x86) and Docker Alpine linux (x86) on server

@dhopkalo
Copy link
Contributor Author

dhopkalo commented May 27, 2021

@48d90782 May be i found the reason
https://github.com/spiral/roadrunner/blob/master/pkg/pool/static_pool.go#L267
this part of the code first in the else condition tries to do sp.ww.Push(w) with force kill inside for the worker that sent frame ERROR

after that it try again to do graceful termination with w.Stop()

when I just remove this else condition all start work as expected and worker_watcher push stopped worker back to the vector queue also stop command have fallback kill logic inside.

@rustatian
Copy link
Member

First of all, please, provide a worker you used and full steps on how to reproduce this issue. I'll definitely take into account your investigation, thanks 👍🏻

@rustatian rustatian removed the B-bug Bug: bug, exception label May 31, 2021
@rustatian
Copy link
Member

rustatian commented Jun 3, 2021

@drefixs Am I right, that you are expecting to see smt like this in the logs output?:
image

where test_error is:
image

@rustatian
Copy link
Member

Or, I guess, that would be better to see smt like this (without RR specific error wrapping):
image

@rustatian rustatian added the B-bug Bug: bug, exception label Jun 3, 2021
@rustatian rustatian added this to the 2.3.0 milestone Jun 3, 2021
@rustatian
Copy link
Member

Fixed, will be as on the second screenshot.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
B-bug Bug: bug, exception F-need-verification
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants