Hey, I'm hitting a very similar problem compared to the last report on this mailing list. I'm using rsync to upload large files onto a S3QL filesystem using B2 backend, no compression and no encryption. In the middle of upload, S3QL terminates with no conclusive error messages in the log. The problem is reproducible every time, on the same very large (>500GB) file.
After the crash, rsync either happily continues to copy the file into nothing, or terminates with "Transport endpoint not connected". This happens randomly and I could not work out the logic that influences each outcome. Versions I use are: -- 8< -- $ pacman -Qi s3ql-git | grep Version Version : 3.5.1.15.g81868632-1 $ pacman -Qi python-pyfuse3 | grep Version Version : 3.1.1-1 $ pacman -Qi python-trio | grep Version Version : 0.17.0-3 $ pacman -Qi python3 | grep Version Version : 3.9.1-1 -- 8< -- Full mount.s3ql invocation is: -- 8< -- /usr/bin/mount.s3ql b2://<mybucket> /mnt/b2/files -o systemd,log=none,authfile=/etc/s3ql/authinfo2,cachedir=/var/tmp/s3ql,debug,allow-other,compress=none,cachesize=10485760,threads=8,keep-cache,backend-options=disable-versions -- 8< -- Full s3ql log (captured stdout/stderr) is available here: https://intelfx.name/files/persistent/2020-12-27%20s3ql/s3ql.2.log.zst https://intelfx.name/files/persistent/2020-12-27%20s3ql/s3ql.3.log.zst (caution -- each log is ~150 MB unpacked, which is a separate concern of mine but irrelevant to this problem.) Manual excerpt from s3ql log relevant to the block that failed: -- 8< -- mount.s3ql[117923]: 2020-12-27 13:02:03.135 117923 DEBUG MainThread s3ql.block_cache.upload_if_dirty: started with <Dirty CacheEntry, inode=11545, blockno=109> mount.s3ql[117923]: 2020-12-27 13:02:03.135 117923 DEBUG MainThread s3ql.block_cache.upload_if_dirty: uploading <Dirty CacheEntry, inode=11545, blockno=109>.. mount.s3ql[117923]: 2020-12-27 13:02:03.980 117923 DEBUG MainThread s3ql.block_cache.upload_if_dirty: created new object 8516 mount.s3ql[117923]: 2020-12-27 13:02:03.980 117923 DEBUG MainThread s3ql.block_cache.upload_if_dirty: created new block 7638 mount.s3ql[117923]: 2020-12-27 13:02:03.980 117923 DEBUG MainThread s3ql.block_cache.upload_if_dirty: adding to upload queue mount.s3ql[117923]: 2020-12-27 13:02:03.981 117923 DEBUG MainThread s3ql.block_cache.upload_if_dirty: no old block mount.s3ql[117923]: 2020-12-27 13:02:03.981 117923 DEBUG Thread-5 s3ql.block_cache._upload_loop: got work mount.s3ql[117923]: 2020-12-27 13:02:03.981 117923 DEBUG Thread-5 s3ql.backends.b2.b2_backend.open_write: started with s3ql_data_8516 mount.s3ql[117923]: 2020-12-27 13:02:03.981 117923 DEBUG Thread-5 s3ql.backends.b2.object_w.close: started with s3ql_data_8516 mount.s3ql[117923]: 2020-12-27 13:02:03.981 117923 DEBUG Thread-5 s3ql.backends.b2.b2_backend._do_request: started with POST /b2api/v2/b2_get_upload_url mount.s3ql[117923]: 2020-12-27 13:02:03.982 117923 DEBUG Thread-5 s3ql.backends.b2.b2_backend._do_request: REQUEST: api003.backblazeb2.com POST /b2api/v2/b2_get_upload_url mount.s3ql[117923]: 2020-12-27 13:02:03.982 117923 DEBUG Thread-5 s3ql.backends.common.wrapped: Average retry rate: 0.05 Hz mount.s3ql[117923]: 2020-12-27 13:02:03.982 117923 DEBUG Thread-5 s3ql.backends.common.wrapped: Encountered ConnectionClosed (server closed connection), retrying B2Backend._request_upload_url_info (attempt 1)... mount.s3ql[117923]: 2020-12-27 13:02:04.009 117923 DEBUG Thread-5 s3ql.backends.b2.b2_backend._do_request: started with POST /b2api/v2/b2_get_upload_url mount.s3ql[117923]: 2020-12-27 13:02:04.009 117923 DEBUG Thread-5 s3ql.backends.b2.b2_backend._do_request: REQUEST: api003.backblazeb2.com POST /b2api/v2/b2_get_upload_url mount.s3ql[117923]: 2020-12-27 13:02:04.205 117923 DEBUG Thread-5 s3ql.backends.b2.b2_backend._do_request: RESPONSE: POST 200 275 mount.s3ql[117923]: 2020-12-27 13:02:04.205 117923 DEBUG Thread-5 s3ql.backends.b2.b2_backend._do_request: started with POST /b2api/v2/b2_upload_file/e77141e88db425f876370514/c003_v0312000_t0001 mount.s3ql[117923]: 2020-12-27 13:02:04.206 117923 DEBUG Thread-5 s3ql.backends.b2.b2_backend._do_request: REQUEST: pod-031-2000-09.backblaze.com POST /b2api/v2/b2_upload_file/e77141e88db425f876370514/c003_v0312000_t0001 mount.s3ql[117923]: 2020-12-27 13:02:04.411 117923 DEBUG MainThread s3ql.block_cache.with_event_loop: upload of 8516 failed mount.s3ql[117923]: NoneType: None mount.s3ql[117923]: 2020-12-27 13:02:04.416 117923 DEBUG Thread-5 s3ql.mount.exchook: recording exception No pending requests umount[135718]: umount: /mnt/b2/files: target is busy. -- 8< -- Strangely, systemd tells me that mount.s3ql does not just exit normally, but is terminated by SIGTERM: -- 8< -- $ systemctl status [email protected] ● [email protected] - s3ql file system at /mnt/b2/files Loaded: loaded (/etc/systemd/system/[email protected]; enabled; vendor preset: disabled) Active: inactive (dead) since Sun 2020-12-27 13:02:05 MSK; 1h 27min ago Process: 117923 ExecStart=/usr/bin/mount.s3ql ${What} /mnt/b2/files -o systemd,log=none,authfile=/etc/s3ql/authinfo2,cachedir=/var/tmp/s3ql,${Options} (code=killed, signal=TERM) Process: 135718 ExecStop=/usr/bin/umount /mnt/b2/files (code=exited, status=32) Main PID: 117923 (code=killed, signal=TERM) IP: 40.5M in, 8.5G out CPU: 6min 11.868s -- 8< -- I'd gladly go debug it myself, but I don't know where to start with this async stuff. Any pointers? How do I read this log? What is this strange "NoneType: None"? Thanks, -- Ivan Shapovalov / intelfx / -- You received this message because you are subscribed to the Google Groups "s3ql" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. To view this discussion on the web visit https://groups.google.com/d/msgid/s3ql/830a5e0c7e809ed6573f8937a461a7d21195ea8a.camel%40intelfx.name.
signature.asc
Description: This is a digitally signed message part
