xmodmap really slow

[Alan Hourihane]

On 30/11/2018 14:48, Olivier Fourdan wrote:
> On Fri, Nov 30, 2018 at 2:38 PM Alan Hourihane <alanh at fairlite.co.uk> wrote:
>> [...]
>> Many thanks for following and providing a patch.
>>
>> Might take me till Monday, but running....
>>
>> xmodmap -pke > /tmp/keydump
>> xmodmap /tmp/keydump
>>
>> Where the last command invokes multi-second delays should be easy to test.
> Unfortunately, I don't see any such slow down here, so I cannot
> reproduce nor test if the change makes any difference.
>
> Yet, several seconds is weird... I mean, even if optimizing that loop
> in ilog2() would be nice, I can't imagine this being the source of
> such long delays...
>
> Can you reproduce with, say, Xephyr? If so maybe try running is strace :
>
>   $ strace -Trttto strace.log Xephyr :12 &
>   $ xmodmap -d :12 -pke > /tmp/keydump
>   $ xmodmap -d :12 /tmp/keydump
>
> That would tell if the Xserver (Xephyr in this case) is spending too
> much time in a syscall, like for example reading a file or something?


Now running strace with Xorg, shows a gazillion entries of....

1543832258.343257 (+     0.000012) recvmsg(51,
1543832258.343278 (+     0.000021) writev(51, [{iov_base=
1543832258.343316 (+     0.000038) writev(51, [{iov_base=
1543832258.343345 (+     0.000028) recvmsg(51,
1543832258.343382 (+     0.000037) writev(51, [{iov_base=
1543832258.343399 (+     0.000016) writev(51, [{iov_base=
1543832258.343415 (+     0.000015) recvmsg(51, {msg_name=
1543832258.343432 (+     0.000017) writev(51, [{iov_base=
1543832258.343446 (+     0.000014) writev(51, [{iov_base=
1543832258.343461 (+     0.000014) recvmsg(51, {msg_name=
1543832258.343477 (+     0.000016) writev(51, [{iov_base=
1543832258.343491 (+     0.000014) recvmsg(51, {msg_name=
1543832258.343513 (+     0.000021) writev(51, [{iov_base=
1543832258.343528 (+     0.000014) writev(51, [{iov_base=
1543832258.343543 (+     0.000015) recvmsg(51, {msg_name=
1543832258.343563 (+     0.000020) writev(51, [{iov_base=
1543832258.343578 (+     0.000014) writev(51, [{iov_base=
1543832258.343595 (+     0.000017) recvmsg(51, {msg_name=
1543832258.343616 (+     0.000021) writev(51, [{iov_base=
1543832258.343631 (+     0.000014) writev(51, [{iov_base=
1543832258.343646 (+     0.000014) recvmsg(51, {msg_name=
1543832258.343662 (+     0.000016) writev(51, [{iov_base=
1543832258.343676 (+     0.000014) writev(51, [{iov_base=
1543832258.343691 (+     0.000014) recvmsg(51, {msg_name=
1543832258.343708 (+     0.000017) writev(51, [{iov_base=
1543832258.343723 (+     0.000014) recvmsg(51, {msg_name=
1543832258.343744 (+     0.000021) writev(51, [{iov_base=
1543832258.343759 (+     0.000014) writev(51, [{iov_base=
1543832258.343774 (+     0.000015) recvmsg(51, {msg_name=

Just grepping for "PC_SUPER_LEVEL2" in shows it appears 248 times...

1543832258.359056 (+     0.000014) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832258.496996 (+     0.000013) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832258.621288 (+     0.000013) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832258.757169 (+     0.000014) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832258.898062 (+     0.000014) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832259.053227 (+     0.000014) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832259.276614 (+     0.000014) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832259.458735 (+     0.000013) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832259.596836 (+     0.000014) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832259.671676 (+     0.000014) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832259.767659 (+     0.000014) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832259.849037 (+     0.000013) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832259.925398 (+     0.000013) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>
1543832259.969188 (+     0.000013) writev(3,
[{iov_base="PC_SUPER_LEVEL2", iov_len=15}, {iov_base="\0", iov_len=1}],
2) = 16 <0.000004>

... and so on

Alan.