[
https://issues.apache.org/jira/browse/VCL-998?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Andy Kurth updated VCL-998:
---------------------------
Description:
{noformat}|inuse|utils.pm:database_select|2820| ---- WARNING ----
|inuse|utils.pm:database_select|2820| 2016-10-18
22:53:23|inuse|utils.pm:database_select|2820|could not execute statement on vcl
database, SELECT
|inuse|utils.pm:database_select|2820| state.name AS state_name,
|inuse|utils.pm:database_select|2820| laststate.name AS laststate_name
|inuse|utils.pm:database_select|2820| FROM
|inuse|utils.pm:database_select|2820| request,
|inuse|utils.pm:database_select|2820| state,
|inuse|utils.pm:database_select|2820| state laststate
|inuse|utils.pm:database_select|2820| WHERE
|inuse|utils.pm:database_select|2820| request.id = 3008649
|inuse|utils.pm:database_select|2820| AND request.stateid = state.id
|inuse|utils.pm:database_select|2820| AND request.laststateid = laststate.id
|inuse|utils.pm:database_select|2820| error: Lost connection to MySQL server
during query
|inuse|utils.pm:database_select|2820| ( 0) utils.pm, database_select (line:
2820)
|inuse|utils.pm:database_select|2820| (-1) utils.pm,
get_request_current_state_name (line: 5394)
|inuse|utils.pm:database_select|2820| (-2) utils.pm, is_request_deleted (line:
1682)
|inuse|utils.pm:database_select|2820| (-3) State.pm, user_connected (line: 266)
|inuse|utils.pm:database_select|2820| (-4) inuse.pm, __ANON__ (line: 306)
|inuse|utils.pm:database_select|2820| (-5) Module.pm, code_loop_timeout (line:
1504)
|inuse|utils.pm:get_request_current_state_name|5398| ---- WARNING ----
|inuse|utils.pm:get_request_current_state_name|5398| 2016-10-18
22:53:23|inuse|utils.pm:get_request_current_state_name|5398|unable to determine
current state of request 3008649, zero rows were returned from database select
|inuse|utils.pm:get_request_current_state_name|5398| ( 0) utils.pm,
get_request_current_state_name (line: 5398)
|inuse|utils.pm:get_request_current_state_name|5398| (-1) utils.pm,
is_request_deleted (line: 1682)
|inuse|utils.pm:get_request_current_state_name|5398| (-2) State.pm,
user_connected (line: 266)
|inuse|utils.pm:get_request_current_state_name|5398| (-3) inuse.pm, __ANON__
(line: 306)
|inuse|utils.pm:get_request_current_state_name|5398| (-4) Module.pm,
code_loop_timeout (line: 1504)
|inuse|utils.pm:get_request_current_state_name|5398| (-5) inuse.pm, process
(line: 306)
|inuse|utils.pm:is_request_deleted|1684| ---- WARNING ----
|inuse|utils.pm:is_request_deleted|1684| 2016-10-18
22:53:23|inuse|utils.pm:is_request_deleted|1684|request 3008649 state data
could not be retrieved, assuming request is deleted and was removed from the
database, returning true
|inuse|utils.pm:is_request_deleted|1684| ( 0) utils.pm, is_request_deleted
(line: 1684)
|inuse|utils.pm:is_request_deleted|1684| (-1) State.pm, user_connected (line:
266)
|inuse|utils.pm:is_request_deleted|1684| (-2) inuse.pm, __ANON__ (line: 306)
|inuse|utils.pm:is_request_deleted|1684| (-3) Module.pm, code_loop_timeout
(line: 1504)
|inuse|utils.pm:is_request_deleted|1684| (-4) inuse.pm, process (line: 306)
|inuse|utils.pm:is_request_deleted|1684| (-5) vcld, make_new_child (line: 602)
2016-10-18 22:53:23|inuse|State.pm:state_exit|863|beginning state module exit
tasks
|inuse|State.pm:state_exit|863| request state argument: <not specified>
|inuse|State.pm:state_exit|863| computer state argument: <not specified>
|inuse|State.pm:state_exit|863| log ending argument: <not specified>
{noformat}
As shown above, while retrieving the current request state an error occurred:
{color:red}*error: Lost connection to MySQL server during query*{color}
The process was able to connect to the database a few seconds later. I believe
this is a very rare situation but we could add some logic to
*State.pm:state_exit* to prevent processes from exiting if the current state in
the database is likely _pending_.
This isn't a major problem because the code eventually cleaned out the orphaned
_pending_/_inuse_ process:
{noformat}
2016-10-19
08:56:22|24164|3008853|3116173|reload|utils.pm:get_request_by_computerid|5351|retrieved
info and DataStructure object for 3008649:3115969
|24164|3008853|3116173|reload|new.pm:computer_not_being_used|703|
request:reservation ID: 3008649:3115969
2016-10-19
08:56:22|24164|3008853|3116173|reload|utils.pm:update_request_state|1399|request
3008649 state updated to complete/inuse
{noformat}
was:
{noformat}|inuse|utils.pm:database_select|2820| ---- WARNING ----
|inuse|utils.pm:database_select|2820| 2016-10-18
22:53:23|inuse|utils.pm:database_select|2820|could not execute statement on vcl
database, SELECT
|inuse|utils.pm:database_select|2820| state.name AS state_name,
|inuse|utils.pm:database_select|2820| laststate.name AS laststate_name
|inuse|utils.pm:database_select|2820| FROM
|inuse|utils.pm:database_select|2820| request,
|inuse|utils.pm:database_select|2820| state,
|inuse|utils.pm:database_select|2820| state laststate
|inuse|utils.pm:database_select|2820| WHERE
|inuse|utils.pm:database_select|2820| request.id = 3008649
|inuse|utils.pm:database_select|2820| AND request.stateid = state.id
|inuse|utils.pm:database_select|2820| AND request.laststateid = laststate.id
|inuse|utils.pm:database_select|2820| error: Lost connection to MySQL server
during query
|inuse|utils.pm:database_select|2820| ( 0) utils.pm, database_select (line:
2820)
|inuse|utils.pm:database_select|2820| (-1) utils.pm,
get_request_current_state_name (line: 5394)
|inuse|utils.pm:database_select|2820| (-2) utils.pm, is_request_deleted (line:
1682)
|inuse|utils.pm:database_select|2820| (-3) State.pm, user_connected (line: 266)
|inuse|utils.pm:database_select|2820| (-4) inuse.pm, __ANON__ (line: 306)
|inuse|utils.pm:database_select|2820| (-5) Module.pm, code_loop_timeout (line:
1504)
|inuse|utils.pm:get_request_current_state_name|5398| ---- WARNING ----
|inuse|utils.pm:get_request_current_state_name|5398| 2016-10-18
22:53:23|inuse|utils.pm:get_request_current_state_name|5398|unable to determine
current state of request 3008649, zero rows were returned from database select
|inuse|utils.pm:get_request_current_state_name|5398| ( 0) utils.pm,
get_request_current_state_name (line: 5398)
|inuse|utils.pm:get_request_current_state_name|5398| (-1) utils.pm,
is_request_deleted (line: 1682)
|inuse|utils.pm:get_request_current_state_name|5398| (-2) State.pm,
user_connected (line: 266)
|inuse|utils.pm:get_request_current_state_name|5398| (-3) inuse.pm, __ANON__
(line: 306)
|inuse|utils.pm:get_request_current_state_name|5398| (-4) Module.pm,
code_loop_timeout (line: 1504)
|inuse|utils.pm:get_request_current_state_name|5398| (-5) inuse.pm, process
(line: 306)
|inuse|utils.pm:is_request_deleted|1684| ---- WARNING ----
|inuse|utils.pm:is_request_deleted|1684| 2016-10-18
22:53:23|inuse|utils.pm:is_request_deleted|1684|request 3008649 state data
could not be retrieved, assuming request is deleted and was removed from the
database, returning true
|inuse|utils.pm:is_request_deleted|1684| ( 0) utils.pm, is_request_deleted
(line: 1684)
|inuse|utils.pm:is_request_deleted|1684| (-1) State.pm, user_connected (line:
266)
|inuse|utils.pm:is_request_deleted|1684| (-2) inuse.pm, __ANON__ (line: 306)
|inuse|utils.pm:is_request_deleted|1684| (-3) Module.pm, code_loop_timeout
(line: 1504)
|inuse|utils.pm:is_request_deleted|1684| (-4) inuse.pm, process (line: 306)
|inuse|utils.pm:is_request_deleted|1684| (-5) vcld, make_new_child (line: 602)
2016-10-18 22:53:23|inuse|State.pm:state_exit|863|beginning state module exit
tasks
|inuse|State.pm:state_exit|863| request state argument: <not specified>
|inuse|State.pm:state_exit|863| computer state argument: <not specified>
|inuse|State.pm:state_exit|863| log ending argument: <not specified>
{noformat}
As shown above, while retrieving the current request state an error occurred:
{color:red}*error: Lost connection to MySQL server during query*{color}
The process was able to connect to the database a few seconds later. I believe
this is a very rare situation but we could add some logic to
*State.pm:state_exit* to prevent processes from exiting if the current state in
the database is likely _pending_.
> Request may be left in pending state if database connection is lost
> -------------------------------------------------------------------
>
> Key: VCL-998
> URL: https://issues.apache.org/jira/browse/VCL-998
> Project: VCL
> Issue Type: Bug
> Components: vcld (backend)
> Affects Versions: 2.4.2
> Reporter: Andy Kurth
>
> {noformat}|inuse|utils.pm:database_select|2820| ---- WARNING ----
> |inuse|utils.pm:database_select|2820| 2016-10-18
> 22:53:23|inuse|utils.pm:database_select|2820|could not execute statement on
> vcl database, SELECT
> |inuse|utils.pm:database_select|2820| state.name AS state_name,
> |inuse|utils.pm:database_select|2820| laststate.name AS laststate_name
> |inuse|utils.pm:database_select|2820| FROM
> |inuse|utils.pm:database_select|2820| request,
> |inuse|utils.pm:database_select|2820| state,
> |inuse|utils.pm:database_select|2820| state laststate
> |inuse|utils.pm:database_select|2820| WHERE
> |inuse|utils.pm:database_select|2820| request.id = 3008649
> |inuse|utils.pm:database_select|2820| AND request.stateid = state.id
> |inuse|utils.pm:database_select|2820| AND request.laststateid = laststate.id
> |inuse|utils.pm:database_select|2820| error: Lost connection to MySQL server
> during query
> |inuse|utils.pm:database_select|2820| ( 0) utils.pm, database_select (line:
> 2820)
> |inuse|utils.pm:database_select|2820| (-1) utils.pm,
> get_request_current_state_name (line: 5394)
> |inuse|utils.pm:database_select|2820| (-2) utils.pm, is_request_deleted
> (line: 1682)
> |inuse|utils.pm:database_select|2820| (-3) State.pm, user_connected (line:
> 266)
> |inuse|utils.pm:database_select|2820| (-4) inuse.pm, __ANON__ (line: 306)
> |inuse|utils.pm:database_select|2820| (-5) Module.pm, code_loop_timeout
> (line: 1504)
> |inuse|utils.pm:get_request_current_state_name|5398| ---- WARNING ----
> |inuse|utils.pm:get_request_current_state_name|5398| 2016-10-18
> 22:53:23|inuse|utils.pm:get_request_current_state_name|5398|unable to
> determine current state of request 3008649, zero rows were returned from
> database select
> |inuse|utils.pm:get_request_current_state_name|5398| ( 0) utils.pm,
> get_request_current_state_name (line: 5398)
> |inuse|utils.pm:get_request_current_state_name|5398| (-1) utils.pm,
> is_request_deleted (line: 1682)
> |inuse|utils.pm:get_request_current_state_name|5398| (-2) State.pm,
> user_connected (line: 266)
> |inuse|utils.pm:get_request_current_state_name|5398| (-3) inuse.pm, __ANON__
> (line: 306)
> |inuse|utils.pm:get_request_current_state_name|5398| (-4) Module.pm,
> code_loop_timeout (line: 1504)
> |inuse|utils.pm:get_request_current_state_name|5398| (-5) inuse.pm, process
> (line: 306)
> |inuse|utils.pm:is_request_deleted|1684| ---- WARNING ----
> |inuse|utils.pm:is_request_deleted|1684| 2016-10-18
> 22:53:23|inuse|utils.pm:is_request_deleted|1684|request 3008649 state data
> could not be retrieved, assuming request is deleted and was removed from the
> database, returning true
> |inuse|utils.pm:is_request_deleted|1684| ( 0) utils.pm, is_request_deleted
> (line: 1684)
> |inuse|utils.pm:is_request_deleted|1684| (-1) State.pm, user_connected (line:
> 266)
> |inuse|utils.pm:is_request_deleted|1684| (-2) inuse.pm, __ANON__ (line: 306)
> |inuse|utils.pm:is_request_deleted|1684| (-3) Module.pm, code_loop_timeout
> (line: 1504)
> |inuse|utils.pm:is_request_deleted|1684| (-4) inuse.pm, process (line: 306)
> |inuse|utils.pm:is_request_deleted|1684| (-5) vcld, make_new_child (line: 602)
> 2016-10-18 22:53:23|inuse|State.pm:state_exit|863|beginning state module exit
> tasks
> |inuse|State.pm:state_exit|863| request state argument: <not specified>
> |inuse|State.pm:state_exit|863| computer state argument: <not specified>
> |inuse|State.pm:state_exit|863| log ending argument: <not specified>
> {noformat}
> As shown above, while retrieving the current request state an error occurred:
> {color:red}*error: Lost connection to MySQL server during query*{color}
> The process was able to connect to the database a few seconds later. I
> believe this is a very rare situation but we could add some logic to
> *State.pm:state_exit* to prevent processes from exiting if the current state
> in the database is likely _pending_.
> This isn't a major problem because the code eventually cleaned out the
> orphaned _pending_/_inuse_ process:
> {noformat}
> 2016-10-19
> 08:56:22|24164|3008853|3116173|reload|utils.pm:get_request_by_computerid|5351|retrieved
> info and DataStructure object for 3008649:3115969
> |24164|3008853|3116173|reload|new.pm:computer_not_being_used|703|
> request:reservation ID: 3008649:3115969
> 2016-10-19
> 08:56:22|24164|3008853|3116173|reload|utils.pm:update_request_state|1399|request
> 3008649 state updated to complete/inuse
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
