search

flatcar / nebraska

Update monitor & manager for applications using the Omaha protocol, optimized for Flatcar Container Linux.
https://kinvolk.io/docs/nebraska/latest
Apache License 2.0
168 stars 42 forks source link

Update error due to DownloadInvalidMetadataMagicString #711

Closed anas-zurkiyeh-sp closed 6 months ago

anas-zurkiyeh-sp commented 6 months ago

Description

Instance update error:

The instance reported an error while updating to version xxxx.x.x: DownloadInvalidMetadataMagicString with TestOmahaUrlFlag

Instance is unable to update to next version and keeps reporting errors:

image

Impact

Unable to upgrade flatcar version

Environment and steps to reproduce

self-hosted nebraska on AWS fronted by cloudflare. 

sudo update_engine_client -reset_status
sudo update_engine_client -check_for_update

journalctl errors:

E0112 19:02:51.636694  3214 update_attempter.cc:615] Update failed.
I0112 19:02:51.636700  3214 payload_state.cc:97] Updating payload state for error code: 21 (kActionCodeDownloadInvalidMetadataMagicString)
I0112 19:02:51.636705  3214 payload_state.cc:262] Resetting the current URL index (0) to 0 as we only have 1 URL(s)
I0112 19:02:51.636709  3214 payload_state.cc:404] Current URL Index = 0
I0112 19:02:51.636776  3214 payload_state.cc:251] Incrementing the payload attempt number
I0112 19:02:51.636785  3214 payload_state.cc:381] Payload Attempt Number = 7
I0112 19:02:51.636847  3214 payload_state.cc:287] Resetting backoff expiry time as payload backoff is disabled
I0112 19:02:51.636854  3214 payload_state.cc:452] Backoff Expiry Time = 01/01/70 00:00:00 UTC
I0112 19:02:51.636919  3214 payload_state.cc:425] Current URL (Url0)'s Failure Count = 0
I0112 19:02:51.637032  3214 action_processor.cc:36] ActionProcessor::StartProcessing: OmahaRequestAction
I0112 19:02:51.637060  3214 omaha_request_action.cc:268] Posting an Omaha request to https://xxxxxxxxxxxxxx.xxxxxx.xxxxxx.com/v1/update
I0112 19:02:51.637066  3214 omaha_request_action.cc:269] Request: <?xml version="1.0" encoding="UTF-8"?>
<request protocol="3.0" version="update_engine-0.4.10" updaterversion="update_engine-0.4.10" installsource="ondemandupdate" ismachine="1">
    <os version="Chateau" platform="CoreOS" sp="3510.2.3_x86_64"></os>
    <app appid="{e96281a6-d1af-4bde-9a0a-97b76e56dc57}" version="3510.2.3" track="beta" bootid="{7b581b1c-3b9d-4bf6-83a2-4fdd6a1f050f}" oem="ami" oemversion="0.1.2-r2" alephversion="3510.2.1" machineid="685dccbef6624f01b606efdd42c8e1ca" machinealias="xxxxxxx-xxxxxxx-xxxxxx-xxxxxx" lang="en-US" board="amd64-usr" hardware_class="" delta_okay="false" >
        <event eventtype="3" eventresult="0" errorcode="268435477"></event>
    </app>
</request>
I0112 19:02:51.637071  3214 libcurl_http_fetcher.cc:47] Starting/Resuming transfer
I0112 19:02:51.637259  3214 libcurl_http_fetcher.cc:174] Setting up curl options for HTTPS
I0112 19:02:51.637408  3214 libcurl_http_fetcher.cc:449] Setting up timeout source: 1 seconds.
I0112 19:02:52.697698  3214 libcurl_http_fetcher.cc:263] HTTP response code: 200
I0112 19:02:52.699204  3214 libcurl_http_fetcher.cc:320] Transfer completed (200), 231 bytes downloaded
I0112 19:02:52.699224  3214 omaha_request_action.cc:619] Omaha request response: <?xml version="1.0" encoding="UTF-8"?>
<response protocol="3.0" server="nebraska"><daystart elapsed_seconds="0"></daystart><app appid="{e96281a6-d1af-4bde-9a0a-97b76e56dc57}" status="ok"><event status="ok"></event></app></response>
E0112 19:02:52.699239  3214 omaha_request_action.cc:626] HTTP reported success but Omaha reports an error.
I0112 19:02:52.699247  3214 action_processor.cc:65] ActionProcessor::ActionComplete: finished last action of type OmahaRequestAction
I0112 19:02:52.699251  3214 action_processor.cc:73] ActionProcessor::ActionComplete: finished last action of type OmahaRequestAction
I0112 19:02:52.699256  3214 update_attempter.cc:302] Processing Done.
I0112 19:02:52.699263  3214 update_attempter.cc:306] Error event sent.

Expected behavior

successful update

Additional information

Resetting machine-id does not have an effect

sudo rm /etc/machine-id
sudo systemd-machine-id-setup
sudo update_engine_client -reset_status
sudo update_engine_client -check_for_update
pothos commented 6 months ago

journalctl errors:

Can you provide the earlier journal entries before the error? These have the Omaha request and response.

anas-zurkiyeh-sp commented 6 months ago

Thank you for your prompt reply. Here are more journal entries (timestamp is removed for better readability):

update_engine[1704]: I0115 16:44:20.827054  1704 main.cc:92] Flatcar Update Engine starting
update_engine[1704]: I0115 16:44:20.827178  1704 payload_state.cc:360] Current Response Signature =
update_engine[1704]: NumURLs = 1
update_engine[1704]: Url0 = https://xxxxxxxxxxxxxxxxxxxxxxxxxx.com/flatcar/flatcar-amd64-3760.1.1.gz
update_engine[1704]: Payload Size = 383439327
update_engine[1704]: Payload Sha256 Hash = spM4NbMn6MrXA2uHBCF3GCjahWbV6bW6LC7ObuFI5fQ=
update_engine[1704]: Is Delta Payload = 0
update_engine[1704]: Max Failure Count Per Url = 10
update_engine[1704]: Disable Payload Backoff = 1
update_engine[1704]: I0115 16:44:20.827327  1704 payload_state.cc:381] Payload Attempt Number = 101
update_engine[1704]: I0115 16:44:20.827425  1704 payload_state.cc:404] Current URL Index = 0
update_engine[1704]: I0115 16:44:20.827515  1704 payload_state.cc:425] Current URL (Url0)'s Failure Count = 0
update_engine[1704]: I0115 16:44:20.827605  1704 payload_state.cc:452] Backoff Expiry Time = 01/01/70 00:00:00 UTC
systemd[1]: Started update-engine.service.
update_engine[1704]: I0115 16:44:20.829259  1704 update_check_scheduler.cc:74] Next update check in 5m42s
update_engine[1704]: I0115 16:45:06.529424  1704 update_attempter.cc:505] Updating boot flags...
update_engine[1704]: I0115 16:46:39.339560  1704 dbus_service.cc:57] Attempting interactive update
update_engine[1704]: I0115 16:46:39.339591  1704 update_attempter.cc:275] New update check requested
update_engine[1704]: I0115 16:46:39.340653  1704 omaha_request_params.cc:62] Current group set to beta
update_engine[1704]: I0115 16:46:39.340818  1704 update_attempter.cc:495] Already updated boot flags. Skipping.
update_engine[1704]: I0115 16:46:39.340835  1704 update_attempter.cc:638] Scheduling an action processor start.
update_engine[1704]: I0115 16:46:39.340858  1704 action_processor.cc:36] ActionProcessor::StartProcessing: OmahaRequestAction
update_engine[1704]: I0115 16:46:39.340971  1704 omaha_request_action.cc:268] Posting an Omaha request to https://xxxxxxxxxxxxxxxxxxxxxxxxxxxx.com/v1/update
update_engine[1704]: I0115 16:46:39.340981  1704 omaha_request_action.cc:269] Request: <?xml version="1.0" encoding="UTF-8"?>
update_engine[1704]: <request protocol="3.0" version="update_engine-0.4.10" updaterversion="update_engine-0.4.10" installsource="ondemandupdate" ismachine="1">
update_engine[1704]:     <os version="Chateau" platform="CoreOS" sp="3510.2.3_x86_64"></os>
update_engine[1704]:     <app appid="{e96281a6-d1af-4bde-9a0a-97b76e56dc57}" version="3510.2.3" track="beta" bootid="{8133c6fe-1276-4924-ac38-24ddc0bfdecf}" oem="ami" oemversion="0.1.2-r2" alephversion="3510.2.1" machineid="3f891185b032436cb68b54ea94250939" machinealias="xxxx-xxxxx-xxxxx-xxxxx" lang="en-US" board="amd64-usr" hardware_class="" delta_okay="false" >
update_engine[1704]:         <ping active="1"></ping>
update_engine[1704]:         <updatecheck></updatecheck>
update_engine[1704]:         <event eventtype="3" eventresult="2" previousversion=""></event>
update_engine[1704]:     </app>
update_engine[1704]: </request>
update_engine[1704]: I0115 16:46:39.340987  1704 libcurl_http_fetcher.cc:47] Starting/Resuming transfer
update_engine[1704]: I0115 16:46:39.350364  1704 libcurl_http_fetcher.cc:174] Setting up curl options for HTTPS
update_engine[1704]: I0115 16:46:39.350560  1704 libcurl_http_fetcher.cc:449] Setting up timeout source: 1 seconds.
update_engine[1704]: I0115 16:46:40.605477  1704 libcurl_http_fetcher.cc:263] HTTP response code: 200
update_engine[1704]: I0115 16:46:40.606750  1704 libcurl_http_fetcher.cc:320] Transfer completed (200), 2189 bytes downloaded
update_engine[1704]: I0115 16:46:40.606771  1704 omaha_request_action.cc:619] Omaha request response: <?xml version="1.0" encoding="UTF-8"?>
update_engine[1704]: <response protocol="3.0" server="nebraska"><daystart elapsed_seconds="0"></daystart><app appid="{e96281a6-d1af-4bde-9a0a-97b76e56dc57}" status="ok"><ping status="ok"></ping><updatecheck status="ok"><urls><url codebase="https://xxxxxxxxxxxxxxxxxxxxxxxxxxxx.com/flatcar/"></url></urls><manifest version="3760.1.1"><packages><package name="flatcar-amd64-3760.1.1.gz" hash="/NHh3BL864Jh1R62p/h5pl9ygYM=" size="383439327" required="true"></package><package name="extrafile-amd64-3760.1.1-oem-ami.gz" hash="eoELgtO3ge77vCDAk41PvytaTOA=" hash_sha256="ef2cda15461a130a4b898ecb8960c2753ea4f35a67064dd08e83e74b35695f75" size="25669804" required="false"></package><package name="extrafile-amd64-3760.1.1-oem-azure.gz" hash="ViGb8cLAm7QUySMYDIf6LV9pNY8=" hash_sha256="71a9159e9315fc85bdc6fb24e3e29f3909c02f50d29ad35aaaed7003fb78d2b2" size="40974866" required="false"></package><package name="extrafile-amd64-3760.1.1-oem-digitalocean.gz" hash="gW9hwLOkyVtdvntiJreDIzUoGXM=" hash_sha256="bdc808b8e43597b2da36c7c8bff21872d00c6fbd370b3abf83c7deae4f3efa57" size="2301" required="false"></package><package name="extrafile-amd64-3760.1.1-oem-openstack.gz" hash="0HNx5v8R0TdgKcONaDB/b0e9o38=" hash_sha256="5ea95abcc7548512228ac02972c8ac5ac5981775ead1c201e0fdd40084f83a90" size="2272" required="false"></package><package name="extrafile-amd64-3760.1.1-oem-packet.gz" hash="47BqAKwSOIZITrJL8lIscsIBYfk=" hash_sha256="6683404c924d858bce0ae56303fa1b774d3d68270f855179c4d297a029025ce0" size="2280" required="false"></package><package name="extrafile-amd64-3760.1.1-oem-qemu.gz" hash="E3rh1aST7bya58HIor4xTqLp+ts=" hash_sha256="043bb7c00bece5f1ee2a08431809962301a212aa7ec0260bef9761b2cc05c14a" size="2283" required="false"></package><package name="extrafile-amd64-3760.1.1-oem-vmware.gz" hash="GIVOIBJmcPUCtb2PrwAb1jMP7OI=" hash_sha256="3bb92c3453eafe85c5bc3fcb7b293045e909eb0678d2a0191347fdd4fb0f9f21" size="1794068" required="false"></package></packages><actions><action event="postinstall" sha256="spM4NbMn6MrXA2uHBCF3GCjahWbV6bW6LC7ObuFI5fQ=" DisablePayloadBackoff="true"></action></actions></manifest></updatecheck><event status="ok"></event></app></response>
update_engine[1704]: I0115 16:46:40.618525  1704 omaha_request_action.cc:447] Omaha Response manifest version = 3760.1.1
update_engine[1704]: I0115 16:46:40.618556  1704 omaha_request_action.cc:470] Found 1 url(s)
update_engine[1704]: I0115 16:46:40.618572  1704 omaha_request_action.cc:506] Processing first of 8 package(s)
update_engine[1704]: I0115 16:46:40.618578  1704 omaha_request_action.cc:513] Omaha Response package name = flatcar-amd64-3760.1.1.gz
update_engine[1704]: I0115 16:46:40.618583  1704 omaha_request_action.cc:529] Url0: https://xxxxxxxxxxxxxxxxxxxxxxxxxxxx.com/flatcar/flatcar-amd64-3760.1.1.gz
update_engine[1704]: I0115 16:46:40.618590  1704 omaha_request_action.cc:541] Payload size = 383439327 bytes
update_engine[1704]: I0115 16:46:40.618604  1704 omaha_request_action.cc:565] Found 1 action(s). Processing the postinstall action.
update_engine[1704]: I0115 16:46:40.618619  1704 payload_state.cc:203] Payload backoff logic is disabled. Can proceed with the download
update_engine[1704]: I0115 16:46:40.618639  1704 action_processor.cc:82] ActionProcessor::ActionComplete: finished OmahaRequestAction, starting OmahaResponseHandlerAction
update_engine[1704]: I0115 16:46:40.618645  1704 omaha_response_handler_action.cc:43] Using Url0 as the download url this time
update_engine[1704]: E0115 16:46:40.621748  1704 payload_processor.cc:487] prefs->GetInt64(kPrefsUpdateStateNextOperation, &next_operation) && next_operation != kUpdateStateOperationInvalid && next_operation > 0 failed.
update_engine[1704]: I0115 16:46:40.622905  1704 omaha_response_handler_action.cc:85] Using this install plan:
update_engine[1704]: I0115 16:46:40.622922  1704 install_plan.cc:53] InstallPlan: , new_update, url: https://xxxxxxxxxxxxxxxxxxxxxxxxxxxx.com/flatcar/flatcar-amd64-3760.1.1.gz, payload size: 383439327, payload hash: spM4NbMn6MrXA2uHBCF3GCjahWbV6bW6LC7ObuFI5fQ=, partition_path: /dev/xvda3, kernel_path: /boot/flatcar/vmlinuz-a, pcr_policy_path: /var/lib/update_engine/pcrs-a.zip, old_partition_path: /dev/xvda4, old_kernel_path: /boot/flatcar/vmlinuz-b
update_engine[1704]: I0115 16:46:40.623066  1704 action_processor.cc:82] ActionProcessor::ActionComplete: finished OmahaResponseHandlerAction, starting FilesystemCopierAction
update_engine[1704]: I0115 16:46:40.623178  1704 filesystem_copier_action.cc:296] Filesystem size: 1073741824
update_engine[1704]: I0115 16:46:50.903151  1704 filesystem_copier_action.cc:274] Hash: sxqBnCMfqOSodTJumDTx3DZABKPHb25Peq6n6ax3Hdk=
update_engine[1704]: I0115 16:46:50.903191  1704 action_processor.cc:82] ActionProcessor::ActionComplete: finished FilesystemCopierAction, starting KernelCopierAction
update_engine[1704]: I0115 16:46:52.031668  1704 action_processor.cc:82] ActionProcessor::ActionComplete: finished KernelCopierAction, starting OmahaRequestAction
update_engine[1704]: I0115 16:46:52.031723  1704 omaha_request_action.cc:268] Posting an Omaha request to https://xxxxxxxxxxxxxxxxxxxxxxxxxxxx.com/v1/update
update_engine[1704]: I0115 16:46:52.031729  1704 omaha_request_action.cc:269] Request: <?xml version="1.0" encoding="UTF-8"?>
update_engine[1704]: <request protocol="3.0" version="update_engine-0.4.10" updaterversion="update_engine-0.4.10" installsource="ondemandupdate" ismachine="1">
update_engine[1704]:     <os version="Chateau" platform="CoreOS" sp="3510.2.3_x86_64"></os>
update_engine[1704]:     <app appid="{e96281a6-d1af-4bde-9a0a-97b76e56dc57}" version="3510.2.3" track="beta" bootid="{8133c6fe-1276-4924-ac38-24ddc0bfdecf}" oem="ami" oemversion="0.1.2-r2" alephversion="3510.2.1" machineid="3f891185b032436cb68b54ea94250939" machinealias="megapod-useast1-org-sigma-31708-37300" lang="en-US" board="amd64-usr" hardware_class="" delta_okay="false" >
update_engine[1704]:         <event eventtype="13" eventresult="1"></event>
update_engine[1704]:     </app>
update_engine[1704]: </request>
update_engine[1704]: I0115 16:46:52.031736  1704 libcurl_http_fetcher.cc:47] Starting/Resuming transfer
update_engine[1704]: I0115 16:46:52.031965  1704 libcurl_http_fetcher.cc:174] Setting up curl options for HTTPS
update_engine[1704]: I0115 16:46:52.032171  1704 libcurl_http_fetcher.cc:449] Setting up timeout source: 1 seconds.
update_engine[1704]: I0115 16:46:57.623111  1704 libcurl_http_fetcher.cc:263] HTTP response code: 200
update_engine[1704]: I0115 16:46:57.624497  1704 libcurl_http_fetcher.cc:320] Transfer completed (200), 231 bytes downloaded
update_engine[1704]: I0115 16:46:57.624517  1704 omaha_request_action.cc:619] Omaha request response: <?xml version="1.0" encoding="UTF-8"?>
update_engine[1704]: <response protocol="3.0" server="nebraska"><daystart elapsed_seconds="0"></daystart><app appid="{e96281a6-d1af-4bde-9a0a-97b76e56dc57}" status="ok"><event status="ok"></event></app></response>
update_engine[1704]: I0115 16:46:57.624526  1704 action_processor.cc:82] ActionProcessor::ActionComplete: finished OmahaRequestAction, starting DownloadAction
update_engine[1704]: I0115 16:46:57.624532  1704 install_plan.cc:53] InstallPlan: , new_update, url: https://xxxxxxxxxxxxxxxxxxxxxxxxxxxx.com/flatcar/flatcar-amd64-3760.1.1.gz, payload size: 383439327, payload hash: spM4NbMn6MrXA2uHBCF3GCjahWbV6bW6LC7ObuFI5fQ=, partition_path: /dev/xvda3, kernel_path: /boot/flatcar/vmlinuz-a, pcr_policy_path: /var/lib/update_engine/pcrs-a.zip, old_partition_path: /dev/xvda4, old_kernel_path: /boot/flatcar/vmlinuz-b
update_engine[1704]: I0115 16:46:57.624609  1704 update_attempter.cc:420] Download status: active
update_engine[1704]: I0115 16:46:57.624619  1704 multi_range_http_fetcher.cc:30] starting first transfer
update_engine[1704]: I0115 16:46:57.624622  1704 multi_range_http_fetcher.cc:58] starting transfer of range 0+?
update_engine[1704]: I0115 16:46:57.624629  1704 libcurl_http_fetcher.cc:47] Starting/Resuming transfer
update_engine[1704]: I0115 16:46:57.624764  1704 libcurl_http_fetcher.cc:174] Setting up curl options for HTTPS
update_engine[1704]: I0115 16:46:57.624925  1704 libcurl_http_fetcher.cc:449] Setting up timeout source: 1 seconds.
update_engine[1704]: I0115 16:46:58.594341  1704 update_attempter.cc:442] Downloaded 1360/383439327 bytes (0%)
update_engine[1704]: E0115 16:46:58.594436  1704 delta_metadata.cc:29] Bad payload format -- invalid delta magic.
update_engine[1704]: E0115 16:46:58.594444  1704 download_action.cc:85] Error 21 while processing the received payload -- Terminating processing
update_engine[1704]: E0115 16:46:58.594481  1704 payload_processor.cc:108] Called Close() while buffer not empty!
update_engine[1704]: W0115 16:46:58.594488  1704 download_action.cc:61] Error closing the writer.
update_engine[1704]: I0115 16:46:58.594492  1704 update_attempter.cc:420] Download status: inactive
update_engine[1704]: E0115 16:46:58.594511  1704 update_attempter.cc:427] BytesReceived called while not downloading.
update_engine[1704]: E0115 16:46:58.594524  1704 update_attempter.cc:427] BytesReceived called while not downloading.
update_engine[1704]: I0115 16:46:58.595820  1704 multi_range_http_fetcher.cc:156] Received transfer terminated.
update_engine[1704]: I0115 16:46:58.595835  1704 multi_range_http_fetcher.cc:108] TransferEnded w/ code 200
update_engine[1704]: I0115 16:46:58.595840  1704 multi_range_http_fetcher.cc:110] Terminating.
update_engine[1704]: I0115 16:46:58.597191  1704 action_processor.cc:68] ActionProcessor::ActionComplete: DownloadAction action failed. Aborting processing.
update_engine[1704]: I0115 16:46:58.597286  1704 action_processor.cc:73] ActionProcessor::ActionComplete: finished last action of type DownloadAction
update_engine[1704]: I0115 16:46:58.597355  1704 update_attempter.cc:302] Processing Done.
update_engine[1704]: E0115 16:46:58.597471  1704 update_attempter.cc:615] Update failed.
update_engine[1704]: I0115 16:46:58.597558  1704 payload_state.cc:97] Updating payload state for error code: 21 (kActionCodeDownloadInvalidMetadataMagicString)
update_engine[1704]: I0115 16:46:58.597635  1704 payload_state.cc:262] Resetting the current URL index (0) to 0 as we only have 1 URL(s)
update_engine[1704]: I0115 16:46:58.597707  1704 payload_state.cc:404] Current URL Index = 0
update_engine[1704]: I0115 16:46:58.597874  1704 payload_state.cc:251] Incrementing the payload attempt number
update_engine[1704]: I0115 16:46:58.597963  1704 payload_state.cc:381] Payload Attempt Number = 102
update_engine[1704]: I0115 16:46:58.598119  1704 payload_state.cc:287] Resetting backoff expiry time as payload backoff is disabled
update_engine[1704]: I0115 16:46:58.598206  1704 payload_state.cc:452] Backoff Expiry Time = 01/01/70 00:00:00 UTC
update_engine[1704]: I0115 16:46:58.598346  1704 payload_state.cc:425] Current URL (Url0)'s Failure Count = 0
update_engine[1704]: I0115 16:46:58.598589  1704 action_processor.cc:36] ActionProcessor::StartProcessing: OmahaRequestAction
update_engine[1704]: I0115 16:46:58.598702  1704 omaha_request_action.cc:268] Posting an Omaha request to https://xxxxxxxxxxxxxxxxxxxxxxxxxxxx.com/v1/update
update_engine[1704]: I0115 16:46:58.598805  1704 omaha_request_action.cc:269] Request: <?xml version="1.0" encoding="UTF-8"?>
update_engine[1704]: <request protocol="3.0" version="update_engine-0.4.10" updaterversion="update_engine-0.4.10" installsource="ondemandupdate" ismachine="1">
update_engine[1704]:     <os version="Chateau" platform="CoreOS" sp="3510.2.3_x86_64"></os>
update_engine[1704]:     <app appid="{e96281a6-d1af-4bde-9a0a-97b76e56dc57}" version="3510.2.3" track="beta" bootid="{8133c6fe-1276-4924-ac38-24ddc0bfdecf}" oem="ami" oemversion="0.1.2-r2" alephversion="3510.2.1" machineid="3f891185b032436cb68b54ea94250939" machinealias="megapod-useast1-org-sigma-31708-37300" lang="en-US" board="amd64-usr" hardware_class="" delta_okay="false" >
update_engine[1704]:         <event eventtype="3" eventresult="0" errorcode="268435477"></event>
update_engine[1704]:     </app>
update_engine[1704]: </request>
update_engine[1704]: I0115 16:46:58.599107  1704 libcurl_http_fetcher.cc:47] Starting/Resuming transfer
update_engine[1704]: I0115 16:46:58.599298  1704 libcurl_http_fetcher.cc:174] Setting up curl options for HTTPS
update_engine[1704]: I0115 16:46:58.599465  1704 libcurl_http_fetcher.cc:449] Setting up timeout source: 1 seconds.
update_engine[1704]: I0115 16:46:59.598491  1704 libcurl_http_fetcher.cc:263] HTTP response code: 200
update_engine[1704]: I0115 16:46:59.599820  1704 libcurl_http_fetcher.cc:320] Transfer completed (200), 231 bytes downloaded
update_engine[1704]: I0115 16:46:59.599840  1704 omaha_request_action.cc:619] Omaha request response: <?xml version="1.0" encoding="UTF-8"?>
update_engine[1704]: <response protocol="3.0" server="nebraska"><daystart elapsed_seconds="0"></daystart><app appid="{e96281a6-d1af-4bde-9a0a-97b76e56dc57}" status="ok"><event status="ok"></event></app></response>
update_engine[1704]: E0115 16:46:59.599855  1704 omaha_request_action.cc:626] HTTP reported success but Omaha reports an error.
update_engine[1704]: I0115 16:46:59.599862  1704 action_processor.cc:65] ActionProcessor::ActionComplete: finished last action of type OmahaRequestAction
update_engine[1704]: I0115 16:46:59.599867  1704 action_processor.cc:73] ActionProcessor::ActionComplete: finished last action of type OmahaRequestAction
update_engine[1704]: I0115 16:46:59.599874  1704 update_attempter.cc:302] Processing Done.
update_engine[1704]: I0115 16:46:59.599879  1704 update_attempter.cc:306] Error event sent.
pothos commented 6 months ago

The download of https://xxxxxxxxxxxxxxxxxxxxxxxxxxxx.com/flatcar/flatcar-amd64-3760.1.1.gz is stopped because the response is not as expected. Can you download the file directly and check that its size and hashsums are correct?

pothos commented 6 months ago

I've tested it with -enable-syncer -host-flatcar-packages -flatcar-packages-path "$PWD/store/flatcar" -syncer-packages-url http://192.168.1.123:8000/flatcar/ and it worked as expected. Without the syncer-packages-url flatcar/ suffix it does not find the files because it clashes with the other routes of the server but this doesn't seem to be your problem because you have the suffix.

anas-zurkiyeh-sp commented 6 months ago

I may have found the root cause but still need to run a few tests. It seems like nebraska does not do a version check and will serve any request with 200 even if package version is invalid or doesn't exist:

wget https://public.update.flatcar-linux.net/flatcar/flatcar-amd64-9999.9.9.gz

--2024-01-16 18:24:07-- https://public.update.flatcar-linux.net/flatcar/flatcar-amd64-9999.9.9.gz ... ... ... HTTP request sent, awaiting response... 200 OK Length: unspecified [text/html] Saving to: ‘flatcar-amd64-9999.9.9.gz’ flatcar-amd64-9999.9.9.gz [ <=> ] 38.65K --.-KB/s in 0.1s 2024-01-16 18:24:08 (395 KB/s) - ‘flatcar-amd64-9999.9.9.gz’ saved [39579]

For some reason, the packages have disappeared (still trying to figure out why) from the host directory. In my case it's /ops/packages and as a result it's not serving the correct payload.

I expected that nebraska will repopulate the package directory if any packages were missing but it does not. Perhaps because they have corresponding entries in the db so it thinks that they exist?

What are your suggestions to try to force nebraska to repopulate the package dir?

For reference, these are the relevant parameters I'm passing:

/nebraska/nebraska -http-static-dir=/nebraska/static -http-log -enable-syncer -sync-interval=8m \
-host-flatcar-packages -flatcar-packages-path=/opt/packages ........
pothos commented 6 months ago

I expected that nebraska will repopulate the package directory if any packages were missing but it does not. Perhaps because they have corresponding entries in the db so it thinks that they exist?

Yes, once they are synced the entries are not changed. If you don't care about old versions you can delete the current packages and at least these will get recreated.

anas-zurkiyeh-sp commented 6 months ago

Thanks @pothos for helping me through this issue!

Deleting the entry from the database didnt trigger resync. Therefore, I had to redeploy nebraska and that seems to have resolved the issue. For those who encounter this issue; delete the package entry from public>package and restart nebraska.