crash report: fsck.s3ql, 5.4 plus metadata patch on debian trixie

[Joseph Maher]

I think this is a different one from the earlier one? Apologies if not...

$ SQLITE_TMPDIR=/mnt/backup/tmp/ fsck.s3ql --fast --log
/mnt/backup/root/.s3ql/fsck.log
--authfile=/mnt/backup/root/.s3ql/authinfo2
--cachedir=/mnt/backup/cache/gs/ gs://backup-echo-maher-org-uk/


2025-09-19 07:25:16.002 2269477:MainThread
s3ql.backends.gs._get_access_token: Requesting new access token
2025-09-19 07:25:16.896 2269477:MainThread s3ql.fsck.main: Starting fast
fsck of gs://backup-echo-maher-org-uk/
2025-09-19 07:25:17.046 2269477:MainThread s3ql.fsck.main: Using cached
metadata.
2025-09-19 07:25:17.062 2269477:MainThread s3ql.database.sqlite3_log:
sqlite3: recovered 7704 frames from WAL file
/mnt/backup/cache/gs/gs:=2F=2Fbackup-echo-maher-org-uk=2F.db-wal
(SQLITE_NOTICE_RECOVER_WAL)
2025-09-19 07:25:17.063 2269477:MainThread s3ql.fsck.main: File system was
not unmounted cleanly
2025-09-19 07:25:17.063 2269477:MainThread s3ql.fsck.main: Checking DB
integrity...
2025-09-19 09:34:53.592 2269477:MainThread
s3ql.backends.gs._get_access_token: Requesting new access token
2025-09-19 09:34:54.074 2269477:MainThread s3ql.fsck.check: Creating
temporary extra indices...
2025-09-19 10:31:05.734 2269477:MainThread s3ql.fsck.check_lof: Checking
lost+found...
2025-09-19 10:31:05.737 2269477:MainThread s3ql.fsck.check_cache: Checking
for dirty cache objects...
2025-09-19 10:31:05.737 2269477:MainThread s3ql.fsck.check_names_refcount:
Checking names (refcounts)...
2025-09-19 10:32:58.618 2269477:MainThread s3ql.fsck.check_contents_name:
Checking contents (names)...
2025-09-19 10:39:10.216 2269477:MainThread s3ql.fsck.check_contents_inode:
Checking contents (inodes)...
2025-09-19 10:45:09.839 2269477:MainThread
s3ql.fsck.check_contents_parent_inode: Checking contents (parent
inodes)...
2025-09-19 10:48:54.754 2269477:MainThread s3ql.fsck.check_objects_hash:
Checking objects.hash...
2025-09-19 10:48:54.754 2269477:MainThread
s3ql.fsck.check_objects_refcount: Checking objects (reference counts)...
2025-09-19 10:50:16.159 2269477:MainThread s3ql.fsck.check_objects_id:
Checking objects (backend)...
2025-09-19 10:50:16.329 2269477:MainThread
s3ql.backends.gs._get_access_token: Requesting new access token
2025-09-19 10:55:31.276 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 865055 objects so far
2025-09-19 10:59:25.101 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 1508462 objects so far
2025-09-19 10:59:46.945 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 1571071 objects so far
2025-09-19 11:02:07.459 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 1967163 objects so far
2025-09-19 11:03:52.466 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 2251577 objects so far
2025-09-19 11:33:09.646 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 7114103 objects so far
2025-09-19 11:47:46.690 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 9570264 objects so far
2025-09-19 11:49:29.233 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 9858110 objects so far
2025-09-19 11:49:56.872 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 9936100 objects so far
2025-09-19 11:51:47.074 2269477:MainThread
s3ql.backends.gs._get_access_token: Requesting new access token
2025-09-19 11:59:01.550 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 11448867 objects so far
2025-09-19 12:04:24.632 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 12356363 objects so far
2025-09-19 12:05:02.372 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 12461733 objects so far
2025-09-19 12:05:33.958 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 12551075 objects so far
2025-09-19 12:08:59.015 2269477:MainThread s3ql.fsck.check_objects_id:
Processed 13126055 objects so far
2025-09-19 12:15:46.547 2269477:MainThread
s3ql.fsck.check_objects_phys_size: Checking objects (physical sizes)...
2025-09-19 12:15:47.544 2269477:MainThread
s3ql.fsck.check_inode_blocks_obj_id: Checking block-object mapping...
2025-09-19 12:19:46.435 2269477:MainThread
s3ql.fsck.check_inode_blocks_inode: Checking inode_blocks.inode...
2025-09-19 12:22:18.268 2269477:MainThread
s3ql.fsck.check_inodes_refcount: Checking inodes (refcounts)...
2025-09-19 12:41:52.621 2269477:MainThread s3ql.fsck.check_inodes_size:
Checking inodes (sizes)...
2025-09-19 14:10:59.768 2269477:MainThread
s3ql.fsck.check_ext_attributes_name: Checking extended attributes
(names)...
2025-09-19 14:10:59.784 2269477:MainThread
s3ql.fsck.check_ext_attributes_inode: Checking extended attributes
(inodes)...
2025-09-19 14:10:59.785 2269477:MainThread s3ql.fsck.check_symlinks_inode:
Checking symlinks (inodes)...
2025-09-19 14:13:39.207 2269477:MainThread s3ql.fsck.check_loops: Checking
directory reachability...
2025-09-19 15:49:06.831 2269477:MainThread s3ql.fsck.check_unix: Checking
unix conventions...
2025-09-19 17:54:31.662 2269477:MainThread s3ql.fsck.check_foreign_keys:
Checking referential integrity...
2025-09-19 18:09:02.559 2269477:MainThread s3ql.fsck.check: Dropping
temporary indices...
2025-09-20 04:43:13.957 2269477:MainThread s3ql.database.upload_metadata:
Uploading metadata...
2025-09-20 04:43:14.228 2269477:MainThread
s3ql.backends.gs._get_access_token: Requesting new access token
2025-09-20 05:43:14.408 2269477:MainThread
s3ql.backends.gs._get_access_token: Requesting new access token
2025-09-20 06:08:29.796 2269477:MainThread __main__.excepthook: Uncaught
top-level exception:
Traceback (most recent call last):
File "/usr/bin/fsck.s3ql", line 33, in <module>
sys.exit(load_entry_point('s3ql==5.4.0', 'console_scripts',
'fsck.s3ql')())

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^
File "/usr/lib/python3/dist-packages/s3ql/fsck.py", line 1383, in main
upload_metadata(backend, db, param, incremental=False)
~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3/dist-packages/s3ql/database.py", line 680, in
upload_metadata
backend.write_fh(obj, fh, len_=blocksize)
~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3/dist-packages/s3ql/backends/comprenc.py", line
279, in write_fh
return self.backend.write_fh(key, fh, meta_raw, len_=len_)
~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3/dist-packages/s3ql/backends/gs.py", line 425, in
write_fh
return self._write_fh(key, fh, off, len_, metadata or {})
~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3/dist-packages/s3ql/backends/common.py", line 114,
in wrapped
return method(*a, **kw)
File "/usr/lib/python3/dist-packages/s3ql/backends/gs.py", line 503, in
_write_fh
exc = _parse_error_response(resp, self.conn.co_readall())
File "/usr/lib/python3/dist-packages/s3ql/backends/gs.py", line 108, in
_parse_error_response
json_resp = _parse_json_response(resp, body)
File "/usr/lib/python3/dist-packages/s3ql/backends/gs.py", line 140, in
_parse_json_response
body_text = body.decode(charset)
^^^^^^^^^^^
AttributeError: 'coroutine' object has no attribute 'decode'

[Nikolaus Rath]

On Tue, 23 Sep 2025, at 14:37, 'Joseph Maher' via s3ql wrote:
> I think this is a different one from the earlier one? Apologies if not...
>
> $ SQLITE_TMPDIR=/mnt/backup/tmp/ fsck.s3ql --fast --log
> /mnt/backup/root/.s3ql/fsck.log
> --authfile=/mnt/backup/root/.s3ql/authinfo2
> --cachedir=/mnt/backup/cache/gs/ gs://backup-echo-maher-org-uk/
>

[...]

That's a different issue (and most likely much easier to fix). Would you mind filing a bug at https://github.com/s3ql/s3ql/issues?


Best,
-Nikolaus

[Nikolaus Rath]

Nevermind that, the fix is trivial:

diff --git a/src/s3ql/backends/gs.py b/src/s3ql/backends/gs.py
index 4ce245fa41..91e5677b6d 100644
--- a/src/s3ql/backends/gs.py
+++ b/src/s3ql/backends/gs.py
@@ -500,7 +500,7 @@
self.conn.discard()
raise AccessTokenExpired()
elif resp.status != 200:
- exc = _parse_error_response(resp, self.conn.co_readall())
+ exc = _parse_error_response(resp, self.conn.readall())
raise _map_request_error(exc, key) or exc
_parse_json_response(resp, self.conn.readall())


Best,
-Nikolasu