How does the sync command works

jnimoth commented 11 months ago

Hey Illyoung, this is more an information request and not a bug report or so.

We started using gocommands to periodically sync a local directory with our iRODS environment. The idea was that just the changes, meaning new/changed files, are transferred to the iRODS side.

We made the following observations:

For subsequent runs, irsync -K is a lot faster. It just displays a a match no sync required for files that are already on the iRODS side.
gocmd sync seems to always first create a tar bundle of a subset of the data, then transfers these bundles, and extracts again on the iRODS side.

Based on our observations, I have some question about gocmd sync vs irsync.

At which point or how does gocmd sync decide which files are changed or not?
As gocmd sync has the additional flag --no_hash, I assume that the command also compares local vs. source checksums for that, correct?

Thanks!

jnimoth commented 11 months ago

We encounter another issue that relates to the above question:

If files/folders are transferred to iRODS using gocmd sync, they do not seem to replicate on the iRODS side.

Our system is setup so that we have two iRODS replica per data object. When I transfer a file with gocmd put everything also looks as expected:

$ ~/git_projects/gocommands_binaries/v0.7.7/gocmd put  ~/Nextcloud/Work/RDMS_SSNMR/ gocmd_put_test/

$  ils -l gocmd_put_test/RDMS_SSNMR
/rug/home/j.p.nimoth@rug.nl/gocmd_put_test/RDMS_SSNMR:
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt014;mnt_irods014         1002 2023-09-19.11:59 & 20221027_SSNMR_RDMS_Setup.md
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt213;mnt_irods213         1002 2023-09-19.11:59 & 20221027_SSNMR_RDMS_Setup.md
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt104;mnt_irods104         1700 2023-09-19.11:59 & Bruker_1D_Metadata.txt
  j.p.nimoth@r      1 rootResc;rootRandy;ptA;replA;randy01;pt024;mnt_irods024         1700 2023-09-19.11:59 & Bruker_1D_Metadata.txt
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt214;mnt_irods214         1846 2023-09-19.11:59 & Bruker_2D_Metadata.txt
  j.p.nimoth@r      1 rootResc;rootRandy;ptC;replC;randy11;pt103;mnt_irods103         1846 2023-09-19.11:59 & Bruker_2D_Metadata.txt
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt214;mnt_irods214          112 2023-09-19.11:59 & delete_logs.sh
  j.p.nimoth@r      1 rootResc;rootRandy;ptC;replC;randy11;pt113;mnt_irods113          112 2023-09-19.11:59 & delete_logs.sh
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204          552 2023-09-19.11:59 & irods_environment.json
  j.p.nimoth@r      1 rootResc;rootRandy;ptC;replC;randy11;pt124;mnt_irods124          552 2023-09-19.11:59 & irods_environment.json
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114         2599 2023-09-19.11:59 & MODIFIED_rdms_user-3.2.err
  j.p.nimoth@r      1 rootResc;rootRandy;ptA;replA;randy01;pt024;mnt_irods024         2599 2023-09-19.11:59 & MODIFIED_rdms_user-3.2.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt214;mnt_irods214         1095 2023-09-19.11:59 & MODIFIED_rdms_user3.2_HX.err
  j.p.nimoth@r      1 rootResc;rootRandy;ptC;replC;randy11;pt103;mnt_irods103         1095 2023-09-19.11:59 & MODIFIED_rdms_user3.2_HX.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt214;mnt_irods214          654 2023-09-19.11:59 & REDUCED_rdms_user-3.2.err
  j.p.nimoth@r      1 rootResc;rootRandy;ptC;replC;randy11;pt103;mnt_irods103          654 2023-09-19.11:59 & REDUCED_rdms_user-3.2.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004          408 2023-09-19.11:59 & REDUCED_rdms_user3.2_HX.err
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt213;mnt_irods213          408 2023-09-19.11:59 & REDUCED_rdms_user3.2_HX.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt104;mnt_irods104          216 2023-09-19.11:59 & ssnmr_sync.sh
  j.p.nimoth@r      1 rootResc;rootRandy;ptA;replA;randy01;pt024;mnt_irods024          216 2023-09-19.11:59 & ssnmr_sync.sh
  C- /rug/home/j.p.nimoth@rug.nl/gocmd_put_test/RDMS_SSNMR/1  
  C- /rug/home/j.p.nimoth@rug.nl/gocmd_put_test/RDMS_SSNMR/test

But when done with gocmd sync, just single replicas appear on the iRODS side:

$ ~/git_projects/gocommands_binaries/v0.7.7/gocmd sync  ~/Nextcloud/Work/RDMS_SSNMR/ i:gocmd_sync_dest/

$ ils -l gocmd_sync_dest/RDMS_SSNMR/
/rug/home/j.p.nimoth@rug.nl/gocmd_sync_dest/RDMS_SSNMR:
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204         1002 2023-09-19.11:58 & 20221027_SSNMR_RDMS_Setup.md
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204         1700 2023-09-19.11:58 & Bruker_1D_Metadata.txt
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204         1846 2023-09-19.11:58 & Bruker_2D_Metadata.txt
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204          112 2023-09-19.11:58 & delete_logs.sh
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204          552 2023-09-19.11:58 & irods_environment.json
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204         2599 2023-09-19.11:58 & MODIFIED_rdms_user-3.2.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204         1095 2023-09-19.11:58 & MODIFIED_rdms_user3.2_HX.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204          654 2023-09-19.11:58 & REDUCED_rdms_user-3.2.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204          408 2023-09-19.11:58 & REDUCED_rdms_user3.2_HX.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204          216 2023-09-19.11:58 & ssnmr_sync.sh
  C- /rug/home/j.p.nimoth@rug.nl/gocmd_sync_dest/RDMS_SSNMR/1  
  C- /rug/home/j.p.nimoth@rug.nl/gocmd_sync_dest/RDMS_SSNMR/test

The same is also observed for bput:

$ ~/git_projects/gocommands_binaries/v0.7.7/gocmd bput  ~/Nextcloud/Work/RDMS_SSNMR/ gocmd_bput_test/

$ ils -l gocmd_bput_test/RDMS_SSNMR
/rug/home/j.p.nimoth@rug.nl/gocmd_bput_test/RDMS_SSNMR:
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114         1002 2023-09-19.12:00 & 20221027_SSNMR_RDMS_Setup.md
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114         1700 2023-09-19.12:00 & Bruker_1D_Metadata.txt
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114         1846 2023-09-19.12:00 & Bruker_2D_Metadata.txt
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114          112 2023-09-19.12:00 & delete_logs.sh
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114          552 2023-09-19.12:00 & irods_environment.json
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114         2599 2023-09-19.12:00 & MODIFIED_rdms_user-3.2.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114         1095 2023-09-19.12:00 & MODIFIED_rdms_user3.2_HX.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114          654 2023-09-19.12:00 & REDUCED_rdms_user-3.2.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114          408 2023-09-19.12:00 & REDUCED_rdms_user3.2_HX.err
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114          216 2023-09-19.12:00 & ssnmr_sync.sh
  C- /rug/home/j.p.nimoth@rug.nl/gocmd_bput_test/RDMS_SSNMR/1  
  C- /rug/home/j.p.nimoth@rug.nl/gocmd_bput_test/RDMS_SSNMR/test

iychoi commented 11 months ago

Hi Jelte,

Sorry for late response. I forgot this issue.

Yes, it uses file size and hashcode (MD5) by default. If user gives --no_hash flag, it only uses file size to determine content change. Use of hashcode gives detection of content change nearly perfectly, but it can fail in following situations:

Hash code is not yet calculated by iRODS. Hash code calculation takes from few seconds to few minutes depending on server load. If iRODS hash code is not available, gocommands will try to overwrite.
Hash algorithm may be different. Gocommands uses MD5 because CyVerse Data Store uses the algorithm as defalut iRODS hash algorithm. I had no chance to test other iRODS servers using different hash algorithms. Let me know if you use different hash algorithm.

iychoi commented 11 months ago

It looks like bput does not handle replication correctly. Let me take a look!

iychoi commented 11 months ago

In our CyVerse Data Store, gocommands bput creates replicas correctly. I think our Data Store has a special rule that handles this.

Can you check how ibun in icommands works in this case? Gocommands actually uses the same APIs that ibun uses. https://docs.irods.org/4.3.0/icommands/user/

jnimoth commented 11 months ago

Hello Illyoung, we indeed use SHA256 as standard for hashing, not MD5.

I also just checked the behavior using ibun. When this is used, two replicas appear after extraction as it also should be:

$ ~/Downloads> ils -l
/rug/home/j.p.nimoth@rug.nl/via_ibun:
j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004     42690560 2023-10-09.15:59 & NMR.tar
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt224;mnt_irods224     42690560 2023-10-09.15:59 & NMR.tar

$ ~/Downloads> ibun -x NMR.tar .

$ ~/Downloads> ils -l
/rug/home/j.p.nimoth@rug.nl/via_ibun:
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004     42690560 2023-10-09.15:59 & NMR.tar
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt224;mnt_irods224     42690560 2023-10-09.15:59 & NMR.tar
  C- /rug/home/j.p.nimoth@rug.nl/via_ibun/NMR_Files
$ ~/Downloads> ils -lr NMR_Files
/rug/home/j.p.nimoth@rug.nl/via_ibun/NMR_Files:
  C- /rug/home/j.p.nimoth@rug.nl/via_ibun/NMR_Files/C6D6
/rug/home/j.p.nimoth@rug.nl/via_ibun/NMR_Files/C6D6:
  C- /rug/home/j.p.nimoth@rug.nl/via_ibun/NMR_Files/C6D6/p302222
/rug/home/j.p.nimoth@rug.nl/via_ibun/NMR_Files/C6D6/p302222:
  C- /rug/home/j.p.nimoth@rug.nl/via_ibun/NMR_Files/C6D6/p302222/mfp-chlorobinol
/rug/home/j.p.nimoth@rug.nl/via_ibun/NMR_Files/C6D6/p302222/mfp-chlorobinol:
  C- /rug/home/j.p.nimoth@rug.nl/via_ibun/NMR_Files/C6D6/p302222/mfp-chlorobinol/10
/rug/home/j.p.nimoth@rug.nl/via_ibun/NMR_Files/C6D6/p302222/mfp-chlorobinol/10:
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         8553 2023-10-09.16:01 & acqu
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt215;mnt_irods215         8553 2023-10-09.16:01 & acqu
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         8800 2023-10-09.16:01 & acqus
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt205;mnt_irods205         8800 2023-10-09.16:01 & acqus
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004          452 2023-10-09.16:01 & adcInfo_TRX1.xml
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt205;mnt_irods205          452 2023-10-09.16:01 & adcInfo_TRX1.xml
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         1100 2023-10-09.16:01 & audita.txt
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt224;mnt_irods224         1100 2023-10-09.16:01 & audita.txt
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004       524288 2023-10-09.16:01 & fid
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt215;mnt_irods215       524288 2023-10-09.16:01 & fid
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         2170 2023-10-09.16:01 & format.temp
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt224;mnt_irods224         2170 2023-10-09.16:01 & format.temp
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         2057 2023-10-09.16:01 & preemp_default_Z114607_0280
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt215;mnt_irods215         2057 2023-10-09.16:01 & preemp_default_Z114607_0280
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004            0 2023-10-09.16:01 & prosol_History
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt224;mnt_irods224            0 2023-10-09.16:01 & prosol_History
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004          561 2023-10-09.16:01 & pulseprogram
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt205;mnt_irods205          561 2023-10-09.16:01 & pulseprogram
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         2469 2023-10-09.16:01 & pulseprogram.precomp
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt205;mnt_irods205         2469 2023-10-09.16:01 & pulseprogram.precomp
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004          639 2023-10-09.16:01 & scon2
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt224;mnt_irods224          639 2023-10-09.16:01 & scon2
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         2940 2023-10-09.16:01 & shimvalues
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt215;mnt_irods215         2940 2023-10-09.16:01 & shimvalues
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         4266 2023-10-09.16:01 & specpar
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt224;mnt_irods224         4266 2023-10-09.16:01 & specpar
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         4674 2023-10-09.16:01 & stanprogram26199
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt215;mnt_irods215         4674 2023-10-09.16:01 & stanprogram26199
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         3114 2023-10-09.16:01 & stanprogram26199.precomp
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt215;mnt_irods215         3114 2023-10-09.16:01 & stanprogram26199.precomp
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         4674 2023-10-09.16:01 & stanprogram26615
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt224;mnt_irods224         4674 2023-10-09.16:01 & stanprogram26615
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         2934 2023-10-09.16:01 & stanprogram26615.precomp
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt205;mnt_irods205         2934 2023-10-09.16:01 & stanprogram26615.precomp
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004         5271 2023-10-09.16:01 & uxnmr.info
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt215;mnt_irods215         5271 2023-10-09.16:01 & uxnmr.info
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004        27889 2023-10-09.16:01 & uxnmr.par
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt205;mnt_irods205        27889 2023-10-09.16:01 & uxnmr.par
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004          486 2023-10-09.16:01 & vtc_pid_settings
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt205;mnt_irods205          486 2023-10-09.16:01 & vtc_pid_settings

[and so on]

But I also realized upon further testing that while ibun -x results in two replicas, it does not compute and store checksums for both replicas. Instead it seems that always just a checksum for replica 1 is created/stored, but not for replica 0. I am not sure how this is related to the gocmd issues that I reported here, but not to leave out any relevant information, this is another simple ibun -x example that shows this behavior quite well:

$ iput -K ~/Downloads/irodsfs_amd64_linux_v0.7.8.tar 

$ ils -L irodsfs_amd64_linux_v0.7.8.tar 
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt025;mnt_irods025     18800640 2023-10-10.11:19 & irodsfs_amd64_linux_v0.7.8.tar
    sha2:XheW5DIqdjEpoDujTSg8ftj2GDPDnTRXTuPPcFS6de0=    generic    /mnt/irods025/home/j.p.nimoth@rug.nl/irodsfs_amd64_linux_v0.7.8.tar
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt215;mnt_irods215     18800640 2023-10-10.11:20 & irodsfs_amd64_linux_v0.7.8.tar
    sha2:XheW5DIqdjEpoDujTSg8ftj2GDPDnTRXTuPPcFS6de0=    generic    /mnt/irods215/home/j.p.nimoth@rug.nl/irodsfs_amd64_linux_v0.7.8.tar

$  ibun -x irodsfs_amd64_linux_v0.7.8.tar irodsfs_extracted

$ ils -L irodsfs_extracted
/rug/home/j.p.nimoth@rug.nl/irodsfs_extracted:
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt025;mnt_irods025     18790648 2023-10-10.11:20 & irodsfs
        generic    /mnt/irods025/home/j.p.nimoth@rug.nl/irodsfs_extracted/irodsfs
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt205;mnt_irods205     18790648 2023-10-10.11:20 & irodsfs
    sha2:w/D7GoyRU3Ahs3KZffFXi5N5UoIJGU71AfBHrLoqoxw=    generic    /mnt/irods205/home/j.p.nimoth@rug.nl/irodsfs_extracted/irodsfs

So using ibun -x creates both replicas, but does not create/store checksums for both replica, but rather just for one. I do not know why this is happening, but I think that our local iRODS system admins have to look into this.

Now back to the gocmd observations: I saw that when I re-run the gocmd sync again, the single replicas get an updated date marked on the iRODS side, even if they where not changed. Using the additional --no_hash flag does not seem to change anything about that:

$  v0.7.9/gocmd sync --progress ~/Downloads/Grafana/ i:
bundle 0 - TAR                                     ... done! [31.02K in 1ms]
bundle 0 - Upload                                  ... done! [36.35KB in 22ms]
bundle 0 - Remove Old Files                        ... done! [5 in 1.737s]
bundle 0 - Extract                                 ... done! [5 in 4.884s]

$  v0.7.9/gocmd ls -l Grafana
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptC;replC;randy20;pt214;mnt_irods214 490     2023-10-10.10:52        &       delayRule_usage.r
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptC;replC;randy20;pt214;mnt_irods214 1431    2023-10-10.10:52        &       general_usage.json
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptC;replC;randy20;pt214;mnt_irods214 2651    2023-10-10.10:52        &       iRODS_Distribution_of_Data_Objects_Quantity_By_Size.json
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptC;replC;randy20;pt214;mnt_irods214 24361   2023-10-10.10:52        &       usage.py
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptC;replC;randy20;pt214;mnt_irods214 2084    2023-10-10.10:52        &       usage_per_user.json

$  v0.7.9/gocmd sync --progress ~/Downloads/Grafana/ i:
bundle 0 - TAR                                     ... done! [31.02K in 1ms]
bundle 0 - Upload                                  ... done! [36.35KB in 9ms]
bundle 0 - Remove Old Files                        ... done! [5 in 1.166s]
bundle 0 - Extract                                 ... done! [5 in 3.703s]

$  v0.7.9/gocmd ls -l Grafana
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004 490     2023-10-10.10:53        &       delayRule_usage.r
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004 1431    2023-10-10.10:53        &       general_usage.json
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004 2651    2023-10-10.10:53        &       iRODS_Distribution_of_Data_Objects_Quantity_By_Size.json
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004 24361   2023-10-10.10:53        &       usage.py
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004 2084    2023-10-10.10:53        &       usage_per_user.json

$  v0.7.9/gocmd sync --progress --no_hash ~/Downloads/Grafana/ i:
bundle 0 - TAR                                     ... done! [31.02K in 1ms]
bundle 0 - Upload                                  ... done! [36.35KB in 2ms]
bundle 0 - Remove Old Files                        ... done! [5 in 1.697s]
bundle 0 - Extract                                 ... done! [5 in 3.887s]

$  v0.7.9/gocmd ls -l Grafana
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225 490     2023-10-10.10:54        &       delayRule_usage.r
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225 1431    2023-10-10.10:54        &       general_usage.json
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225 2651    2023-10-10.10:54        &       iRODS_Distribution_of_Data_Objects_Quantity_By_Size.json
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225 24361   2023-10-10.10:54        &       usage.py
  j.p.nimoth@rug.nl     0       rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225 2084    2023-10-10.10:54        &       usage_per_user.json

I also saw that there does not seem to be a checksum calculated for the files that were transferred via the gocmd sync.

See here the upload via gocmd sync:

ils -L Grafana
/rug/home/j.p.nimoth@rug.nl/Grafana:
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225          490 2023-10-10.10:54 & delayRule_usage.r
        generic    /mnt/irods225/home/j.p.nimoth@rug.nl/Grafana/delayRule_usage.r
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225         1431 2023-10-10.10:54 & general_usage.json
        generic    /mnt/irods225/home/j.p.nimoth@rug.nl/Grafana/general_usage.json
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225         2651 2023-10-10.10:54 & iRODS_Distribution_of_Data_Objects_Quantity_By_Size.json
        generic    /mnt/irods225/home/j.p.nimoth@rug.nl/Grafana/iRODS_Distribution_of_Data_Objects_Quantity_By_Size.json
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225         2084 2023-10-10.10:54 & usage_per_user.json
        generic    /mnt/irods225/home/j.p.nimoth@rug.nl/Grafana/usage_per_user.json
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225        24361 2023-10-10.10:54 & usage.py
        generic    /mnt/irods225/home/j.p.nimoth@rug.nl/Grafana/usage.py

Compared to a standard iput of the original icommands:

$ iput -r ~/Downloads/Grafana/ Grafana2/
Running recursive pre-scan... pre-scan complete... transferring data...

$ ils -L Grafana2
/rug/home/j.p.nimoth@rug.nl/Grafana2:
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy00;pt014;mnt_irods014          490 2023-10-10.10:56 & delayRule_usage.r
    sha2:2WhZCWAVblbKhIkkCOHdEecYNdMUWZsnhCfbxOQC2mA=    generic    /mnt/irods014/home/j.p.nimoth@rug.nl/Grafana2/delayRule_usage.r
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy21;pt224;mnt_irods224          490 2023-10-10.10:56 & delayRule_usage.r
    sha2:2WhZCWAVblbKhIkkCOHdEecYNdMUWZsnhCfbxOQC2mA=    generic    /mnt/irods224/home/j.p.nimoth@rug.nl/Grafana2/delayRule_usage.r
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114         1431 2023-10-10.10:56 & general_usage.json
    sha2:ysM5VSWJzDLF2Y8NW1QSxbPvdhSKjckOivoM2/2guCw=    generic    /mnt/irods114/home/j.p.nimoth@rug.nl/Grafana2/general_usage.json
  j.p.nimoth@r      1 rootResc;rootRandy;ptA;replA;randy01;pt024;mnt_irods024         1431 2023-10-10.10:56 & general_usage.json
    sha2:ysM5VSWJzDLF2Y8NW1QSxbPvdhSKjckOivoM2/2guCw=    generic    /mnt/irods024/home/j.p.nimoth@rug.nl/Grafana2/general_usage.json
  j.p.nimoth@r      0 rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225         2651 2023-10-10.10:56 & iRODS_Distribution_of_Data_Objects_Quantity_By_Size.json
    sha2:S3LOdZOn/7owjJ/v//YP2W1P74xrow5/Fr2wyiSfngk=    generic    /mnt/irods225/home/j.p.nimoth@rug.nl/Grafana2/iRODS_Distribution_of_Data_Objects_Quantity_By_Size.json
  j.p.nimoth@r      1 rootResc;rootRandy;ptC;replC;randy11;pt115;mnt_irods115         2651 2023-10-10.10:56 & iRODS_Distribution_of_Data_Objects_Quantity_By_Size.json
    sha2:S3LOdZOn/7owjJ/v//YP2W1P74xrow5/Fr2wyiSfngk=    generic    /mnt/irods115/home/j.p.nimoth@rug.nl/Grafana2/iRODS_Distribution_of_Data_Objects_Quantity_By_Size.json
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt104;mnt_irods104         2084 2023-10-10.10:56 & usage_per_user.json
    sha2:2o46I+Ox7j3yWoP+Rw/MgqnfISCWTnNaFHPGp3CsMP4=    generic    /mnt/irods104/home/j.p.nimoth@rug.nl/Grafana2/usage_per_user.json
  j.p.nimoth@r      1 rootResc;rootRandy;ptA;replA;randy01;pt005;mnt_irods005         2084 2023-10-10.10:56 & usage_per_user.json
    sha2:2o46I+Ox7j3yWoP+Rw/MgqnfISCWTnNaFHPGp3CsMP4=    generic    /mnt/irods005/home/j.p.nimoth@rug.nl/Grafana2/usage_per_user.json
  j.p.nimoth@r      0 rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114        24361 2023-10-10.10:56 & usage.py
    sha2:0gByr3C9KRSsF0EBcWelSne6g0LgJ9JOqni6Gcf62Bg=    generic    /mnt/irods114/home/j.p.nimoth@rug.nl/Grafana2/usage.py
  j.p.nimoth@r      1 rootResc;rootRandy;ptA;replA;randy01;pt024;mnt_irods024        24361 2023-10-10.10:56 & usage.py
    sha2:0gByr3C9KRSsF0EBcWelSne6g0LgJ9JOqni6Gcf62Bg=    generic    /mnt/irods024/home/j.p.nimoth@rug.nl/Grafana2/usage.py

Compared to the behavior of gocmd put which also results in two replicas per data object (I did not show it here, but the replicas also have both checksums calculated/stored in this case):

$  v0.7.9/gocmd put --progress ~/Downloads/Grafana/ Grafana3/
/home/jelte/Downloads/Grafana/usage_per_user.json  ... done! [2.08KB in 921ms]
/home/jelte/Downloads/Grafana/general_usage.json   ... done! [1.43KB in 1.428s]
/home/jelte/Downloads/Grafana/usage.py             ... done! [24.36KB in 1.816s]
/home/jelte/Downloads/Grafana/delayRule_usage.r    ... done! [490B in 2.359s]
/home/jelte/Downloads/Grafana/iRODS_Distribution_~ ... done! [2.65KB in 3.25s]

$  v0.7.9/gocmd ls -l Grafana3/Grafana/
  j.p.nimoth@rug.nl 0   rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204 490 2023-10-10.15:44    &   delayRule_usage.r
  j.p.nimoth@rug.nl 1   rootResc;rootRandy;ptC;replC;randy11;pt105;mnt_irods105 490 2023-10-10.15:44    &   delayRule_usage.r
  j.p.nimoth@rug.nl 0   rootResc;rootRandy;ptC;replC;randy20;pt204;mnt_irods204 1431    2023-10-10.15:44    &   general_usage.json
  j.p.nimoth@rug.nl 1   rootResc;rootRandy;ptC;replC;randy11;pt115;mnt_irods115 1431    2023-10-10.15:44    &   general_usage.json
  j.p.nimoth@rug.nl 0   rootResc;rootRandy;ptB;replB;randy00;pt025;mnt_irods025 2651    2023-10-10.15:44    &   iRODS_Distribution_of_Data_Objects_Quantity_By_Size.json
  j.p.nimoth@rug.nl 1   rootResc;rootRandy;ptB;replB;randy21;pt215;mnt_irods215 2651    2023-10-10.15:44    &   iRODS_Distribution_of_Data_Objects_Quantity_By_Size.json
  j.p.nimoth@rug.nl 0   rootResc;rootRandy;ptA;replA;randy10;pt114;mnt_irods114 24361   2023-10-10.15:44    &   usage.py
  j.p.nimoth@rug.nl 1   rootResc;rootRandy;ptA;replA;randy01;pt024;mnt_irods024 24361   2023-10-10.15:44    &   usage.py
  j.p.nimoth@rug.nl 0   rootResc;rootRandy;ptC;replC;randy20;pt225;mnt_irods225 2084    2023-10-10.15:44    &   usage_per_user.json
  j.p.nimoth@rug.nl 1   rootResc;rootRandy;ptC;replC;randy11;pt105;mnt_irods105 2084    2023-10-10.15:44    &   usage_per_user.json

Thanks again for your assistance!

iychoi commented 11 months ago

Hi Jelte,

It looks like two separate issues resulted in this symptom. I need to separate them to track and handle. I created another github issue https://github.com/cyverse/gocommands/issues/19 for the hash algorithm support.

About the issue related to the replica, gocmd bput and gocmd sync use bulk registration mode while ibun -x uses normal registration mode. Can you test ibun -x with -b flag? The bulk registration mode reduces overhead of data object registration to iCAT, so gocmd uses it by default.

jnimoth commented 10 months ago

Thanks for looking into this. I agree that it looks to be different issues.

I also compared now how ibun -bx behaves on our system, and indeed, it seems to behave like gocmd bput and gocmd sync:

If ibun -bx is used, just a single replica seems to be created and the single replica does not have a checksum registered

$ ibun -bx irodsfs_amd64_linux_v0.7.8.tar irodsfs_bulk_extracted

$ ils -L irodsfs_bulk_extracted
/rug/home/j.p.nimoth@rug.nl/irodsfs_bulk_extracted:
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy21;pt215;mnt_irods215     18790648 2023-10-12.11:30 & irodsfs
        generic    /mnt/irods215/home/j.p.nimoth@rug.nl/irodsfs_bulk_extracted/irodsfs

Here again for direct comparison the behavior with ibun -x (two replicas, but also just checksum for replica 1)

$ ibun -x irodsfs_amd64_linux_v0.7.8.tar irodsfs_extracted

$ ils -L irodsfs_extracted
/rug/home/j.p.nimoth@rug.nl/irodsfs_extracted:
  j.p.nimoth@r      0 rootResc;rootRandy;ptB;replB;randy21;pt215;mnt_irods215     18790648 2023-10-12.11:31 & irodsfs
        generic    /mnt/irods215/home/j.p.nimoth@rug.nl/irodsfs_extracted/irodsfs
  j.p.nimoth@r      1 rootResc;rootRandy;ptB;replB;randy00;pt004;mnt_irods004     18790648 2023-10-12.11:31 & irodsfs
    sha2:w/D7GoyRU3Ahs3KZffFXi5N5UoIJGU71AfBHrLoqoxw=    generic    /mnt/irods004/home/j.p.nimoth@rug.nl/irodsfs_extracted/irodsfs

iychoi commented 10 months ago

Alright, it looks like the bulk registration option is errornous. I can add a flag that turns the bulk registration option off. Will this fix your issue?

iychoi commented 10 months ago

Just released a new version v0.7.10 that hopefully fixes the issues.

The new flag --no_bulk_reg can be used to disable the bulk registration. This will solve the issue that replicas were not created.

Also, the release fixes the checksum (hash) issue. I added supports for various checksum algorithms supported by iRODS server.

About the issue that sync did not skip uploading existing files even with --no_hash flag, I wasn't able to reproduce the issue. Can you add -d flag to turn on debug log without --progress and share the result? It will tell a reason why a file had to be uploaded or skipped.

https://github.com/cyverse/gocommands/releases/tag/v0.7.10

jnimoth commented 10 months ago

Hi Illyoung, first for the --no_bulk_reg flag: I just tried the sync command using this flag, it now it creates two replica. Still just one replica gets an checksum, but that is also the case for ibun -x, so I think it is unrelated to gocommands. Thanks for that.

Now to the further behavior of gocmd sync (using v0.7.11 now):

First again the initial upload which takes ~24 s.

user@ssh:~/gocommands$ time ./gocmd sync --progress --no_bulk_reg ../iBridges-Gui/ i:                                                                                                                                                                       
bundle 0 - TAR                                     ... done! [2.66M in 87ms]                                                                                                                                                                                   
bundle 1 - TAR                                     ... done! [391.92K in 79ms]                                                                                                                                                                                 
bundle 2 - TAR                                     ... done! [294.65K in 5ms]                                                                                                                                                                                  
bundle 3 - TAR                                     ... done! [526.54K in 3ms]                                                                                                                                                                                  
bundle 0 - Upload                                  ... done! [2.88MB in 52ms]                                                                                                                                                                                  
bundle 1 - Upload                                  ... done! [492.03KB in 18ms]                                                                                                                                                                                
bundle 2 - Upload                                  ... done! [396.80KB in 16ms]                                                                                                                                                                                
bundle 3 - Upload                                  ... done! [585.73KB in 19ms]                                                                                                                                                                                
bundle 0 - Remove Old Files                        ... done! [50 in 4.668s]                                                                                                                                                                                    
bundle 1 - Remove Old Files                        ... done! [50 in 3.377s]                                                                                                                                                                                    
bundle 2 - Remove Old Files                        ... done! [50 in 3.853s]                                                                                                                                                                                    
bundle 3 - Remove Old Files                        ... done! [25 in 1.615s]                                                                                                                                                                                    
bundle 0 - Extract                                 ... done! [50 in 11.503s]                                                                                                                                                                                   
bundle 1 - Extract                                 ... done! [50 in 9.914s]                                                                                                                                                                                    
bundle 3 - Extract                                 ... done! [25 in 7.041s]                                                                                                                                                                                    
bundle 2 - Extract                                 ... done! [50 in 11.488s]                                                                                                                                                                                   

real    0m24.663s                                                                                                                                                                                                                                              
user    0m0.270s                                                                                                                                                                                                                                               
sys     0m0.132s                                                                                                                                                                                                                                               
user@ssh:~/gocommands$ ./gocmd ls -l iBridges-Gui                                                                                                                                                                                                           
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        98      2023-10-20.14:04      &.flake8                                                                                                                         
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        98      2023-10-20.14:04      &.flake8                                                                                                                         
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        1899    2023-10-20.14:04      &.gitignore                                                                                                                      
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        1899    2023-10-20.14:04      &.gitignore                                                                                                                      
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        327     2023-10-20.14:04      &.pylintrc                                                                                                                       
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        327     2023-10-20.14:04      &.pylintrc                                                                                                                       
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        35149   2023-10-20.14:04      &LICENSE                                                                                                                         
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        35149   2023-10-20.14:04      &LICENSE                                                                                                                         
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        3499    2023-10-20.14:04      &README.md                                                                                                                       
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        3499    2023-10-20.14:04      &README.md                                                                                                                       
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        579     2023-10-20.14:04      &_quarto.yml                                                                                                                     
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        579     2023-10-20.14:04      &_quarto.yml                                                                                                                     
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        8588    2023-10-20.14:04      &iBridges.py                                                                                                                     
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        8588    2023-10-20.14:04      &iBridges.py                                                                                                                     
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        16414   2023-10-20.14:04      &iBridgesCli.py                                                                                                                  
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        16414   2023-10-20.14:04      &iBridgesCli.py                                                                                                                  
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        6143    2023-10-20.14:04      &iBridgesGui-HowTo.md                                                                                                            
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        6143    2023-10-20.14:04      &iBridgesGui-HowTo.md                                                                                                            
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        408     2023-10-20.14:04      &index.qmd                                                                                                                       
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        408     2023-10-20.14:04      &index.qmd
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        6349    2023-10-20.14:05      &pyinstaller_script.py
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        6349    2023-10-20.14:05      &pyinstaller_script.py
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        128     2023-10-20.14:05      &requirements.txt
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        128     2023-10-20.14:05      &requirements.txt
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptA;replA;randy01;pt001;mnt_irodst001        61      2023-10-20.14:05      &requirements_dev.txt
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptA;replA;randy10;pt100;mnt_irodst100        61      2023-10-20.14:05      &requirements_dev.txt
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/.git
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/.github
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/_styles
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/docker
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/docs
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/gui
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/meta
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/rules
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/screenshots 
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/test
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/tests
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/utils

On consecutive runs, it takes nearly the same time, also the modification times of the files in iRODS gets still adjusted:

308297@ssh:~/gocommands$ time ./gocmd sync --progress --no_bulk_reg ../iBridges-Gui/ i:
bundle 0 - TAR                                     ... done! [2.61M in 89ms]
bundle 1 - TAR                                     ... done! [175.97K in 55ms]
bundle 2 - TAR                                     ... done! [294.65K in 37ms]
bundle 3 - TAR                                     ... done! [459.68K in 15ms]
bundle 0 - Upload                                  ... done! [2.88MB in 46ms]
bundle 1 - Upload                                  ... done! [492.03KB in 21ms]
bundle 2 - Upload                                  ... done! [396.80KB in 18ms]
bundle 3 - Upload                                  ... done! [585.73KB in 21ms]
bundle 0 - Remove Old Files                        ... done! [50 in 4.328s]
bundle 1 - Remove Old Files                        ... done! [50 in 3.148s]
bundle 2 - Remove Old Files                        ... done! [50 in 3.671s]
bundle 3 - Remove Old Files                        ... done! [25 in 1.536s]
bundle 0 - Extract                                 ... done! [50 in 9.346s]
bundle 1 - Extract                                 ... done! [50 in 10.162s]
bundle 2 - Extract                                 ... done! [50 in 9.392s]
bundle 3 - Extract                                 ... done! [25 in 8.14s]

real    0m23.081s
user    0m0.315s
sys     0m0.136s
user@ssh:~/gocommands$ ./gocmd ls -l iBridges-Gui                                                                            
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptB;replB;randy00;pt000;mnt_irodst000        98      2023-10-20.14:08        &       .flake8
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptB;replB;randy21;pt201;mnt_irodst201        98      2023-10-20.14:08        &       .flake8
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptB;replB;randy00;pt000;mnt_irodst000        1899    2023-10-20.14:08        &       .gitignore
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptB;replB;randy21;pt201;mnt_irodst201        1899    2023-10-20.14:08        &       .gitignore
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptB;replB;randy00;pt000;mnt_irodst000        327     2023-10-20.14:08        &       .pylintrc
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptB;replB;randy21;pt201;mnt_irodst201        327     2023-10-20.14:08        &       .pylintrc
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptB;replB;randy00;pt000;mnt_irodst000        35149   2023-10-20.14:08        &       LICENSE
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptB;replB;randy21;pt201;mnt_irodst201        35149   2023-10-20.14:08        &       LICENSE
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptB;replB;randy00;pt000;mnt_irodst000        3499    2023-10-20.14:08        &       README.md
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptB;replB;randy21;pt201;mnt_irodst201        3499    2023-10-20.14:08        &       README.md
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptB;replB;randy00;pt000;mnt_irodst000        579     2023-10-20.14:08        &       _quarto.yml
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptB;replB;randy21;pt201;mnt_irodst201        579     2023-10-20.14:08        &       _quarto.yml
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200        8588    2023-10-20.14:08        &       iBridges.py
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101        8588    2023-10-20.14:08        &       iBridges.py
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200        16414   2023-10-20.14:08        &       iBridgesCli.py
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101        16414   2023-10-20.14:08        &       iBridgesCli.py
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200        6143    2023-10-20.14:08        &       iBridgesGui-HowTo.md
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101        6143    2023-10-20.14:08        &       iBridgesGui-HowTo.md
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200        408     2023-10-20.14:08        &       index.qmd
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101        408     2023-10-20.14:08        &       index.qmd
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200        6349    2023-10-20.14:08        &       pyinstaller_script.py
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101        6349    2023-10-20.14:08        &       pyinstaller_script.py
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200        128     2023-10-20.14:08        &       requirements.txt
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101        128     2023-10-20.14:08        &       requirements.txt
  rdms-testers@rug.nl   0       rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200        61      2023-10-20.14:08        &       requirements_dev.txt
  rdms-testers@rug.nl   1       rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101        61      2023-10-20.14:08        &       requirements_dev.txt
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/.git
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/.github
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/_styles
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/docker
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/docs
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/gui
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/meta
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/rules
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/screenshots 
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/test
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/tests
  C- /testrug/home/rdms-testers@rug.nl/iBridges-Gui/utils

But, if I use the --no_hash flag, it now skips the existing files in this version of gocommands and the process ends nearly instantly:

user@ssh:~/gocommands$ time ./gocmd sync --progress --no_bulk_reg --no_hash ../iBridges-Gui/ i:                                                                                                                                                             
skip adding a file /home/user/iBridges-Gui/.flake8 to the bundle. The file already exists!                                                                                                                                                                  
skip adding a file /home/user/iBridges-Gui/docs/commandlineclient.qmd to the bundle. The file already exists!       

[...]

skip adding a file /home/user/iBridges-Gui/utils/utils.py to the bundle. The file already exists!

real    0m1.577s
user    0m0.087s
sys     0m0.043s

For comparison, I tried again the same using v0.7.9, and indeed, for this version the behavior is different even when using the --no_hash flag:

user@ssh:~$ mv gocmd gocommands/gocmd-0.7.9
user@ssh:~$ cd gocommands/
user@ssh:~/gocommands$ time ./gocmd-0.7.9 sync --progress  --no_hash ../iBridges-Gui/ i:iBridges2
bundle 0 - TAR                                     ... done! [2.75M in 50ms]
bundle 1 - TAR                                     ... done! [391.92K in 53ms]
bundle 2 - TAR                                     ... done! [294.65K in 50ms]
bundle 3 - TAR                                     ... done! [526.54K in 33ms]
bundle 0 - Upload                                  ... done! [2.88MB in 39ms]
bundle 0 - Remove Old Files                        ... done! [50 in 1.123s]
bundle 1 - Upload                                  ... done! [492.03KB in 10ms]
bundle 2 - Upload                                  ... done! [396.80KB in 23ms]
bundle 3 - Upload                                  ... done! [585.73KB in 27ms]
bundle 1 - Remove Old Files                        ... done! [50 in 1.103s]
bundle 2 - Remove Old Files                        ... done! [50 in 1.044s]
bundle 3 - Remove Old Files                        ... done! [25 in 526ms]
bundle 3 - Extract                                 ... done! [25 in 3.247s]
bundle 2 - Extract                                 ... done! [50 in 4.249s]
bundle 0 - Extract                                 ... done! [50 in 4.649s]
bundle 1 - Extract                                 ... done! [50 in 2.182s]

real    0m10.518s
user    0m0.454s
sys     0m0.194s
user@ssh:~/gocommands$ time ./gocmd-0.7.9 sync --progress  --no_hash ../iBridges-Gui/ i:iBridges2
bundle 0 - TAR                                     ... done! [2.75M in 11ms]
bundle 1 - TAR                                     ... done! [391.92K in 5ms]
bundle 2 - TAR                                     ... done! [48.32K in 1ms]
bundle 3 - TAR                                     ... done! [526.54K in 4ms]
bundle 0 - Upload                                  ... done! [2.88MB in 69ms]
bundle 1 - Upload                                  ... done! [492.03KB in 10ms]
bundle 2 - Upload                                  ... done! [396.80KB in 17ms]
bundle 3 - Upload                                  ... done! [585.73KB in 27ms]
bundle 0 - Remove Old Files                        ... done! [50 in 3.576s]
bundle 1 - Remove Old Files                        ... done! [50 in 3.058s]
bundle 0 - Extract                                 ... done! [50 in 3.87s]
bundle 1 - Extract                                 ... done! [50 in 2.124s]
bundle 2 - Remove Old Files                        ... done! [50 in 2.658s]
bundle 3 - Remove Old Files                        ... done! [25 in 1.877s]
bundle 2 - Extract                                 ... done! [50 in 4.12s]
bundle 3 - Extract                                 ... done! [25 in 3.301s]

real    0m15.223s
user    0m0.203s
sys     0m0.127s

So the new version already improved on that for me! Thanks!

But now, I still wonder why in v0.7.11, it still seems that the files are not detected even when it should now support the different hash algorithms.

For that, here again a smaller example using gocmd sync in v0.7.11 with the additional debug flag for troubleshooting:

# Initital run

user@ssh:~/gocommands$ time ./gocmd sync --progress --no_bulk_reg  ../example_files/ i:                                                                                                                                                                     
bundle 0 - Remove Old Files                        ... done! [10 in 66ms]                                                                                                                                                                                      
bundle 0 - TAR                                     ... done! [10.49M in 478ms]                                                                                                                                                                                 
bundle 0 - Upload                                  ... done! [104.88MB in 1.323s]                                                                                                                                                                              
bundle 0 - Extract                                 ... done! [10 in 10.906s]                                                                                                                                                                                   

real    0m19.843s                                                                                                                                                                                                                                              
user    0m0.164s                                                                                                                                                                                                                                               
sys     0m0.305s                            

# Look at the content after sync
user@ssh:~/gocommands$ time ./gocmd ls example_files/                                                                                                                                                                                                       
  example_file_1                                                                                                                                                                                                                                               
  example_file_10                                                                                                                                                                                                                                              
  example_file_2                                                                                                                                                                                                                                               
  example_file_3                                                                                                                                                                                                                                               
  example_file_4                                                                                                                                                                                                                                               
  example_file_5                                                                                                                                                                                                                                               
  example_file_6                                                                                                                                                                                                                                               
  example_file_7                                                                                                                                                                                                                                               
  example_file_8                                                                                                                                                                                                                                               
  example_file_9                                                                                                                                                                                                                                               

real    0m0.596s                                                                                                                                                                                                                                               
user    0m0.015s                                                                                                                                                                                                                                               
sys     0m0.010s      

# Consecutive run with debug flag

user@ssh:~/gocommands$ time ./gocmd sync -d --no_bulk_reg  ../example_files/ i:
DEBU[2023-10-20 14:43:14.224] use sessionID - 2277008                       function=ProcessCommonFlags package=flag
DEBU[2023-10-20 14:43:14.224] reading config file/dir - /home/user/.irods  function=LoadConfigFromFile package=commons
DEBU[2023-10-20 14:43:14.226] reading icommands environment file - /home/user/.irods/irods_environment.json  function=LoadConfigFromFile package=commons
DEBU[2023-10-20 14:43:14.226] reading environment file /home/user/.irods/irods_environment.json  function=Load package=icommands struct=ICommandsEnvironmentManager
DEBU[2023-10-20 14:43:14.227] reading environment password file /home/user/.irods/.irodsA  function=Load package=icommands struct=ICommandsEnvironmentManager
DEBU[2023-10-20 14:43:14.228] run bput with args: [--diff -d --no_bulk_reg ../example_files/ i:]  function=syncFromLocalToIRODS package=main
DEBU[2023-10-20 14:43:14.228] use sessionID - 2277008                       function=ProcessCommonFlags package=flag
DEBU[2023-10-20 14:43:14.228] reading config file/dir - /home/user/.irods  function=LoadConfigFromFile package=commons
DEBU[2023-10-20 14:43:14.228] reading icommands environment file - /home/user/.irods/irods_environment.json  function=LoadConfigFromFile package=commons
DEBU[2023-10-20 14:43:14.228] reading environment file /home/user/.irods/irods_environment.json  function=Load package=icommands struct=ICommandsEnvironmentManager
DEBU[2023-10-20 14:43:14.228] reading environment password file /home/user/.irods/.irodsA  function=Load package=icommands struct=ICommandsEnvironmentManager
DEBU[2023-10-20 14:43:14.228] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.232] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.469] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.469] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.471] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.489] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.545] testing connection                            function=NewIRODSSession package=session
DEBU[2023-10-20 14:43:14.545] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:14.545] support parallel upload: true                 function=checkConnection package=session
DEBU[2023-10-20 14:43:14.545] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:14.545] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.548] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.790] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.790] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.791] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.805] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.859] testing connection                            function=NewIRODSSession package=session
DEBU[2023-10-20 14:43:14.859] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:14.859] support parallel upload: true                 function=checkConnection package=session
DEBU[2023-10-20 14:43:14.859] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:14.859] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:14.867] failed to commit transaction                  error=SYS_NO_API_PRIV function=endTransaction package=session struct=IRODSSession
DEBU[2023-10-20 14:43:14.872] Returning a connection                        function=Return package=session struct=ConnectionPool
INFO[2023-10-20 14:43:14.872] determining staging dir...                    function=processBputCommand package=main
DEBU[2023-10-20 14:43:14.872] get default staging dir                       function=processBputCommand package=main
INFO[2023-10-20 14:43:14.872] use staging dir - /testrug/home/rdms-testers@rug.nl/.gocmd_staging  function=processBputCommand package=main
DEBU[2023-10-20 14:43:14.872] start transfer thread 0                       function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.872] start transfer thread 4                       function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.872] start transfer thread 1                       function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.872] start bundle thread                           function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.872] start transfer thread 2                       function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.872] start transfer thread 3                       function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.873] start extract thread 1                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.873] start extract thread 2                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.872] start extract thread 0                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.872] start input thread                            function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.873] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:14.873] start stale file remove thread                function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.873] bundle-uploading a local directory /home/user/example_files  function=bputOne package=main
DEBU[2023-10-20 14:43:14.874] assigned a new bundle 0                       function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.874] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_1 for source /home/user/example_files/example_file_1 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:14.874] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:14.877] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:15.087] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:15.087] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:15.089] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:15.103] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:15.155] Created a new connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:15.160] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:15.160] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:15.167] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:15.167] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:15.190] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:15.190] adding a file /home/user/example_files/example_file_1 to the bundle as the file in iRODS doesn't have hash yet  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.190] > scheduled a local file bundle-upload /home/user/example_files/example_file_1  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.191] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_10 for source /home/user/example_files/example_file_10 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.191] adding a file /home/user/example_files/example_file_10 to the bundle as the file in iRODS doesn't have hash yet  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.191] > scheduled a local file bundle-upload /home/user/example_files/example_file_10  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.191] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_2 for source /home/user/example_files/example_file_2 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.191] adding a file /home/user/example_files/example_file_2 to the bundle as the file in iRODS doesn't have hash yet  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.191] > scheduled a local file bundle-upload /home/user/example_files/example_file_2  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.192] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_3 for source /home/user/example_files/example_file_3 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.192] adding a file /home/user/example_files/example_file_3 to the bundle as the file in iRODS doesn't have hash yet  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.192] > scheduled a local file bundle-upload /home/user/example_files/example_file_3  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.193] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_4 for source /home/user/example_files/example_file_4 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.193] adding a file /home/user/example_files/example_file_4 to the bundle as the file in iRODS doesn't have hash yet  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.193] > scheduled a local file bundle-upload /home/user/example_files/example_file_4  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.193] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_5 for source /home/user/example_files/example_file_5 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.193] adding a file /home/user/example_files/example_file_5 to the bundle as the file in iRODS doesn't have hash yet  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.193] > scheduled a local file bundle-upload /home/user/example_files/example_file_5  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.194] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_6 for source /home/user/example_files/example_file_6 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.194] adding a file /home/user/example_files/example_file_6 to the bundle as the file in iRODS doesn't have hash yet  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.194] > scheduled a local file bundle-upload /home/user/example_files/example_file_6  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.194] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_7 for source /home/user/example_files/example_file_7 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.194] adding a file /home/user/example_files/example_file_7 to the bundle as the file in iRODS doesn't have hash yet  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.194] > scheduled a local file bundle-upload /home/user/example_files/example_file_7  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.195] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_8 for source /home/user/example_files/example_file_8 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.195] adding a file /home/user/example_files/example_file_8 to the bundle as the file in iRODS doesn't have hash yet  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.195] > scheduled a local file bundle-upload /home/user/example_files/example_file_8  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.196] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_9 for source /home/user/example_files/example_file_9 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.196] adding a file /home/user/example_files/example_file_9 to the bundle as the file in iRODS doesn't have hash yet  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.196] > scheduled a local file bundle-upload /home/user/example_files/example_file_9  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.196] waiting schedule-wait                         function=Wait package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.196] waiting transfer-wait                         function=Wait package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.219] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:15.219] exit input thread                             function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.219] deleting exising data objects in the bundle 0  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.219] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_1  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.219] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:15.219] creating a tarball for bundle 0 to /tmp/bundle_ckp7bohp1364njarn9lg_0.tar  function=processBundleTar package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.357] created a tarball for bundle 0 to /tmp/bundle_ckp7bohp1364njarn9lg_0.tar  function=processBundleTar package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.357] exit bundle thread                            function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.357] exit transfer thread 4                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.357] exit transfer thread 2                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.357] exit transfer thread 3                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.357] exit transfer thread 1                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.357] uploading bundle 0 to /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7bohp1364njarn9lg_0.tar  function=processBundleUpload package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:15.357] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:15.360] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:15.580] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:15.581] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:15.582] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:15.599] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:15.653] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 14:43:15.653] upload data object in parallel - /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7bohp1364njarn9lg_0.tar, size(104875520), threads(4)  function=UploadDataObjectParallel package=fs
DEBU[2023-10-20 14:43:16.370] replicaToken 8168279d-ffbc-431d-9aa6-3ef3d61ad8a6, resourceHierarchy rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200  function=UploadDataObjectParallel package=fs
DEBU[2023-10-20 14:43:16.370] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.370] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.370] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.370] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.373] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.373] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.374] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.374] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.522] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.522] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_10  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:16.522] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.591] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.591] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.591] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.591] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.592] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.594] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.594] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_2  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:16.594] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.595] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.604] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.604] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.605] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.605] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.606] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.607] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.607] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.608] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.620] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.623] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:16.658] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 14:43:16.668] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.668] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_3  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:16.668] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.669] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 14:43:16.675] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 14:43:16.679] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 14:43:16.744] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.744] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_4  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:16.744] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.821] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.821] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_5  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:16.821] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.894] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.894] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_6  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:16.894] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.974] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:16.974] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_7  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:16.974] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:17.049] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:17.049] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_8  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:17.049] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:17.120] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:17.120] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_9  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:17.120] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:17.197] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:17.197] deleted exising data objects in the bundle 0  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:17.197] exit stale file remove thread                 function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:17.571] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:17.592] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:17.630] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:17.637] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:34.720] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:34.734] uploaded bundle 0 to /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7bohp1364njarn9lg_0.tar  function=processBundleUpload package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:34.734] exit transfer thread 0                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:34.734] exit extract thread 1                         function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:34.735] exit extract thread 0                         function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:34.735] extracting bundle 0 at /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7bohp1364njarn9lg_0.tar  function=processBundleExtract package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:34.735] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:34.738] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:34.962] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:34.962] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:34.964] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:34.983] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:35.038] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 14:43:42.161] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:42.161] removing bundle 0 at /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7bohp1364njarn9lg_0.tar  function=processBundleExtract package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:42.161] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:42.924] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:42.924] extracted bundle 0 at /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7bohp1364njarn9lg_0.tar to /testrug/home/rdms-testers@rug.nl  function=processBundleExtract package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:42.924] exit extract thread 2                         function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:42.924] clearing bundle files in /testrug/home/rdms-testers@rug.nl/.gocmd_staging  function=CleanUpBundles package=commons struct=BundleTransferManager
DEBU[2023-10-20 14:43:42.924] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:42.971] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 14:43:42.971] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:42.971] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 14:43:42.971] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection

real    0m28.771s
user    0m0.109s
sys 0m0.256s

From the debug log, it seems to me as if the command indeed does not find a hash and deletes the already existing files on the iRODS and uploads them again, even if they are identical.

Maybe that is also related to this strange behavior that we see in our system with gocmd sync, but also with ibun -x from the original icommands that for our two replicas, we just see a checksum for replica 1, but not replica 0?

Like that:

p308297@ssh:~/gocommands$ ./gocmd ls -L example_files/
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_1
        /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_1
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_1
    sha2:5E8zwy5RJ+lJ8zb9T8lfNowT89afL/XlvWdvv+Tbe4Y=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_1
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_10
        /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_10
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_10
    sha2:iH+J490hQJi4HNOqTkPx4VxKnzuRFveDJ+kEktcWapg=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_10
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_2
        /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_2
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_2
    sha2:TLzXjj+GiU4sqzo4Mkz8Xn5mHBihlh+Urn71IXSX08w=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_2
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_3
        /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_3
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_3
    sha2:Mh9Phk+7qL/coMFRUw53UYzwuoO7+1FljavRI2D8rgc=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_3
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_4
        /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_4
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_4
    sha2:6zHjhGn2qEWPVIXTKOQwMb/Y9En+SwwdYd4qMJi5qwM=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_4
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_5
        /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_5
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_5
    sha2:Aort/R4dchw7UD497mr3X5WD81iS+pow8wDJiu237d0=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_5
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_6
        /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_6
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_6
    sha2:s/NENifit4M2Yf+eUy8omxt6/C0qa+I87LL7uXzStWY=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_6
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_7
        /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_7
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_7
    sha2:en9+T0VkfzYU8AVh09ubK5OP5RnOxm+gT/dB2iLvctQ=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_7
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_8
        /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_8
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_8
    sha2:+vr3YfWiRng2bvrag0fxffsoK3qSlczRwFLkMwb7oTw=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_8
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_9
        /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_9
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_9
    sha2:nSv2sIR8eUIEmm/wvQD/ImvQ6s59cUGaAIzPUyk7JlU=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_9

trel commented 10 months ago

Replica 0's not having a checksum feels like the main issue here. If you run gocmd sync after you run ichksum or its equivalent and everything has a checksum... does gocmd sync behave better?

jnimoth commented 10 months ago

Hi Terrell, I just tried your suggestion, here my observations:

# Create all checksums
user@ssh:~/gocommands$ ichksum -ar /testrug/home/rdms-testers@rug.nl/example_files
C- /testrug/home/rdms-testers@rug.nl/example_files:
    example_file_1    sha2:5E8zwy5RJ+lJ8zb9T8lfNowT89afL/XlvWdvv+Tbe4Y=
    example_file_10    sha2:iH+J490hQJi4HNOqTkPx4VxKnzuRFveDJ+kEktcWapg=
    example_file_2    sha2:TLzXjj+GiU4sqzo4Mkz8Xn5mHBihlh+Urn71IXSX08w=
    example_file_3    sha2:Mh9Phk+7qL/coMFRUw53UYzwuoO7+1FljavRI2D8rgc=
    example_file_4    sha2:6zHjhGn2qEWPVIXTKOQwMb/Y9En+SwwdYd4qMJi5qwM=
    example_file_5    sha2:Aort/R4dchw7UD497mr3X5WD81iS+pow8wDJiu237d0=
    example_file_6    sha2:s/NENifit4M2Yf+eUy8omxt6/C0qa+I87LL7uXzStWY=
    example_file_7    sha2:en9+T0VkfzYU8AVh09ubK5OP5RnOxm+gT/dB2iLvctQ=
    example_file_8    sha2:+vr3YfWiRng2bvrag0fxffsoK3qSlczRwFLkMwb7oTw=
    example_file_9    sha2:nSv2sIR8eUIEmm/wvQD/ImvQ6s59cUGaAIzPUyk7JlU=

# Check that now indeed all replica have checksums assigned and registered

user@ssh:~/gocommands$ ./gocmd ls -L example_files
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_1
    sha2:5E8zwy5RJ+lJ8zb9T8lfNowT89afL/XlvWdvv+Tbe4Y=   /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_1
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_1
    sha2:5E8zwy5RJ+lJ8zb9T8lfNowT89afL/XlvWdvv+Tbe4Y=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_1
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_10
    sha2:iH+J490hQJi4HNOqTkPx4VxKnzuRFveDJ+kEktcWapg=   /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_10
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_10
    sha2:iH+J490hQJi4HNOqTkPx4VxKnzuRFveDJ+kEktcWapg=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_10
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_2
    sha2:TLzXjj+GiU4sqzo4Mkz8Xn5mHBihlh+Urn71IXSX08w=   /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_2
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_2
    sha2:TLzXjj+GiU4sqzo4Mkz8Xn5mHBihlh+Urn71IXSX08w=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_2
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_3
    sha2:Mh9Phk+7qL/coMFRUw53UYzwuoO7+1FljavRI2D8rgc=   /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_3
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_3
    sha2:Mh9Phk+7qL/coMFRUw53UYzwuoO7+1FljavRI2D8rgc=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_3
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_4
    sha2:6zHjhGn2qEWPVIXTKOQwMb/Y9En+SwwdYd4qMJi5qwM=   /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_4
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_4
    sha2:6zHjhGn2qEWPVIXTKOQwMb/Y9En+SwwdYd4qMJi5qwM=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_4
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_5
    sha2:Aort/R4dchw7UD497mr3X5WD81iS+pow8wDJiu237d0=   /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_5
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_5
    sha2:Aort/R4dchw7UD497mr3X5WD81iS+pow8wDJiu237d0=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_5
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_6
    sha2:s/NENifit4M2Yf+eUy8omxt6/C0qa+I87LL7uXzStWY=   /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_6
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_6
    sha2:s/NENifit4M2Yf+eUy8omxt6/C0qa+I87LL7uXzStWY=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_6
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_7
    sha2:en9+T0VkfzYU8AVh09ubK5OP5RnOxm+gT/dB2iLvctQ=   /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_7
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_7
    sha2:en9+T0VkfzYU8AVh09ubK5OP5RnOxm+gT/dB2iLvctQ=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_7
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_8
    sha2:+vr3YfWiRng2bvrag0fxffsoK3qSlczRwFLkMwb7oTw=   /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_8
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_8
    sha2:+vr3YfWiRng2bvrag0fxffsoK3qSlczRwFLkMwb7oTw=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_8
  rdms-testers@rug.nl   0   rootResc;rootRandy;ptC;replC;randy20;pt200;mnt_irodst200    10485760    2023-10-20.14:43    &   example_file_9
    sha2:nSv2sIR8eUIEmm/wvQD/ImvQ6s59cUGaAIzPUyk7JlU=   /mnt/irodst200/home/rdms-testers@rug.nl/example_files/example_file_9
  rdms-testers@rug.nl   1   rootResc;rootRandy;ptC;replC;randy11;pt101;mnt_irodst101    10485760    2023-10-20.14:43    &   example_file_9
    sha2:nSv2sIR8eUIEmm/wvQD/ImvQ6s59cUGaAIzPUyk7JlU=   /mnt/irodst101/home/rdms-testers@rug.nl/example_files/example_file_9

# Now run the sync with gocommands again

user@ssh:~/gocommands$ time ./gocmd sync -d --no_bulk_reg  ../example_files/ i:
DEBU[2023-10-20 15:17:20.984] use sessionID - 2277008                       function=ProcessCommonFlags package=flag
DEBU[2023-10-20 15:17:20.984] reading config file/dir - /home/user/.irods  function=LoadConfigFromFile package=commons
DEBU[2023-10-20 15:17:20.986] reading icommands environment file - /home/user/.irods/irods_environment.json  function=LoadConfigFromFile package=commons
DEBU[2023-10-20 15:17:20.986] reading environment file /home/user/.irods/irods_environment.json  function=Load package=icommands struct=ICommandsEnvironmentManager
DEBU[2023-10-20 15:17:20.987] reading environment password file /home/user/.irods/.irodsA  function=Load package=icommands struct=ICommandsEnvironmentManager
DEBU[2023-10-20 15:17:20.989] run bput with args: [--diff -d --no_bulk_reg ../example_files/ i:]  function=syncFromLocalToIRODS package=main
DEBU[2023-10-20 15:17:20.989] use sessionID - 2277008                       function=ProcessCommonFlags package=flag
DEBU[2023-10-20 15:17:20.989] reading config file/dir - /home/user/.irods  function=LoadConfigFromFile package=commons
DEBU[2023-10-20 15:17:20.989] reading icommands environment file - /home/user/.irods/irods_environment.json  function=LoadConfigFromFile package=commons
DEBU[2023-10-20 15:17:20.989] reading environment file /home/user/.irods/irods_environment.json  function=Load package=icommands struct=ICommandsEnvironmentManager
DEBU[2023-10-20 15:17:20.989] reading environment password file /home/user/.irods/.irodsA  function=Load package=icommands struct=ICommandsEnvironmentManager
DEBU[2023-10-20 15:17:20.989] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:20.992] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.212] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.212] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.214] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.228] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.279] testing connection                            function=NewIRODSSession package=session
DEBU[2023-10-20 15:17:21.280] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.280] support parallel upload: true                 function=checkConnection package=session
DEBU[2023-10-20 15:17:21.280] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.280] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.284] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.493] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.493] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.495] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.508] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.562] testing connection                            function=NewIRODSSession package=session
DEBU[2023-10-20 15:17:21.562] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.562] support parallel upload: true                 function=checkConnection package=session
DEBU[2023-10-20 15:17:21.562] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.562] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.570] failed to commit transaction                  error=SYS_NO_API_PRIV function=endTransaction package=session struct=IRODSSession
DEBU[2023-10-20 15:17:21.575] Returning a connection                        function=Return package=session struct=ConnectionPool
INFO[2023-10-20 15:17:21.575] determining staging dir...                    function=processBputCommand package=main
DEBU[2023-10-20 15:17:21.575] get default staging dir                       function=processBputCommand package=main
INFO[2023-10-20 15:17:21.575] use staging dir - /testrug/home/rdms-testers@rug.nl/.gocmd_staging  function=processBputCommand package=main
DEBU[2023-10-20 15:17:21.575] start transfer thread 2                       function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.575] start transfer thread 0                       function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.575] start extract thread 1                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.575] start stale file remove thread                function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.575] start extract thread 2                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.575] start extract thread 0                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.575] start input thread                            function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.576] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.575] start transfer thread 3                       function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.575] start transfer thread 4                       function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.575] start bundle thread                           function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.575] start transfer thread 1                       function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.576] bundle-uploading a local directory /home/user/example_files  function=bputOne package=main
DEBU[2023-10-20 15:17:21.578] assigned a new bundle 0                       function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.578] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_1 for source /home/user/example_files/example_file_1 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.578] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.581] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.791] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.791] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.793] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.807] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:21.859] Created a new connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.864] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.864] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.871] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.871] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.898] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.926] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:21.930] adding a file /home/user/example_files/example_file_1 to the bundle as it has different hash, 5E8zwy5RJ+lJ8zb9T8lfNowT89afL/XlvWdvv+Tbe4Y= vs e44f33c32e5127e949f336fd4fc95f368c13f3d69f2ff5e5bd676fbfe4db7b86 (alg SHA-256)  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.930] > scheduled a local file bundle-upload /home/user/example_files/example_file_1  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.931] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_10 for source /home/user/example_files/example_file_10 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.961] adding a file /home/user/example_files/example_file_10 to the bundle as it has different hash, iH+J490hQJi4HNOqTkPx4VxKnzuRFveDJ+kEktcWapg= vs 887f89e3dd214098b81cd3aa4e43f1e15c4a9f3b9116f78327e90492d7166a98 (alg SHA-256)  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.961] > scheduled a local file bundle-upload /home/user/example_files/example_file_10  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.962] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_2 for source /home/user/example_files/example_file_2 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.992] adding a file /home/user/example_files/example_file_2 to the bundle as it has different hash, TLzXjj+GiU4sqzo4Mkz8Xn5mHBihlh+Urn71IXSX08w= vs 4cbcd78e3f86894e2cab3a38324cfc5e7e661c18a1961f94ae7ef5217497d3cc (alg SHA-256)  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.992] > scheduled a local file bundle-upload /home/user/example_files/example_file_2  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:21.993] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_3 for source /home/user/example_files/example_file_3 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.023] adding a file /home/user/example_files/example_file_3 to the bundle as it has different hash, Mh9Phk+7qL/coMFRUw53UYzwuoO7+1FljavRI2D8rgc= vs 321f4f864fbba8bfdca0c151530e77518cf0ba83bbfb51658dabd12360fcae07 (alg SHA-256)  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.023] > scheduled a local file bundle-upload /home/user/example_files/example_file_3  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.024] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_4 for source /home/user/example_files/example_file_4 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.054] adding a file /home/user/example_files/example_file_4 to the bundle as it has different hash, 6zHjhGn2qEWPVIXTKOQwMb/Y9En+SwwdYd4qMJi5qwM= vs eb31e38469f6a8458f5485d328e43031bfd8f449fe4b0c1d61de2a3098b9ab03 (alg SHA-256)  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.054] > scheduled a local file bundle-upload /home/user/example_files/example_file_4  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.055] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_5 for source /home/user/example_files/example_file_5 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.085] adding a file /home/user/example_files/example_file_5 to the bundle as it has different hash, Aort/R4dchw7UD497mr3X5WD81iS+pow8wDJiu237d0= vs 028aedfd1e1d721c3b503e3dee6af75f9583f35892fa9a30f300c98aedb7eddd (alg SHA-256)  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.085] > scheduled a local file bundle-upload /home/user/example_files/example_file_5  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.086] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_6 for source /home/user/example_files/example_file_6 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.116] adding a file /home/user/example_files/example_file_6 to the bundle as it has different hash, s/NENifit4M2Yf+eUy8omxt6/C0qa+I87LL7uXzStWY= vs b3f3443627e2b7833661ff9e532f289b1b7afc2d2a6be23cecb2fbb97cd2b566 (alg SHA-256)  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.117] > scheduled a local file bundle-upload /home/user/example_files/example_file_6  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.117] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_7 for source /home/user/example_files/example_file_7 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.148] adding a file /home/user/example_files/example_file_7 to the bundle as it has different hash, en9+T0VkfzYU8AVh09ubK5OP5RnOxm+gT/dB2iLvctQ= vs 7a7f7e4f45647f3614f00561d3db9b2b938fe519cec66fa04ff741da22ef72d4 (alg SHA-256)  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.148] > scheduled a local file bundle-upload /home/user/example_files/example_file_7  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.148] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_8 for source /home/user/example_files/example_file_8 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.179] adding a file /home/user/example_files/example_file_8 to the bundle as it has different hash, +vr3YfWiRng2bvrag0fxffsoK3qSlczRwFLkMwb7oTw= vs fafaf761f5a24678366efada8347f17dfb282b7a9295ccd1c052e43306fba13c (alg SHA-256)  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.179] > scheduled a local file bundle-upload /home/user/example_files/example_file_8  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.179] checking if target file /testrug/home/rdms-testers@rug.nl/example_files/example_file_9 for source /home/user/example_files/example_file_9 exists  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.209] adding a file /home/user/example_files/example_file_9 to the bundle as it has different hash, nSv2sIR8eUIEmm/wvQD/ImvQ6s59cUGaAIzPUyk7JlU= vs 9d2bf6b0847c7942049a6ff0bd00ff226bd0eace7d71419a008ccf53293b2655 (alg SHA-256)  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.209] > scheduled a local file bundle-upload /home/user/example_files/example_file_9  function=Schedule package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.209] waiting schedule-wait                         function=Wait package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.209] waiting transfer-wait                         function=Wait package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.209] exit input thread                             function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.210] deleting exising data objects in the bundle 0  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.210] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_1  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.210] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:22.210] creating a tarball for bundle 0 to /tmp/bundle_ckp7ro9p1369ajsfhha0_0.tar  function=processBundleTar package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.329] created a tarball for bundle 0 to /tmp/bundle_ckp7ro9p1369ajsfhha0_0.tar  function=processBundleTar package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.330] exit bundle thread                            function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.330] exit transfer thread 0                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.330] exit transfer thread 3                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.330] exit transfer thread 4                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.330] exit transfer thread 1                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.330] uploading bundle 0 to /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7ro9p1369ajsfhha0_0.tar  function=processBundleUpload package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:22.330] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:22.333] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:22.543] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:22.543] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:22.545] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:22.558] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:22.611] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 15:17:22.611] upload data object in parallel - /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7ro9p1369ajsfhha0_0.tar, size(104875520), threads(4)  function=UploadDataObjectParallel package=fs
DEBU[2023-10-20 15:17:23.214] replicaToken 9ababb57-ef0e-4e33-b6ee-db54a1bab7d5, resourceHierarchy rootResc;rootRandy;ptB;replB;randy00;pt000;mnt_irodst000  function=UploadDataObjectParallel package=fs
DEBU[2023-10-20 15:17:23.214] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.214] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.214] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.214] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.218] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.218] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.218] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.218] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.428] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.428] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.430] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.430] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.430] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.432] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.442] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.442] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.443] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.443] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.448] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.457] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.457] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.457] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.459] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.472] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:23.501] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 15:17:23.511] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 15:17:23.511] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 15:17:23.524] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 15:17:23.637] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:23.637] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_10  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:23.637] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:23.708] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:23.708] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_2  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:23.708] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:23.779] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:23.779] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_3  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:23.779] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:23.850] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:23.850] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_4  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:23.850] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:23.926] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:23.926] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_5  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:23.926] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:24.000] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:24.000] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_6  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:24.000] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:24.072] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:24.072] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_7  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:24.072] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:24.143] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:24.144] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_8  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:24.144] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:24.218] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:24.218] deleting exising data object /testrug/home/rdms-testers@rug.nl/example_files/example_file_9  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:24.218] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:24.302] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:24.302] deleted exising data objects in the bundle 0  function=processBundleRemoveFiles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:24.302] exit stale file remove thread                 function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:24.362] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:24.434] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:24.442] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:24.523] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:27.457] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:27.471] uploaded bundle 0 to /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7ro9p1369ajsfhha0_0.tar  function=processBundleUpload package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:27.471] exit transfer thread 2                        function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:27.471] exit extract thread 0                         function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:27.471] extracting bundle 0 at /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7ro9p1369ajsfhha0_0.tar  function=processBundleExtract package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:27.471] exit extract thread 2                         function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:27.471] Connecting to rdms-test-icat.data.rug.nl:1247  function=Connect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:27.475] Start up a connection with CS Negotiation     function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:27.688] Start up CS Negotiation                       function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:27.688] Client policy - CS_NEG_REQUIRE, server policy - CS_NEG_DONT_CARE  function=connectWithCSNegotiation package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:27.690] Start up SSL                                  function=sslStartup package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:27.703] Logging in using native authentication method  function=loginNative package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:27.758] Created a new unmanaged connection            function=AcquireUnmanagedConnection package=session struct=IRODSSession
DEBU[2023-10-20 15:17:35.293] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:35.293] removing bundle 0 at /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7ro9p1369ajsfhha0_0.tar  function=processBundleExtract package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:35.293] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:35.921] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:35.921] extracted bundle 0 at /testrug/home/rdms-testers@rug.nl/.gocmd_staging/bundle_ckp7ro9p1369ajsfhha0_0.tar to /testrug/home/rdms-testers@rug.nl  function=processBundleExtract package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:35.921] exit extract thread 1                         function=Start package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:35.921] clearing bundle files in /testrug/home/rdms-testers@rug.nl/.gocmd_staging  function=CleanUpBundles package=commons struct=BundleTransferManager
DEBU[2023-10-20 15:17:35.921] Reuse an idle connection                      function=Get package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:35.970] Returning a connection                        function=Return package=session struct=ConnectionPool
DEBU[2023-10-20 15:17:35.970] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:35.970] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection
DEBU[2023-10-20 15:17:35.970] Disconnecting the connection                  function=Disconnect package=connection struct=IRODSConnection

real    0m15.047s
user    0m0.406s
sys 0m0.233s

So indeed, the logs changed slightly, but the files where still overwritten as it seems.

This parts in the log caught my attention:

DEBU[2023-10-20 15:17:21.961] adding a file /home/user/example_files/example_file_10 to the bundle as it has different hash, iH+J490hQJi4HNOqTkPx4VxKnzuRFveDJ+kEktcWapg= vs 887f89e3dd214098b81cd3aa4e43f1e15c4a9f3b9116f78327e90492d7166a98 (alg SHA-256)  function=Schedule package=commons struct=BundleTransferManager

It talks about the hashes being different, but I think they are in fact the same, just not with the encoding done in iRODS or?

If I run:

user@ssh:~/gocommands$ echo 321f4f864fbba8bfdca0c151530e77518cf0ba83bbfb51658dabd12360fcae07 | xxd -r -p | base64
Mh9Phk+7qL/coMFRUw53UYzwuoO7+1FljavRI2D8rgc=

So the same checksum, but I am not an expert. :)

Moreover, I also see now in iRODS that the situation is back to the status prior to the sync: No checksums for replicas 0.

@iychoi I see by the way something similar for gocmd put --diff:

For me it does not seem to detect already existing files (which I understand the --diff flag should do).
This is independent of me using --no_hash or not using it.
Also in case of gocmd put --diff all files do have checksums registered, the issue with replica 0 having no checksums was just observered for the jobs that involve some kind of unbundling (gocmd sync, gocmd bput, ibun -x,...).

Should I open a separate issue for that after I made some more trials?

iychoi commented 10 months ago

Thanks for the report. Gocommands thinks hashes are not matching due to base64 encoding. This is a bug. I'll fix it soon.

iychoi commented 10 months ago

The fix for the hash mismatch is included in the new release v0.7.12. Please check it out and let me know if it solves the problem.

https://github.com/cyverse/gocommands/releases/tag/v0.7.12

jnimoth commented 10 months ago

The new version v.0.7.12 seems to fix this issue.

It now detects the files are present by using the checksum. I still have to be certain that all replicas have a checksum registered, but then it works:

# Initital sync
$ ./gocmd sync --no_bulk_reg ../example_files/ i:

# Consecutive sync without checking checksums for all replica gives:
$ ./gocmd sync --no_bulk_reg ../example_files/ i:
skip adding a dir /home/user/example_files to the bundle. The dir already exists!

# First being sure that all checksums are present results in the correct behavior

$ ichksum -ra example_files/
C- /testrug/home/rdms-testers@rug.nl/example_files:
    example_file_1    sha2:5E8zwy5RJ+lJ8zb9T8lfNowT89afL/XlvWdvv+Tbe4Y=
    example_file_10    sha2:iH+J490hQJi4HNOqTkPx4VxKnzuRFveDJ+kEktcWapg=
    example_file_2    sha2:TLzXjj+GiU4sqzo4Mkz8Xn5mHBihlh+Urn71IXSX08w=
    example_file_3    sha2:Mh9Phk+7qL/coMFRUw53UYzwuoO7+1FljavRI2D8rgc=
    example_file_4    sha2:6zHjhGn2qEWPVIXTKOQwMb/Y9En+SwwdYd4qMJi5qwM=
    example_file_5    sha2:Aort/R4dchw7UD497mr3X5WD81iS+pow8wDJiu237d0=
    example_file_6    sha2:s/NENifit4M2Yf+eUy8omxt6/C0qa+I87LL7uXzStWY=
    example_file_7    sha2:en9+T0VkfzYU8AVh09ubK5OP5RnOxm+gT/dB2iLvctQ=
    example_file_8    sha2:+vr3YfWiRng2bvrag0fxffsoK3qSlczRwFLkMwb7oTw=
    example_file_9    sha2:nSv2sIR8eUIEmm/wvQD/ImvQ6s59cUGaAIzPUyk7JlU=

$ ./gocmd sync --no_bulk_reg ../example_files/ i:
skip adding a dir /home/user/example_files to the bundle. The dir already exists!
skip adding a file /home/user/example_files/example_file_1 to the bundle. The file with the same hash already exists!
skip adding a file /home/user/example_files/example_file_10 to the bundle. The file with the same hash already exists!
skip adding a file /home/user/example_files/example_file_2 to the bundle. The file with the same hash already exists!
skip adding a file /home/user/example_files/example_file_3 to the bundle. The file with the same hash already exists!
skip adding a file /home/user/example_files/example_file_4 to the bundle. The file with the same hash already exists!
skip adding a file /home/user/example_files/example_file_5 to the bundle. The file with the same hash already exists!
skip adding a file /home/user/example_files/example_file_6 to the bundle. The file with the same hash already exists!
skip adding a file /home/user/example_files/example_file_7 to the bundle. The file with the same hash already exists!
skip adding a file /home/user/example_files/example_file_8 to the bundle. The file with the same hash already exists!
skip adding a file /home/user/example_files/example_file_9 to the bundle. The file with the same hash already exists!

cyverse / gocommands

How does the sync command works #16