VFS cache mount to BOX no longer uploading

What is the problem you are having with rclone?

I have a vfs cache mount (mode=full) that is accepting files but no longer seems to be uploading them to box. I am seeing these messages in the log

2021/06/11 06:31:58 INFO  : vfs cache: cleaned: objects 8652 (was 8652) in use 8652, to upload 8730, uploading 16, total size 355.182G (was 355.182G)
2021/06/11 06:32:58 INFO  : vfs cache: cleaned: objects 8652 (was 8652) in use 8652, to upload 8730, uploading 16, total size 355.182G (was 355.182G)
2021/06/11 06:33:58 INFO  : vfs cache: cleaned: objects 8652 (was 8652) in use 8652, to upload 8730, uploading 16, total size 355.182G (was 355.182G)
2021/06/11 06:34:58 INFO  : vfs cache: cleaned: objects 8652 (was 8652) in use 8652, to upload 8730, uploading 16, total size 355.182G (was 355.182G)
2021/06/11 06:35:58 INFO  : vfs cache: cleaned: objects 8652 (was 8652) in use 8652, to upload 8730, uploading 16, total size 355.182G (was 355.182G)

Note that the the number of objects to upload didn't change over 5 minutes.

I increased the debugging level to LogLevel 7 but I see nothing that helps other than the cache not removing files

2021/06/11 06:38:58 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item nightly/504L02/TEST2.CommEngine_504L02_Custbuild/2021/202106-June/202106-June-10/bcm96855GWO_SPDSVC_TR069TR143_USBNET_OVS_emmc_squashfs_loader_update.pkgtb.gz not removed, freed 0 bytes
2021/06/11 06:38:58 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item nightly/504L02/TEST2.CommEngine_504L02_Custbuild/2021/202106-June/202106-June-10/bcm96856O_PROV_uboot_rootfs_256.ubifs not removed, freed 0 bytes
2021/06/11 06:38:58 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm96878GWO_DPI_JUMBO_MAP_PURE181_uboot_rootfs_nonubifs not removed, freed 0 bytes
2021/06/11 06:38:58 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item nightly/504L02/TEST2.CommEngine_504L02_Custbuild/2021/202106-June/202106-June-11/bcm96858O_DPOE_TOD_SPDSVC_TR069TR143_linux_raw_image_256.bin not removed, freed 0 bytes
2021/06/11 06:38:58 INFO  : vfs cache: cleaned: objects 8655 (was 8655) in use 8655, to upload 8733, uploading 16, total size 355.182G (was 355.182G)

I tried stopping and starting the mount. When I do so, it does not actually mount from BOX.
I have to remove the cache in order to get it to mount correctly.

If I cd into the mount point, I see

df -h .
Filesystem                    Size  Used Avail Use% Mounted on
/dev/mapper/centos_auto-auto   14T  394G   13T   3% /auto

which is the local filesystem
It should report the following:

Filesystem                         Size  Used Avail Use% Mounted on
Box_BCACPE_VFS_Mount:test_nightly  9.8P  3.1T  9.8P   1% /auto/bcacpebuilder/bca_daemon_vfs/mount

The log shows that it is now uploading files but the mount point is not pointing at box

2021/06/11 06:50:59 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm955153DPU_uboot_bootstrap_image_emmc_boot_part.bin: vfs cache: upload succeeded try #1
2021/06/11 06:51:03 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm955153DPU_uboot_linux.itb: vfs cache: queuing for upload in 5s
2021/06/11 06:51:04 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm955153DPU_uboot_bootstrap_image_emmc_userdata_part.bin: Copied (replaced existing)
2021/06/11 06:51:04 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm955153DPU_uboot_bootstrap_image_emmc_userdata_part.bin: vfs cache: upload succeeded try #1

I have moved the cache aside and restarted and now the mount point is correct but my cache files aren't uploaded.

What is your rclone version (output from rclone version)

../rclone/rclone --version
rclone v1.55.0
- os/type: linux
- os/arch: amd64
- go/version: go1.16.2
- go/linking: static
- go/tags: cmount

Which OS you are using and how many bits (eg Windows 7, 64 bit)

CentOS 7.6.1810, x86_64

uname -a
Linux 3.10.0-1062.1.1.el7.x86_64 #1 SMP Fri Sep 13 22:55:44 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

Which cloud storage system are you using? (eg Google Drive)

Box

The command you were trying to run (eg rclone copy /tmp remote:tmp)

/auto/bcacpebuilder/rclone/rclone mount \
--allow-other \
--buffer-size=128M \
--cache-dir=/auto/bcacpebuilder/bca_daemon_vfs/cache \
--config=/auto/bcacpebuilder/rclone/rclone.conf \
--dir-cache-time=5m0s \
--fast-list \
--log-file=/auto/bcacpebuilder/bca_daemon_vfs/bca_daemon_vfs.log \
--low-level-retries=1 \
--max-read-ahead=128k \
--rc \
--rc-addr=127.0.0.1:5582 \
--transfers=16 \
--vfs-cache-mode=full \
--vfs-read-chunk-size=128M \
--vfs-read-chunk-size-limit=2G \
-v \
Box_BCACPE_VFS_Mount:test_nightly \
/auto/bcacpebuilder/bca_daemon_vfs/mount

The rclone config contents with secrets removed.

type = box
token =

A log from the command with the -vv flag

Duplicating log entries from above

2021/06/11 06:31:58 INFO  : vfs cache: cleaned: objects 8652 (was 8652) in use 8652, to upload 8730, uploading 16, total size 355.182G (was 355.182G)
2021/06/11 06:32:58 INFO  : vfs cache: cleaned: objects 8652 (was 8652) in use 8652, to upload 8730, uploading 16, total size 355.182G (was 355.182G)
2021/06/11 06:33:58 INFO  : vfs cache: cleaned: objects 8652 (was 8652) in use 8652, to upload 8730, uploading 16, total size 355.182G (was 355.182G)
2021/06/11 06:34:58 INFO  : vfs cache: cleaned: objects 8652 (was 8652) in use 8652, to upload 8730, uploading 16, total size 355.182G (was 355.182G)
2021/06/11 06:35:58 INFO  : vfs cache: cleaned: objects 8652 (was 8652) in use 8652, to upload 8730, uploading 16, total size 355.182G (was 355.182G)
[...]
2021/06/11 06:38:58 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item nightly/504L02/TEST2.CommEngine_504L02_Custbuild/2021/202106-June/202106-June-10/bcm96855GWO_SPDSVC_TR069TR143_USBNET_OVS_emmc_squashfs_loader_update.pkgtb.gz not removed, freed 0 bytes
2021/06/11 06:38:58 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item nightly/504L02/TEST2.CommEngine_504L02_Custbuild/2021/202106-June/202106-June-10/bcm96856O_PROV_uboot_rootfs_256.ubifs not removed, freed 0 bytes
2021/06/11 06:38:58 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm96878GWO_DPI_JUMBO_MAP_PURE181_uboot_rootfs_nonubifs not removed, freed 0 bytes
2021/06/11 06:38:58 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item nightly/504L02/TEST2.CommEngine_504L02_Custbuild/2021/202106-June/202106-June-11/bcm96858O_DPOE_TOD_SPDSVC_TR069TR143_linux_raw_image_256.bin not removed, freed 0 bytes
2021/06/11 06:38:58 INFO  : vfs cache: cleaned: objects 8655 (was 8655) in use 8655, to upload 8733, uploading 16, total size 355.182G (was 355.182G)

The log shows the files being uploaded, but you aren't seeing them on your remote?

Bits of a log is tough as the full log would be more meaningful to look at.

Based on what you shared, nothing is broken as there aren't any errors to look at.

If you manually wipe the cache, you lose anything that was going to uploaded.

If you can try to recreate the issue and get a full log, that's what we would want to look at.

You are on an old version as well as there are a few fixes for the cache in the latest. You'd want to update to that as well as that may it.

hi,

--fast-list does nothing on a mount.

dir-cache-time does not impact uploading. That's for the local file caching.

I have the old cache. I tried moving it back in place but I had the same problem that it wasn't creating the fuse mount from Box.

I moved the log aside and restarted rclone. I moved to the latest version

rclone v1.55.1
- os/type: linux
- os/arch: amd64
- go/version: go1.16.3
- go/linking: static
- go/tags: none

Here's the log. It is getting large quickly

2021/06/11 07:15:49 DEBUG : Using config file from "/auto/bcacpebuilder/rclone/rclone.conf"
2021/06/11 07:15:49 DEBUG : rclone: Version "v1.55.1" starting with parameters ["/auto/bcacpebuilder/rclone/rclone" "mount" "--allow-other" "--buffer-size=128M" "--cache-dir=/auto/bcacpebuilder/bca_daemon_vfs/cache" "--config=/auto/bcacpebuilder/rclone/rclone.conf" "--dir-cache-time=5m0s" "--fast-list" "--log-file=/auto/bcacpebuilder/bca_daemon_vfs/bca_daemon_vfs.log" "--low-level-retries=1" "--max-read-ahead=128k" "--rc" "--rc-addr=127.0.0.1:5582" "--transfers=16" "--vfs-cache-mode=full" "--vfs-read-chunk-size=128M" "--vfs-read-chunk-size-limit=2G" "-vv" "Box_BCACPE_VFS_Mount:test_nightly" "/auto/bcacpebuilder/bca_daemon_vfs/mount"]
2021/06/11 07:15:49 NOTICE: Serving remote control on http://127.0.0.1:5582/
2021/06/11 07:15:49 DEBUG : Creating backend with remote "Box_BCACPE_VFS_Mount:test_nightly"
2021/06/11 07:15:50 INFO  : box root 'test_nightly': poll-interval is not supported by this remote
2021/06/11 07:15:50 DEBUG : vfs cache: root is "/auto/bcacpebuilder/bca_daemon_vfs/cache/vfs/Box_BCACPE_VFS_Mount/test_nightly"
2021/06/11 07:15:50 DEBUG : vfs cache: metadata root is "/auto/bcacpebuilder/bca_daemon_vfs/cache/vfs/Box_BCACPE_VFS_Mount/test_nightly"
2021/06/11 07:15:50 DEBUG : Creating backend with remote "/auto/bcacpebuilder/bca_daemon_vfs/cache/vfs/Box_BCACPE_VFS_Mount/test_nightly"
2021/06/11 07:15:57 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: vfs cache: checking remote fingerprint "120833768,2021-06-10 20:07:11 +0000 UTC,23c695dd27a166865073f39bc1fea65217534887" against cached fingerprint "120833768,2021-06-10 20:07:11 +0000 UTC,23c695dd27a166865073f39bc1fea65217534887"
2021/06/11 07:15:57 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: vfs cache: truncate to size=120834012
2021/06/11 07:15:57 DEBUG : vfs cache: looking for range={Pos:0 Size:120834012} in [{Pos:0 Size:120834012}] - present true
2021/06/11 07:15:57 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: vfs cache: setting modification time to 2021-06-10 18:57:11.951990653 -0700 PDT
2021/06/11 07:15:57 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: vfs cache: queuing for upload in 5s
2021/06/11 07:15:59 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10: Added virtual directory entry vAddFile: "bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb"
2021/06/11 07:16:02 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: vfs cache: starting upload
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Multipart upload session started for 15 parts of size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 1/15 offset 0/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 2/15 offset 8M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 3/15 offset 16M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 4/15 offset 24M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 5/15 offset 32M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 6/15 offset 40M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 7/15 offset 48M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 8/15 offset 56M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 9/15 offset 64M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 10/15 offset 72M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 11/15 offset 80M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 12/15 offset 88M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 13/15 offset 96M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 14/15 offset 104M/115.236M part size 8M
2021/06/11 07:16:03 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Uploading part 15/15 offset 112M/115.236M part size 8M
2021/06/11 07:16:05 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: vfs cache: checking remote fingerprint "119784960,2021-06-10 20:07:11 +0000 UTC,5aa3984db56c2e2bb9848f9d1429bda683f15ea8" against cached fingerprint "119784960,2021-06-10 20:07:11 +0000 UTC,5aa3984db56c2e2bb9848f9d1429bda683f15ea8"
2021/06/11 07:16:05 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: vfs cache: truncate to size=119785204
2021/06/11 07:16:05 DEBUG : vfs cache: looking for range={Pos:0 Size:119785204} in [{Pos:0 Size:119785204}] - present true
2021/06/11 07:16:05 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: vfs cache: setting modification time to 2021-06-10 18:57:12.069991588 -0700 PDT
2021/06/11 07:16:05 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: vfs cache: queuing for upload in 5s
2021/06/11 07:16:05 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10: Added virtual directory entry vAddFile: "bcm962118GW_JUMBO_emmc_ext4_update.pkgtb"
2021/06/11 07:16:06 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: commit multipart upload failed 1/100 - trying again in 2 seconds (not ready yet)
2021/06/11 07:16:09 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: SHA-1 = 367cc632ab650873955fc9a2f50f1e6464663542 OK
2021/06/11 07:16:09 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: Copied (replaced existing)
2021/06/11 07:16:09 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: vfs cache: fingerprint now "120834012,2021-06-11 01:57:11 +0000 UTC,367cc632ab650873955fc9a2f50f1e6464663542"
2021/06/11 07:16:09 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_loader_update.pkgtb: vfs cache: upload succeeded try #1
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: vfs cache: starting upload
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_loader_update.pkgtb: vfs cache: checking remote fingerprint "43140860,2021-06-10 20:07:11 +0000 UTC,5a05c68154ee79ffd4d78711d4303ba0991ef8f8" against cached fingerprint "43140860,2021-06-10 20:07:11 +0000 UTC,5a05c68154ee79ffd4d78711d4303ba0991ef8f8"
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_loader_update.pkgtb: vfs cache: truncate to size=43141104
2021/06/11 07:16:10 DEBUG : vfs cache: looking for range={Pos:0 Size:43141104} in [{Pos:0 Size:43141104}] - present true
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_loader_update.pkgtb: vfs cache: setting modification time to 2021-06-10 18:57:12.112991929 -0700 PDT
2021/06/11 07:16:10 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_loader_update.pkgtb: vfs cache: queuing for upload in 5s
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10: Added virtual directory entry vAddFile: "bcm962118GW_JUMBO_emmc_squashfs_loader_update.pkgtb"
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Multipart upload session started for 15 parts of size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 1/15 offset 0/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 2/15 offset 8M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 3/15 offset 16M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 4/15 offset 24M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 5/15 offset 32M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 6/15 offset 40M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 7/15 offset 48M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 8/15 offset 56M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 9/15 offset 64M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 10/15 offset 72M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 11/15 offset 80M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 12/15 offset 88M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 13/15 offset 96M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 14/15 offset 104M/114.236M part size 8M
2021/06/11 07:16:10 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Uploading part 15/15 offset 112M/114.236M part size 8M
2021/06/11 07:16:15 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_loader_update.pkgtb: vfs cache: starting upload
2021/06/11 07:16:15 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: commit multipart upload failed 1/100 - trying again in 4 seconds (not ready yet)
2021/06/11 07:16:17 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: vfs cache: checking remote fingerprint "42092052,2021-06-10 20:07:11 +0000 UTC,2df2ffcec3a45edf32ea837093b2e9ed5a8d7543" against cached fingerprint "42092052,2021-06-10 20:07:11 +0000 UTC,2df2ffcec3a45edf32ea837093b2e9ed5a8d7543"
2021/06/11 07:16:17 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: vfs cache: truncate to size=42092296
2021/06/11 07:16:17 DEBUG : vfs cache: looking for range={Pos:0 Size:42092296} in [{Pos:0 Size:42092296}] - present true
2021/06/11 07:16:17 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: vfs cache: setting modification time to 2021-06-10 18:57:12.153992254 -0700 PDT
2021/06/11 07:16:17 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: vfs cache: queuing for upload in 5s
2021/06/11 07:16:17 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10: Added virtual directory entry vAddFile: "bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb"
2021/06/11 07:16:20 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: SHA-1 = 06f10a8ef8150ed68f9e1eb9bc890228f64df552 OK
2021/06/11 07:16:20 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: Copied (replaced existing)
2021/06/11 07:16:20 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: vfs cache: fingerprint now "119785204,2021-06-11 01:57:12 +0000 UTC,06f10a8ef8150ed68f9e1eb9bc890228f64df552"
2021/06/11 07:16:20 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_ext4_update.pkgtb: vfs cache: upload succeeded try #1
2021/06/11 07:16:20 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_loader_update.pkgtb: SHA-1 = 89c2620b7a6a63ed84080818bc5d5d0aa5538cf7 OK
2021/06/11 07:16:20 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_loader_update.pkgtb: Copied (replaced existing)
2021/06/11 07:16:20 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_loader_update.pkgtb: vfs cache: fingerprint now "43141104,2021-06-11 01:57:12 +0000 UTC,89c2620b7a6a63ed84080818bc5d5d0aa5538cf7"
2021/06/11 07:16:20 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_loader_update.pkgtb: vfs cache: upload succeeded try #1
2021/06/11 07:16:22 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: vfs cache: starting upload
2021/06/11 07:16:22 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: vfs cache: checking remote fingerprint "65011712,2021-06-10 20:07:12 +0000 UTC,71e75cbf8013451675b165bb46a7c85d412cad3b" against cached fingerprint ""
2021/06/11 07:16:22 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: vfs cache: truncate to size=65011712
2021/06/11 07:16:22 DEBUG : vfs cache: looking for range={Pos:0 Size:65011712} in [{Pos:0 Size:65011712}] - present true
2021/06/11 07:16:22 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: vfs cache: setting modification time to 2021-06-10 18:57:12.884998049 -0700 PDT
2021/06/11 07:16:22 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: vfs cache: queuing for upload in 5s
2021/06/11 07:16:22 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10: Added virtual directory entry vAddFile: "bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin"
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: vfs cache: starting upload
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: Multipart upload session started for 8 parts of size 8M
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: Uploading part 1/8 offset 0/62M part size 8M
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: Uploading part 2/8 offset 8M/62M part size 8M
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: Uploading part 3/8 offset 16M/62M part size 8M
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: Uploading part 4/8 offset 24M/62M part size 8M
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: Uploading part 5/8 offset 32M/62M part size 8M
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: Uploading part 6/8 offset 40M/62M part size 8M
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: Uploading part 7/8 offset 48M/62M part size 8M
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_emmc_userdata_part.bin: Uploading part 8/8 offset 56M/62M part size 8M
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: SHA-1 = 57dc47290798594b3087e435353992b8ca044cc9 OK
2021/06/11 07:16:27 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: Copied (replaced existing)
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: vfs cache: fingerprint now "42092296,2021-06-11 01:57:12 +0000 UTC,57dc47290798594b3087e435353992b8ca044cc9"
2021/06/11 07:16:27 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: vfs cache: upload succeeded try #1
2021/06/11 07:16:30 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_image_128.bin: vfs cache: checking remote fingerprint "64880640,2021-06-10 20:07:12 +0000 UTC,18033bac3b88c196db4a2ae524143d3c36c847f7" against cached fingerprint ""
2021/06/11 07:16:30 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_image_128.bin: vfs cache: truncate to size=64880640
2021/06/11 07:16:30 DEBUG : vfs cache: looking for range={Pos:0 Size:64880640} in [{Pos:0 Size:64880640}] - present true
2021/06/11 07:16:30 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_image_128.bin: vfs cache: setting modification time to 2021-06-10 18:57:12.950998572 -0700 PDT
2021/06/11 07:16:30 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_linux_raw_image_128.bin: vfs cache: queuing for upload in 5s
2021/06/11 07:16:30 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10: Added virtual directory entry vAddFile: "bcm962118GW_JUMBO_linux_raw_image_128.bin"

I tried to verify that this file was uploaded

2021/06/11 07:16:27 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: Copied (replaced existing)
2021/06/11 07:16:27 DEBUG : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: vfs cache: fingerprint now "42092296,2021-06-11 01:57:12 +0000 UTC,57dc47290798594b3087e435353992b8ca044cc9"
2021/06/11 07:16:27 INFO  : nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb: vfs cache: upload succeeded try #1

The file was uploaded

../rclone/rclone --config ../rclone/rclone.conf lsl Box_BCACPE_VFS_Mount:test_nightly/nightly/504L02/TEST.CommEngine_504L02_Consbuild/2021/202106-June/202106-June-10/bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb
 42092296 2021-06-10 18:57:12.000000000 bcm962118GW_JUMBO_emmc_squashfs_update.pkgtb

but the fuse mount isn't showing anything

ls -al /auto/bcacpebuilder/bca_daemon_vfs/mount
total 8
drwxr-xr-x 2 bcacpebuilder clearusers 4096 Jun  7 07:09 .
drwxr-xr-x 5 bcacpebuilder clearusers 4096 Jun 11 07:15 ..

The log is currently 207K and 1000+ lines. I think that is too big to include here.

sorry, thanks for catching that, as i misread the post.

If you stopped it and had a lot of uploads, you gotta wait it out until it gets uploaded.

You can share the log via any file share service / pastebin /etc.

I am going to close this thread.
I found out that there was an outage on box which may have caused this problem
I am not sure why it didn't recover but this method isn't going to work for us for a variety of reasons.
We will have to try something different.

1 Like

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.