Uploaded image for project: 'Artifactory Binary Repository'
  1. Artifactory Binary Repository
  2. RTFACT-26431

DockerV2RemoteRepoHandler logs unnecessary ERROR message

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open
    • Resolution: Unresolved
    • Affects Version/s: 7.24.4
    • Fix Version/s: None
    • Component/s: Docker, Remote Repository
    • Labels:
      None
    • Location:
      External

      Description

      In our Artifactory logs we see this pattern multiple times a day:

      artifactory-service.log [ERROR] [jfrt ] [ERROR] [691dff2f945a4e08] [DockerV2RemoteRepoHandler:1438] [p-nio-8081-exec-3935] - Unable to copy blob from 'null' to 'blabla-dev:blabladev/blabla-image/sha256_blabla/sha256_blabla': 'null'

      This is coming from the remote Docker repository cache while downloading and caching remote Docker image layers. Surprisingly, nothing is missing and all the images and their layers are properly cached by our Artifactory instance.

      We investigated the logs a little more and found two patterns.
      Failing:

      ./console.log:2021-10-15T11:38:05.043Z [jfrt ] [INFO ] [c39ec0cc8f4b2017] [o.a.t.OutboundRequestLogger:22] [p-nio-8081-exec-3704] - 2021-10-15T11:38:05.043Z|c39ec0cc8f4b2017|blabla-dev|639dcaae70b7d399aeefb41f44aecba1f190d1d2fce8f125e3204f391d3413b4|GET|https://registry.blabla.com/v2/blabladev/blabla-image/blobs/sha256:10b049b835e53e02c31d0251ea283881d8ab33fabce405e9dc73e102bbcde9c7%7C200%7C0%7C342%7C733
      ./console.log:2021-10-15T11:38:05.449Z [jfrt ] [INFO ] [c39ec0cc8f4b2017] [o.a.t.OutboundRequestLogger:22] [p-nio-8081-exec-3704] - 2021-10-15T11:38:05.449Z|c39ec0cc8f4b2017|blabla-dev|639dcaae70b7d399aeefb41f44aecba1f190d1d2fce8f125e3204f391d3413b4|GET|https://registry.blabla.com/v2/blabladev/blabla-image/blobs/sha256:10b049b835e53e02c31d0251ea283881d8ab33fabce405e9dc73e102bbcde9c7%7C200%7C0%7C342%7C401
      ./console.log:2021-10-15T11:38:05.450Z [jfrt ] [INFO ] [c39ec0cc8f4b2017] [o.a.r.HttpRepo:439 ] [p-nio-8081-exec-3704] - blabla-dev downloading https://registry.blabla.com/v2/blabladev/blabla-image/blobs/sha256:10b049b835e53e02c31d0251ea283881d8ab33fabce405e9dc73e102bbcde9c7 342 bytes
      ./console.log:2021-10-15T11:38:05.459Z [jfrt ] [INFO ] [c39ec0cc8f4b2017] [o.a.r.HttpRepo:452 ] [p-nio-8081-exec-3704] - blabla-dev downloaded https://registry.blabla.com/v2/blabladev/blabla-image/blobs/sha256:10b049b835e53e02c31d0251ea283881d8ab33fabce405e9dc73e102bbcde9c7 342 bytes at 41.65 KB/sec
      ./console.log:2021-10-15T11:38:05.470Z [jfrt ] [ERROR] [c39ec0cc8f4b2017] [DockerV2RemoteRepoHandler:1438] [p-nio-8081-exec-3704] - Unable to copy blob from 'null' to 'blabla-dev:blabladev/blabla-image/sha256_e703c4780a371cf8e8a01596691a4526faca822addfe082eefac514b11b3ca3d/sha256_10b049b835e53e02c31d0251ea283881d8ab33fabce405e9dc73e102bbcde9c7': 'null'
      ./archived/artifactory-request.2021-10-15T12-24-13.829.log:2021-10-15T11:38:05.474Z|c39ec0cc8f4b2017|2a01:4f9:4b:19c1::2|blabla|GET|/api/docker/blabla-dev/v2/blabladev/blabla-image/blobs/sha256:10b049b835e53e02c31d0251ea283881d8ab33fabce405e9dc73e102bbcde9c7|200|-1|342|1169|docker/20.10.8 go/go1.16.6 git-commit/75249d8 kernel/5.4.0-81-generic os/linux arch/amd64 UpstreamClient(Docker-Client/20.10.8 (linux))
      ./artifactory-access.log:2021-10-15T11:38:05.458Z [c39ec0cc8f4b2017] [ACCEPTED DEPLOY] blabla-dev-cache:blabladev/blabla-image/46637511/sha256__10b049b835e53e02c31d0251ea283881d8ab33fabce405e9dc73e102bbcde9c7 for client : blabla / 2a01:4f9:4b:19c1::2.
      ./artifactory-access.log:2021-10-15T11:38:05.465Z [c39ec0cc8f4b2017] [ACCEPTED DOWNLOAD] blabla-dev:blabladev/blabla-image/46637511/sha256__10b049b835e53e02c31d0251ea283881d8ab33fabce405e9dc73e102bbcde9c7 for client : blabla / 2a01:4f9:4b:19c1::2.
      ./artifactory-access.log:2021-10-15T11:38:05.467Z [c39ec0cc8f4b2017] [ACCEPTED DELETE] blabla-dev-cache:blabladev/blabla-image/46637511/sha256_10b049b835e53e02c31d0251ea283881d8ab33fabce405e9dc73e102bbcde9c7.marker for client : _system / 2a01:4f9:4b:19c1::2.
      ./artifactory-access.log:2021-10-15T11:38:05.472Z [c39ec0cc8f4b2017] [ACCEPTED DELETE] blabla-dev-cache:blabladev/blabla-image/sha256_e703c4780a371cf8e8a01596691a4526faca822addfe082eefac514b11b3ca3d/sha25610b049b835e53e02c31d0251ea283881d8ab33fabce405e9dc73e102bbcde9c7.marker for client : _system / 2a01:4f9:4b:19c1::2.
       

      Successful:

      ./console.log:2021-10-15T13:23:05.793Z [jfrt ] [INFO ] [5807e86f4e63a01f] [o.a.t.OutboundRequestLogger:22] [p-nio-8081-exec-3727] - 2021-10-15T13:23:05.793Z|5807e86f4e63a01f|blabla-dev|639dcaae70b7d399aeefb41f44aecba1f190d1d2fce8f125e3204f391d3413b4|HEAD|https://registry.blabla.com/v2/blabladev/blabla-image/manifests/sha256:c549b878c0b5f96208b4e092717f99a0fab867eecbc45e86a8c838816af931e4%7C200%7C0%7C1999%7C644
      ./console.log:2021-10-15T13:23:06.416Z [jfrt ] [INFO ] [5807e86f4e63a01f] [o.a.t.OutboundRequestLogger:22] [p-nio-8081-exec-3727] - 2021-10-15T13:23:06.416Z|5807e86f4e63a01f|blabla-dev|639dcaae70b7d399aeefb41f44aecba1f190d1d2fce8f125e3204f391d3413b4|GET|https://registry.blabla.com/v2/blabladev/blabla-image/manifests/sha256:c549b878c0b5f96208b4e092717f99a0fab867eecbc45e86a8c838816af931e4%7C200%7C0%7C1999%7C618
      ./console.log:2021-10-15T13:23:06.418Z [jfrt ] [INFO ] [5807e86f4e63a01f] [o.a.r.HttpRepo:439 ] [p-nio-8081-exec-3727] - blabla-dev downloading https://registry.blabla.com/v2/blabladev/blabla-image/manifests/sha256:c549b878c0b5f96208b4e092717f99a0fab867eecbc45e86a8c838816af931e4 1.95 KB
      ./console.log:2021-10-15T13:23:06.428Z [jfrt ] [INFO ] [5807e86f4e63a01f] [o.a.r.HttpRepo:452 ] [p-nio-8081-exec-3727] - blabla-dev downloaded https://registry.blabla.com/v2/blabladev/blabla-image/manifests/sha256:c549b878c0b5f96208b4e092717f99a0fab867eecbc45e86a8c838816af931e4 1.95 KB at 197.58 KB/sec
      ./artifactory-request.log:2021-10-15T13:23:06.496Z|5807e86f4e63a01f|2a01:4f9:4b:1597::2|blabla|GET|/api/docker/blabla-dev/v2/blabladev/blabla-image/manifests/sha256:c549b878c0b5f96208b4e092717f99a0fab867eecbc45e86a8c838816af931e4|200|-1|1999|1351|docker/20.10.8 go/go1.16.6 git-commit/75249d8 kernel/5.4.0-81-generic os/linux arch/amd64 UpstreamClient(Docker-Client/20.10.8 (linux))
      ./artifactory-access.log:2021-10-15T13:23:06.426Z [5807e86f4e63a01f] [ACCEPTED DEPLOY] blabla-dev-cache:blabladev/blabla-image/sha256__c549b878c0b5f96208b4e092717f99a0fab867eecbc45e86a8c838816af931e4/manifest.json for client : blabla / 2a01:4f9:4b:1597::2.
      ./artifactory-access.log:2021-10-15T13:23:06.433Z [5807e86f4e63a01f] [ACCEPTED DOWNLOAD] blabla-dev:blabladev/blabla-image/sha256__c549b878c0b5f96208b4e092717f99a0fab867eecbc45e86a8c838816af931e4/manifest.json for client : blabla / 2a01:4f9:4b:1597::2.
      ./artifactory-access.log:2021-10-15T13:23:06.437Z [5807e86f4e63a01f] [ACCEPTED DEPLOY] blabla-dev-cache:blabladev/blabla-image/sha256_c549b878c0b5f96208b4e092717f99a0fab867eecbc45e86a8c838816af931e4/sha256_358d24aea512dad2206d7ef74bc16ae5fc7e02a2d84b0b475d3f2937d4c29070.marker for client : blabla / 2a01:4f9:4b:1597::2.
      ./artifactory-access.log:2021-10-15T13:23:06.485Z [5807e86f4e63a01f] [ACCEPTED DEPLOY] blabla-dev-cache:blabladev/blabla-image/sha256_c549b878c0b5f96208b4e092717f99a0fab867eecbc45e86a8c838816af931e4/sha256_0bebed874f2318456c8cf9f6fe61966bc48406a09ff5b10634e5f885c00d1e93.marker for client : blabla / 2a01:4f9:4b:1597::2.
      ./artifactory-access.log:2021-10-15T13:23:06.490Z [5807e86f4e63a01f] [ACCEPTED DEPLOY] blabla-dev-cache:blabladev/blabla-image/sha256_c549b878c0b5f96208b4e092717f99a0fab867eecbc45e86a8c838816af931e4/sha256_a2a4339265d64bc0c7247889a2ff131a6efef9d17aeb06dbd3cddec4cc2925c7.marker for client : blabla / 2a01:4f9:4b:1597::2.

      The only difference I can spot is that in the error case we see two HTTP GET requests to registry.replicated.com issued by the Artifcatory while in the success case we see HEAD and then GET which is the correct order because Artifactory first checks whether the request artifact exists.

        Attachments

          Activity

              People

              Assignee:
              Unassigned
              Reporter:
              przemek Przemek Bielicki
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Dates

                Created:
                Updated:

                  Sync Status

                  Connection: RTFACT Sync
                  RTMID-26433 -
                  SYNCHRONIZED
                  • Last Sync Date: