container-test-run-matrix-synapse
checks.aarch64-linux.matrix-synapse
· build #661
· raw
1Machine state will be reset. To keep it, pass --keep-machine-state2start all VLans3(finished: start all VLans, in 0.01 seconds)45Test will time out and terminate in 3600.0 seconds6run the VM test script7additionally exposed symbols:8 machine,9 vlan1,10 start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh11start all VMs12machine: systemd-nspawn running (pid 51)13machine: Waiting for journal at /build/vm-state-machine/var/log/journal...14(finished: start all VMs, in 0.00 seconds)15machine: waiting for unit matrix-synapse16nixos-nspawn(machine): TAP vde-tap1 not found; container will be isolated from VDE17nixos-nspawn(machine): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.18Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.19░ Spawning container machine on /build/vm-state-machine.20machine # No journal files were found.21machine # No journal boot entry found for the specified boot (+0).22machine # [976178.958912] machine systemd-journald[96]: Journal started23machine # [976178.958968] machine systemd-journald[96]: Runtime Journal (/run/log/journal/d0a18114d885433e822d3908bbb9c231) is 8M, max 2.5G, 2.4G free.24machine # [976178.968656] machine systemd[1]: Starting Flush Journal to Persistent Storage...25machine # [976178.969988] machine systemd[1]: Starting Network Name Resolution...26machine # [976178.970685] machine systemd[1]: Starting Create Static Device Nodes in /dev...27machine # [976178.981565] machine systemd-journald[96]: Time spent on flushing to /var/log/journal/d0a18114d885433e822d3908bbb9c231 is 2.993ms for 5 entries.28machine # [976178.981565] machine systemd-journald[96]: System Journal (/var/log/journal/d0a18114d885433e822d3908bbb9c231) is 8M, max 4G, 3.9G free.29machine # [976178.988844] machine systemd[1]: Finished Create Static Device Nodes in /dev.30machine # [976178.989105] machine systemd[1]: Reached target Preparation for Local File Systems.31machine # [976178.989191] machine systemd[1]: Reached target Local File Systems.32machine # [976178.989937] machine systemd[1]: Listening on Boot Loader Control Service Socket.33machine # [976178.989982] machine systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container34machine # [976178.990968] machine systemd[1]: Starting Save Transient machine-id to Disk...35machine # [976178.991004] machine systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys36machine # [976179.164265] machine systemd[1]: Finished Firewall.37machine # [976179.164935] machine systemd[1]: Reached target Preparation for Network.38machine # [976179.165257] machine systemd[1]: Listening on Network Management Resolve Hook Socket.39machine # [976179.166793] machine systemd[1]: Starting Network Management...40machine # [976179.200967] machine systemd[1]: Finished Flush Journal to Persistent Storage.41machine # [976179.202679] machine systemd[1]: Starting Create System Files and Directories...42machine # [976179.222886] machine systemd-tmpfiles[207]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted43machine # [976179.223100] machine systemd-tmpfiles[207]: fchmod() of /var/log/journal failed: Operation not permitted44machine # [976179.223237] machine systemd-tmpfiles[207]: fchmod() of /var/log/journal/d0a18114d885433e822d3908bbb9c231 failed: Operation not permitted45machine # [976179.223445] machine systemd-tmpfiles[207]: fchmod() of /run/log/journal failed: Operation not permitted46machine # [976179.225428] machine systemd[1]: Finished Create System Files and Directories.47machine # [976179.227087] machine systemd[1]: Starting Rebuild Journal Catalog...48machine # [976179.228095] machine systemd[1]: Starting Record System Boot/Shutdown in UTMP...49machine # [976179.245197] machine systemd[1]: Finished Record System Boot/Shutdown in UTMP.50machine # [976179.255073] machine systemd[1]: Finished Rebuild Journal Catalog.51machine # [976179.256997] machine systemd[1]: Starting Update is Completed...52machine # [976179.270820] machine systemd[1]: Finished Update is Completed.53machine # [976179.617492] machine systemd-networkd[204]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted54machine # [976179.617583] machine systemd-networkd[204]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted55machine # [976179.627865] machine systemd-networkd[204]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.56machine # [976179.628047] machine systemd-networkd[204]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.57machine # [976179.628214] machine systemd-networkd[204]: lo: Link UP58machine # [976179.628218] machine systemd-networkd[204]: lo: Gained carrier59machine # [976179.628412] machine systemd-networkd[204]: eth1: Configuring with /etc/systemd/network/40-eth1.network.60machine # [976179.628915] machine systemd-networkd[204]: eth1: Link UP61machine # [976179.629151] machine systemd[1]: Started Network Management.62machine # [976179.629183] machine systemd-networkd[204]: eth1: Gained carrier63machine # [976179.630416] machine systemd[1]: Starting Enable Persistent Storage in systemd-networkd...64machine # [976179.670089] machine systemd[1]: Finished Enable Persistent Storage in systemd-networkd.65machine # [976179.738448] machine systemd-resolved[118]: Positive Trust Anchors:66machine # [976179.738461] machine systemd-resolved[118]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d67machine # [976179.738464] machine systemd-resolved[118]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b1668machine # [976179.738500] machine systemd-resolved[118]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test69machine # [976179.761065] machine systemd-resolved[118]: Using system hostname 'machine'.70machine # [976179.762405] machine systemd[1]: Started Network Name Resolution.71machine # [976179.762507] machine systemd[1]: Reached target Network.72machine # [976179.762566] machine systemd[1]: Reached target Network is Online.73machine # [976179.762628] machine systemd[1]: Reached target System Initialization.74machine # [976179.762691] machine systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container75machine # [976179.762731] machine systemd[1]: Started Daily Cleanup of Temporary Directories.76machine # [976179.762752] machine systemd[1]: Reached target Timer Units.77machine # [976179.762903] machine systemd[1]: Listening on D-Bus System Message Bus Socket.78machine # [976179.763056] machine systemd[1]: Listening on Nix Daemon Socket.79machine # [976179.763196] machine systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.80machine # [976179.763225] machine systemd[1]: Reached target Socket Units.81machine # [976179.763271] machine systemd[1]: Reached target Basic System.82machine # [976179.781027] machine systemd[1]: Starting Import lastlog data into lastlog2 database...83machine # [976179.782358] machine systemd[1]: Starting Nginx Web Server...84machine # [976179.783394] machine systemd[1]: Starting Name Service Cache Daemon (nsncd)...85machine # [976179.784530] machine systemd[1]: Starting PostgreSQL Server...86machine # [976179.786120] machine systemd[1]: Starting D-Bus System Message Bus...87machine # [976179.804478] machine systemd[1]: Finished Import lastlog data into lastlog2 database.88machine # [976179.922987] machine nsncd[220]: Sep 15 14:36:39.908 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"89machine # [976179.923056] machine systemd[1]: Started Name Service Cache Daemon (nsncd).90machine # [976179.923157] machine systemd[1]: Reached target Host and Network Name Lookups.91machine # [976179.923264] machine systemd[1]: Reached target User and Group Name Lookups.92machine # [976179.925476] machine systemd[1]: Starting User Login Management...93machine # [976179.927033] machine systemd[1]: Starting Permit User Sessions...94machine # [976179.990498] machine systemd[1]: Finished Permit User Sessions.95machine # [976179.992810] machine systemd[1]: Started Console Getty.96machine # [976179.992880] machine systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty097machine # [976179.992919] machine systemd[1]: Reached target Login Prompts.98machine # [976180.015809] machine dbus-broker-launch[222]: Looking up NSS user entry for 'systemd-timesync'...99machine # [976180.017130] machine dbus-broker-launch[222]: NSS returned no entry for 'systemd-timesync'100machine # [976180.017130] machine dbus-broker-launch[222]: Invalid user-name in /nix/store/22wjl34lb0z90ndaacf5gf54q1q4w2kd-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"101machine # [976180.017615] machine systemd[1]: Started D-Bus System Message Bus.102machine # [976180.026533] machine dbus-broker-launch[222]: Ready103machine # [976180.460129] machine postgresql-pre-start[255]: The files belonging to this database system will be owned by user "postgres".104machine # [976180.460129] machine postgresql-pre-start[255]: This user must also own the server process.105machine # [976180.460882] machine postgresql-pre-start[255]: The database cluster will be initialized with locale "en_US.UTF-8".106machine # [976180.460882] machine postgresql-pre-start[255]: The default database encoding has accordingly been set to "UTF8".107machine # [976180.460882] machine postgresql-pre-start[255]: The default text search configuration will be set to "english".108machine # [976180.460882] machine postgresql-pre-start[255]: Data page checksums are enabled.109machine # [976180.460882] machine postgresql-pre-start[255]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok110machine # [976180.460882] machine postgresql-pre-start[255]: creating subdirectories ... ok111machine # [976180.461180] machine postgresql-pre-start[255]: selecting dynamic shared memory implementation ... posix112machine # [976180.497364] machine postgresql-pre-start[255]: selecting default "max_connections" ... 100113machine # [976180.500764] machine nginx-pre-start[257]: nginx: the configuration file /nix/store/aq8j7h49fppla875s13py3vaf9j5sq4j-nginx.conf syntax is ok114machine # [976180.501615] machine nginx-pre-start[257]: nginx: configuration file /nix/store/aq8j7h49fppla875s13py3vaf9j5sq4j-nginx.conf test is successful115machine # [976180.509674] machine systemd[1]: Started Nginx Web Server.116machine # [976180.531359] machine postgresql-pre-start[255]: selecting default "shared_buffers" ... 128MB117machine # [976180.601426] machine systemd-logind[243]: New seat seat0.118machine # [976180.601729] machine systemd[1]: Started User Login Management.119machine # [976180.604282] machine systemd[1]: Starting linger-users.service...120machine # [976180.624483] machine systemd[1]: linger-users.service: Deactivated successfully.121machine # [976180.624730] machine systemd[1]: Finished linger-users.service.122machine # [976180.802725] machine postgresql-pre-start[255]: selecting default time zone ... UTC123machine # [976180.803438] machine postgresql-pre-start[255]: creating configuration files ... ok124machine # [976181.280155] machine systemd-networkd[204]: eth1: Gained IPv6LL125machine # [976181.728547] machine postgresql-pre-start[255]: running bootstrap script ... ok126machine # [976182.405239] machine postgresql-pre-start[255]: performing post-bootstrap initialization ... ok127machine # [976182.852154] machine postgresql-pre-start[255]: syncing data to disk ... ok128machine # [976182.852154] machine postgresql-pre-start[255]: initdb: warning: enabling "trust" authentication for local connections129machine # [976182.852154] machine postgresql-pre-start[255]: initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.130machine # [976182.852154] machine postgresql-pre-start[255]: Success. You can now start the database server using:131machine # [976182.852154] machine postgresql-pre-start[255]: pg_ctl -D /var/lib/postgresql/18 -l logfile start132machine # [976183.536527] machine postgres[278]: [278] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit133machine # [976183.537935] machine postgres[278]: [278] LOG: listening on IPv6 address "::1", port 5432134machine # [976183.537935] machine postgres[278]: [278] LOG: listening on IPv4 address "127.0.0.1", port 5432135machine # [976183.541149] machine postgres[278]: [278] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"136machine # [976183.547610] machine postgres[287]: [287] LOG: database system was shut down at 2026-09-15 14:36:42 GMT137machine # [976183.555403] machine postgres[278]: [278] LOG: database system is ready to accept connections138machine # [976184.197770] machine postgresql-post-start[300]: CREATE ROLE139machine # [976184.517691] machine postgresql-post-start[305]: CREATE DATABASE140machine # [976184.522985] machine systemd[1]: Started PostgreSQL Server.141machine # [976184.524543] machine systemd[1]: Starting PostgreSQL Setup Scripts...142machine # [976184.592479] machine systemd[1]: Finished PostgreSQL Setup Scripts.143machine # [976184.593374] machine systemd[1]: Reached target PostgreSQL.144machine # [976184.594915] machine systemd[1]: Starting Synapse Matrix homeserver...145machine # [976187.453944] machine matrix-synapse-pre-start[319]: Generating signing key file /var/lib/matrix-synapse/homeserver.signing.key146machine: still waiting for container 'machine' to reach ready state...147machine # [976190.807115] machine synapse_homeserver[330]: This server is configured to use 'matrix.org' as its trusted key server via the148machine # [976190.807115] machine synapse_homeserver[330]: 'trusted_key_servers' config option. 'matrix.org' is a good choice for a key149machine # [976190.807115] machine synapse_homeserver[330]: server since it is long-lived, stable and trusted. However, some admins may150machine # [976190.807115] machine synapse_homeserver[330]: wish to use another server for this purpose.151machine # [976190.807115] machine synapse_homeserver[330]: To suppress this warning and continue using 'matrix.org', admins should set152machine # [976190.807115] machine synapse_homeserver[330]: 'suppress_key_server_warning' to 'true' in homeserver.yaml.153machine # [976190.807115] machine synapse_homeserver[330]: --------------------------------------------------------------------------------154machine # [976190.859813] machine synapse[330]: synapse.config.logger: [main] ***** STARTING SERVER *****155machine # [976190.859919] machine synapse[330]: synapse.config.logger: [main] Server /nix/store/w1dj3n12wq2npv51a0kfsz0aj1wzqmzy-matrix-synapse-1.160.0/bin/synapse_homeserver version 1.160.0156machine # [976190.859982] machine synapse[330]: synapse.config.logger: [main] Copyright (c) 2023 New Vector, Inc157machine # [976190.860053] machine synapse[330]: synapse.config.logger: [main] Licensed under the AGPL 3.0 license. Website: https://github.com/element-hq/synapse158machine # [976190.860275] machine synapse[330]: synapse.config.logger: [main] Server hostname: clan.test159machine # [976190.860355] machine synapse[330]: synapse.config.logger: [main] Public Base URL: https://clan.test/160machine # [976190.860429] machine synapse[330]: synapse.config.logger: [main] Instance name: master161machine # [976190.860501] machine synapse[330]: synapse.config.logger: [main] Twisted reactor: EPollReactor162machine # [976190.860562] machine synapse[330]: synapse.app.homeserver: [main] Setting up server163machine # [976190.860624] machine synapse[330]: synapse.server: [main] Setting up.164machine # [976190.869263] machine synapse[330]: synapse.storage.databases: [main] [database config 'master']: Checking database server165machine # [976190.870399] machine synapse[330]: synapse.storage.databases: [main] [database config 'master']: Preparing for databases ['main', 'state']166machine # [976190.870625] machine synapse[330]: synapse.storage.prepare_database: [main] ['main', 'state']: Checking existing schema version167machine # [976190.878250] machine synapse[330]: synapse.storage.prepare_database: [main] ['main', 'state']: Initialising new database168machine # [976191.143422] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v73169machine # [976191.145629] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/01event_failed_pull_attempts.sql170machine # [976191.149133] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/02add_pusher_enabled.sql171machine # [976191.150534] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/02room_id_indexes_for_purging.sql172machine # [976191.153432] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/03pusher_device_id.sql173machine # [976191.155016] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/03users_approved_column.sql174machine # [976191.156672] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/04partial_join_details.sql175machine # [976191.159134] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/04pending_device_list_updates.sql176machine # [976191.162685] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 73/05old_push_actions.sql.postgres177machine # [976191.164790] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/06thread_notifications_thread_id_idx.sql178machine # [976191.166841] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 73/08thread_receipts_non_null.sql.postgres179machine # [976191.168853] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/09partial_joined_via_destination.sql180machine # [976191.170660] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/09threads_table.sql181machine # [976191.175476] machine synapse[330]: synapse.storage.prepare_database: [main] Running 73/10_update_sqlite_fts4_tokenizer.py:run_create182machine # [976191.175937] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/10login_tokens.sql183machine # [976191.179635] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 73/11event_search_room_id_n_distinct.sql.postgres184machine # [976191.181131] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/12refactor_device_list_outbound_pokes.sql185machine # [976191.186653] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/13add_device_lists_index.sql186machine # [976191.189032] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/20_un_partial_stated_room_stream.sql187machine # [976191.192877] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 73/21_un_partial_stated_room_stream_seq.sql.postgres188machine # [976191.195162] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/22_rebuild_user_dir_stats.sql189machine # [976191.196523] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/22_un_partial_stated_event_stream.sql190machine # [976191.199780] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/23_fix_thread_index.sql191machine # [976191.201613] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 73/23_un_partial_stated_room_stream_seq.sql.postgres192machine # [976191.203110] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/24_events_jump_to_date_index.sql193machine # [976191.204125] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 73/25drop_presence.sql194machine # [976191.205517] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v74195machine # [976191.206221] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 74/01_user_directory_stale_remote_users.sql196machine # [976191.209305] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 74/02_set_device_id_for_pushers_bg_update.sql197machine # [976191.210300] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 74/03_membership_tables_event_stream_ordering.sql.postgres198machine # [976191.212203] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 74/03_room_membership_index.sql199machine # [976191.213148] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 74/04_delete_e2e_backup_keys_for_deactivated_users.sql200machine # [976191.214501] machine synapse[330]: synapse.storage.prepare_database: [main] Running 74/04_membership_tables_event_stream_ordering_triggers.py:run_create201machine # [976191.215999] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 74/05_events_txn_id_device_id.sql202machine # [976191.219580] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 74/90COMMENTS_destinations.sql.postgres203machine # [976191.221193] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v75204machine # [976191.222023] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v76205machine # [976191.222663] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 76/01_add_profiles_full_user_id_column.sql206machine # [976191.223988] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 76/02_add_user_filters_full_user_id_column.sql207machine # [976191.225073] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 76/03_per_user_experimental_features.sql208machine # [976191.227535] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 76/04_add_room_forgetter.sql209machine # [976191.230000] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v77210machine # [976191.230670] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 77/01_add_profiles_not_valid_check.sql.postgres211machine # [976191.231659] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 77/02_add_user_filters_not_valid_check.sql.postgres212machine # [976191.233380] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 77/03bg_populate_full_user_id_profiles.sql213machine # [976191.234367] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 77/04bg_populate_full_user_id_user_filters.sql214machine # [976191.235226] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 77/05thread_notifications_backfill.sql215machine # [976191.237836] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 77/06thread_notifications_not_null_event_push_actions.sql.postgres216machine # [976191.238992] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 77/06thread_notifications_not_null_event_push_actions_staging.sql.postgres217machine # [976191.240051] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 77/06thread_notifications_not_null_event_push_summary.sql.postgres218machine # [976191.241172] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 77/14bg_indices_event_stream_ordering.sql219machine # [976191.242337] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v78220machine # [976191.246049] machine synapse[330]: synapse.storage.prepare_database: [main] Running 78/03event_extremities_constraints.py:run_create221machine # [976191.247829] machine synapse[330]: synapse.storage.prepare_database: [main] Running 78/04_add_full_user_id_index_user_filters.py:run_create222machine # [976191.248191] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v79223machine # [976191.248903] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 79/03_read_write_locks_triggers.sql.postgres224machine # [976191.255031] machine synapse[330]: synapse.storage.prepare_database: [main] Running 79/04_mitigate_stream_ordering_update_race.py:run_create225machine # [976191.255616] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 79/05_read_write_locks_triggers.sql.postgres226machine # [976191.257481] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v80227machine # [976191.258294] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 80/01_users_alter_locked.sql228machine # [976191.259611] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 80/02_read_write_locks_unlogged.sql.postgres229machine # [976191.265137] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 80/02_scheduled_tasks.sql230machine # [976191.268318] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 80/03_read_write_locks_triggers.sql.postgres231machine # [976191.269756] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 80/04_read_write_locks_deadlock.sql.postgres232machine # [976191.271090] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v81233machine # [976191.271712] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v82234machine # [976191.272277] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 82/02_scheduled_tasks_index.sql235machine # [976191.273709] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 82/04_add_indices_for_purging_rooms.sql236machine # [976191.274572] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 82/05gaps.sql237machine # [976191.276619] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v83238machine # [976191.277141] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 83/01_drop_old_tables.sql239machine # [976191.280654] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 83/05_cross_signing_key_update_grant.sql240machine # [976191.283471] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 83/06_event_push_summary_room.sql241machine # [976191.284297] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v84242machine # [976191.284827] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 84/01_auth_links_stats.sql.postgres243machine # [976191.285656] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 84/02_auth_links_index.sql244machine # [976191.286576] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 84/03_auth_links_analyze.sql.postgres245machine # [976191.287571] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 84/04_access_token_index.sql246machine # [976191.288328] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v85247machine # [976191.288869] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 85/01_add_suspended.sql248machine # [976191.290008] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 85/02_add_instance_names.sql249machine # [976191.291334] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 85/03_new_sequences.sql.postgres250machine # [976191.295463] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 85/04_cleanup_device_federation_outbox.sql251machine # [976191.296347] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 85/05_add_instance_names_converted_pos.sql252machine # [976191.297121] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 85/06_add_room_reports.sql253machine # [976191.299177] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v86254machine # [976191.299650] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 86/01_authenticate_media.sql255machine # [976191.301127] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 86/02_receipts_event_id_index.sql256machine # [976191.302420] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v87257machine # [976191.303230] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 87/01_sliding_sync_memberships.sql258machine # [976191.313371] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 87/02_per_connection_state.sql259machine # [976191.326093] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 87/03_current_state_index.sql260machine # [976191.327772] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v88261machine # [976191.328881] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 88/01_add_delayed_events.sql262machine # [976191.335384] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 88/01_custom_profile_fields.sql263machine # [976191.336892] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 88/02_fix_sliding_sync_membership_snapshots_forgotten_column.sql264machine # [976191.338074] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 88/03_add_otk_ts_added_index.sql265machine # [976191.339168] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 88/04_current_state_delta_index.sql266machine # [976191.341037] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 88/05_drop_old_otks.sql.postgres267machine # [976191.342892] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 88/05_sliding_sync_room_config_index.sql268machine # [976191.344069] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 88/06_events_received_ts_index.sql269machine # [976191.345873] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v89270machine # [976191.346881] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 89/01_sliding_sync_membership_snapshot_index.sql271machine # [976191.348220] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 89/01_state_groups_deletion.sql272machine # [976191.353821] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v90273machine # [976191.354805] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 90/01_add_column_participant_room_memberships_table.sql274machine # [976191.357286] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 90/02_delete_unreferenced_state_groups.sql275machine # [976191.358871] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 90/03_remove_old_deletion_bg_update.sql276machine # [976191.360121] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v91277machine # [976191.361221] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 91/01_media_hash.sql278machine # [976191.362962] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v92279machine # [976191.364302] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 92/01_remove_trigger.sql.postgres280machine # [976191.365651] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 92/02_remove_populate_participant_bg_update.sql281machine # [976191.366897] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 92/04_ss_membership_snapshot_idx.sql282machine # [976191.368143] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 92/04_thread_subscriptions.sql283machine # [976191.374882] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 92/04_thread_subscriptions_seq.sql.postgres284machine # [976191.376653] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 92/05_fixup_max_depth_cap.sql285machine # [976191.377922] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 92/05_thread_subscriptions_comments.sql.postgres286machine # [976191.379350] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 92/06_device_federation_inbox_index.sql287machine # [976191.380579] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 92/06_threads_last_sent_stream_ordering_comments.sql.postgres288machine # [976191.381845] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 92/07_add_user_reports.sql289machine # [976191.386054] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 92/07_event_txn_id_device_id_txn_id2.sql290machine # [976191.387375] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 92/08_room_ban_redactions.sql291machine # [976191.390308] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 92/08_thread_subscriptions_seq_fixup.sql.postgres292machine # [976191.392466] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 92/09_thread_subscriptions_update.sql293machine # [976191.394131] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 92/09_thread_subscriptions_update.sql.postgres294machine # [976191.395441] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v93295machine # [976191.396580] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 93/01_add_delayed_events.sql296machine # [976191.398347] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 93/01_sticky_events.sql297machine # [976191.403342] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 93/01_sticky_events_seq.sql.postgres298machine # [976191.405182] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 93/02_sliding_sync_members.sql299machine # [976191.410314] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 93/03_sss_pos_last_used.sql300machine # [976191.412873] machine synapse[330]: synapse.storage.prepare_database: [main] Running 93/04_make_delayed_event_content_text.py:run_create301machine # [976191.417817] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema deltas for v94302machine # [976191.419225] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 94/01_redactions_recheck.sql303machine # [976191.423638] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 94/02_redactions_recheck_bg_update.sql304machine # [976191.424988] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 94/03_device_lists_room_timestamp.sql305machine # [976191.426420] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 94/03_quarantined_media_tracking.sql306machine # [976191.430166] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 94/03_quarantined_media_tracking_seq.sql.postgres307machine # [976191.432130] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 94/03_state_dag_fwd_extrems.sql308machine # [976191.442338] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 94/04_device_lists_changes_max_pruned.sql309machine # [976191.445688] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 94/05_rerun_flag_existing_quarantined_media.sql310machine # [976191.447212] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 94/06_sliding_sync_connections_last_used_ts_index.sql311machine # [976191.448494] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 94/07_profile_updates.sql312machine # [976191.455139] machine synapse[330]: synapse.storage.prepare_database: [main] Applying engine-specific schema 94/07_profile_updates_seq.sql.postgres313machine # [976191.457159] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 94/07_sliding_sync_lazy_members_position_index.sql314machine # [976191.459359] machine synapse[330]: synapse.storage.prepare_database: [main] Applying schema 94/08_device_lists_changes_in_room_unconverted_idx.sql315machine # [976191.460587] machine synapse[330]: synapse.storage.prepare_database: [main] Schema now up to date316machine # [976191.461742] machine synapse[330]: synapse.storage.databases: [main] [database config 'master']: Starting 'main' database317machine # [976191.500205] machine synapse[330]: synapse.storage.util.id_generators: [main] Initialising stream generator for push_rules(id): 1318machine # [976191.501976] machine synapse[330]: synapse.storage.util.id_generators: [main] Initialising stream generator for push_rules_enable(id): 1319machine # [976191.511917] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [main] Searching for stream ordering 1 month ago320machine # [976191.512503] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [main] Found stream ordering 1 month ago: it's 0321machine # [976191.512695] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [main] Searching for stream ordering 1 day ago322machine # [976191.513197] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [main] Found stream ordering 1 day ago: it's 0323machine # [976191.520282] machine synapse[330]: synapse.storage.util.id_generators: [main] Initialising stream generator for access_tokens(id): 1324machine # [976191.521064] machine synapse[330]: synapse.storage.util.id_generators: [main] Initialising stream generator for refresh_tokens(id): 1325machine # [976191.527152] machine synapse[330]: synapse.storage.util.id_generators: [main] Initialising stream generator for event_reports(id): 1326machine # [976191.527800] machine synapse[330]: synapse.storage.util.id_generators: [main] Initialising stream generator for room_reports(id): 1327machine # [976191.528566] machine synapse[330]: synapse.storage.util.id_generators: [main] Initialising stream generator for user_reports(id): 1328machine # [976191.539250] machine synapse[330]: synapse.storage.databases: [main] [database config 'master']: Starting 'state' database329machine # [976191.541526] machine synapse[330]: synapse.storage.databases: [main] [database config 'master']: prepared330machine # [976191.541808] machine synapse[330]: synapse.server: [main] Finished setting up.331machine # [976191.542351] machine synapse[330]: twisted: [main] Redirected stdout/stderr to logs332machine # [976191.542628] machine synapse[330]: synapse.app.homeserver: [main] Running333machine # [976191.551952] machine synapse[330]: synapse.app.homeserver: [main] Set file limit to: 524288334machine # [976191.607835] machine synapse[330]: synapse.push.pusher: [call_when_running] email enable notifs: False335machine # [976191.638656] machine synapse[330]: synapse.federation.federation_server: [call_when_running] Registering federation query handler for 'profile'336machine # [976191.640265] machine synapse[330]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.device_list_update'337machine # [976191.640821] machine synapse[330]: synapse.util.caches.lrucache: [call_when_running] Expiring LRU caches after 1800 seconds338machine # [976191.645513] machine synapse[330]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.presence'339machine # [976191.645982] machine synapse[330]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.typing'340machine # [976191.648206] machine synapse[330]: synapse.federation.federation_server: [call_when_running] Registering federation query handler for 'directory'341machine # [976191.656842] machine synapse[330]: synapse.handlers.deactivate_account: [user_parter_loop-0] Starting user parter342machine # [976191.657917] machine synapse[330]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.receipt'343machine # [976191.658250] machine synapse[330]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.signing_key_update'344machine # [976191.658358] machine synapse[330]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'org.matrix.signing_key_update'345machine # [976191.658459] machine synapse[330]: synapse.federation.federation_server: [call_when_running] Registering federation query handler for 'client_keys'346machine # [976191.659158] machine synapse[330]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.direct_to_device'347machine # [976191.668510] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.health.HealthResource object at 0xffffec6b5aa0> to path b'/health'348machine # [976191.668644] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <twisted.web.resource.EncodingResourceWrapper object at 0xffffec6cefa0> to path b'/_matrix/client'349machine # [976191.668758] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <twisted.web.resource.Resource object at 0xffffec894ca0> to path b'/.well-known'350machine # [976191.668848] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.http.server.JsonResource object at 0xffffec6cf120> to path b'/_synapse/admin'351machine # [976191.668943] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.synapse.client.pick_idp.PickIdpResource object at 0xffffec895120> to path b'/_synapse/client/pick_idp'352machine # [976191.669047] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <twisted.web.resource.Resource object at 0xffffec3d73e0> to path b'/_synapse/client/pick_username'353machine # [976191.669146] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.synapse.client.new_user_consent.NewUserConsentResource object at 0xffffec895720> to path b'/_synapse/client/new_user_consent'354machine # [976191.669237] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.synapse.client.sso_register.SsoRegisterResource object at 0xffffec8958a0> to path b'/_synapse/client/sso_register'355machine # [976191.669330] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.synapse.client.unsubscribe.UnsubscribeResource object at 0xffffec895a20> to path b'/_synapse/client/unsubscribe'356machine # [976191.669427] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.synapse.client.media_upload_limit_exceeded.MediaUploadLimitExceededResource object at 0xffffec895ba0> to path b'/_synapse/client/media_upload_limit_exceeded'357machine # [976191.669529] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching FilePath('/nix/store/w1dj3n12wq2npv51a0kfsz0aj1wzqmzy-matrix-synapse-1.160.0/lib/python3.14/site-packages/synapse/static') to path b'/_matrix/static'358machine # [976191.669617] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.media.media_repository_resource.MediaRepositoryResource object at 0xffffec896020> to path b'/_matrix/media/r0'359machine # [976191.669710] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.media.media_repository_resource.MediaRepositoryResource object at 0xffffec896020> to path b'/_matrix/media/v3'360machine # [976191.669795] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.media.media_repository_resource.MediaRepositoryResource object at 0xffffec896020> to path b'/_matrix/media/v1'361machine # [976191.669877] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.federation.transport.server.TransportLayerServer object at 0xffffec896c20> to path b'/_matrix/federation'362machine # [976191.669963] machine synapse[330]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.key.v2.KeyResource object at 0xffffec899da0> to path b'/_matrix/key'363machine # [976191.671389] machine synapse[330]: twisted: [call_when_running] SynapseSite starting on 8008364machine # [976191.671913] machine synapse[330]: synapse.app._base: [call_when_running] Synapse now listening on TCP port 8008365machine # [976191.674008] machine synapse[330]: synapse.app._base: [call_when_running] garbage collector: Freezing all allocated objects in the hopes that (almost) everything currently allocated are things that will be used by the homeserver for the rest of time. Doing so means less work each GC (hopefully).366machine # [976191.769846] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting background schema updates for database master367machine # [976191.770461] machine synapse[330]: synapse.handlers.deactivate_account: [user_parter_loop-0] User parter finished: stopping368machine # [976191.773980] machine synapse[330]: synapse.push.pusherpool: [start_pushers-0] Started pushers369machine # [976191.822341] machine 5kd0fcsj2nc98pgm5jphfg1gy8k5ly1w-matrix-synapse-create-users[355]: Connection to ::1 8008 port [tcp/http-alt] succeeded!370machine # [976192.343404] machine synapse[330]: synapse.access.http.8008: [GET-0] ::1 - 8008 - {None} Processed request: 0.001sec/0.001sec ru=(0.001sec, 0.000sec) db=(0.000sec/0.000sec/0) 140B 200 "GET /_synapse/admin/v1/register HTTP/1.1" "python-requests/2.34.2" [0 dbevts]371machine # [976192.648138] machine synapse[330]: synapse.handlers.auth: [POST-1] Logging in user @admin:clan.test on device GRLXEFXCQB372machine # [976192.659361] machine synapse[330]: synapse.access.http.8008: [POST-1] ::1 - 8008 - {None} Processed request: 0.310sec/0.001sec ru=(0.259sec, 0.008sec) db=(0.005sec/0.041sec/12) 138B 200 "POST /_synapse/admin/v1/register HTTP/1.1" "python-requests/2.34.2" [0 dbevts]373machine # [976192.662407] machine 5kd0fcsj2nc98pgm5jphfg1gy8k5ly1w-matrix-synapse-create-users[356]: Sending registration request...374machine # [976192.662407] machine 5kd0fcsj2nc98pgm5jphfg1gy8k5ly1w-matrix-synapse-create-users[356]: Success!375machine # [976192.780452] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'threads_backfill'376machine # [976192.787641] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'threads_backfill'. Processed 0 items in 5ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)377machine # [976193.317946] machine synapse[330]: synapse.access.http.8008: [GET-2] ::1 - 8008 - {None} Processed request: 0.000sec/0.000sec ru=(0.000sec, 0.000sec) db=(0.000sec/0.000sec/0) 140B 200 "GET /_synapse/admin/v1/register HTTP/1.1" "python-requests/2.34.2" [0 dbevts]378machine # [976193.588693] machine synapse[330]: synapse.handlers.auth: [POST-3] Logging in user @someuser:clan.test on device KMCINSYDFA379machine # [976193.597082] machine synapse[330]: synapse.access.http.8008: [POST-3] ::1 - 8008 - {None} Processed request: 0.275sec/0.001sec ru=(0.238sec, 0.001sec) db=(0.005sec/0.020sec/12) 145B 200 "POST /_synapse/admin/v1/register HTTP/1.1" "python-requests/2.34.2" [0 dbevts]380machine # [976193.598749] machine 5kd0fcsj2nc98pgm5jphfg1gy8k5ly1w-matrix-synapse-create-users[362]: Sending registration request...381machine # [976193.598749] machine 5kd0fcsj2nc98pgm5jphfg1gy8k5ly1w-matrix-synapse-create-users[362]: Success!382machine # [976193.725125] machine systemd[1]: Started Synapse Matrix homeserver.383machine # [976193.725977] machine systemd[1]: Reached target Multi-User System.384machine # [976193.790112] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'device_lists_changes_in_room_by_room_index'385machine # [976193.792045] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index device_lists_changes_in_room_by_room_idx to device_lists_changes_in_room386machine # [976193.798526] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'device_lists_changes_in_room_by_room_index'. Processed 1 items in 7ms. (total_rate=0.14285714285714285/ms, current_rate=0.14285714285714285/ms, total_updated=1, batch_size=100)387machine # [976194.801437] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'populate_stats_process_rooms'388machine # [976194.807010] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'populate_stats_process_rooms'. Processed 1 items in 4ms. (total_rate=0.25/ms, current_rate=0.25/ms, total_updated=1, batch_size=100)389machine # [976195.809469] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'populate_stats_process_users'390machine # [976195.822530] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'populate_stats_process_users'. Processed 2 items in 12ms. (total_rate=0.16666666666666666/ms, current_rate=0.16666666666666666/ms, total_updated=2, batch_size=100)391machine # [976196.824152] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'populate_stats_process_users'392machine # [976197.192874] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'populate_stats_process_users'. Processed 1 items in 367ms. (total_rate=0.0079155672823219/ms, current_rate=0.0074113287453679184/ms, total_updated=3, batch_size=16)393machine # [976197.195583] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Not starting on bg update populate_user_directory_cleanup until populate_user_directory_process_users is done394machine: still waiting for container 'machine' to reach ready state...395machine # [976198.196669] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'populate_user_directory_createtables'396machine # [976198.215167] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'populate_user_directory_createtables'. Processed 1 items in 16ms. (total_rate=0.0625/ms, current_rate=0.0625/ms, total_updated=1, batch_size=100)397machine # [976198.217261] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Not starting on bg update populate_user_directory_cleanup until populate_user_directory_process_users is done398machine # [976199.218669] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'populate_user_directory_process_rooms'399machine # [976199.235294] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'populate_user_directory_process_rooms'. Processed 1 items in 14ms. (total_rate=0.07142857142857142/ms, current_rate=0.07142857142857142/ms, total_updated=1, batch_size=100)400machine # [976199.237112] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Not starting on bg update populate_user_directory_cleanup until populate_user_directory_process_users is done401machine # [976200.238483] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'populate_user_directory_process_users'402machine # [976200.247004] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'populate_user_directory_process_users'. Processed 2 items in 7ms. (total_rate=0.2857142857142857/ms, current_rate=0.2857142857142857/ms, total_updated=2, batch_size=100)403machine # [976201.247937] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'populate_user_directory_process_users'404machine # [976201.754639] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'populate_user_directory_process_users'. Processed 1 items in 505ms. (total_rate=0.005859375/ms, current_rate=0.005476237042831997/ms, total_updated=3, batch_size=28)405machine # [976202.759946] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'populate_user_directory_cleanup'406machine # [976202.770450] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'populate_user_directory_cleanup'. Processed 1 items in 9ms. (total_rate=0.1111111111111111/ms, current_rate=0.11111111111111112/ms, total_updated=1, batch_size=100)407machine # [976203.772937] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'events_jump_to_date_index'408machine # [976203.774623] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index events_jump_to_date_idx to events409machine # [976203.780885] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'events_jump_to_date_index'. Processed 1 items in 6ms. (total_rate=0.16666666666666666/ms, current_rate=0.16666666666666666/ms, total_updated=1, batch_size=100)410machine # [976204.783736] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'set_device_id_for_pushers'411machine # [976204.789135] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'set_device_id_for_pushers'. Processed 0 items in 3ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)412machine # [976205.791559] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'room_membership_user_room_index'413machine # [976205.793241] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index room_membership_user_room_idx to room_memberships414machine # [976205.799875] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'room_membership_user_room_index'. Processed 1 items in 7ms. (total_rate=0.14285714285714285/ms, current_rate=0.14285714285714285/ms, total_updated=1, batch_size=100)415machine # [976206.802336] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'delete_e2e_backup_keys_for_deactivated_users'416machine # [976206.808837] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'delete_e2e_backup_keys_for_deactivated_users'. Processed 0 items in 3ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)417machine: still waiting for container 'machine' to reach ready state...418machine # [976207.810876] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'profiles_full_user_id_key_idx'419machine # [976207.813031] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index profiles_full_user_id_key to profiles420machine # [976207.818394] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'profiles_full_user_id_key_idx'. Processed 1 items in 5ms. (total_rate=0.2/ms, current_rate=0.2/ms, total_updated=1, batch_size=100)421machine # [976208.821106] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'full_users_filters_unique_idx'422machine # [976208.822956] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index full_users_unique_idx to user_filters423machine # [976208.828243] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'full_users_filters_unique_idx'. Processed 1 items in 5ms. (total_rate=0.2/ms, current_rate=0.2/ms, total_updated=1, batch_size=100)424machine # [976209.830495] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'populate_full_user_id_profiles'425machine # [976209.837939] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'populate_full_user_id_profiles'. Processed 1 items in 6ms. (total_rate=0.16666666666666666/ms, current_rate=0.16666666666666666/ms, total_updated=1, batch_size=100)426machine # [976210.840533] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'populate_full_user_id_user_filters'427machine # [976210.848184] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'populate_full_user_id_user_filters'. Processed 1 items in 6ms. (total_rate=0.16666666666666666/ms, current_rate=0.16666666666666666/ms, total_updated=1, batch_size=100)428machine # [976211.851105] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'event_push_actions_staging_thread_id'429machine # [976211.852887] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Validating constraint event_push_actions_staging_thread_id to event_push_actions_staging430machine # [976211.855843] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'event_push_actions_staging_thread_id'. Processed 1 items in 3ms. (total_rate=0.3333333333333333/ms, current_rate=0.3333333333333333/ms, total_updated=1, batch_size=100)431machine # [976212.857955] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'event_push_actions_thread_id'432machine # [976212.859340] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Validating constraint event_push_actions_thread_id to event_push_actions433machine # [976212.863188] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'event_push_actions_thread_id'. Processed 1 items in 3ms. (total_rate=0.3333333333333333/ms, current_rate=0.3333333333333333/ms, total_updated=1, batch_size=100)434machine # [976212.864513] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Not starting on bg update event_push_drop_null_thread_id_indexes until event_push_summary_thread_id is done435machine # [976213.865783] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'event_push_summary_thread_id'436machine # [976213.867618] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Validating constraint event_push_summary_thread_id to event_push_summary437machine # [976213.870607] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'event_push_summary_thread_id'. Processed 1 items in 3ms. (total_rate=0.3333333333333333/ms, current_rate=0.3333333333333333/ms, total_updated=1, batch_size=100)438machine # [976214.872778] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'event_push_drop_null_thread_id_indexes'439machine # [976214.877477] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'event_push_drop_null_thread_id_indexes'. Processed 0 items in 3ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)440machine # [976215.880031] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'current_state_events_stream_ordering_idx'441machine # [976215.881914] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index current_state_events_stream_ordering_idx to current_state_events442machine # [976215.888020] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'current_state_events_stream_ordering_idx'. Processed 1 items in 6ms. (total_rate=0.16666666666666666/ms, current_rate=0.16666666666666666/ms, total_updated=1, batch_size=100)443machine # [976216.891362] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'local_current_membership_stream_ordering_idx'444machine # [976216.893179] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index local_current_membership_stream_ordering_idx to local_current_membership445machine # [976216.898793] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'local_current_membership_stream_ordering_idx'. Processed 1 items in 6ms. (total_rate=0.16666666666666666/ms, current_rate=0.16666666666666666/ms, total_updated=1, batch_size=100)446machine: still waiting for container 'machine' to reach ready state...447machine # [976217.901005] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'room_memberships_stream_ordering_idx'448machine # [976217.902900] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index room_memberships_stream_ordering_idx to room_memberships449machine # [976217.951982] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'room_memberships_stream_ordering_idx'. Processed 1 items in 49ms. (total_rate=0.02040816326530612/ms, current_rate=0.02040816326530612/ms, total_updated=1, batch_size=100)450machine # [976218.954851] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'event_forward_extremities_event_id_foreign_key_constraint_update'451machine # [976218.962554] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'event_forward_extremities_event_id_foreign_key_constraint_update'. Processed 100 items in 6ms. (total_rate=16.666666666666668/ms, current_rate=16.666666666666664/ms, total_updated=100, batch_size=100)452machine # [976219.964699] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'e2e_room_keys_index_room_id'453machine # [976219.966448] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index e2e_room_keys_room_id to e2e_room_keys454machine # [976219.980749] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'e2e_room_keys_index_room_id'. Processed 1 items in 14ms. (total_rate=0.07142857142857142/ms, current_rate=0.07142857142857142/ms, total_updated=1, batch_size=100)455machine # [976220.983214] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'room_account_data_index_room_id'456machine # [976220.984935] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index room_account_data_room_id to room_account_data457machine # [976220.990145] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'room_account_data_index_room_id'. Processed 1 items in 5ms. (total_rate=0.2/ms, current_rate=0.2/ms, total_updated=1, batch_size=100)458machine # [976221.641632] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-0] Dropped 0 items from caches459machine # [976221.750703] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-0] Rotating notifications460machine # [976221.753386] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-0] Rotating notifications up to: 1461machine # [976221.757469] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-0] Rotating notifications, handling 0 rows462machine # [976221.763262] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-0] Rotating notifications, deleted 0 push actions463machine # [976221.992860] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'event_push_summary_index_room_id'464machine # [976221.994656] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index event_push_summary_index_room_id to event_push_summary465machine # [976222.033189] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'event_push_summary_index_room_id'. Processed 1 items in 38ms. (total_rate=0.02631578947368421/ms, current_rate=0.02631578947368421/ms, total_updated=1, batch_size=100)466machine # [976223.035741] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'event_auth_chain_links_origin_index'467machine # [976223.037573] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index event_auth_chain_links_origin_index to event_auth_chain_links468machine # [976223.043208] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'event_auth_chain_links_origin_index'. Processed 1 items in 5ms. (total_rate=0.2/ms, current_rate=0.2/ms, total_updated=1, batch_size=100)469machine # [976224.045513] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'access_tokens_refresh_token_id_idx'470machine # [976224.047324] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index access_tokens_refresh_token_id_idx to access_tokens471machine # [976224.053703] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'access_tokens_refresh_token_id_idx'. Processed 1 items in 7ms. (total_rate=0.14285714285714285/ms, current_rate=0.14285714285714285/ms, total_updated=1, batch_size=100)472machine # [976225.055757] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'cleanup_device_federation_outbox'473machine # [976225.061068] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'cleanup_device_federation_outbox'. Processed 100 items in 3ms. (total_rate=33.333333333333336/ms, current_rate=33.33333333333333/ms, total_updated=100, batch_size=100)474machine # [976226.063277] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'receipts_room_id_event_id_index'475machine # [976226.064530] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index receipts_linearized_event_id to receipts_linearized476machine # [976226.109720] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'receipts_room_id_event_id_index'. Processed 1 items in 45ms. (total_rate=0.022222222222222223/ms, current_rate=0.022222222222222223/ms, total_updated=1, batch_size=100)477machine # [976227.112174] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'current_state_events_members_room_index'478machine # [976227.113221] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index current_state_events_members_room_index to current_state_events479machine # [976227.156499] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'current_state_events_members_room_index'. Processed 1 items in 44ms. (total_rate=0.022727272727272728/ms, current_rate=0.022727272727272728/ms, total_updated=1, batch_size=100)480machine # [976227.157475] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Not starting on bg update sliding_sync_joined_rooms_bg_update until sliding_sync_prefill_joined_rooms_to_recalculate_table_bg_update is done481machine: still waiting for container 'machine' to reach ready state...482machine # [976228.158331] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'sliding_sync_membership_snapshots_bg_update'483machine # [976228.176781] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'sliding_sync_membership_snapshots_bg_update'. Processed 0 items in 17ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)484machine # [976229.178278] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'sliding_sync_membership_snapshots_bg_update'485machine # [976229.183667] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'sliding_sync_membership_snapshots_bg_update'. Processed 0 items in 4ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)486machine # [976229.184987] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Not starting on bg update sliding_sync_joined_rooms_bg_update until sliding_sync_prefill_joined_rooms_to_recalculate_table_bg_update is done487machine # [976230.186130] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'sliding_sync_prefill_joined_rooms_to_recalculate_table_bg_update'488machine # [976230.206715] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'sliding_sync_prefill_joined_rooms_to_recalculate_table_bg_update'. Processed 0 items in 19ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)489machine # [976231.209036] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'sliding_sync_joined_rooms_bg_update'490machine # [976231.213693] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'sliding_sync_joined_rooms_bg_update'. Processed 0 items in 3ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)491machine # [976232.216491] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'sliding_sync_membership_snapshots_fix_forgotten_column_bg_update'492machine # [976232.221962] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'sliding_sync_membership_snapshots_fix_forgotten_column_bg_update'. Processed 0 items in 4ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)493machine # [976233.224239] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'add_otk_ts_added_index'494machine # [976233.225567] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index e2e_one_time_keys_json_user_id_device_id_algorithm_ts_added_idx to e2e_one_time_keys_json495machine # [976233.234623] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'add_otk_ts_added_index'. Processed 1 items in 9ms. (total_rate=0.1111111111111111/ms, current_rate=0.11111111111111112/ms, total_updated=1, batch_size=100)496machine # [976234.237364] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'current_state_delta_stream_room_index'497machine # [976234.238775] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index current_state_delta_stream_room_idx to current_state_delta_stream498machine # [976234.249142] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'current_state_delta_stream_room_index'. Processed 1 items in 10ms. (total_rate=0.1/ms, current_rate=0.1/ms, total_updated=1, batch_size=100)499machine # [976235.251116] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'sliding_sync_connection_room_configs_required_state_id_idx'500machine # [976235.252142] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index sliding_sync_connection_room_configs_required_state_id_idx to sliding_sync_connection_room_configs501machine # [976235.256142] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'sliding_sync_connection_room_configs_required_state_id_idx'. Processed 1 items in 4ms. (total_rate=0.25/ms, current_rate=0.25/ms, total_updated=1, batch_size=100)502machine # [976236.258088] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'events_received_ts_index'503machine # [976236.259093] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index received_ts_idx to events504machine # [976236.279493] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'events_received_ts_index'. Processed 1 items in 21ms. (total_rate=0.047619047619047616/ms, current_rate=0.047619047619047616/ms, total_updated=1, batch_size=100)505machine # [976237.281404] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'local_media_repository_sha256_idx'506machine # [976237.283219] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index local_media_repository_sha256 to local_media_repository507machine # [976237.316151] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'local_media_repository_sha256_idx'. Processed 1 items in 33ms. (total_rate=0.030303030303030304/ms, current_rate=0.030303030303030304/ms, total_updated=1, batch_size=100)508machine: still waiting for container 'machine' to reach ready state...509machine # [976238.318462] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'remote_media_cache_sha256_idx'510machine # [976238.320331] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index remote_media_cache_sha256 to remote_media_cache511machine # [976238.326335] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'remote_media_cache_sha256_idx'. Processed 1 items in 6ms. (total_rate=0.16666666666666666/ms, current_rate=0.16666666666666666/ms, total_updated=1, batch_size=100)512machine # [976239.328620] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'sliding_sync_membership_snapshots_membership_event_id_idx'513machine # [976239.330374] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index sliding_sync_membership_snapshots_membership_event_id_idx to sliding_sync_membership_snapshots514machine # [976239.341697] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'sliding_sync_membership_snapshots_membership_event_id_idx'. Processed 1 items in 12ms. (total_rate=0.08333333333333333/ms, current_rate=0.08333333333333333/ms, total_updated=1, batch_size=100)515machine # [976240.344215] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'mark_unreferenced_state_groups_for_deletion_bg_update'516machine # [976240.347828] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'mark_unreferenced_state_groups_for_deletion_bg_update'. Processed 100 items in 2ms. (total_rate=50.0/ms, current_rate=50.0/ms, total_updated=100, batch_size=100)517machine # [976241.349597] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'sliding_sync_membership_snapshots_user_id_stream_ordering'518machine # [976241.350691] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index sliding_sync_membership_snapshots_user_id_stream_ordering to sliding_sync_membership_snapshots519machine # [976241.356891] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'sliding_sync_membership_snapshots_user_id_stream_ordering'. Processed 1 items in 6ms. (total_rate=0.16666666666666666/ms, current_rate=0.16666666666666666/ms, total_updated=1, batch_size=100)520machine # [976242.358465] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'fixup_max_depth_cap'521machine # [976242.364396] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'fixup_max_depth_cap'. Processed 0 items in 5ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)522machine # [976243.366486] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'device_federation_inbox_received_ts_index'523machine # [976243.368817] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index device_federation_inbox_received_ts_index to device_federation_inbox524machine # [976243.385094] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'device_federation_inbox_received_ts_index'. Processed 1 items in 16ms. (total_rate=0.0625/ms, current_rate=0.0625/ms, total_updated=1, batch_size=100)525machine # [976244.386669] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'event_txn_id_device_id_txn_id2'526machine # [976244.387959] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index event_txn_id_device_id_txn_id2 to event_txn_id_device_id527machine # [976245.833190] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'event_txn_id_device_id_txn_id2'. Processed 1 items in 1445ms. (total_rate=0.0006920415224913495/ms, current_rate=0.0006920415224913496/ms, total_updated=1, batch_size=100)528machine # [976246.835793] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'delayed_events_idx'529machine # [976246.837635] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index delayed_events_idx to delayed_events530machine # [976246.983844] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'delayed_events_idx'. Processed 1 items in 146ms. (total_rate=0.00684931506849315/ms, current_rate=0.00684931506849315/ms, total_updated=1, batch_size=100)531machine: still waiting for container 'machine' to reach ready state...532machine # [976247.986370] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'redactions_recheck'533machine # [976247.991121] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'redactions_recheck'. Processed 0 items in 3ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)534machine # [976248.992739] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'device_lists_changes_in_room_inserted_ts_idx'535machine # [976248.994511] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index device_lists_changes_in_room_inserted_ts_idx to device_lists_changes_in_room536machine # [976249.062000] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'device_lists_changes_in_room_inserted_ts_idx'. Processed 1 items in 67ms. (total_rate=0.014925373134328358/ms, current_rate=0.014925373134328358/ms, total_updated=1, batch_size=100)537machine # [976250.064079] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'flag_existing_quarantined_media'538machine # [976250.065794] machine synapse[330]: synapse.storage.databases.main.room: [background_updates-0] Flagging existing quarantined media with local offset and remote offset /539machine # [976250.069980] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'flag_existing_quarantined_media'. Processed 0 items in 4ms. (total_rate=None/ms, current_rate=None/ms, total_updated=0, batch_size=100)540machine # [976251.071351] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'sliding_sync_connections_last_used_ts_idx'541machine # [976251.073133] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index sliding_sync_connections_last_used_ts_idx to sliding_sync_connections542machine # [976251.111103] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'sliding_sync_connections_last_used_ts_idx'. Processed 1 items in 38ms. (total_rate=0.02631578947368421/ms, current_rate=0.02631578947368421/ms, total_updated=1, batch_size=100)543machine # [976251.518072] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-1] Rotating notifications544machine # [976251.525886] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-1] Rotating notifications up to: 1545machine # [976251.528083] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-1] Rotating notifications, handling 0 rows546machine # [976251.532398] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-1] Rotating notifications, deleted 0 push actions547machine # [976251.643246] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-1] Dropped 0 items from caches548machine # [976251.655072] machine synapse[330]: synapse.util.task_scheduler: [task-delete_old_otks-0-delete_old_otks_task] Task complete: 0.005sec (0.001sec, 0.000sec) (0.001sec/0.004sec/2) [0 dbevts] None, None549machine # [976252.113241] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'sliding_sync_connection_lazy_members_conn_pos_idx'550machine # [976252.114420] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index sliding_sync_connection_lazy_members_conn_pos_idx to sliding_sync_connection_lazy_members551machine # [976252.117994] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'sliding_sync_connection_lazy_members_conn_pos_idx'. Processed 1 items in 3ms. (total_rate=0.3333333333333333/ms, current_rate=0.3333333333333333/ms, total_updated=1, batch_size=100)552machine # [976253.119655] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Starting update batch on background update 'device_lists_changes_in_room_unconverted_idx'553machine # [976253.121074] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Adding index device_lists_changes_in_room_unconverted_idx to device_lists_changes_in_room554machine # [976253.219702] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] Running background update 'device_lists_changes_in_room_unconverted_idx'. Processed 1 items in 99ms. (total_rate=0.010101010101010102/ms, current_rate=0.010101010101010102/ms, total_updated=1, batch_size=100)555machine # [976253.220739] machine synapse[330]: synapse.storage.background_updates: [background_updates-0] No more background updates to do. Unscheduling background update task.556machine: still waiting for container 'machine' to reach ready state...557machine: still waiting for container 'machine' to reach ready state...558machine # [976269.180922] machine systemd[1]: systemd-machine-id-commit.service: start operation timed out. Terminating.559machine: still waiting for container 'machine' to reach ready state...560machine # [976281.641817] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-2] Dropped 0 items from caches561machine # [976281.656960] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-2] Rotating notifications562machine # [976281.658658] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-2] Rotating notifications up to: 1563machine # [976281.660489] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-2] Rotating notifications, handling 0 rows564machine # [976281.798522] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-2] Rotating notifications, deleted 0 push actions565machine: still waiting for container 'machine' to reach ready state...566machine: still waiting for container 'machine' to reach ready state...567machine: still waiting for container 'machine' to reach ready state...568machine # [976311.517179] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-3] Rotating notifications569machine # [976311.518087] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-3] Rotating notifications up to: 1570machine # [976311.519591] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-3] Rotating notifications, handling 0 rows571machine # [976311.523346] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-3] Rotating notifications, deleted 0 push actions572machine # [976311.641671] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-3] Dropped 0 items from caches573machine: still waiting for container 'machine' to reach ready state...574machine: still waiting for container 'machine' to reach ready state...575machine: still waiting for container 'machine' to reach ready state...576machine # [976341.642272] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-4] Dropped 0 items from caches577machine # [976341.845268] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-4] Rotating notifications578machine # [976341.846810] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-4] Rotating notifications up to: 1579machine # [976341.849121] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-4] Rotating notifications, handling 0 rows580machine # [976341.853867] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-4] Rotating notifications, deleted 0 push actions581machine: still waiting for container 'machine' to reach ready state...582machine: still waiting for container 'machine' to reach ready state...583machine # [976359.289069] machine systemd[1]: systemd-machine-id-commit.service: State 'stop-sigterm' timed out. Killing.584machine # [976359.289135] machine systemd[1]: systemd-machine-id-commit.service: Killing process 133 (systemd-machine) with signal SIGKILL.585machine: still waiting for container 'machine' to reach ready state...586machine # [976371.601996] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-5] Rotating notifications587machine # [976371.603789] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-5] Rotating notifications up to: 1588machine # [976371.607379] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-5] Rotating notifications, handling 0 rows589machine # [976371.615246] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-5] Rotating notifications, deleted 0 push actions590machine # [976371.641837] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-5] Dropped 0 items from caches591machine: still waiting for container 'machine' to reach ready state...592machine: still waiting for container 'machine' to reach ready state...593machine: still waiting for container 'machine' to reach ready state...594machine # [976401.521328] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-6] Rotating notifications595machine # [976401.522892] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-6] Rotating notifications up to: 1596machine # [976401.525331] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-6] Rotating notifications, handling 0 rows597machine # [976401.529478] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-6] Rotating notifications, deleted 0 push actions598machine # [976401.642121] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-6] Dropped 0 items from caches599machine: still waiting for container 'machine' to reach ready state...600machine: still waiting for container 'machine' to reach ready state...601machine: still waiting for container 'machine' to reach ready state...602machine # [976431.641696] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-7] Dropped 0 items from caches603machine # [976431.927607] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-7] Rotating notifications604machine # [976431.929455] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-7] Rotating notifications up to: 1605machine # [976431.932688] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-7] Rotating notifications, handling 0 rows606machine # [976431.940984] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-7] Rotating notifications, deleted 0 push actions607machine: still waiting for container 'machine' to reach ready state...608machine: still waiting for container 'machine' to reach ready state...609machine # [976449.430926] machine systemd[1]: systemd-machine-id-commit.service: Processes still around after SIGKILL. Ignoring.610machine: still waiting for container 'machine' to reach ready state...611machine # [976461.526765] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-8] Rotating notifications612machine # [976461.528756] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-8] Rotating notifications up to: 1613machine # [976461.532757] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-8] Rotating notifications, handling 0 rows614machine # [976461.537586] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-8] Rotating notifications, deleted 0 push actions615machine # [976461.642067] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-8] Dropped 0 items from caches616machine: still waiting for container 'machine' to reach ready state...617machine: still waiting for container 'machine' to reach ready state...618machine # [976483.649049] machine postgres[285]: [285] LOG: checkpoint starting: time619machine: still waiting for container 'machine' to reach ready state...620machine # [976491.518279] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-9] Rotating notifications621machine # [976491.519747] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-9] Rotating notifications up to: 1622machine # [976491.521386] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-9] Rotating notifications, handling 0 rows623machine # [976491.526520] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-9] Rotating notifications, deleted 0 push actions624machine # [976491.641563] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-9] Dropped 0 items from caches625machine # [976491.677629] machine synapse[330]: synapse.storage.databases.main.metrics: [generate_user_daily_visits-0] Calling _generate_user_daily_visits626machine: still waiting for container 'machine' to reach ready state...627machine: still waiting for container 'machine' to reach ready state...628machine: still waiting for container 'machine' to reach ready state...629machine # [976521.518077] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-10] Rotating notifications630machine # [976521.519729] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-10] Rotating notifications up to: 1631machine # [976521.522425] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-10] Rotating notifications, handling 0 rows632machine # [976521.526963] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-10] Rotating notifications, deleted 0 push actions633machine # [976521.641737] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-10] Dropped 0 items from caches634machine: still waiting for container 'machine' to reach ready state...635machine: still waiting for container 'machine' to reach ready state...636machine # [976539.680919] machine systemd[1]: systemd-machine-id-commit.service: State 'final-sigterm' timed out. Killing.637machine # [976539.681005] machine systemd[1]: systemd-machine-id-commit.service: Killing process 133 (systemd-machine) with signal SIGKILL.638machine: still waiting for container 'machine' to reach ready state...639machine # [976551.516344] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-11] Rotating notifications640machine # [976551.517651] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-11] Rotating notifications up to: 1641machine # [976551.519580] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-11] Rotating notifications, handling 0 rows642machine # [976551.522757] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-11] Rotating notifications, deleted 0 push actions643machine # [976551.641171] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-11] Dropped 0 items from caches644machine: still waiting for container 'machine' to reach ready state...645machine: still waiting for container 'machine' to reach ready state...646machine: still waiting for container 'machine' to reach ready state...647machine # [976581.642158] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-12] Dropped 0 items from caches648machine # [976581.720030] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-12] Rotating notifications649machine # [976581.725970] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-12] Rotating notifications up to: 1650machine # [976581.728867] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-12] Rotating notifications, handling 0 rows651machine # [976581.733855] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-12] Rotating notifications, deleted 0 push actions652machine: still waiting for container 'machine' to reach ready state...653machine: still waiting for container 'machine' to reach ready state...654machine: still waiting for container 'machine' to reach ready state...655machine # [976611.518182] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-13] Rotating notifications656machine # [976611.519880] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-13] Rotating notifications up to: 1657machine # [976611.522543] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-13] Rotating notifications, handling 0 rows658machine # [976611.526621] machine synapse[330]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-13] Rotating notifications, deleted 0 push actions659machine # [976611.641580] machine synapse[330]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-13] Dropped 0 items from caches660machine: still waiting for container 'machine' to reach ready state...661machine: still waiting for container 'machine' to reach ready state...662machine: (finished: waiting for unit matrix-synapse, in 452.41 seconds)663machine: must succeed: nc -z -v ::1 8008664Connection to ::1 8008 port [tcp/http-alt] succeeded!665machine: (finished: must succeed: nc -z -v ::1 8008, in 0.02 seconds)666machine: waiting for success: curl -Ssf -L http://localhost/_matrix/static/ -H 'Host: matrix.clan.test'667machine # [976629.931015] machine systemd[1]: systemd-machine-id-commit.service: Processes still around after final SIGKILL. Entering failed mode.668machine # [976629.931044] machine systemd[1]: systemd-machine-id-commit.service: Failed with result 'timeout'.669machine # [976629.931294] machine systemd[1]: systemd-machine-id-commit.service: Unit process 133 (systemd-machine) remains running after unit stopped.670machine # [976629.932158] machine systemd[1]: Failed to start Save Transient machine-id to Disk.671machine # [976629.942031] machine systemd[1]: Startup finished in 7min 31.495s.672machine: (finished: waiting for success: curl -Ssf -L http://localhost/_matrix/static/ -H 'Host: matrix.clan.test', in 0.04 seconds)673machine # [976630.267081] machine synapse[330]: synapse.access.http.8008: [GET-4] ::1 - 8008 - {None} Processed request: 0.004sec/-0.000sec ru=(0.000sec, 0.004sec) db=(0.000sec/0.000sec/0) 10145B 200 "GET /_matrix/static/ HTTP/1.1" "curl/8.21.0" [0 dbevts]674machine # [976630.268948] machine nginx[271]: machine nginx: ::1 - - [15/Sep/2026:14:44:10 +0000] "GET /_matrix/static/ HTTP/1.1" 200 10145 "-" "curl/8.21.0"675machine # [976630.287234] machine systemd[1]: Stopping Synapse Matrix homeserver...676machine # [976630.288853] machine synapse[330]: twisted: [sentinel] Received SIGTERM, shutting down.677machine # [976630.290031] machine synapse[330]: synapse.storage.databases.main.lock: [LockStore._on_shutdown-0] Dropping held locks due to shutdown678machine # [976630.290440] machine synapse[330]: synapse.storage.databases.main.lock: [LockStore._on_shutdown-0] Dropped locks due to shutdown679machine # [976630.291555] machine synapse[330]: synapse.handlers.presence: [PresenceHandler._on_shutdown-0] Performing _on_shutdown. Persisting 0 unpersisted changes680machine # [976630.291657] machine synapse[330]: synapse.handlers.presence: [PresenceHandler._on_shutdown-0] Finished _on_shutdown681machine # [976630.292250] machine synapse[330]: synapse.app._base: [log_shutdown] Shutting down...682machine # [976630.293723] machine synapse[330]: twisted: [sentinel] (TCP Port 8008 Closed)683machine # [976630.310520] machine synapse[330]: twisted: [sentinel] Main loop terminated.684machine # [976630.576331] machine systemd[1]: matrix-synapse.service: Deactivated successfully.685machine # [976630.576747] machine systemd[1]: Stopped Synapse Matrix homeserver.686machine # [976630.576790] machine systemd[1]: matrix-synapse.service: Consumed 9.897s CPU time over 7min 25.981s wall clock time.687machine # [976630.610224] machine systemd[1]: Starting Synapse Matrix homeserver...688machine # [976633.260152] machine postgres[285]: [285] LOG: checkpoint complete: wrote 1424 buffers (8.7%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 1 recycled; write=149.028 s, sync=0.391 s, total=149.612 s; sync files=1286, longest=0.304 s, average=0.001 s; distance=9324 kB, estimate=9324 kB; lsn=0/2081E80, redo lsn=0/2081488689machine # [976636.435933] machine synapse_homeserver[421]: This server is configured to use 'matrix.org' as its trusted key server via the690machine # [976636.435933] machine synapse_homeserver[421]: 'trusted_key_servers' config option. 'matrix.org' is a good choice for a key691machine # [976636.435933] machine synapse_homeserver[421]: server since it is long-lived, stable and trusted. However, some admins may692machine # [976636.435933] machine synapse_homeserver[421]: wish to use another server for this purpose.693machine # [976636.435933] machine synapse_homeserver[421]: To suppress this warning and continue using 'matrix.org', admins should set694machine # [976636.435933] machine synapse_homeserver[421]: 'suppress_key_server_warning' to 'true' in homeserver.yaml.695machine # [976636.435933] machine synapse_homeserver[421]: --------------------------------------------------------------------------------696machine # [976636.492059] machine synapse[421]: synapse.config.logger: [main] ***** STARTING SERVER *****697machine # [976636.492173] machine synapse[421]: synapse.config.logger: [main] Server /nix/store/w1dj3n12wq2npv51a0kfsz0aj1wzqmzy-matrix-synapse-1.160.0/bin/synapse_homeserver version 1.160.0698machine # [976636.492237] machine synapse[421]: synapse.config.logger: [main] Copyright (c) 2023 New Vector, Inc699machine # [976636.492295] machine synapse[421]: synapse.config.logger: [main] Licensed under the AGPL 3.0 license. Website: https://github.com/element-hq/synapse700machine # [976636.492514] machine synapse[421]: synapse.config.logger: [main] Server hostname: clan.test701machine # [976636.492583] machine synapse[421]: synapse.config.logger: [main] Public Base URL: https://clan.test/702machine # [976636.492645] machine synapse[421]: synapse.config.logger: [main] Instance name: master703machine # [976636.492706] machine synapse[421]: synapse.config.logger: [main] Twisted reactor: EPollReactor704machine # [976636.492767] machine synapse[421]: synapse.app.homeserver: [main] Setting up server705machine # [976636.492831] machine synapse[421]: synapse.server: [main] Setting up.706machine # [976636.498234] machine synapse[421]: synapse.storage.databases: [main] [database config 'master']: Checking database server707machine # [976636.499465] machine synapse[421]: synapse.storage.databases: [main] [database config 'master']: Preparing for databases ['main', 'state']708machine # [976636.499684] machine synapse[421]: synapse.storage.prepare_database: [main] ['main', 'state']: Checking existing schema version709machine # [976636.502021] machine synapse[421]: synapse.storage.prepare_database: [main] ['main', 'state']: Existing schema is 94 (+13 deltas)710machine # [976636.502112] machine synapse[421]: synapse.storage.databases.main: [main] Checking database for consistency with configuration...711machine # [976636.502841] machine synapse[421]: synapse.storage.prepare_database: [main] Applying schema deltas for v94712machine # [976636.504513] machine synapse[421]: synapse.storage.prepare_database: [main] Schema now up to date713machine # [976636.505226] machine synapse[421]: synapse.storage.databases: [main] [database config 'master']: Starting 'main' database714machine # [976636.530364] machine synapse[421]: synapse.storage.util.id_generators: [main] Initialising stream generator for push_rules(id): 1715machine # [976636.530938] machine synapse[421]: synapse.storage.util.id_generators: [main] Initialising stream generator for push_rules_enable(id): 1716machine # [976636.538185] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [main] Searching for stream ordering 1 month ago717machine # [976636.538535] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [main] Found stream ordering 1 month ago: it's 0718machine # [976636.538624] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [main] Searching for stream ordering 1 day ago719machine # [976636.538914] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [main] Found stream ordering 1 day ago: it's 0720machine # [976636.543714] machine synapse[421]: synapse.storage.util.id_generators: [main] Initialising stream generator for access_tokens(id): 3721machine # [976636.544447] machine synapse[421]: synapse.storage.util.id_generators: [main] Initialising stream generator for refresh_tokens(id): 1722machine # [976636.548088] machine synapse[421]: synapse.storage.util.id_generators: [main] Initialising stream generator for event_reports(id): 1723machine # [976636.548596] machine synapse[421]: synapse.storage.util.id_generators: [main] Initialising stream generator for room_reports(id): 1724machine # [976636.549172] machine synapse[421]: synapse.storage.util.id_generators: [main] Initialising stream generator for user_reports(id): 1725machine # [976636.558906] machine synapse[421]: synapse.storage.databases: [main] [database config 'master']: Starting 'state' database726machine # [976636.560885] machine synapse[421]: synapse.storage.databases: [main] [database config 'master']: prepared727machine # [976636.561049] machine synapse[421]: synapse.server: [main] Finished setting up.728machine # [976636.561371] machine synapse[421]: twisted: [main] Redirected stdout/stderr to logs729machine # [976636.561535] machine synapse[421]: synapse.app.homeserver: [main] Running730machine # [976636.566671] machine synapse[421]: synapse.app.homeserver: [main] Set file limit to: 524288731machine # [976636.600940] machine synapse[421]: synapse.push.pusher: [call_when_running] email enable notifs: False732machine # [976636.625183] machine synapse[421]: synapse.federation.federation_server: [call_when_running] Registering federation query handler for 'profile'733machine # [976636.626500] machine synapse[421]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.device_list_update'734machine # [976636.626967] machine synapse[421]: synapse.util.caches.lrucache: [call_when_running] Expiring LRU caches after 1800 seconds735machine # [976636.630381] machine synapse[421]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.presence'736machine # [976636.630733] machine synapse[421]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.typing'737machine # [976636.632527] machine synapse[421]: synapse.federation.federation_server: [call_when_running] Registering federation query handler for 'directory'738machine # [976636.638561] machine synapse[421]: synapse.handlers.deactivate_account: [user_parter_loop-0] Starting user parter739machine # [976636.639988] machine synapse[421]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.receipt'740machine # [976636.640258] machine synapse[421]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.signing_key_update'741machine # [976636.640344] machine synapse[421]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'org.matrix.signing_key_update'742machine # [976636.640418] machine synapse[421]: synapse.federation.federation_server: [call_when_running] Registering federation query handler for 'client_keys'743machine # [976636.641002] machine synapse[421]: synapse.federation.federation_server: [call_when_running] Registering federation EDU handler for 'm.direct_to_device'744machine # [976636.647343] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.health.HealthResource object at 0xffffec676220> to path b'/health'745machine # [976636.647439] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <twisted.web.resource.EncodingResourceWrapper object at 0xffffec68f720> to path b'/_matrix/client'746machine # [976636.647533] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <twisted.web.resource.Resource object at 0xffffec8b5420> to path b'/.well-known'747machine # [976636.647602] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.http.server.JsonResource object at 0xffffec68f8a0> to path b'/_synapse/admin'748machine # [976637.461625] machine 5kd0fcsj2nc98pgm5jphfg1gy8k5ly1w-matrix-synapse-create-users[446]: Connection to ::1 8008 port [tcp/http-alt] succeeded!749machine # [976636.647676] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.synapse.client.pick_idp.PickIdpResource object at 0xffffec8b58a0> to path b'/_synapse/client/pick_idp'750machine # [976636.647754] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <twisted.web.resource.Resource object at 0xffffec3c7b60> to path b'/_synapse/client/pick_username'751machine # [976636.647826] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.synapse.client.new_user_consent.NewUserConsentResource object at 0xffffec8b5ea0> to path b'/_synapse/client/new_user_consent'752machine # [976636.647895] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.synapse.client.sso_register.SsoRegisterResource object at 0xffffec8b6020> to path b'/_synapse/client/sso_register'753machine # [976636.647962] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.synapse.client.unsubscribe.UnsubscribeResource object at 0xffffec8b61a0> to path b'/_synapse/client/unsubscribe'754machine # [976636.648046] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.synapse.client.media_upload_limit_exceeded.MediaUploadLimitExceededResource object at 0xffffec8b6320> to path b'/_synapse/client/media_upload_limit_exceeded'755machine # [976636.648123] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching FilePath('/nix/store/w1dj3n12wq2npv51a0kfsz0aj1wzqmzy-matrix-synapse-1.160.0/lib/python3.14/site-packages/synapse/static') to path b'/_matrix/static'756machine # [976636.648189] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.media.media_repository_resource.MediaRepositoryResource object at 0xffffec8b67a0> to path b'/_matrix/media/r0'757machine # [976636.648252] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.media.media_repository_resource.MediaRepositoryResource object at 0xffffec8b67a0> to path b'/_matrix/media/v3'758machine # [976636.648317] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.media.media_repository_resource.MediaRepositoryResource object at 0xffffec8b67a0> to path b'/_matrix/media/v1'759machine # [976636.648383] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.federation.transport.server.TransportLayerServer object at 0xffffec8b73a0> to path b'/_matrix/federation'760machine # [976636.648449] machine synapse[421]: synapse.util.httpresourcetree: [call_when_running] Attaching <synapse.rest.key.v2.KeyResource object at 0xffffec8ba520> to path b'/_matrix/key'761machine # [976636.650944] machine synapse[421]: twisted: [call_when_running] SynapseSite starting on 8008762machine # [976636.651149] machine synapse[421]: synapse.app._base: [call_when_running] Synapse now listening on TCP port 8008763machine # [976636.654043] machine synapse[421]: synapse.app._base: [call_when_running] garbage collector: Freezing all allocated objects in the hopes that (almost) everything currently allocated are things that will be used by the homeserver for the rest of time. Doing so means less work each GC (hopefully).764machine # [976636.738467] machine synapse[421]: synapse.storage.background_updates: [background_updates-0] Starting background schema updates for database master765machine # [976636.739110] machine synapse[421]: synapse.handlers.deactivate_account: [user_parter_loop-0] User parter finished: stopping766machine # [976636.742029] machine synapse[421]: synapse.push.pusherpool: [start_pushers-0] Started pushers767machine # [976636.744085] machine synapse[421]: synapse.storage.background_updates: [background_updates-0] No more background updates to do. Unscheduling background update task.768machine # [976637.564045] machine synapse[421]: synapse.access.http.8008: [GET-0] ::1 - 8008 - {None} Processed request: 0.001sec/0.001sec ru=(0.002sec, 0.000sec) db=(0.000sec/0.000sec/0) 140B 200 "GET /_synapse/admin/v1/register HTTP/1.1" "python-requests/2.34.2" [0 dbevts]769machine # [976637.816164] machine synapse[421]: synapse.http.server: [POST-1] <XForwardedForRequest at 0xffffec39f660 method='POST' uri='/_synapse/admin/v1/register' clientproto='HTTP/1.1' site='8008'> SynapseError: 400 - User ID already taken.770machine # [976637.817311] machine synapse[421]: synapse.access.http.8008: [POST-1] ::1 - 8008 - {None} Processed request: 0.248sec/0.000sec ru=(0.243sec, 0.000sec) db=(0.000sec/0.001sec/1) 60B 400 "POST /_synapse/admin/v1/register HTTP/1.1" "python-requests/2.34.2" [0 dbevts]771machine # [976637.819178] machine 5kd0fcsj2nc98pgm5jphfg1gy8k5ly1w-matrix-synapse-create-users[447]: Sending registration request...772machine # [976637.819178] machine 5kd0fcsj2nc98pgm5jphfg1gy8k5ly1w-matrix-synapse-create-users[447]: User already exists. Skipping.773machine # [976638.433110] machine synapse[421]: synapse.access.http.8008: [GET-2] ::1 - 8008 - {None} Processed request: 0.000sec/0.000sec ru=(0.000sec, 0.000sec) db=(0.000sec/0.000sec/0) 140B 200 "GET /_synapse/admin/v1/register HTTP/1.1" "python-requests/2.34.2" [0 dbevts]774machine # [976638.671209] machine synapse[421]: synapse.http.server: [POST-3] <XForwardedForRequest at 0xffffec39af20 method='POST' uri='/_synapse/admin/v1/register' clientproto='HTTP/1.1' site='8008'> SynapseError: 400 - User ID already taken.775machine # [976638.672336] machine synapse[421]: synapse.access.http.8008: [POST-3] ::1 - 8008 - {None} Processed request: 0.236sec/0.000sec ru=(0.229sec, 0.000sec) db=(0.000sec/0.002sec/1) 60B 400 "POST /_synapse/admin/v1/register HTTP/1.1" "python-requests/2.34.2" [0 dbevts]776machine # [976638.673882] machine 5kd0fcsj2nc98pgm5jphfg1gy8k5ly1w-matrix-synapse-create-users[453]: Sending registration request...777machine # [976638.673882] machine 5kd0fcsj2nc98pgm5jphfg1gy8k5ly1w-matrix-synapse-create-users[453]: User already exists. Skipping.778machine: waiting for unit matrix-synapse779machine: (finished: waiting for unit matrix-synapse, in 0.02 seconds)780machine: must succeed: nc -z -v ::1 8008781Connection to ::1 8008 port [tcp/http-alt] succeeded!782machine: (finished: must succeed: nc -z -v ::1 8008, in 0.01 seconds)783machine: must succeed: curl -Ssf -L http://localhost/_matrix/static/ -H 'Host: matrix.clan.test'784machine: (finished: must succeed: curl -Ssf -L http://localhost/_matrix/static/ -H 'Host: matrix.clan.test', in 0.02 seconds)785(finished: run the VM test script, in 461.04 seconds)786machine # [976638.782772] machine systemd[1]: Started Synapse Matrix homeserver.787machine # [976638.839087] machine nginx[271]: 2026/09/15 14:44:18 [error] 271#271: *3 connect() failed (111: Connection refused) while connecting to upstream, client: ::1, server: matrix.clan.test, request: "GET /_matrix/static/ HTTP/1.1", upstream: "http://127.0.0.1:8008/_matrix/static/", host: "matrix.clan.test"788machine # [976638.842198] machine synapse[421]: synapse.access.http.8008: [GET-4] ::1 - 8008 - {None} Processed request: 0.001sec/-0.000sec ru=(0.000sec, 0.000sec) db=(0.000sec/0.000sec/0) 10145B 200 "GET /_matrix/static/ HTTP/1.1" "curl/8.21.0" [0 dbevts]789machine # [976638.843178] machine nginx[271]: machine nginx: ::1 - - [15/Sep/2026:14:44:18 +0000] "GET /_matrix/static/ HTTP/1.1" 200 10145 "-" "curl/8.21.0"790machine # [976666.547027] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-0] Rotating notifications791machine # [976666.548724] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-0] Rotating notifications up to: 1792machine # [976666.550469] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-0] Rotating notifications, handling 0 rows793machine # [976666.554825] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-0] Rotating notifications, deleted 0 push actions794machine # [976666.628754] machine synapse[421]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-0] Dropped 0 items from caches795machine # [976696.543013] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-1] Rotating notifications796machine # [976696.545509] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-1] Rotating notifications up to: 1797machine # [976696.547873] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-1] Rotating notifications, handling 0 rows798machine # [976696.551460] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-1] Rotating notifications, deleted 0 push actions799machine # [976696.627808] machine synapse[421]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-1] Dropped 0 items from caches800machine # [976726.544384] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-2] Rotating notifications801machine # [976726.546789] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-2] Rotating notifications up to: 1802machine # [976726.550369] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-2] Rotating notifications, handling 0 rows803machine # [976726.554482] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-2] Rotating notifications, deleted 0 push actions804machine # [976726.628035] machine synapse[421]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-2] Dropped 0 items from caches805machine # [976756.543373] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-3] Rotating notifications806machine # [976756.544970] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-3] Rotating notifications up to: 1807machine # [976756.547978] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-3] Rotating notifications, handling 0 rows808machine # [976756.552524] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-3] Rotating notifications, deleted 0 push actions809machine # [976756.628908] machine synapse[421]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-3] Dropped 0 items from caches810machine # [976783.300655] machine postgres[285]: [285] LOG: checkpoint starting: time811machine # [976785.550981] machine postgres[285]: [285] LOG: checkpoint complete: wrote 15 buffers (0.1%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=1.602 s, sync=0.152 s, total=2.251 s; sync files=16, longest=0.151 s, average=0.010 s; distance=13 kB, estimate=8393 kB; lsn=0/2084A70, redo lsn=0/2084A18812machine # [976786.544778] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-4] Rotating notifications813machine # [976786.547330] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-4] Rotating notifications up to: 1814machine # [976786.550834] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-4] Rotating notifications, handling 0 rows815machine # [976786.555751] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-4] Rotating notifications, deleted 0 push actions816machine # [976786.627627] machine synapse[421]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-4] Dropped 0 items from caches817machine # [976816.628672] machine synapse[421]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-5] Dropped 0 items from caches818machine # [976816.875185] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-5] Rotating notifications819machine # [976816.876816] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-5] Rotating notifications up to: 1820machine # [976816.878628] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-5] Rotating notifications, handling 0 rows821machine # [976816.882556] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-5] Rotating notifications, deleted 0 push actions822machine # [976846.628252] machine synapse[421]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-6] Dropped 0 items from caches823machine # [976846.988128] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-6] Rotating notifications824machine # [976846.990841] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-6] Rotating notifications up to: 1825machine # [976846.993824] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-6] Rotating notifications, handling 0 rows826machine # [976846.997199] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-6] Rotating notifications, deleted 0 push actions827machine # [976876.628773] machine synapse[421]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-7] Dropped 0 items from caches828machine # [976876.865333] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-7] Rotating notifications829machine # [976876.867126] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-7] Rotating notifications up to: 1830machine # [976876.869813] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-7] Rotating notifications, handling 0 rows831machine # [976876.882106] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-7] Rotating notifications, deleted 0 push actions832machine # [976906.542644] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-8] Rotating notifications833machine # [976906.544316] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-8] Rotating notifications up to: 1834machine # [976906.547246] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-8] Rotating notifications, handling 0 rows835machine # [976906.551641] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-8] Rotating notifications, deleted 0 push actions836machine # [976906.628034] machine synapse[421]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-8] Dropped 0 items from caches837machine # [976936.628790] machine synapse[421]: synapse.util.caches.lrucache: [LruCache._expire_old_entries-9] Dropped 0 items from caches838machine # [976936.655824] machine synapse[421]: synapse.storage.databases.main.metrics: [generate_user_daily_visits-0] Calling _generate_user_daily_visits839machine # [976937.183342] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-9] Rotating notifications840machine # [976937.187555] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-9] Rotating notifications up to: 1841machine # [976937.190299] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-9] Rotating notifications, handling 0 rows842machine # [976937.193836] machine synapse[421]: synapse.storage.databases.main.event_push_actions: [rotate_notifs-9] Rotating notifications, deleted 0 push actions843test script finished in 777.01s844cleanup845kill NspawnMachine (pid 51)846Container machine terminated by signal KILL.847(finished: cleanup, in 0.27 seconds)