Could not determine default service host / missing configuration hints

Maybe related as well: #1906658: Processes remain in "starting" state

Thanks for your fast response!

If Background Process is configured in settings.php, then this button has no effect and should not be used.

I got the same error when nothing related to Background Process was configured in settings.php.

[…] check the webservers access logs and see if there are any requests made to /bgp-start/ […]

I grepped for "bgp-start" through Apache's complete access.log for this site, with zero results. Other sites on the same host do log stuff like:

.. "POST /bgp-start/uc%25253Axmlsitemap_taxonomy_cron/1200f5866cab56cdd08a7ad577a07095 HTTP/1.0" 200 364 "-" ...

However, the site in question does not log anything about "bgp-start". The site is pretty busy, but 'Ultimate Cron' is pretty silent.

Changes I tried:

• Removed the 'Background Process' snippet from settings.php,
• Configured $base_url in settings.php,
• Removed Crontab entry for this site,
• Re-enabled "Poormans cron" at ./admin/settings/cron/settings,
• Disabled the 'Drupal Queue API' module (can't remember why I needed this, anyway),

./admin/reports/status reports no errors; manually executed ./admin/reports/status/run-cron; Apache's access.log still does not log anything with "bgp-start". Even if settings.php now has a $base_url, ./admin/settings/background-process still claims "Could not determine default service host. Please configure background process in your settings.php". According to the post you mentioned, this variable should do the trick. Very weird…

so much to do and so little to do it in :-(

I know that feeling… Have you considered cloning? ;-)

Greetings, -asb

Thanks for the new dev release. Now I'm getting a massive amount of new entries from 'bg_process' in watchdog log. The messages are arrays like this:

Calling: http://myhost.com/bgp-start/ultimate_cron_poorman/cea6db6f113327a67982e75e14d4e6cf using options: Array
(
 [method] => POST
 [headers] => Array
 (
 [User-Agent] => Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1)
 [Accept] => text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
 [Host] => myhost.com
 [Connection] => close
 )
)

What am I supposed to look for?

Yes, I replaced the real hostname with "myhost.com"; I'm not operating the company myhost.com, so let's better call my site "myhost.tld". My site has been online for a couple of years, it has a fair number of visitors and Google Webmaster Tools do not report problems accessing the host. If there'd be a DNS misconfiguration or accessibility problem, Googlebot usually detects and reports it.

The site is hosted on a dedicated server which hosts a dozend Drupal sites, all D6 (actually Pressflow) with similar setups (caching through Memcached, APC and Boost); the system has been set up in 2011 and had no major configuration changes since then (except updates). The operating system is Debian and Apache 2.2.16's vhosts are configured in /etc/apache2/sites-enabled/. The server has exactly one IPv4 address that is set up in /etc/network/interfaces, let's call it 11.22.33.44. The Apache vhost is set up in /etc/apache2/sites-enabled/myhost, which reads like this:

NameVirtualHost 11.22.33.44:80
<VirtualHost 11.22.33.44:80>
        […]
        ServerName myhost.tld
        ServerAlias myhost.tld *.myhost.tld
        DocumentRoot /var/www/myhost
        […]
 </VirtualHost>

If I am on the remote server and do a hostname lookup for myhost.tld, the local BIND resolves correctly to the server's IP address 11.22.33.44:

$ nslookup myhost.tld
Server:         127.0.0.1
Address:        127.0.0.1#53

Non-authoritative answer:
Name:   myhost.tld
Address: 11.22.33.44

I can do the same thing from my local Linux box at home and get the same result by using a different DNS server.

There's always a remote chance of a configuration error, but I in this case there is no indication for a problem. Also it might be noteworthy that I'm regularily working on the site myhost.tld through regular Internet channels and am not encountering any issues with adding/editing content on the site. Also, Drupal's status report does not report any issues, especially not that popular HTTP request failure that would indicate some networking troubles.

I'll take a recent log entry from watchdog; 'bg_process' logs:

Calling: http://myhost.tld/bgp-start/ultimate_cron_poorman/c13d1eaa5946fac232b713fc4bd768ff using options: Array
(
 [method] => POST
 [headers] => Array
 (
 [User-Agent] => 
 [Host] => myhost.tld
 [Connection] => close
 )
)

Manually loading http://myhost.tld/bgp-start/ultimate_cron_poorman/c13d1eaa5946fac232b713fc4bd768ff results in a blank (white) page. However, this is probably not a WSOD (no corresponding record in Apache's error.log; also, raised PHP memory limit from 400M to 500M with same behaviour).

I'll try out the new dev release as it becomes available. Thanks again for your help!

Hm... it's logging tons of errors.

Could not call service uc:background_process_cron for callback _ultimate_cron_run_hook: stdClass Object […]
Not Found. The requested URL /bgp-start/uc%253Abackground_process_cron/3003da92a6d6322ec3ee4150ff45ff81 was not found on this server.

Could not call service uc:poll_cron for callback _ultimate_cron_run_hook: stdClass Object […]
Not Found. The requested URL /bgp-start/uc%253Apoll_cron/155adfd5a5bd157ba25ac20a2921663a was not found on this server.

"%253A" looks like an encoding problem, probably should be a slash ("/").

The URL it actually tries to access is "http://myhost.tld/bgp-start/uc%25253Apoll_cron/155adfd5a5bd157ba25ac20a2..."

There is an "%25253A", probably should be an underscore ("_").

Disabled "Use double encoding of URLs" at ./admin/settings/background-process/settings to check if this is an ecoding problem in the code or just in the strings submitted into watchdog.

Weird:

Could not call service ultimate_cron_poorman for callback _ultimate_cron_poorman: stdClass Object […]
Not Found. The requested URL /bgp-start/ultimate_cron_poorman/5b184e6544745617c3b55497a4a438b4 was not found on this server.

The double encodings are gone, but it still doesn't find the URL :-(

The "Handle prefix" at ./admin/settings/cron/settings was uc:, which should be the default value. Now changed to uc-, ran cron again. Still:

Could not call service ultimate_cron_poorman for callback _ultimate_cron_poorman […]
Not Found. The requested URL /bgp-start/ultimate_cron_poorman/99ef0a41e051af917da30b0d8e24e700 was not found on this server.

Should I try uc_ (with underscore) as well?

Also, it's unclear to me, if the D6 module 'Poorman's Cron' is a hidden dependency, at least I don't have it installed. Disabled "Poormans cron" at ./admin/settings/cron/settings.

I'm afraid these are two somehow different issues. The URL stub you are mentioning (/cwis/http/htdocs/cpe/bgp-start) comes from #5, a comment from 'codecrow'.

I do not have a similar URL stub in the error messages logged by watchdog (my site lives in /var/www/mysite). In my case, valid paths are requested; the requested "files" (like "99ef0a41e051af917da30b0d8e24e700") are simply not there.

> Is it other sites running Ultimate Cron […]

Yes, those are the sites I installed 'Ultimate Cron' first (there it works, same server, similar configuration).

> […] check the background_process table, to see if it is actually populated with data.

1) Table exists:

mysql> describe background_process;
+--------------+--------------+------+-----+---------+-------+
| Field        | Type         | Null | Key | Default | Extra |
+--------------+--------------+------+-----+---------+-------+
| handle       | varchar(255) | NO   | PRI | NULL    |       |
| callback     | text         | YES  |     | NULL    |       |
| args         | longblob     | YES  |     | NULL    |       |
| uid          | int(11)      | NO   |     | 0       |       |
| token        | varchar(32)  | NO   |     |         |       |
| service_host | varchar(64)  | NO   |     |         |       |
| start_stamp  | varchar(18)  | YES  |     | NULL    |       |
| exec_status  | int(11)      | NO   |     | 0       |       |
+--------------+--------------+------+-----+---------+-------+
8 rows in set (0.02 sec)

2) It contains some data (19 records):

mysql> select handle,uid,service_host,exec_status from background_process;
+--------------------------------+-----+--------------+-------------+
| handle                         | uid | service_host | exec_status |
+--------------------------------+-----+--------------+-------------+
| uc-filter_cron                 |   0 | default      |           1 |
| uc-mollom_cron                 |   0 | default      |           1 |
| uc-xmlsitemap_taxonomy_cron    |   0 | default      |           1 |
| uc-backup_migrate_cron         |   0 | default      |           1 |
| uc-update_cron                 |   0 | default      |           1 |
| uc-boost_cron                  |   0 | default      |           1 |
| uc-logintoboggan_cron          |   0 | default      |           1 |
| uc-l10n_update_cron            |   0 | default      |           1 |
| uc-votingapi_cron              |   0 | default      |           1 |
| uc-xmlsitemap_menu_cron        |   0 | default      |           1 |
| uc-amazon_cron                 |   0 | default      |           1 |
| uc-ultimate_cron_cleanup_log   |   0 | default      |           1 |
| uc-media_youtube_cron          |   0 | default      |           1 |
| uc-xmlsitemap_node_cron        |   0 | default      |           1 |
| uc-dblog_cron                  |   0 | default      |           1 |
| uc-job_scheduler_cron          |   0 | default      |           1 |
| uc-statistics_granularity_cron |   0 | default      |           1 |
| uc-system_cron                 |   0 | default      |           1 |
| uc-background_process_cron     |   0 | default      |           1 |
+--------------------------------+-----+--------------+-------------+
19 rows in set (0.00 sec)

The 'uid' colums says UID=0, which is "anon" if I recall correctly. Tried to log in user #1; switched to that account and called ./admin/reports/status/run-cron,

Green box says:

19 jobs scheduled for launch
15 jobs launched
34 jobs are currently running

At ./admin/settings/cron, red box says:

38 jobs had errors during their last run

Unlocked a task ('boost_cron'), started it manually:

boost_cron could not start (service unavailable)

Watchdog still logs "Not Found. The requested URL /bgp-start/uc-boost_cron/092ac8e02b2db462eb270a41e3f05906 was not found on this server. Apache/2.2.16 (Debian) Server at mysite.tld Port 80".

Disabled and uninstallted 'Ultimate Cron', then enabled and reinstalled it, same outcome as before.

I'll try to summarize what I've tried in the past two weeks. But first I'd like to point out that I'm not trying to use 'Ultimate Cron' just for fun, but because I have ongoing trouble with Drupal core's Cron; 'Ultimate Cron' is definiteley not the reason for those problems, but it doesn't solve them, either (at least not yet).

My assumption from a while ago was: Some job(s) supposed to be executed during Cron runs make the "Cron bundle" (as provided by Drupal core) hang; as long as one site has such a hanging job, the whole Cron daemon might be affected (from my server's syslog I can not diagnose what makes cron to not finalize it's bundles). So I took the whole server and replaced Drupal core's Cron on all Drupal 6 sites (10 sites D6, 1 site D7). On all sites, Ultimate Cron reports an "OK" according to system status, but Cron jobs are not automatically executed (overview attached); the D7 site is marginal (very small, not very busy), but core's Cron works more or less. However, with this attempt I couldn't prove my assumption.

Next I replaced 'Ultimate Cron' on one site with 'Elysia Cron', which partially works better, but doesn't execute Cron Jobs automatically as well. So basically it doesn't matter if I run Drupal core's Cron, 'Elysia Cron' or 'Ultimate Cron' with it's dependencies; the only way to get Cron jobs executed is to call ./admin/reports/status/run-cron manually (multiple times per day and on every site - great ;)

A difference between 'Ultimate Cron' and 'Elysia Cron' appears to be, that the latter seems to actually call the Cron daemon, at least it leaves traces in /var/log/syslog:

May 29 17:19:01 myserver /USR/SBIN/CRON[18420]: (root) CMD (wget -O - -q -t 1 http://mysite.tld/sites/all/modules/elysia_cron/cron.php)
May 29 17:19:01 myserver /USR/SBIN/CRON[18417]: (CRON) error (grandchild #18420 failed with exit status 8)

Exit code 8 means: "Crontab has been run with the -u option by a user other than root. Only root is allowed to use this option." I had 'Elysia Cron' installed on another site months ago, got the same error and never managed to fix it; that's thereason why I tried to move to another Cron replacement. Since 'Elysia Cron' didn't resolve the problem I switched back to 'Ultimate Cron' which now rund on all D6 sites on this server. According to my Crontab, every 5-10 minuts Cron should be called. That is not the case, syslog only logs sporadic calls of cron. However, even without 'Elysia Cron', I'm now getting Cron errors like "grandchild #24608 failed with exit status 8" which I need to investigate somehow. However, it's beyond me where Debian stores the root's crontab, who is calling it and why it suddenly & partially stopped working a couple of months ago (I set up those servers over two years ago).

Also I compared the D6 sites on another server; they show similar symptoms (mostly, Cron isn't executed automatically). Sporadically, syslog logs Cron errors over there as well, but slightly different ones: "(CRON) error (grandchild #8750 failed with exit status 4)". Exit code 4 means: "An attempt to run cron has been made by a user who does not have permission to access the crontabs in /var/cron/tabs. These files should be readable only by root, and the cron daemon must be run as root." Following this error fails since /var/cron/tabs does not even exist. crontab -e edits a temporary file like /tmp/crontab.Osc0Tl/crontab. Even stranger: Other (non-Drupal-) Cron jobs are executed properly (e.g. creating server statistics through Awstats).

Sadly no. Calling Cron via Drush results in a promising output like this:

# drush cron-run all --cli --check-rule
[logintoboggan_cron]: Launching @ 2013-07-04 15:44:45
[xmlsitemap_menu_cron]: Launching @ 2013-07-04 15:44:45
[dblog_cron]: Launching @ 2013-07-04 15:44:45
[media_youtube_cron]: Launching @ 2013-07-04 15:44:45
[xmlsitemap_node_cron]: Launching @ 2013-07-04 15:44:45
[filter_cron]: Launching @ 2013-07-04 15:44:45
[l10n_update_cron]: Launching @ 2013-07-04 15:44:45
[votingapi_cron]: Launching @ 2013-07-04 15:44:45
[boost_cron]: Launching @ 2013-07-04 15:44:45
[amazon_cron]: Launching @ 2013-07-04 15:44:45
[search_log_cron]: Launching @ 2013-07-04 15:44:45
[image_cron]: Launching @ 2013-07-04 15:44:45
[system_cron]: Launching @ 2013-07-04 15:44:45
[job_scheduler_cron]: Launching @ 2013-07-04 15:44:45
[update_cron]: Launching @ 2013-07-04 15:44:45
[statistics_granularity_cron]: Launching @ 2013-07-04 15:44:45
[ultimate_cron_cleanup_log]: Launching @ 2013-07-04 15:44:45
[background_process_ass_cron]: Launching @ 2013-07-04 15:44:45
[background_process_cron]: Launching @ 2013-07-04 15:44:45
[2013-07-04 15:44:45] Launced 19 jobs

But according to ./admin/settings/cron/overview, most of the Cron jobs remain in the usual "Starting" state.

Also I tried a different approach (calling http://mysite.org/admin/reports/status/run-cron through my local PC's Crontab), which basically resulted in a hanging Cron daemon locally. So no luck with workarounds so far.

What still puzzles me is why 'Background Process' can't identify the "Default service host". I don't know if this is important (the "The default service host to use" in the dropdown list at ./admin/settings/background-process is correct), but clicking the "Determine default service host" fails.

You mean multiple sites through one codebase? No, I have one codebase per Drupal site.

I don't intend to bug you with this, but I still don't understand if this "Determine default service host" has any relevance. If it has, I don't get why 'Background Process' seems to be unable to parse the definition given in settings.php.

Maybe the problem is what 'Background Process' considers a valid host? Technically, an URL like https://drupal.org doesn't point to a host (a proper hostnames would be www.drupal.org, mail.drupal.org or en.drupal.org). In fact, Im using on most of my sites these non-strict abbreviated hostnames like http://drupal.org. Could this be a problem?

Not sure what you mean by proper hostname? drupal.org is, to my knowledge, no less "proper" than www.drupal.org.

Yes and no. Technically, IP addresses on the Internet are resolved through the Domain Name System (DNS); in the strict sense, drupal.org is a domain name, consisting of the second-level domain (drupal) and the top-level domain (org). www.drupal.org is a proper hostname or leaf domain, drupal.org is strictly speaking a hack of the DNS records, where an A resource record directly points to a domain, not to a leaf domain:

$ dig -q drupal.org

; <<>> DiG 9.8.1-P1 <<>> -q drupal.org
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 41762
;; flags: qr rd ra; QUERY: 1, ANSWER: 2, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;drupal.org.			IN	A

;; ANSWER SECTION:
drupal.org.		1059	IN	A	140.211.10.62
drupal.org.		1059	IN	A	140.211.10.16

;; Query time: 1 msec
;; SERVER: 192.168.178.1#53(192.168.178.1)
;; WHEN: Mon Jul 15 17:08:19 2013
;; MSG SIZE  rcvd: 60

This works, as far as I know, only for HTTP/1.1 and above, because the resolution of one IP adress to multiple hostnames becomes ambiguous. HTTP can distinguish hostnames through the HTTP header, which allows Virtual hosting (= hosting multiple domain names on a single server). Before HTTP/1.1, Virtual hosting required multiple IP addresses per host (= IP-based virtual hosting), or running the webservers on different ports (= port-based virtual hosting, e.g. www.drupal.org:80 and www.drupal.org:8080). Name-based virtual hosting causes difficulties with SSL/TLS, because the SSL/TLS handshake takes place before the expected hostname is sent to the server.

So running a website without a leaf domain usually works in modern web browsers, because they can (and need to) read the HTTP host header, but other IP-based services might fail with this setup. The question is, on which network level (respectively with which protocol) 'Background Process' tries to determine the hostname and if - on this level - it has the means to get another response than the _real_ hostname of the server on which the websites are running. In my case, the hostname would be somenumber.myhostingcompany.net, and thats probably the (nonexisting) vhost where the "bgp-start" requests end up, if my suspicion is correct.

Edit: If I add the following statement to apache2.conf (according to http://wiki.apache.org/httpd/DebianDeb0rkification):

# Define an access log for VirtualHosts that don't define their own logfiles
CustomLog /var/log/apache2/other_vhosts_access.log vhost_combined

…I get this:

…:80 127.0.0.1 - - [15/Jul/2013:17:53:43 +0200] "POST /bgp-start/ultimate_cron_poorman/fe03ad3d77f9082af7c713d5ca02d56e HTTP/1.0" 404 539 "-" …
…:80 127.0.0.1 - - [15/Jul/2013:17:53:51 +0200] "POST /bgp-start/ultimate_cron_poorman/43bbc3783776e36a66b8f04f61716db9 HTTP/1.0" 404 540 "-" …
…:80 127.0.0.1 - - [15/Jul/2013:17:54:13 +0200] "POST /bgp-start/ultimate_cron_poorman/65288ae6926bce9418de77a54f308c67 HTTP/1.0" 404 544 "-" …
…:80 127.0.0.1 - - [15/Jul/2013:17:54:22 +0200] "POST /bgp-start/ultimate_cron_poorman/bf971315b2fc599d8b9f929aae2b2be2 HTTP/1.0" 404 542 "-" …

The part after the POST record are the HTTP status code (here: 404) and the size of response in bytes (here: 539, 544, 542). So, page not found on somenumber.myhostingcompany.net; still doesn't prove anything :(

Sorry, I'm not sure I understand the question. In Apache's configuration of the vhosts, IP addresses are used. E.g.:

NameVirtualHost 11.22.33.44:80
<VirtualHost 11.22.33.44:80>
  ServerName mysitesdomainname.tld
  […]
</VirtualHost>

The access log of the default vhost (or whatever "other_vhosts_access.log" logs in Debian) does neither log the IP address defined in "NameVirtualHost" or "VirtualHost" (11.22.33.44), nor in "ServerName" (mysitesdomainname.tld). It logs the default name of the server that is given by the ISP. This name resolves to 11.22.33.44 (multihomed server), but it's not using mysitesdomainname.tld. That's wht I meant in #28 ("Name-based virtual hosting causes difficulties…").

Sure, cron is still not executed on most sites. However, we might close the issue as "won't fix" if none of us has any idea how to resolve it.