🐛 Bug Report — Runtime APIs - Making a new request to a bound service causes a "The script will never generate a response." error

[asimpletune]

I'm seeing this issue only when a new request is constructed, not when a request is constructed from another request.

For example, the following code will succeed:

// This works
async fetch(request: Request, env: Env, ctx: ExecutionContext): Promise<Response> {
  env.v1_API.fetch(new Request("https://foo.com/v1/toml/parse", request))

However, in a situation where I can't copy the underlying request, say for example in an email handler, I get the dreaded "The script will never generate a response." error, for example:

// This seems to be impossible
async email(initialEmail: ForwardableEmailMessage, env: Env, ctx: ExecutionContext) {
  return env.v1_API.fetch(new Request("https://foo.com/v1/toml/parse"))

Unfortunately, I can easily do the second example if the request is not done through service bindings, but then what's the point of service bindings?

[kentonv]

Can you please provide a complete self-contained test case that demonstrates this problem?

[asimpletune]

Hey Kenton, thanks for the follow up.

Steps to reproduce:

# step 1: setup service b
wrangler generate service_b https://github.com/asimpletune/cf_issue-825_service-b && cd service_b && npm install && wrangler publish && cd ..

# step 2: setup service a
wrangler generate service_a https://github.com/asimpletune/cf_issue-825_service-a && cd service_a && npm install && SVC_A_WORKER_DEV=$(wrangler publish | grep https | xargs)

# step 3. call service a at /parse_mail_[1...4], and pass in `hello_world.eml` file as argument:
curl --data-binary @hello_world.eml $SVC_A_WORKER_DEV/parse_mail_1 
curl --data-binary @hello_world.eml $SVC_A_WORKER_DEV/parse_mail_2 
curl --data-binary @hello_world.eml $SVC_A_WORKER_DEV/parse_mail_3 
curl --data-binary @hello_world.eml $SVC_A_WORKER_DEV/parse_mail_4 

Also, if you set up an email trigger you can test the email handler in service a as well.

Expect vs Actual

I expect /parse_mail_1 - /parse_mail_4 to work, but what I actually see is that requests to /parse_mail_1 and /parse_mail_2 fail with "The script will never generate a response.", and request to /parse_mail_3 and /parse_mail_4 succeed.

Sending an email triggers the same failure, which is not what is expected.

More information about Services

Service A is just a simple typescript cloudflare worker that switches on the request path and calls Service B, which is bound to A.

// e.g. `curl --data-binary @hello_world.eml https://service_a.spence.workers.dev/parse_mail_1`
export default {
	async fetch(request: Request, env: Env, ctx: ExecutionContext): Promise<Response> {
		let url = new URL(request.url)
		switch (url.pathname) {
			// Fails
			case "/parse_mail_1": return env.ParseMail.fetch("https://foo.com", { method: "POST", body: request.body })
			// Fails
			case "/parse_mail_2": return env.ParseMail.fetch(new Request("https://foo.com", { method: "POST", body: request.body }))
			// Succeeds
			case "/parse_mail_3": return env.ParseMail.fetch("https://foo.com", request)
			// Succeeds
			case "/parse_mail_4": return env.ParseMail.fetch(new Request("https://foo.com", request))
			default: return new Response()
		}
	},
	async email(email: ForwardableEmailMessage, env: Env, ctx: ExecutionContext) {

		return env.ParseMail.fetch("https://foo.com", { method: "POST", body: email.raw })
			.then(response => response.text())
			.then(text => { console.log(text); return new Response() })
	}
};

Service B is a rust worker that uses a mail-parser library and serve to parse the text and return the response as JSON.

use worker::*;

fn log_request(req: &Request) {
    console_log!(
        "{} - [{}], located at: {:?}, within: {}",
        Date::now().to_string(),
        req.path(),
        req.cf().coordinates().unwrap_or_default(),
        req.cf().region().unwrap_or("unknown region".into())
    );
}

#[event(fetch)]
async fn main(mut req: Request, _: Env, _: Context) -> Result<Response> {
    log_request(&req);
    Response::ok("OK")
}

[asimpletune]

Basically

// this fails BUT
env.ParseMail.fetch("https://foo.com", { method: "POST", body: request.body })` 

 // this succeeds
env.ParseMail.fetch("https://foo.com", request)

[kentonv]

@jasnell Could this be a streams bug? For some reason propagating request.body explicitly causes a missing pending event when sending a subrequest?

[asimpletune]

I know the root cause of the issue now. Accessing the cf() method from a downstream, bound rust worker (I.e. service_b) causes a panic when a new request is initiated by a TS/JS worker (in web_sys land).

This was made clear by the logger code of service_b:

Example

fn log_request(req: &Request) {
    console_log!(
        "{} - [{}], located at: {:?}, within: {}",
        "{} - [{}], located at: {:?}, within: {}",
        Date::now().to_string(),
        req.path(),
        req.cf().coordinates().unwrap_or_default(),
        req.cf().region().unwrap_or("unknown region".into())
    );
}

// just this code is enough to cause the same issue
fn log_request(req: &Request) {
    req.cf(); // And commenting out this line will alleviate the issue
    console_log!("{} - [{}]", Date::now().to_string(), req.path(),);
}

The problematic code

If you look at the cf() method, you can see where the panic is coming from:

// (In request.rs)

/// Access this request's Cloudflare-specific properties.
pub fn cf(&self) -> &Cf {
    self.cf.as_ref().unwrap()
}

I can take a look at submitting a patch to fix this.

Edited because I initially thought the request being mut was causing the issue, but I had overlooked the call to log_request.

[asimpletune]

Since this is an issue with worker-rs I'll go ahead and close this and submit a fix there. Thanks for everyone's patience.