Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[BUG] Backing image without checksum value created from older release will not able to be reuse: no expectedChecksum for existing file #4085

Closed
kaxing opened this issue Jun 7, 2022 · 4 comments
Closed

[BUG] Backing image without checksum value created from older release will not able to be reuse: no expectedChecksum for existing file #4085

kaxing opened this issue Jun 7, 2022 · 4 comments
Assignees
@kaxing @shuo-wu
Labels
area/backing-image Backing image related kind/bug severity/4 Function working but has a minor issue (a minor incident with low impact)
Milestone
v1.3.0

Comments

@kaxing
Copy link

kaxing commented Jun 7, 2022

Describe the bug

image

To Reproduce

Steps to reproduce the behavior:

  1. Install v1.1.3
  2. Create Backing Image (leave checksum blank)
  3. Create and attach volume with backing image
  4. Wait until everything settle
  5. Upgrade to master-head

Expected behavior

Able to resolve the situation manually or reuse the imag by filling up the missing checksum

Log or Support bundle

bi manager pod logs:

time="2022-06-07T09:59:44Z" level=debug msg="Sync Service: initialized" component=sync-server listen="0.0.0.0:8001"
time="2022-06-07T09:59:44Z" level=info msg="Started sync server at 0.0.0.0:8001"
time="2022-06-07T09:59:45Z" level=info msg="The sync server of backing Image Manager listening to 0.0.0.0:8001"
time="2022-06-07T09:59:45Z" level=info msg="Backing Image Manager listening to 0.0.0.0:8000"
time="2022-06-07T09:59:48Z" level=info msg="Backing Image Manager: prepare to start backing image update watch" component=backing-image-manager diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076
time="2022-06-07T09:59:48Z" level=info msg="Backing Image Manager: backing image update watch started" component=backing-image-manager diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076
time="2022-06-07T09:59:48Z" level=info msg="Backing Image Manager: prepare to fetch backing image" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076
time="2022-06-07T09:59:48Z" level=info msg="Backing Image Manager: there is no need to transfer the file from the data sourece server, will try to directly reuse the file" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076
time="2022-06-07T09:59:48Z" level=error msg="Backing Image Manager: failed to start fetching backing image" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076 error="resp.StatusCode(500) != http.StatusOK(200), response body content: no expectedChecksum for existing file fetch\n"
time="2022-06-07T10:00:52Z" level=info msg="Backing Image Manager: prepare to fetch backing image" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076
time="2022-06-07T10:00:52Z" level=info msg="Backing Image Manager: there is no need to transfer the file from the data sourece server, will try to directly reuse the file" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076
time="2022-06-07T10:00:52Z" level=error msg="Backing Image Manager: failed to start fetching backing image" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076 error="resp.StatusCode(500) != http.StatusOK(200), response body content: no expectedChecksum for existing file fetch\n"
time="2022-06-07T10:03:22Z" level=info msg="Backing Image Manager: prepare to fetch backing image" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076
time="2022-06-07T10:03:22Z" level=info msg="Backing Image Manager: there is no need to transfer the file from the data sourece server, will try to directly reuse the file" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076
time="2022-06-07T10:03:22Z" level=error msg="Backing Image Manager: failed to start fetching backing image" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076 error="resp.StatusCode(500) != http.StatusOK(200), response body content: no expectedChecksum for existing file fetch\n"
time="2022-06-07T10:07:52Z" level=info msg="Backing Image Manager: prepare to fetch backing image" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076
time="2022-06-07T10:07:52Z" level=info msg="Backing Image Manager: there is no need to transfer the file from the data sourece server, will try to directly reuse the file" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076
time="2022-06-07T10:07:52Z" level=error msg="Backing Image Manager: failed to start fetching backing image" biName=ubuntu-2004-4-server biUUID=1392e696 component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=cc9a0398-b228-468f-bc2c-9dfa7710b076 error="resp.StatusCode(500) != http.StatusOK(200), response body content: no expectedChecksum for existing file fetch\n"

backing image detail:

Name:         ubuntu-2004-4-server
Namespace:    longhorn-system
Labels:       longhorn.io/component=backing-image
              longhorn.io/managed-by=longhorn-manager
Annotations:  <none>
API Version:  longhorn.io/v1beta2
Kind:         BackingImage
Metadata:
  Creation Timestamp:  2022-06-07T09:37:15Z
  Finalizers:
    longhorn.io
  Generation:  6
  Managed Fields:
    API Version:  longhorn.io/v1beta1
    Fields Type:  FieldsV1
    fieldsV1:
      f:metadata:
        f:finalizers:
          .:
          v:"longhorn.io":
        f:labels:
          .:
          f:longhorn.io/component:
          f:longhorn.io/managed-by:
    Manager:      longhorn-manager
    Operation:    Update
    Time:         2022-06-07T09:37:15Z
    API Version:  longhorn.io/v1beta2
    Fields Type:  FieldsV1
    fieldsV1:
      f:spec:
        f:imageURL:
        f:sourceParameters:
          f:url:
    Manager:         longhorn-manager
    Operation:       Update
    Time:            2022-06-07T09:58:51Z
  Resource Version:  55155
  UID:               e9fb82f6-1c74-41be-874b-00bcaeaed640
Spec:
  Checksum:  
  Disks:
    cc9a0398-b228-468f-bc2c-9dfa7710b076:  
    d7017154-d4d6-4191-af07-c2b07006a594:  
    f8694e7f-1bf9-4626-a252-77b8a62880cc:  
  Image URL:                               
  Source Parameters:
    URL:        
  Source Type:  download
Status:
  Checksum:  
  Disk Download Progress Map:
  Disk Download State Map:
  Disk File Status Map:
  Disk Last Ref At Map:
  Owner ID:  rc-test-pool2-7afc2ecb-4cdpz
  Size:      1331691520
  Uuid:      1392e696
Events:
  Type    Reason  Age   From                               Message
  ----    ------  ----  ----                               -------
  Normal  Update  37m   longhorn-backing-image-controller  Initialized UUID to 1392e696
  Normal  Create  35m   longhorn-backing-image-controller  created default backing image manager backing-image-manager-7298-cc9a in disk cc9a0398-b228-468f-bc2c-9dfa7710b076 on node rc-test-pool2-7afc2ecb-rzfc9
  Normal  Create  35m   longhorn-backing-image-controller  created default backing image manager backing-image-manager-7298-d701 in disk d7017154-d4d6-4191-af07-c2b07006a594 on node rc-test-pool2-7afc2ecb-vww5q
  Normal  Create  35m   longhorn-backing-image-controller  created default backing image manager backing-image-manager-7298-f869 in disk f8694e7f-1bf9-4626-a252-77b8a62880cc on node rc-test-pool2-7afc2ecb-4cdpz
  Normal  Update  34m   longhorn-backing-image-controller  Set size to 1331691520
  Normal  Delete  15m   longhorn-backing-image-controller  deleted old/non-default backing image manager backing-image-manager-7298-f869 in disk f8694e7f-1bf9-4626-a252-77b8a62880cc on node rc-test-pool2-7afc2ecb-4cdpz
  Normal  Delete  15m   longhorn-backing-image-controller  deleted old/non-default backing image manager backing-image-manager-7298-cc9a in disk cc9a0398-b228-468f-bc2c-9dfa7710b076 on node rc-test-pool2-7afc2ecb-rzfc9
  Normal  Delete  15m   longhorn-backing-image-controller  deleted old/non-default backing image manager backing-image-manager-7298-d701 in disk d7017154-d4d6-4191-af07-c2b07006a594 on node rc-test-pool2-7afc2ecb-vww5q
  Normal  Create  15m   longhorn-backing-image-controller  created default backing image manager backing-image-manager-88c0-cc9a in disk cc9a0398-b228-468f-bc2c-9dfa7710b076 on node rc-test-pool2-7afc2ecb-rzfc9
  Normal  Create  15m   longhorn-backing-image-controller  created default backing image manager backing-image-manager-88c0-d701 in disk d7017154-d4d6-4191-af07-c2b07006a594 on node rc-test-pool2-7afc2ecb-vww5q
  Normal  Create  15m   longhorn-backing-image-controller  created default backing image manager backing-image-manager-88c0-f869 in disk f8694e7f-1bf9-4626-a252-77b8a62880cc on node rc-test-pool2-7afc2ecb-4cdpz

Environment

  • Longhorn version: v1.1.3 -> master-head (post v1.3.0-rc2)

Additional context

Add any other context about the problem here.
@kaxing kaxing added kind/bug severity/3 Function working but has a major issue w/ workaround labels Jun 7, 2022
@innobead innobead added the priority/2 Nice to implement or fix in this release (managed by PO) label Jun 7, 2022
@innobead innobead added this to the v1.4.0 milestone Jun 7, 2022
@kaxing
Copy link
Author

kaxing commented Jun 8, 2022

Not happening with backing image created with longhorn v1.2.x, logs from bi manager pod:

time="2022-06-08T04:00:00Z" level=debug msg="Sync Service: initialized" component=sync-server listen="0.0.0.0:8001"
time="2022-06-08T04:00:00Z" level=info msg="Started sync server at 0.0.0.0:8001"
time="2022-06-08T04:00:01Z" level=info msg="The sync server of backing Image Manager listening to 0.0.0.0:8001"
time="2022-06-08T04:00:01Z" level=info msg="Backing Image Manager listening to 0.0.0.0:8000"
time="2022-06-08T04:00:06Z" level=info msg="Backing Image Manager: prepare to start backing image update watch" component=backing-image-manager diskPath=/data/ diskUUID=500f15b8-e08b-4624-baf1-d5ed9b820ada
time="2022-06-08T04:00:06Z" level=info msg="Backing Image Manager: backing image update watch started" component=backing-image-manager diskPath=/data/ diskUUID=500f15b8-e08b-4624-baf1-d5ed9b820ada
time="2022-06-08T04:00:06Z" level=info msg="Backing Image Manager: prepare to fetch backing image" biName=opensuse-15-3-server-5gb biUUID=9cd2670b component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=500f15b8-e08b-4624-baf1-d5ed9b820ada
time="2022-06-08T04:00:06Z" level=info msg="Backing Image Manager: there is no need to transfer the file from the data sourece server, will try to directly reuse the file" biName=opensuse-15-3-server-5gb biUUID=9cd2670b component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=500f15b8-e08b-4624-baf1-d5ed9b820ada
time="2022-06-08T04:00:06Z" level=debug msg="Sync Service: initializing sync file /data/backing-images/opensuse-15-3-server-5gb-9cd2670b/backing" component=sync-server listen="0.0.0.0:8001"
time="2022-06-08T04:00:06Z" level=debug msg="SyncingFile: failed to get the checksum from a valid config during file reusage, will directly calculated it then"
time="2022-06-08T04:00:06Z" level=info msg="Backing Image Manager: fetched or reused backing image" biName=opensuse-15-3-server-5gb biUUID=9cd2670b component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=500f15b8-e08b-4624-baf1-d5ed9b820ada
time="2022-06-08T04:00:46Z" level=debug msg="SyncingFile: writing config file when the file becomes ready" component=sync-file currentChecksum=6f7d75aeab3eaad0085942c247a7fc969e85893840546493102b390595e002902f9fe2107283226faa42f700152064b2fc4843df2941b8d80a227566a3417cd8 filePath=/data/backing-images/opensuse-15-3-server-5gb-9cd2670b/backing size=4659871744 uuid=9cd2670b
time="2022-06-08T04:00:46Z" level=info msg="SyncingFile: directly reuse/introduce the existing file in path /data/backing-images/opensuse-15-3-server-5gb-9cd2670b/backing" component=sync-file currentChecksum=6f7d75aeab3eaad0085942c247a7fc969e85893840546493102b390595e002902f9fe2107283226faa42f700152064b2fc4843df2941b8d80a227566a3417cd8 filePath=/data/backing-images/opensuse-15-3-server-5gb-9cd2670b/backing size=4659871744 uuid=9cd2670b
time="2022-06-08T04:00:46Z" level=info msg="SyncingFile: start to fetch sync file from /data/backing-images/opensuse-15-3-server-5gb-9cd2670b/backing" component=sync-file currentChecksum=6f7d75aeab3eaad0085942c247a7fc969e85893840546493102b390595e002902f9fe2107283226faa42f700152064b2fc4843df2941b8d80a227566a3417cd8 filePath=/data/backing-images/opensuse-15-3-server-5gb-9cd2670b/backing size=4659871744 uuid=9cd2670b
time="2022-06-08T04:00:46Z" level=info msg="SyncingFile: file is already state ready, no need to process it" component=sync-file currentChecksum=6f7d75aeab3eaad0085942c247a7fc969e85893840546493102b390595e002902f9fe2107283226faa42f700152064b2fc4843df2941b8d80a227566a3417cd8 filePath=/data/backing-images/opensuse-15-3-server-5gb-9cd2670b/backing size=4659871744 uuid=9cd2670b

@kaxing kaxing added severity/4 Function working but has a minor issue (a minor incident with low impact) and removed severity/3 Function working but has a major issue w/ workaround labels Jun 8, 2022
@innobead innobead added area/backing-image Backing image related and removed priority/2 Nice to implement or fix in this release (managed by PO) labels Jun 8, 2022
@innobead
Copy link
Member

innobead commented Jun 8, 2022

As per #4085 (comment), not a priority to 1.3.0.

@shuo-wu shuo-wu modified the milestones: v1.4.0, v1.3.0 Jun 8, 2022
@shuo-wu shuo-wu mentioned this issue Jun 8, 2022
Merged
@longhorn-io-github-bot
Copy link

longhorn-io-github-bot commented Jun 8, 2022 •
edited by shuo-wu
Loading

Pre Ready-For-Testing Checklist

  • Where is the reproduce steps/test steps documented?
    The reproduce steps/test steps are in the ticket description

  • Have the backend code been merged (Manager, Engine, Instance Manager, BackupStore etc) (including backport-needed/*)?
    The PR is at Reuse the backing images after upgrading from v1.1.x backing-image-manager#61

  • If labeled: require/manual-test-plan Has the manual test plan been documented?
    The updated manual test plan is the same as the reproducing step

@kaxing
Copy link
Author

kaxing commented Jun 9, 2022

Validation - PASSED

Tested with v1.3.0-rc3 + backing-image-manager dev image from: shuowu/backing-image-manager:v3_20220608
As latest backing-image-manager is not ready yet.

For reference this is the bi created from v113 then upgrade to v13.0-rc3 with dev image:

time="2022-06-09T06:30:22Z" level=debug msg="Sync Service: initialized" component=sync-server listen="0.0.0.0:8001"
time="2022-06-09T06:30:22Z" level=info msg="Started sync server at 0.0.0.0:8001"
time="2022-06-09T06:30:23Z" level=info msg="The sync server of backing Image Manager listening to 0.0.0.0:8001"
time="2022-06-09T06:30:23Z" level=info msg="Backing Image Manager listening to 0.0.0.0:8000"
time="2022-06-09T06:30:25Z" level=info msg="Backing Image Manager: prepare to start backing image update watch" component=backing-image-manager diskPath=/data/ diskUUID=f63184a4-9adc-48c9-b33b-fd620aae5977
time="2022-06-09T06:30:25Z" level=info msg="Backing Image Manager: backing image update watch started" component=backing-image-manager diskPath=/data/ diskUUID=f63184a4-9adc-48c9-b33b-fd620aae5977
time="2022-06-09T06:30:25Z" level=info msg="Backing Image Manager: prepare to fetch backing image" biName=bi-v113 biUUID=cffb950c component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=f63184a4-9adc-48c9-b33b-fd620aae5977
time="2022-06-09T06:30:25Z" level=info msg="Backing Image Manager: there is no need to transfer the file from the data sourece server, will try to directly reuse the file" biName=bi-v113 biUUID=cffb950c component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=f63184a4-9adc-48c9-b33b-fd620aae5977
time="2022-06-09T06:30:25Z" level=debug msg="Sync Service: initializing sync file /data/backing-images/bi-v113-cffb950c/backing" component=sync-server listen="0.0.0.0:8001"
time="2022-06-09T06:30:25Z" level=debug msg="SyncingFile: failed to get the checksum from a valid config during file reusage, will directly calculated it then"
time="2022-06-09T06:30:25Z" level=info msg="Backing Image Manager: fetched or reused backing image" biName=bi-v113 biUUID=cffb950c component=backing-image-manager data_source_address= diskPath=/data/ diskUUID=f63184a4-9adc-48c9-b33b-fd620aae5977
time="2022-06-09T06:30:28Z" level=debug msg="SyncingFile: writing config file when the file becomes ready" component=sync-file currentChecksum=0a230fccbcf4acdd600933f94250fc6513bbf207d4e584984fca3e36ce6716a9bf3a3ce6fac3a4d0d08c56609ea8c6f02e9944d96c1080fb0abf0020ad7a268f filePath=/data/backing-images/bi-v113-cffb950c/backing size=534431744 uuid=cffb950c
time="2022-06-09T06:30:28Z" level=info msg="SyncingFile: directly reuse/introduce the existing file in path /data/backing-images/bi-v113-cffb950c/backing" component=sync-file currentChecksum=0a230fccbcf4acdd600933f94250fc6513bbf207d4e584984fca3e36ce6716a9bf3a3ce6fac3a4d0d08c56609ea8c6f02e9944d96c1080fb0abf0020ad7a268f filePath=/data/backing-images/bi-v113-cffb950c/backing size=534431744 uuid=cffb950c
time="2022-06-09T06:30:29Z" level=info msg="SyncingFile: start to fetch sync file from /data/backing-images/bi-v113-cffb950c/backing" component=sync-file currentChecksum=0a230fccbcf4acdd600933f94250fc6513bbf207d4e584984fca3e36ce6716a9bf3a3ce6fac3a4d0d08c56609ea8c6f02e9944d96c1080fb0abf0020ad7a268f filePath=/data/backing-images/bi-v113-cffb950c/backing size=534431744 uuid=cffb950c
time="2022-06-09T06:30:29Z" level=info msg="SyncingFile: file is already state ready, no need to process it" component=sync-file currentChecksum=0a230fccbcf4acdd600933f94250fc6513bbf207d4e584984fca3e36ce6716a9bf3a3ce6fac3a4d0d08c56609ea8c6f02e9944d96c1080fb0abf0020ad7a268f filePath=/data/backing-images/bi-v113-cffb950c/backing size=534431744 uuid=cffb950c

@kaxing kaxing closed this as completed Jun 9, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@kaxing kaxing

@shuo-wu shuo-wu

Labels
area/backing-image Backing image related kind/bug severity/4 Function working but has a minor issue (a minor incident with low impact)
Projects
Longhorn Sprint
Status: Closed
Milestone
v1.3.0
Development

No branches or pull requests
4 participants
@kaxing @innobead @shuo-wu @longhorn-io-github-bot