2022-09-18T08:43:27.790141Z INFO update_engine: [main.cc(55)] A/B Update Engine starting 2022-09-18T08:43:27.796030Z INFO update_engine: [subprocess.cc(98)] Running "/usr/share/fydeos_shell/license-utils.sh id" 2022-09-18T08:43:28.299492Z INFO update_engine: [fydeos_license_checker.cc(41)] FydeOS license id: ce64e3f284f834dc03a22a75ce2600e6efd79e05 2022-09-18T08:43:28.311582Z INFO update_engine: [boot_control_chromeos.cc(180)] Booted from slot 1 (slot B) of 2 slots present on disk /dev/sda 2022-09-18T08:43:28.311740Z INFO update_engine: [real_system_state.cc(60)] Booted in dev mode. 2022-09-18T08:43:28.311839Z INFO update_engine: [real_system_state.cc(61)] Booted non-official build. 2022-09-18T08:43:28.313714Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-18T08:43:28.314194Z INFO update_engine: [omaha_request_params.cc(223)] Download channel for this attempt = stable-channel 2022-09-18T08:43:28.314233Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-18T08:43:28.314346Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T08:43:28.314346Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T08:43:28.320316Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-18T08:43:28.359997Z INFO update_engine: [payload_state.cc(894)] Current Response Signature = Payload 0: Size = 1392499954 Sha256 Hash = cf07a99e34de2fe672953a16ada277e15e2da1d6f2484b5b54d31aea2909d974 Metadata Size = 77327 Metadata Signature = Is Delta = 0 NumURLs = 1 Candidate Url0 = https://cdn-ota.fydeos.com/amd64-fydeos/stable-channel/15.0/14695.91.15.12/9f8770-full.gz Max Failure Count Per Url = 3 Disable Payload Backoff = 0 2022-09-18T08:43:28.366411Z INFO update_engine: [metrics_utils.cc(331)] Payload Attempt Number = 1 2022-09-18T08:43:28.367767Z INFO update_engine: [payload_state.cc(916)] Full Payload Attempt Number = 1 2022-09-18T08:43:28.380952Z INFO update_engine: [payload_state.cc(943)] Current URL Index = 0 2022-09-18T08:43:28.385708Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-18T08:43:28.387113Z INFO update_engine: [payload_state.cc(1000)] Current URL (Url0)'s Failure Count = 0 2022-09-18T08:43:28.389219Z INFO update_engine: [payload_state.cc(990)] URL Switch Count = 0 2022-09-18T08:43:28.395212Z INFO update_engine: [payload_state.cc(1025)] Backoff Expiry Time = 9/19/2022 4:08:26 GMT 2022-09-18T08:43:28.400629Z INFO update_engine: [metrics_utils.cc(348)] Update Monotonic Timestamp Start = 9/18/2022 8:43:28 GMT 2022-09-18T08:43:28.400827Z INFO update_engine: [payload_state.cc(1157)] Update Duration Uptime = 0s 2022-09-18T08:43:28.409090Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpsServer = 0 2022-09-18T08:43:28.411082Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpsServer = 0 2022-09-18T08:43:28.414045Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpServer = 0 2022-09-18T08:43:28.416063Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpServer = 0 2022-09-18T08:43:28.417816Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpPeer = 0 2022-09-18T08:43:28.419646Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpPeer = 0 2022-09-18T08:43:28.428885Z INFO update_engine: [metrics_utils.cc(323)] Number of Reboots during current update attempt = 0 2022-09-18T08:43:28.430373Z INFO update_engine: [payload_state.cc(1230)] Num Responses Seen = 0 2022-09-18T08:43:28.430954Z INFO update_engine: [payload_state.cc(1125)] Setting rollback-happened to 0. 2022-09-18T08:43:28.433209Z INFO update_engine: [payload_state.cc(1381)] p2p First Attempt Timestamp = 1/1/1601 0:00:00 GMT 2022-09-18T08:43:28.435041Z INFO update_engine: [payload_state.cc(1367)] p2p Num Attempts = 0 2022-09-18T08:43:28.435678Z ERROR update_engine: [real_system_state.cc(178)] Failed to set kernel_max_rollforward to infinity for device with test/dev image. 2022-09-18T08:43:28.435678Z ERROR update_engine: [real_system_state.cc(178)] Failed to set kernel_max_rollforward to infinity for device with test/dev image. 2022-09-18T08:43:28.438769Z INFO update_engine: [daemon_chromeos.cc(61)] Waiting for DBus object to be registered. 2022-09-18T08:43:28.452096Z INFO update_engine: [daemon_chromeos.cc(89)] Requesting telemetry info from cros_healthd. 2022-09-18T08:43:28.453234Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T08:43:28.453306Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T08:43:28.453337Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T08:43:28.454096Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 8:51:19 GMT 2022-09-18T08:43:28.454177Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T08:43:28.454207Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T08:43:28.454234Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T08:43:28.454266Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T08:43:28.454299Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T08:43:28.454332Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T08:43:28.460234Z ERROR update_engine: [metrics_utils.cc(373)] time_to_reboot is negative - system_updated_at: 1/1/1970 0:31:12 GMT 2022-09-18T08:43:28.460234Z ERROR update_engine: [metrics_utils.cc(373)] time_to_reboot is negative - system_updated_at: 1/1/1970 0:31:12 GMT 2022-09-18T08:43:28.462097Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable au_p2p_enabled: "No value set for au_p2p_enabled" 2022-09-18T08:43:28.462214Z INFO update_engine: [update_attempter.cc(1928)] Not starting p2p at startup since it's not enabled. 2022-09-18T08:43:28.462713Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable au_p2p_enabled: "No value set for au_p2p_enabled" 2022-09-18T08:43:28.462752Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on p2p_enabled 2022-09-18T08:43:28.462781Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T08:43:28.462809Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on au_p2p_enabled 2022-09-18T08:43:28.462836Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 11h59m59.999345s 2022-09-18T08:43:28.631848Z INFO update_engine: [update_attempter.cc(2024)] Repeated updates has been enabled. 2022-09-18T08:44:13.452572Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting UpdateBootFlagsAction 2022-09-18T08:44:13.452987Z INFO update_engine: [update_boot_flags_action.cc(50)] Marking booted slot as good. 2022-09-18T08:44:13.453098Z INFO update_engine: [subprocess.cc(98)] Running "/usr/sbin/chromeos-setgoodkernel" 2022-09-18T08:44:13.890662Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action UpdateBootFlagsAction with code ErrorCode::kSuccess 2022-09-18T08:44:21.542288Z INFO update_engine: [real_device_policy_provider.cc(78)] Reloading and re-scheduling device policy due to signal received. 2022-09-18T08:45:49.205381Z INFO update_engine: [common_service.cc(82)] Attempt update: app_version="" omaha_url="" flags=0x0 interactive=yes 2022-09-18T08:45:49.212563Z INFO update_engine: [update_attempter.cc(979)] Forced update check requested. 2022-09-18T08:45:49.217633Z INFO update_engine: [update_attempter.cc(2002)] Non-official build; allowing any update source. 2022-09-18T08:45:49.218828Z INFO update_engine: [evaluation_context.cc(108)] ValueChanged() called for variable forced_update_requested 2022-09-18T08:45:49.220140Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T08:45:49.220227Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T08:45:49.220257Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T08:45:49.220290Z INFO update_engine: [interactive_update_policy_impl.cc(40)] Forced update signaled (interactive), allowing update check. 2022-09-18T08:45:49.220326Z INFO update_engine: [update_attempter.cc(1105)] Running interactive update. 2022-09-18T08:45:49.224436Z INFO update_engine: [update_attempter.cc(254)] Last reported daily metrics 29m41.572506s ago. 2022-09-18T08:45:49.230621Z INFO update_engine: [update_attempter.cc(361)] Device policies/settings present 2022-09-18T08:45:49.231632Z INFO update_engine: [update_attempter.cc(505)] Scattering disabled since scatter factor is set to 0 2022-09-18T08:45:49.231750Z INFO update_engine: [update_attempter.cc(380)] p2p is not enabled - disallowing p2p for both downloading and sharing. 2022-09-18T08:45:49.231780Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-18T08:45:49.231810Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-18T08:45:49.233397Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-18T08:45:49.233553Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T08:45:49.233553Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T08:45:49.238524Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-18T08:45:49.238643Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable market_segment: "No value set for market_segment" 2022-09-18T08:45:49.238675Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable quick_fix_build_token: "No value set for quick_fix_build_token" 2022-09-18T08:45:49.238705Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_lts_tag: "No value set for release_lts_tag" 2022-09-18T08:45:49.238734Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_to_target_version: "No value set for rollback_to_target_version" 2022-09-18T08:45:49.238764Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_allowed_milestones: "No value set for rollback_allowed_milestones" 2022-09-18T08:45:49.248924Z INFO update_engine: [update_attempter.cc(448)] target_version_prefix = , rollback_allowed = 0, scatter_factor_in_seconds = 0s 2022-09-18T08:45:49.249091Z INFO update_engine: [update_attempter.cc(455)] Wall Clock Based Wait Enabled = 0, Update Check Count Wait Enabled = 0, Waiting Period = 0s 2022-09-18T08:45:49.249127Z INFO update_engine: [update_attempter.cc(463)] Use p2p For Downloading = 0, Use p2p For Sharing = 0 2022-09-18T08:45:49.249156Z INFO update_engine: [update_attempter.cc(470)] forced to obey proxies 2022-09-18T08:45:49.249183Z INFO update_engine: [update_attempter.cc(473)] proxy manual checks: 1 2022-09-18T08:45:49.250516Z INFO update_engine: [update_attempter.cc(1773)] Scheduling an action processor start. 2022-09-18T08:45:49.250762Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T08:45:49.259109Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T08:45:49.259186Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T08:45:49.268626Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T08:45:49.291291Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T08:45:49.291486Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T08:45:51.648147Z INFO update_engine: [libcurl_http_fetcher.cc(583)] HTTP response unsuccessful (403) or no payload (335), nothing to do 2022-09-18T08:45:51.650164Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 403 2022-09-18T08:45:51.651113Z INFO update_engine: [libcurl_http_fetcher.cc(521)] Transfer resulted in an error (403), 0 bytes downloaded 2022-09-18T08:45:51.651208Z INFO update_engine: [libcurl_http_fetcher.cc(535)] No further proxies, indicating transfer complete 2022-09-18T08:45:51.651266Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T08:45:51.651295Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T08:45:51.651295Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T08:45:51.657794Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished OmahaRequestAction with code Unknown error: 2403 2022-09-18T08:45:51.657869Z INFO update_engine: [action_processor.cc(123)] ActionProcessor: Aborting processing due to failure. 2022-09-18T08:45:51.658661Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T08:45:51.658720Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T08:45:51.658749Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T08:45:51.658749Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T08:45:51.658787Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T08:45:51.658815Z INFO update_engine: [payload_state.cc(263)] Updating payload state for error code: 37 (ErrorCode::kOmahaErrorInHTTPResponse) 2022-09-18T08:45:51.658845Z INFO update_engine: [payload_state.cc(270)] Ignoring failures until we get a valid Omaha response. 2022-09-18T08:45:51.658871Z INFO update_engine: [update_attempter.cc(1759)] Reporting the error event 2022-09-18T08:45:51.659235Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T08:45:51.664452Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T08:45:51.664541Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T08:45:51.667785Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T08:45:51.668782Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T08:45:51.668947Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T08:45:52.446314Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 200 2022-09-18T08:45:52.449069Z INFO update_engine: [libcurl_http_fetcher.cc(562)] Transfer completed (200), 268 bytes downloaded 2022-09-18T08:45:52.449175Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T08:45:52.449221Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action OmahaRequestAction with code ErrorCode::kSuccess 2022-09-18T08:45:52.449251Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T08:45:52.449280Z INFO update_engine: [update_attempter.cc(1158)] Error event sent. 2022-09-18T08:45:52.455566Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T08:45:52.455658Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T08:45:52.455692Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T08:45:52.455792Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 9:34:11 GMT 2022-09-18T08:45:52.455853Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T08:45:52.455881Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T08:45:52.455908Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T08:45:52.455934Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T08:45:52.455962Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T08:45:52.455990Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T08:48:35.200464Z INFO update_engine: [common_service.cc(82)] Attempt update: app_version="" omaha_url="" flags=0x0 interactive=yes 2022-09-18T08:48:35.206809Z INFO update_engine: [update_attempter.cc(979)] Forced update check requested. 2022-09-18T08:48:35.207061Z INFO update_engine: [update_attempter.cc(2002)] Non-official build; allowing any update source. 2022-09-18T08:48:35.207326Z INFO update_engine: [evaluation_context.cc(108)] ValueChanged() called for variable forced_update_requested 2022-09-18T08:48:35.207393Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T08:48:35.207425Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T08:48:35.207457Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T08:48:35.207489Z INFO update_engine: [interactive_update_policy_impl.cc(40)] Forced update signaled (interactive), allowing update check. 2022-09-18T08:48:35.207524Z INFO update_engine: [update_attempter.cc(1105)] Running interactive update. 2022-09-18T08:48:35.208320Z INFO update_engine: [update_attempter.cc(254)] Last reported daily metrics 32m27.559732s ago. 2022-09-18T08:48:35.211705Z INFO update_engine: [update_attempter.cc(361)] Device policies/settings present 2022-09-18T08:48:35.211841Z INFO update_engine: [update_attempter.cc(505)] Scattering disabled since scatter factor is set to 0 2022-09-18T08:48:35.211895Z INFO update_engine: [update_attempter.cc(380)] p2p is not enabled - disallowing p2p for both downloading and sharing. 2022-09-18T08:48:35.211924Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-18T08:48:35.211954Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-18T08:48:35.212411Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-18T08:48:35.212522Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T08:48:35.212522Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T08:48:35.214247Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-18T08:48:35.214355Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable market_segment: "No value set for market_segment" 2022-09-18T08:48:35.214387Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable quick_fix_build_token: "No value set for quick_fix_build_token" 2022-09-18T08:48:35.214417Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_lts_tag: "No value set for release_lts_tag" 2022-09-18T08:48:35.214446Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_to_target_version: "No value set for rollback_to_target_version" 2022-09-18T08:48:35.214475Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_allowed_milestones: "No value set for rollback_allowed_milestones" 2022-09-18T08:48:35.216116Z INFO update_engine: [update_attempter.cc(448)] target_version_prefix = , rollback_allowed = 0, scatter_factor_in_seconds = 0s 2022-09-18T08:48:35.216219Z INFO update_engine: [update_attempter.cc(455)] Wall Clock Based Wait Enabled = 0, Update Check Count Wait Enabled = 0, Waiting Period = 0s 2022-09-18T08:48:35.216251Z INFO update_engine: [update_attempter.cc(463)] Use p2p For Downloading = 0, Use p2p For Sharing = 0 2022-09-18T08:48:35.217521Z INFO update_engine: [update_attempter.cc(1773)] Scheduling an action processor start. 2022-09-18T08:48:35.217758Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T08:48:35.223331Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T08:48:35.223415Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T08:48:35.226345Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T08:48:35.226898Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T08:48:35.227079Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T08:48:36.048266Z INFO update_engine: [libcurl_http_fetcher.cc(583)] HTTP response unsuccessful (403) or no payload (303), nothing to do 2022-09-18T08:48:36.050276Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 403 2022-09-18T08:48:36.051235Z INFO update_engine: [libcurl_http_fetcher.cc(521)] Transfer resulted in an error (403), 0 bytes downloaded 2022-09-18T08:48:36.051333Z INFO update_engine: [libcurl_http_fetcher.cc(535)] No further proxies, indicating transfer complete 2022-09-18T08:48:36.051362Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T08:48:36.051391Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T08:48:36.051391Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T08:48:36.057914Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished OmahaRequestAction with code Unknown error: 2403 2022-09-18T08:48:36.057974Z INFO update_engine: [action_processor.cc(123)] ActionProcessor: Aborting processing due to failure. 2022-09-18T08:48:36.058055Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T08:48:36.058112Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T08:48:36.058214Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T08:48:36.058214Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T08:48:36.058251Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T08:48:36.058280Z INFO update_engine: [payload_state.cc(263)] Updating payload state for error code: 37 (ErrorCode::kOmahaErrorInHTTPResponse) 2022-09-18T08:48:36.058317Z INFO update_engine: [payload_state.cc(270)] Ignoring failures until we get a valid Omaha response. 2022-09-18T08:48:36.058344Z INFO update_engine: [update_attempter.cc(1759)] Reporting the error event 2022-09-18T08:48:36.058640Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T08:48:36.060812Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T08:48:36.060857Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T08:48:36.082916Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T08:48:36.083411Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T08:48:36.083552Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T08:48:36.869674Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 200 2022-09-18T08:48:36.878767Z INFO update_engine: [libcurl_http_fetcher.cc(562)] Transfer completed (200), 268 bytes downloaded 2022-09-18T08:48:36.879071Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T08:48:36.879257Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action OmahaRequestAction with code ErrorCode::kSuccess 2022-09-18T08:48:36.879459Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T08:48:36.879583Z INFO update_engine: [update_attempter.cc(1158)] Error event sent. 2022-09-18T08:48:36.887703Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T08:48:36.887924Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T08:48:36.889972Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T08:48:36.890388Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 9:32:38 GMT 2022-09-18T08:48:36.890551Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T08:48:36.890678Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T08:48:36.890801Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T08:48:36.890922Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T08:48:36.891097Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T08:48:36.891240Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T08:50:50.104658Z INFO update_engine: [common_service.cc(82)] Attempt update: app_version="" omaha_url="" flags=0x0 interactive=yes 2022-09-18T08:50:50.110756Z INFO update_engine: [update_attempter.cc(979)] Forced update check requested. 2022-09-18T08:50:50.111308Z INFO update_engine: [update_attempter.cc(2002)] Non-official build; allowing any update source. 2022-09-18T08:50:50.111861Z INFO update_engine: [evaluation_context.cc(108)] ValueChanged() called for variable forced_update_requested 2022-09-18T08:50:50.112057Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T08:50:50.112165Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T08:50:50.112258Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T08:50:50.112353Z INFO update_engine: [interactive_update_policy_impl.cc(40)] Forced update signaled (interactive), allowing update check. 2022-09-18T08:50:50.112455Z INFO update_engine: [update_attempter.cc(1105)] Running interactive update. 2022-09-18T08:50:50.113557Z INFO update_engine: [update_attempter.cc(254)] Last reported daily metrics 34m42.464693s ago. 2022-09-18T08:50:50.117783Z INFO update_engine: [update_attempter.cc(361)] Device policies/settings present 2022-09-18T08:50:50.118057Z INFO update_engine: [update_attempter.cc(505)] Scattering disabled since scatter factor is set to 0 2022-09-18T08:50:50.118228Z INFO update_engine: [update_attempter.cc(380)] p2p is not enabled - disallowing p2p for both downloading and sharing. 2022-09-18T08:50:50.118320Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-18T08:50:50.118412Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-18T08:50:50.119474Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-18T08:50:50.119751Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T08:50:50.119751Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T08:50:50.125379Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-18T08:50:50.125644Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable market_segment: "No value set for market_segment" 2022-09-18T08:50:50.125738Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable quick_fix_build_token: "No value set for quick_fix_build_token" 2022-09-18T08:50:50.125826Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_lts_tag: "No value set for release_lts_tag" 2022-09-18T08:50:50.125932Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_to_target_version: "No value set for rollback_to_target_version" 2022-09-18T08:50:50.126067Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_allowed_milestones: "No value set for rollback_allowed_milestones" 2022-09-18T08:50:50.130392Z INFO update_engine: [update_attempter.cc(448)] target_version_prefix = , rollback_allowed = 0, scatter_factor_in_seconds = 0s 2022-09-18T08:50:50.130579Z INFO update_engine: [update_attempter.cc(455)] Wall Clock Based Wait Enabled = 0, Update Check Count Wait Enabled = 0, Waiting Period = 0s 2022-09-18T08:50:50.130676Z INFO update_engine: [update_attempter.cc(463)] Use p2p For Downloading = 0, Use p2p For Sharing = 0 2022-09-18T08:50:50.130779Z INFO update_engine: [update_attempter.cc(481)] To help ensure updates work, this update check we are ignoring the proxy settings and using direct connections. 2022-09-18T08:50:50.133042Z INFO update_engine: [update_attempter.cc(1773)] Scheduling an action processor start. 2022-09-18T08:50:50.133477Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T08:50:50.137778Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T08:50:50.137891Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T08:50:50.138167Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T08:50:50.141284Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T08:50:50.141507Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T08:50:50.959159Z INFO update_engine: [libcurl_http_fetcher.cc(583)] HTTP response unsuccessful (403) or no payload (303), nothing to do 2022-09-18T08:50:50.966740Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 403 2022-09-18T08:50:50.969062Z INFO update_engine: [libcurl_http_fetcher.cc(521)] Transfer resulted in an error (403), 0 bytes downloaded 2022-09-18T08:50:50.969264Z INFO update_engine: [libcurl_http_fetcher.cc(535)] No further proxies, indicating transfer complete 2022-09-18T08:50:50.969390Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T08:50:50.969516Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T08:50:50.969516Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T08:50:50.982781Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished OmahaRequestAction with code Unknown error: 2403 2022-09-18T08:50:50.982970Z INFO update_engine: [action_processor.cc(123)] ActionProcessor: Aborting processing due to failure. 2022-09-18T08:50:50.983315Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T08:50:50.983444Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T08:50:50.983570Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T08:50:50.983570Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T08:50:50.983734Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T08:50:50.983861Z INFO update_engine: [payload_state.cc(263)] Updating payload state for error code: 37 (ErrorCode::kOmahaErrorInHTTPResponse) 2022-09-18T08:50:50.983992Z INFO update_engine: [payload_state.cc(270)] Ignoring failures until we get a valid Omaha response. 2022-09-18T08:50:50.984187Z INFO update_engine: [update_attempter.cc(1759)] Reporting the error event 2022-09-18T08:50:50.985078Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T08:50:50.992548Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T08:50:50.992763Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T08:50:50.993359Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T08:50:50.994659Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T08:50:50.995139Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T08:50:51.777994Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 200 2022-09-18T08:50:51.780614Z INFO update_engine: [libcurl_http_fetcher.cc(562)] Transfer completed (200), 268 bytes downloaded 2022-09-18T08:50:51.780721Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T08:50:51.780792Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action OmahaRequestAction with code ErrorCode::kSuccess 2022-09-18T08:50:51.780823Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T08:50:51.780852Z INFO update_engine: [update_attempter.cc(1158)] Error event sent. 2022-09-18T08:50:51.787124Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T08:50:51.787215Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T08:50:51.787248Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T08:50:51.787331Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 9:31:29 GMT 2022-09-18T08:50:51.787369Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T08:50:51.787432Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T08:50:51.787460Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T08:50:51.787488Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T08:50:51.787515Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T08:50:51.787544Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T08:55:51.845199Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T08:55:51.857103Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T08:55:51.857314Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T08:55:51.857458Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T08:55:51.859878Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 9:31:29 GMT 2022-09-18T08:55:51.860185Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T08:55:51.860337Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T08:55:51.860468Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T08:55:51.860598Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T08:55:51.860729Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T08:55:51.860866Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T08:57:18.769487Z INFO update_engine: [main.cc(72)] A/B Update Engine terminating with exit code 0 2022-09-18T08:57:18.776788Z INFO update_engine: [base_message_loop.cc(77)] Leaking 4 canceled tasks. 2022-09-18T08:57:48.838447Z INFO update_engine: [main.cc(55)] A/B Update Engine starting 2022-09-18T08:57:48.845973Z INFO update_engine: [subprocess.cc(98)] Running "/usr/share/fydeos_shell/license-utils.sh id" 2022-09-18T08:57:49.305296Z INFO update_engine: [fydeos_license_checker.cc(41)] FydeOS license id: ce64e3f284f834dc03a22a75ce2600e6efd79e05 2022-09-18T08:57:49.310994Z INFO update_engine: [boot_control_chromeos.cc(180)] Booted from slot 1 (slot B) of 2 slots present on disk /dev/sda 2022-09-18T08:57:49.311201Z INFO update_engine: [real_system_state.cc(60)] Booted in dev mode. 2022-09-18T08:57:49.311297Z INFO update_engine: [real_system_state.cc(61)] Booted non-official build. 2022-09-18T08:57:49.313087Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-18T08:57:49.313472Z INFO update_engine: [omaha_request_params.cc(223)] Download channel for this attempt = stable-channel 2022-09-18T08:57:49.313503Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-18T08:57:49.313624Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T08:57:49.313624Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T08:57:49.317159Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-18T08:57:49.360836Z INFO update_engine: [payload_state.cc(894)] Current Response Signature = Payload 0: Size = 1392499954 Sha256 Hash = cf07a99e34de2fe672953a16ada277e15e2da1d6f2484b5b54d31aea2909d974 Metadata Size = 77327 Metadata Signature = Is Delta = 0 NumURLs = 1 Candidate Url0 = https://cdn-ota.fydeos.com/amd64-fydeos/stable-channel/15.0/14695.91.15.12/9f8770-full.gz Max Failure Count Per Url = 3 Disable Payload Backoff = 0 2022-09-18T08:57:49.364479Z INFO update_engine: [metrics_utils.cc(331)] Payload Attempt Number = 1 2022-09-18T08:57:49.366315Z INFO update_engine: [payload_state.cc(916)] Full Payload Attempt Number = 1 2022-09-18T08:57:49.369147Z INFO update_engine: [payload_state.cc(943)] Current URL Index = 0 2022-09-18T08:57:49.369511Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-18T08:57:49.371355Z INFO update_engine: [payload_state.cc(1000)] Current URL (Url0)'s Failure Count = 0 2022-09-18T08:57:49.373297Z INFO update_engine: [payload_state.cc(990)] URL Switch Count = 0 2022-09-18T08:57:49.382109Z INFO update_engine: [payload_state.cc(1025)] Backoff Expiry Time = 9/19/2022 4:08:26 GMT 2022-09-18T08:57:49.386138Z INFO update_engine: [metrics_utils.cc(348)] Update Monotonic Timestamp Start = 9/18/2022 8:43:28 GMT 2022-09-18T08:57:49.387261Z INFO update_engine: [payload_state.cc(1157)] Update Duration Uptime = 0s 2022-09-18T08:57:49.389820Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpsServer = 0 2022-09-18T08:57:49.391708Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpsServer = 0 2022-09-18T08:57:49.394081Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpServer = 0 2022-09-18T08:57:49.396287Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpServer = 0 2022-09-18T08:57:49.398207Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpPeer = 0 2022-09-18T08:57:49.400240Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpPeer = 0 2022-09-18T08:57:49.402298Z INFO update_engine: [metrics_utils.cc(323)] Number of Reboots during current update attempt = 0 2022-09-18T08:57:49.403916Z INFO update_engine: [payload_state.cc(1230)] Num Responses Seen = 0 2022-09-18T08:57:49.404231Z INFO update_engine: [payload_state.cc(1125)] Setting rollback-happened to 0. 2022-09-18T08:57:49.405649Z INFO update_engine: [payload_state.cc(1381)] p2p First Attempt Timestamp = 1/1/1601 0:00:00 GMT 2022-09-18T08:57:49.409092Z INFO update_engine: [payload_state.cc(1367)] p2p Num Attempts = 0 2022-09-18T08:57:49.409530Z ERROR update_engine: [real_system_state.cc(178)] Failed to set kernel_max_rollforward to infinity for device with test/dev image. 2022-09-18T08:57:49.409530Z ERROR update_engine: [real_system_state.cc(178)] Failed to set kernel_max_rollforward to infinity for device with test/dev image. 2022-09-18T08:57:49.410058Z INFO update_engine: [daemon_chromeos.cc(61)] Waiting for DBus object to be registered. 2022-09-18T08:57:49.415649Z INFO update_engine: [daemon_chromeos.cc(89)] Requesting telemetry info from cros_healthd. 2022-09-18T08:57:49.417261Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T08:57:49.417358Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T08:57:49.417390Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T08:57:49.422431Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 9:05:16 GMT 2022-09-18T08:57:49.422548Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T08:57:49.422579Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T08:57:49.422607Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T08:57:49.422634Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T08:57:49.422661Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T08:57:49.422692Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T08:57:49.429095Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable au_p2p_enabled: "No value set for au_p2p_enabled" 2022-09-18T08:57:49.429224Z INFO update_engine: [update_attempter.cc(1928)] Not starting p2p at startup since it's not enabled. 2022-09-18T08:57:49.429328Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable au_p2p_enabled: "No value set for au_p2p_enabled" 2022-09-18T08:57:49.429360Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on p2p_enabled 2022-09-18T08:57:49.429389Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T08:57:49.429416Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on au_p2p_enabled 2022-09-18T08:57:49.429444Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 11h59m59.999756s 2022-09-18T08:57:49.564621Z INFO update_engine: [update_attempter.cc(2024)] Repeated updates has been enabled. 2022-09-18T08:58:26.432109Z INFO update_engine: [real_device_policy_provider.cc(78)] Reloading and re-scheduling device policy due to signal received. 2022-09-18T08:58:34.424147Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting UpdateBootFlagsAction 2022-09-18T08:58:34.427923Z INFO update_engine: [update_boot_flags_action.cc(50)] Marking booted slot as good. 2022-09-18T08:58:34.428231Z INFO update_engine: [subprocess.cc(98)] Running "/usr/sbin/chromeos-setgoodkernel" 2022-09-18T08:58:34.586724Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action UpdateBootFlagsAction with code ErrorCode::kSuccess 2022-09-18T09:02:49.525402Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T09:02:49.536800Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T09:02:49.537525Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T09:02:49.537679Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T09:02:49.540481Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 9:05:16 GMT 2022-09-18T09:02:49.540716Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T09:02:49.540845Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T09:02:49.540967Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T09:02:49.541215Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T09:02:49.541338Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T09:02:49.541471Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 2m26.788319s 2022-09-18T09:05:16.523236Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T09:05:16.583544Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T09:05:16.583719Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T09:05:16.583752Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T09:05:16.647795Z INFO update_engine: [update_check_allowed_policy.cc(108)] Allowing update check. 2022-09-18T09:05:16.647906Z INFO update_engine: [update_attempter.cc(1105)] Running periodic update. 2022-09-18T09:05:16.680345Z INFO update_engine: [update_attempter.cc(254)] Last reported daily metrics 49m9.026243s ago. 2022-09-18T09:05:16.997085Z INFO update_engine: [update_attempter.cc(361)] Device policies/settings present 2022-09-18T09:05:17.001234Z INFO update_engine: [update_attempter.cc(505)] Scattering disabled since scatter factor is set to 0 2022-09-18T09:05:17.001365Z INFO update_engine: [update_attempter.cc(380)] p2p is not enabled - disallowing p2p for both downloading and sharing. 2022-09-18T09:05:17.001397Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-18T09:05:17.001429Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-18T09:05:17.017547Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-18T09:05:17.017750Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T09:05:17.017750Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T09:05:17.025846Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-18T09:05:17.025957Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable market_segment: "No value set for market_segment" 2022-09-18T09:05:17.026980Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable quick_fix_build_token: "No value set for quick_fix_build_token" 2022-09-18T09:05:17.027096Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_lts_tag: "No value set for release_lts_tag" 2022-09-18T09:05:17.027129Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_to_target_version: "No value set for rollback_to_target_version" 2022-09-18T09:05:17.027160Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_allowed_milestones: "No value set for rollback_allowed_milestones" 2022-09-18T09:05:17.059541Z INFO update_engine: [update_attempter.cc(448)] target_version_prefix = , rollback_allowed = 0, scatter_factor_in_seconds = 0s 2022-09-18T09:05:17.059652Z INFO update_engine: [update_attempter.cc(455)] Wall Clock Based Wait Enabled = 0, Update Check Count Wait Enabled = 0, Waiting Period = 0s 2022-09-18T09:05:17.059717Z INFO update_engine: [update_attempter.cc(463)] Use p2p For Downloading = 0, Use p2p For Sharing = 0 2022-09-18T09:05:17.059747Z INFO update_engine: [update_attempter.cc(470)] forced to obey proxies 2022-09-18T09:05:17.059774Z INFO update_engine: [update_attempter.cc(473)] proxy manual checks: 1 2022-09-18T09:05:17.091418Z INFO update_engine: [update_attempter.cc(1773)] Scheduling an action processor start. 2022-09-18T09:05:17.091646Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T09:05:17.125301Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T09:05:17.125390Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T09:05:17.678170Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T09:05:17.942714Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T09:05:17.943070Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T09:05:19.557073Z INFO update_engine: [libcurl_http_fetcher.cc(583)] HTTP response unsuccessful (403) or no payload (303), nothing to do 2022-09-18T09:05:19.559540Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 403 2022-09-18T09:05:19.560964Z INFO update_engine: [libcurl_http_fetcher.cc(521)] Transfer resulted in an error (403), 0 bytes downloaded 2022-09-18T09:05:19.561124Z INFO update_engine: [libcurl_http_fetcher.cc(535)] No further proxies, indicating transfer complete 2022-09-18T09:05:19.561153Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T09:05:19.561182Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T09:05:19.561182Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T09:05:19.608895Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished OmahaRequestAction with code Unknown error: 2403 2022-09-18T09:05:19.608955Z INFO update_engine: [action_processor.cc(123)] ActionProcessor: Aborting processing due to failure. 2022-09-18T09:05:19.609048Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T09:05:19.609082Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T09:05:19.609110Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T09:05:19.609110Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T09:05:19.609148Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T09:05:19.609176Z INFO update_engine: [payload_state.cc(263)] Updating payload state for error code: 37 (ErrorCode::kOmahaErrorInHTTPResponse) 2022-09-18T09:05:19.609205Z INFO update_engine: [payload_state.cc(270)] Ignoring failures until we get a valid Omaha response. 2022-09-18T09:05:19.609232Z INFO update_engine: [update_attempter.cc(1759)] Reporting the error event 2022-09-18T09:05:19.609518Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T09:05:19.770396Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T09:05:19.770502Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T09:05:19.773451Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T09:05:19.821371Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T09:05:19.821556Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T09:05:20.601378Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 200 2022-09-18T09:05:20.604173Z INFO update_engine: [libcurl_http_fetcher.cc(562)] Transfer completed (200), 268 bytes downloaded 2022-09-18T09:05:20.604284Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T09:05:20.604331Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action OmahaRequestAction with code ErrorCode::kSuccess 2022-09-18T09:05:20.604361Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T09:05:20.604391Z INFO update_engine: [update_attempter.cc(1158)] Error event sent. 2022-09-18T09:05:20.669892Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T09:05:20.669982Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T09:05:20.670078Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T09:05:20.670228Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 9:45:24 GMT 2022-09-18T09:05:20.670275Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T09:05:20.670304Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T09:05:20.670331Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T09:05:20.670358Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T09:05:20.670385Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T09:05:20.670413Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T09:10:20.783414Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T09:10:20.799027Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T09:10:20.799470Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T09:10:20.799504Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T09:10:20.804321Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 9:45:24 GMT 2022-09-18T09:10:20.804437Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T09:10:20.804467Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T09:10:20.804494Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T09:10:20.804522Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T09:10:20.804549Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T09:10:20.804605Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T10:40:18.317988Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T10:40:18.323569Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T10:40:18.323741Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T10:40:18.323798Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T10:40:18.327275Z INFO update_engine: [update_check_allowed_policy.cc(108)] Allowing update check. 2022-09-18T10:40:18.327437Z INFO update_engine: [update_attempter.cc(1105)] Running periodic update. 2022-09-18T10:40:18.331855Z INFO update_engine: [update_attempter.cc(254)] Last reported daily metrics 2h24m10.680666s ago. 2022-09-18T10:40:18.342709Z INFO update_engine: [update_attempter.cc(361)] Device policies/settings present 2022-09-18T10:40:18.342908Z INFO update_engine: [update_attempter.cc(505)] Scattering disabled since scatter factor is set to 0 2022-09-18T10:40:18.342992Z INFO update_engine: [update_attempter.cc(380)] p2p is not enabled - disallowing p2p for both downloading and sharing. 2022-09-18T10:40:18.343024Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-18T10:40:18.343056Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-18T10:40:18.348324Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-18T10:40:18.348550Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T10:40:18.348550Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T10:40:18.353435Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-18T10:40:18.353594Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable market_segment: "No value set for market_segment" 2022-09-18T10:40:18.353629Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable quick_fix_build_token: "No value set for quick_fix_build_token" 2022-09-18T10:40:18.353661Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_lts_tag: "No value set for release_lts_tag" 2022-09-18T10:40:18.353692Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_to_target_version: "No value set for rollback_to_target_version" 2022-09-18T10:40:18.353724Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_allowed_milestones: "No value set for rollback_allowed_milestones" 2022-09-18T10:40:18.362986Z INFO update_engine: [update_attempter.cc(448)] target_version_prefix = , rollback_allowed = 0, scatter_factor_in_seconds = 0s 2022-09-18T10:40:18.363099Z INFO update_engine: [update_attempter.cc(455)] Wall Clock Based Wait Enabled = 0, Update Check Count Wait Enabled = 0, Waiting Period = 0s 2022-09-18T10:40:18.363226Z INFO update_engine: [update_attempter.cc(463)] Use p2p For Downloading = 0, Use p2p For Sharing = 0 2022-09-18T10:40:18.364724Z INFO update_engine: [update_attempter.cc(1773)] Scheduling an action processor start. 2022-09-18T10:40:18.365018Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T10:40:18.371381Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T10:40:18.371467Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T10:40:18.380636Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T10:40:18.385165Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T10:40:18.385350Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T10:40:19.693658Z INFO update_engine: [libcurl_http_fetcher.cc(583)] HTTP response unsuccessful (403) or no payload (303), nothing to do 2022-09-18T10:40:19.695655Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 403 2022-09-18T10:40:19.696634Z INFO update_engine: [libcurl_http_fetcher.cc(521)] Transfer resulted in an error (403), 0 bytes downloaded 2022-09-18T10:40:19.696729Z INFO update_engine: [libcurl_http_fetcher.cc(535)] No further proxies, indicating transfer complete 2022-09-18T10:40:19.696759Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T10:40:19.696787Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T10:40:19.696787Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T10:40:19.703641Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished OmahaRequestAction with code Unknown error: 2403 2022-09-18T10:40:19.703702Z INFO update_engine: [action_processor.cc(123)] ActionProcessor: Aborting processing due to failure. 2022-09-18T10:40:19.703779Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T10:40:19.704299Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T10:40:19.704357Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T10:40:19.704357Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T10:40:19.704394Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T10:40:19.704422Z INFO update_engine: [payload_state.cc(263)] Updating payload state for error code: 37 (ErrorCode::kOmahaErrorInHTTPResponse) 2022-09-18T10:40:19.704452Z INFO update_engine: [payload_state.cc(270)] Ignoring failures until we get a valid Omaha response. 2022-09-18T10:40:19.704479Z INFO update_engine: [update_attempter.cc(1759)] Reporting the error event 2022-09-18T10:40:19.707100Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T10:40:19.710368Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T10:40:19.710456Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T10:40:19.715588Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T10:40:19.716091Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T10:40:19.716304Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T10:40:20.489609Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 200 2022-09-18T10:40:20.492769Z INFO update_engine: [libcurl_http_fetcher.cc(562)] Transfer completed (200), 268 bytes downloaded 2022-09-18T10:40:20.492875Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T10:40:20.492921Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action OmahaRequestAction with code ErrorCode::kSuccess 2022-09-18T10:40:20.492951Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T10:40:20.492981Z INFO update_engine: [update_attempter.cc(1158)] Error event sent. 2022-09-18T10:40:20.500631Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T10:40:20.500723Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T10:40:20.500754Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T10:40:20.500896Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 11:23:06 GMT 2022-09-18T10:40:20.500945Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T10:40:20.500974Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T10:40:20.501001Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T10:40:20.501028Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T10:40:20.501055Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T10:40:20.501084Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T10:43:20.503202Z INFO update_engine: [main.cc(72)] A/B Update Engine terminating with exit code 0 2022-09-18T10:43:20.504537Z INFO update_engine: [base_message_loop.cc(77)] Leaking 4 canceled tasks. 2022-09-18T13:55:45.417307Z INFO update_engine: [main.cc(55)] A/B Update Engine starting 2022-09-18T13:55:45.423272Z INFO update_engine: [subprocess.cc(98)] Running "/usr/share/fydeos_shell/license-utils.sh id" 2022-09-18T13:55:45.905756Z INFO update_engine: [fydeos_license_checker.cc(41)] FydeOS license id: ce64e3f284f834dc03a22a75ce2600e6efd79e05 2022-09-18T13:55:45.911111Z INFO update_engine: [boot_control_chromeos.cc(180)] Booted from slot 1 (slot B) of 2 slots present on disk /dev/sda 2022-09-18T13:55:45.911268Z INFO update_engine: [real_system_state.cc(60)] Booted in dev mode. 2022-09-18T13:55:45.911361Z INFO update_engine: [real_system_state.cc(61)] Booted non-official build. 2022-09-18T13:55:45.913102Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-18T13:55:45.913475Z INFO update_engine: [omaha_request_params.cc(223)] Download channel for this attempt = stable-channel 2022-09-18T13:55:45.913506Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-18T13:55:45.913664Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T13:55:45.913664Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T13:55:45.917359Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-18T13:55:45.959386Z INFO update_engine: [payload_state.cc(894)] Current Response Signature = Payload 0: Size = 1392499954 Sha256 Hash = cf07a99e34de2fe672953a16ada277e15e2da1d6f2484b5b54d31aea2909d974 Metadata Size = 77327 Metadata Signature = Is Delta = 0 NumURLs = 1 Candidate Url0 = https://cdn-ota.fydeos.com/amd64-fydeos/stable-channel/15.0/14695.91.15.12/9f8770-full.gz Max Failure Count Per Url = 3 Disable Payload Backoff = 0 2022-09-18T13:55:45.965681Z INFO update_engine: [metrics_utils.cc(331)] Payload Attempt Number = 1 2022-09-18T13:55:45.966999Z INFO update_engine: [payload_state.cc(916)] Full Payload Attempt Number = 1 2022-09-18T13:55:45.969068Z INFO update_engine: [payload_state.cc(943)] Current URL Index = 0 2022-09-18T13:55:45.972461Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-18T13:55:45.973847Z INFO update_engine: [payload_state.cc(1000)] Current URL (Url0)'s Failure Count = 0 2022-09-18T13:55:45.981375Z INFO update_engine: [payload_state.cc(990)] URL Switch Count = 0 2022-09-18T13:55:45.983590Z INFO update_engine: [payload_state.cc(1025)] Backoff Expiry Time = 9/19/2022 4:08:26 GMT 2022-09-18T13:55:45.990613Z INFO update_engine: [metrics_utils.cc(348)] Update Monotonic Timestamp Start = 9/18/2022 8:43:28 GMT 2022-09-18T13:55:45.992363Z INFO update_engine: [payload_state.cc(1157)] Update Duration Uptime = 0s 2022-09-18T13:55:45.994459Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpsServer = 0 2022-09-18T13:55:45.998616Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpsServer = 0 2022-09-18T13:55:46.001063Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpServer = 0 2022-09-18T13:55:46.008097Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpServer = 0 2022-09-18T13:55:46.009683Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpPeer = 0 2022-09-18T13:55:46.012434Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpPeer = 0 2022-09-18T13:55:46.023229Z INFO update_engine: [metrics_utils.cc(323)] Number of Reboots during current update attempt = 0 2022-09-18T13:55:46.024666Z INFO update_engine: [payload_state.cc(1230)] Num Responses Seen = 0 2022-09-18T13:55:46.025135Z INFO update_engine: [payload_state.cc(1125)] Setting rollback-happened to 0. 2022-09-18T13:55:46.026457Z INFO update_engine: [payload_state.cc(1381)] p2p First Attempt Timestamp = 1/1/1601 0:00:00 GMT 2022-09-18T13:55:46.031430Z INFO update_engine: [payload_state.cc(1367)] p2p Num Attempts = 0 2022-09-18T13:55:46.036244Z ERROR update_engine: [real_system_state.cc(178)] Failed to set kernel_max_rollforward to infinity for device with test/dev image. 2022-09-18T13:55:46.036244Z ERROR update_engine: [real_system_state.cc(178)] Failed to set kernel_max_rollforward to infinity for device with test/dev image. 2022-09-18T13:55:46.036807Z INFO update_engine: [daemon_chromeos.cc(61)] Waiting for DBus object to be registered. 2022-09-18T13:55:46.047185Z INFO update_engine: [daemon_chromeos.cc(89)] Requesting telemetry info from cros_healthd. 2022-09-18T13:55:46.047752Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T13:55:46.047797Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T13:55:46.047827Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T13:55:46.051858Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 13:58:31 GMT 2022-09-18T13:55:46.051923Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T13:55:46.051952Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T13:55:46.051979Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T13:55:46.052028Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T13:55:46.052058Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T13:55:46.052087Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 2m45.872502s 2022-09-18T13:55:46.052602Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable au_p2p_enabled: "No value set for au_p2p_enabled" 2022-09-18T13:55:46.052668Z INFO update_engine: [update_attempter.cc(1928)] Not starting p2p at startup since it's not enabled. 2022-09-18T13:55:46.058800Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable au_p2p_enabled: "No value set for au_p2p_enabled" 2022-09-18T13:55:46.058909Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on p2p_enabled 2022-09-18T13:55:46.058941Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T13:55:46.058969Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on au_p2p_enabled 2022-09-18T13:55:46.058997Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 11h59m59.993659s 2022-09-18T13:55:46.396316Z INFO update_engine: [update_attempter.cc(2024)] Repeated updates has been enabled. 2022-09-18T13:56:31.047965Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting UpdateBootFlagsAction 2022-09-18T13:56:31.048407Z INFO update_engine: [update_boot_flags_action.cc(50)] Marking booted slot as good. 2022-09-18T13:56:31.048465Z INFO update_engine: [subprocess.cc(98)] Running "/usr/sbin/chromeos-setgoodkernel" 2022-09-18T13:56:31.295189Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action UpdateBootFlagsAction with code ErrorCode::kSuccess 2022-09-18T13:56:41.260687Z INFO update_engine: [real_device_policy_provider.cc(78)] Reloading and re-scheduling device policy due to signal received. 2022-09-18T13:58:31.929149Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T13:58:31.932725Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T13:58:31.932841Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T13:58:31.932879Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T13:58:31.935404Z INFO update_engine: [update_check_allowed_policy.cc(108)] Allowing update check. 2022-09-18T13:58:31.935521Z INFO update_engine: [update_attempter.cc(1105)] Running periodic update. 2022-09-18T13:58:31.940246Z INFO update_engine: [update_attempter.cc(254)] Last reported daily metrics 5h42m24.287702s ago. 2022-09-18T13:58:31.970226Z INFO update_engine: [update_attempter.cc(361)] Device policies/settings present 2022-09-18T13:58:31.971557Z INFO update_engine: [update_attempter.cc(505)] Scattering disabled since scatter factor is set to 0 2022-09-18T13:58:31.971680Z INFO update_engine: [update_attempter.cc(380)] p2p is not enabled - disallowing p2p for both downloading and sharing. 2022-09-18T13:58:31.971721Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-18T13:58:31.971751Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-18T13:58:31.979036Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-18T13:58:31.979215Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T13:58:31.979215Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T13:58:31.983859Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-18T13:58:31.983972Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable market_segment: "No value set for market_segment" 2022-09-18T13:58:31.984033Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable quick_fix_build_token: "No value set for quick_fix_build_token" 2022-09-18T13:58:31.984066Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_lts_tag: "No value set for release_lts_tag" 2022-09-18T13:58:31.984096Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_to_target_version: "No value set for rollback_to_target_version" 2022-09-18T13:58:31.984126Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_allowed_milestones: "No value set for rollback_allowed_milestones" 2022-09-18T13:58:31.998049Z INFO update_engine: [update_attempter.cc(448)] target_version_prefix = , rollback_allowed = 0, scatter_factor_in_seconds = 0s 2022-09-18T13:58:31.998192Z INFO update_engine: [update_attempter.cc(455)] Wall Clock Based Wait Enabled = 0, Update Check Count Wait Enabled = 0, Waiting Period = 0s 2022-09-18T13:58:31.998226Z INFO update_engine: [update_attempter.cc(463)] Use p2p For Downloading = 0, Use p2p For Sharing = 0 2022-09-18T13:58:31.998255Z INFO update_engine: [update_attempter.cc(470)] forced to obey proxies 2022-09-18T13:58:31.998282Z INFO update_engine: [update_attempter.cc(473)] proxy manual checks: 1 2022-09-18T13:58:31.999632Z INFO update_engine: [update_attempter.cc(1773)] Scheduling an action processor start. 2022-09-18T13:58:31.999836Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T13:58:32.007905Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T13:58:32.007982Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T13:58:32.021279Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T13:58:32.046155Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T13:58:32.046367Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T13:58:33.695774Z INFO update_engine: [libcurl_http_fetcher.cc(583)] HTTP response unsuccessful (403) or no payload (303), nothing to do 2022-09-18T13:58:33.698376Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 403 2022-09-18T13:58:33.699451Z INFO update_engine: [libcurl_http_fetcher.cc(521)] Transfer resulted in an error (403), 0 bytes downloaded 2022-09-18T13:58:33.699550Z INFO update_engine: [libcurl_http_fetcher.cc(535)] No further proxies, indicating transfer complete 2022-09-18T13:58:33.699611Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T13:58:33.699639Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T13:58:33.699639Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T13:58:33.704272Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished OmahaRequestAction with code Unknown error: 2403 2022-09-18T13:58:33.704353Z INFO update_engine: [action_processor.cc(123)] ActionProcessor: Aborting processing due to failure. 2022-09-18T13:58:33.705188Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T13:58:33.705265Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T13:58:33.705295Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T13:58:33.705295Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T13:58:33.705409Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T13:58:33.705437Z INFO update_engine: [payload_state.cc(263)] Updating payload state for error code: 37 (ErrorCode::kOmahaErrorInHTTPResponse) 2022-09-18T13:58:33.705466Z INFO update_engine: [payload_state.cc(270)] Ignoring failures until we get a valid Omaha response. 2022-09-18T13:58:33.705493Z INFO update_engine: [update_attempter.cc(1759)] Reporting the error event 2022-09-18T13:58:33.705810Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T13:58:33.711214Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T13:58:33.711301Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T13:58:33.718127Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T13:58:33.718636Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T13:58:33.718780Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T13:58:34.553421Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 200 2022-09-18T13:58:34.558577Z INFO update_engine: [libcurl_http_fetcher.cc(562)] Transfer completed (200), 268 bytes downloaded 2022-09-18T13:58:34.558695Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T13:58:34.559299Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action OmahaRequestAction with code ErrorCode::kSuccess 2022-09-18T13:58:34.559331Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T13:58:34.559362Z INFO update_engine: [update_attempter.cc(1158)] Error event sent. 2022-09-18T13:58:34.561990Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T13:58:34.562105Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T13:58:34.562137Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T13:58:34.562260Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 14:44:47 GMT 2022-09-18T13:58:34.562307Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T13:58:34.562335Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T13:58:34.562363Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T13:58:34.562390Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T13:58:34.562417Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T13:58:34.562445Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T14:03:34.679469Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T14:03:34.687047Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T14:03:34.687281Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T14:03:34.687353Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T14:03:34.687897Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 14:44:47 GMT 2022-09-18T14:03:34.687973Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T14:03:34.688043Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T14:03:34.688087Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T14:03:34.688132Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T14:03:34.688173Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T14:03:34.688222Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T14:08:34.788941Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T14:08:34.795638Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T14:08:34.795795Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T14:08:34.795844Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T14:08:34.799238Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 14:44:47 GMT 2022-09-18T14:08:34.799367Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T14:08:34.799398Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T14:08:34.799425Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T14:08:34.799454Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T14:08:34.799481Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T14:08:34.799509Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T14:12:48.769617Z INFO update_engine: [common_service.cc(82)] Attempt update: app_version="" omaha_url="" flags=0x0 interactive=yes 2022-09-18T14:12:48.770988Z INFO update_engine: [update_attempter.cc(979)] Forced update check requested. 2022-09-18T14:12:48.773973Z INFO update_engine: [update_attempter.cc(2002)] Non-official build; allowing any update source. 2022-09-18T14:12:48.775412Z INFO update_engine: [evaluation_context.cc(108)] ValueChanged() called for variable forced_update_requested 2022-09-18T14:12:48.776961Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T14:12:48.777140Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T14:12:48.777204Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T14:12:48.777265Z INFO update_engine: [interactive_update_policy_impl.cc(40)] Forced update signaled (interactive), allowing update check. 2022-09-18T14:12:48.777309Z INFO update_engine: [update_attempter.cc(1105)] Running interactive update. 2022-09-18T14:12:48.780316Z INFO update_engine: [update_attempter.cc(254)] Last reported daily metrics 5h56m41.129647s ago. 2022-09-18T14:12:48.805600Z INFO update_engine: [update_attempter.cc(361)] Device policies/settings present 2022-09-18T14:12:48.806904Z INFO update_engine: [update_attempter.cc(505)] Scattering disabled since scatter factor is set to 0 2022-09-18T14:12:48.807040Z INFO update_engine: [update_attempter.cc(380)] p2p is not enabled - disallowing p2p for both downloading and sharing. 2022-09-18T14:12:48.807087Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-18T14:12:48.807128Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-18T14:12:48.809092Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-18T14:12:48.809270Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T14:12:48.809270Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T14:12:48.810704Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-18T14:12:48.810814Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable market_segment: "No value set for market_segment" 2022-09-18T14:12:48.810848Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable quick_fix_build_token: "No value set for quick_fix_build_token" 2022-09-18T14:12:48.810879Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_lts_tag: "No value set for release_lts_tag" 2022-09-18T14:12:48.810910Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_to_target_version: "No value set for rollback_to_target_version" 2022-09-18T14:12:48.810952Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_allowed_milestones: "No value set for rollback_allowed_milestones" 2022-09-18T14:12:48.821213Z INFO update_engine: [update_attempter.cc(448)] target_version_prefix = , rollback_allowed = 0, scatter_factor_in_seconds = 0s 2022-09-18T14:12:48.821339Z INFO update_engine: [update_attempter.cc(455)] Wall Clock Based Wait Enabled = 0, Update Check Count Wait Enabled = 0, Waiting Period = 0s 2022-09-18T14:12:48.821370Z INFO update_engine: [update_attempter.cc(463)] Use p2p For Downloading = 0, Use p2p For Sharing = 0 2022-09-18T14:12:48.825127Z INFO update_engine: [update_attempter.cc(1773)] Scheduling an action processor start. 2022-09-18T14:12:48.825456Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T14:12:48.829968Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T14:12:48.830083Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T14:12:48.841244Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T14:12:48.854454Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T14:12:48.854849Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T14:12:50.150253Z INFO update_engine: [libcurl_http_fetcher.cc(583)] HTTP response unsuccessful (403) or no payload (303), nothing to do 2022-09-18T14:12:50.157636Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 403 2022-09-18T14:12:50.161119Z INFO update_engine: [libcurl_http_fetcher.cc(521)] Transfer resulted in an error (403), 0 bytes downloaded 2022-09-18T14:12:50.161343Z INFO update_engine: [libcurl_http_fetcher.cc(535)] No further proxies, indicating transfer complete 2022-09-18T14:12:50.161541Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T14:12:50.161668Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T14:12:50.161668Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T14:12:50.171721Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished OmahaRequestAction with code Unknown error: 2403 2022-09-18T14:12:50.171896Z INFO update_engine: [action_processor.cc(123)] ActionProcessor: Aborting processing due to failure. 2022-09-18T14:12:50.173792Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T14:12:50.173939Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T14:12:50.174129Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T14:12:50.174129Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T14:12:50.174292Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T14:12:50.174416Z INFO update_engine: [payload_state.cc(263)] Updating payload state for error code: 37 (ErrorCode::kOmahaErrorInHTTPResponse) 2022-09-18T14:12:50.174544Z INFO update_engine: [payload_state.cc(270)] Ignoring failures until we get a valid Omaha response. 2022-09-18T14:12:50.174663Z INFO update_engine: [update_attempter.cc(1759)] Reporting the error event 2022-09-18T14:12:50.175563Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T14:12:50.185391Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T14:12:50.185627Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T14:12:50.194720Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T14:12:50.195553Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T14:12:50.195792Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T14:12:50.997162Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 200 2022-09-18T14:12:51.000377Z INFO update_engine: [libcurl_http_fetcher.cc(562)] Transfer completed (200), 268 bytes downloaded 2022-09-18T14:12:51.000484Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T14:12:51.000531Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action OmahaRequestAction with code ErrorCode::kSuccess 2022-09-18T14:12:51.000562Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T14:12:51.000591Z INFO update_engine: [update_attempter.cc(1158)] Error event sent. 2022-09-18T14:12:51.008232Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T14:12:51.008288Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T14:12:51.008321Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T14:12:51.008445Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 15:02:28 GMT 2022-09-18T14:12:51.008490Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T14:12:51.008518Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T14:12:51.008546Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T14:12:51.008572Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T14:12:51.008600Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T14:12:51.008627Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T14:17:51.108612Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T14:17:51.108795Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T14:17:51.108878Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T14:17:51.108918Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T14:17:51.109152Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 15:02:28 GMT 2022-09-18T14:17:51.109194Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T14:17:51.109222Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T14:17:51.109249Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T14:17:51.109276Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T14:17:51.109303Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T14:17:51.109331Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T14:22:51.209167Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T14:22:51.214852Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T14:22:51.214932Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T14:22:51.214965Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T14:22:51.216248Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 15:02:28 GMT 2022-09-18T14:22:51.216346Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T14:22:51.216378Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T14:22:51.216407Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T14:22:51.216436Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T14:22:51.216465Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T14:22:51.216495Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T14:23:58.240482Z INFO update_engine: [common_service.cc(82)] Attempt update: app_version="" omaha_url="" flags=0x0 interactive=yes 2022-09-18T14:23:58.255053Z INFO update_engine: [update_attempter.cc(979)] Forced update check requested. 2022-09-18T14:23:58.260536Z INFO update_engine: [update_attempter.cc(2002)] Non-official build; allowing any update source. 2022-09-18T14:23:58.262290Z INFO update_engine: [evaluation_context.cc(108)] ValueChanged() called for variable forced_update_requested 2022-09-18T14:23:58.262564Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T14:23:58.262711Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T14:23:58.262852Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T14:23:58.262994Z INFO update_engine: [interactive_update_policy_impl.cc(40)] Forced update signaled (interactive), allowing update check. 2022-09-18T14:23:58.263219Z INFO update_engine: [update_attempter.cc(1105)] Running interactive update. 2022-09-18T14:23:58.266906Z INFO update_engine: [update_attempter.cc(254)] Last reported daily metrics 6h7m50.615502s ago. 2022-09-18T14:23:58.314149Z INFO update_engine: [update_attempter.cc(361)] Device policies/settings present 2022-09-18T14:23:58.316370Z INFO update_engine: [update_attempter.cc(505)] Scattering disabled since scatter factor is set to 0 2022-09-18T14:23:58.316593Z INFO update_engine: [update_attempter.cc(380)] p2p is not enabled - disallowing p2p for both downloading and sharing. 2022-09-18T14:23:58.316661Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-18T14:23:58.316725Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-18T14:23:58.323562Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-18T14:23:58.323785Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T14:23:58.323785Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-18T14:23:58.325029Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-18T14:23:58.325133Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable market_segment: "No value set for market_segment" 2022-09-18T14:23:58.325165Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable quick_fix_build_token: "No value set for quick_fix_build_token" 2022-09-18T14:23:58.325194Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_lts_tag: "No value set for release_lts_tag" 2022-09-18T14:23:58.325224Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_to_target_version: "No value set for rollback_to_target_version" 2022-09-18T14:23:58.325254Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_allowed_milestones: "No value set for rollback_allowed_milestones" 2022-09-18T14:23:58.334124Z INFO update_engine: [update_attempter.cc(448)] target_version_prefix = , rollback_allowed = 0, scatter_factor_in_seconds = 0s 2022-09-18T14:23:58.334234Z INFO update_engine: [update_attempter.cc(455)] Wall Clock Based Wait Enabled = 0, Update Check Count Wait Enabled = 0, Waiting Period = 0s 2022-09-18T14:23:58.334267Z INFO update_engine: [update_attempter.cc(463)] Use p2p For Downloading = 0, Use p2p For Sharing = 0 2022-09-18T14:23:58.336732Z INFO update_engine: [update_attempter.cc(1773)] Scheduling an action processor start. 2022-09-18T14:23:58.337069Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T14:23:58.345947Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T14:23:58.346047Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T14:23:58.354092Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T14:23:58.363938Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T14:23:58.364157Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T14:24:01.519567Z INFO update_engine: [libcurl_http_fetcher.cc(583)] HTTP response unsuccessful (403) or no payload (303), nothing to do 2022-09-18T14:24:01.527556Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 403 2022-09-18T14:24:01.530280Z INFO update_engine: [libcurl_http_fetcher.cc(521)] Transfer resulted in an error (403), 0 bytes downloaded 2022-09-18T14:24:01.530564Z INFO update_engine: [libcurl_http_fetcher.cc(535)] No further proxies, indicating transfer complete 2022-09-18T14:24:01.530693Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T14:24:01.530819Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T14:24:01.530819Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-18T14:24:01.541375Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished OmahaRequestAction with code Unknown error: 2403 2022-09-18T14:24:01.541435Z INFO update_engine: [action_processor.cc(123)] ActionProcessor: Aborting processing due to failure. 2022-09-18T14:24:01.542500Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T14:24:01.542596Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T14:24:01.542626Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T14:24:01.542626Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-18T14:24:01.542664Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-18T14:24:01.542692Z INFO update_engine: [payload_state.cc(263)] Updating payload state for error code: 37 (ErrorCode::kOmahaErrorInHTTPResponse) 2022-09-18T14:24:01.542722Z INFO update_engine: [payload_state.cc(270)] Ignoring failures until we get a valid Omaha response. 2022-09-18T14:24:01.542749Z INFO update_engine: [update_attempter.cc(1759)] Reporting the error event 2022-09-18T14:24:01.544430Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-18T14:24:01.546085Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-18T14:24:01.546168Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-18T14:24:01.552815Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-18T14:24:01.553625Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-18T14:24:01.553779Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-18T14:24:02.434376Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 200 2022-09-18T14:24:02.445677Z INFO update_engine: [libcurl_http_fetcher.cc(562)] Transfer completed (200), 268 bytes downloaded 2022-09-18T14:24:02.445918Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-18T14:24:02.446152Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action OmahaRequestAction with code ErrorCode::kSuccess 2022-09-18T14:24:02.446298Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-18T14:24:02.446502Z INFO update_engine: [update_attempter.cc(1158)] Error event sent. 2022-09-18T14:24:02.455293Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T14:24:02.455402Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T14:24:02.455436Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T14:24:02.455591Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 15:09:37 GMT 2022-09-18T14:24:02.455632Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T14:24:02.455660Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T14:24:02.455687Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T14:24:02.455714Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T14:24:02.455740Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T14:24:02.455769Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T14:29:02.541021Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T14:29:02.548845Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T14:29:02.549061Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T14:29:02.549139Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T14:29:02.556101Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 15:09:37 GMT 2022-09-18T14:29:02.556233Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T14:29:02.556265Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T14:29:02.556334Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T14:29:02.556364Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T14:29:02.556393Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T14:29:02.556470Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T14:34:02.673923Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T14:34:02.684395Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T14:34:02.684588Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T14:34:02.684658Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T14:34:02.686643Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 15:09:37 GMT 2022-09-18T14:34:02.686766Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T14:34:02.686808Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T14:34:02.686847Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T14:34:02.686924Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T14:34:02.686961Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T14:34:02.687022Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T14:39:02.706126Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-18T14:39:02.713185Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-18T14:39:02.713457Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-18T14:39:02.713753Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-18T14:39:02.720737Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/18/2022 15:09:37 GMT 2022-09-18T14:39:02.721077Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-18T14:39:02.721221Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-18T14:39:02.721367Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-18T14:39:02.721501Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-18T14:39:02.721630Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-18T14:39:02.721764Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-18T14:42:31.408318Z INFO update_engine: [main.cc(72)] A/B Update Engine terminating with exit code 0 2022-09-18T14:42:31.423992Z INFO update_engine: [base_message_loop.cc(77)] Leaking 4 canceled tasks. 2022-09-19T16:51:58.379316Z INFO update_engine: [main.cc(55)] A/B Update Engine starting 2022-09-19T16:51:58.386072Z INFO update_engine: [subprocess.cc(98)] Running "/usr/share/fydeos_shell/license-utils.sh id" 2022-09-19T16:51:58.905647Z INFO update_engine: [fydeos_license_checker.cc(41)] FydeOS license id: ce64e3f284f834dc03a22a75ce2600e6efd79e05 2022-09-19T16:51:58.914388Z INFO update_engine: [boot_control_chromeos.cc(180)] Booted from slot 1 (slot B) of 2 slots present on disk /dev/sda 2022-09-19T16:51:58.914591Z INFO update_engine: [real_system_state.cc(60)] Booted in dev mode. 2022-09-19T16:51:58.914689Z INFO update_engine: [real_system_state.cc(61)] Booted non-official build. 2022-09-19T16:51:58.916422Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-19T16:51:58.916797Z INFO update_engine: [omaha_request_params.cc(223)] Download channel for this attempt = stable-channel 2022-09-19T16:51:58.916829Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-19T16:51:58.916943Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-19T16:51:58.916943Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-19T16:51:58.924585Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-19T16:51:58.961309Z INFO update_engine: [payload_state.cc(894)] Current Response Signature = Payload 0: Size = 1392499954 Sha256 Hash = cf07a99e34de2fe672953a16ada277e15e2da1d6f2484b5b54d31aea2909d974 Metadata Size = 77327 Metadata Signature = Is Delta = 0 NumURLs = 1 Candidate Url0 = https://cdn-ota.fydeos.com/amd64-fydeos/stable-channel/15.0/14695.91.15.12/9f8770-full.gz Max Failure Count Per Url = 3 Disable Payload Backoff = 0 2022-09-19T16:51:58.965032Z INFO update_engine: [metrics_utils.cc(331)] Payload Attempt Number = 1 2022-09-19T16:51:58.967329Z INFO update_engine: [payload_state.cc(916)] Full Payload Attempt Number = 1 2022-09-19T16:51:58.970630Z INFO update_engine: [payload_state.cc(943)] Current URL Index = 0 2022-09-19T16:51:58.970983Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-19T16:51:58.973827Z INFO update_engine: [payload_state.cc(1000)] Current URL (Url0)'s Failure Count = 0 2022-09-19T16:51:58.977090Z INFO update_engine: [payload_state.cc(990)] URL Switch Count = 0 2022-09-19T16:51:58.980088Z INFO update_engine: [payload_state.cc(1025)] Backoff Expiry Time = 9/19/2022 4:08:26 GMT 2022-09-19T16:51:58.982268Z INFO update_engine: [metrics_utils.cc(348)] Update Monotonic Timestamp Start = 9/18/2022 8:43:28 GMT 2022-09-19T16:51:58.987077Z INFO update_engine: [payload_state.cc(1157)] Update Duration Uptime = 0s 2022-09-19T16:51:58.988070Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpsServer = 0 2022-09-19T16:51:58.990370Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpsServer = 0 2022-09-19T16:51:58.995582Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpServer = 0 2022-09-19T16:51:58.997494Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpServer = 0 2022-09-19T16:51:58.999228Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpPeer = 0 2022-09-19T16:51:59.001199Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpPeer = 0 2022-09-19T16:51:59.003386Z INFO update_engine: [metrics_utils.cc(323)] Number of Reboots during current update attempt = 0 2022-09-19T16:51:59.004862Z INFO update_engine: [payload_state.cc(1230)] Num Responses Seen = 0 2022-09-19T16:51:59.005336Z INFO update_engine: [payload_state.cc(1125)] Setting rollback-happened to 0. 2022-09-19T16:51:59.007124Z INFO update_engine: [payload_state.cc(1381)] p2p First Attempt Timestamp = 1/1/1601 0:00:00 GMT 2022-09-19T16:51:59.013387Z INFO update_engine: [payload_state.cc(1367)] p2p Num Attempts = 0 2022-09-19T16:51:59.013875Z ERROR update_engine: [real_system_state.cc(178)] Failed to set kernel_max_rollforward to infinity for device with test/dev image. 2022-09-19T16:51:59.013875Z ERROR update_engine: [real_system_state.cc(178)] Failed to set kernel_max_rollforward to infinity for device with test/dev image. 2022-09-19T16:51:59.014383Z INFO update_engine: [daemon_chromeos.cc(61)] Waiting for DBus object to be registered. 2022-09-19T16:51:59.022628Z INFO update_engine: [daemon_chromeos.cc(89)] Requesting telemetry info from cros_healthd. 2022-09-19T16:51:59.024797Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-19T16:51:59.024897Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-19T16:51:59.024928Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-19T16:51:59.025190Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/19/2022 17:03:17 GMT 2022-09-19T16:51:59.025235Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-19T16:51:59.025265Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-19T16:51:59.025292Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-19T16:51:59.025319Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-19T16:51:59.025346Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-19T16:51:59.025375Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-19T16:51:59.028991Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable au_p2p_enabled: "No value set for au_p2p_enabled" 2022-09-19T16:51:59.029138Z INFO update_engine: [update_attempter.cc(1928)] Not starting p2p at startup since it's not enabled. 2022-09-19T16:51:59.029241Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable au_p2p_enabled: "No value set for au_p2p_enabled" 2022-09-19T16:51:59.029273Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on p2p_enabled 2022-09-19T16:51:59.029302Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-19T16:51:59.029329Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on au_p2p_enabled 2022-09-19T16:51:59.029358Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 11h59m59.999758s 2022-09-19T16:51:59.241276Z INFO update_engine: [update_attempter.cc(2024)] Repeated updates has been enabled. 2022-09-19T16:52:38.022952Z INFO update_engine: [real_device_policy_provider.cc(78)] Reloading and re-scheduling device policy due to signal received. 2022-09-19T16:52:44.029141Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting UpdateBootFlagsAction 2022-09-19T16:52:44.029564Z INFO update_engine: [update_boot_flags_action.cc(50)] Marking booted slot as good. 2022-09-19T16:52:44.029621Z INFO update_engine: [subprocess.cc(98)] Running "/usr/sbin/chromeos-setgoodkernel" 2022-09-19T16:52:44.117660Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action UpdateBootFlagsAction with code ErrorCode::kSuccess 2022-09-19T16:56:59.118547Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-19T16:56:59.126382Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-19T16:56:59.126533Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-19T16:56:59.126566Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-19T16:56:59.128204Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/19/2022 17:03:17 GMT 2022-09-19T16:56:59.128312Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-19T16:56:59.128341Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-19T16:56:59.128405Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-19T16:56:59.128434Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-19T16:56:59.128464Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-19T16:56:59.128495Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-19T17:01:59.246561Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-19T17:01:59.258520Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-19T17:01:59.258875Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-19T17:01:59.259111Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-19T17:01:59.265449Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/19/2022 17:03:17 GMT 2022-09-19T17:01:59.265728Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-19T17:01:59.265869Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-19T17:01:59.265998Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-19T17:01:59.266213Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-19T17:01:59.266367Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-19T17:01:59.266507Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 1m18.672642s 2022-09-19T17:03:17.950384Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-19T17:03:17.950708Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-19T17:03:17.950864Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-19T17:03:17.951115Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-19T17:03:17.951607Z INFO update_engine: [update_check_allowed_policy.cc(108)] Allowing update check. 2022-09-19T17:03:17.951851Z INFO update_engine: [update_attempter.cc(1105)] Running periodic update. 2022-09-19T17:03:17.960640Z INFO update_engine: [update_attempter.cc(258)] Last reported daily metrics 1d8h47m10.310598s ago, which is more than 24 hours ago. 2022-09-19T17:03:17.960862Z INFO update_engine: [update_attempter.cc(264)] Reporting daily metrics. 2022-09-19T17:03:18.014255Z INFO update_engine: [update_attempter.cc(361)] Device policies/settings present 2022-09-19T17:03:18.016791Z INFO update_engine: [update_attempter.cc(505)] Scattering disabled since scatter factor is set to 0 2022-09-19T17:03:18.017235Z INFO update_engine: [update_attempter.cc(380)] p2p is not enabled - disallowing p2p for both downloading and sharing. 2022-09-19T17:03:18.017384Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-19T17:03:18.017522Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-19T17:03:18.029417Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-19T17:03:18.029906Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-19T17:03:18.029906Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-19T17:03:18.036938Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-19T17:03:18.037274Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable market_segment: "No value set for market_segment" 2022-09-19T17:03:18.037435Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable quick_fix_build_token: "No value set for quick_fix_build_token" 2022-09-19T17:03:18.037567Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_lts_tag: "No value set for release_lts_tag" 2022-09-19T17:03:18.037699Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_to_target_version: "No value set for rollback_to_target_version" 2022-09-19T17:03:18.037829Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_allowed_milestones: "No value set for rollback_allowed_milestones" 2022-09-19T17:03:18.059564Z INFO update_engine: [update_attempter.cc(448)] target_version_prefix = , rollback_allowed = 0, scatter_factor_in_seconds = 0s 2022-09-19T17:03:18.059810Z INFO update_engine: [update_attempter.cc(455)] Wall Clock Based Wait Enabled = 0, Update Check Count Wait Enabled = 0, Waiting Period = 0s 2022-09-19T17:03:18.059962Z INFO update_engine: [update_attempter.cc(463)] Use p2p For Downloading = 0, Use p2p For Sharing = 0 2022-09-19T17:03:18.060180Z INFO update_engine: [update_attempter.cc(470)] forced to obey proxies 2022-09-19T17:03:18.060304Z INFO update_engine: [update_attempter.cc(473)] proxy manual checks: 1 2022-09-19T17:03:18.068217Z INFO update_engine: [update_attempter.cc(1773)] Scheduling an action processor start. 2022-09-19T17:03:18.068826Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-19T17:03:18.081337Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-19T17:03:18.081540Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-19T17:03:18.096487Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-19T17:03:18.136991Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-19T17:03:18.137593Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-19T17:03:19.500618Z INFO update_engine: [libcurl_http_fetcher.cc(583)] HTTP response unsuccessful (403) or no payload (333), nothing to do 2022-09-19T17:03:19.506478Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 403 2022-09-19T17:03:19.508779Z INFO update_engine: [libcurl_http_fetcher.cc(521)] Transfer resulted in an error (403), 0 bytes downloaded 2022-09-19T17:03:19.508955Z INFO update_engine: [libcurl_http_fetcher.cc(535)] No further proxies, indicating transfer complete 2022-09-19T17:03:19.509114Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-19T17:03:19.509269Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-19T17:03:19.509269Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-19T17:03:19.518499Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished OmahaRequestAction with code Unknown error: 2403 2022-09-19T17:03:19.518636Z INFO update_engine: [action_processor.cc(123)] ActionProcessor: Aborting processing due to failure. 2022-09-19T17:03:19.518801Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-19T17:03:19.518896Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-19T17:03:19.518992Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-19T17:03:19.518992Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-19T17:03:19.519170Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-19T17:03:19.519264Z INFO update_engine: [payload_state.cc(263)] Updating payload state for error code: 37 (ErrorCode::kOmahaErrorInHTTPResponse) 2022-09-19T17:03:19.519364Z INFO update_engine: [payload_state.cc(270)] Ignoring failures until we get a valid Omaha response. 2022-09-19T17:03:19.519455Z INFO update_engine: [update_attempter.cc(1759)] Reporting the error event 2022-09-19T17:03:19.522779Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-19T17:03:19.526071Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-19T17:03:19.526223Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-19T17:03:19.532230Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-19T17:03:19.533435Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-19T17:03:19.533781Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-19T17:03:20.338981Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 200 2022-09-19T17:03:20.341860Z INFO update_engine: [libcurl_http_fetcher.cc(562)] Transfer completed (200), 268 bytes downloaded 2022-09-19T17:03:20.341963Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-19T17:03:20.342051Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action OmahaRequestAction with code ErrorCode::kSuccess 2022-09-19T17:03:20.342085Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-19T17:03:20.342115Z INFO update_engine: [update_attempter.cc(1158)] Error event sent. 2022-09-19T17:03:20.356141Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-19T17:03:20.356311Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-19T17:03:20.356461Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-19T17:03:20.356699Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/19/2022 17:45:59 GMT 2022-09-19T17:03:20.356828Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-19T17:03:20.356912Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-19T17:03:20.356995Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-19T17:03:20.357128Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-19T17:03:20.357213Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-19T17:03:20.357300Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-19T17:08:20.457601Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-19T17:08:20.463565Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-19T17:08:20.463679Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-19T17:08:20.463721Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-19T17:08:20.463965Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/19/2022 17:45:59 GMT 2022-09-19T17:08:20.464047Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-19T17:08:20.464091Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-19T17:08:20.464128Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-19T17:08:20.464167Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-19T17:08:20.464204Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-19T17:08:20.464244Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-19T17:13:20.572377Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-19T17:13:20.578895Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-19T17:13:20.579094Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-19T17:13:20.579148Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-19T17:13:20.581600Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/19/2022 17:45:59 GMT 2022-09-19T17:13:20.581732Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-19T17:13:20.581763Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-19T17:13:20.581793Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-19T17:13:20.581847Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-19T17:13:20.581878Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-19T17:13:20.581935Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-19T17:18:20.687777Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-19T17:18:20.698092Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-19T17:18:20.698267Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-19T17:18:20.698339Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-19T17:18:20.706237Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/19/2022 17:45:59 GMT 2022-09-19T17:18:20.706393Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-19T17:18:20.706426Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-19T17:18:20.706455Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-19T17:18:20.706485Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-19T17:18:20.706515Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-19T17:18:20.706569Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-19T17:23:20.821381Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-19T17:23:20.838368Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-19T17:23:20.840316Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-19T17:23:20.840626Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-19T17:23:20.846569Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/19/2022 17:45:59 GMT 2022-09-19T17:23:20.846702Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-19T17:23:20.846751Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-19T17:23:20.846797Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-19T17:23:20.846843Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-19T17:23:20.846889Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-19T17:23:20.846937Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s 2022-09-19T17:26:28.864066Z INFO update_engine: [main.cc(72)] A/B Update Engine terminating with exit code 0 2022-09-19T17:26:28.874227Z INFO update_engine: [base_message_loop.cc(77)] Leaking 4 canceled tasks. 2022-09-20T16:01:24.492094Z INFO update_engine: [main.cc(55)] A/B Update Engine starting 2022-09-20T16:01:24.498134Z INFO update_engine: [subprocess.cc(98)] Running "/usr/share/fydeos_shell/license-utils.sh id" 2022-09-20T16:01:25.029435Z INFO update_engine: [fydeos_license_checker.cc(41)] FydeOS license id: ce64e3f284f834dc03a22a75ce2600e6efd79e05 2022-09-20T16:01:25.034591Z INFO update_engine: [boot_control_chromeos.cc(180)] Booted from slot 1 (slot B) of 2 slots present on disk /dev/sda 2022-09-20T16:01:25.034744Z INFO update_engine: [real_system_state.cc(60)] Booted in dev mode. 2022-09-20T16:01:25.034838Z INFO update_engine: [real_system_state.cc(61)] Booted non-official build. 2022-09-20T16:01:25.036600Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-20T16:01:25.037077Z INFO update_engine: [omaha_request_params.cc(223)] Download channel for this attempt = stable-channel 2022-09-20T16:01:25.037117Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-20T16:01:25.037231Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-20T16:01:25.037231Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-20T16:01:25.046088Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-20T16:01:25.325820Z INFO update_engine: [payload_state.cc(894)] Current Response Signature = Payload 0: Size = 1392499954 Sha256 Hash = cf07a99e34de2fe672953a16ada277e15e2da1d6f2484b5b54d31aea2909d974 Metadata Size = 77327 Metadata Signature = Is Delta = 0 NumURLs = 1 Candidate Url0 = https://cdn-ota.fydeos.com/amd64-fydeos/stable-channel/15.0/14695.91.15.12/9f8770-full.gz Max Failure Count Per Url = 3 Disable Payload Backoff = 0 2022-09-20T16:01:25.328084Z INFO update_engine: [metrics_utils.cc(331)] Payload Attempt Number = 1 2022-09-20T16:01:25.335571Z INFO update_engine: [payload_state.cc(916)] Full Payload Attempt Number = 1 2022-09-20T16:01:25.340890Z INFO update_engine: [payload_state.cc(943)] Current URL Index = 0 2022-09-20T16:01:25.341285Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-20T16:01:25.344025Z INFO update_engine: [payload_state.cc(1000)] Current URL (Url0)'s Failure Count = 0 2022-09-20T16:01:25.345866Z INFO update_engine: [payload_state.cc(990)] URL Switch Count = 0 2022-09-20T16:01:25.347701Z INFO update_engine: [payload_state.cc(1025)] Backoff Expiry Time = 9/19/2022 4:08:26 GMT 2022-09-20T16:01:25.349915Z INFO update_engine: [metrics_utils.cc(348)] Update Monotonic Timestamp Start = 9/18/2022 8:43:28 GMT 2022-09-20T16:01:25.352474Z INFO update_engine: [payload_state.cc(1157)] Update Duration Uptime = 0s 2022-09-20T16:01:25.354298Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpsServer = 0 2022-09-20T16:01:25.356169Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpsServer = 0 2022-09-20T16:01:25.358051Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpServer = 0 2022-09-20T16:01:25.361406Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpServer = 0 2022-09-20T16:01:25.363091Z INFO update_engine: [payload_state.cc(1198)] Current bytes downloaded for HttpPeer = 0 2022-09-20T16:01:25.366171Z INFO update_engine: [payload_state.cc(1220)] Total bytes downloaded for HttpPeer = 0 2022-09-20T16:01:25.368246Z INFO update_engine: [metrics_utils.cc(323)] Number of Reboots during current update attempt = 0 2022-09-20T16:01:25.370345Z INFO update_engine: [payload_state.cc(1230)] Num Responses Seen = 0 2022-09-20T16:01:25.370724Z INFO update_engine: [payload_state.cc(1125)] Setting rollback-happened to 0. 2022-09-20T16:01:25.373630Z INFO update_engine: [payload_state.cc(1381)] p2p First Attempt Timestamp = 1/1/1601 0:00:00 GMT 2022-09-20T16:01:25.377135Z INFO update_engine: [payload_state.cc(1367)] p2p Num Attempts = 0 2022-09-20T16:01:25.377752Z ERROR update_engine: [real_system_state.cc(178)] Failed to set kernel_max_rollforward to infinity for device with test/dev image. 2022-09-20T16:01:25.377752Z ERROR update_engine: [real_system_state.cc(178)] Failed to set kernel_max_rollforward to infinity for device with test/dev image. 2022-09-20T16:01:25.378311Z INFO update_engine: [daemon_chromeos.cc(61)] Waiting for DBus object to be registered. 2022-09-20T16:01:25.391739Z INFO update_engine: [daemon_chromeos.cc(89)] Requesting telemetry info from cros_healthd. 2022-09-20T16:01:25.392317Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-20T16:01:25.392374Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-20T16:01:25.392405Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-20T16:01:25.392599Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/20/2022 16:03:38 GMT 2022-09-20T16:01:25.392639Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-20T16:01:25.392669Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-20T16:01:25.392696Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-20T16:01:25.392723Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-20T16:01:25.392750Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-20T16:01:25.392778Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 2m12.66493s 2022-09-20T16:01:25.393172Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable au_p2p_enabled: "No value set for au_p2p_enabled" 2022-09-20T16:01:25.393861Z INFO update_engine: [update_attempter.cc(1928)] Not starting p2p at startup since it's not enabled. 2022-09-20T16:01:25.393991Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable au_p2p_enabled: "No value set for au_p2p_enabled" 2022-09-20T16:01:25.394060Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on p2p_enabled 2022-09-20T16:01:25.394088Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-20T16:01:25.394116Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on au_p2p_enabled 2022-09-20T16:01:25.394144Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 11h59m59.999695s 2022-09-20T16:01:25.607884Z INFO update_engine: [update_attempter.cc(2024)] Repeated updates has been enabled. 2022-09-20T16:02:00.378209Z INFO update_engine: [real_device_policy_provider.cc(78)] Reloading and re-scheduling device policy due to signal received. 2022-09-20T16:02:10.402360Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting UpdateBootFlagsAction 2022-09-20T16:02:10.406179Z INFO update_engine: [update_boot_flags_action.cc(50)] Marking booted slot as good. 2022-09-20T16:02:10.406271Z INFO update_engine: [subprocess.cc(98)] Running "/usr/sbin/chromeos-setgoodkernel" 2022-09-20T16:02:10.604862Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action UpdateBootFlagsAction with code ErrorCode::kSuccess 2022-09-20T16:03:38.133290Z INFO update_engine: [evaluation_context.cc(113)] OnTimeout() called due to poll interval 2022-09-20T16:03:38.150788Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-20T16:03:38.150975Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-20T16:03:38.151076Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-20T16:03:38.157073Z INFO update_engine: [update_check_allowed_policy.cc(108)] Allowing update check. 2022-09-20T16:03:38.157195Z INFO update_engine: [update_attempter.cc(1105)] Running periodic update. 2022-09-20T16:03:38.162263Z INFO update_engine: [update_attempter.cc(254)] Last reported daily metrics 23h0m20.201419s ago. 2022-09-20T16:03:38.226891Z INFO update_engine: [update_attempter.cc(361)] Device policies/settings present 2022-09-20T16:03:38.229243Z INFO update_engine: [update_attempter.cc(505)] Scattering disabled since scatter factor is set to 0 2022-09-20T16:03:38.229382Z INFO update_engine: [update_attempter.cc(380)] p2p is not enabled - disallowing p2p for both downloading and sharing. 2022-09-20T16:03:38.229426Z INFO update_engine: [payload_state.cc(594)] Current download source: Unknown 2022-09-20T16:03:38.229457Z INFO update_engine: [omaha_request_params.cc(72)] Initializing parameters for this update attempt 2022-09-20T16:03:38.245037Z INFO update_engine: [omaha_request_params.cc(83)] Running from channel stable-channel 2022-09-20T16:03:38.245230Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-20T16:03:38.245230Z ERROR update_engine: [hardware_chromeos.cc(199)] Unable to read crossystem key hwid 2022-09-20T16:03:38.249751Z INFO update_engine: [omaha_request_params.cc(166)] No target channel mandated by policy. 2022-09-20T16:03:38.249876Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable market_segment: "No value set for market_segment" 2022-09-20T16:03:38.249908Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable quick_fix_build_token: "No value set for quick_fix_build_token" 2022-09-20T16:03:38.249939Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_lts_tag: "No value set for release_lts_tag" 2022-09-20T16:03:38.249968Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_to_target_version: "No value set for rollback_to_target_version" 2022-09-20T16:03:38.249998Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable rollback_allowed_milestones: "No value set for rollback_allowed_milestones" 2022-09-20T16:03:38.283963Z INFO update_engine: [update_attempter.cc(448)] target_version_prefix = , rollback_allowed = 0, scatter_factor_in_seconds = 0s 2022-09-20T16:03:38.284095Z INFO update_engine: [update_attempter.cc(455)] Wall Clock Based Wait Enabled = 0, Update Check Count Wait Enabled = 0, Waiting Period = 0s 2022-09-20T16:03:38.284128Z INFO update_engine: [update_attempter.cc(463)] Use p2p For Downloading = 0, Use p2p For Sharing = 0 2022-09-20T16:03:38.284158Z INFO update_engine: [update_attempter.cc(470)] forced to obey proxies 2022-09-20T16:03:38.284185Z INFO update_engine: [update_attempter.cc(473)] proxy manual checks: 1 2022-09-20T16:03:38.287670Z INFO update_engine: [update_attempter.cc(1773)] Scheduling an action processor start. 2022-09-20T16:03:38.287884Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-20T16:03:38.308142Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-20T16:03:38.308222Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-20T16:03:38.313447Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-20T16:03:38.340822Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-20T16:03:38.341035Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-20T16:03:39.700365Z INFO update_engine: [libcurl_http_fetcher.cc(583)] HTTP response unsuccessful (403) or no payload (333), nothing to do 2022-09-20T16:03:39.702602Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 403 2022-09-20T16:03:39.703508Z INFO update_engine: [libcurl_http_fetcher.cc(521)] Transfer resulted in an error (403), 0 bytes downloaded 2022-09-20T16:03:39.703607Z INFO update_engine: [libcurl_http_fetcher.cc(535)] No further proxies, indicating transfer complete 2022-09-20T16:03:39.703635Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-20T16:03:39.703665Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-20T16:03:39.703665Z ERROR update_engine: [omaha_request_action.cc(710)] Omaha request network transfer failed with HTTPResponseCode=403 2022-09-20T16:03:39.717935Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished OmahaRequestAction with code Unknown error: 2403 2022-09-20T16:03:39.718027Z INFO update_engine: [action_processor.cc(123)] ActionProcessor: Aborting processing due to failure. 2022-09-20T16:03:39.718092Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-20T16:03:39.718123Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-20T16:03:39.718152Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-20T16:03:39.718152Z ERROR update_engine: [update_attempter.cc(1749)] Update failed. 2022-09-20T16:03:39.718188Z INFO update_engine: [utils.cc(789)] Converting error code 2403 to ErrorCode::kOmahaErrorInHTTPResponse 2022-09-20T16:03:39.718217Z INFO update_engine: [payload_state.cc(263)] Updating payload state for error code: 37 (ErrorCode::kOmahaErrorInHTTPResponse) 2022-09-20T16:03:39.718246Z INFO update_engine: [payload_state.cc(270)] Ignoring failures until we get a valid Omaha response. 2022-09-20T16:03:39.718273Z INFO update_engine: [update_attempter.cc(1759)] Reporting the error event 2022-09-20T16:03:39.718635Z INFO update_engine: [action_processor.cc(53)] ActionProcessor: starting OmahaRequestAction 2022-09-20T16:03:39.729473Z INFO update_engine: [omaha_request_action.cc(271)] Posting an Omaha request to https://up.fydeos.com/service/update2 2022-09-20T16:03:39.729566Z INFO update_engine: [omaha_request_action.cc(272)] Request: 2022-09-20T16:03:39.734545Z INFO update_engine: [libcurl_http_fetcher.cc(131)] Starting/Resuming transfer 2022-09-20T16:03:39.735725Z INFO update_engine: [libcurl_http_fetcher.cc(150)] Using proxy: no 2022-09-20T16:03:39.735901Z INFO update_engine: [libcurl_http_fetcher.cc(263)] Not setting http(s) curl options because we are running a dev/test image 2022-09-20T16:03:41.578247Z INFO update_engine: [libcurl_http_fetcher.cc(465)] HTTP response code: 200 2022-09-20T16:03:41.581183Z INFO update_engine: [libcurl_http_fetcher.cc(562)] Transfer completed (200), 268 bytes downloaded 2022-09-20T16:03:41.581324Z INFO update_engine: [omaha_request_action.cc(686)] Omaha request response: 2022-09-20T16:03:41.581372Z INFO update_engine: [action_processor.cc(118)] ActionProcessor: finished last action OmahaRequestAction with code ErrorCode::kSuccess 2022-09-20T16:03:41.581402Z INFO update_engine: [update_attempter.cc(1290)] Processing Done. 2022-09-20T16:03:41.581432Z INFO update_engine: [update_attempter.cc(1158)] Error event sent. 2022-09-20T16:03:41.587882Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable update_disabled: "No value set for update_disabled" 2022-09-20T16:03:41.587973Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable target_version_prefix: "No value set for target_version_prefix" 2022-09-20T16:03:41.588030Z WARNING update_engine: [evaluation_context-inl.h(43)] Error reading Variable release_channel_delegated: "No value set for release_channel_delegated" 2022-09-20T16:03:41.588167Z INFO update_engine: [next_update_check_policy_impl.cc(63)] Periodic check interval not satisfied, blocking until 9/20/2022 16:45:20 GMT 2022-09-20T16:03:41.588214Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on policy_is_loaded 2022-09-20T16:03:41.588242Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on release_channel_delegated 2022-09-20T16:03:41.588269Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on update_disabled 2022-09-20T16:03:41.588296Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on target_version_prefix 2022-09-20T16:03:41.588323Z INFO update_engine: [evaluation_context.cc(186)] Waiting for value on forced_update_requested 2022-09-20T16:03:41.588351Z INFO update_engine: [evaluation_context.cc(215)] Waiting for timeout in 5m0s