Dispatcher doesn't cache

[kevingtan]

Hi All,

Recently we had VM migration from an old location to another one. The migration cloned one branch of the whole architecture as the following: author -> publisher -> dispatcher. Nothing changes except the new clone has a new domain name. Now we found a problem, the dispatcher doesn't cache.

We can authorize contents from author, the contents will be replicated all the way to the dispatcher, but the dispatcher always skips itself and tries to get contents from the publisher. For instance, if we create a file abc.html directly in the dispatcher, it will report a 404 error because it doesn't exist in the publisher. If we delete a cached file in the dispatcher, say xyz.html, we can get the content directly from the publisher but no xyz.html created in the dispatcher.  At last, if we shut down the publisher, we will see "The proxy server received an invalid response from an upstream server.", a Bad Gateway message.

Any help will be appricated!

Kevin

[Asutosh_Jena_]

Hi @kevingtan 

When you are requesting for a file which is not cached in the dispatcher such as abc.html what you are observing in the dispatcher.log?
If you can share the log for a single file request from both dispatcher and publisher it will be easier to debug.

Thanks!

[kevingtan]

@Asutosh_Jena_, Thanks! I see the dispatcher takes the publisher as the first priority. It is supposed to get the local contents first, but it turns otherwise.

Here is the log, where n_t.html is the file directly created in the cache folder:

[Thu Mar 18 10:17:36 2021] [D] [40151(140249987221472)] Found farm farm1 for my-dev.nyu.edu
[Thu Mar 18 10:17:36 2021] [W] [40151(140249987221472)] Unable to connect to 12.34.56.78:443: Connection refused
[Thu Mar 18 10:17:36 2021] [W] [40151(140249987221472)] Unable to connect to any backend in farm farm1
[Thu Mar 18 10:17:37 2021] [D] [40151(140249987221472)] no backends available....retrying 1/5
[Thu Mar 18 10:17:37 2021] [W] [40151(140249987221472)] Unable to connect to 12.34.56.78:443: Connection refused
[Thu Mar 18 10:17:37 2021] [W] [40151(140249987221472)] Unable to connect to any backend in farm farm1
[Thu Mar 18 10:17:38 2021] [D] [40151(140249987221472)] no backends available....retrying 2/5
.....
[Thu Mar 18 10:17:46 2021] [I] [40151(140249987221472)] "GET /content/my-dev/n_t.html" 502 - 4002ms

[Rohit_Utreja]

@kevingtan,

You can try the below steps to overcome this issue.

1. Check if the apache user has the write permissions and ownership of cache docroot in the dispatcher.
   if the apache user is not the owner and doesn't have the write permissions to this directory, the dispatcher will not cache anything because as a part of cache creation, the dispatcher will create files inside the cache docroot directory.
2. Check the dispatcher cache rules and check what has to be cached or not.

[kevingtan]

Thanks for your help! Well, I created a file directly under the cache folder, and expect the dispatcher can serve it to the end users. Looks like it has nothing to do with permissions.

[Jaideep_Brar · Accepted solution]

• Change dispatcher.log to TRACE level
• Trigger a request and see what is getting logged for that request.
• Check if the user that is used to start dispatcher has create/edit permissions on the docroot directory
• Check if the docroot directory definition is missing in the dispatcher config.

[kevingtan]

The log tells something pretty much as expected. The dispatcher skips itself and goes directly to the publisher to request the file.

I am showing the two different environments so you can see the difference. 

Case 1, the problematic one:

I shut down the publisher. I created a file "n_t.html" directly under the cache folder, here is the log:

[Thu Mar 18 10:17:36 2021] [D] [40151(140249987221472)] Found farm farm1 for my-dev.nyu.edu
[Thu Mar 18 10:17:36 2021] [W] [40151(140249987221472)] Unable to connect to 12.34.56.78:443: Connection refused
[Thu Mar 18 10:17:36 2021] [W] [40151(140249987221472)] Unable to connect to any backend in farm farm1
[Thu Mar 18 10:17:37 2021] [D] [40151(140249987221472)] no backends available....retrying 1/5
[Thu Mar 18 10:17:37 2021] [W] [40151(140249987221472)] Unable to connect to 12.34.56.78:443: Connection refused
[Thu Mar 18 10:17:37 2021] [W] [40151(140249987221472)] Unable to connect to any backend in farm farm1
[Thu Mar 18 10:17:38 2021] [D] [40151(140249987221472)] no backends available....retrying 2/5
.....
[Thu Mar 18 10:17:46 2021] [I] [40151(140249987221472)] "GET /content/my-dev/n_t.html" 502 - 4002ms

Case 2, this one works correctly:

[Thu Mar 18 10:18:07 2021] [D] [20536(139851854460896)] Found farm farm01 for my-dev2.nyu.edu
[Thu Mar 18 10:18:07 2021] [D] [20536(139851854460896)] checking [/content/my-dev2/n_t.html]
[Thu Mar 18 10:18:07 2021] [D] [20536(139851854460896)] cache file is newer than lastflush -> use cache [/var/cache/content/my-dev2/n_t.html]
[Thu Mar 18 10:18:07 2021] [D] [20536(139851854460896)] cache-action for [/content/my-dev2/n_t.html]: DELIVER
[Thu Mar 18 10:18:07 2021] [D] [20536(139851854460896)] request declined
[Thu Mar 18 10:18:07 2021] [I] [20536(139851854460896)] "GET /content/my-dev2/n_t.html" - - 1ms
[Thu Mar 18 10:18:07 2021] [D] [20533(139851854460896)] Found farm farm01 for my-dev2.nyu.edu
....
[Thu Mar 18 10:18:07 2021] [W] [20533(139851854460896)] Unable to connect to 87.65.43.21:443: Connection refused
[Thu Mar 18 10:18:07 2021] [W] [20533(139851854460896)] Unable to connect to any backend in farm farm01
[Thu Mar 18 10:18:08 2021] [D] [20533(139851854460896)] no backends available....retrying 1/5
[Thu Mar 18 10:18:08 2021] [W] [20533(139851854460896)] Unable to connect to 87.65.43.21:443: Connection refused
.....

The problem is that the dispatcher takes the publisher as the first priority, regardless of the underlying cache folder being set or not. I am wondering which attribute in dispatcher.any can dictate this behavior. 

Thanks!