Comment 4 for bug 1869194

Revision history for this message
Bin Qian (bqian20) wrote :

The go-enabled timeout (30s) in this case seems insufficient. Although it may be because the mgmt ip related, enabling actions timeout consistently
| 2020-03-21T09:20:16.508 | 463 | service-scn | dc-iso-fs | enabling-throttle | enabling | enabled-active state requested
| 2020-03-21T09:21:16.529 | 490 | service-scn | dc-iso-fs | enabling | disabling | enable failed

2020-03-21T09:20:16.000 controller-0 sm: debug time[613.439] log<1945> INFO: sm[18147]: sm_service_fsm.c(1032): Service (dc-iso-fs) received event (enable-throttle) was in the enabling-throttle state and is now in the enabling state.
2020-03-21T09:20:46.000 controller-0 sm: debug time[643.439] log<2044> INFO: sm[18147]: sm_service_enable.c(245): Action (enable) timeout with result (failed), state (unknown), status (unknown), and condition (unknown) for service (dc-iso-fs), reason_text=, exit_code=-65534.
2020-03-21T09:20:46.000 controller-0 sm: debug time[643.439] log<2045> INFO: sm[18147]: sm_service_action.c(345): Aborting service (dc-iso-fs) with kill signal, pid=362782.
2020-03-21T09:20:46.000 controller-0 sm: debug time[643.439] log<2046> INFO: sm[18147]: sm_service_enable.c(154): Max retires not met for action (enable) of service (dc-iso-fs), attempts=1.
2020-03-21T09:20:46.000 controller-0 sm: debug time[643.440] log<2047> INFO: sm[18147]: sm_service_enable.c(461): Started enable action (370970) for service (dc-iso-fs).
2020-03-21T09:21:16.000 controller-0 sm: debug time[673.457] log<2092> INFO: sm[18147]: sm_service_enable.c(245): Action (enable) timeout with result (failed), state (unknown), status (unknown), and condition (unknown) for service (dc-iso-fs), reason_text=, exit_code=-65534.
2020-03-21T09:21:16.000 controller-0 sm: debug time[673.457] log<2093> INFO: sm[18147]: sm_service_action.c(345): Aborting service (dc-iso-fs) with kill signal, pid=370970.
2020-03-21T09:21:16.000 controller-0 sm: debug time[673.457] log<2094> INFO: sm[18147]: sm_service_enable.c(149): Max retires met for action (enable) of service (dc-iso-fs), attempts=2.
2020-03-21T09:21:16.000 controller-0 sm: debug time[673.458] log<2095> INFO: sm[18147]: sm_service_disable.c(380): Started disable action (373984) for service (dc-iso-fs), flag (0).
2020-03-21T09:21:16.000 controller-0 sm: debug time[673.458] log<2096> INFO: sm[18147]: sm_service_fsm.c(1032): Service (dc-iso-fs) received event (enable-failed) was in the enabling state and is now in the disabling state.
2020-03-21T09:22:16.000 controller-0 sm: debug time[733.463] log<2181> INFO: sm[18147]: sm_service_disable.c(163): Action (disable) timeout with result (success), state (disabled), status (unknown), and condition (unknown) for service (dc-iso-fs), reason_text=, exit_code=-65534.
2020-03-21T09:22:16.000 controller-0 sm: debug time[733.463] log<2182> INFO: sm[18147]: sm_service_action.c(345): Aborting service (dc-iso-fs) with kill signal, pid=373984.
2020-03-21T09:22:16.000 controller-0 sm: debug time[733.463] log<2183> INFO: sm[18147]: sm_service_fsm.c(1032): Service (dc-iso-fs) received event (disable-success) was in the disabling state and is now in the disabled state.
2020-03-21T09:22:16.000 controller-0 sm: debug time[733.747] log<2191> INFO: sm[18147]: sm_service_enable.c(461): Started enable action (380980) for service (dc-iso-fs).

Suggest to retest with fix: https://review.opendev.org/#/c/715018/