Cancle build api sometimes fail, it's more and more frequently

Hey guys,

I noticed that after our systems were kicked, at the last step, it will
call foreman API to let it cancel build for this host, but for some reason,
it failed to do this and our system got re-installed again and again if we
don't manually cancel the build status for this host, from the log, we saw:
10.241.81.4 - - [13/Jan/2016:11:49:49 +0800] "GET
/unattended/built?token=70816149-f13f-426a-adbb-cdc56ce87aaf HTTP/1.0" 404
1 "-" "Wget/1.12 (linux-gnu)"
10.241.81.5 - - [13/Jan/2016:11:56:12 +0800] "GET
/unattended/built?token=11fe039c-09e4-4232-912e-227482ca1835 HTTP/1.0" 404
1 "-" "Wget/1.12 (linux-gnu)"
10.241.81.6 - - [13/Jan/2016:12:00:25 +0800] "GET
/unattended/built?token=0305ae75-0730-4ab5-9358-6dda4c993290 HTTP/1.0" 404
1 "-" "Wget/1.12 (linux-gnu)"
10.241.81.21 - - [13/Jan/2016:12:03:30 +0800] "GET
/unattended/built?token=78a76cbd-73c7-4599-a68b-bfbbab66a9e0 HTTP/1.0" 404
1 "-" "Wget/1.12 (linux-gnu)"
10.241.81.16 - - [13/Jan/2016:12:06:38 +0800] "GET
/unattended/built?token=3fadde62-7d87-4db7-a879-028ba94ad873 HTTP/1.0" 404
1 "-" "Wget/1.12 (linux-gnu)"
10.241.81.4 - - [13/Jan/2016:12:09:30 +0800] "GET
/unattended/built?token=70816149-f13f-426a-adbb-cdc56ce87aaf HTTP/1.0" 404
1 "-" "Wget/1.12 (linux-gnu)"

why it happened? Any one has any ideas?

Thanks
-Sinux

Some more information from the logs would be useful. Each request is
logged in /var/log/foreman/production.log, it should help indicate why
the status is 404.

··· On 13/01/16 14:44, sinux shen wrote: > Hey guys, > > I noticed that after our systems were kicked, at the last step, it will > call foreman API to let it cancel build for this host, but for some > reason, it failed to do this and our system got re-installed again and > again if we don't manually cancel the build status for this host, from > the log, we saw: > 10.241.81.4 - - [13/Jan/2016:11:49:49 +0800] "GET > /unattended/built?token=70816149-f13f-426a-adbb-cdc56ce87aaf HTTP/1.0" > 404 1 "-" "Wget/1.12 (linux-gnu)" > 10.241.81.5 - - [13/Jan/2016:11:56:12 +0800] "GET > /unattended/built?token=11fe039c-09e4-4232-912e-227482ca1835 HTTP/1.0" > 404 1 "-" "Wget/1.12 (linux-gnu)" > 10.241.81.6 - - [13/Jan/2016:12:00:25 +0800] "GET > /unattended/built?token=0305ae75-0730-4ab5-9358-6dda4c993290 HTTP/1.0" > 404 1 "-" "Wget/1.12 (linux-gnu)" > 10.241.81.21 - - [13/Jan/2016:12:03:30 +0800] "GET > /unattended/built?token=78a76cbd-73c7-4599-a68b-bfbbab66a9e0 HTTP/1.0" > 404 1 "-" "Wget/1.12 (linux-gnu)" > 10.241.81.16 - - [13/Jan/2016:12:06:38 +0800] "GET > /unattended/built?token=3fadde62-7d87-4db7-a879-028ba94ad873 HTTP/1.0" > 404 1 "-" "Wget/1.12 (linux-gnu)" > 10.241.81.4 - - [13/Jan/2016:12:09:30 +0800] "GET > /unattended/built?token=70816149-f13f-426a-adbb-cdc56ce87aaf HTTP/1.0" > 404 1 "-" "Wget/1.12 (linux-gnu)" > > why it happened? Any one has any ideas?


Dominic Cleal
dominic@cleal.org

oh, let me check

··· On Wednesday, January 13, 2016 at 10:46:44 PM UTC+8, Dominic Cleal wrote: > > On 13/01/16 14:44, sinux shen wrote: > > Hey guys, > > > > I noticed that after our systems were kicked, at the last step, it will > > call foreman API to let it cancel build for this host, but for some > > reason, it failed to do this and our system got re-installed again and > > again if we don't manually cancel the build status for this host, from > > the log, we saw: > > 10.241.81.4 - - [13/Jan/2016:11:49:49 +0800] "GET > > /unattended/built?token=70816149-f13f-426a-adbb-cdc56ce87aaf HTTP/1.0" > > 404 1 "-" "Wget/1.12 (linux-gnu)" > > 10.241.81.5 - - [13/Jan/2016:11:56:12 +0800] "GET > > /unattended/built?token=11fe039c-09e4-4232-912e-227482ca1835 HTTP/1.0" > > 404 1 "-" "Wget/1.12 (linux-gnu)" > > 10.241.81.6 - - [13/Jan/2016:12:00:25 +0800] "GET > > /unattended/built?token=0305ae75-0730-4ab5-9358-6dda4c993290 HTTP/1.0" > > 404 1 "-" "Wget/1.12 (linux-gnu)" > > 10.241.81.21 - - [13/Jan/2016:12:03:30 +0800] "GET > > /unattended/built?token=78a76cbd-73c7-4599-a68b-bfbbab66a9e0 HTTP/1.0" > > 404 1 "-" "Wget/1.12 (linux-gnu)" > > 10.241.81.16 - - [13/Jan/2016:12:06:38 +0800] "GET > > /unattended/built?token=3fadde62-7d87-4db7-a879-028ba94ad873 HTTP/1.0" > > 404 1 "-" "Wget/1.12 (linux-gnu)" > > 10.241.81.4 - - [13/Jan/2016:12:09:30 +0800] "GET > > /unattended/built?token=70816149-f13f-426a-adbb-cdc56ce87aaf HTTP/1.0" > > 404 1 "-" "Wget/1.12 (linux-gnu)" > > > > why it happened? Any one has any ideas? > > Some more information from the logs would be useful. Each request is > logged in /var/log/foreman/production.log, it should help indicate why > the status is 404. > > -- > Dominic Cleal > dom...@cleal.org >

This is one of the failed one that I found in the production.log:

> Started GET
"/unattended/built?token=0106926d-9830-4c80-a68c-ba92e56811f4" for
10.241.80.237 at 2016-01-13 17:12:43 +0800
2016-01-13 17:12:43 [app] [I] Processing by UnattendedController#built as
/
2016-01-13 17:12:43 [app] [I] Parameters:
{"token"=>"0106926d-9830-4c80-a68c-ba92e56811f4"}
2016-01-13 17:12:43 [app] [I] Found ih20218.anim.odw.com.cn
2016-01-13 17:12:43 [app] [I] Filter chain halted as :allowed_to_install?
rendered or redirected
2016-01-13 17:12:43 [app] [I] Completed 405 Method Not Allowed in 10ms
(ActiveRecord: 2.1ms)
2016-01-13 17:12:43 [app] [I]

··· On Wednesday, January 13, 2016 at 11:02:25 PM UTC+8, sinux shen wrote: > > > oh, let me check > On Wednesday, January 13, 2016 at 10:46:44 PM UTC+8, Dominic Cleal wrote: >> >> On 13/01/16 14:44, sinux shen wrote: >> > Hey guys, >> > >> > I noticed that after our systems were kicked, at the last step, it will >> > call foreman API to let it cancel build for this host, but for some >> > reason, it failed to do this and our system got re-installed again and >> > again if we don't manually cancel the build status for this host, from >> > the log, we saw: >> > 10.241.81.4 - - [13/Jan/2016:11:49:49 +0800] "GET >> > /unattended/built?token=70816149-f13f-426a-adbb-cdc56ce87aaf HTTP/1.0" >> > 404 1 "-" "Wget/1.12 (linux-gnu)" >> > 10.241.81.5 - - [13/Jan/2016:11:56:12 +0800] "GET >> > /unattended/built?token=11fe039c-09e4-4232-912e-227482ca1835 HTTP/1.0" >> > 404 1 "-" "Wget/1.12 (linux-gnu)" >> > 10.241.81.6 - - [13/Jan/2016:12:00:25 +0800] "GET >> > /unattended/built?token=0305ae75-0730-4ab5-9358-6dda4c993290 HTTP/1.0" >> > 404 1 "-" "Wget/1.12 (linux-gnu)" >> > 10.241.81.21 - - [13/Jan/2016:12:03:30 +0800] "GET >> > /unattended/built?token=78a76cbd-73c7-4599-a68b-bfbbab66a9e0 HTTP/1.0" >> > 404 1 "-" "Wget/1.12 (linux-gnu)" >> > 10.241.81.16 - - [13/Jan/2016:12:06:38 +0800] "GET >> > /unattended/built?token=3fadde62-7d87-4db7-a879-028ba94ad873 HTTP/1.0" >> > 404 1 "-" "Wget/1.12 (linux-gnu)" >> > 10.241.81.4 - - [13/Jan/2016:12:09:30 +0800] "GET >> > /unattended/built?token=70816149-f13f-426a-adbb-cdc56ce87aaf HTTP/1.0" >> > 404 1 "-" "Wget/1.12 (linux-gnu)" >> > >> > why it happened? Any one has any ideas? >> >> Some more information from the logs would be useful. Each request is >> logged in /var/log/foreman/production.log, it should help indicate why >> the status is 404. >> >> -- >> Dominic Cleal >> dom...@cleal.org >> >

Also, this one is for 404 return code:

2016-01-13 14:44:10 [app] [I] Processing by UnattendedController#built as
/
2016-01-13 14:44:10 [app] [I] Parameters:
{"token"=>"94839e1b-a9b8-4b6a-a8e2-b225e818a0d5"}
2016-01-13 14:44:10 [app] [I] unattended: unable to find a host that
matches the request from 10.241.81.19
2016-01-13 14:44:10 [app] [I] Filter chain halted as :get_host_details
rendered or redirected
2016-01-13 14:44:10 [app] [I] Completed 404 Not Found in 7ms (ActiveRecord:
1.6ms)
2016-01-13 14:44:10 [app] [I]

··· On Wednesday, January 13, 2016 at 11:06:21 PM UTC+8, sinux shen wrote: > > This is one of the failed one that I found in the production.log: > > > Started GET > "/unattended/built?token=0106926d-9830-4c80-a68c-ba92e56811f4" for > 10.241.80.237 at 2016-01-13 17:12:43 +0800 > 2016-01-13 17:12:43 [app] [I] Processing by UnattendedController#built as > */* > 2016-01-13 17:12:43 [app] [I] Parameters: > {"token"=>"0106926d-9830-4c80-a68c-ba92e56811f4"} > 2016-01-13 17:12:43 [app] [I] Found ih20218.anim.odw.com.cn > 2016-01-13 17:12:43 [app] [I] Filter chain halted as :allowed_to_install? > rendered or redirected > 2016-01-13 17:12:43 [app] [I] Completed 405 Method Not Allowed in 10ms > (ActiveRecord: 2.1ms) > 2016-01-13 17:12:43 [app] [I] > > On Wednesday, January 13, 2016 at 11:02:25 PM UTC+8, sinux shen wrote: >> >> >> oh, let me check >> On Wednesday, January 13, 2016 at 10:46:44 PM UTC+8, Dominic Cleal wrote: >>> >>> On 13/01/16 14:44, sinux shen wrote: >>> > Hey guys, >>> > >>> > I noticed that after our systems were kicked, at the last step, it >>> will >>> > call foreman API to let it cancel build for this host, but for some >>> > reason, it failed to do this and our system got re-installed again and >>> > again if we don't manually cancel the build status for this host, from >>> > the log, we saw: >>> > 10.241.81.4 - - [13/Jan/2016:11:49:49 +0800] "GET >>> > /unattended/built?token=70816149-f13f-426a-adbb-cdc56ce87aaf HTTP/1.0" >>> > 404 1 "-" "Wget/1.12 (linux-gnu)" >>> > 10.241.81.5 - - [13/Jan/2016:11:56:12 +0800] "GET >>> > /unattended/built?token=11fe039c-09e4-4232-912e-227482ca1835 HTTP/1.0" >>> > 404 1 "-" "Wget/1.12 (linux-gnu)" >>> > 10.241.81.6 - - [13/Jan/2016:12:00:25 +0800] "GET >>> > /unattended/built?token=0305ae75-0730-4ab5-9358-6dda4c993290 HTTP/1.0" >>> > 404 1 "-" "Wget/1.12 (linux-gnu)" >>> > 10.241.81.21 - - [13/Jan/2016:12:03:30 +0800] "GET >>> > /unattended/built?token=78a76cbd-73c7-4599-a68b-bfbbab66a9e0 HTTP/1.0" >>> > 404 1 "-" "Wget/1.12 (linux-gnu)" >>> > 10.241.81.16 - - [13/Jan/2016:12:06:38 +0800] "GET >>> > /unattended/built?token=3fadde62-7d87-4db7-a879-028ba94ad873 HTTP/1.0" >>> > 404 1 "-" "Wget/1.12 (linux-gnu)" >>> > 10.241.81.4 - - [13/Jan/2016:12:09:30 +0800] "GET >>> > /unattended/built?token=70816149-f13f-426a-adbb-cdc56ce87aaf HTTP/1.0" >>> > 404 1 "-" "Wget/1.12 (linux-gnu)" >>> > >>> > why it happened? Any one has any ideas? >>> >>> Some more information from the logs would be useful. Each request is >>> logged in /var/log/foreman/production.log, it should help indicate why >>> the status is 404. >>> >>> -- >>> Dominic Cleal >>> dom...@cleal.org >>> >>

> This is one of the failed one that I found in the production.log:
>
> > Started GET
> "/unattended/built?token=0106926d-9830-4c80-a68c-ba92e56811f4" for
> 10.241.80.237 at 2016-01-13 17:12:43 +0800
> 2016-01-13 17:12:43 [app] [I] Processing by UnattendedController#built
> as /
> 2016-01-13 17:12:43 [app] [I] Parameters:
> {"token"=>"0106926d-9830-4c80-a68c-ba92e56811f4"}
> 2016-01-13 17:12:43 [app] [I] Found ih20218.anim.odw.com.cn
> 2016-01-13 17:12:43 [app] [I] Filter chain halted as
> :allowed_to_install? rendered or redirected

This line with "allowed_to_install" indicates the host (name in the line
above, ih20218…) is not in the build state, so it's unexpected.

I'd suggest either - this is being called twice (so look for more
instances with the same token and/or hostname), or it was called after
somebody had already cancelled the build.

> 2016-01-13 17:12:43 [app] [I] Completed 405 Method Not Allowed in 10ms
> (ActiveRecord: 2.1ms)

The log earlier showed a 404 status, so this doesn't quite match. It
might be useful to dig out all of the logs from the same host, and
ensure you don't hit cancel build when testing.

··· On 13/01/16 15:06, sinux shen wrote:


Dominic Cleal
dominic@cleal.org

This indicates the request is from an unknown host. A few possibilities:

  1. The build was already cancelled before the host called that URL,
    which would delete the token so it's unknown.

  2. The build took so long that the token expired. Check
    "token_duration" in Administer > Settings is long enough for your whole
    host creation and build process - the value is in minutes.

  3. One of the above, and the IP address 10.241.81.19 doesn't match the
    one registered for the host. This isn't critical, but if the token
    and the IP aren't known, then Foreman can't identify it.

··· On 13/01/16 15:10, sinux shen wrote: > Also, this one is for 404 return code: > > 2016-01-13 14:44:10 [app] [I] Processing by UnattendedController#built > as */* > 2016-01-13 14:44:10 [app] [I] Parameters: > {"token"=>"94839e1b-a9b8-4b6a-a8e2-b225e818a0d5"} > 2016-01-13 14:44:10 [app] [I] unattended: unable to find a host that > matches the request from 10.241.81.19 > 2016-01-13 14:44:10 [app] [I] Filter chain halted as :get_host_details > rendered or redirected


Dominic Cleal
dominic@cleal.org

today, I was doing a batch installation, around 7 hosts, and no one call
this API successfully, so I have to manually cancel all of them to stop the
re-installation.

I will try to stick on one machine and see what happened.

Thanks Dom

··· On Wednesday, January 13, 2016 at 11:09:13 PM UTC+8, Dominic Cleal wrote: > > On 13/01/16 15:06, sinux shen wrote: > > This is one of the failed one that I found in the production.log: > > > > > Started GET > > "/unattended/built?token=0106926d-9830-4c80-a68c-ba92e56811f4" for > > 10.241.80.237 at 2016-01-13 17:12:43 +0800 > > 2016-01-13 17:12:43 [app] [I] Processing by UnattendedController#built > > as */* > > 2016-01-13 17:12:43 [app] [I] Parameters: > > {"token"=>"0106926d-9830-4c80-a68c-ba92e56811f4"} > > 2016-01-13 17:12:43 [app] [I] Found ih20218.anim.odw.com.cn > > 2016-01-13 17:12:43 [app] [I] Filter chain halted as > > :allowed_to_install? rendered or redirected > > This line with "allowed_to_install" indicates the host (name in the line > above, ih20218...) is not in the build state, so it's unexpected. > > I'd suggest either - this is being called twice (so look for more > instances with the same token and/or hostname), or it was called after > somebody had already cancelled the build. > > > 2016-01-13 17:12:43 [app] [I] Completed 405 Method Not Allowed in 10ms > > (ActiveRecord: 2.1ms) > > The log earlier showed a 404 status, so this doesn't quite match. It > might be useful to dig out all of the logs from the same host, and > ensure you don't hit cancel build when testing. > > -- > Dominic Cleal > dom...@cleal.org >

I ran a quick test, I build a system, and during the build, I found the pxe
file for that hosts and find the kickstart URL, and then I access that url
in browser and it returned 404, I didn't click any cancel build stuff, so I
suspect once the system finished the build and call the API, it will get
the same result

··· On Wednesday, January 13, 2016 at 11:13:02 PM UTC+8, Dominic Cleal wrote: > > On 13/01/16 15:10, sinux shen wrote: > > Also, this one is for 404 return code: > > > > 2016-01-13 14:44:10 [app] [I] Processing by UnattendedController#built > > as */* > > 2016-01-13 14:44:10 [app] [I] Parameters: > > {"token"=>"94839e1b-a9b8-4b6a-a8e2-b225e818a0d5"} > > 2016-01-13 14:44:10 [app] [I] unattended: unable to find a host that > > matches the request from 10.241.81.19 > > 2016-01-13 14:44:10 [app] [I] Filter chain halted as :get_host_details > > rendered or redirected > > This indicates the request is from an unknown host. A few possibilities: > > 1) The build was already cancelled before the host called that URL, > which would delete the token so it's unknown. > > 2) The build took so long that the token expired. Check > "token_duration" in Administer > Settings is long enough for your whole > host creation and build process - the value is in minutes. > > 3) One of the above, *and* the IP address 10.241.81.19 doesn't match the > one registered for the host. This isn't critical, but if the token > *and* the IP aren't known, then Foreman can't identify it. > > -- > Dominic Cleal > dom...@cleal.org >

This is the log all about the test machine I did:
foreman ODW [/var/log/foreman] 1025# cat production.log | grep -A 5
7aa5557ccfe3
> Started GET
"/unattended/provision?token=7a89e693-281b-4742-a1e8-7aa5557ccfe3" for
10.241.81.62 at 2016-01-13 23:20:59 +0800
2016-01-13 23:20:59 [app] [I] Processing by UnattendedController#provision
as /
2016-01-13 23:20:59 [app] [I] Parameters:
{"token"=>"7a89e693-281b-4742-a1e8-7aa5557ccfe3"}
2016-01-13 23:20:59 [app] [I] Found ih20241.anim.odw.com.cn
2016-01-13 23:20:59 [sql] [I] Remove puppet certificate for
ih20241.anim.odw.com.cn
2016-01-13 23:21:00 [sql] [I] Adding autosign entry for
ih20241.anim.odw.com.cn
2016-01-13 23:21:00 [app] [I] Rendered inline template (148.1ms)
2016-01-13 23:21:00 [app] [I] Completed 200 OK in 1506ms (Views: 141.9ms |
ActiveRecord: 17.1ms)

··· -- > Started GET "/unattended/provision?token=7a89e693-281b-4742-a1e8-7aa5557ccfe3" for 10.241.125.10 at 2016-01-13 23:27:22 +0800 2016-01-13 23:27:22 [app] [I] Processing by UnattendedController#provision as HTML 2016-01-13 23:27:22 [app] [I] Parameters: {"token"=>"7a89e693-281b-4742-a1e8-7aa5557ccfe3"} 2016-01-13 23:27:22 [app] [I] unattended: unable to find a host that matches the request from 10.241.125.10 2016-01-13 23:27:22 [app] [I] Filter chain halted as :get_host_details rendered or redirected 2016-01-13 23:27:22 [app] [I] Completed 404 Not Found in 6ms (ActiveRecord: 1.5ms) 2016-01-13 23:27:24 [app] [I] > -- > Started GET "/unattended/provision?token=7a89e693-281b-4742-a1e8-7aa5557ccfe3" for 10.241.125.10 at 2016-01-13 23:28:13 +0800 2016-01-13 23:28:13 [app] [I] Processing by UnattendedController#provision as HTML 2016-01-13 23:28:13 [app] [I] Parameters: {"token"=>"7a89e693-281b-4742-a1e8-7aa5557ccfe3"} 2016-01-13 23:28:13 [app] [I] unattended: unable to find a host that matches the request from 10.241.125.10 2016-01-13 23:28:13 [app] [I] Filter chain halted as :get_host_details rendered or redirected 2016-01-13 23:28:13 [app] [I] Completed 404 Not Found in 7ms (ActiveRecord: 1.6ms) 2016-01-13 23:28:13 [app] [I] > -- > Started GET "/unattended/provision?token=7a89e693-281b-4742-a1e8-7aa5557ccfe3" for 10.241.125.10 at 2016-01-13 23:28:57 +0800 2016-01-13 23:28:57 [app] [I] Processing by UnattendedController#provision as HTML 2016-01-13 23:28:57 [app] [I] Parameters: {"token"=>"7a89e693-281b-4742-a1e8-7aa5557ccfe3"} 2016-01-13 23:28:57 [app] [I] unattended: unable to find a host that matches the request from 10.241.125.10 2016-01-13 23:28:57 [app] [I] Filter chain halted as :get_host_details rendered or redirected 2016-01-13 23:28:57 [app] [I] Completed 404 Not Found in 8ms (ActiveRecord: 1.6ms) 2016-01-13 23:28:57 [app] [I] > -- > Started GET "/unattended/provision?token=7a89e693-281b-4742-a1e8-7aa5557ccfe3" for 10.241.125.10 at 2016-01-13 23:36:50 +0800 2016-01-13 23:36:50 [app] [I] Processing by UnattendedController#provision as HTML 2016-01-13 23:36:50 [app] [I] Parameters: {"token"=>"7a89e693-281b-4742-a1e8-7aa5557ccfe3"} 2016-01-13 23:36:50 [app] [I] unattended: unable to find a host that matches the request from 10.241.125.10 2016-01-13 23:36:50 [app] [I] Filter chain halted as :get_host_details rendered or redirected 2016-01-13 23:36:50 [app] [I] Completed 404 Not Found in 7ms (ActiveRecord: 1.6ms) 2016-01-13 23:36:52 [app] [I] > -- > Started GET "/unattended/built?token=7a89e693-281b-4742-a1e8-7aa5557ccfe3" for 10.241.81.62 at 2016-01-13 23:37:04 +0800 2016-01-13 23:37:04 [app] [I] Processing by UnattendedController#built as */* 2016-01-13 23:37:04 [app] [I] Parameters: {"token"=>"7a89e693-281b-4742-a1e8-7aa5557ccfe3"} 2016-01-13 23:37:04 [app] [I] unattended: unable to find a host that matches the request from 10.241.81.62 2016-01-13 23:37:04 [app] [I] Filter chain halted as :get_host_details rendered or redirected 2016-01-13 23:37:04 [app] [I] Completed 404 Not Found in 8ms (ActiveRecord: 1.6ms) 2016-01-13 23:37:04 [app] [I]

I access the url couple of times with safari and firefox, all return 404,
and after the system was built, the status in foreman was still “cancel
built” which was wrong

On Wednesday, January 13, 2016 at 11:34:52 PM UTC+8, sinux shen wrote:

I ran a quick test, I build a system, and during the build, I found the
pxe file for that hosts and find the kickstart URL, and then I access that
url in browser and it returned 404, I didn’t click any cancel build stuff,
so I suspect once the system finished the build and call the API, it will
get the same result

On Wednesday, January 13, 2016 at 11:13:02 PM UTC+8, Dominic Cleal wrote:

On 13/01/16 15:10, sinux shen wrote:

Also, this one is for 404 return code:

2016-01-13 14:44:10 [app] [I] Processing by UnattendedController#built
as /
2016-01-13 14:44:10 [app] [I] Parameters:
{“token”=>“94839e1b-a9b8-4b6a-a8e2-b225e818a0d5”}
2016-01-13 14:44:10 [app] [I] unattended: unable to find a host that
matches the request from 10.241.81.19
2016-01-13 14:44:10 [app] [I] Filter chain halted as :get_host_details
rendered or redirected

This indicates the request is from an unknown host. A few possibilities:

  1. The build was already cancelled before the host called that URL,
    which would delete the token so it’s unknown.

  2. The build took so long that the token expired. Check
    "token_duration" in Administer > Settings is long enough for your whole
    host creation and build process - the value is in minutes.

  3. One of the above, and the IP address 10.241.81.19 doesn’t match the
    one registered for the host. This isn’t critical, but if the token
    and the IP aren’t known, then Foreman can’t identify it.


Dominic Cleal
dom...@cleal.org

Did you check the token_duration setting that I mentioned earlier?
What's the value?

I would strongly recommend not accessing the provision URL during build
from a browser as it could invalidate Puppet certs etc. For it to fail
with a 404 though suggests that the token you're using is invalid or
expired.

If it's an anaconda based OS install, then this still suggests the token
has expired and the IP address logged (.62) is not the one registered
for the host's provisioning interface.

··· -- Dominic Cleal dominic@cleal.org

On 13/01/16 15:44, sinux shen wrote:

This is the log all about the test machine I did:
foreman ODW [/var/log/foreman] 1025# cat production.log | grep -A 5
7aa5557ccfe3

Started GET
"/unattended/provision?token=7a89e693-281b-4742-a1e8-7aa5557ccfe3" for
10.241.81.62 at 2016-01-13 23:20:59 +0800
2016-01-13 23:20:59 [app] [I] Processing by
UnattendedController#provision as /
2016-01-13 23:20:59 [app] [I] Parameters:
{“token”=>“7a89e693-281b-4742-a1e8-7aa5557ccfe3”}
2016-01-13 23:20:59 [app] [I] Found ih20241.anim.odw.com.cn
2016-01-13 23:20:59 [sql] [I] Remove puppet certificate for
ih20241.anim.odw.com.cn
2016-01-13 23:21:00 [sql] [I] Adding autosign entry for
ih20241.anim.odw.com.cn
2016-01-13 23:21:00 [app] [I] Rendered inline template (148.1ms)
2016-01-13 23:21:00 [app] [I] Completed 200 OK in 1506ms (Views: 141.9ms
ActiveRecord: 17.1ms)

Started GET
"/unattended/provision?token=7a89e693-281b-4742-a1e8-7aa5557ccfe3" for
10.241.125.10 at 2016-01-13 23:27:22 +0800
2016-01-13 23:27:22 [app] [I] Processing by
UnattendedController#provision as HTML
2016-01-13 23:27:22 [app] [I] Parameters:
{“token”=>“7a89e693-281b-4742-a1e8-7aa5557ccfe3”}
2016-01-13 23:27:22 [app] [I] unattended: unable to find a host that
matches the request from 10.241.125.10
2016-01-13 23:27:22 [app] [I] Filter chain halted as :get_host_details
rendered or redirected
2016-01-13 23:27:22 [app] [I] Completed 404 Not Found in 6ms
(ActiveRecord: 1.5ms)
2016-01-13 23:27:24 [app] [I]

Hi, Dom,

Yes, the token_duration does expired as I added those host 24 hours ago,
that did the trick, thanks for your help!!

-Sinux

··· On Wednesday, January 13, 2016 at 11:50:54 PM UTC+8, Dominic Cleal wrote: > > Did you check the token_duration setting that I mentioned earlier? > What's the value? > > I would strongly recommend not accessing the provision URL during build > from a browser as it could invalidate Puppet certs etc. For it to fail > with a 404 though suggests that the token you're using is invalid or > expired. > > If it's an anaconda based OS install, then this still suggests the token > has expired and the IP address logged (.62) is not the one registered > for the host's provisioning interface. > > -- > Dominic Cleal > dom...@cleal.org > > On 13/01/16 15:44, sinux shen wrote: > > This is the log all about the test machine I did: > > foreman ODW [/var/log/foreman] 1025# cat production.log | grep -A 5 > > 7aa5557ccfe3 > > > Started GET > > "/unattended/provision?token=7a89e693-281b-4742-a1e8-7aa5557ccfe3" for > > 10.241.81.62 at 2016-01-13 23:20:59 +0800 > > 2016-01-13 23:20:59 [app] [I] Processing by > > UnattendedController#provision as */* > > 2016-01-13 23:20:59 [app] [I] Parameters: > > {"token"=>"7a89e693-281b-4742-a1e8-7aa5557ccfe3"} > > 2016-01-13 23:20:59 [app] [I] Found ih20241.anim.odw.com.cn > > 2016-01-13 23:20:59 [sql] [I] Remove puppet certificate for > > ih20241.anim.odw.com.cn > > 2016-01-13 23:21:00 [sql] [I] Adding autosign entry for > > ih20241.anim.odw.com.cn > > 2016-01-13 23:21:00 [app] [I] Rendered inline template (148.1ms) > > 2016-01-13 23:21:00 [app] [I] Completed 200 OK in 1506ms (Views: 141.9ms > > > ActiveRecord: 17.1ms) > > -- > > > Started GET > > "/unattended/provision?token=7a89e693-281b-4742-a1e8-7aa5557ccfe3" for > > 10.241.125.10 at 2016-01-13 23:27:22 +0800 > > 2016-01-13 23:27:22 [app] [I] Processing by > > UnattendedController#provision as HTML > > 2016-01-13 23:27:22 [app] [I] Parameters: > > {"token"=>"7a89e693-281b-4742-a1e8-7aa5557ccfe3"} > > 2016-01-13 23:27:22 [app] [I] unattended: unable to find a host that > > matches the request from 10.241.125.10 > > 2016-01-13 23:27:22 [app] [I] Filter chain halted as :get_host_details > > rendered or redirected > > 2016-01-13 23:27:22 [app] [I] Completed 404 Not Found in 6ms > > (ActiveRecord: 1.5ms) > > 2016-01-13 23:27:24 [app] [I] > > >