Context deadline exceeded

[nmeri17]

After some Googling, I realised this is a Golang specific error, rather than a Roadrunner one. I've been having a string of similar errors trying to get up and running, that make me wonder whether the error reporting for the server can be improved upon.

Yesterday, server was running well but my code was throwing an error because I hadn't connected the cache adapter for production. Even though stack trace was truncated, at least, server produced output that something was wrong. After writing and connecting adapter, server runs briefly before shutting down with this error "context deadline exceeded". When I http pool.debug = true, the connection is sustained, although no request is ever served. Every request causes it to throw that error, but it never shuts down. For this error, I suspect no workers/job is setup. Please see https://gist.github.com/nmeri17/082d6ca1f82b048c13b25902d250584d#file-moduleworkeraccessor-php-L72. My understanding is that for each suphle-test-worker, ModuleWorkerAccessor is spun up and env is updated with the job mode. Unfortunately, I can't debug whether or not that conditional ever runs, since all output is trapped. I run suphle-test-worker alone, no errors, no output. I'm trying to have workers for queue and http. Kindly confirm that's the correct logic for it

Secondly I tried to run the underlying code standalone ie without the server. The code ought to interact with cache and queues. All the while, I used my in-memory doubles and all was fine. Now, when I try to connect to the Roadrunner queue, it fails with the message "no global boltdb configuration". I've checked the configuration reference and boltdb has no global entry. It always lives under something else

You can see https://gist.github.com/nmeri17/082d6ca1f82b048c13b25902d250584d#file-rr-yaml-L88, the jobs section is commented out. I'm just struggling to get the adapters running ie even if queues fail, cache should succeed, right? Roadrunner says "not so fast!". After commenting that out, the page /app/request fails with "socket_connect no connection could be made because the target machine actively refused it". The RPC that works for booting up the server suddenly is actively refused. This happens on this line https://github.com/nmeri17/Tilwa/blob/23ee2d6377e821c770d6487baeb874e26fc69ec6/nmeri/tilwa/src/Adapters/Cache/BoltDbCache.php#L53. That's where I'm lost

I really hope one of the maintainers can help resolve three issues as soon as possible

[rustatian]

Hey @nmeri17 👋🏻 , nice to meet you.
Could you please share debug logs?
pool.debug = true should be used only for local development. In this mode, RR creates a worker right after the request arrives at RR and destroys it after response.

"no global boltdb configuration"

BoltDB has a global configuration -> https://github.com/roadrunner-server/roadrunner/blob/master/.rr.yaml#L1027

Remember that you can't have more than one connection to BoltDB; all other connections will be deadlined due to such database nature (SQLite, boltdb, etc).

Also, there is no sense to use debug and reload (https://gist.github.com/nmeri17/082d6ca1f82b048c13b25902d250584d#file-rr-yaml-L20), because they both solve one purpose but have a different approach. reload will automatically detect the changes and reload workers. But since you're using debug mode, there are no workers, so, nothing to reload.

[nmeri17]

Oh, amazing. I didn't realise you had responded. Sorry about that. Will refresh my mails next time

I added the debug flag in hopes of getting a more verbose message of what is going on. It wasn't originally there

BoltDB has a global configuration

Hmm. I guess I missed it cuz it's just one line and says "boltdb jobs driver". On a side note, why is there a global config and the smaller ones? Could make conflicts like this harder to spot

Remember that you can't have more than one connection to BoltDB; all other connections will be deadlined due to such database nature (SQLite, boltdb, etc).

Yes, I saw that. However, I understood it to mean that I can't use the same database file for the same purpose. Indeed, the docs says this is a concurrency limitation from boltdb. Are you saying if cache uses boltdb, then queues must use a driver like "memory" for testing (automated and manual in basic development environment) ? I suggest there should be a file driver for those two instances mentioned above, that can survive in between requests, without the hard requirement of not being combined with another component ie cache +queues

Also, there is no sense to use debug and reload

"reload", here is my file watcher. Like I said, debug kept server alive, but I'll remove it now

[rustatian]

Hmm. I guess I missed it cuz it's just one line. On a side note, why is there a global config and the smaller ones? Could make conflicts like this harder to spot

Global configuration describes some general parameters for the storage.

Are you saying if cache uses boltdb, then queues must use a driver like "memory" for testing (automated and manual in basic development environment) ?

Yes, correct. This is a file database limitation to have only one connection per file. That is because you're getting the Context deadline exceeded errors. Because if you use a boltdb as a KV storage and specify the same file for the jobs, you'll end up with two concurrent connections to the same file, which is not allowed.

"reload", here is my file watcher. Like I said, debug kept server alive, but I'll remove it now

Remember that you should not use the debug in production.

[rustatian]

That is the worker's main loop. In this loop arrives requests from the RR. This should be the main entrypoint to your app. And it's not freezes it works as expected, waiting for the requests from the RR.

[rustatian]

If you have a look at the docs, you'll see exact same loop:

while (true) {} <---

And this is how the while works in PHP: https://www.php.net/manual/en/control-structures.while.php
(like in any other language, blocking until some condition is met).

[nmeri17]

Maybe I wasn't clear. I send requests and nothing gets logged past the loop, but it logged something before when it was able to handle requests .I even revert to that version of the file just now, when requests enter the loop, something is logged and the server doesn't crash

[nmeri17]

If you have a look at the docs, you'll see exact same loop:

while (true) {} <---

And this is how the while works in PHP: https://www.php.net/manual/en/control-structures.while.php (like in any other language, blocking until some condition is met).

Are you trolling me right now?

[rustatian]

I'm trying to help you.

[rustatian]

My pleasure 👍🏻

And there's no way to debug this.

You may also use an xdebug: https://roadrunner.dev/docs/php-debugging/2.x/en

[nmeri17]

This happens just before server shuts down, so I suspect it may not be the true origin of the problem. Unfortunately, none of breakpoints is reached before server crashes. The server crashes too soon for me to inspect anything. I'm wondering, isn't the server meant to be running the php instance given to it by debugger? Ie it's meant to stay alive as long as the debugger is running. But the server crashes, then I get that error in debugger about incorrect header size

[rustatian]

What RR version are you using?

[rustatian]

Ah, I see, 2.10.6. Ok, as I see from the stack trace, the PHP worker is waiting for the request, which is fine. In your code, I guess you're assuming that the waitRequest should exit, but it should not exit from the loop until RR is stopped.

[nmeri17]

I have accessor - >buildIdentifier() - >setActiveWorker(). If I switchthe calls to set active worker first, it runs smoothly and server does setup. But that's a wrong execution sequence since I'm pulling queueAdapter
from a module's container; at that point, the modules haven't booted. The only reason that line doesn't throw an error is that accessor only receives http mode for those first 4 workers. If for any reason, task mode enters
there, it'll attempt to lift something from container that is still in unusable state

Now, you'll think what freezes it must be in the call to buildIdentifier, but debugger either makes it past that breakpoint or server crashes too fast for it to execute there. And there's no error

[nmeri17]

What RR version are you using?

The version in rr.yaml is 2.7. Composer says 2.10

[nmeri17]

1. How do I make jobs worker start immediately instead of waiting 2 minutes? I've tried relay_timeout and exec_timeout under server key
2. How do I give workers indefinite run time or tie its lifetime to the debugger?
3. If there's an errornous part of my code that causes server setup to freeze, is this error logged anywhere I can view?

I ran endure container in debug mode in hopes of seeing its last action before shutdown. The only thing that seems to stand out compared to other output is

github.com/roadrunner-server/[email protected]/pkg/container/poller.go:54
2022-07-16T06:11:21.678+0100    DEBUG   container/poller.go:49  processing error
 in the main thread     {"id": "jobs.Plugin"}
2022-07-16T06:11:21.679+0100    INFO    container/endure.go:459 exiting from the
 Endure
 [91;1merror: static_pool_allocate_workers: WorkerAllocate: context deadline exc
eeded
plugin: http.Plugin
 [0m

Does this mean it's unable to handle a job plugin setup? If yes, why has it always said plugin: http.Plugin on the last line?

[rustatian]

1. Worker is a system process. Process allocates in a few milliseconds (depending on your OS). Allocate timeout might be set by this key: https://github.com/roadrunner-server/roadrunner/blob/master/.rr.yaml#L242
2. Use allocate_timeout: 9999h.
3. The while loop should be the last step in your setup.

WorkerAllocate: context deadline exceeded means that RR could not allocate a worker because some part of your code is blocking it.
Please, have a look at these integrations, compare them to your code and find a mistake:
https://github.com/spiral/roadrunner-laravel
https://github.com/Baldinof/roadrunner-bundle

[nmeri17]

I removed the http part of rr.yaml to get around the two minutes it takes for job worker allocation to take place.

Process allocates in a few milliseconds (depending on your OS)

This is only true when a solitary worker type/mode is being ran--http OR jobs. When both are combined, http spins up 4 workers instantly. The jobs worker waits exactly 63 seconds before signaling creation of 10 workers. I indicated this four days ago. However, there's another caveat

because some part of your code is blocking it

Spot on. For some reason, Composer was unable to include one of my interfaces while booting the modules, until I emptied the interface's contents and ran again. After it started working, I pasted them back and server stopped crashing mysteriously while trying to hydrate jobs worker handler.

What's interesting is that I spent considerable time pursuing a bug that doesn't exist. It's not mentioned anywhere that this setup timeout "context deadline exceeded" is possible if a debugger breakpoint is set anywhere before any of the while loops, in my case

$consumer = new Consumer;

while ($task = $consumer->waitTask()) {

Following that error lead to me this call stack

Exception has occurred.
Fatal error: Uncaught Spiral\Goridge\Exception\TransportException: An error occurred while write payload to the stream: fwrite(): write of 24 bytes failed with errno=22 Invalid argument in C:\wamp64\www\tilwa\nmeri\tilwa\vendor\spiral\goridge\src\StreamRelay.php:129
Stack trace:
#0 C:\wamp64\www\tilwa\nmeri\tilwa\vendor\spiral\roadrunner-worker\src\Worker.php(145): Spiral\Goridge\StreamRelay->send(Object(Spiral\Goridge\Frame))
#1 C:\wamp64\www\tilwa\nmeri\tilwa\vendor\spiral\roadrunner-worker\src\Worker.php(172): Spiral\RoadRunner\Worker->sendFrame(Object(Spiral\Goridge\Frame))
#2 C:\wamp64\www\tilwa\nmeri\tilwa\vendor\spiral\roadrunner-worker\src\Worker.php(88): Spiral\RoadRunner\Worker->handleControl('{"pid":6720}')
#3 C:\wamp64\www\tilwa\nmeri\tilwa\vendor\spiral\roadrunner-jobs\src\Consumer.php(99): Spiral\RoadRunner\Worker->waitPayload()
#4 C:\wamp64\www\tilwa\nmeri\tilwa\src\Adapters\Queues\BoltDbQueue.php(49): Spiral\RoadRunner\Jobs\Consumer->waitTask()
#5 C:\wamp64\www\tilwa\nmeri\tilwa\src\Modules\ModuleWorkerAcc

So I kept wondering the reason behind that line executing when I was yet to dispatch any tasks. This means I'm prohibited from either var_dump-ing anything or setting breakpoints anywhere before the while loops. This means you have to make this command more visible rr workers since the native ways of knowing whether something work or not don't apply here, even though it doesn't help with knowing what exactly occurred. I can't catch any errors, can't setup exception handlers, can't use try-catch. That brings me to the caveat mentioned earlier

Use allocate_timeout: 9999h

As already mentioned here #1212 (reply in thread), the local allocate_timeout has no effect. Now that my Composer issue is resolved and everything related to jobs plugin is sorted, the workers don't kick in after 2 minutes anymore but instantly. Using the global(?) one under the "activities" key does nothing. Everything happens instantly. Off the top of my head, I feel if there's a json version of this sample yaml it can help with issues such as nested config. I can see a space before "activities" that traces back to temporal, correct? Do I need that for worker allocation? Doubt.

Second suggestion I feel could help is breaking config into different files just like gitignores, so one can tell what config they're looking at (while comparing to the master list), what overrides what, etc.

Lastly, I planned to test this using the following in my test case: exec ('rr serve -c "path/to/test-rr.yaml", then making a http request to localhost or something. This is because my workers' bootstrapper php suphle-test-worker.php works without errors. But in real life i.e. in conjunction with the binary, config, RPC etc, it fails woefully. Which inspired this long thread.
I looked briefly at the tests for one of the libraries you posted and realized the testing is more programmatic. So I want to clarify before digging into their source code whether there's an API to trigger setup the way it happens in real life? I need to ensure that all wiring is done correctly, my app can read headers, post bodies, file upload etc after RR is done setting up the workers. I just need to know whether I can trigger the binary from PHP end

Many thanks for your patience and assistance