"Calculated and written ECMA-119 tree end differ" under very specific circumstances

[Valtteri Vuorikoski]

Hi, I'm hitting a "Calculated and written ECMA-119 tree end differ"
warning which leads to an "ISO overwrite" error later on under what
seems to be very specific circumstances.

The command to trigger the error with xorriso 1.5.2 as distributed with
Ubuntu 20.04 on amd64 (foo3.iso is not present on startup):

xorriso -report_about ALL -dev foo3.iso -hardlinks on -xattr any -md5 on 
-update_r afs/MOVIE /a -find / -type f -pending_data -exec set_filter --zisofs 
-- -commit

The requirements to trigger the error are:

  * A specific directory containing 101 MPEG-1 files with all-numbers
    names, mounted over NFS. Copying the same directory to a local
    filesystem no longer triggers the error but making a copy on the remote
    filesystem to another location does. The error is fully reproducible
    and the numbers "72 <> 73" in the initial warning are always the same.

  * "-hardlinks on -xattr any -md5 on" (or -for_backup, but "-acl on"
    can be removed and the error is still triggered) and "set_filter --zisofs" 
must be
    enabled. Either disabling zisofs or removing any of
    hardlinks/xattr/md5 makes the operation succeed.

  * Adding any other options doesn't seem to affect the result: the
    error is still triggered as long as the directory called "MOVIE" is
    present. Either -update or -update_r will trigger the
    error. Changing the iso_rr_path has no effect.

  * As far as I can tell, the directory contains neither hardlinks, xattrs
    nor ACLs.

Any ideas how I could debug this further? Full log is attached below and
I can provide the produced .iso file if needed.

  -Valtteri
  

xorriso 1.5.2 : RockRidge filesystem manipulator, libburnia project.

xorriso : DEBUG : burn_set_signal_handling(256)
xorriso : DEBUG : libjte-2.0.0 ok, libisofs-1.5.2 ok, libburn-1.5.2 ok, for 
libisoburn-1.5.2
xorriso : DEBUG : Using internal GNU/Linux SG_IO adapter sg-linux
xorriso : DEBUG : Command:    -report_about
xorriso : DEBUG : Parameter:     ALL
xorriso : DEBUG : Command:    -dev
xorriso : DEBUG : Parameter:     foo3.iso
libburn : DEBUG : burn_drive_convert_fs_adr( foo3.iso )
libburn : DEBUG : lstat( foo3.iso ) returns -1
libburn : DEBUG : burn_drive_convert_fs_adr( foo3.iso )
libburn : DEBUG : lstat( foo3.iso ) returns -1
libburn : DEBUG : burn_drive_convert_fs_adr( stdio:foo3.iso )
libburn : DEBUG : Read start address 0s larger than number of readable blocks 0
libburn : DEBUG : burn_drive_convert_fs_adr( foo3.iso )
libburn : DEBUG : lstat( foo3.iso ) returns -1
libburn : DEBUG : burn_drive_convert_fs_adr( foo3.iso )
libburn : DEBUG : lstat( foo3.iso ) returns -1
Drive current: -dev 'foo3.iso'
Media current: stdio file, overwriteable
Media status : is blank
Media summary: 0 sessions, 0 data blocks, 0 data, 67.1g free
xorriso : DEBUG : Command:    -hardlinks
xorriso : DEBUG : Parameter:     on
xorriso : DEBUG : Command:    -xattr
xorriso : DEBUG : Parameter:     any
xorriso : DEBUG : Command:    -md5
xorriso : DEBUG : Parameter:     on
xorriso : DEBUG : Command:    -update
xorriso : DEBUG : Parameter:     afs/MOVIE
xorriso : DEBUG : Parameter:     /a
Updating '/home/vuori/afs/MOVIE' to '/a'
xorriso : UPDATE : Added/overwrote '/a'  (124m)
Differences detected and updated. (runtime 0.0 s)
xorriso : DEBUG : Command:    -find
xorriso : DEBUG : Parameter:     /
xorriso : DEBUG : Parameter:     -type
xorriso : DEBUG : Parameter:     f
xorriso : DEBUG : Parameter:     -pending_data
xorriso : DEBUG : Parameter:     -exec
xorriso : DEBUG : Parameter:     set_filter
xorriso : DEBUG : Parameter:     --zisofs
xorriso : UPDATE :      49 file filters processed in 1 seconds
xorriso : UPDATE :      76 file filters processed in 2 seconds
xorriso : UPDATE :     101 file filters processed in 3 seconds
xorriso : DEBUG : Command:    -commit
libisofs: DEBUG : Creating low level ECMA-119 tree...
libisofs: DEBUG : Matching hardlinks...
libisofs: DEBUG : Sorting the low level tree...
libisofs: DEBUG : Mangling names...
libisofs: DEBUG : Computing position of dir structure
libisofs: DEBUG : Computing length of pathlist
libisofs: DEBUG : Write volume descriptors
libisofs: DEBUG : Write Primary Volume Descriptor
xorriso : DEBUG : burn_set_signal_handling(304)
libisoburn: DEBUG : Write_type = TAO

xorriso : UPDATE : Writing:       1467s    2.4%   fifo   0%  buf  50%
libisofs: DEBUG : Starting image writing...
libisofs: DEBUG : Write volume descriptors
libisofs: DEBUG : Write Primary Volume Descriptor
libisofs: DEBUG : Writing ISO Path tables
libisofs: WARNING : Calculated and written ECMA-119 tree end differ: 72 <> 73
libisofs: DEBUG : Writing Files...
libburn : DEBUG : Allocating buffer via mmap()
libisofs: DEBUG : Processed 5986 of 119706 KB (5 %)
libisofs: DEBUG : Processed 11972 of 119706 KB (10 %)
libisofs: DEBUG : Processed 17956 of 119706 KB (15 %)
xorriso : UPDATE : Writing:      12872s   21.4%   fifo   0%  buf  50%   24.1xD 
libisofs: DEBUG : Processed 23942 of 119706 KB (20 %)
libisofs: DEBUG : Processed 29928 of 119706 KB (25 %)
libisofs: DEBUG : Processed 35912 of 119706 KB (30 %)
libisofs: DEBUG : Processed 41898 of 119706 KB (35 %)
libisofs: DEBUG : Processed 47884 of 119706 KB (40 %)
libisofs: DEBUG : Processed 53868 of 119706 KB (45 %)
xorriso : UPDATE : Writing:      31310s   52.2%   fifo   0%  buf  50%   27.2xD 
libisofs: DEBUG : Processed 59854 of 119706 KB (50 %)
libisofs: DEBUG : Processed 65840 of 119706 KB (55 %)
libisofs: DEBUG : Processed 71824 of 119706 KB (60 %)
libisofs: DEBUG : Processed 77810 of 119706 KB (65 %)
libisofs: DEBUG : Processed 83796 of 119706 KB (70 %)
libisofs: DEBUG : Processed 89780 of 119706 KB (75 %)
libisofs: DEBUG : Processed 95766 of 119706 KB (80 %)
xorriso : UPDATE : Writing:      49795s   82.9%   fifo   0%  buf  50%   27.3xD 
libisofs: DEBUG : Processed 101752 of 119706 KB (85 %)
libisofs: DEBUG : Processed 107736 of 119706 KB (90 %)
libisofs: DEBUG : Processed 113722 of 119706 KB (95 %)
libisofs: DEBUG : Writing Checksums...
libisofs: DEBUG : Processed 119706 of 119706 KB (100 %)
libisofs: FATAL : ISO overwrite
libisofs: FAILURE : Image write error
libisofs: NOTE :  > Caused by: Internal programming error. Please report this 
bug
libburn : DEBUG : syncing cache (stdio fsync)
libburn : DEBUG : Write thread on drive 0 ended
xorriso : FATAL : -abort_on 'FAILURE' encountered 'FATAL' during image writing
xorriso : NOTE : libburn has now been urged to cancel its operation
libburn : DEBUG : burn_drive_cancel() was called
xorriso : DEBUG : burn_set_signal_handling(256)
libisofs: DEBUG : Writer thread joined
xorriso : FAILURE : libburn indicates failure with writing.
libisofs: DEBUG : Ring buffer was 0 times full and 50625 times empty
xorriso : aborting : -abort_on 'FAILURE' encountered 'FATAL'

signature.asc
Description: PGP signature