enihcam/systemd-homed.log

## systemd-homed.log
Apr 26 23:12:40 archlinux systemd-homed[696]: sd-device-monitor(n/a): Unable to get network namespace of udev netlink socket, unable to determine if we are in host netns, ignoring: Operation not permitted
Apr 26 23:12:40 archlinux systemd-homed[696]: User record testuser.identity is signed only by us, accepting.
Apr 26 23:12:40 archlinux systemd-homed[696]: Not scheduling rebalancing, not needed.
Apr 26 23:12:40 archlinux systemd-homed[696]: Added registered home for user testuser.
Apr 26 23:12:40 archlinux systemd-homed[696]: Found an image for user testuser which already has a record, skipping.
Apr 26 23:12:40 archlinux systemd-homed[696]: Found partition (/sys/devices/pci0000:00/0000:00:06.0/virtio1/block/vda/vda1) we don't care about, ignoring.
Apr 26 23:12:40 archlinux systemd-homed[696]: Found partition (/sys/devices/pci0000:00/0000:00:06.0/virtio1/block/vda/vda2) we don't care about, ignoring.
Apr 26 23:12:40 archlinux systemd-homed[696]: Bus n/a: changing state AUTHENTICATING → HELLO
Apr 26 23:12:40 archlinux systemd-homed[696]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=Hello cookie=1 reply_cookie=0 signature=n/a error-name=n/a error-message=n/a
Apr 26 23:12:40 archlinux systemd-homed[696]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=RequestName cookie=2 reply_cookie=0 signature=su error-name=n/a error-message=n/a
Apr 26 23:12:40 archlinux systemd-homed[696]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/home1/home interface=org.freedesktop.DBus.ObjectManager member=InterfacesAdded cookie=3 reply_cookie=0 signature=oa{sa{sv}} error-name=n/a error-message=n/a
Apr 26 23:12:40 archlinux systemd-homed[696]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/home1 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=4 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
Apr 26 23:12:40 archlinux systemd-homed[696]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.4 path=n/a interface=n/a member=n/a  cookie=1 reply_cookie=1 signature=s error-name=n/a error-message=n/a
Apr 26 23:12:40 archlinux systemd-homed[696]: Bus n/a: changing state HELLO → RUNNING
Apr 26 23:12:40 archlinux systemd-homed[696]: Got message type=signal sender=org.freedesktop.DBus destination=:1.4 path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameAcquired  cookie=2 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Apr 26 23:12:40 archlinux systemd-homed[696]: Got message type=signal sender=org.freedesktop.DBus destination=:1.4 path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameAcquired  cookie=3 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Apr 26 23:12:40 archlinux systemd-homed[696]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.4 path=n/a interface=n/a member=n/a  cookie=4 reply_cookie=2 signature=u error-name=n/a error-message=n/a
Apr 26 23:12:40 archlinux systemd-homed[696]: Successfully acquired requested service name.
Apr 26 23:12:40 archlinux systemd[1]: Started Home Area Manager.
░░ Subject: A start job for unit systemd-homed.service has finished successfully
░░ Defined-By: systemd
░░ Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
░░
░░ A start job for unit systemd-homed.service has finished successfully.
░░
░░ The job identifier is 181.
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Setting state idle-server
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → processing-method
Apr 26 23:12:45 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":17,"goodAuthenticationCounter":16,"lastBadAuthenticationUSec":1682521916125873,"lastGoodAuthenticationUSec":1682521918601350,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":2,"state":"inactive","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138156847104,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processing-method → processed-method
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processed-method → idle-server
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Got POLLHUP from socket.
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → pending-disconnect
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processing-disconnect → disconnected
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Setting state idle-server
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"userName":"testuser","service":"io.systemd.Home"},"more":true}
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → processing-method-more
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processing-method-more → processed-method
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processed-method → idle-server
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Got POLLHUP from socket.
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → pending-disconnect
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processing-disconnect → disconnected
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Setting state idle-server
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"wheel","service":"io.systemd.Home"}}
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → processing-method
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processing-method → processed-method
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processed-method → idle-server
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Got POLLHUP from socket.
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → pending-disconnect
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processing-disconnect → disconnected
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Setting state idle-server
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → processing-method
Apr 26 23:12:45 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":17,"goodAuthenticationCounter":16,"lastBadAuthenticationUSec":1682521916125873,"lastGoodAuthenticationUSec":1682521918601350,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":2,"state":"inactive","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138156847104,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processing-method → processed-method
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processed-method → idle-server
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Got POLLHUP from socket.
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → pending-disconnect
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:45 archlinux systemd-homed[696]: varlink-11: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":17,"goodAuthenticationCounter":16,"lastBadAuthenticationUSec":1682521916125873,"lastGoodAuthenticationUSec":1682521918601350,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":2,"state":"inactive","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138156847104,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":17,"goodAuthenticationCounter":16,"lastBadAuthenticationUSec":1682521916125873,"lastGoodAuthenticationUSec":1682521918601350,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":2,"state":"inactive","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138156847104,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-11: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: Got message type=method_call sender=:1.5 destination=org.freedesktop.home1 path=/org/freedesktop/home1 interface=org.freedesktop.home1.Manager member=GetUserRecordByName  cookie=2 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetConnectionUnixUser cookie=5 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.4 path=n/a interface=n/a member=n/a  cookie=5 reply_cookie=5 signature=u error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: Sent message type=method_return sender=n/a destination=:1.5 path=n/a interface=n/a member=n/a cookie=6 reply_cookie=2 signature=sbo error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Got message type=method_call sender=:1.5 destination=org.freedesktop.home1 path=/org/freedesktop/home1 interface=org.freedesktop.home1.Manager member=AcquireHome  cookie=3 reply_cookie=0 signature=ssb error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Sending to worker: {"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":17,"goodAuthenticationCounter":16,"lastBadAuthenticationUSec":1682521916125873,"lastGoodAuthenticationUSec":1682521918601350,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":3}},"secret":{}}
Apr 26 23:12:51 archlinux systemd-homed[696]: Successfully forked off '(sd-homework)' as PID 707.
Apr 26 23:12:51 archlinux systemd-homed[696]: testuser: changing state inactive → activating-for-acquire
Apr 26 23:12:51 archlinux systemd-homework[707]: User record has no recovery keys, plaintext passwords not tested against it.
Apr 26 23:12:51 archlinux systemd-homework[707]: None of the supplied plaintext passwords unlock the user record's hashed passwords.
Apr 26 23:12:51 archlinux systemd-homed[696]: Worker reported error code ENOKEY.
Apr 26 23:12:51 archlinux systemd-homed[696]: Activation failed: Required key not available
Apr 26 23:12:51 archlinux systemd-homed[696]: Sent message type=error sender=n/a destination=:1.5 path=n/a interface=n/a member=n/a cookie=7 reply_cookie=3 signature=s error-name=org.freedesktop.home1.BadPassword error-message=Password for home testuser is incorrect or not sufficient for authentication.
Apr 26 23:12:51 archlinux systemd-homed[696]: testuser: changing state activating-for-acquire → inactive
Apr 26 23:12:51 archlinux systemd-homed[696]: Got notification that all sessions of user testuser ended, deactivating automatically.
Apr 26 23:12:51 archlinux systemd-homed[696]: Home testuser already deactivated, no automatic deactivation needed.
Apr 26 23:12:51 archlinux systemd-homed[696]: Got message type=method_call sender=:1.5 destination=org.freedesktop.home1 path=/org/freedesktop/home1 interface=org.freedesktop.home1.Manager member=AcquireHome  cookie=4 reply_cookie=0 signature=ssb error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Sending to worker: {"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"goodAuthenticationCounter":16,"lastGoodAuthenticationUSec":1682521918601350,"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4}},"secret":{"password":["12Wang17"]}}
Apr 26 23:12:51 archlinux systemd-homed[696]: Successfully forked off '(sd-homework)' as PID 708.
Apr 26 23:12:51 archlinux systemd-homed[696]: testuser: changing state inactive → activating-for-acquire
Apr 26 23:12:51 archlinux systemd-homework[708]: Provided password unlocks user record.
Apr 26 23:12:51 archlinux systemd-homework[708]: Mounting /run (n/a) on /run (MS_REC|MS_SLAVE "")...
Apr 26 23:12:51 archlinux systemd-homework[708]: Bind-mounting /home/testuser.homedir on /run/systemd/user-home-mount (MS_BIND "")...
Apr 26 23:12:51 archlinux systemd-homework[708]: Mounting /run/systemd/user-home-mount (MS_PRIVATE "")...
Apr 26 23:12:51 archlinux systemd-homework[708]: Remounting /run/systemd/user-home-mount (MS_NOSUID|MS_NODEV|MS_REMOUNT|MS_BIND "")...
Apr 26 23:12:51 archlinux systemd-homework[708]: Read embedded .identity file.
Apr 26 23:12:51 archlinux systemd-homework[708]: Provided password unlocks user record.
Apr 26 23:12:51 archlinux systemd-homework[708]: Reconciling embedded user identity completed (host and embedded version were identical).
Apr 26 23:12:51 archlinux systemd-homework[708]: Creating userns with mapping:
Apr 26 23:12:51 archlinux systemd-homework[708]: 0 0 60001
Apr 26 23:12:51 archlinux systemd-homework[708]: 65534 60143 1
Apr 26 23:12:51 archlinux systemd-homework[708]: 60513 60513 5021
Apr 26 23:12:51 archlinux systemd-homework[708]: 524288 524288 1878458369
Apr 26 23:12:51 archlinux systemd-homework[708]: 2147483646 2147483646 1
Apr 26 23:12:51 archlinux systemd-homework[708]: Successfully forked off '(sd-mkuserns)' as PID 709.
Apr 26 23:12:51 archlinux systemd-homework[708]: Applied uidmap mount to n/a. Mapping is 65534 → 60143.
Apr 26 23:12:51 archlinux systemd-homework[708]: Not updating embedded home record.
Apr 26 23:12:51 archlinux systemd-homework[708]: Recursive changing of ownership not necessary, skipped.
Apr 26 23:12:51 archlinux systemd-homework[708]: Synchronized disk.
Apr 26 23:12:51 archlinux systemd-homework[708]: Bind-mounting /run/systemd/user-home-mount on /home/testuser (MS_BIND "")...
Apr 26 23:12:51 archlinux systemd-homework[708]: Successfully unmounted /run/systemd/user-home-mount
Apr 26 23:12:51 archlinux systemd-homework[708]: Successfully unmounted /run/systemd/user-home-mount
Apr 26 23:12:51 archlinux systemd-homework[708]: Moving to final mount point /home/testuser completed.
Apr 26 23:12:51 archlinux systemd-homework[708]: Everything completed.
Apr 26 23:12:51 archlinux systemd-homed[696]: Got from worker: {"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"goodAuthenticationCounter":16,"lastGoodAuthenticationUSec":1682521918601350,"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4}},"binding":{"<MASKED>":{"imagePath":"/home/testuser.homedir","fileSystemType":"btrfs","homeDirectory":"/home/testuser","uid":60143,"gid":60143,"storage":"subvolume"}}}
Apr 26 23:12:51 archlinux systemd-homed[696]: Home testuser is signed exclusively by our key, accepting.
Apr 26 23:12:51 archlinux systemd-homed[696]: Activation of testuser completed.
Apr 26 23:12:51 archlinux systemd-homed[696]: Sent message type=method_return sender=n/a destination=:1.5 path=n/a interface=n/a member=n/a cookie=8 reply_cookie=4 signature=h error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: testuser: changing state activating-for-acquire → active
Apr 26 23:12:51 archlinux systemd-homed[696]: Successfully pinned home directory '/home/testuser'.
Apr 26 23:12:51 archlinux systemd-homed[696]: Not scheduling rebalancing, not needed.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: Got message type=method_call sender=:1.5 destination=org.freedesktop.home1 path=/org/freedesktop/home1 interface=org.freedesktop.home1.Manager member=GetUserRecordByName  cookie=5 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetConnectionUnixUser cookie=9 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.4 path=n/a interface=n/a member=n/a  cookie=6 reply_cookie=9 signature=u error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: Sent message type=method_return sender=n/a destination=:1.5 path=n/a interface=n/a member=n/a cookie=10 reply_cookie=5 signature=sbo error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"userName":"testuser","service":"io.systemd.Home"},"more":true}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"wheel","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"userName":"testuser","service":"io.systemd.Home"},"more":true}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"wheel","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"uid":60143,"service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"uid":60143,"service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"uid":60143,"service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"userName":"testuser","service":"io.systemd.Home"},"more":true}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"wheel","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: Got message type=method_call sender=:1.8 destination=org.freedesktop.home1 path=/org/freedesktop/home1 interface=org.freedesktop.home1.Manager member=GetUserRecordByName  cookie=2 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetConnectionUnixUser cookie=11 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.4 path=n/a interface=n/a member=n/a  cookie=7 reply_cookie=11 signature=u error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: Sent message type=method_return sender=n/a destination=:1.8 path=n/a interface=n/a member=n/a cookie=12 reply_cookie=2 signature=sbo error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Got message type=method_call sender=:1.8 destination=org.freedesktop.home1 path=/org/freedesktop/home1 interface=org.freedesktop.home1.Manager member=RefHome  cookie=3 reply_cookie=0 signature=sb error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetConnectionUnixUser cookie=13 reply_cookie=0 signature=s error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.4 path=n/a interface=n/a member=n/a  cookie=8 reply_cookie=13 signature=u error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: Sent message type=method_return sender=n/a destination=:1.8 path=n/a interface=n/a member=n/a cookie=14 reply_cookie=3 signature=h error-name=n/a error-message=n/a
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"userName":"testuser","service":"io.systemd.Home"},"more":true}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"wheel","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 81: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"uid":60143,"service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":true}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 81: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"userName":"testuser","service":"io.systemd.Home"},"more":true}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 81: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"wheel","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"userName":"testuser","service":"io.systemd.Home"},"more":true}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"wheel","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"tty","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"tty","service":"io.systemd.Home"},"more":true}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"uid":60143,"service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"uid":60143,"service":"io.systemd.Home"}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:12:51 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:12:51 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetUserRecord","parameters":{"userName":"testuser","service":"io.systemd.Home"}}
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:06 archlinux systemd-homed[696]: Failed to query btrfs subtree quota, ignoring: No data available
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"binding":{"<MASKED>":{"fileSystemType":"btrfs","gid":60143,"homeDirectory":"/home/testuser","imagePath":"/home/testuser.homedir","storage":"subvolume","uid":60143}},"disposition":"regular","lastChangeUSec":1682516200992882,"lastPasswordChangeUSec":1682515835044275,"memberOf":["wheel"],"perMachine":[{"matchMachineId":"<MASKED>","storage":"subvolume"}],"privileged":{"hashedPassword":["<MASKED>"],"sshAuthorizedKeys":["ssh-rsa <MASKED>"]},"signature":[{"data":"<MASKED>","key":"-----BEGIN PUBLIC KEY-----\n<MASKED>\n-----END PUBLIC KEY-----\n"}],"userName":"testuser","status":{"<MASKED>":{"badAuthenticationCounter":18,"lastBadAuthenticationUSec":1682521971068503,"rateLimitBeginUSec":1682521916112201,"rateLimitCount":4,"goodAuthenticationCounter":17,"lastGoodAuthenticationUSec":1682521971194526,"state":"active","service":"io.systemd.Home","diskSize":2147483648000,"diskFree":2138152943616,"diskCeiling":5497558138880,"diskFloor":5242880,"signedLocally":true,"fileSystemType":"btrfs"}}},"incomplete":false}}
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"gid":60143,"service":"io.systemd.Home"}}
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"record":{"groupName":"testuser","description":"Primary Group of User testuser","binding":{"<MASKED>":{"gid":60143}},"disposition":"regular","status":{"<MASKED>":{"service":"io.systemd.Home"}}}}}
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink: Connections of user 0: 0 (of 1024 max)
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"userName":"testuser","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:06 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"systemd-journal","service":"io.systemd.Home"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"systemd-journal","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"gid":998,"service":"io.systemd.Home"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"wheel","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"gid":999,"service":"io.systemd.Home"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"adm","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"systemd-journal","service":"io.systemd.Home"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"systemd-journal","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"gid":998,"service":"io.systemd.Home"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"wheel","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"gid":999,"service":"io.systemd.Home"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"adm","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"systemd-journal","service":"io.systemd.Home"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"systemd-journal","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"gid":998,"service":"io.systemd.Home"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"wheel","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"gid":999,"service":"io.systemd.Home"}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"adm","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:24 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"systemd-journal","service":"io.systemd.Home"}}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"systemd-journal","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"gid":998,"service":"io.systemd.Home"}}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"wheel","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"gid":999,"service":"io.systemd.Home"}}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"adm","service":"io.systemd.Home"},"more":true}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:13:26 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"groupName":"systemd-journal","service":"io.systemd.Home"}}
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"systemd-journal","service":"io.systemd.Home"},"more":true}
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"gid":998,"service":"io.systemd.Home"}}
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"groupName":"wheel","service":"io.systemd.Home"},"more":true}
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method-more
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Sending message: {"parameters":{"userName":"testuser","groupName":"wheel"}}
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processing-method-more → processed-method
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink: New incoming connection.
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink: Connections of user 60143: 0 (of 1024 max)
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Setting state idle-server
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: New incoming message: {"method":"io.systemd.UserDatabase.GetGroupRecord","parameters":{"gid":999,"service":"io.systemd.Home"}}
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → processing-method
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}}
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processing-method → processed-method
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processed-method → idle-server
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Got POLLHUP from socket.
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state idle-server → pending-disconnect
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state pending-disconnect → processing-disconnect
Apr 26 23:14:52 archlinux systemd-homed[696]: varlink-15: Changing state processing-disconnect → disconnected